Profiling & Debugging Support For KSP Plugins (22 Aug, Unity 4.5)

[a.g.]

Disclaimer: This is intended only for plugin developers with some experience, and definitely disqualifies from reporting bugs unless reproducible with stock KSP.

Since KSP is distributed as a release build, it does not provide any way to profile and debug even newly written plugin code. However, Unity uses an open-source LGPL mono library to run the code, and the source code for it is publicly available on GitHub. Thus, it is possible to compile a custom version of the dll, with some added options to enable debugging and profiling without cooperation from the main executable. Of course, nothing is that simple, and it was also necessary to fix and merge fixes for a number of bugs in the stale legacy profiler code.

The result is a new capability to:

1. Profile C# code running in KSP.
   The profiler works by sampling the call stack every millisecond, so it should correctly provide the general picture of what is taking time, without much slowdown, or adding any biasing overhead to events like function calls.
   
2. Debug C# code compiled from source using the MonoDevelop debugger, with ability to set breakpoints, single step, and view the values of variables.
   There is however no support for Visual Studio, and it is likely impossible without Professional in any case. Neither is it possible to set breakpoints or step through code you didn't compile from source yourself in MonoDevelop.
   

I've been testing it since around New Year, fixing some issues in the process, and it seems to mostly work OK. Since I'm using Linux however, there may be more issues on Windows.

Currently known issues:

• The profiler seems to have some race-condition style of issues, and occasionally deadlocks and/or crashes. I don't understand the code well enough to find out why, and later mono versions just rewrote it from scratch. Don't profile unless you are willing to reset your progress; it's better to use reproducible scenarios in any case.
  
• The tool for viewing profiling results tends to crash if the data file is truncated or corrupted.
  
• If you try to use the profiler and debugger at the same time, it will appear to work, but the profiling results will be garbage.
  
• Sometimes using single-stepping in the debugger may just resume execution; in other cases it may take multiple steps to proceed over a single line.
  

Downloads:

• Source and documentation on GitHub.
  
• Binaries for 32-bit Linux and Windows - likewise on GitHub.
  

Don't forget to back up the original DLL before overwriting it.

The license is generally LGPL, with GPL, X11 and MIT possibly applying to parts of the code. There was no decompiling or reverse-engineering involved in making this.

Edited August 22, 2014 by a.g.

[NathanKell]

This is excellent stuff--thanks so much for doing this and sharing!

[Padishar]

This looks very helpful, thanks. I use VS at the moment so I'll need to switch over to MonoDevelop before I can try it but I will definitely be giving it a try at some point soon.

I actually had a dream the other night about implementing a replacement mono.dll for windows that uses the .NET runtime and (in my dream) it made KSP run much quicker and allowed direct debugging in VS. I had a bit of a look at how feasible this might be and, well, I don't think I'll be trying it any time soon...

[BGog42]

I followed the instructions. Launched monodevelop with monodevelop.bat and ksp with the debug script. The debugger attaches and catches uncaught exceptions etc. However it is all disassembly and doesn't relate at all to the .cs files. I can set breakpoints but they become a hollow icon and do not work.

Any clues as to what I may be missing?

[a.g.]

Did you follow instructions on how to correctly compile and install the project? Namely, setting output directory to the target GameData subdir, disabling Local Copy etc. Unless the mdb file is next to the dll in GameData, it won't work.

[technogeeky]

Thanks very much for this. I hope it will help me improve the performance of my mods.

I am having trouble getting the toggleable profile...toggled. I'm in Linux, using your binary distribution. The run32-prof-control allows me to connect, but nothing happens no matter what I type in. Furthermore, the FPS plugin works great, and the profiler status appears as expected, but it is impossible to change with either Alt and F10.. or any other combination of keys I tried.

Also, I am a little confused on how to get emveepee working. mprof-decoder works fine. But when I launch either emveepee or mprof-heap-viewer, I get:

Missing method System.Type::op_Inequality(Type,Type) in assembly /usr/lib/mono/2.0/mscorlib.dll, referenced in assembly /usr/lib/mono/gac/gtk-sharp/2.12.0.0__35e10195dab3c99f/gtk-sharp.dll

