[1.1.59] Krastorio and QoL mods desync

Desyncs in modded game will be ignored most of the time, until it is clearly proven that the desync is not caused by scripting.
peternlewis
Inserter
Inserter
Posts: 49
Joined: Mon Aug 27, 2018 4:40 am
Contact:

[1.1.59] Krastorio and QoL mods desync

Post by peternlewis »

Seems to happen shortly after connecting. Frequently when you first use “q” or first place an item.

Frequently, but not always the server crashes.

2022-06-20 14:58:37 [JOIN] peternlewis joined the game
88547.672 Info ServerMultiplayerManager.cpp:947: updateTick(7761359) received stateChanged peerID(6) oldState(InGame) newState(DesyncedWaitingForMap)
88547.672 Info ServerMultiplayerManager.cpp:1032: updateTick(7761359) received playerDesynced peer (6)
88547.683 Info ServerMultiplayerManager.cpp:796: updateTick(7761359) changing state from(InGame) to(InGameSavingMapForDesyncReport)
88547.912 Error CrashHandler.cpp:635: Received SIGSEGV
88549.837 Error StacktraceToStream.cpp:13: Error getting stacktrace: executable file is not an executable
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
Factorio crashed. Generating symbolized stacktrace, please wait ...
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
88549.838 Error StacktraceToStream.cpp:13: Error getting stacktrace: failed to read executable information
Stack trace logging done
88549.838 Error CrashHandler.cpp:191: Map tick at moment of crash: 7761359
88549.838 Error Util.cpp:97: Unexpected error occurred. If you're running the latest version of the game you can help us solve the problem by posting the contents of the log file on the Factorio forums.
Please also include the save file(s), any mods you may be using, and any steps you know of to reproduce the crash.

------------- Error -------------
Unexpected error occurred. If you're running the latest version of the game you can help us solve the problem by posting the contents of the log file on the Factorio forums.
Please also include the save file(s), any mods you may be using, and any steps you know of to reproduce the crash.

Log file location: /Users/peter/Library/Application Support/factorio/factorio-current.log

Would you like to open the folder containing the log file?
---------------------------------
88549.838 Uploading log file
88549.841 Info SystemUtil.cpp:564: Started /Users/peter/factorio.app/Contents/MacOS/factorio; trampoline PID: 41372
88549.844 Info ChildProcessAgent.cpp:60: Child 41372 exited with return value 0

After the server crashes, I have to check when the MAP.zip file or an _autosave is more recent otherwise I can lose a lot of gameplay as frequently the MAP.zip file is hours out of date compared to the 10 minute autosaves.

It looks like the log file is overwritten when I restart the server, so it wont be much use but may indicate something.
Attachments
factorio-current.log
(16.3 KiB) Downloaded 121 times
desync-report-2022-06-20_15-31-54.zip
(79.63 MiB) Downloaded 134 times
desync-report-2022-06-13_18-22-47.zip
(45.94 MiB) Downloaded 138 times
desync-report-2022-06-13_18-14-05.zip
(46.04 MiB) Downloaded 136 times

User avatar
boskid
Factorio Staff
Factorio Staff
Posts: 2752
Joined: Thu Dec 14, 2017 6:56 pm
Contact:

Re: Krastorio and QoL mods desync

Post by boskid »

This is a mod desync related to "Placeables" mod which holds parts of its data outside of save-loaded structures. There are variables like "itemValidCache" and "ignoreEventFlag" which are not save-loaded properly because they are not stored inside of `global` and both of them are used to cause game state differences (inserting some items to inventories or updating guis).

lyvgbfh
Fast Inserter
Fast Inserter
Posts: 167
Joined: Fri Jul 10, 2020 6:48 pm
Contact:

Re: [1.1.59] Krastorio and QoL mods desync

Post by lyvgbfh »

Forwarded the issue to the author, thanks.

KingIonTrueLove
Inserter
Inserter
Posts: 23
Joined: Sun Jun 04, 2017 1:38 am
Contact:

Re: [1.1.59] Krastorio and QoL mods desync

Post by KingIonTrueLove »

The Placeables mod should be fixed now. Sorry about that!
What's crazy is that the mod has been like that since it was made almost 2 years ago but I never knew about this issue o.o

