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