Unhandled Exception:
System.MissingMethodException: Method not found: 'System.Type.op_Inequality'.
  at Gtk.Window..ctor (System.String title) [0x00000] in <filename unknown>:0 
  at Mono.Profiler.Gui.MainWindow..ctor () [0x00000] in <filename unknown>:0 
  at Mono.Profiler.Gui.MainClass.Main (System.String[] args) [0x00000] in <filename unknown>:0 
[ERROR] FATAL UNHANDLED EXCEPTION: System.MissingMethodException: Method not found: 'System.Type.op_Inequality'.
  at Gtk.Window..ctor (System.String title) [0x00000] in <filename unknown>:0 
  at Mono.Profiler.Gui.MainWindow..ctor () [0x00000] in <filename unknown>:0 
  at Mono.Profiler.Gui.MainClass.Main (System.String[] args) [0x00000] in <filename unknown>:0 

I'm sure these are errors on my fault (like I'm not pointing something to the appropriate lib, or I don't really have mono installed correctly or something).

Can you perhaps point me in some direction? It will be difficult to make sense of the profiling results if they are obfuscated by all of the loading process and whatnot.

I haven't yet tried the debugger, and I expect more boneheaded things to happen there -- so I reserve the right to ask again

edit: I also should add: On Ubuntu 12.04, I needed to install autoconf for the mono perl build script to even get started. It hasn't finished successfully yet either, so I may need more deps.

edit2: and bison. and gettext. and libglibmm-2.4-*.

And that was all I needed to run the ./configure script for mono.

Edited April 25, 2014 by technogeeky

[m4v]

Looks like the wrong Mono runtime, should be .NET 3.5

[technogeeky]

Looks like the wrong Mono runtime, should be .NET 3.5

I said it would be something stupid, didn't I? Yes, yes I did!

[m4v]

well if you can make it work let me know, It neither worked for me in Ubuntu, but If I recall correctly it was a different error and gave up without actually trying to solve it.

[technogeeky]

well if you can make it work let me know, It neither worked for me in Ubuntu, but If I recall correctly it was a different error and gave up without actually trying to solve it.

OK. I have the emveepee and mprof-heap-viewer working fine. Though I don't see anything useful coming from mprof-heap-viewer, yet. All I did was pass the paramter

--runtime=v4.0

to mono (in emveepee.sh for instance).

It runs fine. It seems to "just" be the same output that mprof-decoder gives, except it's in a nice selectable GUI window.

Off to try and figure out how to toggle on/off the profiler so I can get useful profiling data.

[technogeeky]

I'm not sure I understand what's really going on. It's obvious that there is something listening on the right port (12345) but it does not do anything, nor does it send back OK or ERROR. I don't know why the telnet server in the "stat" debugger would not work. I can't find much documentation about it either.

If you change MONO_PATH to be the lib directory of different versions, (and you use the associated KSP plugin) you have varying results:

1. /usr/lib/mono/4.5 shows "Off" and it works! Except you must use RightShift + RightAlt + F10 to toggle.

2. /usr/lib/mono/4.0 shows "Off" and it works! with the same exception.

3. /usr/lib/mono/3.5 shows nothing at all

4. /usr/lib/mono/2.0 shows "ERR" then nothing

5. /usr/lib/mono/2.0-compat shows "Off" and it works! With the same exception.

edit:

It works! You need to use RightShift + RightAlt + F10 to toggle the profiler. Unlike the other, always-enabled debug logs, I see my modules (and MechJeb, and all of the other mods I use... tsk tsk!) using significant (5-10%) of the time in the profiler. This means, I think, that I was just profiling when I had the green On text, and was not otherwise. Success!

Also, you need to use the version 4.0 runtime with emveepee (as stated above). I used the version4.5 library in my run32-prof script, and that seems to work fine (4.0 might work fine too). But you must use 4.0 for emveepee, or it crashes.

Edited April 26, 2014 by technogeeky

[a.g.]

There can only be one control link, so if the plugin is running, any subsequent telnet connections won't work. The Alt+F10 problem may be because of the stupid window manager bindings for Alt+*, which I changed on my computer to use the windows or menu key I think.

Also, you are generally not supposed to have any MONO_PATH, although maybe the network code in the plugin needs some dll that is not in KSP_Data/Managed. What does Player.log say about loading the dll?

[technogeeky]

There can only be one control link, so if the plugin is running, any subsequent telnet connections won't work.

Yep. That makes sense, and I realized this is probably the case after I got over the joy of having it working.

