[1.1.19] Crash of non blocking saving process on headless

Things that we don't consider worth fixing at this moment.
luketyleruk
Burner Inserter
Burner Inserter
Posts: 17
Joined: Tue Nov 24, 2020 3:28 pm
Contact:

[1.1.19] Crash of non blocking saving process on headless

Post by luketyleruk »

Hi,
Im getting logs,

Code: Select all

   0.000 2021-01-31 16:54:01; Factorio 1.1.19 (build 57957, linux64, headless)
   0.039 Operating system: Linux (Debian 10)
   0.039 Program arguments: "./bin/x64/factorio" "--port" "34198" "--server-settings" "data/server-settings.json" "--start-server" "megabase_1.zip" 
   0.039 Read data path: /home/container/data
   0.039 Write data path: /home/container [23011/40007MB]
   0.039 Binaries path: /home/container/bin
   0.046 System info: [CPU: QEMU Virtual CPU version 2.5+, 4 cores, RAM: 11981 MB]
   0.046 Environment: DISPLAY=<unset> WAYLAND_DISPLAY=<unset> DESKTOP_SESSION=<unset> XDG_SESSION_DESKTOP=<unset> XDG_CURRENT_DESKTOP=<unset> __GL_FSAA_MODE=<unset> __GL_LOG_MAX_ANISO=<unset> __GL_SYNC_TO_VBLANK=<unset> __GL_SORT_FBCONFIGS=<unset> __GL_YIELD=<unset>
   0.046 Running in headless mode
   0.083 Loading mod core 0.0.0 (data.lua)
   0.144 Loading mod base 1.1.19 (data.lua)
   0.353 Loading mod base 1.1.19 (data-updates.lua)
   0.457 Checksum for core: 1905034584
   0.457 Checksum of base: 1503457007
   0.595 Prototype list checksum: 3034860339
   0.629 Info PlayerData.cpp:70: Local player-data.json available, timestamp 1612111850
   0.629 Info PlayerData.cpp:77: Cloud player-data.json unavailable
   0.630 Factorio initialised
   0.630 Info ServerSynchronizer.cpp:29: nextHeartbeatSequenceNumber(0) initialized Synchronizer nextTickClosureTick(0).
   0.630 Info ServerMultiplayerManager.cpp:780: updateTick(4294967295) changing state from(Ready) to(PreparedToHostGame)
   0.630 Info ServerMultiplayerManager.cpp:780: updateTick(4294967295) changing state from(PreparedToHostGame) to(CreatingGame)
   0.631 Loading map /home/container/megabase_1.zip: 72450066 bytes.
   0.639 Loading level.dat: 227699072 bytes.
   0.649 Info Scenario.cpp:197: Map version 1.1.19-0
   5.458 Loading script.dat: 407 bytes.
   5.460 Checksum for script /home/container/temp/currently-playing/control.lua: 4121531723
   5.507 Info UDPSocket.cpp:27: Opening socket at (IP ADDR:({0.0.0.0:34198}))
   5.507 Hosting game at IP ADDR:({0.0.0.0:34198})
   5.507 Info HttpSharedState.cpp:54: Downloading https://auth.factorio.com/generate-server-padlock-2?api_version=4
   5.836 Info AuthServerConnector.cpp:68: Obtained serverPadlock for serverHash (UTUtQs7sSvYldKR5HlB0nV883FLRa3vY) from the auth server.
   5.836 Info ServerMultiplayerManager.cpp:780: updateTick(3960030) changing state from(CreatingGame) to(InGame)
   5.851 Info ServerRouter.cpp:636: Asking pingpong servers (pingpong1.factorio.com:34197, pingpong2.factorio.com:34197, pingpong3.factorio.com:34197, pingpong4.factorio.com:34197) for own address
   5.851 Info UDPSocket.cpp:39: Opening socket for broadcast
   5.851 Info CommandLineMultiplayer.cpp:278: Maximum segment size = 100; minimum segment size = 25; maximum-segment-size peer count = 10; minimum-segment-size peer count = 20
   5.935 Info ServerRouter.cpp:519: Own address is IP ADDR:({51.77.226.83:34198}) (confirmed by pingpong1)
   5.952 Info ServerRouter.cpp:519: Own address is IP ADDR:({51.77.226.83:34198}) (confirmed by pingpong3)
   6.104 Info ServerRouter.cpp:519: Own address is IP ADDR:({51.77.226.83:34198}) (confirmed by pingpong4)
   6.297 Info MatchingServer.cpp:114: Matching server game `9077237` has been created.
   6.308 Info ServerMultiplayerManager.cpp:712: Matching server connection resumed
  70.311 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({217.137.42.60:3141}))
  70.311 Refusing connection for address (IP ADDR:({217.137.42.60:3141})), username (ColonelWill). UserVerificationMissing
  71.050 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({217.137.42.60:3145}))
  71.050 Refusing connection for address (IP ADDR:({217.137.42.60:3145})), username (ColonelWill). PasswordMissing
  74.911 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({217.137.42.60:3146}))
  74.912 Info ServerRouter.cpp:453: Replying to connectionRequest for address(IP ADDR:({217.137.42.60:3146})).
  74.912 Info ServerSynchronizer.cpp:600: nextHeartbeatSequenceNumber(2058) adding peer(1)
  74.929 Warning WriteFileGuard.cpp:96: Couldn't chown /home/container/player-data.tmp.json: Operation not permitted
  74.930 Info ServerMultiplayerManager.cpp:780: updateTick(3960030) changing state from(InGame) to(InGameSavingMap)
  74.998 Info ServerMultiplayerManager.cpp:930: updateTick(3960030) received stateChanged peerID(1) oldState(Ready) newState(ConnectedWaitingForMap)
  77.154 Info ServerMultiplayerManager.cpp:997: UpdateTick(3960030) Serving map(/home/container/temp/mp-save-0.zip) for peer(1) size(71848340) crc(2174009840)
  77.154 Info ServerMultiplayerManager.cpp:780: updateTick(3960030) changing state from(InGameSavingMap) to(InGame)
  77.255 Info ServerMultiplayerManager.cpp:930: updateTick(3960030) received stateChanged peerID(1) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
  97.266 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({80.3.101.244:56420}))
  97.266 Refusing connection for address (IP ADDR:({80.3.101.244:56420})), username (studix2002). UserVerificationMissing
  97.939 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({80.3.101.244:50802}))
  97.939 Refusing connection for address (IP ADDR:({80.3.101.244:50802})), username (studix2002). PasswordMissing
  98.057 Info ServerMultiplayerManager.cpp:930: updateTick(3960030) received stateChanged peerID(1) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
 103.744 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({80.3.101.244:50079}))
 103.744 Info ServerRouter.cpp:453: Replying to connectionRequest for address(IP ADDR:({80.3.101.244:50079})).
 103.744 Info ServerSynchronizer.cpp:600: nextHeartbeatSequenceNumber(2935) adding peer(2)
 103.755 Info ServerMultiplayerManager.cpp:780: updateTick(3960371) changing state from(InGame) to(InGameSavingMap)
 103.805 Info ServerMultiplayerManager.cpp:930: updateTick(3960371) received stateChanged peerID(2) oldState(Ready) newState(ConnectedWaitingForMap)
 104.023 Info ServerMultiplayerManager.cpp:930: updateTick(3960371) received stateChanged peerID(1) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
 106.012 Info ServerMultiplayerManager.cpp:997: UpdateTick(3960371) Serving map(/home/container/temp/mp-save-1.zip) for peer(2) size(71686744) crc(2516662281)
 106.012 Info ServerMultiplayerManager.cpp:780: updateTick(3960371) changing state from(InGameSavingMap) to(InGame)
 106.120 Info ServerMultiplayerManager.cpp:930: updateTick(3960381) received stateChanged peerID(2) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
 106.258 Info ServerMultiplayerManager.cpp:930: updateTick(3960389) received stateChanged peerID(1) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
 106.259 Info GameActionHandler.cpp:4965: UpdateTick (3960389) processed PlayerJoinGame peerID(1) playerIndex(0) mode(connect) 
 106.366 Info ServerMultiplayerManager.cpp:930: updateTick(3960395) received stateChanged peerID(1) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
 130.699 Info ServerMultiplayerManager.cpp:930: updateTick(3961855) received stateChanged peerID(2) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
 139.794 Info ServerMultiplayerManager.cpp:930: updateTick(3962401) received stateChanged peerID(2) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
 165.024 Info ServerMultiplayerManager.cpp:930: updateTick(3963915) received stateChanged peerID(2) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
 165.025 Info GameActionHandler.cpp:4965: UpdateTick (3963915) processed PlayerJoinGame peerID(2) playerIndex(14) mode(connect) 
 165.125 Info ServerMultiplayerManager.cpp:930: updateTick(3963921) received stateChanged peerID(2) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
 180.896 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({217.123.73.164:56134}))
 180.896 Refusing connection for address (IP ADDR:({217.123.73.164:56134})), username (Devildude1). UserVerificationMissing
 181.480 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({217.123.73.164:59421}))
 181.480 Refusing connection for address (IP ADDR:({217.123.73.164:59421})), username (Devildude1). PasswordMissing
 193.521 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({217.123.73.164:55532}))
 193.521 Info ServerRouter.cpp:453: Replying to connectionRequest for address(IP ADDR:({217.123.73.164:55532})).
 193.521 Info ServerSynchronizer.cpp:600: nextHeartbeatSequenceNumber(5913) adding peer(3)
 193.539 Info ServerMultiplayerManager.cpp:780: updateTick(3965626) changing state from(InGame) to(InGameSavingMap)
 193.572 Info ServerMultiplayerManager.cpp:930: updateTick(3965626) received stateChanged peerID(3) oldState(Ready) newState(ConnectedWaitingForMap)
 195.739 Info ServerMultiplayerManager.cpp:997: UpdateTick(3965626) Serving map(/home/container/temp/mp-save-2.zip) for peer(3) size(70311286) crc(549046561)
 195.740 Info ServerMultiplayerManager.cpp:780: updateTick(3965626) changing state from(InGameSavingMap) to(InGame)
 195.827 Info ServerMultiplayerManager.cpp:930: updateTick(3965634) received stateChanged peerID(3) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
 205.726 Info ServerMultiplayerManager.cpp:930: updateTick(3966228) received stateChanged peerID(3) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
 215.747 Info ServerMultiplayerManager.cpp:930: updateTick(3966829) received stateChanged peerID(3) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
 227.082 Info ServerMultiplayerManager.cpp:930: updateTick(3967509) received stateChanged peerID(3) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
 227.083 Info GameActionHandler.cpp:4965: UpdateTick (3967509) processed PlayerJoinGame peerID(3) playerIndex(5) mode(connect) 
 227.168 Info ServerMultiplayerManager.cpp:930: updateTick(3967515) received stateChanged peerID(3) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
 259.747 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({37.201.214.180:18829}))
 259.747 Refusing connection for address (IP ADDR:({37.201.214.180:18829})), username (posteule). UserVerificationMissing
 260.620 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({37.201.214.180:18831}))
 260.620 Refusing connection for address (IP ADDR:({37.201.214.180:18831})), username (posteule). PasswordMissing
 332.907 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({62.97.182.88:50160}))
 332.907 Refusing connection for address (IP ADDR:({62.97.182.88:50160})), username (ornulv123). UserVerificationMissing
 333.472 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({62.97.182.88:54692}))
 333.472 Info ServerRouter.cpp:453: Replying to connectionRequest for address(IP ADDR:({62.97.182.88:54692})).
 333.472 Info ServerSynchronizer.cpp:600: nextHeartbeatSequenceNumber(10510) adding peer(4)
 333.502 Info ServerMultiplayerManager.cpp:780: updateTick(3973894) changing state from(InGame) to(InGameSavingMap)
 333.536 Info ServerMultiplayerManager.cpp:930: updateTick(3973894) received stateChanged peerID(4) oldState(Ready) newState(ConnectedWaitingForMap)
 335.721 Info ServerMultiplayerManager.cpp:997: UpdateTick(3973894) Serving map(/home/container/temp/mp-save-3.zip) for peer(4) size(70433276) crc(596563961)
 335.721 Info ServerMultiplayerManager.cpp:780: updateTick(3973894) changing state from(InGameSavingMap) to(InGame)
 335.807 Info ServerMultiplayerManager.cpp:930: updateTick(3973903) received stateChanged peerID(4) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
 342.200 Info ServerMultiplayerManager.cpp:930: updateTick(3974286) received stateChanged peerID(4) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
 346.971 Info ServerMultiplayerManager.cpp:930: updateTick(3974573) received stateChanged peerID(4) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
 351.738 Info ServerMultiplayerManager.cpp:930: updateTick(3974859) received stateChanged peerID(4) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
 351.738 Info GameActionHandler.cpp:4965: UpdateTick (3974859) processed PlayerJoinGame peerID(4) playerIndex(2) mode(connect) 
 351.868 Info ServerMultiplayerManager.cpp:930: updateTick(3974867) received stateChanged peerID(4) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
 407.644 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({37.201.214.180:18688}))
 407.644 Info ServerRouter.cpp:453: Replying to connectionRequest for address(IP ADDR:({37.201.214.180:18688})).
 407.644 Info ServerSynchronizer.cpp:600: nextHeartbeatSequenceNumber(13007) adding peer(5)
 407.655 Info ServerMultiplayerManager.cpp:780: updateTick(3978214) changing state from(InGame) to(InGameSavingMap)
 407.722 Info ServerMultiplayerManager.cpp:930: updateTick(3978214) received stateChanged peerID(5) oldState(Ready) newState(ConnectedWaitingForMap)
 409.960 Info ServerMultiplayerManager.cpp:997: UpdateTick(3978214) Serving map(/home/container/temp/mp-save-4.zip) for peer(5) size(70174971) crc(3690501939)
 409.960 Info ServerMultiplayerManager.cpp:780: updateTick(3978214) changing state from(InGameSavingMap) to(InGame)
 410.040 Info ServerMultiplayerManager.cpp:930: updateTick(3978223) received stateChanged peerID(5) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
 423.634 Info ServerMultiplayerManager.cpp:930: updateTick(3979038) received stateChanged peerID(5) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
 432.221 Info ServerMultiplayerManager.cpp:930: updateTick(3979554) received stateChanged peerID(5) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
 450.584 Info ServerMultiplayerManager.cpp:930: updateTick(3980655) received stateChanged peerID(5) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
 450.585 Info GameActionHandler.cpp:4965: UpdateTick (3980655) processed PlayerJoinGame peerID(5) playerIndex(8) mode(connect) 
 450.684 Info ServerMultiplayerManager.cpp:930: updateTick(3980661) received stateChanged peerID(5) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
 677.914 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({162.232.247.1:59056}))
 677.914 Refusing connection for address (IP ADDR:({162.232.247.1:59056})), username (fienxjox). UserVerificationMissing
 678.421 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({162.232.247.1:61759}))
 678.421 Info ServerRouter.cpp:453: Replying to connectionRequest for address(IP ADDR:({162.232.247.1:61759})).
 678.421 Info ServerSynchronizer.cpp:600: nextHeartbeatSequenceNumber(21880) adding peer(6)
 678.452 Info ServerMultiplayerManager.cpp:780: updateTick(3994327) changing state from(InGame) to(InGameSavingMap)
 678.570 Info ServerMultiplayerManager.cpp:930: updateTick(3994327) received stateChanged peerID(6) oldState(Ready) newState(ConnectedWaitingForMap)
 680.665 Info ServerMultiplayerManager.cpp:997: UpdateTick(3994327) Serving map(/home/container/temp/mp-save-5.zip) for peer(6) size(70183332) crc(3234490742)
 680.665 Info ServerMultiplayerManager.cpp:780: updateTick(3994327) changing state from(InGameSavingMap) to(InGame)
 680.867 Info ServerMultiplayerManager.cpp:930: updateTick(3994343) received stateChanged peerID(6) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
 687.517 Info ServerMultiplayerManager.cpp:930: updateTick(3994742) received stateChanged peerID(6) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
 691.496 Info ServerMultiplayerManager.cpp:930: updateTick(3994981) received stateChanged peerID(6) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
 695.309 Info ServerMultiplayerManager.cpp:930: updateTick(3995210) received stateChanged peerID(6) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
 695.310 Info GameActionHandler.cpp:4965: UpdateTick (3995210) processed PlayerJoinGame peerID(6) playerIndex(7) mode(connect) 
 695.477 Info ServerMultiplayerManager.cpp:930: updateTick(3995220) received stateChanged peerID(6) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
 696.038 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({46.231.78.232:61312}))
 696.039 Refusing connection for address (IP ADDR:({46.231.78.232:61312})), username (wellczech). UserVerificationMissing
 696.769 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({46.231.78.232:51710}))
 696.769 Refusing connection for address (IP ADDR:({46.231.78.232:51710})), username (wellczech). PasswordMissing
 708.055 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({46.231.78.232:59173}))
 708.055 Info ServerRouter.cpp:453: Replying to connectionRequest for address(IP ADDR:({46.231.78.232:59173})).
 708.055 Info ServerSynchronizer.cpp:600: nextHeartbeatSequenceNumber(22896) adding peer(7)
 708.071 Info ServerMultiplayerManager.cpp:780: updateTick(3995976) changing state from(InGame) to(InGameSavingMap)
 708.137 Info ServerMultiplayerManager.cpp:930: updateTick(3995976) received stateChanged peerID(7) oldState(Ready) newState(ConnectedWaitingForMap)
 710.205 Info ServerMultiplayerManager.cpp:997: UpdateTick(3995976) Serving map(/home/container/temp/mp-save-6.zip) for peer(7) size(70465233) crc(2402579946)
 710.205 Info ServerMultiplayerManager.cpp:780: updateTick(3995976) changing state from(InGameSavingMap) to(InGame)
 710.340 Info ServerMultiplayerManager.cpp:930: updateTick(3995987) received stateChanged peerID(7) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
 710.555 Info AppManager.cpp:286: Saving to _autosave1 (non-blocking).
 710.597 Info AsyncScenarioSaver.cpp:153: Saving process PID: 1559
 714.699 [1559] Warning WriteFileGuard.cpp:96: Couldn't chown /home/container/saves/_autosave1.tmp.zip: Operation not permitted
 714.763 Info ChildProcessAgent.cpp:60: Child 1559 exited with return value 0
 714.763 Info AppManager.cpp:287: Saving finished
 729.095 Info ServerMultiplayerManager.cpp:930: updateTick(3997104) received stateChanged peerID(7) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
 747.657 Info ServerMultiplayerManager.cpp:930: updateTick(3998218) received stateChanged peerID(7) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
 805.578 Info ServerMultiplayerManager.cpp:930: updateTick(4001693) received stateChanged peerID(7) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
 805.578 Info GameActionHandler.cpp:4965: UpdateTick (4001693) processed PlayerJoinGame peerID(7) playerIndex(11) mode(connect) 
 805.673 Info ServerMultiplayerManager.cpp:930: updateTick(4001699) received stateChanged peerID(7) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
 900.830 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({64.90.210.108:50236}))
 900.830 Refusing connection for address (IP ADDR:({64.90.210.108:50236})), username (mrkrause1). UserVerificationMissing
 901.519 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({64.90.210.108:56400}))
 901.519 Refusing connection for address (IP ADDR:({64.90.210.108:56400})), username (mrkrause1). PasswordMissing
 953.107 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({64.90.210.108:63639}))
 953.107 Info ServerRouter.cpp:453: Replying to connectionRequest for address(IP ADDR:({64.90.210.108:63639})).
 953.107 Info ServerSynchronizer.cpp:600: nextHeartbeatSequenceNumber(31567) adding peer(8)
 953.125 Info ServerMultiplayerManager.cpp:780: updateTick(4010546) changing state from(InGame) to(InGameSavingMap)
 953.276 Info ServerMultiplayerManager.cpp:930: updateTick(4010546) received stateChanged peerID(8) oldState(Ready) newState(ConnectedWaitingForMap)
 955.466 Info ServerMultiplayerManager.cpp:997: UpdateTick(4010546) Serving map(/home/container/temp/mp-save-7.zip) for peer(8) size(70957499) crc(847970186)
 955.466 Info ServerMultiplayerManager.cpp:780: updateTick(4010546) changing state from(InGameSavingMap) to(InGame)
 955.668 Info ServerMultiplayerManager.cpp:930: updateTick(4010561) received stateChanged peerID(8) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
 993.637 Info ServerMultiplayerManager.cpp:930: updateTick(4012841) received stateChanged peerID(8) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
 999.743 Info ServerMultiplayerManager.cpp:930: updateTick(4013207) received stateChanged peerID(8) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
