[1.1.21] Crash loading save: "Energy source error, most probable cause is the double entity problem."

[LPhoenix]

The game crashes when I try to load my last manual savegame (attached), and also my last 10 autosaves.
No mods installed, using vanilla, downloaded from steam.
The only modification I did was that I changed the number of autosave-slots to 10 in %APPDATA%/Factorio/config/config.ini.

My latest savegame which is loadable is from ~4h earlier.

If needed I can upload any of the crashing autosaves too.

Code: Select all

  0.001 2021-02-12 18:04:11; Factorio 1.1.21 (build 58049, win64, steam)
   0.001 Operating system: Windows 10 (version 2004) 
   0.002 Program arguments: "F:\SteamLibrary\steamapps\common\Factorio\bin\x64\Factorio.exe" 
   0.002 Read data path: F:/SteamLibrary/steamapps/common/Factorio/data
   0.002 Write data path: C:/Users/Peti/AppData/Roaming/Factorio [314975/975667MB]
   0.002 Binaries path: F:/SteamLibrary/steamapps/common/Factorio/bin
   0.010 System info: [CPU: AMD Ryzen 5 2600 Six-Core Processor, 12 cores, RAM: 7753/32703 MB, page: 10523/37567 MB, virtual: 4337/134217727 MB, extended virtual: 0 MB]
   0.010 Display options: [FullScreen: 1] [VSync: 1] [UIScale: custom (100.0%)] [Native DPI: 1] [Screen: 255] [Special: lmw] [Lang: en]
   0.017 Available displays: 2
   0.017  [1]: \\.\DISPLAY2 - NVIDIA GeForce GTX 1070 {0x05, [0,0], 1920x1200, 32bit, 59Hz}
   0.018  [0]: \\.\DISPLAY1 - NVIDIA GeForce GTX 1070 {0x01, [-1920,0], 1920x1200, 32bit, 59Hz}
   0.091 [Direct3D11] Display: 0, Output: 0, DisplayAdapter: 0, RenderingAdapter: 0; d3dcompiler_47.dll
   0.224 Initialised Direct3D[0]: NVIDIA GeForce GTX 1070; id: 10de-1b81; driver: nvldumdx.dll 27.21.14.5730
   0.224   D3D Feature Level: 11.1, DXGI 1.5+, SwapChain: 3,flip-discard,-,-,-,none
   0.224   [Local Video Memory] Budget: 7320MB, CurrentUsage: 2MB, Reservation: 0/3788MB
   0.224   [Non-Local Vid.Mem.] Budget: 15583MB, CurrentUsage: 0MB, Reservation: 0/7919MB
   0.224   Tiled resources: Tier 2
   0.224   Unified Memory Architecture: No
   0.224   BGR 565 Supported: Yes
   0.224   MaximumFrameLatency: 3, GPUThreadPriority: 0
   0.224 Graphics settings preset: very-high
   0.224   Dedicated video memory size 8088 MB
   0.271 Desktop composition is active.
   0.271 Graphics options: [Graphics quality: high] [Video memory usage: all] [Light scale: 100%] [DXT: none] [Color: 32bit]
   0.271                   [Max threads (load/render): 32/12] [Max texture size: 0] [Tex.Stream.: 0] [Rotation quality: normal] [Other: STDCWT] [B:0,C:0,S:100]
   0.295 DSound: Starting _dsound_update thread
   0.295 [Audio] Backend:default; Depth:16, Channel:2, Frequency:44100; MixerQuality:linear
   0.296 DSound: Enter _dsound_update; tid=8104
   0.391 Logitech LED Controller initialized.
   0.397 Loading mod core 0.0.0 (data.lua)
   0.500 Loading mod base 1.1.21 (data.lua)
   0.847 Loading mod base 1.1.21 (data-updates.lua)
   1.021 Checksum for core: 1905034584
   1.021 Checksum of base: 1503457007
   1.226 Prototype list checksum: 3034860339
   1.278 Loading sounds...
   1.400 Info PlayerData.cpp:73: Local player-data.json unavailable
   1.400 Info PlayerData.cpp:76: Cloud player-data.json available, timestamp 1613092923
   1.559 Initial atlas bitmap size is 16384
   1.607 Created atlas bitmap 16384x16380 [not-compressed]
   1.613 Created atlas bitmap 16384x12461 [not-compressed]
   1.614 Created atlas bitmap 8192x4195 [decal, not-compressed]
   1.616 Created atlas bitmap 16384x5560 [low-object, not-compressed]
   1.617 Created atlas bitmap 4096x3088 [mipmap]
   1.618 Created atlas bitmap 8192x4464 [not-compressed, mipmap, linear-minification, linear-magnification, linear-mip-level]
   1.620 Created atlas bitmap 16384x6064 [terrain, not-compressed, mipmap, linear-minification, linear-mip-level]
   1.621 Created atlas bitmap 4096x3216 [terrain-effect-map, not-compressed, mipmap, linear-minification, linear-mip-level]
   1.622 Created atlas bitmap 4096x1844 [smoke, not-compressed, mipmap, linear-minification, linear-magnification]
   1.623 Created atlas bitmap 8192x2240 [icon, not-compressed, mipmap, linear-minification, linear-magnification, linear-mip-level]
   1.623 Created atlas bitmap 8192x1496 [alpha-mask]
   1.628 Created atlas bitmap 16384x14748 [shadow, linear-magnification, alpha-mask]
   1.628 Created atlas bitmap 8192x2336 [shadow, mipmap, linear-magnification, alpha-mask]
   1.629 Created atlas bitmap 2048x240 [icon-background, not-compressed, mipmap, linear-minification, linear-magnification, linear-mip-level, ]
   1.636 Texture processor created (2048). GPU accelerated compression Supported: yes, Enabled: yes/yes. Test passed. YCoCgDXT PSNR: 35.83, BC3 PSNR: 33.82
   2.447 Parallel Sprite Loader initialized (threads: 11)
   8.838 Sprites loaded
   8.851 Generated mipmaps (4) for atlas [3] of size 16384x5560   
   8.888 Generated mipmaps (3) for atlas [4] of size 4096x3088   
   8.899 Generated mipmaps (3) for atlas [5] of size 8192x4464   
   8.910 Generated mipmaps (3) for atlas [6] of size 16384x6064   
   8.921 Generated mipmaps (3) for atlas [7] of size 4096x3216   
   8.932 Generated mipmaps (3) for atlas [8] of size 4096x1844   
   8.943 Generated mipmaps (5) for atlas [9] of size 8192x2240   
   8.955 Generated mipmaps (3) for atlas [12] of size 8192x2336   
   8.992 Custom mipmaps uploaded.
   9.190 Factorio initialised
   9.190 Discord overlay detected (DiscordHook64.dll)
   9.246 Steam Storage Quota: 4416/4768
  16.225 Loading map C:\Users\Peti\AppData\Roaming\Factorio\saves\Lazy Bastard 24.zip: 14687120 bytes.
  16.279 Loading level.dat: 38405448 bytes.
  16.284 Info Scenario.cpp:197: Map version 1.1.21-0
