0 | 0:00 | DEBUG | Using configuration file PurpleWaveAIIDETournament.config.json
0 | 0:00 | DEBUG | Human: false
0 | 0:00 | DEBUG | Ladder: false
0 | 0:00 | DEBUG | Stream: false
0 | 0:00 | DEBUG | Tournament: true
0 | 0:00 | DEBUG | Round-robin: true
0 | 0:00 | DEBUG | Elimination: false
0 | 0:00 | DEBUG | Debugging: false
0 | 0:00 | DEBUG | Loading BWTA for Python 1.1 at (4)Python.scx
0 | 0:00 | DEBUG | Strategery.Selection.StrategySelectionRecommended@f8e242 has finished recommended strategy phase in game 148 of 5; will fall back to StrategySelectionGreedy
0 | 0:00 | DEBUG | Game start time:  Sat Oct 17 20:01:32 NDT 2020
0 | 0:00 | DEBUG | OS:               Windows 7 6.1 x86
0 | 0:00 | DEBUG | JRE:              Oracle Corporation - 1.8.0_211
0 | 0:00 | DEBUG | CPUs available:   2
0 | 0:00 | DEBUG | System memory:    2147 MB
0 | 0:00 | DEBUG | JVM Max memory:   1037 MB
0 | 0:00 | DEBUG | JVM Total memory: 1037 MB
0 | 0:00 | DEBUG | JVM Free memory:  722 MB
0 | 0:00 | DEBUG | This copy of PurpleWave was packaged for distribution on Mon, Sep 28, 2020 12:17:44 AM
0 | 0:00 | DEBUG | This copy of PurpleWave came from Git revision 82d99bd1f57d158ab68478e9b35c42d521127e1b
0 | 0:00 | DEBUG | JBWAPI autocontinue: true
0 | 0:00 | DEBUG | JBWAPI debugConnection: false
0 | 0:00 | DEBUG | JBWAPI async: true
0 | 0:00 | DEBUG | JBWAPI async unsafe: true
0 | 0:00 | DEBUG | JBWAPI async frame buffer size: 10
0 | 0:00 | DEBUG | JBWAPI unlimited frame zero: true
0 | 0:00 | DEBUG | JBWAPI max frame duration: 30ms
0 | 0:00 | DEBUG | Strategy	WorkersRaze	PvEStormYes	WorkersSpread	WorkersUnite	PvEStormNo	WorkersKill	PvP2Gate1012Goon	PvPRobo	PvPProxy2Gate	PvP2Gate1012DT	PvP4GateGoon	PvP3GateGoon	PvP1ZealotExpand	PvP2GateDTExpand	PvP3rdBaseSlow	PvP3rdBaseFast
0 | 0:00 | DEBUG | #Games	0.0	0.0	0.0	0.0	0.0	0.0	11.0	63.0	8.0	11.0	16.0	9.0	20.0	10.0	130.0	18.0
0 | 0:00 | DEBUG | #Wtd	0.0	0.0	0.0	0.0	0.0	0.0	5.6	30.0	3.0	4.0	5.0	3.1	8.3	3.3	56.7	5.6
0 | 0:00 | DEBUG | #WtdWins	0.0	0.0	0.0	0.0	0.0	0.0	0.9	7.7	0.0	0.3	0.5	0.0	1.3	0.0	10.6	0.0
0 | 0:00 | DEBUG | WinPct	0%%	0%%	0%%	0%%	0%%	0%%	15%%	25%%	0%%	6%%	9%%	0%%	15%%	0%%	18%%	0%%
0 | 0:00 | DEBUG | WinEst	80%%	80%%	80%%	80%%	80%%	80%%	28%%	28%%	26%%	26%%	26%%	25%%	25%%	25%%	20%%	16%%
0 | 0:00 | DEBUG | Strategy interest
0 | 0:00 | DEBUG | 24%% PvP2Gate1012Goon + PvP3rdBaseSlow
0 | 0:00 | DEBUG | 24%% PvP3rdBaseSlow + PvPRobo
0 | 0:00 | DEBUG | 23%% PvP2Gate1012DT + PvP3rdBaseSlow
0 | 0:00 | DEBUG | 22%% PvP3GateGoon + PvP3rdBaseSlow
0 | 0:00 | DEBUG | 22%% PvP1ZealotExpand + PvP3rdBaseSlow
0 | 0:00 | DEBUG | 22%% PvP2GateDTExpand + PvP3rdBaseSlow
0 | 0:00 | DEBUG | 22%% PvP2Gate1012Goon + PvP3rdBaseFast
0 | 0:00 | DEBUG | 21%% PvP3rdBaseFast + PvPRobo
0 | 0:00 | DEBUG | 21%% PvP2Gate1012DT + PvP3rdBaseFast
0 | 0:00 | DEBUG | 20%% PvP3GateGoon + PvP3rdBaseFast
0 | 0:00 | DEBUG | 20%% PvP1ZealotExpand + PvP3rdBaseFast
0 | 0:00 | DEBUG | 20%% PvP2GateDTExpand + PvP3rdBaseFast
0 | 0:00 | DEBUG | Opponents is Stardust
0 | 0:00 | DEBUG | Rush distances is 5152.0, 5600.0, 5216.0, 5280.0
0 | 0:00 | DEBUG | Playbook is Strategery.TournamentPlaybook$@10e4a43
0 | 0:00 | DEBUG | Policy is Strategery.Selection.StrategySelectionTournament$@eb4ad6
0 | 0:00 | DEBUG | Enemy race is Protoss
0 | 0:00 | DEBUG | Strategy is PvP2Gate1012Goon PvP3rdBaseSlow
0 | 0:00 | DEBUG | Our bases is 0
0 | 0:00 | DEBUG | Enemy bases is 0
0 | 0:00 | DEBUG | Our Factories is 0
0 | 0:00 | DEBUG | Our Barracks is 0
0 | 0:00 | DEBUG | Our Gateways is 0
0 | 0:00 | DEBUG | Our Hatcheries is 0
0 | 0:00 | DEBUG | Enemy Factories is 0
0 | 0:00 | DEBUG | Enemy Barracks is 0
0 | 0:00 | DEBUG | Enemy Gateways is 0
0 | 0:00 | DEBUG | Enemy Hatcheries is 0
0 | 0:00 | DEBUG | Safe at home is true
0 | 0:00 | DEBUG | Safe to move out is true
0 | 0:00 | DEBUG | Should attack is false
0 | 0:00 | DEBUG | Status is PvP2Gate1012GoonOrDT
0 | 0:00 | DEBUG | Performance danger is false
1 | 0:00 | DEBUG | Our bases changed from 0 to 1
305 | 0:12 | WARN  | Microing Probe crossed the 55ms threshold by taking 56ms considering 
305 | 0:12 | DEBUG | Task queue took @ 61ms, crossing the 55ms threshold. Task durations: 
TaskMicro: 58ms
TaskBattles: 1ms
TaskSquads: 1ms
TaskPlanning: 6ms
TaskGrids: 1ms
TaskAccounting: 0ms
TaskManners: 0ms
TaskCamera: 0ms
TaskVisualizations: 0ms
624 | 0:26 | WARN  | TaskArchitecture crossed the 55ms threshold, taking 159ms for 171ms total this frame. 
624 | 0:26 | DEBUG | Task queue took @ 171ms, crossing the 55ms threshold. Task durations: 
TaskMicro: 2ms
TaskBattles: 0ms
TaskSquads: 0ms
TaskPlanning: 6ms
TaskGrids: 2ms
TaskFingerprinting: 3ms
TaskGeography: 1ms
TaskAccounting: 0ms
TaskGathering: 0ms
TaskArchitecture: 159ms
TaskManners: 0ms
TaskCamera: 0ms
TaskVisualizations: 0ms
1172 | 0:48 | WARN  | Microing Probe crossed the 55ms threshold by taking 659ms considering 
1172 | 0:48 | DEBUG | Task queue took @ 661ms, crossing the 55ms threshold. Task durations: 
TaskMicro: 660ms
TaskBattles: 1ms
TaskSquads: 0ms
TaskPlanning: 12ms
TaskGrids: 1ms
TaskGeography: 0ms
TaskAccounting: 0ms
TaskGathering: 1ms
TaskManners: 0ms
TaskCamera: 0ms
TaskVisualizations: 0ms
1585 | 1:06 | DEBUG | Discovered novel enemy unit: Probe
1585 | 1:06 | DEBUG | Probe #135 20/20 (20/20) [82, 90] [2648, 2897] projects to arrive in 475 frames at 1:25
1587 | 1:06 | WARN  | TaskGridEnemyRangeAir crossed the 55ms threshold, taking 1860ms for 1876ms total this frame. 
1587 | 1:06 | DEBUG | Task queue took @ 1876ms, crossing the 55ms threshold. Task durations: 
TaskGridUnits: 0ms
TaskGridEnemyDetection: 0ms
TaskGridEnemyRangeAir: 1860ms
TaskGridEnemyRangeGround: 0ms
TaskGridEnemyRangeAirGround: 0ms
TaskGridEnemyVulnerabilityGround: 0ms
TaskGridPsionicStorm: 0ms
TaskGridBuildable: 0ms
TaskGridBuildableTerrain: 0ms
TaskGridEnemyVision: 0ms
TaskGridFriendlyDetection: 0ms
TaskGridFriendlyVision: 0ms
TaskGridPsi2x2and3x2: 0ms
TaskGridPsi4x3: 0ms
TaskGridAltitudeBonus: 0ms
TaskGridBuildableTownHall: 0ms
TaskGridCreepInitial: 0ms
TaskGridCreep: 0ms
TaskGridMobilityBorder: 0ms
TaskGridMobilityTerrain: 0ms
TaskGridScoutingPathBases: 0ms
TaskGridScoutingPathStartLocations: 0ms
TaskGridWalkable: 0ms
TaskGridWalkableTerrain: 0ms
TaskGridUnwalkableUnits: 1ms
1587 | 1:06 | WARN  | TaskGrids crossed the 55ms threshold, taking 1860ms for 1876ms total this frame. 
1587 | 1:06 | DEBUG | Task queue took @ 1876ms, crossing the 55ms threshold. Task durations: 
TaskBattles: 5ms
TaskMicro: 1ms
TaskSquads: 1ms
TaskPlanning: 5ms
TaskFingerprinting: 3ms
TaskGrids: 1860ms
TaskGeography: 1ms
TaskAccounting: 0ms
TaskGathering: 0ms
TaskArchitecture: 5ms
TaskManners: 0ms
TaskCamera: 0ms
TaskVisualizations: 0ms
1975 | 1:22 | WARN  | Microing Probe crossed the 55ms threshold by taking 52ms considering 
1975 | 1:22 | DEBUG | Task queue took @ 56ms, crossing the 55ms threshold. Task durations: 
TaskMicro: 55ms
TaskBattles: 2ms
TaskSquads: 0ms
TaskGrids: 1ms
TaskFingerprinting: 4ms
TaskGeography: 1ms
TaskAccounting: 0ms
TaskGathering: 0ms
TaskArchitecture: 2ms
TaskManners: 0ms
TaskCamera: 0ms
TaskVisualizations: 0ms
1979 | 1:22 | DEBUG | Our Gateways changed from 0 to 1
2011 | 1:23 | DEBUG | Enemy Gateways changed from 0 to 1
2011 | 1:23 | DEBUG | Fingerprints is GatewayFirst
2011 | 1:23 | DEBUG | Discovered novel enemy unit: Gateway
2011 | 1:23 | DEBUG | Gateway #147 76/500 (78/500) [115, 44] [3680, 1424] projects to complete in 846 frames at 1:59
2039 | 1:24 | DEBUG | Enemy bases changed from 0 to 1
2039 | 1:24 | DEBUG | Discovered novel enemy unit: Nexus
2039 | 1:24 | DEBUG | Nexus #10 750/750 (750/750) [119, 41] [3808, 1328] is already complete
2039 | 1:24 | DEBUG | Discovered novel enemy unit: Pylon
2039 | 1:24 | DEBUG | Pylon #141 300/300 (300/300) [116, 42] [3712, 1344] is already complete
2381 | 1:39 | DEBUG | Discovered novel enemy unit: Assimilator
2381 | 1:39 | DEBUG | Assimilator #95 47/450 (47/450) [119, 36] [3808, 1152] projects to complete in -75879 frames at -51:-2
2382 | 1:39 | DEBUG | Fingerprints changed from GatewayFirst to 1GateCore GatewayFirst
2564 | 1:46 | DEBUG | Our Gateways changed from 1 to 2
2956 | 2:03 | DEBUG | Should attack changed from false to true
3797 | 2:38 | DEBUG | Enemy Gateways changed from 1 to 2
3861 | 2:40 | DEBUG | Discovered novel enemy unit: Zealot
3861 | 2:40 | DEBUG | Zealot #156 100/100 (60/60) [119, 58] [3821, 1856] projects to arrive in 1136 frames at 3:28
5154 | 3:34 | DEBUG | Our Gateways changed from 2 to 3
5607 | 3:53 | DEBUG | Fingerprints changed from 1GateCore GatewayFirst to 1GateCore GatewayFirst 2Gate
5609 | 3:53 | DEBUG | Should attack changed from true to false
5610 | 3:53 | DEBUG | Task queue took @ 106ms, crossing the 55ms threshold. Task durations: 
TaskMicro: 103ms
TaskSquads: 2ms
TaskPlanning: 10ms
TaskGrids: 2ms
TaskGeography: 1ms
TaskAccounting: 0ms
TaskGathering: 1ms
TaskManners: 0ms
TaskCamera: 0ms
TaskVisualizations: 0ms
7746 | 5:22 | DEBUG | Our Gateways changed from 3 to 4
8005 | 5:33 | DEBUG | Should attack changed from false to true
8478 | 5:53 | DEBUG | Discovered novel enemy unit: Dragoon
8478 | 5:53 | DEBUG | Dragoon #206 100/100 (80/80) [100, 69] [3224, 2219] projects to arrive in 717 frames at 6:23
8568 | 5:57 | DEBUG | Our bases changed from 1 to 2
8570 | 5:57 | DEBUG | Should attack changed from true to false
8570 | 5:57 | DEBUG | Status changed from PvP2Gate1012GoonOrDT to PvPLateGame
8584 | 5:57 | DEBUG | Our upgrades is Singularity Charge = 1
9373 | 6:30 | DEBUG | Should attack changed from false to true
10756 | 7:28 | DEBUG | Enemy upgrades is Singularity Charge = 1
10757 | 7:28 | DEBUG | Fingerprints changed from 1GateCore GatewayFirst 2Gate to 1GateCore GatewayFirst 2Gate DragoonRange
10812 | 7:30 | DEBUG | Our Gateways changed from 4 to 5
11254 | 7:48 | DEBUG | Safe to move out changed from true to false
11259 | 7:49 | DEBUG | Should attack changed from true to false
12199 | 8:28 | DEBUG | Safe to move out changed from false to true
12199 | 8:28 | DEBUG | Should attack changed from false to true
12586 | 8:44 | DEBUG | Safe to move out changed from true to false
12591 | 8:44 | DEBUG | Should attack changed from true to false
13756 | 9:33 | DEBUG | Our Gateways changed from 5 to 6
13877 | 9:38 | DEBUG | Safe to move out changed from false to true
13879 | 9:38 | DEBUG | Should attack changed from false to true
14500 | 10:04 | DEBUG | Enemy bases changed from 1 to 2
14686 | 10:11 | DEBUG | Discovered novel enemy unit: Photon Cannon
14686 | 10:11 | DEBUG | Photon Cannon #210 100/100 (100/100) [120, 56] [3840, 1792] is already complete
15036 | 10:26 | DEBUG | Safe to move out changed from true to false
15048 | 10:27 | DEBUG | Should attack changed from true to false
15127 | 10:30 | DEBUG | Safe to move out changed from false to true
15132 | 10:30 | DEBUG | Should attack changed from false to true
15473 | 10:44 | DEBUG | Safe to move out changed from true to false
15473 | 10:44 | DEBUG | Should attack changed from true to false
15512 | 10:46 | DEBUG | Safe to move out changed from false to true
15515 | 10:46 | DEBUG | Should attack changed from false to true
16187 | 11:14 | DEBUG | Our Gateways changed from 6 to 7
16499 | 11:27 | WARN  | Microing Dark Templar crossed the 55ms threshold by taking 53ms considering 
16499 | 11:27 | DEBUG | Task queue took @ 57ms, crossing the 55ms threshold. Task durations: 
TaskMicro: 54ms
TaskBattles: 16ms
TaskVisualizations: 0ms
17141 | 11:54 | DEBUG | Our upgrades changed from Singularity Charge = 1 to Singularity Charge = 1, Leg Enhancements = 1
17526 | 12:10 | WARN  | TaskPlanning crossed the 55ms threshold, taking 70ms for 73ms total this frame. The task was overdue to run this frame.
17526 | 12:10 | DEBUG | Task queue took @ 74ms, crossing the 55ms threshold. Task durations: 
TaskPlanning: 70ms
TaskMicro: 9ms
TaskFingerprinting: 0ms
TaskAccounting: 1ms
TaskGathering: 3ms
TaskArchitecture: 2ms
TaskVisualizations: 0ms
17859 | 12:24 | DEBUG | Enemy Gateways changed from 2 to 4
17882 | 12:25 | DEBUG | Our Gateways changed from 7 to 8
17890 | 12:25 | DEBUG | Our Gateways changed from 8 to 9
17912 | 12:26 | DEBUG | Enemy Gateways changed from 4 to 5
17971 | 12:28 | DEBUG | Our Gateways changed from 9 to 10
18242 | 12:40 | WARN  | TaskPlanning crossed the 55ms threshold, taking 56ms for 58ms total this frame. The task was overdue to run this frame.
18242 | 12:40 | DEBUG | Task queue took @ 58ms, crossing the 55ms threshold. Task durations: 
TaskPlanning: 56ms
TaskMicro: 16ms
TaskVisualizations: 0ms
18301 | 12:42 | DEBUG | Discovered novel enemy unit: Observer
18301 | 12:42 | DEBUG | Observer #389 40/40 (20/20) [113, 59] [3628, 1907] projects to arrive in 663 frames at 13:10
18544 | 12:52 | DEBUG | Our bases changed from 2 to 3
19185 | 13:19 | DEBUG | Our techs is Psionic Storm
19186 | 13:19 | WARN  | Microing High Templar crossed the 55ms threshold by taking 42ms considering 
19186 | 13:19 | DEBUG | Task queue took @ 59ms, crossing the 55ms threshold. Task durations: 
TaskMicro: 56ms
TaskBattles: 12ms
TaskVisualizations: 0ms
19868 | 13:47 | WARN  | TaskPlanning crossed the 55ms threshold, taking 57ms for 60ms total this frame. The task was overdue to run this frame.
19868 | 13:47 | DEBUG | Task queue took @ 60ms, crossing the 55ms threshold. Task durations: 
TaskPlanning: 57ms
TaskMicro: 7ms
TaskGrids: 8ms
TaskManners: 0ms
TaskCamera: 0ms
TaskVisualizations: 0ms
20075 | 13:56 | DEBUG | Enemy upgrades changed from Singularity Charge = 1 to Singularity Charge = 1, Protoss Ground Weapons = 1
20295 | 14:05 | DEBUG | Enemy upgrades changed from Singularity Charge = 1, Protoss Ground Weapons = 1 to Singularity Charge = 1, Gravitic Boosters = 1, Protoss Ground Weapons = 1
20446 | 14:11 | DEBUG | Our upgrades changed from Singularity Charge = 1, Leg Enhancements = 1 to Singularity Charge = 1, Leg Enhancements = 1, Protoss Ground Weapons = 1
22858 | 15:52 | WARN  | TaskPlanning crossed the 55ms threshold, taking 55ms for 58ms total this frame. 
22858 | 15:52 | DEBUG | Task queue took @ 58ms, crossing the 55ms threshold. Task durations: 
TaskPlanning: 55ms
TaskMicro: 17ms
TaskVisualizations: 0ms
22989 | 15:57 | WARN  | TaskPlanning crossed the 55ms threshold, taking 59ms for 61ms total this frame. 
22989 | 15:57 | DEBUG | Task queue took @ 61ms, crossing the 55ms threshold. Task durations: 
TaskPlanning: 59ms
TaskMicro: 1ms
TaskSquads: 2ms
TaskGrids: 6ms
TaskFingerprinting: 0ms
TaskGeography: 1ms
TaskAccounting: 1ms
TaskArchitecture: 3ms
TaskManners: 0ms
TaskCamera: 0ms
TaskVisualizations: 0ms
24089 | 16:43 | DEBUG | Enemy upgrades changed from Singularity Charge = 1, Gravitic Boosters = 1, Protoss Ground Weapons = 1 to Singularity Charge = 1, Gravitic Boosters = 1, Protoss Ground Armor = 1, Protoss Ground Weapons = 1
24406 | 16:56 | WARN  | TaskPlanning crossed the 55ms threshold, taking 57ms for 60ms total this frame. The task was overdue to run this frame.
24406 | 16:56 | DEBUG | Task queue took @ 61ms, crossing the 55ms threshold. Task durations: 
TaskPlanning: 57ms
TaskMicro: 20ms
TaskVisualizations: 0ms
24926 | 17:18 | WARN  | TaskPlanning crossed the 55ms threshold, taking 50ms for 57ms total this frame. The task was overdue to run this frame.
24926 | 17:18 | DEBUG | Task queue took @ 58ms, crossing the 55ms threshold. Task durations: 
TaskPlanning: 50ms
TaskMicro: 12ms
TaskFingerprinting: 0ms
TaskGeography: 2ms
TaskAccounting: 0ms
TaskManners: 0ms
TaskCamera: 0ms
TaskVisualizations: 0ms
25634 | 17:48 | DEBUG | Enemy Gateways changed from 5 to 7
25705 | 17:51 | DEBUG | Enemy Gateways changed from 7 to 8
25749 | 17:52 | DEBUG | Enemy Gateways changed from 8 to 9
25802 | 17:55 | WARN  | TaskPlanning crossed the 55ms threshold, taking 50ms for 55ms total this frame. The task was overdue to run this frame.
25802 | 17:55 | DEBUG | Task queue took @ 55ms, crossing the 55ms threshold. Task durations: 
TaskPlanning: 50ms
TaskMicro: 16ms
TaskVisualizations: 0ms
25881 | 17:58 | WARN  | TaskPlanning crossed the 55ms threshold, taking 67ms for 72ms total this frame. The task was overdue to run this frame.
25881 | 17:58 | DEBUG | Task queue took @ 73ms, crossing the 55ms threshold. Task durations: 
TaskPlanning: 67ms
TaskMicro: 18ms
TaskVisualizations: 0ms
26248 | 18:13 | DEBUG | Enemy Gateways changed from 9 to 10
26295 | 18:15 | DEBUG | Enemy bases changed from 2 to 1
26331 | 18:17 | DEBUG | Our bases changed from 3 to 4
26380 | 18:19 | DEBUG | Discovered novel enemy unit: Observatory
26380 | 18:19 | DEBUG | Observatory #376 250/250 (250/250) [110, 42] [3536, 1344] is already complete
26380 | 18:19 | DEBUG | Discovered novel enemy unit: Cybernetics Core
26380 | 18:19 | DEBUG | Cybernetics Core #194 500/500 (500/500) [113, 42] [3632, 1344] is already complete
26410 | 18:20 | DEBUG | Discovered novel enemy unit: Robotics Facility
26410 | 18:20 | DEBUG | Robotics Facility #348 500/500 (500/500) [110, 40] [3536, 1280] is already complete
26410 | 18:20 | DEBUG | Discovered novel enemy unit: Forge
26410 | 18:20 | DEBUG | Forge #199 550/550 (550/550) [113, 40] [3632, 1280] is already complete
26458 | 18:22 | WARN  | TaskPlanning crossed the 55ms threshold, taking 65ms for 69ms total this frame. The task was overdue to run this frame.
26458 | 18:22 | DEBUG | Task queue took @ 69ms, crossing the 55ms threshold. Task durations: 
TaskPlanning: 65ms
TaskMicro: 17ms
TaskVisualizations: 0ms
26541 | 18:25 | DEBUG | Our upgrades changed from Singularity Charge = 1, Leg Enhancements = 1, Protoss Ground Weapons = 1 to Singularity Charge = 1, Leg Enhancements = 1, Protoss Ground Weapons = 2
26600 | 18:28 | WARN  | TaskPlanning crossed the 55ms threshold, taking 54ms for 57ms total this frame. The task was overdue to run this frame.
26600 | 18:28 | DEBUG | Task queue took @ 57ms, crossing the 55ms threshold. Task durations: 
TaskPlanning: 54ms
TaskMicro: 18ms
TaskVisualizations: 0ms
26616 | 18:29 | WARN  | TaskPlanning crossed the 55ms threshold, taking 59ms for 62ms total this frame. The task was overdue to run this frame.
26616 | 18:29 | DEBUG | Task queue took @ 62ms, crossing the 55ms threshold. Task durations: 
TaskPlanning: 59ms
TaskMicro: 21ms
TaskVisualizations: 0ms
27271 | 18:56 | DEBUG | Enemy bases changed from 1 to 0
27278 | 18:56 | WARN  | TaskPlanning crossed the 55ms threshold, taking 61ms for 66ms total this frame. The task was overdue to run this frame.
27278 | 18:56 | DEBUG | Task queue took @ 66ms, crossing the 55ms threshold. Task durations: 
TaskPlanning: 61ms
TaskMicro: 23ms
TaskVisualizations: 0ms
27288 | 18:57 | DEBUG | Enemy Gateways changed from 10 to 9
27489 | 19:05 | DEBUG | Enemy Gateways changed from 9 to 8
27589 | 19:09 | WARN  | TaskPlanning crossed the 55ms threshold, taking 53ms for 60ms total this frame. The task was overdue to run this frame.
27589 | 19:09 | DEBUG | Task queue took @ 61ms, crossing the 55ms threshold. Task durations: 
TaskPlanning: 53ms
TaskMicro: 16ms
TaskVisualizations: 0ms
27625 | 19:11 | DEBUG | Enemy Gateways changed from 8 to 7
27658 | 19:12 | WARN  | TaskPlanning crossed the 55ms threshold, taking 59ms for 65ms total this frame. 
27658 | 19:12 | DEBUG | Task queue took @ 66ms, crossing the 55ms threshold. Task durations: 
TaskPlanning: 59ms
TaskMicro: 3ms
TaskBattles: 8ms
TaskGrids: 1ms
TaskFingerprinting: 0ms
TaskAccounting: 1ms
TaskGathering: 0ms
TaskManners: 0ms
TaskCamera: 0ms
TaskVisualizations: 0ms
27701 | 19:14 | DEBUG | Enemy Gateways changed from 7 to 6
27786 | 19:17 | DEBUG | Enemy Gateways changed from 6 to 5
27825 | 19:19 | WARN  | TaskPlanning crossed the 55ms threshold, taking 55ms for 58ms total this frame. The task was overdue to run this frame.
27825 | 19:19 | DEBUG | Task queue took @ 59ms, crossing the 55ms threshold. Task durations: 
TaskPlanning: 55ms
TaskMicro: 6ms
TaskGrids: 2ms
TaskFingerprinting: 0ms
TaskGeography: 1ms
TaskAccounting: 0ms
TaskGathering: 2ms
TaskArchitecture: 3ms
TaskManners: 0ms
TaskCamera: 0ms
TaskVisualizations: 0ms
27836 | 19:19 | DEBUG | Enemy Gateways changed from 5 to 4
27952 | 19:24 | WARN  | TaskPlanning crossed the 55ms threshold, taking 51ms for 56ms total this frame. The task was overdue to run this frame.
27952 | 19:24 | DEBUG | Task queue took @ 57ms, crossing the 55ms threshold. Task durations: 
TaskPlanning: 51ms
TaskMicro: 16ms
TaskVisualizations: 0ms
28033 | 19:28 | DEBUG | Enemy Gateways changed from 4 to 3
28096 | 19:30 | WARN  | TaskPlanning crossed the 55ms threshold, taking 72ms for 75ms total this frame. The task was overdue to run this frame.
28096 | 19:30 | DEBUG | Task queue took @ 75ms, crossing the 55ms threshold. Task durations: 
TaskPlanning: 72ms
TaskMicro: 17ms
TaskVisualizations: 0ms
28122 | 19:31 | DEBUG | Enemy Gateways changed from 3 to 2
28161 | 19:33 | WARN  | TaskPlanning crossed the 55ms threshold, taking 54ms for 58ms total this frame. 
28161 | 19:33 | DEBUG | Task queue took @ 59ms, crossing the 55ms threshold. Task durations: 
TaskPlanning: 54ms
TaskMicro: 1ms
TaskBattles: 7ms
TaskSquads: 1ms
TaskGrids: 2ms
TaskFingerprinting: 0ms
TaskGeography: 2ms
TaskAccounting: 0ms
TaskGathering: 1ms
TaskArchitecture: 3ms
TaskManners: 0ms
TaskCamera: 0ms
TaskVisualizations: 1ms
28271 | 19:37 | DEBUG | Enemy Gateways changed from 2 to 1
28377 | 19:42 | DEBUG | Enemy Gateways changed from 1 to 0
28429 | 19:44 | DEBUG | Game ended in victory
28429 | 19:44 | DEBUG | Cutoff: 	55ms
Task	Last run	 Run %	Seconds	Avg ms	Max (Recent)	Max (All time)	Extended	Disqualifying
Accounting          		 44%%	1	0	1	9	2	0
Architecture        		 24%%	18	2	4	159	58	1
Battles             		 41%%	101	1	2	33	143	0
Camera              		 38%%	0	0	0	1	0	0
Fingerprinting      		 42%%	24	0	0	14	26	0
Gathering           		 38%%	12	0	1	17	297	0
Geography           		 43%%	17	1	3	15	471	0
Grids               		 39%%	34	2	5	1860	50	1
Manners             		 38%%	0	0	0	1	0	0
Micro               		 64%%	161	8	17	660	2239	6
Planning            		 22%%	81	38	51	72	1419	19
Squads              		 48%%	28	4	14	23	56	0
Visualizations      		 100%%	0	0	0	9	76	0
28429 | 19:44 | DEBUG | Cutoff: 	55ms
Task	Last run	 Run %	Seconds	Avg ms	Max (Recent)	Max (All time)	Extended	Disqualifying
Accounting          		 44%%	1	0	1	9	2	0
Architecture        		 24%%	18	2	4	159	58	1
Battles             		 41%%	101	1	2	33	143	0
Camera              		 38%%	0	0	0	1	0	0
Fingerprinting      		 42%%	24	0	0	14	26	0
Gathering           		 38%%	12	0	1	17	297	0
Geography           		 43%%	17	1	3	15	471	0
Grids               		 39%%	34	2	5	1860	50	1
Manners             		 38%%	0	0	0	1	0	0
Micro               		 64%%	161	8	17	660	2239	6
Planning            		 22%%	81	38	51	72	1419	19
Squads              		 48%%	28	4	14	23	56	0
Visualizations      		 100%%	0	0	0	9	76	0
28429 | 19:44 | DEBUG | Game duration (fastest):    19m 44s
28429 | 19:44 | DEBUG | Game duration (wall clock): 11m 52s
28429 | 19:44 | DEBUG | 
Bot frames over 55ms: 40
Bot frames over 1000ms: 2
Bot frames over 10000ms: 1
28429 | 19:44 | DEBUG | The bot believes its performance, if running synchronously, would be good
28429 | 19:44 | DEBUG | Performance metrics:
Frame duration: After receiving 'frame ready' -> before sending 'frame done':
28,429 samples averaging 21.6 [5.5 - 1,424.6]
>= 5: 28429 samples averaging 21.6
>= 10: 28292 samples averaging 21.6
>= 15: 27124 samples averaging 22
>= 20: 20558 samples averaging 23.2
>= 25: 3112 samples averaging 31
>= 30: 1370 samples averaging 36.4
>= 35: 506 samples averaging 43.8
>= 40: 163 samples averaging 57.7
>= 45: 36 samples averaging 113
>= 50: 14 samples averaging 218
>= 55: 9 samples averaging 310
>= 85: 5 samples averaging 506.1
Frame duration: After receiving 'frame ready' -> after sending 'frame done':
28,429 samples averaging 21.8 [5.6 - 1,424.6]
>= 5: 28429 samples averaging 21.8
>= 10: 28294 samples averaging 21.8
>= 15: 27175 samples averaging 22.2
>= 20: 20850 samples averaging 23.4
>= 25: 3460 samples averaging 31.1
>= 30: 1450 samples averaging 37
>= 35: 647 samples averaging 43
>= 40: 221 samples averaging 54.3
>= 45: 64 samples averaging 84.7
>= 50: 14 samples averaging 219.4
>= 55: 10 samples averaging 285.9
>= 85: 5 samples averaging 508.4
Frame duration: After receiving 'frame ready' -> after sending 'frame done' (Using GetTickCount()):
28,429 samples averaging 21.7 [0 - 1,422]
>= 5: 28165 samples averaging 21.9
>= 10: 28165 samples averaging 21.9
>= 15: 28165 samples averaging 21.9
>= 20: 10746 samples averaging 32.1
>= 25: 10746 samples averaging 32.1
>= 30: 10746 samples averaging 32.1
>= 35: 453 samples averaging 52.1
>= 40: 453 samples averaging 52.1
>= 45: 453 samples averaging 52.1
>= 50: 10 samples averaging 281.2
>= 55: 10 samples averaging 281.2
>= 85: 4 samples averaging 609.5
Frame duration: After receiving 'frame ready' -> receiving next 'frame ready':
28,429 samples averaging 24.5 [7.1 - 1,426.2]
>= 5: 28429 samples averaging 24.5
>= 10: 28407 samples averaging 24.5
>= 15: 27901 samples averaging 24.7
>= 20: 25356 samples averaging 25.4
>= 25: 10062 samples averaging 29
>= 30: 2373 samples averaging 36.6
>= 35: 1039 samples averaging 42.2
>= 40: 407 samples averaging 50
>= 45: 124 samples averaging 68
>= 50: 33 samples averaging 126
>= 55: 18 samples averaging 187.6
>= 85: 5 samples averaging 509.3
Frame duration: After receiving 'frame ready' -> receiving next 'frame ready' (Using GetTickCount()):
28,429 samples averaging 24.5 [0 - 1,422]
>= 5: 28326 samples averaging 24.6
>= 10: 28326 samples averaging 24.6
>= 15: 28326 samples averaging 24.6
>= 20: 15380 samples averaging 32.2
>= 25: 15380 samples averaging 32.2
>= 30: 15380 samples averaging 32.2
>= 35: 758 samples averaging 50.1
>= 40: 758 samples averaging 50.1
>= 45: 758 samples averaging 50.1
>= 50: 16 samples averaging 200.1
>= 55: 16 samples averaging 200.1
>= 85: 4 samples averaging 609.5
BWAPI duration: Before sending 'frame done' -> After receiving 'frame ready':
28,429 samples averaging 2.9 [0.1 - 56]
>= 1: 28428 samples averaging 2.9
>= 3: 9280 samples averaging 4.1
>= 5: 1235 samples averaging 7
>= 10: 114 samples averaging 15.6
>= 15: 41 samples averaging 21.7
>= 20: 18 samples averaging 27.9
>= 30: 5 samples averaging 42.1
BWAPI duration: Before sending 'frame done' -> After sending 'frame done':
28,429 samples averaging 0.2 [0 - 14.8]
>= 1: 1249 samples averaging 2.5
>= 3: 308 samples averaging 3.9
>= 5: 25 samples averaging 7.3
>= 10: 3 samples averaging 12.7
BWAPI duration: Before listening for 'frame ready' -> After receiving 'frame ready':
28,429 samples averaging 2.7 [0 - 55.1]
>= 1: 27421 samples averaging 2.8
>= 3: 8082 samples averaging 4.1
>= 5: 1098 samples averaging 7
>= 10: 92 samples averaging 15.9
>= 15: 34 samples averaging 22.4
>= 20: 15 samples averaging 29.1
>= 30: 5 samples averaging 41.9
Copying frame to buffer:
28,429 samples averaging 1.9 [0.9 - 204.4]
>= 5: 230 samples averaging 10.1
>= 10: 77 samples averaging 16.6
>= 15: 28 samples averaging 24.5
>= 20: 3 samples averaging 83.9
>= 25: 1 samples averaging 204.4
>= 30: 1 samples averaging 204.4
Time holding frame until buffer frees capacity:
1 samples averaging 1,423.4 [1,423.4 - 1,423.4]
>= 0: 1 samples averaging 1,423.4
Frames already buffered when enqueuing a new frame:
28,430 samples averaging 0 [0 - 9]
>= 0: 28430 samples averaging 0
>= 1: 276 samples averaging 1.2
Frames behind real-time when handling events:
28,430 samples averaging 0 [0 - 8]
>= 0: 28430 samples averaging 0
>= 1: 11 samples averaging 4.8
Time flushing side effects:
28,430 samples averaging 0 [0 - 15.9]
>= 1: 14 samples averaging 9.5
>= 3: 12 samples averaging 10.7
>= 5: 11 samples averaging 11.3
Duration of bot event handlers:
28,428 samples averaging 21.1 [0.9 - 1,877]
>= 5: 28417 samples averaging 21.1
>= 10: 28240 samples averaging 21.2
>= 15: 26906 samples averaging 21.6
>= 20: 18973 samples averaging 22.9
>= 25: 2123 samples averaging 33.3
>= 30: 1047 samples averaging 40
>= 35: 556 samples averaging 47.1
>= 40: 277 samples averaging 56.9
>= 45: 132 samples averaging 73.2
>= 50: 69 samples averaging 97.1
>= 55: 39 samples averaging 131.8
>= 85: 5 samples averaging 606.3
Time bot spent idle:
28,430 samples averaging 3.3 [0 - 90.4]
Time client spent waiting for bot:
28,429 samples averaging 19.5 [0 - 640.7]
>= 30: 888 samples averaging 35.4
Excess duration of client sleep:
30,671 samples averaging 0.2 [0 - 612]
>= 1: 1079 samples averaging 5.8
>= 5: 485 samples averaging 10.2
>= 10: 150 samples averaging 17.9
>= 15: 26 samples averaging 48.3
>= 20: 8 samples averaging 121.5
>= 25: 7 samples averaging 135.4
>= 30: 5 samples averaging 178.6
>= 35: 4 samples averaging 215
>= 40: 4 samples averaging 215
>= 45: 4 samples averaging 215
>= 50: 3 samples averaging 270.3
>= 55: 3 samples averaging 270.3
>= 85: 2 samples averaging 376.5
Positive timer discrepancy compared to BWAPI:
16,274 samples averaging 4.9 [1 - 42]
>= 1: 16274 samples averaging 4.9
>= 2: 15304 samples averaging 5.2
>= 3: 14111 samples averaging 5.4
>= 4: 12393 samples averaging 5.8
>= 5: 9337 samples averaging 6.4
>= 10: 627 samples averaging 11.4
>= 15: 26 samples averaging 17.6
>= 20: 3 samples averaging 30.7
>= 25: 2 samples averaging 34.5
>= 30: 1 samples averaging 42
>= 35: 1 samples averaging 42
>= 40: 1 samples averaging 42
Negative timer discrepancy compared to BWAPI:
11,352 samples averaging 8.4 [1 - 25]
>= 1: 11352 samples averaging 8.4
>= 2: 10604 samples averaging 8.9
>= 3: 10060 samples averaging 9.3
>= 4: 9644 samples averaging 9.6
>= 5: 9313 samples averaging 9.8
>= 10: 5636 samples averaging 11.1
>= 15: 141 samples averaging 15.4
>= 20: 1 samples averaging 25
>= 25: 1 samples averaging 25
Number of events received from BWAPI:
28,429 samples averaging 1.3 [0 - 83]
>= 1: 26999 samples averaging 1.3
>= 2: 2813 samples averaging 4.4
>= 3: 2598 samples averaging 4.6
>= 4: 1111 samples averaging 6.6
>= 5: 552 samples averaging 9.3
>= 6: 310 samples averaging 12.6
>= 8: 172 samples averaging 17.5
>= 10: 129 samples averaging 20.4
>= 15: 74 samples averaging 26.7
>= 20: 44 samples averaging 33.7
Number of events received from BWAPI, multiplied by the receive-to-sent duration of that frame:
28,429 samples averaging 28 [0 - 2,692.4]
>= 5: 26999 samples averaging 29.5
>= 10: 26870 samples averaging 29.6
>= 15: 25825 samples averaging 30.3
>= 20: 20069 samples averaging 33.7
>= 25: 5303 samples averaging 67.1
>= 30: 3865 samples averaging 82
>= 35: 3250 samples averaging 91.5
>= 40: 2924 samples averaging 97.5
>= 45: 2678 samples averaging 102.6
>= 50: 2574 samples averaging 104.8
>= 55: 2492 samples averaging 106.5
>= 85: 1040 samples averaging 161.3
Number of events received from BWAPI, multiplied by the receive-to-sent duration of that frame (Using GetTickCount()):
28,429 samples averaging 27.9 [0 - 2,592]
>= 5: 26738 samples averaging 29.7
>= 10: 26738 samples averaging 29.7
>= 15: 26738 samples averaging 29.7
>= 20: 11626 samples averaging 48
>= 25: 11626 samples averaging 48
>= 30: 11626 samples averaging 48
>= 35: 2954 samples averaging 97
>= 40: 2954 samples averaging 97
>= 45: 2954 samples averaging 97
>= 50: 1788 samples averaging 129.7
>= 55: 1788 samples averaging 129.7
>= 85: 1227 samples averaging 158.4