Need help diagnosing a headless server multiplayer oddity

[Josharias]

Hi all,

This is a request for help diagnosing why JoshariasSurvival blueberry bushes turn into non-entity blocks after harvesting when connected to a headless server. My computer has less than ideal amounts of processing power for testing, basically it takes 5-10 minutes to load up a multiplayer test scenario. And then usually most things go unresponsive for another 5-10 minutes. (yes, my poor poor dual core machine)

This is what harvesting does (activate the blueberry bush block in the world with 'e'):
1. give a blueberry to the player
2. lookup the previous block in its growth sequence
3. set the blueberry bush to the previous block with blockEntityRegistry.setBlockRetainComponent(...)

This is what I have observed so far:
- after harvesting, the block turns into the previous block but without the ability to interact with it further.
- disconnecting, and reconnecting to the server does then allow interaction with the same blueberry bush block again.
- this whole procedure works fine on single player.

What I have not been able to test because of lack of computing power:
- see what happens when there are 2 game clients connected and one of them harvests the blueberry bush
- See what happens if 1 player stays connected and the other player disconnects and rejoins.

My thoughts about what to look for next:
- setBlockRetainComponent(...) is quirky? Typically I have used the world provider's setBlock(...)
- The entity for the blueberry bush block is not sent over the wire to the client because it is trying to reuse the old entity, the client only gets a "change the block" message, but not a "oh, and use this entity".

Other tricks:
- the growthcan and and ungrowthcan items will simulate growth on a planted blueberry bush to help speed things along. Just right click a bush with one of them.


Any help would be appreciated,
Josharias

 

[Cervator]

Interesting! I tested this out real quick with two game clients, one hosting (easier to set up JS that way and I have to run for a while)

I got both players up to a blueberry bush and picked it with player 2 (client only). The bush became visually harvested for both players yet player2 received no blueberries and indeed didn't seem able to interact with the bush (trying the growth cans)

Where it gets interesting is when I then tried to use the growth can with the hosting player - it crashed player 2. Hosting player 1 was fine. Hard lockup after logging exceptions, didn't exit gracefully. Worth noting in the below crash log is that I got the "Updating entity with no network component" for player 2 when I was trying to interact with the bush, well before I crashed player 2 using player 1.

So it distinctly seems like something goes awry when you harvest the bush, involving setBlockRetainComponent - wasn't there something a while back about copying entities leaving out networking explicitly? Something about avoiding duplication at the network layer. I seem to recall something like that, and that certainly would appear relevant if the problem is that the downgraded bush no longer has proper networking hooked up.

@Immortius and @Florian could probably provide more details

