2aw task Poll time.

treeform · January 13, 2009, 4:03am

I have launched a beta of my mmorts build on panda3d engine on Jan11th. Everything went surprisingly well with no server crashes. We did run into some game play balancing issues but i think the release was pretty good with panda3d running well on all computers and taking the heavy load put on it. (except that the mac pro the game fried we don’t talk about)

Any ways we been having occasional lag spikes, when game freezes for a moment and does nothing. The CPU is at zero. The game always seams to correct itself though. After graping the logs i find that the Poll taks for connections has been running abnormally long. Normally server step takes less then a second. But in this case we see that Poll task is taking up to 200 seconds and is always slowly pausing for about 3 seconds:

*Notifier.py:220 :01-02-2009 13:55:02 TaskManager(warning): task Poll the connection reader ran for 6.16 seconds
*Notifier.py:220 :01-02-2009 17:25:40 TaskManager(warning): task Poll the connection reader ran for 3.12 seconds
*Notifier.py:220 :01-02-2009 17:31:20 TaskManager(warning): task Poll the connection reader ran for 4.18 seconds
*Notifier.py:220 :01-02-2009 17:31:47 TaskManager(warning): task Poll the connection reader ran for 4.41 seconds
*Notifier.py:220 :01-02-2009 17:32:37 TaskManager(warning): task Poll the connection reader ran for 3.76 seconds
*Notifier.py:220 :01-02-2009 17:33:52 TaskManager(warning): task Poll the connection reader ran for 6.28 seconds
*Notifier.py:220 :01-02-2009 17:41:43 TaskManager(warning): task Poll the connection reader3  ran for 4.53 seconds
*Notifier.py:220 :01-03-2009 05:22:14 TaskManager(warning): task Poll the connection reader ran for 5.87 seconds
*Notifier.py:220 :01-03-2009 12:07:24 TaskManager(warning): task Poll the connection reader ran for 3.13 seconds
*Notifier.py:220 :01-03-2009 12:21:39 TaskManager(warning): task Poll the connection reader ran for 3.20 seconds
*Notifier.py:220 :01-03-2009 12:54:10 TaskManager(warning): task Poll the connection reader ran for 3.48 seconds
*Notifier.py:220 :01-03-2009 13:36:04 TaskManager(warning): task Poll the connection reader ran for 3.47 seconds
*Notifier.py:220 :01-03-2009 21:54:17 TaskManager(warning): task Poll the connection reader ran for 7.97 seconds
*Notifier.py:220 :01-04-2009 08:05:13 TaskManager(warning): task Poll the connection reader ran for 3.17 seconds
*Notifier.py:220 :01-04-2009 08:05:28 TaskManager(warning): task Poll the connection reader ran for 7.18 seconds
*Notifier.py:220 :01-04-2009 17:13:45 TaskManager(warning): task Poll the connection reader ran for 3.13 seconds
*Notifier.py:220 :01-04-2009 17:25:32 TaskManager(warning): task Poll the connection reader ran for 4.16 seconds
*Notifier.py:220 :01-04-2009 18:12:34 TaskManager(warning): task Poll the connection reader ran for 3.20 seconds
*Notifier.py:220 :01-04-2009 18:36:04 TaskManager(warning): task Poll the connection reader ran for 3.17 seconds
*Notifier.py:220 :01-04-2009 18:42:40 TaskManager(warning): task Poll the connection reader ran for 3.10 seconds
*Notifier.py:220 :01-04-2009 19:36:11 TaskManager(warning): task Poll the connection reader ran for 3.54 seconds
*Notifier.py:220 :01-04-2009 19:40:24 TaskManager(warning): task Poll the connection reader ran for 3.06 seconds
*Notifier.py:220 :01-05-2009 11:24:57 TaskManager(warning): task Poll the connection reader ran for 5.77 seconds
*Notifier.py:220 :01-05-2009 12:06:38 TaskManager(warning): task Poll the connection reader ran for 3.05 seconds
*Notifier.py:220 :01-05-2009 12:19:38 TaskManager(warning): task Poll the connection reader ran for 3.69 seconds
*Notifier.py:220 :01-06-2009 17:31:17 TaskManager(warning): task Poll the connection reader ran for 6.65 seconds
*Notifier.py:220 :01-06-2009 18:36:17 TaskManager(warning): task Poll the connection reader ran for 4.01 seconds
*Notifier.py:220 :01-06-2009 21:30:44 TaskManager(warning): task Poll the connection reader ran for 3.77 seconds
*Notifier.py:220 :01-06-2009 22:30:10 TaskManager(warning): task Poll the connection reader ran for 4.93 seconds
*Notifier.py:220 :01-06-2009 22:35:26 TaskManager(warning): task Poll the connection reader ran for 3.27 seconds
*Notifier.py:220 :01-06-2009 22:36:35 TaskManager(warning): task Poll the connection reader ran for 3.02 seconds
*Notifier.py:220 :01-06-2009 23:11:14 TaskManager(warning): task Poll the connection reader ran for 3.67 seconds
*Notifier.py:220 :01-08-2009 11:45:09 TaskManager(warning): task Poll the connection reader ran for 4.80 seconds
*Notifier.py:220 :01-08-2009 13:02:17 TaskManager(warning): task Poll the connection reader ran for 3.15 seconds
*Notifier.py:220 :01-08-2009 13:33:50 TaskManager(warning): task Poll the connection reader ran for 3.22 seconds
*Notifier.py:220 :01-08-2009 22:13:27 TaskManager(warning): task Poll the connection reader ran for 3.50 seconds
*Notifier.py:220 :01-08-2009 22:57:54 TaskManager(warning): task Poll the connection reader ran for 3.08 seconds
*Notifier.py:220 :01-08-2009 23:15:12 TaskManager(warning): task Poll the connection reader ran for 5.46 seconds
*Notifier.py:220 :01-08-2009 23:33:03 TaskManager(warning): task Poll the connection reader ran for 3.62 seconds
*Notifier.py:220 :01-08-2009 23:33:13 TaskManager(warning): task Poll the connection reader ran for 4.15 seconds
*Notifier.py:220 :01-08-2009 23:39:38 TaskManager(warning): task Poll the connection reader ran for 4.55 seconds
*Notifier.py:220 :01-08-2009 23:46:33 TaskManager(warning): task Poll the connection reader ran for 4.87 seconds
*Notifier.py:220 :01-08-2009 23:46:43 TaskManager(warning): task Poll the connection reader ran for 3.50 seconds
*Notifier.py:220 :01-08-2009 23:50:39 TaskManager(warning): task Poll the connection reader ran for 3.12 seconds
*Notifier.py:220 :01-08-2009 23:51:41 TaskManager(warning): task Poll the connection reader ran for 8.03 seconds
*Notifier.py:220 :01-09-2009 10:23:16 TaskManager(warning): task Poll the connection reader ran for 3.25 seconds
*Notifier.py:220 :01-09-2009 15:41:12 TaskManager(warning): task Poll the connection reader ran for 3.14 seconds
*Notifier.py:220 :01-09-2009 15:44:31 TaskManager(warning): task Poll the connection reader ran for 3.85 seconds
*Notifier.py:220 :01-09-2009 16:32:42 TaskManager(warning): task Poll the connection reader ran for 3.36 seconds
*Notifier.py:220 :01-09-2009 20:31:07 TaskManager(warning): task Poll the connection reader ran for 3.66 seconds
*Notifier.py:220 :01-09-2009 21:39:03 TaskManager(warning): task Poll the connection reader ran for 3.14 seconds
*Notifier.py:220 :01-09-2009 21:54:02 TaskManager(warning): task Poll the connection reader ran for 3.52 seconds
*Notifier.py:220 :01-09-2009 22:40:36 TaskManager(warning): task Poll the connection reader ran for 3.95 seconds
*Notifier.py:220 :01-09-2009 22:40:56 TaskManager(warning): task Poll the connection reader ran for 3.01 seconds
*Notifier.py:220 :01-09-2009 23:40:41 TaskManager(warning): task Poll the connection reader ran for 4.37 seconds
*Notifier.py:220 :01-10-2009 00:13:09 TaskManager(warning): task Poll the connection reader ran for 3.23 seconds
*Notifier.py:220 :01-10-2009 00:14:57 TaskManager(warning): task Poll the connection reader ran for 3.23 seconds
*Notifier.py:220 :01-10-2009 04:41:08 TaskManager(warning): task Poll the connection reader ran for 3.23 seconds
*Notifier.py:220 :01-10-2009 08:10:09 TaskManager(warning): task Poll the connection reader ran for 6.18 seconds
*Notifier.py:220 :01-10-2009 10:13:48 TaskManager(warning): task Poll the connection reader ran for 4.05 seconds
*Notifier.py:220 :01-10-2009 10:14:29 TaskManager(warning): task Poll the connection reader ran for 3.04 seconds
*Notifier.py:220 :01-10-2009 15:00:14 TaskManager(warning): task Poll the connection reader ran for 10.60 seconds
*Notifier.py:220 :01-10-2009 20:45:02 TaskManager(warning): task Poll the connection reader ran for 3.54 seconds
*Notifier.py:220 :01-10-2009 20:46:20 TaskManager(warning): task Poll the connection reader ran for 3.30 seconds
*Notifier.py:220 :01-11-2009 00:10:06 TaskManager(warning): task Poll the connection reader ran for 3.64 seconds
*Notifier.py:220 :01-11-2009 01:35:03 TaskManager(warning): task Poll the connection reader ran for 3.20 seconds
*Notifier.py:220 :01-11-2009 01:35:07 TaskManager(warning): task Poll the connection reader ran for 3.33 seconds
*Notifier.py:220 :01-11-2009 01:40:06 TaskManager(warning): task Poll the connection reader ran for 3.97 seconds
*Notifier.py:220 :01-11-2009 03:43:11 TaskManager(warning): task Poll the connection reader ran for 3.11 seconds
*Notifier.py:220 :01-11-2009 03:50:41 TaskManager(warning): task Poll the connection reader ran for 3.18 seconds
*Notifier.py:220 :01-11-2009 04:42:02 TaskManager(warning): task Poll the connection reader ran for 3.22 seconds
*Notifier.py:220 :01-11-2009 04:58:19 TaskManager(warning): task Poll the connection reader ran for 4.05 seconds
*Notifier.py:220 :01-11-2009 05:04:30 TaskManager(warning): task Poll the connection reader ran for 4.53 seconds
*Notifier.py:220 :01-11-2009 05:06:37 TaskManager(warning): task Poll the connection reader ran for 4.79 seconds
*Notifier.py:220 :01-11-2009 06:00:07 TaskManager(warning): task Poll the connection reader ran for 6.54 seconds
*Notifier.py:220 :01-11-2009 06:11:25 TaskManager(warning): task Poll the connection reader ran for 6.22 seconds
*Notifier.py:220 :01-11-2009 06:26:02 TaskManager(warning): task Poll the connection reader ran for 3.68 seconds
*Notifier.py:220 :01-11-2009 06:37:15 TaskManager(warning): task do updates on zones ran for 5.52 seconds
*Notifier.py:220 :01-11-2009 06:37:56 TaskManager(warning): task do updates on zones ran for 6.80 seconds
*Notifier.py:220 :01-11-2009 06:39:39 TaskManager(warning): task do updates on zones ran for 3.81 seconds
*Notifier.py:220 :01-11-2009 07:10:06 TaskManager(warning): task Poll the connection reader ran for 5.10 seconds
*Notifier.py:220 :01-11-2009 07:15:31 TaskManager(warning): task Poll the connection reader ran for 3.22 seconds
*Notifier.py:220 :01-11-2009 07:40:04 TaskManager(warning): task Poll the connection reader ran for 4.50 seconds
*Notifier.py:220 :01-11-2009 07:50:10 TaskManager(warning): task Poll the connection reader ran for 8.22 seconds
*Notifier.py:220 :01-11-2009 07:56:57 TaskManager(warning): task Poll the connection reader ran for 3.74 seconds
*Notifier.py:220 :01-11-2009 08:09:20 TaskManager(warning): task Poll the connection reader ran for 3.21 seconds
*Notifier.py:220 :01-11-2009 08:09:44 TaskManager(warning): task Poll the connection reader ran for 3.48 seconds
*Notifier.py:220 :01-11-2009 08:10:47 TaskManager(warning): task Poll the connection reader ran for 3.33 seconds
*Notifier.py:220 :01-11-2009 08:15:43 TaskManager(warning): task Poll the connection reader ran for 6.76 seconds
*Notifier.py:220 :01-11-2009 08:15:51 TaskManager(warning): task Poll the connection reader ran for 4.00 seconds
*Notifier.py:220 :01-11-2009 08:19:24 TaskManager(warning): task Poll the connection reader ran for 4.26 seconds
*Notifier.py:220 :01-11-2009 08:22:05 TaskManager(warning): task Poll the connection reader ran for 3.54 seconds
*Notifier.py:220 :01-11-2009 08:27:12 TaskManager(warning): task Poll the connection reader ran for 3.12 seconds
*Notifier.py:220 :01-11-2009 08:27:19 TaskManager(warning): task Poll the connection reader ran for 3.02 seconds
*Notifier.py:220 :01-11-2009 08:36:04 TaskManager(warning): task Poll the connection reader ran for 3.88 seconds
*Notifier.py:220 :01-11-2009 08:44:01 TaskManager(warning): task Poll the connection reader ran for 3.35 seconds
*Notifier.py:220 :01-11-2009 08:50:20 TaskManager(warning): task Poll the connection reader ran for 3.09 seconds
*Notifier.py:220 :01-11-2009 08:57:42 TaskManager(warning): task Poll the connection reader ran for 3.95 seconds
*Notifier.py:220 :01-11-2009 08:59:15 TaskManager(warning): task do updates on zones ran for 5.84 seconds
*Notifier.py:220 :01-11-2009 09:01:42 TaskManager(warning): task Poll the connection reader ran for 5.70 seconds
*Notifier.py:220 :01-11-2009 09:02:44 TaskManager(warning): task do updates on zones ran for 5.76 seconds
*Notifier.py:220 :01-11-2009 09:10:40 TaskManager(warning): task Poll the connection reader ran for 4.07 seconds
*Notifier.py:220 :01-11-2009 09:29:38 TaskManager(warning): task update standing for players ran for 425.22 seconds
*Notifier.py:220 :01-11-2009 09:29:41 TaskManager(warning): task Poll the connection reader ran for 3.18 seconds
*Notifier.py:220 :01-11-2009 09:29:57 TaskManager(warning): task Poll the connection reader ran for 12.60 seconds
*Notifier.py:220 :01-11-2009 09:30:06 TaskManager(warning): task Poll the connection reader ran for 5.43 seconds
*Notifier.py:220 :01-11-2009 09:43:03 TaskManager(warning): task Poll the connection reader ran for 3.39 seconds
*Notifier.py:220 :01-11-2009 10:04:17 TaskManager(warning): task Poll the connection reader ran for 3.03 seconds
*Notifier.py:220 :01-11-2009 10:10:05 TaskManager(warning): task Poll the connection reader ran for 3.95 seconds
*Notifier.py:220 :01-11-2009 10:13:23 TaskManager(warning): task Poll the connection reader ran for 10.03 seconds
*Notifier.py:220 :01-11-2009 10:23:34 TaskManager(warning): task Poll the connection reader ran for 3.86 seconds
*Notifier.py:220 :01-11-2009 10:28:21 TaskManager(warning): task Poll the connection reader ran for 3.48 seconds
*Notifier.py:220 :01-11-2009 10:30:02 TaskManager(warning): task Poll the connection reader ran for 35.85 seconds
*Notifier.py:220 :01-11-2009 10:32:29 TaskManager(warning): task Poll the connection reader ran for 3.02 seconds
*Notifier.py:220 :01-11-2009 10:41:47 TaskManager(warning): task Poll the connection reader ran for 3.19 seconds
*Notifier.py:220 :01-11-2009 11:01:04 TaskManager(warning): task Poll the connection reader ran for 4.80 seconds
*Notifier.py:220 :01-11-2009 11:04:11 TaskManager(warning): task <bound method UsnMilitery.do of <server.ai.stratigic.UsnMilitery instance at 0x2595290>> ran for 6.79 seconds
*Notifier.py:220 :01-11-2009 11:09:55 TaskManager(warning): task Poll the connection reader ran for 3.76 seconds
*Notifier.py:220 :01-11-2009 11:14:49 TaskManager(warning): task Poll the connection reader ran for 3.05 seconds
*Notifier.py:220 :01-11-2009 11:20:19 TaskManager(warning): task Poll the connection reader ran for 3.87 seconds
*Notifier.py:220 :01-11-2009 11:25:22 TaskManager(warning): task Poll the connection reader ran for 27.93 seconds
*Notifier.py:220 :01-11-2009 11:25:37 TaskManager(warning): task Poll the connection reader ran for 8.56 seconds
*Notifier.py:220 :01-11-2009 11:26:40 TaskManager(warning): task Poll the connection reader ran for 3.60 seconds
*Notifier.py:220 :01-11-2009 11:29:59 TaskManager(warning): task Poll the connection reader ran for 5.03 seconds
*Notifier.py:220 :01-11-2009 11:46:16 TaskManager(warning): task Poll the connection reader ran for 5.56 seconds
*Notifier.py:220 :01-11-2009 11:46:58 TaskManager(warning): task Poll the connection reader ran for 23.38 seconds
*Notifier.py:220 :01-11-2009 12:01:35 TaskManager(warning): task Poll the connection reader ran for 3.18 seconds
*Notifier.py:220 :01-11-2009 12:05:30 TaskManager(warning): task Poll the connection reader ran for 4.05 seconds
*Notifier.py:220 :01-11-2009 12:18:17 TaskManager(warning): task Poll the connection reader ran for 9.24 seconds
*Notifier.py:220 :01-11-2009 12:27:30 TaskManager(warning): task Poll the connection reader ran for 5.44 seconds
*Notifier.py:220 :01-11-2009 12:42:31 TaskManager(warning): task Poll the connection reader ran for 3.52 seconds
*Notifier.py:220 :01-11-2009 12:45:12 TaskManager(warning): task Poll the connection reader ran for 3.14 seconds
*Notifier.py:220 :01-11-2009 12:47:08 TaskManager(warning): task do updates on zones ran for 13.24 seconds
*Notifier.py:220 :01-11-2009 12:57:34 TaskManager(warning): task Poll the connection reader ran for 3.29 seconds
*Notifier.py:220 :01-11-2009 13:02:48 TaskManager(warning): task Poll the connection reader ran for 4.84 seconds
*Notifier.py:220 :01-11-2009 13:03:01 TaskManager(warning): task do updates on zones ran for 5.23 seconds
*Notifier.py:220 :01-11-2009 13:11:37 TaskManager(warning): task Poll the connection reader ran for 22.24 seconds
*Notifier.py:220 :01-11-2009 13:15:12 TaskManager(warning): task Poll the connection reader ran for 5.40 seconds
*Notifier.py:220 :01-11-2009 13:15:17 TaskManager(warning): task Poll the connection reader ran for 4.06 seconds
*Notifier.py:220 :01-11-2009 13:18:29 TaskManager(warning): task Poll the connection reader ran for 4.68 seconds
*Notifier.py:220 :01-11-2009 13:20:41 TaskManager(warning): task Poll the connection reader ran for 3.93 seconds
*Notifier.py:220 :01-11-2009 13:21:07 TaskManager(warning): task Poll the connection reader ran for 3.10 seconds
*Notifier.py:220 :01-11-2009 13:26:57 TaskManager(warning): task Poll the connection reader ran for 6.92 seconds
*Notifier.py:220 :01-11-2009 13:37:49 TaskManager(warning): task Poll the connection reader ran for 45.56 seconds
*Notifier.py:220 :01-11-2009 13:38:13 TaskManager(warning): task Poll the connection reader ran for 3.18 seconds
*Notifier.py:220 :01-11-2009 13:48:57 TaskManager(warning): task Poll the connection reader ran for 638.26 seconds
*Notifier.py:220 :01-11-2009 13:58:44 TaskManager(warning): task Poll the connection reader ran for 4.45 seconds
*Notifier.py:220 :01-11-2009 13:58:53 TaskManager(warning): task Poll the connection reader ran for 8.76 seconds
*Notifier.py:220 :01-11-2009 14:00:48 TaskManager(warning): task Poll the connection reader ran for 3.26 seconds
*Notifier.py:220 :01-11-2009 14:04:12 TaskManager(warning): task Poll the connection reader ran for 3.96 seconds
*Notifier.py:220 :01-11-2009 14:11:21 TaskManager(warning): task Poll the connection reader ran for 219.19 seconds
*Notifier.py:220 :01-11-2009 14:11:25 TaskManager(warning): task Poll the connection reader ran for 3.79 seconds
*Notifier.py:220 :01-11-2009 14:11:39 TaskManager(warning): task Poll the connection reader ran for 12.38 seconds
*Notifier.py:220 :01-11-2009 14:19:11 TaskManager(warning): task Poll the connection reader ran for 13.23 seconds
*Notifier.py:220 :01-11-2009 14:31:40 TaskManager(warning): task Poll the connection reader ran for 6.34 seconds
*Notifier.py:220 :01-11-2009 14:36:58 TaskManager(warning): task Poll the connection reader ran for 5.05 seconds
*Notifier.py:220 :01-11-2009 14:39:39 TaskManager(warning): task Poll the connection reader ran for 4.02 seconds
*Notifier.py:220 :01-11-2009 14:47:33 TaskManager(warning): task Poll the connection reader ran for 3.84 seconds
*Notifier.py:220 :01-11-2009 14:47:59 TaskManager(warning): task Poll the connection reader ran for 3.10 seconds
*Notifier.py:220 :01-11-2009 14:55:52 TaskManager(warning): task Poll the connection reader ran for 5.68 seconds
*Notifier.py:220 :01-11-2009 15:01:52 TaskManager(warning): task do updates on zones ran for 287.15 seconds
*Notifier.py:220 :01-11-2009 15:02:03 TaskManager(warning): task Poll the connection reader ran for 9.90 seconds
*Notifier.py:220 :01-11-2009 15:02:08 TaskManager(warning): task Poll the connection reader ran for 4.71 seconds
*Notifier.py:220 :01-11-2009 15:02:12 TaskManager(warning): task Poll the connection reader ran for 3.35 seconds
*Notifier.py:220 :01-11-2009 15:02:39 TaskManager(warning): task Poll the connection reader ran for 3.47 seconds
*Notifier.py:220 :01-11-2009 15:02:47 TaskManager(warning): task Poll the connection reader ran for 3.22 seconds
*Notifier.py:220 :01-11-2009 15:07:03 TaskManager(warning): task Poll the connection reader ran for 4.69 seconds
*Notifier.py:220 :01-11-2009 15:09:12 TaskManager(warning): task Poll the connection reader ran for 3.83 seconds
*Notifier.py:220 :01-11-2009 15:10:07 TaskManager(warning): task Poll the connection reader ran for 4.40 seconds
*Notifier.py:220 :01-11-2009 15:10:39 TaskManager(warning): task Poll the connection reader ran for 3.07 seconds
*Notifier.py:220 :01-11-2009 15:21:35 TaskManager(warning): task Poll the connection reader ran for 3.73 seconds
*Notifier.py:220 :01-11-2009 15:34:35 TaskManager(warning): task Poll the connection reader ran for 259.13 seconds
*Notifier.py:220 :01-11-2009 15:37:49 TaskManager(warning): task Poll the connection reader ran for 20.82 seconds
*Notifier.py:220 :01-11-2009 15:38:47 TaskManager(warning): task Poll the connection reader ran for 17.89 seconds
*Notifier.py:220 :01-11-2009 15:44:01 TaskManager(warning): task Poll the connection reader ran for 35.43 seconds
*Notifier.py:220 :01-11-2009 16:02:26 TaskManager(warning): task Poll the connection reader ran for 3.00 seconds
*Notifier.py:220 :01-11-2009 16:45:05 TaskManager(warning): task Poll the connection reader ran for 4.87 seconds
*Notifier.py:220 :01-11-2009 16:46:21 TaskManager(warning): task Poll the connection reader ran for 3.00 seconds
*Notifier.py:220 :01-11-2009 16:53:02 TaskManager(warning): task Poll the connection reader ran for 3.34 seconds
*Notifier.py:220 :01-11-2009 16:54:09 TaskManager(warning): task Poll the connection reader ran for 3.09 seconds
*Notifier.py:220 :01-11-2009 16:54:12 TaskManager(warning): task Poll the connection reader ran for 3.22 seconds
*Notifier.py:220 :01-11-2009 16:54:17 TaskManager(warning): task Poll the connection reader ran for 3.22 seconds
*Notifier.py:220 :01-11-2009 16:54:20 TaskManager(warning): task Poll the connection reader ran for 3.02 seconds
*Notifier.py:220 :01-11-2009 16:56:06 TaskManager(warning): task do updates on zones ran for 93.31 seconds
*Notifier.py:220 :01-11-2009 16:56:10 TaskManager(warning): task Poll the connection reader ran for 3.36 seconds
*Notifier.py:220 :01-11-2009 16:56:14 TaskManager(warning): task Poll the connection reader ran for 3.08 seconds
*Notifier.py:220 :01-11-2009 16:56:18 TaskManager(warning): task Poll the connection reader ran for 3.25 seconds
*Notifier.py:220 :01-11-2009 16:56:22 TaskManager(warning): task Poll the connection reader ran for 3.16 seconds
*Notifier.py:220 :01-11-2009 16:56:25 TaskManager(warning): task Poll the connection reader ran for 3.00 seconds
*Notifier.py:220 :01-11-2009 16:56:29 TaskManager(warning): task Poll the connection reader ran for 3.02 seconds
*Notifier.py:220 :01-11-2009 16:56:33 TaskManager(warning): task Poll the connection reader ran for 3.27 seconds
*Notifier.py:220 :01-11-2009 16:57:11 TaskManager(warning): task Poll the connection reader ran for 3.04 seconds
*Notifier.py:220 :01-11-2009 17:01:45 TaskManager(warning): task Poll the connection reader ran for 3.68 seconds
*Notifier.py:220 :01-11-2009 17:07:23 TaskManager(warning): task do updates on zones ran for 4.27 seconds
*Notifier.py:220 :01-11-2009 17:12:49 TaskManager(warning): task Poll the connection reader ran for 4.00 seconds
*Notifier.py:220 :01-11-2009 17:17:28 TaskManager(warning): task do updates on zones ran for 37.87 seconds
*Notifier.py:220 :01-11-2009 17:18:06 TaskManager(warning): task Poll the connection reader ran for 6.57 seconds
*Notifier.py:220 :01-11-2009 17:34:24 TaskManager(warning): task Poll the connection reader ran for 3.01 seconds
*Notifier.py:220 :01-11-2009 17:38:21 TaskManager(warning): task Poll the connection reader ran for 6.82 seconds
*Notifier.py:220 :01-11-2009 17:40:44 TaskManager(warning): task Poll the connection reader ran for 3.18 seconds
*Notifier.py:220 :01-11-2009 18:01:51 TaskManager(warning): task Poll the connection reader ran for 3.32 seconds
*Notifier.py:220 :01-11-2009 18:07:46 TaskManager(warning): task Poll the connection reader ran for 3.97 seconds
*Notifier.py:220 :01-11-2009 18:13:59 TaskManager(warning): task Poll the connection reader ran for 20.61 seconds
*Notifier.py:220 :01-11-2009 18:19:26 TaskManager(warning): task do updates on zones ran for 3.62 seconds
*Notifier.py:220 :01-11-2009 18:22:24 TaskManager(warning): task Poll the connection reader ran for 3.36 seconds
*Notifier.py:220 :01-11-2009 18:34:27 TaskManager(warning): task Poll the connection reader ran for 3.82 seconds
*Notifier.py:220 :01-11-2009 18:49:49 TaskManager(warning): task do updates on zones ran for 73.01 seconds
*Notifier.py:220 :01-11-2009 18:52:24 TaskManager(warning): task Poll the connection reader ran for 3.06 seconds
*Notifier.py:220 :01-11-2009 18:54:31 TaskManager(warning): task Poll the connection reader ran for 12.36 seconds
*Notifier.py:220 :01-11-2009 18:59:06 TaskManager(warning): task Poll the connection reader ran for 5.53 seconds
*Notifier.py:220 :01-11-2009 19:00:20 TaskManager(warning): task Poll the connection reader ran for 6.26 seconds
*Notifier.py:220 :01-11-2009 19:15:39 TaskManager(warning): task Poll the connection reader ran for 5.10 seconds
*Notifier.py:220 :01-11-2009 19:17:04 TaskManager(warning): task Poll the connection reader ran for 4.34 seconds
*Notifier.py:220 :01-11-2009 19:17:10 TaskManager(warning): task Poll the connection reader ran for 4.05 seconds
*Notifier.py:220 :01-11-2009 19:24:21 TaskManager(warning): task Poll the connection reader ran for 31.33 seconds
*Notifier.py:220 :01-11-2009 19:26:22 TaskManager(warning): task Poll the connection reader ran for 5.27 seconds
*Notifier.py:220 :01-11-2009 19:35:12 TaskManager(warning): task Poll the connection reader ran for 5.22 seconds
*Notifier.py:220 :01-11-2009 19:38:04 TaskManager(warning): task Poll the connection reader ran for 4.60 seconds
*Notifier.py:220 :01-11-2009 19:42:53 TaskManager(warning): task Poll the connection reader ran for 4.86 seconds
*Notifier.py:220 :01-11-2009 19:44:20 TaskManager(warning): task Poll the connection reader ran for 3.14 seconds
*Notifier.py:220 :01-11-2009 19:48:23 TaskManager(warning): task do updates on zones ran for 4.42 seconds
*Notifier.py:220 :01-11-2009 19:49:19 TaskManager(warning): task Poll the connection reader ran for 3.18 seconds
*Notifier.py:220 :01-11-2009 19:50:11 TaskManager(warning): task Poll the connection reader ran for 9.12 seconds
*Notifier.py:220 :01-11-2009 19:51:03 TaskManager(warning): task Poll the connection reader ran for 3.71 seconds
*Notifier.py:220 :01-11-2009 19:53:36 TaskManager(warning): task Poll the connection reader ran for 11.15 seconds
*Notifier.py:220 :01-11-2009 19:57:31 TaskManager(warning): task Poll the connection reader ran for 183.87 seconds
*Notifier.py:220 :01-11-2009 19:57:43 TaskManager(warning): task Poll the connection reader ran for 9.95 seconds
*Notifier.py:220 :01-11-2009 19:58:25 TaskManager(warning): task do updates on zones ran for 5.23 seconds
*Notifier.py:220 :01-11-2009 19:58:53 TaskManager(warning): task Poll the connection reader ran for 4.42 seconds
*Notifier.py:220 :01-11-2009 20:19:44 TaskManager(warning): task Poll the connection reader ran for 6.95 seconds
*Notifier.py:220 :01-11-2009 20:36:18 TaskManager(warning): task Poll the connection reader ran for 3.21 seconds
*Notifier.py:220 :01-11-2009 20:40:10 TaskManager(warning): task Poll the connection reader ran for 4.48 seconds
*Notifier.py:220 :01-11-2009 20:45:08 TaskManager(warning): task Poll the connection reader ran for 4.86 seconds
*Notifier.py:220 :01-11-2009 20:50:21 TaskManager(warning): task Poll the connection reader ran for 4.39 seconds
*Notifier.py:220 :01-11-2009 20:50:41 TaskManager(warning): task do updates on zones ran for 20.46 seconds
*Notifier.py:220 :01-11-2009 20:50:58 TaskManager(warning): task Poll the connection reader ran for 6.66 seconds
*Notifier.py:220 :01-11-2009 21:09:47 TaskManager(warning): task Poll the connection reader ran for 3.27 seconds
*Notifier.py:220 :01-11-2009 21:22:12 TaskManager(warning): task Poll the connection reader ran for 56.59 seconds
*Notifier.py:220 :01-11-2009 21:27:37 TaskManager(warning): task Poll the connection reader ran for 3.33 seconds
*Notifier.py:220 :01-11-2009 21:28:16 TaskManager(warning): task Poll the connection reader ran for 6.46 seconds
*Notifier.py:220 :01-11-2009 21:32:04 TaskManager(warning): task Poll the connection reader ran for 3.68 seconds
*Notifier.py:220 :01-11-2009 21:36:21 TaskManager(warning): task <bound method AisnMilitery.do of <server.ai.stratigic.AisnMilitery instance at 0x26250e0>> ran for 3.01 seconds
*Notifier.py:220 :01-11-2009 21:40:45 TaskManager(warning): task Poll the connection reader ran for 7.64 seconds
*Notifier.py:220 :01-11-2009 21:41:52 TaskManager(warning): task Poll the connection reader ran for 8.26 seconds
*Notifier.py:220 :01-11-2009 21:42:11 TaskManager(warning): task Poll the connection reader ran for 15.51 seconds
*Notifier.py:220 :01-11-2009 22:05:21 TaskManager(warning): task Poll the connection reader ran for 6.47 seconds
*Notifier.py:220 :01-11-2009 22:16:41 TaskManager(warning): task Poll the connection reader ran for 4.73 seconds
*Notifier.py:220 :01-11-2009 22:29:19 TaskManager(warning): task Poll the connection reader ran for 3.64 seconds
*Notifier.py:220 :01-11-2009 22:31:43 TaskManager(warning): task Poll the connection reader ran for 5.44 seconds
*Notifier.py:220 :01-11-2009 22:36:52 TaskManager(warning): task Poll the connection reader ran for 207.19 seconds
*Notifier.py:220 :01-11-2009 22:36:57 TaskManager(warning): task Poll the connection reader ran for 3.36 seconds
*Notifier.py:220 :01-11-2009 22:37:04 TaskManager(warning): task Poll the connection reader ran for 4.22 seconds
*Notifier.py:220 :01-11-2009 22:40:36 TaskManager(warning): task Poll the connection reader ran for 5.10 seconds
*Notifier.py:220 :01-11-2009 22:47:52 TaskManager(warning): task Poll the connection reader ran for 4.46 seconds
*Notifier.py:220 :01-11-2009 22:50:45 TaskManager(warning): task Poll the connection reader ran for 6.78 seconds
*Notifier.py:220 :01-11-2009 22:53:01 TaskManager(warning): task Poll the connection reader ran for 3.81 seconds
*Notifier.py:220 :01-11-2009 22:54:02 TaskManager(warning): task Poll the connection reader ran for 3.42 seconds
*Notifier.py:220 :01-11-2009 23:01:38 TaskManager(warning): task Poll the connection reader ran for 4.21 seconds
*Notifier.py:220 :01-11-2009 23:03:22 TaskManager(warning): task Poll the connection reader ran for 6.06 seconds
*Notifier.py:220 :01-11-2009 23:05:21 TaskManager(warning): task Poll the connection reader ran for 4.71 seconds
*Notifier.py:220 :01-11-2009 23:19:53 TaskManager(warning): task Poll the connection reader ran for 3.88 seconds
*Notifier.py:220 :01-11-2009 23:21:38 TaskManager(warning): task Poll the connection reader ran for 6.08 seconds
*Notifier.py:220 :01-11-2009 23:23:06 TaskManager(warning): task Poll the connection reader ran for 6.76 seconds
*Notifier.py:220 :01-11-2009 23:25:15 TaskManager(warning): task Poll the connection reader ran for 3.74 seconds
*Notifier.py:220 :01-11-2009 23:31:01 TaskManager(warning): task Poll the connection reader ran for 35.17 seconds
*Notifier.py:220 :01-11-2009 23:38:17 TaskManager(warning): task Poll the connection reader ran for 10.58 seconds
*Notifier.py:220 :01-11-2009 23:44:53 TaskManager(warning): task do updates on zones ran for 8.10 seconds
*Notifier.py:220 :01-11-2009 23:46:12 TaskManager(warning): task Poll the connection reader ran for 7.09 seconds
*Notifier.py:220 :01-11-2009 23:50:05 TaskManager(warning): task Poll the connection reader ran for 4.64 seconds
*Notifier.py:220 :01-11-2009 23:56:27 TaskManager(warning): task do updates on zones ran for 6.50 seconds
*Notifier.py:220 :01-12-2009 00:05:31 TaskManager(warning): task Poll the connection reader ran for 3.29 seconds
*Notifier.py:220 :01-12-2009 00:06:09 TaskManager(warning): task Poll the connection reader ran for 8.25 seconds
*Notifier.py:220 :01-12-2009 00:06:42 TaskManager(warning): task Poll the connection reader ran for 9.54 seconds
*Notifier.py:220 :01-12-2009 00:08:40 TaskManager(warning): task Poll the connection reader ran for 4.59 seconds
*Notifier.py:220 :01-12-2009 00:10:11 TaskManager(warning): task Poll the connection reader ran for 6.93 seconds
*Notifier.py:220 :01-12-2009 00:12:14 TaskManager(warning): task Poll the connection reader ran for 3.61 seconds
*Notifier.py:220 :01-12-2009 00:18:46 TaskManager(warning): task Poll the connection reader ran for 3.16 seconds
*Notifier.py:220 :01-12-2009 00:24:15 TaskManager(warning): task Poll the connection reader ran for 3.23 seconds
*Notifier.py:220 :01-12-2009 00:25:41 TaskManager(warning): task Poll the connection reader ran for 3.24 seconds
*Notifier.py:220 :01-12-2009 00:49:09 TaskManager(warning): task Poll the connection reader ran for 73.66 seconds
*Notifier.py:220 :01-12-2009 00:49:13 TaskManager(warning): task Poll the connection reader ran for 3.96 seconds
*Notifier.py:220 :01-12-2009 00:53:53 TaskManager(warning): task Poll the connection reader ran for 5.62 seconds
*Notifier.py:220 :01-12-2009 00:56:33 TaskManager(warning): task Poll the connection reader ran for 3.16 seconds
*Notifier.py:220 :01-12-2009 01:13:03 TaskManager(warning): task Poll the connection reader ran for 6.95 seconds
*Notifier.py:220 :01-12-2009 01:18:10 TaskManager(warning): task Poll the connection reader ran for 5.99 seconds
*Notifier.py:220 :01-12-2009 01:19:28 TaskManager(warning): task Poll the connection reader ran for 4.38 seconds
*Notifier.py:220 :01-12-2009 01:26:04 TaskManager(warning): task Poll the connection reader ran for 89.59 seconds
*Notifier.py:220 :01-12-2009 01:26:12 TaskManager(warning): task Poll the connection reader ran for 7.16 seconds
*Notifier.py:220 :01-12-2009 01:40:16 TaskManager(warning): task Poll the connection reader ran for 3.46 seconds
*Notifier.py:220 :01-12-2009 01:50:50 TaskManager(warning): task Poll the connection reader ran for 3.13 seconds
*Notifier.py:220 :01-12-2009 02:00:04 TaskManager(warning): task Poll the connection reader ran for 3.12 seconds
*Notifier.py:220 :01-12-2009 02:05:20 TaskManager(warning): task Poll the connection reader ran for 3.51 seconds
*Notifier.py:220 :01-12-2009 02:12:22 TaskManager(warning): task Poll the connection reader ran for 9.72 seconds
*Notifier.py:220 :01-12-2009 02:25:07 TaskManager(warning): task Poll the connection reader ran for 6.39 seconds
*Notifier.py:220 :01-12-2009 02:25:12 TaskManager(warning): task Poll the connection reader ran for 3.61 seconds
*Notifier.py:220 :01-12-2009 02:25:54 TaskManager(warning): task Poll the connection reader ran for 3.38 seconds
*Notifier.py:220 :01-12-2009 02:34:25 TaskManager(warning): task Poll the connection reader ran for 146.88 seconds
*Notifier.py:220 :01-12-2009 02:34:29 TaskManager(warning): task Poll the connection reader ran for 3.13 seconds
*Notifier.py:220 :01-12-2009 02:34:36 TaskManager(warning): task Poll the connection reader ran for 5.14 seconds
*Notifier.py:220 :01-12-2009 02:54:13 TaskManager(warning): task Poll the connection reader ran for 5.45 seconds
*Notifier.py:220 :01-12-2009 03:11:07 TaskManager(warning): task Poll the connection reader ran for 6.26 seconds
*Notifier.py:220 :01-12-2009 03:24:30 TaskManager(warning): task Poll the connection reader ran for 3.92 seconds
*Notifier.py:220 :01-12-2009 03:36:11 TaskManager(warning): task Poll the connection reader ran for 4.25 seconds
*Notifier.py:220 :01-12-2009 04:07:44 TaskManager(warning): task Poll the connection reader ran for 4.08 seconds
*Notifier.py:220 :01-12-2009 04:20:42 TaskManager(warning): task Poll the connection reader ran for 4.28 seconds
*Notifier.py:220 :01-12-2009 04:22:39 TaskManager(warning): task Poll the connection reader ran for 3.26 seconds
*Notifier.py:220 :01-12-2009 04:28:54 TaskManager(warning): task do updates on zones ran for 159.78 seconds
*Notifier.py:220 :01-12-2009 04:29:00 TaskManager(warning): task Poll the connection reader ran for 5.82 seconds
*Notifier.py:220 :01-12-2009 04:29:34 TaskManager(warning): task Poll the connection reader ran for 4.07 seconds
*Notifier.py:220 :01-12-2009 04:31:48 TaskManager(warning): task Poll the connection reader ran for 6.98 seconds
*Notifier.py:220 :01-12-2009 04:35:53 TaskManager(warning): task Poll the connection reader ran for 3.17 seconds
*Notifier.py:220 :01-12-2009 04:38:00 TaskManager(warning): task Poll the connection reader ran for 3.04 seconds
*Notifier.py:220 :01-12-2009 04:39:35 TaskManager(warning): task do updates on zones ran for 3.70 seconds
*Notifier.py:220 :01-12-2009 04:45:47 TaskManager(warning): task Poll the connection reader ran for 4.34 seconds
*Notifier.py:220 :01-12-2009 04:46:02 TaskManager(warning): task Poll the connection reader ran for 3.11 seconds
*Notifier.py:220 :01-12-2009 04:49:09 TaskManager(warning): task Poll the connection reader ran for 3.08 seconds
*Notifier.py:220 :01-12-2009 04:51:36 TaskManager(warning): task Poll the connection reader ran for 5.70 seconds
*Notifier.py:220 :01-12-2009 04:53:14 TaskManager(warning): task Poll the connection reader ran for 11.26 seconds
*Notifier.py:220 :01-12-2009 04:56:04 TaskManager(warning): task Poll the connection reader ran for 3.88 seconds
*Notifier.py:220 :01-12-2009 04:59:57 TaskManager(warning): task Poll the connection reader ran for 4.15 seconds
*Notifier.py:220 :01-12-2009 05:00:30 TaskManager(warning): task Poll the connection reader ran for 3.92 seconds
*Notifier.py:220 :01-12-2009 05:01:37 TaskManager(warning): task Poll the connection reader ran for 6.71 seconds
*Notifier.py:220 :01-12-2009 05:01:59 TaskManager(warning): task Poll the connection reader ran for 3.18 seconds
*Notifier.py:220 :01-12-2009 05:05:40 TaskManager(warning): task Poll the connection reader ran for 4.19 seconds
*Notifier.py:220 :01-12-2009 05:06:14 TaskManager(warning): task Poll the connection reader ran for 3.32 seconds
*Notifier.py:220 :01-12-2009 05:07:05 TaskManager(warning): task Poll the connection reader ran for 12.28 seconds
*Notifier.py:220 :01-12-2009 05:07:16 TaskManager(warning): task Poll the connection reader ran for 7.90 seconds
*Notifier.py:220 :01-12-2009 05:11:53 TaskManager(warning): task Poll the connection reader ran for 6.62 seconds
*Notifier.py:220 :01-12-2009 05:20:06 TaskManager(warning): task Poll the connection reader ran for 3.59 seconds
*Notifier.py:220 :01-12-2009 05:22:05 TaskManager(warning): task Poll the connection reader ran for 62.63 seconds
*Notifier.py:220 :01-12-2009 05:22:09 TaskManager(warning): task Poll the connection reader ran for 3.45 seconds
*Notifier.py:220 :01-12-2009 05:28:37 TaskManager(warning): task Poll the connection reader ran for 5.15 seconds
*Notifier.py:220 :01-12-2009 05:32:46 TaskManager(warning): task Poll the connection reader ran for 6.32 seconds
*Notifier.py:220 :01-12-2009 05:34:51 TaskManager(warning): task Poll the connection reader ran for 4.38 seconds
*Notifier.py:220 :01-12-2009 05:38:01 TaskManager(warning): task Poll the connection reader ran for 3.80 seconds
*Notifier.py:220 :01-12-2009 06:07:27 TaskManager(warning): task Poll the connection reader ran for 5.06 seconds
*Notifier.py:220 :01-12-2009 06:08:55 TaskManager(warning): task Poll the connection reader ran for 3.15 seconds
*Notifier.py:220 :01-12-2009 06:11:54 TaskManager(warning): task Poll the connection reader ran for 5.80 seconds
*Notifier.py:220 :01-12-2009 06:14:47 TaskManager(warning): task Poll the connection reader ran for 9.11 seconds
*Notifier.py:220 :01-12-2009 06:32:25 TaskManager(warning): task Poll the connection reader ran for 3.73 seconds
*Notifier.py:220 :01-12-2009 07:08:55 TaskManager(warning): task Poll the connection reader ran for 9.08 seconds
*Notifier.py:220 :01-12-2009 07:13:47 TaskManager(warning): task Poll the connection reader ran for 4.20 seconds
*Notifier.py:220 :01-12-2009 07:18:40 TaskManager(warning): task Poll the connection reader ran for 7.72 seconds
*Notifier.py:220 :01-12-2009 07:19:44 TaskManager(warning): task Poll the connection reader ran for 3.62 seconds
*Notifier.py:220 :01-12-2009 07:19:48 TaskManager(warning): task Poll the connection reader ran for 3.63 seconds
*Notifier.py:220 :01-12-2009 07:20:17 TaskManager(warning): task Poll the connection reader ran for 6.29 seconds
*Notifier.py:220 :01-12-2009 07:23:49 TaskManager(warning): task Poll the connection reader ran for 156.48 seconds
*Notifier.py:220 :01-12-2009 07:23:53 TaskManager(warning): task Poll the connection reader ran for 4.00 seconds
*Notifier.py:220 :01-12-2009 07:24:02 TaskManager(warning): task Poll the connection reader ran for 3.74 seconds
*Notifier.py:220 :01-12-2009 07:39:39 TaskManager(warning): task Poll the connection reader ran for 3.79 seconds
*Notifier.py:220 :01-12-2009 07:40:20 TaskManager(warning): task Poll the connection reader ran for 7.37 seconds
*Notifier.py:220 :01-12-2009 07:46:09 TaskManager(warning): task Poll the connection reader ran for 3.90 seconds
*Notifier.py:220 :01-12-2009 08:05:08 TaskManager(warning): task Poll the connection reader ran for 3.16 seconds
*Notifier.py:220 :01-12-2009 08:12:38 TaskManager(warning): task Poll the connection reader ran for 4.71 seconds
*Notifier.py:220 :01-12-2009 08:20:22 TaskManager(warning): task Poll the connection reader ran for 46.07 seconds
*Notifier.py:220 :01-12-2009 08:20:26 TaskManager(warning): task Poll the connection reader ran for 4.20 seconds
*Notifier.py:220 :01-12-2009 08:20:49 TaskManager(warning): task Poll the connection reader ran for 3.52 seconds
*Notifier.py:220 :01-12-2009 08:26:44 TaskManager(warning): task Poll the connection reader ran for 5.71 seconds
*Notifier.py:220 :01-12-2009 08:28:24 TaskManager(warning): task Poll the connection reader ran for 6.08 seconds
*Notifier.py:220 :01-12-2009 08:32:10 TaskManager(warning): task Poll the connection reader ran for 4.60 seconds
*Notifier.py:220 :01-12-2009 08:34:52 TaskManager(warning): task Poll the connection reader ran for 5.07 seconds
*Notifier.py:220 :01-12-2009 08:35:29 TaskManager(warning): task Poll the connection reader ran for 3.10 seconds
*Notifier.py:220 :01-12-2009 08:42:46 TaskManager(warning): task Poll the connection reader ran for 3.97 seconds
*Notifier.py:220 :01-12-2009 08:44:51 TaskManager(warning): task Poll the connection reader ran for 4.11 seconds
*Notifier.py:220 :01-12-2009 08:49:34 TaskManager(warning): task Poll the connection reader ran for 4.46 seconds
*Notifier.py:220 :01-12-2009 08:51:51 TaskManager(warning): task Poll the connection reader ran for 13.70 seconds
*Notifier.py:220 :01-12-2009 09:01:46 TaskManager(warning): task Poll the connection reader ran for 11.50 seconds
*Notifier.py:220 :01-12-2009 09:02:50 TaskManager(warning): task Poll the connection reader ran for 3.78 seconds
*Notifier.py:220 :01-12-2009 09:03:38 TaskManager(warning): task Poll the connection reader ran for 3.60 seconds
*Notifier.py:220 :01-12-2009 09:05:09 TaskManager(warning): task Poll the connection reader ran for 4.48 seconds
*Notifier.py:220 :01-12-2009 09:05:14 TaskManager(warning): task Poll the connection reader ran for 4.91 seconds
*Notifier.py:220 :01-12-2009 09:09:29 TaskManager(warning): task Poll the connection reader ran for 4.47 seconds
*Notifier.py:220 :01-12-2009 09:23:40 TaskManager(warning): task do updates on zones ran for 73.50 seconds
*Notifier.py:220 :01-12-2009 09:38:09 TaskManager(warning): task Poll the connection reader ran for 8.16 seconds
*Notifier.py:220 :01-12-2009 09:45:35 TaskManager(warning): task Poll the connection reader ran for 8.16 seconds
*Notifier.py:220 :01-12-2009 09:45:48 TaskManager(warning): task Poll the connection reader ran for 12.88 seconds
*Notifier.py:220 :01-12-2009 09:46:08 TaskManager(warning): task Poll the connection reader ran for 5.66 seconds
*Notifier.py:220 :01-12-2009 09:47:16 TaskManager(warning): task Poll the connection reader ran for 6.40 seconds
*Notifier.py:220 :01-12-2009 09:48:25 TaskManager(warning): task Poll the connection reader ran for 12.38 seconds
*Notifier.py:220 :01-12-2009 09:48:41 TaskManager(warning): task Poll the connection reader ran for 14.47 seconds
*Notifier.py:220 :01-12-2009 09:48:45 TaskManager(warning): task Poll the connection reader ran for 3.88 seconds
*Notifier.py:220 :01-12-2009 09:49:04 TaskManager(warning): task Poll the connection reader ran for 3.22 seconds
*Notifier.py:220 :01-12-2009 09:53:08 TaskManager(warning): task Poll the connection reader ran for 3.18 seconds
*Notifier.py:220 :01-12-2009 10:08:35 TaskManager(warning): task Poll the connection reader ran for 3.62 seconds
*Notifier.py:220 :01-12-2009 11:39:46 TaskManager(warning): task Poll the connection reader ran for 3.02 seconds
*Notifier.py:220 :01-12-2009 12:51:45 TaskManager(warning): task Poll the connection reader ran for 3.36 seconds
*Notifier.py:220 :01-12-2009 12:54:38 TaskManager(warning): task Poll the connection reader ran for 3.23 seconds
*Notifier.py:220 :01-12-2009 15:10:44 TaskManager(warning): task Poll the connection reader ran for 3.03 seconds
*Notifier.py:220 :01-12-2009 15:20:33 TaskManager(warning): task Poll the connection reader ran for 3.22 seconds
*Notifier.py:220 :01-12-2009 15:31:13 TaskManager(warning): task Poll the connection reader ran for 3.22 seconds
*Notifier.py:220 :01-12-2009 15:43:35 TaskManager(warning): task Poll the connection reader ran for 6.77 seconds
*Notifier.py:220 :01-12-2009 15:55:42 TaskManager(warning): task do updates on zones ran for 4.90 seconds
*Notifier.py:220 :01-12-2009 16:00:43 TaskManager(warning): task do updates on zones ran for 8.17 seconds
*Notifier.py:220 :01-12-2009 17:18:45 TaskManager(warning): task Poll the connection reader ran for 3.66 seconds
*Notifier.py:220 :01-12-2009 17:39:50 TaskManager(warning): task do updates on zones ran for 4.46 seconds
*Notifier.py:220 :01-12-2009 17:55:35 TaskManager(warning): task Poll the connection reader ran for 3.32 seconds
*Notifier.py:220 :01-12-2009 18:18:05 TaskManager(warning): task Poll the connection reader ran for 5.19 seconds
*Notifier.py:220 :01-12-2009 18:19:40 TaskManager(warning): task Poll the connection reader ran for 4.14 seconds
*Notifier.py:220 :01-12-2009 18:21:25 TaskManager(warning): task Poll the connection reader ran for 27.38 seconds