1041.386 Info ServerMultiplayerManager.cpp:930: updateTick(4015706) received stateChanged peerID(8) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
1041.387 Info GameActionHandler.cpp:4965: UpdateTick (4015706) processed PlayerJoinGame peerID(8) playerIndex(19) mode(connect) 
1041.596 Info ServerMultiplayerManager.cpp:930: updateTick(4015718) received stateChanged peerID(8) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
1292.243 Info ServerMultiplayerManager.cpp:1048: Disconnect notification for peer (2)
1292.243 Info ServerMultiplayerManager.cpp:930: updateTick(4030757) received stateChanged peerID(2) oldState(InGame) newState(DisconnectScheduled)
1292.244 Info ServerSynchronizer.cpp:619: nextHeartbeatSequenceNumber(43157) removing peer(2).
1312.966 Info AppManager.cpp:286: Saving to _autosave2 (non-blocking).
1312.988 Info AsyncScenarioSaver.cpp:153: Saving process PID: 1999
1316.019 [1999] Warning WriteFileGuard.cpp:96: Couldn't chown /home/container/saves/_autosave2.tmp.zip: Operation not permitted
1316.070 Info ChildProcessAgent.cpp:60: Child 1999 exited with return value 0
1316.070 Info AppManager.cpp:287: Saving finished
1678.036 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({80.3.101.244:61548}))
1678.036 Info ServerRouter.cpp:453: Replying to connectionRequest for address(IP ADDR:({80.3.101.244:61548})).
1678.036 Info ServerSynchronizer.cpp:600: nextHeartbeatSequenceNumber(56535) adding peer(9)
1678.053 Info ServerMultiplayerManager.cpp:780: updateTick(4053902) changing state from(InGame) to(InGameSavingMap)
1678.104 Info ServerMultiplayerManager.cpp:930: updateTick(4053902) received stateChanged peerID(9) oldState(Ready) newState(ConnectedWaitingForMap)
1680.493 Info ServerMultiplayerManager.cpp:997: UpdateTick(4053902) Serving map(/home/container/temp/mp-save-8.zip) for peer(9) size(71687065) crc(1620706068)
1680.493 Info ServerMultiplayerManager.cpp:780: updateTick(4053902) changing state from(InGameSavingMap) to(InGame)
1680.591 Info ServerMultiplayerManager.cpp:930: updateTick(4053909) received stateChanged peerID(9) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
1707.210 Info ServerMultiplayerManager.cpp:930: updateTick(4055508) received stateChanged peerID(9) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
1716.641 Info ServerMultiplayerManager.cpp:930: updateTick(4056074) received stateChanged peerID(9) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
1795.090 Info ServerMultiplayerManager.cpp:930: updateTick(4060781) received stateChanged peerID(9) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
1795.091 Info GameActionHandler.cpp:4965: UpdateTick (4060781) processed PlayerJoinGame peerID(9) playerIndex(14) mode(connect) 
1795.176 Info ServerMultiplayerManager.cpp:930: updateTick(4060786) received stateChanged peerID(9) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
1916.139 Info AppManager.cpp:286: Saving to _autosave3 (non-blocking).
1916.171 Info AsyncScenarioSaver.cpp:153: Saving process PID: 2444
1920.006 [2444] Warning WriteFileGuard.cpp:96: Couldn't chown /home/container/saves/_autosave3.tmp.zip: Operation not permitted
1920.078 Info ChildProcessAgent.cpp:60: Child 2444 exited with return value 0
1920.078 Info AppManager.cpp:287: Saving finished
2517.423 Info AppManager.cpp:286: Saving to _autosave4 (non-blocking).
2517.452 Info AsyncScenarioSaver.cpp:153: Saving process PID: 2680
2520.681 [2680] Warning WriteFileGuard.cpp:96: Couldn't chown /home/container/saves/_autosave4.tmp.zip: Operation not permitted
2520.758 Info ChildProcessAgent.cpp:60: Child 2680 exited with return value 0
2520.758 Info AppManager.cpp:287: Saving finished
3117.492 Info AppManager.cpp:286: Saving to _autosave5 (non-blocking).
3117.521 Info AsyncScenarioSaver.cpp:153: Saving process PID: 2918
3120.874 [2918] Warning WriteFileGuard.cpp:96: Couldn't chown /home/container/saves/_autosave5.tmp.zip: Operation not permitted
3120.953 Info ChildProcessAgent.cpp:60: Child 2918 exited with return value 0
3120.953 Info AppManager.cpp:287: Saving finished
3386.788 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({176.27.22.249:56394}))
3386.788 Refusing connection for address (IP ADDR:({176.27.22.249:56394})), username (wakjah). UserVerificationMissing
3387.255 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({176.27.22.249:50669}))
3387.255 Info ServerRouter.cpp:453: Replying to connectionRequest for address(IP ADDR:({176.27.22.249:50669})).
3387.255 Info ServerSynchronizer.cpp:600: nextHeartbeatSequenceNumber(115720) adding peer(10)
3387.284 Info ServerMultiplayerManager.cpp:780: updateTick(4156185) changing state from(InGame) to(InGameSavingMap)
3387.285 Info ServerMultiplayerManager.cpp:930: updateTick(4156185) received stateChanged peerID(10) oldState(Ready) newState(ConnectedWaitingForMap)
3389.759 Info ServerMultiplayerManager.cpp:997: UpdateTick(4156185) Serving map(/home/container/temp/mp-save-9.zip) for peer(10) size(72893820) crc(555159596)
3389.759 Info ServerMultiplayerManager.cpp:780: updateTick(4156185) changing state from(InGameSavingMap) to(InGame)
3389.811 Info ServerMultiplayerManager.cpp:930: updateTick(4156191) received stateChanged peerID(10) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
3409.760 Info ServerMultiplayerManager.cpp:930: updateTick(4157389) received stateChanged peerID(10) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
3415.820 Info ServerMultiplayerManager.cpp:930: updateTick(4157753) received stateChanged peerID(10) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
3432.042 Info ServerMultiplayerManager.cpp:930: updateTick(4158726) received stateChanged peerID(10) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
3432.043 Info GameActionHandler.cpp:4965: UpdateTick (4158726) processed PlayerJoinGame peerID(10) playerIndex(13) mode(connect) 
3432.109 Info ServerMultiplayerManager.cpp:930: updateTick(4158730) received stateChanged peerID(10) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
3610.797 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({174.109.139.69:50135}))
3610.797 Refusing connection for address (IP ADDR:({174.109.139.69:50135})), username (mathturtle). UserVerificationMissing
3611.272 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({174.109.139.69:51646}))
3611.272 Refusing connection for address (IP ADDR:({174.109.139.69:51646})), username (mathturtle). PasswordMissing
3618.103 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({174.109.139.69:60142}))
3618.103 Info ServerRouter.cpp:453: Replying to connectionRequest for address(IP ADDR:({174.109.139.69:60142})).
3618.103 Info ServerSynchronizer.cpp:600: nextHeartbeatSequenceNumber(123500) adding peer(11)
3618.121 Info ServerMultiplayerManager.cpp:780: updateTick(4169891) changing state from(InGame) to(InGameSavingMap)
3618.239 Info ServerMultiplayerManager.cpp:930: updateTick(4169891) received stateChanged peerID(11) oldState(Ready) newState(ConnectedWaitingForMap)
3620.607 Info ServerMultiplayerManager.cpp:997: UpdateTick(4169891) Serving map(/home/container/temp/mp-save-10.zip) for peer(11) size(72934296) crc(3668610006)
3620.607 Info ServerMultiplayerManager.cpp:780: updateTick(4169891) changing state from(InGameSavingMap) to(InGame)
3620.795 Info ServerMultiplayerManager.cpp:930: updateTick(4169905) received stateChanged peerID(11) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
3635.021 Info ServerMultiplayerManager.cpp:930: updateTick(4170760) received stateChanged peerID(11) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
3642.278 Info ServerMultiplayerManager.cpp:930: updateTick(4171195) received stateChanged peerID(11) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
3667.146 Info ServerMultiplayerManager.cpp:930: updateTick(4172687) received stateChanged peerID(11) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
3667.147 Info GameActionHandler.cpp:4965: UpdateTick (4172687) processed PlayerJoinGame peerID(11) playerIndex(18) mode(connect) 
3667.318 Info ServerMultiplayerManager.cpp:930: updateTick(4172697) received stateChanged peerID(11) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
3722.372 Info AppManager.cpp:286: Saving to _autosave1 (non-blocking).
3722.401 Info AsyncScenarioSaver.cpp:153: Saving process PID: 3615
3725.625 Info ChildProcessAgent.cpp:60: Child 3615 exited with return value 0
3725.625 Info AppManager.cpp:287: Saving finished
4322.561 Info AppManager.cpp:286: Saving to _autosave2 (non-blocking).
4322.590 Info AsyncScenarioSaver.cpp:153: Saving process PID: 3855
4325.937 Info ChildProcessAgent.cpp:60: Child 3855 exited with return value 0
4325.937 Info AppManager.cpp:287: Saving finished
4924.304 Info AppManager.cpp:286: Saving to _autosave3 (non-blocking).
4924.344 Info AsyncScenarioSaver.cpp:153: Saving process PID: 4095
4927.825 Info ChildProcessAgent.cpp:60: Child 4095 exited with return value 0
4927.825 Info AppManager.cpp:287: Saving finished
5302.832 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({77.163.79.107:64424}))
5302.832 Refusing connection for address (IP ADDR:({77.163.79.107:64424})), username (Izzybel). UserVerificationMissing
5303.348 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({77.163.79.107:50874}))
5303.348 Info ServerRouter.cpp:453: Replying to connectionRequest for address(IP ADDR:({77.163.79.107:50874})).
5303.348 Info ServerSynchronizer.cpp:600: nextHeartbeatSequenceNumber(180243) adding peer(12)
5303.366 Info ServerMultiplayerManager.cpp:780: updateTick(4270741) changing state from(InGame) to(InGameSavingMap)
5303.382 Info ServerMultiplayerManager.cpp:930: updateTick(4270741) received stateChanged peerID(12) oldState(Ready) newState(ConnectedWaitingForMap)
5305.870 Info ServerMultiplayerManager.cpp:997: UpdateTick(4270741) Serving map(/home/container/temp/mp-save-11.zip) for peer(12) size(74262485) crc(4049713352)
5305.870 Info ServerMultiplayerManager.cpp:780: updateTick(4270741) changing state from(InGameSavingMap) to(InGame)
5305.936 Info ServerMultiplayerManager.cpp:930: updateTick(4270746) received stateChanged peerID(12) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
5312.222 Info ServerMultiplayerManager.cpp:930: updateTick(4271126) received stateChanged peerID(12) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
5318.279 Info ServerMultiplayerManager.cpp:930: updateTick(4271489) received stateChanged peerID(12) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
5330.243 Info ServerMultiplayerManager.cpp:930: updateTick(4272207) received stateChanged peerID(12) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
5330.243 Info GameActionHandler.cpp:4965: UpdateTick (4272207) processed PlayerJoinGame peerID(12) playerIndex(6) mode(connect) 
5330.322 Info ServerMultiplayerManager.cpp:930: updateTick(4272212) received stateChanged peerID(12) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
5526.808 Info AppManager.cpp:286: Saving to _autosave4 (non-blocking).
5526.860 Info AsyncScenarioSaver.cpp:153: Saving process PID: 4581
5530.184 Info ChildProcessAgent.cpp:60: Child 4581 exited with return value 0
5530.184 Info AppManager.cpp:287: Saving finished
5720.632 Info ServerMultiplayerManager.cpp:1048: Disconnect notification for peer (4)
5720.632 Info ServerMultiplayerManager.cpp:930: updateTick(4295625) received stateChanged peerID(4) oldState(InGame) newState(DisconnectScheduled)
5720.633 Info ServerSynchronizer.cpp:619: nextHeartbeatSequenceNumber(192928) removing peer(4).
6126.893 Info AppManager.cpp:286: Saving to _autosave5 (non-blocking).
6126.926 Info AsyncScenarioSaver.cpp:153: Saving process PID: 4829
6130.360 Info ChildProcessAgent.cpp:60: Child 4829 exited with return value 0
6130.360 Info AppManager.cpp:287: Saving finished
6727.149 Info AppManager.cpp:286: Saving to _autosave1 (non-blocking).
6727.197 Info AsyncScenarioSaver.cpp:153: Saving process PID: 5080
6730.765 Info ChildProcessAgent.cpp:60: Child 5080 exited with return value 0
6730.765 Info AppManager.cpp:287: Saving finished
7327.239 Info AppManager.cpp:286: Saving to _autosave2 (non-blocking).
7327.291 Info AsyncScenarioSaver.cpp:153: Saving process PID: 5341
7330.852 Info ChildProcessAgent.cpp:60: Child 5341 exited with return value 0
7330.852 Info AppManager.cpp:287: Saving finished
7851.424 Info ServerMultiplayerManager.cpp:1048: Disconnect notification for peer (5)
7851.424 Info ServerMultiplayerManager.cpp:930: updateTick(4423422) received stateChanged peerID(5) oldState(InGame) newState(DisconnectScheduled)
7851.438 Info ServerSynchronizer.cpp:619: nextHeartbeatSequenceNumber(263127) removing peer(5).
7921.885 Info ServerMultiplayerManager.cpp:1048: Disconnect notification for peer (10)
7921.885 Info ServerMultiplayerManager.cpp:930: updateTick(4427616) received stateChanged peerID(10) oldState(InGame) newState(DisconnectScheduled)
7921.885 Info ServerSynchronizer.cpp:619: nextHeartbeatSequenceNumber(265271) removing peer(10).
7928.217 Info AppManager.cpp:286: Saving to _autosave3 (non-blocking).
7928.252 Info AsyncScenarioSaver.cpp:153: Saving process PID: 5604
7932.103 Info ChildProcessAgent.cpp:60: Child 5604 exited with return value 0
7932.103 Info AppManager.cpp:287: Saving finished
8202.959 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({176.27.22.249:63560}))
8202.959 Info ServerRouter.cpp:453: Replying to connectionRequest for address(IP ADDR:({176.27.22.249:63560})).
8202.959 Info ServerSynchronizer.cpp:600: nextHeartbeatSequenceNumber(274298) adding peer(13)
8202.977 Info ServerMultiplayerManager.cpp:780: updateTick(4444479) changing state from(InGame) to(InGameSavingMap)
8203.010 Info ServerMultiplayerManager.cpp:930: updateTick(4444479) received stateChanged peerID(13) oldState(Ready) newState(ConnectedWaitingForMap)
8205.970 Info ServerMultiplayerManager.cpp:997: UpdateTick(4444479) Serving map(/home/container/temp/mp-save-12.zip) for peer(13) size(80075357) crc(3201472856)
8205.970 Info ServerMultiplayerManager.cpp:780: updateTick(4444479) changing state from(InGameSavingMap) to(InGame)
8206.032 Info ServerMultiplayerManager.cpp:930: updateTick(4444483) received stateChanged peerID(13) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
8227.440 Info ServerMultiplayerManager.cpp:930: updateTick(4445742) received stateChanged peerID(13) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
8234.565 Info ServerMultiplayerManager.cpp:930: updateTick(4446169) received stateChanged peerID(13) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
8264.770 Info ServerMultiplayerManager.cpp:930: updateTick(4447982) received stateChanged peerID(13) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
8264.771 Info GameActionHandler.cpp:4965: UpdateTick (4447982) processed PlayerJoinGame peerID(13) playerIndex(13) mode(connect) 
8264.848 Info ServerMultiplayerManager.cpp:930: updateTick(4447986) received stateChanged peerID(13) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
8489.488 Info ServerMultiplayerManager.cpp:1048: Disconnect notification for peer (13)
8489.489 Info ServerMultiplayerManager.cpp:930: updateTick(4461278) received stateChanged peerID(13) oldState(InGame) newState(DisconnectScheduled)
8489.490 Info ServerSynchronizer.cpp:619: nextHeartbeatSequenceNumber(283003) removing peer(13).
8534.826 Info AppManager.cpp:286: Saving to _autosave4 (non-blocking).
8534.882 Info AsyncScenarioSaver.cpp:153: Saving process PID: 6128
8538.722 Info ChildProcessAgent.cpp:60: Child 6128 exited with return value 0
8538.723 Info AppManager.cpp:287: Saving finished
8621.603 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({176.27.22.249:51673}))
8621.604 Info ServerRouter.cpp:453: Replying to connectionRequest for address(IP ADDR:({176.27.22.249:51673})).
8621.604 Info ServerSynchronizer.cpp:600: nextHeartbeatSequenceNumber(287203) adding peer(14)
8621.626 Info ServerMultiplayerManager.cpp:780: updateTick(4469193) changing state from(InGame) to(InGameSavingMap)
8621.659 Info ServerMultiplayerManager.cpp:930: updateTick(4469193) received stateChanged peerID(14) oldState(Ready) newState(ConnectedWaitingForMap)
8624.507 Info ServerMultiplayerManager.cpp:997: UpdateTick(4469193) Serving map(/home/container/temp/mp-save-13.zip) for peer(14) size(80626771) crc(863241923)
8624.507 Info ServerMultiplayerManager.cpp:780: updateTick(4469193) changing state from(InGameSavingMap) to(InGame)
8624.589 Info ServerMultiplayerManager.cpp:930: updateTick(4469198) received stateChanged peerID(14) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
8645.861 Info ServerMultiplayerManager.cpp:930: updateTick(4470468) received stateChanged peerID(14) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
8653.479 Info ServerMultiplayerManager.cpp:930: updateTick(4470925) received stateChanged peerID(14) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
8681.835 Info ServerMultiplayerManager.cpp:930: updateTick(4472627) received stateChanged peerID(14) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
8681.835 Info GameActionHandler.cpp:4965: UpdateTick (4472627) processed PlayerJoinGame peerID(14) playerIndex(13) mode(connect) 
8681.932 Info ServerMultiplayerManager.cpp:930: updateTick(4472632) received stateChanged peerID(14) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
9138.962 Info AppManager.cpp:286: Saving to _autosave5 (non-blocking).
9138.998 Info AsyncScenarioSaver.cpp:153: Saving process PID: 6657
9142.775 Info ChildProcessAgent.cpp:60: Child 6657 exited with return value 0
9142.775 Info AppManager.cpp:287: Saving finished
9739.376 Info AppManager.cpp:286: Saving to _autosave1 (non-blocking).
9739.414 Info AsyncScenarioSaver.cpp:153: Saving process PID: 6927
9743.101 Info ChildProcessAgent.cpp:60: Child 6927 exited with return value 0
9743.101 Info AppManager.cpp:287: Saving finished
10341.625 Info AppManager.cpp:286: Saving to _autosave2 (non-blocking).
10341.690 Info AsyncScenarioSaver.cpp:153: Saving process PID: 7197
10345.633 Info ChildProcessAgent.cpp:60: Child 7197 exited with return value 0
10345.633 Info AppManager.cpp:287: Saving finished
10945.193 Info AppManager.cpp:286: Saving to _autosave3 (non-blocking).
10945.230 Info AsyncScenarioSaver.cpp:153: Saving process PID: 7468
10949.190 Info ChildProcessAgent.cpp:60: Child 7468 exited with return value 0
10949.190 Info AppManager.cpp:287: Saving finished
11547.188 Info AppManager.cpp:286: Saving to _autosave4 (non-blocking).
11547.227 Info AsyncScenarioSaver.cpp:153: Saving process PID: 7743
11551.431 Info ChildProcessAgent.cpp:60: Child 7743 exited with return value 0
11551.432 Info AppManager.cpp:287: Saving finished
12152.582 Info AppManager.cpp:286: Saving to _autosave5 (non-blocking).
12152.626 Info AsyncScenarioSaver.cpp:153: Saving process PID: 8018
12156.814 Info ChildProcessAgent.cpp:60: Child 8018 exited with return value 0
12156.814 Info AppManager.cpp:287: Saving finished
12758.104 Info AppManager.cpp:286: Saving to _autosave1 (non-blocking).
12758.160 Info AsyncScenarioSaver.cpp:153: Saving process PID: 8295
12762.395 Info ChildProcessAgent.cpp:60: Child 8295 exited with return value 0
12762.395 Info AppManager.cpp:287: Saving finished
13363.593 Info AppManager.cpp:286: Saving to _autosave2 (non-blocking).
13363.654 Info AsyncScenarioSaver.cpp:153: Saving process PID: 8578
13367.761 Info ChildProcessAgent.cpp:60: Child 8578 exited with return value 0
13367.761 Info AppManager.cpp:287: Saving finished
13965.940 Info AppManager.cpp:286: Saving to _autosave3 (non-blocking).
13965.985 Info AsyncScenarioSaver.cpp:153: Saving process PID: 8842
13970.192 Info ChildProcessAgent.cpp:60: Child 8842 exited with return value 0
13970.192 Info AppManager.cpp:287: Saving finished
14566.045 Info AppManager.cpp:286: Saving to _autosave4 (non-blocking).
14566.097 Info AsyncScenarioSaver.cpp:153: Saving process PID: 9109
14570.337 Info ChildProcessAgent.cpp:60: Child 9109 exited with return value 0
14570.338 Info AppManager.cpp:287: Saving finished
15166.393 Info AppManager.cpp:286: Saving to _autosave5 (non-blocking).
15166.459 Info AsyncScenarioSaver.cpp:153: Saving process PID: 9376
15170.695 Info ChildProcessAgent.cpp:60: Child 9376 exited with return value 0
15170.695 Info AppManager.cpp:287: Saving finished
15766.516 Info AppManager.cpp:286: Saving to _autosave1 (non-blocking).
15766.588 Info AsyncScenarioSaver.cpp:153: Saving process PID: 9644
15770.956 Info ChildProcessAgent.cpp:60: Child 9644 exited with return value 0
15770.957 Info AppManager.cpp:287: Saving finished
16366.640 Info AppManager.cpp:286: Saving to _autosave2 (non-blocking).
16366.709 Info AsyncScenarioSaver.cpp:153: Saving process PID: 9912
16370.943 Info ChildProcessAgent.cpp:60: Child 9912 exited with return value 0
16370.943 Info AppManager.cpp:287: Saving finished
16967.094 Info AppManager.cpp:286: Saving to _autosave3 (non-blocking).
16967.153 Info AsyncScenarioSaver.cpp:153: Saving process PID: 10183
16971.540 Info ChildProcessAgent.cpp:60: Child 10183 exited with return value 0
16971.540 Info AppManager.cpp:287: Saving finished
17567.228 Info AppManager.cpp:286: Saving to _autosave4 (non-blocking).
17567.285 Info AsyncScenarioSaver.cpp:153: Saving process PID: 10455
17571.627 Info ChildProcessAgent.cpp:60: Child 10455 exited with return value 0
17571.627 Info AppManager.cpp:287: Saving finished
18167.355 Info AppManager.cpp:286: Saving to _autosave5 (non-blocking).
18167.409 Info AsyncScenarioSaver.cpp:153: Saving process PID: 10726
18171.700 Info ChildProcessAgent.cpp:60: Child 10726 exited with return value 0
18171.701 Info AppManager.cpp:287: Saving finished
18344.761 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({37.201.214.180:18733}))
18344.762 Refusing connection for address (IP ADDR:({37.201.214.180:18733})), username (posteule). UserVerificationMissing
18345.639 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({37.201.214.180:18835}))
18345.640 Refusing connection for address (IP ADDR:({37.201.214.180:18835})), username (posteule). PasswordMissing
18350.211 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({37.201.214.180:18701}))
18350.211 Info ServerRouter.cpp:453: Replying to connectionRequest for address(IP ADDR:({37.201.214.180:18701})).
18350.212 Info ServerSynchronizer.cpp:600: nextHeartbeatSequenceNumber(599916) adding peer(15)
18350.233 Info ServerMultiplayerManager.cpp:780: updateTick(5050969) changing state from(InGame) to(InGameSavingMap)
18350.268 Info ServerMultiplayerManager.cpp:930: updateTick(5050969) received stateChanged peerID(15) oldState(Ready) newState(ConnectedWaitingForMap)
18353.557 Info ServerMultiplayerManager.cpp:997: UpdateTick(5050969) Serving map(/home/container/temp/mp-save-14.zip) for peer(15) size(85838227) crc(3981454333)
18353.558 Info ServerMultiplayerManager.cpp:780: updateTick(5050969) changing state from(InGameSavingMap) to(InGame)
18353.667 Info ServerMultiplayerManager.cpp:930: updateTick(5050980) received stateChanged peerID(15) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
18367.442 Info ServerMultiplayerManager.cpp:930: updateTick(5051806) received stateChanged peerID(15) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
18377.462 Info ServerMultiplayerManager.cpp:930: updateTick(5052407) received stateChanged peerID(15) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
18392.775 Info ServerMultiplayerManager.cpp:930: updateTick(5053326) received stateChanged peerID(15) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
18392.777 Info GameActionHandler.cpp:4965: UpdateTick (5053326) processed PlayerJoinGame peerID(15) playerIndex(8) mode(connect) 
18392.872 Info ServerMultiplayerManager.cpp:930: updateTick(5053332) received stateChanged peerID(15) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
18770.687 Info AppManager.cpp:286: Saving to _autosave1 (non-blocking).
18770.751 Info AsyncScenarioSaver.cpp:153: Saving process PID: 11257
18775.028 Info ChildProcessAgent.cpp:60: Child 11257 exited with return value 0
18775.028 Info AppManager.cpp:287: Saving finished
19370.737 Info AppManager.cpp:286: Saving to _autosave2 (non-blocking).
19370.797 Info AsyncScenarioSaver.cpp:153: Saving process PID: 11527
19374.980 Info ChildProcessAgent.cpp:60: Child 11527 exited with return value 0
19374.980 Info AppManager.cpp:287: Saving finished
19532.038 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({203.214.73.186:51053}))
19532.038 Refusing connection for address (IP ADDR:({203.214.73.186:51053})), username (Operator911). UserVerificationMissing
19533.673 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({203.214.73.186:62240}))
19533.673 Refusing connection for address (IP ADDR:({203.214.73.186:62240})), username (Operator911). PasswordMissing
19539.827 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(IP ADDR:({203.214.73.186:62245}))
19539.827 Info ServerRouter.cpp:453: Replying to connectionRequest for address(IP ADDR:({203.214.73.186:62245})).
19539.827 Info ServerSynchronizer.cpp:600: nextHeartbeatSequenceNumber(640274) adding peer(16)
19539.839 Info ServerMultiplayerManager.cpp:780: updateTick(5122146) changing state from(InGame) to(InGameSavingMap)
19540.158 Info ServerMultiplayerManager.cpp:930: updateTick(5122146) received stateChanged peerID(16) oldState(Ready) newState(ConnectedWaitingForMap)
19543.096 Info ServerMultiplayerManager.cpp:997: UpdateTick(5122146) Serving map(/home/container/temp/mp-save-15.zip) for peer(16) size(84578481) crc(1814760870)
19543.096 Info ServerMultiplayerManager.cpp:780: updateTick(5122146) changing state from(InGameSavingMap) to(InGame)
19543.508 Info ServerMultiplayerManager.cpp:930: updateTick(5122174) received stateChanged peerID(16) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
19563.510 Info ServerMultiplayerManager.cpp:930: updateTick(5123374) received stateChanged peerID(16) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
19574.872 Info ServerMultiplayerManager.cpp:930: updateTick(5124056) received stateChanged peerID(16) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
19605.501 Info ServerMultiplayerManager.cpp:930: updateTick(5125894) received stateChanged peerID(16) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
19605.504 Info GameActionHandler.cpp:4965: UpdateTick (5125894) processed PlayerJoinGame peerID(16) playerIndex(21) mode(create) 
19605.890 Info ServerMultiplayerManager.cpp:930: updateTick(5125917) received stateChanged peerID(16) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
19867.417 Info ServerMultiplayerManager.cpp:1048: Disconnect notification for peer (12)
19867.417 Info ServerMultiplayerManager.cpp:930: updateTick(5141499) received stateChanged peerID(12) oldState(InGame) newState(DisconnectScheduled)
19867.420 Info ServerSynchronizer.cpp:619: nextHeartbeatSequenceNumber(651212) removing peer(12).
19915.759 Info ServerMultiplayerManager.cpp:1048: Disconnect notification for peer (7)
19915.759 Info ServerMultiplayerManager.cpp:930: updateTick(5144400) received stateChanged peerID(7) oldState(InGame) newState(DisconnectScheduled)
19915.760 Info ServerSynchronizer.cpp:619: nextHeartbeatSequenceNumber(652724) removing peer(7).
19975.763 Info AppManager.cpp:286: Saving to _autosave3 (non-blocking).
19975.842 Info AsyncScenarioSaver.cpp:153: Saving process PID: 12058
19995.177 Error ChildProcessAgent.cpp:62: Child 12058 was terminated by signal 9
19995.194 Error Util.cpp:83: Attempting to create notice box in headless mode. Message: 'Saving process crashed.'
19997.481 Info ServerMultiplayerManager.cpp:113: Disconnecting multiplayer connection.
19997.481 Info ServerMultiplayerManager.cpp:780: updateTick(4294967295) changing state from(InGame) to(DisconnectingScheduled)
19997.802 Info ServerMultiplayerManager.cpp:140: Quitting multiplayer connection.
19997.802 Info ServerMultiplayerManager.cpp:780: updateTick(4294967295) changing state from(DisconnectingScheduled) to(Closed)
19997.806 Info HttpSharedState.cpp:54: Downloading https://multiplayer.factorio.com/remove-game/9077237
19998.193 Info UDPSocket.cpp:218: Closing socket
19998.193 Info UDPSocket.cpp:248: Socket closed
19998.193 Info UDPSocket.cpp:218: Closing socket
19998.255 Info UDPSocket.cpp:218: Closing socket
19998.255 Info UDPSocket.cpp:248: Socket closed
19998.258 Goodbye
luketyleruk
Burner Inserter
Burner Inserter
Posts: 17
Joined: Tue Nov 24, 2020 3:28 pm
Contact:

Re: Server crashing bug

Post by luketyleruk »

server then restarts reverting back to original game save, not from autosave.
User avatar
bormand
Fast Inserter
Fast Inserter
Posts: 201
Joined: Fri Jun 05, 2020 9:59 am
Contact:

Re: [1.1.19] Server crashing bug (Saving process crashed.)

Post by bormand »

luketyleruk wrote: Mon Feb 01, 2021 10:18 am 19995.177 Error ChildProcessAgent.cpp:62: Child 12058 was terminated by signal 9
9 = SIGKILL

OOM killer? Well, shouldn't be on a machine with 12GB of ram. Try to grep other system logs about process 12058, maybe they give you more info...
luketyleruk
Burner Inserter
Burner Inserter
Posts: 17
Joined: Tue Nov 24, 2020 3:28 pm
Contact:

Re: [1.1.19] Server crashing bug (Saving process crashed.)

Post by luketyleruk »

bormand wrote: Mon Feb 01, 2021 10:28 am
luketyleruk wrote: Mon Feb 01, 2021 10:18 am 19995.177 Error ChildProcessAgent.cpp:62: Child 12058 was terminated by signal 9
9 = SIGKILL

OOM killer? Well, shouldn't be on a machine with 12GB of ram. Try to grep other system logs about process 12058, maybe they give you more info...
server has 64gb RAM,

