2 * decode.c: mprof-report program source: decode and analyze the log profiler data
5 * Paolo Molaro (lupus@ximian.com)
7 * Copyright 2010 Novell, Inc (http://www.novell.com)
15 #if !defined(__APPLE__) && !defined(__FreeBSD__)
20 #if defined (HAVE_SYS_ZLIB)
24 #include <mono/metadata/profiler.h>
25 #include <mono/metadata/object.h>
26 #include <mono/metadata/debug-helpers.h>
27 #include <mono/utils/mono-counters.h>
29 #define HASH_SIZE 9371
30 #define SMALL_HASH_SIZE 31
32 #if defined(__native_client__) || defined(__native_client_codegen__)
33 volatile int __nacl_thread_suspension_needed = 0;
34 void __nacl_suspend_thread_if_needed() {}
38 static int collect_traces = 0;
39 static int show_traces = 0;
40 static int trace_max = 6;
41 static int verbose = 0;
42 static uintptr_t *tracked_objects = 0;
43 static int num_tracked_objects = 0;
44 static uintptr_t thread_filter = 0;
45 static uint64_t find_size = 0;
46 static const char* find_name = NULL;
47 static uint64_t time_from = 0;
48 static uint64_t time_to = 0xffffffffffffffffULL;
49 static int use_time_filter = 0;
50 static uint64_t startup_time = 0;
51 static FILE* outfile = NULL;
54 read_int16 (unsigned char *p)
62 read_int32 (unsigned char *p)
66 value |= (*p++) << 16;
67 value |= (uint32_t)(*p++) << 24;
72 read_int64 (unsigned char *p)
74 uint64_t value = *p++;
76 value |= (*p++) << 16;
77 value |= (uint64_t)(*p++) << 24;
78 value |= (uint64_t)(*p++) << 32;
79 value |= (uint64_t)(*p++) << 40;
80 value |= (uint64_t)(*p++) << 48;
81 value |= (uint64_t)(*p++) << 54;
86 pstrdup (const char *s)
88 int len = strlen (s) + 1;
89 char *p = malloc (len);
94 typedef struct _CounterValue CounterValue;
95 struct _CounterValue {
97 unsigned char *buffer;
101 typedef struct _Counter Counter;
109 CounterValue *values;
110 CounterValue *values_last;
113 typedef struct _CounterList CounterList;
114 struct _CounterList {
119 typedef struct _CounterSection CounterSection;
120 struct _CounterSection {
122 CounterList *counters;
123 CounterList *counters_last;
124 CounterSection *next;
127 typedef struct _CounterTimestamp CounterTimestamp;
128 struct _CounterTimestamp {
130 CounterSection *sections;
131 CounterSection *sections_last;
132 CounterTimestamp *next;
135 static CounterList *counters = NULL;
136 static CounterSection *counters_sections = NULL;
137 static CounterTimestamp *counters_timestamps = NULL;
141 COUNTERS_SORT_CATEGORY
144 static int counters_sort_mode = COUNTERS_SORT_TIME;
147 add_counter_to_section (Counter *counter)
149 CounterSection *csection, *s;
152 clist = calloc (1, sizeof (CounterList));
153 clist->counter = counter;
155 for (csection = counters_sections; csection; csection = csection->next) {
156 if (strcmp (csection->value, counter->section) == 0) {
157 /* If section exist */
158 if (!csection->counters)
159 csection->counters = clist;
161 csection->counters_last->next = clist;
162 csection->counters_last = clist;
167 /* If section does not exist */
168 csection = calloc (1, sizeof (CounterSection));
169 csection->value = counter->section;
170 csection->counters = clist;
171 csection->counters_last = clist;
173 if (!counters_sections) {
174 counters_sections = csection;
176 s = counters_sections;
184 add_counter (const char *section, const char *name, int type, int unit, int variance, int index)
186 CounterList *list, *l;
189 for (list = counters; list; list = list->next)
190 if (list->counter->index == index)
193 counter = calloc (1, sizeof (Counter));
194 counter->section = section;
195 counter->name = name;
196 counter->type = type;
197 counter->unit = unit;
198 counter->variance = variance;
199 counter->index = index;
201 list = calloc (1, sizeof (CounterList));
202 list->counter = counter;
213 if (counters_sort_mode == COUNTERS_SORT_CATEGORY || !verbose)
214 add_counter_to_section (counter);
218 add_counter_to_timestamp (uint64_t timestamp, Counter *counter)
220 CounterTimestamp *ctimestamp, *t;
221 CounterSection *csection;
224 clist = calloc (1, sizeof (CounterList));
225 clist->counter = counter;
227 for (ctimestamp = counters_timestamps; ctimestamp; ctimestamp = ctimestamp->next) {
228 if (ctimestamp->value == timestamp) {
229 for (csection = ctimestamp->sections; csection; csection = csection->next) {
230 if (strcmp (csection->value, counter->section) == 0) {
231 /* if timestamp exist and section exist */
232 if (!csection->counters)
233 csection->counters = clist;
235 csection->counters_last->next = clist;
236 csection->counters_last = clist;
241 /* if timestamp exist and section does not exist */
242 csection = calloc (1, sizeof (CounterSection));
243 csection->value = counter->section;
244 csection->counters = clist;
245 csection->counters_last = clist;
247 if (!ctimestamp->sections)
248 ctimestamp->sections = csection;
250 ctimestamp->sections_last->next = csection;
251 ctimestamp->sections_last = csection;
256 /* If timestamp do not exist and section does not exist */
257 csection = calloc (1, sizeof (CounterSection));
258 csection->value = counter->section;
259 csection->counters = clist;
260 csection->counters_last = clist;
262 ctimestamp = calloc (1, sizeof (CounterTimestamp));
263 ctimestamp->value = timestamp;
264 ctimestamp->sections = csection;
265 ctimestamp->sections_last = csection;
267 if (!counters_timestamps) {
268 counters_timestamps = ctimestamp;
270 t = counters_timestamps;
273 t->next = ctimestamp;
278 add_counter_value (int index, CounterValue *value)
282 for (list = counters; list; list = list->next) {
283 if (list->counter->index == index) {
284 if (!list->counter->values)
285 list->counter->values = value;
287 list->counter->values_last->next = value;
288 list->counter->values_last = value;
290 if (counters_sort_mode == COUNTERS_SORT_TIME)
291 add_counter_to_timestamp (value->timestamp, list->counter);
299 section_name (int section)
302 case MONO_COUNTER_JIT: return "Mono JIT";
303 case MONO_COUNTER_GC: return "Mono GC";
304 case MONO_COUNTER_METADATA: return "Mono Metadata";
305 case MONO_COUNTER_GENERICS: return "Mono Generics";
306 case MONO_COUNTER_SECURITY: return "Mono Security";
307 case MONO_COUNTER_RUNTIME: return "Mono Runtime";
308 case MONO_COUNTER_SYSTEM: return "Mono System";
309 default: return "<unknown>";
317 case MONO_COUNTER_INT: return "Int";
318 case MONO_COUNTER_UINT: return "UInt";
319 case MONO_COUNTER_WORD: return "Word";
320 case MONO_COUNTER_LONG: return "Long";
321 case MONO_COUNTER_ULONG: return "ULong";
322 case MONO_COUNTER_DOUBLE: return "Double";
323 case MONO_COUNTER_STRING: return "String";
324 case MONO_COUNTER_TIME_INTERVAL: return "Time Interval";
325 default: return "<unknown>";
333 case MONO_COUNTER_RAW: return "Raw";
334 case MONO_COUNTER_BYTES: return "Bytes";
335 case MONO_COUNTER_TIME: return "Time";
336 case MONO_COUNTER_COUNT: return "Count";
337 case MONO_COUNTER_PERCENTAGE: return "Percentage";
338 default: return "<unknown>";
343 variance_name (int variance)
346 case MONO_COUNTER_MONOTONIC: return "Monotonic";
347 case MONO_COUNTER_CONSTANT: return "Constant";
348 case MONO_COUNTER_VARIABLE: return "Variable";
349 default: return "<unknown>";
354 dump_counters_value (Counter *counter, const char *key_format, const char *key, void *value)
359 snprintf (format, sizeof (format), "%s : %%s\n", key_format);
360 fprintf (outfile, format, key, "<null>");
362 switch (counter->type) {
363 case MONO_COUNTER_INT:
364 #if SIZEOF_VOID_P == 4
365 case MONO_COUNTER_WORD:
367 snprintf (format, sizeof (format), "%s : %%d\n", key_format);
368 fprintf (outfile, format, key, *(int32_t*)value);
370 case MONO_COUNTER_UINT:
371 snprintf (format, sizeof (format), "%s : %%u\n", key_format);
372 fprintf (outfile, format, key, *(uint32_t*)value);
374 case MONO_COUNTER_LONG:
375 #if SIZEOF_VOID_P == 8
376 case MONO_COUNTER_WORD:
378 case MONO_COUNTER_TIME_INTERVAL:
379 if (counter->type == MONO_COUNTER_LONG && counter->unit == MONO_COUNTER_TIME) {
380 snprintf (format, sizeof (format), "%s : %%0.3fms\n", key_format);
381 fprintf (outfile, format, key, (double)*(int64_t*)value / 10000.0);
382 } else if (counter->type == MONO_COUNTER_TIME_INTERVAL) {
383 snprintf (format, sizeof (format), "%s : %%0.3fms\n", key_format);
384 fprintf (outfile, format, key, (double)*(int64_t*)value / 1000.0);
386 snprintf (format, sizeof (format), "%s : %%u\n", key_format);
387 fprintf (outfile, format, key, *(int64_t*)value);
390 case MONO_COUNTER_ULONG:
391 snprintf (format, sizeof (format), "%s : %%llu\n", key_format);
392 fprintf (outfile, format, key, *(uint64_t*)value);
394 case MONO_COUNTER_DOUBLE:
395 snprintf (format, sizeof (format), "%s : %%f\n", key_format);
396 fprintf (outfile, format, key, *(double*)value);
398 case MONO_COUNTER_STRING:
399 snprintf (format, sizeof (format), "%s : %%s\n", key_format);
400 fprintf (outfile, format, key, *(char*)value);
410 CounterValue *cvalue;
411 CounterTimestamp *ctimestamp;
412 CounterSection *csection;
414 char strtimestamp[17];
415 int i, section_printed;
417 fprintf (outfile, "\nCounters:\n");
420 char counters_to_print[][64] = {
422 "Methods JITted using mono JIT",
423 "Methods JITted using LLVM",
424 "Total time spent JITting (sec)",
432 "CPU Load Average - 1min",
433 "CPU Load Average - 5min",
434 "CPU Load Average - 15min",
438 for (csection = counters_sections; csection; csection = csection->next) {
441 for (clist = csection->counters; clist; clist = clist->next) {
442 counter = clist->counter;
443 if (!counter->values_last)
446 for (i = 0; counters_to_print [i][0] != 0; i++) {
447 if (strcmp (counters_to_print [i], counter->name) == 0) {
448 if (!section_printed) {
449 fprintf (outfile, "\t%s:\n", csection->value);
453 dump_counters_value (counter, "\t\t%-30s", counter->name, counter->values_last->buffer);
459 } else if (counters_sort_mode == COUNTERS_SORT_TIME) {
460 for (ctimestamp = counters_timestamps; ctimestamp; ctimestamp = ctimestamp->next) {
461 fprintf (outfile, "\t%llu:%02llu:%02llu:%02llu.%03llu:\n",
462 (unsigned long long) (ctimestamp->value / 1000 / 60 / 60 / 24 % 1000),
463 (unsigned long long) (ctimestamp->value / 1000 / 60 / 60 % 24),
464 (unsigned long long) (ctimestamp->value / 1000 / 60 % 60),
465 (unsigned long long) (ctimestamp->value / 1000 % 60),
466 (unsigned long long) (ctimestamp->value % 1000));
468 for (csection = ctimestamp->sections; csection; csection = csection->next) {
469 fprintf (outfile, "\t\t%s:\n", csection->value);
471 for (clist = csection->counters; clist; clist = clist->next) {
472 counter = clist->counter;
473 for (cvalue = counter->values; cvalue; cvalue = cvalue->next) {
474 if (cvalue->timestamp != ctimestamp->value)
477 dump_counters_value (counter, "\t\t\t%-30s", counter->name, cvalue->buffer);
482 } else if (counters_sort_mode == COUNTERS_SORT_CATEGORY) {
483 for (csection = counters_sections; csection; csection = csection->next) {
484 fprintf (outfile, "\t%s:\n", csection->value);
486 for (clist = csection->counters; clist; clist = clist->next) {
487 counter = clist->counter;
488 fprintf (outfile, "\t\t%s: [type: %s, unit: %s, variance: %s]\n",
489 counter->name, type_name (counter->type), unit_name (counter->unit), variance_name (counter->variance));
491 for (cvalue = counter->values; cvalue; cvalue = cvalue->next) {
492 snprintf (strtimestamp, sizeof (strtimestamp), "%llu:%02llu:%02llu:%02llu.%03llu",
493 (unsigned long long) (cvalue->timestamp / 1000 / 60 / 60 / 24 % 1000),
494 (unsigned long long) (cvalue->timestamp / 1000 / 60 / 60 % 24),
495 (unsigned long long) (cvalue->timestamp / 1000 / 60 % 60),
496 (unsigned long long) (cvalue->timestamp / 1000 % 60),
497 (unsigned long long) (cvalue->timestamp % 1000));
499 dump_counters_value (counter, "\t\t\t%s", strtimestamp, cvalue->buffer);
506 static int num_images;
507 typedef struct _ImageDesc ImageDesc;
514 static ImageDesc* image_hash [SMALL_HASH_SIZE] = {0};
517 add_image (intptr_t image, char *name)
519 int slot = ((image >> 2) & 0xffff) % SMALL_HASH_SIZE;
520 ImageDesc *cd = malloc (sizeof (ImageDesc));
522 cd->filename = pstrdup (name);
523 cd->next = image_hash [slot];
524 image_hash [slot] = cd;
528 typedef struct _BackTrace BackTrace;
540 typedef struct _ClassDesc ClassDesc;
550 static ClassDesc* class_hash [HASH_SIZE] = {0};
551 static int num_classes = 0;
554 add_class (intptr_t klass, const char *name)
556 int slot = ((klass >> 2) & 0xffff) % HASH_SIZE;
558 cd = class_hash [slot];
559 while (cd && cd->klass != klass)
561 /* we resolved an unknown class (unless we had the code unloaded) */
563 /*printf ("resolved unknown: %s\n", name);*/
565 cd->name = pstrdup (name);
568 cd = calloc (sizeof (ClassDesc), 1);
570 cd->name = pstrdup (name);
571 cd->next = class_hash [slot];
574 cd->traces.count = 0;
576 cd->traces.traces = NULL;
577 class_hash [slot] = cd;
583 lookup_class (intptr_t klass)
585 int slot = ((klass >> 2) & 0xffff) % HASH_SIZE;
586 ClassDesc *cd = class_hash [slot];
587 while (cd && cd->klass != klass)
591 snprintf (buf, sizeof (buf), "unresolved class %p", (void*)klass);
592 return add_class (klass, buf);
597 typedef struct _MethodDesc MethodDesc;
606 int ignore_jit; /* when this is set, we collect the metadata but don't count this method fot jit time and code size, when filtering events */
609 uint64_t callee_time;
614 static MethodDesc* method_hash [HASH_SIZE] = {0};
615 static int num_methods = 0;
618 add_method (intptr_t method, const char *name, intptr_t code, int len)
620 int slot = ((method >> 2) & 0xffff) % HASH_SIZE;
622 cd = method_hash [slot];
623 while (cd && cd->method != method)
625 /* we resolved an unknown method (unless we had the code unloaded) */
629 /*printf ("resolved unknown: %s\n", name);*/
631 cd->name = pstrdup (name);
634 cd = calloc (sizeof (MethodDesc), 1);
636 cd->name = pstrdup (name);
641 cd->traces.count = 0;
643 cd->traces.traces = NULL;
644 cd->next = method_hash [slot];
645 method_hash [slot] = cd;
651 lookup_method (intptr_t method)
653 int slot = ((method >> 2) & 0xffff) % HASH_SIZE;
654 MethodDesc *cd = method_hash [slot];
655 while (cd && cd->method != method)
659 snprintf (buf, sizeof (buf), "unknown method %p", (void*)method);
660 return add_method (method, buf, 0, 0);
665 static int num_stat_samples = 0;
666 static int size_stat_samples = 0;
667 uintptr_t *stat_samples = NULL;
668 int *stat_sample_desc = NULL;
671 add_stat_sample (int type, uintptr_t ip) {
672 if (num_stat_samples == size_stat_samples) {
673 size_stat_samples *= 2;
674 if (!size_stat_samples)
675 size_stat_samples = 32;
676 stat_samples = realloc (stat_samples, size_stat_samples * sizeof (uintptr_t));
677 stat_sample_desc = realloc (stat_sample_desc, size_stat_samples * sizeof (int));
679 stat_samples [num_stat_samples] = ip;
680 stat_sample_desc [num_stat_samples++] = type;
684 lookup_method_by_ip (uintptr_t ip)
689 for (i = 0; i < HASH_SIZE; ++i) {
692 //printf ("checking %p against %p-%p\n", (void*)ip, (void*)(m->code), (void*)(m->code + m->len));
693 if (ip >= (uintptr_t)m->code && ip < (uintptr_t)m->code + m->len) {
703 compare_method_samples (const void *a, const void *b)
705 MethodDesc *const*A = a;
706 MethodDesc *const*B = b;
707 if ((*A)->sample_hits == (*B)->sample_hits)
709 if ((*B)->sample_hits < (*A)->sample_hits)
714 typedef struct _UnmanagedSymbol UnmanagedSymbol;
715 struct _UnmanagedSymbol {
716 UnmanagedSymbol *parent;
721 uintptr_t sample_hits;
724 static UnmanagedSymbol **usymbols = NULL;
725 static int usymbols_size = 0;
726 static int usymbols_num = 0;
729 compare_usymbol_addr (const void *a, const void *b)
731 UnmanagedSymbol *const*A = a;
732 UnmanagedSymbol *const*B = b;
733 if ((*B)->addr == (*A)->addr)
735 if ((*B)->addr > (*A)->addr)
741 compare_usymbol_samples (const void *a, const void *b)
743 UnmanagedSymbol *const*A = a;
744 UnmanagedSymbol *const*B = b;
745 if ((*B)->sample_hits == (*A)->sample_hits)
747 if ((*B)->sample_hits < (*A)->sample_hits)
753 add_unmanaged_symbol (uintptr_t addr, char *name, uintptr_t size)
755 UnmanagedSymbol *sym;
756 if (usymbols_num == usymbols_size) {
757 int new_size = usymbols_size * 2;
760 usymbols = realloc (usymbols, sizeof (void*) * new_size);
761 usymbols_size = new_size;
763 sym = calloc (sizeof (UnmanagedSymbol), 1);
767 usymbols [usymbols_num++] = sym;
770 /* only valid after the symbols are sorted */
771 static UnmanagedSymbol*
772 lookup_unmanaged_symbol (uintptr_t addr)
774 int r = usymbols_num - 1;
776 UnmanagedSymbol *sym;
781 if (addr == sym->addr)
783 if (addr < sym->addr) {
785 } else if (addr > sym->addr) {
790 if (last_best >= 0 && (addr - usymbols [last_best]->addr) < 4096)
791 return usymbols [last_best];
795 /* we use the same structure for binaries */
796 static UnmanagedSymbol **ubinaries = NULL;
797 static int ubinaries_size = 0;
798 static int ubinaries_num = 0;
801 add_unmanaged_binary (uintptr_t addr, char *name, uintptr_t size)
803 UnmanagedSymbol *sym;
804 if (ubinaries_num == ubinaries_size) {
805 int new_size = ubinaries_size * 2;
808 ubinaries = realloc (ubinaries, sizeof (void*) * new_size);
809 ubinaries_size = new_size;
811 sym = calloc (sizeof (UnmanagedSymbol), 1);
816 ubinaries [ubinaries_num++] = sym;
819 static UnmanagedSymbol*
820 lookup_unmanaged_binary (uintptr_t addr)
823 for (i = 0; i < ubinaries_num; ++i) {
824 UnmanagedSymbol *ubin = ubinaries [i];
825 if (addr >= ubin->addr && addr < ubin->addr + ubin->size) {
833 sample_type_name (int type)
836 case SAMPLE_CYCLES: return "cycles";
837 case SAMPLE_INSTRUCTIONS: return "instructions retired";
838 case SAMPLE_CACHE_MISSES: return "cache misses";
839 case SAMPLE_CACHE_REFS: return "cache references";
840 case SAMPLE_BRANCHES: return "executed branches";
841 case SAMPLE_BRANCH_MISSES: return "unpredicted branches";
847 set_usym_parent (UnmanagedSymbol** cachedus, int count)
850 for (i = 0; i < count; ++i) {
851 UnmanagedSymbol *ubin = lookup_unmanaged_binary (cachedus [i]->addr);
852 if (ubin == cachedus [i])
854 cachedus [i]->parent = ubin;
859 print_usym (UnmanagedSymbol* um)
862 fprintf (outfile, "\t%6zd %6.2f %-36s in %s\n", um->sample_hits, um->sample_hits*100.0/num_stat_samples, um->name, um->parent->name);
864 fprintf (outfile, "\t%6zd %6.2f %s\n", um->sample_hits, um->sample_hits*100.0/num_stat_samples, um->name);
868 sym_percent (uintptr_t sample_hits)
873 pc = sample_hits*100.0/num_stat_samples;
881 int count = 0, msize = 0;
882 int unmanaged_hits = 0;
883 int unresolved_hits = 0;
884 MethodDesc** cachedm = NULL;
885 int ucount = 0, usize = 0;
886 UnmanagedSymbol** cachedus = NULL;
887 if (!num_stat_samples)
889 qsort (usymbols, usymbols_num, sizeof (UnmanagedSymbol*), compare_usymbol_addr);
890 for (i = 0; i < num_stat_samples; ++i) {
891 MethodDesc *m = lookup_method_by_ip (stat_samples [i]);
893 if (!m->sample_hits) {
894 if (count == msize) {
898 cachedm = realloc (cachedm, sizeof (void*) * msize);
900 cachedm [count++] = m;
904 UnmanagedSymbol *usym = lookup_unmanaged_symbol (stat_samples [i]);
907 //printf ("unmanaged hit at %p\n", (void*)stat_samples [i]);
908 usym = lookup_unmanaged_binary (stat_samples [i]);
911 if (!usym->sample_hits) {
912 if (ucount == usize) {
916 cachedus = realloc (cachedus, sizeof (void*) * usize);
918 cachedus [ucount++] = usym;
925 qsort (cachedm, count, sizeof (MethodDesc*), compare_method_samples);
926 qsort (cachedus, ucount, sizeof (UnmanagedSymbol*), compare_usymbol_samples);
927 set_usym_parent (cachedus, ucount);
928 fprintf (outfile, "\nStatistical samples summary\n");
929 fprintf (outfile, "\tSample type: %s\n", sample_type_name (stat_sample_desc [0]));
930 fprintf (outfile, "\tUnmanaged hits: %6d (%4.1f%%)\n", unmanaged_hits, (100.0*unmanaged_hits)/num_stat_samples);
931 fprintf (outfile, "\tManaged hits: %6d (%4.1f%%)\n", num_stat_samples - unmanaged_hits, (100.0*(num_stat_samples-unmanaged_hits))/num_stat_samples);
932 fprintf (outfile, "\tUnresolved hits: %6d (%4.1f%%)\n", unresolved_hits, (100.0*unresolved_hits)/num_stat_samples);
933 fprintf (outfile, "\t%6s %6s %s\n", "Hits", "%", "Method name");
936 while (i < count || u < ucount) {
938 MethodDesc *m = cachedm [i];
940 UnmanagedSymbol *um = cachedus [u];
941 if (um->sample_hits > m->sample_hits) {
942 if (!sym_percent (um->sample_hits))
949 if (!sym_percent (m->sample_hits))
951 fprintf (outfile, "\t%6d %6.2f %s\n", m->sample_hits, m->sample_hits*100.0/num_stat_samples, m->name);
956 UnmanagedSymbol *um = cachedus [u];
957 if (!sym_percent (um->sample_hits))
966 typedef struct _HeapClassDesc HeapClassDesc;
968 HeapClassDesc *klass;
972 struct _HeapClassDesc {
976 HeapClassRevRef *rev_hash;
979 uintptr_t pinned_references;
980 uintptr_t root_references;
984 add_rev_class_hashed (HeapClassRevRef *rev_hash, uintptr_t size, HeapClassDesc *hklass, uint64_t value)
988 start_pos = (hklass->klass->klass >> 2) % size;
989 assert (start_pos < size);
992 if (rev_hash [i].klass == hklass) {
993 rev_hash [i].count += value;
995 } else if (!rev_hash [i].klass) {
996 rev_hash [i].klass = hklass;
997 rev_hash [i].count += value;
999 for (i = 0; i < size; ++i)
1000 if (rev_hash [i].klass && rev_hash [i].klass->klass == hklass->klass)
1002 assert (start_pos == 1);
1008 } while (i != start_pos);
1009 /* should not happen */
1010 printf ("failed revref store\n");
1015 add_heap_class_rev (HeapClassDesc *from, HeapClassDesc *to)
1018 if (to->rev_count * 2 >= to->rev_hash_size) {
1020 uintptr_t old_size = to->rev_hash_size;
1021 to->rev_hash_size *= 2;
1022 if (to->rev_hash_size == 0)
1023 to->rev_hash_size = 4;
1024 n = calloc (sizeof (HeapClassRevRef) * to->rev_hash_size, 1);
1025 for (i = 0; i < old_size; ++i) {
1026 if (to->rev_hash [i].klass)
1027 add_rev_class_hashed (n, to->rev_hash_size, to->rev_hash [i].klass, to->rev_hash [i].count);
1030 free (to->rev_hash);
1033 to->rev_count += add_rev_class_hashed (to->rev_hash, to->rev_hash_size, from, 1);
1038 HeapClassDesc *hklass;
1043 typedef struct _HeapShot HeapShot;
1049 HeapClassDesc **class_hash;
1050 HeapClassDesc **sorted;
1051 HeapObjectDesc **objects_hash;
1052 uintptr_t objects_count;
1053 uintptr_t objects_hash_size;
1054 uintptr_t num_roots;
1056 uintptr_t *roots_extra;
1060 static HeapShot *heap_shots = NULL;
1061 static int num_heap_shots = 0;
1064 new_heap_shot (uint64_t timestamp)
1066 HeapShot *hs = calloc (sizeof (HeapShot), 1);
1068 hs->class_hash = calloc (sizeof (void*), hs->hash_size);
1069 hs->timestamp = timestamp;
1071 hs->next = heap_shots;
1076 static HeapClassDesc*
1077 heap_class_lookup (HeapShot *hs, ClassDesc *klass)
1080 unsigned int start_pos;
1081 start_pos = ((uintptr_t)klass->klass >> 2) % hs->hash_size;
1084 HeapClassDesc* cd = hs->class_hash [i];
1087 if (cd->klass == klass)
1090 if (++i == hs->hash_size)
1092 } while (i != start_pos);
1097 add_heap_hashed (HeapClassDesc **hash, HeapClassDesc **retv, uintptr_t hsize, ClassDesc *klass, uint64_t size, uint64_t count)
1100 uintptr_t start_pos;
1101 start_pos = ((uintptr_t)klass->klass >> 2) % hsize;
1104 if (hash [i] && hash [i]->klass == klass) {
1105 hash [i]->total_size += size;
1106 hash [i]->count += count;
1109 } else if (!hash [i]) {
1114 hash [i] = calloc (sizeof (HeapClassDesc), 1);
1115 hash [i]->klass = klass;
1116 hash [i]->total_size += size;
1117 hash [i]->count += count;
1124 } while (i != start_pos);
1125 /* should not happen */
1126 printf ("failed heap class store\n");
1130 static HeapClassDesc*
1131 add_heap_shot_class (HeapShot *hs, ClassDesc *klass, uint64_t size)
1135 if (hs->class_count * 2 >= hs->hash_size) {
1137 int old_size = hs->hash_size;
1139 if (hs->hash_size == 0)
1141 n = calloc (sizeof (void*) * hs->hash_size, 1);
1142 for (i = 0; i < old_size; ++i) {
1143 res = hs->class_hash [i];
1144 if (hs->class_hash [i])
1145 add_heap_hashed (n, &res, hs->hash_size, hs->class_hash [i]->klass, hs->class_hash [i]->total_size, hs->class_hash [i]->count);
1148 free (hs->class_hash);
1152 hs->class_count += add_heap_hashed (hs->class_hash, &res, hs->hash_size, klass, size, 1);
1153 //if (res->count == 1)
1154 // printf ("added heap class: %s\n", res->klass->name);
1158 static HeapObjectDesc*
1159 alloc_heap_obj (uintptr_t objaddr, HeapClassDesc *hklass, uintptr_t num_refs)
1161 HeapObjectDesc* ho = calloc (sizeof (HeapObjectDesc) + num_refs * sizeof (uintptr_t), 1);
1162 ho->objaddr = objaddr;
1163 ho->hklass = hklass;
1164 ho->num_refs = num_refs;
1169 heap_shot_find_obj_slot (HeapShot *hs, uintptr_t objaddr)
1172 uintptr_t start_pos;
1173 HeapObjectDesc **hash = hs->objects_hash;
1174 start_pos = ((uintptr_t)objaddr >> 3) % hs->objects_hash_size;
1177 if (hash [i] && hash [i]->objaddr == objaddr) {
1179 } else if (!hash [i]) {
1183 if (++i == hs->objects_hash_size)
1185 } while (i != start_pos);
1186 /* should not happen */
1187 //printf ("failed heap obj slot\n");
1191 static HeapObjectDesc*
1192 heap_shot_obj_add_refs (HeapShot *hs, uintptr_t objaddr, uintptr_t num, uintptr_t *ref_offset)
1194 HeapObjectDesc **hash = hs->objects_hash;
1195 uintptr_t i = heap_shot_find_obj_slot (hs, objaddr);
1197 HeapObjectDesc* ho = alloc_heap_obj (objaddr, hash [i]->hklass, hash [i]->num_refs + num);
1198 *ref_offset = hash [i]->num_refs;
1199 memcpy (ho->refs, hash [i]->refs, hash [i]->num_refs * sizeof (uintptr_t));
1204 /* should not happen */
1205 printf ("failed heap obj update\n");
1211 add_heap_hashed_obj (HeapObjectDesc **hash, uintptr_t hsize, HeapObjectDesc *obj)
1214 uintptr_t start_pos;
1215 start_pos = ((uintptr_t)obj->objaddr >> 3) % hsize;
1218 if (hash [i] && hash [i]->objaddr == obj->objaddr) {
1219 printf ("duplicate object!\n");
1221 } else if (!hash [i]) {
1228 } while (i != start_pos);
1229 /* should not happen */
1230 printf ("failed heap obj store\n");
1235 add_heap_shot_obj (HeapShot *hs, HeapObjectDesc *obj)
1238 if (hs->objects_count * 2 >= hs->objects_hash_size) {
1240 uintptr_t old_size = hs->objects_hash_size;
1241 hs->objects_hash_size *= 2;
1242 if (hs->objects_hash_size == 0)
1243 hs->objects_hash_size = 4;
1244 n = calloc (sizeof (void*) * hs->objects_hash_size, 1);
1245 for (i = 0; i < old_size; ++i) {
1246 if (hs->objects_hash [i])
1247 add_heap_hashed_obj (n, hs->objects_hash_size, hs->objects_hash [i]);
1249 if (hs->objects_hash)
1250 free (hs->objects_hash);
1251 hs->objects_hash = n;
1253 hs->objects_count += add_heap_hashed_obj (hs->objects_hash, hs->objects_hash_size, obj);
1257 heap_shot_resolve_reverse_refs (HeapShot *hs)
1260 for (i = 0; i < hs->objects_hash_size; ++i) {
1262 HeapObjectDesc *ho = hs->objects_hash [i];
1265 for (r = 0; r < ho->num_refs; ++r) {
1266 uintptr_t oi = heap_shot_find_obj_slot (hs, ho->refs [r]);
1267 add_heap_class_rev (ho->hklass, hs->objects_hash [oi]->hklass);
1273 #define MARK_BLACK 2
1276 heap_shot_mark_objects (HeapShot *hs)
1279 unsigned char *marks;
1280 HeapObjectDesc *obj, *ref;
1282 uintptr_t num_marked = 0, num_unmarked;
1283 for (i = 0; i < hs->num_roots; ++i) {
1285 oi = heap_shot_find_obj_slot (hs, hs->roots [i]);
1289 obj = hs->objects_hash [oi];
1291 if (hs->roots_types [i] & MONO_PROFILE_GC_ROOT_PINNING)
1292 cd->pinned_references++;
1293 cd->root_references++;
1297 /* consistency checks: it seems not all the objects are walked in the heap in some cases */
1298 marks = calloc (hs->objects_hash_size, 1);
1301 for (i = 0; i < hs->num_roots; ++i) {
1302 oi = heap_shot_find_obj_slot (hs, hs->roots [i]);
1304 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);
1307 obj = hs->objects_hash [oi];
1309 marks [oi] = obj->num_refs? MARK_GRAY: MARK_BLACK;
1314 while (marked_some) {
1316 for (i = 0; i < hs->objects_hash_size; ++i) {
1317 if (marks [i] != MARK_GRAY)
1319 marks [i] = MARK_BLACK;
1320 obj = hs->objects_hash [i];
1321 for (r = 0; r < obj->num_refs; ++r) {
1322 oi = heap_shot_find_obj_slot (hs, obj->refs [r]);
1324 fprintf (outfile, "referenced obj %p not found in heap\n", (void*)obj->refs [r]);
1327 ref = hs->objects_hash [oi];
1329 marks [oi] = ref->num_refs? MARK_GRAY: MARK_BLACK;
1337 for (i = 0; i < hs->objects_hash_size; ++i) {
1338 if (hs->objects_hash [i] && !marks [i]) {
1340 fprintf (outfile, "object %p (%s) unmarked\n", (void*)hs->objects_hash [i], hs->objects_hash [i]->hklass->klass->name);
1343 fprintf (outfile, "Total unmarked: %zd/%zd\n", num_unmarked, hs->objects_count);
1348 heap_shot_free_objects (HeapShot *hs)
1351 for (i = 0; i < hs->objects_hash_size; ++i) {
1352 HeapObjectDesc *ho = hs->objects_hash [i];
1356 if (hs->objects_hash)
1357 free (hs->objects_hash);
1358 hs->objects_hash = NULL;
1359 hs->objects_hash_size = 0;
1360 hs->objects_count = 0;
1369 MethodDesc *methods [1];
1372 static BackTrace *backtrace_hash [HASH_SIZE];
1373 static BackTrace **backtraces = NULL;
1374 static int num_backtraces = 0;
1375 static int next_backtrace = 0;
1378 hash_backtrace (int count, MethodDesc **methods)
1382 for (i = 0; i < count; ++i) {
1383 hash = (hash << 5) - hash + methods [i]->method;
1389 compare_backtrace (BackTrace *bt, int count, MethodDesc **methods)
1392 if (bt->count != count)
1394 for (i = 0; i < count; ++i)
1395 if (methods [i] != bt->methods [i])
1401 add_backtrace (int count, MethodDesc **methods)
1403 int hash = hash_backtrace (count, methods);
1404 int slot = (hash & 0xffff) % HASH_SIZE;
1405 BackTrace *bt = backtrace_hash [slot];
1407 if (bt->hash == hash && compare_backtrace (bt, count, methods))
1411 bt = malloc (sizeof (BackTrace) + ((count - 1) * sizeof (void*)));
1412 bt->next = backtrace_hash [slot];
1413 backtrace_hash [slot] = bt;
1414 if (next_backtrace == num_backtraces) {
1415 num_backtraces *= 2;
1416 if (!num_backtraces)
1417 num_backtraces = 16;
1418 backtraces = realloc (backtraces, sizeof (void*) * num_backtraces);
1420 bt->id = next_backtrace++;
1421 backtraces [bt->id] = bt;
1424 for (slot = 0; slot < count; ++slot)
1425 bt->methods [slot] = methods [slot];
1430 typedef struct _MonitorDesc MonitorDesc;
1431 typedef struct _ThreadContext ThreadContext;
1435 #if defined (HAVE_SYS_ZLIB)
1446 uint64_t startup_time;
1447 ThreadContext *threads;
1448 ThreadContext *current;
1451 struct _ThreadContext {
1452 ThreadContext *next;
1455 /* emulated stack */
1457 uint64_t *time_stack;
1458 uint64_t *callee_time_stack;
1460 uint64_t contention_start;
1461 MonitorDesc *monitor;
1464 HeapShot *current_heap_shot;
1465 uintptr_t num_roots;
1466 uintptr_t size_roots;
1468 uintptr_t *roots_extra;
1470 uint64_t gc_start_times [3];
1474 ensure_buffer (ProfContext *ctx, int size)
1476 if (ctx->size < size) {
1477 ctx->buf = realloc (ctx->buf, size);
1483 load_data (ProfContext *ctx, int size)
1485 ensure_buffer (ctx, size);
1486 #if defined (HAVE_SYS_ZLIB)
1488 int r = gzread (ctx->gzfile, ctx->buf, size);
1490 return size == 0? 1: 0;
1495 int r = fread (ctx->buf, size, 1, ctx->file);
1497 return size == 0? 1: 0;
1502 static ThreadContext*
1503 get_thread (ProfContext *ctx, intptr_t thread_id)
1505 ThreadContext *thread;
1506 if (ctx->current && ctx->current->thread_id == thread_id)
1507 return ctx->current;
1508 thread = ctx->threads;
1510 if (thread->thread_id == thread_id) {
1513 thread = thread->next;
1515 thread = calloc (sizeof (ThreadContext), 1);
1516 thread->next = ctx->threads;
1517 ctx->threads = thread;
1518 thread->thread_id = thread_id;
1519 thread->last_time = 0;
1520 thread->stack_id = 0;
1521 thread->stack_size = 32;
1522 thread->stack = malloc (thread->stack_size * sizeof (void*));
1523 thread->time_stack = malloc (thread->stack_size * sizeof (uint64_t));
1524 thread->callee_time_stack = malloc (thread->stack_size * sizeof (uint64_t));
1528 static ThreadContext*
1529 load_thread (ProfContext *ctx, intptr_t thread_id)
1531 ThreadContext *thread = get_thread (ctx, thread_id);
1532 ctx->current = thread;
1537 ensure_thread_stack (ThreadContext *thread)
1539 if (thread->stack_id == thread->stack_size) {
1540 thread->stack_size *= 2;
1541 thread->stack = realloc (thread->stack, thread->stack_size * sizeof (void*));
1542 thread->time_stack = realloc (thread->time_stack, thread->stack_size * sizeof (uint64_t));
1543 thread->callee_time_stack = realloc (thread->callee_time_stack, thread->stack_size * sizeof (uint64_t));
1548 add_trace_hashed (CallContext *traces, int size, BackTrace *bt, uint64_t value)
1551 unsigned int start_pos;
1552 start_pos = bt->hash % size;
1555 if (traces [i].bt == bt) {
1556 traces [i].count += value;
1558 } else if (!traces [i].bt) {
1560 traces [i].count += value;
1566 } while (i != start_pos);
1567 /* should not happen */
1568 printf ("failed trace store\n");
1573 add_trace_bt (BackTrace *bt, TraceDesc *trace, uint64_t value)
1576 if (!collect_traces)
1578 if (trace->count * 2 >= trace->size) {
1580 int old_size = trace->size;
1582 if (trace->size == 0)
1584 n = calloc (sizeof (CallContext) * trace->size, 1);
1585 for (i = 0; i < old_size; ++i) {
1586 if (trace->traces [i].bt)
1587 add_trace_hashed (n, trace->size, trace->traces [i].bt, trace->traces [i].count);
1590 free (trace->traces);
1593 trace->count += add_trace_hashed (trace->traces, trace->size, bt, value);
1597 add_trace_thread (ThreadContext *thread, TraceDesc *trace, uint64_t value)
1600 int count = thread->stack_id;
1601 if (!collect_traces)
1603 if (count > trace_max)
1605 bt = add_backtrace (count, thread->stack + thread->stack_id - count);
1606 add_trace_bt (bt, trace, value);
1611 add_trace_methods (MethodDesc **methods, int count, TraceDesc *trace, uint64_t value)
1614 if (!collect_traces)
1616 if (count > trace_max)
1618 bt = add_backtrace (count, methods);
1619 add_trace_bt (bt, trace, value);
1624 thread_add_root (ThreadContext *ctx, uintptr_t obj, int root_type, uintptr_t extra_info)
1626 if (ctx->num_roots == ctx->size_roots) {
1627 int new_size = ctx->size_roots * 2;
1630 ctx->roots = realloc (ctx->roots, new_size * sizeof (uintptr_t));
1631 ctx->roots_extra = realloc (ctx->roots_extra, new_size * sizeof (uintptr_t));
1632 ctx->roots_types = realloc (ctx->roots_types, new_size * sizeof (int));
1633 ctx->size_roots = new_size;
1635 ctx->roots_types [ctx->num_roots] = root_type;
1636 ctx->roots_extra [ctx->num_roots] = extra_info;
1637 ctx->roots [ctx->num_roots++] = obj;
1641 compare_callc (const void *a, const void *b)
1643 const CallContext *A = a;
1644 const CallContext *B = b;
1645 if (B->count == A->count)
1647 if (B->count < A->count)
1653 sort_context_array (TraceDesc* traces)
1656 for (i = 0, j = 0; i < traces->size; ++i) {
1657 if (traces->traces [i].bt) {
1658 traces->traces [j].bt = traces->traces [i].bt;
1659 traces->traces [j].count = traces->traces [i].count;
1663 qsort (traces->traces, traces->count, sizeof (CallContext), compare_callc);
1667 push_method (ThreadContext *thread, MethodDesc *method, uint64_t timestamp)
1669 ensure_thread_stack (thread);
1670 thread->time_stack [thread->stack_id] = timestamp;
1671 thread->callee_time_stack [thread->stack_id] = 0;
1672 thread->stack [thread->stack_id++] = method;
1673 method->recurse_count++;
1677 pop_method (ThreadContext *thread, MethodDesc *method, uint64_t timestamp)
1679 method->recurse_count--;
1680 if (thread->stack_id > 0 && thread->stack [thread->stack_id - 1] == method) {
1684 if (timestamp < thread->time_stack [thread->stack_id])
1685 fprintf (outfile, "time went backwards for %s\n", method->name);
1686 tdiff = timestamp - thread->time_stack [thread->stack_id];
1687 if (thread->callee_time_stack [thread->stack_id] > tdiff)
1688 fprintf (outfile, "callee time bigger for %s\n", method->name);
1689 method->self_time += tdiff - thread->callee_time_stack [thread->stack_id];
1690 method->callee_time += thread->callee_time_stack [thread->stack_id];
1691 if (thread->stack_id)
1692 thread->callee_time_stack [thread->stack_id - 1] += tdiff;
1693 //fprintf (outfile, "method %s took %d\n", method->name, (int)(tdiff/1000));
1695 fprintf (outfile, "unmatched leave at stack pos: %d for method %s\n", thread->stack_id, method->name);
1700 uint64_t total_time;
1704 static GCDesc gc_info [3];
1705 static uint64_t max_heap_size;
1706 static uint64_t gc_object_moves;
1707 static int gc_resizes;
1715 static HandleInfo handle_info [4];
1718 gc_event_name (int ev)
1721 case MONO_GC_EVENT_START: return "start";
1722 case MONO_GC_EVENT_MARK_START: return "mark start";
1723 case MONO_GC_EVENT_MARK_END: return "mark end";
1724 case MONO_GC_EVENT_RECLAIM_START: return "reclaim start";
1725 case MONO_GC_EVENT_RECLAIM_END: return "reclaim end";
1726 case MONO_GC_EVENT_END: return "end";
1727 case MONO_GC_EVENT_PRE_STOP_WORLD: return "pre stop";
1728 case MONO_GC_EVENT_POST_STOP_WORLD: return "post stop";
1729 case MONO_GC_EVENT_PRE_START_WORLD: return "pre start";
1730 case MONO_GC_EVENT_POST_START_WORLD: return "post start";
1736 static uint64_t clause_summary [MONO_EXCEPTION_CLAUSE_FAULT + 1];
1737 static uint64_t throw_count = 0;
1738 static TraceDesc exc_traces;
1741 clause_name (int type)
1744 case MONO_EXCEPTION_CLAUSE_NONE: return "catch";
1745 case MONO_EXCEPTION_CLAUSE_FILTER: return "filter";
1746 case MONO_EXCEPTION_CLAUSE_FINALLY: return "finally";
1747 case MONO_EXCEPTION_CLAUSE_FAULT: return "fault";
1748 default: return "invalid";
1752 static uint64_t monitor_contention;
1753 static uint64_t monitor_failed;
1754 static uint64_t monitor_acquired;
1756 struct _MonitorDesc {
1759 uintptr_t contentions;
1761 uint64_t max_wait_time;
1765 static MonitorDesc* monitor_hash [SMALL_HASH_SIZE] = {0};
1766 static int num_monitors = 0;
1769 lookup_monitor (uintptr_t objid)
1771 int slot = ((objid >> 3) & 0xffff) % SMALL_HASH_SIZE;
1772 MonitorDesc *cd = monitor_hash [slot];
1773 while (cd && cd->objid != objid)
1776 cd = calloc (sizeof (MonitorDesc), 1);
1778 cd->next = monitor_hash [slot];
1779 monitor_hash [slot] = cd;
1786 monitor_ev_name (int ev)
1789 case MONO_PROFILER_MONITOR_CONTENTION: return "contended";
1790 case MONO_PROFILER_MONITOR_DONE: return "acquired";
1791 case MONO_PROFILER_MONITOR_FAIL: return "not taken";
1792 default: return "invalid";
1797 get_handle_name (int htype)
1800 case 0: return "weak";
1801 case 1: return "weaktrack";
1802 case 2: return "normal";
1803 case 3: return "pinned";
1804 default: return "unknown";
1809 get_root_name (int rtype)
1811 switch (rtype & MONO_PROFILE_GC_ROOT_TYPEMASK) {
1812 case MONO_PROFILE_GC_ROOT_STACK: return "stack";
1813 case MONO_PROFILE_GC_ROOT_FINALIZER: return "finalizer";
1814 case MONO_PROFILE_GC_ROOT_HANDLE: return "handle";
1815 case MONO_PROFILE_GC_ROOT_OTHER: return "other";
1816 case MONO_PROFILE_GC_ROOT_MISC: return "misc";
1817 default: return "unknown";
1822 decode_bt (MethodDesc** sframes, int *size, unsigned char *p, unsigned char **endp, intptr_t ptr_base)
1824 MethodDesc **frames;
1826 int flags = decode_uleb128 (p, &p);
1827 int count = decode_uleb128 (p, &p);
1831 frames = malloc (count * sizeof (void*));
1834 for (i = 0; i < count; ++i) {
1835 intptr_t ptrdiff = decode_sleb128 (p, &p);
1836 frames [i] = lookup_method (ptr_base + ptrdiff);
1844 tracked_creation (uintptr_t obj, ClassDesc *cd, uint64_t size, BackTrace *bt, uint64_t timestamp)
1847 for (i = 0; i < num_tracked_objects; ++i) {
1848 if (tracked_objects [i] != obj)
1850 fprintf (outfile, "Object %p created (%s, %llu bytes) at %.3f secs.\n", (void*)obj, cd->name, (unsigned long long) size, (timestamp - startup_time)/1000000000.0);
1851 if (bt && bt->count) {
1853 for (k = 0; k < bt->count; ++k)
1854 fprintf (outfile, "\t%s\n", bt->methods [k]->name);
1860 track_handle (uintptr_t obj, int htype, uint32_t handle)
1863 for (i = 0; i < num_tracked_objects; ++i) {
1864 if (tracked_objects [i] == obj)
1865 fprintf (outfile, "Object %p referenced from handle %u\n", (void*)obj, handle);
1870 track_move (uintptr_t src, uintptr_t dst)
1873 for (i = 0; i < num_tracked_objects; ++i) {
1874 if (tracked_objects [i] == src)
1875 fprintf (outfile, "Object %p moved to %p\n", (void*)src, (void*)dst);
1876 else if (tracked_objects [i] == dst)
1877 fprintf (outfile, "Object %p moved from %p\n", (void*)dst, (void*)src);
1882 track_obj_reference (uintptr_t obj, uintptr_t parent, ClassDesc *cd)
1885 for (i = 0; i < num_tracked_objects; ++i) {
1886 if (tracked_objects [i] == obj)
1887 fprintf (outfile, "Object %p referenced from %p (%s).\n", (void*)obj, (void*)parent, cd->name);
1892 found_object (uintptr_t obj)
1894 num_tracked_objects ++;
1895 tracked_objects = realloc (tracked_objects, num_tracked_objects * sizeof (tracked_objects [0]));
1896 tracked_objects [num_tracked_objects - 1] = obj;
1899 static int num_jit_helpers = 0;
1900 static int jit_helpers_code_size = 0;
1903 code_buffer_desc (int type)
1906 case MONO_PROFILER_CODE_BUFFER_METHOD:
1908 case MONO_PROFILER_CODE_BUFFER_METHOD_TRAMPOLINE:
1909 return "method trampoline";
1910 case MONO_PROFILER_CODE_BUFFER_UNBOX_TRAMPOLINE:
1911 return "unbox trampoline";
1912 case MONO_PROFILER_CODE_BUFFER_IMT_TRAMPOLINE:
1913 return "imt trampoline";
1914 case MONO_PROFILER_CODE_BUFFER_GENERICS_TRAMPOLINE:
1915 return "generics trampoline";
1916 case MONO_PROFILER_CODE_BUFFER_SPECIFIC_TRAMPOLINE:
1917 return "specific trampoline";
1918 case MONO_PROFILER_CODE_BUFFER_HELPER:
1919 return "misc helper";
1920 case MONO_PROFILER_CODE_BUFFER_MONITOR:
1921 return "monitor/lock";
1922 case MONO_PROFILER_CODE_BUFFER_DELEGATE_INVOKE:
1923 return "delegate invoke";
1924 case MONO_PROFILER_CODE_BUFFER_EXCEPTION_HANDLING:
1925 return "exception handling";
1927 return "unspecified";
1931 #define OBJ_ADDR(diff) ((obj_base + diff) << 3)
1932 #define LOG_TIME(base,diff) /*fprintf("outfile, time %llu + %llu near offset %d\n", base, diff, p - ctx->buf)*/
1935 decode_buffer (ProfContext *ctx)
1942 intptr_t method_base;
1944 uint64_t file_offset;
1946 ThreadContext *thread;
1948 #ifdef HAVE_SYS_ZLIB
1950 file_offset = gztell (ctx->gzfile);
1953 file_offset = ftell (ctx->file);
1954 if (!load_data (ctx, 48))
1957 if (read_int32 (p) != BUF_ID) {
1958 fprintf (outfile, "Incorrect buffer id: 0x%x\n", read_int32 (p));
1959 for (i = 0; i < 48; ++i) {
1960 fprintf (outfile, "0x%x%s", p [i], i % 8?" ":"\n");
1964 len = read_int32 (p + 4);
1965 time_base = read_int64 (p + 8);
1966 ptr_base = read_int64 (p + 16);
1967 obj_base = read_int64 (p + 24);
1968 thread_id = read_int64 (p + 32);
1969 method_base = read_int64 (p + 40);
1971 fprintf (outfile, "buf: thread:%zx, len: %d, time: %llu, file offset: %llu\n", thread_id, len, (unsigned long long) time_base, (unsigned long long) file_offset);
1972 thread = load_thread (ctx, thread_id);
1973 if (!load_data (ctx, len))
1975 if (!startup_time) {
1976 startup_time = time_base;
1977 if (use_time_filter) {
1978 time_from += startup_time;
1979 time_to += startup_time;
1982 thread->name = pstrdup ("Main");
1984 for (i = 0; i < thread->stack_id; ++i)
1985 thread->stack [i]->recurse_count++;
1991 int subtype = *p & 0xf0;
1992 uint64_t tdiff = decode_uleb128 (p + 1, &p);
1993 LOG_TIME (time_base, tdiff);
1995 if (subtype == TYPE_GC_RESIZE) {
1996 uint64_t new_size = decode_uleb128 (p, &p);
1998 fprintf (outfile, "gc heap resized to %llu\n", (unsigned long long) new_size);
2000 if (new_size > max_heap_size)
2001 max_heap_size = new_size;
2002 } else if (subtype == TYPE_GC_EVENT) {
2003 uint64_t ev = decode_uleb128 (p, &p);
2004 int gen = decode_uleb128 (p, &p);
2006 fprintf (outfile, "gc event for gen%d: %s at %llu (thread: 0x%zx)\n", gen, gc_event_name (ev), (unsigned long long) time_base, thread->thread_id);
2008 fprintf (outfile, "incorrect gc gen: %d\n", gen);
2011 if (ev == MONO_GC_EVENT_START) {
2012 thread->gc_start_times [gen] = time_base;
2013 gc_info [gen].count++;
2014 } else if (ev == MONO_GC_EVENT_END) {
2015 tdiff = time_base - thread->gc_start_times [gen];
2016 gc_info [gen].total_time += tdiff;
2017 if (tdiff > gc_info [gen].max_time)
2018 gc_info [gen].max_time = tdiff;
2020 } else if (subtype == TYPE_GC_MOVE) {
2021 int j, num = decode_uleb128 (p, &p);
2022 gc_object_moves += num / 2;
2023 for (j = 0; j < num; j += 2) {
2024 intptr_t obj1diff = decode_sleb128 (p, &p);
2025 intptr_t obj2diff = decode_sleb128 (p, &p);
2026 if (num_tracked_objects)
2027 track_move (OBJ_ADDR (obj1diff), OBJ_ADDR (obj2diff));
2029 fprintf (outfile, "moved obj %p to %p\n", (void*)OBJ_ADDR (obj1diff), (void*)OBJ_ADDR (obj2diff));
2032 } else if (subtype == TYPE_GC_HANDLE_CREATED) {
2033 int htype = decode_uleb128 (p, &p);
2034 uint32_t handle = decode_uleb128 (p, &p);
2035 intptr_t objdiff = decode_sleb128 (p, &p);
2038 handle_info [htype].created++;
2039 handle_info [htype].live++;
2040 add_trace_thread (thread, &handle_info [htype].traces, 1);
2041 /* FIXME: we don't take into account timing here */
2042 if (handle_info [htype].live > handle_info [htype].max_live)
2043 handle_info [htype].max_live = handle_info [htype].live;
2044 if (num_tracked_objects)
2045 track_handle (OBJ_ADDR (objdiff), htype, handle);
2047 fprintf (outfile, "handle (%s) %u created for object %p\n", get_handle_name (htype), handle, (void*)OBJ_ADDR (objdiff));
2048 } else if (subtype == TYPE_GC_HANDLE_DESTROYED) {
2049 int htype = decode_uleb128 (p, &p);
2050 uint32_t handle = decode_uleb128 (p, &p);
2053 handle_info [htype].destroyed ++;
2054 handle_info [htype].live--;
2056 fprintf (outfile, "handle (%s) %u destroyed\n", get_handle_name (htype), handle);
2060 case TYPE_METADATA: {
2061 int error = *p & TYPE_LOAD_ERR;
2062 uint64_t tdiff = decode_uleb128 (p + 1, &p);
2064 intptr_t ptrdiff = decode_sleb128 (p, &p);
2065 LOG_TIME (time_base, tdiff);
2067 if (mtype == TYPE_CLASS) {
2068 intptr_t imptrdiff = decode_sleb128 (p, &p);
2069 uint64_t flags = decode_uleb128 (p, &p);
2071 fprintf (outfile, "non-zero flags in class\n");
2075 fprintf (outfile, "loaded class %p (%s in %p) at %llu\n", (void*)(ptr_base + ptrdiff), p, (void*)(ptr_base + imptrdiff), (unsigned long long) time_base);
2077 add_class (ptr_base + ptrdiff, (char*)p);
2080 } else if (mtype == TYPE_IMAGE) {
2081 uint64_t flags = decode_uleb128 (p, &p);
2083 fprintf (outfile, "non-zero flags in image\n");
2087 fprintf (outfile, "loaded image %p (%s) at %llu\n", (void*)(ptr_base + ptrdiff), p, (unsigned long long) time_base);
2089 add_image (ptr_base + ptrdiff, (char*)p);
2092 } else if (mtype == TYPE_THREAD) {
2094 uint64_t flags = decode_uleb128 (p, &p);
2096 fprintf (outfile, "non-zero flags in thread\n");
2099 nt = get_thread (ctx, ptr_base + ptrdiff);
2100 nt->name = pstrdup ((char*)p);
2102 fprintf (outfile, "thread %p named: %s\n", (void*)(ptr_base + ptrdiff), p);
2109 int has_bt = *p & TYPE_ALLOC_BT;
2110 uint64_t tdiff = decode_uleb128 (p + 1, &p);
2111 intptr_t ptrdiff = decode_sleb128 (p, &p);
2112 intptr_t objdiff = decode_sleb128 (p, &p);
2115 MethodDesc* sframes [8];
2116 MethodDesc** frames = sframes;
2117 ClassDesc *cd = lookup_class (ptr_base + ptrdiff);
2118 len = decode_uleb128 (p, &p);
2119 LOG_TIME (time_base, tdiff);
2122 fprintf (outfile, "alloced object %p, size %llu (%s) at %llu\n", (void*)OBJ_ADDR (objdiff), (unsigned long long) len, lookup_class (ptr_base + ptrdiff)->name, (unsigned long long) time_base);
2125 frames = decode_bt (sframes, &num_bt, p, &p, ptr_base);
2127 fprintf (outfile, "Cannot load backtrace\n");
2131 if ((thread_filter && thread_filter == thread->thread_id) || (time_base >= time_from && time_base < time_to)) {
2134 cd->alloc_size += len;
2136 bt = add_trace_methods (frames, num_bt, &cd->traces, len);
2138 bt = add_trace_thread (thread, &cd->traces, len);
2139 if (find_size && len >= find_size) {
2140 if (!find_name || strstr (cd->name, find_name))
2141 found_object (OBJ_ADDR (objdiff));
2142 } else if (!find_size && find_name && strstr (cd->name, find_name)) {
2143 found_object (OBJ_ADDR (objdiff));
2145 if (num_tracked_objects)
2146 tracked_creation (OBJ_ADDR (objdiff), cd, len, bt, time_base);
2148 if (frames != sframes)
2153 int subtype = *p & 0xf0;
2154 uint64_t tdiff = decode_uleb128 (p + 1, &p);
2155 int64_t ptrdiff = decode_sleb128 (p, &p);
2156 LOG_TIME (time_base, tdiff);
2158 method_base += ptrdiff;
2159 if (subtype == TYPE_JIT) {
2160 intptr_t codediff = decode_sleb128 (p, &p);
2161 int codelen = decode_uleb128 (p, &p);
2162 MethodDesc *jitted_method;
2164 fprintf (outfile, "jitted method %p (%s), size: %d, code: %p\n", (void*)(method_base), p, codelen, (void*)(ptr_base + codediff));
2165 jitted_method = add_method (method_base, (char*)p, ptr_base + codediff, codelen);
2166 if (!(time_base >= time_from && time_base < time_to))
2167 jitted_method->ignore_jit = 1;
2172 if ((thread_filter && thread_filter != thread->thread_id))
2174 if (!(time_base >= time_from && time_base < time_to))
2176 method = lookup_method (method_base);
2177 if (subtype == TYPE_ENTER) {
2178 add_trace_thread (thread, &method->traces, 1);
2179 push_method (thread, method, time_base);
2181 pop_method (thread, method, time_base);
2184 fprintf (outfile, "%s method %s\n", subtype == TYPE_ENTER? "enter": subtype == TYPE_EXC_LEAVE? "exleave": "leave", method->name);
2189 int subtype = *p & 0xf0;
2190 if (subtype == TYPE_HEAP_OBJECT) {
2191 HeapObjectDesc *ho = NULL;
2193 intptr_t objdiff = decode_sleb128 (p + 1, &p);
2194 intptr_t ptrdiff = decode_sleb128 (p, &p);
2195 uint64_t size = decode_uleb128 (p, &p);
2196 uintptr_t num = decode_uleb128 (p, &p);
2197 uintptr_t ref_offset = 0;
2198 uintptr_t last_obj_offset = 0;
2199 ClassDesc *cd = lookup_class (ptr_base + ptrdiff);
2201 HeapClassDesc *hcd = add_heap_shot_class (thread->current_heap_shot, cd, size);
2202 if (collect_traces) {
2203 ho = alloc_heap_obj (OBJ_ADDR (objdiff), hcd, num);
2204 add_heap_shot_obj (thread->current_heap_shot, ho);
2209 ho = heap_shot_obj_add_refs (thread->current_heap_shot, OBJ_ADDR (objdiff), num, &ref_offset);
2211 for (i = 0; i < num; ++i) {
2212 /* FIXME: use object distance to measure how good
2213 * the GC is at keeping related objects close
2215 uintptr_t offset = ctx->data_version > 1? last_obj_offset + decode_uleb128 (p, &p): -1;
2216 intptr_t obj1diff = decode_sleb128 (p, &p);
2217 last_obj_offset = offset;
2219 ho->refs [ref_offset + i] = OBJ_ADDR (obj1diff);
2220 if (num_tracked_objects)
2221 track_obj_reference (OBJ_ADDR (obj1diff), OBJ_ADDR (objdiff), cd);
2224 fprintf (outfile, "traced object %p, size %llu (%s), refs: %zd\n", (void*)OBJ_ADDR (objdiff), (unsigned long long) size, cd->name, num);
2225 } else if (subtype == TYPE_HEAP_ROOT) {
2226 uintptr_t num = decode_uleb128 (p + 1, &p);
2227 uintptr_t gc_num G_GNUC_UNUSED = decode_uleb128 (p, &p);
2229 for (i = 0; i < num; ++i) {
2230 intptr_t objdiff = decode_sleb128 (p, &p);
2231 int root_type = decode_uleb128 (p, &p);
2232 /* we just discard the extra info for now */
2233 uintptr_t extra_info = decode_uleb128 (p, &p);
2235 fprintf (outfile, "object %p is a %s root\n", (void*)OBJ_ADDR (objdiff), get_root_name (root_type));
2237 thread_add_root (thread, OBJ_ADDR (objdiff), root_type, extra_info);
2239 } else if (subtype == TYPE_HEAP_END) {
2240 uint64_t tdiff = decode_uleb128 (p + 1, &p);
2241 LOG_TIME (time_base, tdiff);
2244 fprintf (outfile, "heap shot end\n");
2245 if (collect_traces) {
2246 HeapShot *hs = thread->current_heap_shot;
2247 if (hs && thread->num_roots) {
2248 /* transfer the root ownershipt to the heapshot */
2249 hs->num_roots = thread->num_roots;
2250 hs->roots = thread->roots;
2251 hs->roots_extra = thread->roots_extra;
2252 hs->roots_types = thread->roots_types;
2254 free (thread->roots);
2255 free (thread->roots_extra);
2256 free (thread->roots_types);
2258 thread->num_roots = 0;
2259 thread->size_roots = 0;
2260 thread->roots = NULL;
2261 thread->roots_extra = NULL;
2262 thread->roots_types = NULL;
2263 heap_shot_resolve_reverse_refs (hs);
2264 heap_shot_mark_objects (hs);
2265 heap_shot_free_objects (hs);
2267 thread->current_heap_shot = NULL;
2268 } else if (subtype == TYPE_HEAP_START) {
2269 uint64_t tdiff = decode_uleb128 (p + 1, &p);
2270 LOG_TIME (time_base, tdiff);
2273 fprintf (outfile, "heap shot start\n");
2274 thread->current_heap_shot = new_heap_shot (time_base);
2278 case TYPE_MONITOR: {
2279 int event = (*p >> 4) & 0x3;
2280 int has_bt = *p & TYPE_MONITOR_BT;
2281 uint64_t tdiff = decode_uleb128 (p + 1, &p);
2282 intptr_t objdiff = decode_sleb128 (p, &p);
2283 MethodDesc* sframes [8];
2284 MethodDesc** frames = sframes;
2287 LOG_TIME (time_base, tdiff);
2289 record = (!thread_filter || thread_filter == thread->thread_id);
2290 if (!(time_base >= time_from && time_base < time_to))
2292 if (event == MONO_PROFILER_MONITOR_CONTENTION) {
2293 MonitorDesc *mdesc = lookup_monitor (OBJ_ADDR (objdiff));
2295 monitor_contention++;
2296 mdesc->contentions++;
2297 thread->monitor = mdesc;
2298 thread->contention_start = time_base;
2302 frames = decode_bt (sframes, &num_bt, p, &p, ptr_base);
2304 fprintf (outfile, "Cannot load backtrace\n");
2308 add_trace_methods (frames, num_bt, &mdesc->traces, 1);
2311 add_trace_thread (thread, &mdesc->traces, 1);
2313 } else if (event == MONO_PROFILER_MONITOR_FAIL) {
2316 if (thread->monitor && thread->contention_start) {
2317 uint64_t wait_time = time_base - thread->contention_start;
2318 if (wait_time > thread->monitor->max_wait_time)
2319 thread->monitor->max_wait_time = wait_time;
2320 thread->monitor->wait_time += wait_time;
2321 thread->monitor = NULL;
2322 thread->contention_start = 0;
2325 } else if (event == MONO_PROFILER_MONITOR_DONE) {
2328 if (thread->monitor && thread->contention_start) {
2329 uint64_t wait_time = time_base - thread->contention_start;
2330 if (wait_time > thread->monitor->max_wait_time)
2331 thread->monitor->max_wait_time = wait_time;
2332 thread->monitor->wait_time += wait_time;
2333 thread->monitor = NULL;
2334 thread->contention_start = 0;
2339 fprintf (outfile, "monitor %s for object %p\n", monitor_ev_name (event), (void*)OBJ_ADDR (objdiff));
2340 if (frames != sframes)
2344 case TYPE_EXCEPTION: {
2345 int subtype = *p & 0x70;
2346 int has_bt = *p & TYPE_EXCEPTION_BT;
2347 uint64_t tdiff = decode_uleb128 (p + 1, &p);
2348 MethodDesc* sframes [8];
2349 MethodDesc** frames = sframes;
2351 LOG_TIME (time_base, tdiff);
2353 record = (!thread_filter || thread_filter == thread->thread_id);
2354 if (!(time_base >= time_from && time_base < time_to))
2356 if (subtype == TYPE_CLAUSE) {
2357 int clause_type = decode_uleb128 (p, &p);
2358 int clause_num = decode_uleb128 (p, &p);
2359 int64_t ptrdiff = decode_sleb128 (p, &p);
2360 method_base += ptrdiff;
2362 clause_summary [clause_type]++;
2364 fprintf (outfile, "clause %s (%d) in method %s\n", clause_name (clause_type), clause_num, lookup_method (method_base)->name);
2366 intptr_t objdiff = decode_sleb128 (p, &p);
2371 frames = decode_bt (sframes, &has_bt, p, &p, ptr_base);
2373 fprintf (outfile, "Cannot load backtrace\n");
2377 add_trace_methods (frames, has_bt, &exc_traces, 1);
2380 add_trace_thread (thread, &exc_traces, 1);
2382 if (frames != sframes)
2385 fprintf (outfile, "throw %p\n", (void*)OBJ_ADDR (objdiff));
2389 case TYPE_RUNTIME: {
2390 int subtype = *p & 0xf0;
2391 uint64_t tdiff = decode_uleb128 (p + 1, &p);
2392 LOG_TIME (time_base, tdiff);
2394 if (subtype == TYPE_JITHELPER) {
2395 int type = decode_uleb128 (p, &p);
2396 intptr_t codediff = decode_sleb128 (p, &p);
2397 int codelen = decode_uleb128 (p, &p);
2399 if (type == MONO_PROFILER_CODE_BUFFER_SPECIFIC_TRAMPOLINE) {
2404 name = code_buffer_desc (type);
2407 jit_helpers_code_size += codelen;
2409 fprintf (outfile, "jit helper %s, size: %d, code: %p\n", name, codelen, (void*)(ptr_base + codediff));
2414 int subtype = *p & 0xf0;
2415 if (subtype == TYPE_SAMPLE_HIT) {
2417 int sample_type = decode_uleb128 (p + 1, &p);
2418 uint64_t tstamp = decode_uleb128 (p, &p);
2419 int count = decode_uleb128 (p, &p);
2420 for (i = 0; i < count; ++i) {
2421 uintptr_t ip = ptr_base + decode_sleb128 (p, &p);
2422 if ((tstamp >= time_from && tstamp < time_to))
2423 add_stat_sample (sample_type, ip);
2425 fprintf (outfile, "sample hit, type: %d at %p\n", sample_type, (void*)ip);
2427 if (ctx->data_version > 5) {
2428 count = decode_uleb128 (p, &p);
2429 for (i = 0; i < count; ++i) {
2431 int64_t ptrdiff = decode_sleb128 (p, &p);
2432 int il_offset = decode_sleb128 (p, &p);
2433 int native_offset = decode_sleb128 (p, &p);
2434 method_base += ptrdiff;
2435 method = lookup_method (method_base);
2437 fprintf (outfile, "sample hit bt %d: %s at IL offset %d (native: %d)\n", i, method->name, il_offset, native_offset);
2440 } else if (subtype == TYPE_SAMPLE_USYM) {
2441 /* un unmanaged symbol description */
2442 uintptr_t addr = ptr_base + decode_sleb128 (p + 1, &p);
2443 uintptr_t size = decode_uleb128 (p, &p);
2445 name = pstrdup ((char*)p);
2446 add_unmanaged_symbol (addr, name, size);
2448 fprintf (outfile, "unmanaged symbol %s at %p\n", name, (void*)addr);
2451 } else if (subtype == TYPE_SAMPLE_UBIN) {
2452 /* un unmanaged binary loaded in memory */
2453 uint64_t tdiff = decode_uleb128 (p + 1, &p);
2454 uintptr_t addr = decode_sleb128 (p, &p);
2455 uint64_t offset G_GNUC_UNUSED = decode_uleb128 (p, &p);
2456 uintptr_t size = decode_uleb128 (p, &p);
2458 LOG_TIME (time_base, tdiff);
2460 name = pstrdup ((char*)p);
2461 add_unmanaged_binary (addr, name, size);
2463 fprintf (outfile, "unmanaged binary %s at %p\n", name, (void*)addr);
2466 } else if (subtype == TYPE_SAMPLE_COUNTERS_DESC) {
2467 uint64_t i, len = decode_uleb128 (p + 1, &p);
2468 for (i = 0; i < len; i++) {
2469 uint64_t type, unit, variance, index;
2470 uint64_t section = decode_uleb128 (p, &p);
2471 char *section_str, *name;
2472 if (section != MONO_COUNTER_PERFCOUNTERS) {
2473 section_str = (char*) section_name (section);
2475 section_str = pstrdup ((char*)p);
2478 name = pstrdup ((char*)p);
2480 type = decode_uleb128 (p, &p);
2481 unit = decode_uleb128 (p, &p);
2482 variance = decode_uleb128 (p, &p);
2483 index = decode_uleb128 (p, &p);
2484 add_counter (section_str, name, (int)type, (int)unit, (int)variance, (int)index);
2486 } else if (subtype == TYPE_SAMPLE_COUNTERS) {
2488 CounterValue *value, *previous = NULL;
2490 uint64_t timestamp = decode_uleb128 (p + 1, &p);
2491 uint64_t time_between = timestamp / 1000 * 1000 * 1000 * 1000 + startup_time;
2493 uint64_t type, index = decode_uleb128 (p, &p);
2497 for (list = counters; list; list = list->next) {
2498 if (list->counter->index == (int)index) {
2499 previous = list->counter->values_last;
2504 type = decode_uleb128 (p, &p);
2506 value = calloc (1, sizeof (CounterValue));
2507 value->timestamp = timestamp;
2510 case MONO_COUNTER_INT:
2511 #if SIZEOF_VOID_P == 4
2512 case MONO_COUNTER_WORD:
2514 value->buffer = malloc (sizeof (int32_t));
2515 *(int32_t*)value->buffer = (int32_t)decode_sleb128 (p, &p) + (previous ? (*(int32_t*)previous->buffer) : 0);
2517 case MONO_COUNTER_UINT:
2518 value->buffer = malloc (sizeof (uint32_t));
2519 *(uint32_t*)value->buffer = (uint32_t)decode_uleb128 (p, &p) + (previous ? (*(uint32_t*)previous->buffer) : 0);
2521 case MONO_COUNTER_LONG:
2522 #if SIZEOF_VOID_P == 8
2523 case MONO_COUNTER_WORD:
2525 case MONO_COUNTER_TIME_INTERVAL:
2526 value->buffer = malloc (sizeof (int64_t));
2527 *(int64_t*)value->buffer = (int64_t)decode_sleb128 (p, &p) + (previous ? (*(int64_t*)previous->buffer) : 0);
2529 case MONO_COUNTER_ULONG:
2530 value->buffer = malloc (sizeof (uint64_t));
2531 *(uint64_t*)value->buffer = (uint64_t)decode_uleb128 (p, &p) + (previous ? (*(uint64_t*)previous->buffer) : 0);
2533 case MONO_COUNTER_DOUBLE:
2534 value->buffer = malloc (sizeof (double));
2535 #if TARGET_BYTE_ORDER == G_LITTLE_ENDIAN
2536 for (i = 0; i < sizeof (double); i++)
2538 for (i = sizeof (double) - 1; i >= 0; i--)
2540 value->buffer[i] = *p++;
2542 case MONO_COUNTER_STRING:
2544 value->buffer = NULL;
2546 value->buffer = (unsigned char*) pstrdup ((char*)p);
2551 if (time_between >= time_from && time_between <= time_to)
2552 add_counter_value (index, value);
2560 fprintf (outfile, "unhandled profiler event: 0x%x at file offset: %llu + %lld (len: %d\n)\n", *p, (unsigned long long) file_offset, (long long) (p - ctx->buf), len);
2564 thread->last_time = time_base;
2565 for (i = 0; i < thread->stack_id; ++i)
2566 thread->stack [i]->recurse_count = 0;
2571 load_file (char *name)
2574 ProfContext *ctx = calloc (sizeof (ProfContext), 1);
2575 if (strcmp (name, "-") == 0)
2578 ctx->file = fopen (name, "rb");
2580 printf ("Cannot open file: %s\n", name);
2583 #if defined (HAVE_SYS_ZLIB)
2584 if (ctx->file != stdin)
2585 ctx->gzfile = gzdopen (fileno (ctx->file), "rb");
2587 if (!load_data (ctx, 32))
2590 if (read_int32 (p) != LOG_HEADER_ID || p [6] > LOG_DATA_VERSION)
2592 ctx->version_major = p [4];
2593 ctx->version_minor = p [5];
2594 ctx->data_version = p [6];
2595 /* reading 64 bit files on 32 bit systems not supported yet */
2596 if (p [7] > sizeof (void*))
2598 if (read_int32 (p + 20)) /* flags must be 0 */
2600 ctx->startup_time = read_int64 (p + 8);
2601 ctx->timer_overhead = read_int32 (p + 16);
2602 ctx->pid = read_int32 (p + 24);
2603 ctx->port = read_int16 (p + 28);
2611 static int alloc_sort_mode = ALLOC_SORT_BYTES;
2614 compare_class (const void *a, const void *b)
2616 ClassDesc *const*A = a;
2617 ClassDesc *const*B = b;
2618 uint64_t vala, valb;
2619 if (alloc_sort_mode == ALLOC_SORT_BYTES) {
2620 vala = (*A)->alloc_size;
2621 valb = (*B)->alloc_size;
2623 vala = (*A)->allocs;
2624 valb = (*B)->allocs;
2634 dump_header (ProfContext *ctx)
2636 time_t st = ctx->startup_time / 1000;
2637 char *t = ctime (&st);
2638 fprintf (outfile, "\nMono log profiler data\n");
2639 fprintf (outfile, "\tProfiler version: %d.%d\n", ctx->version_major, ctx->version_minor);
2640 fprintf (outfile, "\tData version: %d\n", ctx->data_version);
2641 fprintf (outfile, "\tMean timer overhead: %d nanoseconds\n", ctx->timer_overhead);
2642 fprintf (outfile, "\tProgram startup: %s", t);
2644 fprintf (outfile, "\tProgram ID: %d\n", ctx->pid);
2646 fprintf (outfile, "\tServer listening on: %d\n", ctx->port);
2650 dump_traces (TraceDesc *traces, const char *desc)
2657 sort_context_array (traces);
2658 for (j = 0; j < traces->count; ++j) {
2661 bt = traces->traces [j].bt;
2664 fprintf (outfile, "\t%llu %s from:\n", (unsigned long long) traces->traces [j].count, desc);
2665 for (k = 0; k < bt->count; ++k)
2666 fprintf (outfile, "\t\t%s\n", bt->methods [k]->name);
2671 dump_threads (ProfContext *ctx)
2673 ThreadContext *thread;
2674 fprintf (outfile, "\nThread summary\n");
2675 for (thread = ctx->threads; thread; thread = thread->next) {
2676 fprintf (outfile, "\tThread: %p, name: \"%s\"\n", (void*)thread->thread_id, thread->name? thread->name: "");
2681 dump_exceptions (void)
2684 fprintf (outfile, "\nException summary\n");
2685 fprintf (outfile, "\tThrows: %llu\n", (unsigned long long) throw_count);
2686 dump_traces (&exc_traces, "throws");
2687 for (i = 0; i <= MONO_EXCEPTION_CLAUSE_FAULT; ++i) {
2688 if (!clause_summary [i])
2690 fprintf (outfile, "\tExecuted %s clauses: %llu\n", clause_name (i), (unsigned long long) clause_summary [i]);
2695 compare_monitor (const void *a, const void *b)
2697 MonitorDesc *const*A = a;
2698 MonitorDesc *const*B = b;
2699 if ((*B)->wait_time == (*A)->wait_time)
2701 if ((*B)->wait_time < (*A)->wait_time)
2707 dump_monitors (void)
2709 MonitorDesc **monitors;
2713 monitors = malloc (sizeof (void*) * num_monitors);
2714 for (i = 0, j = 0; i < SMALL_HASH_SIZE; ++i) {
2715 MonitorDesc *mdesc = monitor_hash [i];
2717 monitors [j++] = mdesc;
2718 mdesc = mdesc->next;
2721 qsort (monitors, num_monitors, sizeof (void*), compare_monitor);
2722 fprintf (outfile, "\nMonitor lock summary\n");
2723 for (i = 0; i < num_monitors; ++i) {
2724 MonitorDesc *mdesc = monitors [i];
2725 fprintf (outfile, "\tLock object %p: %d contentions\n", (void*)mdesc->objid, (int)mdesc->contentions);
2726 fprintf (outfile, "\t\t%.6f secs total wait time, %.6f max, %.6f average\n",
2727 mdesc->wait_time/1000000000.0, mdesc->max_wait_time/1000000000.0, mdesc->wait_time/1000000000.0/mdesc->contentions);
2728 dump_traces (&mdesc->traces, "contentions");
2730 fprintf (outfile, "\tLock contentions: %llu\n", (unsigned long long) monitor_contention);
2731 fprintf (outfile, "\tLock acquired: %llu\n", (unsigned long long) monitor_acquired);
2732 fprintf (outfile, "\tLock failures: %llu\n", (unsigned long long) monitor_failed);
2739 fprintf (outfile, "\nGC summary\n");
2740 fprintf (outfile, "\tGC resizes: %d\n", gc_resizes);
2741 fprintf (outfile, "\tMax heap size: %llu\n", (unsigned long long) max_heap_size);
2742 fprintf (outfile, "\tObject moves: %llu\n", (unsigned long long) gc_object_moves);
2743 for (i = 0; i < 3; ++i) {
2744 if (!gc_info [i].count)
2746 fprintf (outfile, "\tGen%d collections: %d, max time: %lluus, total time: %lluus, average: %lluus\n",
2747 i, gc_info [i].count,
2748 (unsigned long long) (gc_info [i].max_time / 1000),
2749 (unsigned long long) (gc_info [i].total_time / 1000),
2750 (unsigned long long) (gc_info [i].total_time / gc_info [i].count / 1000));
2752 for (i = 0; i < 3; ++i) {
2753 if (!handle_info [i].max_live)
2755 fprintf (outfile, "\tGC handles %s: created: %llu, destroyed: %llu, max: %llu\n",
2756 get_handle_name (i),
2757 (unsigned long long) (handle_info [i].created),
2758 (unsigned long long) (handle_info [i].destroyed),
2759 (unsigned long long) (handle_info [i].max_live));
2760 dump_traces (&handle_info [i].traces, "created");
2769 int compiled_methods = 0;
2771 fprintf (outfile, "\nJIT summary\n");
2772 for (i = 0; i < HASH_SIZE; ++i) {
2773 m = method_hash [i];
2774 for (m = method_hash [i]; m; m = m->next) {
2775 if (!m->code || m->ignore_jit)
2778 code_size += m->len;
2781 fprintf (outfile, "\tCompiled methods: %d\n", compiled_methods);
2782 fprintf (outfile, "\tGenerated code size: %d\n", code_size);
2783 fprintf (outfile, "\tJIT helpers: %d\n", num_jit_helpers);
2784 fprintf (outfile, "\tJIT helpers code size: %d\n", jit_helpers_code_size);
2788 dump_allocations (void)
2791 intptr_t allocs = 0;
2793 int header_done = 0;
2794 ClassDesc **classes = malloc (num_classes * sizeof (void*));
2797 for (i = 0; i < HASH_SIZE; ++i) {
2798 cd = class_hash [i];
2804 qsort (classes, num_classes, sizeof (void*), compare_class);
2805 for (i = 0; i < num_classes; ++i) {
2809 allocs += cd->allocs;
2810 size += cd->alloc_size;
2811 if (!header_done++) {
2812 fprintf (outfile, "\nAllocation summary\n");
2813 fprintf (outfile, "%10s %10s %8s Type name\n", "Bytes", "Count", "Average");
2815 fprintf (outfile, "%10llu %10zd %8llu %s\n",
2816 (unsigned long long) (cd->alloc_size),
2818 (unsigned long long) (cd->alloc_size / cd->allocs),
2820 dump_traces (&cd->traces, "bytes");
2823 fprintf (outfile, "Total memory allocated: %llu bytes in %zd objects\n", (unsigned long long) size, allocs);
2832 static int method_sort_mode = METHOD_SORT_TOTAL;
2835 compare_method (const void *a, const void *b)
2837 MethodDesc *const*A = a;
2838 MethodDesc *const*B = b;
2839 uint64_t vala, valb;
2840 if (method_sort_mode == METHOD_SORT_SELF) {
2841 vala = (*A)->self_time;
2842 valb = (*B)->self_time;
2843 } else if (method_sort_mode == METHOD_SORT_CALLS) {
2847 vala = (*A)->total_time;
2848 valb = (*B)->total_time;
2858 dump_metadata (void)
2860 fprintf (outfile, "\nMetadata summary\n");
2861 fprintf (outfile, "\tLoaded images: %d\n", num_images);
2865 for (i = 0; i < SMALL_HASH_SIZE; ++i) {
2866 image = image_hash [i];
2868 fprintf (outfile, "\t\t%s\n", image->filename);
2869 image = image->next;
2881 int header_done = 0;
2882 MethodDesc **methods = malloc (num_methods * sizeof (void*));
2885 for (i = 0; i < HASH_SIZE; ++i) {
2886 cd = method_hash [i];
2888 cd->total_time = cd->self_time + cd->callee_time;
2893 qsort (methods, num_methods, sizeof (void*), compare_method);
2894 for (i = 0; i < num_methods; ++i) {
2901 msecs = cd->total_time / 1000000;
2902 smsecs = (cd->total_time - cd->callee_time) / 1000000;
2903 if (!msecs && !verbose)
2905 if (!header_done++) {
2906 fprintf (outfile, "\nMethod call summary\n");
2907 fprintf (outfile, "%8s %8s %10s Method name\n", "Total(ms)", "Self(ms)", "Calls");
2909 fprintf (outfile, "%8llu %8llu %10llu %s\n",
2910 (unsigned long long) (msecs),
2911 (unsigned long long) (smsecs),
2912 (unsigned long long) (cd->calls),
2914 dump_traces (&cd->traces, "calls");
2917 fprintf (outfile, "Total calls: %llu\n", (unsigned long long) calls);
2921 compare_heap_class (const void *a, const void *b)
2923 HeapClassDesc *const*A = a;
2924 HeapClassDesc *const*B = b;
2925 uint64_t vala, valb;
2926 if (alloc_sort_mode == ALLOC_SORT_BYTES) {
2927 vala = (*A)->total_size;
2928 valb = (*B)->total_size;
2941 compare_rev_class (const void *a, const void *b)
2943 const HeapClassRevRef *A = a;
2944 const HeapClassRevRef *B = b;
2945 if (B->count == A->count)
2947 if (B->count < A->count)
2953 dump_rev_claases (HeapClassRevRef *revs, int count)
2960 for (j = 0; j < count; ++j) {
2961 HeapClassDesc *cd = revs [j].klass;
2962 fprintf (outfile, "\t\t%llu references from: %s\n",
2963 (unsigned long long) (revs [j].count),
2969 heap_shot_summary (HeapShot *hs, int hs_num, HeapShot *last_hs)
2976 HeapClassDesc **sorted;
2977 sorted = malloc (sizeof (void*) * hs->class_count);
2978 for (i = 0; i < hs->hash_size; ++i) {
2979 cd = hs->class_hash [i];
2983 size += cd->total_size;
2984 sorted [ccount++] = cd;
2986 hs->sorted = sorted;
2987 qsort (sorted, ccount, sizeof (void*), compare_heap_class);
2988 fprintf (outfile, "\n\tHeap shot %d at %.3f secs: size: %llu, object count: %llu, class count: %d, roots: %zd\n",
2990 (hs->timestamp - startup_time)/1000000000.0,
2991 (unsigned long long) (size),
2992 (unsigned long long) (count),
2993 ccount, hs->num_roots);
2994 if (!verbose && ccount > 30)
2996 fprintf (outfile, "\t%10s %10s %8s Class name\n", "Bytes", "Count", "Average");
2997 for (i = 0; i < ccount; ++i) {
2998 HeapClassRevRef *rev_sorted;
3000 HeapClassDesc *ocd = NULL;
3003 ocd = heap_class_lookup (last_hs, cd->klass);
3004 fprintf (outfile, "\t%10llu %10llu %8llu %s",
3005 (unsigned long long) (cd->total_size),
3006 (unsigned long long) (cd->count),
3007 (unsigned long long) (cd->total_size / cd->count),
3010 int64_t bdiff = cd->total_size - ocd->total_size;
3011 int64_t cdiff = cd->count - ocd->count;
3012 fprintf (outfile, " (bytes: %+lld, count: %+lld)\n", (long long) bdiff, (long long) cdiff);
3014 fprintf (outfile, "\n");
3016 if (!collect_traces)
3018 rev_sorted = malloc (cd->rev_count * sizeof (HeapClassRevRef));
3020 for (j = 0; j < cd->rev_hash_size; ++j) {
3021 if (cd->rev_hash [j].klass)
3022 rev_sorted [k++] = cd->rev_hash [j];
3024 assert (cd->rev_count == k);
3025 qsort (rev_sorted, cd->rev_count, sizeof (HeapClassRevRef), compare_rev_class);
3026 if (cd->root_references)
3027 fprintf (outfile, "\t\t%zd root references (%zd pinning)\n", cd->root_references, cd->pinned_references);
3028 dump_rev_claases (rev_sorted, cd->rev_count);
3035 compare_heap_shots (const void *a, const void *b)
3037 HeapShot *const*A = a;
3038 HeapShot *const*B = b;
3039 if ((*B)->timestamp == (*A)->timestamp)
3041 if ((*B)->timestamp > (*A)->timestamp)
3047 dump_heap_shots (void)
3049 HeapShot **hs_sorted;
3051 HeapShot *last_hs = NULL;
3055 hs_sorted = malloc (num_heap_shots * sizeof (void*));
3056 fprintf (outfile, "\nHeap shot summary\n");
3058 for (hs = heap_shots; hs; hs = hs->next)
3059 hs_sorted [i++] = hs;
3060 qsort (hs_sorted, num_heap_shots, sizeof (void*), compare_heap_shots);
3061 for (i = 0; i < num_heap_shots; ++i) {
3063 heap_shot_summary (hs, i, last_hs);
3069 flush_context (ProfContext *ctx)
3071 ThreadContext *thread;
3072 /* FIXME: sometimes there are leftovers: indagate */
3073 for (thread = ctx->threads; thread; thread = thread->next) {
3074 while (thread->stack_id) {
3076 fprintf (outfile, "thread %p has %d items on stack\n", (void*)thread->thread_id, thread->stack_id);
3077 pop_method (thread, thread->stack [thread->stack_id - 1], thread->last_time);
3082 static const char *reports = "header,jit,gc,sample,alloc,call,metadata,exception,monitor,thread,heapshot,counters";
3085 match_option (const char *p, const char *opt)
3087 int len = strlen (opt);
3088 if (strncmp (p, opt, len) == 0) {
3097 print_reports (ProfContext *ctx, const char *reps, int parse_only)
3101 for (p = reps; *p; p = opt) {
3102 if ((opt = match_option (p, "header")) != p) {
3107 if ((opt = match_option (p, "thread")) != p) {
3112 if ((opt = match_option (p, "gc")) != p) {
3117 if ((opt = match_option (p, "jit")) != p) {
3122 if ((opt = match_option (p, "alloc")) != p) {
3124 dump_allocations ();
3127 if ((opt = match_option (p, "call")) != p) {
3132 if ((opt = match_option (p, "metadata")) != p) {
3137 if ((opt = match_option (p, "exception")) != p) {
3142 if ((opt = match_option (p, "monitor")) != p) {
3147 if ((opt = match_option (p, "heapshot")) != p) {
3152 if ((opt = match_option (p, "sample")) != p) {
3157 if ((opt = match_option (p, "counters")) != p) {
3168 add_find_spec (const char *p)
3170 if (p [0] == 'S' && p [1] == ':') {
3172 find_size = strtoul (p + 2, &vale, 10);
3174 } else if (p [0] == 'T' && p [1] == ':') {
3184 printf ("Mono log profiler report version %d.%d\n", LOG_VERSION_MAJOR, LOG_VERSION_MINOR);
3185 printf ("Usage: mprof-report [OPTIONS] FILENAME\n");
3186 printf ("FILENAME can be '-' to read from standard input.\n");
3187 printf ("Options:\n");
3188 printf ("\t--help display this help\n");
3189 printf ("\t--out=FILE write to FILE instead of stdout\n");
3190 printf ("\t--traces collect and show backtraces\n");
3191 printf ("\t--maxframes=NUM limit backtraces to NUM entries\n");
3192 printf ("\t--reports=R1[,R2...] print the specified reports. Defaults are:\n");
3193 printf ("\t %s\n", reports);
3194 printf ("\t--method-sort=MODE sort methods according to MODE: total, self, calls\n");
3195 printf ("\t--alloc-sort=MODE sort allocations according to MODE: bytes, count\n");
3196 printf ("\t--counters-sort=MODE sort counters according to MODE: time, category\n");
3197 printf ("\t only accessible in verbose mode\n");
3198 printf ("\t--track=OB1[,OB2...] track what happens to objects OBJ1, O2 etc.\n");
3199 printf ("\t--find=FINDSPEC find and track objects matching FINFSPEC, where FINDSPEC is:\n");
3200 printf ("\t S:minimum_size or T:partial_name\n");
3201 printf ("\t--thread=THREADID consider just the data for thread THREADID\n");
3202 printf ("\t--time=FROM-TO consider data FROM seconds from startup up to TO seconds\n");
3203 printf ("\t--verbose increase verbosity level\n");
3204 printf ("\t--debug display decoding debug info for mprof-report devs\n");
3208 main (int argc, char *argv[])
3213 for (i = 1; i < argc; ++i) {
3214 if (strcmp ("--debug", argv [i]) == 0) {
3216 } else if (strcmp ("--help", argv [i]) == 0) {
3219 } else if (strncmp ("--alloc-sort=", argv [i], 13) == 0) {
3220 const char *val = argv [i] + 13;
3221 if (strcmp (val, "bytes") == 0) {
3222 alloc_sort_mode = ALLOC_SORT_BYTES;
3223 } else if (strcmp (val, "count") == 0) {
3224 alloc_sort_mode = ALLOC_SORT_COUNT;
3229 } else if (strncmp ("--method-sort=", argv [i], 14) == 0) {
3230 const char *val = argv [i] + 14;
3231 if (strcmp (val, "total") == 0) {
3232 method_sort_mode = METHOD_SORT_TOTAL;
3233 } else if (strcmp (val, "self") == 0) {
3234 method_sort_mode = METHOD_SORT_SELF;
3235 } else if (strcmp (val, "calls") == 0) {
3236 method_sort_mode = METHOD_SORT_CALLS;
3241 } else if (strncmp ("--counters-sort=", argv [i], 16) == 0) {
3242 const char *val = argv [i] + 16;
3243 if (strcmp (val, "time") == 0) {
3244 counters_sort_mode = COUNTERS_SORT_TIME;
3245 } else if (strcmp (val, "category") == 0) {
3246 counters_sort_mode = COUNTERS_SORT_CATEGORY;
3251 } else if (strncmp ("--reports=", argv [i], 10) == 0) {
3252 const char *val = argv [i] + 10;
3253 if (!print_reports (NULL, val, 1)) {
3258 } else if (strncmp ("--out=", argv [i], 6) == 0) {
3259 const char *val = argv [i] + 6;
3260 outfile = fopen (val, "w");
3262 printf ("Cannot open output file: %s\n", val);
3265 } else if (strncmp ("--maxframes=", argv [i], 12) == 0) {
3266 const char *val = argv [i] + 12;
3268 trace_max = strtoul (val, &vale, 10);
3269 } else if (strncmp ("--find=", argv [i], 7) == 0) {
3270 const char *val = argv [i] + 7;
3271 if (!add_find_spec (val)) {
3275 } else if (strncmp ("--track=", argv [i], 8) == 0) {
3276 const char *val = argv [i] + 8;
3279 uintptr_t tracked_obj;
3284 tracked_obj = strtoul (val, &vale, 0);
3285 found_object (tracked_obj);
3288 } else if (strncmp ("--thread=", argv [i], 9) == 0) {
3289 const char *val = argv [i] + 9;
3291 thread_filter = strtoul (val, &vale, 0);
3292 } else if (strncmp ("--time=", argv [i], 7) == 0) {
3293 char *val = pstrdup (argv [i] + 7);
3294 double from_secs, to_secs;
3295 char *top = strchr (val, '-');
3301 from_secs = atof (val);
3302 to_secs = atof (top);
3304 if (from_secs > to_secs) {
3308 time_from = from_secs * 1000000000;
3309 time_to = to_secs * 1000000000;
3310 use_time_filter = 1;
3311 } else if (strcmp ("--verbose", argv [i]) == 0) {
3313 } else if (strcmp ("--traces", argv [i]) == 0) {
3324 ctx = load_file (argv [i]);
3326 printf ("Not a log profiler data file (or unsupported version).\n");
3329 while (decode_buffer (ctx));
3330 flush_context (ctx);
3331 if (num_tracked_objects)
3333 print_reports (ctx, reports, 0);