[0.16.47] Desync on connect with LTN for 2nd player

[gleber]

As reported on https://github.com/Yousei9/Logistic-Tra ... issues/120 :

we're late stage in a multiplayer game and after stopping to play yesterday (we expanded the base, nothing out of the regular) now all of a sudden only 1 player can concurrently connect/play.

tried with headless hosted server, only 1 player could connect.
tried with normal windows game client hosting, no player could connect.
according to the log, the disconnect happens due to a failing CRC check

34.522 Error GameActionHandler.cpp:2676: Multiplayer desynchronisation: crc test (heuristic) failed for crcTick(18621407) serverCRC(880134861) localCRC(1558050798)

we enabled/disabled all other mods and nailed the problem down to LTN.

• if we play without any mods, the map works
  if we play with any other mods, the map works
  only basemod+LTN enabled --> desync

we really love the mod and don't want to continue without it!

we documented one setup: both players on windows, hosting a normal multiplayer game.
all mods disabled besides LTN, the player disconnected with desynch

client desync report: https://drive.google.com/drive/folders/ ... zKgYoKuK3j
only the log file: https://drive.google.com/file/d/1N_Ch-6 ... IIkJI/view

server log:

171.719 Info ServerRouter.cpp:409: Replying to connectionRequest for address(IP ADDR:({77.56.208.212:51261})).
171.719 Info ServerSynchronizer.cpp:557: nextHeartbeatSequenceNumber(434) adding peer(1)
171.751 Info ServerMultiplayerManager.cpp:699: mapTick(18613662) changing state from(InGame) to(InGameSavingMap)
171.802 Info ServerMultiplayerManager.cpp:795: mapTick(18613662) received stateChanged peerID(1) oldState(Ready) newState(ConnectedWaitingForMap)
173.178 Info ServerMultiplayerManager.cpp:855: MapTick(18613662) Serving map(C:\Users\vossi\AppData\Roaming\Factorio\temp\mp-save-0.zip) for peer(1) size(25640924) crc(961567700)
173.178 Info ServerMultiplayerManager.cpp:699: mapTick(18613662) changing state from(InGameSavingMap) to(InGame)
173.285 Info ServerMultiplayerManager.cpp:795: mapTick(18613669) received stateChanged peerID(1) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
188.134 Info ServerMultiplayerManager.cpp:795: mapTick(18614560) received stateChanged peerID(1) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
190.484 Info ServerMultiplayerManager.cpp:795: mapTick(18614701) received stateChanged peerID(1) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
190.551 Info ServerMultiplayerManager.cpp:795: mapTick(18614705) received stateChanged peerID(1) oldState(TryingToCatchUp) newState(DesyncedWaitingForMap)
190.551 Info ServerMultiplayerManager.cpp:872: mapTick(18614705) received playerDesynced peer (1)
190.567 Info ServerMultiplayerManager.cpp:699: mapTick(18614705) changing state from(InGame) to(InGameSavingMapForDesyncReport)
199.201 Info ServerMultiplayerManager.cpp:855: MapTick(18614705) Serving map(C:\Users\vossi\AppData\Roaming\Factorio\temp\mp-save-1.zip) for peer(1) size(104135349) crc(767865006)
199.201 Info ServerMultiplayerManager.cpp:699: mapTick(18614705) changing state from(InGameSavingMapForDesyncReport) to(InGame)
199.319 Info ServerMultiplayerManager.cpp:795: mapTick(18614712) received stateChanged peerID(1) oldState(DesyncedWaitingForMap) newState(DesyncedCatchingUpWithMapReadyForDownload)
199.319 Info ServerMultiplayerManager.cpp:795: mapTick(18614712) received stateChanged peerID(1) oldState(DesyncedCatchingUpWithMapReadyForDownload) newState(DesyncedSavingLocalVariantOfMap)
208.285 Info ServerMultiplayerManager.cpp:795: mapTick(18615250) received stateChanged peerID(1) oldState(DesyncedSavingLocalVariantOfMap) newState(DesyncedDownloadingMap)
268.752 Info ServerMultiplayerManager.cpp:795: mapTick(18618878) received stateChanged peerID(1) oldState(DesyncedDownloadingMap) newState(DesyncedCreatingReport)
275.485 Info ServerMultiplayerManager.cpp:901: Disconnect notification for peer (1)
275.485 Info ServerMultiplayerManager.cpp:795: mapTick(18619281) received stateChanged peerID(1) oldState(DesyncedCreatingReport)

[gleber]

For what it's worth, we have tried a paused game with no mods except for LTN. I was able to join the game, but as soon as the game has been unpaused I got desynced.

[orzelek]

I took a prod at the desync report and it shows LTN doing two different things on both machines.

On reference it printed that it's creating a delivery of 16k iron plates while at same spot on desynced level it shows that there is an invalid stop with id 2123745.
After this happens it goes downhill

Looking at script.dat there is a differene near one of the stops but I'm not sure what it means - it looks like lua table for certain stop has few different bytes first then diff breaks a bit due to that.

If you can recall if there was a delivery for 16k plates on server at moment of desync it could help in investigation.

[gleber]

orzelek, thank you! Your information allowed us to pinpoint the area which was at fault. We essentially had to delete all LTN stops in the newest smelting area, which worked. Deleting the LTN stops directly related to 16k iron plates did not work though, but we are back in the game! Thanks again

[vossi_plays]

yes the 16k iron plate comment was a big help. may i ask how you found that out? at which files did you look? and by what you said it seems you used a hex editor / diff tool?
thanks!!

[orzelek]

I have found a difference in level with tags dat files using binary compare. It was easily visible since it was the section where game stores recent chat messages.
You need to have a tool that can compare two files that are binary (Since files here are not 100% text so text editors can have trouble).

I won't recommend you nice one since I don't have a preffered one. I'm usually using any freerly available hex editor that can compare two files. Using Total Commander or Double Commander might be helpful to diff whole directory quickly to see where the differences can be found.

[jarquafelmu]

I am having a similar issue in factorio 0.16.51. The first time we placed down LTN stations we were okay. But after saving exiting the game then coming back any other player besides the host desyncs from the game.

I have tried removing the LTN stations but the other players still cannot join.

Our game is now essentially dead until this is resolved .

[orzelek]

I'd recommend posting desync report on some cloud storage and posting link to it here.
Maybe we can spot something that will help catching the issue.

[jarquafelmu]

Sorry that it took me a while to get back to this. I have a desync log for you guys. Please fix this, I really want to use the Logistic train network in multiplayer

Reproduce:

• Load world in multiplayer
• Have second player join
• Second player desyncs after downloading world.

desync-report-2018-07-04_21-44-51.zip

lTN - Testing Save File

Mods in case you need them

[Optera]

there-is-my-ghost is incompatible with LTN and probably many other mods using composite entities.

Edit: I'm tired of seeing LTN causing desync popping up over and over so I've marked there-is-my-ghost as incompatible until the author fixes the bug.
I originally didn't want to do that since Factorio doesn't warn about incompatible mods. It will just silently deactivate LTN making all LTN stops vanish on loading a game.

[jarquafelmu]

Thanks for looking into things. After removing there-is-my-ghost completely we were able to get people loading into the world with LTN stations after a bit. At first we had a desync which I've posted here to maybe hopefully show why the desync is still happening, but after the first desync and quitting and trying again they were able to join the world fully.

desync-report-2018-07-18_17-54-56