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 typedef struct {
 644         uint64_t created;
 645         uint64_t destroyed;
 646         uint64_t max_live;
 647         TraceDesc traces;
 648 } HandleInfo;
 649 static HandleInfo handle_info [4];
 650
 651 static const char*
 652 gc_event_name (int ev)
 653 {
 654         switch (ev) {
 655         case MONO_GC_EVENT_START: return "start";
 656         case MONO_GC_EVENT_MARK_START: return "mark start";
 657         case MONO_GC_EVENT_MARK_END: return "mark end";
 658         case MONO_GC_EVENT_RECLAIM_START: return "reclaim start";
 659         case MONO_GC_EVENT_RECLAIM_END: return "reclaim end";
 660         case MONO_GC_EVENT_END: return "end";
 661         case MONO_GC_EVENT_PRE_STOP_WORLD: return "pre stop";
 662         case MONO_GC_EVENT_POST_STOP_WORLD: return "post stop";
 663         case MONO_GC_EVENT_PRE_START_WORLD: return "pre start";
 664         case MONO_GC_EVENT_POST_START_WORLD: return "post start";
 665         default:
 666                 return "unknown";
 667         }
 668 }
 669
 670 static uint64_t clause_summary [MONO_EXCEPTION_CLAUSE_FAULT + 1];
 671 static uint64_t throw_count = 0;
 672 static TraceDesc exc_traces;
 673
 674 static const char*
 675 clause_name (int type)
 676 {
 677         switch (type) {
 678         case MONO_EXCEPTION_CLAUSE_NONE: return "catch";
 679         case MONO_EXCEPTION_CLAUSE_FILTER: return "filter";
 680         case MONO_EXCEPTION_CLAUSE_FINALLY: return "finally";
 681         case MONO_EXCEPTION_CLAUSE_FAULT: return "fault";
 682         default: return "invalid";
 683         }
 684 }
 685
 686 static uint64_t monitor_contention;
 687 static uint64_t monitor_failed;
 688 static uint64_t monitor_acquired;
 689
 690 struct _MonitorDesc {
 691         MonitorDesc *next;
 692         uintptr_t objid;
 693         uintptr_t contentions;
 694         uint64_t wait_time;
 695         uint64_t max_wait_time;
 696         TraceDesc traces;
 697 };
 698
 699 static MonitorDesc* monitor_hash [SMALL_HASH_SIZE] = {0};
 700 static int num_monitors = 0;
 701
 702 static MonitorDesc*
 703 lookup_monitor (uintptr_t objid)
 704 {
 705         int slot = ((objid >> 3) & 0xffff) % SMALL_HASH_SIZE;
 706         MonitorDesc *cd = monitor_hash [slot];
 707         while (cd && cd->objid != objid)
 708                 cd = cd->next;
 709         if (!cd) {
 710                 cd = calloc (sizeof (MonitorDesc), 1);
 711                 cd->objid = objid;
 712                 cd->next = monitor_hash [slot];
 713                 monitor_hash [slot] = cd;
 714                 num_monitors++;
 715         }
 716         return cd;
 717 }
 718
 719 static const char*
 720 monitor_ev_name (int ev)
 721 {
 722         switch (ev) {
 723         case MONO_PROFILER_MONITOR_CONTENTION: return "contended";
 724         case MONO_PROFILER_MONITOR_DONE: return "acquired";
 725         case MONO_PROFILER_MONITOR_FAIL: return "not taken";
 726         default: return "invalid";
 727         }
 728 }
 729
 730 static const char*
 731 get_handle_name (int htype)
 732 {
 733         switch (htype) {
 734         case 0: return "weak";
 735         case 1: return "weaktrack";
 736         case 2: return "normal";
 737         case 3: return "pinned";
 738         default: return "unknown";
 739         }
 740 }
 741
 742 static MethodDesc**
 743 decode_bt (MethodDesc** sframes, int *size, unsigned char *p, unsigned char **endp, intptr_t ptr_base)
 744 {
 745         MethodDesc **frames;
 746         int i;
 747         int flags = decode_uleb128 (p, &p);
 748         int count = decode_uleb128 (p, &p);
 749         if (flags != 0)
 750                 return NULL;
 751         if (count > *size)
 752                 frames = malloc (count * sizeof (void*));
 753         else
 754                 frames = sframes;
 755         for (i = 0; i < count; ++i) {
 756                 intptr_t ptrdiff = decode_sleb128 (p, &p);
 757                 frames [i] = lookup_method (ptr_base + ptrdiff);
 758         }
 759         *size = count;
 760         *endp = p;
 761         return frames;
 762 }
 763
 764 static void
 765 tracked_creation (uintptr_t obj, ClassDesc *cd, uint64_t size, BackTrace *bt, uint64_t timestamp)
 766 {
 767         int i;
 768         for (i = 0; i < num_tracked_objects; ++i) {
 769                 if (tracked_objects [i] != obj)
 770                         continue;
 771                 fprintf (outfile, "Object %p created (%s, %llu bytes) at %.3f secs.\n", (void*)obj, cd->name, size, (timestamp - startup_time)/1000000000.0);
 772                 if (bt && bt->count) {
 773                         int k;
 774                         for (k = 0; k < bt->count; ++k)
 775                                 fprintf (outfile, "\t%s\n", bt->methods [k]->name);
 776                 }
 777         }
 778 }
 779
 780 static void
 781 track_handle (uintptr_t obj, int htype, uint32_t handle)
 782 {
 783         int i;
 784         for (i = 0; i < num_tracked_objects; ++i) {
 785                 if (tracked_objects [i] == obj)
 786                         fprintf (outfile, "Object %p referenced from handle %u\n", (void*)obj, handle);
 787         }
 788 }
 789
 790 static void
 791 track_move (uintptr_t src, uintptr_t dst)
 792 {
 793         int i;
 794         for (i = 0; i < num_tracked_objects; ++i) {
 795                 if (tracked_objects [i] == src)
 796                         fprintf (outfile, "Object %p moved to %p\n", (void*)src, (void*)dst);
 797                 else if (tracked_objects [i] == dst)
 798                         fprintf (outfile, "Object %p moved from %p\n", (void*)dst, (void*)src);
 799         }
 800 }
 801
 802 static void
 803 track_obj_reference (uintptr_t obj, uintptr_t parent, ClassDesc *cd)
 804 {
 805         int i;
 806         for (i = 0; i < num_tracked_objects; ++i) {
 807                 if (tracked_objects [i] == obj)
 808                         fprintf (outfile, "Object %p referenced from %p (%s).\n", (void*)obj, (void*)parent, cd->name);
 809         }
 810 }
 811
 812 static void
 813 found_object (uintptr_t obj)
 814 {
 815         num_tracked_objects ++;
 816         tracked_objects = realloc (tracked_objects, num_tracked_objects * sizeof (tracked_objects [0]));
 817         tracked_objects [num_tracked_objects - 1] = obj;
 818 }
 819
 820 #define OBJ_ADDR(diff) ((obj_base + diff) << 3)
 821 #define LOG_TIME(base,diff) /*fprintf("outfile, time %llu + %llu near offset %d\n", base, diff, p - ctx->buf)*/
 822
 823 static int
 824 decode_buffer (ProfContext *ctx)
 825 {
 826         unsigned char *p;
 827         unsigned char *end;
 828         intptr_t thread_id;
 829         intptr_t ptr_base;
 830         intptr_t obj_base;
 831         intptr_t method_base;
 832         uint64_t time_base;
 833         uint64_t file_offset;
 834         int len, i;
 835         ThreadContext *thread;
 836
 837         file_offset = ftell (ctx->file);
 838         if (!load_data (ctx, 48))
 839                 return 0;
 840         p = ctx->buf;
 841         if (read_int32 (p) != BUF_ID)
 842                 return 0;
 843         len = read_int32 (p + 4);
 844         time_base = read_int64 (p + 8);
 845         ptr_base = read_int64 (p + 16);
 846         obj_base = read_int64 (p + 24);
 847         thread_id = read_int64 (p + 32);
 848         method_base = read_int64 (p + 40);
 849         if (debug)
 850                 fprintf (outfile, "buf: thread:%x, len: %d, time: %llu, file offset: %llu\n", thread_id, len, time_base, file_offset);
 851         thread = load_thread (ctx, thread_id);
 852         if (!load_data (ctx, len))
 853                 return 0;
 854         if (!startup_time) {
 855                 startup_time = time_base;
 856                 if (time_from) {
 857                         time_from += startup_time;
 858                         time_to += startup_time;
 859                 }
 860         }
 861         for (i = 0; i < thread->stack_id; ++i)
 862                 thread->stack [i]->recurse_count++;
 863         p = ctx->buf;
 864         end = p + len;
 865         while (p < end) {
 866                 switch (*p & 0xf) {
 867                 case TYPE_GC: {
 868                         int subtype = *p & 0xf0;
 869                         uint64_t tdiff = decode_uleb128 (p + 1, &p);
 870                         LOG_TIME (time_base, tdiff);
 871                         time_base += tdiff;
 872                         if (subtype == TYPE_GC_RESIZE) {
 873                                 uint64_t new_size = decode_uleb128 (p, &p);
 874                                 if (debug)
 875                                         fprintf (outfile, "gc heap resized to %llu\n", new_size);
 876                                 gc_resizes++;
 877                                 if (new_size > max_heap_size)
 878                                         max_heap_size = new_size;
 879                         } else if (subtype == TYPE_GC_EVENT) {
 880                                 uint64_t ev = decode_uleb128 (p, &p);
 881                                 int gen = decode_uleb128 (p, &p);
 882                                 if (debug)
 883                                         fprintf (outfile, "gc event for gen%d: %s at %llu\n", gen - 1, gc_event_name (ev), time_base);
 884                                 if (gen > 2) {
 885                                         fprintf (outfile, "incorrect gc gen: %d\n", gen);
 886                                         break;
 887                                 }
 888                                 if (ev == MONO_GC_EVENT_START) {
 889                                         gc_info [gen].start_time = time_base;
 890                                         gc_info [gen].count++;
 891                                 } else if (ev == MONO_GC_EVENT_END) {
 892                                         tdiff = time_base - gc_info [gen].start_time;
 893                                         gc_info [gen].total_time += tdiff;
 894                                         if (tdiff > gc_info [gen].max_time)
 895                                                 gc_info [gen].max_time = tdiff;
 896                                 }
 897                         } else if (subtype == TYPE_GC_MOVE) {
 898                                 int j, num = decode_uleb128 (p, &p);
 899                                 gc_object_moves += num / 2;
 900                                 for (j = 0; j < num; j += 2) {
 901                                         intptr_t obj1diff = decode_sleb128 (p, &p);
 902                                         intptr_t obj2diff = decode_sleb128 (p, &p);
 903                                         if (num_tracked_objects)
 904                                                 track_move (OBJ_ADDR (obj1diff), OBJ_ADDR (obj2diff));
 905                                         if (debug) {
 906                                                 fprintf (outfile, "moved obj %p to %p\n", (void*)OBJ_ADDR (obj1diff), (void*)OBJ_ADDR (obj2diff));
 907                                         }
 908                                 }
 909                         } else if (subtype == TYPE_GC_HANDLE_CREATED) {
 910                                 int htype = decode_uleb128 (p, &p);
 911                                 uint32_t handle = decode_uleb128 (p, &p);
 912                                 intptr_t objdiff = decode_sleb128 (p, &p);
 913                                 if (htype > 3)
 914                                         return 0;
 915                                 handle_info [htype].created++;
 916                                 add_trace_thread (thread, &handle_info [htype].traces, 1);
 917                                 /* FIXME: we don't take into account timing here */
 918                                 if (handle_info [htype].created > handle_info [htype].max_live)
 919                                         handle_info [htype].max_live = handle_info [htype].created;
 920                                 if (num_tracked_objects)
 921                                         track_handle (OBJ_ADDR (objdiff), htype, handle);
 922                                 if (debug)
 923                                         fprintf (outfile, "handle (%s) %u created for object %p\n", get_handle_name (htype), handle, (void*)OBJ_ADDR (objdiff));
 924                         } else if (subtype == TYPE_GC_HANDLE_DESTROYED) {
 925                                 int htype = decode_uleb128 (p, &p);
 926                                 uint32_t handle = decode_uleb128 (p, &p);
 927                                 if (htype > 3)
 928                                         return 0;
 929                                 handle_info [htype].created--;
 930                                 if (debug)
 931                                         fprintf (outfile, "handle (%s) %u destroyed\n", get_handle_name (htype), handle);
 932                         }
 933                         break;
 934                 }
 935                 case TYPE_METADATA: {
 936                         int error = *p & TYPE_LOAD_ERR;
 937                         uint64_t tdiff = decode_uleb128 (p + 1, &p);
 938                         int mtype = *p++;
 939                         intptr_t ptrdiff = decode_sleb128 (p, &p);
 940                         LOG_TIME (time_base, tdiff);
 941                         time_base += tdiff;
 942                         if (mtype == TYPE_CLASS) {
 943                                 intptr_t imptrdiff = decode_sleb128 (p, &p);
 944                                 uint64_t flags = decode_uleb128 (p, &p);
 945                                 if (flags) {
 946                                         fprintf (outfile, "non-zero flags in class\n");
 947                                         return 0;
 948                                 }
 949                                 if (debug)
 950                                         fprintf (outfile, "loaded class %p (%s in %p) at %llu\n", (void*)(ptr_base + ptrdiff), p, (void*)(ptr_base + imptrdiff), time_base);
 951                                 if (!error)
 952                                         add_class (ptr_base + ptrdiff, (char*)p);
 953                                 while (*p) p++;
 954                                 p++;
 955                         } else if (mtype == TYPE_IMAGE) {
 956                                 uint64_t flags = decode_uleb128 (p, &p);
 957                                 if (flags) {
 958                                         fprintf (outfile, "non-zero flags in image\n");
 959                                         return 0;
 960                                 }
 961                                 if (debug)
 962                                         fprintf (outfile, "loaded image %p (%s) at %llu\n", (void*)(ptr_base + ptrdiff), p, time_base);
 963                                 if (!error)
 964                                         add_image (ptr_base + ptrdiff, (char*)p);
 965                                 while (*p) p++;
 966                                 p++;
 967                         }
 968                         break;
 969                 }
 970                 case TYPE_ALLOC: {
 971                         int has_bt = *p & TYPE_ALLOC_BT;
 972                         uint64_t tdiff = decode_uleb128 (p + 1, &p);
 973                         intptr_t ptrdiff = decode_sleb128 (p, &p);
 974                         intptr_t objdiff = decode_sleb128 (p, &p);
 975                         uint64_t len;
 976                         int num_bt = 0;
 977                         MethodDesc* sframes [8];
 978                         MethodDesc** frames = sframes;
 979                         ClassDesc *cd = lookup_class (ptr_base + ptrdiff);
 980                         len = decode_uleb128 (p, &p);
 981                         LOG_TIME (time_base, tdiff);
 982                         time_base += tdiff;
 983                         if (debug)
 984                                 fprintf (outfile, "alloced object %p, size %llu (%s) at %llu\n", (void*)OBJ_ADDR (objdiff), len, lookup_class (ptr_base + ptrdiff)->name, time_base);
 985                         if (has_bt) {
 986                                 num_bt = 8;
 987                                 frames = decode_bt (sframes, &num_bt, p, &p, ptr_base);
 988                                 if (!frames) {
 989                                         fprintf (outfile, "Cannot load backtrace\n");
 990                                         return 0;
 991                                 }
 992                         }
 993                         if ((thread_filter && thread_filter == thread->thread_id) || (time_base >= time_from && time_base < time_to)) {
 994                                 BackTrace *bt;
 995                                 cd->allocs++;
 996                                 cd->alloc_size += len;
 997                                 if (has_bt)
 998                                         bt = add_trace_methods (frames, num_bt, &cd->traces, len);
 999                                 else
1000                                         bt = add_trace_thread (thread, &cd->traces, len);
1001                                 if (find_size && len >= find_size) {
1002                                         if (!find_name || strstr (cd->name, find_name))
1003                                                 found_object (OBJ_ADDR (objdiff));
1004                                 } else if (!find_size && find_name && strstr (cd->name, find_name)) {
1005                                         found_object (OBJ_ADDR (objdiff));
1006                                 }
1007                                 if (num_tracked_objects)
1008                                         tracked_creation (OBJ_ADDR (objdiff), cd, len, bt, time_base);
1009                         }
1010                         if (frames != sframes)
1011                                 free (frames);
1012                         break;
1013                 }
1014                 case TYPE_METHOD: {
1015                         int subtype = *p & 0xf0;
1016                         uint64_t tdiff = decode_uleb128 (p + 1, &p);
1017                         int64_t ptrdiff = decode_sleb128 (p, &p);
1018                         LOG_TIME (time_base, tdiff);
1019                         time_base += tdiff;
1020                         method_base += ptrdiff;
1021                         if (subtype == TYPE_JIT) {
1022                                 intptr_t codediff = decode_sleb128 (p, &p);
1023                                 int codelen = decode_uleb128 (p, &p);
1024                                 if (debug)
1025                                         fprintf (outfile, "jitted method %p (%s), size: %d\n", (void*)(method_base), p, codelen);
1026                                 add_method (method_base, (char*)p, ptr_base + codediff, codelen);
1027                                 while (*p) p++;
1028                                 p++;
1029                         } else {
1030                                 MethodDesc *method;
1031                                 if ((thread_filter && thread_filter != thread->thread_id))
1032                                         break;
1033                                 method = lookup_method (method_base);
1034                                 if (subtype == TYPE_ENTER) {
1035                                         add_trace_thread (thread, &method->traces, 1);
1036                                         push_method (thread, method, time_base);
1037                                 } else {
1038                                         pop_method (thread, method, time_base);
1039                                 }
1040                                 if (debug)
1041                                         fprintf (outfile, "%s method %s\n", subtype == TYPE_ENTER? "enter": subtype == TYPE_EXC_LEAVE? "exleave": "leave", method->name);
1042                         }
1043                         break;
1044                 }
1045                 case TYPE_HEAP: {
1046                         int subtype = *p & 0xf0;
1047                         if (subtype == TYPE_HEAP_OBJECT) {
1048                                 int i;
1049                                 intptr_t objdiff = decode_sleb128 (p + 1, &p);
1050                                 intptr_t ptrdiff = decode_sleb128 (p, &p);
1051                                 uint64_t size = decode_uleb128 (p, &p);
1052                                 int num = decode_uleb128 (p, &p);
1053                                 ClassDesc *cd = lookup_class (ptr_base + ptrdiff);
1054                                 for (i = 0; i < num; ++i) {
1055                                         /* FIXME: use object distance to measure how good
1056                                          * the GC is at keeping related objects close
1057                                          */
1058                                         intptr_t obj1diff = decode_sleb128 (p, &p);
1059                                         if (num_tracked_objects)
1060                                                 track_obj_reference (OBJ_ADDR (obj1diff), OBJ_ADDR (objdiff), cd);
1061                                 }
1062                                 if (debug && size)
1063                                         fprintf (outfile, "traced object %p, size %llu (%s), refs: %d\n", (void*)OBJ_ADDR (objdiff), size, cd->name, num);
1064                                 if (size)
1065                                         add_heap_shot_obj (current_heap_shot, cd, size);
1066                         } else if (subtype == TYPE_HEAP_END) {
1067                                 uint64_t tdiff = decode_uleb128 (p + 1, &p);
1068                                 LOG_TIME (time_base, tdiff);
1069                                 time_base += tdiff;
1070                                 if (debug)
1071                                         fprintf (outfile, "heap shot end\n");
1072                                 current_heap_shot = NULL;
1073                         } else if (subtype == TYPE_HEAP_START) {
1074                                 uint64_t tdiff = decode_uleb128 (p + 1, &p);
1075                                 LOG_TIME (time_base, tdiff);
1076                                 time_base += tdiff;
1077                                 if (debug)
1078                                         fprintf (outfile, "heap shot start\n");
1079                                 current_heap_shot = new_heap_shot (time_base);
1080                         }
1081                         break;
1082                 }
1083                 case TYPE_MONITOR: {
1084                         int event = (*p >> 4) & 0x3;
1085                         int has_bt = *p & TYPE_MONITOR_BT;
1086                         uint64_t tdiff = decode_uleb128 (p + 1, &p);
1087                         intptr_t objdiff = decode_sleb128 (p, &p);
1088                         MethodDesc* sframes [8];
1089                         MethodDesc** frames = sframes;
1090                         int record;
1091                         int num_bt = 0;
1092                         LOG_TIME (time_base, tdiff);
1093                         time_base += tdiff;
1094                         record = (!thread_filter || thread_filter == thread->thread_id);
1095                         if (event == MONO_PROFILER_MONITOR_CONTENTION) {
1096                                 MonitorDesc *mdesc = lookup_monitor (OBJ_ADDR (objdiff));
1097                                 if (record) {
1098                                         monitor_contention++;
1099                                         mdesc->contentions++;
1100                                         thread->monitor = mdesc;
1101                                         thread->contention_start = time_base;
1102                                 }
1103                                 if (has_bt) {
1104                                         num_bt = 8;
1105                                         frames = decode_bt (sframes, &num_bt, p, &p, ptr_base);
1106                                         if (!frames) {
1107                                                 fprintf (outfile, "Cannot load backtrace\n");
1108                                                 return 0;
1109                                         }
1110                                         if (record)
1111                                                 add_trace_methods (frames, num_bt, &mdesc->traces, 1);
1112                                 } else {
1113                                         if (record)
1114                                                 add_trace_thread (thread, &mdesc->traces, 1);
1115                                 }
1116                         } else if (event == MONO_PROFILER_MONITOR_FAIL) {
1117                                 if (record) {
1118                                         monitor_failed++;
1119                                         if (thread->monitor && thread->contention_start) {
1120                                                 uint64_t wait_time = time_base - thread->contention_start;
1121                                                 if (wait_time > thread->monitor->max_wait_time)
1122                                                         thread->monitor->max_wait_time = wait_time;
1123                                                 thread->monitor->wait_time += wait_time;
1124                                                 thread->monitor = NULL;
1125                                                 thread->contention_start = 0;
1126                                         }
1127                                 }
1128                         } else if (event == MONO_PROFILER_MONITOR_DONE) {
1129                                 if (record) {
1130                                         monitor_acquired++;
1131                                         if (thread->monitor && thread->contention_start) {
1132                                                 uint64_t wait_time = time_base - thread->contention_start;
1133                                                 if (wait_time > thread->monitor->max_wait_time)
1134                                                         thread->monitor->max_wait_time = wait_time;
1135                                                 thread->monitor->wait_time += wait_time;
1136                                                 thread->monitor = NULL;
1137                                                 thread->contention_start = 0;
1138                                         }
1139                                 }
1140                         }
1141                         if (debug)
1142                                 fprintf (outfile, "monitor %s for object %p\n", monitor_ev_name (event), (void*)OBJ_ADDR (objdiff));
1143                         if (frames != sframes)
1144                                 free (frames);
1145                         break;
1146                 }
1147                 case TYPE_EXCEPTION: {
1148                         int subtype = *p & 0x70;
1149                         int has_bt = *p & TYPE_EXCEPTION_BT;
1150                         uint64_t tdiff = decode_uleb128 (p + 1, &p);
1151                         MethodDesc* sframes [8];
1152                         MethodDesc** frames = sframes;
1153                         int record;
1154                         LOG_TIME (time_base, tdiff);
1155                         time_base += tdiff;
1156                         record = (!thread_filter || thread_filter == thread->thread_id);
1157                         if (subtype == TYPE_CLAUSE) {
1158                                 int clause_type = decode_uleb128 (p, &p);
1159                                 int clause_num = decode_uleb128 (p, &p);
1160                                 int64_t ptrdiff = decode_sleb128 (p, &p);
1161                                 method_base += ptrdiff;
1162                                 if (record)
1163                                         clause_summary [clause_type]++;
1164                                 if (debug)
1165                                         fprintf (outfile, "clause %s (%d) in method %s\n", clause_name (clause_type), clause_num, lookup_method (method_base)->name);
1166                         } else {
1167                                 intptr_t objdiff = decode_sleb128 (p, &p);
1168                                 if (record)
1169                                         throw_count++;
1170                                 if (has_bt) {
1171                                         has_bt = 8;
1172                                         frames = decode_bt (sframes, &has_bt, p, &p, ptr_base);
1173                                         if (!frames) {
1174                                                 fprintf (outfile, "Cannot load backtrace\n");
1175                                                 return 0;
1176                                         }
1177                                         if (record)
1178                                                 add_trace_methods (frames, has_bt, &exc_traces, 1);
1179                                 } else {
1180                                         if (record)
1181                                                 add_trace_thread (thread, &exc_traces, 1);
1182                                 }
1183                                 if (frames != sframes)
1184                                         free (frames);
1185                                 if (debug)
1186                                         fprintf (outfile, "throw %p\n", (void*)OBJ_ADDR (objdiff));
1187                         }
1188                         break;
1189                 }
1190                 default:
1191                         fprintf (outfile, "unhandled profiler event: 0x%x\n", *p);
1192                         exit (1);
1193                 }
1194         }
1195         thread->last_time = time_base;
1196         for (i = 0; i < thread->stack_id; ++i)
1197                 thread->stack [i]->recurse_count = 0;
1198         return 1;
1199 }
1200
1201 static ProfContext*
1202 load_file (char *name)
1203 {
1204         unsigned char *p;
1205         ProfContext *ctx = calloc (sizeof (ProfContext), 1);
1206         if (strcmp (name, "-") == 0)
1207                 ctx->file = stdin;
1208         else
1209                 ctx->file = fopen (name, "rb");
1210         if (!ctx->file) {
1211                 printf ("Cannot open file: %s\n", name);
1212                 exit (1);
1213         }
1214 #if defined (HAVE_ZLIB)
1215         ctx->gzfile = gzdopen (fileno (ctx->file), "rb");
1216 #endif
1217         if (!load_data (ctx, 32))
1218                 return NULL;
1219         p = ctx->buf;
1220         if (read_int32 (p) != LOG_HEADER_ID || p [6] != LOG_DATA_VERSION)
1221                 return NULL;
1222         ctx->version_major = p [4];
1223         ctx->version_minor = p [5];
1224         ctx->data_version = p [6];
1225         /* reading 64 bit files on 32 bit systems not supported yet */
1226         if (p [7] > sizeof (void*))
1227                 return NULL;
1228         if (read_int32 (p + 20)) /* flags must be 0 */
1229                 return NULL;
1230         ctx->startup_time = read_int64 (p + 8);
1231         ctx->timer_overhead = read_int32 (p + 16);
1232         return ctx;
1233 }
1234
1235 enum {
1236         ALLOC_SORT_BYTES,
1237         ALLOC_SORT_COUNT
1238 };
1239 static int alloc_sort_mode = ALLOC_SORT_BYTES;
1240
1241 static int
1242 compare_class (const void *a, const void *b)
1243 {
1244         ClassDesc *const*A = a;
1245         ClassDesc *const*B = b;
1246         uint64_t vala, valb;
1247         if (alloc_sort_mode == ALLOC_SORT_BYTES) {
1248                 vala = (*A)->alloc_size;
1249                 valb = (*B)->alloc_size;
1250         } else {
1251                 vala = (*A)->allocs;
1252                 valb = (*B)->allocs;
1253         }
1254         if (valb == vala)
1255                 return 0;
1256         if (valb < vala)
1257                 return -1;
1258         return 1;
1259 }
1260
1261 static void
1262 dump_header (ProfContext *ctx)
1263 {
1264         time_t st = ctx->startup_time / 1000;
1265         char *t = ctime (&st);
1266         fprintf (outfile, "\nMono log profiler data\n");
1267         fprintf (outfile, "\tProfiler version: %d.%d\n", ctx->version_major, ctx->version_minor);
1268         fprintf (outfile, "\tData version: %d\n", ctx->data_version);
1269         fprintf (outfile, "\tMean timer overhead: %d nanoseconds\n", ctx->timer_overhead);
1270         fprintf (outfile, "\tProgram startup: %s\n", t);
1271 }
1272
1273 static void
1274 dump_traces (TraceDesc *traces, const char *desc)
1275 {
1276         int j;
1277         if (!show_traces)
1278                 return;
1279         if (!traces->count)
1280                 return;
1281         sort_context_array (traces);
1282         for (j = 0; j < traces->count; ++j) {
1283                 int k;
1284                 BackTrace *bt;
1285                 bt = traces->traces [j].bt;
1286                 if (!bt->count)
1287                         continue;
1288                 fprintf (outfile, "\t%llu %s from:\n", traces->traces [j].count, desc);
1289                 for (k = 0; k < bt->count; ++k)
1290                         fprintf (outfile, "\t\t%s\n", bt->methods [k]->name);
1291         }
1292 }
1293
1294 static void
1295 dump_threads (ProfContext *ctx)
1296 {
1297         ThreadContext *thread;
1298         fprintf (outfile, "\nThread summary\n");
1299         for (thread = ctx->threads; thread; thread = thread->next) {
1300                 fprintf (outfile, "\tThread: %p\n", (void*)thread->thread_id);
1301         }
1302 }
1303
1304 static void
1305 dump_exceptions (void)
1306 {
1307         int i;
1308         fprintf (outfile, "\nException summary\n");
1309         fprintf (outfile, "\tThrows: %llu\n", throw_count);
1310         dump_traces (&exc_traces, "throws");
1311         for (i = 0; i <= MONO_EXCEPTION_CLAUSE_FAULT; ++i) {
1312                 if (!clause_summary [i])
1313                         continue;
1314                 fprintf (outfile, "\tExecuted %s clauses: %llu\n", clause_name (i), clause_summary [i]);
1315         }
1316 }
1317
1318 static int
1319 compare_monitor (const void *a, const void *b)
1320 {
1321         MonitorDesc *const*A = a;
1322         MonitorDesc *const*B = b;
1323         if ((*B)->wait_time == (*A)->wait_time)
1324                 return 0;
1325         if ((*B)->wait_time < (*A)->wait_time)
1326                 return -1;
1327         return 1;
1328 }
1329
1330 static void
1331 dump_monitors (void)
1332 {
1333         MonitorDesc **monitors;
1334         int i, j;
1335         if (!num_monitors)
1336                 return;
1337         monitors = malloc (sizeof (void*) * num_monitors);
1338         for (i = 0, j = 0; i < SMALL_HASH_SIZE; ++i) {
1339                 MonitorDesc *mdesc = monitor_hash [i];
1340                 while (mdesc) {
1341                         monitors [j++] = mdesc;
1342                         mdesc = mdesc->next;
1343                 }
1344         }
1345         qsort (monitors, num_monitors, sizeof (void*), compare_monitor);
1346         fprintf (outfile, "\nMonitor lock summary\n");
1347         for (i = 0; i < num_monitors; ++i) {
1348                 MonitorDesc *mdesc = monitors [i];
1349                 fprintf (outfile, "\tLock object %p: %d contentions\n", (void*)mdesc->objid, (int)mdesc->contentions);
1350                 fprintf (outfile, "\t\t%.6f secs total wait time, %.6f max, %.6f average\n",
1351                         mdesc->wait_time/1000000000.0, mdesc->max_wait_time/1000000000.0, mdesc->wait_time/1000000000.0/mdesc->contentions);
1352                 dump_traces (&mdesc->traces, "contentions");
1353         }
1354         fprintf (outfile, "\tLock contentions: %llu\n", monitor_contention);
1355         fprintf (outfile, "\tLock acquired: %llu\n", monitor_acquired);
1356         fprintf (outfile, "\tLock failures: %llu\n", monitor_failed);
1357 }
1358
1359 static void
1360 dump_gcs (void)
1361 {
1362         int i;
1363         fprintf (outfile, "\nGC summary\n");
1364         fprintf (outfile, "\tGC resizes: %d\n", gc_resizes);
1365         fprintf (outfile, "\tMax heap size: %llu\n", max_heap_size);
1366         fprintf (outfile, "\tObject moves: %llu\n", gc_object_moves);
1367         for (i = 0; i < 3; ++i) {
1368                 if (!gc_info [i].count)
1369                         continue;
1370                 fprintf (outfile, "\tGen%d collections: %d, max time: %lluus, total time: %lluus, average: %lluus\n",
1371                         i, gc_info [i].count, gc_info [i].max_time / 1000, gc_info [i].total_time / 1000,
1372                         gc_info [i].total_time / gc_info [i].count / 1000);
1373         }
1374         for (i = 0; i < 3; ++i) {
1375                 if (!handle_info [i].max_live)
1376                         continue;
1377                 fprintf (outfile, "\tGC handles %s: created: %llu, destroyed: %llu, max: %llu\n",
1378                         get_handle_name (i), handle_info [i].created, handle_info [i].destroyed, handle_info [i].max_live);
1379                 dump_traces (&handle_info [i].traces, "created");
1380         }
1381 }
1382
1383 static void
1384 dump_allocations (void)
1385 {
1386         int i, c;
1387         intptr_t allocs = 0;
1388         uint64_t size = 0;
1389         int header_done = 0;
1390         ClassDesc **classes = malloc (num_classes * sizeof (void*));
1391         ClassDesc *cd;
1392         c = 0;
1393         for (i = 0; i < HASH_SIZE; ++i) {
1394                 cd = class_hash [i];
1395                 while (cd) {
1396                         classes [c++] = cd;
1397                         cd = cd->next;
1398                 }
1399         }
1400         qsort (classes, num_classes, sizeof (void*), compare_class);
1401         for (i = 0; i < num_classes; ++i) {
1402                 cd = classes [i];
1403                 if (!cd->allocs)
1404                         continue;
1405                 allocs += cd->allocs;
1406                 size += cd->alloc_size;
1407                 if (!header_done++) {
1408                         fprintf (outfile, "\nAllocation summary\n");
1409                         fprintf (outfile, "%10s %10s %8s Type name\n", "Bytes", "Count", "Average");
1410                 }
1411                 fprintf (outfile, "%10llu %10d %8llu %s\n", cd->alloc_size, cd->allocs, cd->alloc_size / cd->allocs, cd->name);
1412                 dump_traces (&cd->traces, "bytes");
1413         }
1414         if (allocs)
1415                 fprintf (outfile, "Total memory allocated: %llu bytes in %d objects\n", size, allocs);
1416 }
1417
1418 enum {
1419         METHOD_SORT_TOTAL,
1420         METHOD_SORT_SELF,
1421         METHOD_SORT_CALLS
1422 };
1423
1424 static int method_sort_mode = METHOD_SORT_TOTAL;
1425
1426 static int
1427 compare_method (const void *a, const void *b)
1428 {
1429         MethodDesc *const*A = a;
1430         MethodDesc *const*B = b;
1431         uint64_t vala, valb;
1432         if (method_sort_mode == METHOD_SORT_SELF) {
1433                 vala = (*A)->self_time;
1434                 valb = (*B)->self_time;
1435         } else if (method_sort_mode == METHOD_SORT_CALLS) {
1436                 vala = (*A)->calls;
1437                 valb = (*B)->calls;
1438         } else {
1439                 vala = (*A)->total_time;
1440                 valb = (*B)->total_time;
1441         }
1442         if (vala == valb)
1443                 return 0;
1444         if (valb < vala)
1445                 return -1;
1446         return 1;
1447 }
1448
1449 static void
1450 dump_metadata (void)
1451 {
1452         fprintf (outfile, "\nMetadata summary\n");
1453         fprintf (outfile, "\tLoaded images: %d\n", num_images);
1454         if (verbose) {
1455                 ImageDesc *image;
1456                 int i;
1457                 for (i = 0; i < SMALL_HASH_SIZE; ++i) {
1458                         image = image_hash [i];
1459                         while (image) {
1460                                 fprintf (outfile, "\t\t%s\n", image->filename);
1461                                 image = image->next;
1462                         }
1463                 }
1464         }
1465
1466 }
1467
1468 static void
1469 dump_methods (void)
1470 {
1471         int i, c;
1472         uint64_t calls = 0;
1473         int header_done = 0;
1474         MethodDesc **methods = malloc (num_methods * sizeof (void*));
1475         MethodDesc *cd;
1476         c = 0;
1477         for (i = 0; i < HASH_SIZE; ++i) {
1478                 cd = method_hash [i];
1479                 while (cd) {
1480                         cd->total_time = cd->self_time + cd->callee_time;
1481                         methods [c++] = cd;
1482                         cd = cd->next;
1483                 }
1484         }
1485         qsort (methods, num_methods, sizeof (void*), compare_method);
1486         for (i = 0; i < num_methods; ++i) {
1487                 uint64_t msecs;
1488                 uint64_t smsecs;
1489                 cd = methods [i];
1490                 if (!cd->calls)
1491                         continue;
1492                 calls += cd->calls;
1493                 msecs = cd->total_time / 1000000;
1494                 smsecs = (cd->total_time - cd->callee_time) / 1000000;
1495                 if (!msecs && !verbose)
1496                         continue;
1497                 if (!header_done++) {
1498                         fprintf (outfile, "\nMethod call summary\n");
1499                         fprintf (outfile, "%8s %8s %10s Method name\n", "Total(ms)", "Self(ms)", "Calls");
1500                 }
1501                 fprintf (outfile, "%8llu %8llu %10llu %s\n", msecs, smsecs, cd->calls, cd->name);
1502                 dump_traces (&cd->traces, "calls");
1503         }
1504         if (calls)
1505                 fprintf (outfile, "Total calls: %llu\n", calls);
1506 }
1507
1508 static int
1509 compare_heap_class (const void *a, const void *b)
1510 {
1511         HeapClassDesc *const*A = a;
1512         HeapClassDesc *const*B = b;
1513         uint64_t vala, valb;
1514         if (alloc_sort_mode == ALLOC_SORT_BYTES) {
1515                 vala = (*A)->total_size;
1516                 valb = (*B)->total_size;
1517         } else {
1518                 vala = (*A)->count;
1519                 valb = (*B)->count;
1520         }
1521         if (valb == vala)
1522                 return 0;
1523         if (valb < vala)
1524                 return -1;
1525         return 1;
1526 }
1527
1528 static void
1529 heap_shot_summary (HeapShot *hs, int hs_num, HeapShot *last_hs)
1530 {
1531         uint64_t size = 0;
1532         uint64_t count = 0;
1533         int ccount = 0;
1534         int i;
1535         HeapClassDesc *cd;
1536         HeapClassDesc **sorted;
1537         sorted = malloc (sizeof (void*) * hs->class_count);
1538         for (i = 0; i < hs->hash_size; ++i) {
1539                 cd = hs->class_hash [i];
1540                 if (!cd)
1541                         continue;
1542                 count += cd->count;
1543                 size += cd->total_size;
1544                 sorted [ccount++] = cd;
1545         }
1546         hs->sorted = sorted;
1547         qsort (sorted, ccount, sizeof (void*), compare_heap_class);
1548         fprintf (outfile, "\n\tHeap shot %d at %.3f secs: size: %llu, object count: %llu, class count: %d\n",
1549                 hs_num, (hs->timestamp - startup_time)/1000000000.0, size, count, ccount);
1550         if (!verbose && ccount > 30)
1551                 ccount = 30;
1552         fprintf (outfile, "\t%10s %10s %8s Class name\n", "Bytes", "Count", "Average");
1553         for (i = 0; i < ccount; ++i) {
1554                 HeapClassDesc *ocd = NULL;
1555                 cd = sorted [i];
1556                 if (last_hs)
1557                         ocd = heap_class_lookup (last_hs, cd->klass);
1558                 fprintf (outfile, "\t%10llu %10llu %8llu %s", cd->total_size, cd->count, cd->total_size / cd->count, cd->klass->name);
1559                 if (ocd) {
1560                         int64_t bdiff = cd->total_size - ocd->total_size;
1561                         int64_t cdiff = cd->count - ocd->count;
1562                         fprintf (outfile, " (bytes: %+lld, count: %+lld)\n", bdiff, cdiff);
1563                 } else {
1564                         fprintf (outfile, "\n");
1565                 }
1566         }
1567 }
1568
1569 static void
1570 dump_heap_shots (void)
1571 {
1572         HeapShot *hs;
1573         HeapShot *last_hs = NULL;
1574         int i;
1575         if (!heap_shots)
1576                 return;
1577         fprintf (outfile, "\nHeap shot summary\n");
1578         i = 0;
1579         for (hs = heap_shots; hs; hs = hs->next) {
1580                 heap_shot_summary (hs, i++, last_hs);
1581                 last_hs = hs;
1582         }
1583 }
1584
1585 static void
1586 flush_context (ProfContext *ctx)
1587 {
1588         ThreadContext *thread;
1589         /* FIXME: sometimes there are leftovers: indagate */
1590         for (thread = ctx->threads; thread; thread = thread->next) {
1591                 while (thread->stack_id) {
1592                         if (debug)
1593                                 fprintf (outfile, "thread %p has %d items on stack\n", (void*)thread->thread_id, thread->stack_id);
1594                         pop_method (thread, thread->stack [thread->stack_id - 1], thread->last_time);
1595                 }
1596         }
1597 }
1598
1599 static const char *reports = "header,gc,alloc,call,metadata,exception,monitor,thread,heapshot";
1600
1601 static const char*
1602 match_option (const char *p, const char *opt)
1603 {
1604         int len = strlen (opt);
1605         if (strncmp (p, opt, len) == 0) {
1606                 if (p [len] == ',')
1607                         len++;
1608                 return p + len;
1609         }
1610         return p;
1611 }
1612
1613 static int
1614 print_reports (ProfContext *ctx, const char *reps, int parse_only)
1615 {
1616         const char *opt;
1617         const char *p;
1618         for (p = reps; *p; p = opt) {
1619                 if ((opt = match_option (p, "header")) != p) {
1620                         if (!parse_only)
1621                                 dump_header (ctx);
1622                         continue;
1623                 }
1624                 if ((opt = match_option (p, "thread")) != p) {
1625                         if (!parse_only)
1626                                 dump_threads (ctx);
1627                         continue;
1628                 }
1629                 if ((opt = match_option (p, "gc")) != p) {
1630                         if (!parse_only)
1631                                 dump_gcs ();
1632                         continue;
1633                 }
1634                 if ((opt = match_option (p, "alloc")) != p) {
1635                         if (!parse_only)
1636                                 dump_allocations ();
1637                         continue;
1638                 }
1639                 if ((opt = match_option (p, "call")) != p) {
1640                         if (!parse_only)
1641                                 dump_methods ();
1642                         continue;
1643                 }
1644                 if ((opt = match_option (p, "metadata")) != p) {
1645                         if (!parse_only)
1646                                 dump_metadata ();
1647                         continue;
1648                 }
1649                 if ((opt = match_option (p, "exception")) != p) {
1650                         if (!parse_only)
1651                                 dump_exceptions ();
1652                         continue;
1653                 }
1654                 if ((opt = match_option (p, "monitor")) != p) {
1655                         if (!parse_only)
1656                                 dump_monitors ();
1657                         continue;
1658                 }
1659                 if ((opt = match_option (p, "heapshot")) != p) {
1660                         if (!parse_only)
1661                                 dump_heap_shots ();
1662                         continue;
1663                 }
1664                 return 0;
1665         }
1666         return 1;
1667 }
1668
1669 static int
1670 add_find_spec (const char *p)
1671 {
1672         if (p [0] == 'S' && p [1] == ':') {
1673                 char *vale;
1674                 find_size = strtoul (p + 2, &vale, 10);
1675                 return 1;
1676         } else if (p [0] == 'T' && p [1] == ':') {
1677                 find_name = p + 2;
1678                 return 1;
1679         }
1680         return 0;
1681 }
1682
1683 static void
1684 usage (void)
1685 {
1686         printf ("Mono log profiler report version %d.%d\n", LOG_VERSION_MAJOR, LOG_VERSION_MINOR);
1687         printf ("Usage: mprof-report [OPTIONS] FILENAME\n");
1688         printf ("FILENAME can be '-' to read from standard input.\n");
1689         printf ("Options:\n");
1690         printf ("\t--help               display this help\n");
1691         printf ("\t--out=FILE           write to FILE instead of stdout\n");
1692         printf ("\t--traces             collect and show backtraces\n");
1693         printf ("\t--maxframes=NUM      limit backtraces to NUM entries\n");
1694         printf ("\t--reports=R1[,R2...] print the specified reports. Defaults are:\n");
1695         printf ("\t                     %s\n", reports);
1696         printf ("\t--method-sort=MODE   sort methods according to MODE: total, self, calls\n");
1697         printf ("\t--alloc-sort=MODE    sort allocations according to MODE: bytes, count\n");
1698         printf ("\t--track=OB1[,OB2...] track what happens to objects OBJ1, O2 etc.\n");
1699         printf ("\t--find=FINDSPEC      find and track objects matching FINFSPEC, where FINDSPEC is:\n");
1700         printf ("\t                     S:minimum_size or T:partial_name\n");
1701         printf ("\t--thread=THREADID    consider just the data for thread THREADID\n");
1702         printf ("\t--time=FROM-TO       consider data FROM seconds from startup up to TO seconds\n");
1703         printf ("\t--verbose            increase verbosity level\n");
1704         printf ("\t--debug              display decoding debug info for mprof-report devs\n");
1705 }
1706
1707 int
1708 main (int argc, char *argv[])
1709 {
1710         ProfContext *ctx;
1711         int i;
1712         outfile = stdout;
1713         for (i = 1; i < argc; ++i) {
1714                 if (strcmp ("--debug", argv [i]) == 0) {
1715                         debug++;
1716                 } else if (strcmp ("--help", argv [i]) == 0) {
1717                         usage ();
1718                         return 0;
1719                 } else if (strncmp ("--alloc-sort=", argv [i], 13) == 0) {
1720                         const char *val = argv [i] + 13;
1721                         if (strcmp (val, "bytes") == 0) {
1722                                 alloc_sort_mode = ALLOC_SORT_BYTES;
1723                         } else if (strcmp (val, "count") == 0) {
1724                                 alloc_sort_mode = ALLOC_SORT_COUNT;
1725                         } else {
1726                                 usage ();
1727                                 return 1;
1728                         }
1729                 } else if (strncmp ("--method-sort=", argv [i], 14) == 0) {
1730                         const char *val = argv [i] + 14;
1731                         if (strcmp (val, "total") == 0) {
1732                                 method_sort_mode = METHOD_SORT_TOTAL;
1733                         } else if (strcmp (val, "self") == 0) {
1734                                 method_sort_mode = METHOD_SORT_SELF;
1735                         } else if (strcmp (val, "calls") == 0) {
1736                                 method_sort_mode = METHOD_SORT_CALLS;
1737                         } else {
1738                                 usage ();
1739                                 return 1;
1740                         }
1741                 } else if (strncmp ("--reports=", argv [i], 10) == 0) {
1742                         const char *val = argv [i] + 10;
1743                         if (!print_reports (NULL, val, 1)) {
1744                                 usage ();
1745                                 return 1;
1746                         }
1747                         reports = val;
1748                 } else if (strncmp ("--out=", argv [i], 6) == 0) {
1749                         const char *val = argv [i] + 6;
1750                         outfile = fopen (val, "w");
1751                         if (!outfile) {
1752                                 printf ("Cannot open output file: %s\n", val);
1753                                 return 1;
1754                         }
1755                 } else if (strncmp ("--maxframes=", argv [i], 12) == 0) {
1756                         const char *val = argv [i] + 12;
1757                         char *vale;
1758                         trace_max = strtoul (val, &vale, 10);
1759                 } else if (strncmp ("--find=", argv [i], 7) == 0) {
1760                         const char *val = argv [i] + 7;
1761                         if (!add_find_spec (val)) {
1762                                 usage ();
1763                                 return 1;
1764                         }
1765                 } else if (strncmp ("--track=", argv [i], 8) == 0) {
1766                         const char *val = argv [i] + 8;
1767                         char *vale;
1768                         while (*val) {
1769                                 uintptr_t tracked_obj;
1770                                 if (*val == ',') {
1771                                         val++;
1772                                         continue;
1773                                 }
1774                                 tracked_obj = strtoul (val, &vale, 0);
1775                                 found_object (tracked_obj);
1776                                 val = vale;
1777                         }
1778                 } else if (strncmp ("--thread=", argv [i], 9) == 0) {
1779                         const char *val = argv [i] + 9;
1780                         char *vale;
1781                         thread_filter = strtoul (val, &vale, 0);
1782                 } else if (strncmp ("--time=", argv [i], 7) == 0) {
1783                         char *val = pstrdup (argv [i] + 7);
1784                         double from_secs, to_secs;
1785                         char *top = strchr (val, '-');
1786                         if (!top) {
1787                                 usage ();
1788                                 return 1;
1789                         }
1790                         *top++ = 0;
1791                         from_secs = atof (val);
1792                         to_secs = atof (top);
1793                         free (val);
1794                         if (from_secs > to_secs) {
1795                                 usage ();
1796                                 return 1;
1797                         }
1798                         time_from = from_secs * 1000000000;
1799                         time_to = to_secs * 1000000000;
1800                 } else if (strcmp ("--verbose", argv [i]) == 0) {
1801                         verbose++;
1802                 } else if (strcmp ("--traces", argv [i]) == 0) {
1803                         show_traces = 1;
1804                         collect_traces = 1;
1805                 } else {
1806                         break;
1807                 }
1808         }
1809         if (i >= argc) {
1810                 usage ();
1811                 return 2;
1812         }
1813         ctx = load_file (argv [i]);
1814         if (!ctx) {
1815                 printf ("Not a log profiler data file (or unsupported version).\n");
1816                 return 1;
1817         }
1818         while (decode_buffer (ctx));
1819         flush_context (ctx);
1820         if (num_tracked_objects)
1821                 return 0;
1822         print_reports (ctx, reports, 0);
1823         return 0;
1824 }
1825