[Oxyd] [0.15.10] Main save file not updating

[Drac346]

We have noticed that the last two patches have caused a rollback in our save game. Entire bases have been removed and a number of resource fields that we drained have come back. Pretty sure it is not someone hacking the whitelist and messing with us due to the resources reappearing.

I don't have solid testing but it first occurred with .9 (I thought they were crazy), and then we noticed it a second time in .10. Something is up with save files.

I restored from the latest autosave and it looks solid. My guess is that the game server is correctly updating autosaves, but not saving at all to the main save file. The size of the main file was 5 MB smaller than the autosaves. It was several days out of sync.

Logs show that the server shutdown properly each time before the updates to .9 and .10. There's no errors and it was graceful in each instance.

Edit: I didn't make a copy of the log file before the update and I already overwrote the 'previous' log while rolling back to an autosave. I'll grab a copy of the log during the next update.

[TruePikachu]

Logs show that the server shutdown properly each time before the updates to .9 and .10.

Which includes a "successful" save to the main save file?

[Drac346]

I honestly don't remember TruePikachu.

The test of the post .10 update shows that it successfully saved when I shutdown the server to roll back to the _autosave14.zip file.

Code: Select all

41635.673 Received SIGINT, shutting down
41635.673 Info MainLoop.cpp:242: Saving map as /home/steam/factorio/bin/x64/failpire153.zip

I vaguely remember looking at the log when I shutdown the .9 server to perform the update to .10. I don't remember their being any entry after "Received SIGINT, shutting down.' But my memory isn't perfect and I did not make a backup of the log file at the time since I assumed that it exited successfully. (assumptions here)

Here's an image of the all of the save files when we noticed there was an issue (they were combined into a single directory for the screenshot).


Normally I wouldn't have posted except that it happened twice in a row (reported by two different users on my server) and only with the last two updates (making it .8 and .9). The test of .10 seems to be working based on the above log file but I wanted to bring it up just in case there's something weird going on.

Edit:
Server: Ubuntu 16.04 LTS
Account: Non sudo service account called steam
Ownership and permissions have not changed since the .15.01 setup (steam:steam 775) (confirmed they are still set this way)
Map Generated during version 15.03

[Oxyd]

I vaguely remember looking at the log when I shutdown the .9 server to perform the update to .10. I don't remember their being any entry after "Received SIGINT, shutting down.' But my memory isn't perfect and I did not make a backup of the log file at the time since I assumed that it exited successfully. (assumptions here)

There are meant to be entries after that. On a graceful shutdown, Factorio will print “Goodbye” as the last line in the log. If the log does end right after the “Saving map” line, it sounds like Factorio got killed before it could finish saving. If your save is 42 MB, it will take a bit for it to save. You might be running some custom script that'll first send SIGTERM to Factorio and then kill it after a while, thinking the process is stuck when it's really just busy saving the map. But that's just a speculation, of course.

[Drac346]

Thanks for the reply Oxyd.

I'll keep an eye on it and let you know if happens again. I've been monitoring the save file since .10 and I'll post back again if it occurs again. I have seen the save file update on every MP JOIN but I have not noticed the main save file update any other time unless the server is SIGINT.

I think I am shutting it down correctly with a SIGINT command but I would not consider myself even a Linux novice (window's powershell guy). I could be doing it wrong.

Code: Select all

FactorioStop()
{
	cat /home/steam/factorio/bin/x64/nohup.out | grep UserNotWhitelisted >> /home/steam/pastfailures.out
	#Get the process ID
	StopPID=$(pgrep factorio)
        printf "\n"
	echo "Stopping process ID: $StopPID"
	#Send a CTRL + C command, SIGINT.  This is the official way to shut down
	kill -INT $StopPID
        printf "\n"
	echo "Sleeping for 10 Seconds to give the process time to save and exit gracefully"
	sleep 10s
	echo "Checking for factorio Process, you should see no results after this line:"
	pgrep factorio
}

As I was writing this I had an idea. pgrep has never returned more than one PID. But I think there are a few second factorio processes (like joining, disconnecting, and saving) which are short lived and non-persistent. I wonder if I captured the wrong PID due to bad timing and killed some temporary factorio secondary process. I think that sounds feasable.

[Drac346]

When does the main savegame file get updated?

The first 24 hours of the server start showed some regular save activity, including a save a ~90 minutes after the last member logged out on 5/11. However, I noticed it is a few days out of sync again.

Is this expected behavior? I'd hate to keep tracking something that isn't a bug. I would much rather the dev team work on multithreading


.
.

[Oxyd]

As I was writing this I had an idea. pgrep has never returned more than one PID. But I think there are a few second factorio processes (like joining, disconnecting, and saving) which are short lived and non-persistent. I wonder if I captured the wrong PID due to bad timing and killed some temporary factorio secondary process. I think that sounds feasable.

Factorio uses multiple threads, but should be all in one process. So unless you're running multiple servers on the same machine, you should have only one Factorio process at any time. (Or none, of course.)

When does the main savegame file get updated?

On a graceful shutdown. Or when you explicitly give the /save command on standard input or via RCON, or when you run /c game.server_save() in the in-game console. It looks like the autosaves are working for you, but the save on shutdown is having some issues.

It would be nice to see the logfile if it happens again. Also if this is the Steam version, you might try the non-Steam version and see if that changes anything. Although for the headless server, Steam shouldn't make much of a difference, if any at all.

[Oxyd]

I added some extra logging, so if you could post a log from 0.15.14 or later with the issue happening, that would be helpful.