Factorio crashed. Generating symbolized stacktrace, please wait ...
c:\cygwin64\tmp\factorio-build-uvvw4g\src\energy\electricenergysourceprototype.cpp (57): ElectricEnergySourcePrototype::createInternal
c:\cygwin64\tmp\factorio-build-uvvw4g\src\energy\energysourceprototype.cpp (94): EnergySourcePrototype::loadInstance
c:\cygwin64\tmp\factorio-build-uvvw4g\src\entity\craftingmachine.cpp (70): CraftingMachine::CraftingMachine
c:\cygwin64\tmp\factorio-build-uvvw4g\src\entity\furnaceprototype.cpp (38): FurnacePrototype::createInternal
c:\cygwin64\tmp\factorio-build-uvvw4g\src\entity\entityprototype.cpp (664): EntityPrototype::loadEntity
c:\cygwin64\tmp\factorio-build-uvvw4g\src\surface\chunk.cpp (433): Chunk::load
c:\cygwin64\tmp\factorio-build-uvvw4g\src\surface\surface.cpp (965): Surface::load
c:\cygwin64\tmp\factorio-build-uvvw4g\src\map\map.cpp (557): Map::loadData
c:\cygwin64\tmp\factorio-build-uvvw4g\src\map\map.cpp (323): Map::load
c:\cygwin64\tmp\factorio-build-uvvw4g\src\scenario\scenario.cpp (248): Scenario::loadFactory
c:\cygwin64\tmp\factorio-build-uvvw4g\src\scenario\parallelscenarioloader.cpp (161): ParallelScenarioLoader::doLoad
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*)(MapInterface,ParallelScenarioLoader *,MapDeserialiser *,enum InputType,InputHandler *,MultiplayerManagerBase *,NamedBool<EnableReplayTag>),MapInterface,ParallelScenarioLoader *,MapDeserialiser *,enum InputType,InputHandler *,MultiplayerManagerBase *,enum NamedBool<EnableReplayTag>::Enum>,std::default_delete<std::tuple<void (__cdecl*)(MapInterface,ParallelScenarioLoader *,MapDeserialiser *,enum InputType,InputHandler *,MultiplayerManagerBase *,NamedBool<EnableReplayTag>),MapInterface,ParallelScenarioLoader *,MapDeserialiser *,enum InputType,InputHandler *,MultiplayerManagerBase *,enum NamedBool<EnableReplayTag>::Enum> > > >::_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: 00007FF8E1317034)
00007FF8E1317034 (KERNEL32): (filename not available): BaseThreadInitThunk
ERROR: SymGetLineFromAddr64, GetLastError: 487 (Address: 00007FF8E28DD241)
00007FF8E28DD241 (ntdll): (filename not available): RtlUserThreadStart
Stack trace logging done
  19.094 Error ElectricEnergySourcePrototype.cpp:57: Energy source error, most probable cause is the double entity problem.
