0.12.30 Multiplayer crash on linux

[silent]

Happens fairly regularly:

2727.887 Error Util.cpp:58: Unhandled exception: std::bad_alloc
2727.888 Error Router.cpp:331: Unhandled exception: std::bad_alloc
Factorio crashed. Generating symbolized stacktrace, please wait ...

Edit: running 0.12.30 headless...

[TruePikachu]

Are you running out of memory? You can check `top` or `htop` to tell.

[fsargent]

I too am getting this.
Not running out of memory:

Code: Select all

[@ip-172-30-1-223 factorio]# cat /proc/meminfo
MemTotal:        1015472 kB
MemFree:          487068 kB
MemAvailable:     718780 kB
Buffers:               0 kB
Cached:           384428 kB
SwapCached:            0 kB
Active:           347136 kB

Code: Select all

 0.000 2016-04-09 23:42:25; Factorio 0.12.30 (Build 17998, linux64, headless)
   0.000 Operating system: Linux
   0.000 Program arguments: "/opt/factorio/bin/x64/factorio" "--start-server" "factorio-init-save" "--autosave-interval" "10" "--autosave-slots" "3" "--latency-ms" "250" "--disallow-commands" "--peer-to-peer"
   0.000 Read data path: /opt/factorio/data
   0.000 Write data path: /opt/factorio
 0.000 Binaries path: /opt/factorio/bin
   0.007 Running in headless mode
   0.019 Loading mod core 0.0.0 (data.lua)
   0.021 Loading mod base 0.12.30 (data.lua)
   0.071 Loading mod marathon 1.0.1 (data.lua)
   0.109 Loading mod Honk 0.2.1 (data.lua)
   0.151 Loading mod RailTanker 1.1.3 (data.lua)
   0.191 Loading mod SignPosts 0.2.0 (data.lua)
   0.231 Loading mod marathon 1.0.1 (data-updates.lua)
   0.282 Loading mod rso-mod 1.5.0 (data-updates.lua)
   0.320 Checksum for core: 3711505753
   0.320 Checksum for mod base: 2829195351
   0.320 Checksum for mod marathon: 1548922137
   0.320 Checksum for mod Honk: 2302555571
   0.320 Checksum for mod RailTanker: 166006525
   0.320 Checksum for mod rso-mod: 4065594479
   0.320 Checksum for mod SignPosts: 1481126112
   0.543 Factorio initialised
   0.544 Info Router.cpp:509: Router peerID(65535) shutting down.
   0.544 Info Router.cpp:536: Router state -> Disconnected
   0.544 Info MultiplayerManager.cpp:913: networkTick(0) mapTick(-1) changing state from(Ready) to(PreparedToHostGame)
   0.544 Info MultiplayerManager.cpp:913: networkTick(0) mapTick(-1) changing state from(PreparedToHostGame) to(CreatingGame)
   0.544 Loading map /opt/factorio/saves/factorio-init-save.zip
   0.562 Info Scenario.cpp:124: Map version 0.12.29-0
   1.493 Checksum for script /opt/factorio/temp/currently-playing/control.lua: 393467729
   1.494 Checksum for script __Honk__/control.lua: 13648026
   1.495 Checksum for script __RailTanker__/control.lua: 2799235931
   1.502 Checksum for script __rso-mod__/control.lua: 3316624002
   1.503 Checksum for script __SignPosts__/control.lua: 895918544
   1.540 Info MultiplayerManager.cpp:282: 0x7f9d0e861c10, (nil)
   1.540 Info PosixUDPSocket.cpp:34: Opening socket at port 34197
   1.541 Info Router.cpp:536: Router state -> Connected
   1.541 Info Synchronizer.cpp:54: NetworkTick(0) initialized Synchronizer local peer(0) latency(15).
   1.541 Hosting game at port 34197, peerID 0, session magic 1935
   1.541 Info MultiplayerManager.cpp:304: 0x7f9d0e861c10, 0x7f9d0e861c10
   1.541 Info MultiplayerManager.cpp:913: networkTick(0) mapTick(15568355) changing state from(CreatingGame) to(InGame)
   1.541 Info NetworkInputHandler.cpp:45: mapTick(15568355) networkTick(0) initialized NetworkInputHandler local peer(0).
   1.808 Info MultiplayerManager.cpp:1433: Received peer info for peer(0) username(<server>).
   1.808 Info MultiplayerManager.cpp:1060: networkTick(15) mapTick(15568355) received stateChanged peerID(0) oldState(Ready) newState(CreatingGame)
   1.808 Info MultiplayerManager.cpp:1060: networkTick(15) mapTick(15568355) received stateChanged peerID(0) oldState(CreatingGame) newState(InGame)
   5.304 Error Util.cpp:58: Unhandled exception: std::bad_alloc
   5.305 Error Router.cpp:331: Unhandled exception: std::bad_alloc
Factorio crashed. Generating symbolized stacktrace, please wait ...
   5.808 Warning Logger.cpp:338: Symbols.size() == 9, usedSize == 8
