[Oxyd] Server not saving properly

Bugs that we were not able to reproduce, and/or are waiting for more detailed info.
Post Reply
19wolf
Long Handed Inserter
Long Handed Inserter
Posts: 61
Joined: Fri May 06, 2016 3:49 pm
Contact:

[Oxyd] Server not saving properly

Post by 19wolf »

For a while now, whenever I stop my Factorio server (running via systemd on Ubuntu 16.04), I end up with a corrupt save file labelled "_autosave2.tmp.zip" (or whatever number was the latest autosave). When I go to start up my server again, I loads the latest file in the save directory, which is always this temp file. The problem is, the temp file is usually less than 1/10th the size of the actual save file. Additionally, the "server.zip" save file is never updated/re-saved.

My save folder:

Code: Select all

root@server:/opt/factorio# ls -l saves/
total 79836
-rw-r--r-- 1 root root 17025619 May  9 22:09 _autosave1.zip
-rw-r--r-- 1 root root  1492993 May 10 09:33 _autosave2.tmp.zip
-rw-r--r-- 1 root root 19464560 May  9 22:19 _autosave2.zip
-rw-r--r-- 1 root root 10007723 May  9 21:39 _autosave3.zip
-rw-r--r-- 1 root root 10101697 May  9 21:49 _autosave4.zip
-rw-r--r-- 1 root root 13024984 May  9 21:59 _autosave5.zip
-rw-r--r-- 1 root root 10617032 May  8 21:41 server.zip
My factorio-current.log:

Code: Select all

0.000 2017-05-10 06:01:41; Factorio 0.15.9 (build 29504, linux64, headless)
   0.176 Operating system: Linux (Ubuntu 16.04)
   0.177 Program arguments: "/opt/factorio/bin/x64/factorio" "--server-settings" "/opt/factorio/data/server-settings.json" "--start-server-load-latest" "server.zip" 
   0.177 Read data path: /opt/factorio/data
   0.177 Write data path: /opt/factorio
   0.177 Binaries path: /opt/factorio/bin
   0.313 System info: [CPU:        Intel(R) Celeron(R) CPU G1610T @ 2.30GHz, 2 cores, RAM: 3907MB]
   0.313 Running in headless mode
   1.577 Loading mod settings even-distribution 0.1.0 (settings.lua)
   1.613 Loading mod core 0.0.0 (data.lua)
   1.680 Loading mod base 0.15.9 (data.lua)
   3.190 Loading mod auto-research 3.1.0 (data.lua)
   3.325 Loading mod autofill 1.4.7 (data.lua)
   3.431 Loading mod Bottleneck 0.6.3 (data.lua)
   3.556 Loading mod even-distribution 0.1.0 (data.lua)
   3.656 Loading mod research-queue 1.5.1 (data.lua)
   3.763 Loading mod base 0.15.9 (data-updates.lua)
   3.910 Loading mod auto-research 3.1.0 (data-final-fixes.lua)
   4.013 Loading mod research-queue 1.5.1 (data-final-fixes.lua)
   4.127 Checksum for core: 3409166051
   4.127 Checksum of base: 3769930138
   4.127 Checksum of auto-research: 1568893371
   4.127 Checksum of AutoDeconstruct: 0
   4.127 Checksum of autofill: 3086359458
   4.127 Checksum of Bottleneck: 110869948
   4.127 Checksum of even-distribution: 4168107971
   4.127 Checksum of research-queue: 615097349
   4.411 Info PlayerData.cpp:55: Local player-data.json available, timestamp 1494017988
   4.412 Info PlayerData.cpp:62: Cloud player-data.json unavailable
   4.413 Custom inputs active: 0
   4.414 Info Updater.cpp:753: Downloading https://updater.factorio.com/get-available-versions?username=19wolf&token=<private>&apiVersion=2
   5.019 0 packages available to download (experimental updates disabled).
   5.023 Factorio initialised
   5.024 Info HttpSharedState.cpp:44: Downloading https://auth.factorio.com/api-login?api_version=2
   5.452 Info HttpSharedState.cpp:111: Status code: 200
   5.453 Info AuthServerConnector.cpp:169: Got token from auth server for username(19wolf).
   5.516 Info ServerSynchronizer.cpp:27: nextHeartbeatSequenceNumber(0) initialized Synchronizer nextTickClosureTick(0).
   5.516 Info ServerMultiplayerManager.cpp:663: mapTick(-1) changing state from(Ready) to(PreparedToHostGame)
   5.516 Info ServerMultiplayerManager.cpp:663: mapTick(-1) changing state from(PreparedToHostGame) to(CreatingGame)
   5.523 Loading map /opt/factorio/saves/_autosave2.zip: 19464560 bytes.
   5.678 Loading Level.dat: 46267543 bytes.
   5.691 Info Scenario.cpp:133: Map version 0.15.9-0
   8.432 Loading script.dat: 536701 bytes.
   8.486 Checksum for script /opt/factorio/temp/currently-playing/control.lua: 76911248
   8.489 Checksum for script __auto-research__/control.lua: 2608236854
   8.491 Checksum for script __AutoDeconstruct__/control.lua: 3034658017
   8.503 Checksum for script __autofill__/control.lua: 3455809202
   8.505 Checksum for script __Bottleneck__/control.lua: 2468296750
   8.509 Checksum for script __even-distribution__/control.lua: 2743291030
   8.602 Checksum for script __research-queue__/control.lua: 688964699
  10.402 Info UDPSocket.cpp:27: Opening socket at (0.0.0.0:34197)
  10.402 Hosting game at 0.0.0.0:34197
  10.402 Info HttpSharedState.cpp:44: Downloading https://auth.factorio.com/generate-server-padlock
  10.449 Info HttpSharedState.cpp:111: Status code: 200
  10.449 Info AuthServerConnector.cpp:106: Obtained serverPadlock for serverHash (6brrstQ8dP3JA4okEidRsF48NYQcY3Hf) from the auth server.
  10.450 Info ServerMultiplayerManager.cpp:663: mapTick(15876001) changing state from(CreatingGame) to(InGame)
  10.450 Info UDPSocket.cpp:39: Opening socket for broadcast
  10.471 Error InterruptibleStdioStream.cpp:53: Reading stdin failed
12652.152 Received SIGTERM, shutting down
12652.361 Info MainLoop.cpp:242: Saving map as /opt/factorio/saves/_autosave2.zip
My systemd unit file:

Code: Select all

[Unit]
Description=Factorio Server
After=network.target

[Service]
Type=simple
User=root
Group=root
ExecStart=/opt/factorio/bin/x64/factorio --server-settings /opt/factorio/data/server-settings.json --start-server-load-latest server.zip
Restart=always

[Install]
WantedBy=multi-user.target

Oxyd
Former Staff
Former Staff
Posts: 1428
Joined: Thu May 07, 2015 8:42 am
Contact:

Re: Server not saving properly

Post by Oxyd »

If you end up with one of these .tmp.zip files, it means that Factorio died before it could finish saving. Your log file also ends abruptly, indicating sudden termination of the process whilst it's saving. And there's no indication of a crash.

So, it looks like something is killing your Factorio process. Check what and why. Factorio should exit cleanly when you send it SIGTERM once, but it will terminate immediatelly if you send it SIGTERM twice – so one possibility is that something sends that signal twice.

archlol
Manual Inserter
Manual Inserter
Posts: 1
Joined: Thu May 25, 2017 2:16 pm
Contact:

Re: Server not saving properly

Post by archlol »

I have the same issue only that my server crashes on auto-saving. Left with a .tmp.zip file, no information in the log file. Running on Linux Ubuntu on DigitalOcean.

Rseding91
Factorio Staff
Factorio Staff
Posts: 13175
Joined: Wed Jun 11, 2014 5:23 am
Contact:

Re: Server not saving properly

Post by Rseding91 »

archlol wrote:I have the same issue only that my server crashes on auto-saving. Left with a .tmp.zip file, no information in the log file. Running on Linux Ubuntu on DigitalOcean.
Did it run out of RAM while saving? If that happens there's a good chance it won't have RAM to even generate the stack trace and just gets aborted by the operating system.
If you want to get ahold of me I'm almost always on Discord.

AlienX
Fast Inserter
Fast Inserter
Posts: 103
Joined: Wed May 17, 2017 7:13 pm
Contact:

Re: Server not saving properly

Post by AlienX »

I've had this issue before when the saves directory does not have the correct chmod and chown permissions for the user that the factrio binary is running as, I would double check this.

p.s
If you're running it as root, you're very naughty.

