[Rseding91] [0.17.62] Crash on save: "Count of indexed targeters doesn't match count of saved targetables"

[Muppet9010]

When an MP server running "_autosave2" attempts to make the next auto save the server crashes with the attached errors.
The autosave interval is 11 minutes.

I have tried loading the server again from a copy of "_autosave2" and the game crashed with the same error on first autosave attempt.

However, in SP loading the save it doesn't error saving or loading.

Code: Select all

842.331 Info AppManager.cpp:287: Saving to _autosave3 (blocking).
 842.669 Error Scenario.cpp:922: Targeter for 14CustomChartTag was saved but the targetable instance wasn't saved.
 842.669 Error Scenario.cpp:922: Targeter for 14CustomChartTag was saved but the targetable instance wasn't saved.
 842.669 Time travel logging:
 638.268 Deleting surface warpsurf_33 index 3.
Factorio crashed. Generating symbolized stacktrace, please wait ...
Raw stacktrace: 0xb249d8, 0xcf0b4d, 0x9d7e69, 0x9f152f, 0xe38400, 0xf0dbb4, 0x1950a7f, 0x7d2c, 0
 847.944 Warning Logger.cpp:518: Symbols.size() == 13, usedSize == 8
#0  0x0000000000cf0b4d in std::__uniq_ptr_impl<LoggerFileWriteStream, std::default_delete<LoggerFileWriteStream> >::_M_ptr() const at /usr/include/c++/8/bits/unique_ptr.h:150
#1  0x00000000009d7e69 in std::unique_ptr<LoggerFileWriteStream, std::default_delete<LoggerFileWriteStream> >::get() const at /usr/include/c++/8/bits/unique_ptr.h:343
#2  0x00000000009f152f in std::unique_ptr<LoggerFileWriteStream, std::default_delete<LoggerFileWriteStream> >::operator->() const at /usr/include/c++/8/bits/unique_ptr.h:337
#3  0x0000000000e38400 in Logger::flush() at /tmp/factorio-build-wwc89H/src/Util/Logger.cpp:558
#4  0x0000000000f0dbb4 in Logger::logStacktrace(StackTraceInfo*) at /tmp/factorio-build-wwc89H/src/Util/Logger.cpp:544
#5  0x0000000001950a7f in Logging::flush() at /tmp/factorio-build-wwc89H/src/Util/Logging.cpp:69
#6  0x0000000000007d2c in Logging::logAndAbortOrThrow(char const*, unsigned int, LogLevel, std::string const&) at /tmp/factorio-build-wwc89H/src/Util/Logging.cpp:103
#7  (nil) in Logging::logAndAbortOrThrow(char const*, unsigned int, LogLevel, char const*, ...) at /tmp/factorio-build-wwc89H/src/Util/Logging.cpp:93
#8  (nil) in Scenario::saveAs(Filesystem::Path const&, std::string const&, Filesystem::Path const&, ProgressObserver*, SaveType) at /tmp/factorio-build-wwc89H/src/Scenario/Scenario.cpp:932
#9  0x3438333231303738 in ParallelScenarioSaver::doSave(ParallelScenarioSaver*) at /tmp/factorio-build-wwc89H/src/Scenario/ParallelScenarioSaver.cpp:99
#10 0x742c223332313037 in execute_native_thread_routine at tmpaa03R.fake.c:?
#11 0x703078303d657079 in ?? at ??:0
#12 0x7469746e652c302b in ?? at ??:0
Stack trace logging done
 853.212 Warning Logger.cpp:518: Symbols.size() == 8, usedSize == 7
 853.212 Error Scenario.cpp:929: Count of indexed targeters (13664) doesn't match count of saved targetables (13662).
This means that a Targeter was saved but the thing it was targeting wasn't.
See the log file for more information.
Logger::writeStacktrace skipped.
 853.212 Error CrashHandler.cpp:189: Map tick at moment of crash: 4474801
 853.212 Error Util.cpp:97: Unexpected error occurred. If you're running the latest version of the game you can help us solve the problem by posting the contents of the log file on the Factorio forums.