14:51:42.218 [main] INFO  o.t.w.b.internal.BlockManagerImpl - Registered BlockFamily[SimpleFarming:BerryBush]
14:51:42.218 [main] INFO  o.t.w.b.internal.BlockManagerImpl - Registered Block SimpleFarming:BerryBush with id 190
14:51:42.220 [main] INFO  o.t.w.b.internal.BlockManagerImpl - Registered BlockFamily[SimpleFarming:MatureBerryBush]
14:51:42.221 [main] INFO  o.t.w.b.internal.BlockManagerImpl - Registered Block SimpleFarming:MatureBerryBush with id 191
14:51:47.296 [main] INFO  o.t.logic.console.ConsoleImpl - [CONSOLE] You received an item of SimpleFarming:GrowthCan
14:51:50.464 [main] INFO  o.t.logic.console.ConsoleImpl - [CONSOLE] You received an item of SimpleFarming:UnGrowthCan
14:52:02.546 [main] ERROR o.t.network.internal.ServerImpl - Updating entity with no network component: EntityRef{id = 195}, expected netId 579
14:52:03.545 [main] ERROR o.t.network.internal.ServerImpl - Updating entity with no network component: EntityRef{id = 195}, expected netId 579
14:52:03.795 [main] ERROR o.t.network.internal.ServerImpl - Updating entity with no network component: EntityRef{id = 195}, expected netId 579
14:52:04.745 [main] ERROR o.t.network.internal.ServerImpl - Updating entity with no network component: EntityRef{id = 195}, expected netId 579
14:52:05.595 [main] ERROR o.t.network.internal.ServerImpl - Updating entity with no network component: EntityRef{id = 195}, expected netId 579
14:52:06.582 [main] ERROR o.t.network.internal.ServerImpl - Updating entity with no network component: EntityRef{id = 195}, expected netId 579
14:52:28.258 [main] ERROR o.terasology.engine.TerasologyEngine - Uncaught exception, attempting clean game shutdown
java.lang.NullPointerException: null
   at org.terasology.world.internal.EntityAwareWorldProvider.updateBlockEntityComponents(EntityAwareWorldProvider.java:237) ~[classes/:na]
   at org.terasology.world.internal.EntityAwareWorldProvider.updateBlockEntity(EntityAwareWorldProvider.java:153) ~[classes/:na]
   at org.terasology.world.internal.EntityAwareWorldProvider.setBlock(EntityAwareWorldProvider.java:124) ~[classes/:na]
   at org.terasology.world.internal.WorldProviderWrapper.setBlock(WorldProviderWrapper.java:52) ~[classes/:na]
   at org.terasology.network.internal.ServerImpl.processBlockChanges(ServerImpl.java:299) ~[classes/:na]
   at org.terasology.network.internal.ServerImpl.processMessages(ServerImpl.java:260) ~[classes/:na]
   at org.terasology.network.internal.ServerImpl.update(ServerImpl.java:176) ~[classes/:na]
   at org.terasology.network.internal.NetworkSystemImpl.update(NetworkSystemImpl.java:322) ~[classes/:na]
   at org.terasology.engine.subsystem.common.NetworkSubsystem.preUpdate(NetworkSubsystem.java:47) ~[classes/:na]
   at org.terasology.engine.TerasologyEngine.mainLoop(TerasologyEngine.java:407) ~[classes/:na]
   at org.terasology.engine.TerasologyEngine.run(TerasologyEngine.java:369) ~[classes/:na]
   at org.terasology.engine.Terasology.main(Terasology.java:154) [classes/:na]
   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_45]
   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_45]
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_45]
   at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_45]
   at com.intellij.rt.execution.application.AppMain.main(AppMain.java:140) [idea_rt.jar:na]
