Finish spliting sgen-nursery-allocator into a separate compilation unit
[mono-project.git] / mono / profiler / decode.c
blob1f893ce8128de73911cd3db3216dcb675ccc970e
1 /*
2 * decode.c: mprof-report program source: decode and analyze the log profiler data
4 * Author:
5 * Paolo Molaro (lupus@ximian.com)
7 * Copyright 2010 Novell, Inc (http://www.novell.com)
8 */
9 #include <config.h>
10 #include "utils.c"
11 #include "proflog.h"
12 #include <string.h>
13 #include <assert.h>
14 #include <stdio.h>
15 #if !defined(__APPLE__) && !defined(__FreeBSD__)
16 #include <malloc.h>
17 #endif
18 #include <unistd.h>
19 #include <stdlib.h>
20 #if defined (HAVE_SYS_ZLIB)
21 #include <zlib.h>
22 #endif
23 #include <mono/metadata/profiler.h>
24 #include <mono/metadata/object.h>
25 #include <mono/metadata/debug-helpers.h>
27 #define HASH_SIZE 9371
28 #define SMALL_HASH_SIZE 31
30 static int debug = 0;
31 static int collect_traces = 0;
32 static int show_traces = 0;
33 static int trace_max = 6;
34 static int verbose = 0;
35 static uintptr_t *tracked_objects = 0;
36 static int num_tracked_objects = 0;
37 static uintptr_t thread_filter = 0;
38 static uint64_t find_size = 0;
39 static const char* find_name = NULL;
40 static uint64_t time_from = 0;
41 static uint64_t time_to = 0xffffffffffffffffULL;
42 static uint64_t startup_time = 0;
43 static FILE* outfile = NULL;
45 static int32_t
46 read_int16 (unsigned char *p)
48 int32_t value = *p++;
49 value |= (*p++) << 8;
50 return value;
53 static int32_t
54 read_int32 (unsigned char *p)
56 int32_t value = *p++;
57 value |= (*p++) << 8;
58 value |= (*p++) << 16;
59 value |= (uint32_t)(*p++) << 24;
60 return value;
63 static int64_t
64 read_int64 (unsigned char *p)
66 uint64_t value = *p++;
67 value |= (*p++) << 8;
68 value |= (*p++) << 16;
69 value |= (uint64_t)(*p++) << 24;
70 value |= (uint64_t)(*p++) << 32;
71 value |= (uint64_t)(*p++) << 40;
72 value |= (uint64_t)(*p++) << 48;
73 value |= (uint64_t)(*p++) << 54;
74 return value;
77 static char*
78 pstrdup (const char *s)
80 int len = strlen (s) + 1;
81 char *p = malloc (len);
82 memcpy (p, s, len);
83 return p;
86 static int num_images;
87 typedef struct _ImageDesc ImageDesc;
88 struct _ImageDesc {
89 ImageDesc *next;
90 intptr_t image;
91 char *filename;
94 static ImageDesc* image_hash [SMALL_HASH_SIZE] = {0};
96 static void
97 add_image (intptr_t image, char *name)
99 int slot = ((image >> 2) & 0xffff) % SMALL_HASH_SIZE;
100 ImageDesc *cd = malloc (sizeof (ImageDesc));
101 cd->image = image;
102 cd->filename = pstrdup (name);
103 cd->next = image_hash [slot];
104 image_hash [slot] = cd;
105 num_images++;
108 typedef struct _BackTrace BackTrace;
109 typedef struct {
110 uint64_t count;
111 BackTrace *bt;
112 } CallContext;
114 typedef struct {
115 int count;
116 int size;
117 CallContext *traces;
118 } TraceDesc;
120 typedef struct _ClassDesc ClassDesc;
121 struct _ClassDesc {
122 ClassDesc *next;
123 intptr_t klass;
124 char *name;
125 intptr_t allocs;
126 uint64_t alloc_size;
127 TraceDesc traces;
130 static ClassDesc* class_hash [HASH_SIZE] = {0};
131 static int num_classes = 0;
133 static ClassDesc*
134 add_class (intptr_t klass, const char *name)
136 int slot = ((klass >> 2) & 0xffff) % HASH_SIZE;
137 ClassDesc *cd;
138 cd = class_hash [slot];
139 while (cd && cd->klass != klass)
140 cd = cd->next;
141 /* we resolved an unknown class (unless we had the code unloaded) */
142 if (cd) {
143 /*printf ("resolved unknown: %s\n", name);*/
144 free (cd->name);
145 cd->name = pstrdup (name);
146 return cd;
148 cd = calloc (sizeof (ClassDesc), 1);
149 cd->klass = klass;
150 cd->name = pstrdup (name);
151 cd->next = class_hash [slot];
152 cd->allocs = 0;
153 cd->alloc_size = 0;
154 cd->traces.count = 0;
155 cd->traces.size = 0;
156 cd->traces.traces = NULL;
157 class_hash [slot] = cd;
158 num_classes++;
159 return cd;
162 static ClassDesc *
163 lookup_class (intptr_t klass)
165 int slot = ((klass >> 2) & 0xffff) % HASH_SIZE;
166 ClassDesc *cd = class_hash [slot];
167 while (cd && cd->klass != klass)
168 cd = cd->next;
169 if (!cd) {
170 char buf [128];
171 snprintf (buf, sizeof (buf), "unresolved class %p", (void*)klass);
172 return add_class (klass, buf);
174 return cd;
177 typedef struct _MethodDesc MethodDesc;
178 struct _MethodDesc {
179 MethodDesc *next;
180 intptr_t method;
181 char *name;
182 intptr_t code;
183 int len;
184 int recurse_count;
185 int sample_hits;
186 uint64_t calls;
187 uint64_t total_time;
188 uint64_t callee_time;
189 uint64_t self_time;
190 TraceDesc traces;
193 static MethodDesc* method_hash [HASH_SIZE] = {0};
194 static int num_methods = 0;
196 static MethodDesc*
197 add_method (intptr_t method, const char *name, intptr_t code, int len)
199 int slot = ((method >> 2) & 0xffff) % HASH_SIZE;
200 MethodDesc *cd;
201 cd = method_hash [slot];
202 while (cd && cd->method != method)
203 cd = cd->next;
204 /* we resolved an unknown method (unless we had the code unloaded) */
205 if (cd) {
206 cd->code = code;
207 cd->len = len;
208 /*printf ("resolved unknown: %s\n", name);*/
209 free (cd->name);
210 cd->name = pstrdup (name);
211 return cd;
213 cd = calloc (sizeof (MethodDesc), 1);
214 cd->method = method;
215 cd->name = pstrdup (name);
216 cd->code = code;
217 cd->len = len;
218 cd->calls = 0;
219 cd->total_time = 0;
220 cd->traces.count = 0;
221 cd->traces.size = 0;
222 cd->traces.traces = NULL;
223 cd->next = method_hash [slot];
224 method_hash [slot] = cd;
225 num_methods++;
226 return cd;
229 static MethodDesc *
230 lookup_method (intptr_t method)
232 int slot = ((method >> 2) & 0xffff) % HASH_SIZE;
233 MethodDesc *cd = method_hash [slot];
234 while (cd && cd->method != method)
235 cd = cd->next;
236 if (!cd) {
237 char buf [128];
238 snprintf (buf, sizeof (buf), "unknown method %p", (void*)method);
239 return add_method (method, buf, 0, 0);
241 return cd;
244 static int num_stat_samples = 0;
245 static int size_stat_samples = 0;
246 uintptr_t *stat_samples = NULL;
247 int *stat_sample_desc = NULL;
249 static void
250 add_stat_sample (int type, uintptr_t ip) {
251 if (num_stat_samples == size_stat_samples) {
252 size_stat_samples *= 2;
253 if (!size_stat_samples)
254 size_stat_samples = 32;
255 stat_samples = realloc (stat_samples, size_stat_samples * sizeof (uintptr_t));
256 stat_sample_desc = realloc (stat_sample_desc, size_stat_samples * sizeof (int));
258 stat_samples [num_stat_samples] = ip;
259 stat_sample_desc [num_stat_samples++] = type;
262 static MethodDesc*
263 lookup_method_by_ip (uintptr_t ip)
265 int i;
266 MethodDesc* m;
267 /* dumb */
268 for (i = 0; i < HASH_SIZE; ++i) {
269 m = method_hash [i];
270 while (m) {
271 //printf ("checking %p against %p-%p\n", (void*)ip, (void*)(m->code), (void*)(m->code + m->len));
272 if (ip >= (uintptr_t)m->code && ip < (uintptr_t)m->code + m->len) {
273 return m;
275 m = m->next;
278 return NULL;
281 static int
282 compare_method_samples (const void *a, const void *b)
284 MethodDesc *const*A = a;
285 MethodDesc *const*B = b;
286 if ((*A)->sample_hits == (*B)->sample_hits)
287 return 0;
288 if ((*B)->sample_hits < (*A)->sample_hits)
289 return -1;
290 return 1;
293 typedef struct _UnmanagedSymbol UnmanagedSymbol;
294 struct _UnmanagedSymbol {
295 UnmanagedSymbol *parent;
296 char *name;
297 int is_binary;
298 uintptr_t addr;
299 uintptr_t size;
300 uintptr_t sample_hits;
303 static UnmanagedSymbol **usymbols = NULL;
304 static int usymbols_size = 0;
305 static int usymbols_num = 0;
307 static int
308 compare_usymbol_addr (const void *a, const void *b)
310 UnmanagedSymbol *const*A = a;
311 UnmanagedSymbol *const*B = b;
312 if ((*B)->addr == (*A)->addr)
313 return 0;
314 if ((*B)->addr > (*A)->addr)
315 return -1;
316 return 1;
319 static int
320 compare_usymbol_samples (const void *a, const void *b)
322 UnmanagedSymbol *const*A = a;
323 UnmanagedSymbol *const*B = b;
324 if ((*B)->sample_hits == (*A)->sample_hits)
325 return 0;
326 if ((*B)->sample_hits < (*A)->sample_hits)
327 return -1;
328 return 1;
331 static void
332 add_unmanaged_symbol (uintptr_t addr, char *name, uintptr_t size)
334 UnmanagedSymbol *sym;
335 if (usymbols_num == usymbols_size) {
336 int new_size = usymbols_size * 2;
337 if (!new_size)
338 new_size = 16;
339 usymbols = realloc (usymbols, sizeof (void*) * new_size);
340 usymbols_size = new_size;
342 sym = calloc (sizeof (UnmanagedSymbol), 1);
343 sym->addr = addr;
344 sym->name = name;
345 sym->size = size;
346 usymbols [usymbols_num++] = sym;
349 /* only valid after the symbols are sorted */
350 static UnmanagedSymbol*
351 lookup_unmanaged_symbol (uintptr_t addr)
353 int r = usymbols_num - 1;
354 int l = 0;
355 UnmanagedSymbol *sym;
356 int last_best = -1;
357 while (r >= l) {
358 int m = (l + r) / 2;
359 sym = usymbols [m];
360 if (addr == sym->addr)
361 return sym;
362 if (addr < sym->addr) {
363 r = m - 1;
364 } else if (addr > sym->addr) {
365 l = m + 1;
366 last_best = m;
369 if (last_best >= 0 && (addr - usymbols [last_best]->addr) < 4096)
370 return usymbols [last_best];
371 return NULL;
374 /* we use the same structure for binaries */
375 static UnmanagedSymbol **ubinaries = NULL;
376 static int ubinaries_size = 0;
377 static int ubinaries_num = 0;
379 static void
380 add_unmanaged_binary (uintptr_t addr, char *name, uintptr_t size)
382 UnmanagedSymbol *sym;
383 if (ubinaries_num == ubinaries_size) {
384 int new_size = ubinaries_size * 2;
385 if (!new_size)
386 new_size = 16;
387 ubinaries = realloc (ubinaries, sizeof (void*) * new_size);
388 ubinaries_size = new_size;
390 sym = calloc (sizeof (UnmanagedSymbol), 1);
391 sym->addr = addr;
392 sym->name = name;
393 sym->size = size;
394 sym->is_binary = 1;
395 ubinaries [ubinaries_num++] = sym;
398 static UnmanagedSymbol*
399 lookup_unmanaged_binary (uintptr_t addr)
401 int i;
402 for (i = 0; i < ubinaries_num; ++i) {
403 UnmanagedSymbol *ubin = ubinaries [i];
404 if (addr >= ubin->addr && addr < ubin->addr + ubin->size) {
405 return ubin;
408 return NULL;
411 static const char*
412 sample_type_name (int type)
414 switch (type) {
415 case SAMPLE_CYCLES: return "cycles";
416 case SAMPLE_INSTRUCTIONS: return "instructions retired";
417 case SAMPLE_CACHE_MISSES: return "cache misses";
418 case SAMPLE_CACHE_REFS: return "cache references";
419 case SAMPLE_BRANCHES: return "executed branches";
420 case SAMPLE_BRANCH_MISSES: return "unpredicted branches";
422 return "unknown";
425 static void
426 set_usym_parent (UnmanagedSymbol** cachedus, int count)
428 int i;
429 for (i = 0; i < count; ++i) {
430 UnmanagedSymbol *ubin = lookup_unmanaged_binary (cachedus [i]->addr);
431 if (ubin == cachedus [i])
432 continue;
433 cachedus [i]->parent = ubin;
437 static void
438 print_usym (UnmanagedSymbol* um)
440 if (um->parent)
441 fprintf (outfile, "\t%6d %6.2f %-36s in %s\n", um->sample_hits, um->sample_hits*100.0/num_stat_samples, um->name, um->parent->name);
442 else
443 fprintf (outfile, "\t%6d %6.2f %s\n", um->sample_hits, um->sample_hits*100.0/num_stat_samples, um->name);
446 static int
447 sym_percent (uintptr_t sample_hits)
449 double pc;
450 if (verbose)
451 return 1;
452 pc = sample_hits*100.0/num_stat_samples;
453 return pc >= 0.1;
456 static void
457 dump_samples (void)
459 int i, u;
460 int count = 0, msize = 0;
461 int unmanaged_hits = 0;
462 int unresolved_hits = 0;
463 MethodDesc** cachedm = NULL;
464 int ucount = 0, usize = 0;
465 UnmanagedSymbol** cachedus = NULL;
466 if (!num_stat_samples)
467 return;
468 qsort (usymbols, usymbols_num, sizeof (UnmanagedSymbol*), compare_usymbol_addr);
469 for (i = 0; i < num_stat_samples; ++i) {
470 MethodDesc *m = lookup_method_by_ip (stat_samples [i]);
471 if (m) {
472 if (!m->sample_hits) {
473 if (count == msize) {
474 msize *= 2;
475 if (!msize)
476 msize = 4;
477 cachedm = realloc (cachedm, sizeof (void*) * msize);
479 cachedm [count++] = m;
481 m->sample_hits++;
482 } else {
483 UnmanagedSymbol *usym = lookup_unmanaged_symbol (stat_samples [i]);
484 if (!usym) {
485 unresolved_hits++;
486 //printf ("unmanaged hit at %p\n", (void*)stat_samples [i]);
487 usym = lookup_unmanaged_binary (stat_samples [i]);
489 if (usym) {
490 if (!usym->sample_hits) {
491 if (ucount == usize) {
492 usize *= 2;
493 if (!usize)
494 usize = 4;
495 cachedus = realloc (cachedus, sizeof (void*) * usize);
497 cachedus [ucount++] = usym;
499 usym->sample_hits++;
501 unmanaged_hits++;
504 qsort (cachedm, count, sizeof (MethodDesc*), compare_method_samples);
505 qsort (cachedus, ucount, sizeof (UnmanagedSymbol*), compare_usymbol_samples);
506 set_usym_parent (cachedus, ucount);
507 fprintf (outfile, "\nStatistical samples summary\n");
508 fprintf (outfile, "\tSample type: %s\n", sample_type_name (stat_sample_desc [0]));
509 fprintf (outfile, "\tUnmanaged hits: %6d (%4.1f%%)\n", unmanaged_hits, (100.0*unmanaged_hits)/num_stat_samples);
510 fprintf (outfile, "\tManaged hits: %6d (%4.1f%%)\n", num_stat_samples - unmanaged_hits, (100.0*(num_stat_samples-unmanaged_hits))/num_stat_samples);
511 fprintf (outfile, "\tUnresolved hits: %6d (%4.1f%%)\n", unresolved_hits, (100.0*unresolved_hits)/num_stat_samples);
512 fprintf (outfile, "\t%6s %6s %s\n", "Hits", "%", "Method name");
513 i = 0;
514 u = 0;
515 while (i < count || u < ucount) {
516 if (i < count) {
517 MethodDesc *m = cachedm [i];
518 if (u < ucount) {
519 UnmanagedSymbol *um = cachedus [u];
520 if (um->sample_hits > m->sample_hits) {
521 if (!sym_percent (um->sample_hits))
522 break;
523 print_usym (um);
524 u++;
525 continue;
528 if (!sym_percent (m->sample_hits))
529 break;
530 fprintf (outfile, "\t%6d %6.2f %s\n", m->sample_hits, m->sample_hits*100.0/num_stat_samples, m->name);
531 i++;
532 continue;
534 if (u < ucount) {
535 UnmanagedSymbol *um = cachedus [u];
536 if (!sym_percent (um->sample_hits))
537 break;
538 print_usym (um);
539 u++;
540 continue;
545 typedef struct _HeapClassDesc HeapClassDesc;
546 typedef struct {
547 HeapClassDesc *klass;
548 uint64_t count;
549 } HeapClassRevRef;
551 struct _HeapClassDesc {
552 ClassDesc *klass;
553 int64_t count;
554 int64_t total_size;
555 HeapClassRevRef *rev_hash;
556 int rev_hash_size;
557 int rev_count;
558 uintptr_t pinned_references;
559 uintptr_t root_references;
562 static int
563 add_rev_class_hashed (HeapClassRevRef *rev_hash, uintptr_t size, HeapClassDesc *hklass, uint64_t value)
565 uintptr_t i;
566 uintptr_t start_pos;
567 start_pos = (hklass->klass->klass >> 2) % size;
568 assert (start_pos < size);
569 i = start_pos;
570 do {
571 if (rev_hash [i].klass == hklass) {
572 rev_hash [i].count += value;
573 return 0;
574 } else if (!rev_hash [i].klass) {
575 rev_hash [i].klass = hklass;
576 rev_hash [i].count += value;
577 start_pos = 0;
578 for (i = 0; i < size; ++i)
579 if (rev_hash [i].klass && rev_hash [i].klass->klass == hklass->klass)
580 start_pos ++;
581 assert (start_pos == 1);
582 return 1;
584 /* wrap around */
585 if (++i == size)
586 i = 0;
587 } while (i != start_pos);
588 /* should not happen */
589 printf ("failed revref store\n");
590 return 0;
593 static void
594 add_heap_class_rev (HeapClassDesc *from, HeapClassDesc *to)
596 uintptr_t i;
597 if (to->rev_count * 2 >= to->rev_hash_size) {
598 HeapClassRevRef *n;
599 uintptr_t old_size = to->rev_hash_size;
600 to->rev_hash_size *= 2;
601 if (to->rev_hash_size == 0)
602 to->rev_hash_size = 4;
603 n = calloc (sizeof (HeapClassRevRef) * to->rev_hash_size, 1);
604 for (i = 0; i < old_size; ++i) {
605 if (to->rev_hash [i].klass)
606 add_rev_class_hashed (n, to->rev_hash_size, to->rev_hash [i].klass, to->rev_hash [i].count);
608 if (to->rev_hash)
609 free (to->rev_hash);
610 to->rev_hash = n;
612 to->rev_count += add_rev_class_hashed (to->rev_hash, to->rev_hash_size, from, 1);
615 typedef struct {
616 uintptr_t objaddr;
617 HeapClassDesc *hklass;
618 uintptr_t num_refs;
619 uintptr_t refs [0];
620 } HeapObjectDesc;
622 typedef struct _HeapShot HeapShot;
623 struct _HeapShot {
624 HeapShot *next;
625 uint64_t timestamp;
626 int class_count;
627 int hash_size;
628 HeapClassDesc **class_hash;
629 HeapClassDesc **sorted;
630 HeapObjectDesc **objects_hash;
631 uintptr_t objects_count;
632 uintptr_t objects_hash_size;
633 uintptr_t num_roots;
634 uintptr_t *roots;
635 uintptr_t *roots_extra;
636 int *roots_types;
639 static HeapShot *heap_shots = NULL;
640 static int num_heap_shots = 0;
642 static HeapShot*
643 new_heap_shot (uint64_t timestamp)
645 HeapShot *hs = calloc (sizeof (HeapShot), 1);
646 hs->hash_size = 4;
647 hs->class_hash = calloc (sizeof (void*), hs->hash_size);
648 hs->timestamp = timestamp;
649 num_heap_shots++;
650 hs->next = heap_shots;
651 heap_shots = hs;
652 return hs;
655 static HeapClassDesc*
656 heap_class_lookup (HeapShot *hs, ClassDesc *klass)
658 int i;
659 unsigned int start_pos;
660 start_pos = ((uintptr_t)klass->klass >> 2) % hs->hash_size;
661 i = start_pos;
662 do {
663 HeapClassDesc* cd = hs->class_hash [i];
664 if (!cd)
665 return NULL;
666 if (cd->klass == klass)
667 return cd;
668 /* wrap around */
669 if (++i == hs->hash_size)
670 i = 0;
671 } while (i != start_pos);
672 return NULL;
675 static int
676 add_heap_hashed (HeapClassDesc **hash, HeapClassDesc **retv, uintptr_t hsize, ClassDesc *klass, uint64_t size, uint64_t count)
678 uintptr_t i;
679 uintptr_t start_pos;
680 start_pos = ((uintptr_t)klass->klass >> 2) % hsize;
681 i = start_pos;
682 do {
683 if (hash [i] && hash [i]->klass == klass) {
684 hash [i]->total_size += size;
685 hash [i]->count += count;
686 *retv = hash [i];
687 return 0;
688 } else if (!hash [i]) {
689 if (*retv) {
690 hash [i] = *retv;
691 return 1;
693 hash [i] = calloc (sizeof (HeapClassDesc), 1);
694 hash [i]->klass = klass;
695 hash [i]->total_size += size;
696 hash [i]->count += count;
697 *retv = hash [i];
698 return 1;
700 /* wrap around */
701 if (++i == hsize)
702 i = 0;
703 } while (i != start_pos);
704 /* should not happen */
705 printf ("failed heap class store\n");
706 return 0;
709 static HeapClassDesc*
710 add_heap_shot_class (HeapShot *hs, ClassDesc *klass, uint64_t size)
712 HeapClassDesc *res;
713 int i;
714 if (hs->class_count * 2 >= hs->hash_size) {
715 HeapClassDesc **n;
716 int old_size = hs->hash_size;
717 hs->hash_size *= 2;
718 if (hs->hash_size == 0)
719 hs->hash_size = 4;
720 n = calloc (sizeof (void*) * hs->hash_size, 1);
721 for (i = 0; i < old_size; ++i) {
722 res = hs->class_hash [i];
723 if (hs->class_hash [i])
724 add_heap_hashed (n, &res, hs->hash_size, hs->class_hash [i]->klass, hs->class_hash [i]->total_size, hs->class_hash [i]->count);
726 if (hs->class_hash)
727 free (hs->class_hash);
728 hs->class_hash = n;
730 res = NULL;
731 hs->class_count += add_heap_hashed (hs->class_hash, &res, hs->hash_size, klass, size, 1);
732 //if (res->count == 1)
733 // printf ("added heap class: %s\n", res->klass->name);
734 return res;
737 static HeapObjectDesc*
738 alloc_heap_obj (uintptr_t objaddr, HeapClassDesc *hklass, uintptr_t num_refs)
740 HeapObjectDesc* ho = calloc (sizeof (HeapObjectDesc) + num_refs * sizeof (uintptr_t), 1);
741 ho->objaddr = objaddr;
742 ho->hklass = hklass;
743 ho->num_refs = num_refs;
744 return ho;
747 static uintptr_t
748 heap_shot_find_obj_slot (HeapShot *hs, uintptr_t objaddr)
750 uintptr_t i;
751 uintptr_t start_pos;
752 HeapObjectDesc **hash = hs->objects_hash;
753 start_pos = ((uintptr_t)objaddr >> 3) % hs->objects_hash_size;
754 i = start_pos;
755 do {
756 if (hash [i] && hash [i]->objaddr == objaddr) {
757 return i;
758 } else if (!hash [i]) {
759 break; /* fail */
761 /* wrap around */
762 if (++i == hs->objects_hash_size)
763 i = 0;
764 } while (i != start_pos);
765 /* should not happen */
766 //printf ("failed heap obj slot\n");
767 return -1;
770 static HeapObjectDesc*
771 heap_shot_obj_add_refs (HeapShot *hs, uintptr_t objaddr, uintptr_t num, uintptr_t *ref_offset)
773 HeapObjectDesc **hash = hs->objects_hash;
774 uintptr_t i = heap_shot_find_obj_slot (hs, objaddr);
775 if (i >= 0) {
776 HeapObjectDesc* ho = alloc_heap_obj (objaddr, hash [i]->hklass, hash [i]->num_refs + num);
777 *ref_offset = hash [i]->num_refs;
778 memcpy (ho->refs, hash [i]->refs, hash [i]->num_refs * sizeof (uintptr_t));
779 free (hash [i]);
780 hash [i] = ho;
781 return ho;
783 /* should not happen */
784 printf ("failed heap obj update\n");
785 return NULL;
789 static uintptr_t
790 add_heap_hashed_obj (HeapObjectDesc **hash, uintptr_t hsize, HeapObjectDesc *obj)
792 uintptr_t i;
793 uintptr_t start_pos;
794 start_pos = ((uintptr_t)obj->objaddr >> 3) % hsize;
795 i = start_pos;
796 do {
797 if (hash [i] && hash [i]->objaddr == obj->objaddr) {
798 printf ("duplicate object!\n");
799 return 0;
800 } else if (!hash [i]) {
801 hash [i] = obj;
802 return 1;
804 /* wrap around */
805 if (++i == hsize)
806 i = 0;
807 } while (i != start_pos);
808 /* should not happen */
809 printf ("failed heap obj store\n");
810 return 0;
813 static void
814 add_heap_shot_obj (HeapShot *hs, HeapObjectDesc *obj)
816 uintptr_t i;
817 if (hs->objects_count * 2 >= hs->objects_hash_size) {
818 HeapObjectDesc **n;
819 uintptr_t old_size = hs->objects_hash_size;
820 hs->objects_hash_size *= 2;
821 if (hs->objects_hash_size == 0)
822 hs->objects_hash_size = 4;
823 n = calloc (sizeof (void*) * hs->objects_hash_size, 1);
824 for (i = 0; i < old_size; ++i) {
825 if (hs->objects_hash [i])
826 add_heap_hashed_obj (n, hs->objects_hash_size, hs->objects_hash [i]);
828 if (hs->objects_hash)
829 free (hs->objects_hash);
830 hs->objects_hash = n;
832 hs->objects_count += add_heap_hashed_obj (hs->objects_hash, hs->objects_hash_size, obj);
835 static void
836 heap_shot_resolve_reverse_refs (HeapShot *hs)
838 uintptr_t i;
839 for (i = 0; i < hs->objects_hash_size; ++i) {
840 uintptr_t r;
841 HeapObjectDesc *ho = hs->objects_hash [i];
842 if (!ho)
843 continue;
844 for (r = 0; r < ho->num_refs; ++r) {
845 uintptr_t oi = heap_shot_find_obj_slot (hs, ho->refs [r]);
846 add_heap_class_rev (ho->hklass, hs->objects_hash [oi]->hklass);
851 #define MARK_GRAY 1
852 #define MARK_BLACK 2
854 static void
855 heap_shot_mark_objects (HeapShot *hs)
857 uintptr_t i, oi, r;
858 unsigned char *marks;
859 HeapObjectDesc *obj, *ref;
860 int marked_some;
861 uintptr_t num_marked = 0, num_unmarked;
862 for (i = 0; i < hs->num_roots; ++i) {
863 HeapClassDesc *cd;
864 oi = heap_shot_find_obj_slot (hs, hs->roots [i]);
865 if (oi == -1) {
866 continue;
868 obj = hs->objects_hash [oi];
869 cd = obj->hklass;
870 if (hs->roots_types [i] & MONO_PROFILE_GC_ROOT_PINNING)
871 cd->pinned_references++;
872 cd->root_references++;
874 if (!debug)
875 return;
876 /* consistency checks: it seems not all the objects are walked in the heap in some cases */
877 marks = calloc (hs->objects_hash_size, 1);
878 if (!marks)
879 return;
880 for (i = 0; i < hs->num_roots; ++i) {
881 oi = heap_shot_find_obj_slot (hs, hs->roots [i]);
882 if (oi == -1) {
883 fprintf (outfile, "root type 0x%x for obj %p (%s) not found in heap\n", hs->roots_types [i], (void*)hs->roots [i], lookup_class (hs->roots_extra [i])->name);
884 continue;
886 obj = hs->objects_hash [oi];
887 if (!marks [oi]) {
888 marks [oi] = obj->num_refs? MARK_GRAY: MARK_BLACK;
889 num_marked++;
892 marked_some = 1;
893 while (marked_some) {
894 marked_some = 0;
895 for (i = 0; i < hs->objects_hash_size; ++i) {
896 if (marks [i] != MARK_GRAY)
897 continue;
898 marks [i] = MARK_BLACK;
899 obj = hs->objects_hash [i];
900 for (r = 0; r < obj->num_refs; ++r) {
901 oi = heap_shot_find_obj_slot (hs, obj->refs [r]);
902 if (oi == -1) {
903 fprintf (outfile, "referenced obj %p not found in heap\n", (void*)obj->refs [r]);
904 continue;
906 ref = hs->objects_hash [oi];
907 if (!marks [oi]) {
908 marks [oi] = ref->num_refs? MARK_GRAY: MARK_BLACK;
911 marked_some++;
915 num_unmarked = 0;
916 for (i = 0; i < hs->objects_hash_size; ++i) {
917 if (hs->objects_hash [i] && !marks [i]) {
918 num_unmarked++;
919 fprintf (outfile, "object %p (%s) unmarked\n", (void*)hs->objects_hash [i], hs->objects_hash [i]->hklass->klass->name);
922 fprintf (outfile, "Total unmarked: %d/%d\n", num_unmarked, hs->objects_count);
923 free (marks);
926 static void
927 heap_shot_free_objects (HeapShot *hs)
929 uintptr_t i;
930 for (i = 0; i < hs->objects_hash_size; ++i) {
931 HeapObjectDesc *ho = hs->objects_hash [i];
932 if (ho)
933 free (ho);
935 if (hs->objects_hash)
936 free (hs->objects_hash);
937 hs->objects_hash = NULL;
938 hs->objects_hash_size = 0;
939 hs->objects_count = 0;
943 struct _BackTrace {
944 BackTrace *next;
945 unsigned int hash;
946 int count;
947 int id;
948 MethodDesc *methods [1];
951 static BackTrace *backtrace_hash [HASH_SIZE];
952 static BackTrace **backtraces = NULL;
953 static int num_backtraces = 0;
954 static int next_backtrace = 0;
956 static int
957 hash_backtrace (int count, MethodDesc **methods)
959 int hash = count;
960 int i;
961 for (i = 0; i < count; ++i) {
962 hash = (hash << 5) - hash + methods [i]->method;
964 return hash;
967 static int
968 compare_backtrace (BackTrace *bt, int count, MethodDesc **methods)
970 int i;
971 if (bt->count != count)
972 return 0;
973 for (i = 0; i < count; ++i)
974 if (methods [i] != bt->methods [i])
975 return 0;
976 return 1;
979 static BackTrace*
980 add_backtrace (int count, MethodDesc **methods)
982 int hash = hash_backtrace (count, methods);
983 int slot = (hash & 0xffff) % HASH_SIZE;
984 BackTrace *bt = backtrace_hash [slot];
985 while (bt) {
986 if (bt->hash == hash && compare_backtrace (bt, count, methods))
987 return bt;
988 bt = bt->next;
990 bt = malloc (sizeof (BackTrace) + ((count - 1) * sizeof (void*)));
991 bt->next = backtrace_hash [slot];
992 backtrace_hash [slot] = bt;
993 if (next_backtrace == num_backtraces) {
994 num_backtraces *= 2;
995 if (!num_backtraces)
996 num_backtraces = 16;
997 backtraces = realloc (backtraces, sizeof (void*) * num_backtraces);
999 bt->id = next_backtrace++;
1000 backtraces [bt->id] = bt;
1001 bt->count = count;
1002 bt->hash = hash;
1003 for (slot = 0; slot < count; ++slot)
1004 bt->methods [slot] = methods [slot];
1006 return bt;
1009 typedef struct _MonitorDesc MonitorDesc;
1010 typedef struct _ThreadContext ThreadContext;
1012 typedef struct {
1013 FILE *file;
1014 #if defined (HAVE_SYS_ZLIB)
1015 gzFile *gzfile;
1016 #endif
1017 unsigned char *buf;
1018 int size;
1019 int data_version;
1020 int version_major;
1021 int version_minor;
1022 int timer_overhead;
1023 int pid;
1024 int port;
1025 uint64_t startup_time;
1026 ThreadContext *threads;
1027 ThreadContext *current;
1028 } ProfContext;
1030 struct _ThreadContext {
1031 ThreadContext *next;
1032 intptr_t thread_id;
1033 char *name;
1034 /* emulated stack */
1035 MethodDesc **stack;
1036 uint64_t *time_stack;
1037 uint64_t *callee_time_stack;
1038 uint64_t last_time;
1039 uint64_t contention_start;
1040 MonitorDesc *monitor;
1041 int stack_size;
1042 int stack_id;
1043 HeapShot *current_heap_shot;
1044 uintptr_t num_roots;
1045 uintptr_t size_roots;
1046 uintptr_t *roots;
1047 uintptr_t *roots_extra;
1048 int *roots_types;
1049 uint64_t gc_start_times [3];
1052 static void
1053 ensure_buffer (ProfContext *ctx, int size)
1055 if (ctx->size < size) {
1056 ctx->buf = realloc (ctx->buf, size);
1057 ctx->size = size;
1061 static int
1062 load_data (ProfContext *ctx, int size)
1064 ensure_buffer (ctx, size);
1065 #if defined (HAVE_SYS_ZLIB)
1066 if (ctx->gzfile) {
1067 int r = gzread (ctx->gzfile, ctx->buf, size);
1068 if (r == 0)
1069 return size == 0? 1: 0;
1070 return r == size;
1071 } else
1072 #endif
1074 int r = fread (ctx->buf, size, 1, ctx->file);
1075 if (r == 0)
1076 return size == 0? 1: 0;
1077 return r;
1081 static ThreadContext*
1082 get_thread (ProfContext *ctx, intptr_t thread_id)
1084 ThreadContext *thread;
1085 if (ctx->current && ctx->current->thread_id == thread_id)
1086 return ctx->current;
1087 thread = ctx->threads;
1088 while (thread) {
1089 if (thread->thread_id == thread_id) {
1090 return thread;
1092 thread = thread->next;
1094 thread = calloc (sizeof (ThreadContext), 1);
1095 thread->next = ctx->threads;
1096 ctx->threads = thread;
1097 thread->thread_id = thread_id;
1098 thread->last_time = 0;
1099 thread->stack_id = 0;
1100 thread->stack_size = 32;
1101 thread->stack = malloc (thread->stack_size * sizeof (void*));
1102 thread->time_stack = malloc (thread->stack_size * sizeof (uint64_t));
1103 thread->callee_time_stack = malloc (thread->stack_size * sizeof (uint64_t));
1104 return thread;
1107 static ThreadContext*
1108 load_thread (ProfContext *ctx, intptr_t thread_id)
1110 ThreadContext *thread = get_thread (ctx, thread_id);
1111 ctx->current = thread;
1112 return thread;
1115 static void
1116 ensure_thread_stack (ThreadContext *thread)
1118 if (thread->stack_id == thread->stack_size) {
1119 thread->stack_size *= 2;
1120 thread->stack = realloc (thread->stack, thread->stack_size * sizeof (void*));
1121 thread->time_stack = realloc (thread->time_stack, thread->stack_size * sizeof (uint64_t));
1122 thread->callee_time_stack = realloc (thread->callee_time_stack, thread->stack_size * sizeof (uint64_t));
1126 static int
1127 add_trace_hashed (CallContext *traces, int size, BackTrace *bt, uint64_t value)
1129 int i;
1130 unsigned int start_pos;
1131 start_pos = bt->hash % size;
1132 i = start_pos;
1133 do {
1134 if (traces [i].bt == bt) {
1135 traces [i].count += value;
1136 return 0;
1137 } else if (!traces [i].bt) {
1138 traces [i].bt = bt;
1139 traces [i].count += value;
1140 return 1;
1142 /* wrap around */
1143 if (++i == size)
1144 i = 0;
1145 } while (i != start_pos);
1146 /* should not happen */
1147 printf ("failed trace store\n");
1148 return 0;
1151 static void
1152 add_trace_bt (BackTrace *bt, TraceDesc *trace, uint64_t value)
1154 int i;
1155 if (!collect_traces)
1156 return;
1157 if (trace->count * 2 >= trace->size) {
1158 CallContext *n;
1159 int old_size = trace->size;
1160 trace->size *= 2;
1161 if (trace->size == 0)
1162 trace->size = 4;
1163 n = calloc (sizeof (CallContext) * trace->size, 1);
1164 for (i = 0; i < old_size; ++i) {
1165 if (trace->traces [i].bt)
1166 add_trace_hashed (n, trace->size, trace->traces [i].bt, trace->traces [i].count);
1168 if (trace->traces)
1169 free (trace->traces);
1170 trace->traces = n;
1172 trace->count += add_trace_hashed (trace->traces, trace->size, bt, value);
1175 static BackTrace*
1176 add_trace_thread (ThreadContext *thread, TraceDesc *trace, uint64_t value)
1178 BackTrace *bt;
1179 int count = thread->stack_id;
1180 if (!collect_traces)
1181 return NULL;
1182 if (count > trace_max)
1183 count = trace_max;
1184 bt = add_backtrace (count, thread->stack + thread->stack_id - count);
1185 add_trace_bt (bt, trace, value);
1186 return bt;
1189 static BackTrace*
1190 add_trace_methods (MethodDesc **methods, int count, TraceDesc *trace, uint64_t value)
1192 BackTrace *bt;
1193 if (!collect_traces)
1194 return NULL;
1195 if (count > trace_max)
1196 count = trace_max;
1197 bt = add_backtrace (count, methods);
1198 add_trace_bt (bt, trace, value);
1199 return bt;
1202 static void
1203 thread_add_root (ThreadContext *ctx, uintptr_t obj, int root_type, uintptr_t extra_info)
1205 if (ctx->num_roots == ctx->size_roots) {
1206 int new_size = ctx->size_roots * 2;
1207 if (!new_size)
1208 new_size = 4;
1209 ctx->roots = realloc (ctx->roots, new_size * sizeof (uintptr_t));
1210 ctx->roots_extra = realloc (ctx->roots_extra, new_size * sizeof (uintptr_t));
1211 ctx->roots_types = realloc (ctx->roots_types, new_size * sizeof (int));
1212 ctx->size_roots = new_size;
1214 ctx->roots_types [ctx->num_roots] = root_type;
1215 ctx->roots_extra [ctx->num_roots] = extra_info;
1216 ctx->roots [ctx->num_roots++] = obj;
1219 static int
1220 compare_callc (const void *a, const void *b)
1222 const CallContext *A = a;
1223 const CallContext *B = b;
1224 if (B->count == A->count)
1225 return 0;
1226 if (B->count < A->count)
1227 return -1;
1228 return 1;
1231 static void
1232 sort_context_array (TraceDesc* traces)
1234 int i, j;
1235 for (i = 0, j = 0; i < traces->size; ++i) {
1236 if (traces->traces [i].bt) {
1237 traces->traces [j].bt = traces->traces [i].bt;
1238 traces->traces [j].count = traces->traces [i].count;
1239 j++;
1242 qsort (traces->traces, traces->count, sizeof (CallContext), compare_callc);
1245 static void
1246 push_method (ThreadContext *thread, MethodDesc *method, uint64_t timestamp)
1248 ensure_thread_stack (thread);
1249 thread->time_stack [thread->stack_id] = timestamp;
1250 thread->callee_time_stack [thread->stack_id] = 0;
1251 thread->stack [thread->stack_id++] = method;
1252 method->recurse_count++;
1255 static void
1256 pop_method (ThreadContext *thread, MethodDesc *method, uint64_t timestamp)
1258 method->recurse_count--;
1259 if (thread->stack_id > 0 && thread->stack [thread->stack_id - 1] == method) {
1260 uint64_t tdiff;
1261 thread->stack_id--;
1262 method->calls++;
1263 if (timestamp < thread->time_stack [thread->stack_id])
1264 fprintf (outfile, "time went backwards for %s\n", method->name);
1265 tdiff = timestamp - thread->time_stack [thread->stack_id];
1266 if (thread->callee_time_stack [thread->stack_id] > tdiff)
1267 fprintf (outfile, "callee time bigger for %s\n", method->name);
1268 method->self_time += tdiff - thread->callee_time_stack [thread->stack_id];
1269 method->callee_time += thread->callee_time_stack [thread->stack_id];
1270 if (thread->stack_id)
1271 thread->callee_time_stack [thread->stack_id - 1] += tdiff;
1272 //fprintf (outfile, "method %s took %d\n", method->name, (int)(tdiff/1000));
1273 } else {
1274 fprintf (outfile, "unmatched leave at stack pos: %d for method %s\n", thread->stack_id, method->name);
1278 typedef struct {
1279 uint64_t total_time;
1280 uint64_t max_time;
1281 int count;
1282 } GCDesc;
1283 static GCDesc gc_info [3];
1284 static uint64_t max_heap_size;
1285 static uint64_t gc_object_moves;
1286 static int gc_resizes;
1287 typedef struct {
1288 uint64_t created;
1289 uint64_t destroyed;
1290 uint64_t live;
1291 uint64_t max_live;
1292 TraceDesc traces;
1293 } HandleInfo;
1294 static HandleInfo handle_info [4];
1296 static const char*
1297 gc_event_name (int ev)
1299 switch (ev) {
1300 case MONO_GC_EVENT_START: return "start";
1301 case MONO_GC_EVENT_MARK_START: return "mark start";
1302 case MONO_GC_EVENT_MARK_END: return "mark end";
1303 case MONO_GC_EVENT_RECLAIM_START: return "reclaim start";
1304 case MONO_GC_EVENT_RECLAIM_END: return "reclaim end";
1305 case MONO_GC_EVENT_END: return "end";
1306 case MONO_GC_EVENT_PRE_STOP_WORLD: return "pre stop";
1307 case MONO_GC_EVENT_POST_STOP_WORLD: return "post stop";
1308 case MONO_GC_EVENT_PRE_START_WORLD: return "pre start";
1309 case MONO_GC_EVENT_POST_START_WORLD: return "post start";
1310 default:
1311 return "unknown";
1315 static uint64_t clause_summary [MONO_EXCEPTION_CLAUSE_FAULT + 1];
1316 static uint64_t throw_count = 0;
1317 static TraceDesc exc_traces;
1319 static const char*
1320 clause_name (int type)
1322 switch (type) {
1323 case MONO_EXCEPTION_CLAUSE_NONE: return "catch";
1324 case MONO_EXCEPTION_CLAUSE_FILTER: return "filter";
1325 case MONO_EXCEPTION_CLAUSE_FINALLY: return "finally";
1326 case MONO_EXCEPTION_CLAUSE_FAULT: return "fault";
1327 default: return "invalid";
1331 static uint64_t monitor_contention;
1332 static uint64_t monitor_failed;
1333 static uint64_t monitor_acquired;
1335 struct _MonitorDesc {
1336 MonitorDesc *next;
1337 uintptr_t objid;
1338 uintptr_t contentions;
1339 uint64_t wait_time;
1340 uint64_t max_wait_time;
1341 TraceDesc traces;
1344 static MonitorDesc* monitor_hash [SMALL_HASH_SIZE] = {0};
1345 static int num_monitors = 0;
1347 static MonitorDesc*
1348 lookup_monitor (uintptr_t objid)
1350 int slot = ((objid >> 3) & 0xffff) % SMALL_HASH_SIZE;
1351 MonitorDesc *cd = monitor_hash [slot];
1352 while (cd && cd->objid != objid)
1353 cd = cd->next;
1354 if (!cd) {
1355 cd = calloc (sizeof (MonitorDesc), 1);
1356 cd->objid = objid;
1357 cd->next = monitor_hash [slot];
1358 monitor_hash [slot] = cd;
1359 num_monitors++;
1361 return cd;
1364 static const char*
1365 monitor_ev_name (int ev)
1367 switch (ev) {
1368 case MONO_PROFILER_MONITOR_CONTENTION: return "contended";
1369 case MONO_PROFILER_MONITOR_DONE: return "acquired";
1370 case MONO_PROFILER_MONITOR_FAIL: return "not taken";
1371 default: return "invalid";
1375 static const char*
1376 get_handle_name (int htype)
1378 switch (htype) {
1379 case 0: return "weak";
1380 case 1: return "weaktrack";
1381 case 2: return "normal";
1382 case 3: return "pinned";
1383 default: return "unknown";
1387 static const char*
1388 get_root_name (int rtype)
1390 switch (rtype & MONO_PROFILE_GC_ROOT_TYPEMASK) {
1391 case MONO_PROFILE_GC_ROOT_STACK: return "stack";
1392 case MONO_PROFILE_GC_ROOT_FINALIZER: return "finalizer";
1393 case MONO_PROFILE_GC_ROOT_HANDLE: return "handle";
1394 case MONO_PROFILE_GC_ROOT_OTHER: return "other";
1395 case MONO_PROFILE_GC_ROOT_MISC: return "misc";
1396 default: return "unknown";
1400 static MethodDesc**
1401 decode_bt (MethodDesc** sframes, int *size, unsigned char *p, unsigned char **endp, intptr_t ptr_base)
1403 MethodDesc **frames;
1404 int i;
1405 int flags = decode_uleb128 (p, &p);
1406 int count = decode_uleb128 (p, &p);
1407 if (flags != 0)
1408 return NULL;
1409 if (count > *size)
1410 frames = malloc (count * sizeof (void*));
1411 else
1412 frames = sframes;
1413 for (i = 0; i < count; ++i) {
1414 intptr_t ptrdiff = decode_sleb128 (p, &p);
1415 frames [i] = lookup_method (ptr_base + ptrdiff);
1417 *size = count;
1418 *endp = p;
1419 return frames;
1422 static void
1423 tracked_creation (uintptr_t obj, ClassDesc *cd, uint64_t size, BackTrace *bt, uint64_t timestamp)
1425 int i;
1426 for (i = 0; i < num_tracked_objects; ++i) {
1427 if (tracked_objects [i] != obj)
1428 continue;
1429 fprintf (outfile, "Object %p created (%s, %llu bytes) at %.3f secs.\n", (void*)obj, cd->name, size, (timestamp - startup_time)/1000000000.0);
1430 if (bt && bt->count) {
1431 int k;
1432 for (k = 0; k < bt->count; ++k)
1433 fprintf (outfile, "\t%s\n", bt->methods [k]->name);
1438 static void
1439 track_handle (uintptr_t obj, int htype, uint32_t handle)
1441 int i;
1442 for (i = 0; i < num_tracked_objects; ++i) {
1443 if (tracked_objects [i] == obj)
1444 fprintf (outfile, "Object %p referenced from handle %u\n", (void*)obj, handle);
1448 static void
1449 track_move (uintptr_t src, uintptr_t dst)
1451 int i;
1452 for (i = 0; i < num_tracked_objects; ++i) {
1453 if (tracked_objects [i] == src)
1454 fprintf (outfile, "Object %p moved to %p\n", (void*)src, (void*)dst);
1455 else if (tracked_objects [i] == dst)
1456 fprintf (outfile, "Object %p moved from %p\n", (void*)dst, (void*)src);
1460 static void
1461 track_obj_reference (uintptr_t obj, uintptr_t parent, ClassDesc *cd)
1463 int i;
1464 for (i = 0; i < num_tracked_objects; ++i) {
1465 if (tracked_objects [i] == obj)
1466 fprintf (outfile, "Object %p referenced from %p (%s).\n", (void*)obj, (void*)parent, cd->name);
1470 static void
1471 found_object (uintptr_t obj)
1473 num_tracked_objects ++;
1474 tracked_objects = realloc (tracked_objects, num_tracked_objects * sizeof (tracked_objects [0]));
1475 tracked_objects [num_tracked_objects - 1] = obj;
1478 #define OBJ_ADDR(diff) ((obj_base + diff) << 3)
1479 #define LOG_TIME(base,diff) /*fprintf("outfile, time %llu + %llu near offset %d\n", base, diff, p - ctx->buf)*/
1481 static int
1482 decode_buffer (ProfContext *ctx)
1484 unsigned char *p;
1485 unsigned char *end;
1486 intptr_t thread_id;
1487 intptr_t ptr_base;
1488 intptr_t obj_base;
1489 intptr_t method_base;
1490 uint64_t time_base;
1491 uint64_t file_offset;
1492 int len, i;
1493 ThreadContext *thread;
1495 #ifdef HAVE_SYS_ZLIB
1496 if (ctx->gzfile)
1497 file_offset = gztell (ctx->gzfile);
1498 else
1499 #endif
1500 file_offset = ftell (ctx->file);
1501 if (!load_data (ctx, 48))
1502 return 0;
1503 p = ctx->buf;
1504 if (read_int32 (p) != BUF_ID) {
1505 fprintf (outfile, "Incorrect buffer id: 0x%x\n", read_int32 (p));
1506 for (i = 0; i < 48; ++i) {
1507 fprintf (outfile, "0x%x%s", p [i], i % 8?" ":"\n");
1509 return 0;
1511 len = read_int32 (p + 4);
1512 time_base = read_int64 (p + 8);
1513 ptr_base = read_int64 (p + 16);
1514 obj_base = read_int64 (p + 24);
1515 thread_id = read_int64 (p + 32);
1516 method_base = read_int64 (p + 40);
1517 if (debug)
1518 fprintf (outfile, "buf: thread:%x, len: %d, time: %llu, file offset: %llu\n", thread_id, len, time_base, file_offset);
1519 thread = load_thread (ctx, thread_id);
1520 if (!load_data (ctx, len))
1521 return 0;
1522 if (!startup_time) {
1523 startup_time = time_base;
1524 if (time_from) {
1525 time_from += startup_time;
1526 time_to += startup_time;
1528 if (!thread->name)
1529 thread->name = pstrdup ("Main");
1531 for (i = 0; i < thread->stack_id; ++i)
1532 thread->stack [i]->recurse_count++;
1533 p = ctx->buf;
1534 end = p + len;
1535 while (p < end) {
1536 switch (*p & 0xf) {
1537 case TYPE_GC: {
1538 int subtype = *p & 0xf0;
1539 uint64_t tdiff = decode_uleb128 (p + 1, &p);
1540 LOG_TIME (time_base, tdiff);
1541 time_base += tdiff;
1542 if (subtype == TYPE_GC_RESIZE) {
1543 uint64_t new_size = decode_uleb128 (p, &p);
1544 if (debug)
1545 fprintf (outfile, "gc heap resized to %llu\n", new_size);
1546 gc_resizes++;
1547 if (new_size > max_heap_size)
1548 max_heap_size = new_size;
1549 } else if (subtype == TYPE_GC_EVENT) {
1550 uint64_t ev = decode_uleb128 (p, &p);
1551 int gen = decode_uleb128 (p, &p);
1552 if (debug)
1553 fprintf (outfile, "gc event for gen%d: %s at %llu (thread: 0x%x)\n", gen, gc_event_name (ev), time_base, thread->thread_id);
1554 if (gen > 2) {
1555 fprintf (outfile, "incorrect gc gen: %d\n", gen);
1556 break;
1558 if (ev == MONO_GC_EVENT_START) {
1559 thread->gc_start_times [gen] = time_base;
1560 gc_info [gen].count++;
1561 } else if (ev == MONO_GC_EVENT_END) {
1562 tdiff = time_base - thread->gc_start_times [gen];
1563 gc_info [gen].total_time += tdiff;
1564 if (tdiff > gc_info [gen].max_time)
1565 gc_info [gen].max_time = tdiff;
1567 } else if (subtype == TYPE_GC_MOVE) {
1568 int j, num = decode_uleb128 (p, &p);
1569 gc_object_moves += num / 2;
1570 for (j = 0; j < num; j += 2) {
1571 intptr_t obj1diff = decode_sleb128 (p, &p);
1572 intptr_t obj2diff = decode_sleb128 (p, &p);
1573 if (num_tracked_objects)
1574 track_move (OBJ_ADDR (obj1diff), OBJ_ADDR (obj2diff));
1575 if (debug) {
1576 fprintf (outfile, "moved obj %p to %p\n", (void*)OBJ_ADDR (obj1diff), (void*)OBJ_ADDR (obj2diff));
1579 } else if (subtype == TYPE_GC_HANDLE_CREATED) {
1580 int htype = decode_uleb128 (p, &p);
1581 uint32_t handle = decode_uleb128 (p, &p);
1582 intptr_t objdiff = decode_sleb128 (p, &p);
1583 if (htype > 3)
1584 return 0;
1585 handle_info [htype].created++;
1586 handle_info [htype].live++;
1587 add_trace_thread (thread, &handle_info [htype].traces, 1);
1588 /* FIXME: we don't take into account timing here */
1589 if (handle_info [htype].live > handle_info [htype].max_live)
1590 handle_info [htype].max_live = handle_info [htype].live;
1591 if (num_tracked_objects)
1592 track_handle (OBJ_ADDR (objdiff), htype, handle);
1593 if (debug)
1594 fprintf (outfile, "handle (%s) %u created for object %p\n", get_handle_name (htype), handle, (void*)OBJ_ADDR (objdiff));
1595 } else if (subtype == TYPE_GC_HANDLE_DESTROYED) {
1596 int htype = decode_uleb128 (p, &p);
1597 uint32_t handle = decode_uleb128 (p, &p);
1598 if (htype > 3)
1599 return 0;
1600 handle_info [htype].destroyed ++;
1601 handle_info [htype].live--;
1602 if (debug)
1603 fprintf (outfile, "handle (%s) %u destroyed\n", get_handle_name (htype), handle);
1605 break;
1607 case TYPE_METADATA: {
1608 int error = *p & TYPE_LOAD_ERR;
1609 uint64_t tdiff = decode_uleb128 (p + 1, &p);
1610 int mtype = *p++;
1611 intptr_t ptrdiff = decode_sleb128 (p, &p);
1612 LOG_TIME (time_base, tdiff);
1613 time_base += tdiff;
1614 if (mtype == TYPE_CLASS) {
1615 intptr_t imptrdiff = decode_sleb128 (p, &p);
1616 uint64_t flags = decode_uleb128 (p, &p);
1617 if (flags) {
1618 fprintf (outfile, "non-zero flags in class\n");
1619 return 0;
1621 if (debug)
1622 fprintf (outfile, "loaded class %p (%s in %p) at %llu\n", (void*)(ptr_base + ptrdiff), p, (void*)(ptr_base + imptrdiff), time_base);
1623 if (!error)
1624 add_class (ptr_base + ptrdiff, (char*)p);
1625 while (*p) p++;
1626 p++;
1627 } else if (mtype == TYPE_IMAGE) {
1628 uint64_t flags = decode_uleb128 (p, &p);
1629 if (flags) {
1630 fprintf (outfile, "non-zero flags in image\n");
1631 return 0;
1633 if (debug)
1634 fprintf (outfile, "loaded image %p (%s) at %llu\n", (void*)(ptr_base + ptrdiff), p, time_base);
1635 if (!error)
1636 add_image (ptr_base + ptrdiff, (char*)p);
1637 while (*p) p++;
1638 p++;
1639 } else if (mtype == TYPE_THREAD) {
1640 ThreadContext *nt;
1641 uint64_t flags = decode_uleb128 (p, &p);
1642 if (flags) {
1643 fprintf (outfile, "non-zero flags in thread\n");
1644 return 0;
1646 nt = get_thread (ctx, ptr_base * ptrdiff);
1647 nt->name = pstrdup ((char*)p);
1648 if (debug)
1649 fprintf (outfile, "thread %p named: %s\n", (void*)(ptr_base + ptrdiff), p);
1650 while (*p) p++;
1651 p++;
1653 break;
1655 case TYPE_ALLOC: {
1656 int has_bt = *p & TYPE_ALLOC_BT;
1657 uint64_t tdiff = decode_uleb128 (p + 1, &p);
1658 intptr_t ptrdiff = decode_sleb128 (p, &p);
1659 intptr_t objdiff = decode_sleb128 (p, &p);
1660 uint64_t len;
1661 int num_bt = 0;
1662 MethodDesc* sframes [8];
1663 MethodDesc** frames = sframes;
1664 ClassDesc *cd = lookup_class (ptr_base + ptrdiff);
1665 len = decode_uleb128 (p, &p);
1666 LOG_TIME (time_base, tdiff);
1667 time_base += tdiff;
1668 if (debug)
1669 fprintf (outfile, "alloced object %p, size %llu (%s) at %llu\n", (void*)OBJ_ADDR (objdiff), len, lookup_class (ptr_base + ptrdiff)->name, time_base);
1670 if (has_bt) {
1671 num_bt = 8;
1672 frames = decode_bt (sframes, &num_bt, p, &p, ptr_base);
1673 if (!frames) {
1674 fprintf (outfile, "Cannot load backtrace\n");
1675 return 0;
1678 if ((thread_filter && thread_filter == thread->thread_id) || (time_base >= time_from && time_base < time_to)) {
1679 BackTrace *bt;
1680 cd->allocs++;
1681 cd->alloc_size += len;
1682 if (has_bt)
1683 bt = add_trace_methods (frames, num_bt, &cd->traces, len);
1684 else
1685 bt = add_trace_thread (thread, &cd->traces, len);
1686 if (find_size && len >= find_size) {
1687 if (!find_name || strstr (cd->name, find_name))
1688 found_object (OBJ_ADDR (objdiff));
1689 } else if (!find_size && find_name && strstr (cd->name, find_name)) {
1690 found_object (OBJ_ADDR (objdiff));
1692 if (num_tracked_objects)
1693 tracked_creation (OBJ_ADDR (objdiff), cd, len, bt, time_base);
1695 if (frames != sframes)
1696 free (frames);
1697 break;
1699 case TYPE_METHOD: {
1700 int subtype = *p & 0xf0;
1701 uint64_t tdiff = decode_uleb128 (p + 1, &p);
1702 int64_t ptrdiff = decode_sleb128 (p, &p);
1703 LOG_TIME (time_base, tdiff);
1704 time_base += tdiff;
1705 method_base += ptrdiff;
1706 if (subtype == TYPE_JIT) {
1707 intptr_t codediff = decode_sleb128 (p, &p);
1708 int codelen = decode_uleb128 (p, &p);
1709 if (debug)
1710 fprintf (outfile, "jitted method %p (%s), size: %d, code: %p\n", (void*)(method_base), p, codelen, (void*)(ptr_base + codediff));
1711 add_method (method_base, (char*)p, ptr_base + codediff, codelen);
1712 while (*p) p++;
1713 p++;
1714 } else {
1715 MethodDesc *method;
1716 if ((thread_filter && thread_filter != thread->thread_id))
1717 break;
1718 method = lookup_method (method_base);
1719 if (subtype == TYPE_ENTER) {
1720 add_trace_thread (thread, &method->traces, 1);
1721 push_method (thread, method, time_base);
1722 } else {
1723 pop_method (thread, method, time_base);
1725 if (debug)
1726 fprintf (outfile, "%s method %s\n", subtype == TYPE_ENTER? "enter": subtype == TYPE_EXC_LEAVE? "exleave": "leave", method->name);
1728 break;
1730 case TYPE_HEAP: {
1731 int subtype = *p & 0xf0;
1732 if (subtype == TYPE_HEAP_OBJECT) {
1733 HeapObjectDesc *ho;
1734 int i;
1735 intptr_t objdiff = decode_sleb128 (p + 1, &p);
1736 intptr_t ptrdiff = decode_sleb128 (p, &p);
1737 uint64_t size = decode_uleb128 (p, &p);
1738 uintptr_t num = decode_uleb128 (p, &p);
1739 uintptr_t ref_offset;
1740 uintptr_t last_obj_offset = 0;
1741 ClassDesc *cd = lookup_class (ptr_base + ptrdiff);
1742 if (size) {
1743 HeapClassDesc *hcd = add_heap_shot_class (thread->current_heap_shot, cd, size);
1744 if (collect_traces) {
1745 ho = alloc_heap_obj (OBJ_ADDR (objdiff), hcd, num);
1746 add_heap_shot_obj (thread->current_heap_shot, ho);
1747 ref_offset = 0;
1749 } else {
1750 if (collect_traces)
1751 ho = heap_shot_obj_add_refs (thread->current_heap_shot, OBJ_ADDR (objdiff), num, &ref_offset);
1753 for (i = 0; i < num; ++i) {
1754 /* FIXME: use object distance to measure how good
1755 * the GC is at keeping related objects close
1757 uintptr_t offset = ctx->data_version > 1? last_obj_offset + decode_uleb128 (p, &p): -1;
1758 intptr_t obj1diff = decode_sleb128 (p, &p);
1759 last_obj_offset = offset;
1760 if (collect_traces)
1761 ho->refs [ref_offset + i] = OBJ_ADDR (obj1diff);
1762 if (num_tracked_objects)
1763 track_obj_reference (OBJ_ADDR (obj1diff), OBJ_ADDR (objdiff), cd);
1765 if (debug && size)
1766 fprintf (outfile, "traced object %p, size %llu (%s), refs: %d\n", (void*)OBJ_ADDR (objdiff), size, cd->name, num);
1767 } else if (subtype == TYPE_HEAP_ROOT) {
1768 uintptr_t num = decode_uleb128 (p + 1, &p);
1769 uintptr_t gc_num = decode_uleb128 (p, &p);
1770 int i;
1771 for (i = 0; i < num; ++i) {
1772 intptr_t objdiff = decode_sleb128 (p, &p);
1773 int root_type = decode_uleb128 (p, &p);
1774 /* we just discard the extra info for now */
1775 uintptr_t extra_info = decode_uleb128 (p, &p);
1776 if (debug)
1777 fprintf (outfile, "object %p is a %s root\n", (void*)OBJ_ADDR (objdiff), get_root_name (root_type));
1778 if (collect_traces)
1779 thread_add_root (thread, OBJ_ADDR (objdiff), root_type, extra_info);
1781 } else if (subtype == TYPE_HEAP_END) {
1782 uint64_t tdiff = decode_uleb128 (p + 1, &p);
1783 LOG_TIME (time_base, tdiff);
1784 time_base += tdiff;
1785 if (debug)
1786 fprintf (outfile, "heap shot end\n");
1787 if (collect_traces) {
1788 HeapShot *hs = thread->current_heap_shot;
1789 if (hs && thread->num_roots) {
1790 /* transfer the root ownershipt to the heapshot */
1791 hs->num_roots = thread->num_roots;
1792 hs->roots = thread->roots;
1793 hs->roots_extra = thread->roots_extra;
1794 hs->roots_types = thread->roots_types;
1795 } else {
1796 free (thread->roots);
1797 free (thread->roots_extra);
1798 free (thread->roots_types);
1800 thread->num_roots = 0;
1801 thread->size_roots = 0;
1802 thread->roots = NULL;
1803 thread->roots_extra = NULL;
1804 thread->roots_types = NULL;
1805 heap_shot_resolve_reverse_refs (hs);
1806 heap_shot_mark_objects (hs);
1807 heap_shot_free_objects (hs);
1809 thread->current_heap_shot = NULL;
1810 } else if (subtype == TYPE_HEAP_START) {
1811 uint64_t tdiff = decode_uleb128 (p + 1, &p);
1812 LOG_TIME (time_base, tdiff);
1813 time_base += tdiff;
1814 if (debug)
1815 fprintf (outfile, "heap shot start\n");
1816 thread->current_heap_shot = new_heap_shot (time_base);
1818 break;
1820 case TYPE_MONITOR: {
1821 int event = (*p >> 4) & 0x3;
1822 int has_bt = *p & TYPE_MONITOR_BT;
1823 uint64_t tdiff = decode_uleb128 (p + 1, &p);
1824 intptr_t objdiff = decode_sleb128 (p, &p);
1825 MethodDesc* sframes [8];
1826 MethodDesc** frames = sframes;
1827 int record;
1828 int num_bt = 0;
1829 LOG_TIME (time_base, tdiff);
1830 time_base += tdiff;
1831 record = (!thread_filter || thread_filter == thread->thread_id);
1832 if (event == MONO_PROFILER_MONITOR_CONTENTION) {
1833 MonitorDesc *mdesc = lookup_monitor (OBJ_ADDR (objdiff));
1834 if (record) {
1835 monitor_contention++;
1836 mdesc->contentions++;
1837 thread->monitor = mdesc;
1838 thread->contention_start = time_base;
1840 if (has_bt) {
1841 num_bt = 8;
1842 frames = decode_bt (sframes, &num_bt, p, &p, ptr_base);
1843 if (!frames) {
1844 fprintf (outfile, "Cannot load backtrace\n");
1845 return 0;
1847 if (record)
1848 add_trace_methods (frames, num_bt, &mdesc->traces, 1);
1849 } else {
1850 if (record)
1851 add_trace_thread (thread, &mdesc->traces, 1);
1853 } else if (event == MONO_PROFILER_MONITOR_FAIL) {
1854 if (record) {
1855 monitor_failed++;
1856 if (thread->monitor && thread->contention_start) {
1857 uint64_t wait_time = time_base - thread->contention_start;
1858 if (wait_time > thread->monitor->max_wait_time)
1859 thread->monitor->max_wait_time = wait_time;
1860 thread->monitor->wait_time += wait_time;
1861 thread->monitor = NULL;
1862 thread->contention_start = 0;
1865 } else if (event == MONO_PROFILER_MONITOR_DONE) {
1866 if (record) {
1867 monitor_acquired++;
1868 if (thread->monitor && thread->contention_start) {
1869 uint64_t wait_time = time_base - thread->contention_start;
1870 if (wait_time > thread->monitor->max_wait_time)
1871 thread->monitor->max_wait_time = wait_time;
1872 thread->monitor->wait_time += wait_time;
1873 thread->monitor = NULL;
1874 thread->contention_start = 0;
1878 if (debug)
1879 fprintf (outfile, "monitor %s for object %p\n", monitor_ev_name (event), (void*)OBJ_ADDR (objdiff));
1880 if (frames != sframes)
1881 free (frames);
1882 break;
1884 case TYPE_EXCEPTION: {
1885 int subtype = *p & 0x70;
1886 int has_bt = *p & TYPE_EXCEPTION_BT;
1887 uint64_t tdiff = decode_uleb128 (p + 1, &p);
1888 MethodDesc* sframes [8];
1889 MethodDesc** frames = sframes;
1890 int record;
1891 LOG_TIME (time_base, tdiff);
1892 time_base += tdiff;
1893 record = (!thread_filter || thread_filter == thread->thread_id);
1894 if (subtype == TYPE_CLAUSE) {
1895 int clause_type = decode_uleb128 (p, &p);
1896 int clause_num = decode_uleb128 (p, &p);
1897 int64_t ptrdiff = decode_sleb128 (p, &p);
1898 method_base += ptrdiff;
1899 if (record)
1900 clause_summary [clause_type]++;
1901 if (debug)
1902 fprintf (outfile, "clause %s (%d) in method %s\n", clause_name (clause_type), clause_num, lookup_method (method_base)->name);
1903 } else {
1904 intptr_t objdiff = decode_sleb128 (p, &p);
1905 if (record)
1906 throw_count++;
1907 if (has_bt) {
1908 has_bt = 8;
1909 frames = decode_bt (sframes, &has_bt, p, &p, ptr_base);
1910 if (!frames) {
1911 fprintf (outfile, "Cannot load backtrace\n");
1912 return 0;
1914 if (record)
1915 add_trace_methods (frames, has_bt, &exc_traces, 1);
1916 } else {
1917 if (record)
1918 add_trace_thread (thread, &exc_traces, 1);
1920 if (frames != sframes)
1921 free (frames);
1922 if (debug)
1923 fprintf (outfile, "throw %p\n", (void*)OBJ_ADDR (objdiff));
1925 break;
1927 case TYPE_SAMPLE: {
1928 int subtype = *p & 0xf0;
1929 if (subtype == TYPE_SAMPLE_HIT) {
1930 int i;
1931 int sample_type = decode_uleb128 (p + 1, &p);
1932 uint64_t tstamp = decode_uleb128 (p, &p);
1933 int count = decode_uleb128 (p, &p);
1934 for (i = 0; i < count; ++i) {
1935 uintptr_t ip = ptr_base + decode_sleb128 (p, &p);
1936 add_stat_sample (sample_type, ip);
1937 if (debug)
1938 fprintf (outfile, "sample hit, type: %d at %p\n", sample_type, (void*)ip);
1940 } else if (subtype == TYPE_SAMPLE_USYM) {
1941 /* un unmanaged symbol description */
1942 uintptr_t addr = ptr_base + decode_sleb128 (p + 1, &p);
1943 uintptr_t size = decode_uleb128 (p, &p);
1944 char *name;
1945 name = pstrdup ((char*)p);
1946 add_unmanaged_symbol (addr, name, size);
1947 if (debug)
1948 fprintf (outfile, "unmanaged symbol %s at %p\n", name, (void*)addr);
1949 while (*p) p++;
1950 p++;
1951 } else if (subtype == TYPE_SAMPLE_UBIN) {
1952 /* un unmanaged binary loaded in memory */
1953 uint64_t tdiff = decode_uleb128 (p + 1, &p);
1954 uintptr_t addr = decode_sleb128 (p, &p);
1955 uint64_t offset = decode_uleb128 (p, &p);
1956 uintptr_t size = decode_uleb128 (p, &p);
1957 char *name;
1958 LOG_TIME (time_base, tdiff);
1959 time_base += tdiff;
1960 name = pstrdup ((char*)p);
1961 add_unmanaged_binary (addr, name, size);
1962 if (debug)
1963 fprintf (outfile, "unmanaged binary %s at %p\n", name, (void*)addr);
1964 while (*p) p++;
1965 p++;
1966 } else {
1967 return 0;
1969 break;
1971 default:
1972 fprintf (outfile, "unhandled profiler event: 0x%x at file offset: %llu + %d (len: %d\n)\n", *p, file_offset, p - ctx->buf, len);
1973 exit (1);
1976 thread->last_time = time_base;
1977 for (i = 0; i < thread->stack_id; ++i)
1978 thread->stack [i]->recurse_count = 0;
1979 return 1;
1982 static ProfContext*
1983 load_file (char *name)
1985 unsigned char *p;
1986 ProfContext *ctx = calloc (sizeof (ProfContext), 1);
1987 if (strcmp (name, "-") == 0)
1988 ctx->file = stdin;
1989 else
1990 ctx->file = fopen (name, "rb");
1991 if (!ctx->file) {
1992 printf ("Cannot open file: %s\n", name);
1993 exit (1);
1995 #if defined (HAVE_SYS_ZLIB)
1996 if (ctx->file != stdin)
1997 ctx->gzfile = gzdopen (fileno (ctx->file), "rb");
1998 #endif
1999 if (!load_data (ctx, 32))
2000 return NULL;
2001 p = ctx->buf;
2002 if (read_int32 (p) != LOG_HEADER_ID || p [6] > LOG_DATA_VERSION)
2003 return NULL;
2004 ctx->version_major = p [4];
2005 ctx->version_minor = p [5];
2006 ctx->data_version = p [6];
2007 /* reading 64 bit files on 32 bit systems not supported yet */
2008 if (p [7] > sizeof (void*))
2009 return NULL;
2010 if (read_int32 (p + 20)) /* flags must be 0 */
2011 return NULL;
2012 ctx->startup_time = read_int64 (p + 8);
2013 ctx->timer_overhead = read_int32 (p + 16);
2014 ctx->pid = read_int32 (p + 24);
2015 ctx->port = read_int16 (p + 28);
2016 return ctx;
2019 enum {
2020 ALLOC_SORT_BYTES,
2021 ALLOC_SORT_COUNT
2023 static int alloc_sort_mode = ALLOC_SORT_BYTES;
2025 static int
2026 compare_class (const void *a, const void *b)
2028 ClassDesc *const*A = a;
2029 ClassDesc *const*B = b;
2030 uint64_t vala, valb;
2031 if (alloc_sort_mode == ALLOC_SORT_BYTES) {
2032 vala = (*A)->alloc_size;
2033 valb = (*B)->alloc_size;
2034 } else {
2035 vala = (*A)->allocs;
2036 valb = (*B)->allocs;
2038 if (valb == vala)
2039 return 0;
2040 if (valb < vala)
2041 return -1;
2042 return 1;
2045 static void
2046 dump_header (ProfContext *ctx)
2048 time_t st = ctx->startup_time / 1000;
2049 char *t = ctime (&st);
2050 fprintf (outfile, "\nMono log profiler data\n");
2051 fprintf (outfile, "\tProfiler version: %d.%d\n", ctx->version_major, ctx->version_minor);
2052 fprintf (outfile, "\tData version: %d\n", ctx->data_version);
2053 fprintf (outfile, "\tMean timer overhead: %d nanoseconds\n", ctx->timer_overhead);
2054 fprintf (outfile, "\tProgram startup: %s", t);
2055 if (ctx->pid)
2056 fprintf (outfile, "\tProgram ID: %d\n", ctx->pid);
2057 if (ctx->port)
2058 fprintf (outfile, "\tServer listening on: %d\n", ctx->port);
2061 static void
2062 dump_traces (TraceDesc *traces, const char *desc)
2064 int j;
2065 if (!show_traces)
2066 return;
2067 if (!traces->count)
2068 return;
2069 sort_context_array (traces);
2070 for (j = 0; j < traces->count; ++j) {
2071 int k;
2072 BackTrace *bt;
2073 bt = traces->traces [j].bt;
2074 if (!bt->count)
2075 continue;
2076 fprintf (outfile, "\t%llu %s from:\n", traces->traces [j].count, desc);
2077 for (k = 0; k < bt->count; ++k)
2078 fprintf (outfile, "\t\t%s\n", bt->methods [k]->name);
2082 static void
2083 dump_threads (ProfContext *ctx)
2085 ThreadContext *thread;
2086 fprintf (outfile, "\nThread summary\n");
2087 for (thread = ctx->threads; thread; thread = thread->next) {
2088 fprintf (outfile, "\tThread: %p, name: \"%s\"\n", (void*)thread->thread_id, thread->name? thread->name: "");
2092 static void
2093 dump_exceptions (void)
2095 int i;
2096 fprintf (outfile, "\nException summary\n");
2097 fprintf (outfile, "\tThrows: %llu\n", throw_count);
2098 dump_traces (&exc_traces, "throws");
2099 for (i = 0; i <= MONO_EXCEPTION_CLAUSE_FAULT; ++i) {
2100 if (!clause_summary [i])
2101 continue;
2102 fprintf (outfile, "\tExecuted %s clauses: %llu\n", clause_name (i), clause_summary [i]);
2106 static int
2107 compare_monitor (const void *a, const void *b)
2109 MonitorDesc *const*A = a;
2110 MonitorDesc *const*B = b;
2111 if ((*B)->wait_time == (*A)->wait_time)
2112 return 0;
2113 if ((*B)->wait_time < (*A)->wait_time)
2114 return -1;
2115 return 1;
2118 static void
2119 dump_monitors (void)
2121 MonitorDesc **monitors;
2122 int i, j;
2123 if (!num_monitors)
2124 return;
2125 monitors = malloc (sizeof (void*) * num_monitors);
2126 for (i = 0, j = 0; i < SMALL_HASH_SIZE; ++i) {
2127 MonitorDesc *mdesc = monitor_hash [i];
2128 while (mdesc) {
2129 monitors [j++] = mdesc;
2130 mdesc = mdesc->next;
2133 qsort (monitors, num_monitors, sizeof (void*), compare_monitor);
2134 fprintf (outfile, "\nMonitor lock summary\n");
2135 for (i = 0; i < num_monitors; ++i) {
2136 MonitorDesc *mdesc = monitors [i];
2137 fprintf (outfile, "\tLock object %p: %d contentions\n", (void*)mdesc->objid, (int)mdesc->contentions);
2138 fprintf (outfile, "\t\t%.6f secs total wait time, %.6f max, %.6f average\n",
2139 mdesc->wait_time/1000000000.0, mdesc->max_wait_time/1000000000.0, mdesc->wait_time/1000000000.0/mdesc->contentions);
2140 dump_traces (&mdesc->traces, "contentions");
2142 fprintf (outfile, "\tLock contentions: %llu\n", monitor_contention);
2143 fprintf (outfile, "\tLock acquired: %llu\n", monitor_acquired);
2144 fprintf (outfile, "\tLock failures: %llu\n", monitor_failed);
2147 static void
2148 dump_gcs (void)
2150 int i;
2151 fprintf (outfile, "\nGC summary\n");
2152 fprintf (outfile, "\tGC resizes: %d\n", gc_resizes);
2153 fprintf (outfile, "\tMax heap size: %llu\n", max_heap_size);
2154 fprintf (outfile, "\tObject moves: %llu\n", gc_object_moves);
2155 for (i = 0; i < 3; ++i) {
2156 if (!gc_info [i].count)
2157 continue;
2158 fprintf (outfile, "\tGen%d collections: %d, max time: %lluus, total time: %lluus, average: %lluus\n",
2159 i, gc_info [i].count, gc_info [i].max_time / 1000, gc_info [i].total_time / 1000,
2160 gc_info [i].total_time / gc_info [i].count / 1000);
2162 for (i = 0; i < 3; ++i) {
2163 if (!handle_info [i].max_live)
2164 continue;
2165 fprintf (outfile, "\tGC handles %s: created: %llu, destroyed: %llu, max: %llu\n",
2166 get_handle_name (i), handle_info [i].created, handle_info [i].destroyed, handle_info [i].max_live);
2167 dump_traces (&handle_info [i].traces, "created");
2171 static void
2172 dump_jit (void)
2174 int i;
2175 int code_size = 0;
2176 int compiled_methods = 0;
2177 MethodDesc* m;
2178 fprintf (outfile, "\nJIT summary\n");
2179 for (i = 0; i < HASH_SIZE; ++i) {
2180 m = method_hash [i];
2181 for (m = method_hash [i]; m; m = m->next) {
2182 if (!m->code)
2183 continue;
2184 compiled_methods++;
2185 code_size += m->len;
2188 fprintf (outfile, "\tCompiled methods: %d\n", compiled_methods);
2189 fprintf (outfile, "\tGenerated code size: %d\n", code_size);
2192 static void
2193 dump_allocations (void)
2195 int i, c;
2196 intptr_t allocs = 0;
2197 uint64_t size = 0;
2198 int header_done = 0;
2199 ClassDesc **classes = malloc (num_classes * sizeof (void*));
2200 ClassDesc *cd;
2201 c = 0;
2202 for (i = 0; i < HASH_SIZE; ++i) {
2203 cd = class_hash [i];
2204 while (cd) {
2205 classes [c++] = cd;
2206 cd = cd->next;
2209 qsort (classes, num_classes, sizeof (void*), compare_class);
2210 for (i = 0; i < num_classes; ++i) {
2211 cd = classes [i];
2212 if (!cd->allocs)
2213 continue;
2214 allocs += cd->allocs;
2215 size += cd->alloc_size;
2216 if (!header_done++) {
2217 fprintf (outfile, "\nAllocation summary\n");
2218 fprintf (outfile, "%10s %10s %8s Type name\n", "Bytes", "Count", "Average");
2220 fprintf (outfile, "%10llu %10d %8llu %s\n", cd->alloc_size, cd->allocs, cd->alloc_size / cd->allocs, cd->name);
2221 dump_traces (&cd->traces, "bytes");
2223 if (allocs)
2224 fprintf (outfile, "Total memory allocated: %llu bytes in %d objects\n", size, allocs);
2227 enum {
2228 METHOD_SORT_TOTAL,
2229 METHOD_SORT_SELF,
2230 METHOD_SORT_CALLS
2233 static int method_sort_mode = METHOD_SORT_TOTAL;
2235 static int
2236 compare_method (const void *a, const void *b)
2238 MethodDesc *const*A = a;
2239 MethodDesc *const*B = b;
2240 uint64_t vala, valb;
2241 if (method_sort_mode == METHOD_SORT_SELF) {
2242 vala = (*A)->self_time;
2243 valb = (*B)->self_time;
2244 } else if (method_sort_mode == METHOD_SORT_CALLS) {
2245 vala = (*A)->calls;
2246 valb = (*B)->calls;
2247 } else {
2248 vala = (*A)->total_time;
2249 valb = (*B)->total_time;
2251 if (vala == valb)
2252 return 0;
2253 if (valb < vala)
2254 return -1;
2255 return 1;
2258 static void
2259 dump_metadata (void)
2261 fprintf (outfile, "\nMetadata summary\n");
2262 fprintf (outfile, "\tLoaded images: %d\n", num_images);
2263 if (verbose) {
2264 ImageDesc *image;
2265 int i;
2266 for (i = 0; i < SMALL_HASH_SIZE; ++i) {
2267 image = image_hash [i];
2268 while (image) {
2269 fprintf (outfile, "\t\t%s\n", image->filename);
2270 image = image->next;
2277 static void
2278 dump_methods (void)
2280 int i, c;
2281 uint64_t calls = 0;
2282 int header_done = 0;
2283 MethodDesc **methods = malloc (num_methods * sizeof (void*));
2284 MethodDesc *cd;
2285 c = 0;
2286 for (i = 0; i < HASH_SIZE; ++i) {
2287 cd = method_hash [i];
2288 while (cd) {
2289 cd->total_time = cd->self_time + cd->callee_time;
2290 methods [c++] = cd;
2291 cd = cd->next;
2294 qsort (methods, num_methods, sizeof (void*), compare_method);
2295 for (i = 0; i < num_methods; ++i) {
2296 uint64_t msecs;
2297 uint64_t smsecs;
2298 cd = methods [i];
2299 if (!cd->calls)
2300 continue;
2301 calls += cd->calls;
2302 msecs = cd->total_time / 1000000;
2303 smsecs = (cd->total_time - cd->callee_time) / 1000000;
2304 if (!msecs && !verbose)
2305 continue;
2306 if (!header_done++) {
2307 fprintf (outfile, "\nMethod call summary\n");
2308 fprintf (outfile, "%8s %8s %10s Method name\n", "Total(ms)", "Self(ms)", "Calls");
2310 fprintf (outfile, "%8llu %8llu %10llu %s\n", msecs, smsecs, cd->calls, cd->name);
2311 dump_traces (&cd->traces, "calls");
2313 if (calls)
2314 fprintf (outfile, "Total calls: %llu\n", calls);
2317 static int
2318 compare_heap_class (const void *a, const void *b)
2320 HeapClassDesc *const*A = a;
2321 HeapClassDesc *const*B = b;
2322 uint64_t vala, valb;
2323 if (alloc_sort_mode == ALLOC_SORT_BYTES) {
2324 vala = (*A)->total_size;
2325 valb = (*B)->total_size;
2326 } else {
2327 vala = (*A)->count;
2328 valb = (*B)->count;
2330 if (valb == vala)
2331 return 0;
2332 if (valb < vala)
2333 return -1;
2334 return 1;
2337 static int
2338 compare_rev_class (const void *a, const void *b)
2340 const HeapClassRevRef *A = a;
2341 const HeapClassRevRef *B = b;
2342 if (B->count == A->count)
2343 return 0;
2344 if (B->count < A->count)
2345 return -1;
2346 return 1;
2349 static void
2350 dump_rev_claases (HeapClassRevRef *revs, int count)
2352 int j;
2353 if (!show_traces)
2354 return;
2355 if (!count)
2356 return;
2357 for (j = 0; j < count; ++j) {
2358 HeapClassDesc *cd = revs [j].klass;
2359 fprintf (outfile, "\t\t%llu references from: %s\n", revs [j].count, cd->klass->name);
2363 static void
2364 heap_shot_summary (HeapShot *hs, int hs_num, HeapShot *last_hs)
2366 uint64_t size = 0;
2367 uint64_t count = 0;
2368 int ccount = 0;
2369 int i;
2370 HeapClassDesc *cd;
2371 HeapClassDesc **sorted;
2372 sorted = malloc (sizeof (void*) * hs->class_count);
2373 for (i = 0; i < hs->hash_size; ++i) {
2374 cd = hs->class_hash [i];
2375 if (!cd)
2376 continue;
2377 count += cd->count;
2378 size += cd->total_size;
2379 sorted [ccount++] = cd;
2381 hs->sorted = sorted;
2382 qsort (sorted, ccount, sizeof (void*), compare_heap_class);
2383 fprintf (outfile, "\n\tHeap shot %d at %.3f secs: size: %llu, object count: %llu, class count: %d, roots: %d\n",
2384 hs_num, (hs->timestamp - startup_time)/1000000000.0, size, count, ccount, hs->num_roots);
2385 if (!verbose && ccount > 30)
2386 ccount = 30;
2387 fprintf (outfile, "\t%10s %10s %8s Class name\n", "Bytes", "Count", "Average");
2388 for (i = 0; i < ccount; ++i) {
2389 HeapClassRevRef *rev_sorted;
2390 int j, k;
2391 HeapClassDesc *ocd = NULL;
2392 cd = sorted [i];
2393 if (last_hs)
2394 ocd = heap_class_lookup (last_hs, cd->klass);
2395 fprintf (outfile, "\t%10llu %10llu %8llu %s", cd->total_size, cd->count, cd->total_size / cd->count, cd->klass->name);
2396 if (ocd) {
2397 int64_t bdiff = cd->total_size - ocd->total_size;
2398 int64_t cdiff = cd->count - ocd->count;
2399 fprintf (outfile, " (bytes: %+lld, count: %+lld)\n", bdiff, cdiff);
2400 } else {
2401 fprintf (outfile, "\n");
2403 if (!collect_traces)
2404 continue;
2405 rev_sorted = malloc (cd->rev_count * sizeof (HeapClassRevRef));
2406 k = 0;
2407 for (j = 0; j < cd->rev_hash_size; ++j) {
2408 if (cd->rev_hash [j].klass)
2409 rev_sorted [k++] = cd->rev_hash [j];
2411 assert (cd->rev_count == k);
2412 qsort (rev_sorted, cd->rev_count, sizeof (HeapClassRevRef), compare_rev_class);
2413 if (cd->root_references)
2414 fprintf (outfile, "\t\t%d root references (%d pinning)\n", cd->root_references, cd->pinned_references);
2415 dump_rev_claases (rev_sorted, cd->rev_count);
2416 free (rev_sorted);
2418 free (sorted);
2421 static int
2422 compare_heap_shots (const void *a, const void *b)
2424 HeapShot *const*A = a;
2425 HeapShot *const*B = b;
2426 if ((*B)->timestamp == (*A)->timestamp)
2427 return 0;
2428 if ((*B)->timestamp > (*A)->timestamp)
2429 return -1;
2430 return 1;
2433 static void
2434 dump_heap_shots (void)
2436 HeapShot **hs_sorted;
2437 HeapShot *hs;
2438 HeapShot *last_hs = NULL;
2439 int i;
2440 if (!heap_shots)
2441 return;
2442 hs_sorted = malloc (num_heap_shots * sizeof (void*));
2443 fprintf (outfile, "\nHeap shot summary\n");
2444 i = 0;
2445 for (hs = heap_shots; hs; hs = hs->next)
2446 hs_sorted [i++] = hs;
2447 qsort (hs_sorted, num_heap_shots, sizeof (void*), compare_heap_shots);
2448 for (i = 0; i < num_heap_shots; ++i) {
2449 hs = hs_sorted [i];
2450 heap_shot_summary (hs, i, last_hs);
2451 last_hs = hs;
2455 static void
2456 flush_context (ProfContext *ctx)
2458 ThreadContext *thread;
2459 /* FIXME: sometimes there are leftovers: indagate */
2460 for (thread = ctx->threads; thread; thread = thread->next) {
2461 while (thread->stack_id) {
2462 if (debug)
2463 fprintf (outfile, "thread %p has %d items on stack\n", (void*)thread->thread_id, thread->stack_id);
2464 pop_method (thread, thread->stack [thread->stack_id - 1], thread->last_time);
2469 static const char *reports = "header,jit,gc,sample,alloc,call,metadata,exception,monitor,thread,heapshot";
2471 static const char*
2472 match_option (const char *p, const char *opt)
2474 int len = strlen (opt);
2475 if (strncmp (p, opt, len) == 0) {
2476 if (p [len] == ',')
2477 len++;
2478 return p + len;
2480 return p;
2483 static int
2484 print_reports (ProfContext *ctx, const char *reps, int parse_only)
2486 const char *opt;
2487 const char *p;
2488 for (p = reps; *p; p = opt) {
2489 if ((opt = match_option (p, "header")) != p) {
2490 if (!parse_only)
2491 dump_header (ctx);
2492 continue;
2494 if ((opt = match_option (p, "thread")) != p) {
2495 if (!parse_only)
2496 dump_threads (ctx);
2497 continue;
2499 if ((opt = match_option (p, "gc")) != p) {
2500 if (!parse_only)
2501 dump_gcs ();
2502 continue;
2504 if ((opt = match_option (p, "jit")) != p) {
2505 if (!parse_only)
2506 dump_jit ();
2507 continue;
2509 if ((opt = match_option (p, "alloc")) != p) {
2510 if (!parse_only)
2511 dump_allocations ();
2512 continue;
2514 if ((opt = match_option (p, "call")) != p) {
2515 if (!parse_only)
2516 dump_methods ();
2517 continue;
2519 if ((opt = match_option (p, "metadata")) != p) {
2520 if (!parse_only)
2521 dump_metadata ();
2522 continue;
2524 if ((opt = match_option (p, "exception")) != p) {
2525 if (!parse_only)
2526 dump_exceptions ();
2527 continue;
2529 if ((opt = match_option (p, "monitor")) != p) {
2530 if (!parse_only)
2531 dump_monitors ();
2532 continue;
2534 if ((opt = match_option (p, "heapshot")) != p) {
2535 if (!parse_only)
2536 dump_heap_shots ();
2537 continue;
2539 if ((opt = match_option (p, "sample")) != p) {
2540 if (!parse_only)
2541 dump_samples ();
2542 continue;
2544 return 0;
2546 return 1;
2549 static int
2550 add_find_spec (const char *p)
2552 if (p [0] == 'S' && p [1] == ':') {
2553 char *vale;
2554 find_size = strtoul (p + 2, &vale, 10);
2555 return 1;
2556 } else if (p [0] == 'T' && p [1] == ':') {
2557 find_name = p + 2;
2558 return 1;
2560 return 0;
2563 static void
2564 usage (void)
2566 printf ("Mono log profiler report version %d.%d\n", LOG_VERSION_MAJOR, LOG_VERSION_MINOR);
2567 printf ("Usage: mprof-report [OPTIONS] FILENAME\n");
2568 printf ("FILENAME can be '-' to read from standard input.\n");
2569 printf ("Options:\n");
2570 printf ("\t--help display this help\n");
2571 printf ("\t--out=FILE write to FILE instead of stdout\n");
2572 printf ("\t--traces collect and show backtraces\n");
2573 printf ("\t--maxframes=NUM limit backtraces to NUM entries\n");
2574 printf ("\t--reports=R1[,R2...] print the specified reports. Defaults are:\n");
2575 printf ("\t %s\n", reports);
2576 printf ("\t--method-sort=MODE sort methods according to MODE: total, self, calls\n");
2577 printf ("\t--alloc-sort=MODE sort allocations according to MODE: bytes, count\n");
2578 printf ("\t--track=OB1[,OB2...] track what happens to objects OBJ1, O2 etc.\n");
2579 printf ("\t--find=FINDSPEC find and track objects matching FINFSPEC, where FINDSPEC is:\n");
2580 printf ("\t S:minimum_size or T:partial_name\n");
2581 printf ("\t--thread=THREADID consider just the data for thread THREADID\n");
2582 printf ("\t--time=FROM-TO consider data FROM seconds from startup up to TO seconds\n");
2583 printf ("\t--verbose increase verbosity level\n");
2584 printf ("\t--debug display decoding debug info for mprof-report devs\n");
2588 main (int argc, char *argv[])
2590 ProfContext *ctx;
2591 int i;
2592 outfile = stdout;
2593 for (i = 1; i < argc; ++i) {
2594 if (strcmp ("--debug", argv [i]) == 0) {
2595 debug++;
2596 } else if (strcmp ("--help", argv [i]) == 0) {
2597 usage ();
2598 return 0;
2599 } else if (strncmp ("--alloc-sort=", argv [i], 13) == 0) {
2600 const char *val = argv [i] + 13;
2601 if (strcmp (val, "bytes") == 0) {
2602 alloc_sort_mode = ALLOC_SORT_BYTES;
2603 } else if (strcmp (val, "count") == 0) {
2604 alloc_sort_mode = ALLOC_SORT_COUNT;
2605 } else {
2606 usage ();
2607 return 1;
2609 } else if (strncmp ("--method-sort=", argv [i], 14) == 0) {
2610 const char *val = argv [i] + 14;
2611 if (strcmp (val, "total") == 0) {
2612 method_sort_mode = METHOD_SORT_TOTAL;
2613 } else if (strcmp (val, "self") == 0) {
2614 method_sort_mode = METHOD_SORT_SELF;
2615 } else if (strcmp (val, "calls") == 0) {
2616 method_sort_mode = METHOD_SORT_CALLS;
2617 } else {
2618 usage ();
2619 return 1;
2621 } else if (strncmp ("--reports=", argv [i], 10) == 0) {
2622 const char *val = argv [i] + 10;
2623 if (!print_reports (NULL, val, 1)) {
2624 usage ();
2625 return 1;
2627 reports = val;
2628 } else if (strncmp ("--out=", argv [i], 6) == 0) {
2629 const char *val = argv [i] + 6;
2630 outfile = fopen (val, "w");
2631 if (!outfile) {
2632 printf ("Cannot open output file: %s\n", val);
2633 return 1;
2635 } else if (strncmp ("--maxframes=", argv [i], 12) == 0) {
2636 const char *val = argv [i] + 12;
2637 char *vale;
2638 trace_max = strtoul (val, &vale, 10);
2639 } else if (strncmp ("--find=", argv [i], 7) == 0) {
2640 const char *val = argv [i] + 7;
2641 if (!add_find_spec (val)) {
2642 usage ();
2643 return 1;
2645 } else if (strncmp ("--track=", argv [i], 8) == 0) {
2646 const char *val = argv [i] + 8;
2647 char *vale;
2648 while (*val) {
2649 uintptr_t tracked_obj;
2650 if (*val == ',') {
2651 val++;
2652 continue;
2654 tracked_obj = strtoul (val, &vale, 0);
2655 found_object (tracked_obj);
2656 val = vale;
2658 } else if (strncmp ("--thread=", argv [i], 9) == 0) {
2659 const char *val = argv [i] + 9;
2660 char *vale;
2661 thread_filter = strtoul (val, &vale, 0);
2662 } else if (strncmp ("--time=", argv [i], 7) == 0) {
2663 char *val = pstrdup (argv [i] + 7);
2664 double from_secs, to_secs;
2665 char *top = strchr (val, '-');
2666 if (!top) {
2667 usage ();
2668 return 1;
2670 *top++ = 0;
2671 from_secs = atof (val);
2672 to_secs = atof (top);
2673 free (val);
2674 if (from_secs > to_secs) {
2675 usage ();
2676 return 1;
2678 time_from = from_secs * 1000000000;
2679 time_to = to_secs * 1000000000;
2680 } else if (strcmp ("--verbose", argv [i]) == 0) {
2681 verbose++;
2682 } else if (strcmp ("--traces", argv [i]) == 0) {
2683 show_traces = 1;
2684 collect_traces = 1;
2685 } else {
2686 break;
2689 if (i >= argc) {
2690 usage ();
2691 return 2;
2693 ctx = load_file (argv [i]);
2694 if (!ctx) {
2695 printf ("Not a log profiler data file (or unsupported version).\n");
2696 return 1;
2698 while (decode_buffer (ctx));
2699 flush_context (ctx);
2700 if (num_tracked_objects)
2701 return 0;
2702 print_reports (ctx, reports, 0);
2703 return 0;