The logging profiler is the new profiler we are developing, which will eventually replace the current one.
It is called this way because it does not process the profiling events inside the running process printing the results at the end, but instead it logs them into a file, that can then be analyzed by a separate process (a sort of decoder tool).
The biggest advantages of this approach are:
- since the file is written incrementally, it is possible to examine partial results while the application is still running,
- the fact that the results are not directly displayed in "printed" form can facilitate the creation of GUI front-ends (think Monodevelop integration),
- this flexibility could also be used to output the data in different ways (like in plain CSV to import in a spreadsheet, which is typical when one wants to then present the results),
- most important, the current profiler has a technical limitation: it stores the data in memory until the end of the process, and these data still reference the internal Mono metadata, so it cannot work if the relevant application domain is unloaded (the new profiler will simply trigger a file write just before the appdomain unload, and continue working).
This new profiler is now usable and installed by default on Linux (current svn), and is activated running mono with the "--profile=logging" argument. To obtain the file decoder, you should check out the Mono.Profiler svn module:
svn co svn://anonsvn.mono-project.com/source/trunk/mono-tools/Mono.Profiler
and then do one of the following:
- load the Monodevelop solution and build it, or
- try the supplied configure and makefile scripts (autogenerated by Monodevelop), or
- as a last and quick resort, just run the "compile" script.
The decoder program will analyze the file and print the data it finds inside. To control what kind of profiling is done, you should pass options to the profiler when you start the profiled application, with the syntax "--profile=logging:option1,option2,option3...". Some of the options require a value (they take the form "option=value"), and most options have also abbreviated forms.
As a quick primer, here are a few examples:
- mono --profile=logging:s program.exe to use the statistical profiler,
- mono --profile=logging:c,a program.exe to profile method enter-exit and allocations,
- and mono --profile=logging:c,j,o=mydata.mprof program.exe to profile method enter-exit and jit time, and write the data to "mydata.mprof".
Then you would need to invoke the decoder on "mydata.mprof" to see the profiling results.
Here is the full list of the available options:
Output file name
- "output" (or "out" or "o", default "o=profiler-log.prof"): the name of the output file.
Profiling flags
- "jit" (or "j"): collect information about time spent jitting methods.
- "allocations" (or "alloc" or "a"): collect information about each allocation (object class and size).
- "enter-leave" (or "calls" or "c"): measure the time spent inside each method call.
- "statistical" (or "stat" or "s"): do statistical profiling.
Heap profiling control
With this kind of profiling the profiler keeps track of the full heap contents, so that at each collection it can examine it and dump the required data. Since the dumps can be large (especially in the case of heap snapshots), it is possible to control how many of them are actually written to disk. The profiler keeps a counter, called "gc-dumps", which states the number of dumps that must be saved. When a collection takes place, if the counter is greater than zero, the information is written and the counter is decremented. If the counter is zero no information is written (a and the counter stays zero). On the other hand, if the counter is less than zero, at every collection the information is written. The counter value can be given to the profiler in two ways:
- with an argument at application start up, or
- written in a "control file".
The argument, of course, has effect only at application start, so "0" means "never dump", "-1" means "always dump", and a positive value "n" means "dump the next n collections and then nothing". The control file, on the other hand, must contain the value in ASCII form, and it is examined just before each collection to read the counter value. It works this way: it is read at the first collection, and then it is re-read if it has been modified since the last read. So, for instance, an easy way to say "dump at the next collection, and then never" would be to write "1" into the control file, and "touch" it every time we want to have a dump (at the next collection). We are also preparing a way to trigger a garbage collection explicitly using a signal, just like heap-shot used to do.
So, here are the available options:
- "unreachable" (or "free" or "f"): enable garbage collection profiling in its lightweight form (at each collection, the list if unreachable objects is dumped, and for each object the class and size is provided, which together with the basic allocation information allows to compute the heap size broken down by class).
- "heap-shot" (or "heap" or "h"): enable full heap profiling, in this case at each collection a full heap snapshot is dumped to disk.
- "gc-commands" (or "gc-c" or "gcc", default none, file name required): the name of the file that controls the heap snapshot dumps.
- "gc-dumps" (or "gc-d" or "gcd", default "gcd=0"): the initial number of heap snapshots to dump (if the control file is not used).
Buffer sizes
Most of the time you will never use these options...
- "per-thread-buffer-size" (or "tbs", default "tbs=10000"): the number of events that a thread buffer can hold, when it's full it is written to disk (the writing thread is the one that filled its buffer).
- "statistical-thread-buffer-size" (or "sbs", default "sbs=10000"): the number of statistical samples that are hold in memory before they are dumped to disk (the system does double-buffering and the statistical samples are written by a helper thread).
- "write-buffer-size" (or "wbs", default "wbs=1024"): size in bytes of the internal write buffers.