14:52:28.258 [main] INFO  o.terasology.engine.TerasologyEngine - Shutting down Terasology...
14:52:28.281 [main] INFO  o.t.n.internal.NetworkSystemImpl - Network shutdown
14:52:28.295 [main] WARN  org.reflections.Reflections - given scan urls are empty. set urls in the configuration
14:52:31.975 [main] WARN  o.t.rendering.nui.asset.UIFormat - Field 'emptyIcon' not recognized for interface org.terasology.rendering.nui.UIWidget in {"type":"UIIconBar","id":"breathBar","icon":"engine:icons#bubble","family":"breathBar","emptyIcon":"engine:icons#burstBubble","halfIconMode":"shrink","spacing":2,"maxIcons":10,"layoutInfo":{"use-content-width":true,"use-content-height":true,"position-left":{"target":"CENTER"},"position-right":{"target":"RIGHT","widget":"toolbar"},"position-bottom":{"target":"TOP","widget":"toolbar","offset":1}}}
14:52:31.975 [main] WARN  o.t.rendering.nui.asset.UIFormat - Field 'crosshairIcon' not recognized for interface org.terasology.rendering.nui.UIWidget in {"type":"UICrosshair","id":"crosshair","crosshairIcon":"engine:gui#crosshair","chargeStages":["engine:gui#crosshairCharge1","engine:gui#crosshairCharge2","engine:gui#crosshairCharge3","engine:gui#crosshairCharge4","engine:gui#crosshairCharge5","engine:gui#crosshairCharge6","engine:gui#crosshairCharge7","engine:gui#crosshairCharge8"],"layoutInfo":{"use-content-width":true,"use-content-height":true,"position-horizontal-center":{},"position-vertical-center":{}}}
14:52:31.994 [main] ERROR o.terasology.engine.TerasologyEngine - Clean game shutdown after an uncaught exception failed
java.lang.NullPointerException: null
   at org.terasology.rendering.opengl.OpenGLTexture.getData(OpenGLTexture.java:183) ~[classes/:na]
   at org.terasology.rendering.iconmesh.IconMeshFactory.generateIconMeshData(IconMeshFactory.java:74) ~[classes/:na]
   at org.terasology.rendering.iconmesh.IconMeshFactory.generateIconMeshData(IconMeshFactory.java:62) ~[classes/:na]
   at org.terasology.rendering.iconmesh.IconMeshDataProducer.getAssetData(IconMeshDataProducer.java:80) ~[classes/:na]
   at org.terasology.assets.AssetType.reloadFromProducers(AssetType.java:467) ~[gestalt-asset-core-4.1.2.jar:4.1.2]
   at org.terasology.assets.AssetType.refresh(AssetType.java:155) ~[gestalt-asset-core-4.1.2.jar:4.1.2]
   at org.terasology.assets.module.ModuleAwareAssetTypeManager.switchEnvironment(ModuleAwareAssetTypeManager.java:389) ~[gestalt-asset-core-4.1.2.jar:4.1.2]
   at org.terasology.engine.bootstrap.EnvironmentSwitchHandler.cheapAssetManagerUpdate(EnvironmentSwitchHandler.java:128) ~[classes/:na]
   at org.terasology.engine.bootstrap.EnvironmentSwitchHandler.handleSwitchToEmptyEnivronment(EnvironmentSwitchHandler.java:149) ~[classes/:na]
   at org.terasology.engine.modes.StateIngame.dispose(StateIngame.java:157) ~[classes/:na]
   at org.terasology.engine.TerasologyEngine.cleanup(TerasologyEngine.java:438) ~[classes/:na]
   at org.terasology.engine.TerasologyEngine.run(TerasologyEngine.java:375) ~[classes/:na]
   at org.terasology.engine.Terasology.main(Terasology.java:154) [classes/:na]
   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_45]
   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_45]
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_45]
   at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_45]
   at com.intellij.rt.execution.application.AppMain.main(AppMain.java:140) [idea_rt.jar:na]
java.lang.NullPointerException
   at org.terasology.world.internal.EntityAwareWorldProvider.updateBlockEntityComponents(EntityAwareWorldProvider.java:237)
   at org.terasology.world.internal.EntityAwareWorldProvider.updateBlockEntity(EntityAwareWorldProvider.java:153)
   at org.terasology.world.internal.EntityAwareWorldProvider.setBlock(EntityAwareWorldProvider.java:124)
   at org.terasology.world.internal.WorldProviderWrapper.setBlock(WorldProviderWrapper.java:52)
   at org.terasology.network.internal.ServerImpl.processBlockChanges(ServerImpl.java:299)
   at org.terasology.network.internal.ServerImpl.processMessages(ServerImpl.java:260)
   at org.terasology.network.internal.ServerImpl.update(ServerImpl.java:176)
   at org.terasology.network.internal.NetworkSystemImpl.update(NetworkSystemImpl.java:322)
   at org.terasology.engine.subsystem.common.NetworkSubsystem.preUpdate(NetworkSubsystem.java:47)
   at org.terasology.engine.TerasologyEngine.mainLoop(TerasologyEngine.java:407)
   at org.terasology.engine.TerasologyEngine.run(TerasologyEngine.java:369)
   at org.terasology.engine.Terasology.main(Terasology.java:154)
   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   at java.lang.reflect.Method.invoke(Method.java:497)
   at com.intellij.rt.execution.application.AppMain.main(AppMain.java:140)
For more details, see the log files in C:\Dev\Terasology\Git\integrate\Terasology\terasology-2ndclient\logs\2015-09-06_14-48-36

 

[Florian]

After a hell of trouble of getting terasology running with Josharias survival, I managed to get it running with binaries and had a look at the issue.

