mono/profiler/decode.c

   1 /*
   2  * decode.c: mprof-report program source: decode and analyze the log profiler data
   3  *
   4  * Author:
   5  *   Paolo Molaro (lupus@ximian.com)
   6  *
   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 <stdio.h>
  14 #if !defined(__APPLE__)
  15 #include <malloc.h>
  16 #endif
  17 #include <unistd.h>
  18 #include <stdlib.h>
  19 #ifdef HOST_WIN32
  20 #undef HAVE_ZLIB
  21 #endif
  22 #if defined (HAVE_ZLIB)
  23 #include <zlib.h>
  24 #endif
  25 #include <mono/metadata/profiler.h>
  26 #include <mono/metadata/object.h>
  27 #include <mono/metadata/debug-helpers.h>
  28
  29 #define HASH_SIZE 9371
  30 #define SMALL_HASH_SIZE 31
  31
  32 static int debug = 0;
  33 static int collect_traces = 0;
  34 static int show_traces = 0;
  35 static int trace_max = 6;
  36 static int verbose = 0;
  37 static uintptr_t *tracked_objects = 0;
  38 static int num_tracked_objects = 0;
  39 static uintptr_t thread_filter = 0;
  40 static uint64_t find_size = 0;
  41 static const char* find_name = NULL;
  42 static uint64_t time_from = 0;
  43 static uint64_t time_to = 0xffffffffffffffffULL;
  44 static uint64_t startup_time = 0;
  45 static FILE* outfile = NULL;
  46
  47 static int32_t
  48 read_int32 (unsigned char *p)
  49 {
  50         int32_t value = *p++;
  51         value |= (*p++) << 8;
  52         value |= (*p++) << 16;
  53         value |= (uint32_t)(*p++) << 24;
  54         return value;
  55 }
  56
  57 static int64_t
  58 read_int64 (unsigned char *p)
  59 {
  60         uint64_t value = *p++;
  61         value |= (*p++) << 8;
  62         value |= (*p++) << 16;
  63         value |= (uint64_t)(*p++) << 24;
  64         value |= (uint64_t)(*p++) << 32;
  65         value |= (uint64_t)(*p++) << 40;
  66         value |= (uint64_t)(*p++) << 48;
  67         value |= (uint64_t)(*p++) << 54;
  68         return value;
  69 }
  70
  71 static char*
  72 pstrdup (const char *s)
  73 {
  74         int len = strlen (s) + 1;
  75         char *p = malloc (len);
  76         memcpy (p, s, len);
  77         return p;
  78 }
  79
  80 static int num_images;
  81 typedef struct _ImageDesc ImageDesc;
  82 struct _ImageDesc {
  83         ImageDesc *next;
  84         intptr_t image;
  85         char *filename;
  86 };
  87
  88 static ImageDesc* image_hash [SMALL_HASH_SIZE] = {0};
  89
  90 static void
  91 add_image (intptr_t image, char *name)
  92 {
  93         int slot = ((image >> 2) & 0xffff) % SMALL_HASH_SIZE;
  94         ImageDesc *cd = malloc (sizeof (ImageDesc));
  95         cd->image = image;
  96         cd->filename = pstrdup (name);
  97         cd->next = image_hash [slot];
  98         image_hash [slot] = cd;
  99         num_images++;
 100 }
 101
 102 typedef struct _BackTrace BackTrace;
 103 typedef struct {
 104         uint64_t count;
 105         BackTrace *bt;
 106 } CallContext;
 107
 108 typedef struct {
 109         int count;
 110         int size;
 111         CallContext *traces;
 112 } TraceDesc;
 113
 114 typedef struct _ClassDesc ClassDesc;
 115 struct _ClassDesc {
 116         ClassDesc *next;
 117         intptr_t klass;
 118         char *name;
 119         intptr_t allocs;
 120         uint64_t alloc_size;
 121         TraceDesc traces;
 122 };
 123
 124 static ClassDesc* class_hash [HASH_SIZE] = {0};
 125 static int num_classes = 0;
 126
 127 static ClassDesc*
 128 add_class (intptr_t klass, const char *name)
 129 {
 130         int slot = ((klass >> 2) & 0xffff) % HASH_SIZE;
 131         ClassDesc *cd;
 132         cd = class_hash [slot];
 133         while (cd && cd->klass != klass)
 134                 cd = cd->next;
 135         /* we resolved an unknown class (unless we had the code unloaded) */
 136         if (cd) {
 137                 /*printf ("resolved unknown: %s\n", name);*/
 138                 free (cd->name);
 139                 cd->name = pstrdup (name);
 140                 return cd;
 141         }
 142         cd = calloc (sizeof (ClassDesc), 1);
 143         cd->klass = klass;
 144         cd->name = pstrdup (name);
 145         cd->next = class_hash [slot];
 146         cd->allocs = 0;
 147         cd->alloc_size = 0;
 148         cd->traces.count = 0;
 149         cd->traces.size = 0;
 150         cd->traces.traces = NULL;
 151         class_hash [slot] = cd;
 152         num_classes++;
 153         return cd;
 154 }
 155
 156 static ClassDesc *
 157 lookup_class (intptr_t klass)
 158 {
 159         int slot = ((klass >> 2) & 0xffff) % HASH_SIZE;
 160         ClassDesc *cd = class_hash [slot];
 161         while (cd && cd->klass != klass)
 162                 cd = cd->next;
 163         if (!cd)
 164                 return add_class (klass, "unresolved class");
 165         return cd;
 166 }
 167
 168 typedef struct _MethodDesc MethodDesc;
 169 struct _MethodDesc {
 170         MethodDesc *next;
 171         intptr_t method;
 172         char *name;
 173         intptr_t code;
 174         int len;
 175         int recurse_count;
 176         uint64_t calls;
 177         uint64_t total_time;
 178         uint64_t callee_time;
 179         uint64_t self_time;
 180         TraceDesc traces;
 181 };
 182
 183 static MethodDesc* method_hash [HASH_SIZE] = {0};
 184 static int num_methods = 0;
 185
 186 static MethodDesc*
 187 add_method (intptr_t method, const char *name, intptr_t code, int len)
 188 {
 189         int slot = ((method >> 2) & 0xffff) % HASH_SIZE;
 190         MethodDesc *cd;
 191         cd = method_hash [slot];
 192         while (cd && cd->method != method)
 193                 cd = cd->next;
 194         /* we resolved an unknown method (unless we had the code unloaded) */
 195         if (cd) {
 196                 cd->code = code;
 197                 cd->len = len;
 198                 /*printf ("resolved unknown: %s\n", name);*/
 199                 free (cd->name);
 200                 cd->name = pstrdup (name);
 201                 return cd;
 202         }
 203         cd = calloc (sizeof (MethodDesc), 1);
 204         cd->method = method;
 205         cd->name = pstrdup (name);
 206         cd->code = code;
 207         cd->len = len;
 208         cd->calls = 0;
 209         cd->total_time = 0;
 210         cd->traces.count = 0;
 211         cd->traces.size = 0;
 212         cd->traces.traces = NULL;
 213         cd->next = method_hash [slot];
 214         method_hash [slot] = cd;
 215         num_methods++;
 216         return cd;
 217 }
 218
 219 static MethodDesc *
 220 lookup_method (intptr_t method)
 221 {
 222         int slot = ((method >> 2) & 0xffff) % HASH_SIZE;
 223         MethodDesc *cd = method_hash [slot];
 224         while (cd && cd->method != method)
 225                 cd = cd->next;
 226         if (!cd)
 227                 return add_method (method, "unknown method", 0, 0);
 228         return cd;
 229 }
 230
 231 typedef struct {
 232         ClassDesc *klass;
 233         int64_t count;
 234         int64_t total_size;
 235 } HeapClassDesc;
 236
 237 typedef struct _HeapShot HeapShot;
 238 struct _HeapShot {
 239         HeapShot *next;
 240         uint64_t timestamp;
 241         int class_count;
 242         int hash_size;
 243         HeapClassDesc **class_hash;
 244         HeapClassDesc **sorted;
 245 };
 246
 247 static HeapShot *heap_shots = NULL;
 248 static HeapShot *current_heap_shot = NULL;
 249
 250 static HeapShot*
 251 new_heap_shot (uint64_t timestamp)
 252 {
 253         HeapShot *p;
 254         HeapShot *hs = calloc (sizeof (HeapShot), 1);
 255         hs->hash_size = 4;
 256         hs->class_hash = calloc (sizeof (void*), hs->hash_size);
 257         hs->timestamp = timestamp;
 258         /* append it to the list */
 259         p = heap_shots;
 260         while (p && p->next)
 261                 p = p->next;
 262         if (p)
 263                 p->next = hs;
 264         else
 265                 heap_shots = hs;
 266         return hs;
 267 }
 268
 269 static HeapClassDesc*
 270 heap_class_lookup (HeapShot *hs, ClassDesc *klass)
 271 {
 272         int i;
 273         unsigned int start_pos;
 274         start_pos = ((uintptr_t)klass->klass >> 2) % hs->hash_size;
 275         i = start_pos;
 276         do {
 277                 HeapClassDesc* cd = hs->class_hash [i];
 278                 if (!cd)
 279                         return NULL;
 280                 if (cd->klass == klass)
 281                         return cd;
 282                 /* wrap around */
 283                 if (++i == hs->hash_size)
 284                         i = 0;
 285         } while (i != start_pos);
 286         return NULL;
 287 }
 288
 289 static int
 290 add_heap_hashed (HeapClassDesc **hash, int hsize, ClassDesc *klass, uint64_t size, uint64_t count)
 291 {
 292         int i;
 293         unsigned int start_pos;
 294         start_pos = ((uintptr_t)klass->klass >> 2) % hsize;
 295         i = start_pos;
 296         do {
 297                 if (hash [i] && hash [i]->klass == klass) {
 298                         hash [i]->total_size += size;
 299                         hash [i]->count += count;
 300                         return 0;
 301                 } else if (!hash [i]) {
 302                         hash [i] = calloc (sizeof (HeapClassDesc), 1);
 303                         hash [i]->klass = klass;
 304                         hash [i]->total_size += size;
 305                         hash [i]->count += count;
 306                         return 1;
 307                 }
 308                 /* wrap around */
 309                 if (++i == hsize)
 310                         i = 0;
 311         } while (i != start_pos);
 312         /* should not happen */
 313         printf ("failed heap class store\n");
 314         return 0;
 315 }
 316
 317 static void
 318 add_heap_shot_obj (HeapShot *hs, ClassDesc *klass, uint64_t size)
 319 {
 320         int i;
 321         if (hs->class_count * 2 >= hs->hash_size) {
 322                 HeapClassDesc **n;
 323                 int old_size = hs->hash_size;
 324                 hs->hash_size *= 2;
 325                 if (hs->hash_size == 0)
 326                         hs->hash_size = 4;
 327                 n = calloc (sizeof (void*) * hs->hash_size, 1);
 328                 for (i = 0; i < old_size; ++i) {
 329                         if (hs->class_hash [i])
 330                                 add_heap_hashed (n, hs->hash_size, hs->class_hash [i]->klass, hs->class_hash [i]->total_size, hs->class_hash [i]->count);
 331                 }
 332                 if (hs->class_hash)
 333                         free (hs->class_hash);
 334                 hs->class_hash = n;
 335         }
 336         hs->class_count += add_heap_hashed (hs->class_hash, hs->hash_size, klass, size, 1);
 337 }
 338
 339 struct _BackTrace {
 340         BackTrace *next;
 341         unsigned int hash;
 342         int count;
 343         int id;
 344         MethodDesc *methods [1];
 345 };
 346
 347 static BackTrace *backtrace_hash [HASH_SIZE];
 348 static BackTrace **backtraces = NULL;
 349 static int num_backtraces = 0;
 350 static int next_backtrace = 0;
 351
 352 static int
 353 hash_backtrace (int count, MethodDesc **methods)
 354 {
 355         int hash = count;
 356         int i;
 357         for (i = 0; i < count; ++i) {
 358                 hash = (hash << 5) - hash + methods [i]->method;
 359         }
 360         return hash;
 361 }
 362
 363 static int
 364 compare_backtrace (BackTrace *bt, int count, MethodDesc **methods)
 365 {
 366         int i;
 367         if (bt->count != count)
 368                 return 0;
 369         for (i = 0; i < count; ++i)
 370                 if (methods [i] != bt->methods [i])
 371                         return 0;
 372         return 1;
 373 }
 374
 375 static BackTrace*
 376 add_backtrace (int count, MethodDesc **methods)
 377 {
 378         int hash = hash_backtrace (count, methods);
 379         int slot = (hash & 0xffff) % HASH_SIZE;
 380         BackTrace *bt = backtrace_hash [slot];
 381         while (bt) {
 382                 if (bt->hash == hash && compare_backtrace (bt, count, methods))
 383                         return bt;
 384                 bt = bt->next;
 385         }
 386         bt = malloc (sizeof (BackTrace) + ((count - 1) * sizeof (void*)));
 387         bt->next = backtrace_hash [slot];
 388         backtrace_hash [slot] = bt;
 389         if (next_backtrace == num_backtraces) {
 390                 num_backtraces *= 2;
 391                 if (!num_backtraces)
 392                         num_backtraces = 16;
 393                 backtraces = realloc (backtraces, sizeof (void*) * num_backtraces);
 394         }
 395         bt->id = next_backtrace++;
 396         backtraces [bt->id] = bt;
 397         bt->count = count;
 398         bt->hash = hash;
 399         for (slot = 0; slot < count; ++slot)
 400                 bt->methods [slot] = methods [slot];
 401
 402         return bt;
 403 }
 404
 405 typedef struct _MonitorDesc MonitorDesc;
 406 typedef struct _ThreadContext ThreadContext;
 407
 408 typedef struct {
 409         FILE *file;
 410 #if defined (HAVE_ZLIB)
 411         gzFile *gzfile;
 412 #endif
 413         unsigned char *buf;
 414         int size;
 415         int data_version;
 416         int version_major;
 417         int version_minor;
 418         int timer_overhead;
 419         uint64_t startup_time;
 420         ThreadContext *threads;
 421         ThreadContext *current;
 422 } ProfContext;
 423
 424 struct _ThreadContext {
 425         ThreadContext *next;
 426         intptr_t thread_id;
 427         /* emulated stack */
 428         MethodDesc **stack;
 429         uint64_t *time_stack;
 430         uint64_t *callee_time_stack;
 431         uint64_t last_time;
 432         uint64_t contention_start;
 433         MonitorDesc *monitor;
 434         int stack_size;
 435         int stack_id;
 436 };
 437
 438 static void
 439 ensure_buffer (ProfContext *ctx, int size)
 440 {
 441         if (ctx->size < size) {
 442                 ctx->buf = realloc (ctx->buf, size);
 443                 ctx->size = size;
 444         }
 445 }
 446
 447 static int
 448 load_data (ProfContext *ctx, int size)
 449 {
 450         ensure_buffer (ctx, size);
 451 #if defined (HAVE_ZLIB)
 452         if (ctx->gzfile)
 453                 return gzread (ctx->gzfile, ctx->buf, size) == size;
 454         else
 455 #endif
 456                 return fread (ctx->buf, size, 1, ctx->file);
 457 }
 458
 459 static ThreadContext*
 460 load_thread (ProfContext *ctx, intptr_t thread_id)
 461 {
 462         ThreadContext *thread;
 463         if (ctx->current && ctx->current->thread_id == thread_id)
 464                 return ctx->current;
 465         thread = ctx->threads;
 466         while (thread) {
 467                 if (thread->thread_id == thread_id) {
 468                         ctx->current = thread;
 469                         return thread;
 470                 }
 471                 thread = thread->next;
 472         }
 473         thread = calloc (sizeof (ThreadContext), 1);
 474         thread->next = ctx->threads;
 475         ctx->threads = thread;
 476         ctx->current = thread;
 477         thread->thread_id = thread_id;
 478         thread->last_time = 0;
 479         thread->stack_id = 0;
 480         thread->stack_size = 32;
 481         thread->stack = malloc (thread->stack_size * sizeof (void*));
 482         thread->time_stack = malloc (thread->stack_size * sizeof (uint64_t));
 483         thread->callee_time_stack = malloc (thread->stack_size * sizeof (uint64_t));
 484         return thread;
 485 }
 486
 487 static void
 488 ensure_thread_stack (ThreadContext *thread)
 489 {
 490         if (thread->stack_id == thread->stack_size) {
 491                 thread->stack_size *= 2;
 492                 thread->stack = realloc (thread->stack, thread->stack_size * sizeof (void*));
 493                 thread->time_stack = realloc (thread->time_stack, thread->stack_size * sizeof (uint64_t));
 494                 thread->callee_time_stack = realloc (thread->callee_time_stack, thread->stack_size * sizeof (uint64_t));
 495         }
 496 }
 497
 498 static int
 499 add_trace_hashed (CallContext *traces, int size, BackTrace *bt, uint64_t value)
 500 {
 501         int i;
 502         unsigned int start_pos;
 503         start_pos = bt->hash % size;
 504         i = start_pos;
 505         do {
 506                 if (traces [i].bt == bt) {
 507                         traces [i].count += value;
 508                         return 0;
 509                 } else if (!traces [i].bt) {
 510                         traces [i].bt = bt;
 511                         traces [i].count += value;
 512                         return 1;
 513                 }
 514                 /* wrap around */
 515                 if (++i == size)
 516                         i = 0;
 517         } while (i != start_pos);
 518         /* should not happen */
 519         printf ("failed trace store\n");
 520         return 0;
 521 }
 522
 523 static void
 524 add_trace_bt (BackTrace *bt, TraceDesc *trace, uint64_t value)
 525 {
 526         int i;
 527         if (!collect_traces)
 528                 return;
 529         if (trace->count * 2 >= trace->size) {
 530                 CallContext *n;
 531                 int old_size = trace->size;
 532                 trace->size *= 2;
 533                 if (trace->size == 0)
 534                         trace->size = 4;
 535                 n = calloc (sizeof (CallContext) * trace->size, 1);
 536                 for (i = 0; i < old_size; ++i) {
 537                         if (trace->traces [i].bt)
 538                                 add_trace_hashed (n, trace->size, trace->traces [i].bt, trace->traces [i].count);
 539                 }
 540                 if (trace->traces)
 541                         free (trace->traces);
 542                 trace->traces = n;
 543         }
 544         trace->count += add_trace_hashed (trace->traces, trace->size, bt, value);
 545 }
 546
 547 static BackTrace*
 548 add_trace_thread (ThreadContext *thread, TraceDesc *trace, uint64_t value)
 549 {
 550         BackTrace *bt;
 551         int count = thread->stack_id;
 552         if (!collect_traces)
 553                 return NULL;
 554         if (count > trace_max)
 555                 count = trace_max;
 556         bt = add_backtrace (count, thread->stack + thread->stack_id - count);
 557         add_trace_bt (bt, trace, value);
 558         return bt;
 559 }
 560
 561 static BackTrace*
 562 add_trace_methods (MethodDesc **methods, int count, TraceDesc *trace, uint64_t value)
 563 {
 564         BackTrace *bt;
 565         if (!collect_traces)
 566                 return NULL;
 567         if (count > trace_max)
 568                 count = trace_max;
 569         bt = add_backtrace (count, methods);
 570         add_trace_bt (bt, trace, value);
 571         return bt;
 572 }
 573
 574 static int
 575 compare_callc (const void *a, const void *b)
 576 {
 577         const CallContext *A = a;
 578         const CallContext *B = b;
 579         if (B->count == A->count)
 580                 return 0;
 581         if (B->count < A->count)
 582                 return -1;
 583         return 1;
 584 }
 585
 586 static void
 587 sort_context_array (TraceDesc* traces)
 588 {
 589         int i, j;
 590         for (i = 0, j = 0; i < traces->size; ++i) {
 591                 if (traces->traces [i].bt) {
 592                         traces->traces [j].bt = traces->traces [i].bt;
 593                         traces->traces [j].count = traces->traces [i].count;
 594                         j++;
 595                 }
 596         }
 597         qsort (traces->traces, traces->count, sizeof (CallContext), compare_callc);
 598 }
 599
 600 static void
 601 push_method (ThreadContext *thread, MethodDesc *method, uint64_t timestamp)
 602 {
 603         ensure_thread_stack (thread);
 604         thread->time_stack [thread->stack_id] = timestamp;
 605         thread->callee_time_stack [thread->stack_id] = 0;
 606         thread->stack [thread->stack_id++] = method;
 607         method->recurse_count++;
 608 }
 609
 610 static void
 611 pop_method (ThreadContext *thread, MethodDesc *method, uint64_t timestamp)
 612 {
 613         method->recurse_count--;
 614         if (thread->stack_id > 0 && thread->stack [thread->stack_id - 1] == method) {
 615                 uint64_t tdiff;
 616                 thread->stack_id--;
 617                 method->calls++;
 618                 if (timestamp < thread->time_stack [thread->stack_id])
 619                         fprintf (outfile, "time went backwards for %s\n", method->name);
 620                 tdiff = timestamp - thread->time_stack [thread->stack_id];
 621                 if (thread->callee_time_stack [thread->stack_id] > tdiff)
 622                         fprintf (outfile, "callee time bigger for %s\n", method->name);
 623                 method->self_time += tdiff - thread->callee_time_stack [thread->stack_id];
 624                 method->callee_time += thread->callee_time_stack [thread->stack_id];
 625                 if (thread->stack_id)
 626                         thread->callee_time_stack [thread->stack_id - 1] += tdiff;
 627                 //fprintf (outfile, "method %s took %d\n", method->name, (int)(tdiff/1000));
 628         } else {
 629                 fprintf (outfile, "unmatched leave at stack pos: %d for method %s\n", thread->stack_id, method->name);
 630         }
 631 }
 632
 633 typedef struct {
 634         uint64_t start_time; /* move this per-thread? */
 635         uint64_t total_time;
 636         uint64_t max_time;
 637         int count;
 638 } GCDesc;
 639 static GCDesc gc_info [3];
 640 static uint64_t max_heap_size;
 641 static uint64_t gc_object_moves;
 642 static int gc_resizes;
 643
 644 static const char*
 645 gc_event_name (int ev)
 646 {
 647         switch (ev) {
 648         case MONO_GC_EVENT_START: return "start";
 649         case MONO_GC_EVENT_MARK_START: return "mark start";
 650         case MONO_GC_EVENT_MARK_END: return "mark end";
 651         case MONO_GC_EVENT_RECLAIM_START: return "reclaim start";
 652         case MONO_GC_EVENT_RECLAIM_END: return "reclaim end";
 653         case MONO_GC_EVENT_END: return "end";
 654         case MONO_GC_EVENT_PRE_STOP_WORLD: return "pre stop";
 655         case MONO_GC_EVENT_POST_STOP_WORLD: return "post stop";
 656         case MONO_GC_EVENT_PRE_START_WORLD: return "pre start";
 657         case MONO_GC_EVENT_POST_START_WORLD: return "post start";
 658         default:
 659                 return "unknown";
 660         }
 661 }
 662
 663 static uint64_t clause_summary [MONO_EXCEPTION_CLAUSE_FAULT + 1];
 664 static uint64_t throw_count = 0;
 665 static TraceDesc exc_traces;
 666
 667 static const char*
 668 clause_name (int type)
 669 {
 670         switch (type) {
 671         case MONO_EXCEPTION_CLAUSE_NONE: return "catch";
 672         case MONO_EXCEPTION_CLAUSE_FILTER: return "filter";
 673         case MONO_EXCEPTION_CLAUSE_FINALLY: return "finally";
 674         case MONO_EXCEPTION_CLAUSE_FAULT: return "fault";
 675         default: return "invalid";
 676         }
 677 }
 678
 679 static uint64_t monitor_contention;
 680 static uint64_t monitor_failed;
 681 static uint64_t monitor_acquired;
 682
 683 struct _MonitorDesc {
 684         MonitorDesc *next;
 685         uintptr_t objid;
 686         uintptr_t contentions;
 687         uint64_t wait_time;
 688         uint64_t max_wait_time;
 689         TraceDesc traces;
 690 };
 691
 692 static MonitorDesc* monitor_hash [SMALL_HASH_SIZE] = {0};
 693 static int num_monitors = 0;
 694
 695 static MonitorDesc*
 696 lookup_monitor (uintptr_t objid)
 697 {
 698         int slot = ((objid >> 3) & 0xffff) % SMALL_HASH_SIZE;
 699         MonitorDesc *cd = monitor_hash [slot];
 700         while (cd && cd->objid != objid)
 701                 cd = cd->next;
 702         if (!cd) {
 703                 cd = calloc (sizeof (MonitorDesc), 1);
 704                 cd->objid = objid;
 705                 cd->next = monitor_hash [slot];
 706                 monitor_hash [slot] = cd;
 707                 num_monitors++;
 708         }
 709         return cd;
 710 }
 711
 712 static const char*
 713 monitor_ev_name (int ev)
 714 {
 715         switch (ev) {
 716         case MONO_PROFILER_MONITOR_CONTENTION: return "contended";
 717         case MONO_PROFILER_MONITOR_DONE: return "acquired";
 718         case MONO_PROFILER_MONITOR_FAIL: return "not taken";
 719         default: return "invalid";
 720         }
 721 }
 722
 723 static MethodDesc**
 724 decode_bt (MethodDesc** sframes, int *size, unsigned char *p, unsigned char **endp, intptr_t ptr_base)
 725 {
 726         MethodDesc **frames;
 727         int i;
 728         int flags = decode_uleb128 (p, &p);
 729         int count = decode_uleb128 (p, &p);
 730         if (flags != 0)
 731                 return NULL;
 732         if (count > *size)
 733                 frames = malloc (count * sizeof (void*));
 734         else
 735                 frames = sframes;
 736         for (i = 0; i < count; ++i) {
 737                 intptr_t ptrdiff = decode_sleb128 (p, &p);
 738                 frames [i] = lookup_method (ptr_base + ptrdiff);
 739         }
 740         *size = count;
 741         *endp = p;
 742         return frames;
 743 }
 744
 745 static void
 746 tracked_creation (uintptr_t obj, ClassDesc *cd, uint64_t size, BackTrace *bt, uint64_t timestamp)
 747 {
 748         int i;
 749         for (i = 0; i < num_tracked_objects; ++i) {
 750                 if (tracked_objects [i] != obj)
 751                         continue;
 752                 fprintf (outfile, "Object %p created (%s, %llu bytes) at %.3f secs.\n", (void*)obj, cd->name, size, (timestamp - startup_time)/1000000000.0);
 753                 if (bt && bt->count) {
 754                         int k;
 755                         for (k = 0; k < bt->count; ++k)
 756                                 fprintf (outfile, "\t%s\n", bt->methods [k]->name);
 757                 }
 758         }
 759 }
 760
 761 static void
 762 track_move (uintptr_t src, uintptr_t dst)
 763 {
 764         int i;
 765         for (i = 0; i < num_tracked_objects; ++i) {
 766                 if (tracked_objects [i] == src)
 767                         fprintf (outfile, "Object %p moved to %p\n", (void*)src, (void*)dst);
 768                 else if (tracked_objects [i] == dst)
 769                         fprintf (outfile, "Object %p moved from %p\n", (void*)dst, (void*)src);
 770         }
 771 }
 772
 773 static void
 774 track_obj_reference (uintptr_t obj, uintptr_t parent, ClassDesc *cd)
 775 {
 776         int i;
 777         for (i = 0; i < num_tracked_objects; ++i) {
 778                 if (tracked_objects [i] == obj)
 779                         fprintf (outfile, "Object %p referenced from %p (%s).\n", (void*)obj, (void*)parent, cd->name);
 780         }
 781 }
 782
 783 static void
 784 found_object (uintptr_t obj)
 785 {
 786         num_tracked_objects ++;
 787         tracked_objects = realloc (tracked_objects, num_tracked_objects * sizeof (tracked_objects [0]));
 788         tracked_objects [num_tracked_objects - 1] = obj;
 789 }
 790
 791 #define OBJ_ADDR(diff) ((obj_base + diff) << 3)
 792 #define LOG_TIME(base,diff) /*fprintf("outfile, time %llu + %llu near offset %d\n", base, diff, p - ctx->buf)*/
 793
 794 static int
 795 decode_buffer (ProfContext *ctx)
 796 {
 797         unsigned char *p;
 798         unsigned char *end;
 799         intptr_t thread_id;
 800         intptr_t ptr_base;
 801         intptr_t obj_base;
 802         intptr_t method_base;
 803         uint64_t time_base;
 804         uint64_t file_offset;
 805         int len, i;
 806         ThreadContext *thread;
 807
 808         file_offset = ftell (ctx->file);
 809         if (!load_data (ctx, 48))
 810                 return 0;
 811         p = ctx->buf;
 812         if (read_int32 (p) != BUF_ID)
 813                 return 0;
 814         len = read_int32 (p + 4);
 815         time_base = read_int64 (p + 8);
 816         ptr_base = read_int64 (p + 16);
 817         obj_base = read_int64 (p + 24);
 818         thread_id = read_int64 (p + 32);
 819         method_base = read_int64 (p + 40);
 820         if (debug)
 821                 fprintf (outfile, "buf: thread:%x, len: %d, time: %llu, file offset: %llu\n", thread_id, len, time_base, file_offset);
 822         thread = load_thread (ctx, thread_id);
 823         if (!load_data (ctx, len))
 824                 return 0;
 825         if (!startup_time) {
 826                 startup_time = time_base;
 827                 if (time_from) {
 828                         time_from += startup_time;
 829                         time_to += startup_time;
 830                 }
 831         }
 832         for (i = 0; i < thread->stack_id; ++i)
 833                 thread->stack [i]->recurse_count++;
 834         p = ctx->buf;
 835         end = p + len;
 836         while (p < end) {
 837                 switch (*p & 0xf) {
 838                 case TYPE_GC: {
 839                         int subtype = *p & 0xf0;
 840                         uint64_t tdiff = decode_uleb128 (p + 1, &p);
 841                         LOG_TIME (time_base, tdiff);
 842                         time_base += tdiff;
 843                         if (subtype == TYPE_GC_RESIZE) {
 844                                 uint64_t new_size = decode_uleb128 (p, &p);
 845                                 if (debug)
 846                                         fprintf (outfile, "gc heap resized to %llu\n", new_size);
 847                                 gc_resizes++;
 848                                 if (new_size > max_heap_size)
 849                                         max_heap_size = new_size;
 850                         } else if (subtype == TYPE_GC_EVENT) {
 851                                 uint64_t ev = decode_uleb128 (p, &p);
 852                                 int gen = decode_uleb128 (p, &p);
 853                                 if (debug)
 854                                         fprintf (outfile, "gc event for gen%d: %s at %llu\n", gen - 1, gc_event_name (ev), time_base);
 855                                 if (gen > 2) {
 856                                         fprintf (outfile, "incorrect gc gen: %d\n", gen);
 857                                         break;
 858                                 }
 859                                 if (ev == MONO_GC_EVENT_START) {
 860                                         gc_info [gen].start_time = time_base;
 861                                         gc_info [gen].count++;
 862                                 } else if (ev == MONO_GC_EVENT_END) {
 863                                         tdiff = time_base - gc_info [gen].start_time;
 864                                         gc_info [gen].total_time += tdiff;
 865                                         if (tdiff > gc_info [gen].max_time)
 866                                                 gc_info [gen].max_time = tdiff;
 867                                 }
 868                         } else if (subtype == TYPE_GC_MOVE) {
 869                                 int j, num = decode_uleb128 (p, &p);
 870                                 gc_object_moves += num / 2;
 871                                 for (j = 0; j < num; j += 2) {
 872                                         intptr_t obj1diff = decode_sleb128 (p, &p);
 873                                         intptr_t obj2diff = decode_sleb128 (p, &p);
 874                                         if (num_tracked_objects)
 875                                                 track_move (OBJ_ADDR (obj1diff), OBJ_ADDR (obj2diff));
 876                                         if (debug) {
 877                                                 fprintf (outfile, "moved obj %p to %p\n", (void*)OBJ_ADDR (obj1diff), (void*)OBJ_ADDR (obj2diff));
 878                                         }
 879                                 }
 880                         }
 881                         break;
 882                 }
 883                 case TYPE_METADATA: {
 884                         int error = *p & TYPE_LOAD_ERR;
 885                         uint64_t tdiff = decode_uleb128 (p + 1, &p);
 886                         int mtype = *p++;
 887                         intptr_t ptrdiff = decode_sleb128 (p, &p);
 888                         LOG_TIME (time_base, tdiff);
 889                         time_base += tdiff;
 890                         if (mtype == TYPE_CLASS) {
 891                                 intptr_t imptrdiff = decode_sleb128 (p, &p);
 892                                 uint64_t flags = decode_uleb128 (p, &p);
 893                                 if (flags) {
 894                                         fprintf (outfile, "non-zero flags in class\n");
 895                                         return 0;
 896                                 }
 897                                 if (debug)
 898                                         fprintf (outfile, "loaded class %p (%s in %p) at %llu\n", (void*)(ptr_base + ptrdiff), p, (void*)(ptr_base + imptrdiff), time_base);
 899                                 if (!error)
 900                                         add_class (ptr_base + ptrdiff, (char*)p);
 901                                 while (*p) p++;
 902                                 p++;
 903                         } else if (mtype == TYPE_IMAGE) {
 904                                 uint64_t flags = decode_uleb128 (p, &p);
 905                                 if (flags) {
 906                                         fprintf (outfile, "non-zero flags in image\n");
 907                                         return 0;
 908                                 }
 909                                 if (debug)
 910                                         fprintf (outfile, "loaded image %p (%s) at %llu\n", (void*)(ptr_base + ptrdiff), p, time_base);
 911                                 if (!error)
 912                                         add_image (ptr_base + ptrdiff, (char*)p);
 913                                 while (*p) p++;
 914                                 p++;
 915                         }
 916                         break;
 917                 }
 918                 case TYPE_ALLOC: {
 919                         int has_bt = *p & TYPE_ALLOC_BT;
 920                         uint64_t tdiff = decode_uleb128 (p + 1, &p);
 921                         intptr_t ptrdiff = decode_sleb128 (p, &p);
 922                         intptr_t objdiff = decode_sleb128 (p, &p);
 923                         uint64_t len;
 924                         int num_bt = 0;
 925                         MethodDesc* sframes [8];
 926                         MethodDesc** frames = sframes;
 927                         ClassDesc *cd = lookup_class (ptr_base + ptrdiff);
 928                         len = decode_uleb128 (p, &p);
 929                         LOG_TIME (time_base, tdiff);
 930                         time_base += tdiff;
 931                         if (debug)
 932                                 fprintf (outfile, "alloced object %p, size %llu (%s) at %llu\n", (void*)OBJ_ADDR (objdiff), len, lookup_class (ptr_base + ptrdiff)->name, time_base);
 933                         if (has_bt) {
 934                                 num_bt = 8;
 935                                 frames = decode_bt (sframes, &num_bt, p, &p, ptr_base);
 936                                 if (!frames) {
 937                                         fprintf (outfile, "Cannot load backtrace\n");
 938                                         return 0;
 939                                 }
 940                         }
 941                         if ((thread_filter && thread_filter == thread->thread_id) || (time_base >= time_from && time_base < time_to)) {
 942                                 BackTrace *bt;
 943                                 cd->allocs++;
 944                                 cd->alloc_size += len;
 945                                 if (has_bt)
 946                                         bt = add_trace_methods (frames, num_bt, &cd->traces, len);
 947                                 else
 948                                         bt = add_trace_thread (thread, &cd->traces, len);
 949                                 if (find_size && len >= find_size) {
 950                                         if (!find_name || strstr (cd->name, find_name))
 951                                                 found_object (OBJ_ADDR (objdiff));
 952                                 } else if (!find_size && find_name && strstr (cd->name, find_name)) {
 953                                         found_object (OBJ_ADDR (objdiff));
 954                                 }
 955                                 if (num_tracked_objects)
 956                                         tracked_creation (OBJ_ADDR (objdiff), cd, len, bt, time_base);
 957                         }
 958                         if (frames != sframes)
 959                                 free (frames);
 960                         break;
 961                 }
 962                 case TYPE_METHOD: {
 963                         int subtype = *p & 0xf0;
 964                         uint64_t tdiff = decode_uleb128 (p + 1, &p);
 965                         int64_t ptrdiff = decode_sleb128 (p, &p);
 966                         LOG_TIME (time_base, tdiff);
 967                         time_base += tdiff;
 968                         method_base += ptrdiff;
 969                         if (subtype == TYPE_JIT) {
 970                                 intptr_t codediff = decode_sleb128 (p, &p);
 971                                 int codelen = decode_uleb128 (p, &p);
 972                                 if (debug)
 973                                         fprintf (outfile, "jitted method %p (%s), size: %d\n", (void*)(method_base), p, codelen);
 974                                 add_method (method_base, (char*)p, ptr_base + codediff, codelen);
 975                                 while (*p) p++;
 976                                 p++;
 977                         } else {
 978                                 MethodDesc *method;
 979                                 if ((thread_filter && thread_filter != thread->thread_id))
 980                                         break;
 981                                 method = lookup_method (method_base);
 982                                 if (subtype == TYPE_ENTER) {
 983                                         add_trace_thread (thread, &method->traces, 1);
 984                                         push_method (thread, method, time_base);
 985                                 } else {
 986                                         pop_method (thread, method, time_base);
 987                                 }
 988                                 if (debug)
 989                                         fprintf (outfile, "%s method %s\n", subtype == TYPE_ENTER? "enter": subtype == TYPE_EXC_LEAVE? "exleave": "leave", method->name);
 990                         }
 991                         break;
 992                 }
 993                 case TYPE_HEAP: {
 994                         int subtype = *p & 0xf0;
 995                         if (subtype == TYPE_HEAP_OBJECT) {
 996                                 int i;
 997                                 intptr_t objdiff = decode_sleb128 (p + 1, &p);
 998                                 intptr_t ptrdiff = decode_sleb128 (p, &p);
 999                                 uint64_t size = decode_uleb128 (p, &p);
1000                                 int num = decode_uleb128 (p, &p);
1001                                 ClassDesc *cd = lookup_class (ptr_base + ptrdiff);
1002                                 for (i = 0; i < num; ++i) {
1003                                         /* FIXME: use object distance to measure how good
1004                                          * the GC is at keeping related objects close
1005                                          */
1006                                         intptr_t obj1diff = decode_sleb128 (p, &p);
1007                                         if (num_tracked_objects)
1008                                                 track_obj_reference (OBJ_ADDR (obj1diff), OBJ_ADDR (objdiff), cd);
1009                                 }
1010                                 if (debug && size)
1011                                         fprintf (outfile, "traced object %p, size %llu (%s), refs: %d\n", (void*)OBJ_ADDR (objdiff), size, cd->name, num);
1012                                 if (size)
1013                                         add_heap_shot_obj (current_heap_shot, cd, size);
1014                         } else if (subtype == TYPE_HEAP_END) {
1015                                 uint64_t tdiff = decode_uleb128 (p + 1, &p);
1016                                 LOG_TIME (time_base, tdiff);
1017                                 time_base += tdiff;
1018                                 if (debug)
1019                                         fprintf (outfile, "heap shot end\n");
1020                                 current_heap_shot = NULL;
1021                         } else if (subtype == TYPE_HEAP_START) {
1022                                 uint64_t tdiff = decode_uleb128 (p + 1, &p);
1023                                 LOG_TIME (time_base, tdiff);
1024                                 time_base += tdiff;
1025                                 if (debug)
1026                                         fprintf (outfile, "heap shot start\n");
1027                                 current_heap_shot = new_heap_shot (time_base);
1028                         }
1029                         break;
1030                 }
1031                 case TYPE_MONITOR: {
1032                         int event = (*p >> 4) & 0x3;
1033                         int has_bt = *p & TYPE_MONITOR_BT;
1034                         uint64_t tdiff = decode_uleb128 (p + 1, &p);
1035                         intptr_t objdiff = decode_sleb128 (p, &p);
1036                         MethodDesc* sframes [8];
1037                         MethodDesc** frames = sframes;
1038                         int record;
1039                         int num_bt = 0;
1040                         LOG_TIME (time_base, tdiff);
1041                         time_base += tdiff;
1042                         record = (!thread_filter || thread_filter == thread->thread_id);
1043                         if (event == MONO_PROFILER_MONITOR_CONTENTION) {
1044                                 MonitorDesc *mdesc = lookup_monitor (OBJ_ADDR (objdiff));
1045                                 if (record) {
1046                                         monitor_contention++;
1047                                         mdesc->contentions++;
1048                                         thread->monitor = mdesc;
1049                                         thread->contention_start = time_base;
1050                                 }
1051                                 if (has_bt) {
1052                                         num_bt = 8;
1053                                         frames = decode_bt (sframes, &num_bt, p, &p, ptr_base);
1054                                         if (!frames) {
1055                                                 fprintf (outfile, "Cannot load backtrace\n");
1056                                                 return 0;
1057                                         }
1058                                         if (record)
1059                                                 add_trace_methods (frames, num_bt, &mdesc->traces, 1);
1060                                 } else {
1061                                         if (record)
1062                                                 add_trace_thread (thread, &mdesc->traces, 1);
1063                                 }
1064                         } else if (event == MONO_PROFILER_MONITOR_FAIL) {
1065                                 if (record) {
1066                                         monitor_failed++;
1067                                         if (thread->monitor && thread->contention_start) {
1068                                                 uint64_t wait_time = time_base - thread->contention_start;
1069                                                 if (wait_time > thread->monitor->max_wait_time)
1070                                                         thread->monitor->max_wait_time = wait_time;
1071                                                 thread->monitor->wait_time += wait_time;
1072                                                 thread->monitor = NULL;
1073                                                 thread->contention_start = 0;
1074                                         }
1075                                 }
1076                         } else if (event == MONO_PROFILER_MONITOR_DONE) {
1077                                 if (record) {
1078                                         monitor_acquired++;
1079                                         if (thread->monitor && thread->contention_start) {
1080                                                 uint64_t wait_time = time_base - thread->contention_start;
1081                                                 if (wait_time > thread->monitor->max_wait_time)
1082                                                         thread->monitor->max_wait_time = wait_time;
1083                                                 thread->monitor->wait_time += wait_time;
1084                                                 thread->monitor = NULL;
1085                                                 thread->contention_start = 0;
1086                                         }
1087                                 }
1088                         }
1089                         if (debug)
1090                                 fprintf (outfile, "monitor %s for object %p\n", monitor_ev_name (event), (void*)OBJ_ADDR (objdiff));
1091                         if (frames != sframes)
1092                                 free (frames);
1093                         break;
1094                 }
1095                 case TYPE_EXCEPTION: {
1096                         int subtype = *p & 0x70;
1097                         int has_bt = *p & TYPE_EXCEPTION_BT;
1098                         uint64_t tdiff = decode_uleb128 (p + 1, &p);
1099                         MethodDesc* sframes [8];
1100                         MethodDesc** frames = sframes;
1101                         int record;
1102                         LOG_TIME (time_base, tdiff);
1103                         time_base += tdiff;
1104                         record = (!thread_filter || thread_filter == thread->thread_id);
1105                         if (subtype == TYPE_CLAUSE) {
1106                                 int clause_type = decode_uleb128 (p, &p);
1107                                 int clause_num = decode_uleb128 (p, &p);
1108                                 int64_t ptrdiff = decode_sleb128 (p, &p);
1109                                 method_base += ptrdiff;
1110                                 if (record)
1111                                         clause_summary [clause_type]++;
1112                                 if (debug)
1113                                         fprintf (outfile, "clause %s (%d) in method %s\n", clause_name (clause_type), clause_num, lookup_method (method_base)->name);
1114                         } else {
1115                                 intptr_t objdiff = decode_sleb128 (p, &p);
1116                                 if (record)
1117                                         throw_count++;
1118                                 if (has_bt) {
1119                                         has_bt = 8;
1120                                         frames = decode_bt (sframes, &has_bt, p, &p, ptr_base);
1121                                         if (!frames) {
1122                                                 fprintf (outfile, "Cannot load backtrace\n");
1123                                                 return 0;
1124                                         }
1125                                         if (record)
1126                                                 add_trace_methods (frames, has_bt, &exc_traces, 1);
1127                                 } else {
1128                                         if (record)
1129                                                 add_trace_thread (thread, &exc_traces, 1);
1130                                 }
1131                                 if (frames != sframes)
1132                                         free (frames);
1133                                 if (debug)
1134                                         fprintf (outfile, "throw %p\n", (void*)OBJ_ADDR (objdiff));
1135                         }
1136                         break;
1137                 }
1138                 default:
1139                         fprintf (outfile, "unhandled profiler event: 0x%x\n", *p);
1140                         exit (1);
1141                 }
1142         }
1143         thread->last_time = time_base;
1144         for (i = 0; i < thread->stack_id; ++i)
1145                 thread->stack [i]->recurse_count = 0;
1146         return 1;
1147 }
1148
1149 static ProfContext*
1150 load_file (char *name)
1151 {
1152         unsigned char *p;
1153         ProfContext *ctx = calloc (sizeof (ProfContext), 1);
1154         if (strcmp (name, "-") == 0)
1155                 ctx->file = stdin;
1156         else
1157                 ctx->file = fopen (name, "rb");
1158         if (!ctx->file) {
1159                 printf ("Cannot open file: %s\n", name);
1160                 exit (1);
1161         }
1162 #if defined (HAVE_ZLIB)
1163         ctx->gzfile = gzdopen (fileno (ctx->file), "rb");
1164 #endif
1165         if (!load_data (ctx, 32))
1166                 return NULL;
1167         p = ctx->buf;
1168         if (read_int32 (p) != LOG_HEADER_ID || p [6] != LOG_DATA_VERSION)
1169                 return NULL;
1170         ctx->version_major = p [4];
1171         ctx->version_minor = p [5];
1172         ctx->data_version = p [6];
1173         /* reading 64 bit files on 32 bit systems not supported yet */
1174         if (p [7] > sizeof (void*))
1175                 return NULL;
1176         if (read_int32 (p + 20)) /* flags must be 0 */
1177                 return NULL;
1178         ctx->startup_time = read_int64 (p + 8);
1179         ctx->timer_overhead = read_int32 (p + 16);
1180         return ctx;
1181 }
1182
1183 enum {
1184         ALLOC_SORT_BYTES,
1185         ALLOC_SORT_COUNT
1186 };
1187 static int alloc_sort_mode = ALLOC_SORT_BYTES;
1188
1189 static int
1190 compare_class (const void *a, const void *b)
1191 {
1192         ClassDesc *const*A = a;
1193         ClassDesc *const*B = b;
1194         uint64_t vala, valb;
1195         if (alloc_sort_mode == ALLOC_SORT_BYTES) {
1196                 vala = (*A)->alloc_size;
1197                 valb = (*B)->alloc_size;
1198         } else {
1199                 vala = (*A)->allocs;
1200                 valb = (*B)->allocs;
1201         }
1202         if (valb == vala)
1203                 return 0;
1204         if (valb < vala)
1205                 return -1;
1206         return 1;
1207 }
1208
1209 static void
1210 dump_header (ProfContext *ctx)
1211 {
1212         time_t st = ctx->startup_time / 1000;
1213         char *t = ctime (&st);
1214         fprintf (outfile, "\nMono log profiler data\n");
1215         fprintf (outfile, "\tProfiler version: %d.%d\n", ctx->version_major, ctx->version_minor);
1216         fprintf (outfile, "\tData version: %d\n", ctx->data_version);
1217         fprintf (outfile, "\tMean timer overhead: %d nanoseconds\n", ctx->timer_overhead);
1218         fprintf (outfile, "\tProgram startup: %s\n", t);
1219 }
1220
1221 static void
1222 dump_traces (TraceDesc *traces, const char *desc)
1223 {
1224         int j;
1225         if (!show_traces)
1226                 return;
1227         if (!traces->count)
1228                 return;
1229         sort_context_array (traces);
1230         for (j = 0; j < traces->count; ++j) {
1231                 int k;
1232                 BackTrace *bt;
1233                 bt = traces->traces [j].bt;
1234                 if (!bt->count)
1235                         continue;
1236                 fprintf (outfile, "\t%llu %s from:\n", traces->traces [j].count, desc);
1237                 for (k = 0; k < bt->count; ++k)
1238                         fprintf (outfile, "\t\t%s\n", bt->methods [k]->name);
1239         }
1240 }
1241
1242 static void
1243 dump_threads (ProfContext *ctx)
1244 {
1245         ThreadContext *thread;
1246         fprintf (outfile, "\nThread summary\n");
1247         for (thread = ctx->threads; thread; thread = thread->next) {
1248                 fprintf (outfile, "\tThread: %p\n", (void*)thread->thread_id);
1249         }
1250 }
1251
1252 static void
1253 dump_exceptions (void)
1254 {
1255         int i;
1256         fprintf (outfile, "\nException summary\n");
1257         fprintf (outfile, "\tThrows: %llu\n", throw_count);
1258         dump_traces (&exc_traces, "throws");
1259         for (i = 0; i <= MONO_EXCEPTION_CLAUSE_FAULT; ++i) {
1260                 if (!clause_summary [i])
1261                         continue;
1262                 fprintf (outfile, "\tExecuted %s clauses: %llu\n", clause_name (i), clause_summary [i]);
1263         }
1264 }
1265
1266 static int
1267 compare_monitor (const void *a, const void *b)
1268 {
1269         MonitorDesc *const*A = a;
1270         MonitorDesc *const*B = b;
1271         if ((*B)->wait_time == (*A)->wait_time)
1272                 return 0;
1273         if ((*B)->wait_time < (*A)->wait_time)
1274                 return -1;
1275         return 1;
1276 }
1277
1278 static void
1279 dump_monitors (void)
1280 {
1281         MonitorDesc **monitors;
1282         int i, j;
1283         if (!num_monitors)
1284                 return;
1285         monitors = malloc (sizeof (void*) * num_monitors);
1286         for (i = 0, j = 0; i < SMALL_HASH_SIZE; ++i) {
1287                 MonitorDesc *mdesc = monitor_hash [i];
1288                 while (mdesc) {
1289                         monitors [j++] = mdesc;
1290                         mdesc = mdesc->next;
1291                 }
1292         }
1293         qsort (monitors, num_monitors, sizeof (void*), compare_monitor);
1294         fprintf (outfile, "\nMonitor lock summary\n");
1295         for (i = 0; i < num_monitors; ++i) {
1296                 MonitorDesc *mdesc = monitors [i];
1297                 fprintf (outfile, "\tLock object %p: %d contentions\n", (void*)mdesc->objid, (int)mdesc->contentions);
1298                 fprintf (outfile, "\t\t%.6f secs total wait time, %.6f max, %.6f average\n",
1299                         mdesc->wait_time/1000000000.0, mdesc->max_wait_time/1000000000.0, mdesc->wait_time/1000000000.0/mdesc->contentions);
1300                 dump_traces (&mdesc->traces, "contentions");
1301         }
1302         fprintf (outfile, "\tLock contentions: %llu\n", monitor_contention);
1303         fprintf (outfile, "\tLock acquired: %llu\n", monitor_acquired);
1304         fprintf (outfile, "\tLock failures: %llu\n", monitor_failed);
1305 }
1306
1307 static void
1308 dump_gcs (void)
1309 {
1310         int i;
1311         fprintf (outfile, "\nGC summary\n");
1312         fprintf (outfile, "\tGC resizes: %d\n", gc_resizes);
1313         fprintf (outfile, "\tMax heap size: %llu\n", max_heap_size);
1314         fprintf (outfile, "\tObject moves: %llu\n", gc_object_moves);
1315         for (i = 0; i < 3; ++i) {
1316                 if (!gc_info [i].count)
1317                         continue;
1318                 fprintf (outfile, "\tGen%d collections: %d, max time: %lluus, total time: %lluus, average: %lluus\n",
1319                         i, gc_info [i].count, gc_info [i].max_time / 1000, gc_info [i].total_time / 1000,
1320                         gc_info [i].total_time / gc_info [i].count / 1000);
1321         }
1322 }
1323
1324 static void
1325 dump_allocations (void)
1326 {
1327         int i, c;
1328         intptr_t allocs = 0;
1329         uint64_t size = 0;
1330         int header_done = 0;
1331         ClassDesc **classes = malloc (num_classes * sizeof (void*));
1332         ClassDesc *cd;
1333         c = 0;
1334         for (i = 0; i < HASH_SIZE; ++i) {
1335                 cd = class_hash [i];
1336                 while (cd) {
1337                         classes [c++] = cd;
1338                         cd = cd->next;
1339                 }
1340         }
1341         qsort (classes, num_classes, sizeof (void*), compare_class);
1342         for (i = 0; i < num_classes; ++i) {
1343                 cd = classes [i];
1344                 if (!cd->allocs)
1345                         continue;
1346                 allocs += cd->allocs;
1347                 size += cd->alloc_size;
1348                 if (!header_done++) {
1349                         fprintf (outfile, "\nAllocation summary\n");
1350                         fprintf (outfile, "%10s %10s %8s Type name\n", "Bytes", "Count", "Average");
1351                 }
1352                 fprintf (outfile, "%10llu %10d %8llu %s\n", cd->alloc_size, cd->allocs, cd->alloc_size / cd->allocs, cd->name);
1353                 dump_traces (&cd->traces, "bytes");
1354         }
1355         if (allocs)
1356                 fprintf (outfile, "Total memory allocated: %llu bytes in %d objects\n", size, allocs);
1357 }
1358
1359 enum {
1360         METHOD_SORT_TOTAL,
1361         METHOD_SORT_SELF,
1362         METHOD_SORT_CALLS
1363 };
1364
1365 static int method_sort_mode = METHOD_SORT_TOTAL;
1366
1367 static int
1368 compare_method (const void *a, const void *b)
1369 {
1370         MethodDesc *const*A = a;
1371         MethodDesc *const*B = b;
1372         uint64_t vala, valb;
1373         if (method_sort_mode == METHOD_SORT_SELF) {
1374                 vala = (*A)->self_time;
1375                 valb = (*B)->self_time;
1376         } else if (method_sort_mode == METHOD_SORT_CALLS) {
1377                 vala = (*A)->calls;
1378                 valb = (*B)->calls;
1379         } else {
1380                 vala = (*A)->total_time;
1381                 valb = (*B)->total_time;
1382         }
1383         if (vala == valb)
1384                 return 0;
1385         if (valb < vala)
1386                 return -1;
1387         return 1;
1388 }
1389
1390 static void
1391 dump_metadata (void)
1392 {
1393         fprintf (outfile, "\nMetadata summary\n");
1394         fprintf (outfile, "\tLoaded images: %d\n", num_images);
1395         if (verbose) {
1396                 ImageDesc *image;
1397                 int i;
1398                 for (i = 0; i < SMALL_HASH_SIZE; ++i) {
1399                         image = image_hash [i];
1400                         while (image) {
1401                                 fprintf (outfile, "\t\t%s\n", image->filename);
1402                                 image = image->next;
1403                         }
1404                 }
1405         }
1406
1407 }
1408
1409 static void
1410 dump_methods (void)
1411 {
1412         int i, c;
1413         uint64_t calls = 0;
1414         int header_done = 0;
1415         MethodDesc **methods = malloc (num_methods * sizeof (void*));
1416         MethodDesc *cd;
1417         c = 0;
1418         for (i = 0; i < HASH_SIZE; ++i) {
1419                 cd = method_hash [i];
1420                 while (cd) {
1421                         cd->total_time = cd->self_time + cd->callee_time;
1422                         methods [c++] = cd;
1423                         cd = cd->next;
1424                 }
1425         }
1426         qsort (methods, num_methods, sizeof (void*), compare_method);
1427         for (i = 0; i < num_methods; ++i) {
1428                 uint64_t msecs;
1429                 uint64_t smsecs;
1430                 cd = methods [i];
1431                 if (!cd->calls)
1432                         continue;
1433                 calls += cd->calls;
1434                 msecs = cd->total_time / 1000000;
1435                 smsecs = (cd->total_time - cd->callee_time) / 1000000;
1436                 if (!msecs && !verbose)
1437                         continue;
1438                 if (!header_done++) {
1439                         fprintf (outfile, "\nMethod call summary\n");
1440                         fprintf (outfile, "%8s %8s %10s Method name\n", "Total(ms)", "Self(ms)", "Calls");
1441                 }
1442                 fprintf (outfile, "%8llu %8llu %10llu %s\n", msecs, smsecs, cd->calls, cd->name);
1443                 dump_traces (&cd->traces, "calls");
1444         }
1445         if (calls)
1446                 fprintf (outfile, "Total calls: %llu\n", calls);
1447 }
1448
1449 static int
1450 compare_heap_class (const void *a, const void *b)
1451 {
1452         HeapClassDesc *const*A = a;
1453         HeapClassDesc *const*B = b;
1454         uint64_t vala, valb;
1455         if (alloc_sort_mode == ALLOC_SORT_BYTES) {
1456                 vala = (*A)->total_size;
1457                 valb = (*B)->total_size;
1458         } else {
1459                 vala = (*A)->count;
1460                 valb = (*B)->count;
1461         }
1462         if (valb == vala)
1463                 return 0;
1464         if (valb < vala)
1465                 return -1;
1466         return 1;
1467 }
1468
1469 static void
1470 heap_shot_summary (HeapShot *hs, int hs_num, HeapShot *last_hs)
1471 {
1472         uint64_t size = 0;
1473         uint64_t count = 0;
1474         int ccount = 0;
1475         int i;
1476         HeapClassDesc *cd;
1477         HeapClassDesc **sorted;
1478         sorted = malloc (sizeof (void*) * hs->class_count);
1479         for (i = 0; i < hs->hash_size; ++i) {
1480                 cd = hs->class_hash [i];
1481                 if (!cd)
1482                         continue;
1483                 count += cd->count;
1484                 size += cd->total_size;
1485                 sorted [ccount++] = cd;
1486         }
1487         hs->sorted = sorted;
1488         qsort (sorted, ccount, sizeof (void*), compare_heap_class);
1489         fprintf (outfile, "\n\tHeap shot %d at %.3f secs: size: %llu, object count: %llu, class count: %d\n",
1490                 hs_num, (hs->timestamp - startup_time)/1000000000.0, size, count, ccount);
1491         if (!verbose && ccount > 30)
1492                 ccount = 30;
1493         fprintf (outfile, "\t%10s %10s %8s Class name\n", "Bytes", "Count", "Average");
1494         for (i = 0; i < ccount; ++i) {
1495                 HeapClassDesc *ocd = NULL;
1496                 cd = sorted [i];
1497                 if (last_hs)
1498                         ocd = heap_class_lookup (last_hs, cd->klass);
1499                 fprintf (outfile, "\t%10llu %10llu %8llu %s", cd->total_size, cd->count, cd->total_size / cd->count, cd->klass->name);
1500                 if (ocd) {
1501                         int64_t bdiff = cd->total_size - ocd->total_size;
1502                         int64_t cdiff = cd->count - ocd->count;
1503                         fprintf (outfile, " (bytes: %+lld, count: %+lld)\n", bdiff, cdiff);
1504                 } else {
1505                         fprintf (outfile, "\n");
1506                 }
1507         }
1508 }
1509
1510 static void
1511 dump_heap_shots (void)
1512 {
1513         HeapShot *hs;
1514         HeapShot *last_hs = NULL;
1515         int i;
1516         if (!heap_shots)
1517                 return;
1518         fprintf (outfile, "\nHeap shot summary\n");
1519         i = 0;
1520         for (hs = heap_shots; hs; hs = hs->next) {
1521                 heap_shot_summary (hs, i++, last_hs);
1522                 last_hs = hs;
1523         }
1524 }
1525
1526 static void
1527 flush_context (ProfContext *ctx)
1528 {
1529         ThreadContext *thread;
1530         /* FIXME: sometimes there are leftovers: indagate */
1531         for (thread = ctx->threads; thread; thread = thread->next) {
1532                 while (thread->stack_id) {
1533                         if (debug)
1534                                 fprintf (outfile, "thread %p has %d items on stack\n", (void*)thread->thread_id, thread->stack_id);
1535                         pop_method (thread, thread->stack [thread->stack_id - 1], thread->last_time);
1536                 }
1537         }
1538 }
1539
1540 static const char *reports = "header,gc,alloc,call,metadata,exception,monitor,thread,heapshot";
1541
1542 static const char*
1543 match_option (const char *p, const char *opt)
1544 {
1545         int len = strlen (opt);
1546         if (strncmp (p, opt, len) == 0) {
1547                 if (p [len] == ',')
1548                         len++;
1549                 return p + len;
1550         }
1551         return p;
1552 }
1553
1554 static int
1555 print_reports (ProfContext *ctx, const char *reps, int parse_only)
1556 {
1557         const char *opt;
1558         const char *p;
1559         for (p = reps; *p; p = opt) {
1560                 if ((opt = match_option (p, "header")) != p) {
1561                         if (!parse_only)
1562                                 dump_header (ctx);
1563                         continue;
1564                 }
1565                 if ((opt = match_option (p, "thread")) != p) {
1566                         if (!parse_only)
1567                                 dump_threads (ctx);
1568                         continue;
1569                 }
1570                 if ((opt = match_option (p, "gc")) != p) {
1571                         if (!parse_only)
1572                                 dump_gcs ();
1573                         continue;
1574                 }
1575                 if ((opt = match_option (p, "alloc")) != p) {
1576                         if (!parse_only)
1577                                 dump_allocations ();
1578                         continue;
1579                 }
1580                 if ((opt = match_option (p, "call")) != p) {
1581                         if (!parse_only)
1582                                 dump_methods ();
1583                         continue;
1584                 }
1585                 if ((opt = match_option (p, "metadata")) != p) {
1586                         if (!parse_only)
1587                                 dump_metadata ();
1588                         continue;
1589                 }
1590                 if ((opt = match_option (p, "exception")) != p) {
1591                         if (!parse_only)
1592                                 dump_exceptions ();
1593                         continue;
1594                 }
1595                 if ((opt = match_option (p, "monitor")) != p) {
1596                         if (!parse_only)
1597                                 dump_monitors ();
1598                         continue;
1599                 }
1600                 if ((opt = match_option (p, "heapshot")) != p) {
1601                         if (!parse_only)
1602                                 dump_heap_shots ();
1603                         continue;
1604                 }
1605                 return 0;
1606         }
1607         return 1;
1608 }
1609
1610 static int
1611 add_find_spec (const char *p)
1612 {
1613         if (p [0] == 'S' && p [1] == ':') {
1614                 char *vale;
1615                 find_size = strtoul (p + 2, &vale, 10);
1616                 return 1;
1617         } else if (p [0] == 'T' && p [1] == ':') {
1618                 find_name = p + 2;
1619                 return 1;
1620         }
1621         return 0;
1622 }
1623
1624 static void
1625 usage (void)
1626 {
1627         printf ("Mono log profiler report version %d.%d\n", LOG_VERSION_MAJOR, LOG_VERSION_MINOR);
1628         printf ("Usage: mprof-report [OPTIONS] FILENAME\n");
1629         printf ("FILENAME can be '-' to read from standard input.\n");
1630         printf ("Options:\n");
1631         printf ("\t--help               display this help\n");
1632         printf ("\t--out=FILE           write to FILE instead of stdout\n");
1633         printf ("\t--traces             collect and show backtraces\n");
1634         printf ("\t--maxframes=NUM      limit backtraces to NUM entries\n");
1635         printf ("\t--reports=R1[,R2...] print the specified reports. Defaults are:\n");
1636         printf ("\t                     %s\n", reports);
1637         printf ("\t--method-sort=MODE   sort methods according to MODE: total, self, calls\n");
1638         printf ("\t--alloc-sort=MODE    sort allocations according to MODE: bytes, count\n");
1639         printf ("\t--track=OB1[,OB2...] track what happens to objects OBJ1, O2 etc.\n");
1640         printf ("\t--find=FINDSPEC      find and track objects matching FINFSPEC, where FINDSPEC is:\n");
1641         printf ("\t                     S:minimum_size or T:partial_name\n");
1642         printf ("\t--thread=THREADID    consider just the data for thread THREADID\n");
1643         printf ("\t--time=FROM-TO       consider data FROM seconds from startup up to TO seconds\n");
1644         printf ("\t--verbose            increase verbosity level\n");
1645         printf ("\t--debug              display decoding debug info for mprof-report devs\n");
1646 }
1647
1648 int
1649 main (int argc, char *argv[])
1650 {
1651         ProfContext *ctx;
1652         int i;
1653         outfile = stdout;
1654         for (i = 1; i < argc; ++i) {
1655                 if (strcmp ("--debug", argv [i]) == 0) {
1656                         debug++;
1657                 } else if (strcmp ("--help", argv [i]) == 0) {
1658                         usage ();
1659                         return 0;
1660                 } else if (strncmp ("--alloc-sort=", argv [i], 13) == 0) {
1661                         const char *val = argv [i] + 13;
1662                         if (strcmp (val, "bytes") == 0) {
1663                                 alloc_sort_mode = ALLOC_SORT_BYTES;
1664                         } else if (strcmp (val, "count") == 0) {
1665                                 alloc_sort_mode = ALLOC_SORT_COUNT;
1666                         } else {
1667                                 usage ();
1668                                 return 1;
1669                         }
1670                 } else if (strncmp ("--method-sort=", argv [i], 14) == 0) {
1671                         const char *val = argv [i] + 14;
1672                         if (strcmp (val, "total") == 0) {
1673                                 method_sort_mode = METHOD_SORT_TOTAL;
1674                         } else if (strcmp (val, "self") == 0) {
1675                                 method_sort_mode = METHOD_SORT_SELF;
1676                         } else if (strcmp (val, "calls") == 0) {
1677                                 method_sort_mode = METHOD_SORT_CALLS;
1678                         } else {
1679                                 usage ();
1680                                 return 1;
1681                         }
1682                 } else if (strncmp ("--reports=", argv [i], 10) == 0) {
1683                         const char *val = argv [i] + 10;
1684                         if (!print_reports (NULL, val, 1)) {
1685                                 usage ();
1686                                 return 1;
1687                         }
1688                         reports = val;
1689                 } else if (strncmp ("--out=", argv [i], 6) == 0) {
1690                         const char *val = argv [i] + 6;
1691                         outfile = fopen (val, "w");
1692                         if (!outfile) {
1693                                 printf ("Cannot open output file: %s\n", val);
1694                                 return 1;
1695                         }
1696                 } else if (strncmp ("--maxframes=", argv [i], 12) == 0) {
1697                         const char *val = argv [i] + 12;
1698                         char *vale;
1699                         trace_max = strtoul (val, &vale, 10);
1700                 } else if (strncmp ("--find=", argv [i], 7) == 0) {
1701                         const char *val = argv [i] + 7;
1702                         if (!add_find_spec (val)) {
1703                                 usage ();
1704                                 return 1;
1705                         }
1706                 } else if (strncmp ("--track=", argv [i], 8) == 0) {
1707                         const char *val = argv [i] + 8;
1708                         char *vale;
1709                         while (*val) {
1710                                 uintptr_t tracked_obj;
1711                                 if (*val == ',') {
1712                                         val++;
1713                                         continue;
1714                                 }
1715                                 tracked_obj = strtoul (val, &vale, 0);
1716                                 found_object (tracked_obj);
1717                                 val = vale;
1718                         }
1719                 } else if (strncmp ("--thread=", argv [i], 9) == 0) {
1720                         const char *val = argv [i] + 9;
1721                         char *vale;
1722                         thread_filter = strtoul (val, &vale, 0);
1723                 } else if (strncmp ("--time=", argv [i], 7) == 0) {
1724                         char *val = pstrdup (argv [i] + 7);
1725                         double from_secs, to_secs;
1726                         char *top = strchr (val, '-');
1727                         if (!top) {
1728                                 usage ();
1729                                 return 1;
1730                         }
1731                         *top++ = 0;
1732                         from_secs = atof (val);
1733                         to_secs = atof (top);
1734                         free (val);
1735                         if (from_secs > to_secs) {
1736                                 usage ();
1737                                 return 1;
1738                         }
1739                         time_from = from_secs * 1000000000;
1740                         time_to = to_secs * 1000000000;
1741                 } else if (strcmp ("--verbose", argv [i]) == 0) {
1742                         verbose++;
1743                 } else if (strcmp ("--traces", argv [i]) == 0) {
1744                         show_traces = 1;
1745                         collect_traces = 1;
1746                 } else {
1747                         break;
1748                 }
1749         }
1750         if (i >= argc) {
1751                 usage ();
1752                 return 2;
1753         }
1754         ctx = load_file (argv [i]);
1755         if (!ctx) {
1756                 printf ("Not a log profiler data file (or unsupported version).\n");
1757                 return 1;
1758         }
1759         while (decode_buffer (ctx));
1760         flush_context (ctx);
1761         if (num_tracked_objects)
1762                 return 0;
1763         print_reports (ctx, reports, 0);
1764         return 0;
1765 }
1766