Skip to content

Instantly share code, notes, and snippets.

@brandonhoughton
Created July 26, 2019 20:17
Show Gist options
  • Save brandonhoughton/69c2a85043471c0043f9c9a003d9bf91 to your computer and use it in GitHub Desktop.
Save brandonhoughton/69c2a85043471c0043f9c9a003d9bf91 to your computer and use it in GitHub Desktop.
logs of when shit goes wrong
</ServerHandlers>
</ServerSection>
<AgentSe
[14:48:00] [EnvServerSocketHandler/INFO]: [STDOUT]: REPLYING WITH: MALMOBUSY
[14:48:01] [EnvServerSocketHandler/INFO]: [STDOUT]: Received from localhost:<MissionInit xmlns="http://ProjectMalmo.microsoft.com" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" SchemaVersion="" PlatformVersion="0.37.0">
<Mission>
<About>
<Summary>MineRLTreechop-v0</Summary>
</About>
<ModSettings>
<MsPerTick>50</MsPerTick>
<!--<PrioritiseOffscreenRendering>true</PrioritiseOffscreenRendering>-->
</ModSettings>
<ServerSection>
<ServerInitialConditions>
<Time>
<!--<StartTime>0</StartTime>-->
<AllowPassageOfTime>false</AllowPassageOfTime>
</Time>
<AllowSpawning>true</AllowSpawning>
</ServerInitialConditions>
<ServerHandlers>
<FileWorldGenerator src="/home/madcowd/workspace/cmu/herobraine/minerl/minerl/env/missions/forest_survival" forceReset="true"/>
<!-- <BiomeGenerator forceReset="true" biome="4"/>-->
<ServerQuitFromTimeUp timeLimitMs="400000"/>
<ServerQuitWhenAnyAgentFinishes/>
</ServerHandlers>
</ServerSection>
<AgentSe
[14:48:01] [EnvServerSocketHandler/INFO]: [STDOUT]: REPLYING WITH: MALMOBUSY
[14:48:02] [Client thread/INFO]: [STDOUT]: CLIENT request state: CREATING_NEW_WORLD
[14:48:02] [Client thread/INFO]: [STDOUT]: CLIENT enter state: CREATING_NEW_WORLD
[14:48:02] [Client thread/INFO]: [STDOUT]: Current directory: /tmp/tmp81zy_rln/Minecraft/run
[14:48:03] [EnvServerSocketHandler/INFO]: [STDOUT]: Received from localhost:<MissionInit xmlns="http://ProjectMalmo.microsoft.com" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" SchemaVersion="" PlatformVersion="0.37.0">
<Mission>
<About>
<Summary>MineRLTreechop-v0</Summary>
</About>
<ModSettings>
<MsPerTick>50</MsPerTick>
<!--<PrioritiseOffscreenRendering>true</PrioritiseOffscreenRendering>-->
</ModSettings>
<ServerSection>
<ServerInitialConditions>
<Time>
<!--<StartTime>0</StartTime>-->
<AllowPassageOfTime>false</AllowPassageOfTime>
</Time>
<AllowSpawning>true</AllowSpawning>
</ServerInitialConditions>
<ServerHandlers>
<FileWorldGenerator src="/home/madcowd/workspace/cmu/herobraine/minerl/minerl/env/missions/forest_survival" forceReset="true"/>
<!-- <BiomeGenerator forceReset="true" biome="4"/>-->
<ServerQuitFromTimeUp timeLimitMs="400000"/>
<ServerQuitWhenAnyAgentFinishes/>
</ServerHandlers>
</ServerSection>
<AgentSe
[14:48:03] [Server thread/INFO]: Starting integrated minecraft server version 1.11.2
[14:48:03] [Server thread/INFO]: Generating keypair
[14:48:03] [EnvServerSocketHandler/INFO]: [STDOUT]: REPLYING WITH: MALMOBUSY
[14:48:03] [Server thread/INFO]: Loading dimension 0 (forest_survival) (net.minecraft.server.integrated.IntegratedServer@23cc3250)
[14:48:03] [Server thread/INFO]: Loading dimension 1 (forest_survival) (net.minecraft.server.integrated.IntegratedServer@23cc3250)
[14:48:03] [Server thread/INFO]: Loading dimension -1 (forest_survival) (net.minecraft.server.integrated.IntegratedServer@23cc3250)
[14:48:03] [Server thread/INFO]: Preparing start region for level 0
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 0
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 0
[14:48:04] [Server thread/INFO]: Changing view distance to 4, from 10
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 1
[14:48:04] [EnvServerSocketHandler/INFO]: [STDOUT]: Received from localhost:<MissionInit xmlns="http://ProjectMalmo.microsoft.com" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" SchemaVersion="" PlatformVersion="0.37.0">
<Mission>
<About>
<Summary>MineRLTreechop-v0</Summary>
</About>
<ModSettings>
<MsPerTick>50</MsPerTick>
<!--<PrioritiseOffscreenRendering>true</PrioritiseOffscreenRendering>-->
</ModSettings>
<ServerSection>
<ServerInitialConditions>
<Time>
<!--<StartTime>0</StartTime>-->
<AllowPassageOfTime>false</AllowPassageOfTime>
</Time>
<AllowSpawning>true</AllowSpawning>
</ServerInitialConditions>
<ServerHandlers>
<FileWorldGenerator src="/home/madcowd/workspace/cmu/herobraine/minerl/minerl/env/missions/forest_survival" forceReset="true"/>
<!-- <BiomeGenerator forceReset="true" biome="4"/>-->
<ServerQuitFromTimeUp timeLimitMs="400000"/>
<ServerQuitWhenAnyAgentFinishes/>
</ServerHandlers>
</ServerSection>
<AgentSe
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 2
[14:48:04] [Client thread/INFO]: Deleting level TEMP_0_0cf53df5-bfc4-4e21-b78c-f902899ca3a8
[14:48:04] [Client thread/INFO]: Attempt 1...
[14:48:04] [EnvServerSocketHandler/INFO]: [STDOUT]: REPLYING WITH: MALMOBUSY
[14:48:04] [Server thread/INFO]: [STDOUT]: SERVER request state: WAITING_FOR_MOD_READY
[14:48:04] [Server thread/INFO]: [STDOUT]: CLIENT request state: WAITING_FOR_SERVER_READY
[14:48:04] [Netty Local Client IO #1/INFO]: Server protocol version 2
[14:48:04] [Netty Server IO #3/INFO]: Client protocol version 2
[14:48:04] [Netty Server IO #3/INFO]: Client attempting to join with 5 mods : minecraft@1.11.2,FML@8.0.99.99,malmomod@0.37.0,forge@13.20.0.2228,mcp@9.19
[14:48:04] [Netty Local Client IO #1/INFO]: [Netty Local Client IO #1] Client side modded connection established
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 3
[14:48:04] [Server thread/INFO]: [STDOUT]: SERVER enter state: WAITING_FOR_MOD_READY
[14:48:04] [Server thread/INFO]: [Server thread] Server side modded connection established
[14:48:04] [Server thread/INFO]: MineRLAgent[local:E:f057498a] logged in with entity id 366 at (-23.10090232557063, 72.38169374121333, 277.7496717180228)
[14:48:04] [Server thread/INFO]: MineRLAgent joined the game
[14:48:04] [Server thread/INFO]: [STDOUT]: SERVER request state: DORMANT
[14:48:04] [Server thread/INFO]: [STDOUT]: SERVER enter state: DORMANT
[14:48:04] [Server thread/INFO]: [STDOUT]: INCOMING MISSION: Received MissionInit directly through ServerStateMachine constructor.
[14:48:04] [Server thread/INFO]: [STDOUT]: Mission received: MineRLTreechop-v0
[14:48:04] [Server thread/INFO]: Received mission: §9MineRLTreechop-v0
[14:48:04] [Server thread/INFO]: Source: §alocalhost
[14:48:04] [Server thread/INFO]: [STDOUT]: SERVER request state: BUILDING_WORLD
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 4
[14:48:04] [Server thread/INFO]: [STDOUT]: SERVER enter state: BUILDING_WORLD
[14:48:04] [Server thread/INFO]: [STDOUT]: SERVER request state: WAITING_FOR_AGENTS_TO_ASSEMBLE
[14:48:04] [Server thread/INFO]: [STDOUT]: SERVER enter state: WAITING_FOR_AGENTS_TO_ASSEMBLE
[14:48:04] [Server thread/INFO]: [STDOUT]: Experiment requires:
[14:48:04] [Server thread/INFO]: [STDOUT]: >>>> MineRLAgent
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 5
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 6
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 7
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 8
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 9
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 10
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 11
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 12
[14:48:05] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 13
[14:48:05] [Server thread/INFO]: Saving and pausing game...
[14:48:05] [Server thread/INFO]: Saving chunks for level 'forest_survival'/Overworld
[14:48:05] [Client thread/INFO]: [CHAT] Received mission: §9MineRLTreechop-v0
[14:48:05] [Client thread/INFO]: [CHAT] Source: §alocalhost
[14:48:05] [Client thread/INFO]: [STDOUT]: CLIENT enter state: WAITING_FOR_SERVER_READY
[14:48:05] [Client thread/INFO]: [STDOUT]: ***Telling server we are ready - MineRLAgent
[14:48:05] [Client thread/INFO]: [STDOUT]: ***Telling server we are ready - MineRLAgent
[14:48:05] [Client thread/INFO]: [STDOUT]: ***Telling server we are ready - MineRLAgent
[14:48:05] [Server thread/INFO]: Saving chunks for level 'forest_survival'/Nether
[14:48:05] [Server thread/INFO]: Saving chunks for level 'forest_survival'/The End
[14:48:05] [EnvServerSocketHandler/INFO]: [STDOUT]: Received from localhost:<MissionInit xmlns="http://ProjectMalmo.microsoft.com" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" SchemaVersion="" PlatformVersion="0.37.0">
<Mission>
<About>
<Summary>MineRLTreechop-v0</Summary>
</About>
<ModSettings>
<MsPerTick>50</MsPerTick>
<!--<PrioritiseOffscreenRendering>true</PrioritiseOffscreenRendering>-->
</ModSettings>
<ServerSection>
<ServerInitialConditions>
<Time>
<!--<StartTime>0</StartTime>-->
<AllowPassageOfTime>false</AllowPassageOfTime>
</Time>
<AllowSpawning>true</AllowSpawning>
</ServerInitialConditions>
<ServerHandlers>
<FileWorldGenerator src="/home/madcowd/workspace/cmu/herobraine/minerl/minerl/env/missions/forest_survival" forceReset="true"/>
<!-- <BiomeGenerator forceReset="true" biome="4"/>-->
<ServerQuitFromTimeUp timeLimitMs="400000"/>
<ServerQuitWhenAnyAgentFinishes/>
</ServerHandlers>
</ServerSection>
<AgentSe
[14:48:05] [EnvServerSocketHandler/INFO]: [STDOUT]: REPLYING WITH: MALMOBUSY
[14:48:05] [Client thread/INFO]: [STDOUT]: CLIENT request state: RUNNING
[14:48:05] [Client thread/INFO]: [STDOUT]: CLIENT enter state: RUNNING
[14:48:05] [Client thread/INFO]: [STDOUT]: Unpausing
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Server thread/INFO]: [STDOUT]: SERVER request state: RUNNING
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Server thread/INFO]: [STDOUT]: SERVER enter state: RUNNING
[14:48:05] [Client thread/INFO]: [CHAT] §l400...
[14:48:05] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 20
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: Server pistol has started firing.
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":17,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":72.38169374121333,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931662}
[14:48:05] [Client thread/INFO]: [STDOUT]: Unpausing
[14:48:05] [Client thread/INFO]: [STDOUT]: CLIENT request state: MISSION_ABORTED
[14:48:05] [Client thread/INFO]: [STDOUT]: CLIENT enter state: MISSION_ABORTED
[14:48:05] [Client thread/INFO]: [STDOUT]: inform the agent
[14:48:05] [Server thread/INFO]: [STDOUT]: SERVER request state: CLEAN_UP
[14:48:05] [Server thread/INFO]: [STDOUT]: SERVER enter state: CLEAN_UP
[14:48:05] [Server thread/INFO]: [STDOUT]: SERVER request state: DORMANT
[14:48:05] [Server thread/INFO]: [STDOUT]: SERVER enter state: DORMANT
[14:48:05] [Client thread/INFO]: [STDOUT]: CLIENT request state: DORMANT
[14:48:05] [Client thread/INFO]: [STDOUT]: CLIENT enter state: DORMANT
[14:48:05] [Client thread/INFO]: [STDOUT]: JETTISONING 0 COMMANDS
[14:48:05] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 27
[14:48:05] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 33
[14:48:05] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 34
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 35
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 36
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 37
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 38
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 39
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 40
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 41
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 42
[14:48:06] [EnvServerSocketHandler/INFO]: [STDOUT]: Received from localhost:<MissionInit xmlns="http://ProjectMalmo.microsoft.com" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" SchemaVersion="" PlatformVersion="0.37.0">
<Mission>
<About>
<Summary>MineRLTreechop-v0</Summary>
</About>
<ModSettings>
<MsPerTick>50</MsPerTick>
<!--<PrioritiseOffscreenRendering>true</PrioritiseOffscreenRendering>-->
</ModSettings>
<ServerSection>
<ServerInitialConditions>
<Time>
<!--<StartTime>0</StartTime>-->
<AllowPassageOfTime>false</AllowPassageOfTime>
</Time>
<AllowSpawning>true</AllowSpawning>
</ServerInitialConditions>
<ServerHandlers>
<FileWorldGenerator src="/home/madcowd/workspace/cmu/herobraine/minerl/minerl/env/missions/forest_survival" forceReset="true"/>
<!-- <BiomeGenerator forceReset="true" biome="4"/>-->
<ServerQuitFromTimeUp timeLimitMs="400000"/>
<ServerQuitWhenAnyAgentFinishes/>
</ServerHandlers>
</ServerSection>
<AgentSe
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 43
[14:48:06] [EnvServerSocketHandler/INFO]: [STDOUT]: REPLYING WITH: MALMOOK
[14:48:06] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <PEEK> Waiting for pistol to fire.
[14:48:06] [Client thread/INFO]: [STDOUT]: Mission received: MineRLTreechop-v0
[14:48:06] [Client thread/INFO]: [STDOUT]: CLIENT request state: CREATING_HANDLERS
[14:48:06] [Client thread/INFO]: [STDOUT]: CLIENT enter state: CREATING_HANDLERS
[14:48:06] [Client thread/INFO]: [STDOUT]: CLIENT request state: EVALUATING_WORLD_REQUIREMENTS
[14:48:06] [Client thread/INFO]: [STDOUT]: CLIENT enter state: EVALUATING_WORLD_REQUIREMENTS
[14:48:06] [Client thread/INFO]: [STDOUT]: CLIENT request state: PAUSING_OLD_SERVER
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 0
[14:48:06] [Client thread/INFO]: [STDOUT]: CLIENT enter state: PAUSING_OLD_SERVER
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 1
[14:48:06] [Server thread/INFO]: Saving and pausing game...
[14:48:06] [Server thread/INFO]: Saving chunks for level 'forest_survival'/Overworld
[14:48:06] [Server thread/INFO]: Saving chunks for level 'forest_survival'/Nether
[14:48:06] [Server thread/INFO]: Saving chunks for level 'forest_survival'/The End
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 2
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 4
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 4
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 5
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 5
[14:48:06] [Client thread/INFO]: [STDOUT]: CLIENT request state: CLOSING_OLD_SERVER
[14:48:06] [Client thread/INFO]: [STDOUT]: CLIENT enter state: CLOSING_OLD_SERVER
[14:48:06] [Client thread/INFO]: [STDOUT]: Unpausing
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 6
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 6
[14:48:06] [Server thread/INFO]: Stopping server
[14:48:06] [Server thread/INFO]: Saving players
[14:48:06] [Server thread/INFO]: MineRLAgent lost connection: TextComponent{text='Disconnected', siblings=[], style=Style{hasParent=false, color=null, bold=null, italic=null, underlined=null, obfuscated=null, clickEvent=null, hoverEvent=null, insertion=null}}
[14:48:06] [Server thread/INFO]: MineRLAgent left the game
[14:48:06] [Server thread/INFO]: Stopping singleplayer server as player logged out
[14:48:06] [Server thread/INFO]: Saving worlds
[14:48:06] [Server thread/INFO]: Saving chunks for level 'forest_survival'/Overworld
[14:48:06] [Server thread/INFO]: Saving chunks for level 'forest_survival'/Nether
[14:48:06] [Server thread/INFO]: Saving chunks for level 'forest_survival'/The End
[14:48:06] [Server thread/INFO]: [STDOUT]: Unpausing
[14:48:07] [Server thread/INFO]: [STDOUT]: Unpausing
[14:48:07] [Server thread/INFO]: [STDOUT]: Unpausing
[14:48:07] [Server thread/INFO]: Unloading dimension 0
[14:48:07] [Server thread/INFO]: Unloading dimension -1
[14:48:07] [Server thread/INFO]: Unloading dimension 1
[14:48:07] [Server thread/INFO]: Applying holder lookups
[14:48:07] [Server thread/INFO]: Holder lookups applied
[14:48:17] [Client thread/INFO]: [STDOUT]: CLIENT request state: CREATING_NEW_WORLD
[14:48:17] [Client thread/INFO]: [STDOUT]: CLIENT enter state: CREATING_NEW_WORLD
[14:48:17] [Client thread/INFO]: [STDOUT]: Current directory: /tmp/tmp81zy_rln/Minecraft/run
[14:48:18] [Server thread/INFO]: Starting integrated minecraft server version 1.11.2
[14:48:18] [Server thread/INFO]: Generating keypair
[14:48:18] [Server thread/INFO]: Loading dimension 0 (forest_survival) (net.minecraft.server.integrated.IntegratedServer@14a621d2)
[14:48:18] [Server thread/INFO]: Loading dimension 1 (forest_survival) (net.minecraft.server.integrated.IntegratedServer@14a621d2)
[14:48:18] [Server thread/INFO]: Loading dimension -1 (forest_survival) (net.minecraft.server.integrated.IntegratedServer@14a621d2)
[14:48:18] [Server thread/INFO]: Preparing start region for level 0
[14:48:18] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 0
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 0
[14:48:19] [Server thread/INFO]: Changing view distance to 4, from 10
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 1
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 2
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 3
[14:48:19] [Client thread/INFO]: Deleting level TEMP_0_b1871d1f-2595-4cdc-8417-71aa3a4c74c7
[14:48:19] [Client thread/INFO]: Attempt 1...
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 4
[14:48:19] [Server thread/INFO]: [STDOUT]: SERVER request state: WAITING_FOR_MOD_READY
[14:48:19] [Server thread/INFO]: [STDOUT]: CLIENT request state: WAITING_FOR_SERVER_READY
[14:48:19] [Server thread/INFO]: [STDOUT]: SERVER enter state: WAITING_FOR_MOD_READY
[14:48:19] [Netty Local Client IO #2/INFO]: Server protocol version 2
[14:48:19] [Netty Server IO #5/INFO]: Client protocol version 2
[14:48:19] [Netty Server IO #5/INFO]: Client attempting to join with 5 mods : minecraft@1.11.2,FML@8.0.99.99,malmomod@0.37.0,forge@13.20.0.2228,mcp@9.19
[14:48:19] [Client thread/INFO]: [STDOUT]: CLIENT enter state: WAITING_FOR_SERVER_READY
[14:48:19] [Netty Local Client IO #2/INFO]: [Netty Local Client IO #2] Client side modded connection established
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 5
[14:48:19] [Server thread/INFO]: [STDOUT]: SERVER request state: DORMANT
[14:48:19] [Server thread/INFO]: [STDOUT]: SERVER enter state: DORMANT
[14:48:19] [Server thread/INFO]: [STDOUT]: INCOMING MISSION: Received MissionInit directly through ServerStateMachine constructor.
[14:48:19] [Server thread/INFO]: [STDOUT]: Mission received: MineRLTreechop-v0
[14:48:19] [Server thread/INFO]: Received mission: §9MineRLTreechop-v0
[14:48:19] [Server thread/INFO]: Source: §alocalhost
[14:48:19] [Server thread/INFO]: [STDOUT]: SERVER request state: BUILDING_WORLD
[14:48:19] [Server thread/INFO]: [Server thread] Server side modded connection established
[14:48:19] [Server thread/INFO]: MineRLAgent[local:E:44bef054] logged in with entity id 549 at (-23.10090232557063, 72.38169374121333, 277.7496717180228)
[14:48:19] [Server thread/INFO]: MineRLAgent joined the game
[14:48:19] [Server thread/INFO]: [STDOUT]: SERVER enter state: BUILDING_WORLD
[14:48:19] [Server thread/INFO]: [STDOUT]: SERVER request state: WAITING_FOR_AGENTS_TO_ASSEMBLE
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 6
[14:48:19] [Server thread/INFO]: [STDOUT]: SERVER enter state: WAITING_FOR_AGENTS_TO_ASSEMBLE
[14:48:19] [Server thread/INFO]: [STDOUT]: Experiment requires:
[14:48:19] [Server thread/INFO]: [STDOUT]: >>>> MineRLAgent
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 7
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 8
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 9
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 10
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 16
[14:48:19] [Client thread/INFO]: [STDOUT]: ***Telling server we are ready - MineRLAgent
[14:48:19] [Client thread/INFO]: [STDOUT]: ***Telling server we are ready - MineRLAgent
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 17
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 18
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 19
[14:48:19] [Client thread/INFO]: [STDOUT]: CLIENT request state: RUNNING
[14:48:19] [Client thread/INFO]: [STDOUT]: CLIENT enter state: RUNNING
[14:48:19] [Client thread/INFO]: [STDOUT]: Unpausing
[14:48:19] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 20
[14:48:20] [Server thread/INFO]: [STDOUT]: SERVER request state: RUNNING
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SERVER enter state: RUNNING
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 21
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 22
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 23
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 24
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 25
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 26
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 27
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 28
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 29
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 30
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 31
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 32
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.33
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.33
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [Client thread/INFO]: [CHAT] §l400...
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: Server pistol has started firing.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.34
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.34
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":30,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":72.38169374121333,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931654}
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.35
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.35
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":31,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":72.38169374121333,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931655}
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <PEEK> Pistol fired!.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <PEEK> Pistol fired!.
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.36
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.36
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":32,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":72.30329373968745,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931656}
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.37
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.37
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":33,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":72.14806173517084,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931657}
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <PEEK> Getting observation.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <PEEK> Observation acquired.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Entering synchronous step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Acquiring lock for synchronous step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock is acquired.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Received: attack 0
back 0
camera 0.0 0.0
forward 0
jump 0
left 0
right 0
sneak 0
sprint 0
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Requesting tick.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Tick request granted.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Waiting for tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.38
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.38
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":34,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":71.91753436625788,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931658}
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> TICK DONE. Getting observation.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Observation received. Getting info.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING INFO: NULL
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":34,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":71.91753436625788,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931658}
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> STATUS false
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Info received..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock released. Writing observation, info, done.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Packets written. Flushing.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Done with step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Entering synchronous step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Acquiring lock for synchronous step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock is acquired.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Received: attack 0
back 0
camera 0.0 0.0
forward 0
jump 0
left 0
right 0
sneak 0
sprint 0
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Requesting tick.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Tick request granted.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Waiting for tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.39
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.39
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":35,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":71.61321753880034,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931659}
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> TICK DONE. Getting observation.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Observation received. Getting info.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING INFO: NULL
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":35,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":71.61321753880034,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931659}
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> STATUS false
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Info received..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock released. Writing observation, info, done.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Packets written. Flushing.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Done with step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Entering synchronous step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Acquiring lock for synchronous step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock is acquired.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Received: attack 0
back 0
camera 0.0 0.0
forward 0
jump 0
left 0
right 0
sneak 0
sprint 0
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Requesting tick.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Tick request granted.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Waiting for tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.40
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.40
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":36,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":71.23658704056169,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931673}
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.41
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.41
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":37,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":70.78908914357827,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931674}
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> TICK DONE. Getting observation.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Observation received. Getting info.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING INFO: NULL
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":37,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":70.78908914357827,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931674}
[14:48:20] [Client thread/INFO]: [CHAT] §l399...
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> STATUS false
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Info received..
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock released. Writing observation, info, done.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Packets written. Flushing.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Done with step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Entering synchronous step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Acquiring lock for synchronous step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock is acquired.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Received: attack 0
back 0
camera 0.0 0.0
forward 0
jump 0
left 0
right 0
sneak 0
sprint 0
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Requesting tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.42
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.42
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":38,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":70.27214119447329,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931675}
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Tick request granted.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Waiting for tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.43
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.43
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":39,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":69.68713219296454,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931676}
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> TICK DONE. Getting observation.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Observation received. Getting info.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING INFO: NULL
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":39,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":69.68713219296454,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931676}
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> STATUS false
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Info received..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock released. Writing observation, info, done.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Packets written. Flushing.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Done with step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Entering synchronous step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Acquiring lock for synchronous step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock is acquired.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Received: attack 0
back 0
camera 0.0 0.0
forward 0
jump 0
left 0
right 0
sneak 0
sprint 0
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Requesting tick.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Tick request granted.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Waiting for tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.44
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.44
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":40,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":69.03542335880192,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931677}
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> TICK DONE. Getting observation.
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Observation received. Getting info.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING INFO: NULL
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":40,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":69.03542335880192,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931677}
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> STATUS false
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Info received..
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock released. Writing observation, info, done.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Packets written. Flushing.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Done with step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <PEEK> Getting observation.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: [ERROR] Video observation is null; please notify the developer.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <PEEK> Observation acquired.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Entering synchronous step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Acquiring lock for synchronous step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock is acquired.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Received: attack 0
back 0
camera 0.0 0.0
forward 0
jump 0
left 0
right 0
sneak 0
sprint 0
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Requesting tick.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Tick request granted.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Waiting for tick.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDERR]: java.lang.NullPointerException
[14:48:21] [EnvServerSocketHandler/INFO]: [STDERR]: at com.microsoft.Malmo.Client.MalmoEnvServer.peek(MalmoEnvServer.java:595)
[14:48:21] [EnvServerSocketHandler/INFO]: [STDERR]: at com.microsoft.Malmo.Client.MalmoEnvServer.access$700(MalmoEnvServer.java:51)
Exception in thread "EnvServerSocketHandler" [14:48:21] [EnvServerSocketHandler/INFO]: [STDERR]: at com.microsoft.Malmo.Client.MalmoEnvServer$1.run(MalmoEnvServer.java:167)
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:21] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.45
[14:48:21] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.45
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":41,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":68.31834868736632,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931678}
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> TICK DONE. Getting observation.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Observation received. Getting info.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING INFO: NULL
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":41,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":68.31834868736632,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931678}
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> STATUS false
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Info received..
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock released. Writing observation, info, done.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Packets written. Flushing.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Done with step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Entering synchronous step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Acquiring lock for synchronous step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock is acquired.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Received: attack 0
back 0
camera 0.0 0.0
forward 0
jump 0
left 0
right 0
sneak 0
sprint 0
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Requesting tick.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Tick request granted.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Waiting for tick.
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:21] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.46
[14:48:21] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.46
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":42,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":67.53721549415644,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931679}
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> TICK DONE. Getting observation.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Observation received. Getting info.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING INFO: NULL
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":42,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":67.53721549415644,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931679}
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> STATUS false
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Info received..
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock released. Writing observation, info, done.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Packets written. Flushing.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Done with step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Entering synchronous step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Acquiring lock for synchronous step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: </ServerHandlers>
</ServerSection>
<AgentSe
[14:48:00] [EnvServerSocketHandler/INFO]: [STDOUT]: REPLYING WITH: MALMOBUSY
[14:48:01] [EnvServerSocketHandler/INFO]: [STDOUT]: Received from localhost:<MissionInit xmlns="http://ProjectMalmo.microsoft.com" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" SchemaVersion="" PlatformVersion="0.37.0">
<Mission>
<About>
<Summary>MineRLTreechop-v0</Summary>
</About>
<ModSettings>
<MsPerTick>50</MsPerTick>
<!--<PrioritiseOffscreenRendering>true</PrioritiseOffscreenRendering>-->
</ModSettings>
<ServerSection>
<ServerInitialConditions>
<Time>
<!--<StartTime>0</StartTime>-->
<AllowPassageOfTime>false</AllowPassageOfTime>
</Time>
<AllowSpawning>true</AllowSpawning>
</ServerInitialConditions>
<ServerHandlers>
<FileWorldGenerator src="/home/madcowd/workspace/cmu/herobraine/minerl/minerl/env/missions/forest_survival" forceReset="true"/>
<!-- <BiomeGenerator forceReset="true" biome="4"/>-->
<ServerQuitFromTimeUp timeLimitMs="400000"/>
<ServerQuitWhenAnyAgentFinishes/>
</ServerHandlers>
</ServerSection>
<AgentSe
[14:48:01] [EnvServerSocketHandler/INFO]: [STDOUT]: REPLYING WITH: MALMOBUSY
[14:48:02] [Client thread/INFO]: [STDOUT]: CLIENT request state: CREATING_NEW_WORLD
[14:48:02] [Client thread/INFO]: [STDOUT]: CLIENT enter state: CREATING_NEW_WORLD
[14:48:02] [Client thread/INFO]: [STDOUT]: Current directory: /tmp/tmp81zy_rln/Minecraft/run
[14:48:03] [EnvServerSocketHandler/INFO]: [STDOUT]: Received from localhost:<MissionInit xmlns="http://ProjectMalmo.microsoft.com" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" SchemaVersion="" PlatformVersion="0.37.0">
<Mission>
<About>
<Summary>MineRLTreechop-v0</Summary>
</About>
<ModSettings>
<MsPerTick>50</MsPerTick>
<!--<PrioritiseOffscreenRendering>true</PrioritiseOffscreenRendering>-->
</ModSettings>
<ServerSection>
<ServerInitialConditions>
<Time>
<!--<StartTime>0</StartTime>-->
<AllowPassageOfTime>false</AllowPassageOfTime>
</Time>
<AllowSpawning>true</AllowSpawning>
</ServerInitialConditions>
<ServerHandlers>
<FileWorldGenerator src="/home/madcowd/workspace/cmu/herobraine/minerl/minerl/env/missions/forest_survival" forceReset="true"/>
<!-- <BiomeGenerator forceReset="true" biome="4"/>-->
<ServerQuitFromTimeUp timeLimitMs="400000"/>
<ServerQuitWhenAnyAgentFinishes/>
</ServerHandlers>
</ServerSection>
<AgentSe
[14:48:03] [Server thread/INFO]: Starting integrated minecraft server version 1.11.2
[14:48:03] [Server thread/INFO]: Generating keypair
[14:48:03] [EnvServerSocketHandler/INFO]: [STDOUT]: REPLYING WITH: MALMOBUSY
[14:48:03] [Server thread/INFO]: Loading dimension 0 (forest_survival) (net.minecraft.server.integrated.IntegratedServer@23cc3250)
[14:48:03] [Server thread/INFO]: Loading dimension 1 (forest_survival) (net.minecraft.server.integrated.IntegratedServer@23cc3250)
[14:48:03] [Server thread/INFO]: Loading dimension -1 (forest_survival) (net.minecraft.server.integrated.IntegratedServer@23cc3250)
[14:48:03] [Server thread/INFO]: Preparing start region for level 0
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 0
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 0
[14:48:04] [Server thread/INFO]: Changing view distance to 4, from 10
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 1
[14:48:04] [EnvServerSocketHandler/INFO]: [STDOUT]: Received from localhost:<MissionInit xmlns="http://ProjectMalmo.microsoft.com" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" SchemaVersion="" PlatformVersion="0.37.0">
<Mission>
<About>
<Summary>MineRLTreechop-v0</Summary>
</About>
<ModSettings>
<MsPerTick>50</MsPerTick>
<!--<PrioritiseOffscreenRendering>true</PrioritiseOffscreenRendering>-->
</ModSettings>
<ServerSection>
<ServerInitialConditions>
<Time>
<!--<StartTime>0</StartTime>-->
<AllowPassageOfTime>false</AllowPassageOfTime>
</Time>
<AllowSpawning>true</AllowSpawning>
</ServerInitialConditions>
<ServerHandlers>
<FileWorldGenerator src="/home/madcowd/workspace/cmu/herobraine/minerl/minerl/env/missions/forest_survival" forceReset="true"/>
<!-- <BiomeGenerator forceReset="true" biome="4"/>-->
<ServerQuitFromTimeUp timeLimitMs="400000"/>
<ServerQuitWhenAnyAgentFinishes/>
</ServerHandlers>
</ServerSection>
<AgentSe
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 2
[14:48:04] [Client thread/INFO]: Deleting level TEMP_0_0cf53df5-bfc4-4e21-b78c-f902899ca3a8
[14:48:04] [Client thread/INFO]: Attempt 1...
[14:48:04] [EnvServerSocketHandler/INFO]: [STDOUT]: REPLYING WITH: MALMOBUSY
[14:48:04] [Server thread/INFO]: [STDOUT]: SERVER request state: WAITING_FOR_MOD_READY
[14:48:04] [Server thread/INFO]: [STDOUT]: CLIENT request state: WAITING_FOR_SERVER_READY
[14:48:04] [Netty Local Client IO #1/INFO]: Server protocol version 2
[14:48:04] [Netty Server IO #3/INFO]: Client protocol version 2
[14:48:04] [Netty Server IO #3/INFO]: Client attempting to join with 5 mods : minecraft@1.11.2,FML@8.0.99.99,malmomod@0.37.0,forge@13.20.0.2228,mcp@9.19
[14:48:04] [Netty Local Client IO #1/INFO]: [Netty Local Client IO #1] Client side modded connection established
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 3
[14:48:04] [Server thread/INFO]: [STDOUT]: SERVER enter state: WAITING_FOR_MOD_READY
[14:48:04] [Server thread/INFO]: [Server thread] Server side modded connection established
[14:48:04] [Server thread/INFO]: MineRLAgent[local:E:f057498a] logged in with entity id 366 at (-23.10090232557063, 72.38169374121333, 277.7496717180228)
[14:48:04] [Server thread/INFO]: MineRLAgent joined the game
[14:48:04] [Server thread/INFO]: [STDOUT]: SERVER request state: DORMANT
[14:48:04] [Server thread/INFO]: [STDOUT]: SERVER enter state: DORMANT
[14:48:04] [Server thread/INFO]: [STDOUT]: INCOMING MISSION: Received MissionInit directly through ServerStateMachine constructor.
[14:48:04] [Server thread/INFO]: [STDOUT]: Mission received: MineRLTreechop-v0
[14:48:04] [Server thread/INFO]: Received mission: §9MineRLTreechop-v0
[14:48:04] [Server thread/INFO]: Source: §alocalhost
[14:48:04] [Server thread/INFO]: [STDOUT]: SERVER request state: BUILDING_WORLD
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 4
[14:48:04] [Server thread/INFO]: [STDOUT]: SERVER enter state: BUILDING_WORLD
[14:48:04] [Server thread/INFO]: [STDOUT]: SERVER request state: WAITING_FOR_AGENTS_TO_ASSEMBLE
[14:48:04] [Server thread/INFO]: [STDOUT]: SERVER enter state: WAITING_FOR_AGENTS_TO_ASSEMBLE
[14:48:04] [Server thread/INFO]: [STDOUT]: Experiment requires:
[14:48:04] [Server thread/INFO]: [STDOUT]: >>>> MineRLAgent
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 5
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 6
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 7
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 8
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 9
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 10
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 11
[14:48:04] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 12
[14:48:05] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 13
[14:48:05] [Server thread/INFO]: Saving and pausing game...
[14:48:05] [Server thread/INFO]: Saving chunks for level 'forest_survival'/Overworld
[14:48:05] [Client thread/INFO]: [CHAT] Received mission: §9MineRLTreechop-v0
[14:48:05] [Client thread/INFO]: [CHAT] Source: §alocalhost
[14:48:05] [Client thread/INFO]: [STDOUT]: CLIENT enter state: WAITING_FOR_SERVER_READY
[14:48:05] [Client thread/INFO]: [STDOUT]: ***Telling server we are ready - MineRLAgent
[14:48:05] [Client thread/INFO]: [STDOUT]: ***Telling server we are ready - MineRLAgent
[14:48:05] [Client thread/INFO]: [STDOUT]: ***Telling server we are ready - MineRLAgent
[14:48:05] [Server thread/INFO]: Saving chunks for level 'forest_survival'/Nether
[14:48:05] [Server thread/INFO]: Saving chunks for level 'forest_survival'/The End
[14:48:05] [EnvServerSocketHandler/INFO]: [STDOUT]: Received from localhost:<MissionInit xmlns="http://ProjectMalmo.microsoft.com" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" SchemaVersion="" PlatformVersion="0.37.0">
<Mission>
<About>
<Summary>MineRLTreechop-v0</Summary>
</About>
<ModSettings>
<MsPerTick>50</MsPerTick>
<!--<PrioritiseOffscreenRendering>true</PrioritiseOffscreenRendering>-->
</ModSettings>
<ServerSection>
<ServerInitialConditions>
<Time>
<!--<StartTime>0</StartTime>-->
<AllowPassageOfTime>false</AllowPassageOfTime>
</Time>
<AllowSpawning>true</AllowSpawning>
</ServerInitialConditions>
<ServerHandlers>
<FileWorldGenerator src="/home/madcowd/workspace/cmu/herobraine/minerl/minerl/env/missions/forest_survival" forceReset="true"/>
<!-- <BiomeGenerator forceReset="true" biome="4"/>-->
<ServerQuitFromTimeUp timeLimitMs="400000"/>
<ServerQuitWhenAnyAgentFinishes/>
</ServerHandlers>
</ServerSection>
<AgentSe
[14:48:05] [EnvServerSocketHandler/INFO]: [STDOUT]: REPLYING WITH: MALMOBUSY
[14:48:05] [Client thread/INFO]: [STDOUT]: CLIENT request state: RUNNING
[14:48:05] [Client thread/INFO]: [STDOUT]: CLIENT enter state: RUNNING
[14:48:05] [Client thread/INFO]: [STDOUT]: Unpausing
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Server thread/INFO]: [STDOUT]: SERVER request state: RUNNING
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Server thread/INFO]: [STDOUT]: SERVER enter state: RUNNING
[14:48:05] [Client thread/INFO]: [CHAT] §l400...
[14:48:05] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 20
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: Server pistol has started firing.
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:05] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":17,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":72.38169374121333,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931662}
[14:48:05] [Client thread/INFO]: [STDOUT]: Unpausing
[14:48:05] [Client thread/INFO]: [STDOUT]: CLIENT request state: MISSION_ABORTED
[14:48:05] [Client thread/INFO]: [STDOUT]: CLIENT enter state: MISSION_ABORTED
[14:48:05] [Client thread/INFO]: [STDOUT]: inform the agent
[14:48:05] [Server thread/INFO]: [STDOUT]: SERVER request state: CLEAN_UP
[14:48:05] [Server thread/INFO]: [STDOUT]: SERVER enter state: CLEAN_UP
[14:48:05] [Server thread/INFO]: [STDOUT]: SERVER request state: DORMANT
[14:48:05] [Server thread/INFO]: [STDOUT]: SERVER enter state: DORMANT
[14:48:05] [Client thread/INFO]: [STDOUT]: CLIENT request state: DORMANT
[14:48:05] [Client thread/INFO]: [STDOUT]: CLIENT enter state: DORMANT
[14:48:05] [Client thread/INFO]: [STDOUT]: JETTISONING 0 COMMANDS
[14:48:05] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 27
[14:48:05] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 33
[14:48:05] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 34
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 35
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 36
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 37
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 38
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 39
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 40
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 41
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 42
[14:48:06] [EnvServerSocketHandler/INFO]: [STDOUT]: Received from localhost:<MissionInit xmlns="http://ProjectMalmo.microsoft.com" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" SchemaVersion="" PlatformVersion="0.37.0">
<Mission>
<About>
<Summary>MineRLTreechop-v0</Summary>
</About>
<ModSettings>
<MsPerTick>50</MsPerTick>
<!--<PrioritiseOffscreenRendering>true</PrioritiseOffscreenRendering>-->
</ModSettings>
<ServerSection>
<ServerInitialConditions>
<Time>
<!--<StartTime>0</StartTime>-->
<AllowPassageOfTime>false</AllowPassageOfTime>
</Time>
<AllowSpawning>true</AllowSpawning>
</ServerInitialConditions>
<ServerHandlers>
<FileWorldGenerator src="/home/madcowd/workspace/cmu/herobraine/minerl/minerl/env/missions/forest_survival" forceReset="true"/>
<!-- <BiomeGenerator forceReset="true" biome="4"/>-->
<ServerQuitFromTimeUp timeLimitMs="400000"/>
<ServerQuitWhenAnyAgentFinishes/>
</ServerHandlers>
</ServerSection>
<AgentSe
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 43
[14:48:06] [EnvServerSocketHandler/INFO]: [STDOUT]: REPLYING WITH: MALMOOK
[14:48:06] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <PEEK> Waiting for pistol to fire.
[14:48:06] [Client thread/INFO]: [STDOUT]: Mission received: MineRLTreechop-v0
[14:48:06] [Client thread/INFO]: [STDOUT]: CLIENT request state: CREATING_HANDLERS
[14:48:06] [Client thread/INFO]: [STDOUT]: CLIENT enter state: CREATING_HANDLERS
[14:48:06] [Client thread/INFO]: [STDOUT]: CLIENT request state: EVALUATING_WORLD_REQUIREMENTS
[14:48:06] [Client thread/INFO]: [STDOUT]: CLIENT enter state: EVALUATING_WORLD_REQUIREMENTS
[14:48:06] [Client thread/INFO]: [STDOUT]: CLIENT request state: PAUSING_OLD_SERVER
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 0
[14:48:06] [Client thread/INFO]: [STDOUT]: CLIENT enter state: PAUSING_OLD_SERVER
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 1
[14:48:06] [Server thread/INFO]: Saving and pausing game...
[14:48:06] [Server thread/INFO]: Saving chunks for level 'forest_survival'/Overworld
[14:48:06] [Server thread/INFO]: Saving chunks for level 'forest_survival'/Nether
[14:48:06] [Server thread/INFO]: Saving chunks for level 'forest_survival'/The End
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 2
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 4
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 4
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 5
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 5
[14:48:06] [Client thread/INFO]: [STDOUT]: CLIENT request state: CLOSING_OLD_SERVER
[14:48:06] [Client thread/INFO]: [STDOUT]: CLIENT enter state: CLOSING_OLD_SERVER
[14:48:06] [Client thread/INFO]: [STDOUT]: Unpausing
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 6
[14:48:06] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 6
[14:48:06] [Server thread/INFO]: Stopping server
[14:48:06] [Server thread/INFO]: Saving players
[14:48:06] [Server thread/INFO]: MineRLAgent lost connection: TextComponent{text='Disconnected', siblings=[], style=Style{hasParent=false, color=null, bold=null, italic=null, underlined=null, obfuscated=null, clickEvent=null, hoverEvent=null, insertion=null}}
[14:48:06] [Server thread/INFO]: MineRLAgent left the game
[14:48:06] [Server thread/INFO]: Stopping singleplayer server as player logged out
[14:48:06] [Server thread/INFO]: Saving worlds
[14:48:06] [Server thread/INFO]: Saving chunks for level 'forest_survival'/Overworld
[14:48:06] [Server thread/INFO]: Saving chunks for level 'forest_survival'/Nether
[14:48:06] [Server thread/INFO]: Saving chunks for level 'forest_survival'/The End
[14:48:06] [Server thread/INFO]: [STDOUT]: Unpausing
[14:48:07] [Server thread/INFO]: [STDOUT]: Unpausing
[14:48:07] [Server thread/INFO]: [STDOUT]: Unpausing
[14:48:07] [Server thread/INFO]: Unloading dimension 0
[14:48:07] [Server thread/INFO]: Unloading dimension -1
[14:48:07] [Server thread/INFO]: Unloading dimension 1
[14:48:07] [Server thread/INFO]: Applying holder lookups
[14:48:07] [Server thread/INFO]: Holder lookups applied
[14:48:17] [Client thread/INFO]: [STDOUT]: CLIENT request state: CREATING_NEW_WORLD
[14:48:17] [Client thread/INFO]: [STDOUT]: CLIENT enter state: CREATING_NEW_WORLD
[14:48:17] [Client thread/INFO]: [STDOUT]: Current directory: /tmp/tmp81zy_rln/Minecraft/run
[14:48:18] [Server thread/INFO]: Starting integrated minecraft server version 1.11.2
[14:48:18] [Server thread/INFO]: Generating keypair
[14:48:18] [Server thread/INFO]: Loading dimension 0 (forest_survival) (net.minecraft.server.integrated.IntegratedServer@14a621d2)
[14:48:18] [Server thread/INFO]: Loading dimension 1 (forest_survival) (net.minecraft.server.integrated.IntegratedServer@14a621d2)
[14:48:18] [Server thread/INFO]: Loading dimension -1 (forest_survival) (net.minecraft.server.integrated.IntegratedServer@14a621d2)
[14:48:18] [Server thread/INFO]: Preparing start region for level 0
[14:48:18] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 0
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 0
[14:48:19] [Server thread/INFO]: Changing view distance to 4, from 10
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 1
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 2
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 3
[14:48:19] [Client thread/INFO]: Deleting level TEMP_0_b1871d1f-2595-4cdc-8417-71aa3a4c74c7
[14:48:19] [Client thread/INFO]: Attempt 1...
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 4
[14:48:19] [Server thread/INFO]: [STDOUT]: SERVER request state: WAITING_FOR_MOD_READY
[14:48:19] [Server thread/INFO]: [STDOUT]: CLIENT request state: WAITING_FOR_SERVER_READY
[14:48:19] [Server thread/INFO]: [STDOUT]: SERVER enter state: WAITING_FOR_MOD_READY
[14:48:19] [Netty Local Client IO #2/INFO]: Server protocol version 2
[14:48:19] [Netty Server IO #5/INFO]: Client protocol version 2
[14:48:19] [Netty Server IO #5/INFO]: Client attempting to join with 5 mods : minecraft@1.11.2,FML@8.0.99.99,malmomod@0.37.0,forge@13.20.0.2228,mcp@9.19
[14:48:19] [Client thread/INFO]: [STDOUT]: CLIENT enter state: WAITING_FOR_SERVER_READY
[14:48:19] [Netty Local Client IO #2/INFO]: [Netty Local Client IO #2] Client side modded connection established
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 5
[14:48:19] [Server thread/INFO]: [STDOUT]: SERVER request state: DORMANT
[14:48:19] [Server thread/INFO]: [STDOUT]: SERVER enter state: DORMANT
[14:48:19] [Server thread/INFO]: [STDOUT]: INCOMING MISSION: Received MissionInit directly through ServerStateMachine constructor.
[14:48:19] [Server thread/INFO]: [STDOUT]: Mission received: MineRLTreechop-v0
[14:48:19] [Server thread/INFO]: Received mission: §9MineRLTreechop-v0
[14:48:19] [Server thread/INFO]: Source: §alocalhost
[14:48:19] [Server thread/INFO]: [STDOUT]: SERVER request state: BUILDING_WORLD
[14:48:19] [Server thread/INFO]: [Server thread] Server side modded connection established
[14:48:19] [Server thread/INFO]: MineRLAgent[local:E:44bef054] logged in with entity id 549 at (-23.10090232557063, 72.38169374121333, 277.7496717180228)
[14:48:19] [Server thread/INFO]: MineRLAgent joined the game
[14:48:19] [Server thread/INFO]: [STDOUT]: SERVER enter state: BUILDING_WORLD
[14:48:19] [Server thread/INFO]: [STDOUT]: SERVER request state: WAITING_FOR_AGENTS_TO_ASSEMBLE
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 6
[14:48:19] [Server thread/INFO]: [STDOUT]: SERVER enter state: WAITING_FOR_AGENTS_TO_ASSEMBLE
[14:48:19] [Server thread/INFO]: [STDOUT]: Experiment requires:
[14:48:19] [Server thread/INFO]: [STDOUT]: >>>> MineRLAgent
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 7
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 8
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 9
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 10
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 16
[14:48:19] [Client thread/INFO]: [STDOUT]: ***Telling server we are ready - MineRLAgent
[14:48:19] [Client thread/INFO]: [STDOUT]: ***Telling server we are ready - MineRLAgent
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 17
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 18
[14:48:19] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 19
[14:48:19] [Client thread/INFO]: [STDOUT]: CLIENT request state: RUNNING
[14:48:19] [Client thread/INFO]: [STDOUT]: CLIENT enter state: RUNNING
[14:48:19] [Client thread/INFO]: [STDOUT]: Unpausing
[14:48:19] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 20
[14:48:20] [Server thread/INFO]: [STDOUT]: SERVER request state: RUNNING
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SERVER enter state: RUNNING
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 21
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 22
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 23
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 24
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 25
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 26
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 27
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 28
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 29
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 30
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 31
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] Regular ticking ! 32
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.33
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.33
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [Client thread/INFO]: [CHAT] §l400...
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: Server pistol has started firing.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.34
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.34
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":30,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":72.38169374121333,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931654}
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.35
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.35
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":31,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":72.38169374121333,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931655}
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <PEEK> Pistol fired!.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <PEEK> Pistol fired!.
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.36
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.36
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":32,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":72.30329373968745,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931656}
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.37
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.37
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":33,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":72.14806173517084,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931657}
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <PEEK> Getting observation.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <PEEK> Observation acquired.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Entering synchronous step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Acquiring lock for synchronous step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock is acquired.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Received: attack 0
back 0
camera 0.0 0.0
forward 0
jump 0
left 0
right 0
sneak 0
sprint 0
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Requesting tick.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Tick request granted.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Waiting for tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.38
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.38
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":34,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":71.91753436625788,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931658}
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> TICK DONE. Getting observation.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Observation received. Getting info.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING INFO: NULL
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":34,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":71.91753436625788,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931658}
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> STATUS false
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Info received..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock released. Writing observation, info, done.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Packets written. Flushing.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Done with step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Entering synchronous step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Acquiring lock for synchronous step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock is acquired.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Received: attack 0
back 0
camera 0.0 0.0
forward 0
jump 0
left 0
right 0
sneak 0
sprint 0
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Requesting tick.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Tick request granted.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Waiting for tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.39
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.39
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":35,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":71.61321753880034,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931659}
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> TICK DONE. Getting observation.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Observation received. Getting info.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING INFO: NULL
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":35,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":71.61321753880034,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931659}
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> STATUS false
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Info received..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock released. Writing observation, info, done.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Packets written. Flushing.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Done with step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Entering synchronous step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Acquiring lock for synchronous step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock is acquired.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Received: attack 0
back 0
camera 0.0 0.0
forward 0
jump 0
left 0
right 0
sneak 0
sprint 0
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Requesting tick.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Tick request granted.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Waiting for tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.40
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.40
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":36,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":71.23658704056169,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931673}
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.41
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.41
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":37,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":70.78908914357827,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931674}
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> TICK DONE. Getting observation.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Observation received. Getting info.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING INFO: NULL
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":37,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":70.78908914357827,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931674}
[14:48:20] [Client thread/INFO]: [CHAT] §l399...
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> STATUS false
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Info received..
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock released. Writing observation, info, done.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Packets written. Flushing.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Done with step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Entering synchronous step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Acquiring lock for synchronous step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock is acquired.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Received: attack 0
back 0
camera 0.0 0.0
forward 0
jump 0
left 0
right 0
sneak 0
sprint 0
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Requesting tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.42
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.42
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":38,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":70.27214119447329,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931675}
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Tick request granted.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Waiting for tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.43
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.43
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":39,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":69.68713219296454,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931676}
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> TICK DONE. Getting observation.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Observation received. Getting info.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING INFO: NULL
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":39,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":69.68713219296454,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931676}
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> STATUS false
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Info received..
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock released. Writing observation, info, done.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Packets written. Flushing.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Done with step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Entering synchronous step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Acquiring lock for synchronous step.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock is acquired.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Received: attack 0
back 0
camera 0.0 0.0
forward 0
jump 0
left 0
right 0
sneak 0
sprint 0
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Requesting tick.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Tick request granted.
[14:48:20] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Waiting for tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:20] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.44
[14:48:20] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.44
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":40,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":69.03542335880192,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931677}
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> TICK DONE. Getting observation.
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Observation received. Getting info.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING INFO: NULL
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":40,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":69.03542335880192,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931677}
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> STATUS false
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Info received..
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock released. Writing observation, info, done.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Packets written. Flushing.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Done with step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <PEEK> Getting observation.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: [ERROR] Video observation is null; please notify the developer.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <PEEK> Observation acquired.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Entering synchronous step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Acquiring lock for synchronous step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock is acquired.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Received: attack 0
back 0
camera 0.0 0.0
forward 0
jump 0
left 0
right 0
sneak 0
sprint 0
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Requesting tick.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Tick request granted.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Waiting for tick.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDERR]: java.lang.NullPointerException
[14:48:21] [EnvServerSocketHandler/INFO]: [STDERR]: at com.microsoft.Malmo.Client.MalmoEnvServer.peek(MalmoEnvServer.java:595)
[14:48:21] [EnvServerSocketHandler/INFO]: [STDERR]: at com.microsoft.Malmo.Client.MalmoEnvServer.access$700(MalmoEnvServer.java:51)
Exception in thread "EnvServerSocketHandler" [14:48:21] [EnvServerSocketHandler/INFO]: [STDERR]: at com.microsoft.Malmo.Client.MalmoEnvServer$1.run(MalmoEnvServer.java:167)
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:21] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.45
[14:48:21] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.45
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":41,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":68.31834868736632,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931678}
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> TICK DONE. Getting observation.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Observation received. Getting info.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING INFO: NULL
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":41,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":68.31834868736632,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931678}
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> STATUS false
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Info received..
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock released. Writing observation, info, done.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Packets written. Flushing.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Done with step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Entering synchronous step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Acquiring lock for synchronous step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock is acquired.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Received: attack 0
back 0
camera 0.0 0.0
forward 0
jump 0
left 0
right 0
sneak 0
sprint 0
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Requesting tick.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Tick request granted.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Waiting for tick.
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:21] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.46
[14:48:21] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.46
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":42,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":67.53721549415644,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931679}
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> TICK DONE. Getting observation.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Observation received. Getting info.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING INFO: NULL
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":42,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":67.53721549415644,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931679}
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> STATUS false
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Info received..
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock released. Writing observation, info, done.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Packets written. Flushing.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Done with step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Entering synchronous step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Acquiring lock for synchronous step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock is acquired.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Received: attack 0
back 0
camera 0.0 0.0
forward 0
jump 0
left 0
right 0
sneak 0
sprint 0
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Requesting tick.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Tick request granted.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Waiting for tick.
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:21] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.47
[14:48:21] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.47
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":43,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":66.69330494838594,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931680}
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> TICK DONE. Getting observation.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Observation received. Getting info.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING INFO: NULL
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":43,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":66.69330494838594,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931680}
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> STATUS false
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Info received..
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock released. Writing observation, info, done.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Packets written. Flushing.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Done with step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Entering synchronous step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Acquiring lock for synchronous step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock is acquired.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Received: attack 0
back 0
camera 0.0 0.0
forward 0
jump 0
left 0
right 0
sneak 0
sprint 0
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Requesting tick.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Tick request granted.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Waiting for tick.
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:21] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.48
[14:48:21] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.48 [MALMO_ENV_SERVER] <STEP> Lock is acquired.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Received: attack 0
back 0
camera 0.0 0.0
forward 0
jump 0
left 0
right 0
sneak 0
sprint 0
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Requesting tick.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Tick request granted.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Waiting for tick.
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:21] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.47
[14:48:21] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.47
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> END
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE INFO] 0
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <OBSERVATION> Inserting: {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":43,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":66.69330494838594,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931680}
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Tick fully complete..
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Waiting for tick request!
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> TICK DONE. Getting observation.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Observation received. Getting info.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING INFO: NULL
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> FILLING {"inventory":[{"type":"iron_axe","index":0,"quantity":1,"inventory":"inventory"}],"inventoriesAvailable":[{"name":"inventory","size":41}],"currentItemIndex":0,"DistanceTravelled":0,"TimeAlive":43,"MobsKilled":0,"PlayersKilled":0,"DamageTaken":0,"DamageDealt":0,"Life":20.0,"Score":0,"Food":20,"XP":0,"IsAlive":true,"Air":300,"Name":"MineRLAgent","XPos":-23.10090232557063,"YPos":66.69330494838594,"ZPos":277.7496717180228,"Pitch":22.199987,"Yaw":-178.05008,"WorldTime":6000,"TotalTime":11931680}
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> STATUS false
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Info received..
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock released. Writing observation, info, done.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Packets written. Flushing.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Done with step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Entering synchronous step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Acquiring lock for synchronous step.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Lock is acquired.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Received: attack 0
back 0
camera 0.0 0.0
forward 0
jump 0
left 0
right 0
sneak 0
sprint 0
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Requesting tick.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: ============ SYNC TICK STARTED ===========
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Tick request granted.
[14:48:21] [EnvServerSocketHandler/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [MALMO_ENV_SERVER] <STEP> Waiting for tick.
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Starting client tick.
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [CLIENT_STATE_MACHINE] <onTICK> START
[14:48:21] [Client thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [Client] Client tick end. Client Waiting for server to tick!
[14:48:21] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick start.48
[14:48:21] [Server thread/INFO]: [STDOUT]: SYNCMANAGER DEBUG: [SERVER] tick end.48
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment