mono/profiler/proflog.c

   1 #include <mono/metadata/profiler.h>
   2 #include <mono/metadata/mono-gc.h>
   3 #include <mono/metadata/debug-helpers.h>
   4 #include <stdlib.h>
   5 #include <inttypes.h>
   6 #include <string.h>
   7 #include <zlib.h>
   8 #include <assert.h>
   9 #include <pthread.h>
  10
  11 #include "utils.h"
  12 #include "proflog.h"
  13
  14 #define BUFFER_SIZE (4096 * 16)
  15 static int nocalls = 0;
  16 static int notraces = 0;
  17 static int use_zip = 0;
  18 static int do_report = 0;
  19 static int do_heap_shot = 0;
  20 static int max_call_depth = 100;
  21 static int runtime_inited = 0;
  22
  23 /* For linux compile with:
  24  * gcc -fPIC -shared -o libmono-profiler-log.so proflog.c utils.c -Wall -g -lz `pkg-config --cflags --libs mono-2`
  25  * gcc -o mprof-report decode.c utils.c -Wall -g -lz -lrt -lpthread `pkg-config --cflags mono-2`
  26  *
  27  * For osx compile with:
  28  * gcc -m32 -Dmono_free=free shared -o libmono-profiler-log.dylib proflog.c utils.c -Wall -g -lz `pkg-config --cflags mono-2` -undefined suppress -flat_namespace
  29  * gcc -m32 -o mprof-report decode.c utils.c -Wall -g -lz -lrt -lpthread `pkg-config --cflags mono-2`
  30  *
  31  * Install with:
  32  * sudo cp mprof-report /usr/local/bin
  33  * sudo cp libmono-profiler-log.so /usr/local/lib
  34  * sudo ldconfig
  35  */
  36
  37 typedef struct _LogBuffer LogBuffer;
  38
  39 /*
  40  * file format: [OBSOLETE]
  41  * [header] [buffer]*
  42  * each buffer contains events
  43  *
  44  * header format:
  45  * [id: 4 bytes] [major: 1 byte] [minor: 1 byte] [length: 2 bytes]
  46  * [time: 8 bytes]
  47  * [bitness: 1 byte]
  48  * [mono version: variable]
  49  * [other data]
  50  *
  51  * buffer format:
  52  * [bufid: 4 bytes] [len: 4 bytes]
  53  * [time_base: 8 bytes]
  54  * [ptr_base: 8 bytes]
  55  * [obj_base: 8 bytes]
  56  * [thread id: 8 bytes]
  57  *
  58  * event format:
  59  * [extended type: 4 bits] [type: 4 bits]
  60  * The data that follows depend on type.
  61  * Time values are relative to the last time base of the buffer.
  62  *
  63  * type alloc format:
  64  * [ptr: encoded] [class: encoded] [time: encoded] size?
  65  *
  66  * type enter/leave format:
  67  * [method: encoded] [time: encoded]
  68  *
  69  */
  70 struct _LogBuffer {
  71         LogBuffer *next;
  72         uint64_t time_base;
  73         uint64_t last_time;
  74         uintptr_t ptr_base;
  75         uintptr_t method_base;
  76         uintptr_t last_method;
  77         uintptr_t obj_base;
  78         uintptr_t thread_id;
  79         unsigned char* data_end;
  80         unsigned char* data;
  81         int size;
  82         int call_depth;
  83         unsigned char buf [1];
  84 };
  85
  86 struct _MonoProfiler {
  87         LogBuffer *buffers;
  88         FILE* file;
  89         gzFile *gzfile;
  90         int pipe_output;
  91         int last_gc_gen_started;
  92 };
  93
  94 #if HAVE_KW_THREAD
  95 #define TLS_SET(x,y) x = y
  96 #define TLS_GET(x) x
  97 #define TLS_INIT(x)
  98 static __thread LogBuffer* tlsbuffer = NULL;
  99 #else
 100 #define TLS_SET(x,y) pthread_setspecific(x, y)
 101 #define TLS_GET(x) ((LogBuffer *) pthread_getspecific(x))
 102 #define TLS_INIT(x) pthread_key_create(&x, NULL)
 103 static pthread_key_t tlsbuffer;
 104 #endif
 105
 106 static LogBuffer*
 107 create_buffer (void)
 108 {
 109         LogBuffer* buf = alloc_buffer (BUFFER_SIZE);
 110         buf->size = BUFFER_SIZE;
 111         buf->time_base = current_time ();
 112         buf->last_time = buf->time_base;
 113         buf->data_end = (unsigned char*)buf + buf->size;
 114         buf->data = buf->buf;
 115         return buf;
 116 }
 117
 118 static void
 119 init_thread (void)
 120 {
 121         LogBuffer *logbuffer;
 122         if (TLS_GET (tlsbuffer))
 123                 return;
 124         logbuffer = create_buffer ();
 125         TLS_SET (tlsbuffer, logbuffer);
 126         logbuffer->thread_id = thread_id ();
 127         //printf ("thread %p at time %llu\n", (void*)logbuffer->thread_id, logbuffer->time_base);
 128 }
 129
 130 static LogBuffer*
 131 ensure_logbuf (int bytes)
 132 {
 133         LogBuffer *old = TLS_GET (tlsbuffer);
 134         if (old && old->data + bytes + 100 < old->data_end)
 135                 return old;
 136         TLS_SET (tlsbuffer, NULL);
 137         init_thread ();
 138         TLS_GET (tlsbuffer)->next = old;
 139         if (old)
 140                 TLS_GET (tlsbuffer)->call_depth = old->call_depth;
 141         //printf ("new logbuffer\n");
 142         return TLS_GET (tlsbuffer);
 143 }
 144
 145 static void
 146 emit_byte (LogBuffer *logbuffer, int value)
 147 {
 148         logbuffer->data [0] = value;
 149         logbuffer->data++;
 150         assert (logbuffer->data <= logbuffer->data_end);
 151 }
 152
 153 static void
 154 emit_value (LogBuffer *logbuffer, int value)
 155 {
 156         encode_uleb128 (value, logbuffer->data, &logbuffer->data);
 157         assert (logbuffer->data <= logbuffer->data_end);
 158 }
 159
 160 static void
 161 emit_time (LogBuffer *logbuffer, uint64_t value)
 162 {
 163         uint64_t tdiff = value - logbuffer->last_time;
 164         unsigned char *p;
 165         if (value < logbuffer->last_time)
 166                 printf ("time went backwards\n");
 167         //if (tdiff > 1000000)
 168         //      printf ("large time offset: %llu\n", tdiff);
 169         p = logbuffer->data;
 170         encode_uleb128 (tdiff, logbuffer->data, &logbuffer->data);
 171         /*if (tdiff != decode_uleb128 (p, &p))
 172                 printf ("incorrect encoding: %llu\n", tdiff);*/
 173         logbuffer->last_time = value;
 174         assert (logbuffer->data <= logbuffer->data_end);
 175 }
 176
 177 static void
 178 emit_svalue (LogBuffer *logbuffer, int64_t value)
 179 {
 180         encode_sleb128 (value, logbuffer->data, &logbuffer->data);
 181         assert (logbuffer->data <= logbuffer->data_end);
 182 }
 183
 184 static void
 185 emit_ptr (LogBuffer *logbuffer, void *ptr)
 186 {
 187         if (!logbuffer->ptr_base)
 188                 logbuffer->ptr_base = (uintptr_t)ptr;
 189         emit_svalue (logbuffer, (intptr_t)ptr - logbuffer->ptr_base);
 190         assert (logbuffer->data <= logbuffer->data_end);
 191 }
 192
 193 static void
 194 emit_method (LogBuffer *logbuffer, void *method)
 195 {
 196         if (!logbuffer->method_base) {
 197                 logbuffer->method_base = (intptr_t)method;
 198                 logbuffer->last_method = (intptr_t)method;
 199         }
 200         encode_sleb128 ((intptr_t)((char*)method - (char*)logbuffer->last_method), logbuffer->data, &logbuffer->data);
 201         logbuffer->last_method = (intptr_t)method;
 202         assert (logbuffer->data <= logbuffer->data_end);
 203 }
 204
 205 static void
 206 emit_obj (LogBuffer *logbuffer, void *ptr)
 207 {
 208         if (!logbuffer->obj_base)
 209                 logbuffer->obj_base = (uintptr_t)ptr >> 3;
 210         emit_svalue (logbuffer, ((uintptr_t)ptr >> 3) - logbuffer->obj_base);
 211         assert (logbuffer->data <= logbuffer->data_end);
 212 }
 213
 214 static char*
 215 write_int32 (char *buf, int32_t value)
 216 {
 217         int i;
 218         for (i = 0; i < 4; ++i) {
 219                 buf [i] = value;
 220                 value >>= 8;
 221         }
 222         return buf + 4;
 223 }
 224
 225 static char*
 226 write_int64 (char *buf, int64_t value)
 227 {
 228         int i;
 229         for (i = 0; i < 8; ++i) {
 230                 buf [i] = value;
 231                 value >>= 8;
 232         }
 233         return buf + 8;
 234 }
 235
 236 static void
 237 dump_header (MonoProfiler *profiler)
 238 {
 239         char hbuf [128];
 240         char *p = hbuf;
 241         p = write_int32 (p, LOG_HEADER_ID);
 242         *p++ = LOG_VERSION_MAJOR;
 243         *p++ = LOG_VERSION_MINOR;
 244         *p++ = LOG_DATA_VERSION;
 245         *p++ = sizeof (void*);
 246         p = write_int64 (p, 0); /* startup time */
 247         p = write_int32 (p, 0); /* timer overhead */
 248         p = write_int32 (p, 0); /* flags */
 249         p = write_int32 (p, 0); /* pid */
 250         p = write_int32 (p, 0); /* opsystem */
 251         if (profiler->gzfile) {
 252                 gzwrite (profiler->gzfile, hbuf, p - hbuf);
 253         } else {
 254                 fwrite (hbuf, p - hbuf, 1, profiler->file);
 255         }
 256 }
 257
 258 static void
 259 dump_buffer (MonoProfiler *profiler, LogBuffer *buf)
 260 {
 261         char hbuf [128];
 262         char *p = hbuf;
 263         if (buf->next)
 264                 dump_buffer (profiler, buf->next);
 265         p = write_int32 (p, BUF_ID);
 266         p = write_int32 (p, buf->data - buf->buf);
 267         p = write_int64 (p, buf->time_base);
 268         p = write_int64 (p, buf->ptr_base);
 269         p = write_int64 (p, buf->obj_base);
 270         p = write_int64 (p, buf->thread_id);
 271         p = write_int64 (p, buf->method_base);
 272         if (profiler->gzfile) {
 273                 gzwrite (profiler->gzfile, hbuf, p - hbuf);
 274                 gzwrite (profiler->gzfile, buf->buf, buf->data - buf->buf);
 275         } else {
 276                 fwrite (hbuf, p - hbuf, 1, profiler->file);
 277                 fwrite (buf->buf, buf->data - buf->buf, 1, profiler->file);
 278         }
 279         free_buffer (buf, buf->size);
 280 }
 281
 282 static void
 283 runtime_initialized (MonoProfiler *profiler)
 284 {
 285         runtime_inited = 1;
 286 }
 287
 288 /*
 289  * Can be called only at safe callback locations.
 290  */
 291 static void
 292 safe_dump (MonoProfiler *profiler, LogBuffer *logbuffer)
 293 {
 294         int cd = logbuffer->call_depth;
 295         take_lock ();
 296         dump_buffer (profiler, TLS_GET (tlsbuffer));
 297         release_lock ();
 298         TLS_SET (tlsbuffer, NULL);
 299         init_thread ();
 300         TLS_GET (tlsbuffer)->call_depth = cd;
 301 }
 302
 303 static int
 304 gc_reference (MonoObject *obj, MonoClass *klass, uintptr_t size, uintptr_t num, MonoObject **refs, void *data)
 305 {
 306         int i;
 307         //const char *name = mono_class_get_name (klass);
 308         LogBuffer *logbuffer = ensure_logbuf (20 + num * 8);
 309         emit_byte (logbuffer, TYPE_HEAP_OBJECT | TYPE_HEAP);
 310         emit_obj (logbuffer, obj);
 311         emit_ptr (logbuffer, klass);
 312         emit_value (logbuffer, size);
 313         emit_value (logbuffer, num);
 314         for (i = 0; i < num; ++i)
 315                 emit_obj (logbuffer, refs [i]);
 316         //if (num)
 317         //      printf ("obj: %p, klass: %s, refs: %d, size: %d\n", obj, name, (int)num, (int)size);
 318         return 0;
 319 }
 320
 321 static unsigned int hs_mode_ms = 0;
 322 static unsigned int hs_mode_gc = 0;
 323 static unsigned int gc_count = 0;
 324 static uint64_t last_hs_time = 0;
 325
 326 static void
 327 heap_walk (MonoProfiler *profiler)
 328 {
 329         int do_walk = 0;
 330         uint64_t now;
 331         LogBuffer *logbuffer;
 332         if (!do_heap_shot)
 333                 return;
 334         logbuffer = ensure_logbuf (10);
 335         now = current_time ();
 336         if (hs_mode_ms && (now - last_hs_time)/1000000 >= hs_mode_ms)
 337                 do_walk = 1;
 338         else if (hs_mode_gc && (gc_count % hs_mode_gc) == 0)
 339                 do_walk = 1;
 340         else if (!hs_mode_ms && !hs_mode_gc && profiler->last_gc_gen_started == mono_gc_max_generation ())
 341                 do_walk = 1;
 342
 343         if (!do_walk)
 344                 return;
 345         emit_byte (logbuffer, TYPE_HEAP_START | TYPE_HEAP);
 346         emit_time (logbuffer, now);
 347         mono_gc_walk_heap (0, gc_reference, NULL);
 348         logbuffer = ensure_logbuf (10);
 349         now = current_time ();
 350         emit_byte (logbuffer, TYPE_HEAP_END | TYPE_HEAP);
 351         emit_time (logbuffer, now);
 352 }
 353
 354 static void
 355 gc_event (MonoProfiler *profiler, MonoGCEvent ev, int generation) {
 356         uint64_t now;
 357         LogBuffer *logbuffer = ensure_logbuf (10);
 358         now = current_time ();
 359         emit_byte (logbuffer, TYPE_GC_EVENT | TYPE_GC);
 360         emit_time (logbuffer, now);
 361         emit_value (logbuffer, ev);
 362         emit_value (logbuffer, generation);
 363         /* to deal with nested gen1 after gen0 started */
 364         if (ev == MONO_GC_EVENT_START) {
 365                 profiler->last_gc_gen_started = generation;
 366                 gc_count++;
 367         }
 368         if (ev == MONO_GC_EVENT_PRE_START_WORLD)
 369                 heap_walk (profiler);
 370         if (ev == MONO_GC_EVENT_POST_START_WORLD)
 371                 safe_dump (profiler, logbuffer);
 372         //printf ("gc event %d for generation %d\n", ev, generation);
 373 }
 374
 375 static void
 376 gc_resize (MonoProfiler *profiler, int64_t new_size) {
 377         uint64_t now;
 378         LogBuffer *logbuffer = ensure_logbuf (10);
 379         now = current_time ();
 380         emit_byte (logbuffer, TYPE_GC_RESIZE | TYPE_GC);
 381         emit_time (logbuffer, now);
 382         emit_value (logbuffer, new_size);
 383         //printf ("gc resized to %lld\n", new_size);
 384 }
 385
 386 #define MAX_FRAMES 16
 387 typedef struct {
 388         int count;
 389         MonoMethod* methods [MAX_FRAMES];
 390 } FrameData;
 391 static int num_frames = MAX_FRAMES / 2;
 392
 393 static mono_bool
 394 walk_stack (MonoMethod *method, int32_t native_offset, int32_t il_offset, mono_bool managed, void* data)
 395 {
 396         FrameData *frame = data;
 397         if (method && frame->count < num_frames) {
 398                 frame->methods [frame->count++] = method;
 399                 //printf ("In %d %s\n", frame->count, mono_method_get_name (method));
 400         }
 401         return frame->count == num_frames;
 402 }
 403
 404 /*
 405  * a note about stack walks: they can cause more profiler events to fire,
 406  * so we need to make sure they don't happen after we started emitting an
 407  * event, hence the collect_bt/emit_bt split.
 408  */
 409 static void
 410 collect_bt (FrameData *data)
 411 {
 412         data->count = 0;
 413         mono_stack_walk_no_il (walk_stack, data);
 414 }
 415
 416 static void
 417 emit_bt (LogBuffer *logbuffer, FrameData *data)
 418 {
 419         /* FIXME: this is actually tons of data and we should
 420          * just output it the first time and use an id the next
 421          */
 422         if (data->count > num_frames)
 423                 printf ("bad num frames: %d\n", data->count);
 424         emit_value (logbuffer, 0); /* flags */
 425         emit_value (logbuffer, data->count);
 426         //if (*p != data.count) {
 427         //      printf ("bad num frames enc at %d: %d -> %d\n", count, data.count, *p); printf ("frames end: %p->%p\n", p, logbuffer->data); exit(0);}
 428         while (data->count) {
 429                 emit_ptr (logbuffer, data->methods [--data->count]);
 430         }
 431 }
 432
 433 static void
 434 gc_alloc (MonoProfiler *prof, MonoObject *obj, MonoClass *klass)
 435 {
 436         uint64_t now;
 437         uintptr_t len;
 438         int do_bt = (nocalls && runtime_inited && !notraces)? TYPE_ALLOC_BT: 0;
 439         FrameData data;
 440         LogBuffer *logbuffer;
 441         len = mono_object_get_size (obj);
 442         if (do_bt)
 443                 collect_bt (&data);
 444         logbuffer = ensure_logbuf (32 + MAX_FRAMES * 8);
 445         now = current_time ();
 446         emit_byte (logbuffer, do_bt | TYPE_ALLOC);
 447         emit_time (logbuffer, now);
 448         emit_ptr (logbuffer, klass);
 449         emit_obj (logbuffer, obj);
 450         emit_value (logbuffer, len);
 451         if (do_bt)
 452                 emit_bt (logbuffer, &data);
 453         if (logbuffer->next)
 454                 safe_dump (prof, logbuffer);
 455         //printf ("gc alloc %s at %p\n", mono_class_get_name (klass), obj);
 456 }
 457
 458 static void
 459 gc_moves (MonoProfiler *prof, void **objects, int num)
 460 {
 461         int i;
 462         uint64_t now;
 463         LogBuffer *logbuffer = ensure_logbuf (10 + num * 8);
 464         now = current_time ();
 465         emit_byte (logbuffer, TYPE_GC_MOVE | TYPE_GC);
 466         emit_time (logbuffer, now);
 467         emit_value (logbuffer, num);
 468         for (i = 0; i < num; ++i)
 469                 emit_obj (logbuffer, objects [i]);
 470         //printf ("gc moved %d objects\n", num/2);
 471 }
 472
 473 static char*
 474 push_nesting (char *p, MonoClass *klass)
 475 {
 476         MonoClass *nesting;
 477         const char *name;
 478         const char *nspace;
 479         nesting = mono_class_get_nesting_type (klass);
 480         if (nesting) {
 481                 p = push_nesting (p, nesting);
 482                 *p++ = '/';
 483                 *p = 0;
 484         }
 485         name = mono_class_get_name (klass);
 486         nspace = mono_class_get_namespace (klass);
 487         if (*nspace) {
 488                 strcpy (p, nspace);
 489                 p += strlen (nspace);
 490                 *p++ = '.';
 491                 *p = 0;
 492         }
 493         strcpy (p, name);
 494         p += strlen (name);
 495         return p;
 496 }
 497
 498 static char*
 499 type_name (MonoClass *klass)
 500 {
 501         char buf [1024];
 502         char *p;
 503         push_nesting (buf, klass);
 504         p = malloc (strlen (buf) + 1);
 505         strcpy (p, buf);
 506         return p;
 507 }
 508
 509 static void
 510 image_loaded (MonoProfiler *prof, MonoImage *image, int result)
 511 {
 512         uint64_t now;
 513         const char *name;
 514         int nlen;
 515         LogBuffer *logbuffer;
 516         if (result != MONO_PROFILE_OK)
 517                 return;
 518         name = mono_image_get_filename (image);
 519         nlen = strlen (name) + 1;
 520         logbuffer = ensure_logbuf (16 + nlen);
 521         now = current_time ();
 522         emit_byte (logbuffer, TYPE_END_LOAD | TYPE_METADATA);
 523         emit_time (logbuffer, now);
 524         emit_byte (logbuffer, TYPE_IMAGE);
 525         emit_ptr (logbuffer, image);
 526         emit_value (logbuffer, 0); /* flags */
 527         memcpy (logbuffer->data, name, nlen);
 528         logbuffer->data += nlen;
 529         //printf ("loaded image %p (%s)\n", image, name);
 530         if (logbuffer->next)
 531                 safe_dump (prof, logbuffer);
 532 }
 533
 534 static void
 535 class_loaded (MonoProfiler *prof, MonoClass *klass, int result)
 536 {
 537         uint64_t now;
 538         char *name;
 539         int nlen;
 540         MonoImage *image;
 541         LogBuffer *logbuffer;
 542         if (result != MONO_PROFILE_OK)
 543                 return;
 544         if (runtime_inited)
 545                 name = mono_type_get_name (mono_class_get_type (klass));
 546         else
 547                 name = type_name (klass);
 548         nlen = strlen (name) + 1;
 549         image = mono_class_get_image (klass);
 550         logbuffer = ensure_logbuf (24 + nlen);
 551         now = current_time ();
 552         emit_byte (logbuffer, TYPE_END_LOAD | TYPE_METADATA);
 553         emit_time (logbuffer, now);
 554         emit_byte (logbuffer, TYPE_CLASS);
 555         emit_ptr (logbuffer, klass);
 556         emit_ptr (logbuffer, image);
 557         emit_value (logbuffer, 0); /* flags */
 558         memcpy (logbuffer->data, name, nlen);
 559         logbuffer->data += nlen;
 560         //printf ("loaded class %p (%s)\n", klass, name);
 561         if (runtime_inited)
 562                 mono_free (name);
 563         else
 564                 free (name);
 565         if (logbuffer->next)
 566                 safe_dump (prof, logbuffer);
 567 }
 568
 569 static void
 570 method_enter (MonoProfiler *prof, MonoMethod *method)
 571 {
 572         uint64_t now;
 573         LogBuffer *logbuffer = ensure_logbuf (16);
 574         if (logbuffer->call_depth++ > max_call_depth)
 575                 return;
 576         now = current_time ();
 577         emit_byte (logbuffer, TYPE_ENTER | TYPE_METHOD);
 578         emit_time (logbuffer, now);
 579         emit_method (logbuffer, method);
 580 }
 581
 582 static void
 583 method_leave (MonoProfiler *prof, MonoMethod *method)
 584 {
 585         uint64_t now;
 586         LogBuffer *logbuffer = ensure_logbuf (16);
 587         if (--logbuffer->call_depth > max_call_depth)
 588                 return;
 589         now = current_time ();
 590         emit_byte (logbuffer, TYPE_LEAVE | TYPE_METHOD);
 591         emit_time (logbuffer, now);
 592         emit_method (logbuffer, method);
 593         if (logbuffer->next)
 594                 safe_dump (prof, logbuffer);
 595 }
 596
 597 static void
 598 method_exc_leave (MonoProfiler *prof, MonoMethod *method)
 599 {
 600         uint64_t now;
 601         LogBuffer *logbuffer;
 602         if (nocalls)
 603                 return;
 604         logbuffer = ensure_logbuf (16);
 605         if (--logbuffer->call_depth > max_call_depth)
 606                 return;
 607         now = current_time ();
 608         emit_byte (logbuffer, TYPE_EXC_LEAVE | TYPE_METHOD);
 609         emit_time (logbuffer, now);
 610         emit_method (logbuffer, method);
 611 }
 612
 613 static void
 614 method_jitted (MonoProfiler *prof, MonoMethod *method, MonoJitInfo* jinfo, int result)
 615 {
 616         uint64_t now;
 617         char *name;
 618         int nlen;
 619         LogBuffer *logbuffer;
 620         if (result != MONO_PROFILE_OK)
 621                 return;
 622         name = mono_method_full_name (method, 1);
 623         nlen = strlen (name) + 1;
 624         logbuffer = ensure_logbuf (32 + nlen);
 625         now = current_time ();
 626         emit_byte (logbuffer, TYPE_JIT | TYPE_METHOD);
 627         emit_time (logbuffer, now);
 628         emit_method (logbuffer, method);
 629         emit_ptr (logbuffer, mono_jit_info_get_code_start (jinfo));
 630         emit_value (logbuffer, mono_jit_info_get_code_size (jinfo));
 631         memcpy (logbuffer->data, name, nlen);
 632         logbuffer->data += nlen;
 633         mono_free (name);
 634         if (logbuffer->next)
 635                 safe_dump (prof, logbuffer);
 636 }
 637
 638 static void
 639 throw_exc (MonoProfiler *prof, MonoObject *object)
 640 {
 641         int do_bt = (nocalls && runtime_inited && !notraces)? TYPE_EXCEPTION_BT: 0;
 642         uint64_t now;
 643         FrameData data;
 644         LogBuffer *logbuffer;
 645         if (do_bt)
 646                 collect_bt (&data);
 647         logbuffer = ensure_logbuf (16 + MAX_FRAMES * 8);
 648         now = current_time ();
 649         emit_byte (logbuffer, do_bt | TYPE_EXCEPTION);
 650         emit_time (logbuffer, now);
 651         emit_obj (logbuffer, object);
 652         if (do_bt)
 653                 emit_bt (logbuffer, &data);
 654 }
 655
 656 static void
 657 clause_exc (MonoProfiler *prof, MonoMethod *method, int clause_type, int clause_num)
 658 {
 659         uint64_t now;
 660         LogBuffer *logbuffer = ensure_logbuf (16);
 661         now = current_time ();
 662         emit_byte (logbuffer, TYPE_EXCEPTION | TYPE_CLAUSE);
 663         emit_time (logbuffer, now);
 664         emit_value (logbuffer, clause_type);
 665         emit_value (logbuffer, clause_num);
 666         emit_method (logbuffer, method);
 667 }
 668
 669 static void
 670 monitor_event (MonoProfiler *profiler, MonoObject *object, MonoProfilerMonitorEvent event)
 671 {
 672         int do_bt = (nocalls && runtime_inited && !notraces && event == MONO_PROFILER_MONITOR_CONTENTION)? TYPE_MONITOR_BT: 0;
 673         uint64_t now;
 674         FrameData data;
 675         LogBuffer *logbuffer;
 676         if (do_bt)
 677                 collect_bt (&data);
 678         logbuffer = ensure_logbuf (16 + MAX_FRAMES * 8);
 679         now = current_time ();
 680         emit_byte (logbuffer, (event << 4) | do_bt | TYPE_MONITOR);
 681         emit_time (logbuffer, now);
 682         emit_obj (logbuffer, object);
 683         if (do_bt)
 684                 emit_bt (logbuffer, &data);
 685 }
 686
 687 static void
 688 thread_start (MonoProfiler *prof, uintptr_t tid)
 689 {
 690         //printf ("thread start %p\n", (void*)tid);
 691         init_thread ();
 692 }
 693
 694 static void
 695 thread_end (MonoProfiler *prof, uintptr_t tid)
 696 {
 697         take_lock ();
 698         if (TLS_GET (tlsbuffer))
 699                 dump_buffer (prof, TLS_GET (tlsbuffer));
 700         release_lock ();
 701         TLS_SET (tlsbuffer, NULL);
 702 }
 703
 704 static void
 705 log_shutdown (MonoProfiler *prof)
 706 {
 707         take_lock ();
 708         if (TLS_GET (tlsbuffer))
 709                 dump_buffer (prof, TLS_GET (tlsbuffer));
 710         TLS_SET (tlsbuffer, NULL);
 711         release_lock ();
 712         if (prof->gzfile)
 713                 gzclose (prof->gzfile);
 714         if (prof->pipe_output)
 715                 pclose (prof->file);
 716         else
 717                 fclose (prof->file);
 718         free (prof);
 719 }
 720
 721 static MonoProfiler*
 722 create_profiler (char *filename)
 723 {
 724         MonoProfiler *prof;
 725         prof = calloc (1, sizeof (MonoProfiler));
 726         if (do_report) /* FIXME: use filename as output */
 727                 filename = "|mprof-report -";
 728
 729         if (!filename)
 730                 filename = "output.mlpd";
 731         if (*filename == '|') {
 732                 prof->file = popen (filename + 1, "w");
 733                 prof->pipe_output = 1;
 734         } else {
 735                 prof->file = fopen (filename, "wb");
 736         }
 737         if (!prof->file) {
 738                 printf ("Cannot create profiler output: %s\n", filename);
 739                 exit (1);
 740         }
 741         if (use_zip)
 742                 prof->gzfile = gzdopen (fileno (prof->file), "wb");
 743         dump_header (prof);
 744         return prof;
 745 }
 746
 747 static void
 748 usage (int do_exit)
 749 {
 750         printf ("Log profiler version %d.%d (format: %d)\n", LOG_VERSION_MAJOR, LOG_VERSION_MINOR, LOG_DATA_VERSION);
 751         printf ("Usage: mono --profile=log[:OPTION1[,OPTION2...]] program.exe\n");
 752         printf ("Options:\n");
 753         printf ("\thelp             show this usage info\n");
 754         printf ("\t[no]alloc        enable/disable recording allocation info\n");
 755         printf ("\t[no]calls        enable/disable recording enter/leave method events\n");
 756         printf ("\theapshot         record heap shot info (by default at each major collection)\n");
 757         printf ("\thsmode=MODE      heapshot mode: every XXms milliseconds or every YYgc collections\n");
 758         printf ("\ttime=fast        use a faster (but more inaccurate) timer\n");
 759         printf ("\tmaxframes=NUM    collect up to NUM stack frames\n");
 760         printf ("\tcalldepth=NUM    ignore method events for call chain depth bigger than NUM\n");
 761         printf ("\toutput=FILENAME  write the data to file FILENAME\n");
 762         printf ("\toutput=|PROGRAM  write the data to the stdin of PROGRAM\n");
 763         printf ("\treport           create a report instead of writing the raw data to a file\n");
 764         printf ("\tzip              compress the output data\n");
 765         if (do_exit)
 766                 exit (1);
 767 }
 768
 769 const char*
 770 match_option (const char* p, const char *opt, char **rval)
 771 {
 772         int len = strlen (opt);
 773         if (strncmp (p, opt, len) == 0) {
 774                 if (rval) {
 775                         if (p [len] == '=' && p [len + 1]) {
 776                                 const char *opt = p + len + 1;
 777                                 const char *end = strchr (opt, ',');
 778                                 char *val;
 779                                 int l;
 780                                 if (end == NULL) {
 781                                         l = strlen (opt);
 782                                 } else {
 783                                         l = end - opt;
 784                                 }
 785                                 val = malloc (l + 1);
 786                                 memcpy (val, opt, l);
 787                                 val [l] = 0;
 788                                 *rval = val;
 789                                 return opt + l;
 790                         }
 791                         usage (1);
 792                 } else {
 793                         if (p [len] == 0)
 794                                 return p + len;
 795                         if (p [len] == ',')
 796                                 return p + len + 1;
 797                 }
 798         }
 799         return p;
 800 }
 801
 802 void
 803 mono_profiler_startup (const char *desc)
 804 {
 805         MonoProfiler *prof;
 806         char *filename = NULL;
 807         const char *p;
 808         const char *opt;
 809         int fast_time = 0;
 810         int calls_enabled = 0;
 811         int allocs_enabled = 0;
 812         int events = MONO_PROFILE_GC|MONO_PROFILE_ALLOCATIONS|
 813                 MONO_PROFILE_GC_MOVES|MONO_PROFILE_CLASS_EVENTS|MONO_PROFILE_THREADS|
 814                 MONO_PROFILE_ENTER_LEAVE|MONO_PROFILE_JIT_COMPILATION|MONO_PROFILE_EXCEPTIONS|
 815                 MONO_PROFILE_MONITOR_EVENTS|MONO_PROFILE_MODULE_EVENTS;
 816
 817         p = desc;
 818         if (strncmp (p, "log", 3))
 819                 usage (1);
 820         p += 3;
 821         if (*p == ':')
 822                 p++;
 823         for (; *p; p = opt) {
 824                 char *val;
 825                 if (*p == ',') {
 826                         opt = p + 1;
 827                         continue;
 828                 }
 829                 if ((opt = match_option (p, "help", NULL)) != p) {
 830                         usage (0);
 831                         continue;
 832                 }
 833                 if ((opt = match_option (p, "calls", NULL)) != p) {
 834                         calls_enabled = 1;
 835                         continue;
 836                 }
 837                 if ((opt = match_option (p, "nocalls", NULL)) != p) {
 838                         events &= ~MONO_PROFILE_ENTER_LEAVE;
 839                         nocalls = 1;
 840                         continue;
 841                 }
 842                 if ((opt = match_option (p, "alloc", NULL)) != p) {
 843                         allocs_enabled = 1;
 844                         continue;
 845                 }
 846                 if ((opt = match_option (p, "noalloc", NULL)) != p) {
 847                         events &= ~MONO_PROFILE_ALLOCATIONS;
 848                         continue;
 849                 }
 850                 if ((opt = match_option (p, "time", &val)) != p) {
 851                         if (strcmp (val, "fast") == 0)
 852                                 fast_time = 1;
 853                         else if (strcmp (val, "null") == 0)
 854                                 fast_time = 2;
 855                         else
 856                                 usage (1);
 857                         free (val);
 858                         continue;
 859                 }
 860                 if ((opt = match_option (p, "report", NULL)) != p) {
 861                         do_report = 1;
 862                         continue;
 863                 }
 864                 if ((opt = match_option (p, "heapshot", NULL)) != p) {
 865                         events &= ~MONO_PROFILE_ALLOCATIONS;
 866                         events &= ~MONO_PROFILE_ENTER_LEAVE;
 867                         nocalls = 1;
 868                         do_heap_shot = 1;
 869                         continue;
 870                 }
 871                 if ((opt = match_option (p, "hsmode", &val)) != p) {
 872                         char *end;
 873                         unsigned int count = strtoul (val, &end, 10);
 874                         if (val == end)
 875                                 usage (1);
 876                         if (strcmp (end, "ms") == 0)
 877                                 hs_mode_ms = count;
 878                         else if (strcmp (end, "gc") == 0)
 879                                 hs_mode_gc = count;
 880                         else
 881                                 usage (1);
 882                         free (val);
 883                         continue;
 884                 }
 885                 if ((opt = match_option (p, "zip", NULL)) != p) {
 886                         use_zip = 1;
 887                         continue;
 888                 }
 889                 if ((opt = match_option (p, "output", &val)) != p) {
 890                         filename = val;
 891                         continue;
 892                 }
 893                 if ((opt = match_option (p, "maxframes", &val)) != p) {
 894                         char *end;
 895                         num_frames = strtoul (val, &end, 10);
 896                         if (num_frames > MAX_FRAMES)
 897                                 num_frames = MAX_FRAMES;
 898                         free (val);
 899                         notraces = num_frames == 0;
 900                         continue;
 901                 }
 902                 if ((opt = match_option (p, "calldepth", &val)) != p) {
 903                         char *end;
 904                         max_call_depth = strtoul (val, &end, 10);
 905                         free (val);
 906                         continue;
 907                 }
 908                 if (opt == p) {
 909                         usage (0);
 910                         exit (0);
 911                 }
 912         }
 913         if (calls_enabled) {
 914                 events |= MONO_PROFILE_ENTER_LEAVE;
 915                 nocalls = 0;
 916         }
 917         if (allocs_enabled)
 918                 events |= MONO_PROFILE_ALLOCATIONS;
 919         utils_init (fast_time);
 920
 921         prof = create_profiler (filename);
 922         init_thread ();
 923
 924         mono_profiler_install (prof, log_shutdown);
 925         mono_profiler_install_gc (gc_event, gc_resize);
 926         mono_profiler_install_allocation (gc_alloc);
 927         mono_profiler_install_gc_moves (gc_moves);
 928         mono_profiler_install_class (NULL, class_loaded, NULL, NULL);
 929         mono_profiler_install_module (NULL, image_loaded, NULL, NULL);
 930         mono_profiler_install_thread (thread_start, thread_end);
 931         mono_profiler_install_enter_leave (method_enter, method_leave);
 932         mono_profiler_install_jit_end (method_jitted);
 933         mono_profiler_install_exception (throw_exc, method_exc_leave, clause_exc);
 934         mono_profiler_install_monitor (monitor_event);
 935         mono_profiler_install_runtime_initialized (runtime_initialized);
 936
 937         mono_profiler_set_events (events);
 938
 939         TLS_INIT (tlsbuffer);
 940 }
 941