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"
24 #ifdef HAVE_BACKTRACE_SYMBOLS
28 static MonoProfiler * current_profiler = NULL;
30 static MonoProfileAppDomainFunc domain_start_load;
31 static MonoProfileAppDomainResult domain_end_load;
32 static MonoProfileAppDomainFunc domain_start_unload;
33 static MonoProfileAppDomainFunc domain_end_unload;
35 static MonoProfileAssemblyFunc assembly_start_load;
36 static MonoProfileAssemblyResult assembly_end_load;
37 static MonoProfileAssemblyFunc assembly_start_unload;
38 static MonoProfileAssemblyFunc assembly_end_unload;
40 static MonoProfileModuleFunc module_start_load;
41 static MonoProfileModuleResult module_end_load;
42 static MonoProfileModuleFunc module_start_unload;
43 static MonoProfileModuleFunc module_end_unload;
45 static MonoProfileClassFunc class_start_load;
46 static MonoProfileClassResult class_end_load;
47 static MonoProfileClassFunc class_start_unload;
48 static MonoProfileClassFunc class_end_unload;
50 static MonoProfileMethodFunc jit_start;
51 static MonoProfileMethodResult jit_end;
52 static MonoProfileJitResult jit_end2;
53 static MonoProfileMethodResult man_unman_transition;
54 static MonoProfileAllocFunc allocation_cb;
55 static MonoProfileStatFunc statistical_cb;
56 static MonoProfileMethodFunc method_enter;
57 static MonoProfileMethodFunc method_leave;
59 static MonoProfileThreadFunc thread_start;
60 static MonoProfileThreadFunc thread_end;
62 static MonoProfileCoverageFilterFunc coverage_filter_cb;
64 static MonoProfileFunc shutdown_callback;
66 static MonoProfileGCFunc gc_event;
67 static MonoProfileGCResizeFunc gc_heap_resize;
69 #define mono_profiler_coverage_lock() EnterCriticalSection (&profiler_coverage_mutex)
70 #define mono_profiler_coverage_unlock() LeaveCriticalSection (&profiler_coverage_mutex)
71 static CRITICAL_SECTION profiler_coverage_mutex;
73 /* this is directly accessible to other mono libs. */
74 MonoProfileFlags mono_profiler_events;
77 * mono_profiler_install:
78 * @prof: a MonoProfiler structure pointer, or a pointer to a derived structure.
79 * @callback: the function to invoke at shutdown
81 * Use mono_profiler_install to activate profiling in the Mono runtime.
82 * Typically developers of new profilers will create a new structure whose
83 * first field is a MonoProfiler and put any extra information that they need
84 * to access from the various profiling callbacks there.
88 mono_profiler_install (MonoProfiler *prof, MonoProfileFunc callback)
91 g_error ("profiler already setup");
92 current_profiler = prof;
93 shutdown_callback = callback;
94 InitializeCriticalSection (&profiler_coverage_mutex);
98 * mono_profiler_set_events:
99 * @events: an ORed set of values made up of MONO_PROFILER_ flags
101 * The events descriped in the @events argument is a set of flags
102 * that represent which profiling events must be triggered. For
103 * example if you have registered a set of methods for tracking
104 * JIT compilation start and end with mono_profiler_install_jit_compile,
105 * you will want to pass the MONO_PROFILE_JIT_COMPILATION flag to
108 * You can call mono_profile_set_events more than once and you can
109 * do this at runtime to modify which methods are invoked.
112 mono_profiler_set_events (MonoProfileFlags events)
114 mono_profiler_events = events;
118 * mono_profiler_get_events:
120 * Returns a list of active events that will be intercepted.
123 mono_profiler_get_events (void)
125 return mono_profiler_events;
129 * mono_profiler_install_enter_leave:
130 * @enter: the routine to be called on each method entry
131 * @fleave: the routine to be called each time a method returns
133 * Use this routine to install routines that will be called everytime
134 * a method enters and leaves. The routines will receive as an argument
135 * the MonoMethod representing the method that is entering or leaving.
138 mono_profiler_install_enter_leave (MonoProfileMethodFunc enter, MonoProfileMethodFunc fleave)
140 method_enter = enter;
141 method_leave = fleave;
145 * mono_profiler_install_jit_compile:
146 * @start: the routine to be called when the JIT process starts.
147 * @end: the routine to be called when the JIT process ends.
149 * Use this routine to install routines that will be called when JIT
150 * compilation of a method starts and completes.
153 mono_profiler_install_jit_compile (MonoProfileMethodFunc start, MonoProfileMethodResult end)
160 mono_profiler_install_jit_end (MonoProfileJitResult end)
166 mono_profiler_install_thread (MonoProfileThreadFunc start, MonoProfileThreadFunc end)
168 thread_start = start;
173 mono_profiler_install_transition (MonoProfileMethodResult callback)
175 man_unman_transition = callback;
179 mono_profiler_install_allocation (MonoProfileAllocFunc callback)
181 allocation_cb = callback;
185 mono_profiler_install_statistical (MonoProfileStatFunc callback)
187 statistical_cb = callback;
191 mono_profiler_install_coverage_filter (MonoProfileCoverageFilterFunc callback)
193 coverage_filter_cb = callback;
197 mono_profiler_install_appdomain (MonoProfileAppDomainFunc start_load, MonoProfileAppDomainResult end_load,
198 MonoProfileAppDomainFunc start_unload, MonoProfileAppDomainFunc end_unload)
201 domain_start_load = start_load;
202 domain_end_load = end_load;
203 domain_start_unload = start_unload;
204 domain_end_unload = end_unload;
208 mono_profiler_install_assembly (MonoProfileAssemblyFunc start_load, MonoProfileAssemblyResult end_load,
209 MonoProfileAssemblyFunc start_unload, MonoProfileAssemblyFunc end_unload)
211 assembly_start_load = start_load;
212 assembly_end_load = end_load;
213 assembly_start_unload = start_unload;
214 assembly_end_unload = end_unload;
218 mono_profiler_install_module (MonoProfileModuleFunc start_load, MonoProfileModuleResult end_load,
219 MonoProfileModuleFunc start_unload, MonoProfileModuleFunc end_unload)
221 module_start_load = start_load;
222 module_end_load = end_load;
223 module_start_unload = start_unload;
224 module_end_unload = end_unload;
228 mono_profiler_install_class (MonoProfileClassFunc start_load, MonoProfileClassResult end_load,
229 MonoProfileClassFunc start_unload, MonoProfileClassFunc end_unload)
231 class_start_load = start_load;
232 class_end_load = end_load;
233 class_start_unload = start_unload;
234 class_end_unload = end_unload;
238 mono_profiler_method_enter (MonoMethod *method)
240 if ((mono_profiler_events & MONO_PROFILE_ENTER_LEAVE) && method_enter)
241 method_enter (current_profiler, method);
245 mono_profiler_method_leave (MonoMethod *method)
247 if ((mono_profiler_events & MONO_PROFILE_ENTER_LEAVE) && method_leave)
248 method_leave (current_profiler, method);
252 mono_profiler_method_jit (MonoMethod *method)
254 if ((mono_profiler_events & MONO_PROFILE_JIT_COMPILATION) && jit_start)
255 jit_start (current_profiler, method);
259 mono_profiler_method_end_jit (MonoMethod *method, MonoJitInfo* jinfo, int result)
261 if ((mono_profiler_events & MONO_PROFILE_JIT_COMPILATION)) {
263 jit_end (current_profiler, method, result);
265 jit_end2 (current_profiler, method, jinfo, result);
270 mono_profiler_code_transition (MonoMethod *method, int result)
272 if ((mono_profiler_events & MONO_PROFILE_TRANSITIONS) && man_unman_transition)
273 man_unman_transition (current_profiler, method, result);
277 mono_profiler_allocation (MonoObject *obj, MonoClass *klass)
279 if ((mono_profiler_events & MONO_PROFILE_ALLOCATIONS) && allocation_cb)
280 allocation_cb (current_profiler, obj, klass);
284 mono_profiler_stat_hit (guchar *ip, void *context)
286 if ((mono_profiler_events & MONO_PROFILE_STATISTICAL) && statistical_cb)
287 statistical_cb (current_profiler, ip, context);
291 mono_profiler_thread_start (gsize tid)
293 if ((mono_profiler_events & MONO_PROFILE_THREADS) && thread_start)
294 thread_start (current_profiler, tid);
298 mono_profiler_thread_end (gsize tid)
300 if ((mono_profiler_events & MONO_PROFILE_THREADS) && thread_end)
301 thread_end (current_profiler, tid);
305 mono_profiler_assembly_event (MonoAssembly *assembly, int code)
307 if (!(mono_profiler_events & MONO_PROFILE_ASSEMBLY_EVENTS))
311 case MONO_PROFILE_START_LOAD:
312 if (assembly_start_load)
313 assembly_start_load (current_profiler, assembly);
315 case MONO_PROFILE_START_UNLOAD:
316 if (assembly_start_unload)
317 assembly_start_unload (current_profiler, assembly);
319 case MONO_PROFILE_END_UNLOAD:
320 if (assembly_end_unload)
321 assembly_end_unload (current_profiler, assembly);
324 g_assert_not_reached ();
329 mono_profiler_assembly_loaded (MonoAssembly *assembly, int result)
331 if ((mono_profiler_events & MONO_PROFILE_ASSEMBLY_EVENTS) && assembly_end_load)
332 assembly_end_load (current_profiler, assembly, result);
336 mono_profiler_module_event (MonoImage *module, int code)
338 if (!(mono_profiler_events & MONO_PROFILE_MODULE_EVENTS))
342 case MONO_PROFILE_START_LOAD:
343 if (module_start_load)
344 module_start_load (current_profiler, module);
346 case MONO_PROFILE_START_UNLOAD:
347 if (module_start_unload)
348 module_start_unload (current_profiler, module);
350 case MONO_PROFILE_END_UNLOAD:
351 if (module_end_unload)
352 module_end_unload (current_profiler, module);
355 g_assert_not_reached ();
360 mono_profiler_module_loaded (MonoImage *module, int result)
362 if ((mono_profiler_events & MONO_PROFILE_MODULE_EVENTS) && module_end_load)
363 module_end_load (current_profiler, module, result);
367 mono_profiler_class_event (MonoClass *klass, int code)
369 if (!(mono_profiler_events & MONO_PROFILE_CLASS_EVENTS))
373 case MONO_PROFILE_START_LOAD:
374 if (class_start_load)
375 class_start_load (current_profiler, klass);
377 case MONO_PROFILE_START_UNLOAD:
378 if (class_start_unload)
379 class_start_unload (current_profiler, klass);
381 case MONO_PROFILE_END_UNLOAD:
382 if (class_end_unload)
383 class_end_unload (current_profiler, klass);
386 g_assert_not_reached ();
391 mono_profiler_class_loaded (MonoClass *klass, int result)
393 if ((mono_profiler_events & MONO_PROFILE_CLASS_EVENTS) && class_end_load)
394 class_end_load (current_profiler, klass, result);
398 mono_profiler_appdomain_event (MonoDomain *domain, int code)
400 if (!(mono_profiler_events & MONO_PROFILE_APPDOMAIN_EVENTS))
404 case MONO_PROFILE_START_LOAD:
405 if (domain_start_load)
406 domain_start_load (current_profiler, domain);
408 case MONO_PROFILE_START_UNLOAD:
409 if (domain_start_unload)
410 domain_start_unload (current_profiler, domain);
412 case MONO_PROFILE_END_UNLOAD:
413 if (domain_end_unload)
414 domain_end_unload (current_profiler, domain);
417 g_assert_not_reached ();
422 mono_profiler_appdomain_loaded (MonoDomain *domain, int result)
424 if ((mono_profiler_events & MONO_PROFILE_APPDOMAIN_EVENTS) && domain_end_load)
425 domain_end_load (current_profiler, domain, result);
429 mono_profiler_shutdown (void)
431 if (current_profiler && shutdown_callback)
432 shutdown_callback (current_profiler);
436 mono_profiler_gc_heap_resize (gint64 new_size)
438 if ((mono_profiler_events & MONO_PROFILE_GC) && gc_heap_resize)
439 gc_heap_resize (current_profiler, new_size);
443 mono_profiler_gc_event (MonoGCEvent event, int generation)
445 if ((mono_profiler_events & MONO_PROFILE_GC) && gc_event)
446 gc_event (current_profiler, event, generation);
450 mono_profiler_install_gc (MonoProfileGCFunc callback, MonoProfileGCResizeFunc heap_resize_callback)
452 mono_gc_enable_events ();
454 gc_heap_resize = heap_resize_callback;
457 static GHashTable *coverage_hash = NULL;
459 MonoProfileCoverageInfo*
460 mono_profiler_coverage_alloc (MonoMethod *method, int entries)
462 MonoProfileCoverageInfo *res;
464 if (coverage_filter_cb)
465 if (! (*coverage_filter_cb) (current_profiler, method))
468 mono_profiler_coverage_lock ();
470 coverage_hash = g_hash_table_new (NULL, NULL);
472 res = g_malloc0 (sizeof (MonoProfileCoverageInfo) + sizeof (void*) * 2 * entries);
474 res->entries = entries;
476 g_hash_table_insert (coverage_hash, method, res);
477 mono_profiler_coverage_unlock ();
482 /* safe only when the method antive code has been unloaded */
484 mono_profiler_coverage_free (MonoMethod *method)
486 MonoProfileCoverageInfo* info;
488 mono_profiler_coverage_lock ();
489 if (!coverage_hash) {
490 mono_profiler_coverage_unlock ();
494 info = g_hash_table_lookup (coverage_hash, method);
497 g_hash_table_remove (coverage_hash, method);
499 mono_profiler_coverage_unlock ();
503 * mono_profiler_coverage_get:
504 * @prof: The profiler handle, installed with mono_profiler_install
505 * @method: the method to gather information from.
506 * @func: A routine that will be called back with the results
508 * If the MONO_PROFILER_INS_COVERAGE flag was active during JIT compilation
509 * it is posisble to obtain coverage information about a give method.
511 * The function @func will be invoked repeatedly with instances of the
512 * MonoProfileCoverageEntry structure.
515 mono_profiler_coverage_get (MonoProfiler *prof, MonoMethod *method, MonoProfileCoverageFunc func)
517 MonoProfileCoverageInfo* info;
520 const unsigned char *start, *end, *cil_code;
521 MonoMethodHeader *header;
522 MonoProfileCoverageEntry entry;
523 MonoDebugMethodInfo *debug_minfo;
525 mono_profiler_coverage_lock ();
526 info = g_hash_table_lookup (coverage_hash, method);
527 mono_profiler_coverage_unlock ();
532 header = mono_method_get_header (method);
533 start = mono_method_header_get_code (header, &code_size, NULL);
534 debug_minfo = mono_debug_lookup_method (method);
536 end = start + code_size;
537 for (i = 0; i < info->entries; ++i) {
538 cil_code = info->data [i].cil_code;
539 if (cil_code && cil_code >= start && cil_code < end) {
540 offset = cil_code - start;
541 entry.iloffset = offset;
542 entry.method = method;
543 entry.counter = info->data [i].count;
544 entry.line = entry.col = 1;
545 entry.filename = NULL;
547 MonoDebugSourceLocation *location;
549 location = mono_debug_symfile_lookup_location (debug_minfo, offset);
551 entry.line = location->row;
552 entry.col = location->column;
553 entry.filename = g_strdup (location->source_file);
554 mono_debug_free_source_location (location);
559 g_free (entry.filename);
564 #ifndef DISABLE_PROFILER
566 * Small profiler extracted from mint: we should move it in a loadable module
567 * and improve it to do graphs and more accurate timestamping with rdtsc.
570 static FILE* poutput = NULL;
573 #define USE_WIN32COUNTER 0
577 unsigned int lows, highs, lowe, highe;
580 #define rdtsc(low,high) \
581 __asm__ __volatile__("rdtsc" : "=a" (low), "=d" (high))
586 rdtsc_elapsed (MonoRdtscTimer *t)
588 unsigned long long diff;
589 unsigned int highe = t->highe;
590 if (t->lowe < t->lows)
592 diff = (((unsigned long long) highe - t->highs) << 32) + (t->lowe - t->lows);
593 return ((double)diff / freq) / 1000000; /* have to return the result in seconds */
604 if (!(cpuinfo = fopen ("/proc/cpuinfo", "r")))
606 while (fgets (buf, sizeof(buf), cpuinfo)) {
607 if (sscanf (buf, "cpu MHz : %f", &val) == 1) {
608 /*printf ("got mh: %f\n", val);*/
611 if (strncmp (buf, "flags", 5) == 0) {
612 if (strstr (buf, "tsc")) {
614 /*printf ("have tsc\n");*/
619 return have_flag? have_freq: 0;
622 #define MONO_TIMER_STARTUP \
623 if (!(freq = have_rdtsc ())) g_error ("Compiled with TSC support, but none found");
624 #define MONO_TIMER_TYPE MonoRdtscTimer
625 #define MONO_TIMER_INIT(t)
626 #define MONO_TIMER_DESTROY(t)
627 #define MONO_TIMER_START(t) rdtsc ((t).lows, (t).highs);
628 #define MONO_TIMER_STOP(t) rdtsc ((t).lowe, (t).highe);
629 #define MONO_TIMER_ELAPSED(t) rdtsc_elapsed (&(t))
631 #elif USE_WIN32COUNTER
635 LARGE_INTEGER start, stop;
641 win32_elapsed (MonoWin32Timer *t)
643 LONGLONG diff = t->stop.QuadPart - t->start.QuadPart;
644 return ((double)diff / freq) / 1000000; /* have to return the result in seconds */
648 have_win32counter (void) {
651 if (!QueryPerformanceFrequency (&f))
656 #define MONO_TIMER_STARTUP \
657 if (!(freq = have_win32counter ())) g_error ("Compiled with Win32 counter support, but none found");
658 #define MONO_TIMER_TYPE MonoWin32Timer
659 #define MONO_TIMER_INIT(t)
660 #define MONO_TIMER_DESTROY(t)
661 #define MONO_TIMER_START(t) QueryPerformanceCounter (&(t).start)
662 #define MONO_TIMER_STOP(t) QueryPerformanceCounter (&(t).stop)
663 #define MONO_TIMER_ELAPSED(t) win32_elapsed (&(t))
668 GTimeVal start, stop;
672 timeval_elapsed (MonoGLibTimer *t)
674 if (t->start.tv_usec > t->stop.tv_usec) {
675 t->stop.tv_usec += G_USEC_PER_SEC;
678 return (t->stop.tv_sec - t->start.tv_sec)
679 + ((double)(t->stop.tv_usec - t->start.tv_usec))/ G_USEC_PER_SEC;
682 #define MONO_TIMER_STARTUP
683 #define MONO_TIMER_TYPE MonoGLibTimer
684 #define MONO_TIMER_INIT(t)
685 #define MONO_TIMER_DESTROY(t)
686 #define MONO_TIMER_START(t) g_get_current_time (&(t).start)
687 #define MONO_TIMER_STOP(t) g_get_current_time (&(t).stop)
688 #define MONO_TIMER_ELAPSED(t) timeval_elapsed (&(t))
691 typedef struct _AllocInfo AllocInfo;
692 typedef struct _CallerInfo CallerInfo;
693 typedef struct _LastCallerInfo LastCallerInfo;
695 struct _MonoProfiler {
697 MonoMemPool *mempool;
698 /* info about JIT time */
699 MONO_TIMER_TYPE jit_timer;
702 MonoMethod *max_jit_method;
707 /* chain of callers for the current thread */
708 LastCallerInfo *callers;
709 /* LastCallerInfo nodes for faster allocation */
710 LastCallerInfo *cstorage;
717 AllocInfo *alloc_info;
718 CallerInfo *caller_info;
721 typedef struct _MethodCallProfile MethodCallProfile;
723 struct _MethodCallProfile {
724 MethodCallProfile *next;
725 MONO_TIMER_TYPE timer;
742 struct _LastCallerInfo {
743 LastCallerInfo *next;
745 MONO_TIMER_TYPE timer;
749 create_profiler (void)
751 MonoProfiler *prof = g_new0 (MonoProfiler, 1);
753 prof->methods = g_hash_table_new (mono_aligned_addr_hash, NULL);
754 MONO_TIMER_INIT (prof->jit_timer);
755 prof->mempool = mono_mempool_new ();
760 #ifdef HAVE_KW_THREAD
761 static __thread MonoProfiler * tls_profiler;
762 # define GET_PROFILER() tls_profiler
763 # define SET_PROFILER(x) tls_profiler = (x)
764 # define ALLOC_PROFILER() /* nop */
766 static guint32 profiler_thread_id = -1;
767 # define GET_PROFILER() ((MonoProfiler *)TlsGetValue (profiler_thread_id))
768 # define SET_PROFILER(x) TlsSetValue (profiler_thread_id, x);
769 # define ALLOC_PROFILER() profiler_thread_id = TlsAlloc ()
772 #define GET_THREAD_PROF(prof) do { \
773 MonoProfiler *_tprofiler = GET_PROFILER (); \
775 _tprofiler = create_profiler (); \
776 prof->per_thread = g_slist_prepend (prof->per_thread, _tprofiler); \
777 SET_PROFILER (_tprofiler); \
782 /* thread unsafe but faster variant */
783 #define GET_THREAD_PROF(prof)
787 compare_profile (MethodProfile *profa, MethodProfile *profb)
789 return (gint)((profb->total - profa->total)*1000);
793 build_profile (MonoMethod *m, MethodProfile *prof, GList **funcs)
796 *funcs = g_list_insert_sorted (*funcs, prof, (GCompareFunc)compare_profile);
800 method_get_name (MonoMethod* method)
804 sig = mono_signature_get_desc (mono_method_signature (method), FALSE);
805 res = g_strdup_printf ("%s%s%s::%s(%s)", method->klass->name_space,
806 method->klass->name_space ? "." : "", method->klass->name,
812 static void output_callers (MethodProfile *p);
815 output_profile (GList *funcs)
820 guint64 total_calls = 0;
823 fprintf (poutput, "Time(ms) Count P/call(ms) Method name\n");
824 for (tmp = funcs; tmp; tmp = tmp->next) {
826 total_calls += p->count;
827 if (!(gint)(p->total*1000))
829 m = method_get_name (p->method);
830 fprintf (poutput, "########################\n");
831 fprintf (poutput, "% 8.3f ", (double) (p->total * 1000));
832 fprintf (poutput, "%7llu ", (unsigned long long)p->count);
833 fprintf (poutput, "% 8.3f ", (double) (p->total * 1000)/(double)p->count);
834 fprintf (poutput, " %s\n", m);
840 fprintf (poutput, "Total number of calls: %lld\n", (long long)total_calls);
849 compare_newobj_profile (NewobjProfile *profa, NewobjProfile *profb)
851 if (profb->count == profa->count)
854 return profb->count > profa->count ? 1 : -1;
858 build_newobj_profile (MonoClass *class, MethodProfile *mprof, GList **funcs)
860 NewobjProfile *prof = g_new (NewobjProfile, 1);
865 /* we use the total amount of memory to sort */
866 for (tmp = mprof->alloc_info; tmp; tmp = tmp->next)
869 *funcs = g_list_insert_sorted (*funcs, prof, (GCompareFunc)compare_newobj_profile);
873 compare_caller (CallerInfo *a, CallerInfo *b)
875 return b->count - a->count;
879 compare_alloc (AllocInfo *a, AllocInfo *b)
881 return b->mem - a->mem;
885 sort_alloc_list (AllocInfo *ai)
889 for (tmp = ai; tmp; tmp = tmp->next) {
890 l = g_slist_insert_sorted (l, tmp, (GCompareFunc)compare_alloc);
896 sort_caller_list (CallerInfo *ai)
900 for (tmp = ai; tmp; tmp = tmp->next) {
901 l = g_slist_insert_sorted (l, tmp, (GCompareFunc)compare_caller);
907 output_callers (MethodProfile *p) {
908 guint total_callers, percent;
909 GSList *sorted, *tmps;
913 fprintf (poutput, " Callers (with count) that contribute at least for 1%%:\n");
915 for (cinfo = p->caller_info; cinfo; cinfo = cinfo->next) {
916 total_callers += cinfo->count;
918 sorted = sort_caller_list (p->caller_info);
919 for (tmps = sorted; tmps; tmps = tmps->next) {
921 percent = (cinfo->count * 100)/total_callers;
924 m = method_get_name (cinfo->caller);
925 fprintf (poutput, " %8d % 3d %% %s\n", cinfo->count, percent, m);
930 /* This isn't defined on older glib versions and on some platforms */
931 #ifndef G_GUINT64_FORMAT
932 #define G_GUINT64_FORMAT "ul"
936 output_newobj_profile (GList *proflist)
947 GSList *sorted, *tmps;
949 fprintf (poutput, "\nAllocation profiler\n");
952 fprintf (poutput, "%-9s %s\n", "Total mem", "Method");
953 for (tmp = proflist; tmp; tmp = tmp->next) {
956 if (p->count < 50000)
959 m = method_get_name (mp->method);
960 fprintf (poutput, "########################\n%8" G_GUINT64_FORMAT " KB %s\n", (p->count / 1024), m);
962 sorted = sort_alloc_list (mp->alloc_info);
963 for (tmps = sorted; tmps; tmps = tmps->next) {
965 if (ainfo->mem < 50000)
967 klass = ainfo->klass;
970 klass = klass->element_class;
974 g_snprintf (buf, sizeof (buf), "%s%s%s%s",
975 klass->name_space, klass->name_space ? "." : "", klass->name, isarray);
976 fprintf (poutput, " %8" G_GUINT64_FORMAT " KB %8" G_GUINT64_FORMAT " %-48s\n", (ainfo->mem / 1024), ainfo->count, buf);
981 fprintf (poutput, "Total memory allocated: %" G_GUINT64_FORMAT " KB\n", total / 1024);
985 merge_methods (MonoMethod *method, MethodProfile *profile, MonoProfiler *prof)
987 MethodProfile *mprof;
988 AllocInfo *talloc_info, *alloc_info;
989 CallerInfo *tcaller_info, *caller_info;
991 mprof = g_hash_table_lookup (prof->methods, method);
993 /* the master thread didn't see this method, just transfer the info as is */
994 g_hash_table_insert (prof->methods, method, profile);
997 /* merge the info from profile into mprof */
998 mprof->count += profile->count;
999 mprof->total += profile->total;
1000 /* merge alloc info */
1001 for (talloc_info = profile->alloc_info; talloc_info; talloc_info = talloc_info->next) {
1002 for (alloc_info = mprof->alloc_info; alloc_info; alloc_info = alloc_info->next) {
1003 if (alloc_info->klass == talloc_info->klass) {
1004 /* mprof already has a record for the klass, merge */
1005 alloc_info->count += talloc_info->count;
1006 alloc_info->mem += talloc_info->mem;
1011 /* mprof didn't have the info, just copy it over */
1012 alloc_info = mono_mempool_alloc0 (prof->mempool, sizeof (AllocInfo));
1013 *alloc_info = *talloc_info;
1014 alloc_info->next = mprof->alloc_info;
1015 mprof->alloc_info = alloc_info->next;
1018 /* merge callers info */
1019 for (tcaller_info = profile->caller_info; tcaller_info; tcaller_info = tcaller_info->next) {
1020 for (caller_info = mprof->caller_info; caller_info; caller_info = caller_info->next) {
1021 if (caller_info->caller == tcaller_info->caller) {
1022 /* mprof already has a record for the caller method, merge */
1023 caller_info->count += tcaller_info->count;
1028 /* mprof didn't have the info, just copy it over */
1029 caller_info = mono_mempool_alloc0 (prof->mempool, sizeof (CallerInfo));
1030 *caller_info = *tcaller_info;
1031 caller_info->next = mprof->caller_info;
1032 mprof->caller_info = caller_info;
1038 merge_thread_data (MonoProfiler *master, MonoProfiler *tprof)
1040 master->jit_time += tprof->jit_time;
1041 master->methods_jitted += tprof->methods_jitted;
1042 if (master->max_jit_time < tprof->max_jit_time) {
1043 master->max_jit_time = tprof->max_jit_time;
1044 master->max_jit_method = tprof->max_jit_method;
1047 g_hash_table_foreach (tprof->methods, (GHFunc)merge_methods, master);
1051 simple_method_enter (MonoProfiler *prof, MonoMethod *method)
1053 MethodProfile *profile_info;
1054 LastCallerInfo *callinfo;
1055 GET_THREAD_PROF (prof);
1056 /*g_print ("enter %p %s::%s in %d (%p)\n", method, method->klass->name, method->name, GetCurrentThreadId (), prof);*/
1057 if (!(profile_info = g_hash_table_lookup (prof->methods, method))) {
1058 profile_info = mono_mempool_alloc0 (prof->mempool, sizeof (MethodProfile));
1059 MONO_TIMER_INIT (profile_info->u.timer);
1060 g_hash_table_insert (prof->methods, method, profile_info);
1062 profile_info->count++;
1063 if (prof->callers) {
1065 MonoMethod *caller = prof->callers->method;
1066 for (cinfo = profile_info->caller_info; cinfo; cinfo = cinfo->next) {
1067 if (cinfo->caller == caller)
1071 cinfo = mono_mempool_alloc0 (prof->mempool, sizeof (CallerInfo));
1072 cinfo->caller = caller;
1073 cinfo->next = profile_info->caller_info;
1074 profile_info->caller_info = cinfo;
1078 if (!(callinfo = prof->cstorage)) {
1079 callinfo = mono_mempool_alloc (prof->mempool, sizeof (LastCallerInfo));
1080 MONO_TIMER_INIT (callinfo->timer);
1082 prof->cstorage = prof->cstorage->next;
1084 callinfo->method = method;
1085 callinfo->next = prof->callers;
1086 prof->callers = callinfo;
1087 MONO_TIMER_START (callinfo->timer);
1091 simple_method_leave (MonoProfiler *prof, MonoMethod *method)
1093 MethodProfile *profile_info;
1094 LastCallerInfo *callinfo, *newcallinfo = NULL;
1096 GET_THREAD_PROF (prof);
1097 /*g_print ("leave %p %s::%s in %d (%p)\n", method, method->klass->name, method->name, GetCurrentThreadId (), prof);*/
1098 callinfo = prof->callers;
1099 /* should really not happen, but we don't catch exceptions events, yet ... */
1101 MONO_TIMER_STOP (callinfo->timer);
1102 profile_info = g_hash_table_lookup (prof->methods, callinfo->method);
1104 profile_info->total += MONO_TIMER_ELAPSED (callinfo->timer);
1105 newcallinfo = callinfo->next;
1106 callinfo->next = prof->cstorage;
1107 prof->cstorage = callinfo;
1108 if (callinfo->method == method)
1110 callinfo = newcallinfo;
1112 prof->callers = newcallinfo;
1116 simple_allocation (MonoProfiler *prof, MonoObject *obj, MonoClass *klass)
1118 MethodProfile *profile_info;
1121 GET_THREAD_PROF (prof);
1122 if (prof->callers) {
1123 MonoMethod *caller = prof->callers->method;
1125 /* Otherwise all allocations are attributed to icall_wrapper_mono_object_new */
1126 if (caller->wrapper_type == MONO_WRAPPER_MANAGED_TO_NATIVE)
1127 caller = prof->callers->next->method;
1129 if (!(profile_info = g_hash_table_lookup (prof->methods, caller)))
1130 g_assert_not_reached ();
1132 return; /* fine for now */
1135 for (tmp = profile_info->alloc_info; tmp; tmp = tmp->next) {
1136 if (tmp->klass == klass)
1140 tmp = mono_mempool_alloc0 (prof->mempool, sizeof (AllocInfo));
1142 tmp->next = profile_info->alloc_info;
1143 profile_info->alloc_info = tmp;
1146 tmp->mem += mono_object_get_size (obj);
1150 simple_method_jit (MonoProfiler *prof, MonoMethod *method)
1152 GET_THREAD_PROF (prof);
1153 prof->methods_jitted++;
1154 MONO_TIMER_START (prof->jit_timer);
1158 simple_method_end_jit (MonoProfiler *prof, MonoMethod *method, int result)
1161 GET_THREAD_PROF (prof);
1162 MONO_TIMER_STOP (prof->jit_timer);
1163 jtime = MONO_TIMER_ELAPSED (prof->jit_timer);
1164 prof->jit_time += jtime;
1165 if (jtime > prof->max_jit_time) {
1166 prof->max_jit_time = jtime;
1167 prof->max_jit_method = method;
1171 /* about 10 minutes of samples */
1172 #define MAX_PROF_SAMPLES (1000*60*10)
1173 static int prof_counts = 0;
1174 static int prof_ucounts = 0;
1175 static gpointer* prof_addresses = NULL;
1176 static GHashTable *prof_table = NULL;
1179 simple_stat_hit (MonoProfiler *prof, guchar *ip, void *context)
1183 if (prof_counts >= MAX_PROF_SAMPLES)
1185 pos = InterlockedIncrement (&prof_counts);
1186 prof_addresses [pos - 1] = ip;
1190 compare_methods_prof (gconstpointer a, gconstpointer b)
1192 int ca = GPOINTER_TO_UINT (g_hash_table_lookup (prof_table, a));
1193 int cb = GPOINTER_TO_UINT (g_hash_table_lookup (prof_table, b));
1198 prof_foreach (char *method, gpointer c, gpointer data)
1200 GList **list = data;
1201 *list = g_list_insert_sorted (*list, method, compare_methods_prof);
1204 typedef struct Addr2LineData Addr2LineData;
1206 struct Addr2LineData {
1207 Addr2LineData *next;
1214 static Addr2LineData *addr2line_pipes = NULL;
1217 try_addr2line (const char* binary, gpointer ip)
1221 Addr2LineData *addr2line;
1223 for (addr2line = addr2line_pipes; addr2line; addr2line = addr2line->next) {
1224 if (strcmp (binary, addr2line->binary) == 0)
1228 const char *addr_argv[] = {"addr2line", "-f", "-e", binary, NULL};
1231 if (!g_spawn_async_with_pipes (NULL, (char**)addr_argv, NULL, G_SPAWN_SEARCH_PATH, NULL, NULL,
1232 &child_pid, &ch_in, &ch_out, NULL, NULL)) {
1233 return g_strdup (binary);
1235 addr2line = g_new0 (Addr2LineData, 1);
1236 addr2line->child_pid = child_pid;
1237 addr2line->binary = g_strdup (binary);
1238 addr2line->pipein = fdopen (ch_in, "w");
1239 addr2line->pipeout = fdopen (ch_out, "r");
1240 addr2line->next = addr2line_pipes;
1241 addr2line_pipes = addr2line;
1243 fprintf (addr2line->pipein, "%p\n", ip);
1244 fflush (addr2line->pipein);
1245 /* we first get the func name and then file:lineno in a second line */
1246 if (fgets (buf, sizeof (buf), addr2line->pipeout) && buf [0] != '?') {
1247 char *end = strchr (buf, '\n');
1250 res = g_strdup_printf ("%s(%s", binary, buf);
1251 /* discard the filename/line info */
1252 fgets (buf, sizeof (buf), addr2line->pipeout);
1254 res = g_strdup (binary);
1260 stat_prof_report (void)
1263 int count = prof_counts;
1267 GList *tmp, *sorted = NULL;
1268 int pcount = ++ prof_counts;
1270 prof_counts = MAX_PROF_SAMPLES;
1271 for (i = 0; i < count; ++i) {
1272 ip = prof_addresses [i];
1273 ji = mono_jit_info_table_find (mono_domain_get (), ip);
1275 mn = mono_method_full_name (ji->method, TRUE);
1277 #ifdef HAVE_BACKTRACE_SYMBOLS
1282 names = backtrace_symbols (&ip, 1);
1283 send = strchr (names [0], '+');
1290 send = strchr (names [0], '[');
1293 if (no_func && names [0][0]) {
1294 char *endp = strchr (names [0], 0);
1295 while (--endp >= names [0] && g_ascii_isspace (*endp))
1297 mn = try_addr2line (names [0], ip);
1299 mn = g_strdup (names [0]);
1304 mn = g_strdup_printf ("unmanaged [%p]", ip);
1307 c = GPOINTER_TO_UINT (g_hash_table_lookup (prof_table, mn));
1309 g_hash_table_insert (prof_table, mn, GUINT_TO_POINTER (c));
1313 fprintf (poutput, "prof counts: total/unmanaged: %d/%d\n", pcount, prof_ucounts);
1314 g_hash_table_foreach (prof_table, (GHFunc)prof_foreach, &sorted);
1315 for (tmp = sorted; tmp; tmp = tmp->next) {
1317 c = GPOINTER_TO_UINT (g_hash_table_lookup (prof_table, tmp->data));
1318 perc = c*100.0/count;
1319 fprintf (poutput, "%7d\t%5.2f %% %s\n", c, perc, (char*)tmp->data);
1321 g_list_free (sorted);
1325 simple_appdomain_unload (MonoProfiler *prof, MonoDomain *domain)
1327 /* FIXME: we should actually record partial data for each domain,
1328 * since the ip->ji->method mappings are going away at domain unload time.
1330 if (domain == mono_get_root_domain ())
1331 stat_prof_report ();
1335 simple_shutdown (MonoProfiler *prof)
1337 GList *profile = NULL;
1338 MonoProfiler *tprof;
1342 for (tmp = prof->per_thread; tmp; tmp = tmp->next) {
1344 merge_thread_data (prof, tprof);
1347 fprintf (poutput, "Total time spent compiling %d methods (sec): %.4g\n", prof->methods_jitted, prof->jit_time);
1348 if (prof->max_jit_method) {
1349 str = method_get_name (prof->max_jit_method);
1350 fprintf (poutput, "Slowest method to compile (sec): %.4g: %s\n", prof->max_jit_time, str);
1353 g_hash_table_foreach (prof->methods, (GHFunc)build_profile, &profile);
1354 output_profile (profile);
1355 g_list_free (profile);
1358 g_hash_table_foreach (prof->methods, (GHFunc)build_newobj_profile, &profile);
1359 output_newobj_profile (profile);
1360 g_list_free (profile);
1362 g_free (prof_addresses);
1363 prof_addresses = NULL;
1364 g_hash_table_destroy (prof_table);
1368 mono_profiler_install_simple (const char *desc)
1371 gchar **args, **ptr;
1372 MonoProfileFlags flags = 0;
1378 desc = "alloc,time,jit";
1382 if (strstr (desc, ":"))
1383 desc = strstr (desc, ":") + 1;
1385 desc = "alloc,time,jit";
1386 args = g_strsplit (desc, ",", -1);
1388 for (ptr = args; ptr && *ptr; ptr++) {
1389 const char *arg = *ptr;
1391 if (!strcmp (arg, "time"))
1392 flags |= MONO_PROFILE_ENTER_LEAVE;
1393 else if (!strcmp (arg, "alloc"))
1394 flags |= MONO_PROFILE_ALLOCATIONS;
1395 else if (!strcmp (arg, "stat"))
1396 flags |= MONO_PROFILE_STATISTICAL | MONO_PROFILE_APPDOMAIN_EVENTS;
1397 else if (!strcmp (arg, "jit"))
1398 flags |= MONO_PROFILE_JIT_COMPILATION;
1399 else if (strncmp (arg, "file=", 5) == 0) {
1400 poutput = fopen (arg + 5, "wb");
1403 fprintf (stderr, "profiler : cannot open profile output file '%s'.\n", arg + 5);
1406 fprintf (stderr, "profiler : Unknown argument '%s'.\n", arg);
1411 if (flags & MONO_PROFILE_ALLOCATIONS)
1412 flags |= MONO_PROFILE_ENTER_LEAVE;
1414 flags = MONO_PROFILE_ENTER_LEAVE | MONO_PROFILE_ALLOCATIONS | MONO_PROFILE_JIT_COMPILATION;
1416 prof = create_profiler ();
1418 SET_PROFILER (prof);
1420 /* statistical profiler data */
1421 prof_addresses = g_new0 (gpointer, MAX_PROF_SAMPLES);
1422 prof_table = g_hash_table_new (g_str_hash, g_str_equal);
1424 mono_profiler_install (prof, simple_shutdown);
1425 mono_profiler_install_enter_leave (simple_method_enter, simple_method_leave);
1426 mono_profiler_install_jit_compile (simple_method_jit, simple_method_end_jit);
1427 mono_profiler_install_allocation (simple_allocation);
1428 mono_profiler_install_appdomain (NULL, NULL, simple_appdomain_unload, NULL);
1429 mono_profiler_install_statistical (simple_stat_hit);
1430 mono_profiler_set_events (flags);
1433 #endif /* DISABLE_PROFILER */
1435 typedef void (*ProfilerInitializer) (const char*);
1436 #define INITIALIZER_NAME "mono_profiler_startup"
1439 * mono_profiler_load:
1440 * @desc: arguments to configure the profiler
1442 * Invoke this method to initialize the profiler. This will drive the
1443 * loading of the internal ("default") or any external profilers.
1445 * This routine is invoked by Mono's driver, but must be called manually
1446 * if you embed Mono into your application.
1449 mono_profiler_load (const char *desc)
1451 #ifndef DISABLE_PROFILER
1452 if (!desc || (strcmp ("default", desc) == 0) || (strncmp (desc, "default:", 8) == 0)) {
1453 mono_profiler_install_simple (desc);
1463 const char* col = strchr (desc, ':');
1468 mname = g_memdup (desc, col - desc);
1469 mname [col - desc] = 0;
1471 mname = g_strdup (desc);
1473 libname = g_strdup_printf ("mono-profiler-%s", mname);
1474 path = g_module_build_path (NULL, libname);
1475 pmodule = g_module_open (path, G_MODULE_BIND_LAZY);
1477 ProfilerInitializer func;
1478 if (!g_module_symbol (pmodule, INITIALIZER_NAME, (gpointer *)&func)) {
1479 g_warning ("Cannot find initializer function %s in profiler module: %s", INITIALIZER_NAME, libname);
1484 g_warning ("Error loading profiler module '%s': %s", libname, g_module_error ());