This is the code that does the networking:

 def __init__(self,address,map=[]):
        """ 
            address ("hostname",port) 
            map is the message map see pack for more details
                defult is none send only basic types no classes
        """
        self.protocolAddress = None
        self.address = address        
        self.pack = Pack(map)
        self.manager = QueuedConnectionManager()
        self.listener = QueuedConnectionListener(self.manager, 0)
        self.reader = QueuedConnectionReader(self.manager, 0)
        self.writer = ConnectionWriter(self.manager,0)
        self.activeConnections =  {}
        self.backlog=1000 #If we ignore 1,000 connection attempts, something is wrong!
        self.tcpSocket = self.manager.openTCPServerRendezvous(self.address[1],self.backlog)
        self.tcpSocket.setNoDelay(True)
        if self.tcpSocket:
            self.listener.addConnection(self.tcpSocket)        
        else:
            print "there is a server running"
            raise "cant start server becouse one already using the socet "
            raise "    it might just resently crashed and has not relesed the socet yet"
        taskMgr.add(self._listenerPolling,"Poll the connection listener")
        taskMgr.add(self._readerPolling,"Poll the connection reader")
            
    def _listenerPolling(self,tsk):
        """ poll for conections """
        if self.listener.newConnectionAvailable():        
            rendezvous = PointerToConnection()
            netAddress = NetAddress()
            newConnection = PointerToConnection()        
            if self.listener.getNewConnection(rendezvous,netAddress,newConnection):
                newConnection = newConnection.p()
                self.activeConnections[newConnection] = True # Remember connection
                self.reader.addConnection(newConnection) # Begin reading connection
        if self.manager.resetConnectionAvailable():
            connPointer = PointerToConnection()
            self.manager.getResetConnection(connPointer)
            connection = connPointer.p()                   
            if self.activeConnections.has_key(connection):
                del self.activeConnections[connection]
            self.manager.closeConnection(connection)
        return Task.cont