where can i find the logs on 12058?
User avatar
bormand
Fast Inserter
Fast Inserter
Posts: 201
Joined: Fri Jun 05, 2020 9:59 am
Contact:

Re: [1.1.19] Server crashing bug (Saving process crashed.)

Post by bormand »

luketyleruk wrote: Mon Feb 01, 2021 10:42 am where can i find the logs on 12058?
I dunno, I usually grep whole /var/log when I want to find something. Most probably dmesg or syslog in that directory.

It's interesting that almost 20 seconds passed before the kill:
19975.842 Info AsyncScenarioSaver.cpp:153: Saving process PID: 12058
19995.177 Error ChildProcessAgent.cpp:62: Child 12058 was terminated by signal 9
But previous saves were complete in just 3-5 seconds.
luketyleruk
Burner Inserter
Burner Inserter
Posts: 17
Joined: Tue Nov 24, 2020 3:28 pm
Contact:

Re: [1.1.19] Server crashing bug (Saving process crashed.)

Post by luketyleruk »

Im, getting this via pterodactyl.
I had this same issue in 1.1.0, after this version i had no issues, in till now on version 1.1.19, i thinking it might be a bug in the stable versions. last time to get round it i had to turn of auto save. I will have a look at non blocking this time and see if that helps.
User avatar
bormand
Fast Inserter
Fast Inserter
Posts: 201
Joined: Fri Jun 05, 2020 9:59 am
Contact:

