[Pending] 12.33 Desyncing due to 100% CPU spike

[malk0lm]

We enter a desync loop once the CPU hits 100%, on future connections even if the CPU is <100% it still desyncs.

Code: Select all

161372.992 Error NetworkInputHandler.cpp:360: Multiplayer desynchronisation: crc test(CheckCRCHeuristic) failed for mapTick(43347000) peer(7) testCrc(-237165950) testCrcPeerID(0) currentCrc(2090073090)
161372.993 Info NetworkInputHandler.cpp:402: Desync specification: Reference CRC = 4057801346, reference peers = {0}; desynced CRC = 2090073090, desynced peer = 7 (malk0lm)
161373.409 Info MultiplayerManager.cpp:1060: networkTick(9664556) mapTick(43347028) received stateChanged peerID(7) oldState(InGame) newState(Desynced)
161373.410 Info MultiplayerManager.cpp:913: networkTick(9664556) mapTick(43347028) changing state from(InGame) to(InGameAligning)
161373.411 Info MultiplayerManager.cpp:1719: networkTick(9664556) mapTick(43347028) starting mapAlign
161373.623 Info MultiplayerManager.cpp:1060: networkTick(9664568) mapTick(43347028) received stateChanged peerID(0) oldState(InGame) newState(InGameAligning)
161373.624 Info MultiplayerManager.cpp:1060: networkTick(9664568) mapTick(43347028) received stateChanged peerID(7) oldState(Desynced) newState(DesyncedAligning)
161373.624 Info MultiplayerManager.cpp:1653: networkTick(9664568) mapTick(43347028) sending mapAlignAction
161373.823 Info MultiplayerManager.cpp:1307: networkTick(9664580) mapTick(43347028) received MapAlignAction from peer(0), mapAlignTick(43347029) appliedTickClosuresCount(0)
161373.824 Info MultiplayerManager.cpp:1307: networkTick(9664580) mapTick(43347028) received MapAlignAction from peer(7), mapAlignTick(43347016) appliedTickClosuresCount(42)
161373.824 Info MultiplayerManager.cpp:1735: networkTick(9664581) mapTick(43347028) mapAlign finished targetTick(43347029) updating map and running the tasks ...
161373.824 Info MultiplayerManager.cpp:1607: networkTick(9664581) mapTick(43347028) peerID(0) fullStateLog: local state(InGameAligning) local peers(((peerID(0) state(InGameAligning) mapAlignTick(43347029))
((peerID(7) state(DesyncedAligning) mapAlignTick(43347016))
)
161373.852 Info MultiplayerManager.cpp:1754: maptick(43347029) crc before applying all ticks: 1644269338
161373.852 Info NetworkInputHandler.cpp:661: applyAllTickClosures: expectedMapTick(43347029) lastTickApplied(43347014) referenceMapTick(43347029) networkTick(9664581)
161373.853 Info MultiplayerManager.cpp:1762: maptick(43347029) crc after applying all ticks: 1644269338
161373.853 Info MultiplayerManager.cpp:913: networkTick(9664581) mapTick(43347029) changing state from(InGameAligning) to(InGameAligned)
161374.240 Info MultiplayerManager.cpp:1060: networkTick(9664593) mapTick(43347029) received stateChanged peerID(0) oldState(InGameAligning) newState(InGameAligned)
161374.241 Info MultiplayerManager.cpp:1060: networkTick(9664593) mapTick(43347029) received stateChanged peerID(7) oldState(DesyncedAligning) newState(DesyncedAligned)
161374.440 Info MultiplayerManager.cpp:1324: networkTick(9664605) mapTick(43347029) received playerReconnect
161374.441 Info MultiplayerManager.cpp:2121: NetworkTick(9664605) MapTick(43347029) disconnecting player(0) from the user.
161374.443 Info NetworkInputHandler.cpp:544: expectedMapTick(43347029) removing peer(7) success(true).
161374.443 Info NetworkInputHandler.cpp:520: expectedMapTick(43347029) adding peer(7).
161374.443 Info MultiplayerManager.cpp:1060: networkTick(9664605) mapTick(43347029) received stateChanged peerID(7) oldState(DesyncedAligned) newState(DesyncedCreatingReport)
161386.489 Info Synchronizer.cpp:444: NetworkTick(9665248) peer(7) drop detection state(100/900).
161388.156 Info Synchronizer.cpp:444: NetworkTick(9665248) peer(7) drop detection state(200/900).
161389.207 Info MultiplayerManager.cpp:1060: networkTick(9665248) mapTick(43347029) received stateChanged peerID(7) oldState(DesyncedCreatingReport) newState(DesyncedWaitingForMap)
161389.212 Info MultiplayerManager.cpp:913: networkTick(9665248) mapTick(43347029) changing state from(InGameAligned) to(InGameSavingMap)
161389.406 Info MultiplayerManager.cpp:1060: networkTick(9665260) mapTick(43347029) received stateChanged peerID(0) oldState(InGameAligned) newState(InGameSavingMap)
161426.190 Info MultiplayerManager.cpp:913: networkTick(9667468) mapTick(43347029) changing state from(InGameSavingMap) to(InGameSendingMap)
161426.313 Info MultiplayerManager.cpp:1177: MapTick(43347029) Serving map(/srv/factorio/temp/mp-download.zip) for peer(7) size(21896450) crc(-1796873536)
161426.397 Info MultiplayerManager.cpp:1060: networkTick(9667480) mapTick(43347029) received stateChanged peerID(0) oldState(InGameSavingMap) newState(InGameSendingMap)
161426.605 Info MultiplayerManager.cpp:1060: networkTick(9667492) mapTick(43347029) received stateChanged peerID(7) oldState(DesyncedWaitingForMap) newState(DesyncedDownloadingMap)
161438.221 Info MultiplayerManager.cpp:1060: networkTick(9668172) mapTick(43347029) received stateChanged peerID(7) oldState(DesyncedDownloadingMap) newState(DesyncedLoadingMap)
161438.222 Canceling serving for peer 7
161438.227 Info MultiplayerManager.cpp:913: networkTick(9668172) mapTick(43347029) changing state from(InGameSendingMap) to(InGameWaitingForOthers)
161438.421 Info MultiplayerManager.cpp:1060: networkTick(9668184) mapTick(43347029) received stateChanged peerID(0) oldState(InGameSendingMap) newState(InGameWaitingForOthers)
161450.204 Info MultiplayerManager.cpp:1060: networkTick(9668891) mapTick(43347029) received stateChanged peerID(7) oldState(DesyncedLoadingMap) newState(InGameWaitingForOthers)
161450.212 Info MultiplayerManager.cpp:1259: networkTick(9668891) mapTick(43347029) stopping mapAlign
161450.212 Info MultiplayerManager.cpp:913: networkTick(9668891) mapTick(43347029) changing state from(InGameWaitingForOthers) to(InGame)
161450.213 Info MultiplayerManager.cpp:1607: networkTick(9668891) mapTick(43347029) peerID(0) fullStateLog: local state(InGame) local peers(((peerID(0) state(InGameWaitingForOthers) mapAlignTick(-1))
((peerID(7) state(InGameWaitingForOthers) mapAlignTick(-1))
)
161450.443 Info MultiplayerManager.cpp:1060: networkTick(9668903) mapTick(43347030) received stateChanged peerID(0) oldState(InGameWaitingForOthers) newState(InGame)
161450.443 Info MultiplayerManager.cpp:1060: networkTick(9668903) mapTick(43347030) received stateChanged peerID(7) oldState(InGameWaitingForOthers) newState(InGame)
161451.056 Info NetworkInputHandler.cpp:599: assigning playerIndex(0) to peer(7)
161451.057 Info GameActionHandler.cpp:1949: MapTick(43347044) processed PlayerJoinGame peerID(7) playerIndex(0) mode(connect)
161453.487 Error NetworkInputHandler.cpp:360: Multiplayer desynchronisation: crc test(CheckCRCHeuristic) failed for mapTick(43347120) peer(7) testCrc(18953913) testCrcPeerID(0) currentCrc(-579860020)
161453.488 Info NetworkInputHandler.cpp:402: Desync specification: Reference CRC = 18953913, reference peers = {0}; desynced CRC = 3715107276, desynced peer = 7 (malk0lm)

[Loewchen]

I would not give much thought to the CPU utilization. Please upload mod-list and the desync-report from the desynced peer.

Greetings Loewchen

[Klonan]

Thanks for the report,

Can you provide a save game, mods and any steps to reproduce the issue?
Does it still desync without mods?

[malk0lm]

With no mods the CPU never reaches 100%

We have a savegame which uses about two dozen belts in a bus, and no one can connect. We think the rendering thread is utilizing 100% cpu which leads to the netcode not being able to keep up with the peer traffic. We updated the savegame to use underground belts and now we can connect.

Mod list is here: https://aerodo.me/

[Rseding91]

If the hardware can't process the game fast enough then it's not going to work - it's as simple as that. Who ever is hitting 100% CPU usage and lagging behind the rest needs to get better hardware to keep playing with the rest - that's not something we can fix.

[sillyfly]

If the hardware can't process the game fast enough then it's not going to work - it's as simple as that. Who ever is hitting 100% CPU usage and lagging behind the rest needs to get better hardware to keep playing with the rest - that's not something we can fix.

Err... isn't a more elegant behavior to have the others wait for the slowest peer? I thought that was what the game is already doing to account for network latency etc.

[Loewchen]

If the hardware can't process the game fast enough then it's not going to work - it's as simple as that. Who ever is hitting 100% CPU usage and lagging behind the rest needs to get better hardware to keep playing with the rest - that's not something we can fix.

Err... isn't a more elegant behaviour to have the others wait for the slowest peer? I thought that was what the game is already doing to account for network latency etc.

Not only that, we had games running at a fraction of the normal speed because of one peer having slow hardware, this works without error until the drop detection kicks in, but It is unplayable way before that and certainly does not cause desyncs.

[malk0lm]

If the hardware can't process the game fast enough then it's not going to work - it's as simple as that. Who ever is hitting 100% CPU usage and lagging behind the rest needs to get better hardware to keep playing with the rest - that's not something we can fix.

It's not a peer issue. You can desync from the headless server even when it is only you connected to the server. It's a 2.3Ghz Xenon E5-2630.