I want to learn how to read my own error logs

[MisterFister]

Hello folks. I'm running KSP 0.24.2 x86 on Win 7. My system incudes 16gb of RAM. I'm a mod-happy little nimrod, currently running approximately 100 mods, give or take. I run ATM at the default-aggressive level, though I know it's possible to make it even more aggressive if I don't mind making everything almost ugly-blurry by manually tweaking its config file.

I was told by none other than Majiir, the creator of kethane itself, a while ago said ...

It's important to note that while part memory consumption is fairly easy to predict, plugins are much harder to predict. In particular, plugins can have bursty memory consumption. So, even if everything seems fine when idle, a plugin might need to allocate a large portion of memory even for just a millisecond, and that can contribute to instability. Some plugins might maintain large data sets in memory at all times, too.

I think that's what I'm running into here. I know that the normal troubleshooting steps calls for me to strip down to a stock-only install and reintroduce the mods one or a few at a time, but in my case, that would actually make my problem MORE difficult to track if it is indeed a RAM overflow issue.

x64 is no help either, since it's widely-enough considered to be broken that it's not even supported here on the forums.

I want to learn more about this than I do. I have my output_log.txt at this link, and I know that there is a trove of information in that file, but I don't know how to read it. I don't know how to make sense of it. I do know that I throw a crapton of NRE's which become visible when I open up the debug menu in-game, but they're anonymous and I can't make sense of that info either.

As for steps to reproduce my problem, the fact that it's difficult to predict when it happens lends credibility to my sense that it's a plugin-driven RAM overflow. Like I said, I run about 100 mods, and while only B9 / KW / NovaPunch are part-only mods, I do have a fair number of mods designed for VAB / SPH use, to include KCT, Fusebox, Editor Extensions, Part Highlighter, MJ, KER, and some others. To generate this specific log, my game CTD'd when exiting the VAB to the KSC main screen.

Can someone help me figure out how to read this? I mean, sure, if you can read it and tell me right away what you think the problem is, that's great, but I'm specifically asking for you to help me learn how to read it for myself. If you do provide a troubleshooting opinion, can you show me how you arrived at it?

Thanks!

Edited October 5, 2015 by MisterFister

[Wanderfound]

I'm also in a similar position to this, albeit with far fewer mods (and a presumably much dodgier computer). A "how to read the error logs" tutorial would be a very useful thing if it's possible.

[Master Tao]

Here's the process I took looking through your log:

1. Search for "mod dlls" to find the Module Manager list of mods and plugins. It lists versions for all plugins, though as you can see, many of them report incorrect versions. I'm looking for seriously outdated mods, conflicting versions of mods (like KSPAPIExtensions and Scale). Recognizing plugins takes some memorization. For example, TweakScale is still known as Scale because it's based on Goodspeed Scale. That's a common conflict. Only odd thing I noted is that your Scale reports version 0.0, but the current version reports the correct 1.43.

2. Drop to the end of the log, looking for a stack trace following a crash or some other sign of what went wrong. This is why's it's important to quit as soon as you cause the problem – so everyone knows where to look for the problem. In your case, there's a crash with the following stack trace:

(0x10106E5E) (mono): (filename not available): (function-name not available) + 0x0

(0x10106EB7) (mono): (filename not available): (function-name not available) + 0x0

(0x101073C4) (mono): (filename not available): (function-name not available) + 0x0

(0x001BD792) (KSP): (filename not available): Behaviour::Transfer<SafeBinaryRead> + 0x902a2

(0x001CF9C7) (KSP): (filename not available): Behaviour::Transfer<SafeBinaryRead> + 0xa24d7

(0x001C1399) (KSP): (filename not available): Behaviour::Transfer<SafeBinaryRead> + 0x93ea9

(0x001C1854) (KSP): (filename not available): Behaviour::Transfer<SafeBinaryRead> + 0x94364

(0x001C29D9) (KSP): (filename not available): Behaviour::Transfer<SafeBinaryRead> + 0x954e9

(0x001C2B84) (KSP): (filename not available): Behaviour::Transfer<SafeBinaryRead> + 0x95694

(0x00233E4B) (KSP): (filename not available): Behaviour::Transfer<SafeBinaryRead> + 0x10695b

(0x0023566B) (KSP): (filename not available): Behaviour::Transfer<SafeBinaryRead> + 0x10817b

(0x0049E948) (KSP): (filename not available): AnimationEvent::Transfer<StreamedBinaryRead<1> > + 0x119b28

(0x004D3830) (KSP): (filename not available): AnimationEvent::Transfer<StreamedBinaryRead<1> > + 0x14ea10

(0x7540338A) (kernel32): (filename not available): BaseThreadInitThunk + 0x12

(0x770F9F72) (ntdll): (filename not available): RtlInitializeExceptionChain + 0x63

(0x770F9F45) (ntdll): (filename not available): RtlInitializeExceptionChain + 0x36

