[Mono-dev] Debugging suggestion requested

[James P Michels III]

I am trying to learn more about a problem that I am having with
monodevelop and I need some guidance.

Symptoms: Monodevelop frequently exhibits a behavior where it pins one
of my CPU's indefinitely. This often occurs at startup and after
operations such as compiling. This can not be explained by the
operations described as the CPU will remain pinned forever, unless I
apply a simple workaround.

Workaround: When I observe that the problem is expressing itself, I
simply need to switch a tab in any GUI element to stop the CPU from
spinning.

Troubleshoot Attempt 1: I had asked around about this problem and the
first suggestion that I received was to kill -QUIT the process and
observe the stack trace to see what function could be the culprit. Have
done this, there was nothing that jumped out as likely cause.

Troubleshoot Attempt 2: I ran monodevelop with the --profile=logging:c
option and observed the results with the expectation that the
responsible function would be amoung the top time consumers. A sample of
the output is provided below.

Troubleshoot Attempt 3: Looking at the logging output left me somewhat
confused. I expected to see 100% of the time accounted for. Adding up
all of the log entries does not equal 100% as far as I can tell.
However, seeing that 39 calls to System.IO.InotifyWatcher.ReadFromFD did
explain the wall clock time I remembered, I assumed this function must
be involved somehow. I modified the source code for this section to
effectively NOOP and Thread.Sleep(1). Even if the code still spun here,
Thread.Sleep(1) should have prevented it from pinning the CPU. Assuming
that the pinning stopped with the modified code, I would be confident
that I has identified the problem area for futher investigation. After
building the modified code, the problem remained.

Plea for help! Having ruled out System.IO.InotifyWatcher.ReadFromFD as
the cause of the spinning, I am confused as to how I can gather useful
information about the CPU consumption. It didn't logically make sense
that System.IO.InotifyWatcher.ReadFromFD was the cause as it would not
explain how interacting with the GUI could positively impact the
situation, but this is where the profiler lead me. I know how to do this
on Windows, but clearly I am missing something crucial to understanding
this on Linux. (BTW, I am using Ubuntu 9.04 amd64).

Any suggestions? My goal here is to learn more about Linux as well as to
troubleshoot this problem. Am I using the wrong tools?

Thanks
Jim

---------------- begin mprof-decode output --------------

ERROR: DecodingException in block of code 0, length 0, file offset
202162125, block offset 0: unknown block code 0
  at
Mono.Profiler.BlockData.Decode[LoadedClass,LoadedMethod,UnmanagedFunctionFromRegion,UnmanagedFunctionFromID,ExecutableMemoryRegion,LoadedElementHandler`7,HeapObject,HeapSnapshot]
(IProfilerEventHandler`8 handler) [0x00000]
Attempting to decode data printing block contents...
Current block of type 0 (file offset 202162125, length 0)
While attempting decoding, got exception unknown block code 0

Stopping decoding after a DecodingException in block of code 0, length
0, file offset 202162125, block offset 0: unknown block code 0
No allocations reported (on 7024 classes)


------------------------------------------------
Reporting execution time (on 8822 methods)
37.68% (36.896543s) System.IO.InotifyWatcher.ReadFromFD
(intptr,byte[],intptr)
        39 calls from System.IO.InotifyWatcher.Monitor ()
 1.92% (1.878966s) Gtk.Widget.exposeevent_cb (intptr,intptr)
        17 calls from
Gtk.Container.gtksharp_container_invoke_gtk_callback (intptr,intptr,intptr)
        10 calls from Gtk.Application.gtk_main_iteration_do (bool)
        9 calls from Gtk.Container.gtk_container_propagate_expose
(intptr,intptr,intptr)
 1.92% (1.878947s) Gtk.Widget.exposeevent_cb (intptr,intptr)
        59 calls from Gtk.Widget.exposeevent_cb (intptr,intptr)

<remainder not show for brevity>

---------------- end mprof-decode output --------------