The Alt+F10 problem may be because of the stupid window manager bindings for Alt+*, which I changed on my computer to use the windows or menu key I think.

I thought of this too, but I figured you would have remembered this. But now, I think.. *I* wouldn't have remembered this, so I wouldn't have put it in the docs either.

Also, you are generally not supposed to have any MONO_PATH, although maybe the network code in the plugin needs some dll that is not in KSP_Data/Managed. What does Player.log say about loading the dll?

Not for the plugin. I was using MONO_PATH because I was debugging why the profiler wasn't working, because I didn't know about the above (namely that the plugin took the only connection && the plugin hotkey was not as advertized).

The one thing I do know is that it is necessary to use the 4.0 runtime to use the (compiled) version of emveepee, and that my system was apparently defaulting to the 2.0 runtime. Other than that, no runtime or path changes should be necessary.

Without me doing anything, the special key inside KSP is RightShift. For example, debug menu is RightShift + F12. So I presume it's just that the Alt modifier in your code is unnecessary in my case, but it doesn't matter to me. I know how to make it work.

There should be other commands available from the telnet (other than enable and disable). Namely, heap_snapshot and heap_snapshot. I presume that is what you would want to use that 3rd tool which doesn't give me much information. Speaking of which...

Do you know how to interpret the results of the profiler, in terms of making code better? Are the percentages listed the percentage of total (sampled) time that were spent inside some particular function call? Or just the percentage of the total number of function calls?

I still haven't even tried to get the debugger working yet.

[technogeeky]

Well, I have the debugger running and connected, but I don't really know how to get any useful information out of it.

I tried adding Watches like suggested, but I can't find anything appropriate to put inside Wrap().

Breakpoints don't seem to work, so I can't use it to look at the values of things in my code.

I can inspect the call stack when I pause it, but I can't really control what's on the stack when I pause.

[Xty]

Hey, this sounds useful and like exactly what I need right now. I'm righting an addon but part of my code is crashing KSP for some reason and I can't understand why.

I'm using Windows. I tried using the debugger, I got it started the first time but it wasn't stopping on the break points (possibly because I forgot to uncheck use local copy on the references, or because I set the breakpoints after starting), so hit stop in monodevelop which didn't stop KSP but caused it to freeze so I used the command prompt to close it. Now I can't get it to work anymore. I run the monodevelop script, start the custom debugger and set it to listen, but then when I run run32-debug monodevelop pops up with an error "Could not connect to the debugger." and KSP doesn't start up (at least not properly, it shows in the Task Manager but its using almost no memory so clearly isnt starting right).

I tried recopying all the files into the KSP directory, and restarting the computer, but its still doing the same thing, any idea how I can fix this?

[a.g.]

Breakpoints don't seem to work, so I can't use it to look at the values of things in my code.

Did you do the steps to set up the project exactly to the letter, like setting the build output directory to inside GameData. Unless the mdb file is placed next to the dll in there, breakpoints won't work.

Profiler percentages are of total measured time, even though they can be >100% in places because of weirdness when measuring recursive calls.

Now I can't get it to work anymore. I run the monodevelop script, start the custom debugger and set it to listen, but then when I run run32-debug monodevelop pops up with an error "Could not connect to the debugger." and KSP doesn't start up (at least not properly, it shows in the Task Manager but its using almost no memory so clearly isnt starting right).

Do you have any stupid antivirus firewalls or anything active? I have no idea otherwise.

Edited April 28, 2014 by a.g.

[m4v]

I tried once more and this time around it worked without issues, before KSP would consistently crash when I ran ./run32-prof.sh. Now it isn't as consistent, it just crashes on startup now and then, not sure what's up with that.

The only change I had to do was add "export LANG=C" in all scripts because KSP can't parse a number if the locale isn't English. But that's a known KSP's Linux shenanigan.

Did you do the steps to set up the project exactly to the letter, like setting the build output directory to inside GameData. Unless the mdb file is placed next to the dll in there, breakpoints won't work.

Yeah, has to be the build output directory, in my first try breakpoints didn't work either, changed the build directory and worked. Edited April 28, 2014 by m4v

[technogeeky]

I tried once more and this time around it worked without issues, before KSP would consistently crash when I ran ./run32-prof.sh. Now it isn't as consistent, it just crashes on startup now and then, not sure what's up with that.

