Jox Posted June 28, 2023 Report Share Posted June 28, 2023 (edited) Heyo; Been having a blast with this game running a server on an Ubuntu box at home, no mods. Updated to v1.18.6-rc.1 a while back to deal with some bug with crock pots spoiling, or so I was told by a friend. Unsure if this is related, but worth mentioning. Anyway it's on us ofc if this breaks because we run test version of pre-released game. Anyway we seem to have some issue with a particular [EDIT:several] chunks around our base when some players enter it. Everything works fine for players inside other chunks but when a particular player inside the 'cursed' chunk logs in the server crash. This happened after we used a Spoiler translocator and then returned. Players who did not go along with us have no issues. [EDIT: this affects other players now too who didn't go with us and appears to be different chunks] Tried to update to latest test version; but same story. We're doing some more testing and troubleshooting in general but this is the current status. Anyone experienced anything like this before? I wanted to check before I post to the bug tracker. 1) Appears that there is some repair mode; any idea how to run that on a server world?https://www.vintagestory.at/forums/forum/6-questions/ 2) Found this which could be related, but I wanted to check if anyone has experienced anything like this before I go ahead an clear a chunk in the middle of our base. Got this excerpt from the server logs as I log into this chunk let me know if I can supply anything else. A second player got OP and TPed me away from the chunk and after that he too crashed the server. This is why you should run daily backup on data folder, not every couple of weeks - lesson for everyone! This is a small highlight: Spoiler 28.6.2023 20:01:47 [Error] Failed deserializing a map chunk. Not in repair mode, will exit. ==> server-event.txt <== 28.6.2023 20:01:47 [Error] Failed deserializing a map chunk. Not in repair mode, will exit. ==> server-main.txt <== 28.6.2023 20:01:47 [Fatal] Caught unhandled exception in thread 'chunkdbthread'. Shutting down server. ==> server-event.txt <== 28.6.2023 20:01:47 [Fatal] Caught unhandled exception in thread 'chunkdbthread'. Shutting down server. Spoiler ==> server-storyevent.txt <== 28.6.2023 20:00:49 [Event] Grand inventions... 28.6.2023 20:00:50 [Event] Glimmers in the soil... 28.6.2023 20:00:50 [Event] Burning sparks... 28.6.2023 20:00:50 [Event] Molded forms... 28.6.2023 20:00:50 [Event] Simple tools... 28.6.2023 20:00:51 [Event] A world unbroken... 28.6.2023 20:00:51 [Event] The center unfolding... 28.6.2023 20:00:52 [Event] The carved mountains... 28.6.2023 20:00:53 [Event] ... it calls to you 28.6.2023 20:00:53 [Event] Return again. ==> server-worldgen.txt <== ==> server-main.txt <== 28.6.2023 20:01:36 [Notification] A Client attempts connecting via TCP, assigning client id 2 28.6.2023 20:01:37 [Notification] Client uid uaiDLEcXg6ZylWmihZ72Jv95 attempting identification. Name: Jox ==> server-debug.txt <== 28.6.2023 20:01:37 [Debug] Client uid uaiDLEcXg6ZylWmihZ72Jv95, mp token K98U8+Pab3ku3Kaopls2ys9oaeBvzJlkdmJ60dpPEdE=: Verifying with auth server 28.6.2023 20:01:38 [Debug] Response from auth server: {"playername":"Jox","entitlements":null,"valid":1} 28.6.2023 20:01:38.773 [VerboseDebug] Received identification packet from Jox ==> server-main.txt <== 28.6.2023 20:01:38 [Notification] Sending server identification with remap False. Server control privilege is True 28.6.2023 20:01:38 [Notification] Placing player at 511610.016144795 111 512022.000913199 ==> server-audit.txt <== 28.6.2023 20:01:38 [Audit] Jox joined. ==> server-debug.txt <== 28.6.2023 20:01:39.234 [VerboseDebug] HandleRequestJoin: Begin. Player: Jox 28.6.2023 20:01:39.234 [VerboseDebug] HandleRequestJoin: Before set name 28.6.2023 20:01:39.246 [VerboseDebug] HandleRequestJoin: After Level initialize ==> server-audit.txt <== 28.6.2023 20:01:39 [Audit] Jox opened inventory hotbar-uaiDLEcXg6ZylWmihZ72Jv95 28.6.2023 20:01:39 [Audit] Jox opened inventory creative-uaiDLEcXg6ZylWmihZ72Jv95 28.6.2023 20:01:39 [Audit] Jox opened inventory creative-uaiDLEcXg6ZylWmihZ72Jv95 28.6.2023 20:01:39 [Audit] Jox opened inventory backpack-uaiDLEcXg6ZylWmihZ72Jv95 28.6.2023 20:01:39 [Audit] Jox opened inventory ground-uaiDLEcXg6ZylWmihZ72Jv95 28.6.2023 20:01:39 [Audit] Jox opened inventory mouse-uaiDLEcXg6ZylWmihZ72Jv95 28.6.2023 20:01:39 [Audit] Jox opened inventory craftinggrid-uaiDLEcXg6ZylWmihZ72Jv95 28.6.2023 20:01:39 [Audit] Jox opened inventory character-uaiDLEcXg6ZylWmihZ72Jv95 ==> server-debug.txt <== 28.6.2023 20:01:39.387 [VerboseDebug] HandleRequestJoin: After broadcastplayerdata. hotbarslot: Vintagestory.API.Common.ItemSlotSurvival 28.6.2023 20:01:39.387 [VerboseDebug] HandleRequestJoin: After LevelFinalize ==> server-event.txt <== 28.6.2023 20:01:45 [Event] Jox [XXXXX]:15822 joins. ==> server-main.txt <== 28.6.2023 20:01:45 [Event] Jox [XXXXX]:15822 joins. ==> server-audit.txt <== 28.6.2023 20:01:46 [Audit] Client Copo disconnected. ==> server-event.txt <== 28.6.2023 20:01:46 [Event] Player Copo left. ==> server-main.txt <== 28.6.2023 20:01:46 [Event] Player Copo left. 28.6.2023 20:01:47 [Error] Failed deserializing a map chunk. Not in repair mode, will exit. ==> server-event.txt <== 28.6.2023 20:01:47 [Error] Failed deserializing a map chunk. Not in repair mode, will exit. ==> server-main.txt <== 28.6.2023 20:01:47 [Fatal] Caught unhandled exception in thread 'chunkdbthread'. Shutting down server. ==> server-event.txt <== 28.6.2023 20:01:47 [Fatal] Caught unhandled exception in thread 'chunkdbthread'. Shutting down server. ==> server-main.txt <== 28.6.2023 20:01:47 [Fatal] ProtoBuf.ProtoException: Sub-message not read entirely at Vintagestory.Server.ServerSystemSupplyChunks.TryLoadMapChunk (System.Int32 chunkX, System.Int32 chunkZ, Vintagestory.Server.ServerMapRegion forRegion) [0x000b5] in <d43db316d87d49cc812ebb995fd901bf>:0 at Vintagestory.Server.ServerSystemSupplyChunks.GetOrCreateMapChunk (Vintagestory.Server.ChunkColumnLoadRequest chunkRequest, System.Boolean forceCreate) [0x0004e] in <d43db316d87d49cc812ebb995fd901bf>:0 at Vintagestory.Server.ServerSystemSupplyChunks.loadOrGenerateChunkColumn () [0x00037] in <d43db316d87d49cc812ebb995fd901bf>:0 at Vintagestory.Server.ServerSystemSupplyChunks.OnSeparateThreadTick () [0x002a6] in <d43db316d87d49cc812ebb995fd901bf>:0 at Vintagestory.Server.ServerThread.Update () [0x00048] in <d43db316d87d49cc812ebb995fd901bf>:0 at Vintagestory.Server.ServerThread.Process () [0x00053] in <d43db316d87d49cc812ebb995fd901bf>:0 ==> server-event.txt <== 28.6.2023 20:01:47 [Fatal] ProtoBuf.ProtoException: Sub-message not read entirely at Vintagestory.Server.ServerSystemSupplyChunks.TryLoadMapChunk (System.Int32 chunkX, System.Int32 chunkZ, Vintagestory.Server.ServerMapRegion forRegion) [0x000b5] in <d43db316d87d49cc812ebb995fd901bf>:0 at Vintagestory.Server.ServerSystemSupplyChunks.GetOrCreateMapChunk (Vintagestory.Server.ChunkColumnLoadRequest chunkRequest, System.Boolean forceCreate) [0x0004e] in <d43db316d87d49cc812ebb995fd901bf>:0 at Vintagestory.Server.ServerSystemSupplyChunks.loadOrGenerateChunkColumn () [0x00037] in <d43db316d87d49cc812ebb995fd901bf>:0 at Vintagestory.Server.ServerSystemSupplyChunks.OnSeparateThreadTick () [0x002a6] in <d43db316d87d49cc812ebb995fd901bf>:0 at Vintagestory.Server.ServerThread.Update () [0x00048] in <d43db316d87d49cc812ebb995fd901bf>:0 at Vintagestory.Server.ServerThread.Process () [0x00053] in <d43db316d87d49cc812ebb995fd901bf>:0 ==> server-audit.txt <== 28.6.2023 20:01:47 [Audit] Client Jox got removed: 'Server shutting down - Exeption during Process' (Server shutting down - Exeption during Process) ==> server-main.txt <== 28.6.2023 20:01:47 [Notification] Last player disconnected, compacting large object heap... ==> server-event.txt <== 28.6.2023 20:01:47 [Event] Player Jox got removed. Reason: Server shutting down - Exeption during Process ==> server-main.txt <== 28.6.2023 20:01:47 [Event] Player Jox got removed. Reason: Server shutting down - Exeption during Process 28.6.2023 20:01:47 [Notification] Server stop requested, begin shutdown sequence. Stop reason: Exeption during Process 28.6.2023 20:01:47 [Notification] Server ticking has been suspended 28.6.2023 20:01:47 [Notification] Entering runphase Shutdown ==> server-debug.txt <== 28.6.2023 20:01:47.609 [VerboseDebug] Entering runphase Shutdown ==> server-main.txt <== 28.6.2023 20:01:47 [Notification] Defragmented listener lists ==> server-event.txt <== 28.6.2023 20:01:47 [Event] Mods and systems notified, now saving everything... ==> server-main.txt <== 28.6.2023 20:01:47 [Event] Mods and systems notified, now saving everything... ==> server-storyevent.txt <== 28.6.2023 20:01:47 [Event] It pauses. 28.6.2023 20:01:47 [Event] One last gaze... ==> server-event.txt <== 28.6.2023 20:01:47 [Event] Saved player world data... ==> server-main.txt <== 28.6.2023 20:01:47 [Event] Saved player world data... ==> server-event.txt <== 28.6.2023 20:01:47 [Event] Saved map regions... ==> server-main.txt <== 28.6.2023 20:01:47 [Event] Saved map regions... ==> server-storyevent.txt <== 28.6.2023 20:01:47 [Event] Then all goes quiet... ==> server-event.txt <== 28.6.2023 20:01:47 [Event] Saved map chunks... ==> server-main.txt <== 28.6.2023 20:01:47 [Event] Saved map chunks... ==> server-storyevent.txt <== 28.6.2023 20:01:47 [Event] The waters recede... ==> server-event.txt <== 28.6.2023 20:01:47 [Event] Saved loaded chunks... ==> server-main.txt <== 28.6.2023 20:01:47 [Event] Saved loaded chunks... ==> server-storyevent.txt <== 28.6.2023 20:01:47 [Event] The mountains fade... 28.6.2023 20:01:47 [Event] The dark settles in. ==> server-event.txt <== 28.6.2023 20:01:47 [Event] Saved generating chunks... ==> server-main.txt <== 28.6.2023 20:01:47 [Event] Saved generating chunks... ==> server-event.txt <== 28.6.2023 20:01:47 [Event] Saved savegamedata...2 28.6.2023 20:01:47 [Event] World saved! Saved 148 chunks, 117 mapchunks, 20 mapregions. ==> server-main.txt <== 28.6.2023 20:01:47 [Event] Saved savegamedata...2 28.6.2023 20:01:47 [Event] World saved! Saved 148 chunks, 117 mapchunks, 20 mapregions. ==> server-storyevent.txt <== 28.6.2023 20:01:47 [Event] It sighs... ==> server-event.txt <== 28.6.2023 20:01:47 [Event] Shutting down 7 server threads... ==> server-main.txt <== 28.6.2023 20:01:47 [Event] Shutting down 7 server threads... ==> server-event.txt <== 28.6.2023 20:01:47 [Event] Killed console thread ==> server-main.txt <== 28.6.2023 20:01:47 [Event] Killed console thread ==> server-storyevent.txt <== 28.6.2023 20:01:47 [Event] Alone again... ==> server-event.txt <== 28.6.2023 20:01:48 [Event] All threads gracefully shut down ==> server-main.txt <== 28.6.2023 20:01:48 [Event] All threads gracefully shut down ==> server-storyevent.txt <== 28.6.2023 20:01:48 [Event] Time to rest. ==> server-event.txt <== 28.6.2023 20:01:48 [Event] Doing last tick... ==> server-main.txt <== 28.6.2023 20:01:48 [Event] Doing last tick... ==> server-event.txt <== 28.6.2023 20:01:48 [Event] Stopped the server! ==> server-main.txt <== 28.6.2023 20:01:48 [Event] Stopped the server! 28.6.2023 20:01:48 [Warning] Server overloaded. A tick took 1059ms to complete. EDIT: Perhaps move this to discussion -> Questions? Might be a better place for it EDIT2: Possible interesting thing; restore to backup from before server update and the first time we loaded the chunk we got the following before the crash condition: 28.6.2023 21:43:05 [Warning] BETransient @511725, 114, 511997 for Block tallgrass-eaten-free, but there is tallgrass-eaten-snow at this position? Will delete BE and attempt to recreate it EDIT3: Possibly another red herring ; navigated to the area on foot and I got deserialization error without the grass condition.Tried to copy over to local machine, run repair mode and copy back but that just caused the SQLI save to bork out. Idk at this point; any advice would be helpful EDIT4: Will post to bug tracker on gitlab. Thanks! Edited June 28, 2023 by Jox Link to comment Share on other sites More sharing options...
Jox Posted June 28, 2023 Author Report Share Posted June 28, 2023 (edited) Resolved issue! Outstanding question; can you do this directly on the server? Copied over world files to windows box with UI; ran repair mode and flew to chunk. Copied back; replaced old data in /var/vintagestory/data/. [optional?]: Got an SQLi error; restored after following steps on https://wiki.vintagestory.at/index.php/Repairing_a_corrupt_savegame_or_worldmap Renamed save to match that of my existing save, in my case `default.vcdbs` Copied back over to /var/vintagestory/data/Save/default.vcdbs profit In case anyone else stumbles on this. No more crashes. Edited June 28, 2023 by Jox Link to comment Share on other sites More sharing options...
Recommended Posts