Re: [1.1.19] Server crashing bug (Saving process crashed.)

Post by bormand »

luketyleruk wrote: Mon Feb 01, 2021 10:56 am i thinking it might be a bug in the stable versions
I don't think it a bug on factorio side...

SIGKILL usually means that someone deliberately killed your process for some reason. Some script on your server, parent process, kernel itself on out-of-memory condition etc. It's not a usual crash like SIGSEGV, it's a deliberate kill.
User avatar
bormand
Fast Inserter
Fast Inserter
Posts: 201
Joined: Fri Jun 05, 2020 9:59 am
Contact:

Re: [1.1.19] Server crashing bug (Saving process crashed.)

Post by bormand »

luketyleruk wrote: Mon Feb 01, 2021 10:56 am pterodactyl
Worth trying to ask them about this bug too. They should know what runs in their container aside from factorio, so they may help you if the issue is on their side.
Oxyd
Former Staff
Former Staff
Posts: 1428
Joined: Thu May 07, 2015 8:42 am
Contact:

Re: [1.1.19] Server crashing bug (Saving process crashed.)

Post by Oxyd »

bormand wrote: Mon Feb 01, 2021 11:14 am
luketyleruk wrote: Mon Feb 01, 2021 10:56 am i thinking it might be a bug in the stable versions
I don't think it a bug on factorio side...