Logger::writeStacktrace skipped.
  19.094 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.
  41.881 Uploading log file
  41.892 Error CrashHandler.cpp:258: Heap validation: success.
  41.894 Creating crash dump.
  42.179 CrashDump success

[LPhoenix]

Exact same crash happens with the "full" version of the game, without steam

[kovarex]

My best guess is, that this is a random memory flip. I suggest running CPU/MEM check.
Let me know how it went.

[LPhoenix]

I ran Windows Memory Diagnostic and OCCT to test. They didn't report any problems.

I'm not sure from your answer, but were you able to reproduce the issue?
Also I'm skeptic about the random memory flip. How can that cause this error for 11 saves, spanning more than 1 hours?

I'm happy to help in finding out the issue (I'm a SW Engineer myself)

Is it possible to somehow fix the save?

[kovarex]

If the bit changes in memory, which is then not changed and used to save the game X times, it can easily overwrite the same problem several times, we had this kind of problem before.
Obviously, in some simple cases, we added fast consistency check when saving, to at least avoid overwriting the save and get error instead of making corrupt save. But obviously, we can't check 100% of everything, as it would slow down the saving process.

I can try to look into this, and see if I can figure out a save lightweight consistency check that would catch this problem.

By a reproduction I mean to search for the X in:

• Start with a save that is loadable just fine
• Do <X>
• Save the game into unloadable save.

I know that it might be asking little bit too much, but sometimes people were able to pinpoint the X which helped us to understand bugs that would be otherwise really really hard to figure out.

[LPhoenix]

I'll try to recreate what I did in those 4 hours (I wanted to do that anyway if the save is not fixable) and I'll just set the number of autosaves higher and we'll see if I can pinpont something usable for You.
Maybe I'll not find anything, who knows with errors like this.

[kovarex]

Ok, I looked more into it.
I could now raise my memory flip hypothesis confidence level from 80% to 99.9%, why?

In the electric network internal indexing, there were two entities (electric furnaces) pointing at index 68, and one slot at index 196 was empty.
Since 196 - 68 = 128 = 2^7, it takes exactly one bit flip of one of the indexes to get to this result.

Obviously, this doesn't need to be a faulty hardware, it can just be a slightly more potent cosmic particle finding its way into your RAM, I vaguely remember having more random reports when the sun activity was higher, so there is a correlation.

Once I had this info, I could easily manually fix the index while loading to produce a fixed save.
The save is saved in the newest version which wasn't released yet so you need to wait for the release (monday probably) to be able to use it.

[LPhoenix]

Wow, thank you very much for looking into it. I can consider myself lucky that it happened in a place like this and you were able to find it.

Yeah, I know about the cosmic ray/particle "risk". This is why ECC RAM is a thing. I heard about the correlation myself also.

Thank you very much again! You guys are awesome! I wish you the best in the future!

[kovarex]

Wow, thank you very much for looking into it. I can consider myself lucky that it happened in a place like this and you were able to find it.

It is happening in a lot of other places much more often generally, but no one will notice that their decorative variation is suddenly different etc.

[LPhoenix]

Since my original post I encountered the same problem. It happened with the assemblers this time. I didn't report this, because I didn't loose any significant progress and also it was quite peculiar that I encountered this again in this short amount of time. So I dug deeper and I'd like to share my experience. Maybe in the future you can help others who encounter this problem with some additional hints.

So when I added my 2 extra RAM modules (4 in total now) like a year ago, I realized that I need to underclock my RAM for it to work with my current Motherboard (bummer). I completely forgot about this until the following happened.

Shortly after I encountered the crash the second time my windows started to throw BSODs with increasing frequency and completely inconsistent messages, which in the end resulted in being unable to boot into windows. This is when I remembered my underclock.

I searched for proper methods to test my RAM for errors and found out that Windows Memory Diagnostic is bad, because it only tests the 1st 4GB (maybe 32bit limitation). Anyway, I found Memtest86 which did encounter few errors while running, and the errors were exactly 1 bitflip, as in the savefile in my original post. So basically my underclock wasn't 100% stable, only like 99.99%. I lowered the frequency a tiny bit more, and now it's seems stable. No errors with Memtest86.

Maybe in the future this could be a good hint for others who encounter this!

TL;DR:
Windows Memory Diagnostic bad
Memtest86 good
If similar problem, hint for others if RAM setup is 100% stable