mono/profiler/proflog.c

   1 /*
   2  * proflog.c: mono log profiler
   3  *
   4  * Author:
   5  *   Paolo Molaro (lupus@ximian.com)
   6  *
   7  * Copyright 2010 Novell, Inc (http://www.novell.com)
   8  */
   9
  10 #include <config.h>
  11 #include <mono/metadata/profiler.h>
  12 #include <mono/metadata/threads.h>
  13 #include <mono/metadata/mono-gc.h>
  14 #include <mono/metadata/debug-helpers.h>
  15 #include <stdlib.h>
  16 #include <string.h>
  17 #include <assert.h>
  18 #include <errno.h>
  19 #if defined(HOST_WIN32) || defined(DISABLE_SOCKETS)
  20 #define DISABLE_HELPER_THREAD 1
  21 #endif
  22
  23 #ifndef DISABLE_HELPER_THREAD
  24 #include <sys/types.h>
  25 #include <sys/socket.h>
  26 #include <netinet/in.h>
  27 #include <sys/select.h>
  28 #endif
  29
  30 #ifdef HOST_WIN32
  31 #include <windows.h>
  32 #else
  33 #include <pthread.h>
  34 #endif
  35
  36 #include "utils.c"
  37 #include "proflog.h"
  38
  39 #if defined (HAVE_SYS_ZLIB)
  40 #include <zlib.h>
  41 #endif
  42
  43 #define BUFFER_SIZE (4096 * 16)
  44 static int nocalls = 0;
  45 static int notraces = 0;
  46 static int use_zip = 0;
  47 static int do_report = 0;
  48 static int do_heap_shot = 0;
  49 static int max_call_depth = 100;
  50 static int runtime_inited = 0;
  51 static int command_port = 0;
  52 static int heapshot_requested = 0;
  53
  54 /* For linux compile with:
  55  * gcc -fPIC -shared -o libmono-profiler-log.so proflog.c utils.c -Wall -g -lz `pkg-config --cflags --libs mono-2`
  56  * gcc -o mprof-report decode.c utils.c -Wall -g -lz -lrt -lpthread `pkg-config --cflags mono-2`
  57  *
  58  * For osx compile with:
  59  * 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
  60  * gcc -m32 -o mprof-report decode.c utils.c -Wall -g -lz -lrt -lpthread `pkg-config --cflags mono-2`
  61  *
  62  * Install with:
  63  * sudo cp mprof-report /usr/local/bin
  64  * sudo cp libmono-profiler-log.so /usr/local/lib
  65  * sudo ldconfig
  66  */
  67
  68 typedef struct _LogBuffer LogBuffer;
  69
  70 /*
  71  * file format:
  72  * [header] [buffer]*
  73  *
  74  * The file is composed by a header followed by 0 or more buffers.
  75  * Each buffer contains events that happened on a thread: for a given thread
  76  * buffers that appear later in the file are guaranteed to contain events
  77  * that happened later in time. Buffers from separate threads could be interleaved,
  78  * though.
  79  * Buffers are not required to be aligned.
  80  *
  81  * header format:
  82  * [id: 4 bytes] constant value: LOG_HEADER_ID
  83  * [major: 1 byte] [minor: 1 byte] major and minor version of the log profiler
  84  * [format: 1 byte] version of the data format for the rest of the file
  85  * [ptrsize: 1 byte] size in bytes of a pointer in the profiled program
  86  * [startup time: 8 bytes] time in milliseconds since the unix epoch when the program started
  87  * [timer overhead: 4 bytes] approximate overhead in nanoseconds of the timer
  88  * [flags: 4 bytes] file format flags, should be 0 for now
  89  * [pid: 4 bytes] pid of the profiled process
  90  * [port: 2 bytes] tcp port for server if != 0
  91  * [sysid: 2 bytes] operating system and architecture identifier
  92  *
  93  * The multiple byte integers are in little-endian format.
  94  *
  95  * buffer format:
  96  * [buffer header] [event]*
  97  * Buffers have a fixed-size header followed by 0 or more bytes of event data.
  98  * Timing information and other values in the event data are usually stored
  99  * as uleb128 or sleb128 integers. To save space, as noted for each item below,
 100  * some data is represented as a difference between the actual value and
 101  * either the last value of the same type (like for timing information) or
 102  * as the difference from a value stored in a buffer header.
 103  *
 104  * For timing information the data is stored as uleb128, since timing
 105  * increases in a monotonic way in each thread: the value is the number of
 106  * nanoseconds to add to the last seen timing data in a buffer. The first value
 107  * in a buffer will be calculated from the time_base field in the buffer head.
 108  *
 109  * Object or heap sizes are stored as uleb128.
 110  * Pointer differences are stored as sleb128, instead.
 111  *
 112  * If an unexpected value is found, the rest of the buffer should be ignored,
 113  * as generally the later values need the former to be interpreted correctly.
 114  *
 115  * buffer header format:
 116  * [bufid: 4 bytes] constant value: BUF_ID
 117  * [len: 4 bytes] size of the data following the buffer header
 118  * [time_base: 8 bytes] time base in nanoseconds since an unspecified epoch
 119  * [ptr_base: 8 bytes] base value for pointers
 120  * [obj_base: 8 bytes] base value for object addresses
 121  * [thread id: 8 bytes] system-specific thread ID (pthread_t for example)
 122  * [method_base: 8 bytes] base value for MonoMethod pointers
 123  *
 124  * event format:
 125  * [extended info: upper 4 bits] [type: lower 4 bits] [data]*
 126  * The data that follows depends on type and the extended info.
 127  * Type is one of the enum values in proflog.h: TYPE_ALLOC, TYPE_GC,
 128  * TYPE_METADATA, TYPE_METHOD, TYPE_EXCEPTION, TYPE_MONITOR, TYPE_HEAP.
 129  * The extended info bits are interpreted based on type, see
 130  * each individual event description below.
 131  * strings are represented as a 0-terminated utf8 sequence.
 132  *
 133  * backtrace format:
 134  * [flags: uleb128] must be 0
 135  * [num: uleb128] number of frames following
 136  * [frame: sleb128]* num MonoMethod pointers as differences from ptr_base
 137  *
 138  * type alloc format:
 139  * type: TYPE_ALLOC
 140  * exinfo: flags: TYPE_ALLOC_BT
 141  * [time diff: uleb128] nanoseconds since last timing
 142  * [ptr: sleb128] class as a byte difference from ptr_base
 143  * [obj: sleb128] object address as a byte difference from obj_base
 144  * [size: uleb128] size of the object in the heap
 145  * If the TYPE_ALLOC_BT flag is set, a backtrace follows.
 146  *
 147  * type GC format:
 148  * type: TYPE_GC
 149  * exinfo: one of TYPE_GC_EVENT, TYPE_GC_RESIZE, TYPE_GC_MOVE, TYPE_GC_HANDLE_CREATED,
 150  * TYPE_GC_HANDLE_DESTROYED
 151  * [time diff: uleb128] nanoseconds since last timing
 152  * if exinfo == TYPE_GC_RESIZE
 153  *      [heap_size: uleb128] new heap size
 154  * if exinfo == TYPE_GC_EVENT
 155  *      [event type: uleb128] GC event (MONO_GC_EVENT_* from profiler.h)
 156  *      [generation: uleb128] GC generation event refers to
 157  * if exinfo == TYPE_GC_MOVE
 158  *      [num_objects: uleb128] number of object moves that follow
 159  *      [objaddr: sleb128]+ num_objects object pointer differences from obj_base
 160  *      num is always an even number: the even items are the old
 161  *      addresses, the odd numbers are the respective new object addresses
 162  * if exinfo == TYPE_GC_HANDLE_CREATED
 163  *      [handle_type: uleb128] GC handle type (System.Runtime.InteropServices.GCHandleType)
 164  *      upper bits reserved as flags
 165  *      [handle: uleb128] GC handle value
 166  *      [objaddr: sleb128] object pointer differences from obj_base
 167  * if exinfo == TYPE_GC_HANDLE_DESTROYED
 168  *      [handle_type: uleb128] GC handle type (System.Runtime.InteropServices.GCHandleType)
 169  *      upper bits reserved as flags
 170  *      [handle: uleb128] GC handle value
 171  *
 172  * type metadata format:
 173  * type: TYPE_METADATA
 174  * exinfo: flags: TYPE_LOAD_ERR
 175  * [time diff: uleb128] nanoseconds since last timing
 176  * [mtype: byte] metadata type, one of: TYPE_CLASS, TYPE_IMAGE, TYPE_ASSEMBLY, TYPE_DOMAIN,
 177  * TYPE_THREAD
 178  * [pointer: sleb128] pointer of the metadata type depending on mtype
 179  * if mtype == TYPE_CLASS
 180  *      [image: sleb128] MonoImage* as a pointer difference from ptr_base
 181  *      [flags: uleb128] must be 0
 182  *      [name: string] full class name
 183  * if mtype == TYPE_IMAGE
 184  *      [flags: uleb128] must be 0
 185  *      [name: string] image file name
 186  * if mtype == TYPE_THREAD
 187  *      [flags: uleb128] must be 0
 188  *      [name: string] thread name
 189  *
 190  * type method format:
 191  * type: TYPE_METHOD
 192  * exinfo: one of: TYPE_LEAVE, TYPE_ENTER, TYPE_EXC_LEAVE, TYPE_JIT
 193  * [time diff: uleb128] nanoseconds since last timing
 194  * [method: sleb128] MonoMethod* as a pointer difference from the last such
 195  * pointer or the buffer method_base
 196  * if exinfo == TYPE_JIT
 197  *      [code address: sleb128] pointer to the native code as a diff from ptr_base
 198  *      [code size: uleb128] size of the generated code
 199  *      [name: string] full method name
 200  *
 201  * type exception format:
 202  * type: TYPE_EXCEPTION
 203  * exinfo: TYPE_EXCEPTION_BT flag and one of: TYPE_THROW, TYPE_CLAUSE
 204  * [time diff: uleb128] nanoseconds since last timing
 205  * if exinfo.low3bits == TYPE_CLAUSE
 206  *      [clause type: uleb128] finally/catch/fault/filter
 207  *      [clause num: uleb128] the clause number in the method header
 208  *      [method: sleb128] MonoMethod* as a pointer difference from the last such
 209  *      pointer or the buffer method_base
 210  * if exinfo.low3bits == TYPE_THROW
 211  *      [object: sleb128] the object that was thrown as a difference from obj_base
 212  *      If the TYPE_EXCEPTION_BT flag is set, a backtrace follows.
 213  *
 214  * type monitor format:
 215  * type: TYPE_MONITOR
 216  * exinfo: TYPE_MONITOR_BT flag and one of: MONO_PROFILER_MONITOR_(CONTENTION|FAIL|DONE)
 217  * [time diff: uleb128] nanoseconds since last timing
 218  * [object: sleb128] the lock object as a difference from obj_base
 219  * if exinfo.low3bits == MONO_PROFILER_MONITOR_CONTENTION
 220  *      If the TYPE_MONITOR_BT flag is set, a backtrace follows.
 221  *
 222  * type heap format
 223  * type: TYPE_HEAP
 224  * exinfo: one of TYPE_HEAP_START, TYPE_HEAP_END, TYPE_HEAP_OBJECT, TYPE_HEAP_ROOT
 225  * if exinfo == TYPE_HEAP_START
 226  *      [time diff: uleb128] nanoseconds since last timing
 227  * if exinfo == TYPE_HEAP_END
 228  *      [time diff: uleb128] nanoseconds since last timing
 229  * if exinfo == TYPE_HEAP_OBJECT
 230  *      [object: sleb128] the object as a difference from obj_base
 231  *      [class: sleb128] the object MonoClass* as a difference from ptr_base
 232  *      [size: uleb128] size of the object on the heap
 233  *      [num_refs: uleb128] number of object references
 234  *      if (format version > 1) each referenced objref is preceded by a
 235  *      uleb128 encoded offset: the first offset is from the object address
 236  *      and each next offset is relative to the previous one
 237  *      [objrefs: sleb128]+ object referenced as a difference from obj_base
 238  * if exinfo == TYPE_HEAP_ROOT
 239  *      [num_roots: uleb128] number of root references
 240  *      [num_gc: uleb128] number of major gcs
 241  *      [object: sleb128] the object as a difference from obj_base
 242  *      [root_type: uleb128] the root_type
 243  *      [extra_info: uleb128] the extra_info value
 244  *      object, root_type_extra_info are repeated num_roots times
 245  *
 246  */
 247 struct _LogBuffer {
 248         LogBuffer *next;
 249         uint64_t time_base;
 250         uint64_t last_time;
 251         uintptr_t ptr_base;
 252         uintptr_t method_base;
 253         uintptr_t last_method;
 254         uintptr_t obj_base;
 255         uintptr_t thread_id;
 256         unsigned char* data_end;
 257         unsigned char* data;
 258         int locked;
 259         int size;
 260         int call_depth;
 261         unsigned char buf [1];
 262 };
 263
 264 #define ENTER_LOG(lb,str) if ((lb)->locked) {write(2, str, strlen(str)); write(2, "\n", 1);return;} else {(lb)->locked++;}
 265 #define EXIT_LOG(lb) (lb)->locked--;
 266
 267 struct _MonoProfiler {
 268         LogBuffer *buffers;
 269         FILE* file;
 270 #if defined (HAVE_SYS_ZLIB)
 271         gzFile *gzfile;
 272 #endif
 273         int pipe_output;
 274         int last_gc_gen_started;
 275         int command_port;
 276         int server_socket;
 277         int pipes [2];
 278 #ifndef HOST_WIN32
 279         pthread_t helper_thread;
 280 #endif
 281 };
 282
 283 #ifdef HOST_WIN32
 284 #define TLS_SET(x,y) TlsSetValue(x, y)
 285 #define TLS_GET(x) ((LogBuffer *) TlsGetValue(x))
 286 #define TLS_INIT(x) x = TlsAlloc ()
 287 static int tlsbuffer;
 288 #elif HAVE_KW_THREAD
 289 #define TLS_SET(x,y) x = y
 290 #define TLS_GET(x) x
 291 #define TLS_INIT(x)
 292 static __thread LogBuffer* tlsbuffer = NULL;
 293 #else
 294 #define TLS_SET(x,y) pthread_setspecific(x, y)
 295 #define TLS_GET(x) ((LogBuffer *) pthread_getspecific(x))
 296 #define TLS_INIT(x) pthread_key_create(&x, NULL)
 297 static pthread_key_t tlsbuffer;
 298 #endif
 299
 300 static char*
 301 pstrdup (const char *s)
 302 {
 303         int len = strlen (s) + 1;
 304         char *p = malloc (len);
 305         memcpy (p, s, len);
 306         return p;
 307 }
 308
 309 static LogBuffer*
 310 create_buffer (void)
 311 {
 312         LogBuffer* buf = alloc_buffer (BUFFER_SIZE);
 313         buf->size = BUFFER_SIZE;
 314         buf->time_base = current_time ();
 315         buf->last_time = buf->time_base;
 316         buf->data_end = (unsigned char*)buf + buf->size;
 317         buf->data = buf->buf;
 318         return buf;
 319 }
 320
 321 static void
 322 init_thread (void)
 323 {
 324         LogBuffer *logbuffer;
 325         if (TLS_GET (tlsbuffer))
 326                 return;
 327         logbuffer = create_buffer ();
 328         TLS_SET (tlsbuffer, logbuffer);
 329         logbuffer->thread_id = thread_id ();
 330         //printf ("thread %p at time %llu\n", (void*)logbuffer->thread_id, logbuffer->time_base);
 331 }
 332
 333 static LogBuffer*
 334 ensure_logbuf (int bytes)
 335 {
 336         LogBuffer *old = TLS_GET (tlsbuffer);
 337         if (old && old->data + bytes + 100 < old->data_end)
 338                 return old;
 339         TLS_SET (tlsbuffer, NULL);
 340         init_thread ();
 341         TLS_GET (tlsbuffer)->next = old;
 342         if (old)
 343                 TLS_GET (tlsbuffer)->call_depth = old->call_depth;
 344         //printf ("new logbuffer\n");
 345         return TLS_GET (tlsbuffer);
 346 }
 347
 348 static void
 349 emit_byte (LogBuffer *logbuffer, int value)
 350 {
 351         logbuffer->data [0] = value;
 352         logbuffer->data++;
 353         assert (logbuffer->data <= logbuffer->data_end);
 354 }
 355
 356 static void
 357 emit_value (LogBuffer *logbuffer, int value)
 358 {
 359         encode_uleb128 (value, logbuffer->data, &logbuffer->data);
 360         assert (logbuffer->data <= logbuffer->data_end);
 361 }
 362
 363 static void
 364 emit_time (LogBuffer *logbuffer, uint64_t value)
 365 {
 366         uint64_t tdiff = value - logbuffer->last_time;
 367         unsigned char *p;
 368         if (value < logbuffer->last_time)
 369                 printf ("time went backwards\n");
 370         //if (tdiff > 1000000)
 371         //      printf ("large time offset: %llu\n", tdiff);
 372         p = logbuffer->data;
 373         encode_uleb128 (tdiff, logbuffer->data, &logbuffer->data);
 374         /*if (tdiff != decode_uleb128 (p, &p))
 375                 printf ("incorrect encoding: %llu\n", tdiff);*/
 376         logbuffer->last_time = value;
 377         assert (logbuffer->data <= logbuffer->data_end);
 378 }
 379
 380 static void
 381 emit_svalue (LogBuffer *logbuffer, int64_t value)
 382 {
 383         encode_sleb128 (value, logbuffer->data, &logbuffer->data);
 384         assert (logbuffer->data <= logbuffer->data_end);
 385 }
 386
 387 static void
 388 emit_ptr (LogBuffer *logbuffer, void *ptr)
 389 {
 390         if (!logbuffer->ptr_base)
 391                 logbuffer->ptr_base = (uintptr_t)ptr;
 392         emit_svalue (logbuffer, (intptr_t)ptr - logbuffer->ptr_base);
 393         assert (logbuffer->data <= logbuffer->data_end);
 394 }
 395
 396 static void
 397 emit_method (LogBuffer *logbuffer, void *method)
 398 {
 399         if (!logbuffer->method_base) {
 400                 logbuffer->method_base = (intptr_t)method;
 401                 logbuffer->last_method = (intptr_t)method;
 402         }
 403         encode_sleb128 ((intptr_t)((char*)method - (char*)logbuffer->last_method), logbuffer->data, &logbuffer->data);
 404         logbuffer->last_method = (intptr_t)method;
 405         assert (logbuffer->data <= logbuffer->data_end);
 406 }
 407
 408 static void
 409 emit_obj (LogBuffer *logbuffer, void *ptr)
 410 {
 411         if (!logbuffer->obj_base)
 412                 logbuffer->obj_base = (uintptr_t)ptr >> 3;
 413         emit_svalue (logbuffer, ((uintptr_t)ptr >> 3) - logbuffer->obj_base);
 414         assert (logbuffer->data <= logbuffer->data_end);
 415 }
 416
 417 static char*
 418 write_int16 (char *buf, int32_t value)
 419 {
 420         int i;
 421         for (i = 0; i < 2; ++i) {
 422                 buf [i] = value;
 423                 value >>= 8;
 424         }
 425         return buf + 2;
 426 }
 427
 428 static char*
 429 write_int32 (char *buf, int32_t value)
 430 {
 431         int i;
 432         for (i = 0; i < 4; ++i) {
 433                 buf [i] = value;
 434                 value >>= 8;
 435         }
 436         return buf + 4;
 437 }
 438
 439 static char*
 440 write_int64 (char *buf, int64_t value)
 441 {
 442         int i;
 443         for (i = 0; i < 8; ++i) {
 444                 buf [i] = value;
 445                 value >>= 8;
 446         }
 447         return buf + 8;
 448 }
 449
 450 static void
 451 dump_header (MonoProfiler *profiler)
 452 {
 453         char hbuf [128];
 454         char *p = hbuf;
 455         p = write_int32 (p, LOG_HEADER_ID);
 456         *p++ = LOG_VERSION_MAJOR;
 457         *p++ = LOG_VERSION_MINOR;
 458         *p++ = LOG_DATA_VERSION;
 459         *p++ = sizeof (void*);
 460         p = write_int64 (p, ((uint64_t)time (NULL)) * 1000); /* startup time */
 461         p = write_int32 (p, get_timer_overhead ()); /* timer overhead */
 462         p = write_int32 (p, 0); /* flags */
 463         p = write_int32 (p, process_id ()); /* pid */
 464         p = write_int16 (p, profiler->command_port); /* port */
 465         p = write_int16 (p, 0); /* opsystem */
 466 #if defined (HAVE_SYS_ZLIB)
 467         if (profiler->gzfile) {
 468                 gzwrite (profiler->gzfile, hbuf, p - hbuf);
 469         } else {
 470                 fwrite (hbuf, p - hbuf, 1, profiler->file);
 471         }
 472 #else
 473         fwrite (hbuf, p - hbuf, 1, profiler->file);
 474 #endif
 475 }
 476
 477 static void
 478 dump_buffer (MonoProfiler *profiler, LogBuffer *buf)
 479 {
 480         char hbuf [128];
 481         char *p = hbuf;
 482         if (buf->next)
 483                 dump_buffer (profiler, buf->next);
 484         p = write_int32 (p, BUF_ID);
 485         p = write_int32 (p, buf->data - buf->buf);
 486         p = write_int64 (p, buf->time_base);
 487         p = write_int64 (p, buf->ptr_base);
 488         p = write_int64 (p, buf->obj_base);
 489         p = write_int64 (p, buf->thread_id);
 490         p = write_int64 (p, buf->method_base);
 491 #if defined (HAVE_SYS_ZLIB)
 492         if (profiler->gzfile) {
 493                 gzwrite (profiler->gzfile, hbuf, p - hbuf);
 494                 gzwrite (profiler->gzfile, buf->buf, buf->data - buf->buf);
 495         } else {
 496 #endif
 497                 fwrite (hbuf, p - hbuf, 1, profiler->file);
 498                 fwrite (buf->buf, buf->data - buf->buf, 1, profiler->file);
 499 #if defined (HAVE_SYS_ZLIB)
 500         }
 501 #endif
 502         free_buffer (buf, buf->size);
 503 }
 504
 505 static void
 506 process_requests (MonoProfiler *profiler)
 507 {
 508         if (heapshot_requested)
 509                 mono_gc_collect (mono_gc_max_generation ());
 510 }
 511
 512 static void
 513 runtime_initialized (MonoProfiler *profiler)
 514 {
 515         runtime_inited = 1;
 516 }
 517
 518 /*
 519  * Can be called only at safe callback locations.
 520  */
 521 static void
 522 safe_dump (MonoProfiler *profiler, LogBuffer *logbuffer)
 523 {
 524         int cd = logbuffer->call_depth;
 525         take_lock ();
 526         dump_buffer (profiler, TLS_GET (tlsbuffer));
 527         release_lock ();
 528         TLS_SET (tlsbuffer, NULL);
 529         init_thread ();
 530         TLS_GET (tlsbuffer)->call_depth = cd;
 531 }
 532
 533 static int
 534 gc_reference (MonoObject *obj, MonoClass *klass, uintptr_t size, uintptr_t num, MonoObject **refs, uintptr_t *offsets, void *data)
 535 {
 536         int i;
 537         uintptr_t last_offset = 0;
 538         //const char *name = mono_class_get_name (klass);
 539         LogBuffer *logbuffer = ensure_logbuf (20 + num * 8);
 540         emit_byte (logbuffer, TYPE_HEAP_OBJECT | TYPE_HEAP);
 541         emit_obj (logbuffer, obj);
 542         emit_ptr (logbuffer, klass);
 543         /* account for object alignment in the heap */
 544         size += 7;
 545         size &= ~7;
 546         emit_value (logbuffer, size);
 547         emit_value (logbuffer, num);
 548         for (i = 0; i < num; ++i) {
 549                 emit_value (logbuffer, offsets [i] - last_offset);
 550                 last_offset = offsets [i];
 551                 emit_obj (logbuffer, refs [i]);
 552         }
 553         //if (num)
 554         //      printf ("obj: %p, klass: %s, refs: %d, size: %d\n", obj, name, (int)num, (int)size);
 555         return 0;
 556 }
 557
 558 static unsigned int hs_mode_ms = 0;
 559 static unsigned int hs_mode_gc = 0;
 560 static unsigned int hs_mode_ondemand = 0;
 561 static unsigned int gc_count = 0;
 562 static uint64_t last_hs_time = 0;
 563
 564 static void
 565 heap_walk (MonoProfiler *profiler)
 566 {
 567         int do_walk = 0;
 568         uint64_t now;
 569         LogBuffer *logbuffer;
 570         if (!do_heap_shot)
 571                 return;
 572         logbuffer = ensure_logbuf (10);
 573         now = current_time ();
 574         if (hs_mode_ms && (now - last_hs_time)/1000000 >= hs_mode_ms)
 575                 do_walk = 1;
 576         else if (hs_mode_gc && (gc_count % hs_mode_gc) == 0)
 577                 do_walk = 1;
 578         else if (hs_mode_ondemand && heapshot_requested)
 579                 do_walk = 1;
 580         else if (!hs_mode_ms && !hs_mode_gc && profiler->last_gc_gen_started == mono_gc_max_generation ())
 581                 do_walk = 1;
 582
 583         if (!do_walk)
 584                 return;
 585         heapshot_requested = 0;
 586         emit_byte (logbuffer, TYPE_HEAP_START | TYPE_HEAP);
 587         emit_time (logbuffer, now);
 588         mono_gc_walk_heap (0, gc_reference, NULL);
 589         logbuffer = ensure_logbuf (10);
 590         now = current_time ();
 591         emit_byte (logbuffer, TYPE_HEAP_END | TYPE_HEAP);
 592         emit_time (logbuffer, now);
 593         last_hs_time = now;
 594 }
 595
 596 static void
 597 gc_event (MonoProfiler *profiler, MonoGCEvent ev, int generation) {
 598         uint64_t now;
 599         LogBuffer *logbuffer = ensure_logbuf (10);
 600         now = current_time ();
 601         ENTER_LOG (logbuffer, "gcevent");
 602         emit_byte (logbuffer, TYPE_GC_EVENT | TYPE_GC);
 603         emit_time (logbuffer, now);
 604         emit_value (logbuffer, ev);
 605         emit_value (logbuffer, generation);
 606         /* to deal with nested gen1 after gen0 started */
 607         if (ev == MONO_GC_EVENT_START) {
 608                 profiler->last_gc_gen_started = generation;
 609                 if (generation == mono_gc_max_generation ())
 610                         gc_count++;
 611         }
 612         if (ev == MONO_GC_EVENT_PRE_START_WORLD)
 613                 heap_walk (profiler);
 614         EXIT_LOG (logbuffer);
 615         if (ev == MONO_GC_EVENT_POST_START_WORLD)
 616                 safe_dump (profiler, logbuffer);
 617         //printf ("gc event %d for generation %d\n", ev, generation);
 618 }
 619
 620 static void
 621 gc_resize (MonoProfiler *profiler, int64_t new_size) {
 622         uint64_t now;
 623         LogBuffer *logbuffer = ensure_logbuf (10);
 624         now = current_time ();
 625         ENTER_LOG (logbuffer, "gcresize");
 626         emit_byte (logbuffer, TYPE_GC_RESIZE | TYPE_GC);
 627         emit_time (logbuffer, now);
 628         emit_value (logbuffer, new_size);
 629         //printf ("gc resized to %lld\n", new_size);
 630         EXIT_LOG (logbuffer);
 631 }
 632
 633 #define MAX_FRAMES 16
 634 typedef struct {
 635         int count;
 636         MonoMethod* methods [MAX_FRAMES];
 637 } FrameData;
 638 static int num_frames = MAX_FRAMES / 2;
 639
 640 static mono_bool
 641 walk_stack (MonoMethod *method, int32_t native_offset, int32_t il_offset, mono_bool managed, void* data)
 642 {
 643         FrameData *frame = data;
 644         if (method && frame->count < num_frames) {
 645                 frame->methods [frame->count++] = method;
 646                 //printf ("In %d %s\n", frame->count, mono_method_get_name (method));
 647         }
 648         return frame->count == num_frames;
 649 }
 650
 651 /*
 652  * a note about stack walks: they can cause more profiler events to fire,
 653  * so we need to make sure they don't happen after we started emitting an
 654  * event, hence the collect_bt/emit_bt split.
 655  */
 656 static void
 657 collect_bt (FrameData *data)
 658 {
 659         data->count = 0;
 660         mono_stack_walk_no_il (walk_stack, data);
 661 }
 662
 663 static void
 664 emit_bt (LogBuffer *logbuffer, FrameData *data)
 665 {
 666         /* FIXME: this is actually tons of data and we should
 667          * just output it the first time and use an id the next
 668          */
 669         if (data->count > num_frames)
 670                 printf ("bad num frames: %d\n", data->count);
 671         emit_value (logbuffer, 0); /* flags */
 672         emit_value (logbuffer, data->count);
 673         //if (*p != data.count) {
 674         //      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);}
 675         while (data->count) {
 676                 emit_ptr (logbuffer, data->methods [--data->count]);
 677         }
 678 }
 679
 680 static void
 681 gc_alloc (MonoProfiler *prof, MonoObject *obj, MonoClass *klass)
 682 {
 683         uint64_t now;
 684         uintptr_t len;
 685         int do_bt = (nocalls && runtime_inited && !notraces)? TYPE_ALLOC_BT: 0;
 686         FrameData data;
 687         LogBuffer *logbuffer;
 688         len = mono_object_get_size (obj);
 689         /* account for object alignment in the heap */
 690         len += 7;
 691         len &= ~7;
 692         if (do_bt)
 693                 collect_bt (&data);
 694         logbuffer = ensure_logbuf (32 + MAX_FRAMES * 8);
 695         now = current_time ();
 696         ENTER_LOG (logbuffer, "gcalloc");
 697         emit_byte (logbuffer, do_bt | TYPE_ALLOC);
 698         emit_time (logbuffer, now);
 699         emit_ptr (logbuffer, klass);
 700         emit_obj (logbuffer, obj);
 701         emit_value (logbuffer, len);
 702         if (do_bt)
 703                 emit_bt (logbuffer, &data);
 704         EXIT_LOG (logbuffer);
 705         if (logbuffer->next)
 706                 safe_dump (prof, logbuffer);
 707         process_requests (prof);
 708         //printf ("gc alloc %s at %p\n", mono_class_get_name (klass), obj);
 709 }
 710
 711 static void
 712 gc_moves (MonoProfiler *prof, void **objects, int num)
 713 {
 714         int i;
 715         uint64_t now;
 716         LogBuffer *logbuffer = ensure_logbuf (10 + num * 8);
 717         now = current_time ();
 718         ENTER_LOG (logbuffer, "gcmove");
 719         emit_byte (logbuffer, TYPE_GC_MOVE | TYPE_GC);
 720         emit_time (logbuffer, now);
 721         emit_value (logbuffer, num);
 722         for (i = 0; i < num; ++i)
 723                 emit_obj (logbuffer, objects [i]);
 724         //printf ("gc moved %d objects\n", num/2);
 725         EXIT_LOG (logbuffer);
 726 }
 727
 728 static void
 729 gc_roots (MonoProfiler *prof, int num, void **objects, int *root_types, uintptr_t *extra_info)
 730 {
 731         int i;
 732         LogBuffer *logbuffer = ensure_logbuf (5 + num * 18);
 733         ENTER_LOG (logbuffer, "gcroots");
 734         emit_byte (logbuffer, TYPE_HEAP_ROOT | TYPE_HEAP);
 735         emit_value (logbuffer, num);
 736         emit_value (logbuffer, mono_gc_collection_count (mono_gc_max_generation ()));
 737         for (i = 0; i < num; ++i) {
 738                 emit_obj (logbuffer, objects [i]);
 739                 emit_value (logbuffer, root_types [i]);
 740                 emit_value (logbuffer, extra_info [i]);
 741         }
 742         EXIT_LOG (logbuffer);
 743 }
 744
 745 static void
 746 gc_handle (MonoProfiler *prof, int op, int type, uintptr_t handle, MonoObject *obj)
 747 {
 748         uint64_t now;
 749         LogBuffer *logbuffer = ensure_logbuf (16);
 750         now = current_time ();
 751         ENTER_LOG (logbuffer, "gchandle");
 752         if (op == MONO_PROFILER_GC_HANDLE_CREATED)
 753                 emit_byte (logbuffer, TYPE_GC_HANDLE_CREATED | TYPE_GC);
 754         else if (op == MONO_PROFILER_GC_HANDLE_DESTROYED)
 755                 emit_byte (logbuffer, TYPE_GC_HANDLE_DESTROYED | TYPE_GC);
 756         else
 757                 return;
 758         emit_time (logbuffer, now);
 759         emit_value (logbuffer, type);
 760         emit_value (logbuffer, handle);
 761         if (op == MONO_PROFILER_GC_HANDLE_CREATED)
 762                 emit_obj (logbuffer, obj);
 763         EXIT_LOG (logbuffer);
 764         process_requests (prof);
 765 }
 766
 767 static char*
 768 push_nesting (char *p, MonoClass *klass)
 769 {
 770         MonoClass *nesting;
 771         const char *name;
 772         const char *nspace;
 773         nesting = mono_class_get_nesting_type (klass);
 774         if (nesting) {
 775                 p = push_nesting (p, nesting);
 776                 *p++ = '/';
 777                 *p = 0;
 778         }
 779         name = mono_class_get_name (klass);
 780         nspace = mono_class_get_namespace (klass);
 781         if (*nspace) {
 782                 strcpy (p, nspace);
 783                 p += strlen (nspace);
 784                 *p++ = '.';
 785                 *p = 0;
 786         }
 787         strcpy (p, name);
 788         p += strlen (name);
 789         return p;
 790 }
 791
 792 static char*
 793 type_name (MonoClass *klass)
 794 {
 795         char buf [1024];
 796         char *p;
 797         push_nesting (buf, klass);
 798         p = malloc (strlen (buf) + 1);
 799         strcpy (p, buf);
 800         return p;
 801 }
 802
 803 static void
 804 image_loaded (MonoProfiler *prof, MonoImage *image, int result)
 805 {
 806         uint64_t now;
 807         const char *name;
 808         int nlen;
 809         LogBuffer *logbuffer;
 810         if (result != MONO_PROFILE_OK)
 811                 return;
 812         name = mono_image_get_filename (image);
 813         nlen = strlen (name) + 1;
 814         logbuffer = ensure_logbuf (16 + nlen);
 815         now = current_time ();
 816         ENTER_LOG (logbuffer, "image");
 817         emit_byte (logbuffer, TYPE_END_LOAD | TYPE_METADATA);
 818         emit_time (logbuffer, now);
 819         emit_byte (logbuffer, TYPE_IMAGE);
 820         emit_ptr (logbuffer, image);
 821         emit_value (logbuffer, 0); /* flags */
 822         memcpy (logbuffer->data, name, nlen);
 823         logbuffer->data += nlen;
 824         //printf ("loaded image %p (%s)\n", image, name);
 825         EXIT_LOG (logbuffer);
 826         if (logbuffer->next)
 827                 safe_dump (prof, logbuffer);
 828         process_requests (prof);
 829 }
 830
 831 static void
 832 class_loaded (MonoProfiler *prof, MonoClass *klass, int result)
 833 {
 834         uint64_t now;
 835         char *name;
 836         int nlen;
 837         MonoImage *image;
 838         LogBuffer *logbuffer;
 839         if (result != MONO_PROFILE_OK)
 840                 return;
 841         if (runtime_inited)
 842                 name = mono_type_get_name (mono_class_get_type (klass));
 843         else
 844                 name = type_name (klass);
 845         nlen = strlen (name) + 1;
 846         image = mono_class_get_image (klass);
 847         logbuffer = ensure_logbuf (24 + nlen);
 848         now = current_time ();
 849         ENTER_LOG (logbuffer, "class");
 850         emit_byte (logbuffer, TYPE_END_LOAD | TYPE_METADATA);
 851         emit_time (logbuffer, now);
 852         emit_byte (logbuffer, TYPE_CLASS);
 853         emit_ptr (logbuffer, klass);
 854         emit_ptr (logbuffer, image);
 855         emit_value (logbuffer, 0); /* flags */
 856         memcpy (logbuffer->data, name, nlen);
 857         logbuffer->data += nlen;
 858         //printf ("loaded class %p (%s)\n", klass, name);
 859         if (runtime_inited)
 860                 mono_free (name);
 861         else
 862                 free (name);
 863         EXIT_LOG (logbuffer);
 864         if (logbuffer->next)
 865                 safe_dump (prof, logbuffer);
 866         process_requests (prof);
 867 }
 868
 869 static void
 870 method_enter (MonoProfiler *prof, MonoMethod *method)
 871 {
 872         uint64_t now;
 873         LogBuffer *logbuffer = ensure_logbuf (16);
 874         if (logbuffer->call_depth++ > max_call_depth)
 875                 return;
 876         now = current_time ();
 877         ENTER_LOG (logbuffer, "enter");
 878         emit_byte (logbuffer, TYPE_ENTER | TYPE_METHOD);
 879         emit_time (logbuffer, now);
 880         emit_method (logbuffer, method);
 881         EXIT_LOG (logbuffer);
 882         process_requests (prof);
 883 }
 884
 885 static void
 886 method_leave (MonoProfiler *prof, MonoMethod *method)
 887 {
 888         uint64_t now;
 889         LogBuffer *logbuffer = ensure_logbuf (16);
 890         if (--logbuffer->call_depth > max_call_depth)
 891                 return;
 892         now = current_time ();
 893         ENTER_LOG (logbuffer, "leave");
 894         emit_byte (logbuffer, TYPE_LEAVE | TYPE_METHOD);
 895         emit_time (logbuffer, now);
 896         emit_method (logbuffer, method);
 897         EXIT_LOG (logbuffer);
 898         if (logbuffer->next)
 899                 safe_dump (prof, logbuffer);
 900         process_requests (prof);
 901 }
 902
 903 static void
 904 method_exc_leave (MonoProfiler *prof, MonoMethod *method)
 905 {
 906         uint64_t now;
 907         LogBuffer *logbuffer;
 908         if (nocalls)
 909                 return;
 910         logbuffer = ensure_logbuf (16);
 911         if (--logbuffer->call_depth > max_call_depth)
 912                 return;
 913         now = current_time ();
 914         ENTER_LOG (logbuffer, "eleave");
 915         emit_byte (logbuffer, TYPE_EXC_LEAVE | TYPE_METHOD);
 916         emit_time (logbuffer, now);
 917         emit_method (logbuffer, method);
 918         EXIT_LOG (logbuffer);
 919         process_requests (prof);
 920 }
 921
 922 static void
 923 method_jitted (MonoProfiler *prof, MonoMethod *method, MonoJitInfo* jinfo, int result)
 924 {
 925         uint64_t now;
 926         char *name;
 927         int nlen;
 928         LogBuffer *logbuffer;
 929         if (result != MONO_PROFILE_OK)
 930                 return;
 931         name = mono_method_full_name (method, 1);
 932         nlen = strlen (name) + 1;
 933         logbuffer = ensure_logbuf (32 + nlen);
 934         now = current_time ();
 935         ENTER_LOG (logbuffer, "jit");
 936         emit_byte (logbuffer, TYPE_JIT | TYPE_METHOD);
 937         emit_time (logbuffer, now);
 938         emit_method (logbuffer, method);
 939         emit_ptr (logbuffer, mono_jit_info_get_code_start (jinfo));
 940         emit_value (logbuffer, mono_jit_info_get_code_size (jinfo));
 941         memcpy (logbuffer->data, name, nlen);
 942         logbuffer->data += nlen;
 943         mono_free (name);
 944         EXIT_LOG (logbuffer);
 945         if (logbuffer->next)
 946                 safe_dump (prof, logbuffer);
 947         process_requests (prof);
 948 }
 949
 950 static void
 951 throw_exc (MonoProfiler *prof, MonoObject *object)
 952 {
 953         int do_bt = (nocalls && runtime_inited && !notraces)? TYPE_EXCEPTION_BT: 0;
 954         uint64_t now;
 955         FrameData data;
 956         LogBuffer *logbuffer;
 957         if (do_bt)
 958                 collect_bt (&data);
 959         logbuffer = ensure_logbuf (16 + MAX_FRAMES * 8);
 960         now = current_time ();
 961         ENTER_LOG (logbuffer, "throw");
 962         emit_byte (logbuffer, do_bt | TYPE_EXCEPTION);
 963         emit_time (logbuffer, now);
 964         emit_obj (logbuffer, object);
 965         if (do_bt)
 966                 emit_bt (logbuffer, &data);
 967         EXIT_LOG (logbuffer);
 968         process_requests (prof);
 969 }
 970
 971 static void
 972 clause_exc (MonoProfiler *prof, MonoMethod *method, int clause_type, int clause_num)
 973 {
 974         uint64_t now;
 975         LogBuffer *logbuffer = ensure_logbuf (16);
 976         now = current_time ();
 977         ENTER_LOG (logbuffer, "clause");
 978         emit_byte (logbuffer, TYPE_EXCEPTION | TYPE_CLAUSE);
 979         emit_time (logbuffer, now);
 980         emit_value (logbuffer, clause_type);
 981         emit_value (logbuffer, clause_num);
 982         emit_method (logbuffer, method);
 983         EXIT_LOG (logbuffer);
 984 }
 985
 986 static void
 987 monitor_event (MonoProfiler *profiler, MonoObject *object, MonoProfilerMonitorEvent event)
 988 {
 989         int do_bt = (nocalls && runtime_inited && !notraces && event == MONO_PROFILER_MONITOR_CONTENTION)? TYPE_MONITOR_BT: 0;
 990         uint64_t now;
 991         FrameData data;
 992         LogBuffer *logbuffer;
 993         if (do_bt)
 994                 collect_bt (&data);
 995         logbuffer = ensure_logbuf (16 + MAX_FRAMES * 8);
 996         now = current_time ();
 997         ENTER_LOG (logbuffer, "monitor");
 998         emit_byte (logbuffer, (event << 4) | do_bt | TYPE_MONITOR);
 999         emit_time (logbuffer, now);
1000         emit_obj (logbuffer, object);
1001         if (do_bt)
1002                 emit_bt (logbuffer, &data);
1003         EXIT_LOG (logbuffer);
1004         process_requests (profiler);
1005 }
1006
1007 static void
1008 thread_start (MonoProfiler *prof, uintptr_t tid)
1009 {
1010         //printf ("thread start %p\n", (void*)tid);
1011         init_thread ();
1012 }
1013
1014 static void
1015 thread_end (MonoProfiler *prof, uintptr_t tid)
1016 {
1017         take_lock ();
1018         if (TLS_GET (tlsbuffer))
1019                 dump_buffer (prof, TLS_GET (tlsbuffer));
1020         release_lock ();
1021         TLS_SET (tlsbuffer, NULL);
1022 }
1023
1024 static void
1025 thread_name (MonoProfiler *prof, uintptr_t tid, const char *name)
1026 {
1027         int len = strlen (name) + 1;
1028         uint64_t now;
1029         LogBuffer *logbuffer;
1030         logbuffer = ensure_logbuf (10 + len);
1031         now = current_time ();
1032         ENTER_LOG (logbuffer, "tname");
1033         emit_byte (logbuffer, TYPE_METADATA);
1034         emit_time (logbuffer, now);
1035         emit_byte (logbuffer, TYPE_THREAD);
1036         emit_ptr (logbuffer, (void*)tid);
1037         emit_value (logbuffer, 0); /* flags */
1038         memcpy (logbuffer->data, name, len);
1039         logbuffer->data += len;
1040         EXIT_LOG (logbuffer);
1041 }
1042
1043 static void
1044 log_shutdown (MonoProfiler *prof)
1045 {
1046 #ifndef DISABLE_HELPER_THREAD
1047         if (prof->command_port) {
1048                 char c = 1;
1049                 void *res;
1050                 write (prof->pipes [1], &c, 1);
1051                 pthread_join (prof->helper_thread, &res);
1052         }
1053 #endif
1054         take_lock ();
1055         if (TLS_GET (tlsbuffer))
1056                 dump_buffer (prof, TLS_GET (tlsbuffer));
1057         TLS_SET (tlsbuffer, NULL);
1058         release_lock ();
1059 #if defined (HAVE_SYS_ZLIB)
1060         if (prof->gzfile)
1061                 gzclose (prof->gzfile);
1062 #endif
1063         if (prof->pipe_output)
1064                 pclose (prof->file);
1065         else
1066                 fclose (prof->file);
1067         free (prof);
1068 }
1069
1070 static char*
1071 new_filename (const char* filename)
1072 {
1073         time_t t = time (NULL);
1074         int pid = process_id ();
1075         char pid_buf [16];
1076         char time_buf [16];
1077         char *res, *d;
1078         const char *p;
1079         int count_dates = 0;
1080         int count_pids = 0;
1081         int s_date, s_pid;
1082         struct tm *ts;
1083         for (p = filename; *p; p++) {
1084                 if (*p != '%')
1085                         continue;
1086                 p++;
1087                 if (*p == 't')
1088                         count_dates++;
1089                 else if (*p == 'p')
1090                         count_pids++;
1091                 else if (*p == 0)
1092                         break;
1093         }
1094         if (!count_dates && !count_pids)
1095                 return pstrdup (filename);
1096         snprintf (pid_buf, sizeof (pid_buf), "%d", pid);
1097         ts = gmtime (&t);
1098         snprintf (time_buf, sizeof (time_buf), "%d%02d%02d%02d%02d%02d",
1099                 1900 + ts->tm_year, 1 + ts->tm_mon, ts->tm_mday, ts->tm_hour, ts->tm_min, ts->tm_sec);
1100         s_date = strlen (time_buf);
1101         s_pid = strlen (pid_buf);
1102         d = res = malloc (strlen (filename) + s_date * count_dates + s_pid * count_pids);
1103         for (p = filename; *p; p++) {
1104                 if (*p != '%') {
1105                         *d++ = *p;
1106                         continue;
1107                 }
1108                 p++;
1109                 if (*p == 't') {
1110                         strcpy (d, time_buf);
1111                         d += s_date;
1112                         continue;
1113                 } else if (*p == 'p') {
1114                         strcpy (d, pid_buf);
1115                         d += s_pid;
1116                         continue;
1117                 } else if (*p == '%') {
1118                         *d++ = '%';
1119                         continue;
1120                 } else if (*p == 0)
1121                         break;
1122                 *d++ = '%';
1123                 *d++ = *p;
1124         }
1125         *d = 0;
1126         return res;
1127 }
1128
1129 #ifndef DISABLE_HELPER_THREAD
1130 static void*
1131 helper_thread (void* arg)
1132 {
1133         MonoProfiler* prof = arg;
1134         int command_socket;
1135         int len;
1136         char buf [64];
1137         MonoThread *thread = NULL;
1138
1139         //fprintf (stderr, "Server listening\n");
1140         command_socket = -1;
1141         while (1) {
1142                 fd_set rfds;
1143                 struct timeval tv;
1144                 int max_fd = -1;
1145                 FD_ZERO (&rfds);
1146                 FD_SET (prof->server_socket, &rfds);
1147                 max_fd = prof->server_socket;
1148                 FD_SET (prof->pipes [0], &rfds);
1149                 if (max_fd < prof->pipes [0])
1150                         max_fd = prof->pipes [0];
1151                 if (command_socket >= 0) {
1152                         FD_SET (command_socket, &rfds);
1153                         if (max_fd < command_socket)
1154                                 max_fd = command_socket;
1155                 }
1156                 tv.tv_sec = 1;
1157                 tv.tv_usec = 0;
1158                 len = select (max_fd + 1, &rfds, NULL, NULL, &tv);
1159                 if (FD_ISSET (prof->pipes [0], &rfds)) {
1160                         /* time to shut down */
1161                         if (thread)
1162                                 mono_thread_detach (thread);
1163                         /*fprintf (stderr, "helper shutdown\n");*/
1164                         return NULL;
1165                 }
1166                 if (runtime_inited && !thread) {
1167                         thread = mono_thread_attach (mono_get_root_domain ());
1168                         /*fprintf (stderr, "attached\n");*/
1169                 }
1170                 if (command_socket >= 0 && FD_ISSET (command_socket, &rfds)) {
1171                         len = read (command_socket, buf, sizeof (buf) - 1);
1172                         if (len < 0)
1173                                 continue;
1174                         if (len == 0) {
1175                                 close (command_socket);
1176                                 command_socket = -1;
1177                                 continue;
1178                         }
1179                         buf [len] = 0;
1180                         if (strcmp (buf, "heapshot\n") == 0) {
1181                                 heapshot_requested = 1;
1182                                 //fprintf (stderr, "perform heapshot\n");
1183                                 if (thread)
1184                                         process_requests (prof);
1185                         }
1186                         continue;
1187                 }
1188                 if (!FD_ISSET (prof->server_socket, &rfds)) {
1189                         continue;
1190                 }
1191                 command_socket = accept (prof->server_socket, NULL, NULL);
1192                 if (command_socket < 0)
1193                         continue;
1194                 //fprintf (stderr, "Accepted connection\n");
1195         }
1196         return NULL;
1197 }
1198
1199 static int
1200 start_helper_thread (MonoProfiler* prof)
1201 {
1202         struct sockaddr_in server_address;
1203         int r;
1204         socklen_t slen;
1205         if (pipe (prof->pipes) < 0) {
1206                 fprintf (stderr, "Cannot create pipe\n");
1207                 return 0;
1208         }
1209         prof->server_socket = socket (PF_INET, SOCK_STREAM, 0);
1210         if (prof->server_socket < 0) {
1211                 fprintf (stderr, "Cannot create server socket\n");
1212                 return 0;
1213         }
1214         memset (&server_address, 0, sizeof (server_address));
1215         server_address.sin_family = AF_INET;
1216         server_address.sin_addr.s_addr = INADDR_ANY;
1217         server_address.sin_port = htons (prof->command_port);
1218         if (bind (prof->server_socket, (struct sockaddr *) &server_address, sizeof (server_address)) < 0) {
1219                 fprintf (stderr, "Cannot bind server socket, port: %d: %s\n", prof->command_port, strerror (errno));
1220                 close (prof->server_socket);
1221                 return 0;
1222         }
1223         if (listen (prof->server_socket, 1) < 0) {
1224                 fprintf (stderr, "Cannot listen server socket\n");
1225                 close (prof->server_socket);
1226                 return 0;
1227         }
1228         if (getsockname (prof->server_socket, (struct sockaddr *)&server_address, &slen) == 0) {
1229                 prof->command_port = ntohs (server_address.sin_port);
1230                 /*fprintf (stderr, "Assigned server port: %d\n", prof->command_port);*/
1231         }
1232
1233         r = pthread_create (&prof->helper_thread, NULL, helper_thread, prof);
1234         if (r) {
1235                 close (prof->server_socket);
1236                 return 0;
1237         }
1238         return 1;
1239 }
1240 #endif
1241
1242 static MonoProfiler*
1243 create_profiler (const char *filename)
1244 {
1245         MonoProfiler *prof;
1246         char *nf;
1247         int force_delete = 0;
1248         prof = calloc (1, sizeof (MonoProfiler));
1249
1250         prof->command_port = command_port;
1251         if (filename && *filename == '-') {
1252                 force_delete = 1;
1253                 filename++;
1254         }
1255         if (!filename) {
1256                 if (do_report)
1257                         filename = "|mprof-report -";
1258                 else
1259                         filename = "output.mlpd";
1260                 nf = filename;
1261         } else {
1262                 nf = new_filename (filename);
1263                 if (do_report) {
1264                         int s = strlen (nf) + 32;
1265                         char *p = malloc (s);
1266                         snprintf (p, s, "|mprof-report '--out=%s' -", nf);
1267                         free (nf);
1268                         nf = p;
1269                 }
1270         }
1271         if (*nf == '|') {
1272                 prof->file = popen (nf + 1, "w");
1273                 prof->pipe_output = 1;
1274         } else {
1275                 FILE *f;
1276                 if (force_delete)
1277                         unlink (nf);
1278                 if ((f = fopen (nf, "r"))) {
1279                         fclose (f);
1280                         fprintf (stderr, "The Mono profiler won't overwrite existing filename: %s.\n", nf);
1281                         fprintf (stderr, "Profiling disabled: use a different name or -FILENAME to force overwrite.\n");
1282                         free (prof);
1283                         return NULL;
1284                 }
1285                 prof->file = fopen (nf, "wb");
1286         }
1287         if (!prof->file) {
1288                 fprintf (stderr, "Cannot create profiler output: %s\n", nf);
1289                 exit (1);
1290         }
1291 #if defined (HAVE_SYS_ZLIB)
1292         if (use_zip)
1293                 prof->gzfile = gzdopen (fileno (prof->file), "wb");
1294 #endif
1295 #ifndef DISABLE_HELPER_THREAD
1296         if (hs_mode_ondemand) {
1297                 if (!start_helper_thread (prof))
1298                         prof->command_port = 0;
1299         }
1300 #else
1301         if (hs_mode_ondemand)
1302                 fprintf (stderr, "Ondemand heapshot unavailable on this arch.\n");
1303 #endif
1304         dump_header (prof);
1305         return prof;
1306 }
1307
1308 static void
1309 usage (int do_exit)
1310 {
1311         printf ("Log profiler version %d.%d (format: %d)\n", LOG_VERSION_MAJOR, LOG_VERSION_MINOR, LOG_DATA_VERSION);
1312         printf ("Usage: mono --profile=log[:OPTION1[,OPTION2...]] program.exe\n");
1313         printf ("Options:\n");
1314         printf ("\thelp             show this usage info\n");
1315         printf ("\t[no]alloc        enable/disable recording allocation info\n");
1316         printf ("\t[no]calls        enable/disable recording enter/leave method events\n");
1317         printf ("\theapshot[=MODE]  record heap shot info (by default at each major collection)\n");
1318         printf ("\t                 MODE: every XXms milliseconds, every YYgc collections, ondemand\n");
1319         printf ("\ttime=fast        use a faster (but more inaccurate) timer\n");
1320         printf ("\tmaxframes=NUM    collect up to NUM stack frames\n");
1321         printf ("\tcalldepth=NUM    ignore method events for call chain depth bigger than NUM\n");
1322         printf ("\toutput=FILENAME  write the data to file FILENAME (-FILENAME to overwrite)\n");
1323         printf ("\toutput=|PROGRAM  write the data to the stdin of PROGRAM\n");
1324         printf ("\t                 %%t is subtituted with date and time, %%p with the pid\n");
1325         printf ("\treport           create a report instead of writing the raw data to a file\n");
1326         printf ("\tzip              compress the output data\n");
1327         printf ("\tport=PORTNUM     use PORTNUM for the listening command server\n");
1328         if (do_exit)
1329                 exit (1);
1330 }
1331
1332 static const char*
1333 match_option (const char* p, const char *opt, char **rval)
1334 {
1335         int len = strlen (opt);
1336         if (strncmp (p, opt, len) == 0) {
1337                 if (rval) {
1338                         if (p [len] == '=' && p [len + 1]) {
1339                                 const char *opt = p + len + 1;
1340                                 const char *end = strchr (opt, ',');
1341                                 char *val;
1342                                 int l;
1343                                 if (end == NULL) {
1344                                         l = strlen (opt);
1345                                 } else {
1346                                         l = end - opt;
1347                                 }
1348                                 val = malloc (l + 1);
1349                                 memcpy (val, opt, l);
1350                                 val [l] = 0;
1351                                 *rval = val;
1352                                 return opt + l;
1353                         }
1354                         if (p [len] == 0 || p [len] == ',') {
1355                                 *rval = NULL;
1356                                 return p + len + (p [len] == ',');
1357                         }
1358                         usage (1);
1359                 } else {
1360                         if (p [len] == 0)
1361                                 return p + len;
1362                         if (p [len] == ',')
1363                                 return p + len + 1;
1364                 }
1365         }
1366         return p;
1367 }
1368
1369 static void
1370 set_hsmode (char* val, int allow_empty)
1371 {
1372         char *end;
1373         unsigned int count;
1374         if (allow_empty && !val)
1375                 return;
1376         if (strcmp (val, "ondemand") == 0) {
1377                 hs_mode_ondemand = 1;
1378                 free (val);
1379                 return;
1380         }
1381         count = strtoul (val, &end, 10);
1382         if (val == end)
1383                 usage (1);
1384         if (strcmp (end, "ms") == 0)
1385                 hs_mode_ms = count;
1386         else if (strcmp (end, "gc") == 0)
1387                 hs_mode_gc = count;
1388         else
1389                 usage (1);
1390         free (val);
1391 }
1392
1393 /*
1394  * declaration to silence the compiler: this is the entry point that
1395  * mono will load from the shared library and call.
1396  */
1397 extern void
1398 mono_profiler_startup (const char *desc);
1399
1400 void
1401 mono_profiler_startup (const char *desc)
1402 {
1403         MonoProfiler *prof;
1404         char *filename = NULL;
1405         const char *p;
1406         const char *opt;
1407         int fast_time = 0;
1408         int calls_enabled = 0;
1409         int allocs_enabled = 0;
1410         int events = MONO_PROFILE_GC|MONO_PROFILE_ALLOCATIONS|
1411                 MONO_PROFILE_GC_MOVES|MONO_PROFILE_CLASS_EVENTS|MONO_PROFILE_THREADS|
1412                 MONO_PROFILE_ENTER_LEAVE|MONO_PROFILE_JIT_COMPILATION|MONO_PROFILE_EXCEPTIONS|
1413                 MONO_PROFILE_MONITOR_EVENTS|MONO_PROFILE_MODULE_EVENTS|MONO_PROFILE_GC_ROOTS;
1414
1415         p = desc;
1416         if (strncmp (p, "log", 3))
1417                 usage (1);
1418         p += 3;
1419         if (*p == ':')
1420                 p++;
1421         for (; *p; p = opt) {
1422                 char *val;
1423                 if (*p == ',') {
1424                         opt = p + 1;
1425                         continue;
1426                 }
1427                 if ((opt = match_option (p, "help", NULL)) != p) {
1428                         usage (0);
1429                         continue;
1430                 }
1431                 if ((opt = match_option (p, "calls", NULL)) != p) {
1432                         calls_enabled = 1;
1433                         continue;
1434                 }
1435                 if ((opt = match_option (p, "nocalls", NULL)) != p) {
1436                         events &= ~MONO_PROFILE_ENTER_LEAVE;
1437                         nocalls = 1;
1438                         continue;
1439                 }
1440                 if ((opt = match_option (p, "alloc", NULL)) != p) {
1441                         allocs_enabled = 1;
1442                         continue;
1443                 }
1444                 if ((opt = match_option (p, "noalloc", NULL)) != p) {
1445                         events &= ~MONO_PROFILE_ALLOCATIONS;
1446                         continue;
1447                 }
1448                 if ((opt = match_option (p, "time", &val)) != p) {
1449                         if (strcmp (val, "fast") == 0)
1450                                 fast_time = 1;
1451                         else if (strcmp (val, "null") == 0)
1452                                 fast_time = 2;
1453                         else
1454                                 usage (1);
1455                         free (val);
1456                         continue;
1457                 }
1458                 if ((opt = match_option (p, "report", NULL)) != p) {
1459                         do_report = 1;
1460                         continue;
1461                 }
1462                 if ((opt = match_option (p, "heapshot", &val)) != p) {
1463                         events &= ~MONO_PROFILE_ALLOCATIONS;
1464                         events &= ~MONO_PROFILE_ENTER_LEAVE;
1465                         nocalls = 1;
1466                         do_heap_shot = 1;
1467                         set_hsmode (val, 1);
1468                         continue;
1469                 }
1470                 if ((opt = match_option (p, "hsmode", &val)) != p) {
1471                         fprintf (stderr, "The hsmode profiler option is obsolete, use heapshot=MODE.\n");
1472                         set_hsmode (val, 0);
1473                         continue;
1474                 }
1475                 if ((opt = match_option (p, "zip", NULL)) != p) {
1476                         use_zip = 1;
1477                         continue;
1478                 }
1479                 if ((opt = match_option (p, "output", &val)) != p) {
1480                         filename = val;
1481                         continue;
1482                 }
1483                 if ((opt = match_option (p, "port", &val)) != p) {
1484                         char *end;
1485                         command_port = strtoul (val, &end, 10);
1486                         free (val);
1487                         continue;
1488                 }
1489                 if ((opt = match_option (p, "maxframes", &val)) != p) {
1490                         char *end;
1491                         num_frames = strtoul (val, &end, 10);
1492                         if (num_frames > MAX_FRAMES)
1493                                 num_frames = MAX_FRAMES;
1494                         free (val);
1495                         notraces = num_frames == 0;
1496                         continue;
1497                 }
1498                 if ((opt = match_option (p, "calldepth", &val)) != p) {
1499                         char *end;
1500                         max_call_depth = strtoul (val, &end, 10);
1501                         free (val);
1502                         continue;
1503                 }
1504                 if (opt == p) {
1505                         usage (0);
1506                         exit (0);
1507                 }
1508         }
1509         if (calls_enabled) {
1510                 events |= MONO_PROFILE_ENTER_LEAVE;
1511                 nocalls = 0;
1512         }
1513         if (allocs_enabled)
1514                 events |= MONO_PROFILE_ALLOCATIONS;
1515         utils_init (fast_time);
1516
1517         prof = create_profiler (filename);
1518         if (!prof)
1519                 return;
1520         init_thread ();
1521
1522         mono_profiler_install (prof, log_shutdown);
1523         mono_profiler_install_gc (gc_event, gc_resize);
1524         mono_profiler_install_allocation (gc_alloc);
1525         mono_profiler_install_gc_moves (gc_moves);
1526         mono_profiler_install_gc_roots (gc_handle, gc_roots);
1527         mono_profiler_install_class (NULL, class_loaded, NULL, NULL);
1528         mono_profiler_install_module (NULL, image_loaded, NULL, NULL);
1529         mono_profiler_install_thread (thread_start, thread_end);
1530         mono_profiler_install_thread_name (thread_name);
1531         mono_profiler_install_enter_leave (method_enter, method_leave);
1532         mono_profiler_install_jit_end (method_jitted);
1533         mono_profiler_install_exception (throw_exc, method_exc_leave, clause_exc);
1534         mono_profiler_install_monitor (monitor_event);
1535         mono_profiler_install_runtime_initialized (runtime_initialized);
1536
1537         mono_profiler_set_events (events);
1538
1539         TLS_INIT (tlsbuffer);
1540 }
1541