The only change I had to do was add "export LANG=C" in all scripts because KSP can't parse a number if the locale isn't English. But that's a known KSP's Linux shenanigan.

Yeah, has to be the build output directory, in my first try breakpoints didn't work either, changed the build directory and worked.

My build directory is currently: Kerbal Space Program/GameData/SCANsat/. For the DLL part. For the executable part, it's whatever is default.

What is an mdb file? There are PDB files that appear to be needed for win32 only. MDB seems to be associated with the mono debugger from naive searches, but I don't know what that is yet.

I just ran the debugger now, and I do not see anything other than the intended DLL in GameData/SCANsat.

edit: This might be related to me not using the "Debug" configuration while building, because it gives me an error every time. Perhaps I should fix that. I suspect there must be a box somewhere that I haven't checked in the release version. Like emit debugging symbols.

That's what pdb and mdb are, after all, I gather.

Edited April 29, 2014 by technogeeky

[technogeeky]

That was indeed the problem.

When I selected the 'debug' release, I would get an error that looks like:

Error CS1902: Invalid debug option `+'. Valid options are `full' or `pdbonly' (CS1902) (TAG)

For that reason, I had simply been avoiding Debug. Comparing Debug and Release, I noticed that the "Emit Debugging Symbols" box was checked.

So I unchecked that box and instead put -debug:full in the additional options field.

Whala, breakpoints work (and SCANsat.dll.mdb suddenly appears!).

Some follow up questions, then:

1) If I really want to be able to "Watch" (haven't done this yet) anything (and not just things in my .DLL file), shouldn't I need to generate mdb files for several other DLLs and/or EXEs? If so, what is the strategy here? Should I uncheck "Local Copy" long enough to get MDBs, put them in the same directories as the files they represent in the KSP tree?

2) Is turning on "enable optimizations" going to destroy the utility of profiling or debugging? (Before I try both)?

Thanks again for your patience. Yes, I tried to follow the instructions down to the letter but evidently my setup is a little bit more buggy.

[a.g.]

You can look at fields of all objects; mdb is only needed for breakpoints and single stepping. Also, all Local Copy does is copy all kind of junk like even Assembly-CSharp.dll into the directory with the dll, which isn't a good idea seeing as KSP would try to load all of them from GameData.

Apparently that debug option error is some kind of bug in some versions of MonoDevelop or something.

Edited April 29, 2014 by a.g.

[Xty]

Do you have any stupid antivirus firewalls or anything active? I have no idea otherwise.

Nope, I do not have any antivirus or firewall, other than the built in windows firewall.

[technogeeky]

The 0.24 update includes different versions of libmono.dll and also includes 64-bit versions of them. The current ones distributed with ksp-devtools are incompatible with the 0.24 executables.

Also, if you're on Linux (like me), you'll want to compile a 64-bit version of load-fork.so.

I have made some of these changes, but I never actually built libmono.dll myself. I'll have to go through that process. It seems to involve grabbing a more recent version of Unity's fork of mono, a newer version of mono-tools, and building them.

The other outstanding problem I have identified is that MonoDevelop 5 (5.1 actually) doesn't seem to behave the same with regard to the Listen step of the debugger. The result of pressing either Connect or Listen is the same -- it goes straight to Application Output, and it never pops up a dialogue that indicates it's waiting for the process to connect.

Any help in either of these two directions would be greatly appreciated.

[m4v]

The other outstanding problem I have identified is that MonoDevelop 5 (5.1 actually) doesn't seem to behave the same with regard to the Listen step of the debugger. The result of pressing either Connect or Listen is the same -- it goes straight to Application Output, and it never pops up a dialogue that indicates it's waiting for the process to connect.

Any help in either of these two directions would be greatly appreciated.

Monodevelop 5 works for me, there's no dialog but is indeed waiting for the process to connect, after everything runs breakpoints work. Still using 0.23.5 for debugging though.

Edited August 16, 2014 by m4v
fixed a wrong statement.

[Cyrik]

is there any chance of getting a version that works with .24?

all i am getting is a "Failled to load mono" error and im not smart enough to compile it myself:(

[a.g.]

So I've recompiled the libraries for Unity 4.5 and briefly tested debugging on linux, but windows is completely untested. The binaries and sources are on github.