Does any one have any suggestions on improving this? I would think panda3d networking would run great? Maybe trying to use some thing like twisted or racknet is better solution?

drwr · January 13, 2009, 4:34am

Hmm, this is very surprising, especially considering that Panda’s connection system is just a very thin layer on top of the raw OS-level networking. It’s hard to imagine what it could be doing in there to take multiple seconds.

How many connections does your server typically handle at a time?

David

treeform · January 13, 2009, 6:35am

Peek use was 11 beta testers with 8 normal. So about 0-11 connections. Is it something i am not setting? Maybe some debug flags need to be removed? Right now i pass threads at 0 maybe threads need to go up?

drwr · January 13, 2009, 7:11am

What does your _readerPolling method look like?

David

treeform · January 13, 2009, 8:44am

    def _readerPolling(self,tsk):
        """ this will poll for conections """
        if self.reader.dataAvailable():
            datagram=NetDatagram()
            if self.reader.getData(datagram):
                self.protocolAddress = datagram.getConnection()
                data = datagram.getMessage()
                packet = self.pack.unPack(data)
                print packet
                if type(packet) != list or len(packet) != 3:
                    return
                functionName = str(packet[0])
                args = tuple(packet[1])
                krags = dict(packet[2])
                try:
                    self.__getattribute__(functionName)(*args,**krags)
                except:
                    print datagram
                    print packet
                    traceback.print_exc()
                    
        return Task.cont

