[0.17.14] Game crashes when syncing mods with vanilla multiplayer server, but only when using "Join server after sync"

[audigex]

1. What did I do?

When I have mods enabled and try to join a multiplayer server (clicking the "Join Game" Button after selecting a server in the "Browse Public Games" dialog) , the game asks if I would like to sync with the server. The selected server has no mods (base 0.17.14). This has happened with several servers, all vanilla (I've not tested vs modded servers)



It correctly shows the dialog regarding which mods will be removed



2. What happened?

But then crashes immediately after confirming



List of all installed mods (same as above confirmation, plus creative mod which is disabled)



When I restart the game after the crash, the mods have all been disabled, so that step appears to be happening properly. I can then join the server normally

If I deselect "join server after sync", the game does the whole refreshing thing (like if you manually change mods) and I can join the server manually immediately, so it appears to be related to this setting

3. What did you expect to happen instead? It might be obvious to you, but do it anyway!

I expected the game to either do the "mod refresh" thing and join the game, or just join it. Probably the latter.

[Rseding91]

Thanks for the report. Can you please upload factorio-previous.log as well?

[audigex]

Sure - I've opened the game again since the report, so I've just reproduced the bug and added both current and previous, in case it matters that they're a matching set

[TruePikachu]

Neither of those logs contain a crash.

[audigex]

Then the crash is presumably not being logged... my further investigation may shed some light on that though: the game doesn't crash if I delete the logs before launching Factorio.

Just to be sure I was getting the right logs, I deleted my logs and repeated (so I could see the files being created)

1. Delete both logs
2. Open Factorio, enable mods, connect. It worked (weird, first time it's worked)
3. Quit multiplayer, Re-enabled mod, Rejoined a server. Crash
4. Upload logs
5. Renabled mods. Reconnected. Crash
6. Uploaded logs with 2 suffix
7. Deleted logs to see if that makes a difference
8. Enable mods, connect... no crash (although I was kicked due to server whitelist)
9. Quit, upload logs (3)
10. Restart game, connect, crash
11. Uploaded logs (4)

So it appears that the presence of logs in my appdata folder is related to the crash?

- Log pair 1 is the first attempt: logs were deleted, one successful connect, one crash
- Pair 2 is with the above logs present in the folder. Crashed on first attempt
- Pair 3 is after deleting the logs, successful connect. Quit without allowing a crash, to get logs from a different scenario to pair 1
- Pair 4 is launching again without deleting log pair 3. Crashed on connect again

Any other scenarios you'd like me to test?

[TruePikachu]

These logs all indicate normal game shutdown states. Perhaps they're being locked by the parent process for too long, resulting in the child being unable to open them for writing?

[audigex]

I couldn’t even take a guess - your suggestion sounds plausible but I know nothing about how Factorio works internally

[Rseding91]

When Factorio is in the crashed state (the window is showing the crashed message) can you open task manager, find Factorio in the list of processes, right click on it and select "create dump"?

Once that finishes, zip it (or 7zip it), and upload it somewhere.

It will be huge so it's not going to let you upload it here due to file size limits.

[audigex]

Dump file. Produced in 0.17.15 due to the update, but I get the same issue - let me know if you'd like me to download .14 to reproduce it there instead

https://file.io/LVz5cD

[TruePikachu]

Code: Select all

0:000> kpn
 # Child-SP          RetAddr           Call Site
00 000000c5`9d4f69f8 00007ff9`7d229c7c win32u!NtUserWaitMessage+0x14
01 000000c5`9d4f6a00 00007ff9`7d229a5e user32!DialogBox2+0x1fc
02 000000c5`9d4f6a90 00007ff9`7d26f630 user32!InternalDialogBox+0x11e
03 000000c5`9d4f6af0 00007ff9`7d26e085 user32!SoftModalMessageBox+0x7f0
04 000000c5`9d4f6c40 00007ff9`7d26eda2 user32!MessageBoxWorker+0x2f9
05 000000c5`9d4f6df0 00007ff9`7d26ee2e user32!MessageBoxTimeoutW+0x192
06 000000c5`9d4f6ef0 00007ff7`35fd228d user32!MessageBoxW+0x4e
07 000000c5`9d4f6f30 00007ff7`35f18a58 factorio!MessageDialog::showDialogWin32(class std::basic_string<char,std::char_traits<char>,std::allocator<char> > * title = 0x000000c5`9d4f70d8, class std::basic_string<char,std::char_traits<char>,std::allocator<char> > * text = 0x000000c5`9d4f70f8, unsigned int messageBoxType = 0x10010)+0x16d [c:\cygwin64\tmp\factorio-build-z2hre9\src\messagedialog.cpp @ 147]
08 (Inline Function) --------`-------- factorio!MessageDialog::showError+0x3b [c:\cygwin64\tmp\factorio-build-z2hre9\src\messagedialog.cpp @ 173]
09 000000c5`9d4f7020 00007ff7`35edc3b1 factorio!Util::showCrashedError(class std::basic_string<char,std::char_traits<char>,std::allocator<char> > * title = <Value unavailable error>, class std::basic_string<char,std::char_traits<char>,std::allocator<char> > * error = <Value unavailable error>)+0x248 [c:\cygwin64\tmp\factorio-build-z2hre9\src\util\util.cpp @ 124]
0a (Inline Function) --------`-------- factorio!Util::showCrashedError+0x3a [c:\cygwin64\tmp\factorio-build-z2hre9\src\util\util.cpp @ 91]
0b 000000c5`9d4f70b0 00007ff7`35edc1aa factorio!CrashHandler::showCrashedMessage(void)+0x81 [c:\cygwin64\tmp\factorio-build-z2hre9\src\util\crashhandler.cpp @ 203]
0c 000000c5`9d4f7130 00007ff7`35edd429 factorio!CrashHandler::writeStackTrace(void)+0x11a [c:\cygwin64\tmp\factorio-build-z2hre9\src\util\crashhandler.cpp @ 193]
0d 000000c5`9d4f71d0 00007ff7`36577ac9 factorio!CrashHandler::SignalHandler(int signal = <Value unavailable error>)+0x9 [c:\cygwin64\tmp\factorio-build-z2hre9\src\util\crashhandler.cpp @ 557]
0e 000000c5`9d4f7200 00007ff7`3660a568 factorio!_seh_filter_exe(unsigned long xcptnum = 0xc0000005, struct _EXCEPTION_POINTERS * pxcptinfoptrs = 0x000000c5`9d4f7290)+0x16d [minkernel\crts\ucrt\src\appcrt\misc\exception_filter.cpp @ 219]
0f 000000c5`9d4f7230 00007ff7`3654ca48 factorio!`__scrt_common_main_seh'::`1'::filt$0+0x16 [f:\dd\vctools\crt\vcstartup\src\startup\exe_common.inl @ 304]
10 000000c5`9d4f7260 00007ff9`7d51f7dd factorio!__C_specific_handler(struct _EXCEPTION_RECORD * ExceptionRecord = 0x000000c5`9d4f7ef0, void * EstablisherFrame = 0x000000c5`9d4ff790, struct _CONTEXT * ContextRecord = <Value unavailable error>, struct _DISPATCHER_CONTEXT * DispatcherContext = 0x000000c5`9d4f73b0)+0xa0
11 000000c5`9d4f72d0 00007ff9`7d48d856 ntdll!RtlpExecuteHandlerForException+0xd
12 000000c5`9d4f7300 00007ff9`7d51e70e ntdll!RtlDispatchException+0x3c6
13 000000c5`9d4f7a00 00007ff7`35fbacbf ntdll!KiUserExceptionDispatch+0x2e
14 000000c5`9d4f81a0 00007ff7`3654aee8 factorio!wmain(int argc = 0n0, wchar_t ** argv = 0x00000000`00000000)+0xa6ef [c:\cygwin64\tmp\factorio-build-z2hre9\src\main.cpp @ 1215]
15 (Inline Function) --------`-------- factorio!invoke_main+0x22 [f:\dd\vctools\crt\vcstartup\src\startup\exe_common.inl @ 90]
16 000000c5`9d4ff790 00007ff9`7c6b3dc4 factorio!__scrt_common_main_seh(void)+0x10c [f:\dd\vctools\crt\vcstartup\src\startup\exe_common.inl @ 288]
17 000000c5`9d4ff7d0 00007ff9`7d4f3691 kernel32!BaseThreadInitThunk+0x14
18 000000c5`9d4ff800 00000000`00000000 ntdll!RtlUserThreadStart+0x21
0:000> .frame 10
10 000000c5`9d4f7260 00007ff9`7d51f7dd factorio!__C_specific_handler+0xa0
0:000> dv
   ExceptionRecord = 0x000000c5`9d4f7ef0
  EstablisherFrame = 0x000000c5`9d4ff790
     ContextRecord = <value unavailable>
 DispatcherContext = 0x000000c5`9d4f73b0
         ImageBase = 0x00007ff7`356d0000
   ExceptionFilter = <value unavailable>
             Index = 0
       TargetIndex = <value unavailable>
          TargetPc = <value unavailable>
TerminationHandler = <value unavailable>
        ScopeTable = 0x00007ff7`36b70a24
           Handler = <value unavailable>
 ExceptionPointers = struct _EXCEPTION_POINTERS
             Value = 0n4111
         ControlPc = 0xe7aee8
0:000> .exr c5`9d4f7ef0
ExceptionAddress: 00007ff735fbacbf (factorio!wmain+0x000000000000a6ef)
   ExceptionCode: c0000005 (Access violation)
  ExceptionFlags: 00000000
NumberParameters: 2
   Parameter[0]: 0000000000000000
   Parameter[1]: 0000000000000260
Attempt to read from address 0000000000000260

I don't have time right this moment to look for a better backtrace, but the log file was indeed clobbered, it appears.

[Rseding91]

Dump file. Produced in 0.17.15 due to the update, but I get the same issue - let me know if you'd like me to download .14 to reproduce it there instead

https://file.io/LVz5cD

It says file not found when I try to download the dump. Maybe it timed out?

[TruePikachu]

The dump doesn't appear available anymore either, but you'd probably have to really dig into it anyway to get a workable backtrace, since it appears that the actual context record (with the useful backtrace) was no longer needed (since the backtrace was already "written" to the log), so the location containing it appears to have been cleared.

Probably first thing to investigate would be why the log isn't getting reopened. Since this is going to lead to a process restart, it might not be so simple to ensure the debugger attaches to the child correctly, so the only way to "easily" get a usable backtrace out of there would be to ensure the context record pointer doesn't go out-of-scope (I have no idea if it would work, but maybe declaring a local `volatile`, setting the context pointer into it, doing the log-write-and-error-message-print logic, then finally writing `nullptr`?)

[Rseding91]

The dump doesn't appear available anymore either, but you'd probably have to really dig into it anyway to get a workable backtrace, since it appears that the actual context record (with the useful backtrace) was no longer needed (since the backtrace was already "written" to the log), so the location containing it appears to have been cleared.

Probably first thing to investigate would be why the log isn't getting reopened. Since this is going to lead to a process restart, it might not be so simple to ensure the debugger attaches to the child correctly, so the only way to "easily" get a usable backtrace out of there would be to ensure the context record pointer doesn't go out-of-scope (I have no idea if it would work, but maybe declaring a local `volatile`, setting the context pointer into it, doing the log-write-and-error-message-print logic, then finally writing `nullptr`?)

A full memory dump I can load into Visual Studio and show the entire programs memory in the debugger. So, if you still have it - could you re-upload it?

[TruePikachu]

A full memory dump I can load into Visual Studio and show the entire programs memory in the debugger. So, if you still have it - could you re-upload it?

Already deleted, unfortunately; I'm not a fan of keeping large dumps from other people for programs I don't develop sitting around on this hard drive. I didn't think the upload would expire like it had, either, or else I would have kept it around until the issue was closed.

[audigex]

It didn't expire... the file was removed because TruePikachu downloaded it - it's a file sharing service, not a file hosting one. I wasn't expecting anyone else to download the dump file.

https://file.io/ljYWc3

[Rseding91]

Got it. I'll look into it and let you know what I find.

[exi2163]

I experienced the exact same issue, i will try to reproduce it after work.

Basically the game crashed every time i tried to sync-join a vanilla server while my factorio had mods loaded. Syncing and joining a modded server with a vanilla client works flawlessly.

[Rseding91]

The dump file was pretty much useless - it's from the instance of the game trying to upload the log file - not the one playing the game.

What antivirus do you have? I was talking with Posila and he mentioned that in the past we've had antivirus software mess with the game and cause these kinds of crashes.

[posila]

Thanks for the report. The dump file turned out to be usefull after all.
The dump was helpful. It crashes when the server is hosted over Steam Networking.
Fixed for 0.17.17

[audigex]

Disabling AV is always my first step when encountering a bug, but actually this happened to be a fresh Windows install with literally drivers and Factorio and a couple of utilities on.

Great that it’s fixed though, top service as always (although I’m still waiting for the “gates as player detectors, with smart velocity disabled” option one of the devs promised me a couple of years ago :p)