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"
26 #ifdef HAVE_SYS_TIME_H
29 #ifdef HAVE_BACKTRACE_SYMBOLS
33 static MonoProfiler * current_profiler = NULL;
35 static MonoProfileAppDomainFunc domain_start_load;
36 static MonoProfileAppDomainResult domain_end_load;
37 static MonoProfileAppDomainFunc domain_start_unload;
38 static MonoProfileAppDomainFunc domain_end_unload;
40 static MonoProfileAssemblyFunc assembly_start_load;
41 static MonoProfileAssemblyResult assembly_end_load;
42 static MonoProfileAssemblyFunc assembly_start_unload;
43 static MonoProfileAssemblyFunc assembly_end_unload;
45 static MonoProfileModuleFunc module_start_load;
46 static MonoProfileModuleResult module_end_load;
47 static MonoProfileModuleFunc module_start_unload;
48 static MonoProfileModuleFunc module_end_unload;
50 static MonoProfileClassFunc class_start_load;
51 static MonoProfileClassResult class_end_load;
52 static MonoProfileClassFunc class_start_unload;
53 static MonoProfileClassFunc class_end_unload;
55 static MonoProfileMethodFunc jit_start;
56 static MonoProfileMethodResult jit_end;
57 static MonoProfileJitResult jit_end2;
58 static MonoProfileMethodFunc method_free;
59 static MonoProfileMethodResult man_unman_transition;
60 static MonoProfileAllocFunc allocation_cb;
61 static MonoProfileStatFunc statistical_cb;
62 static MonoProfileStatCallChainFunc statistical_call_chain_cb;
63 static int statistical_call_chain_depth;
64 static MonoProfileMethodFunc method_enter;
65 static MonoProfileMethodFunc method_leave;
67 static MonoProfileExceptionFunc exception_throw_cb;
68 static MonoProfileMethodFunc exception_method_leave_cb;
69 static MonoProfileExceptionClauseFunc exception_clause_cb;
71 static MonoProfileThreadFunc thread_start;
72 static MonoProfileThreadFunc thread_end;
74 static MonoProfileCoverageFilterFunc coverage_filter_cb;
76 static MonoProfileFunc shutdown_callback;
78 static MonoProfileGCFunc gc_event;
79 static MonoProfileGCResizeFunc gc_heap_resize;
81 #define mono_profiler_coverage_lock() EnterCriticalSection (&profiler_coverage_mutex)
82 #define mono_profiler_coverage_unlock() LeaveCriticalSection (&profiler_coverage_mutex)
83 static CRITICAL_SECTION profiler_coverage_mutex;
85 /* this is directly accessible to other mono libs. */
86 MonoProfileFlags mono_profiler_events;
89 * mono_profiler_install:
90 * @prof: a MonoProfiler structure pointer, or a pointer to a derived structure.
91 * @callback: the function to invoke at shutdown
93 * Use mono_profiler_install to activate profiling in the Mono runtime.
94 * Typically developers of new profilers will create a new structure whose
95 * first field is a MonoProfiler and put any extra information that they need
96 * to access from the various profiling callbacks there.
100 mono_profiler_install (MonoProfiler *prof, MonoProfileFunc callback)
102 if (current_profiler)
103 g_error ("profiler already setup");
104 current_profiler = prof;
105 shutdown_callback = callback;
106 InitializeCriticalSection (&profiler_coverage_mutex);
110 * mono_profiler_set_events:
111 * @events: an ORed set of values made up of MONO_PROFILER_ flags
113 * The events descriped in the @events argument is a set of flags
114 * that represent which profiling events must be triggered. For
115 * example if you have registered a set of methods for tracking
116 * JIT compilation start and end with mono_profiler_install_jit_compile,
117 * you will want to pass the MONO_PROFILE_JIT_COMPILATION flag to
120 * You can call mono_profile_set_events more than once and you can
121 * do this at runtime to modify which methods are invoked.
124 mono_profiler_set_events (MonoProfileFlags events)
126 mono_profiler_events = events;
130 * mono_profiler_get_events:
132 * Returns a list of active events that will be intercepted.
135 mono_profiler_get_events (void)
137 return mono_profiler_events;
141 * mono_profiler_install_enter_leave:
142 * @enter: the routine to be called on each method entry
143 * @fleave: the routine to be called each time a method returns
145 * Use this routine to install routines that will be called everytime
146 * a method enters and leaves. The routines will receive as an argument
147 * the MonoMethod representing the method that is entering or leaving.
150 mono_profiler_install_enter_leave (MonoProfileMethodFunc enter, MonoProfileMethodFunc fleave)
152 method_enter = enter;
153 method_leave = fleave;
157 * mono_profiler_install_jit_compile:
158 * @start: the routine to be called when the JIT process starts.
159 * @end: the routine to be called when the JIT process ends.
161 * Use this routine to install routines that will be called when JIT
162 * compilation of a method starts and completes.
165 mono_profiler_install_jit_compile (MonoProfileMethodFunc start, MonoProfileMethodResult end)
172 mono_profiler_install_jit_end (MonoProfileJitResult end)
178 mono_profiler_install_method_free (MonoProfileMethodFunc callback)
180 method_free = callback;
184 mono_profiler_install_thread (MonoProfileThreadFunc start, MonoProfileThreadFunc end)
186 thread_start = start;
191 mono_profiler_install_transition (MonoProfileMethodResult callback)
193 man_unman_transition = callback;
197 mono_profiler_install_allocation (MonoProfileAllocFunc callback)
199 allocation_cb = callback;
203 mono_profiler_install_statistical (MonoProfileStatFunc callback)
205 statistical_cb = callback;
209 mono_profiler_install_statistical_call_chain (MonoProfileStatCallChainFunc callback, int call_chain_depth) {
210 statistical_call_chain_cb = callback;
211 statistical_call_chain_depth = call_chain_depth;
212 if (statistical_call_chain_depth > MONO_PROFILER_MAX_STAT_CALL_CHAIN_DEPTH) {
213 statistical_call_chain_depth = MONO_PROFILER_MAX_STAT_CALL_CHAIN_DEPTH;
218 mono_profiler_stat_get_call_chain_depth (void) {
219 if (statistical_call_chain_cb != NULL) {
220 return statistical_call_chain_depth;
226 void mono_profiler_install_exception (MonoProfileExceptionFunc throw_callback, MonoProfileMethodFunc exc_method_leave, MonoProfileExceptionClauseFunc clause_callback)
228 exception_throw_cb = throw_callback;
229 exception_method_leave_cb = exc_method_leave;
230 exception_clause_cb = clause_callback;
234 mono_profiler_install_coverage_filter (MonoProfileCoverageFilterFunc callback)
236 coverage_filter_cb = callback;
240 mono_profiler_install_appdomain (MonoProfileAppDomainFunc start_load, MonoProfileAppDomainResult end_load,
241 MonoProfileAppDomainFunc start_unload, MonoProfileAppDomainFunc end_unload)
244 domain_start_load = start_load;
245 domain_end_load = end_load;
246 domain_start_unload = start_unload;
247 domain_end_unload = end_unload;
251 mono_profiler_install_assembly (MonoProfileAssemblyFunc start_load, MonoProfileAssemblyResult end_load,
252 MonoProfileAssemblyFunc start_unload, MonoProfileAssemblyFunc end_unload)
254 assembly_start_load = start_load;
255 assembly_end_load = end_load;
256 assembly_start_unload = start_unload;
257 assembly_end_unload = end_unload;
261 mono_profiler_install_module (MonoProfileModuleFunc start_load, MonoProfileModuleResult end_load,
262 MonoProfileModuleFunc start_unload, MonoProfileModuleFunc end_unload)
264 module_start_load = start_load;
265 module_end_load = end_load;
266 module_start_unload = start_unload;
267 module_end_unload = end_unload;
271 mono_profiler_install_class (MonoProfileClassFunc start_load, MonoProfileClassResult end_load,
272 MonoProfileClassFunc start_unload, MonoProfileClassFunc end_unload)
274 class_start_load = start_load;
275 class_end_load = end_load;
276 class_start_unload = start_unload;
277 class_end_unload = end_unload;
281 mono_profiler_method_enter (MonoMethod *method)
283 if ((mono_profiler_events & MONO_PROFILE_ENTER_LEAVE) && method_enter)
284 method_enter (current_profiler, method);
288 mono_profiler_method_leave (MonoMethod *method)
290 if ((mono_profiler_events & MONO_PROFILE_ENTER_LEAVE) && method_leave)
291 method_leave (current_profiler, method);
295 mono_profiler_method_jit (MonoMethod *method)
297 if ((mono_profiler_events & MONO_PROFILE_JIT_COMPILATION) && jit_start)
298 jit_start (current_profiler, method);
302 mono_profiler_method_end_jit (MonoMethod *method, MonoJitInfo* jinfo, int result)
304 if ((mono_profiler_events & MONO_PROFILE_JIT_COMPILATION)) {
306 jit_end (current_profiler, method, result);
308 jit_end2 (current_profiler, method, jinfo, result);
313 mono_profiler_method_free (MonoMethod *method)
315 if ((mono_profiler_events & MONO_PROFILE_METHOD_EVENTS) && method_free)
316 method_free (current_profiler, method);
320 mono_profiler_code_transition (MonoMethod *method, int result)
322 if ((mono_profiler_events & MONO_PROFILE_TRANSITIONS) && man_unman_transition)
323 man_unman_transition (current_profiler, method, result);
327 mono_profiler_allocation (MonoObject *obj, MonoClass *klass)
329 if ((mono_profiler_events & MONO_PROFILE_ALLOCATIONS) && allocation_cb)
330 allocation_cb (current_profiler, obj, klass);
334 mono_profiler_stat_hit (guchar *ip, void *context)
336 if ((mono_profiler_events & MONO_PROFILE_STATISTICAL) && statistical_cb)
337 statistical_cb (current_profiler, ip, context);
341 mono_profiler_stat_call_chain (int call_chain_depth, guchar **ips, void *context)
343 if ((mono_profiler_events & MONO_PROFILE_STATISTICAL) && statistical_call_chain_cb)
344 statistical_call_chain_cb (current_profiler, call_chain_depth, ips, context);
348 mono_profiler_exception_thrown (MonoObject *exception)
350 if ((mono_profiler_events & MONO_PROFILE_EXCEPTIONS) && exception_throw_cb)
351 exception_throw_cb (current_profiler, exception);
355 mono_profiler_exception_method_leave (MonoMethod *method)
357 if ((mono_profiler_events & MONO_PROFILE_EXCEPTIONS) && exception_method_leave_cb)
358 exception_method_leave_cb (current_profiler, method);
362 mono_profiler_exception_clause_handler (MonoMethod *method, int clause_type, int clause_num)
364 if ((mono_profiler_events & MONO_PROFILE_EXCEPTIONS) && exception_clause_cb)
365 exception_clause_cb (current_profiler, method, clause_type, clause_num);
369 mono_profiler_thread_start (gsize tid)
371 if ((mono_profiler_events & MONO_PROFILE_THREADS) && thread_start)
372 thread_start (current_profiler, tid);
376 mono_profiler_thread_end (gsize tid)
378 if ((mono_profiler_events & MONO_PROFILE_THREADS) && thread_end)
379 thread_end (current_profiler, tid);
383 mono_profiler_assembly_event (MonoAssembly *assembly, int code)
385 if (!(mono_profiler_events & MONO_PROFILE_ASSEMBLY_EVENTS))
389 case MONO_PROFILE_START_LOAD:
390 if (assembly_start_load)
391 assembly_start_load (current_profiler, assembly);
393 case MONO_PROFILE_START_UNLOAD:
394 if (assembly_start_unload)
395 assembly_start_unload (current_profiler, assembly);
397 case MONO_PROFILE_END_UNLOAD:
398 if (assembly_end_unload)
399 assembly_end_unload (current_profiler, assembly);
402 g_assert_not_reached ();
407 mono_profiler_assembly_loaded (MonoAssembly *assembly, int result)
409 if ((mono_profiler_events & MONO_PROFILE_ASSEMBLY_EVENTS) && assembly_end_load)
410 assembly_end_load (current_profiler, assembly, result);
414 mono_profiler_module_event (MonoImage *module, int code)
416 if (!(mono_profiler_events & MONO_PROFILE_MODULE_EVENTS))
420 case MONO_PROFILE_START_LOAD:
421 if (module_start_load)
422 module_start_load (current_profiler, module);
424 case MONO_PROFILE_START_UNLOAD:
425 if (module_start_unload)
426 module_start_unload (current_profiler, module);
428 case MONO_PROFILE_END_UNLOAD:
429 if (module_end_unload)
430 module_end_unload (current_profiler, module);
433 g_assert_not_reached ();
438 mono_profiler_module_loaded (MonoImage *module, int result)
440 if ((mono_profiler_events & MONO_PROFILE_MODULE_EVENTS) && module_end_load)
441 module_end_load (current_profiler, module, result);
445 mono_profiler_class_event (MonoClass *klass, int code)
447 if (!(mono_profiler_events & MONO_PROFILE_CLASS_EVENTS))
451 case MONO_PROFILE_START_LOAD:
452 if (class_start_load)
453 class_start_load (current_profiler, klass);
455 case MONO_PROFILE_START_UNLOAD:
456 if (class_start_unload)
457 class_start_unload (current_profiler, klass);
459 case MONO_PROFILE_END_UNLOAD:
460 if (class_end_unload)
461 class_end_unload (current_profiler, klass);
464 g_assert_not_reached ();
469 mono_profiler_class_loaded (MonoClass *klass, int result)
471 if ((mono_profiler_events & MONO_PROFILE_CLASS_EVENTS) && class_end_load)
472 class_end_load (current_profiler, klass, result);
476 mono_profiler_appdomain_event (MonoDomain *domain, int code)
478 if (!(mono_profiler_events & MONO_PROFILE_APPDOMAIN_EVENTS))
482 case MONO_PROFILE_START_LOAD:
483 if (domain_start_load)
484 domain_start_load (current_profiler, domain);
486 case MONO_PROFILE_START_UNLOAD:
487 if (domain_start_unload)
488 domain_start_unload (current_profiler, domain);
490 case MONO_PROFILE_END_UNLOAD:
491 if (domain_end_unload)
492 domain_end_unload (current_profiler, domain);
495 g_assert_not_reached ();
500 mono_profiler_appdomain_loaded (MonoDomain *domain, int result)
502 if ((mono_profiler_events & MONO_PROFILE_APPDOMAIN_EVENTS) && domain_end_load)
503 domain_end_load (current_profiler, domain, result);
507 mono_profiler_shutdown (void)
509 if (current_profiler && shutdown_callback)
510 shutdown_callback (current_profiler);
514 mono_profiler_gc_heap_resize (gint64 new_size)
516 if ((mono_profiler_events & MONO_PROFILE_GC) && gc_heap_resize)
517 gc_heap_resize (current_profiler, new_size);
521 mono_profiler_gc_event (MonoGCEvent event, int generation)
523 if ((mono_profiler_events & MONO_PROFILE_GC) && gc_event)
524 gc_event (current_profiler, event, generation);
528 mono_profiler_install_gc (MonoProfileGCFunc callback, MonoProfileGCResizeFunc heap_resize_callback)
530 mono_gc_enable_events ();
532 gc_heap_resize = heap_resize_callback;
535 static GHashTable *coverage_hash = NULL;
537 MonoProfileCoverageInfo*
538 mono_profiler_coverage_alloc (MonoMethod *method, int entries)
540 MonoProfileCoverageInfo *res;
542 if (coverage_filter_cb)
543 if (! (*coverage_filter_cb) (current_profiler, method))
546 mono_profiler_coverage_lock ();
548 coverage_hash = g_hash_table_new (NULL, NULL);
550 res = g_malloc0 (sizeof (MonoProfileCoverageInfo) + sizeof (void*) * 2 * entries);
552 res->entries = entries;
554 g_hash_table_insert (coverage_hash, method, res);
555 mono_profiler_coverage_unlock ();
560 /* safe only when the method antive code has been unloaded */
562 mono_profiler_coverage_free (MonoMethod *method)
564 MonoProfileCoverageInfo* info;
566 mono_profiler_coverage_lock ();
567 if (!coverage_hash) {
568 mono_profiler_coverage_unlock ();
572 info = g_hash_table_lookup (coverage_hash, method);
575 g_hash_table_remove (coverage_hash, method);
577 mono_profiler_coverage_unlock ();
581 * mono_profiler_coverage_get:
582 * @prof: The profiler handle, installed with mono_profiler_install
583 * @method: the method to gather information from.
584 * @func: A routine that will be called back with the results
586 * If the MONO_PROFILER_INS_COVERAGE flag was active during JIT compilation
587 * it is posisble to obtain coverage information about a give method.
589 * The function @func will be invoked repeatedly with instances of the
590 * MonoProfileCoverageEntry structure.
593 mono_profiler_coverage_get (MonoProfiler *prof, MonoMethod *method, MonoProfileCoverageFunc func)
595 MonoProfileCoverageInfo* info;
598 const unsigned char *start, *end, *cil_code;
599 MonoMethodHeader *header;
600 MonoProfileCoverageEntry entry;
601 MonoDebugMethodInfo *debug_minfo;
603 mono_profiler_coverage_lock ();
604 info = g_hash_table_lookup (coverage_hash, method);
605 mono_profiler_coverage_unlock ();
610 header = mono_method_get_header (method);
611 start = mono_method_header_get_code (header, &code_size, NULL);
612 debug_minfo = mono_debug_lookup_method (method);
614 end = start + code_size;
615 for (i = 0; i < info->entries; ++i) {
616 cil_code = info->data [i].cil_code;
617 if (cil_code && cil_code >= start && cil_code < end) {
619 offset = cil_code - start;
620 entry.iloffset = offset;
621 entry.method = method;
622 entry.counter = info->data [i].count;
623 entry.line = entry.col = 1;
624 entry.filename = NULL;
626 MonoDebugSourceLocation *location;
628 location = mono_debug_symfile_lookup_location (debug_minfo, offset);
630 entry.line = location->row;
631 entry.col = location->column;
632 entry.filename = fname = g_strdup (location->source_file);
633 mono_debug_free_source_location (location);
643 #ifndef DISABLE_PROFILER
645 * Small profiler extracted from mint: we should move it in a loadable module
646 * and improve it to do graphs and more accurate timestamping with rdtsc.
649 static FILE* poutput = NULL;
652 #define USE_WIN32COUNTER 0
656 unsigned int lows, highs, lowe, highe;
659 #define rdtsc(low,high) \
660 __asm__ __volatile__("rdtsc" : "=a" (low), "=d" (high))
665 rdtsc_elapsed (MonoRdtscTimer *t)
667 unsigned long long diff;
668 unsigned int highe = t->highe;
669 if (t->lowe < t->lows)
671 diff = (((unsigned long long) highe - t->highs) << 32) + (t->lowe - t->lows);
672 return ((double)diff / freq) / 1000000; /* have to return the result in seconds */
683 if (!(cpuinfo = fopen ("/proc/cpuinfo", "r")))
685 while (fgets (buf, sizeof(buf), cpuinfo)) {
686 if (sscanf (buf, "cpu MHz : %f", &val) == 1) {
687 /*printf ("got mh: %f\n", val);*/
690 if (strncmp (buf, "flags", 5) == 0) {
691 if (strstr (buf, "tsc")) {
693 /*printf ("have tsc\n");*/
698 return have_flag? have_freq: 0;
701 #define MONO_TIMER_STARTUP \
702 if (!(freq = have_rdtsc ())) g_error ("Compiled with TSC support, but none found");
703 #define MONO_TIMER_TYPE MonoRdtscTimer
704 #define MONO_TIMER_INIT(t)
705 #define MONO_TIMER_DESTROY(t)
706 #define MONO_TIMER_START(t) rdtsc ((t).lows, (t).highs);
707 #define MONO_TIMER_STOP(t) rdtsc ((t).lowe, (t).highe);
708 #define MONO_TIMER_ELAPSED(t) rdtsc_elapsed (&(t))
710 #elif USE_WIN32COUNTER
714 LARGE_INTEGER start, stop;
720 win32_elapsed (MonoWin32Timer *t)
722 LONGLONG diff = t->stop.QuadPart - t->start.QuadPart;
723 return ((double)diff / freq) / 1000000; /* have to return the result in seconds */
727 have_win32counter (void) {
730 if (!QueryPerformanceFrequency (&f))
735 #define MONO_TIMER_STARTUP \
736 if (!(freq = have_win32counter ())) g_error ("Compiled with Win32 counter support, but none found");
737 #define MONO_TIMER_TYPE MonoWin32Timer
738 #define MONO_TIMER_INIT(t)
739 #define MONO_TIMER_DESTROY(t)
740 #define MONO_TIMER_START(t) QueryPerformanceCounter (&(t).start)
741 #define MONO_TIMER_STOP(t) QueryPerformanceCounter (&(t).stop)
742 #define MONO_TIMER_ELAPSED(t) win32_elapsed (&(t))
747 GTimeVal start, stop;
751 timeval_elapsed (MonoGLibTimer *t)
753 if (t->start.tv_usec > t->stop.tv_usec) {
754 t->stop.tv_usec += G_USEC_PER_SEC;
757 return (t->stop.tv_sec - t->start.tv_sec)
758 + ((double)(t->stop.tv_usec - t->start.tv_usec))/ G_USEC_PER_SEC;
761 #define MONO_TIMER_STARTUP
762 #define MONO_TIMER_TYPE MonoGLibTimer
763 #define MONO_TIMER_INIT(t)
764 #define MONO_TIMER_DESTROY(t)
765 #define MONO_TIMER_START(t) g_get_current_time (&(t).start)
766 #define MONO_TIMER_STOP(t) g_get_current_time (&(t).stop)
767 #define MONO_TIMER_ELAPSED(t) timeval_elapsed (&(t))
770 typedef struct _AllocInfo AllocInfo;
771 typedef struct _CallerInfo CallerInfo;
772 typedef struct _LastCallerInfo LastCallerInfo;
774 struct _MonoProfiler {
776 MonoMemPool *mempool;
777 /* info about JIT time */
778 MONO_TIMER_TYPE jit_timer;
781 MonoMethod *max_jit_method;
786 /* chain of callers for the current thread */
787 LastCallerInfo *callers;
788 /* LastCallerInfo nodes for faster allocation */
789 LastCallerInfo *cstorage;
796 AllocInfo *alloc_info;
797 CallerInfo *caller_info;
800 typedef struct _MethodCallProfile MethodCallProfile;
802 struct _MethodCallProfile {
803 MethodCallProfile *next;
804 MONO_TIMER_TYPE timer;
821 struct _LastCallerInfo {
822 LastCallerInfo *next;
824 MONO_TIMER_TYPE timer;
828 create_profiler (void)
830 MonoProfiler *prof = g_new0 (MonoProfiler, 1);
832 prof->methods = g_hash_table_new (mono_aligned_addr_hash, NULL);
833 MONO_TIMER_INIT (prof->jit_timer);
834 prof->mempool = mono_mempool_new ();
839 #ifdef HAVE_KW_THREAD
840 static __thread MonoProfiler * tls_profiler;
841 # define GET_PROFILER() tls_profiler
842 # define SET_PROFILER(x) tls_profiler = (x)
843 # define ALLOC_PROFILER() /* nop */
845 static guint32 profiler_thread_id = -1;
846 # define GET_PROFILER() ((MonoProfiler *)TlsGetValue (profiler_thread_id))
847 # define SET_PROFILER(x) TlsSetValue (profiler_thread_id, x);
848 # define ALLOC_PROFILER() profiler_thread_id = TlsAlloc ()
851 #define GET_THREAD_PROF(prof) do { \
852 MonoProfiler *_tprofiler = GET_PROFILER (); \
854 _tprofiler = create_profiler (); \
855 prof->per_thread = g_slist_prepend (prof->per_thread, _tprofiler); \
856 SET_PROFILER (_tprofiler); \
861 /* thread unsafe but faster variant */
862 #define GET_THREAD_PROF(prof)
866 compare_profile (MethodProfile *profa, MethodProfile *profb)
868 return (gint)((profb->total - profa->total)*1000);
872 build_profile (MonoMethod *m, MethodProfile *prof, GList **funcs)
875 *funcs = g_list_insert_sorted (*funcs, prof, (GCompareFunc)compare_profile);
879 method_get_name (MonoMethod* method)
883 sig = mono_signature_get_desc (mono_method_signature (method), FALSE);
884 res = g_strdup_printf ("%s%s%s::%s(%s)", method->klass->name_space,
885 method->klass->name_space ? "." : "", method->klass->name,
891 static void output_callers (MethodProfile *p);
893 /* This isn't defined on older glib versions and on some platforms */
894 #ifndef G_GUINT64_FORMAT
895 #define G_GUINT64_FORMAT "ul"
897 #ifndef G_GINT64_FORMAT
898 #define G_GINT64_FORMAT "lld"
902 output_profile (GList *funcs)
907 guint64 total_calls = 0;
910 fprintf (poutput, "Time(ms) Count P/call(ms) Method name\n");
911 for (tmp = funcs; tmp; tmp = tmp->next) {
913 total_calls += p->count;
914 if (!(gint)(p->total*1000))
916 m = method_get_name (p->method);
917 fprintf (poutput, "########################\n");
918 fprintf (poutput, "% 8.3f ", (double) (p->total * 1000));
919 fprintf (poutput, "%7" G_GUINT64_FORMAT " ", (guint64)p->count);
920 fprintf (poutput, "% 8.3f ", (double) (p->total * 1000)/(double)p->count);
921 fprintf (poutput, " %s\n", m);
927 fprintf (poutput, "Total number of calls: %" G_GINT64_FORMAT "\n", (gint64)total_calls);
936 compare_newobj_profile (NewobjProfile *profa, NewobjProfile *profb)
938 if (profb->count == profa->count)
941 return profb->count > profa->count ? 1 : -1;
945 build_newobj_profile (MonoClass *class, MethodProfile *mprof, GList **funcs)
947 NewobjProfile *prof = g_new (NewobjProfile, 1);
952 /* we use the total amount of memory to sort */
953 for (tmp = mprof->alloc_info; tmp; tmp = tmp->next)
956 *funcs = g_list_insert_sorted (*funcs, prof, (GCompareFunc)compare_newobj_profile);
960 compare_caller (CallerInfo *a, CallerInfo *b)
962 return b->count - a->count;
966 compare_alloc (AllocInfo *a, AllocInfo *b)
968 return b->mem - a->mem;
972 sort_alloc_list (AllocInfo *ai)
976 for (tmp = ai; tmp; tmp = tmp->next) {
977 l = g_slist_insert_sorted (l, tmp, (GCompareFunc)compare_alloc);
983 sort_caller_list (CallerInfo *ai)
987 for (tmp = ai; tmp; tmp = tmp->next) {
988 l = g_slist_insert_sorted (l, tmp, (GCompareFunc)compare_caller);
994 output_callers (MethodProfile *p) {
995 guint total_callers, percent;
996 GSList *sorted, *tmps;
1000 fprintf (poutput, " Callers (with count) that contribute at least for 1%%:\n");
1002 for (cinfo = p->caller_info; cinfo; cinfo = cinfo->next) {
1003 total_callers += cinfo->count;
1005 sorted = sort_caller_list (p->caller_info);
1006 for (tmps = sorted; tmps; tmps = tmps->next) {
1008 percent = (cinfo->count * 100)/total_callers;
1011 m = method_get_name (cinfo->caller);
1012 fprintf (poutput, " %8d % 3d %% %s\n", cinfo->count, percent, m);
1018 output_newobj_profile (GList *proflist)
1025 const char* isarray;
1029 GSList *sorted, *tmps;
1031 fprintf (poutput, "\nAllocation profiler\n");
1034 fprintf (poutput, "%-9s %s\n", "Total mem", "Method");
1035 for (tmp = proflist; tmp; tmp = tmp->next) {
1038 if (p->count < 50000)
1041 m = method_get_name (mp->method);
1042 fprintf (poutput, "########################\n%8" G_GUINT64_FORMAT " KB %s\n", (p->count / 1024), m);
1044 sorted = sort_alloc_list (mp->alloc_info);
1045 for (tmps = sorted; tmps; tmps = tmps->next) {
1047 if (ainfo->mem < 50000)
1049 klass = ainfo->klass;
1052 klass = klass->element_class;
1056 g_snprintf (buf, sizeof (buf), "%s%s%s%s",
1057 klass->name_space, klass->name_space ? "." : "", klass->name, isarray);
1058 fprintf (poutput, " %8" G_GUINT64_FORMAT " KB %8" G_GUINT64_FORMAT " %-48s\n", (ainfo->mem / 1024), ainfo->count, buf);
1061 output_callers (mp);
1063 fprintf (poutput, "Total memory allocated: %" G_GUINT64_FORMAT " KB\n", total / 1024);
1067 merge_methods (MonoMethod *method, MethodProfile *profile, MonoProfiler *prof)
1069 MethodProfile *mprof;
1070 AllocInfo *talloc_info, *alloc_info;
1071 CallerInfo *tcaller_info, *caller_info;
1073 mprof = g_hash_table_lookup (prof->methods, method);
1075 /* the master thread didn't see this method, just transfer the info as is */
1076 g_hash_table_insert (prof->methods, method, profile);
1079 /* merge the info from profile into mprof */
1080 mprof->count += profile->count;
1081 mprof->total += profile->total;
1082 /* merge alloc info */
1083 for (talloc_info = profile->alloc_info; talloc_info; talloc_info = talloc_info->next) {
1084 for (alloc_info = mprof->alloc_info; alloc_info; alloc_info = alloc_info->next) {
1085 if (alloc_info->klass == talloc_info->klass) {
1086 /* mprof already has a record for the klass, merge */
1087 alloc_info->count += talloc_info->count;
1088 alloc_info->mem += talloc_info->mem;
1093 /* mprof didn't have the info, just copy it over */
1094 alloc_info = mono_mempool_alloc0 (prof->mempool, sizeof (AllocInfo));
1095 *alloc_info = *talloc_info;
1096 alloc_info->next = mprof->alloc_info;
1097 mprof->alloc_info = alloc_info->next;
1100 /* merge callers info */
1101 for (tcaller_info = profile->caller_info; tcaller_info; tcaller_info = tcaller_info->next) {
1102 for (caller_info = mprof->caller_info; caller_info; caller_info = caller_info->next) {
1103 if (caller_info->caller == tcaller_info->caller) {
1104 /* mprof already has a record for the caller method, merge */
1105 caller_info->count += tcaller_info->count;
1110 /* mprof didn't have the info, just copy it over */
1111 caller_info = mono_mempool_alloc0 (prof->mempool, sizeof (CallerInfo));
1112 *caller_info = *tcaller_info;
1113 caller_info->next = mprof->caller_info;
1114 mprof->caller_info = caller_info;
1120 merge_thread_data (MonoProfiler *master, MonoProfiler *tprof)
1122 master->jit_time += tprof->jit_time;
1123 master->methods_jitted += tprof->methods_jitted;
1124 if (master->max_jit_time < tprof->max_jit_time) {
1125 master->max_jit_time = tprof->max_jit_time;
1126 master->max_jit_method = tprof->max_jit_method;
1129 g_hash_table_foreach (tprof->methods, (GHFunc)merge_methods, master);
1133 simple_method_enter (MonoProfiler *prof, MonoMethod *method)
1135 MethodProfile *profile_info;
1136 LastCallerInfo *callinfo;
1137 GET_THREAD_PROF (prof);
1138 /*g_print ("enter %p %s::%s in %d (%p)\n", method, method->klass->name, method->name, GetCurrentThreadId (), prof);*/
1139 if (!(profile_info = g_hash_table_lookup (prof->methods, method))) {
1140 profile_info = mono_mempool_alloc0 (prof->mempool, sizeof (MethodProfile));
1141 MONO_TIMER_INIT (profile_info->u.timer);
1142 g_hash_table_insert (prof->methods, method, profile_info);
1144 profile_info->count++;
1145 if (prof->callers) {
1147 MonoMethod *caller = prof->callers->method;
1148 for (cinfo = profile_info->caller_info; cinfo; cinfo = cinfo->next) {
1149 if (cinfo->caller == caller)
1153 cinfo = mono_mempool_alloc0 (prof->mempool, sizeof (CallerInfo));
1154 cinfo->caller = caller;
1155 cinfo->next = profile_info->caller_info;
1156 profile_info->caller_info = cinfo;
1160 if (!(callinfo = prof->cstorage)) {
1161 callinfo = mono_mempool_alloc (prof->mempool, sizeof (LastCallerInfo));
1162 MONO_TIMER_INIT (callinfo->timer);
1164 prof->cstorage = prof->cstorage->next;
1166 callinfo->method = method;
1167 callinfo->next = prof->callers;
1168 prof->callers = callinfo;
1169 MONO_TIMER_START (callinfo->timer);
1173 simple_method_leave (MonoProfiler *prof, MonoMethod *method)
1175 MethodProfile *profile_info;
1176 LastCallerInfo *callinfo, *newcallinfo = NULL;
1178 GET_THREAD_PROF (prof);
1179 /*g_print ("leave %p %s::%s in %d (%p)\n", method, method->klass->name, method->name, GetCurrentThreadId (), prof);*/
1180 callinfo = prof->callers;
1181 /* should really not happen, but we don't catch exceptions events, yet ... */
1183 MONO_TIMER_STOP (callinfo->timer);
1184 profile_info = g_hash_table_lookup (prof->methods, callinfo->method);
1186 profile_info->total += MONO_TIMER_ELAPSED (callinfo->timer);
1187 newcallinfo = callinfo->next;
1188 callinfo->next = prof->cstorage;
1189 prof->cstorage = callinfo;
1190 if (callinfo->method == method)
1192 callinfo = newcallinfo;
1194 prof->callers = newcallinfo;
1198 simple_allocation (MonoProfiler *prof, MonoObject *obj, MonoClass *klass)
1200 MethodProfile *profile_info;
1203 GET_THREAD_PROF (prof);
1204 if (prof->callers) {
1205 MonoMethod *caller = prof->callers->method;
1207 /* Otherwise all allocations are attributed to icall_wrapper_mono_object_new */
1208 if (caller->wrapper_type == MONO_WRAPPER_MANAGED_TO_NATIVE)
1209 caller = prof->callers->next->method;
1211 if (!(profile_info = g_hash_table_lookup (prof->methods, caller)))
1212 g_assert_not_reached ();
1214 return; /* fine for now */
1217 for (tmp = profile_info->alloc_info; tmp; tmp = tmp->next) {
1218 if (tmp->klass == klass)
1222 tmp = mono_mempool_alloc0 (prof->mempool, sizeof (AllocInfo));
1224 tmp->next = profile_info->alloc_info;
1225 profile_info->alloc_info = tmp;
1228 tmp->mem += mono_object_get_size (obj);
1232 simple_method_jit (MonoProfiler *prof, MonoMethod *method)
1234 GET_THREAD_PROF (prof);
1235 prof->methods_jitted++;
1236 MONO_TIMER_START (prof->jit_timer);
1240 simple_method_end_jit (MonoProfiler *prof, MonoMethod *method, int result)
1243 GET_THREAD_PROF (prof);
1244 MONO_TIMER_STOP (prof->jit_timer);
1245 jtime = MONO_TIMER_ELAPSED (prof->jit_timer);
1246 prof->jit_time += jtime;
1247 if (jtime > prof->max_jit_time) {
1248 prof->max_jit_time = jtime;
1249 prof->max_jit_method = method;
1253 /* about 10 minutes of samples */
1254 #define MAX_PROF_SAMPLES (1000*60*10)
1255 static int prof_counts = 0;
1256 static int prof_ucounts = 0;
1257 static gpointer* prof_addresses = NULL;
1258 static GHashTable *prof_table = NULL;
1261 simple_stat_hit (MonoProfiler *prof, guchar *ip, void *context)
1265 if (prof_counts >= MAX_PROF_SAMPLES)
1267 pos = InterlockedIncrement (&prof_counts);
1268 prof_addresses [pos - 1] = ip;
1272 compare_methods_prof (gconstpointer a, gconstpointer b)
1274 int ca = GPOINTER_TO_UINT (g_hash_table_lookup (prof_table, a));
1275 int cb = GPOINTER_TO_UINT (g_hash_table_lookup (prof_table, b));
1280 prof_foreach (char *method, gpointer c, gpointer data)
1282 GList **list = data;
1283 *list = g_list_insert_sorted (*list, method, compare_methods_prof);
1286 typedef struct Addr2LineData Addr2LineData;
1288 struct Addr2LineData {
1289 Addr2LineData *next;
1296 static Addr2LineData *addr2line_pipes = NULL;
1299 try_addr2line (const char* binary, gpointer ip)
1303 Addr2LineData *addr2line;
1305 for (addr2line = addr2line_pipes; addr2line; addr2line = addr2line->next) {
1306 if (strcmp (binary, addr2line->binary) == 0)
1310 const char *addr_argv[] = {"addr2line", "-f", "-e", binary, NULL};
1314 char monobin [1024];
1315 /* non-linux platforms will need different code here */
1316 if (strcmp (binary, "mono") == 0) {
1317 int count = readlink ("/proc/self/exe", monobin, sizeof (monobin));
1318 if (count >= 0 && count < sizeof (monobin)) {
1319 monobin [count] = 0;
1320 addr_argv [3] = monobin;
1324 if (!g_spawn_async_with_pipes (NULL, (char**)addr_argv, NULL, G_SPAWN_SEARCH_PATH, NULL, NULL,
1325 &child_pid, &ch_in, &ch_out, NULL, NULL)) {
1326 return g_strdup (binary);
1328 addr2line = g_new0 (Addr2LineData, 1);
1329 addr2line->child_pid = child_pid;
1330 addr2line->binary = g_strdup (binary);
1331 addr2line->pipein = fdopen (ch_in, "w");
1332 addr2line->pipeout = fdopen (ch_out, "r");
1333 addr2line->next = addr2line_pipes;
1334 addr2line_pipes = addr2line;
1336 fprintf (addr2line->pipein, "%p\n", ip);
1337 fflush (addr2line->pipein);
1338 /* we first get the func name and then file:lineno in a second line */
1339 if (fgets (buf, sizeof (buf), addr2line->pipeout) && buf [0] != '?') {
1340 char *end = strchr (buf, '\n');
1343 res = g_strdup_printf ("%s(%s", binary, buf);
1344 /* discard the filename/line info */
1345 fgets (buf, sizeof (buf), addr2line->pipeout);
1347 res = g_strdup (binary);
1353 stat_prof_report (void)
1356 int count = prof_counts;
1360 GList *tmp, *sorted = NULL;
1361 int pcount = ++ prof_counts;
1363 prof_counts = MAX_PROF_SAMPLES;
1364 for (i = 0; i < count; ++i) {
1365 ip = prof_addresses [i];
1366 ji = mono_jit_info_table_find (mono_domain_get (), ip);
1368 mn = mono_method_full_name (ji->method, TRUE);
1370 #ifdef HAVE_BACKTRACE_SYMBOLS
1375 names = backtrace_symbols (&ip, 1);
1376 send = strchr (names [0], '+');
1383 send = strchr (names [0], '[');
1386 if (no_func && names [0][0]) {
1387 char *endp = strchr (names [0], 0);
1388 while (--endp >= names [0] && g_ascii_isspace (*endp))
1390 mn = try_addr2line (names [0], ip);
1392 mn = g_strdup (names [0]);
1397 mn = g_strdup_printf ("unmanaged [%p]", ip);
1400 c = GPOINTER_TO_UINT (g_hash_table_lookup (prof_table, mn));
1402 g_hash_table_insert (prof_table, mn, GUINT_TO_POINTER (c));
1406 fprintf (poutput, "prof counts: total/unmanaged: %d/%d\n", pcount, prof_ucounts);
1407 g_hash_table_foreach (prof_table, (GHFunc)prof_foreach, &sorted);
1408 for (tmp = sorted; tmp; tmp = tmp->next) {
1410 c = GPOINTER_TO_UINT (g_hash_table_lookup (prof_table, tmp->data));
1411 perc = c*100.0/count;
1412 fprintf (poutput, "%7d\t%5.2f %% %s\n", c, perc, (char*)tmp->data);
1414 g_list_free (sorted);
1418 simple_appdomain_unload (MonoProfiler *prof, MonoDomain *domain)
1420 /* FIXME: we should actually record partial data for each domain,
1421 * but at this point it's must easier using the new logging profiler.
1423 mono_profiler_shutdown ();
1426 static gint32 simple_shutdown_done = FALSE;
1429 simple_shutdown (MonoProfiler *prof)
1431 GList *profile = NULL;
1432 MonoProfiler *tprof;
1435 gint32 see_shutdown_done;
1437 // Make sure we execute simple_shutdown only once
1438 see_shutdown_done = InterlockedExchange(& simple_shutdown_done, TRUE);
1439 if (see_shutdown_done)
1442 if (mono_profiler_events & MONO_PROFILE_STATISTICAL) {
1443 stat_prof_report ();
1446 // Stop all incoming events
1447 mono_profiler_set_events (0);
1449 for (tmp = prof->per_thread; tmp; tmp = tmp->next) {
1451 merge_thread_data (prof, tprof);
1454 fprintf (poutput, "Total time spent compiling %d methods (sec): %.4g\n", prof->methods_jitted, prof->jit_time);
1455 if (prof->max_jit_method) {
1456 str = method_get_name (prof->max_jit_method);
1457 fprintf (poutput, "Slowest method to compile (sec): %.4g: %s\n", prof->max_jit_time, str);
1460 g_hash_table_foreach (prof->methods, (GHFunc)build_profile, &profile);
1461 output_profile (profile);
1462 g_list_free (profile);
1465 g_hash_table_foreach (prof->methods, (GHFunc)build_newobj_profile, &profile);
1466 output_newobj_profile (profile);
1467 g_list_free (profile);
1469 g_free (prof_addresses);
1470 prof_addresses = NULL;
1471 g_hash_table_destroy (prof_table);
1475 mono_profiler_install_simple (const char *desc)
1478 gchar **args, **ptr;
1479 MonoProfileFlags flags = 0;
1485 desc = "alloc,time,jit";
1489 if (strstr (desc, ":"))
1490 desc = strstr (desc, ":") + 1;
1492 desc = "alloc,time,jit";
1493 args = g_strsplit (desc, ",", -1);
1495 for (ptr = args; ptr && *ptr; ptr++) {
1496 const char *arg = *ptr;
1498 // Alwais listen to appdomaon events to shutdown at the first unload
1499 flags |= MONO_PROFILE_APPDOMAIN_EVENTS;
1500 if (!strcmp (arg, "time"))
1501 flags |= MONO_PROFILE_ENTER_LEAVE | MONO_PROFILE_EXCEPTIONS;
1502 else if (!strcmp (arg, "alloc"))
1503 flags |= MONO_PROFILE_ALLOCATIONS;
1504 else if (!strcmp (arg, "stat"))
1505 flags |= MONO_PROFILE_STATISTICAL;
1506 else if (!strcmp (arg, "jit"))
1507 flags |= MONO_PROFILE_JIT_COMPILATION;
1508 else if (strncmp (arg, "file=", 5) == 0) {
1509 poutput = fopen (arg + 5, "wb");
1512 fprintf (stderr, "profiler : cannot open profile output file '%s'.\n", arg + 5);
1515 fprintf (stderr, "profiler : Unknown argument '%s'.\n", arg);
1520 if (flags & MONO_PROFILE_ALLOCATIONS)
1521 flags |= MONO_PROFILE_ENTER_LEAVE | MONO_PROFILE_EXCEPTIONS;
1523 flags = MONO_PROFILE_ENTER_LEAVE | MONO_PROFILE_ALLOCATIONS | MONO_PROFILE_JIT_COMPILATION | MONO_PROFILE_EXCEPTIONS;
1525 prof = create_profiler ();
1527 SET_PROFILER (prof);
1529 /* statistical profiler data */
1530 prof_addresses = g_new0 (gpointer, MAX_PROF_SAMPLES);
1531 prof_table = g_hash_table_new (g_str_hash, g_str_equal);
1533 mono_profiler_install (prof, simple_shutdown);
1534 mono_profiler_install_enter_leave (simple_method_enter, simple_method_leave);
1535 mono_profiler_install_exception (NULL, simple_method_leave, NULL);
1536 mono_profiler_install_jit_compile (simple_method_jit, simple_method_end_jit);
1537 mono_profiler_install_allocation (simple_allocation);
1538 mono_profiler_install_appdomain (NULL, NULL, simple_appdomain_unload, NULL);
1539 mono_profiler_install_statistical (simple_stat_hit);
1540 mono_profiler_set_events (flags);
1543 #endif /* DISABLE_PROFILER */
1545 typedef void (*ProfilerInitializer) (const char*);
1546 #define INITIALIZER_NAME "mono_profiler_startup"
1549 * mono_profiler_load:
1550 * @desc: arguments to configure the profiler
1552 * Invoke this method to initialize the profiler. This will drive the
1553 * loading of the internal ("default") or any external profilers.
1555 * This routine is invoked by Mono's driver, but must be called manually
1556 * if you embed Mono into your application.
1559 mono_profiler_load (const char *desc)
1561 #ifndef DISABLE_PROFILER
1562 if (!desc || (strcmp ("default", desc) == 0) || (strncmp (desc, "default:", 8) == 0)) {
1563 mono_profiler_install_simple (desc);
1573 const char* col = strchr (desc, ':');
1580 mname = g_memdup (desc, col - desc + 1);
1581 mname [col - desc] = 0;
1583 mname = g_strdup (desc);
1585 libname = g_strdup_printf ("mono-profiler-%s", mname);
1588 while ((path = mono_dl_build_path (NULL, libname, &iter))) {
1590 pmodule = mono_dl_open (path, MONO_DL_LAZY, &err);
1592 ProfilerInitializer func;
1593 if ((err = mono_dl_symbol (pmodule, INITIALIZER_NAME, (gpointer *)&func))) {
1594 g_warning ("Cannot find initializer function %s in profiler module: %s (%s)", INITIALIZER_NAME, libname, err);
1605 g_warning ("Error loading profiler module '%s': %s", libname, err);