[1.1.39] Server without players not paused while catching up

Bugs that are actually features.
Post Reply
oof2win2
Long Handed Inserter
Long Handed Inserter
Posts: 56
Joined: Wed Nov 18, 2020 8:13 am
Contact:

[1.1.39] Server without players not paused while catching up

Post by oof2win2 »

So I have a server with large hardware requirements for players to join.
The following scenario is with no players in-game or connecting, except for me.
My issue is that when downloading the map, the server is paused, and the tick stays the same. Whilst loading and catching up, the server however turns back on (the tick is unpaused), as you can see in the image below. I believe that this is a bug since it is unwanted passing of time on the server. If a person that doesn't have a good computer joins, has the progress bar in the middle for catching up and goes away, the server will be left running for an undetermined period of time, probably until the connection from the client is ended. This can advance time in-game severely and cause unnecessary strain on the server itself.
pic
In the image above, the game's save is _autosave21 (as it has been copied from another server) and autosave69 is an actual autosave.
Here is the relevant log

Code: Select all

  61.768 Info ServerSynchronizer.cpp:600: nextHeartbeatSequenceNumber(1500) adding peer(1)
  61.786 Info ServerMultiplayerManager.cpp:780: updateTick(63119710) changing state from(InGame) to(InGameSavingMap)
  61.854 Info ServerMultiplayerManager.cpp:930: updateTick(63119710) received stateChanged peerID(1) oldState(Ready) newState(ConnectedWaitingForMap)
  66.387 Info ServerMultiplayerManager.cpp:997: UpdateTick(63119710) Serving map(/opt/factorio/servers/test/temp/mp-save-0.zip) for peer(1) size(193674018) crc(2213513611)
  66.387 Info ServerMultiplayerManager.cpp:780: updateTick(63119710) changing state from(InGameSavingMap) to(InGame)
  66.572 Info ServerMultiplayerManager.cpp:930: updateTick(63119710) received stateChanged peerID(1) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
 100.514 Info ServerMultiplayerManager.cpp:1048: Disconnect notification for peer (1)
 100.514 Info ServerMultiplayerManager.cpp:930: updateTick(63119710) received stateChanged peerID(1) oldState(ConnectedDownloadingMap) newState(DisconnectScheduled)
 100.544 Info ServerSynchronizer.cpp:619: nextHeartbeatSequenceNumber(2649) removing peer(1).
 129.908 Info RemoteCommandProcessor.cpp:241: New RCON connection from IP ADDR:({127.0.0.1:33310})
 148.752 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({94.142.236.149:49057}))
 148.752 Info ServerRouter.cpp:459: Replying to connectionRequest for address(IP ADDR:({94.142.236.149:49057})).
 148.752 Info ServerSynchronizer.cpp:600: nextHeartbeatSequenceNumber(4083) adding peer(2)
 148.771 Info ServerMultiplayerManager.cpp:780: updateTick(63119713) changing state from(InGame) to(InGameSavingMap)
 148.821 Info ServerMultiplayerManager.cpp:930: updateTick(63119713) received stateChanged peerID(2) oldState(Ready) newState(ConnectedWaitingForMap)
 153.317 Info ServerMultiplayerManager.cpp:997: UpdateTick(63119713) Serving map(/opt/factorio/servers/test/temp/mp-save-1.zip) for peer(2) size(193674534) crc(1028429284)
 153.317 Info ServerMultiplayerManager.cpp:780: updateTick(63119713) changing state from(InGameSavingMap) to(InGame)
 153.502 Info ServerMultiplayerManager.cpp:930: updateTick(63119713) received stateChanged peerID(2) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
 360.603 Info ServerMultiplayerManager.cpp:930: updateTick(63119715) received stateChanged peerID(2) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
 369.901 Script @/opt/factorio/servers/test/temp/currently-playing/overrides/print.lua:7: [PRINT] JLOGGER: ROCKET: ROCKET LAUNCHED
 380.446 Script @/opt/factorio/servers/test/temp/currently-playing/overrides/print.lua:7: [PRINT] JLOGGER: ROCKET: ROCKET LAUNCHED
 403.422 Script @/opt/factorio/servers/test/temp/currently-playing/overrides/print.lua:7: [PRINT] JLOGGER: ROCKET: ROCKET LAUNCHED
 405.507 Script @/opt/factorio/servers/test/temp/currently-playing/overrides/print.lua:7: [PRINT] JLOGGER: EVOLUTION: 0.9990
 409.970 Script @/opt/factorio/servers/test/temp/currently-playing/overrides/print.lua:7: [PRINT] JLOGGER: ROCKET: ROCKET LAUNCHED
 424.993 Info ServerMultiplayerManager.cpp:930: updateTick(63123570) received stateChanged peerID(2) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
 454.540 Script @/opt/factorio/servers/test/temp/currently-playing/overrides/print.lua:7: [PRINT] JLOGGER: ROCKET: ROCKET LAUNCHED
 465.508 Script @/opt/factorio/servers/test/temp/currently-playing/overrides/print.lua:7: [PRINT] JLOGGER: EVOLUTION: 0.9990
 465.509 Script @/opt/factorio/servers/test/temp/currently-playing/overrides/print.lua:7: [PRINT] JLOGGER: STATS: Windsinger 0 6024
 465.509 Script @/opt/factorio/servers/test/temp/currently-playing/overrides/print.lua:7: [PRINT] JLOGGER: STATS: Acidlemon 0 13339
 465.525 Info AppManager.cpp:286: Saving to _autosave69 (non-blocking).
 465.583 Info AsyncScenarioSaver.cpp:156: Saving process PID: 1544414
 471.968 Info ChildProcessAgent.cpp:60: Child 1544414 exited with return value 0
 471.968 Info AppManager.cpp:287: Saving finished
 497.084 Info ServerMultiplayerManager.cpp:1048: Disconnect notification for peer (2)
 497.084 Info ServerMultiplayerManager.cpp:930: updateTick(63127885) received stateChanged peerID(2) oldState(TryingToCatchUp) newState(DisconnectScheduled)
 497.098 Info ServerSynchronizer.cpp:619: nextHeartbeatSequenceNumber(14507) removing peer(2).
 498.104 Info ServerMultiplayerManager.cpp:1196: Auto saving map as /opt/factorio/servers/test/saves/_autosave21.zip
 498.104 Info AppManager.cpp:420: Saving game as /opt/factorio/servers/test/saves/_autosave21.zip
 498.172 Info AsyncScenarioSaver.cpp:156: Saving process PID: 1544910
 504.220 Info ChildProcessAgent.cpp:60: Child 1544910 exited with return value 0
 504.221 Info AppManager.cpp:423: Saving finished