Oxyd
Former Staff
Former Staff
Posts: 1428
Joined: Thu May 07, 2015 8:42 am
Contact:

Re: Server not saving properly

Post by Oxyd »

I've added some logging to 0.15.14, so if you're still experiencing this, i'd like the 0.15.14 log as well.

19wolf
Long Handed Inserter
Long Handed Inserter
Posts: 61
Joined: Fri May 06, 2016 3:49 pm
Contact:

Re: Server not saving properly

Post by 19wolf »

AlienX wrote:I've had this issue before when the saves directory does not have the correct chmod and chown permissions for the user that the factrio binary is running as, I would double check this.

p.s
If you're running it as root, you're very naughty.
I'm running in a completely stand-alone vm container that doesn't even have ssh installed, I should be okay

19wolf
Long Handed Inserter
Long Handed Inserter
Posts: 61
Joined: Fri May 06, 2016 3:49 pm
Contact:

Re: Server not saving properly

Post by 19wolf »

Still having the problem. My .15.15 logs:

factorio-current.log

Code: Select all

0.000 2017-05-27 04:01:10; Factorio 0.15.15 (build 30025, linux64, headless)
   0.964 Operating system: Linux (Ubuntu 16.04)
   0.965 Program arguments: "/opt/factorio/bin/x64/factorio" "--server-settings" "/opt/factorio/data/server-settings.json" "--start-server-load-latest" "server.zip" 
   0.965 Read data path: /opt/factorio/data
   0.965 Write data path: /opt/factorio
   0.965 Binaries path: /opt/factorio/bin
   0.999 System info: [CPU:        Intel(R) Celeron(R) CPU G1610T @ 2.30GHz, 2 cores, RAM: 3907MB]
   1.003 Running in headless mode
   1.979 Loading mod settings axial-tilt 0.15.1 (settings.lua)
   1.980 Loading mod settings Bottleneck 0.7.3 (settings.lua)
   1.980 Loading mod settings even-distribution 0.1.1 (settings.lua)
   1.980 Loading mod settings helmod 0.5.2 (settings.lua)
   1.988 Loading mod core 0.0.0 (data.lua)
   1.997 Loading mod base 0.15.15 (data.lua)
   2.191 Loading mod autofill 1.4.8 (data.lua)
   2.293 Loading mod BeltImmunity 0.15.0 (data.lua)
   2.401 Loading mod Bottleneck 0.7.3 (data.lua)
   3.024 Loading mod even-distribution 0.1.1 (data.lua)
   3.149 Loading mod helmod 0.5.2 (data.lua)
   3.295 Loading mod Honk 2.1.3 (data.lua)
   3.390 Loading mod Orphan Finder 1.0.5 (data.lua)
   3.487 Loading mod VehicleSnap 1.15.1 (data.lua)
   3.614 Loading mod base 0.15.15 (data-updates.lua)
   3.720 Loading mod helmod 0.5.2 (data-final-fixes.lua)
   3.849 Checksum for core: 2224076952
   3.849 Checksum of base: 2355693671
   3.849 Checksum of AutoDeconstruct: 0
   3.849 Checksum of autofill: 3086359458
   3.849 Checksum of axial-tilt: 3570238031
   3.849 Checksum of BeltImmunity: 2499314336
   3.849 Checksum of Bottleneck: 2602391719
   3.849 Checksum of even-distribution: 1881901252
   3.849 Checksum of helmod: 1882751409
   3.849 Checksum of Honk: 3337765968
   3.849 Checksum of Orphan Finder: 169567895
   3.849 Checksum of VehicleSnap: 3379580387
   4.025 Info PlayerData.cpp:56: Local player-data.json available, timestamp 1495855573
   4.025 Info PlayerData.cpp:63: Cloud player-data.json unavailable
   4.026 Custom inputs active: 0
   4.027 Info Updater.cpp:751: Downloading https://updater.factorio.com/get-available-versions?username=19wolf&token=<private>&apiVersion=2
   4.441 0 packages available to download (experimental updates disabled).
   4.446 Factorio initialised
   4.446 Info HttpSharedState.cpp:44: Downloading https://auth.factorio.com/api-login?api_version=2
   4.764 Info HttpSharedState.cpp:111: Status code: 200
   4.764 Info AuthServerConnector.cpp:169: Got token from auth server for username(19wolf).
   4.765 Info ServerSynchronizer.cpp:27: nextHeartbeatSequenceNumber(0) initialized Synchronizer nextTickClosureTick(0).
   4.765 Info ServerMultiplayerManager.cpp:670: mapTick(-1) changing state from(Ready) to(PreparedToHostGame)
   4.765 Info ServerMultiplayerManager.cpp:670: mapTick(-1) changing state from(PreparedToHostGame) to(CreatingGame)
   4.765 Loading map /opt/factorio/saves/server.tmp.zip: 262455 bytes.
   4.831 Error ServerMultiplayerManager.cpp:94: MultiplayerManager failed: "Opening zip /opt/factorio/saves/server.tmp.zip failed: Bad zip file"
   4.831 Info ServerMultiplayerManager.cpp:670: mapTick(-1) changing state from(CreatingGame) to(InitializationFailed)
factorio-previous.log

Code: Select all