SIGKILL usually means that someone deliberately killed your process for some reason. Some script on your server, parent process, kernel itself on out-of-memory condition etc. It's not a usual crash like SIGSEGV, it's a deliberate kill.
That's what I'm thinking as well. I can't think of any situation where Factorio would decide to kill itself by means of SIGKILL.

Does this happen with any sort of regularity or was this a one-off?
User avatar
bormand
Fast Inserter
Fast Inserter
Posts: 201
Joined: Fri Jun 05, 2020 9:59 am
Contact:

Re: [1.1.19] Server crashing bug (Saving process crashed.)

Post by bormand »

Oxyd wrote: Mon Feb 01, 2021 12:12 pm I can't think of any situation where Factorio would decide to kill itself by means of SIGKILL.
Well, I can imagine that Factorio can kill autosave instance after timeout or during shutdown of the main process... But you certainly will log that before attempting SIGKILL.

I guess it's just a buggy script that tries to kill something else, but uses stale PID file and hits Factorio instead.
luketyleruk
Burner Inserter
Burner Inserter
Posts: 17
Joined: Tue Nov 24, 2020 3:28 pm
Contact:

Re: [1.1.19] Server crashing bug (Saving process crashed.)

Post by luketyleruk »

this is what happened just before the crash https://clips.twitch.tv/GloriousBigChim ... oneyBadger
User avatar
bormand
Fast Inserter
Fast Inserter
Posts: 201
Joined: Fri Jun 05, 2020 9:59 am
Contact:

Re: [1.1.19] Server crashing bug (Saving process crashed.)

Post by bormand »

luketyleruk wrote: Mon Feb 01, 2021 12:36 pm this is what happened just before the crash
Lag spike before disconnect? This agrees with unusually slow save before crash (20s vs 5s normally). Save time in your previous post is also unusually large (about 28 seconds). May be a heavy swapping before out of memory and summoning of the OOM killer, at least in theory.
0.046 System info: [CPU: QEMU Virtual CPU version 2.5+, 4 cores, RAM: 11981 MB]
You said that your server has 64GB of memory, but log shows that only 12 of them are available for Factorio container. Worth trying to increase that number somehow.
Twinsen
Factorio Staff
Factorio Staff
Posts: 1359
Joined: Tue Sep 23, 2014 7:10 am
Contact:

Re: Server crashing bug

Post by Twinsen »

luketyleruk wrote: Mon Feb 01, 2021 10:19 am server then restarts reverting back to original game save, not from autosave.
One of the arguments is "--start-server" "megabase_1.zip". I assume it's being called with same arguments so it makes sense it reverts to original save.

Regarding the crash, maybe it's related to the experimental non-blocking saving.
Or something caused a loop in the saving process which caused it to leak too much ram witch caused it to be killed by the OS, but without a way to reproduce there's probably nothing we can do.
Since this is a megabase and saving could increase the ram usage, it possible it exceeded the allocated 12GB.
luketyleruk
Burner Inserter
Burner Inserter
Posts: 17
Joined: Tue Nov 24, 2020 3:28 pm
Contact:

Re: [1.1.19] Server crashing bug (Saving process crashed.)

Post by luketyleruk »

i have now removed the non blocking saves, and i have changed the settings to revert back to auto save upon a crash ( if it does crash).
posila
Factorio Staff
Factorio Staff
Posts: 5409
Joined: Thu Jun 11, 2015 1:35 pm
Contact:

Re: [1.1.19] Crash of non blocking saving process on headless

Post by posila »

Non-blocking saving will potentially cause duplication of entire game state memory space, due to fork and copy-on-write.
Post Reply

Return to “Won't fix.”