2 * profiler.c: Profiler interface for Mono
5 * Paolo Molaro (lupus@ximian.com)
7 * (C) 2001-2003 Ximian, Inc.
8 * (C) 2003-2006 Novell, Inc.
12 #include "mono/metadata/profiler-private.h"
13 #include "mono/metadata/debug-helpers.h"
14 #include "mono/metadata/mono-debug.h"
15 #include "mono/metadata/debug-mono-symfile.h"
16 #include "mono/metadata/metadata-internals.h"
17 #include "mono/metadata/class-internals.h"
18 #include "mono/metadata/domain-internals.h"
19 #include "mono/metadata/gc-internal.h"
20 #include "mono/io-layer/io-layer.h"
21 #include "mono/utils/mono-dl.h"
25 #ifdef HAVE_BACKTRACE_SYMBOLS
29 static MonoProfiler
* current_profiler
= NULL
;
31 static MonoProfileAppDomainFunc domain_start_load
;
32 static MonoProfileAppDomainResult domain_end_load
;
33 static MonoProfileAppDomainFunc domain_start_unload
;
34 static MonoProfileAppDomainFunc domain_end_unload
;
36 static MonoProfileAssemblyFunc assembly_start_load
;
37 static MonoProfileAssemblyResult assembly_end_load
;
38 static MonoProfileAssemblyFunc assembly_start_unload
;
39 static MonoProfileAssemblyFunc assembly_end_unload
;
41 static MonoProfileModuleFunc module_start_load
;
42 static MonoProfileModuleResult module_end_load
;
43 static MonoProfileModuleFunc module_start_unload
;
44 static MonoProfileModuleFunc module_end_unload
;
46 static MonoProfileClassFunc class_start_load
;
47 static MonoProfileClassResult class_end_load
;
48 static MonoProfileClassFunc class_start_unload
;
49 static MonoProfileClassFunc class_end_unload
;
51 static MonoProfileMethodFunc jit_start
;
52 static MonoProfileMethodResult jit_end
;
53 static MonoProfileJitResult jit_end2
;
54 static MonoProfileMethodResult man_unman_transition
;
55 static MonoProfileAllocFunc allocation_cb
;
56 static MonoProfileStatFunc statistical_cb
;
57 static MonoProfileMethodFunc method_enter
;
58 static MonoProfileMethodFunc method_leave
;
60 static MonoProfileThreadFunc thread_start
;
61 static MonoProfileThreadFunc thread_end
;
63 static MonoProfileCoverageFilterFunc coverage_filter_cb
;
65 static MonoProfileFunc shutdown_callback
;
67 static MonoProfileGCFunc gc_event
;
68 static MonoProfileGCResizeFunc gc_heap_resize
;
70 #define mono_profiler_coverage_lock() EnterCriticalSection (&profiler_coverage_mutex)
71 #define mono_profiler_coverage_unlock() LeaveCriticalSection (&profiler_coverage_mutex)
72 static CRITICAL_SECTION profiler_coverage_mutex
;
74 /* this is directly accessible to other mono libs. */
75 MonoProfileFlags mono_profiler_events
;
78 * mono_profiler_install:
79 * @prof: a MonoProfiler structure pointer, or a pointer to a derived structure.
80 * @callback: the function to invoke at shutdown
82 * Use mono_profiler_install to activate profiling in the Mono runtime.
83 * Typically developers of new profilers will create a new structure whose
84 * first field is a MonoProfiler and put any extra information that they need
85 * to access from the various profiling callbacks there.
89 mono_profiler_install (MonoProfiler
*prof
, MonoProfileFunc callback
)
92 g_error ("profiler already setup");
93 current_profiler
= prof
;
94 shutdown_callback
= callback
;
95 InitializeCriticalSection (&profiler_coverage_mutex
);
99 * mono_profiler_set_events:
100 * @events: an ORed set of values made up of MONO_PROFILER_ flags
102 * The events descriped in the @events argument is a set of flags
103 * that represent which profiling events must be triggered. For
104 * example if you have registered a set of methods for tracking
105 * JIT compilation start and end with mono_profiler_install_jit_compile,
106 * you will want to pass the MONO_PROFILE_JIT_COMPILATION flag to
109 * You can call mono_profile_set_events more than once and you can
110 * do this at runtime to modify which methods are invoked.
113 mono_profiler_set_events (MonoProfileFlags events
)
115 mono_profiler_events
= events
;
119 * mono_profiler_get_events:
121 * Returns a list of active events that will be intercepted.
124 mono_profiler_get_events (void)
126 return mono_profiler_events
;
130 * mono_profiler_install_enter_leave:
131 * @enter: the routine to be called on each method entry
132 * @fleave: the routine to be called each time a method returns
134 * Use this routine to install routines that will be called everytime
135 * a method enters and leaves. The routines will receive as an argument
136 * the MonoMethod representing the method that is entering or leaving.
139 mono_profiler_install_enter_leave (MonoProfileMethodFunc enter
, MonoProfileMethodFunc fleave
)
141 method_enter
= enter
;
142 method_leave
= fleave
;
146 * mono_profiler_install_jit_compile:
147 * @start: the routine to be called when the JIT process starts.
148 * @end: the routine to be called when the JIT process ends.
150 * Use this routine to install routines that will be called when JIT
151 * compilation of a method starts and completes.
154 mono_profiler_install_jit_compile (MonoProfileMethodFunc start
, MonoProfileMethodResult end
)
161 mono_profiler_install_jit_end (MonoProfileJitResult end
)
167 mono_profiler_install_thread (MonoProfileThreadFunc start
, MonoProfileThreadFunc end
)
169 thread_start
= start
;
174 mono_profiler_install_transition (MonoProfileMethodResult callback
)
176 man_unman_transition
= callback
;
180 mono_profiler_install_allocation (MonoProfileAllocFunc callback
)
182 allocation_cb
= callback
;
186 mono_profiler_install_statistical (MonoProfileStatFunc callback
)
188 statistical_cb
= callback
;
192 mono_profiler_install_coverage_filter (MonoProfileCoverageFilterFunc callback
)
194 coverage_filter_cb
= callback
;
198 mono_profiler_install_appdomain (MonoProfileAppDomainFunc start_load
, MonoProfileAppDomainResult end_load
,
199 MonoProfileAppDomainFunc start_unload
, MonoProfileAppDomainFunc end_unload
)
202 domain_start_load
= start_load
;
203 domain_end_load
= end_load
;
204 domain_start_unload
= start_unload
;
205 domain_end_unload
= end_unload
;
209 mono_profiler_install_assembly (MonoProfileAssemblyFunc start_load
, MonoProfileAssemblyResult end_load
,
210 MonoProfileAssemblyFunc start_unload
, MonoProfileAssemblyFunc end_unload
)
212 assembly_start_load
= start_load
;
213 assembly_end_load
= end_load
;
214 assembly_start_unload
= start_unload
;
215 assembly_end_unload
= end_unload
;
219 mono_profiler_install_module (MonoProfileModuleFunc start_load
, MonoProfileModuleResult end_load
,
220 MonoProfileModuleFunc start_unload
, MonoProfileModuleFunc end_unload
)
222 module_start_load
= start_load
;
223 module_end_load
= end_load
;
224 module_start_unload
= start_unload
;
225 module_end_unload
= end_unload
;
229 mono_profiler_install_class (MonoProfileClassFunc start_load
, MonoProfileClassResult end_load
,
230 MonoProfileClassFunc start_unload
, MonoProfileClassFunc end_unload
)
232 class_start_load
= start_load
;
233 class_end_load
= end_load
;
234 class_start_unload
= start_unload
;
235 class_end_unload
= end_unload
;
239 mono_profiler_method_enter (MonoMethod
*method
)
241 if ((mono_profiler_events
& MONO_PROFILE_ENTER_LEAVE
) && method_enter
)
242 method_enter (current_profiler
, method
);
246 mono_profiler_method_leave (MonoMethod
*method
)
248 if ((mono_profiler_events
& MONO_PROFILE_ENTER_LEAVE
) && method_leave
)
249 method_leave (current_profiler
, method
);
253 mono_profiler_method_jit (MonoMethod
*method
)
255 if ((mono_profiler_events
& MONO_PROFILE_JIT_COMPILATION
) && jit_start
)
256 jit_start (current_profiler
, method
);
260 mono_profiler_method_end_jit (MonoMethod
*method
, MonoJitInfo
* jinfo
, int result
)
262 if ((mono_profiler_events
& MONO_PROFILE_JIT_COMPILATION
)) {
264 jit_end (current_profiler
, method
, result
);
266 jit_end2 (current_profiler
, method
, jinfo
, result
);
271 mono_profiler_code_transition (MonoMethod
*method
, int result
)
273 if ((mono_profiler_events
& MONO_PROFILE_TRANSITIONS
) && man_unman_transition
)
274 man_unman_transition (current_profiler
, method
, result
);
278 mono_profiler_allocation (MonoObject
*obj
, MonoClass
*klass
)
280 if ((mono_profiler_events
& MONO_PROFILE_ALLOCATIONS
) && allocation_cb
)
281 allocation_cb (current_profiler
, obj
, klass
);
285 mono_profiler_stat_hit (guchar
*ip
, void *context
)
287 if ((mono_profiler_events
& MONO_PROFILE_STATISTICAL
) && statistical_cb
)
288 statistical_cb (current_profiler
, ip
, context
);
292 mono_profiler_thread_start (gsize tid
)
294 if ((mono_profiler_events
& MONO_PROFILE_THREADS
) && thread_start
)
295 thread_start (current_profiler
, tid
);
299 mono_profiler_thread_end (gsize tid
)
301 if ((mono_profiler_events
& MONO_PROFILE_THREADS
) && thread_end
)
302 thread_end (current_profiler
, tid
);
306 mono_profiler_assembly_event (MonoAssembly
*assembly
, int code
)
308 if (!(mono_profiler_events
& MONO_PROFILE_ASSEMBLY_EVENTS
))
312 case MONO_PROFILE_START_LOAD
:
313 if (assembly_start_load
)
314 assembly_start_load (current_profiler
, assembly
);
316 case MONO_PROFILE_START_UNLOAD
:
317 if (assembly_start_unload
)
318 assembly_start_unload (current_profiler
, assembly
);
320 case MONO_PROFILE_END_UNLOAD
:
321 if (assembly_end_unload
)
322 assembly_end_unload (current_profiler
, assembly
);
325 g_assert_not_reached ();
330 mono_profiler_assembly_loaded (MonoAssembly
*assembly
, int result
)
332 if ((mono_profiler_events
& MONO_PROFILE_ASSEMBLY_EVENTS
) && assembly_end_load
)
333 assembly_end_load (current_profiler
, assembly
, result
);
337 mono_profiler_module_event (MonoImage
*module
, int code
)
339 if (!(mono_profiler_events
& MONO_PROFILE_MODULE_EVENTS
))
343 case MONO_PROFILE_START_LOAD
:
344 if (module_start_load
)
345 module_start_load (current_profiler
, module
);
347 case MONO_PROFILE_START_UNLOAD
:
348 if (module_start_unload
)
349 module_start_unload (current_profiler
, module
);
351 case MONO_PROFILE_END_UNLOAD
:
352 if (module_end_unload
)
353 module_end_unload (current_profiler
, module
);
356 g_assert_not_reached ();
361 mono_profiler_module_loaded (MonoImage
*module
, int result
)
363 if ((mono_profiler_events
& MONO_PROFILE_MODULE_EVENTS
) && module_end_load
)
364 module_end_load (current_profiler
, module
, result
);
368 mono_profiler_class_event (MonoClass
*klass
, int code
)
370 if (!(mono_profiler_events
& MONO_PROFILE_CLASS_EVENTS
))
374 case MONO_PROFILE_START_LOAD
:
375 if (class_start_load
)
376 class_start_load (current_profiler
, klass
);
378 case MONO_PROFILE_START_UNLOAD
:
379 if (class_start_unload
)
380 class_start_unload (current_profiler
, klass
);
382 case MONO_PROFILE_END_UNLOAD
:
383 if (class_end_unload
)
384 class_end_unload (current_profiler
, klass
);
387 g_assert_not_reached ();
392 mono_profiler_class_loaded (MonoClass
*klass
, int result
)
394 if ((mono_profiler_events
& MONO_PROFILE_CLASS_EVENTS
) && class_end_load
)
395 class_end_load (current_profiler
, klass
, result
);
399 mono_profiler_appdomain_event (MonoDomain
*domain
, int code
)
401 if (!(mono_profiler_events
& MONO_PROFILE_APPDOMAIN_EVENTS
))
405 case MONO_PROFILE_START_LOAD
:
406 if (domain_start_load
)
407 domain_start_load (current_profiler
, domain
);
409 case MONO_PROFILE_START_UNLOAD
:
410 if (domain_start_unload
)
411 domain_start_unload (current_profiler
, domain
);
413 case MONO_PROFILE_END_UNLOAD
:
414 if (domain_end_unload
)
415 domain_end_unload (current_profiler
, domain
);
418 g_assert_not_reached ();
423 mono_profiler_appdomain_loaded (MonoDomain
*domain
, int result
)
425 if ((mono_profiler_events
& MONO_PROFILE_APPDOMAIN_EVENTS
) && domain_end_load
)
426 domain_end_load (current_profiler
, domain
, result
);
430 mono_profiler_shutdown (void)
432 if (current_profiler
&& shutdown_callback
)
433 shutdown_callback (current_profiler
);
437 mono_profiler_gc_heap_resize (gint64 new_size
)
439 if ((mono_profiler_events
& MONO_PROFILE_GC
) && gc_heap_resize
)
440 gc_heap_resize (current_profiler
, new_size
);
444 mono_profiler_gc_event (MonoGCEvent event
, int generation
)
446 if ((mono_profiler_events
& MONO_PROFILE_GC
) && gc_event
)
447 gc_event (current_profiler
, event
, generation
);
451 mono_profiler_install_gc (MonoProfileGCFunc callback
, MonoProfileGCResizeFunc heap_resize_callback
)
453 mono_gc_enable_events ();
455 gc_heap_resize
= heap_resize_callback
;
458 static GHashTable
*coverage_hash
= NULL
;
460 MonoProfileCoverageInfo
*
461 mono_profiler_coverage_alloc (MonoMethod
*method
, int entries
)
463 MonoProfileCoverageInfo
*res
;
465 if (coverage_filter_cb
)
466 if (! (*coverage_filter_cb
) (current_profiler
, method
))
469 mono_profiler_coverage_lock ();
471 coverage_hash
= g_hash_table_new (NULL
, NULL
);
473 res
= g_malloc0 (sizeof (MonoProfileCoverageInfo
) + sizeof (void*) * 2 * entries
);
475 res
->entries
= entries
;
477 g_hash_table_insert (coverage_hash
, method
, res
);
478 mono_profiler_coverage_unlock ();
483 /* safe only when the method antive code has been unloaded */
485 mono_profiler_coverage_free (MonoMethod
*method
)
487 MonoProfileCoverageInfo
* info
;
489 mono_profiler_coverage_lock ();
490 if (!coverage_hash
) {
491 mono_profiler_coverage_unlock ();
495 info
= g_hash_table_lookup (coverage_hash
, method
);
498 g_hash_table_remove (coverage_hash
, method
);
500 mono_profiler_coverage_unlock ();
504 * mono_profiler_coverage_get:
505 * @prof: The profiler handle, installed with mono_profiler_install
506 * @method: the method to gather information from.
507 * @func: A routine that will be called back with the results
509 * If the MONO_PROFILER_INS_COVERAGE flag was active during JIT compilation
510 * it is posisble to obtain coverage information about a give method.
512 * The function @func will be invoked repeatedly with instances of the
513 * MonoProfileCoverageEntry structure.
516 mono_profiler_coverage_get (MonoProfiler
*prof
, MonoMethod
*method
, MonoProfileCoverageFunc func
)
518 MonoProfileCoverageInfo
* info
;
521 const unsigned char *start
, *end
, *cil_code
;
522 MonoMethodHeader
*header
;
523 MonoProfileCoverageEntry entry
;
524 MonoDebugMethodInfo
*debug_minfo
;
526 mono_profiler_coverage_lock ();
527 info
= g_hash_table_lookup (coverage_hash
, method
);
528 mono_profiler_coverage_unlock ();
533 header
= mono_method_get_header (method
);
534 start
= mono_method_header_get_code (header
, &code_size
, NULL
);
535 debug_minfo
= mono_debug_lookup_method (method
);
537 end
= start
+ code_size
;
538 for (i
= 0; i
< info
->entries
; ++i
) {
539 cil_code
= info
->data
[i
].cil_code
;
540 if (cil_code
&& cil_code
>= start
&& cil_code
< end
) {
542 offset
= cil_code
- start
;
543 entry
.iloffset
= offset
;
544 entry
.method
= method
;
545 entry
.counter
= info
->data
[i
].count
;
546 entry
.line
= entry
.col
= 1;
547 entry
.filename
= NULL
;
549 MonoDebugSourceLocation
*location
;
551 location
= mono_debug_symfile_lookup_location (debug_minfo
, offset
);
553 entry
.line
= location
->row
;
554 entry
.col
= location
->column
;
555 entry
.filename
= fname
= g_strdup (location
->source_file
);
556 mono_debug_free_source_location (location
);
566 #ifndef DISABLE_PROFILER
568 * Small profiler extracted from mint: we should move it in a loadable module
569 * and improve it to do graphs and more accurate timestamping with rdtsc.
572 static FILE* poutput
= NULL
;
575 #define USE_WIN32COUNTER 0
579 unsigned int lows
, highs
, lowe
, highe
;
582 #define rdtsc(low,high) \
583 __asm__ __volatile__("rdtsc" : "=a" (low), "=d" (high))
588 rdtsc_elapsed (MonoRdtscTimer
*t
)
590 unsigned long long diff
;
591 unsigned int highe
= t
->highe
;
592 if (t
->lowe
< t
->lows
)
594 diff
= (((unsigned long long) highe
- t
->highs
) << 32) + (t
->lowe
- t
->lows
);
595 return ((double)diff
/ freq
) / 1000000; /* have to return the result in seconds */
606 if (!(cpuinfo
= fopen ("/proc/cpuinfo", "r")))
608 while (fgets (buf
, sizeof(buf
), cpuinfo
)) {
609 if (sscanf (buf
, "cpu MHz : %f", &val
) == 1) {
610 /*printf ("got mh: %f\n", val);*/
613 if (strncmp (buf
, "flags", 5) == 0) {
614 if (strstr (buf
, "tsc")) {
616 /*printf ("have tsc\n");*/
621 return have_flag
? have_freq
: 0;
624 #define MONO_TIMER_STARTUP \
625 if (!(freq = have_rdtsc ())) g_error ("Compiled with TSC support, but none found");
626 #define MONO_TIMER_TYPE MonoRdtscTimer
627 #define MONO_TIMER_INIT(t)
628 #define MONO_TIMER_DESTROY(t)
629 #define MONO_TIMER_START(t) rdtsc ((t).lows, (t).highs);
630 #define MONO_TIMER_STOP(t) rdtsc ((t).lowe, (t).highe);
631 #define MONO_TIMER_ELAPSED(t) rdtsc_elapsed (&(t))
633 #elif USE_WIN32COUNTER
637 LARGE_INTEGER start
, stop
;
643 win32_elapsed (MonoWin32Timer
*t
)
645 LONGLONG diff
= t
->stop
.QuadPart
- t
->start
.QuadPart
;
646 return ((double)diff
/ freq
) / 1000000; /* have to return the result in seconds */
650 have_win32counter (void) {
653 if (!QueryPerformanceFrequency (&f
))
658 #define MONO_TIMER_STARTUP \
659 if (!(freq = have_win32counter ())) g_error ("Compiled with Win32 counter support, but none found");
660 #define MONO_TIMER_TYPE MonoWin32Timer
661 #define MONO_TIMER_INIT(t)
662 #define MONO_TIMER_DESTROY(t)
663 #define MONO_TIMER_START(t) QueryPerformanceCounter (&(t).start)
664 #define MONO_TIMER_STOP(t) QueryPerformanceCounter (&(t).stop)
665 #define MONO_TIMER_ELAPSED(t) win32_elapsed (&(t))
670 GTimeVal start
, stop
;
674 timeval_elapsed (MonoGLibTimer
*t
)
676 if (t
->start
.tv_usec
> t
->stop
.tv_usec
) {
677 t
->stop
.tv_usec
+= G_USEC_PER_SEC
;
680 return (t
->stop
.tv_sec
- t
->start
.tv_sec
)
681 + ((double)(t
->stop
.tv_usec
- t
->start
.tv_usec
))/ G_USEC_PER_SEC
;
684 #define MONO_TIMER_STARTUP
685 #define MONO_TIMER_TYPE MonoGLibTimer
686 #define MONO_TIMER_INIT(t)
687 #define MONO_TIMER_DESTROY(t)
688 #define MONO_TIMER_START(t) g_get_current_time (&(t).start)
689 #define MONO_TIMER_STOP(t) g_get_current_time (&(t).stop)
690 #define MONO_TIMER_ELAPSED(t) timeval_elapsed (&(t))
693 typedef struct _AllocInfo AllocInfo
;
694 typedef struct _CallerInfo CallerInfo
;
695 typedef struct _LastCallerInfo LastCallerInfo
;
697 struct _MonoProfiler
{
699 MonoMemPool
*mempool
;
700 /* info about JIT time */
701 MONO_TIMER_TYPE jit_timer
;
704 MonoMethod
*max_jit_method
;
709 /* chain of callers for the current thread */
710 LastCallerInfo
*callers
;
711 /* LastCallerInfo nodes for faster allocation */
712 LastCallerInfo
*cstorage
;
719 AllocInfo
*alloc_info
;
720 CallerInfo
*caller_info
;
723 typedef struct _MethodCallProfile MethodCallProfile
;
725 struct _MethodCallProfile
{
726 MethodCallProfile
*next
;
727 MONO_TIMER_TYPE timer
;
744 struct _LastCallerInfo
{
745 LastCallerInfo
*next
;
747 MONO_TIMER_TYPE timer
;
751 create_profiler (void)
753 MonoProfiler
*prof
= g_new0 (MonoProfiler
, 1);
755 prof
->methods
= g_hash_table_new (mono_aligned_addr_hash
, NULL
);
756 MONO_TIMER_INIT (prof
->jit_timer
);
757 prof
->mempool
= mono_mempool_new ();
762 #ifdef HAVE_KW_THREAD
763 static __thread MonoProfiler
* tls_profiler
;
764 # define GET_PROFILER() tls_profiler
765 # define SET_PROFILER(x) tls_profiler = (x)
766 # define ALLOC_PROFILER() /* nop */
768 static guint32 profiler_thread_id
= -1;
769 # define GET_PROFILER() ((MonoProfiler *)TlsGetValue (profiler_thread_id))
770 # define SET_PROFILER(x) TlsSetValue (profiler_thread_id, x);
771 # define ALLOC_PROFILER() profiler_thread_id = TlsAlloc ()
774 #define GET_THREAD_PROF(prof) do { \
775 MonoProfiler *_tprofiler = GET_PROFILER (); \
777 _tprofiler = create_profiler (); \
778 prof->per_thread = g_slist_prepend (prof->per_thread, _tprofiler); \
779 SET_PROFILER (_tprofiler); \
784 /* thread unsafe but faster variant */
785 #define GET_THREAD_PROF(prof)
789 compare_profile (MethodProfile
*profa
, MethodProfile
*profb
)
791 return (gint
)((profb
->total
- profa
->total
)*1000);
795 build_profile (MonoMethod
*m
, MethodProfile
*prof
, GList
**funcs
)
798 *funcs
= g_list_insert_sorted (*funcs
, prof
, (GCompareFunc
)compare_profile
);
802 method_get_name (MonoMethod
* method
)
806 sig
= mono_signature_get_desc (mono_method_signature (method
), FALSE
);
807 res
= g_strdup_printf ("%s%s%s::%s(%s)", method
->klass
->name_space
,
808 method
->klass
->name_space
? "." : "", method
->klass
->name
,
814 static void output_callers (MethodProfile
*p
);
816 /* This isn't defined on older glib versions and on some platforms */
817 #ifndef G_GUINT64_FORMAT
818 #define G_GUINT64_FORMAT "ul"
820 #ifndef G_GINT64_FORMAT
821 #define G_GINT64_FORMAT "lld"
825 output_profile (GList
*funcs
)
830 guint64 total_calls
= 0;
833 fprintf (poutput
, "Time(ms) Count P/call(ms) Method name\n");
834 for (tmp
= funcs
; tmp
; tmp
= tmp
->next
) {
836 total_calls
+= p
->count
;
837 if (!(gint
)(p
->total
*1000))
839 m
= method_get_name (p
->method
);
840 fprintf (poutput
, "########################\n");
841 fprintf (poutput
, "% 8.3f ", (double) (p
->total
* 1000));
842 fprintf (poutput
, "%7" G_GUINT64_FORMAT
" ", (unsigned long long)p
->count
);
843 fprintf (poutput
, "% 8.3f ", (double) (p
->total
* 1000)/(double)p
->count
);
844 fprintf (poutput
, " %s\n", m
);
850 fprintf (poutput
, "Total number of calls: %" G_GINT64_FORMAT
"\n", (long long)total_calls
);
859 compare_newobj_profile (NewobjProfile
*profa
, NewobjProfile
*profb
)
861 if (profb
->count
== profa
->count
)
864 return profb
->count
> profa
->count
? 1 : -1;
868 build_newobj_profile (MonoClass
*class, MethodProfile
*mprof
, GList
**funcs
)
870 NewobjProfile
*prof
= g_new (NewobjProfile
, 1);
875 /* we use the total amount of memory to sort */
876 for (tmp
= mprof
->alloc_info
; tmp
; tmp
= tmp
->next
)
879 *funcs
= g_list_insert_sorted (*funcs
, prof
, (GCompareFunc
)compare_newobj_profile
);
883 compare_caller (CallerInfo
*a
, CallerInfo
*b
)
885 return b
->count
- a
->count
;
889 compare_alloc (AllocInfo
*a
, AllocInfo
*b
)
891 return b
->mem
- a
->mem
;
895 sort_alloc_list (AllocInfo
*ai
)
899 for (tmp
= ai
; tmp
; tmp
= tmp
->next
) {
900 l
= g_slist_insert_sorted (l
, tmp
, (GCompareFunc
)compare_alloc
);
906 sort_caller_list (CallerInfo
*ai
)
910 for (tmp
= ai
; tmp
; tmp
= tmp
->next
) {
911 l
= g_slist_insert_sorted (l
, tmp
, (GCompareFunc
)compare_caller
);
917 output_callers (MethodProfile
*p
) {
918 guint total_callers
, percent
;
919 GSList
*sorted
, *tmps
;
923 fprintf (poutput
, " Callers (with count) that contribute at least for 1%%:\n");
925 for (cinfo
= p
->caller_info
; cinfo
; cinfo
= cinfo
->next
) {
926 total_callers
+= cinfo
->count
;
928 sorted
= sort_caller_list (p
->caller_info
);
929 for (tmps
= sorted
; tmps
; tmps
= tmps
->next
) {
931 percent
= (cinfo
->count
* 100)/total_callers
;
934 m
= method_get_name (cinfo
->caller
);
935 fprintf (poutput
, " %8d % 3d %% %s\n", cinfo
->count
, percent
, m
);
941 output_newobj_profile (GList
*proflist
)
952 GSList
*sorted
, *tmps
;
954 fprintf (poutput
, "\nAllocation profiler\n");
957 fprintf (poutput
, "%-9s %s\n", "Total mem", "Method");
958 for (tmp
= proflist
; tmp
; tmp
= tmp
->next
) {
961 if (p
->count
< 50000)
964 m
= method_get_name (mp
->method
);
965 fprintf (poutput
, "########################\n%8" G_GUINT64_FORMAT
" KB %s\n", (p
->count
/ 1024), m
);
967 sorted
= sort_alloc_list (mp
->alloc_info
);
968 for (tmps
= sorted
; tmps
; tmps
= tmps
->next
) {
970 if (ainfo
->mem
< 50000)
972 klass
= ainfo
->klass
;
975 klass
= klass
->element_class
;
979 g_snprintf (buf
, sizeof (buf
), "%s%s%s%s",
980 klass
->name_space
, klass
->name_space
? "." : "", klass
->name
, isarray
);
981 fprintf (poutput
, " %8" G_GUINT64_FORMAT
" KB %8" G_GUINT64_FORMAT
" %-48s\n", (ainfo
->mem
/ 1024), ainfo
->count
, buf
);
986 fprintf (poutput
, "Total memory allocated: %" G_GUINT64_FORMAT
" KB\n", total
/ 1024);
990 merge_methods (MonoMethod
*method
, MethodProfile
*profile
, MonoProfiler
*prof
)
992 MethodProfile
*mprof
;
993 AllocInfo
*talloc_info
, *alloc_info
;
994 CallerInfo
*tcaller_info
, *caller_info
;
996 mprof
= g_hash_table_lookup (prof
->methods
, method
);
998 /* the master thread didn't see this method, just transfer the info as is */
999 g_hash_table_insert (prof
->methods
, method
, profile
);
1002 /* merge the info from profile into mprof */
1003 mprof
->count
+= profile
->count
;
1004 mprof
->total
+= profile
->total
;
1005 /* merge alloc info */
1006 for (talloc_info
= profile
->alloc_info
; talloc_info
; talloc_info
= talloc_info
->next
) {
1007 for (alloc_info
= mprof
->alloc_info
; alloc_info
; alloc_info
= alloc_info
->next
) {
1008 if (alloc_info
->klass
== talloc_info
->klass
) {
1009 /* mprof already has a record for the klass, merge */
1010 alloc_info
->count
+= talloc_info
->count
;
1011 alloc_info
->mem
+= talloc_info
->mem
;
1016 /* mprof didn't have the info, just copy it over */
1017 alloc_info
= mono_mempool_alloc0 (prof
->mempool
, sizeof (AllocInfo
));
1018 *alloc_info
= *talloc_info
;
1019 alloc_info
->next
= mprof
->alloc_info
;
1020 mprof
->alloc_info
= alloc_info
->next
;
1023 /* merge callers info */
1024 for (tcaller_info
= profile
->caller_info
; tcaller_info
; tcaller_info
= tcaller_info
->next
) {
1025 for (caller_info
= mprof
->caller_info
; caller_info
; caller_info
= caller_info
->next
) {
1026 if (caller_info
->caller
== tcaller_info
->caller
) {
1027 /* mprof already has a record for the caller method, merge */
1028 caller_info
->count
+= tcaller_info
->count
;
1033 /* mprof didn't have the info, just copy it over */
1034 caller_info
= mono_mempool_alloc0 (prof
->mempool
, sizeof (CallerInfo
));
1035 *caller_info
= *tcaller_info
;
1036 caller_info
->next
= mprof
->caller_info
;
1037 mprof
->caller_info
= caller_info
;
1043 merge_thread_data (MonoProfiler
*master
, MonoProfiler
*tprof
)
1045 master
->jit_time
+= tprof
->jit_time
;
1046 master
->methods_jitted
+= tprof
->methods_jitted
;
1047 if (master
->max_jit_time
< tprof
->max_jit_time
) {
1048 master
->max_jit_time
= tprof
->max_jit_time
;
1049 master
->max_jit_method
= tprof
->max_jit_method
;
1052 g_hash_table_foreach (tprof
->methods
, (GHFunc
)merge_methods
, master
);
1056 simple_method_enter (MonoProfiler
*prof
, MonoMethod
*method
)
1058 MethodProfile
*profile_info
;
1059 LastCallerInfo
*callinfo
;
1060 GET_THREAD_PROF (prof
);
1061 /*g_print ("enter %p %s::%s in %d (%p)\n", method, method->klass->name, method->name, GetCurrentThreadId (), prof);*/
1062 if (!(profile_info
= g_hash_table_lookup (prof
->methods
, method
))) {
1063 profile_info
= mono_mempool_alloc0 (prof
->mempool
, sizeof (MethodProfile
));
1064 MONO_TIMER_INIT (profile_info
->u
.timer
);
1065 g_hash_table_insert (prof
->methods
, method
, profile_info
);
1067 profile_info
->count
++;
1068 if (prof
->callers
) {
1070 MonoMethod
*caller
= prof
->callers
->method
;
1071 for (cinfo
= profile_info
->caller_info
; cinfo
; cinfo
= cinfo
->next
) {
1072 if (cinfo
->caller
== caller
)
1076 cinfo
= mono_mempool_alloc0 (prof
->mempool
, sizeof (CallerInfo
));
1077 cinfo
->caller
= caller
;
1078 cinfo
->next
= profile_info
->caller_info
;
1079 profile_info
->caller_info
= cinfo
;
1083 if (!(callinfo
= prof
->cstorage
)) {
1084 callinfo
= mono_mempool_alloc (prof
->mempool
, sizeof (LastCallerInfo
));
1085 MONO_TIMER_INIT (callinfo
->timer
);
1087 prof
->cstorage
= prof
->cstorage
->next
;
1089 callinfo
->method
= method
;
1090 callinfo
->next
= prof
->callers
;
1091 prof
->callers
= callinfo
;
1092 MONO_TIMER_START (callinfo
->timer
);
1096 simple_method_leave (MonoProfiler
*prof
, MonoMethod
*method
)
1098 MethodProfile
*profile_info
;
1099 LastCallerInfo
*callinfo
, *newcallinfo
= NULL
;
1101 GET_THREAD_PROF (prof
);
1102 /*g_print ("leave %p %s::%s in %d (%p)\n", method, method->klass->name, method->name, GetCurrentThreadId (), prof);*/
1103 callinfo
= prof
->callers
;
1104 /* should really not happen, but we don't catch exceptions events, yet ... */
1106 MONO_TIMER_STOP (callinfo
->timer
);
1107 profile_info
= g_hash_table_lookup (prof
->methods
, callinfo
->method
);
1109 profile_info
->total
+= MONO_TIMER_ELAPSED (callinfo
->timer
);
1110 newcallinfo
= callinfo
->next
;
1111 callinfo
->next
= prof
->cstorage
;
1112 prof
->cstorage
= callinfo
;
1113 if (callinfo
->method
== method
)
1115 callinfo
= newcallinfo
;
1117 prof
->callers
= newcallinfo
;
1121 simple_allocation (MonoProfiler
*prof
, MonoObject
*obj
, MonoClass
*klass
)
1123 MethodProfile
*profile_info
;
1126 GET_THREAD_PROF (prof
);
1127 if (prof
->callers
) {
1128 MonoMethod
*caller
= prof
->callers
->method
;
1130 /* Otherwise all allocations are attributed to icall_wrapper_mono_object_new */
1131 if (caller
->wrapper_type
== MONO_WRAPPER_MANAGED_TO_NATIVE
)
1132 caller
= prof
->callers
->next
->method
;
1134 if (!(profile_info
= g_hash_table_lookup (prof
->methods
, caller
)))
1135 g_assert_not_reached ();
1137 return; /* fine for now */
1140 for (tmp
= profile_info
->alloc_info
; tmp
; tmp
= tmp
->next
) {
1141 if (tmp
->klass
== klass
)
1145 tmp
= mono_mempool_alloc0 (prof
->mempool
, sizeof (AllocInfo
));
1147 tmp
->next
= profile_info
->alloc_info
;
1148 profile_info
->alloc_info
= tmp
;
1151 tmp
->mem
+= mono_object_get_size (obj
);
1155 simple_method_jit (MonoProfiler
*prof
, MonoMethod
*method
)
1157 GET_THREAD_PROF (prof
);
1158 prof
->methods_jitted
++;
1159 MONO_TIMER_START (prof
->jit_timer
);
1163 simple_method_end_jit (MonoProfiler
*prof
, MonoMethod
*method
, int result
)
1166 GET_THREAD_PROF (prof
);
1167 MONO_TIMER_STOP (prof
->jit_timer
);
1168 jtime
= MONO_TIMER_ELAPSED (prof
->jit_timer
);
1169 prof
->jit_time
+= jtime
;
1170 if (jtime
> prof
->max_jit_time
) {
1171 prof
->max_jit_time
= jtime
;
1172 prof
->max_jit_method
= method
;
1176 /* about 10 minutes of samples */
1177 #define MAX_PROF_SAMPLES (1000*60*10)
1178 static int prof_counts
= 0;
1179 static int prof_ucounts
= 0;
1180 static gpointer
* prof_addresses
= NULL
;
1181 static GHashTable
*prof_table
= NULL
;
1184 simple_stat_hit (MonoProfiler
*prof
, guchar
*ip
, void *context
)
1188 if (prof_counts
>= MAX_PROF_SAMPLES
)
1190 pos
= InterlockedIncrement (&prof_counts
);
1191 prof_addresses
[pos
- 1] = ip
;
1195 compare_methods_prof (gconstpointer a
, gconstpointer b
)
1197 int ca
= GPOINTER_TO_UINT (g_hash_table_lookup (prof_table
, a
));
1198 int cb
= GPOINTER_TO_UINT (g_hash_table_lookup (prof_table
, b
));
1203 prof_foreach (char *method
, gpointer c
, gpointer data
)
1205 GList
**list
= data
;
1206 *list
= g_list_insert_sorted (*list
, method
, compare_methods_prof
);
1209 typedef struct Addr2LineData Addr2LineData
;
1211 struct Addr2LineData
{
1212 Addr2LineData
*next
;
1219 static Addr2LineData
*addr2line_pipes
= NULL
;
1222 try_addr2line (const char* binary
, gpointer ip
)
1226 Addr2LineData
*addr2line
;
1228 for (addr2line
= addr2line_pipes
; addr2line
; addr2line
= addr2line
->next
) {
1229 if (strcmp (binary
, addr2line
->binary
) == 0)
1233 const char *addr_argv
[] = {"addr2line", "-f", "-e", binary
, NULL
};
1237 char monobin
[1024];
1238 /* non-linux platforms will need different code here */
1239 if (strcmp (binary
, "mono") == 0) {
1240 int count
= readlink ("/proc/self/exe", monobin
, sizeof (monobin
));
1241 if (count
>= 0 && count
< sizeof (monobin
)) {
1242 monobin
[count
] = 0;
1243 addr_argv
[3] = monobin
;
1247 if (!g_spawn_async_with_pipes (NULL
, (char**)addr_argv
, NULL
, G_SPAWN_SEARCH_PATH
, NULL
, NULL
,
1248 &child_pid
, &ch_in
, &ch_out
, NULL
, NULL
)) {
1249 return g_strdup (binary
);
1251 addr2line
= g_new0 (Addr2LineData
, 1);
1252 addr2line
->child_pid
= child_pid
;
1253 addr2line
->binary
= g_strdup (binary
);
1254 addr2line
->pipein
= fdopen (ch_in
, "w");
1255 addr2line
->pipeout
= fdopen (ch_out
, "r");
1256 addr2line
->next
= addr2line_pipes
;
1257 addr2line_pipes
= addr2line
;
1259 fprintf (addr2line
->pipein
, "%p\n", ip
);
1260 fflush (addr2line
->pipein
);
1261 /* we first get the func name and then file:lineno in a second line */
1262 if (fgets (buf
, sizeof (buf
), addr2line
->pipeout
) && buf
[0] != '?') {
1263 char *end
= strchr (buf
, '\n');
1266 res
= g_strdup_printf ("%s(%s", binary
, buf
);
1267 /* discard the filename/line info */
1268 fgets (buf
, sizeof (buf
), addr2line
->pipeout
);
1270 res
= g_strdup (binary
);
1276 stat_prof_report (void)
1279 int count
= prof_counts
;
1283 GList
*tmp
, *sorted
= NULL
;
1284 int pcount
= ++ prof_counts
;
1286 prof_counts
= MAX_PROF_SAMPLES
;
1287 for (i
= 0; i
< count
; ++i
) {
1288 ip
= prof_addresses
[i
];
1289 ji
= mono_jit_info_table_find (mono_domain_get (), ip
);
1291 mn
= mono_method_full_name (ji
->method
, TRUE
);
1293 #ifdef HAVE_BACKTRACE_SYMBOLS
1298 names
= backtrace_symbols (&ip
, 1);
1299 send
= strchr (names
[0], '+');
1306 send
= strchr (names
[0], '[');
1309 if (no_func
&& names
[0][0]) {
1310 char *endp
= strchr (names
[0], 0);
1311 while (--endp
>= names
[0] && g_ascii_isspace (*endp
))
1313 mn
= try_addr2line (names
[0], ip
);
1315 mn
= g_strdup (names
[0]);
1320 mn
= g_strdup_printf ("unmanaged [%p]", ip
);
1323 c
= GPOINTER_TO_UINT (g_hash_table_lookup (prof_table
, mn
));
1325 g_hash_table_insert (prof_table
, mn
, GUINT_TO_POINTER (c
));
1329 fprintf (poutput
, "prof counts: total/unmanaged: %d/%d\n", pcount
, prof_ucounts
);
1330 g_hash_table_foreach (prof_table
, (GHFunc
)prof_foreach
, &sorted
);
1331 for (tmp
= sorted
; tmp
; tmp
= tmp
->next
) {
1333 c
= GPOINTER_TO_UINT (g_hash_table_lookup (prof_table
, tmp
->data
));
1334 perc
= c
*100.0/count
;
1335 fprintf (poutput
, "%7d\t%5.2f %% %s\n", c
, perc
, (char*)tmp
->data
);
1337 g_list_free (sorted
);
1341 simple_appdomain_unload (MonoProfiler
*prof
, MonoDomain
*domain
)
1343 /* FIXME: we should actually record partial data for each domain,
1344 * since the ip->ji->method mappings are going away at domain unload time.
1346 if (domain
== mono_get_root_domain ())
1347 stat_prof_report ();
1351 simple_shutdown (MonoProfiler
*prof
)
1353 GList
*profile
= NULL
;
1354 MonoProfiler
*tprof
;
1358 for (tmp
= prof
->per_thread
; tmp
; tmp
= tmp
->next
) {
1360 merge_thread_data (prof
, tprof
);
1363 fprintf (poutput
, "Total time spent compiling %d methods (sec): %.4g\n", prof
->methods_jitted
, prof
->jit_time
);
1364 if (prof
->max_jit_method
) {
1365 str
= method_get_name (prof
->max_jit_method
);
1366 fprintf (poutput
, "Slowest method to compile (sec): %.4g: %s\n", prof
->max_jit_time
, str
);
1369 g_hash_table_foreach (prof
->methods
, (GHFunc
)build_profile
, &profile
);
1370 output_profile (profile
);
1371 g_list_free (profile
);
1374 g_hash_table_foreach (prof
->methods
, (GHFunc
)build_newobj_profile
, &profile
);
1375 output_newobj_profile (profile
);
1376 g_list_free (profile
);
1378 g_free (prof_addresses
);
1379 prof_addresses
= NULL
;
1380 g_hash_table_destroy (prof_table
);
1384 mono_profiler_install_simple (const char *desc
)
1387 gchar
**args
, **ptr
;
1388 MonoProfileFlags flags
= 0;
1394 desc
= "alloc,time,jit";
1398 if (strstr (desc
, ":"))
1399 desc
= strstr (desc
, ":") + 1;
1401 desc
= "alloc,time,jit";
1402 args
= g_strsplit (desc
, ",", -1);
1404 for (ptr
= args
; ptr
&& *ptr
; ptr
++) {
1405 const char *arg
= *ptr
;
1407 if (!strcmp (arg
, "time"))
1408 flags
|= MONO_PROFILE_ENTER_LEAVE
;
1409 else if (!strcmp (arg
, "alloc"))
1410 flags
|= MONO_PROFILE_ALLOCATIONS
;
1411 else if (!strcmp (arg
, "stat"))
1412 flags
|= MONO_PROFILE_STATISTICAL
| MONO_PROFILE_APPDOMAIN_EVENTS
;
1413 else if (!strcmp (arg
, "jit"))
1414 flags
|= MONO_PROFILE_JIT_COMPILATION
;
1415 else if (strncmp (arg
, "file=", 5) == 0) {
1416 poutput
= fopen (arg
+ 5, "wb");
1419 fprintf (stderr
, "profiler : cannot open profile output file '%s'.\n", arg
+ 5);
1422 fprintf (stderr
, "profiler : Unknown argument '%s'.\n", arg
);
1427 if (flags
& MONO_PROFILE_ALLOCATIONS
)
1428 flags
|= MONO_PROFILE_ENTER_LEAVE
;
1430 flags
= MONO_PROFILE_ENTER_LEAVE
| MONO_PROFILE_ALLOCATIONS
| MONO_PROFILE_JIT_COMPILATION
;
1432 prof
= create_profiler ();
1434 SET_PROFILER (prof
);
1436 /* statistical profiler data */
1437 prof_addresses
= g_new0 (gpointer
, MAX_PROF_SAMPLES
);
1438 prof_table
= g_hash_table_new (g_str_hash
, g_str_equal
);
1440 mono_profiler_install (prof
, simple_shutdown
);
1441 mono_profiler_install_enter_leave (simple_method_enter
, simple_method_leave
);
1442 mono_profiler_install_jit_compile (simple_method_jit
, simple_method_end_jit
);
1443 mono_profiler_install_allocation (simple_allocation
);
1444 mono_profiler_install_appdomain (NULL
, NULL
, simple_appdomain_unload
, NULL
);
1445 mono_profiler_install_statistical (simple_stat_hit
);
1446 mono_profiler_set_events (flags
);
1449 #endif /* DISABLE_PROFILER */
1451 typedef void (*ProfilerInitializer
) (const char*);
1452 #define INITIALIZER_NAME "mono_profiler_startup"
1455 * mono_profiler_load:
1456 * @desc: arguments to configure the profiler
1458 * Invoke this method to initialize the profiler. This will drive the
1459 * loading of the internal ("default") or any external profilers.
1461 * This routine is invoked by Mono's driver, but must be called manually
1462 * if you embed Mono into your application.
1465 mono_profiler_load (const char *desc
)
1467 #ifndef DISABLE_PROFILER
1468 if (!desc
|| (strcmp ("default", desc
) == 0) || (strncmp (desc
, "default:", 8) == 0)) {
1469 mono_profiler_install_simple (desc
);
1479 const char* col
= strchr (desc
, ':');
1486 mname
= g_memdup (desc
, col
- desc
);
1487 mname
[col
- desc
] = 0;
1489 mname
= g_strdup (desc
);
1491 libname
= g_strdup_printf ("mono-profiler-%s", mname
);
1494 while ((path
= mono_dl_build_path (NULL
, libname
, &iter
))) {
1496 pmodule
= mono_dl_open (path
, MONO_DL_LAZY
, &err
);
1498 ProfilerInitializer func
;
1499 if ((err
= mono_dl_symbol (pmodule
, INITIALIZER_NAME
, (gpointer
*)&func
))) {
1500 g_warning ("Cannot find initializer function %s in profiler module: %s (%s)", INITIALIZER_NAME
, libname
, err
);
1511 g_warning ("Error loading profiler module '%s': %s", libname
, err
);