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