2005-08-19 Dick Porter <dick@ximian.com>
[mono.git] / mono / metadata / profiler.c
1
2 #include "config.h"
3 #include "mono/metadata/profiler-private.h"
4 #include "mono/metadata/debug-helpers.h"
5 #include "mono/metadata/mono-debug.h"
6 #include "mono/metadata/class-internals.h"
7 #include "mono/metadata/domain-internals.h"
8 #include "mono/metadata/gc-internal.h"
9 #include "mono/io-layer/io-layer.h"
10 #include <string.h>
11 #include <sys/time.h>
12 #include <gmodule.h>
13 #ifdef HAVE_BACKTRACE_SYMBOLS
14 #include <execinfo.h>
15 #endif
16
17 static MonoProfiler * current_profiler = NULL;
18
19 static MonoProfileAppDomainFunc   domain_start_load;
20 static MonoProfileAppDomainResult domain_end_load;
21 static MonoProfileAppDomainFunc   domain_start_unload;
22 static MonoProfileAppDomainFunc   domain_end_unload;
23
24 static MonoProfileAssemblyFunc   assembly_start_load;
25 static MonoProfileAssemblyResult assembly_end_load;
26 static MonoProfileAssemblyFunc   assembly_start_unload;
27 static MonoProfileAssemblyFunc   assembly_end_unload;
28
29 static MonoProfileModuleFunc   module_start_load;
30 static MonoProfileModuleResult module_end_load;
31 static MonoProfileModuleFunc   module_start_unload;
32 static MonoProfileModuleFunc   module_end_unload;
33
34 static MonoProfileClassFunc   class_start_load;
35 static MonoProfileClassResult class_end_load;
36 static MonoProfileClassFunc   class_start_unload;
37 static MonoProfileClassFunc   class_end_unload;
38
39 static MonoProfileMethodFunc   jit_start;
40 static MonoProfileMethodResult jit_end;
41 static MonoProfileMethodResult man_unman_transition;
42 static MonoProfileAllocFunc    allocation_cb;
43 static MonoProfileStatFunc     statistical_cb;
44 static MonoProfileMethodFunc   method_enter;
45 static MonoProfileMethodFunc   method_leave;
46
47 static MonoProfileThreadFunc   thread_start;
48 static MonoProfileThreadFunc   thread_end;
49
50 static MonoProfileCoverageFilterFunc coverage_filter_cb;
51
52 static MonoProfileFunc shutdown_callback;
53
54 static MonoProfileGCFunc        gc_event;
55 static MonoProfileGCResizeFunc  gc_heap_resize;
56
57 static CRITICAL_SECTION profiler_coverage_mutex;
58
59 /* this is directly accessible to other mono libs. */
60 MonoProfileFlags mono_profiler_events;
61
62 void
63 mono_profiler_install (MonoProfiler *prof, MonoProfileFunc callback)
64 {
65         if (current_profiler)
66                 g_error ("profiler already setup");
67         current_profiler = prof;
68         shutdown_callback = callback;
69         InitializeCriticalSection (&profiler_coverage_mutex);
70 }
71
72 void
73 mono_profiler_set_events (MonoProfileFlags events)
74 {
75         mono_profiler_events = events;
76 }
77
78 MonoProfileFlags
79 mono_profiler_get_events (void)
80 {
81         return mono_profiler_events;
82 }
83
84 void
85 mono_profiler_install_enter_leave (MonoProfileMethodFunc enter, MonoProfileMethodFunc fleave)
86 {
87         method_enter = enter;
88         method_leave = fleave;
89 }
90
91 void 
92 mono_profiler_install_jit_compile (MonoProfileMethodFunc start, MonoProfileMethodResult end)
93 {
94         jit_start = start;
95         jit_end = end;
96 }
97
98 void 
99 mono_profiler_install_thread (MonoProfileThreadFunc start, MonoProfileThreadFunc end)
100 {
101         thread_start = start;
102         thread_end = end;
103 }
104
105 void 
106 mono_profiler_install_transition (MonoProfileMethodResult callback)
107 {
108         man_unman_transition = callback;
109 }
110
111 void 
112 mono_profiler_install_allocation (MonoProfileAllocFunc callback)
113 {
114         allocation_cb = callback;
115 }
116
117 void 
118 mono_profiler_install_statistical (MonoProfileStatFunc callback)
119 {
120         statistical_cb = callback;
121 }
122
123 void 
124 mono_profiler_install_coverage_filter (MonoProfileCoverageFilterFunc callback)
125 {
126         coverage_filter_cb = callback;
127 }
128
129 void 
130 mono_profiler_install_appdomain   (MonoProfileAppDomainFunc start_load, MonoProfileAppDomainResult end_load,
131                                    MonoProfileAppDomainFunc start_unload, MonoProfileAppDomainFunc end_unload)
132
133 {
134         domain_start_load = start_load;
135         domain_end_load = end_load;
136         domain_start_unload = start_unload;
137         domain_end_unload = end_unload;
138 }
139
140 void 
141 mono_profiler_install_assembly    (MonoProfileAssemblyFunc start_load, MonoProfileAssemblyResult end_load,
142                                    MonoProfileAssemblyFunc start_unload, MonoProfileAssemblyFunc end_unload)
143 {
144         assembly_start_load = start_load;
145         assembly_end_load = end_load;
146         assembly_start_unload = start_unload;
147         assembly_end_unload = end_unload;
148 }
149
150 void 
151 mono_profiler_install_module      (MonoProfileModuleFunc start_load, MonoProfileModuleResult end_load,
152                                    MonoProfileModuleFunc start_unload, MonoProfileModuleFunc end_unload)
153 {
154         module_start_load = start_load;
155         module_end_load = end_load;
156         module_start_unload = start_unload;
157         module_end_unload = end_unload;
158 }
159
160 void
161 mono_profiler_install_class       (MonoProfileClassFunc start_load, MonoProfileClassResult end_load,
162                                    MonoProfileClassFunc start_unload, MonoProfileClassFunc end_unload)
163 {
164         class_start_load = start_load;
165         class_end_load = end_load;
166         class_start_unload = start_unload;
167         class_end_unload = end_unload;
168 }
169
170 void
171 mono_profiler_method_enter (MonoMethod *method)
172 {
173         if ((mono_profiler_events & MONO_PROFILE_ENTER_LEAVE) && method_enter)
174                 method_enter (current_profiler, method);
175 }
176
177 void
178 mono_profiler_method_leave (MonoMethod *method)
179 {
180         if ((mono_profiler_events & MONO_PROFILE_ENTER_LEAVE) && method_leave)
181                 method_leave (current_profiler, method);
182 }
183
184 void 
185 mono_profiler_method_jit (MonoMethod *method)
186 {
187         if ((mono_profiler_events & MONO_PROFILE_JIT_COMPILATION) && jit_start)
188                 jit_start (current_profiler, method);
189 }
190
191 void 
192 mono_profiler_method_end_jit (MonoMethod *method, int result)
193 {
194         if ((mono_profiler_events & MONO_PROFILE_JIT_COMPILATION) && jit_end)
195                 jit_end (current_profiler, method, result);
196 }
197
198 void 
199 mono_profiler_code_transition (MonoMethod *method, int result)
200 {
201         if ((mono_profiler_events & MONO_PROFILE_TRANSITIONS) && man_unman_transition)
202                 man_unman_transition (current_profiler, method, result);
203 }
204
205 void 
206 mono_profiler_allocation (MonoObject *obj, MonoClass *klass)
207 {
208         if ((mono_profiler_events & MONO_PROFILE_ALLOCATIONS) && allocation_cb)
209                 allocation_cb (current_profiler, obj, klass);
210 }
211
212 void
213 mono_profiler_stat_hit (guchar *ip, void *context)
214 {
215         if ((mono_profiler_events & MONO_PROFILE_STATISTICAL) && statistical_cb)
216                 statistical_cb (current_profiler, ip, context);
217 }
218
219 void
220 mono_profiler_thread_start (gsize tid)
221 {
222         if ((mono_profiler_events & MONO_PROFILE_THREADS) && thread_start)
223                 thread_start (current_profiler, tid);
224 }
225
226 void 
227 mono_profiler_thread_end (gsize tid)
228 {
229         if ((mono_profiler_events & MONO_PROFILE_THREADS) && thread_end)
230                 thread_end (current_profiler, tid);
231 }
232
233 void 
234 mono_profiler_assembly_event  (MonoAssembly *assembly, int code)
235 {
236         if (!(mono_profiler_events & MONO_PROFILE_ASSEMBLY_EVENTS))
237                 return;
238         
239         switch (code) {
240         case MONO_PROFILE_START_LOAD:
241                 if (assembly_start_load)
242                         assembly_start_load (current_profiler, assembly);
243                 break;
244         case MONO_PROFILE_START_UNLOAD:
245                 if (assembly_start_unload)
246                         assembly_start_unload (current_profiler, assembly);
247                 break;
248         case MONO_PROFILE_END_UNLOAD:
249                 if (assembly_end_unload)
250                         assembly_end_unload (current_profiler, assembly);
251                 break;
252         default:
253                 g_assert_not_reached ();
254         }
255 }
256
257 void 
258 mono_profiler_assembly_loaded (MonoAssembly *assembly, int result)
259 {
260         if ((mono_profiler_events & MONO_PROFILE_ASSEMBLY_EVENTS) && assembly_end_load)
261                 assembly_end_load (current_profiler, assembly, result);
262 }
263
264 void 
265 mono_profiler_module_event  (MonoImage *module, int code)
266 {
267         if (!(mono_profiler_events & MONO_PROFILE_MODULE_EVENTS))
268                 return;
269         
270         switch (code) {
271         case MONO_PROFILE_START_LOAD:
272                 if (module_start_load)
273                         module_start_load (current_profiler, module);
274                 break;
275         case MONO_PROFILE_START_UNLOAD:
276                 if (module_start_unload)
277                         module_start_unload (current_profiler, module);
278                 break;
279         case MONO_PROFILE_END_UNLOAD:
280                 if (module_end_unload)
281                         module_end_unload (current_profiler, module);
282                 break;
283         default:
284                 g_assert_not_reached ();
285         }
286 }
287
288 void 
289 mono_profiler_module_loaded (MonoImage *module, int result)
290 {
291         if ((mono_profiler_events & MONO_PROFILE_MODULE_EVENTS) && module_end_load)
292                 module_end_load (current_profiler, module, result);
293 }
294
295 void 
296 mono_profiler_class_event  (MonoClass *klass, int code)
297 {
298         if (!(mono_profiler_events & MONO_PROFILE_CLASS_EVENTS))
299                 return;
300         
301         switch (code) {
302         case MONO_PROFILE_START_LOAD:
303                 if (class_start_load)
304                         class_start_load (current_profiler, klass);
305                 break;
306         case MONO_PROFILE_START_UNLOAD:
307                 if (class_start_unload)
308                         class_start_unload (current_profiler, klass);
309                 break;
310         case MONO_PROFILE_END_UNLOAD:
311                 if (class_end_unload)
312                         class_end_unload (current_profiler, klass);
313                 break;
314         default:
315                 g_assert_not_reached ();
316         }
317 }
318
319 void 
320 mono_profiler_class_loaded (MonoClass *klass, int result)
321 {
322         if ((mono_profiler_events & MONO_PROFILE_CLASS_EVENTS) && class_end_load)
323                 class_end_load (current_profiler, klass, result);
324 }
325
326 void 
327 mono_profiler_appdomain_event  (MonoDomain *domain, int code)
328 {
329         if (!(mono_profiler_events & MONO_PROFILE_APPDOMAIN_EVENTS))
330                 return;
331         
332         switch (code) {
333         case MONO_PROFILE_START_LOAD:
334                 if (domain_start_load)
335                         domain_start_load (current_profiler, domain);
336                 break;
337         case MONO_PROFILE_START_UNLOAD:
338                 if (domain_start_unload)
339                         domain_start_unload (current_profiler, domain);
340                 break;
341         case MONO_PROFILE_END_UNLOAD:
342                 if (domain_end_unload)
343                         domain_end_unload (current_profiler, domain);
344                 break;
345         default:
346                 g_assert_not_reached ();
347         }
348 }
349
350 void 
351 mono_profiler_appdomain_loaded (MonoDomain *domain, int result)
352 {
353         if ((mono_profiler_events & MONO_PROFILE_APPDOMAIN_EVENTS) && domain_end_load)
354                 domain_end_load (current_profiler, domain, result);
355 }
356
357 void 
358 mono_profiler_shutdown (void)
359 {
360         if (current_profiler && shutdown_callback)
361                 shutdown_callback (current_profiler);
362 }
363
364 void
365 mono_profiler_gc_heap_resize (gint64 new_size)
366 {
367         if ((mono_profiler_events & MONO_PROFILE_GC) && gc_heap_resize)
368                 gc_heap_resize (current_profiler, new_size);
369 }
370
371 void
372 mono_profiler_gc_event (MonoGCEvent event, int generation)
373 {
374         if ((mono_profiler_events & MONO_PROFILE_GC) && gc_event)
375                 gc_event (current_profiler, event, generation);
376 }
377
378 void
379 mono_profiler_install_gc (MonoProfileGCFunc callback, MonoProfileGCResizeFunc heap_resize_callback)
380 {
381         mono_gc_enable_events ();
382         gc_event = callback;
383         gc_heap_resize = heap_resize_callback;
384 }
385
386 static GHashTable *coverage_hash = NULL;
387
388 MonoProfileCoverageInfo* 
389 mono_profiler_coverage_alloc (MonoMethod *method, int entries)
390 {
391         MonoProfileCoverageInfo *res;
392
393         if (coverage_filter_cb)
394                 if (! (*coverage_filter_cb) (current_profiler, method))
395                         return NULL;
396
397         EnterCriticalSection (&profiler_coverage_mutex);
398         if (!coverage_hash)
399                 coverage_hash = g_hash_table_new (NULL, NULL);
400
401         res = g_malloc0 (sizeof (MonoProfileCoverageInfo) + sizeof (void*) * 2 * entries);
402
403         res->entries = entries;
404
405         g_hash_table_insert (coverage_hash, method, res);
406         LeaveCriticalSection (&profiler_coverage_mutex);
407
408         return res;
409 }
410
411 /* safe only when the method antive code has been unloaded */
412 void
413 mono_profiler_coverage_free (MonoMethod *method)
414 {
415         MonoProfileCoverageInfo* info;
416
417         EnterCriticalSection (&profiler_coverage_mutex);
418         if (!coverage_hash) {
419                 LeaveCriticalSection (&profiler_coverage_mutex);
420                 return;
421         }
422
423         info = g_hash_table_lookup (coverage_hash, method);
424         if (info) {
425                 g_free (info);
426                 g_hash_table_remove (coverage_hash, method);
427         }
428         LeaveCriticalSection (&profiler_coverage_mutex);
429 }
430
431 void 
432 mono_profiler_coverage_get (MonoProfiler *prof, MonoMethod *method, MonoProfileCoverageFunc func)
433 {
434         MonoProfileCoverageInfo* info;
435         int i, offset;
436         guint32 line, col;
437         unsigned char *start, *end, *cil_code;
438         MonoMethodHeader *header;
439         MonoProfileCoverageEntry entry;
440
441         EnterCriticalSection (&profiler_coverage_mutex);
442         info = g_hash_table_lookup (coverage_hash, method);
443         LeaveCriticalSection (&profiler_coverage_mutex);
444
445         if (!info)
446                 return;
447
448         header = mono_method_get_header (method);
449         start = (unsigned char*)header->code;
450         end = start + header->code_size;
451         for (i = 0; i < info->entries; ++i) {
452                 cil_code = info->data [i].cil_code;
453                 if (cil_code && cil_code >= start && cil_code < end) {
454                         offset = cil_code - start;
455                         entry.iloffset = offset;
456                         entry.method = method;
457                         entry.counter = info->data [i].count;
458                         /* the debug interface doesn't support column info, sigh */
459                         col = line = 1;
460                         entry.filename = mono_debug_source_location_from_il_offset (method, offset, &line);
461                         entry.line = line;
462                         entry.col = col;
463                         func (prof, &entry);
464                 }
465         }
466 }
467
468 #ifndef DISABLE_PROFILER
469 /*
470  * Small profiler extracted from mint: we should move it in a loadable module
471  * and improve it to do graphs and more accurate timestamping with rdtsc.
472  */
473
474 #define USE_X86TSC 0
475 #define USE_WIN32COUNTER 0
476 #if USE_X86TSC
477
478 typedef struct {
479         unsigned int lows, highs, lowe, highe;
480 } MonoRdtscTimer;
481
482 #define rdtsc(low,high) \
483         __asm__ __volatile__("rdtsc" : "=a" (low), "=d" (high))
484
485 static int freq;
486
487 static double
488 rdtsc_elapsed (MonoRdtscTimer *t)
489 {
490         unsigned long long diff;
491         unsigned int highe = t->highe;
492         if (t->lowe < t->lows)
493                 highe--;
494         diff = (((unsigned long long) highe - t->highs) << 32) + (t->lowe - t->lows);
495         return ((double)diff / freq) / 1000000; /* have to return the result in seconds */
496 }
497
498 static int 
499 have_rdtsc (void) {
500         char buf[256];
501         int have_freq = 0;
502         int have_flag = 0;
503         float val;
504         FILE *cpuinfo;
505
506         if (!(cpuinfo = fopen ("/proc/cpuinfo", "r")))
507                 return 0;
508         while (fgets (buf, sizeof(buf), cpuinfo)) {
509                 if (sscanf (buf, "cpu MHz : %f", &val) == 1) {
510                         /*printf ("got mh: %f\n", val);*/
511                         have_freq = val;
512                 }
513                 if (strncmp (buf, "flags", 5) == 0) {
514                         if (strstr (buf, "tsc")) {
515                                 have_flag = 1;
516                                 /*printf ("have tsc\n");*/
517                         }
518                 }
519         }
520         fclose (cpuinfo);
521         return have_flag? have_freq: 0;
522 }
523
524 #define MONO_TIMER_STARTUP      \
525         if (!(freq = have_rdtsc ())) g_error ("Compiled with TSC support, but none found");
526 #define MONO_TIMER_TYPE  MonoRdtscTimer
527 #define MONO_TIMER_INIT(t)
528 #define MONO_TIMER_DESTROY(t)
529 #define MONO_TIMER_START(t) rdtsc ((t).lows, (t).highs);
530 #define MONO_TIMER_STOP(t) rdtsc ((t).lowe, (t).highe);
531 #define MONO_TIMER_ELAPSED(t) rdtsc_elapsed (&(t))
532
533 #elif USE_WIN32COUNTER
534 #include <windows.h>
535
536 typedef struct {
537         LARGE_INTEGER start, stop;
538 } MonoWin32Timer;
539
540 static int freq;
541
542 static double
543 win32_elapsed (MonoWin32Timer *t)
544 {
545         LONGLONG diff = t->stop.QuadPart - t->start.QuadPart;
546         return ((double)diff / freq) / 1000000; /* have to return the result in seconds */
547 }
548
549 static int 
550 have_win32counter (void) {
551         LARGE_INTEGER f;
552
553         if (!QueryPerformanceFrequency (&f))
554                 return 0;
555         return f.LowPart;
556 }
557
558 #define MONO_TIMER_STARTUP      \
559         if (!(freq = have_win32counter ())) g_error ("Compiled with Win32 counter support, but none found");
560 #define MONO_TIMER_TYPE  MonoWin32Timer
561 #define MONO_TIMER_INIT(t)
562 #define MONO_TIMER_DESTROY(t)
563 #define MONO_TIMER_START(t) QueryPerformanceCounter (&(t).start)
564 #define MONO_TIMER_STOP(t) QueryPerformanceCounter (&(t).stop)
565 #define MONO_TIMER_ELAPSED(t) win32_elapsed (&(t))
566
567 #else
568
569 typedef struct {
570         GTimeVal start, stop;
571 } MonoGLibTimer;
572
573 static double
574 timeval_elapsed (MonoGLibTimer *t)
575 {
576         if (t->start.tv_usec > t->stop.tv_usec) {
577                 t->stop.tv_usec += G_USEC_PER_SEC;
578                 t->stop.tv_sec--;
579         }
580         return (t->stop.tv_sec - t->start.tv_sec) 
581                 + ((double)(t->stop.tv_usec - t->start.tv_usec))/ G_USEC_PER_SEC;
582 }
583
584 #define MONO_TIMER_STARTUP
585 #define MONO_TIMER_TYPE MonoGLibTimer
586 #define MONO_TIMER_INIT(t)
587 #define MONO_TIMER_DESTROY(t)
588 #define MONO_TIMER_START(t) g_get_current_time (&(t).start)
589 #define MONO_TIMER_STOP(t) g_get_current_time (&(t).stop)
590 #define MONO_TIMER_ELAPSED(t) timeval_elapsed (&(t))
591 #endif
592
593 typedef struct _AllocInfo AllocInfo;
594 typedef struct _CallerInfo CallerInfo;
595 typedef struct _LastCallerInfo LastCallerInfo;
596
597 struct _MonoProfiler {
598         GHashTable *methods;
599         MonoMemPool *mempool;
600         /* info about JIT time */
601         MONO_TIMER_TYPE jit_timer;
602         double      jit_time;
603         double      max_jit_time;
604         MonoMethod *max_jit_method;
605         int         methods_jitted;
606         
607         GSList     *per_thread;
608         
609         /* chain of callers for the current thread */
610         LastCallerInfo *callers;
611         /* LastCallerInfo nodes for faster allocation */
612         LastCallerInfo *cstorage;
613 };
614
615 typedef struct {
616         MonoMethod *method;
617         guint64 count;
618         double total;
619         AllocInfo *alloc_info;
620         CallerInfo *caller_info;
621 } MethodProfile;
622
623 typedef struct _MethodCallProfile MethodCallProfile;
624
625 struct _MethodCallProfile {
626         MethodCallProfile *next;
627         MONO_TIMER_TYPE timer;
628         MonoMethod *method;
629 };
630
631 struct _AllocInfo {
632         AllocInfo *next;
633         MonoClass *klass;
634         guint count;
635         guint mem;
636 };
637
638 struct _CallerInfo {
639         CallerInfo *next;
640         MonoMethod *caller;
641         guint count;
642 };
643
644 struct _LastCallerInfo {
645         LastCallerInfo *next;
646         MonoMethod *method;
647         MONO_TIMER_TYPE timer;
648 };
649
650 static MonoProfiler*
651 create_profiler (void)
652 {
653         MonoProfiler *prof = g_new0 (MonoProfiler, 1);
654
655         prof->methods = g_hash_table_new (NULL, NULL);
656         MONO_TIMER_INIT (prof->jit_timer);
657         prof->mempool = mono_mempool_new ();
658         return prof;
659 }
660 #if 1
661
662 #ifdef HAVE_KW_THREAD
663         static __thread MonoProfiler * tls_profiler;
664 #       define GET_PROFILER() tls_profiler
665 #       define SET_PROFILER(x) tls_profiler = (x)
666 #       define ALLOC_PROFILER() /* nop */
667 #else
668         static guint32 profiler_thread_id = -1;
669 #       define GET_PROFILER() ((MonoProfiler *)TlsGetValue (profiler_thread_id))
670 #       define SET_PROFILER(x) TlsSetValue (profiler_thread_id, x);
671 #       define ALLOC_PROFILER() profiler_thread_id = TlsAlloc ()
672 #endif
673
674 #define GET_THREAD_PROF(prof) do {                                                           \
675                 MonoProfiler *_tprofiler = GET_PROFILER ();                                  \
676                 if (!_tprofiler) {                                                           \
677                         _tprofiler = create_profiler ();                                     \
678                         prof->per_thread = g_slist_prepend (prof->per_thread, _tprofiler);   \
679                         SET_PROFILER (_tprofiler);                                           \
680                 }                                                                            \
681                 prof = _tprofiler;                                                           \
682         } while (0)
683 #else
684 /* thread unsafe but faster variant */
685 #define GET_THREAD_PROF(prof)
686 #endif
687
688 static gint
689 compare_profile (MethodProfile *profa, MethodProfile *profb)
690 {
691         return (gint)((profb->total - profa->total)*1000);
692 }
693
694 static void
695 build_profile (MonoMethod *m, MethodProfile *prof, GList **funcs)
696 {
697         prof->method = m;
698         *funcs = g_list_insert_sorted (*funcs, prof, (GCompareFunc)compare_profile);
699 }
700
701 static char*
702 method_get_name (MonoMethod* method)
703 {
704         char *sig, *res;
705         
706         sig = mono_signature_get_desc (mono_method_signature (method), FALSE);
707         res = g_strdup_printf ("%s.%s::%s(%s)", method->klass->name_space, method->klass->name,
708                 method->name, sig);
709         g_free (sig);
710         return res;
711 }
712
713 static void output_callers (MethodProfile *p);
714
715 static void
716 output_profile (GList *funcs)
717 {
718         GList *tmp;
719         MethodProfile *p;
720         char *m;
721         guint64 total_calls = 0;
722
723         if (funcs)
724                 g_print ("Time(ms) Count   P/call(ms) Method name\n");
725         for (tmp = funcs; tmp; tmp = tmp->next) {
726                 p = tmp->data;
727                 total_calls += p->count;
728                 if (!(gint)(p->total*1000))
729                         continue;
730                 m = method_get_name (p->method);
731                 printf ("########################\n");
732                 printf ("% 8.3f ", (double) (p->total * 1000));
733                 printf ("%7llu ", (unsigned long long)p->count);
734                 printf ("% 8.3f ", (double) (p->total * 1000)/(double)p->count);
735                 printf ("  %s\n", m);
736
737                 g_free (m);
738                 /* callers */
739                 output_callers (p);
740         }
741         printf ("Total number of calls: %lld\n", (long long)total_calls);
742 }
743
744 typedef struct {
745         MethodProfile *mp;
746         guint count;
747 } NewobjProfile;
748
749 static gint
750 compare_newobj_profile (NewobjProfile *profa, NewobjProfile *profb)
751 {
752         return (gint)profb->count - (gint)profa->count;
753 }
754
755 static void
756 build_newobj_profile (MonoClass *class, MethodProfile *mprof, GList **funcs)
757 {
758         NewobjProfile *prof = g_new (NewobjProfile, 1);
759         AllocInfo *tmp;
760         guint count = 0;
761         
762         prof->mp = mprof;
763         /* we use the total amount of memory to sort */
764         for (tmp = mprof->alloc_info; tmp; tmp = tmp->next)
765                 count += tmp->mem;
766         prof->count = count;
767         *funcs = g_list_insert_sorted (*funcs, prof, (GCompareFunc)compare_newobj_profile);
768 }
769
770 static int
771 compare_caller (CallerInfo *a, CallerInfo *b)
772 {
773         return b->count - a->count;
774 }
775
776 static int
777 compare_alloc (AllocInfo *a, AllocInfo *b)
778 {
779         return b->mem - a->mem;
780 }
781
782 static GSList*
783 sort_alloc_list (AllocInfo *ai)
784 {
785         GSList *l = NULL;
786         AllocInfo *tmp;
787         for (tmp = ai; tmp; tmp = tmp->next) {
788                 l = g_slist_insert_sorted (l, tmp, (GCompareFunc)compare_alloc);
789         }
790         return l;
791 }
792
793 static GSList*
794 sort_caller_list (CallerInfo *ai)
795 {
796         GSList *l = NULL;
797         CallerInfo *tmp;
798         for (tmp = ai; tmp; tmp = tmp->next) {
799                 l = g_slist_insert_sorted (l, tmp, (GCompareFunc)compare_caller);
800         }
801         return l;
802 }
803
804 static void
805 output_callers (MethodProfile *p) {
806         guint total_callers, percent;
807         GSList *sorted, *tmps;
808         CallerInfo *cinfo;
809         char *m;
810         
811         g_print ("  Callers (with count) that contribute at least for 1%%:\n");
812         total_callers = 0;
813         for (cinfo = p->caller_info; cinfo; cinfo = cinfo->next) {
814                 total_callers += cinfo->count;
815         }
816         sorted = sort_caller_list (p->caller_info);
817         for (tmps = sorted; tmps; tmps = tmps->next) {
818                 cinfo = tmps->data;
819                 percent = (cinfo->count * 100)/total_callers;
820                 if (percent < 1)
821                         continue;
822                 m = method_get_name (cinfo->caller);
823                 g_print ("    %8d % 3d %% %s\n", cinfo->count, percent, m);
824                 g_free (m);
825         }
826 }
827
828 static void
829 output_newobj_profile (GList *proflist)
830 {
831         GList *tmp;
832         NewobjProfile *p;
833         MethodProfile *mp;
834         AllocInfo *ainfo;
835         MonoClass *klass;
836         const char* isarray;
837         char buf [256];
838         char *m;
839         guint total = 0;
840         GSList *sorted, *tmps;
841
842         g_print ("\nAllocation profiler\n");
843
844         if (proflist)
845                 g_print ("%-9s %s\n", "Total mem", "Method");
846         for (tmp = proflist; tmp; tmp = tmp->next) {
847                 p = tmp->data;
848                 total += p->count;
849                 if (p->count < 50000)
850                         continue;
851                 mp = p->mp;
852                 m = method_get_name (mp->method);
853                 g_print ("########################\n%8d KB %s\n", p->count / 1024, m);
854                 g_free (m);
855                 sorted = sort_alloc_list (mp->alloc_info);
856                 for (tmps = sorted; tmps; tmps = tmps->next) {
857                         ainfo = tmps->data;
858                         if (ainfo->mem < 50000)
859                                 continue;
860                         klass = ainfo->klass;
861                         if (klass->rank) {
862                                 isarray = "[]";
863                                 klass = klass->element_class;
864                         } else {
865                                 isarray = "";
866                         }
867                         g_snprintf (buf, sizeof (buf), "%s.%s%s",
868                                 klass->name_space, klass->name, isarray);
869                         g_print ("    %8d KB %8d %-48s\n", ainfo->mem / 1024, ainfo->count, buf);
870                 }
871                 /* callers */
872                 output_callers (mp);
873         }
874         g_print ("Total memory allocated: %d KB\n", total / 1024);
875 }
876
877 static void
878 merge_methods (MonoMethod *method, MethodProfile *profile, MonoProfiler *prof)
879 {
880         MethodProfile *mprof;
881         AllocInfo *talloc_info, *alloc_info;
882         CallerInfo *tcaller_info, *caller_info;
883
884         mprof = g_hash_table_lookup (prof->methods, method);
885         if (!mprof) {
886                 /* the master thread didn't see this method, just transfer the info as is */
887                 g_hash_table_insert (prof->methods, method, profile);
888                 return;
889         }
890         /* merge the info from profile into mprof */
891         mprof->count += profile->count;
892         mprof->total += profile->total;
893         /* merge alloc info */
894         for (talloc_info = profile->alloc_info; talloc_info; talloc_info = talloc_info->next) {
895                 for (alloc_info = mprof->alloc_info; alloc_info; alloc_info = alloc_info->next) {
896                         if (alloc_info->klass == talloc_info->klass) {
897                                 /* mprof already has a record for the klass, merge */
898                                 alloc_info->count += talloc_info->count;
899                                 alloc_info->mem += talloc_info->mem;
900                                 break;
901                         }
902                 }
903                 if (!alloc_info) {
904                         /* mprof didn't have the info, just copy it over */
905                         alloc_info = mono_mempool_alloc0 (prof->mempool, sizeof (AllocInfo));
906                         *alloc_info = *talloc_info;
907                         alloc_info->next = mprof->alloc_info;
908                         mprof->alloc_info = alloc_info->next;
909                 }
910         }
911         /* merge callers info */
912         for (tcaller_info = profile->caller_info; tcaller_info; tcaller_info = tcaller_info->next) {
913                 for (caller_info = mprof->caller_info; caller_info; caller_info = caller_info->next) {
914                         if (caller_info->caller == tcaller_info->caller) {
915                                 /* mprof already has a record for the caller method, merge */
916                                 caller_info->count += tcaller_info->count;
917                                 break;
918                         }
919                 }
920                 if (!caller_info) {
921                         /* mprof didn't have the info, just copy it over */
922                         caller_info = mono_mempool_alloc0 (prof->mempool, sizeof (CallerInfo));
923                         *caller_info = *tcaller_info;
924                         caller_info->next = mprof->caller_info;
925                         mprof->caller_info = caller_info;
926                 }
927         }
928 }
929
930 static void
931 merge_thread_data (MonoProfiler *master, MonoProfiler *tprof)
932 {
933         master->jit_time += tprof->jit_time;
934         master->methods_jitted += tprof->methods_jitted;
935         if (master->max_jit_time < tprof->max_jit_time) {
936                 master->max_jit_time = tprof->max_jit_time;
937                 master->max_jit_method = tprof->max_jit_method;
938         }
939
940         g_hash_table_foreach (tprof->methods, (GHFunc)merge_methods, master);
941 }
942
943 static void
944 simple_method_enter (MonoProfiler *prof, MonoMethod *method)
945 {
946         MethodProfile *profile_info;
947         LastCallerInfo *callinfo;
948         GET_THREAD_PROF (prof);
949         /*g_print ("enter %p %s::%s in %d (%p)\n", method, method->klass->name, method->name, GetCurrentThreadId (), prof);*/
950         if (!(profile_info = g_hash_table_lookup (prof->methods, method))) {
951                 profile_info = mono_mempool_alloc0 (prof->mempool, sizeof (MethodProfile));
952                 MONO_TIMER_INIT (profile_info->u.timer);
953                 g_hash_table_insert (prof->methods, method, profile_info);
954         }
955         profile_info->count++;
956         if (prof->callers) {
957                 CallerInfo *cinfo;
958                 MonoMethod *caller = prof->callers->method;
959                 for (cinfo = profile_info->caller_info; cinfo; cinfo = cinfo->next) {
960                         if (cinfo->caller == caller)
961                                 break;
962                 }
963                 if (!cinfo) {
964                         cinfo = mono_mempool_alloc0 (prof->mempool, sizeof (CallerInfo));
965                         cinfo->caller = caller;
966                         cinfo->next = profile_info->caller_info;
967                         profile_info->caller_info = cinfo;
968                 }
969                 cinfo->count++;
970         }
971         if (!(callinfo = prof->cstorage)) {
972                 callinfo = mono_mempool_alloc (prof->mempool, sizeof (LastCallerInfo));
973                 MONO_TIMER_INIT (callinfo->timer);
974         } else {
975                 prof->cstorage = prof->cstorage->next;
976         }
977         callinfo->method = method;
978         callinfo->next = prof->callers;
979         prof->callers = callinfo;
980         MONO_TIMER_START (callinfo->timer);
981 }
982
983 static void
984 simple_method_leave (MonoProfiler *prof, MonoMethod *method)
985 {
986         MethodProfile *profile_info;
987         LastCallerInfo *callinfo, *newcallinfo = NULL;
988         
989         GET_THREAD_PROF (prof);
990         /*g_print ("leave %p %s::%s in %d (%p)\n", method, method->klass->name, method->name, GetCurrentThreadId (), prof);*/
991         callinfo = prof->callers;
992         /* should really not happen, but we don't catch exceptions events, yet ... */
993         while (callinfo) {
994                 MONO_TIMER_STOP (callinfo->timer);
995                 profile_info = g_hash_table_lookup (prof->methods, callinfo->method);
996                 if (profile_info)
997                         profile_info->total += MONO_TIMER_ELAPSED (callinfo->timer);
998                 newcallinfo = callinfo->next;
999                 callinfo->next = prof->cstorage;
1000                 prof->cstorage = callinfo;
1001                 if (callinfo->method == method)
1002                         break;
1003                 callinfo = newcallinfo;
1004         }
1005         prof->callers = newcallinfo;
1006 }
1007
1008 static void
1009 simple_allocation (MonoProfiler *prof, MonoObject *obj, MonoClass *klass)
1010 {
1011         MethodProfile *profile_info;
1012         AllocInfo *tmp;
1013
1014         GET_THREAD_PROF (prof);
1015         if (prof->callers) {
1016                 MonoMethod *caller = prof->callers->method;
1017
1018                 /* Otherwise all allocations are attributed to icall_wrapper_mono_object_new */
1019                 if (caller->wrapper_type == MONO_WRAPPER_MANAGED_TO_NATIVE)
1020                         caller = prof->callers->next->method;
1021
1022                 if (!(profile_info = g_hash_table_lookup (prof->methods, caller)))
1023                         g_assert_not_reached ();
1024         } else {
1025                 return; /* fine for now */
1026         }
1027
1028         for (tmp = profile_info->alloc_info; tmp; tmp = tmp->next) {
1029                 if (tmp->klass == klass)
1030                         break;
1031         }
1032         if (!tmp) {
1033                 tmp = mono_mempool_alloc0 (prof->mempool, sizeof (AllocInfo));
1034                 tmp->klass = klass;
1035                 tmp->next = profile_info->alloc_info;
1036                 profile_info->alloc_info = tmp;
1037         }
1038         tmp->count++;
1039         tmp->mem += mono_object_get_size (obj);
1040 }
1041
1042 static void
1043 simple_method_jit (MonoProfiler *prof, MonoMethod *method)
1044 {
1045         GET_THREAD_PROF (prof);
1046         prof->methods_jitted++;
1047         MONO_TIMER_START (prof->jit_timer);
1048 }
1049
1050 static void
1051 simple_method_end_jit (MonoProfiler *prof, MonoMethod *method, int result)
1052 {
1053         double jtime;
1054         GET_THREAD_PROF (prof);
1055         MONO_TIMER_STOP (prof->jit_timer);
1056         jtime = MONO_TIMER_ELAPSED (prof->jit_timer);
1057         prof->jit_time += jtime;
1058         if (jtime > prof->max_jit_time) {
1059                 prof->max_jit_time = jtime;
1060                 prof->max_jit_method = method;
1061         }
1062 }
1063
1064 /* about 10 minutes of samples */
1065 #define MAX_PROF_SAMPLES (1000*60*10)
1066 static int prof_counts = 0;
1067 static int prof_ucounts = 0;
1068 static gpointer* prof_addresses = NULL;
1069 static GHashTable *prof_table = NULL;
1070
1071 static void
1072 simple_stat_hit (MonoProfiler *prof, guchar *ip, void *context)
1073 {
1074         int pos;
1075
1076         if (prof_counts >= MAX_PROF_SAMPLES)
1077                 return;
1078         pos = InterlockedIncrement (&prof_counts);
1079         prof_addresses [pos - 1] = ip;
1080 }
1081
1082 static int
1083 compare_methods_prof (gconstpointer a, gconstpointer b)
1084 {
1085         int ca = GPOINTER_TO_UINT (g_hash_table_lookup (prof_table, a));
1086         int cb = GPOINTER_TO_UINT (g_hash_table_lookup (prof_table, b));
1087         return cb-ca;
1088 }
1089
1090 static void
1091 prof_foreach (char *method, gpointer c, gpointer data)
1092 {
1093         GList **list = data;
1094         *list = g_list_insert_sorted (*list, method, compare_methods_prof);
1095 }
1096
1097 typedef struct Addr2LineData Addr2LineData;
1098
1099 struct Addr2LineData {
1100         Addr2LineData *next;
1101         FILE *pipein;
1102         FILE *pipeout;
1103         char *binary;
1104         int child_pid;
1105 };
1106
1107 static Addr2LineData *addr2line_pipes = NULL;
1108
1109 static char*
1110 try_addr2line (const char* binary, gpointer ip)
1111 {
1112         char buf [1024];
1113         char *res;
1114         Addr2LineData *addr2line;
1115
1116         for (addr2line = addr2line_pipes; addr2line; addr2line = addr2line->next) {
1117                 if (strcmp (binary, addr2line->binary) == 0)
1118                         break;
1119         }
1120         if (!addr2line) {
1121                 const char *addr_argv[] = {"addr2line", "-f", "-e", binary, NULL};
1122                 int child_pid;
1123                 int ch_in, ch_out;
1124                 if (!g_spawn_async_with_pipes (NULL, (char**)addr_argv, NULL, G_SPAWN_SEARCH_PATH, NULL, NULL,
1125                                 &child_pid, &ch_in, &ch_out, NULL, NULL)) {
1126                         return g_strdup (binary);
1127                 }
1128                 addr2line = g_new0 (Addr2LineData, 1);
1129                 addr2line->child_pid = child_pid;
1130                 addr2line->binary = g_strdup (binary);
1131                 addr2line->pipein = fdopen (ch_in, "w");
1132                 addr2line->pipeout = fdopen (ch_out, "r");
1133                 addr2line->next = addr2line_pipes;
1134                 addr2line_pipes = addr2line;
1135         }
1136         fprintf (addr2line->pipein, "%p\n", ip);
1137         fflush (addr2line->pipein);
1138         /* we first get the func name and then file:lineno in a second line */
1139         if (fgets (buf, sizeof (buf), addr2line->pipeout) && buf [0] != '?') {
1140                 char *end = strchr (buf, '\n');
1141                 if (end)
1142                         *end = 0;
1143                 res = g_strdup_printf ("%s(%s", binary, buf);
1144                 /* discard the filename/line info */
1145                 fgets (buf, sizeof (buf), addr2line->pipeout);
1146         } else {
1147                 res = g_strdup (binary);
1148         }
1149         return res;
1150 }
1151
1152 static void
1153 stat_prof_report (void)
1154 {
1155         MonoJitInfo *ji;
1156         int count = prof_counts;
1157         int i, c;
1158         char *mn;
1159         gpointer ip;
1160         GList *tmp, *sorted = NULL;
1161         int pcount = ++ prof_counts;
1162
1163         prof_counts = MAX_PROF_SAMPLES;
1164         for (i = 0; i < count; ++i) {
1165                 ip = prof_addresses [i];
1166                 ji = mono_jit_info_table_find (mono_domain_get (), ip);
1167                 if (ji) {
1168                         mn = mono_method_full_name (ji->method, TRUE);
1169                 } else {
1170 #ifdef HAVE_BACKTRACE_SYMBOLS
1171                         char **names;
1172                         char *send;
1173                         int no_func;
1174                         prof_ucounts++;
1175                         names = backtrace_symbols (&ip, 1);
1176                         send = strchr (names [0], '+');
1177                         if (send) {
1178                                 *send = 0;
1179                                 no_func = 0;
1180                         } else {
1181                                 no_func = 1;
1182                         }
1183                         send = strchr (names [0], '[');
1184                         if (send)
1185                                 *send = 0;
1186                         if (no_func && names [0][0]) {
1187                                 char *endp = strchr (names [0], 0);
1188                                 while (--endp >= names [0] && g_ascii_isspace (*endp))
1189                                         *endp = 0;
1190                                 mn = try_addr2line (names [0], ip);
1191                         } else {
1192                                 mn = g_strdup (names [0]);
1193                         }
1194                         free (names);
1195 #else
1196                         prof_ucounts++;
1197                         mn = g_strdup_printf ("unmanaged [%p]", ip);
1198 #endif
1199                 }
1200                 c = GPOINTER_TO_UINT (g_hash_table_lookup (prof_table, mn));
1201                 c++;
1202                 g_hash_table_insert (prof_table, mn, GUINT_TO_POINTER (c));
1203                 if (c > 1)
1204                         g_free (mn);
1205         }
1206         g_print ("prof counts: total/unmanaged: %d/%d\n", pcount, prof_ucounts);
1207         g_hash_table_foreach (prof_table, (GHFunc)prof_foreach, &sorted);
1208         for (tmp = sorted; tmp; tmp = tmp->next) {
1209                 double perc;
1210                 c = GPOINTER_TO_UINT (g_hash_table_lookup (prof_table, tmp->data));
1211                 perc = c*100.0/count;
1212                 g_print ("%7d\t%5.2f %% %s\n", c, perc, (char*)tmp->data);
1213         }
1214         g_list_free (sorted);
1215 }
1216
1217 static void
1218 simple_appdomain_unload (MonoProfiler *prof, MonoDomain *domain)
1219 {
1220         /* FIXME: we should actually record partial data for each domain, 
1221          * since the ip->ji->method mappings are going away at domain unload time.
1222          */
1223         if (domain == mono_get_root_domain ())
1224                 stat_prof_report ();
1225 }
1226
1227 static void
1228 simple_shutdown (MonoProfiler *prof)
1229 {
1230         GList *profile = NULL;
1231         MonoProfiler *tprof;
1232         GSList *tmp;
1233         char *str;
1234
1235         for (tmp = prof->per_thread; tmp; tmp = tmp->next) {
1236                 tprof = tmp->data;
1237                 merge_thread_data (prof, tprof);
1238         }
1239
1240         printf("Total time spent compiling %d methods (sec): %.4g\n", prof->methods_jitted, prof->jit_time);
1241         if (prof->max_jit_method) {
1242                 str = method_get_name (prof->max_jit_method);
1243                 printf("Slowest method to compile (sec): %.4g: %s\n", prof->max_jit_time, str);
1244                 g_free (str);
1245         }
1246         g_hash_table_foreach (prof->methods, (GHFunc)build_profile, &profile);
1247         output_profile (profile);
1248         g_list_free (profile);
1249         profile = NULL;
1250                 
1251         g_hash_table_foreach (prof->methods, (GHFunc)build_newobj_profile, &profile);
1252         output_newobj_profile (profile);
1253         g_list_free (profile);
1254
1255         g_free (prof_addresses);
1256         prof_addresses = NULL;
1257         g_hash_table_destroy (prof_table);
1258 }
1259
1260 static void
1261 mono_profiler_install_simple (const char *desc)
1262 {
1263         MonoProfiler *prof;
1264         gchar **args, **ptr;
1265         MonoProfileFlags flags = 0;
1266
1267         MONO_TIMER_STARTUP;
1268
1269         if (!desc)
1270                 desc = "alloc,time,jit";
1271
1272         if (desc) {
1273                 /* Parse options */
1274                 if (strstr (desc, ":"))
1275                         desc = strstr (desc, ":") + 1;
1276                 else
1277                         desc = "alloc,time,jit";
1278                 args = g_strsplit (desc, ",", -1);
1279
1280                 for (ptr = args; ptr && *ptr; ptr++) {
1281                         const char *arg = *ptr;
1282
1283                         if (!strcmp (arg, "time"))
1284                                 flags |= MONO_PROFILE_ENTER_LEAVE;
1285                         else if (!strcmp (arg, "alloc"))
1286                                 flags |= MONO_PROFILE_ALLOCATIONS;
1287                         else if (!strcmp (arg, "stat"))
1288                                 flags |= MONO_PROFILE_STATISTICAL | MONO_PROFILE_APPDOMAIN_EVENTS;
1289                         else if (!strcmp (arg, "jit"))
1290                                 flags |= MONO_PROFILE_JIT_COMPILATION;
1291                         else {
1292                                 fprintf (stderr, "profiler : Unknown argument '%s'.\n", arg);
1293                                 return;
1294                         }
1295                 }
1296         }
1297
1298         prof = create_profiler ();
1299         ALLOC_PROFILER ();
1300         SET_PROFILER (prof);
1301
1302         /* statistical profiler data */
1303         prof_addresses = g_new0 (gpointer, MAX_PROF_SAMPLES);
1304         prof_table = g_hash_table_new (g_str_hash, g_str_equal);
1305
1306         mono_profiler_install (prof, simple_shutdown);
1307         mono_profiler_install_enter_leave (simple_method_enter, simple_method_leave);
1308         mono_profiler_install_jit_compile (simple_method_jit, simple_method_end_jit);
1309         mono_profiler_install_allocation (simple_allocation);
1310         mono_profiler_install_appdomain (NULL, NULL, simple_appdomain_unload, NULL);
1311         mono_profiler_install_statistical (simple_stat_hit);
1312         mono_profiler_set_events (flags);
1313 }
1314
1315 #endif /* DISABLE_PROFILER */
1316
1317 typedef void (*ProfilerInitializer) (const char*);
1318 #define INITIALIZER_NAME "mono_profiler_startup"
1319
1320 void 
1321 mono_profiler_load (const char *desc)
1322 {
1323 #ifndef DISABLE_PROFILER
1324         if (!desc || (strcmp ("default", desc) == 0) || (strncmp (desc, "default:", 8) == 0)) {
1325                 mono_profiler_install_simple (desc);
1326                 return;
1327         }
1328 #else
1329         if (!desc) {
1330                 desc = "default";
1331         }
1332 #endif
1333         {
1334                 GModule *pmodule;
1335                 const char* col = strchr (desc, ':');
1336                 char* libname;
1337                 char* path;
1338                 char *mname;
1339                 if (col != NULL) {
1340                         mname = g_memdup (desc, col - desc);
1341                         mname [col - desc] = 0;
1342                 } else {
1343                         mname = g_strdup (desc);
1344                 }
1345                 libname = g_strdup_printf ("mono-profiler-%s", mname);
1346                 path = g_module_build_path (NULL, libname);
1347                 pmodule = g_module_open (path, G_MODULE_BIND_LAZY);
1348                 if (pmodule) {
1349                         ProfilerInitializer func;
1350                         if (!g_module_symbol (pmodule, INITIALIZER_NAME, (gpointer *)&func)) {
1351                                 g_warning ("Cannot find initializer function %s in profiler module: %s", INITIALIZER_NAME, libname);
1352                         } else {
1353                                 func (desc);
1354                         }
1355                 } else {
1356                         g_warning ("Error loading profiler module '%s': %s", libname, g_module_error ());
1357                 }
1358
1359                 g_free (libname);
1360                 g_free (mname);
1361                 g_free (path);
1362         }
1363 }
1364