That's flat out useless. Stack traces like that are why so many modders refuse to support Windows 64-bit KSP. All it really shows is that a crash happened in an unnamed Mono function called by an unnamed Mono function called by what's probably a recursive KSP function. It's the particular sort of useless that I've come to expect from out-of-memory errors with Win64 KSP.

Normally I'd stop there – it seems clear enough that that's the issue.

3. Run a Find All search for "exception" to get an overview of the pattern of errors. There are 222. There are normal exceptions like TweakScale_RealFuels (can't load because you don't have RealFuels installed). DangIt! for FAR complains, though I suspect that's a version incompatibility because I've seen similar issues with the MechJeb FAR modules with the dev version of FAR. PunishTheLazy is having trouble finding out what time it is in the game. Is that Rover Wheel Sounds that always puts out four NullReferenceExceptions in a row? I know I've seen that pattern before, but it's never been relevant. I see the ReflectionTypeLoadException a fair amount, but have never needed to track it down. EVE (Clouds) complains as usual.

4. It can be helpful to look backwards from the crash or issue, but in this case, there's nothing obvious before the crash. Looks like you reverted to launch ("Scene Change : From FLIGHT to FLIGHT"), some plugins redisplayed themselves, and the game autosaved.

5. It helps to have a programmers text editor like Notepad++ for Windows or TextWrangler for Macs. If I suspect that someone has installed a mod incorrectly, I'll make a regex/grep search for ^AssemblyLoader[^\r\n]+\.dll$. That search gives me a list of all plugins and their locations as they're loaded by KSP. Since I'm trying to document my thought process, I won't edit part 1 after finding these:

AssemblyLoader: Loading assembly at D:\Games\Steam\steamapps\common\Kerbal Space Program\GameData\DangIt\ModuleManager.2.2.0.dll
...
AssemblyLoader: Loading assembly at D:\Games\Steam\steamapps\common\Kerbal Space Program\GameData\Goodspeed\Plugins\Scale.dll

Totally did not plan that . You have an old version of ModuleManager in the DangIt folder (probably not an issue) and Goodspeed Scale still installed. That explains the version 0.0 – I'd bet TweakScale doesn't even work for you. At a glance, everything looks like it's installed correctly.

6. Look for evidence of problems that I've seen before. There have been a few cases recently of an old ModuleManager config causing issues with TweakScale and the Infernal Robotics Rework. Once I started recognizing the symptoms, I found that I could locate it by looking for distinctive @PART lines. In one case, I identified similar issues by noticing that the player was making similar changes to IR with a different config. At this point, though, I'm getting to the point where you have to understand how the mod works to be able to solve problems by reading the log.

So that's a largely unedited look through a log. Like pretty much everything else you learn, experience is more helpful than explanation. You've already reached the point where you can recognize a common problem with enough confidence to ask for confirmation. Keep going.

[NathanKell]

I really have nothing to add to that excellent post.

Well, ok, one thing: if something internal in KSP 32bit broke, that's the same kind of useless stack trace you'd see, because SQUAD (to no purpose, and to much decrease in speed and added difficulty) obfuscates their code in the DLLs. Which is silly, because they also then by the rules don't allow us to look into the DLL anyway so what's the point.

[MisterFister]