#0  0x7a5e59 in SignalHandler at /tmp/factorio-gpN9b3/src/Util/CrashHandler.cpp:176
#1  0x7f9d1c362670 in ?? at ??:0
#2  0x7f9d1c3625f7 in ?? at ??:0
#3  0x7f9d1c363ce8 in ?? at ??:0
#4  0x92339f in unhandledException at /tmp/factorio-gpN9b3/src/Util/Exceptions.cpp:36
#5  0xd514ef in readPacketsLoop at /tmp/factorio-gpN9b3/src/Net/Router.cpp:331
#6  0x7f9d1ce15dc5 in thread_proxy at thread.cpp:?
#7  0x7f9d1c4231cd in ?? at ??:0
   6.296 Warning Logger.cpp:338: Symbols.size() == 8, usedSize == 7
   6.296 Error Util.cpp:78: Unexpected error occurred. You can help us to solve the problem by posting the contents of the log file on the Factorio forums.

[fsargent]

After a few restarts, it cleared. Not sure why, but not seeing it anymore.

[AGTMADCAT]

Actually @fsargent, we're still having the problem, so there's something more to troubleshoot here.

The server starts up fine, and seems to run okay as long as no one connects to it. As soon as I try to connect, the service goes down. After the first couple of seconds of standard startup log information, we receive this block of errors in the code, right when someone goes to connect:

Code: Select all

91.207 Error Util.cpp:58: Unhandled exception: std::bad_alloc
  91.208 Error Router.cpp:331: Unhandled exception: std::bad_alloc
Factorio crashed. Generating symbolized stacktrace, please wait ...
  91.717 Warning Logger.cpp:338: Symbols.size() == 9, usedSize == 8
#0  0x7a5e59 in SignalHandler at /tmp/factorio-gpN9b3/src/Util/CrashHandler.cpp:176
#1  0x7f450eacf670 in ?? at ??:0
#2  0x7f450eacf5f7 in ?? at ??:0
#3  0x7f450ead0ce8 in ?? at ??:0
#4  0x92339f in unhandledException at /tmp/factorio-gpN9b3/src/Util/Exceptions.cpp:36
#5  0xd514ef in readPacketsLoop at /tmp/factorio-gpN9b3/src/Net/Router.cpp:331
#6  0x7f450f582dc5 in thread_proxy at thread.cpp:?
#7  0x7f450eb901cd in ?? at ??:0
  92.211 Warning Logger.cpp:338: Symbols.size() == 8, usedSize == 7
  92.211 Error Util.cpp:78: Unexpected error occurred. You can help us to solve the problem by posting the contents of the log file on the Factorio forums.

I'll give the server a couple more reboots to see if that sorts it. We're on 12.30, with these mods:
maration 1.0.1
Honk 0.2.1
RailTanker 1.1.3
SignPosts 0.2.0
rso-mod 1.5.0

Cheers,
-AGT

**EDIT**: Just opted into the 12.30 beta on my desktop, and then I was able to connect normally. Didn't realise we were on experimental. I will post another reply if it reoccurs.

[silent]

Are you running out of memory? You can check `top` or `htop` to tell.

I didn't check pages or anything, but the system isn't running out of memory...

Code: Select all

head factorio_memory.log 
top - 11:47:27 up 20:19,  1 user,  load average: 0.00, 0.01, 0.05
Tasks:   1 total,   0 running,   1 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.9 us,  0.1 sy,  0.0 ni, 99.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.1 st
KiB Mem:   1016324 total,   566904 used,   449420 free,    33636 buffers
KiB Swap:        0 total,        0 used,        0 free.   290156 cached Mem

  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND
 5657 ****      20   0  323236 183476   6988 S  0.0 18.1   0:08.66 factorio

Code: Select all

grep -B 20 5657 factorio_memory.log | tail

top - 01:10:48 up 1 day,  9:42,  0 users,  load average: 0.00, 0.01, 0.05
Tasks:   1 total,   0 running,   1 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.0 us,  0.0 sy,  0.0 ni,100.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem:   1016324 total,   647020 used,   369304 free,    95656 buffers
KiB Swap:        0 total,        0 used,        0 free.   302768 cached Mem

  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND
 5657 ****      20   0  392836 191028   7692 S  0.0 18.8   9:55.06 factorio

[Koub]

Just in case it could help, I just saw a dev saying that Rail Tanker 1.1.3 was not developped to be MP bugfree :
viewtopic.php?p=147191#p147191

[silent]

Just in case it could help, I just saw a dev saying that Rail Tanker 1.1.3 was not developped to be MP bugfree :
viewtopic.php?p=147191#p147191

That log is from my pvp server, it doesn't have railtanker.

That being said, the pvp server does have other mods and the vanilla server seems to be doing ok, so I can't rule out mod-related issues. Even so, the exception is clearly generated in the C++ code, so my first hypothesis would be mishandling of a Lua call or data operation of some sort.

*sigh* if only I had a work-permit for the czech republic...

[TruePikachu]

The thing is, bad_alloc is only thrown when there's a failure allocating memory. Something is trying to get more memory than there actually is free. What I can't tell is if it is a large-but-actually-reasonable amount of memory (e.g. new int[100*100]), or an unreasonable amount of memory (e.g. new int[-1]).

All I can possibly think of is setting a catchpoint for bad_alloc. Anyone with the issue experienced enough with gdb to get the full callstack and attempted allocation size?

[Oxyd]

I suspect that this is actually the same bug as this one.

[silent]

I suspect that this is actually the same bug as this one.

Whelp, looks like we'll find out when 0.12.31 is out...

[Klonan]

Thanks for the report

I suspect that this is actually the same bug as this one.

Whelp, looks like we'll find out when 0.12.31 is out...

I will assume the same too, moved to resolved for the next release