KeepResearchinSpoons
Long Handed Inserter
Long Handed Inserter
Posts: 77
Joined: Tue Dec 01, 2020 6:57 pm
Contact:

Re: [1.1.39] Server without players not paused while catching up

Post by KeepResearchinSpoons »

hello,
can you pls check how often the rcon "usually" goes for the server?
I want to cross-check if this one is related again yet another time.

(i.e. I expect something like this)
webm
(to be the reason underneath)

oof2win2
Long Handed Inserter
Long Handed Inserter
Posts: 56
Joined: Wed Nov 18, 2020 8:13 am
Contact:

Re: [1.1.39] Server without players not paused while catching up

Post by oof2win2 »

I understand, however that is not what is occurring here. My rcon is polling only once a second when players are online, which they are not - since it is only me who is connecting. Even if the checking logic was broken and the handlers ran, the time difference would be inexplicable; from the Discord photo, you can see the bot showing me the game's tick. It's a time difference of ~136 seconds (8174 ticks), so that would take over 2 hours for the bot to poll at the speed that it normally does, which it did not, rather the 136 seconds correspond about to the times when I joined and left.

If you want to handle your issue, you could try saving the amount of players through the `/c rcon.print(#game.players)` lua script (on bot/script init) and the factorio-current log which outputs player joins and leaves.

User avatar
Klonan
Factorio Staff
Factorio Staff
Posts: 5150
Joined: Sun Jan 11, 2015 2:09 pm
Contact:

Re: [1.1.39] Server without players not paused while catching up

Post by Klonan »

oof2win2 wrote:
Wed Sep 22, 2021 6:01 pm
Whilst loading and catching up, the server however turns back on (the tick is unpaused), as you can see in the image below.
As the code is written, this is not a bug

There is also a related topic that was moved to ideas, you can post support to it:
viewtopic.php?f=6&t=94793

Post Reply

Return to “Not a bug”