Page 1 of 1

Service is not responding shortly after connecting

Posted: Sun Jul 31, 2022 8:50 am
by peternlewis
I'm trying to run a server, and I've had this issue with a variety of mod selections. Sometimes it works, sometimes it fails with “Service is not responding”. Sometimes there is an error “peternlewis’s computer or network could not keep up with the server, so they have been disconnected”, except my network connection is a direct ethernet connection, and my Mac is a Mac Studio, so very fast, and the server is a good speed iMac, so this seems unlikely.

If I fiddle with mods, enabling/disabling some mods, then I'll likely get it working. And then from past experience it is extremely fragile - as long as I touch nothing, it will stay working, but if I change *anything* (upgrade a mod, remove a mod, upgrade Factorio, pretty much anything), it will get back in to this state where if fails quickly after connecting with “Service is not responding”. If I restore the server Factorio app, mods folder and map from a backup, it will go back to working. Change anything and it breaks again. So it does not feel like a situation where it's actually caused by the network or computer speeds (there is no reason a Factorio app update or removing a mod would make that difference).

This is the console messages on the server when this happens:

86394.536 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({10.0.0.3:53700}))
86394.544 Refusing connection for address (IP ADDR:({10.0.0.3:53700})), username (peternlewis). UserVerificationMissing
86395.604 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({10.0.0.3:60166}))
86395.604 Info ServerRouter.cpp:451: Replying to connectionRequest for address(IP ADDR:({10.0.0.3:60166})).
86395.604 Info ServerSynchronizer.cpp:604: nextHeartbeatSequenceNumber(5183507) adding peer(5)
86395.629 Info ServerMultiplayerManager.cpp:797: updateTick(8077) changing state from(InGame) to(InGameSavingMap)
86395.636 Info ServerMultiplayerManager.cpp:948: updateTick(8077) received stateChanged peerID(5) oldState(Ready) newState(ConnectedWaitingForMap)
86396.158 Info ServerMultiplayerManager.cpp:1011: UpdateTick(8077) Serving map(/Users/peter/Library/Application Support/factorio/temp/mp-save-4.zip) for peer(5) size(3116785) auxiliary(530) crc(264570133)
86396.158 Info ServerMultiplayerManager.cpp:797: updateTick(8077) changing state from(InGameSavingMap) to(InGame)
86396.221 Info ServerMultiplayerManager.cpp:948: updateTick(8077) received stateChanged peerID(5) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
86397.136 Info ServerMultiplayerManager.cpp:948: updateTick(8077) received stateChanged peerID(5) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
86398.470 Info ServerMultiplayerManager.cpp:948: updateTick(8156) received stateChanged peerID(5) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
86398.587 Info ServerMultiplayerManager.cpp:948: updateTick(8163) received stateChanged peerID(5) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
86398.587 Info GameActionHandler.cpp:5016: UpdateTick (8163) processed PlayerJoinGame peerID(5) playerIndex(0) mode(connect)
86398.638 Info ServerMultiplayerManager.cpp:948: updateTick(8166) received stateChanged peerID(5) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
2022-07-31 15:48:40 [JOIN] peternlewis joined the game
86420.987 Warning ServerSynchronizer.cpp:115: nextHeartbeatSequenceNumber(5185030) peer(5) wants a heartbeat(5183818) that we don't have.
86423.840 Info ServerMultiplayerManager.cpp:1058: Disconnect notification for peer (5)
86423.840 Info ServerSynchronizer.cpp:623: nextHeartbeatSequenceNumber(5185202) removing peer(5).
86424.836 Info ServerMultiplayerManager.cpp:1205: Auto saving map as /Users/peter/factorio/MAP.zip
86424.853 Info AppManager.cpp:420: Saving game as /Users/peter/factorio/MAP.zip
86424.856 Info AsyncScenarioSaver.cpp:156: Saving process PID: 75221
86425.591 Info ChildProcessAgent.cpp:60: Child 75221 exited with return value 0
86425.592 Info AppManager.cpp:423: Saving finished

I've attached the factorio-current.log from the client, which shows it going astray with:

68.349 Info ClientMultiplayerManager.cpp:610: UpdateTick(9679) changing state from(ConnectedLoadingMap) to(TryingToCatchUp)
68.484 Info ClientMultiplayerManager.cpp:610: UpdateTick(9765) changing state from(TryingToCatchUp) to(WaitingForCommandToStartSendingTickClosures)
68.548 Info ClientMultiplayerManager.cpp:610: UpdateTick(9765) changing state from(WaitingForCommandToStartSendingTickClosures) to(InGame)
68.582 Info GameActionHandler.cpp:5016: UpdateTick (9767) processed PlayerJoinGame peerID(6) playerIndex(0) mode(connect)
81.869 Info ClientSynchronizer.cpp:327: Latency changed to (254)
106.115 Info UnparsedNetworkMessage.cpp:91: Invalid packet (type ServerToClientHeartbeat) received from IP ADDR:({10.0.0.4:34197}): heartbeat sequence number (5201234) outside latency window [5200034, 5201234)
106.115 Info UnparsedNetworkMessage.cpp:102: Message data: 27 16 52 5d 4f 00 f6 2e 00 00 04 24 01 4a ff ff ff 43 95 44 22 f5 2e 00 00 01 0f f6 2e 00 00 00 00

(and then lots more UnparsedNetworkMessage messages)

I'd love to figure out the cause of this since it's reoccurred pretty much every time I've set up a network game - I get it working, play through the whole game (eg Space Exploration, Nullius or Krastorio), but once started I cannot touch anything without this behaviour resurfacing, so if there is a mod update or a Factorio update, we just have to avoid the update until the game is finished.

Current mods for this game are listed below, but again, I don't really think it is an issue of a specific mod, as I get the issue with each different set of mods. Maybe one of the QoL mods since they might be consistent across the different runs, but most of the mods are not consistent, and again, I can get it working with the QoL mods, just after some random fiddling around, enabling/disabling mods until it works.

248k_1.0.29.zip
aai-programmable-structures_0.7.4.zip
aai-programmable-vehicles_0.7.22.zip
aai-signal-transmission_0.4.7.zip
aai-signals_0.6.1.zip
aai-vehicles-chaingunner_0.6.1.zip
aai-vehicles-flame-tank_0.5.1.zip
aai-vehicles-flame-tumbler_0.6.1.zip
aai-vehicles-hauler_0.6.1.zip
aai-vehicles-ironclad_0.6.5.zip
aai-vehicles-laser-tank_0.6.4.zip
aai-vehicles-miner_0.6.4.zip
aai-vehicles-warden_0.5.3.zip
aai-zones_0.6.4.zip
factoryplanner_1.1.51.zip
FactorySearch_1.9.1.zip
FasterPavements_0.3.0.zip
flib_0.10.1.zip
informatron_0.2.2.zip
LogisticTrainNetwork_1.16.10.zip
LTN_Combinator_Modernized_1.0.11.zip
LTN_Content_Reader_1.0.2.zip
LtnManager_0.4.15.zip
mod-list.json
mod-settings.dat
RateCalculator_2.4.4.zip
RecipeBook_3.4.5.zip
textplates_0.6.9.zip
Todo-List_19.2.0.zip
VehicleSnap_1.18.4.zip

I've also attached the server settings, since they tend to be consistent between games, and its possible something in there could be the issue. I normally use non_blocking_saving, which I've never had any trouble with, but I turned it off just in case that was an issue, but that made no difference.

Thanks for any suggestions as to where the issue might really lie, or how to resolve it.

Re: Service is not responding shortly after connecting

Posted: Sun Jul 31, 2022 9:00 am
by Loewchen

Re: Service is not responding shortly after connecting

Posted: Mon Aug 01, 2022 1:47 am
by peternlewis
Loewchen wrote: Sun Jul 31, 2022 9:00 am Check viewtopic.php?p=570111#p570111
That seems to have done it, I changed the Map setting for Factorio Library, Dictionary levels per batch from 15 to 5 and it seems to have resolved the problem.

I imagine Factorio Library awesome. No idea why it sometimes worked and sometimes didn't and was so consistent as to what worked and what didn't, but hopefully this will resolve it going forward.

Much appreciated!