BeforeChunkUnload sending now in multiplayer on invalidate. Fix Respawn in multiplayer

[DarkWeird]

Contains

Added missing event source: BeforeChunkUnload.Client's
Systems will be notified of unloaded chunks now.

Fixes #3006
Possible fix #2477

How to test

---

1. Multiplayer:

• Start server
• Start client
• Connect to server
• Go far from the spawn area (minimum distance to draw)
• Open Console
• Type 'kill'
• Press 'Enter'
• You on spawn area
• World load, chunks visible

---

2. Singleplayer

• Start client
• Create game
• Go far from the spawn area (minimum distance to draw)
• Open Console
• Type 'kill'
• Press 'Enter'
• You on spawn area
• World load, chunks visible

[lgtm-com]

This pull request introduces 1 alert when merging ddb4813 into 70ac0dc - view on LGTM.com

new alerts:

• 1 for Dereferenced variable may be null

[GooeyHub]

Hooray Jenkins reported success with all tests good!

[GooeyHub]

Hooray Jenkins reported success with all tests good!

[Cervator]

Tried to test this but I still get the old behavior. Ran a headless server + standalone client and flew far from spawn then fell from a high place and respawned in the usual void :-(

Loads of spammy logs like the following:

20:36:49.566 [main] ERROR o.t.l.debug.ChunkEventErrorLogger - Unload event for not loaded chunk (3, 1, 19)
20:36:49.566 [main] ERROR o.t.l.debug.ChunkEventErrorLogger - Unload event for not loaded chunk (3, -1, 19)

Additionally if I had two players the first player leaving spawn would actually cause the chunks there to unload despite the other player standing there 😁 So there's something wrong with the chunk relevancy calculation still

[DarkWeird]

@Cervator
Am retested too, its invisible...
I think that problem with renderer.
About spam - i think problem with netclient :)
Detective work go on...

[Cervator]

If the chunks are there and just invisible that beats being unloaded - and I guess that can be an easy bit of confusion. Both result in a void but in one you can move. Maybe in that case it is a chunk readiness pass that's broken - the chunk loads but lighting calcs or something never finish and let it continue to the next stage of readiness.

Also: be mindful of how you update a a topic branch - if at all possible please rebase on top of latest upstream, avoid merging into topic branches as that just creates messy history or possibly even problems merging into upstream later :-)

[GooeyHub]

Hooray Jenkins reported success with all tests good!

[GooeyHub]

Hooray Jenkins reported success with all tests good!

[GooeyHub]

Hooray Jenkins reported success with all tests good!

[GooeyHub]

Hooray Jenkins reported success with all tests good!

[GooeyHub]

Uh oh, something went wrong with the build. Need to check on that

[Cervator]

Almost ! It works great in multiplayer! But now respawn isn't fully working in single player 😅

I can test in headless + two regular clients just fine. But if I start in single player, fly far away, drop from a high place, and respawn my player isn't quite right. I can't move the camera up or down, and if I try to take actions the game thinks I'm still in a different place:

23:24:30.821 [Saving-0] INFO  o.t.p.internal.SaveTransaction - Save game finished
23:25:22.956 [main] ERROR o.t.logic.characters.CharacterSystem - Direction at client (0.30901682, 0.0, -0.9510566) was different than direction at server (0.030020624, -0.99526983, -0.092394024)
23:25:22.956 [main] INFO  o.t.logic.characters.CharacterSystem - Player Cervator seems to have cheated: It stated that it performed an action from (-2.7841837, 37.40111, -6.1891923) but the predicted position is (-2.7841837, 38.101112, -6.1891923)
23:25:22.973 [main] ERROR o.t.logic.characters.CharacterSystem - Direction at client (0.30901682, 0.0, -0.9510566) was different than direction at server (0.030020624, -0.99526983, -0.092394024)

I'm pretty sure this has happened before, it feels very familiar. We had a fun round of changes with this in the past when messing with the whole alive or not, respawning, etc. Probably not a hard fix. Nearly there!

[GooeyHub]

Hooray Jenkins reported success with all tests good!

[Cervator]

So! Good news with a hint of mystery :-)

It works now in single player! 🎉

It seemingly also works in headed multiplayer (server/client hosting) 🎉

But while the chunk reloading seems to work after a death in headless multiplayer I was able to provoke a server crash - but seemingly only with very specific config, and only twice. Now I cannot replicate 😞

My testing setup here is JoshariasSurvival + HumanoidCharacters + Rails + CheatsForAll. It did not crash in the headless attempt with Rails and HC removed. But then I put those back, simplified the seed, tried again, and didn't crash. Restored the initial seed, still didn't crash 🤔

So the error reported below is not something I can replicate, but I'll leave it in anyway - will merge this now as seemingly working :-)

One issue I did notice and am not sure if pre-existing but in one test I started the headless server, joined a player, flew away, died, and respawned. Everything was fine so I logged out. I then started a second different game client, and did the exact same thing. On that attempt after respawning I got logged errors about multiple loads of every chunk that then loaded.

Anyway since that may be pre-existing and may just cause some wasted cycles I won't worry about it right now.

For the former issue I now cannot replicate keep reading, but optionally just ignore at this point.

