0ptera / Logistic-Train-Network

Factorio mod adding logistic network for trains.
Other
155 stars 55 forks source link

Factorio desynch on connect with LTN enabled #120

Closed vossiman closed 5 years ago

vossiman commented 6 years ago

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.

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/1BiGaEdoL0QtQJv4owsluEfzKgYoKuK3j only the log file: https://drive.google.com/file/d/1N_Ch-68QzqMwDDb3DcyVF7US0O8IIkJI/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) 
0ptera commented 6 years ago

If you successfully played with LTN before having desyncs all of a sudden makes no sense to me. There hasn't been any change in months that should cause desyncs.

gleber commented 6 years ago

It worked yesterday night. This morning we've tried rejoining the game and it does not allow more than one person to join to the headless server. We were testing with 3 people connecting to a headless server. Only the first player was able to join, the next player would always get desync

0ptera commented 6 years ago

Problem with those desync reports is, no one but wube can read those darn things. Best bet is to post those reports on the forum and ask wube to tell me what caused the desync so i can fix it.

vossiman commented 6 years ago

yeah it might be related to a change in 0.16.46 https://wiki.factorio.com/Version_history/0.16.0#0.16.46

Fixed possible desync related to circuit networks.

0ptera commented 6 years ago

A very likely culprit. Post the desync on the bug report forum and attach a link in here so i can follow that thread. Also, try loading the game with 0.16.45 if possible.

vossiman commented 6 years ago

when we try to load the game with an older version, it says the map can't be loaded with an older version. is there a way around this? we'll post the link as soon as it is approved/live

0ptera commented 6 years ago

No. Factorio saves are only forward compatible. You have to load a save created with an older version.

vossiman commented 6 years ago

https://forums.factorio.com/viewtopic.php?f=209&t=60764

gleber commented 6 years ago

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.

0ptera commented 6 years ago

Did you try a completely new game with 0.16.45 and only planting down 2-3 LTN stops?

You could also do this test with 0.16.36 stable. I'm sure more would've complained about desync if they happened with the stable release.

0ptera commented 6 years ago

I just tested LTN with 0.16.47 on a base with 100+ trains and didn't get desynced.

gleber commented 6 years ago

We have been playing the same game for tens of hours. The failure happened in between two games, where the game and no plugins were upgraded. It must be a heisenbug :/ I am sure things would work for a simple setup with few LTN stops only.

gleber commented 6 years ago

I am not familiar with Factorio debugging, but I am an software engineer myself. How feasible is it to debug our specific case using specifically our saved game?

0ptera commented 6 years ago

You can try the switch Dave posted me here: https://forums.factorio.com/viewtopic.php?f=34&t=60765 Maybe it'd give you some insight.

gleber commented 6 years ago

I have tried using the /toggle-heavy-mode, but it made it impossible for the second player to connect due to slowdown of the game. So no luck there.

One interesting find is that I see: [LTN] Error: Invalid stop: 2123745. Any pointers how I could debug it further?

0ptera commented 6 years ago

Reduce the game speed i think the console command is /c game.speed = 0.9 for 90%.

That entry you found is made by ltn when it encounters a stop where the stop or io entities are missing or invalidated. The stop is then removed from the global list of stops and shouldn't cause any further problems. (it just wont work until its rebuilt).

jarquafelmu commented 6 years ago

My friend and I are getting this as well. We thought it was problem relating to this mod and There Is My Ghost but now I am not sure.

When trying to place an LTN station on a ghost with the mod There Is my Ghost enabled and the placing on ghost restrictions turned on, the station places down the Logistic Train Stop Output and the Logistic Train Stop Input, then fails to place the station and reports the error [LTN] Error: Invalid stop: <stop id>.

Once this problem happens then the output combinator and the input lamp remain but they are unable to be interacted with or mined. The only way to remove them is to use a deconstruction planner on them. This does not remove the entity but allows a new entity to be placed there.

Turning off There Is My Ghost allows for the station to be placed down correctly but the input lamp and output combinator cannot be interacted with.

Besides this everything works fine, until you leave that game session. After leaving that game session, no one else but the host is able to join. Everyone else desyncs.

I have tried removing the LTN stations but the other people still cannot join. Additionally on game load we get a series of messages about invalid stations.

So from what I can see, the first session you place down an LTN station things are okay, except for the issues we were having. But after that the game is essentially dead :(.

0ptera commented 6 years ago

Going by your description There is my Ghost should add LTN entities either manually to a blacklist of entities that it mustn't mess up or add a hook like Creative Mode where mods can register their special entities them self. No way I can fix or prevent any bug that occurs from other mods changing default factorio behavior.

jarquafelmu commented 6 years ago

It wasn't just the there is my ghost issue though, even placing the ltn stops manually I was unable to interact with the combinator and lamp and also my friend couldn't join the game after reloading the save after placing our first LTN station. Do want me to make a new ticket for the lamp and combinator issue?

0ptera commented 5 years ago

You are mixing two very different things here.

1) IO entities have user interactions blocked since they are entirely script controlled. Changing their settings or removing them will cause errors.

2) I haven't heard anything about desync since There is my Ghost was fixed.