{I could've sworn that I replied to this earlier.}

You've already reached the point where you can recognize a common problem with enough confidence to ask for confirmation. Keep going.

High praise. Thank you. My walkaway from your reply is that my ceiling for ever learning how to read these will be capped by my inability to program. It sounds as if your experiential knowledge is based primarily on things you've had to troubleshoot previously from a coding / modding standpoint. I did a lot of neato fun things in vBASIC back in high school twenty years ago (jeez it frightens me to say that!!) so I understand the general mentality that it would take. But I have NO basis in any C-derived environment.

With respect to #2 in your reply, I hope I didn't convey the impression that I was crashing in x64. I stopped trying to get x64 to work last weekend. This is an x86 issue.

And on #6, thanks for the spot. I thought I'd cleaned out all duplicate MM files. With respect to TweakScale not working, you're correct that I wasn't happy with it, but I could get it to work (partially...?) in the Control Group editor. I'd chalked up my difficulties to my own poor familiarity with the mod. I'll re-assess now that I've cleaned out the MM and update you further.

Also, What are your thoughts on this? http://forum.kerbalspaceprogram.com/threads/94086-x64-works-%21-But-I-don-t-know-why%21-Please-help-me-replicate Someone else seems to think that by converting texture files to the tighter PNG format, memory footprint can be vastly reduced. I think his own context was in attempting to remain below x64's instability threshold, but for my own x86 purposes here, if he's onto something, it could help me here.

Just so I'm clear on what you were conveying, you see no blatant evidence of an improperly installed mod, or a freakishly serious mod intercompatibility issue? In other words, my memory overflow theory still works as an explanation? Which leads me to another point: I posted that thread (the one I quote Majiir from, above) a few moons ago. My understanding from back then was, "nice idea, but so far no dice." In fact, it was Majiir's own explanation that led me to abandon my plans to take a few hours, run mods one at a time, and take Task Manager snapshots of my footprint with each one. It occurs to me now that memory-usage utilities have to exist somewhere, even if not for KSP. I'll run my own googles myself, so no worries, but does anyone have any head start info on where to look?

Edited September 20, 2014 by MisterFister
addendum

[NathanKell]

I posted in the other thread about textures, but I'll post here too. Go here for details on how KSP *actually handles textures. tl;dr aside from some loader bugs ATM fixes, and leaks in the texture loader (minor, IIRC), format on disk doesn't matter a bit.

[Supergamervictor]

I had the same post but it never got a reply.Thanks for the answer,Really helpful

[Master Tao]

My walkaway from your reply is that my ceiling for ever learning how to read these will be capped by my inability to program. It sounds as if your experiential knowledge is based primarily on things you've had to troubleshoot previously from a coding / modding standpoint. I did a lot of neato fun things in vBASIC back in high school twenty years ago (jeez it frightens me to say that!!) so I understand the general mentality that it would take. But I have NO basis in any C-derived environment.

While I do have a some programming experience, I've never done any C# programming. It's the mentality and some experience with a few debugging concepts. Most of what you need are regular expressions and reading stack traces. Regular expressions are helpful for finding patterns in logs, though it absolutely takes time and practice to wrap your head around them. Stack traces are easier, since they list functions inside-out. The first function listed is the one that broke. The second is that function that called the first, and third function listed called the second. Basically, read down the list until you get to a function you can associate with a particular mod. Then remove all your other mods to see if it's really just that mod causing the problem. (In the example in #6, the TweakScale conflicts visibly broke Infernal Robotics, but also managed to break FAR first in the log.)

With respect to #2 in your reply, I hope I didn't convey the impression that I was crashing in x64. I stopped trying to get x64 to work last weekend. This is an x86 issue.

Whoops. You're right. I missed that you'd switched back to 32-bit. I honestly barely even look at that part of the log – some current installs of KSP for Mac report "Windows 64-bit build detected."

Usually, out-of-memory issues in 32-bit KSP will explicitly say that's the problem. There will be lots of references to ALLOC (Win) or malloc (Mac, Linux) at the end of the log. It's still possible that this is the memory issue you've theorized. Confirming that as a player (rather than SQUAD) would probably take more work than it's worth. You'd need to run many trials with the same mods and action sequence, monitoring memory load and adjusting ATM settings for at least high/low test cases. I can see that taking days of testing.

With respect to TweakScale not working, you're correct that I wasn't happy with it, but I could get it to work (partially...?) in the Control Group editor.

You can just delete KSP\Goodspeed\Plugins\Scale.dll. TweakScale is the successor, so Goodspeed parts will still scale without it.

Just so I'm clear on what you were conveying, you see no blatant evidence of an improperly installed mod, or a freakishly serious mod intercompatibility issue?

Nothing that I've seen so far. The major mod incompatibilities I'm familiar with are with conflicting versions of KSPAPIExtensions and mods that add multiple resources. There are also a few others that either say they have conflicts or people can hopefully figure out on their own (NEAR+FAR = bad). swamp_ig (and taniwha & NathanKell) helpfully list all the mods that use KSPAPIExtensions on the first page. Those issues should be resolved for the future now that everyone has updated to KAE 1.7.0, but every once in a while someone still has an old version installed.

For installation issues, I'm looking for:

• Mods I'm familiar with – is the folder strucure right?
  
• Mods installed in a folder with the version number. No mod does that when installed correctly, so there's always a plain old ModName folder a little deeper.
  
• GameData folders inside GameData or a mod folder.
  

Based on that, everything you have looks installed correctly.

[MisterFister]

You can just delete KSP\Goodspeed\Plugins\Scale.dll. TweakScale is the successor, so Goodspeed parts will still scale without it.

Sweetness! I'll do this right away.

For installation issues, I'm looking for:

• Mods I'm familiar with – is the folder strucure right?
  
• Mods installed in a folder with the version number. No mod does that when installed correctly, so there's always a plain old ModName folder a little deeper.
  
• GameData folders inside GameData or a mod folder.
  

Based on that, everything you have looks installed correctly.

Yeah, I made that mistake a while ago and really pissed off Cilph in the RT2 thread. The varying organization of mod download zipfiles can get maddening. To reduce it, I've taken to prepping all downloaded mods with a blank .txt file, with a filename signifying the exact zipfile I downloaded it from. This allows me to do some of my own version tracking. Also, happy side effect, I found it's REALLY useful in uninstalling mods (for example, to reduce ram-load). A lot of GameData folders get joined or partially overwritten by multiple mods, such that deleting a GameData folder can break another mod if you don't replace that other mod's dependencies afterward. For example, my BoulderCo directory has ... six .txt files like that, so that if I wanna uninstall any of those, I have a list of other mods dependent on it, so I can reconstruct the dependencies after deleting the mod I wanna uninstall.