Please also include the save file(s), any mods you may be using, and any steps you know of to reproduce the crash.
 853.212 Uploading log file
 853.221 Info SystemUtil.cpp:538: Started /home/container/bin/x64/factorio; trampoline PID: 270

[Rseding91]

Thanks for the report. I looked over the code and can't see any way that could happen without some corruption issue through a mod or on the server.

I tried to reproduce the crash locally but it just desynced after a few minutes of waiting doing nothing. So, I would look at your mods and figure out the desync first. It happened right when an alarm started playing.

[Muppet9010]

Further to the discord discussion earlier.

I've just tried running this save on a headless windows install of 0.17.62 on a secondary pc in my house. I can reproduce the server crash when the autosave runs after I connect to the server with my main pc.
The attached save should skip basically all of the waiting of the previous save. It seems to crash the game after the mod Warptorio has done its warp action as if you force a save before the game is happy.

1. Run headless server on the attached save "JD server crash pre.zip".
2. Join the game with a client
3. Once caught up the text at top of screen "Auto-Warp In" should be 60+ minutes. If not wait for it to count down to 0 and reset back to 70~ minutes.
4. Trigger a server side save with "/server-save"
5. The server should die with the error.

Code: Select all

 333.213 Deleting surface warpsurf_33 index 3.
Factorio crashed. Generating symbolized stacktrace, please wait ...
c:\cygwin64\tmp\factorio-build-c3ygos\src\scenario\scenario.cpp (925): Scenario::saveAs
c:\cygwin64\tmp\factorio-build-c3ygos\src\scenario\parallelscenariosaver.cpp (99): ParallelScenarioSaver::doSave
c:\program files (x86)\microsoft visual studio\2017\buildtools\vc\tools\msvc\14.15.26726\include\thr\xthread (230): std::_LaunchPad<std::unique_ptr<std::tuple<void (__cdecl MapGenerationHelper::*)(void),MapGenerationHelper *>,std::default_delete<std::tuple<void (__cdecl MapGenerationHelper::*)(void),MapGenerationHelper *> > > >::_Go
c:\program files (x86)\microsoft visual studio\2017\buildtools\vc\tools\msvc\14.15.26726\include\thr\xthread (209): std::_Pad::_Call_func
minkernel\crts\ucrt\src\appcrt\startup\thread.cpp (115): thread_start<unsigned int (__cdecl*)(void * __ptr64)>
ERROR: SymGetLineFromAddr64, GetLastError: 487 (Address: 00007FFD3CFD7BD4)
00007FFD3CFD7BD4 (KERNEL32): (filename not available): BaseThreadInitThunk
ERROR: SymGetLineFromAddr64, GetLastError: 487 (Address: 00007FFD3D9ACE71)
00007FFD3D9ACE71 (ntdll): (filename not available): RtlUserThreadStart
Stack trace logging done
 486.985 Error Scenario.cpp:929: Count of indexed targeters (13508) doesn't match count of saved targetables (13506).
This means that a Targeter was saved but the thing it was targeting wasn't.
See the log file for more information.
Logger::writeStacktrace skipped.
 486.988 Error CrashHandler.cpp:189: Map tick at moment of crash: 4471706
 486.989 Error Util.cpp:97: Unexpected error occurred. If you're running the latest version of the game you can help us solve the problem by posting the contents of the log file on the Factorio forums.
Please also include the save file(s), any mods you may be using, and any steps you know of to reproduce the crash.
 486.996 Uploading log file
 487.141 Error CrashHandler.cpp:245: Heap validation: success.
 487.144 Creating crash dump.
 488.065 CrashDump success

[Rseding91]

Ok, I figured it out. The time-travel logging was actually useful in seeing that it was always deleting a surface right before it would crash. The reproduction steps where: make a reference to a lua chart tag on a surface, delete the surface, and in the same tick auto-save happens.

It's now fixed for the next version of 0.17.