peternlewis
Inserter
Inserter
Posts: 49
Joined: Mon Aug 27, 2018 4:40 am
Contact:

Re: [1.1.59] Krastorio and QoL mods desync

Post by peternlewis »

Thanks, much appreciated, I will update the mod and verify that the desyncs stop.

peternlewis
Inserter
Inserter
Posts: 49
Joined: Mon Aug 27, 2018 4:40 am
Contact:

Re: [1.1.59] Krastorio and QoL mods desync

Post by peternlewis »

OK, I can't really determine if this fixes the issue because if I make any changes to the mods on the server, then after syncing the client it connects and then quickly gives a Server is Not Responding and drops the connection. It does not seem to matter what mod change I make - if I upgrade Placeables, or Delete Placeables, any change results in the same issue.

To get back to working I need to restore the map and mods and factorio settings to as they were before the change. Anything else results in Server Not Responding.

The client log indicates:

26.517 Info ClientMultiplayerManager.cpp:610: UpdateTick(9305083) changing state from(ConnectedLoadingMap) to(TryingToCatchUp)
26.767 Info ClientMultiplayerManager.cpp:610: UpdateTick(9305174) changing state from(TryingToCatchUp) to(WaitingForCommandToStartSendingTickClosures)
26.815 Info ClientMultiplayerManager.cpp:610: UpdateTick(9305174) changing state from(WaitingForCommandToStartSendingTickClosures) to(InGame)
26.833 Info GameActionHandler.cpp:5015: UpdateTick (9305175) processed PlayerJoinGame peerID(1) playerIndex(0) mode(connect)
48.449 Info UnparsedNetworkMessage.cpp:91: Invalid packet (type ServerToClientHeartbeat) received from IP ADDR:({10.0.0.4:34197}): heartbeat sequence number (5724) outside latency window [4524, 5724)
48.449 Info UnparsedNetworkMessage.cpp:102: Message data: 07 16 5c 16 00 00 6a 01 8e 00 04 24 01 4a ff ff ff 0a b1 ab 15 69 01 8e 00 01 0f 6a 01 8e 00 00 00
48.466 Info UnparsedNetworkMessage.cpp:91: Invalid packet (type ServerToClientHeartbeat) received from IP ADDR:({10.0.0.4:34197}): heartbeat sequence number (5725) outside latency window [4524, 5724)
48.466 Info UnparsedNetworkMessage.cpp:102: Message data: 07 16 5d 16 00 00 6b 01 8e 00 04 24 01 4a ff ff ff 72 53 e2 5c 6a 01 8e 00 01 0f 6b 01 8e 00 00 00


The server logs indicate:

74.120 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({10.0.0.3:52313}))
74.120 Refusing connection for address (IP ADDR:({10.0.0.3:52313})), username (peternlewis). UserVerificationMissing
75.384 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({10.0.0.3:63215}))
75.384 Info ServerRouter.cpp:467: Replying to connectionRequest for address(IP ADDR:({10.0.0.3:63215})).
75.384 Info ServerSynchronizer.cpp:608: nextHeartbeatSequenceNumber(4175) adding peer(1)
75.413 Info ServerMultiplayerManager.cpp:796: updateTick(9305083) changing state from(InGame) to(InGameSavingMap)
75.417 Info ServerMultiplayerManager.cpp:947: updateTick(9305083) received stateChanged peerID(1) oldState(Ready) newState(ConnectedWaitingForMap)
75.966 Info ServerMultiplayerManager.cpp:1015: UpdateTick(9305083) Serving map(/Users/peter/Library/Application Support/factorio/temp/mp-save-0.zip) for peer(1) size(13323700) crc(1250038298)
75.966 Info ServerMultiplayerManager.cpp:796: updateTick(9305083) changing state from(InGameSavingMap) to(InGame)
76.017 Info ServerMultiplayerManager.cpp:947: updateTick(9305083) received stateChanged peerID(1) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
78.000 Info ServerMultiplayerManager.cpp:947: updateTick(9305083) received stateChanged peerID(1) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
79.367 Info ServerMultiplayerManager.cpp:947: updateTick(9305164) received stateChanged peerID(1) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
79.553 Info ServerMultiplayerManager.cpp:947: updateTick(9305175) received stateChanged peerID(1) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
79.554 Info GameActionHandler.cpp:5015: UpdateTick (9305175) processed PlayerJoinGame peerID(1) playerIndex(0) mode(connect)
79.603 Info ServerMultiplayerManager.cpp:947: updateTick(9305178) received stateChanged peerID(1) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
101.383 Warning ServerSynchronizer.cpp:115: nextHeartbeatSequenceNumber(5735) peer(1) wants a heartbeat(4524) that we don't have.
105.819 Info ServerMultiplayerManager.cpp:1061: Disconnect notification for peer (1)
105.819 Info ServerSynchronizer.cpp:627: nextHeartbeatSequenceNumber(6002) removing peer(1).
106.817 Info ServerMultiplayerManager.cpp:1209: Auto saving map as /Users/peter/factorio/MAP.zip
106.833 Info AppManager.cpp:420: Saving game as /Users/peter/factorio/MAP.zip
106.837 Info AsyncScenarioSaver.cpp:156: Saving process PID: 95817
107.838 Info ChildProcessAgent.cpp:60: Child 95817 exited with return value 0
107.839 Info AppManager.cpp:423: Saving finished

