mono/profiler/decode.c

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