0.000 2017-05-27 00:44:50; Factorio 0.15.15 (build 30025, linux64, headless)
   1.760 Operating system: Linux (Ubuntu 16.04)
   1.760 Program arguments: "/opt/factorio/bin/x64/factorio" "--server-settings" "/opt/factorio/data/server-settings.json" "--start-server-load-latest" "server.zip" 
   1.760 Read data path: /opt/factorio/data
   1.760 Write data path: /opt/factorio
   1.760 Binaries path: /opt/factorio/bin
   1.774 System info: [CPU:        Intel(R) Celeron(R) CPU G1610T @ 2.30GHz, 2 cores, RAM: 3907MB]
   1.775 Running in headless mode
   2.105 Loading mod settings axial-tilt 0.15.1 (settings.lua)
   2.106 Loading mod settings Bottleneck 0.7.3 (settings.lua)
   2.107 Loading mod settings even-distribution 0.1.1 (settings.lua)
   2.107 Loading mod settings helmod 0.5.2 (settings.lua)
   2.202 Loading mod core 0.0.0 (data.lua)
   2.227 Loading mod base 0.15.15 (data.lua)
   2.443 Loading mod autofill 1.4.8 (data.lua)
   2.601 Loading mod BeltImmunity 0.15.0 (data.lua)
   2.704 Loading mod Bottleneck 0.7.3 (data.lua)
   2.868 Loading mod even-distribution 0.1.1 (data.lua)
   2.984 Loading mod helmod 0.5.2 (data.lua)
   3.088 Loading mod Honk 2.1.3 (data.lua)
   3.223 Loading mod Orphan Finder 1.0.5 (data.lua)
   3.323 Loading mod VehicleSnap 1.15.1 (data.lua)
   3.445 Loading mod base 0.15.15 (data-updates.lua)
   3.604 Loading mod helmod 0.5.2 (data-final-fixes.lua)
   3.791 Checksum for core: 2224076952
   3.791 Checksum of base: 2355693671
   3.791 Checksum of AutoDeconstruct: 0
   3.791 Checksum of autofill: 3086359458
   3.791 Checksum of axial-tilt: 3570238031
   3.791 Checksum of BeltImmunity: 2499314336
   3.791 Checksum of Bottleneck: 2602391719
   3.791 Checksum of even-distribution: 1881901252
   3.791 Checksum of helmod: 1882751409
   3.791 Checksum of Honk: 3337765968
   3.792 Checksum of Orphan Finder: 169567895
   3.792 Checksum of VehicleSnap: 3379580387
   4.066 Info PlayerData.cpp:56: Local player-data.json available, timestamp 1495855573
   4.066 Info PlayerData.cpp:63: Cloud player-data.json unavailable
   4.068 Custom inputs active: 0
   4.068 Info Updater.cpp:751: Downloading https://updater.factorio.com/get-available-versions?username=19wolf&token=<private>&apiVersion=2
   4.583 0 packages available to download (experimental updates disabled).
   4.587 Factorio initialised
   4.588 Info HttpSharedState.cpp:44: Downloading https://auth.factorio.com/api-login?api_version=2
   4.789 Info HttpSharedState.cpp:111: Status code: 200
   4.790 Info AuthServerConnector.cpp:169: Got token from auth server for username(19wolf).
   4.790 Info ServerSynchronizer.cpp:27: nextHeartbeatSequenceNumber(0) initialized Synchronizer nextTickClosureTick(0).
   4.790 Info ServerMultiplayerManager.cpp:670: mapTick(-1) changing state from(Ready) to(PreparedToHostGame)
   4.790 Info ServerMultiplayerManager.cpp:670: mapTick(-1) changing state from(PreparedToHostGame) to(CreatingGame)
   4.795 Loading map /opt/factorio/saves/server.zip: 36456549 bytes.
   4.853 Loading Level.dat: 80299583 bytes.
   4.889 Info Scenario.cpp:134: Map version 0.15.15-1
  11.110 Info BlueprintLibrary.cpp:190: Loaded library shelves:
  11.122 Info BlueprintLibrary.cpp:679: Game shelf: playerIndex = 65535, nextRecordID = 61; timestamp = 1493074362; records: (id: 65535, 60; label: "Alphabet", preview: false, empty: false; book [id: 65535, 24; label: "A", preview: false, empty: false] [id: 65535, 25; label: "B", preview: false, empty: false] [id: 65535, 26; label: "C", preview: false, empty: false] [id: 65535, 27; label: "D", preview: false, empty: false] [id: 65535, 28; label: "E", preview: false, empty: false] [id: 65535, 29; label: "F", preview: false, empty: false] [id: 65535, 30; label: "G", preview: false, empty: false] [id: 65535, 31; label: "H", preview: false, empty: false] [id: 65535, 32; label: "I", preview: false, empty: false] [id: 65535, 33; label: "J", preview: false, empty: false] [id: 65535, 34; label: "K", preview: false, empty: false] [id: 65535, 35; label: "L", preview: false, empty: false] [id: 65535, 36; label: "M", preview: false, empty: false] [id: 65535, 37; label: "N", preview: false, empty: false] [id: 65535, 38; label: "O", preview: false, empty: false] [id: 65535, 39; label: "P", preview: false, empty: false] [id: 65535, 40; label: "Q", preview: false, empty: false] [id: 65535, 41; label: "R", preview: false, empty: false] [id: 65535, 42; label: "S", preview: false, empty: false] [id: 65535, 43; label: "T", preview: false, empty: false] [id: 65535, 44; label: "U", preview: false, empty: false] [id: 65535, 45; label: "V", preview: false, empty: false] [id: 65535, 46; label: "W", preview: false, empty: false] [id: 65535, 47; label: "X", preview: false, empty: false] [id: 65535, 48; label: "Y", preview: false, empty: false] [id: 65535, 49; label: "Z", preview: false, empty: false] [id: 65535, 50; label: "0", preview: false, empty: false] [id: 65535, 51; label: "1", preview: false, empty: false] [id: 65535, 52; label: "2", preview: false, empty: false] [id: 65535, 53; label: "3", preview: false, empty: false] [id: 65535, 54; label: "4", preview: false, empty: false] [id: 65535, 55; label: "5", preview: false, empty: false] [id: 65535, 56; label: "6", preview: false, empty: false] [id: 65535, 57; label: "7", preview: false, empty: false] [id: 65535, 58; label: "8", preview: false, empty: false] [id: 65535, 59; label: "9", preview: false, empty: false])
  11.122 Info BlueprintLibrary.cpp:681: Player shelf: playerIndex = 0, nextRecordID = 159; timestamp = 1495838851; records: (id: 0, 156; label: "Alphabet", preview: false, empty: false; book [id: 0, 120; label: "A", preview: false, empty: false] [id: 0, 121; label: "B", preview: false, empty: false] [id: 0, 122; label: "C", preview: false, empty: false] [id: 0, 123; label: "D", preview: false, empty: false] [id: 0, 124; label: "E", preview: false, empty: false] [id: 0, 125; label: "F", preview: false, empty: false] [id: 0, 126; label: "G", preview: false, empty: false] [id: 0, 127; label: "H", preview: false, empty: false] [id: 0, 128; label: "I", preview: false, empty: false] [id: 0, 129; label: "J", preview: false, empty: false] [id: 0, 130; label: "K", preview: false, empty: false] [id: 0, 131; label: "L", preview: false, empty: false] [id: 0, 132; label: "M", preview: false, empty: false] [id: 0, 133; label: "N", preview: false, empty: false] [id: 0, 134; label: "O", preview: false, empty: false] [id: 0, 135; label: "P", preview: false, empty: false] [id: 0, 136; label: "Q", preview: false, empty: false] [id: 0, 137; label: "R", preview: false, empty: false] [id: 0, 138; label: "S", preview: false, empty: false] [id: 0, 139; label: "T", preview: false, empty: false] [id: 0, 140; label: "U", preview: false, empty: false] [id: 0, 141; label: "V", preview: false, empty: false] [id: 0, 142; label: "W", preview: false, empty: false] [id: 0, 143; label: "X", preview: false, empty: false] [id: 0, 144; label: "Y", preview: false, empty: false] [id: 0, 145; label: "Z", preview: false, empty: false] [id: 0, 146; label: "0", preview: false, empty: false] [id: 0, 147; label: "1", preview: false, empty: false] [id: 0, 148; label: "2", preview: false, empty: false] [id: 0, 149; label: "3", preview: false, empty: false] [id: 0, 150; label: "4", preview: false, empty: false] [id: 0, 151; label: "5", preview: false, empty: false] [id: 0, 152; label: "6", preview: false, empty: false] [id: 0, 153; label: "7", preview: false, empty: false] [id: 0, 154; label: "8", preview: false, empty: false] [id: 0, 155; label: "9", preview: false, empty: false]) (id: 0, 104; label: "Blue Balancers", preview: false, empty: false; book [id: 0, 114; label: "", preview: false, empty: false] [id: 0, 67; label: "2 to 3 (Long Variant)", preview: false, empty: false] [id: 0, 68; label: "2 to 3 (Wide Variant)", preview: false, empty: false] [id: 0, 69; label: "2 to 4", preview: false, empty: false] [id: 0, 70; label: "2 to 5 (Long Variant)", preview: false, empty: false] [id: 0, 71; label: "2 to 5 (Wide Variant)", preview: false, empty: false] [id: 0, 72; label: "2 to 6", preview: false, empty: false] [id: 0, 73; label: "2 to 7", preview: false, empty: false] [id: 0, 74; label: "2 to 8", preview: false, empty: false] [id: 0, 75; label: "3 to 2", preview: false, empty: false] [id: 0, 76; label: "3 to 3", preview: false, empty: false] [id: 0, 77; label: "3 to 4", preview: false, empty: false] [id: 0, 78; label: "3 to 5", preview: false, empty: false] [id: 0, 79; label: "3 to 6", preview: false, empty: false] [id: 0, 80; label: "3 to 7", preview: false, empty: false] [id: 0, 81; label: "3 to 8", preview: false, empty: false] [id: 0, 82; label: "4 to 3", preview: false, empty: false] [id: 0, 83; label: "4 to 4", preview: false, empty: false] [id: 0, 84; label: "4 to 5", preview: false, empty: false] [id: 0, 85; label: "4 to 6", preview: false, empty: false] [id: 0, 86; label: "4 to 7", preview: false, empty: false] [id: 0, 87; label: "4 to 8", preview: false, empty: false] [id: 0, 88; label: "5 to 3", preview: false, empty: false] [id: 0, 89; label: "5 to 4", preview: false, empty: false] [id: 0, 90; label: "5 to 5", preview: false, empty: false] [id: 0, 91; label: "5 to 6", preview: false, empty: false] [id: 0, 92; label: "5 to 7", preview: false, empty: false] [id: 0, 93; label: "5 to 8", preview: false, empty: false] [id: 0, 94; label: "6 to 4", preview: false, empty: false] [id: 0, 95; label: "6 to 5", preview: false, empty: false] [id: 0, 96; label: "6 to 6", preview: false, empty: false] [id: 0, 97; label: "6 to 7", preview: false, empty: false] [id: 0, 98; label: "6 to 8", preview: false, empty: false] [id: 0, 99; label: "8 to 4", preview: false, empty: false] [id: 0, 100; label: "8 to 5", preview: false, empty: false] [id: 0, 101; label: "8 to 6", preview: false, empty: false] [id: 0, 102; label: "8 to 7", preview: false, empty: false] [id: 0, 106; label: "8x8", preview: false, empty: false]) (id: 0, 105; label: "Trains", preview: false, empty: false; book [id: 0, 13; label: "1 block", preview: false, empty: false] [id: 0, 157; label: "3-way", preview: false, empty: false] [id: 0, 62; label: "Base - Liquid", preview: false, empty: false] [id: 0, 63; label: "Base - Ore", preview: false, empty: false] [id: 0, 49; label: "Outpost", preview: false, empty: false] [id: 0, 158; label: "PAX", preview: false, empty: false] [id: 0, 55; label: "Supply", preview: false, empty: false]) (id: 0, 113; label: "", preview: false, empty: false; single) (id: 0, 108; label: "4-2 Priority", preview: false, empty: false; single) (id: 0, 115; label: "4-2 Priority", preview: false, empty: false; single) (id: 0, 110; label: "8-2 Priority", preview: false, empty: false; single) (id: 0, 118; label: "Beacon Smelter", preview: false, empty: false; single) (id: 0, 12; label: "Belts", preview: false, empty: false; single) (id: 0, 46; label: "Blue Circuit", preview: false, empty: false; single) (id: 0, 38; label: "Blue Smelt", preview: false, empty: false; single) (id: 0, 36; label: "Blue Steel", preview: false, empty: false; single) (id: 0, 117; label: "Green Circuits", preview: false, empty: false; single) (id: 0, 119; label: "Letters", preview: false, empty: false; single) (id: 0, 39; label: "LogiConcrete", preview: false, empty: false; single) (id: 0, 56; label: "Maker", preview: false, empty: false; single) (id: 0, 20; label: "Mining", preview: false, empty: false; single) (id: 0, 61; label: "Nuke", preview: false, empty: false; single) (id: 0, 116; label: "Productive Circuits", preview: false, empty: false; single) (id: 0, 47; label: "RoboStation", preview: false, empty: false; single) (id: 0, 34; label: "Solar", preview: false, empty: false; single) (id: 0, 32; label: "Steam", preview: false, empty: false; single)
  11.122 Info BlueprintLibrary.cpp:681: Player shelf: playerIndex = 1, nextRecordID = 0; timestamp = 1495596236; records:
  11.122 Info BlueprintLibrary.cpp:681: Player shelf: playerIndex = 2, nextRecordID = 0; timestamp = 1495496074; records:
  12.083 Info BlueprintLibrary.cpp:47: Loaded external blueprint storage: playerIndex = 65535, nextRecordID = 0; timestamp = 1495860302; records:
  12.093 Loading script.dat: 532913 bytes.
  12.155 Checksum for script /opt/factorio/temp/currently-playing/control.lua: 282129324
  12.158 Checksum for script __AutoDeconstruct__/control.lua: 3034658017
  12.169 Checksum for script __autofill__/control.lua: 428222097
  12.183 Checksum for script __axial-tilt__/control.lua: 2477845871
  12.186 Checksum for script __BeltImmunity__/control.lua: 0
  12.188 Checksum for script __Bottleneck__/control.lua: 1037364004
  12.195 Checksum for script __even-distribution__/control.lua: 3272626212
  12.271 Checksum for script __helmod__/control.lua: 3004994211
  12.276 Checksum for script __Honk__/control.lua: 1248643386
  12.279 Checksum for script __Orphan Finder__/control.lua: 3794858359
  12.284 Checksum for script __VehicleSnap__/control.lua: 3426081906
  14.000 Script control.lua:356: AutoFill: Defaults Updated
  16.075 Info UDPSocket.cpp:27: Opening socket at (0.0.0.0:34197)
  16.075 Hosting game at 0.0.0.0:34197
  16.075 Info ServerMultiplayerManager.cpp:670: mapTick(26568001) changing state from(CreatingGame) to(InGame)
  16.075 Info UDPSocket.cpp:39: Opening socket for broadcast
  16.096 Error InterruptibleStdioStream.cpp:53: Reading stdin failed
  29.603 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(10.0.1.20:64819)
  29.604 Info ServerRouter.cpp:389: Replying to connectionRequest for address(10.0.1.20:64819).
  29.604 Info ServerSynchronizer.cpp:542: nextHeartbeatSequenceNumber(400) adding peer(1)
  29.621 Info ServerMultiplayerManager.cpp:670: mapTick(26568001) changing state from(InGame) to(InGameSavingMap)
  29.638 Info ServerMultiplayerManager.cpp:754: mapTick(26568001) received stateChanged peerID(1) oldState(Ready) newState(ConnectedWaitingForMap)
  34.169 Info ServerMultiplayerManager.cpp:808: MapTick(26568001) Serving map(/opt/factorio/temp/mp-save-0.zip) for peer(1) size(36447097) crc(153983951)
  34.169 Info ServerMultiplayerManager.cpp:670: mapTick(26568001) changing state from(InGameSavingMap) to(InGame)
  34.237 Info ServerMultiplayerManager.cpp:754: mapTick(26568001) received stateChanged peerID(1) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
  41.591 Info ServerMultiplayerManager.cpp:754: mapTick(26568001) received stateChanged peerID(1) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
  45.094 Info ServerMultiplayerManager.cpp:754: mapTick(26568209) received stateChanged peerID(1) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
  46.607 Info ServerMultiplayerManager.cpp:754: mapTick(26568297) received stateChanged peerID(1) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
  46.609 Info GameActionHandler.cpp:3236: MapTick (26568297) processed PlayerJoinGame peerID(1) playerIndex(0) mode(connect ) 
  46.967 Info ServerMultiplayerManager.cpp:754: mapTick(26568301) received stateChanged peerID(1) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
 118.189 Info ServerMultiplayerManager.cpp:854: Disconnect notification for peer (1)
 118.194 Info ServerMultiplayerManager.cpp:754: mapTick(26572567) received stateChanged peerID(1) oldState(InGame) newState(DisconnectScheduled)
 118.196 Info ServerSynchronizer.cpp:557: nextHeartbeatSequenceNumber(3306) removing peer(1).
 938.707 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(10.0.1.20:52977)
 938.713 Info ServerRouter.cpp:389: Replying to connectionRequest for address(10.0.1.20:52977).
 938.713 Info ServerSynchronizer.cpp:542: nextHeartbeatSequenceNumber(27707) adding peer(2)
 938.713 Info ServerMultiplayerManager.cpp:670: mapTick(26572568) changing state from(InGame) to(InGameSavingMap)
 938.747 Info ServerMultiplayerManager.cpp:754: mapTick(26572568) received stateChanged peerID(2) oldState(Ready) newState(ConnectedWaitingForMap)
 942.292 Info ServerMultiplayerManager.cpp:808: MapTick(26572568) Serving map(/opt/factorio/temp/mp-save-1.zip) for peer(2) size(36455297) crc(2711260588)
 942.292 Info ServerMultiplayerManager.cpp:670: mapTick(26572568) changing state from(InGameSavingMap) to(InGame)
 942.376 Info ServerMultiplayerManager.cpp:754: mapTick(26572568) received stateChanged peerID(2) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
 948.642 Info ServerMultiplayerManager.cpp:754: mapTick(26572568) received stateChanged peerID(2) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
 952.073 Info ServerMultiplayerManager.cpp:754: mapTick(26572773) received stateChanged peerID(2) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
 953.486 Info ServerMultiplayerManager.cpp:754: mapTick(26572858) received stateChanged peerID(2) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
 953.486 Info GameActionHandler.cpp:3236: MapTick (26572858) processed PlayerJoinGame peerID(2) playerIndex(0) mode(connect ) 
 953.553 Info ServerMultiplayerManager.cpp:754: mapTick(26572862) received stateChanged peerID(2) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