The call of setBlockRetainComponent results in a standard block change transfer to the client which knows nothing about the wish to retain component information:

    at org.terasology.network.internal.NetClient.onBlockChanged(NetClient.java:394)
    at org.terasology.world.internal.WorldProviderCoreImpl.notifyBlockChanged(WorldProviderCoreImpl.java:222)
    - locked <0x215b> (a java.util.ArrayList)
    at org.terasology.world.internal.WorldProviderCoreImpl.setBlock(WorldProviderCoreImpl.java:209)
    at org.terasology.world.internal.AbstractWorldProviderDecorator.setBlock(AbstractWorldProviderDecorator.java:98)
    at org.terasology.world.internal.EntityAwareWorldProvider.setBlockRetainComponent(EntityAwareWorldProvider.java:136)

The client updates the block via a standard setBlock call and throws the component information away:

at org.terasology.world.internal.EntityAwareWorldProvider.setBlock(EntityAwareWorldProvider.java:124)
at org.terasology.world.internal.WorldProviderWrapper.setBlock(WorldProviderWrapper.java:52)
at org.terasology.network.internal.ServerImpl.processBlockChanges(ServerImpl.java:299)
at org.terasology.network.internal.ServerImpl.processMessages(ServerImpl.java:260)
at org.terasology.network.internal.ServerImpl.update(ServerImpl.java:176)

@Immortius What do you think about this situation?

 

[Immortius]

I think the whole block<->entity binding is somewhat convoluted at the moment, and while I would like to rework it I'm think the entity system needs improving first. That said:

There are a few possible models for how block entities should behave, probably depending on the exact behavior desired for a specific block:

1. Server should have persistent entity information, client should not.

This is behavior for blocks where something needs to be driven server-side, but isn't needed on the client. Such as a block that may evolve over time.

2. Server has persistent entity information, client should share it.

This is behavior for blocks where information needs to be shared to the clients. Such as if when a user looks at a block that evolves over time they get some information on how close it is to evolving.

3. Server and client have persistent entity information, but independently

This can occur where a component drives some sort of behavior that isn't gameplay affecting, such as having a light component or particle effect.

4. (Trivial) No persistence, entities dynamically created on server/client side as needed.


There are a couple of complexities.

• If a client uses a block, the event sent to the server needs to resolve to the correct server-side entity in each case above. Likewise events going the other way.
• There are some timing related issues involving chunk availability that come into play as well. If a client interacts with a block and by the time the event is being processed the chunk is gone, that needs to be handled correctly.

Case 2 is the easiest. The block should have a network component, and its entity replicated. Standard replication rules apply - information will be pushed to clients, references to the entity will be handled as normal. Some slight complexity in that when a block is replicated, there may be a temporary entity for the same block at that time that needs to be replaced.

Case 1 and case 3 are similar. It ties into the creation of entities as part of chunk creation/load. To support case 1 the client should be creating block entities as well during load of chunks. They would need to be careful to both not create entities for blocks that have already been replicated, and to remove entities for blocks that are replicated later. To differentiate case 1 and 3 some additional information would need to drive whether a block shouldn't have an entity in different networking modes.

For the particular case described... I think in general we should move towards a more naturally behaving entity model. In this particular case either:

• Use an event against the entity to drive the change, and replicate it; or
• Update the block entity directly, and have systems trigger updates as needed. This could include changing the block type, directly in the block component.

If chunks or worlds were entities, the events could be sent against them. But that leads back to the need to improve the entity system (specifically the need for multi-thread support so that our background chunk stuff can work).

 

[Josharias]

Thank you all for taking a look. It sounds like, at least for the short term, I should avoid setBlockRetainComponent for multiplayer. When we get some fancier stuff with entities and block changes, I can move towards that.

I have resorted to using WorldProvider.setBlock(...) and then grabbing the entity manually afterwards and giving it the "retained" components. It seems to work for multiplayer, but there are some timing things still to work out. (just dont use the growthcan too quickly). At least it can function.

Also, chunk and world entities sound tasty.