The UserVerificationMissing is weird because I am logged in on the client, which is required by the server and works normally.
Attachments
factorio-current.log
(10.31 KiB) Downloaded 106 times
factorio-current.log
(111.28 KiB) Downloaded 105 times

lyvgbfh
Fast Inserter
Fast Inserter
Posts: 167
Joined: Fri Jul 10, 2020 6:48 pm
Contact:

Re: [1.1.59] Krastorio and QoL mods desync

Post by lyvgbfh »

It looks like the servers are currently having issues, folks have been reporting both here on the forums (viewtopic.php?f=49&t=102726) and on the discord. May just need to give it some time or disable verification for the time being.

peternlewis
Inserter
Inserter
Posts: 49
Joined: Mon Aug 27, 2018 4:40 am
Contact:

Re: [1.1.59] Krastorio and QoL mods desync

Post by peternlewis »

lyvgbfh wrote:
Tue Jun 21, 2022 7:28 am
It looks like the servers are currently having issues, folks have been reporting both here on the forums (viewtopic.php?f=49&t=102726) and on the discord. May just need to give it some time or disable verification for the time being.
Why would that only affect my server if I change the mods?

I have a two local Macs, one client, one server. I change the mods on the client, and then stop the server, change the mods on the server, start the server, and the connection fails. Any change to the mods seems to cause the issue, change version, or remove the mod, either way it fails with Server is Not Responding and dropped connection.Both Macs are fast and well connected, so network or computer speed should not be an issue, and the game runs normally (when it is running normally) at 60/60.

If I stop the server, restore the server (map, mods, settings), and restart it, and sync up to the original mods, then it works.

I've repeated the above process in various ways with various mod changes, and the result is consistent - any change to the mods results in Server is Not Responding quickly after connection.

Unless Factorio is doing some sort of extra check when the server notices the mods are changed, I don't see how the Factorio servers behaviour should make any difference.

peternlewis
Inserter
Inserter
Posts: 49
Joined: Mon Aug 27, 2018 4:40 am
Contact:

Re: [1.1.59] Krastorio and QoL mods desync

Post by peternlewis »

No ideas what would cause the Server Not Responding when I change the mods? I'd really like to update the mod as the desyncs are quite annoyingly frequent and the crashes that sometimes happen can lose a few minutes of build.

Thanks.

lyvgbfh
Fast Inserter
Fast Inserter
Posts: 167
Joined: Fri Jul 10, 2020 6:48 pm
Contact:

Re: [1.1.59] Krastorio and QoL mods desync

Post by lyvgbfh »

peternlewis wrote:
Wed Jun 22, 2022 9:45 am
No ideas what would cause the Server Not Responding when I change the mods? I'd really like to update the mod as the desyncs are quite annoyingly frequent and the crashes that sometimes happen can lose a few minutes of build.

Thanks.
Can you try with RecipeBook disabled, or reducing the dictionary levels per batch mod setting? If you can provide a log as well for the new issue that would help.

Post Reply

Return to “Desyncs with mods”