6476.786 Info ServerMultiplayerManager.cpp:854: Disconnect notification for peer (2)
6476.859 Info ServerMultiplayerManager.cpp:754: mapTick(26892001) received stateChanged peerID(2) oldState(InGame) newState(DisconnectScheduled)
6477.001 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (2) that is not disconnected yet.
6477.001 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (2) that is not disconnected yet.
6477.001 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (2) that is not disconnected yet.
6477.001 Info ServerSynchronizer.cpp:557: nextHeartbeatSequenceNumber(186388) removing peer(2).
11710.967 Received SIGTERM, shutting down
11711.078 Info MainLoop.cpp:251: Saving map as /opt/factorio/saves/server.zip
systemd unit file

Code: Select all

Unit]
Description=Factorio Server
After=network.target

[Service]
Type=simple
User=root
Group=root
ExecStart=/opt/factorio/bin/x64/factorio --server-settings /opt/factorio/data/server-settings.json --start-server-load-latest server.zip
Restart=always
TimeoutSec=60

[Install]
WantedBy=multi-user.target
my update script (runs at 4am local time daily + manually when I see an update)

Code: Select all

#!/bin/bash

echo "Stopping Factorio..."
systemctl stop factorio
echo "Downloading latest version..."
cd /tmp && touch temp && rm -r /tmp/* && wget -q --show-progress https://www.factorio.com/get-download/latest/headless/linux64
echo "Extracting and Installing..."
tar xf linux64 && rsync -a factorio/ /opt/factorio/
echo "Starting Factorio..."
systemctl start factorio
sleep 2
echo "Update to version $(head -n 1 /opt/factorio/factorio-current.log | awk '{print $5}') finished"
echo "Updated to version $(head -n 1 /opt/factorio/factorio-current.log | awk '{print $5}') on $(date)" >> /root/factorio.log
my 'factorio.log'

Code: Select all

Updated to version 0.15.13 on Tue May 23 12:54:21 EDT 2017
Updated to version 0.15.13 on Wed May 24 01:47:08 EDT 2017
Updated to version 0.15.13 on Wed May 24 04:00:48 EDT 2017
Updated to version 0.15.13 on Wed May 24 07:20:48 EDT 2017
Updated to version 0.15.13 on Wed May 24 17:25:48 EDT 2017
Updated to version 0.15.13 on Thu May 25 04:01:43 EDT 2017
Updated to version 0.15.13 on Fri May 26 04:01:31 EDT 2017
Updated to version 0.15.14 on Fri May 26 10:56:06 EDT 2017
Updated to version 0.15.15 on Fri May 26 16:59:58 EDT 2017
Updated to version 0.15.15 on Sat May 27 04:01:13 EDT 2017
I also want to note that 'systemctl stop factorio' sometimes takes 5 seconds, sometimes takes over 60. No idea why. Are there any other logs I can submit?

19wolf
Long Handed Inserter
Long Handed Inserter
Posts: 61
Joined: Fri May 06, 2016 3:49 pm
Contact:

Re: Server not saving properly

Post by 19wolf »

More logs

factorio-current.log

Code: Select all

0.000 2017-05-30 19:27:57; Factorio 0.15.16 (build 30063, linux64, headless)
   2.687 Operating system: Linux (Ubuntu 16.04)
   2.687 Program arguments: "/opt/factorio/bin/x64/factorio" "--server-settings" "/opt/factorio/data/server-settings.json" "--start-server-load-latest" "server.zip" 
   2.687 Read data path: /opt/factorio/data
   2.687 Write data path: /opt/factorio
   2.687 Binaries path: /opt/factorio/bin
   2.700 System info: [CPU:        Intel(R) Celeron(R) CPU G1610T @ 2.30GHz, 2 cores, RAM: 3907MB]
   2.700 Running in headless mode
   3.141 Loading mod settings axial-tilt 0.15.1 (settings.lua)
   3.142 Loading mod settings Bottleneck 0.7.3 (settings.lua)
   3.142 Loading mod settings even-distribution 0.1.1 (settings.lua)
   3.142 Loading mod settings helmod 0.5.2 (settings.lua)
   3.380 Loading mod core 0.0.0 (data.lua)
   3.426 Loading mod base 0.15.16 (data.lua)
   3.587 Loading mod autofill 1.4.8 (data.lua)
   3.692 Loading mod BeltImmunity 0.15.0 (data.lua)
   3.792 Loading mod Bottleneck 0.7.3 (data.lua)
   3.911 Loading mod even-distribution 0.1.1 (data.lua)
   4.007 Loading mod helmod 0.5.2 (data.lua)
   4.112 Loading mod Honk 2.1.3 (data.lua)
   4.246 Loading mod Orphan Finder 1.0.5 (data.lua)
   4.345 Loading mod VehicleSnap 1.15.1 (data.lua)
   4.446 Loading mod base 0.15.16 (data-updates.lua)
   4.616 Loading mod helmod 0.5.2 (data-final-fixes.lua)
   4.757 Checksum for core: 2224076952
   4.757 Checksum of base: 2355693671
   4.757 Checksum of AutoDeconstruct: 0
   4.757 Checksum of autofill: 3086359458
   4.757 Checksum of axial-tilt: 3570238031
   4.757 Checksum of BeltImmunity: 2499314336
   4.757 Checksum of Bottleneck: 2602391719
   4.757 Checksum of even-distribution: 1881901252
   4.757 Checksum of helmod: 1882751409
   4.757 Checksum of Honk: 3337765968
   4.757 Checksum of Orphan Finder: 169567895
   4.757 Checksum of VehicleSnap: 3379580387
   4.930 Info PlayerData.cpp:56: Local player-data.json available, timestamp 1495921592
   4.930 Info PlayerData.cpp:63: Cloud player-data.json unavailable
   4.935 Custom inputs active: 0
   4.936 Info Updater.cpp:751: Downloading https://updater.factorio.com/get-available-versions?username=19wolf&token=<private>&apiVersion=2
   5.448 0 packages available to download (experimental updates disabled).
   5.605 Factorio initialised
   5.605 Info HttpSharedState.cpp:44: Downloading https://auth.factorio.com/api-login?api_version=2
   5.920 Info HttpSharedState.cpp:111: Status code: 200
   5.921 Info AuthServerConnector.cpp:169: Got token from auth server for username(19wolf).
   6.204 Info ServerSynchronizer.cpp:27: nextHeartbeatSequenceNumber(0) initialized Synchronizer nextTickClosureTick(0).
   6.204 Info ServerMultiplayerManager.cpp:670: mapTick(-1) changing state from(Ready) to(PreparedToHostGame)
   6.204 Info ServerMultiplayerManager.cpp:670: mapTick(-1) changing state from(PreparedToHostGame) to(CreatingGame)
   6.205 Loading map /opt/factorio/saves/server.tmp.zip: 2145931 bytes.
   6.235 Error ServerMultiplayerManager.cpp:94: MultiplayerManager failed: "Opening zip /opt/factorio/saves/server.tmp.zip failed: Bad zip file"
   6.235 Info ServerMultiplayerManager.cpp:670: mapTick(-1) changing state from(CreatingGame) to(InitializationFailed)
factorio-previous.log

Code: Select all

0.000 2017-05-30 12:07:37; Factorio 0.15.16 (build 30063, linux64, headless)
   0.952 Operating system: Linux (Ubuntu 16.04)
   0.952 Program arguments: "/opt/factorio/bin/x64/factorio" "--server-settings" "/opt/factorio/data/server-settings.json" "--start-server-load-latest" "server.zip" 
   0.952 Read data path: /opt/factorio/data
   0.952 Write data path: /opt/factorio
   0.952 Binaries path: /opt/factorio/bin
   1.046 System info: [CPU:        Intel(R) Celeron(R) CPU G1610T @ 2.30GHz, 2 cores, RAM: 3907MB]
   1.047 Running in headless mode
   1.877 Loading mod settings axial-tilt 0.15.1 (settings.lua)
   1.877 Loading mod settings Bottleneck 0.7.3 (settings.lua)
   1.877 Loading mod settings even-distribution 0.1.1 (settings.lua)
   1.878 Loading mod settings helmod 0.5.2 (settings.lua)
   1.883 Loading mod core 0.0.0 (data.lua)
   1.933 Loading mod base 0.15.16 (data.lua)
   2.945 Loading mod autofill 1.4.8 (data.lua)
   3.068 Loading mod BeltImmunity 0.15.0 (data.lua)
   3.183 Loading mod Bottleneck 0.7.3 (data.lua)
   3.309 Loading mod even-distribution 0.1.1 (data.lua)
   3.419 Loading mod helmod 0.5.2 (data.lua)
   3.554 Loading mod Honk 2.1.3 (data.lua)
   3.693 Loading mod Orphan Finder 1.0.5 (data.lua)
   3.792 Loading mod VehicleSnap 1.15.1 (data.lua)
   3.892 Loading mod base 0.15.16 (data-updates.lua)
   4.087 Loading mod helmod 0.5.2 (data-final-fixes.lua)
   4.210 Checksum for core: 2224076952
   4.210 Checksum of base: 2355693671
   4.210 Checksum of AutoDeconstruct: 0
   4.210 Checksum of autofill: 3086359458
   4.210 Checksum of axial-tilt: 3570238031
   4.210 Checksum of BeltImmunity: 2499314336
   4.210 Checksum of Bottleneck: 2602391719
   4.210 Checksum of even-distribution: 1881901252
   4.210 Checksum of helmod: 1882751409
   4.210 Checksum of Honk: 3337765968
   4.210 Checksum of Orphan Finder: 169567895
   4.210 Checksum of VehicleSnap: 3379580387
   4.384 Info PlayerData.cpp:56: Local player-data.json available, timestamp 1495921592
   4.384 Info PlayerData.cpp:63: Cloud player-data.json unavailable
   4.385 Custom inputs active: 0
   4.386 Info Updater.cpp:751: Downloading https://updater.factorio.com/get-available-versions?username=19wolf&token=<private>&apiVersion=2
   5.119 0 packages available to download (experimental updates disabled).
   5.123 Factorio initialised
   5.124 Info HttpSharedState.cpp:44: Downloading https://auth.factorio.com/api-login?api_version=2
   5.626 Info HttpSharedState.cpp:111: Status code: 200
   5.626 Info AuthServerConnector.cpp:169: Got token from auth server for username(19wolf).
   5.627 Info ServerSynchronizer.cpp:27: nextHeartbeatSequenceNumber(0) initialized Synchronizer nextTickClosureTick(0).
   5.627 Info ServerMultiplayerManager.cpp:670: mapTick(-1) changing state from(Ready) to(PreparedToHostGame)
   5.627 Info ServerMultiplayerManager.cpp:670: mapTick(-1) changing state from(PreparedToHostGame) to(CreatingGame)
   5.630 Loading map /opt/factorio/saves/server.zip: 36149618 bytes.
   5.753 Loading Level.dat: 80077011 bytes.
   5.762 Info Scenario.cpp:134: Map version 0.15.15-1
  10.217 Info BlueprintLibrary.cpp:190: Loaded library shelves:
  10.217 Info BlueprintLibrary.cpp:679: Game shelf: playerIndex = 65535, nextRecordID = 61; timestamp = 1493074362; records: (id: 65535, 60; label: "Alphabet", preview: false, empty: false; book [id: 65535, 24; label: "A", preview: false, empty: false] [id: 65535, 25; label: "B", preview: false, empty: false] [id: 65535, 26; label: "C", preview: false, empty: false] [id: 65535, 27; label: "D", preview: false, empty: false] [id: 65535, 28; label: "E", preview: false, empty: false] [id: 65535, 29; label: "F", preview: false, empty: false] [id: 65535, 30; label: "G", preview: false, empty: false] [id: 65535, 31; label: "H", preview: false, empty: false] [id: 65535, 32; label: "I", preview: false, empty: false] [id: 65535, 33; label: "J", preview: false, empty: false] [id: 65535, 34; label: "K", preview: false, empty: false] [id: 65535, 35; label: "L", preview: false, empty: false] [id: 65535, 36; label: "M", preview: false, empty: false] [id: 65535, 37; label: "N", preview: false, empty: false] [id: 65535, 38; label: "O", preview: false, empty: false] [id: 65535, 39; label: "P", preview: false, empty: false] [id: 65535, 40; label: "Q", preview: false, empty: false] [id: 65535, 41; label: "R", preview: false, empty: false] [id: 65535, 42; label: "S", preview: false, empty: false] [id: 65535, 43; label: "T", preview: false, empty: false] [id: 65535, 44; label: "U", preview: false, empty: false] [id: 65535, 45; label: "V", preview: false, empty: false] [id: 65535, 46; label: "W", preview: false, empty: false] [id: 65535, 47; label: "X", preview: false, empty: false] [id: 65535, 48; label: "Y", preview: false, empty: false] [id: 65535, 49; label: "Z", preview: false, empty: false] [id: 65535, 50; label: "0", preview: false, empty: false] [id: 65535, 51; label: "1", preview: false, empty: false] [id: 65535, 52; label: "2", preview: false, empty: false] [id: 65535, 53; label: "3", preview: false, empty: false] [id: 65535, 54; label: "4", preview: false, empty: false] [id: 65535, 55; label: "5", preview: false, empty: false] [id: 65535, 56; label: "6", preview: false, empty: false] [id: 65535, 57; label: "7", preview: false, empty: false] [id: 65535, 58; label: "8", preview: false, empty: false] [id: 65535, 59; label: "9", preview: false, empty: false])
  10.217 Info BlueprintLibrary.cpp:681: Player shelf: playerIndex = 0, nextRecordID = 159; timestamp = 1495838851; records: (id: 0, 156; label: "Alphabet", preview: false, empty: false; book [id: 0, 120; label: "A", preview: false, empty: false] [id: 0, 121; label: "B", preview: false, empty: false] [id: 0, 122; label: "C", preview: false, empty: false] [id: 0, 123; label: "D", preview: false, empty: false] [id: 0, 124; label: "E", preview: false, empty: false] [id: 0, 125; label: "F", preview: false, empty: false] [id: 0, 126; label: "G", preview: false, empty: false] [id: 0, 127; label: "H", preview: false, empty: false] [id: 0, 128; label: "I", preview: false, empty: false] [id: 0, 129; label: "J", preview: false, empty: false] [id: 0, 130; label: "K", preview: false, empty: false] [id: 0, 131; label: "L", preview: false, empty: false] [id: 0, 132; label: "M", preview: false, empty: false] [id: 0, 133; label: "N", preview: false, empty: false] [id: 0, 134; label: "O", preview: false, empty: false] [id: 0, 135; label: "P", preview: false, empty: false] [id: 0, 136; label: "Q", preview: false, empty: false] [id: 0, 137; label: "R", preview: false, empty: false] [id: 0, 138; label: "S", preview: false, empty: false] [id: 0, 139; label: "T", preview: false, empty: false] [id: 0, 140; label: "U", preview: false, empty: false] [id: 0, 141; label: "V", preview: false, empty: false] [id: 0, 142; label: "W", preview: false, empty: false] [id: 0, 143; label: "X", preview: false, empty: false] [id: 0, 144; label: "Y", preview: false, empty: false] [id: 0, 145; label: "Z", preview: false, empty: false] [id: 0, 146; label: "0", preview: false, empty: false] [id: 0, 147; label: "1", preview: false, empty: false] [id: 0, 148; label: "2", preview: false, empty: false] [id: 0, 149; label: "3", preview: false, empty: false] [id: 0, 150; label: "4", preview: false, empty: false] [id: 0, 151; label: "5", preview: false, empty: false] [id: 0, 152; label: "6", preview: false, empty: false] [id: 0, 153; label: "7", preview: false, empty: false] [id: 0, 154; label: "8", preview: false, empty: false] [id: 0, 155; label: "9", preview: false, empty: false]) (id: 0, 104; label: "Blue Balancers", preview: false, empty: false; book [id: 0, 114; label: "", preview: false, empty: false] [id: 0, 67; label: "2 to 3 (Long Variant)", preview: false, empty: false] [id: 0, 68; label: "2 to 3 (Wide Variant)", preview: false, empty: false] [id: 0, 69; label: "2 to 4", preview: false, empty: false] [id: 0, 70; label: "2 to 5 (Long Variant)", preview: false, empty: false] [id: 0, 71; label: "2 to 5 (Wide Variant)", preview: false, empty: false] [id: 0, 72; label: "2 to 6", preview: false, empty: false] [id: 0, 73; label: "2 to 7", preview: false, empty: false] [id: 0, 74; label: "2 to 8", preview: false, empty: false] [id: 0, 75; label: "3 to 2", preview: false, empty: false] [id: 0, 76; label: "3 to 3", preview: false, empty: false] [id: 0, 77; label: "3 to 4", preview: false, empty: false] [id: 0, 78; label: "3 to 5", preview: false, empty: false] [id: 0, 79; label: "3 to 6", preview: false, empty: false] [id: 0, 80; label: "3 to 7", preview: false, empty: false] [id: 0, 81; label: "3 to 8", preview: false, empty: false] [id: 0, 82; label: "4 to 3", preview: false, empty: false] [id: 0, 83; label: "4 to 4", preview: false, empty: false] [id: 0, 84; label: "4 to 5", preview: false, empty: false] [id: 0, 85; label: "4 to 6", preview: false, empty: false] [id: 0, 86; label: "4 to 7", preview: false, empty: false] [id: 0, 87; label: "4 to 8", preview: false, empty: false] [id: 0, 88; label: "5 to 3", preview: false, empty: false] [id: 0, 89; label: "5 to 4", preview: false, empty: false] [id: 0, 90; label: "5 to 5", preview: false, empty: false] [id: 0, 91; label: "5 to 6", preview: false, empty: false] [id: 0, 92; label: "5 to 7", preview: false, empty: false] [id: 0, 93; label: "5 to 8", preview: false, empty: false] [id: 0, 94; label: "6 to 4", preview: false, empty: false] [id: 0, 95; label: "6 to 5", preview: false, empty: false] [id: 0, 96; label: "6 to 6", preview: false, empty: false] [id: 0, 97; label: "6 to 7", preview: false, empty: false] [id: 0, 98; label: "6 to 8", preview: false, empty: false] [id: 0, 99; label: "8 to 4", preview: false, empty: false] [id: 0, 100; label: "8 to 5", preview: false, empty: false] [id: 0, 101; label: "8 to 6", preview: false, empty: false] [id: 0, 102; label: "8 to 7", preview: false, empty: false] [id: 0, 106; label: "8x8", preview: false, empty: false]) (id: 0, 105; label: "Trains", preview: false, empty: false; book [id: 0, 13; label: "1 block", preview: false, empty: false] [id: 0, 157; label: "3-way", preview: false, empty: false] [id: 0, 62; label: "Base - Liquid", preview: false, empty: false] [id: 0, 63; label: "Base - Ore", preview: false, empty: false] [id: 0, 49; label: "Outpost", preview: false, empty: false] [id: 0, 158; label: "PAX", preview: false, empty: false] [id: 0, 55; label: "Supply", preview: false, empty: false]) (id: 0, 113; label: "", preview: false, empty: false; single) (id: 0, 108; label: "4-2 Priority", preview: false, empty: false; single) (id: 0, 115; label: "4-2 Priority", preview: false, empty: false; single) (id: 0, 110; label: "8-2 Priority", preview: false, empty: false; single) (id: 0, 118; label: "Beacon Smelter", preview: false, empty: false; single) (id: 0, 12; label: "Belts", preview: false, empty: false; single) (id: 0, 46; label: "Blue Circuit", preview: false, empty: false; single) (id: 0, 38; label: "Blue Smelt", preview: false, empty: false; single) (id: 0, 36; label: "Blue Steel", preview: false, empty: false; single) (id: 0, 117; label: "Green Circuits", preview: false, empty: false; single) (id: 0, 119; label: "Letters", preview: false, empty: false; single) (id: 0, 39; label: "LogiConcrete", preview: false, empty: false; single) (id: 0, 56; label: "Maker", preview: false, empty: false; single) (id: 0, 20; label: "Mining", preview: false, empty: false; single) (id: 0, 61; label: "Nuke", preview: false, empty: false; single) (id: 0, 116; label: "Productive Circuits", preview: false, empty: false; single) (id: 0, 47; label: "RoboStation", preview: false, empty: false; single) (id: 0, 34; label: "Solar", preview: false, empty: false; single) (id: 0, 32; label: "Steam", preview: false, empty: false; single)
  10.217 Info BlueprintLibrary.cpp:681: Player shelf: playerIndex = 1, nextRecordID = 0; timestamp = 1495596236; records:
  10.217 Info BlueprintLibrary.cpp:681: Player shelf: playerIndex = 2, nextRecordID = 0; timestamp = 1495496074; records:
  11.267 Info BlueprintLibrary.cpp:47: Loaded external blueprint storage: playerIndex = 65535, nextRecordID = 0; timestamp = 1496160468; records:
  11.273 Loading script.dat: 646549 bytes.
  11.290 Checksum for script /opt/factorio/temp/currently-playing/control.lua: 282129324
  11.293 Checksum for script __AutoDeconstruct__/control.lua: 3034658017
  11.298 Checksum for script __autofill__/control.lua: 428222097
  11.300 Checksum for script __axial-tilt__/control.lua: 2477845871
  11.301 Checksum for script __BeltImmunity__/control.lua: 0
  11.303 Checksum for script __Bottleneck__/control.lua: 1037364004
  11.306 Checksum for script __even-distribution__/control.lua: 3272626212
  11.401 Checksum for script __helmod__/control.lua: 3004994211
  11.403 Checksum for script __Honk__/control.lua: 1248643386
  11.405 Checksum for script __Orphan Finder__/control.lua: 3794858359
  11.407 Checksum for script __VehicleSnap__/control.lua: 3426081906
  12.892 Script control.lua:356: AutoFill: Defaults Updated
  13.823 Info UDPSocket.cpp:27: Opening socket at (0.0.0.0:34197)
  13.827 Hosting game at 0.0.0.0:34197
  13.827 Info ServerMultiplayerManager.cpp:670: mapTick(26892001) changing state from(CreatingGame) to(InGame)
  13.827 Info UDPSocket.cpp:39: Opening socket for broadcast
  13.851 Error InterruptibleStdioStream.cpp:53: Reading stdin failed
  26.931 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(10.0.1.20:61414)
  26.931 Info ServerRouter.cpp:389: Replying to connectionRequest for address(10.0.1.20:61414).
  26.931 Info ServerSynchronizer.cpp:542: nextHeartbeatSequenceNumber(390) adding peer(1)
  26.948 Info ServerMultiplayerManager.cpp:670: mapTick(26892001) changing state from(InGame) to(InGameSavingMap)
  26.982 Info ServerMultiplayerManager.cpp:754: mapTick(26892001) received stateChanged peerID(1) oldState(Ready) newState(ConnectedWaitingForMap)
  30.082 Info ServerMultiplayerManager.cpp:808: MapTick(26892001) Serving map(/opt/factorio/temp/mp-save-0.zip) for peer(1) size(36132990) crc(461711892)
  30.082 Info ServerMultiplayerManager.cpp:670: mapTick(26892001) changing state from(InGameSavingMap) to(InGame)
  30.167 Info ServerMultiplayerManager.cpp:754: mapTick(26892001) received stateChanged peerID(1) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
  34.849 Info ServerMultiplayerManager.cpp:754: mapTick(26892001) received stateChanged peerID(1) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
  38.369 Info ServerMultiplayerManager.cpp:754: mapTick(26892207) received stateChanged peerID(1) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
  38.997 Info ServerMultiplayerManager.cpp:754: mapTick(26892244) received stateChanged peerID(1) oldState(TryingToCatchUp) newState(WaitingForCommandToStartSendingTickClosures)
  38.998 Info GameActionHandler.cpp:3236: MapTick (26892244) processed PlayerJoinGame peerID(1) playerIndex(0) mode(connect ) 
  39.062 Info ServerMultiplayerManager.cpp:754: mapTick(26892248) received stateChanged peerID(1) oldState(WaitingForCommandToStartSendingTickClosures) newState(InGame)
6613.706 Info ServerMultiplayerManager.cpp:854: Disconnect notification for peer (1)
6614.082 Info ServerMultiplayerManager.cpp:754: mapTick(27282765) received stateChanged peerID(1) oldState(InGame) newState(DisconnectScheduled)
6614.542 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.542 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.542 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.542 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.542 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.542 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.543 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (1) that is not disconnected yet.
6614.568 Info ServerSynchronizer.cpp:557: nextHeartbeatSequenceNumber(224850) removing peer(1).
10815.621 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(10.0.1.20:52638)
10815.780 Info ServerRouter.cpp:389: Replying to connectionRequest for address(10.0.1.20:52638).
10815.953 Info ServerSynchronizer.cpp:542: nextHeartbeatSequenceNumber(350090) adding peer(2)
10816.412 Info ServerMultiplayerManager.cpp:670: mapTick(27282766) changing state from(InGame) to(InGameSavingMap)
10816.437 ConnectionRequestReplyConfirm (type(ConnectionRequestReplyConfirm) ) from(10.0.1.20:52638)
10816.437 Info ServerRouter.cpp:389: Replying to connectionRequest for address(10.0.1.20:52638).
10816.437 Info ServerMultiplayerManager.cpp:754: mapTick(27282766) received stateChanged peerID(2) oldState(Ready) newState(ConnectedWaitingForMap)
11031.953 Info ServerMultiplayerManager.cpp:808: MapTick(27282766) Serving map(/opt/factorio/temp/mp-save-1.zip) for peer(2) size(36649653) crc(2485426629)
11031.954 Info ServerMultiplayerManager.cpp:670: mapTick(27282766) changing state from(InGameSavingMap) to(InGame)
11032.038 Info ServerMultiplayerManager.cpp:754: mapTick(27282766) received stateChanged peerID(2) oldState(ConnectedWaitingForMap) newState(ConnectedDownloadingMap)
11038.179 Info ServerMultiplayerManager.cpp:754: mapTick(27282766) received stateChanged peerID(2) oldState(ConnectedDownloadingMap) newState(ConnectedLoadingMap)
11041.773 Info ServerMultiplayerManager.cpp:754: mapTick(27282938) received stateChanged peerID(2) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
11041.827 Info ServerMultiplayerManager.cpp:754: mapTick(27282941) received stateChanged peerID(2) oldState(TryingToCatchUp) newState(DesyncedWaitingForMap)
11041.827 Info ServerMultiplayerManager.cpp:825: mapTick(27282941) received playerDesynced peer (2)
11041.827 Info ServerMultiplayerManager.cpp:670: mapTick(27282941) changing state from(InGame) to(InGameSavingMapForDesyncReport)
11089.826 Info ServerMultiplayerManager.cpp:808: MapTick(27282941) Serving map(/opt/factorio/temp/mp-save-2.zip) for peer(2) size(186231339) crc(4244165838)
11089.827 Info ServerMultiplayerManager.cpp:670: mapTick(27282941) changing state from(InGameSavingMapForDesyncReport) to(InGame)
11089.879 Info ServerMultiplayerManager.cpp:754: mapTick(27282941) received stateChanged peerID(2) oldState(DesyncedWaitingForMap) newState(DesyncedCatchingUpWithMapReadyForDownload)
11089.913 Info ServerMultiplayerManager.cpp:754: mapTick(27282941) received stateChanged peerID(2) oldState(DesyncedCatchingUpWithMapReadyForDownload) newState(DesyncedSavingLocalVariantOfMap)
11128.497 Info ServerMultiplayerManager.cpp:754: mapTick(27282941) received stateChanged peerID(2) oldState(DesyncedSavingLocalVariantOfMap) newState(DesyncedDownloadingMap)
11159.988 Info ServerMultiplayerManager.cpp:754: mapTick(27282941) received stateChanged peerID(2) oldState(DesyncedDownloadingMap) newState(DesyncedCreatingReport)
11173.426 Info ServerMultiplayerManager.cpp:754: mapTick(27283656) received stateChanged peerID(2) oldState(DesyncedCreatingReport) newState(ConnectedLoadingMap)
11176.825 Info ServerMultiplayerManager.cpp:754: mapTick(27283860) received stateChanged peerID(2) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
11176.858 Info ServerMultiplayerManager.cpp:754: mapTick(27283862) received stateChanged peerID(2) oldState(TryingToCatchUp) newState(DesyncedWaitingForMap)
11176.858 Info ServerMultiplayerManager.cpp:825: mapTick(27283862) received playerDesynced peer (2)
11176.859 Info ServerMultiplayerManager.cpp:670: mapTick(27283862) changing state from(InGame) to(InGameSavingMapForDesyncReport)
11222.158 Info ServerMultiplayerManager.cpp:808: MapTick(27283862) Serving map(/opt/factorio/temp/mp-save-3.zip) for peer(2) size(186392813) crc(415817009)
11222.158 Info ServerMultiplayerManager.cpp:670: mapTick(27283862) changing state from(InGameSavingMapForDesyncReport) to(InGame)
11222.242 Info ServerMultiplayerManager.cpp:754: mapTick(27283862) received stateChanged peerID(2) oldState(DesyncedWaitingForMap) newState(DesyncedCatchingUpWithMapReadyForDownload)
11222.242 Info ServerMultiplayerManager.cpp:754: mapTick(27283862) received stateChanged peerID(2) oldState(DesyncedCatchingUpWithMapReadyForDownload) newState(DesyncedSavingLocalVariantOfMap)
11260.198 Info ServerMultiplayerManager.cpp:754: mapTick(27283862) received stateChanged peerID(2) oldState(DesyncedSavingLocalVariantOfMap) newState(DesyncedDownloadingMap)
11291.601 Info ServerMultiplayerManager.cpp:754: mapTick(27283862) received stateChanged peerID(2) oldState(DesyncedDownloadingMap) newState(DesyncedCreatingReport)
11304.739 Info ServerMultiplayerManager.cpp:754: mapTick(27284642) received stateChanged peerID(2) oldState(DesyncedCreatingReport) newState(ConnectedLoadingMap)
11308.080 Info ServerMultiplayerManager.cpp:754: mapTick(27284825) received stateChanged peerID(2) oldState(ConnectedLoadingMap) newState(TryingToCatchUp)
11308.089 Info ServerMultiplayerManager.cpp:754: mapTick(27284826) received stateChanged peerID(2) oldState(TryingToCatchUp) newState(DesyncedWaitingForMap)
11308.089 Info ServerMultiplayerManager.cpp:825: mapTick(27284826) received playerDesynced peer (2)
11308.089 Info ServerMultiplayerManager.cpp:670: mapTick(27284826) changing state from(InGame) to(InGameSavingMapForDesyncReport)
11354.092 Info ServerMultiplayerManager.cpp:808: MapTick(27284826) Serving map(/opt/factorio/temp/mp-save-4.zip) for peer(2) size(186629998) crc(1652405164)
11354.093 Info ServerMultiplayerManager.cpp:670: mapTick(27284826) changing state from(InGameSavingMapForDesyncReport) to(InGame)
11354.177 Info ServerMultiplayerManager.cpp:754: mapTick(27284826) received stateChanged peerID(2) oldState(DesyncedWaitingForMap) newState(DesyncedCatchingUpWithMapReadyForDownload)
11354.177 Info ServerMultiplayerManager.cpp:754: mapTick(27284826) received stateChanged peerID(2) oldState(DesyncedCatchingUpWithMapReadyForDownload) newState(DesyncedSavingLocalVariantOfMap)
11355.823 Info ServerMultiplayerManager.cpp:854: Disconnect notification for peer (2)
11355.823 Info ServerMultiplayerManager.cpp:754: mapTick(27284826) received stateChanged peerID(2) oldState(DesyncedSavingLocalVariantOfMap) newState(DisconnectScheduled)
11355.857 Info ServerSynchronizer.cpp:557: nextHeartbeatSequenceNumber(365721) removing peer(2).
25819.787 Received SIGTERM, shutting down
25820.002 Info MainLoop.cpp:251: Saving map as /opt/factorio/saves/server.zip

User avatar
TruePikachu
Filter Inserter
Filter Inserter
Posts: 978
Joined: Sat Apr 09, 2016 8:39 pm
Contact:

Re: Server not saving properly

Post by TruePikachu »

One thing that can be done is checking the system log (usually `/var/log/messages` or somesuch) for whatever reason Factorio's process is being terminated.

19wolf
Long Handed Inserter
Long Handed Inserter
Posts: 61
Joined: Fri May 06, 2016 3:49 pm
Contact:

Re: Server not saving properly

Post by 19wolf »

Code: Select all

May 30 19:17:56 Paidia systemd[1]: Stopping Factorio Server...
May 30 19:17:57 Paidia factorio[4866]: 25819.787 Received SIGTERM, shutting down
May 30 19:17:57 Paidia factorio[4866]: 25820.002 Info MainLoop.cpp:251: Saving map as /opt/factorio/saves/server.zip
May 30 19:27:56 Paidia systemd[1]: factorio.service: State 'stop-sigterm' timed out. Killing.
May 30 19:27:57 Paidia systemd[1]: factorio.service: Main process exited, code=killed, status=9/KILL
May 30 19:27:57 Paidia systemd[1]: Stopped Factorio Server.
May 30 19:27:57 Paidia systemd[1]: factorio.service: Unit entered failed state.
May 30 19:27:58 Paidia systemd[1]: factorio.service: Failed with result 'signal'.
Looks like it's timing out (after 10 minutes?) I feel like it shouldn't take 10 minutes to stop

Oxyd
Former Staff
Former Staff
Posts: 1428
Joined: Thu May 07, 2015 8:42 am
Contact:

Re: Server not saving properly

Post by Oxyd »

10 minutes definitely sounds wrong. Can you post the save and your mod folder? It might be something about those.

19wolf
Long Handed Inserter
Long Handed Inserter
Posts: 61
Joined: Fri May 06, 2016 3:49 pm
Contact:

Re: Server not saving properly

Post by 19wolf »

https://www.dropbox.com/sh/5a39q2mx3axb ... WkHFa?dl=0

Hopefully it's done uploading when you see this

Oxyd
Former Staff
Former Staff
Posts: 1428
Joined: Thu May 07, 2015 8:42 am
Contact:

Re: [Oxyd] Server not saving properly

Post by Oxyd »

Very interesting. It saves within a few seconds for me, even on a debug build (which otherwise struggles a lot on that save). Does it take 10 minutes even if you run the server without systemd? Your unit file contains “TimeoutSec=60” which means that systemd should kill it after one minute, not 10 minutes.

Also, what Rseding said – are you sure you have enough memory and other resources when you stop the server? One scenario I can imagine happening is that your server runs out of RAM, starts thrashing and even a simple task like saving the map takes 10 minutes or longer.

And if all else fails, could you get a backtrace of the process when it's stuck saving? Something like

Code: Select all

gdb -batch -ex 'thread apply all bt' /opt/factorio/bin/x64/factorio $(pgrep factorio)
and send me the output. That might at least give me an idea where it's getting hung.

Post Reply

Return to “Pending”