It crashes with the following override.cfg used to start the headless run config in IntelliJ (huh, forgot I had CheatsForAll enabled, didn't actually need usePermissionKey after all):

{
    "defaultModSelection": {
    "modules": [
      "JoshariasSurvival",
      "HumanoidCharacters",
      "Rails",
      "CheatsForAll"
    ],
    "defaultGameplayModuleName": "JoshariasSurvival"
    },
    "worldGeneration": {
      "worldTitle": "Dec2019",
      "defaultSeed": "Vq1tAcQAe9cpt2FAHgkZk7Kr7BEBS2qjShattered Planes-00",
      "defaultGenerator": "Core:facetedperlin"
    }
}

Server log:

20:27:52.365 [Saving-0] INFO  o.t.p.internal.SaveTransaction - Save game finished
20:27:58.728 [main] INFO  o.t.n.internal.NetworkSystemImpl - Component class org.terasology.logic.health.RegenComponent added to EntityRef{id = 2177, netId = 1437, prefab = 'engine:player'}
20:27:58.729 [main] INFO  o.t.logic.characters.CharacterSystem - engine:physicalDamage is missing a readable DisplayName
20:27:58.729 [main] INFO  o.t.logic.characters.CharacterSystem - engine:physicalDamage is missing a readable DisplayName
20:27:58.730 [main] INFO  o.t.n.internal.NetworkSystemImpl - Component class org.terasology.logic.characters.AliveCharacterComponent removed from EntityRef{id = 2177, netId = 1437, prefab = 'engine:player'}
20:27:58.757 [main] ERROR o.t.p.t.TypeHandlerLibrary - Unsupported field: 'Health:Regen.regenEndTime'
20:28:00.820 [main] INFO  o.t.p.i.ReadWriteStorageManager - Auto Saving - Creating game snapshot
20:28:00.822 [main] INFO  o.t.p.i.ReadWriteStorageManager - Auto Saving - Snapshot created: Writing phase starts
20:28:01.062 [main] INFO  o.t.n.internal.NetworkSystemImpl - Component class org.terasology.logic.characters.AliveCharacterComponent added to EntityRef{id = 2177, netId = 1437, prefab = 'engine:player'}
20:28:01.168 [main] ERROR o.terasology.engine.TerasologyEngine - Uncaught exception, attempting clean game shutdown
java.lang.ArithmeticException: input is infinite or NaN
	at com.google.common.math.DoubleMath.roundIntermediate(DoubleMath.java:57)
	at com.google.common.math.DoubleMath.roundToInt(DoubleMath.java:132)
	at org.terasology.math.geom.Vector3i.<init>(Vector3i.java:87)
	at org.terasology.math.ChunkMath.calcChunkPos(ChunkMath.java:79)
	at org.terasology.world.chunks.internal.ChunkRelevanceRegion.calculateCenter(ChunkRelevanceRegion.java:132)
	at org.terasology.world.chunks.internal.ChunkRelevanceRegion.update(ChunkRelevanceRegion.java:110)
	at org.terasology.world.chunks.localChunkProvider.LocalChunkProvider.updateRelevance(LocalChunkProvider.java:483)
	at org.terasology.world.chunks.localChunkProvider.LocalChunkProvider.beginUpdate(LocalChunkProvider.java:345)
	at org.terasology.engine.subsystem.headless.renderer.HeadlessWorldRenderer.update(HeadlessWorldRenderer.java:109)
	at org.terasology.engine.modes.StateIngame.update(StateIngame.java:176)
	at org.terasology.engine.TerasologyEngine.tick(TerasologyEngine.java:462)
	at org.terasology.engine.TerasologyEngine.mainLoop(TerasologyEngine.java:425)
	at org.terasology.engine.TerasologyEngine.run(TerasologyEngine.java:401)
	at org.terasology.engine.Terasology.main(Terasology.java:145)
20:28:01.168 [main] INFO  o.terasology.engine.TerasologyEngine - Shutting down Terasology...

Client (may be a solely a consequence of the server dying)

20:27:09.122 [main] INFO  o.t.logic.console.ConsoleImpl - [CONSOLE] Permission key used: You have now the following permissions: [cheat, serverManagement, userManagement, debug, chat]
20:27:11.322 [main] INFO  o.t.logic.console.ConsoleImpl - [CONSOLE] Ghost mode toggled
20:27:12.022 [main] INFO  o.t.logic.console.ConsoleImpl - [CONSOLE] High-speed mode activated
20:27:40.364 [main] INFO  o.t.logic.console.ConsoleImpl - [CONSOLE] You received 16 blocks of Torch
20:27:55.825 [main] INFO  o.t.logic.console.ConsoleImpl - [CONSOLE] Ghost mode toggled
20:27:58.791 [main] ERROR o.t.p.t.TypeHandlerLibrary - Unsupported field: 'Health:Regen.regenEndTime'
20:27:58.791 [main] ERROR o.t.p.typeHandling.Serializer - No type handler for type interface com.google.common.collect.SortedSetMultimap used by class org.terasology.logic.health.RegenComponent::regenEndTime
20:28:03.635 [main] INFO  o.t.n.internal.NetworkSystemImpl - Network shutdown
20:28:07.200 [pool-12-thread-1] INFO  o.t.e.module.ModuleListDownloader - Downloading modules ..
20:28:07.204 [main] WARN  o.t.engine.internal.TimeBase - Delta too great (3599), capping to 1000
20:28:07.208 [main] ERROR o.t.rendering.opengl.GLSLMaterial - Attempted to bind disposed texture Thirst:thirstBar
20:28:07.208 [main] ERROR o.t.rendering.opengl.GLSLMaterial - Attempted to bind disposed texture Thirst:thirstBar
20:28:07.209 [main] ERROR o.t.rendering.opengl.GLSLMaterial - Attempted to bind disposed texture Thirst:thirstBar

It did not crash after I update the seed value - something specific about that world? Seed came from a play test I was trying to run ShatteredPlanes with, but that wasn't working for another reason so I went back to plain faceted Perlin just with the same seed value. So "defaultSeed": "Vq1tAcQAe9cpt2FAHgkZk7Kr7BEBS", worked fine.

But then even after reverting to the "bad" seed it then promptly did not crash ...