Oh crap i though “Poll the connection reader ran” was some panda3d internal task. But no its this task right here! I am stupid some times. Maybe some thing really slow going on in there i will optimize it now that i know where it is.

treeform · January 13, 2009, 8:51am

can QueuedConnectionReader.getData be still blocked on read even after the QueuedConnectionReader.dataAvailable() is true?

Hypnos · January 13, 2009, 10:13am

is this task called for each client or is it only called once on the server? i am not avare of the overall structure of your code, but shouldnt you call this task as long as data is available:

while self.reader.dataAvailable(): 
  ...
  #read data
  ...

it may not make a difference to the problem you have. (except if the buffer fills up and causes a delay once it’s full, but that’s just guessing)

treeform · January 13, 2009, 6:46pm

this is called in a task globally on the server.

Hypnos · January 13, 2009, 7:42pm

hmm…

so you have like 20 clients sending data (like 10times a second) -> 200 packages received in a second, versus the 60 times the server reads packages from the socket (assumed the server runs 60 steps in a second)?

drwr · January 13, 2009, 8:10pm

No.

Yeah, I’ll bet you a dollar it’s something in your handler functions, not in the network processing at all.

David

treeform · January 13, 2009, 9:10pm

Yeah i think so too.

Does Disney use python based servers? How is the profiling done on the servers? I can connect pstats when i am running the server locally but pstats cant seem to be reconnected after the server starts like in mid session.

Is there a way to just dump the pstats output in a file for later analyses?

But i probably should just output more timing information in my own logs. Do you have any tips for profiling a server under use?

If you dont mind answering, what is the architecture of Disney’s MMO servers?

Currently mine is just a single server blob. As i would have to transition to multiple boxes i will probably split the server up into “gateway”, “administrative”, and “zone servers.” Gateway is just a broker for the player so that the client would not have to connect to multiple servers. The other servers like chat, galaxy and zones would be connected either just through TCP or some Queue.

drwr · January 13, 2009, 9:19pm

Our servers are a combination of Python and C++; the meat of the game logic is handled by Python code, and we have a C++ layer that just handles the heavy lifting, dispatching millions of messages between the different servers, and managing the database and whatnot.

The Python part of it uses an event-handler loop very similar to what you’ve got. We also have problems with individual tasks that take too much time (and clog up the pipe for everyone else). We use a combination of Panda’s PStats and Python’s profile module to help identify and fix these problems.

You should be able to start up PStats in the middle of a session. You just need to run the command PStatClient.connect(‘host’) on your server; you can create a special message that means to run this command, for instance, and then deliver that message to your server. If you want to dump the PStats output for later analysis, use the text-stats program instead of the graphical pstats.

We have also had good luck with Python’s profile module, once you have used PStats to narrow down a particular poorly-performing function. The profile module is useful to figure out what in the function is taking so long.

David