mono/profiler/log.c

   1 /*
   2  * log.c: mono log profiler
   3  *
   4  * Authors:
   5  *   Paolo Molaro (lupus@ximian.com)
   6  *   Alex Rønne Petersen (alexrp@xamarin.com)
   7  *
   8  * Copyright 2010 Novell, Inc (http://www.novell.com)
   9  * Copyright 2011 Xamarin Inc (http://www.xamarin.com)
  10  * Licensed under the MIT license. See LICENSE file in the project root for full license information.
  11  */
  12
  13 #include <config.h>
  14 #include <mono/metadata/assembly.h>
  15 #include <mono/metadata/debug-helpers.h>
  16 #include "../metadata/metadata-internals.h"
  17 #include <mono/metadata/mono-config.h>
  18 #include <mono/metadata/mono-gc.h>
  19 #include <mono/metadata/mono-perfcounters.h>
  20 #include <mono/metadata/tabledefs.h>
  21 #include <mono/utils/atomic.h>
  22 #include <mono/utils/hazard-pointer.h>
  23 #include <mono/utils/lock-free-alloc.h>
  24 #include <mono/utils/lock-free-queue.h>
  25 #include <mono/utils/mono-conc-hashtable.h>
  26 #include <mono/utils/mono-counters.h>
  27 #include <mono/utils/mono-logger-internals.h>
  28 #include <mono/utils/mono-linked-list-set.h>
  29 #include <mono/utils/mono-membar.h>
  30 #include <mono/utils/mono-mmap.h>
  31 #include <mono/utils/mono-os-mutex.h>
  32 #include <mono/utils/mono-os-semaphore.h>
  33 #include <mono/utils/mono-threads.h>
  34 #include <mono/utils/mono-threads-api.h>
  35 #include "log.h"
  36
  37 #ifdef HAVE_DLFCN_H
  38 #include <dlfcn.h>
  39 #endif
  40 #include <fcntl.h>
  41 #ifdef HAVE_LINK_H
  42 #include <link.h>
  43 #endif
  44 #ifdef HAVE_UNISTD_H
  45 #include <unistd.h>
  46 #endif
  47 #if defined(__APPLE__)
  48 #include <mach/mach_time.h>
  49 #endif
  50 #include <netinet/in.h>
  51 #ifdef HAVE_SYS_MMAN_H
  52 #include <sys/mman.h>
  53 #endif
  54 #include <sys/socket.h>
  55 #if defined (HAVE_SYS_ZLIB)
  56 #include <zlib.h>
  57 #endif
  58
  59 // Statistics for internal profiler data structures.
  60 static gint32 sample_allocations_ctr,
  61               buffer_allocations_ctr;
  62
  63 // Statistics for profiler events.
  64 static gint32 sync_points_ctr,
  65               heap_objects_ctr,
  66               heap_starts_ctr,
  67               heap_ends_ctr,
  68               heap_roots_ctr,
  69               gc_events_ctr,
  70               gc_resizes_ctr,
  71               gc_allocs_ctr,
  72               gc_moves_ctr,
  73               gc_handle_creations_ctr,
  74               gc_handle_deletions_ctr,
  75               finalize_begins_ctr,
  76               finalize_ends_ctr,
  77               finalize_object_begins_ctr,
  78               finalize_object_ends_ctr,
  79               image_loads_ctr,
  80               image_unloads_ctr,
  81               assembly_loads_ctr,
  82               assembly_unloads_ctr,
  83               class_loads_ctr,
  84               class_unloads_ctr,
  85               method_entries_ctr,
  86               method_exits_ctr,
  87               method_exception_exits_ctr,
  88               method_jits_ctr,
  89               code_buffers_ctr,
  90               exception_throws_ctr,
  91               exception_clauses_ctr,
  92               monitor_events_ctr,
  93               thread_starts_ctr,
  94               thread_ends_ctr,
  95               thread_names_ctr,
  96               domain_loads_ctr,
  97               domain_unloads_ctr,
  98               domain_names_ctr,
  99               context_loads_ctr,
 100               context_unloads_ctr,
 101               sample_ubins_ctr,
 102               sample_usyms_ctr,
 103               sample_hits_ctr,
 104               counter_descriptors_ctr,
 105               counter_samples_ctr,
 106               perfcounter_descriptors_ctr,
 107               perfcounter_samples_ctr,
 108               coverage_methods_ctr,
 109               coverage_statements_ctr,
 110               coverage_classes_ctr,
 111               coverage_assemblies_ctr;
 112
 113 // Pending data to be written to the log, for a single thread.
 114 // Threads periodically flush their own LogBuffers by calling safe_send
 115 typedef struct _LogBuffer LogBuffer;
 116 struct _LogBuffer {
 117         // Next (older) LogBuffer in processing queue
 118         LogBuffer *next;
 119
 120         uint64_t time_base;
 121         uint64_t last_time;
 122         uintptr_t ptr_base;
 123         uintptr_t method_base;
 124         uintptr_t last_method;
 125         uintptr_t obj_base;
 126         uintptr_t thread_id;
 127
 128         // Bytes allocated for this LogBuffer
 129         int size;
 130
 131         // Start of currently unused space in buffer
 132         unsigned char* cursor;
 133
 134         // Pointer to start-of-structure-plus-size (for convenience)
 135         unsigned char* buf_end;
 136
 137         // Start of data in buffer. Contents follow "buffer format" described above.
 138         unsigned char buf [1];
 139 };
 140
 141 typedef struct {
 142         MonoLinkedListSetNode node;
 143
 144         // Was this thread added to the LLS?
 145         gboolean attached;
 146
 147         // The current log buffer for this thread.
 148         LogBuffer *buffer;
 149
 150         // Methods referenced by events in `buffer`, see `MethodInfo`.
 151         GPtrArray *methods;
 152
 153         // Current call depth for enter/leave events.
 154         int call_depth;
 155
 156         // Indicates whether this thread is currently writing to its `buffer`.
 157         gboolean busy;
 158
 159         // Has this thread written a thread end event to `buffer`?
 160         gboolean ended;
 161
 162         // Stored in `buffer_lock_state` to take the exclusive lock.
 163         int small_id;
 164 } MonoProfilerThread;
 165
 166 // Do not use these TLS macros directly unless you know what you're doing.
 167
 168 #ifdef HOST_WIN32
 169
 170 #define PROF_TLS_SET(VAL) (TlsSetValue (profiler_tls, (VAL)))
 171 #define PROF_TLS_GET() ((MonoProfilerThread *) TlsGetValue (profiler_tls))
 172 #define PROF_TLS_INIT() (profiler_tls = TlsAlloc ())
 173 #define PROF_TLS_FREE() (TlsFree (profiler_tls))
 174
 175 static DWORD profiler_tls;
 176
 177 #elif HAVE_KW_THREAD
 178
 179 #define PROF_TLS_SET(VAL) (profiler_tls = (VAL))
 180 #define PROF_TLS_GET() (profiler_tls)
 181 #define PROF_TLS_INIT()
 182 #define PROF_TLS_FREE()
 183
 184 static __thread MonoProfilerThread *profiler_tls;
 185
 186 #else
 187
 188 #define PROF_TLS_SET(VAL) (pthread_setspecific (profiler_tls, (VAL)))
 189 #define PROF_TLS_GET() ((MonoProfilerThread *) pthread_getspecific (profiler_tls))
 190 #define PROF_TLS_INIT() (pthread_key_create (&profiler_tls, NULL))
 191 #define PROF_TLS_FREE() (pthread_key_delete (profiler_tls))
 192
 193 static pthread_key_t profiler_tls;
 194
 195 #endif
 196
 197 static uintptr_t
 198 thread_id (void)
 199 {
 200         return (uintptr_t) mono_native_thread_id_get ();
 201 }
 202
 203 static uintptr_t
 204 process_id (void)
 205 {
 206 #ifdef HOST_WIN32
 207         return (uintptr_t) GetCurrentProcessId ();
 208 #else
 209         return (uintptr_t) getpid ();
 210 #endif
 211 }
 212
 213 #define ENABLED(EVT) (log_config.effective_mask & (EVT))
 214
 215 /*
 216  * These macros should be used when writing an event to a log buffer. They
 217  * take care of a bunch of stuff that can be repetitive and error-prone, such
 218  * as attaching the current thread, acquiring/releasing the buffer lock,
 219  * incrementing the event counter, expanding the log buffer, etc. They also
 220  * create a scope so that it's harder to leak the LogBuffer pointer, which can
 221  * be problematic as the pointer is unstable when the buffer lock isn't
 222  * acquired.
 223  *
 224  * If the calling thread is already attached, these macros will not alter its
 225  * attach mode (i.e. whether it's added to the LLS). If the thread is not
 226  * attached, init_thread () will be called with add_to_lls = TRUE.
 227  */
 228
 229 #define ENTER_LOG(COUNTER, BUFFER, SIZE) \
 230         do { \
 231                 MonoProfilerThread *thread__ = get_thread (); \
 232                 if (thread__->attached) \
 233                         buffer_lock (); \
 234                 g_assert (!thread__->busy && "Why are we trying to write a new event while already writing one?"); \
 235                 thread__->busy = TRUE; \
 236                 InterlockedIncrement ((COUNTER)); \
 237                 LogBuffer *BUFFER = ensure_logbuf_unsafe (thread__, (SIZE))
 238
 239 #define EXIT_LOG_EXPLICIT(SEND) \
 240                 thread__->busy = FALSE; \
 241                 if ((SEND)) \
 242                         send_log_unsafe (TRUE); \
 243                 if (thread__->attached) \
 244                         buffer_unlock (); \
 245         } while (0)
 246
 247 // Pass these to EXIT_LOG_EXPLICIT () for easier reading.
 248 #define DO_SEND TRUE
 249 #define NO_SEND FALSE
 250
 251 #define EXIT_LOG EXIT_LOG_EXPLICIT (DO_SEND)
 252
 253 typedef struct _BinaryObject BinaryObject;
 254 struct _BinaryObject {
 255         BinaryObject *next;
 256         void *addr;
 257         char *name;
 258 };
 259
 260 typedef struct MonoCounterAgent {
 261         MonoCounter *counter;
 262         // MonoCounterAgent specific data :
 263         void *value;
 264         size_t value_size;
 265         guint32 index;
 266         gboolean emitted;
 267         struct MonoCounterAgent *next;
 268 } MonoCounterAgent;
 269
 270 typedef struct _PerfCounterAgent PerfCounterAgent;
 271 struct _PerfCounterAgent {
 272         PerfCounterAgent *next;
 273         guint32 index;
 274         char *category_name;
 275         char *name;
 276         gint64 value;
 277         gboolean emitted;
 278         gboolean updated;
 279         gboolean deleted;
 280 };
 281
 282 struct _MonoProfiler {
 283         MonoProfilerHandle handle;
 284
 285         FILE* file;
 286 #if defined (HAVE_SYS_ZLIB)
 287         gzFile gzfile;
 288 #endif
 289
 290         char *args;
 291         uint64_t startup_time;
 292         int timer_overhead;
 293
 294 #ifdef __APPLE__
 295         mach_timebase_info_data_t timebase_info;
 296 #elif defined (HOST_WIN32)
 297         LARGE_INTEGER pcounter_freq;
 298 #endif
 299
 300         int pipe_output;
 301         int command_port;
 302         int server_socket;
 303         int pipes [2];
 304
 305         MonoLinkedListSet profiler_thread_list;
 306         volatile gint32 buffer_lock_state;
 307         volatile gint32 buffer_lock_exclusive_intent;
 308
 309         volatile gint32 runtime_inited;
 310         volatile gint32 in_shutdown;
 311
 312         MonoNativeThreadId helper_thread;
 313
 314         MonoNativeThreadId writer_thread;
 315         volatile gint32 run_writer_thread;
 316         MonoLockFreeQueue writer_queue;
 317         MonoSemType writer_queue_sem;
 318
 319         MonoLockFreeAllocSizeClass writer_entry_size_class;
 320         MonoLockFreeAllocator writer_entry_allocator;
 321
 322         MonoConcurrentHashTable *method_table;
 323         mono_mutex_t method_table_mutex;
 324
 325         MonoNativeThreadId dumper_thread;
 326         volatile gint32 run_dumper_thread;
 327         MonoLockFreeQueue dumper_queue;
 328         MonoSemType dumper_queue_sem;
 329
 330         MonoLockFreeAllocSizeClass sample_size_class;
 331         MonoLockFreeAllocator sample_allocator;
 332         MonoLockFreeQueue sample_reuse_queue;
 333
 334         BinaryObject *binary_objects;
 335
 336         volatile gint32 heapshot_requested;
 337         guint64 gc_count;
 338         guint64 last_hs_time;
 339         gboolean do_heap_walk;
 340
 341         mono_mutex_t counters_mutex;
 342         MonoCounterAgent *counters;
 343         PerfCounterAgent *perfcounters;
 344         guint32 counters_index;
 345
 346         mono_mutex_t coverage_mutex;
 347         GPtrArray *coverage_data;
 348
 349         GPtrArray *coverage_filters;
 350         MonoConcurrentHashTable *coverage_filtered_classes;
 351         MonoConcurrentHashTable *coverage_suppressed_assemblies;
 352
 353         MonoConcurrentHashTable *coverage_methods;
 354         MonoConcurrentHashTable *coverage_assemblies;
 355         MonoConcurrentHashTable *coverage_classes;
 356
 357         MonoConcurrentHashTable *coverage_image_to_methods;
 358
 359         guint32 coverage_previous_offset;
 360         guint32 coverage_method_id;
 361 };
 362
 363 static ProfilerConfig log_config;
 364 static struct _MonoProfiler log_profiler;
 365
 366 typedef struct {
 367         MonoLockFreeQueueNode node;
 368         GPtrArray *methods;
 369         LogBuffer *buffer;
 370 } WriterQueueEntry;
 371
 372 #define WRITER_ENTRY_BLOCK_SIZE (mono_pagesize ())
 373
 374 typedef struct {
 375         MonoMethod *method;
 376         MonoJitInfo *ji;
 377         uint64_t time;
 378 } MethodInfo;
 379
 380 #define TICKS_PER_SEC 1000000000LL
 381
 382 static uint64_t
 383 current_time (void)
 384 {
 385 #ifdef __APPLE__
 386         uint64_t time = mach_absolute_time ();
 387
 388         time *= log_profiler.timebase_info.numer;
 389         time /= log_profiler.timebase_info.denom;
 390
 391         return time;
 392 #elif defined (HOST_WIN32)
 393         LARGE_INTEGER value;
 394
 395         QueryPerformanceCounter (&value);
 396
 397         return value.QuadPart * TICKS_PER_SEC / log_profiler.pcounter_freq.QuadPart;
 398 #elif defined (CLOCK_MONOTONIC)
 399         struct timespec tspec;
 400
 401         clock_gettime (CLOCK_MONOTONIC, &tspec);
 402
 403         return ((uint64_t) tspec.tv_sec * TICKS_PER_SEC + tspec.tv_nsec);
 404 #else
 405         struct timeval tv;
 406
 407         gettimeofday (&tv, NULL);
 408
 409         return ((uint64_t) tv.tv_sec * TICKS_PER_SEC + tv.tv_usec * 1000);
 410 #endif
 411 }
 412
 413 static void
 414 init_time (void)
 415 {
 416 #ifdef __APPLE__
 417         mach_timebase_info (&log_profiler.timebase_info);
 418 #elif defined (HOST_WIN32)
 419         QueryPerformanceFrequency (&log_profiler.pcounter_freq);
 420 #endif
 421
 422         uint64_t time_start = current_time ();
 423
 424         for (int i = 0; i < 256; ++i)
 425                 current_time ();
 426
 427         uint64_t time_end = current_time ();
 428
 429         log_profiler.timer_overhead = (time_end - time_start) / 256;
 430 }
 431
 432 static char*
 433 pstrdup (const char *s)
 434 {
 435         int len = strlen (s) + 1;
 436         char *p = (char *) g_malloc (len);
 437         memcpy (p, s, len);
 438         return p;
 439 }
 440
 441 #define BUFFER_SIZE (4096 * 16)
 442
 443 /* Worst-case size in bytes of a 64-bit value encoded with LEB128. */
 444 #define LEB128_SIZE 10
 445
 446 /* Size of a value encoded as a single byte. */
 447 #undef BYTE_SIZE // mach/i386/vm_param.h on OS X defines this to 8, but it isn't used for anything.
 448 #define BYTE_SIZE 1
 449
 450 /* Size in bytes of the event prefix (ID + time). */
 451 #define EVENT_SIZE (BYTE_SIZE + LEB128_SIZE)
 452
 453 static void *
 454 alloc_buffer (int size)
 455 {
 456         return mono_valloc (NULL, size, MONO_MMAP_READ | MONO_MMAP_WRITE | MONO_MMAP_ANON | MONO_MMAP_PRIVATE, MONO_MEM_ACCOUNT_PROFILER);
 457 }
 458
 459 static void
 460 free_buffer (void *buf, int size)
 461 {
 462         mono_vfree (buf, size, MONO_MEM_ACCOUNT_PROFILER);
 463 }
 464
 465 static LogBuffer*
 466 create_buffer (uintptr_t tid, int bytes)
 467 {
 468         LogBuffer* buf = (LogBuffer *) alloc_buffer (MAX (BUFFER_SIZE, bytes));
 469
 470         InterlockedIncrement (&buffer_allocations_ctr);
 471
 472         buf->size = BUFFER_SIZE;
 473         buf->time_base = current_time ();
 474         buf->last_time = buf->time_base;
 475         buf->buf_end = (unsigned char *) buf + buf->size;
 476         buf->cursor = buf->buf;
 477         buf->thread_id = tid;
 478
 479         return buf;
 480 }
 481
 482 /*
 483  * Must be called with the reader lock held if thread is the current thread, or
 484  * the exclusive lock if thread is a different thread. However, if thread is
 485  * the current thread, and init_thread () was called with add_to_lls = FALSE,
 486  * then no locking is necessary.
 487  */
 488 static void
 489 init_buffer_state (MonoProfilerThread *thread)
 490 {
 491         thread->buffer = create_buffer (thread->node.key, 0);
 492         thread->methods = NULL;
 493 }
 494
 495 static void
 496 clear_hazard_pointers (MonoThreadHazardPointers *hp)
 497 {
 498         mono_hazard_pointer_clear (hp, 0);
 499         mono_hazard_pointer_clear (hp, 1);
 500         mono_hazard_pointer_clear (hp, 2);
 501 }
 502
 503 static MonoProfilerThread *
 504 init_thread (gboolean add_to_lls)
 505 {
 506         MonoProfilerThread *thread = PROF_TLS_GET ();
 507
 508         /*
 509          * Sometimes we may try to initialize a thread twice. One example is the
 510          * main thread: We initialize it when setting up the profiler, but we will
 511          * also get a thread_start () callback for it. Another example is when
 512          * attaching new threads to the runtime: We may get a gc_alloc () callback
 513          * for that thread's thread object (where we initialize it), soon followed
 514          * by a thread_start () callback.
 515          *
 516          * These cases are harmless anyhow. Just return if we've already done the
 517          * initialization work.
 518          */
 519         if (thread)
 520                 return thread;
 521
 522         thread = g_malloc (sizeof (MonoProfilerThread));
 523         thread->node.key = thread_id ();
 524         thread->attached = add_to_lls;
 525         thread->call_depth = 0;
 526         thread->busy = 0;
 527         thread->ended = FALSE;
 528
 529         init_buffer_state (thread);
 530
 531         thread->small_id = mono_thread_info_register_small_id ();
 532
 533         /*
 534          * Some internal profiler threads don't need to be cleaned up
 535          * by the main thread on shutdown.
 536          */
 537         if (add_to_lls) {
 538                 MonoThreadHazardPointers *hp = mono_hazard_pointer_get ();
 539                 g_assert (mono_lls_insert (&log_profiler.profiler_thread_list, hp, &thread->node) && "Why can't we insert the thread in the LLS?");
 540                 clear_hazard_pointers (hp);
 541         }
 542
 543         PROF_TLS_SET (thread);
 544
 545         return thread;
 546 }
 547
 548 // Only valid if init_thread () was called with add_to_lls = FALSE.
 549 static void
 550 deinit_thread (MonoProfilerThread *thread)
 551 {
 552         g_assert (!thread->attached && "Why are we manually freeing an attached thread?");
 553
 554         g_free (thread);
 555         PROF_TLS_SET (NULL);
 556 }
 557
 558 static MonoProfilerThread *
 559 get_thread (void)
 560 {
 561         return init_thread (TRUE);
 562 }
 563
 564 // Only valid if init_thread () was called with add_to_lls = FALSE.
 565 static LogBuffer *
 566 ensure_logbuf_unsafe (MonoProfilerThread *thread, int bytes)
 567 {
 568         LogBuffer *old = thread->buffer;
 569
 570         if (old->cursor + bytes < old->buf_end)
 571                 return old;
 572
 573         LogBuffer *new_ = create_buffer (thread->node.key, bytes);
 574         new_->next = old;
 575         thread->buffer = new_;
 576
 577         return new_;
 578 }
 579
 580 /*
 581  * This is a reader/writer spin lock of sorts used to protect log buffers.
 582  * When a thread modifies its own log buffer, it increments the reader
 583  * count. When a thread wants to access log buffers of other threads, it
 584  * takes the exclusive lock.
 585  *
 586  * `buffer_lock_state` holds the reader count in its lower 16 bits, and
 587  * the small ID of the thread currently holding the exclusive (writer)
 588  * lock in its upper 16 bits. Both can be zero. It's important that the
 589  * whole lock state is a single word that can be read/written atomically
 590  * to avoid race conditions where there could end up being readers while
 591  * the writer lock is held.
 592  *
 593  * The lock is writer-biased. When a thread wants to take the exclusive
 594  * lock, it increments `buffer_lock_exclusive_intent` which will make new
 595  * readers spin until it's back to zero, then takes the exclusive lock
 596  * once the reader count has reached zero. After releasing the exclusive
 597  * lock, it decrements `buffer_lock_exclusive_intent`, which, when it
 598  * reaches zero again, allows readers to increment the reader count.
 599  *
 600  * The writer bias is necessary because we take the exclusive lock in
 601  * `gc_event ()` during STW. If the writer bias was not there, and a
 602  * program had a large number of threads, STW-induced pauses could be
 603  * significantly longer than they have to be. Also, we emit periodic
 604  * sync points from the helper thread, which requires taking the
 605  * exclusive lock, and we need those to arrive with a reasonably
 606  * consistent frequency so that readers don't have to queue up too many
 607  * events between sync points.
 608  *
 609  * The lock does not support recursion.
 610  */
 611
 612 static void
 613 buffer_lock (void)
 614 {
 615         /*
 616          * If the thread holding the exclusive lock tries to modify the
 617          * reader count, just make it a no-op. This way, we also avoid
 618          * invoking the GC safe point macros below, which could break if
 619          * done from a thread that is currently the initiator of STW.
 620          *
 621          * In other words, we rely on the fact that the GC thread takes
 622          * the exclusive lock in the gc_event () callback when the world
 623          * is about to stop.
 624          */
 625         if (InterlockedRead (&log_profiler.buffer_lock_state) != get_thread ()->small_id << 16) {
 626                 MONO_ENTER_GC_SAFE;
 627
 628                 gint32 old, new_;
 629
 630                 do {
 631                 restart:
 632                         // Hold off if a thread wants to take the exclusive lock.
 633                         while (InterlockedRead (&log_profiler.buffer_lock_exclusive_intent))
 634                                 mono_thread_info_yield ();
 635
 636                         old = InterlockedRead (&log_profiler.buffer_lock_state);
 637
 638                         // Is a thread holding the exclusive lock?
 639                         if (old >> 16) {
 640                                 mono_thread_info_yield ();
 641                                 goto restart;
 642                         }
 643
 644                         new_ = old + 1;
 645                 } while (InterlockedCompareExchange (&log_profiler.buffer_lock_state, new_, old) != old);
 646
 647                 MONO_EXIT_GC_SAFE;
 648         }
 649
 650         mono_memory_barrier ();
 651 }
 652
 653 static void
 654 buffer_unlock (void)
 655 {
 656         mono_memory_barrier ();
 657
 658         gint32 state = InterlockedRead (&log_profiler.buffer_lock_state);
 659
 660         // See the comment in buffer_lock ().
 661         if (state == PROF_TLS_GET ()->small_id << 16)
 662                 return;
 663
 664         g_assert (state && "Why are we decrementing a zero reader count?");
 665         g_assert (!(state >> 16) && "Why is the exclusive lock held?");
 666
 667         InterlockedDecrement (&log_profiler.buffer_lock_state);
 668 }
 669
 670 static void
 671 buffer_lock_excl (void)
 672 {
 673         gint32 new_ = get_thread ()->small_id << 16;
 674
 675         g_assert (InterlockedRead (&log_profiler.buffer_lock_state) != new_ && "Why are we taking the exclusive lock twice?");
 676
 677         InterlockedIncrement (&log_profiler.buffer_lock_exclusive_intent);
 678
 679         MONO_ENTER_GC_SAFE;
 680
 681         while (InterlockedCompareExchange (&log_profiler.buffer_lock_state, new_, 0))
 682                 mono_thread_info_yield ();
 683
 684         MONO_EXIT_GC_SAFE;
 685
 686         mono_memory_barrier ();
 687 }
 688
 689 static void
 690 buffer_unlock_excl (void)
 691 {
 692         mono_memory_barrier ();
 693
 694         gint32 state = InterlockedRead (&log_profiler.buffer_lock_state);
 695         gint32 excl = state >> 16;
 696
 697         g_assert (excl && "Why is the exclusive lock not held?");
 698         g_assert (excl == PROF_TLS_GET ()->small_id && "Why does another thread hold the exclusive lock?");
 699         g_assert (!(state & 0xFFFF) && "Why are there readers when the exclusive lock is held?");
 700
 701         InterlockedWrite (&log_profiler.buffer_lock_state, 0);
 702         InterlockedDecrement (&log_profiler.buffer_lock_exclusive_intent);
 703 }
 704
 705 static void
 706 encode_uleb128 (uint64_t value, uint8_t *buf, uint8_t **endbuf)
 707 {
 708         uint8_t *p = buf;
 709
 710         do {
 711                 uint8_t b = value & 0x7f;
 712                 value >>= 7;
 713
 714                 if (value != 0) /* more bytes to come */
 715                         b |= 0x80;
 716
 717                 *p ++ = b;
 718         } while (value);
 719
 720         *endbuf = p;
 721 }
 722
 723 static void
 724 encode_sleb128 (intptr_t value, uint8_t *buf, uint8_t **endbuf)
 725 {
 726         int more = 1;
 727         int negative = (value < 0);
 728         unsigned int size = sizeof (intptr_t) * 8;
 729         uint8_t byte;
 730         uint8_t *p = buf;
 731
 732         while (more) {
 733                 byte = value & 0x7f;
 734                 value >>= 7;
 735
 736                 /* the following is unnecessary if the
 737                  * implementation of >>= uses an arithmetic rather
 738                  * than logical shift for a signed left operand
 739                  */
 740                 if (negative)
 741                         /* sign extend */
 742                         value |= - ((intptr_t) 1 <<(size - 7));
 743
 744                 /* sign bit of byte is second high order bit (0x40) */
 745                 if ((value == 0 && !(byte & 0x40)) ||
 746                     (value == -1 && (byte & 0x40)))
 747                         more = 0;
 748                 else
 749                         byte |= 0x80;
 750
 751                 *p ++= byte;
 752         }
 753
 754         *endbuf = p;
 755 }
 756
 757 static void
 758 emit_byte (LogBuffer *logbuffer, int value)
 759 {
 760         logbuffer->cursor [0] = value;
 761         logbuffer->cursor++;
 762
 763         g_assert (logbuffer->cursor <= logbuffer->buf_end && "Why are we writing past the buffer end?");
 764 }
 765
 766 static void
 767 emit_value (LogBuffer *logbuffer, int value)
 768 {
 769         encode_uleb128 (value, logbuffer->cursor, &logbuffer->cursor);
 770
 771         g_assert (logbuffer->cursor <= logbuffer->buf_end && "Why are we writing past the buffer end?");
 772 }
 773
 774 static void
 775 emit_time (LogBuffer *logbuffer, uint64_t value)
 776 {
 777         uint64_t tdiff = value - logbuffer->last_time;
 778         encode_uleb128 (tdiff, logbuffer->cursor, &logbuffer->cursor);
 779         logbuffer->last_time = value;
 780
 781         g_assert (logbuffer->cursor <= logbuffer->buf_end && "Why are we writing past the buffer end?");
 782 }
 783
 784 static void
 785 emit_event_time (LogBuffer *logbuffer, int event, uint64_t time)
 786 {
 787         emit_byte (logbuffer, event);
 788         emit_time (logbuffer, time);
 789 }
 790
 791 static void
 792 emit_event (LogBuffer *logbuffer, int event)
 793 {
 794         emit_event_time (logbuffer, event, current_time ());
 795 }
 796
 797 static void
 798 emit_svalue (LogBuffer *logbuffer, int64_t value)
 799 {
 800         encode_sleb128 (value, logbuffer->cursor, &logbuffer->cursor);
 801
 802         g_assert (logbuffer->cursor <= logbuffer->buf_end && "Why are we writing past the buffer end?");
 803 }
 804
 805 static void
 806 emit_uvalue (LogBuffer *logbuffer, uint64_t value)
 807 {
 808         encode_uleb128 (value, logbuffer->cursor, &logbuffer->cursor);
 809
 810         g_assert (logbuffer->cursor <= logbuffer->buf_end && "Why are we writing past the buffer end?");
 811 }
 812
 813 static void
 814 emit_ptr (LogBuffer *logbuffer, const void *ptr)
 815 {
 816         if (!logbuffer->ptr_base)
 817                 logbuffer->ptr_base = (uintptr_t) ptr;
 818
 819         emit_svalue (logbuffer, (intptr_t) ptr - logbuffer->ptr_base);
 820
 821         g_assert (logbuffer->cursor <= logbuffer->buf_end && "Why are we writing past the buffer end?");
 822 }
 823
 824 static void
 825 emit_method_inner (LogBuffer *logbuffer, void *method)
 826 {
 827         if (!logbuffer->method_base) {
 828                 logbuffer->method_base = (intptr_t) method;
 829                 logbuffer->last_method = (intptr_t) method;
 830         }
 831
 832         encode_sleb128 ((intptr_t) ((char *) method - (char *) logbuffer->last_method), logbuffer->cursor, &logbuffer->cursor);
 833         logbuffer->last_method = (intptr_t) method;
 834
 835         g_assert (logbuffer->cursor <= logbuffer->buf_end && "Why are we writing past the buffer end?");
 836 }
 837
 838 // The reader lock must be held.
 839 static void
 840 register_method_local (MonoMethod *method, MonoJitInfo *ji)
 841 {
 842         MonoProfilerThread *thread = get_thread ();
 843
 844         if (!mono_conc_hashtable_lookup (log_profiler.method_table, method)) {
 845                 MethodInfo *info = (MethodInfo *) g_malloc (sizeof (MethodInfo));
 846
 847                 info->method = method;
 848                 info->ji = ji;
 849                 info->time = current_time ();
 850
 851                 GPtrArray *arr = thread->methods ? thread->methods : (thread->methods = g_ptr_array_new ());
 852                 g_ptr_array_add (arr, info);
 853         }
 854 }
 855
 856 static void
 857 emit_method (LogBuffer *logbuffer, MonoMethod *method)
 858 {
 859         register_method_local (method, NULL);
 860         emit_method_inner (logbuffer, method);
 861 }
 862
 863 static void
 864 emit_obj (LogBuffer *logbuffer, void *ptr)
 865 {
 866         if (!logbuffer->obj_base)
 867                 logbuffer->obj_base = (uintptr_t) ptr >> 3;
 868
 869         emit_svalue (logbuffer, ((uintptr_t) ptr >> 3) - logbuffer->obj_base);
 870
 871         g_assert (logbuffer->cursor <= logbuffer->buf_end && "Why are we writing past the buffer end?");
 872 }
 873
 874 static void
 875 emit_string (LogBuffer *logbuffer, const char *str, size_t size)
 876 {
 877         size_t i = 0;
 878         if (str) {
 879                 for (; i < size; i++) {
 880                         if (str[i] == '\0')
 881                                 break;
 882                         emit_byte (logbuffer, str [i]);
 883                 }
 884         }
 885         emit_byte (logbuffer, '\0');
 886 }
 887
 888 static void
 889 emit_double (LogBuffer *logbuffer, double value)
 890 {
 891         int i;
 892         unsigned char buffer[8];
 893         memcpy (buffer, &value, 8);
 894 #if G_BYTE_ORDER == G_BIG_ENDIAN
 895         for (i = 7; i >= 0; i--)
 896 #else
 897         for (i = 0; i < 8; i++)
 898 #endif
 899                 emit_byte (logbuffer, buffer[i]);
 900 }
 901
 902 static char*
 903 write_int16 (char *buf, int32_t value)
 904 {
 905         int i;
 906         for (i = 0; i < 2; ++i) {
 907                 buf [i] = value;
 908                 value >>= 8;
 909         }
 910         return buf + 2;
 911 }
 912
 913 static char*
 914 write_int32 (char *buf, int32_t value)
 915 {
 916         int i;
 917         for (i = 0; i < 4; ++i) {
 918                 buf [i] = value;
 919                 value >>= 8;
 920         }
 921         return buf + 4;
 922 }
 923
 924 static char*
 925 write_int64 (char *buf, int64_t value)
 926 {
 927         int i;
 928         for (i = 0; i < 8; ++i) {
 929                 buf [i] = value;
 930                 value >>= 8;
 931         }
 932         return buf + 8;
 933 }
 934
 935 static char *
 936 write_header_string (char *p, const char *str)
 937 {
 938         size_t len = strlen (str) + 1;
 939
 940         p = write_int32 (p, len);
 941         strcpy (p, str);
 942
 943         return p + len;
 944 }
 945
 946 static void
 947 dump_header (void)
 948 {
 949         const char *args = log_profiler.args;
 950         const char *arch = mono_config_get_cpu ();
 951         const char *os = mono_config_get_os ();
 952
 953         char *hbuf = g_malloc (
 954                 sizeof (gint32) /* header id */ +
 955                 sizeof (gint8) /* major version */ +
 956                 sizeof (gint8) /* minor version */ +
 957                 sizeof (gint8) /* data version */ +
 958                 sizeof (gint8) /* word size */ +
 959                 sizeof (gint64) /* startup time */ +
 960                 sizeof (gint32) /* timer overhead */ +
 961                 sizeof (gint32) /* flags */ +
 962                 sizeof (gint32) /* process id */ +
 963                 sizeof (gint16) /* command port */ +
 964                 sizeof (gint32) + strlen (args) + 1 /* arguments */ +
 965                 sizeof (gint32) + strlen (arch) + 1 /* architecture */ +
 966                 sizeof (gint32) + strlen (os) + 1 /* operating system */
 967         );
 968         char *p = hbuf;
 969
 970         p = write_int32 (p, LOG_HEADER_ID);
 971         *p++ = LOG_VERSION_MAJOR;
 972         *p++ = LOG_VERSION_MINOR;
 973         *p++ = LOG_DATA_VERSION;
 974         *p++ = sizeof (void *);
 975         p = write_int64 (p, ((uint64_t) time (NULL)) * 1000);
 976         p = write_int32 (p, log_profiler.timer_overhead);
 977         p = write_int32 (p, 0); /* flags */
 978         p = write_int32 (p, process_id ());
 979         p = write_int16 (p, log_profiler.command_port);
 980         p = write_header_string (p, args);
 981         p = write_header_string (p, arch);
 982         p = write_header_string (p, os);
 983
 984 #if defined (HAVE_SYS_ZLIB)
 985         if (log_profiler.gzfile) {
 986                 gzwrite (log_profiler.gzfile, hbuf, p - hbuf);
 987         } else
 988 #endif
 989         {
 990                 fwrite (hbuf, p - hbuf, 1, log_profiler.file);
 991                 fflush (log_profiler.file);
 992         }
 993
 994         g_free (hbuf);
 995 }
 996
 997 /*
 998  * Must be called with the reader lock held if thread is the current thread, or
 999  * the exclusive lock if thread is a different thread. However, if thread is
1000  * the current thread, and init_thread () was called with add_to_lls = FALSE,
1001  * then no locking is necessary.
1002  */
1003 static void
1004 send_buffer (MonoProfilerThread *thread)
1005 {
1006         WriterQueueEntry *entry = mono_lock_free_alloc (&log_profiler.writer_entry_allocator);
1007         entry->methods = thread->methods;
1008         entry->buffer = thread->buffer;
1009
1010         mono_lock_free_queue_node_init (&entry->node, FALSE);
1011
1012         mono_lock_free_queue_enqueue (&log_profiler.writer_queue, &entry->node);
1013         mono_os_sem_post (&log_profiler.writer_queue_sem);
1014 }
1015
1016 static void
1017 free_thread (gpointer p)
1018 {
1019         MonoProfilerThread *thread = p;
1020
1021         if (!thread->ended) {
1022                 /*
1023                  * The thread is being cleaned up by the main thread during
1024                  * shutdown. This typically happens for internal runtime
1025                  * threads. We need to synthesize a thread end event.
1026                  */
1027
1028                 InterlockedIncrement (&thread_ends_ctr);
1029
1030                 LogBuffer *buf = ensure_logbuf_unsafe (thread,
1031                         EVENT_SIZE /* event */ +
1032                         BYTE_SIZE /* type */ +
1033                         LEB128_SIZE /* tid */
1034                 );
1035
1036                 emit_event (buf, TYPE_END_UNLOAD | TYPE_METADATA);
1037                 emit_byte (buf, TYPE_THREAD);
1038                 emit_ptr (buf, (void *) thread->node.key);
1039         }
1040
1041         send_buffer (thread);
1042
1043         g_free (thread);
1044 }
1045
1046 static void
1047 remove_thread (MonoProfilerThread *thread)
1048 {
1049         MonoThreadHazardPointers *hp = mono_hazard_pointer_get ();
1050
1051         if (mono_lls_remove (&log_profiler.profiler_thread_list, hp, &thread->node))
1052                 mono_thread_hazardous_try_free (thread, free_thread);
1053
1054         clear_hazard_pointers (hp);
1055 }
1056
1057 static void
1058 dump_buffer (LogBuffer *buf)
1059 {
1060         char hbuf [128];
1061         char *p = hbuf;
1062
1063         if (buf->next)
1064                 dump_buffer (buf->next);
1065
1066         if (buf->cursor - buf->buf) {
1067                 p = write_int32 (p, BUF_ID);
1068                 p = write_int32 (p, buf->cursor - buf->buf);
1069                 p = write_int64 (p, buf->time_base);
1070                 p = write_int64 (p, buf->ptr_base);
1071                 p = write_int64 (p, buf->obj_base);
1072                 p = write_int64 (p, buf->thread_id);
1073                 p = write_int64 (p, buf->method_base);
1074
1075 #if defined (HAVE_SYS_ZLIB)
1076                 if (log_profiler.gzfile) {
1077                         gzwrite (log_profiler.gzfile, hbuf, p - hbuf);
1078                         gzwrite (log_profiler.gzfile, buf->buf, buf->cursor - buf->buf);
1079                 } else
1080 #endif
1081                 {
1082                         fwrite (hbuf, p - hbuf, 1, log_profiler.file);
1083                         fwrite (buf->buf, buf->cursor - buf->buf, 1, log_profiler.file);
1084                         fflush (log_profiler.file);
1085                 }
1086         }
1087
1088         free_buffer (buf, buf->size);
1089 }
1090
1091 static void
1092 dump_buffer_threadless (LogBuffer *buf)
1093 {
1094         for (LogBuffer *iter = buf; iter; iter = iter->next)
1095                 iter->thread_id = 0;
1096
1097         dump_buffer (buf);
1098 }
1099
1100 // Only valid if init_thread () was called with add_to_lls = FALSE.
1101 static void
1102 send_log_unsafe (gboolean if_needed)
1103 {
1104         MonoProfilerThread *thread = PROF_TLS_GET ();
1105
1106         if (!if_needed || (if_needed && thread->buffer->next)) {
1107                 if (!thread->attached)
1108                         for (LogBuffer *iter = thread->buffer; iter; iter = iter->next)
1109                                 iter->thread_id = 0;
1110
1111                 send_buffer (thread);
1112                 init_buffer_state (thread);
1113         }
1114 }
1115
1116 // Assumes that the exclusive lock is held.
1117 static void
1118 sync_point_flush (void)
1119 {
1120         g_assert (InterlockedRead (&log_profiler.buffer_lock_state) == PROF_TLS_GET ()->small_id << 16 && "Why don't we hold the exclusive lock?");
1121
1122         MONO_LLS_FOREACH_SAFE (&log_profiler.profiler_thread_list, MonoProfilerThread, thread) {
1123                 g_assert (thread->attached && "Why is a thread in the LLS not attached?");
1124
1125                 send_buffer (thread);
1126                 init_buffer_state (thread);
1127         } MONO_LLS_FOREACH_SAFE_END
1128 }
1129
1130 // Assumes that the exclusive lock is held.
1131 static void
1132 sync_point_mark (MonoProfilerSyncPointType type)
1133 {
1134         g_assert (InterlockedRead (&log_profiler.buffer_lock_state) == PROF_TLS_GET ()->small_id << 16 && "Why don't we hold the exclusive lock?");
1135
1136         ENTER_LOG (&sync_points_ctr, logbuffer,
1137                 EVENT_SIZE /* event */ +
1138                 LEB128_SIZE /* type */
1139         );
1140
1141         emit_event (logbuffer, TYPE_META | TYPE_SYNC_POINT);
1142         emit_byte (logbuffer, type);
1143
1144         EXIT_LOG_EXPLICIT (NO_SEND);
1145
1146         send_log_unsafe (FALSE);
1147 }
1148
1149 // Assumes that the exclusive lock is held.
1150 static void
1151 sync_point (MonoProfilerSyncPointType type)
1152 {
1153         sync_point_flush ();
1154         sync_point_mark (type);
1155 }
1156
1157 static int
1158 gc_reference (MonoObject *obj, MonoClass *klass, uintptr_t size, uintptr_t num, MonoObject **refs, uintptr_t *offsets, void *data)
1159 {
1160         /* account for object alignment in the heap */
1161         size += 7;
1162         size &= ~7;
1163
1164         ENTER_LOG (&heap_objects_ctr, logbuffer,
1165                 EVENT_SIZE /* event */ +
1166                 LEB128_SIZE /* obj */ +
1167                 LEB128_SIZE /* klass */ +
1168                 LEB128_SIZE /* size */ +
1169                 LEB128_SIZE /* num */ +
1170                 num * (
1171                         LEB128_SIZE /* offset */ +
1172                         LEB128_SIZE /* ref */
1173                 )
1174         );
1175
1176         emit_event (logbuffer, TYPE_HEAP_OBJECT | TYPE_HEAP);
1177         emit_obj (logbuffer, obj);
1178         emit_ptr (logbuffer, klass);
1179         emit_value (logbuffer, size);
1180         emit_value (logbuffer, num);
1181
1182         uintptr_t last_offset = 0;
1183
1184         for (int i = 0; i < num; ++i) {
1185                 emit_value (logbuffer, offsets [i] - last_offset);
1186                 last_offset = offsets [i];
1187                 emit_obj (logbuffer, refs [i]);
1188         }
1189
1190         EXIT_LOG;
1191
1192         return 0;
1193 }
1194
1195 static void
1196 gc_roots (MonoProfiler *prof, MonoObject *const *objects, const MonoProfilerGCRootType *root_types, const uintptr_t *extra_info, uint64_t num)
1197 {
1198         ENTER_LOG (&heap_roots_ctr, logbuffer,
1199                 EVENT_SIZE /* event */ +
1200                 LEB128_SIZE /* num */ +
1201                 LEB128_SIZE /* collections */ +
1202                 num * (
1203                         LEB128_SIZE /* object */ +
1204                         LEB128_SIZE /* root type */ +
1205                         LEB128_SIZE /* extra info */
1206                 )
1207         );
1208
1209         emit_event (logbuffer, TYPE_HEAP_ROOT | TYPE_HEAP);
1210         emit_value (logbuffer, num);
1211         emit_value (logbuffer, mono_gc_collection_count (mono_gc_max_generation ()));
1212
1213         for (int i = 0; i < num; ++i) {
1214                 emit_obj (logbuffer, objects [i]);
1215                 emit_byte (logbuffer, root_types [i]);
1216                 emit_value (logbuffer, extra_info [i]);
1217         }
1218
1219         EXIT_LOG;
1220 }
1221
1222
1223 static void
1224 trigger_on_demand_heapshot (void)
1225 {
1226         if (InterlockedRead (&log_profiler.heapshot_requested))
1227                 mono_gc_collect (mono_gc_max_generation ());
1228 }
1229
1230 #define ALL_GC_EVENTS_MASK (PROFLOG_GC_EVENTS | PROFLOG_GC_MOVE_EVENTS | PROFLOG_GC_ROOT_EVENTS)
1231
1232 static void
1233 gc_event (MonoProfiler *profiler, MonoProfilerGCEvent ev, uint32_t generation)
1234 {
1235         if (ENABLED (PROFLOG_GC_EVENTS)) {
1236                 ENTER_LOG (&gc_events_ctr, logbuffer,
1237                         EVENT_SIZE /* event */ +
1238                         BYTE_SIZE /* gc event */ +
1239                         BYTE_SIZE /* generation */
1240                 );
1241
1242                 emit_event (logbuffer, TYPE_GC_EVENT | TYPE_GC);
1243                 emit_byte (logbuffer, ev);
1244                 emit_byte (logbuffer, generation);
1245
1246                 EXIT_LOG;
1247         }
1248
1249         switch (ev) {
1250         case MONO_GC_EVENT_START:
1251                 if (generation == mono_gc_max_generation ())
1252                         log_profiler.gc_count++;
1253
1254                 switch (log_config.hs_mode) {
1255                 case MONO_PROFILER_HEAPSHOT_NONE:
1256                         log_profiler.do_heap_walk = FALSE;
1257                         break;
1258                 case MONO_PROFILER_HEAPSHOT_MAJOR:
1259                         log_profiler.do_heap_walk = generation == mono_gc_max_generation ();
1260                         break;
1261                 case MONO_PROFILER_HEAPSHOT_ON_DEMAND:
1262                         log_profiler.do_heap_walk = InterlockedRead (&log_profiler.heapshot_requested);
1263                         break;
1264                 case MONO_PROFILER_HEAPSHOT_X_GC:
1265                         log_profiler.do_heap_walk = !(log_profiler.gc_count % log_config.hs_freq_gc);
1266                         break;
1267                 case MONO_PROFILER_HEAPSHOT_X_MS:
1268                         log_profiler.do_heap_walk = (current_time () - log_profiler.last_hs_time) / 1000 * 1000 >= log_config.hs_freq_ms;
1269                         break;
1270                 default:
1271                         g_assert_not_reached ();
1272                 }
1273
1274                 if (ENABLED (PROFLOG_GC_ROOT_EVENTS) && log_profiler.do_heap_walk)
1275                         mono_profiler_set_gc_roots_callback (log_profiler.handle, gc_roots);
1276
1277                 break;
1278         case MONO_GC_EVENT_PRE_STOP_WORLD_LOCKED:
1279                 /*
1280                  * Ensure that no thread can be in the middle of writing to
1281                  * a buffer when the world stops...
1282                  */
1283                 buffer_lock_excl ();
1284                 break;
1285         case MONO_GC_EVENT_POST_STOP_WORLD:
1286                 /*
1287                  * ... So that we now have a consistent view of all buffers.
1288                  * This allows us to flush them. We need to do this because
1289                  * they may contain object allocation events that need to be
1290                  * committed to the log file before any object move events
1291                  * that will be produced during this GC.
1292                  */
1293                 if (ENABLED (ALL_GC_EVENTS_MASK))
1294                         sync_point (SYNC_POINT_WORLD_STOP);
1295
1296                 // Surround heapshots with HEAP_START/HEAP_END events.
1297                 if (log_profiler.do_heap_walk) {
1298                         ENTER_LOG (&heap_starts_ctr, logbuffer,
1299                                 EVENT_SIZE /* event */
1300                         );
1301
1302                         emit_event (logbuffer, TYPE_HEAP_START | TYPE_HEAP);
1303
1304                         EXIT_LOG;
1305                 }
1306
1307                 break;
1308         case MONO_GC_EVENT_PRE_START_WORLD:
1309                 mono_profiler_set_gc_roots_callback (log_profiler.handle, NULL);
1310
1311                 if (log_profiler.do_heap_walk) {
1312                         mono_gc_walk_heap (0, gc_reference, NULL);
1313
1314                         ENTER_LOG (&heap_ends_ctr, logbuffer,
1315                                 EVENT_SIZE /* event */
1316                         );
1317
1318                         emit_event (logbuffer, TYPE_HEAP_END | TYPE_HEAP);
1319
1320                         EXIT_LOG;
1321
1322                         log_profiler.do_heap_walk = FALSE;
1323                         log_profiler.last_hs_time = current_time ();
1324
1325                         InterlockedWrite (&log_profiler.heapshot_requested, 0);
1326                 }
1327
1328                 /*
1329                  * Similarly, we must now make sure that any object moves
1330                  * written to the GC thread's buffer are flushed. Otherwise,
1331                  * object allocation events for certain addresses could come
1332                  * after the move events that made those addresses available.
1333                  */
1334                 if (ENABLED (ALL_GC_EVENTS_MASK))
1335                         sync_point_mark (SYNC_POINT_WORLD_START);
1336                 break;
1337         case MONO_GC_EVENT_POST_START_WORLD_UNLOCKED:
1338                 /*
1339                  * Finally, it is safe to allow other threads to write to
1340                  * their buffers again.
1341                  */
1342                 buffer_unlock_excl ();
1343                 break;
1344         default:
1345                 break;
1346         }
1347 }
1348
1349 static void
1350 gc_resize (MonoProfiler *profiler, uintptr_t new_size)
1351 {
1352         ENTER_LOG (&gc_resizes_ctr, logbuffer,
1353                 EVENT_SIZE /* event */ +
1354                 LEB128_SIZE /* new size */
1355         );
1356
1357         emit_event (logbuffer, TYPE_GC_RESIZE | TYPE_GC);
1358         emit_value (logbuffer, new_size);
1359
1360         EXIT_LOG;
1361 }
1362
1363 typedef struct {
1364         int count;
1365         MonoMethod* methods [MAX_FRAMES];
1366         int32_t il_offsets [MAX_FRAMES];
1367         int32_t native_offsets [MAX_FRAMES];
1368 } FrameData;
1369
1370 static mono_bool
1371 walk_stack (MonoMethod *method, int32_t native_offset, int32_t il_offset, mono_bool managed, void* data)
1372 {
1373         FrameData *frame = (FrameData *)data;
1374         if (method && frame->count < log_config.num_frames) {
1375                 frame->il_offsets [frame->count] = il_offset;
1376                 frame->native_offsets [frame->count] = native_offset;
1377                 frame->methods [frame->count++] = method;
1378         }
1379         return frame->count == log_config.num_frames;
1380 }
1381
1382 /*
1383  * a note about stack walks: they can cause more profiler events to fire,
1384  * so we need to make sure they don't happen after we started emitting an
1385  * event, hence the collect_bt/emit_bt split.
1386  */
1387 static void
1388 collect_bt (FrameData *data)
1389 {
1390         data->count = 0;
1391         mono_stack_walk_no_il (walk_stack, data);
1392 }
1393
1394 static void
1395 emit_bt (LogBuffer *logbuffer, FrameData *data)
1396 {
1397         emit_value (logbuffer, data->count);
1398
1399         while (data->count)
1400                 emit_method (logbuffer, data->methods [--data->count]);
1401 }
1402
1403 static void
1404 gc_alloc (MonoProfiler *prof, MonoObject *obj)
1405 {
1406         int do_bt = (!log_config.enter_leave && InterlockedRead (&log_profiler.runtime_inited) && log_config.num_frames) ? TYPE_ALLOC_BT : 0;
1407         FrameData data;
1408         uintptr_t len = mono_object_get_size (obj);
1409         /* account for object alignment in the heap */
1410         len += 7;
1411         len &= ~7;
1412
1413         if (do_bt)
1414                 collect_bt (&data);
1415
1416         ENTER_LOG (&gc_allocs_ctr, logbuffer,
1417                 EVENT_SIZE /* event */ +
1418                 LEB128_SIZE /* klass */ +
1419                 LEB128_SIZE /* obj */ +
1420                 LEB128_SIZE /* size */ +
1421                 (do_bt ? (
1422                         LEB128_SIZE /* count */ +
1423                         data.count * (
1424                                 LEB128_SIZE /* method */
1425                         )
1426                 ) : 0)
1427         );
1428
1429         emit_event (logbuffer, do_bt | TYPE_ALLOC);
1430         emit_ptr (logbuffer, mono_object_get_class (obj));
1431         emit_obj (logbuffer, obj);
1432         emit_value (logbuffer, len);
1433
1434         if (do_bt)
1435                 emit_bt (logbuffer, &data);
1436
1437         EXIT_LOG;
1438 }
1439
1440 static void
1441 gc_moves (MonoProfiler *prof, MonoObject *const *objects, uint64_t num)
1442 {
1443         ENTER_LOG (&gc_moves_ctr, logbuffer,
1444                 EVENT_SIZE /* event */ +
1445                 LEB128_SIZE /* num */ +
1446                 num * (
1447                         LEB128_SIZE /* object */
1448                 )
1449         );
1450
1451         emit_event (logbuffer, TYPE_GC_MOVE | TYPE_GC);
1452         emit_value (logbuffer, num);
1453
1454         for (int i = 0; i < num; ++i)
1455                 emit_obj (logbuffer, objects [i]);
1456
1457         EXIT_LOG;
1458 }
1459
1460 static void
1461 gc_handle (MonoProfiler *prof, int op, MonoGCHandleType type, uint32_t handle, MonoObject *obj)
1462 {
1463         int do_bt = !log_config.enter_leave && InterlockedRead (&log_profiler.runtime_inited) && log_config.num_frames;
1464         FrameData data;
1465
1466         if (do_bt)
1467                 collect_bt (&data);
1468
1469         gint32 *ctr = op == MONO_PROFILER_GC_HANDLE_CREATED ? &gc_handle_creations_ctr : &gc_handle_deletions_ctr;
1470
1471         ENTER_LOG (ctr, logbuffer,
1472                 EVENT_SIZE /* event */ +
1473                 LEB128_SIZE /* type */ +
1474                 LEB128_SIZE /* handle */ +
1475                 (op == MONO_PROFILER_GC_HANDLE_CREATED ? (
1476                         LEB128_SIZE /* obj */
1477                 ) : 0) +
1478                 (do_bt ? (
1479                         LEB128_SIZE /* count */ +
1480                         data.count * (
1481                                 LEB128_SIZE /* method */
1482                         )
1483                 ) : 0)
1484         );
1485
1486         if (op == MONO_PROFILER_GC_HANDLE_CREATED)
1487                 emit_event (logbuffer, (do_bt ? TYPE_GC_HANDLE_CREATED_BT : TYPE_GC_HANDLE_CREATED) | TYPE_GC);
1488         else if (op == MONO_PROFILER_GC_HANDLE_DESTROYED)
1489                 emit_event (logbuffer, (do_bt ? TYPE_GC_HANDLE_DESTROYED_BT : TYPE_GC_HANDLE_DESTROYED) | TYPE_GC);
1490         else
1491                 g_assert_not_reached ();
1492
1493         emit_value (logbuffer, type);
1494         emit_value (logbuffer, handle);
1495
1496         if (op == MONO_PROFILER_GC_HANDLE_CREATED)
1497                 emit_obj (logbuffer, obj);
1498
1499         if (do_bt)
1500                 emit_bt (logbuffer, &data);
1501
1502         EXIT_LOG;
1503 }
1504
1505 static void
1506 gc_handle_created (MonoProfiler *prof, uint32_t handle, MonoGCHandleType type, MonoObject *obj)
1507 {
1508         gc_handle (prof, MONO_PROFILER_GC_HANDLE_CREATED, type, handle, obj);
1509 }
1510
1511 static void
1512 gc_handle_deleted (MonoProfiler *prof, uint32_t handle, MonoGCHandleType type)
1513 {
1514         gc_handle (prof, MONO_PROFILER_GC_HANDLE_DESTROYED, type, handle, NULL);
1515 }
1516
1517 static void
1518 finalize_begin (MonoProfiler *prof)
1519 {
1520         ENTER_LOG (&finalize_begins_ctr, buf,
1521                 EVENT_SIZE /* event */
1522         );
1523
1524         emit_event (buf, TYPE_GC_FINALIZE_START | TYPE_GC);
1525
1526         EXIT_LOG;
1527 }
1528
1529 static void
1530 finalize_end (MonoProfiler *prof)
1531 {
1532         trigger_on_demand_heapshot ();
1533         if (ENABLED (PROFLOG_FINALIZATION_EVENTS)) {
1534                 ENTER_LOG (&finalize_ends_ctr, buf,
1535                         EVENT_SIZE /* event */
1536                 );
1537
1538                 emit_event (buf, TYPE_GC_FINALIZE_END | TYPE_GC);
1539
1540                 EXIT_LOG;
1541         }
1542 }
1543
1544 static void
1545 finalize_object_begin (MonoProfiler *prof, MonoObject *obj)
1546 {
1547         ENTER_LOG (&finalize_object_begins_ctr, buf,
1548                 EVENT_SIZE /* event */ +
1549                 LEB128_SIZE /* obj */
1550         );
1551
1552         emit_event (buf, TYPE_GC_FINALIZE_OBJECT_START | TYPE_GC);
1553         emit_obj (buf, obj);
1554
1555         EXIT_LOG;
1556 }
1557
1558 static void
1559 finalize_object_end (MonoProfiler *prof, MonoObject *obj)
1560 {
1561         ENTER_LOG (&finalize_object_ends_ctr, buf,
1562                 EVENT_SIZE /* event */ +
1563                 LEB128_SIZE /* obj */
1564         );
1565
1566         emit_event (buf, TYPE_GC_FINALIZE_OBJECT_END | TYPE_GC);
1567         emit_obj (buf, obj);
1568
1569         EXIT_LOG;
1570 }
1571
1572 static char*
1573 push_nesting (char *p, MonoClass *klass)
1574 {
1575         MonoClass *nesting;
1576         const char *name;
1577         const char *nspace;
1578         nesting = mono_class_get_nesting_type (klass);
1579         if (nesting) {
1580                 p = push_nesting (p, nesting);
1581                 *p++ = '/';
1582                 *p = 0;
1583         }
1584         name = mono_class_get_name (klass);
1585         nspace = mono_class_get_namespace (klass);
1586         if (*nspace) {
1587                 strcpy (p, nspace);
1588                 p += strlen (nspace);
1589                 *p++ = '.';
1590                 *p = 0;
1591         }
1592         strcpy (p, name);
1593         p += strlen (name);
1594         return p;
1595 }
1596
1597 static char*
1598 type_name (MonoClass *klass)
1599 {
1600         char buf [1024];
1601         char *p;
1602         push_nesting (buf, klass);
1603         p = (char *) g_malloc (strlen (buf) + 1);
1604         strcpy (p, buf);
1605         return p;
1606 }
1607
1608 static void
1609 image_loaded (MonoProfiler *prof, MonoImage *image)
1610 {
1611         const char *name = mono_image_get_filename (image);
1612         int nlen = strlen (name) + 1;
1613
1614         ENTER_LOG (&image_loads_ctr, logbuffer,
1615                 EVENT_SIZE /* event */ +
1616                 BYTE_SIZE /* type */ +
1617                 LEB128_SIZE /* image */ +
1618                 nlen /* name */
1619         );
1620
1621         emit_event (logbuffer, TYPE_END_LOAD | TYPE_METADATA);
1622         emit_byte (logbuffer, TYPE_IMAGE);
1623         emit_ptr (logbuffer, image);
1624         memcpy (logbuffer->cursor, name, nlen);
1625         logbuffer->cursor += nlen;
1626
1627         EXIT_LOG;
1628 }
1629
1630 static void
1631 image_unloaded (MonoProfiler *prof, MonoImage *image)
1632 {
1633         const char *name = mono_image_get_filename (image);
1634         int nlen = strlen (name) + 1;
1635
1636         ENTER_LOG (&image_unloads_ctr, logbuffer,
1637                 EVENT_SIZE /* event */ +
1638                 BYTE_SIZE /* type */ +
1639                 LEB128_SIZE /* image */ +
1640                 nlen /* name */
1641         );
1642
1643         emit_event (logbuffer, TYPE_END_UNLOAD | TYPE_METADATA);
1644         emit_byte (logbuffer, TYPE_IMAGE);
1645         emit_ptr (logbuffer, image);
1646         memcpy (logbuffer->cursor, name, nlen);
1647         logbuffer->cursor += nlen;
1648
1649         EXIT_LOG;
1650 }
1651
1652 static void
1653 assembly_loaded (MonoProfiler *prof, MonoAssembly *assembly)
1654 {
1655         char *name = mono_stringify_assembly_name (mono_assembly_get_name (assembly));
1656         int nlen = strlen (name) + 1;
1657         MonoImage *image = mono_assembly_get_image (assembly);
1658
1659         ENTER_LOG (&assembly_loads_ctr, logbuffer,
1660                 EVENT_SIZE /* event */ +
1661                 BYTE_SIZE /* type */ +
1662                 LEB128_SIZE /* assembly */ +
1663                 LEB128_SIZE /* image */ +
1664                 nlen /* name */
1665         );
1666
1667         emit_event (logbuffer, TYPE_END_LOAD | TYPE_METADATA);
1668         emit_byte (logbuffer, TYPE_ASSEMBLY);
1669         emit_ptr (logbuffer, assembly);
1670         emit_ptr (logbuffer, image);
1671         memcpy (logbuffer->cursor, name, nlen);
1672         logbuffer->cursor += nlen;
1673
1674         EXIT_LOG;
1675
1676         mono_free (name);
1677 }
1678
1679 static void
1680 assembly_unloaded (MonoProfiler *prof, MonoAssembly *assembly)
1681 {
1682         char *name = mono_stringify_assembly_name (mono_assembly_get_name (assembly));
1683         int nlen = strlen (name) + 1;
1684         MonoImage *image = mono_assembly_get_image (assembly);
1685
1686         ENTER_LOG (&assembly_unloads_ctr, logbuffer,
1687                 EVENT_SIZE /* event */ +
1688                 BYTE_SIZE /* type */ +
1689                 LEB128_SIZE /* assembly */ +
1690                 LEB128_SIZE /* image */ +
1691                 nlen /* name */
1692         );
1693
1694         emit_event (logbuffer, TYPE_END_UNLOAD | TYPE_METADATA);
1695         emit_byte (logbuffer, TYPE_ASSEMBLY);
1696         emit_ptr (logbuffer, assembly);
1697         emit_ptr (logbuffer, image);
1698         memcpy (logbuffer->cursor, name, nlen);
1699         logbuffer->cursor += nlen;
1700
1701         EXIT_LOG;
1702
1703         mono_free (name);
1704 }
1705
1706 static void
1707 class_loaded (MonoProfiler *prof, MonoClass *klass)
1708 {
1709         char *name;
1710
1711         if (InterlockedRead (&log_profiler.runtime_inited))
1712                 name = mono_type_get_name (mono_class_get_type (klass));
1713         else
1714                 name = type_name (klass);
1715
1716         int nlen = strlen (name) + 1;
1717         MonoImage *image = mono_class_get_image (klass);
1718
1719         ENTER_LOG (&class_loads_ctr, logbuffer,
1720                 EVENT_SIZE /* event */ +
1721                 BYTE_SIZE /* type */ +
1722                 LEB128_SIZE /* klass */ +
1723                 LEB128_SIZE /* image */ +
1724                 nlen /* name */
1725         );
1726
1727         emit_event (logbuffer, TYPE_END_LOAD | TYPE_METADATA);
1728         emit_byte (logbuffer, TYPE_CLASS);
1729         emit_ptr (logbuffer, klass);
1730         emit_ptr (logbuffer, image);
1731         memcpy (logbuffer->cursor, name, nlen);
1732         logbuffer->cursor += nlen;
1733
1734         EXIT_LOG;
1735
1736         if (InterlockedRead (&log_profiler.runtime_inited))
1737                 mono_free (name);
1738         else
1739                 g_free (name);
1740 }
1741
1742 static void
1743 method_enter (MonoProfiler *prof, MonoMethod *method)
1744 {
1745         if (get_thread ()->call_depth++ <= log_config.max_call_depth) {
1746                 ENTER_LOG (&method_entries_ctr, logbuffer,
1747                         EVENT_SIZE /* event */ +
1748                         LEB128_SIZE /* method */
1749                 );
1750
1751                 emit_event (logbuffer, TYPE_ENTER | TYPE_METHOD);
1752                 emit_method (logbuffer, method);
1753
1754                 EXIT_LOG;
1755         }
1756 }
1757
1758 static void
1759 method_leave (MonoProfiler *prof, MonoMethod *method)
1760 {
1761         if (--get_thread ()->call_depth <= log_config.max_call_depth) {
1762                 ENTER_LOG (&method_exits_ctr, logbuffer,
1763                         EVENT_SIZE /* event */ +
1764                         LEB128_SIZE /* method */
1765                 );
1766
1767                 emit_event (logbuffer, TYPE_LEAVE | TYPE_METHOD);
1768                 emit_method (logbuffer, method);
1769
1770                 EXIT_LOG;
1771         }
1772 }
1773
1774 static void
1775 method_exc_leave (MonoProfiler *prof, MonoMethod *method, MonoObject *exc)
1776 {
1777         if (--get_thread ()->call_depth <= log_config.max_call_depth) {
1778                 ENTER_LOG (&method_exception_exits_ctr, logbuffer,
1779                         EVENT_SIZE /* event */ +
1780                         LEB128_SIZE /* method */
1781                 );
1782
1783                 emit_event (logbuffer, TYPE_EXC_LEAVE | TYPE_METHOD);
1784                 emit_method (logbuffer, method);
1785
1786                 EXIT_LOG;
1787         }
1788 }
1789
1790 static MonoProfilerCallInstrumentationFlags
1791 method_filter (MonoProfiler *prof, MonoMethod *method)
1792 {
1793         return MONO_PROFILER_CALL_INSTRUMENTATION_PROLOGUE | MONO_PROFILER_CALL_INSTRUMENTATION_EPILOGUE;
1794 }
1795
1796 static void
1797 method_jitted (MonoProfiler *prof, MonoMethod *method, MonoJitInfo *ji)
1798 {
1799         buffer_lock ();
1800
1801         register_method_local (method, ji);
1802
1803         buffer_unlock ();
1804 }
1805
1806 static void
1807 code_buffer_new (MonoProfiler *prof, const mono_byte *buffer, uint64_t size, MonoProfilerCodeBufferType type, const void *data)
1808 {
1809         const char *name;
1810         int nlen;
1811
1812         if (type == MONO_PROFILER_CODE_BUFFER_SPECIFIC_TRAMPOLINE) {
1813                 name = (const char *) data;
1814                 nlen = strlen (name) + 1;
1815         } else {
1816                 name = NULL;
1817                 nlen = 0;
1818         }
1819
1820         ENTER_LOG (&code_buffers_ctr, logbuffer,
1821                 EVENT_SIZE /* event */ +
1822                 BYTE_SIZE /* type */ +
1823                 LEB128_SIZE /* buffer */ +
1824                 LEB128_SIZE /* size */ +
1825                 (name ? (
1826                         nlen /* name */
1827                 ) : 0)
1828         );
1829
1830         emit_event (logbuffer, TYPE_JITHELPER | TYPE_RUNTIME);
1831         emit_byte (logbuffer, type);
1832         emit_ptr (logbuffer, buffer);
1833         emit_value (logbuffer, size);
1834
1835         if (name) {
1836                 memcpy (logbuffer->cursor, name, nlen);
1837                 logbuffer->cursor += nlen;
1838         }
1839
1840         EXIT_LOG;
1841 }
1842
1843 static void
1844 throw_exc (MonoProfiler *prof, MonoObject *object)
1845 {
1846         int do_bt = (!log_config.enter_leave && InterlockedRead (&log_profiler.runtime_inited) && log_config.num_frames) ? TYPE_THROW_BT : 0;
1847         FrameData data;
1848
1849         if (do_bt)
1850                 collect_bt (&data);
1851
1852         ENTER_LOG (&exception_throws_ctr, logbuffer,
1853                 EVENT_SIZE /* event */ +
1854                 LEB128_SIZE /* object */ +
1855                 (do_bt ? (
1856                         LEB128_SIZE /* count */ +
1857                         data.count * (
1858                                 LEB128_SIZE /* method */
1859                         )
1860                 ) : 0)
1861         );
1862
1863         emit_event (logbuffer, do_bt | TYPE_EXCEPTION);
1864         emit_obj (logbuffer, object);
1865
1866         if (do_bt)
1867                 emit_bt (logbuffer, &data);
1868
1869         EXIT_LOG;
1870 }
1871
1872 static void
1873 clause_exc (MonoProfiler *prof, MonoMethod *method, uint32_t clause_num, MonoExceptionEnum clause_type, MonoObject *exc)
1874 {
1875         ENTER_LOG (&exception_clauses_ctr, logbuffer,
1876                 EVENT_SIZE /* event */ +
1877                 BYTE_SIZE /* clause type */ +
1878                 LEB128_SIZE /* clause num */ +
1879                 LEB128_SIZE /* method */
1880         );
1881
1882         emit_event (logbuffer, TYPE_EXCEPTION | TYPE_CLAUSE);
1883         emit_byte (logbuffer, clause_type);
1884         emit_value (logbuffer, clause_num);
1885         emit_method (logbuffer, method);
1886         emit_obj (logbuffer, exc);
1887
1888         EXIT_LOG;
1889 }
1890
1891 static void
1892 monitor_event (MonoProfiler *profiler, MonoObject *object, MonoProfilerMonitorEvent ev)
1893 {
1894         int do_bt = (!log_config.enter_leave && InterlockedRead (&log_profiler.runtime_inited) && log_config.num_frames) ? TYPE_MONITOR_BT : 0;
1895         FrameData data;
1896
1897         if (do_bt)
1898                 collect_bt (&data);
1899
1900         ENTER_LOG (&monitor_events_ctr, logbuffer,
1901                 EVENT_SIZE /* event */ +
1902                 BYTE_SIZE /* ev */ +
1903                 LEB128_SIZE /* object */ +
1904                 (do_bt ? (
1905                         LEB128_SIZE /* count */ +
1906                         data.count * (
1907                                 LEB128_SIZE /* method */
1908                         )
1909                 ) : 0)
1910         );
1911
1912         emit_event (logbuffer, do_bt | TYPE_MONITOR);
1913         emit_byte (logbuffer, ev);
1914         emit_obj (logbuffer, object);
1915
1916         if (do_bt)
1917                 emit_bt (logbuffer, &data);
1918
1919         EXIT_LOG;
1920 }
1921
1922 static void
1923 monitor_contention (MonoProfiler *prof, MonoObject *object)
1924 {
1925         monitor_event (prof, object, MONO_PROFILER_MONITOR_CONTENTION);
1926 }
1927
1928 static void
1929 monitor_acquired (MonoProfiler *prof, MonoObject *object)
1930 {
1931         monitor_event (prof, object, MONO_PROFILER_MONITOR_DONE);
1932 }
1933
1934 static void
1935 monitor_failed (MonoProfiler *prof, MonoObject *object)
1936 {
1937         monitor_event (prof, object, MONO_PROFILER_MONITOR_FAIL);
1938 }
1939
1940 static void
1941 thread_start (MonoProfiler *prof, uintptr_t tid)
1942 {
1943         ENTER_LOG (&thread_starts_ctr, logbuffer,
1944                 EVENT_SIZE /* event */ +
1945                 BYTE_SIZE /* type */ +
1946                 LEB128_SIZE /* tid */
1947         );
1948
1949         emit_event (logbuffer, TYPE_END_LOAD | TYPE_METADATA);
1950         emit_byte (logbuffer, TYPE_THREAD);
1951         emit_ptr (logbuffer, (void*) tid);
1952
1953         EXIT_LOG;
1954 }
1955
1956 static void
1957 thread_end (MonoProfiler *prof, uintptr_t tid)
1958 {
1959         ENTER_LOG (&thread_ends_ctr, logbuffer,
1960                 EVENT_SIZE /* event */ +
1961                 BYTE_SIZE /* type */ +
1962                 LEB128_SIZE /* tid */
1963         );
1964
1965         emit_event (logbuffer, TYPE_END_UNLOAD | TYPE_METADATA);
1966         emit_byte (logbuffer, TYPE_THREAD);
1967         emit_ptr (logbuffer, (void*) tid);
1968
1969         EXIT_LOG_EXPLICIT (NO_SEND);
1970
1971         MonoProfilerThread *thread = get_thread ();
1972
1973         thread->ended = TRUE;
1974         remove_thread (thread);
1975
1976         PROF_TLS_SET (NULL);
1977 }
1978
1979 static void
1980 thread_name (MonoProfiler *prof, uintptr_t tid, const char *name)
1981 {
1982         int len = strlen (name) + 1;
1983
1984         ENTER_LOG (&thread_names_ctr, logbuffer,
1985                 EVENT_SIZE /* event */ +
1986                 BYTE_SIZE /* type */ +
1987                 LEB128_SIZE /* tid */ +
1988                 len /* name */
1989         );
1990
1991         emit_event (logbuffer, TYPE_METADATA);
1992         emit_byte (logbuffer, TYPE_THREAD);
1993         emit_ptr (logbuffer, (void*)tid);
1994         memcpy (logbuffer->cursor, name, len);
1995         logbuffer->cursor += len;
1996
1997         EXIT_LOG;
1998 }
1999
2000 static void
2001 domain_loaded (MonoProfiler *prof, MonoDomain *domain)
2002 {
2003         ENTER_LOG (&domain_loads_ctr, logbuffer,
2004                 EVENT_SIZE /* event */ +
2005                 BYTE_SIZE /* type */ +
2006                 LEB128_SIZE /* domain id */
2007         );
2008
2009         emit_event (logbuffer, TYPE_END_LOAD | TYPE_METADATA);
2010         emit_byte (logbuffer, TYPE_DOMAIN);
2011         emit_ptr (logbuffer, (void*)(uintptr_t) mono_domain_get_id (domain));
2012
2013         EXIT_LOG;
2014 }
2015
2016 static void
2017 domain_unloaded (MonoProfiler *prof, MonoDomain *domain)
2018 {
2019         ENTER_LOG (&domain_unloads_ctr, logbuffer,
2020                 EVENT_SIZE /* event */ +
2021                 BYTE_SIZE /* type */ +
2022                 LEB128_SIZE /* domain id */
2023         );
2024
2025         emit_event (logbuffer, TYPE_END_UNLOAD | TYPE_METADATA);
2026         emit_byte (logbuffer, TYPE_DOMAIN);
2027         emit_ptr (logbuffer, (void*)(uintptr_t) mono_domain_get_id (domain));
2028
2029         EXIT_LOG;
2030 }
2031
2032 static void
2033 domain_name (MonoProfiler *prof, MonoDomain *domain, const char *name)
2034 {
2035         int nlen = strlen (name) + 1;
2036
2037         ENTER_LOG (&domain_names_ctr, logbuffer,
2038                 EVENT_SIZE /* event */ +
2039                 BYTE_SIZE /* type */ +
2040                 LEB128_SIZE /* domain id */ +
2041                 nlen /* name */
2042         );
2043
2044         emit_event (logbuffer, TYPE_METADATA);
2045         emit_byte (logbuffer, TYPE_DOMAIN);
2046         emit_ptr (logbuffer, (void*)(uintptr_t) mono_domain_get_id (domain));
2047         memcpy (logbuffer->cursor, name, nlen);
2048         logbuffer->cursor += nlen;
2049
2050         EXIT_LOG;
2051 }
2052
2053 static void
2054 context_loaded (MonoProfiler *prof, MonoAppContext *context)
2055 {
2056         ENTER_LOG (&context_loads_ctr, logbuffer,
2057                 EVENT_SIZE /* event */ +
2058                 BYTE_SIZE /* type */ +
2059                 LEB128_SIZE /* context id */ +
2060                 LEB128_SIZE /* domain id */
2061         );
2062
2063         emit_event (logbuffer, TYPE_END_LOAD | TYPE_METADATA);
2064         emit_byte (logbuffer, TYPE_CONTEXT);
2065         emit_ptr (logbuffer, (void*)(uintptr_t) mono_context_get_id (context));
2066         emit_ptr (logbuffer, (void*)(uintptr_t) mono_context_get_domain_id (context));
2067
2068         EXIT_LOG;
2069 }
2070
2071 static void
2072 context_unloaded (MonoProfiler *prof, MonoAppContext *context)
2073 {
2074         ENTER_LOG (&context_unloads_ctr, logbuffer,
2075                 EVENT_SIZE /* event */ +
2076                 BYTE_SIZE /* type */ +
2077                 LEB128_SIZE /* context id */ +
2078                 LEB128_SIZE /* domain id */
2079         );
2080
2081         emit_event (logbuffer, TYPE_END_UNLOAD | TYPE_METADATA);
2082         emit_byte (logbuffer, TYPE_CONTEXT);
2083         emit_ptr (logbuffer, (void*)(uintptr_t) mono_context_get_id (context));
2084         emit_ptr (logbuffer, (void*)(uintptr_t) mono_context_get_domain_id (context));
2085
2086         EXIT_LOG;
2087 }
2088
2089 typedef struct {
2090         MonoMethod *method;
2091         MonoDomain *domain;
2092         void *base_address;
2093         int offset;
2094 } AsyncFrameInfo;
2095
2096 typedef struct {
2097         MonoLockFreeQueueNode node;
2098         uint64_t time;
2099         uintptr_t tid;
2100         const void *ip;
2101         int count;
2102         AsyncFrameInfo frames [MONO_ZERO_LEN_ARRAY];
2103 } SampleHit;
2104
2105 static mono_bool
2106 async_walk_stack (MonoMethod *method, MonoDomain *domain, void *base_address, int offset, void *data)
2107 {
2108         SampleHit *sample = (SampleHit *) data;
2109
2110         if (sample->count < log_config.num_frames) {
2111                 int i = sample->count;
2112
2113                 sample->frames [i].method = method;
2114                 sample->frames [i].domain = domain;
2115                 sample->frames [i].base_address = base_address;
2116                 sample->frames [i].offset = offset;
2117
2118                 sample->count++;
2119         }
2120
2121         return sample->count == log_config.num_frames;
2122 }
2123
2124 #define SAMPLE_SLOT_SIZE(FRAMES) (sizeof (SampleHit) + sizeof (AsyncFrameInfo) * (FRAMES - MONO_ZERO_LEN_ARRAY))
2125 #define SAMPLE_BLOCK_SIZE (mono_pagesize ())
2126
2127 static void
2128 enqueue_sample_hit (gpointer p)
2129 {
2130         SampleHit *sample = p;
2131
2132         mono_lock_free_queue_node_unpoison (&sample->node);
2133         mono_lock_free_queue_enqueue (&log_profiler.dumper_queue, &sample->node);
2134         mono_os_sem_post (&log_profiler.dumper_queue_sem);
2135 }
2136
2137 static void
2138 mono_sample_hit (MonoProfiler *profiler, const mono_byte *ip, const void *context)
2139 {
2140         /*
2141          * Please note: We rely on the runtime loading the profiler with
2142          * MONO_DL_EAGER (RTLD_NOW) so that references to runtime functions within
2143          * this function (and its siblings) are resolved when the profiler is
2144          * loaded. Otherwise, we would potentially invoke the dynamic linker when
2145          * invoking runtime functions, which is not async-signal-safe.
2146          */
2147
2148         if (InterlockedRead (&log_profiler.in_shutdown))
2149                 return;
2150
2151         SampleHit *sample = (SampleHit *) mono_lock_free_queue_dequeue (&profiler->sample_reuse_queue);
2152
2153         if (!sample) {
2154                 /*
2155                  * If we're out of reusable sample events and we're not allowed to
2156                  * allocate more, we have no choice but to drop the event.
2157                  */
2158                 if (InterlockedRead (&sample_allocations_ctr) >= log_config.max_allocated_sample_hits)
2159                         return;
2160
2161                 sample = mono_lock_free_alloc (&profiler->sample_allocator);
2162                 mono_lock_free_queue_node_init (&sample->node, TRUE);
2163
2164                 InterlockedIncrement (&sample_allocations_ctr);
2165         }
2166
2167         sample->count = 0;
2168         mono_stack_walk_async_safe (&async_walk_stack, (void *) context, sample);
2169
2170         sample->time = current_time ();
2171         sample->tid = thread_id ();
2172         sample->ip = ip;
2173
2174         mono_thread_hazardous_try_free (sample, enqueue_sample_hit);
2175 }
2176
2177 static uintptr_t *code_pages = 0;
2178 static int num_code_pages = 0;
2179 static int size_code_pages = 0;
2180 #define CPAGE_SHIFT (9)
2181 #define CPAGE_SIZE (1 << CPAGE_SHIFT)
2182 #define CPAGE_MASK (~(CPAGE_SIZE - 1))
2183 #define CPAGE_ADDR(p) ((p) & CPAGE_MASK)
2184
2185 static uintptr_t
2186 add_code_page (uintptr_t *hash, uintptr_t hsize, uintptr_t page)
2187 {
2188         uintptr_t i;
2189         uintptr_t start_pos;
2190         start_pos = (page >> CPAGE_SHIFT) % hsize;
2191         i = start_pos;
2192         do {
2193                 if (hash [i] && CPAGE_ADDR (hash [i]) == CPAGE_ADDR (page)) {
2194                         return 0;
2195                 } else if (!hash [i]) {
2196                         hash [i] = page;
2197                         return 1;
2198                 }
2199                 /* wrap around */
2200                 if (++i == hsize)
2201                         i = 0;
2202         } while (i != start_pos);
2203         g_assert_not_reached ();
2204         return 0;
2205 }
2206
2207 static void
2208 add_code_pointer (uintptr_t ip)
2209 {
2210         uintptr_t i;
2211         if (num_code_pages * 2 >= size_code_pages) {
2212                 uintptr_t *n;
2213                 uintptr_t old_size = size_code_pages;
2214                 size_code_pages *= 2;
2215                 if (size_code_pages == 0)
2216                         size_code_pages = 16;
2217                 n = (uintptr_t *) g_calloc (sizeof (uintptr_t) * size_code_pages, 1);
2218                 for (i = 0; i < old_size; ++i) {
2219                         if (code_pages [i])
2220                                 add_code_page (n, size_code_pages, code_pages [i]);
2221                 }
2222                 if (code_pages)
2223                         g_free (code_pages);
2224                 code_pages = n;
2225         }
2226         num_code_pages += add_code_page (code_pages, size_code_pages, ip & CPAGE_MASK);
2227 }
2228
2229 /* ELF code crashes on some systems. */
2230 //#if defined(HAVE_DL_ITERATE_PHDR) && defined(ELFMAG0)
2231 #if 0
2232 static void
2233 dump_ubin (const char *filename, uintptr_t load_addr, uint64_t offset, uintptr_t size)
2234 {
2235         int len = strlen (filename) + 1;
2236
2237         ENTER_LOG (&sample_ubins_ctr, logbuffer,
2238                 EVENT_SIZE /* event */ +
2239                 LEB128_SIZE /* load address */ +
2240                 LEB128_SIZE /* offset */ +
2241                 LEB128_SIZE /* size */ +
2242                 nlen /* file name */
2243         );
2244
2245         emit_event (logbuffer, TYPE_SAMPLE | TYPE_SAMPLE_UBIN);
2246         emit_ptr (logbuffer, load_addr);
2247         emit_uvalue (logbuffer, offset);
2248         emit_uvalue (logbuffer, size);
2249         memcpy (logbuffer->cursor, filename, len);
2250         logbuffer->cursor += len;
2251
2252         EXIT_LOG;
2253 }
2254 #endif
2255
2256 static void
2257 dump_usym (const char *name, uintptr_t value, uintptr_t size)
2258 {
2259         int len = strlen (name) + 1;
2260
2261         ENTER_LOG (&sample_usyms_ctr, logbuffer,
2262                 EVENT_SIZE /* event */ +
2263                 LEB128_SIZE /* value */ +
2264                 LEB128_SIZE /* size */ +
2265                 len /* name */
2266         );
2267
2268         emit_event (logbuffer, TYPE_SAMPLE | TYPE_SAMPLE_USYM);
2269         emit_ptr (logbuffer, (void*)value);
2270         emit_value (logbuffer, size);
2271         memcpy (logbuffer->cursor, name, len);
2272         logbuffer->cursor += len;
2273
2274         EXIT_LOG;
2275 }
2276
2277 /* ELF code crashes on some systems. */
2278 //#if defined(ELFMAG0)
2279 #if 0
2280
2281 #if SIZEOF_VOID_P == 4
2282 #define ELF_WSIZE 32
2283 #else
2284 #define ELF_WSIZE 64
2285 #endif
2286 #ifndef ElfW
2287 #define ElfW(type)      _ElfW (Elf, ELF_WSIZE, type)
2288 #define _ElfW(e,w,t)    _ElfW_1 (e, w, _##t)
2289 #define _ElfW_1(e,w,t)  e##w##t
2290 #endif
2291
2292 static void
2293 dump_elf_symbols (ElfW(Sym) *symbols, int num_symbols, const char *strtab, void *load_addr)
2294 {
2295         int i;
2296         for (i = 0; i < num_symbols; ++i) {
2297                 const char* sym;
2298                 sym =  strtab + symbols [i].st_name;
2299                 if (!symbols [i].st_name || !symbols [i].st_size || (symbols [i].st_info & 0xf) != STT_FUNC)
2300                         continue;
2301                 dump_usym (sym, (uintptr_t)load_addr + symbols [i].st_value, symbols [i].st_size);
2302         }
2303 }
2304
2305 static int
2306 read_elf_symbols (MonoProfiler *prof, const char *filename, void *load_addr)
2307 {
2308         int fd, i;
2309         void *data;
2310         struct stat statb;
2311         uint64_t file_size;
2312         ElfW(Ehdr) *header;
2313         ElfW(Shdr) *sheader;
2314         ElfW(Shdr) *shstrtabh;
2315         ElfW(Shdr) *symtabh = NULL;
2316         ElfW(Shdr) *strtabh = NULL;
2317         ElfW(Sym) *symbols = NULL;
2318         const char *strtab;
2319         int num_symbols;
2320
2321         fd = open (filename, O_RDONLY);
2322         if (fd < 0)
2323                 return 0;
2324         if (fstat (fd, &statb) != 0) {
2325                 close (fd);
2326                 return 0;
2327         }
2328         file_size = statb.st_size;
2329         data = mmap (NULL, file_size, PROT_READ, MAP_PRIVATE, fd, 0);
2330         close (fd);
2331         if (data == MAP_FAILED)
2332                 return 0;
2333         header = data;
2334         if (header->e_ident [EI_MAG0] != ELFMAG0 ||
2335                         header->e_ident [EI_MAG1] != ELFMAG1 ||
2336                         header->e_ident [EI_MAG2] != ELFMAG2 ||
2337                         header->e_ident [EI_MAG3] != ELFMAG3 ) {
2338                 munmap (data, file_size);
2339                 return 0;
2340         }
2341         sheader = (void*)((char*)data + header->e_shoff);
2342         shstrtabh = (void*)((char*)sheader + (header->e_shentsize * header->e_shstrndx));
2343         strtab = (const char*)data + shstrtabh->sh_offset;
2344         for (i = 0; i < header->e_shnum; ++i) {
2345                 if (sheader->sh_type == SHT_SYMTAB) {
2346                         symtabh = sheader;
2347                         strtabh = (void*)((char*)data + header->e_shoff + sheader->sh_link * header->e_shentsize);
2348                         break;
2349                 }
2350                 sheader = (void*)((char*)sheader + header->e_shentsize);
2351         }
2352         if (!symtabh || !strtabh) {
2353                 munmap (data, file_size);
2354                 return 0;
2355         }
2356         strtab = (const char*)data + strtabh->sh_offset;
2357         num_symbols = symtabh->sh_size / symtabh->sh_entsize;
2358         symbols = (void*)((char*)data + symtabh->sh_offset);
2359         dump_elf_symbols (symbols, num_symbols, strtab, load_addr);
2360         munmap (data, file_size);
2361         return 1;
2362 }
2363 #endif
2364
2365 /* ELF code crashes on some systems. */
2366 //#if defined(HAVE_DL_ITERATE_PHDR) && defined(ELFMAG0)
2367 #if 0
2368 static int
2369 elf_dl_callback (struct dl_phdr_info *info, size_t size, void *data)
2370 {
2371         char buf [256];
2372         const char *filename;
2373         BinaryObject *obj;
2374         char *a = (void*)info->dlpi_addr;
2375         int i, num_sym;
2376         ElfW(Dyn) *dyn = NULL;
2377         ElfW(Sym) *symtab = NULL;
2378         ElfW(Word) *hash_table = NULL;
2379         ElfW(Ehdr) *header = NULL;
2380         const char* strtab = NULL;
2381         for (obj = log_profiler.binary_objects; obj; obj = obj->next) {
2382                 if (obj->addr == a)
2383                         return 0;
2384         }
2385         filename = info->dlpi_name;
2386         if (!filename)
2387                 return 0;
2388         if (!info->dlpi_addr && !filename [0]) {
2389                 int l = readlink ("/proc/self/exe", buf, sizeof (buf) - 1);
2390                 if (l > 0) {
2391                         buf [l] = 0;
2392                         filename = buf;
2393                 }
2394         }
2395         obj = g_calloc (sizeof (BinaryObject), 1);
2396         obj->addr = (void*)info->dlpi_addr;
2397         obj->name = pstrdup (filename);
2398         obj->next = log_profiler.binary_objects;
2399         log_profiler.binary_objects = obj;
2400         a = NULL;
2401         for (i = 0; i < info->dlpi_phnum; ++i) {
2402                 if (info->dlpi_phdr[i].p_type == PT_LOAD && !header) {
2403                         header = (ElfW(Ehdr)*)(info->dlpi_addr + info->dlpi_phdr[i].p_vaddr);
2404                         if (header->e_ident [EI_MAG0] != ELFMAG0 ||
2405                                         header->e_ident [EI_MAG1] != ELFMAG1 ||
2406                                         header->e_ident [EI_MAG2] != ELFMAG2 ||
2407                                         header->e_ident [EI_MAG3] != ELFMAG3 ) {
2408                                 header = NULL;
2409                         }
2410                         dump_ubin (filename, info->dlpi_addr + info->dlpi_phdr[i].p_vaddr, info->dlpi_phdr[i].p_offset, info->dlpi_phdr[i].p_memsz);
2411                 } else if (info->dlpi_phdr[i].p_type == PT_DYNAMIC) {
2412                         dyn = (ElfW(Dyn) *)(info->dlpi_addr + info->dlpi_phdr[i].p_vaddr);
2413                 }
2414         }
2415         if (read_elf_symbols (filename, (void*)info->dlpi_addr))
2416                 return 0;
2417         if (!info->dlpi_name || !info->dlpi_name[0])
2418                 return 0;
2419         if (!dyn)
2420                 return 0;
2421         for (i = 0; dyn [i].d_tag != DT_NULL; ++i) {
2422                 if (dyn [i].d_tag == DT_SYMTAB) {
2423                         symtab = (ElfW(Sym) *)(a + dyn [i].d_un.d_ptr);
2424                 } else if (dyn [i].d_tag == DT_HASH) {
2425                         hash_table = (ElfW(Word) *)(a + dyn [i].d_un.d_ptr);
2426                 } else if (dyn [i].d_tag == DT_STRTAB) {
2427                         strtab = (const char*)(a + dyn [i].d_un.d_ptr);
2428                 }
2429         }
2430         if (!hash_table)
2431                 return 0;
2432         num_sym = hash_table [1];
2433         dump_elf_symbols (symtab, num_sym, strtab, (void*)info->dlpi_addr);
2434         return 0;
2435 }
2436
2437 static int
2438 load_binaries (void)
2439 {
2440         dl_iterate_phdr (elf_dl_callback, NULL);
2441         return 1;
2442 }
2443 #else
2444 static int
2445 load_binaries (void)
2446 {
2447         return 0;
2448 }
2449 #endif
2450
2451 static const char*
2452 symbol_for (uintptr_t code)
2453 {
2454 #ifdef HAVE_DLADDR
2455         void *ip = (void*)code;
2456         Dl_info di;
2457         if (dladdr (ip, &di)) {
2458                 if (di.dli_sname)
2459                         return di.dli_sname;
2460         } else {
2461         /*      char **names;
2462                 names = backtrace_symbols (&ip, 1);
2463                 if (names) {
2464                         const char* p = names [0];
2465                         g_free (names);
2466                         return p;
2467                 }
2468                 */
2469         }
2470 #endif
2471         return NULL;
2472 }
2473
2474 static void
2475 dump_unmanaged_coderefs (void)
2476 {
2477         int i;
2478         const char* last_symbol;
2479         uintptr_t addr, page_end;
2480
2481         if (load_binaries ())
2482                 return;
2483         for (i = 0; i < size_code_pages; ++i) {
2484                 const char* sym;
2485                 if (!code_pages [i] || code_pages [i] & 1)
2486                         continue;
2487                 last_symbol = NULL;
2488                 addr = CPAGE_ADDR (code_pages [i]);
2489                 page_end = addr + CPAGE_SIZE;
2490                 code_pages [i] |= 1;
2491                 /* we dump the symbols for the whole page */
2492                 for (; addr < page_end; addr += 16) {
2493                         sym = symbol_for (addr);
2494                         if (sym && sym == last_symbol)
2495                                 continue;
2496                         last_symbol = sym;
2497                         if (!sym)
2498                                 continue;
2499                         dump_usym (sym, addr, 0); /* let's not guess the size */
2500                 }
2501         }
2502 }
2503
2504 static void
2505 counters_add_agent (MonoCounter *counter)
2506 {
2507         if (InterlockedRead (&log_profiler.in_shutdown))
2508                 return;
2509
2510         MonoCounterAgent *agent, *item;
2511
2512         mono_os_mutex_lock (&log_profiler.counters_mutex);
2513
2514         for (agent = log_profiler.counters; agent; agent = agent->next) {
2515                 if (agent->counter == counter) {
2516                         agent->value_size = 0;
2517                         if (agent->value) {
2518                                 g_free (agent->value);
2519                                 agent->value = NULL;
2520                         }
2521                         goto done;
2522                 }
2523         }
2524
2525         agent = (MonoCounterAgent *) g_malloc (sizeof (MonoCounterAgent));
2526         agent->counter = counter;
2527         agent->value = NULL;
2528         agent->value_size = 0;
2529         agent->index = log_profiler.counters_index++;
2530         agent->emitted = FALSE;
2531         agent->next = NULL;
2532
2533         if (!log_profiler.counters) {
2534                 log_profiler.counters = agent;
2535         } else {
2536                 item = log_profiler.counters;
2537                 while (item->next)
2538                         item = item->next;
2539                 item->next = agent;
2540         }
2541
2542 done:
2543         mono_os_mutex_unlock (&log_profiler.counters_mutex);
2544 }
2545
2546 static mono_bool
2547 counters_init_foreach_callback (MonoCounter *counter, gpointer data)
2548 {
2549         counters_add_agent (counter);
2550         return TRUE;
2551 }
2552
2553 static void
2554 counters_init (void)
2555 {
2556         mono_os_mutex_init (&log_profiler.counters_mutex);
2557
2558         log_profiler.counters_index = 1;
2559
2560         mono_counters_on_register (&counters_add_agent);
2561         mono_counters_foreach (counters_init_foreach_callback, NULL);
2562 }
2563
2564 static void
2565 counters_emit (void)
2566 {
2567         MonoCounterAgent *agent;
2568         int len = 0;
2569         int size =
2570                 EVENT_SIZE /* event */ +
2571                 LEB128_SIZE /* len */
2572         ;
2573
2574         mono_os_mutex_lock (&log_profiler.counters_mutex);
2575
2576         for (agent = log_profiler.counters; agent; agent = agent->next) {
2577                 if (agent->emitted)
2578                         continue;
2579
2580                 size +=
2581                         LEB128_SIZE /* section */ +
2582                         strlen (mono_counter_get_name (agent->counter)) + 1 /* name */ +
2583                         BYTE_SIZE /* type */ +
2584                         BYTE_SIZE /* unit */ +
2585                         BYTE_SIZE /* variance */ +
2586                         LEB128_SIZE /* index */
2587                 ;
2588
2589                 len++;
2590         }
2591
2592         if (!len)
2593                 goto done;
2594
2595         ENTER_LOG (&counter_descriptors_ctr, logbuffer, size);
2596
2597         emit_event (logbuffer, TYPE_SAMPLE_COUNTERS_DESC | TYPE_SAMPLE);
2598         emit_value (logbuffer, len);
2599
2600         for (agent = log_profiler.counters; agent; agent = agent->next) {
2601                 const char *name;
2602
2603                 if (agent->emitted)
2604                         continue;
2605
2606                 name = mono_counter_get_name (agent->counter);
2607                 emit_value (logbuffer, mono_counter_get_section (agent->counter));
2608                 emit_string (logbuffer, name, strlen (name) + 1);
2609                 emit_byte (logbuffer, mono_counter_get_type (agent->counter));
2610                 emit_byte (logbuffer, mono_counter_get_unit (agent->counter));
2611                 emit_byte (logbuffer, mono_counter_get_variance (agent->counter));
2612                 emit_value (logbuffer, agent->index);
2613
2614                 agent->emitted = TRUE;
2615         }
2616
2617         EXIT_LOG;
2618
2619 done:
2620         mono_os_mutex_unlock (&log_profiler.counters_mutex);
2621 }
2622
2623 static void
2624 counters_sample (uint64_t timestamp)
2625 {
2626         MonoCounterAgent *agent;
2627         MonoCounter *counter;
2628         int type;
2629         int buffer_size;
2630         void *buffer;
2631         int size;
2632
2633         counters_emit ();
2634
2635         buffer_size = 8;
2636         buffer = g_calloc (1, buffer_size);
2637
2638         mono_os_mutex_lock (&log_profiler.counters_mutex);
2639
2640         size =
2641                 EVENT_SIZE /* event */
2642         ;
2643
2644         for (agent = log_profiler.counters; agent; agent = agent->next) {
2645                 size +=
2646                         LEB128_SIZE /* index */ +
2647                         BYTE_SIZE /* type */ +
2648                         mono_counter_get_size (agent->counter) /* value */
2649                 ;
2650         }
2651
2652         size +=
2653                 LEB128_SIZE /* stop marker */
2654         ;
2655
2656         ENTER_LOG (&counter_samples_ctr, logbuffer, size);
2657
2658         emit_event_time (logbuffer, TYPE_SAMPLE_COUNTERS | TYPE_SAMPLE, timestamp);
2659
2660         for (agent = log_profiler.counters; agent; agent = agent->next) {
2661                 size_t size;
2662
2663                 counter = agent->counter;
2664
2665                 size = mono_counter_get_size (counter);
2666
2667                 if (size > buffer_size) {
2668                         buffer_size = size;
2669                         buffer = g_realloc (buffer, buffer_size);
2670                 }
2671
2672                 memset (buffer, 0, buffer_size);
2673
2674                 g_assert (mono_counters_sample (counter, buffer, size));
2675
2676                 type = mono_counter_get_type (counter);
2677
2678                 if (!agent->value) {
2679                         agent->value = g_calloc (1, size);
2680                         agent->value_size = size;
2681                 } else {
2682                         if (type == MONO_COUNTER_STRING) {
2683                                 if (strcmp (agent->value, buffer) == 0)
2684                                         continue;
2685                         } else {
2686                                 if (agent->value_size == size && memcmp (agent->value, buffer, size) == 0)
2687                                         continue;
2688                         }
2689                 }
2690
2691                 emit_uvalue (logbuffer, agent->index);
2692                 emit_byte (logbuffer, type);
2693                 switch (type) {
2694                 case MONO_COUNTER_INT:
2695 #if SIZEOF_VOID_P == 4
2696                 case MONO_COUNTER_WORD:
2697 #endif
2698                         emit_svalue (logbuffer, *(int*)buffer - *(int*)agent->value);
2699                         break;
2700                 case MONO_COUNTER_UINT:
2701                         emit_uvalue (logbuffer, *(guint*)buffer - *(guint*)agent->value);
2702                         break;
2703                 case MONO_COUNTER_TIME_INTERVAL:
2704                 case MONO_COUNTER_LONG:
2705 #if SIZEOF_VOID_P == 8
2706                 case MONO_COUNTER_WORD:
2707 #endif
2708                         emit_svalue (logbuffer, *(gint64*)buffer - *(gint64*)agent->value);
2709                         break;
2710                 case MONO_COUNTER_ULONG:
2711                         emit_uvalue (logbuffer, *(guint64*)buffer - *(guint64*)agent->value);
2712                         break;
2713                 case MONO_COUNTER_DOUBLE:
2714                         emit_double (logbuffer, *(double*)buffer);
2715                         break;
2716                 case MONO_COUNTER_STRING:
2717                         if (size == 0) {
2718                                 emit_byte (logbuffer, 0);
2719                         } else {
2720                                 emit_byte (logbuffer, 1);
2721                                 emit_string (logbuffer, (char*)buffer, size);
2722                         }
2723                         break;
2724                 default:
2725                         g_assert_not_reached ();
2726                 }
2727
2728                 if (type == MONO_COUNTER_STRING && size > agent->value_size) {
2729                         agent->value = g_realloc (agent->value, size);
2730                         agent->value_size = size;
2731                 }
2732
2733                 if (size > 0)
2734                         memcpy (agent->value, buffer, size);
2735         }
2736         g_free (buffer);
2737
2738         emit_value (logbuffer, 0);
2739
2740         EXIT_LOG;
2741
2742         mono_os_mutex_unlock (&log_profiler.counters_mutex);
2743 }
2744
2745 static void
2746 perfcounters_emit (void)
2747 {
2748         PerfCounterAgent *pcagent;
2749         int len = 0;
2750         int size =
2751                 EVENT_SIZE /* event */ +
2752                 LEB128_SIZE /* len */
2753         ;
2754
2755         for (pcagent = log_profiler.perfcounters; pcagent; pcagent = pcagent->next) {
2756                 if (pcagent->emitted)
2757                         continue;
2758
2759                 size +=
2760                         LEB128_SIZE /* section */ +
2761                         strlen (pcagent->category_name) + 1 /* category name */ +
2762                         strlen (pcagent->name) + 1 /* name */ +
2763                         BYTE_SIZE /* type */ +
2764                         BYTE_SIZE /* unit */ +
2765                         BYTE_SIZE /* variance */ +
2766                         LEB128_SIZE /* index */
2767                 ;
2768
2769                 len++;
2770         }
2771
2772         if (!len)
2773                 return;
2774
2775         ENTER_LOG (&perfcounter_descriptors_ctr, logbuffer, size);
2776
2777         emit_event (logbuffer, TYPE_SAMPLE_COUNTERS_DESC | TYPE_SAMPLE);
2778         emit_value (logbuffer, len);
2779
2780         for (pcagent = log_profiler.perfcounters; pcagent; pcagent = pcagent->next) {
2781                 if (pcagent->emitted)
2782                         continue;
2783
2784                 emit_value (logbuffer, MONO_COUNTER_PERFCOUNTERS);
2785                 emit_string (logbuffer, pcagent->category_name, strlen (pcagent->category_name) + 1);
2786                 emit_string (logbuffer, pcagent->name, strlen (pcagent->name) + 1);
2787                 emit_byte (logbuffer, MONO_COUNTER_LONG);
2788                 emit_byte (logbuffer, MONO_COUNTER_RAW);
2789                 emit_byte (logbuffer, MONO_COUNTER_VARIABLE);
2790                 emit_value (logbuffer, pcagent->index);
2791
2792                 pcagent->emitted = TRUE;
2793         }
2794
2795         EXIT_LOG;
2796 }
2797
2798 static gboolean
2799 perfcounters_foreach (char *category_name, char *name, unsigned char type, gint64 value, gpointer user_data)
2800 {
2801         PerfCounterAgent *pcagent;
2802
2803         for (pcagent = log_profiler.perfcounters; pcagent; pcagent = pcagent->next) {
2804                 if (strcmp (pcagent->category_name, category_name) != 0 || strcmp (pcagent->name, name) != 0)
2805                         continue;
2806                 if (pcagent->value == value)
2807                         return TRUE;
2808
2809                 pcagent->value = value;
2810                 pcagent->updated = TRUE;
2811                 pcagent->deleted = FALSE;
2812                 return TRUE;
2813         }
2814
2815         pcagent = g_new0 (PerfCounterAgent, 1);
2816         pcagent->next = log_profiler.perfcounters;
2817         pcagent->index = log_profiler.counters_index++;
2818         pcagent->category_name = g_strdup (category_name);
2819         pcagent->name = g_strdup (name);
2820         pcagent->value = value;
2821         pcagent->emitted = FALSE;
2822         pcagent->updated = TRUE;
2823         pcagent->deleted = FALSE;
2824
2825         log_profiler.perfcounters = pcagent;
2826
2827         return TRUE;
2828 }
2829
2830 static void
2831 perfcounters_sample (uint64_t timestamp)
2832 {
2833         PerfCounterAgent *pcagent;
2834         int len = 0;
2835         int size;
2836
2837         mono_os_mutex_lock (&log_profiler.counters_mutex);
2838
2839         /* mark all perfcounters as deleted, foreach will unmark them as necessary */
2840         for (pcagent = log_profiler.perfcounters; pcagent; pcagent = pcagent->next)
2841                 pcagent->deleted = TRUE;
2842
2843         mono_perfcounter_foreach (perfcounters_foreach, NULL);
2844
2845         perfcounters_emit ();
2846
2847         size =
2848                 EVENT_SIZE /* event */
2849         ;
2850
2851         for (pcagent = log_profiler.perfcounters; pcagent; pcagent = pcagent->next) {
2852                 if (pcagent->deleted || !pcagent->updated)
2853                         continue;
2854
2855                 size +=
2856                         LEB128_SIZE /* index */ +
2857                         BYTE_SIZE /* type */ +
2858                         LEB128_SIZE /* value */
2859                 ;
2860
2861                 len++;
2862         }
2863
2864         if (!len)
2865                 goto done;
2866
2867         size +=
2868                 LEB128_SIZE /* stop marker */
2869         ;
2870
2871         ENTER_LOG (&perfcounter_samples_ctr, logbuffer, size);
2872
2873         emit_event_time (logbuffer, TYPE_SAMPLE_COUNTERS | TYPE_SAMPLE, timestamp);
2874
2875         for (pcagent = log_profiler.perfcounters; pcagent; pcagent = pcagent->next) {
2876                 if (pcagent->deleted || !pcagent->updated)
2877                         continue;
2878                 emit_uvalue (logbuffer, pcagent->index);
2879                 emit_byte (logbuffer, MONO_COUNTER_LONG);
2880                 emit_svalue (logbuffer, pcagent->value);
2881
2882                 pcagent->updated = FALSE;
2883         }
2884
2885         emit_value (logbuffer, 0);
2886
2887         EXIT_LOG;
2888
2889 done:
2890         mono_os_mutex_unlock (&log_profiler.counters_mutex);
2891 }
2892
2893 static void
2894 counters_and_perfcounters_sample (void)
2895 {
2896         uint64_t now = current_time ();
2897
2898         counters_sample (now);
2899         perfcounters_sample (now);
2900 }
2901
2902 typedef struct {
2903         MonoLockFreeQueueNode node;
2904         MonoMethod *method;
2905 } MethodNode;
2906
2907 typedef struct {
2908         int offset;
2909         int counter;
2910         char *filename;
2911         int line;
2912         int column;
2913 } CoverageEntry;
2914
2915 static void
2916 free_coverage_entry (gpointer data, gpointer userdata)
2917 {
2918         CoverageEntry *entry = (CoverageEntry *)data;
2919         g_free (entry->filename);
2920         g_free (entry);
2921 }
2922
2923 static void
2924 obtain_coverage_for_method (MonoProfiler *prof, const MonoProfilerCoverageData *entry)
2925 {
2926         int offset = entry->il_offset - log_profiler.coverage_previous_offset;
2927         CoverageEntry *e = g_new (CoverageEntry, 1);
2928
2929         log_profiler.coverage_previous_offset = entry->il_offset;
2930
2931         e->offset = offset;
2932         e->counter = entry->counter;
2933         e->filename = g_strdup(entry->file_name ? entry->file_name : "");
2934         e->line = entry->line;
2935         e->column = entry->column;
2936
2937         g_ptr_array_add (log_profiler.coverage_data, e);
2938 }
2939
2940 static char *
2941 parse_generic_type_names(char *name)
2942 {
2943         char *new_name, *ret;
2944         int within_generic_declaration = 0, generic_members = 1;
2945
2946         if (name == NULL || *name == '\0')
2947                 return g_strdup ("");
2948
2949         if (!(ret = new_name = (char *) g_calloc (strlen (name) * 4 + 1, sizeof (char))))
2950                 return NULL;
2951
2952         do {
2953                 switch (*name) {
2954                         case '<':
2955                                 within_generic_declaration = 1;
2956                                 break;
2957
2958                         case '>':
2959                                 within_generic_declaration = 0;
2960
2961                                 if (*(name - 1) != '<') {
2962                                         *new_name++ = '`';
2963                                         *new_name++ = '0' + generic_members;
2964                                 } else {
2965                                         memcpy (new_name, "&lt;&gt;", 8);
2966                                         new_name += 8;
2967                                 }
2968
2969                                 generic_members = 0;
2970                                 break;
2971
2972                         case ',':
2973                                 generic_members++;
2974                                 break;
2975
2976                         default:
2977                                 if (!within_generic_declaration)
2978                                         *new_name++ = *name;
2979
2980                                 break;
2981                 }
2982         } while (*name++);
2983
2984         return ret;
2985 }
2986
2987 static void
2988 build_method_buffer (gpointer key, gpointer value, gpointer userdata)
2989 {
2990         MonoMethod *method = (MonoMethod *)value;
2991         MonoClass *klass;
2992         MonoImage *image;
2993         char *class_name;
2994         const char *image_name, *method_name, *sig, *first_filename;
2995         guint i;
2996
2997         log_profiler.coverage_previous_offset = 0;
2998         log_profiler.coverage_data = g_ptr_array_new ();
2999
3000         mono_profiler_get_coverage_data (log_profiler.handle, method, obtain_coverage_for_method);
3001
3002         klass = mono_method_get_class (method);
3003         image = mono_class_get_image (klass);
3004         image_name = mono_image_get_name (image);
3005
3006         sig = mono_signature_get_desc (mono_method_signature (method), TRUE);
3007         class_name = parse_generic_type_names (mono_type_get_name (mono_class_get_type (klass)));
3008         method_name = mono_method_get_name (method);
3009
3010         if (log_profiler.coverage_data->len != 0) {
3011                 CoverageEntry *entry = (CoverageEntry *)log_profiler.coverage_data->pdata[0];
3012                 first_filename = entry->filename ? entry->filename : "";
3013         } else
3014                 first_filename = "";
3015
3016         image_name = image_name ? image_name : "";
3017         sig = sig ? sig : "";
3018         method_name = method_name ? method_name : "";
3019
3020         ENTER_LOG (&coverage_methods_ctr, logbuffer,
3021                 EVENT_SIZE /* event */ +
3022                 strlen (image_name) + 1 /* image name */ +
3023                 strlen (class_name) + 1 /* class name */ +
3024                 strlen (method_name) + 1 /* method name */ +
3025                 strlen (sig) + 1 /* signature */ +
3026                 strlen (first_filename) + 1 /* first file name */ +
3027                 LEB128_SIZE /* token */ +
3028                 LEB128_SIZE /* method id */ +
3029                 LEB128_SIZE /* entries */
3030         );
3031
3032         emit_event (logbuffer, TYPE_COVERAGE_METHOD | TYPE_COVERAGE);
3033         emit_string (logbuffer, image_name, strlen (image_name) + 1);
3034         emit_string (logbuffer, class_name, strlen (class_name) + 1);
3035         emit_string (logbuffer, method_name, strlen (method_name) + 1);
3036         emit_string (logbuffer, sig, strlen (sig) + 1);
3037         emit_string (logbuffer, first_filename, strlen (first_filename) + 1);
3038
3039         emit_uvalue (logbuffer, mono_method_get_token (method));
3040         emit_uvalue (logbuffer, log_profiler.coverage_method_id);
3041         emit_value (logbuffer, log_profiler.coverage_data->len);
3042
3043         EXIT_LOG;
3044
3045         for (i = 0; i < log_profiler.coverage_data->len; i++) {
3046                 CoverageEntry *entry = (CoverageEntry *)log_profiler.coverage_data->pdata[i];
3047
3048                 ENTER_LOG (&coverage_statements_ctr, logbuffer,
3049                         EVENT_SIZE /* event */ +
3050                         LEB128_SIZE /* method id */ +
3051                         LEB128_SIZE /* offset */ +
3052                         LEB128_SIZE /* counter */ +
3053                         LEB128_SIZE /* line */ +
3054                         LEB128_SIZE /* column */
3055                 );
3056
3057                 emit_event (logbuffer, TYPE_COVERAGE_STATEMENT | TYPE_COVERAGE);
3058                 emit_uvalue (logbuffer, log_profiler.coverage_method_id);
3059                 emit_uvalue (logbuffer, entry->offset);
3060                 emit_uvalue (logbuffer, entry->counter);
3061                 emit_uvalue (logbuffer, entry->line);
3062                 emit_uvalue (logbuffer, entry->column);
3063
3064                 EXIT_LOG;
3065         }
3066
3067         log_profiler.coverage_method_id++;
3068
3069         g_free (class_name);
3070
3071         g_ptr_array_foreach (log_profiler.coverage_data, free_coverage_entry, NULL);
3072         g_ptr_array_free (log_profiler.coverage_data, TRUE);
3073 }
3074
3075 /* This empties the queue */
3076 static guint
3077 count_queue (MonoLockFreeQueue *queue)
3078 {
3079         MonoLockFreeQueueNode *node;
3080         guint count = 0;
3081
3082         while ((node = mono_lock_free_queue_dequeue (queue))) {
3083                 count++;
3084                 mono_thread_hazardous_try_free (node, g_free);
3085         }
3086
3087         return count;
3088 }
3089
3090 static void
3091 build_class_buffer (gpointer key, gpointer value, gpointer userdata)
3092 {
3093         MonoClass *klass = (MonoClass *)key;
3094         MonoLockFreeQueue *class_methods = (MonoLockFreeQueue *)value;
3095         MonoImage *image;
3096         char *class_name;
3097         const char *assembly_name;
3098         int number_of_methods, partially_covered;
3099         guint fully_covered;
3100
3101         image = mono_class_get_image (klass);
3102         assembly_name = mono_image_get_name (image);
3103         class_name = mono_type_get_name (mono_class_get_type (klass));
3104
3105         assembly_name = assembly_name ? assembly_name : "";
3106         number_of_methods = mono_class_num_methods (klass);
3107         fully_covered = count_queue (class_methods);
3108         /* We don't handle partial covered yet */
3109         partially_covered = 0;
3110
3111         ENTER_LOG (&coverage_classes_ctr, logbuffer,
3112                 EVENT_SIZE /* event */ +
3113                 strlen (assembly_name) + 1 /* assembly name */ +
3114                 strlen (class_name) + 1 /* class name */ +
3115                 LEB128_SIZE /* no. methods */ +
3116                 LEB128_SIZE /* fully covered */ +
3117                 LEB128_SIZE /* partially covered */
3118         );
3119
3120         emit_event (logbuffer, TYPE_COVERAGE_CLASS | TYPE_COVERAGE);
3121         emit_string (logbuffer, assembly_name, strlen (assembly_name) + 1);
3122         emit_string (logbuffer, class_name, strlen (class_name) + 1);
3123         emit_uvalue (logbuffer, number_of_methods);
3124         emit_uvalue (logbuffer, fully_covered);
3125         emit_uvalue (logbuffer, partially_covered);
3126
3127         EXIT_LOG;
3128
3129         g_free (class_name);
3130 }
3131
3132 static void
3133 get_coverage_for_image (MonoImage *image, int *number_of_methods, guint *fully_covered, int *partially_covered)
3134 {
3135         MonoLockFreeQueue *image_methods = (MonoLockFreeQueue *)mono_conc_hashtable_lookup (log_profiler.coverage_image_to_methods, image);
3136
3137         *number_of_methods = mono_image_get_table_rows (image, MONO_TABLE_METHOD);
3138         if (image_methods)
3139                 *fully_covered = count_queue (image_methods);
3140         else
3141                 *fully_covered = 0;
3142
3143         // FIXME: We don't handle partially covered yet.
3144         *partially_covered = 0;
3145 }
3146
3147 static void
3148 build_assembly_buffer (gpointer key, gpointer value, gpointer userdata)
3149 {
3150         MonoAssembly *assembly = (MonoAssembly *)value;
3151         MonoImage *image = mono_assembly_get_image (assembly);
3152         const char *name, *guid, *filename;
3153         int number_of_methods = 0, partially_covered = 0;
3154         guint fully_covered = 0;
3155
3156         name = mono_image_get_name (image);
3157         guid = mono_image_get_guid (image);
3158         filename = mono_image_get_filename (image);
3159
3160         name = name ? name : "";
3161         guid = guid ? guid : "";
3162         filename = filename ? filename : "";
3163
3164         get_coverage_for_image (image, &number_of_methods, &fully_covered, &partially_covered);
3165
3166         ENTER_LOG (&coverage_assemblies_ctr, logbuffer,
3167                 EVENT_SIZE /* event */ +
3168                 strlen (name) + 1 /* name */ +
3169                 strlen (guid) + 1 /* guid */ +
3170                 strlen (filename) + 1 /* file name */ +
3171                 LEB128_SIZE /* no. methods */ +
3172                 LEB128_SIZE /* fully covered */ +
3173                 LEB128_SIZE /* partially covered */
3174         );
3175
3176         emit_event (logbuffer, TYPE_COVERAGE_ASSEMBLY | TYPE_COVERAGE);
3177         emit_string (logbuffer, name, strlen (name) + 1);
3178         emit_string (logbuffer, guid, strlen (guid) + 1);
3179         emit_string (logbuffer, filename, strlen (filename) + 1);
3180         emit_uvalue (logbuffer, number_of_methods);
3181         emit_uvalue (logbuffer, fully_covered);
3182         emit_uvalue (logbuffer, partially_covered);
3183
3184         EXIT_LOG;
3185 }
3186
3187 static void
3188 dump_coverage (void)
3189 {
3190         mono_os_mutex_lock (&log_profiler.coverage_mutex);
3191         mono_conc_hashtable_foreach (log_profiler.coverage_assemblies, build_assembly_buffer, NULL);
3192         mono_conc_hashtable_foreach (log_profiler.coverage_classes, build_class_buffer, NULL);
3193         mono_conc_hashtable_foreach (log_profiler.coverage_methods, build_method_buffer, NULL);
3194         mono_os_mutex_unlock (&log_profiler.coverage_mutex);
3195 }
3196
3197 static MonoLockFreeQueueNode *
3198 create_method_node (MonoMethod *method)
3199 {
3200         MethodNode *node = (MethodNode *) g_malloc (sizeof (MethodNode));
3201         mono_lock_free_queue_node_init ((MonoLockFreeQueueNode *) node, FALSE);
3202         node->method = method;
3203
3204         return (MonoLockFreeQueueNode *) node;
3205 }
3206
3207 static gboolean
3208 coverage_filter (MonoProfiler *prof, MonoMethod *method)
3209 {
3210         MonoError error;
3211         MonoClass *klass;
3212         MonoImage *image;
3213         MonoAssembly *assembly;
3214         MonoMethodHeader *header;
3215         guint32 iflags, flags, code_size;
3216         char *fqn, *classname;
3217         gboolean has_positive, found;
3218         MonoLockFreeQueue *image_methods, *class_methods;
3219         MonoLockFreeQueueNode *node;
3220
3221         flags = mono_method_get_flags (method, &iflags);
3222         if ((iflags & METHOD_IMPL_ATTRIBUTE_INTERNAL_CALL) ||
3223             (flags & METHOD_ATTRIBUTE_PINVOKE_IMPL))
3224                 return FALSE;
3225
3226         // Don't need to do anything else if we're already tracking this method
3227         if (mono_conc_hashtable_lookup (log_profiler.coverage_methods, method))
3228                 return TRUE;
3229
3230         klass = mono_method_get_class (method);
3231         image = mono_class_get_image (klass);
3232
3233         // Don't handle coverage for the core assemblies
3234         if (mono_conc_hashtable_lookup (log_profiler.coverage_suppressed_assemblies, (gpointer) mono_image_get_name (image)) != NULL)
3235                 return FALSE;
3236
3237         if (prof->coverage_filters) {
3238                 /* Check already filtered classes first */
3239                 if (mono_conc_hashtable_lookup (log_profiler.coverage_filtered_classes, klass))
3240                         return FALSE;
3241
3242                 classname = mono_type_get_name (mono_class_get_type (klass));
3243
3244                 fqn = g_strdup_printf ("[%s]%s", mono_image_get_name (image), classname);
3245
3246                 // Check positive filters first
3247                 has_positive = FALSE;
3248                 found = FALSE;
3249                 for (guint i = 0; i < prof->coverage_filters->len; ++i) {
3250                         char *filter = (char *)g_ptr_array_index (prof->coverage_filters, i);
3251
3252                         if (filter [0] == '+') {
3253                                 filter = &filter [1];
3254
3255                                 if (strstr (fqn, filter) != NULL)
3256                                         found = TRUE;
3257
3258                                 has_positive = TRUE;
3259                         }
3260                 }
3261
3262                 if (has_positive && !found) {
3263                         mono_os_mutex_lock (&log_profiler.coverage_mutex);
3264                         mono_conc_hashtable_insert (log_profiler.coverage_filtered_classes, klass, klass);
3265                         mono_os_mutex_unlock (&log_profiler.coverage_mutex);
3266                         g_free (fqn);
3267                         g_free (classname);
3268
3269                         return FALSE;
3270                 }
3271
3272                 for (guint i = 0; i < prof->coverage_filters->len; ++i) {
3273                         // FIXME: Is substring search sufficient?
3274                         char *filter = (char *)g_ptr_array_index (prof->coverage_filters, i);
3275                         if (filter [0] == '+')
3276                                 continue;
3277
3278                         // Skip '-'
3279                         filter = &filter [1];
3280
3281                         if (strstr (fqn, filter) != NULL) {
3282                                 mono_os_mutex_lock (&log_profiler.coverage_mutex);
3283                                 mono_conc_hashtable_insert (log_profiler.coverage_filtered_classes, klass, klass);
3284                                 mono_os_mutex_unlock (&log_profiler.coverage_mutex);
3285                                 g_free (fqn);
3286                                 g_free (classname);
3287
3288                                 return FALSE;
3289                         }
3290                 }
3291
3292                 g_free (fqn);
3293                 g_free (classname);
3294         }
3295
3296         header = mono_method_get_header_checked (method, &error);
3297         mono_error_cleanup (&error);
3298
3299         mono_method_header_get_code (header, &code_size, NULL);
3300
3301         assembly = mono_image_get_assembly (image);
3302
3303         // Need to keep the assemblies around for as long as they are kept in the hashtable
3304         // Nunit, for example, has a habit of unloading them before the coverage statistics are
3305         // generated causing a crash. See https://bugzilla.xamarin.com/show_bug.cgi?id=39325
3306         mono_assembly_addref (assembly);
3307
3308         mono_os_mutex_lock (&log_profiler.coverage_mutex);
3309         mono_conc_hashtable_insert (log_profiler.coverage_methods, method, method);
3310         mono_conc_hashtable_insert (log_profiler.coverage_assemblies, assembly, assembly);
3311         mono_os_mutex_unlock (&log_profiler.coverage_mutex);
3312
3313         image_methods = (MonoLockFreeQueue *)mono_conc_hashtable_lookup (log_profiler.coverage_image_to_methods, image);
3314
3315         if (image_methods == NULL) {
3316                 image_methods = (MonoLockFreeQueue *) g_malloc (sizeof (MonoLockFreeQueue));
3317                 mono_lock_free_queue_init (image_methods);
3318                 mono_os_mutex_lock (&log_profiler.coverage_mutex);
3319                 mono_conc_hashtable_insert (log_profiler.coverage_image_to_methods, image, image_methods);
3320                 mono_os_mutex_unlock (&log_profiler.coverage_mutex);
3321         }
3322
3323         node = create_method_node (method);
3324         mono_lock_free_queue_enqueue (image_methods, node);
3325
3326         class_methods = (MonoLockFreeQueue *)mono_conc_hashtable_lookup (log_profiler.coverage_classes, klass);
3327
3328         if (class_methods == NULL) {
3329                 class_methods = (MonoLockFreeQueue *) g_malloc (sizeof (MonoLockFreeQueue));
3330                 mono_lock_free_queue_init (class_methods);
3331                 mono_os_mutex_lock (&log_profiler.coverage_mutex);
3332                 mono_conc_hashtable_insert (log_profiler.coverage_classes, klass, class_methods);
3333                 mono_os_mutex_unlock (&log_profiler.coverage_mutex);
3334         }
3335
3336         node = create_method_node (method);
3337         mono_lock_free_queue_enqueue (class_methods, node);
3338
3339         return TRUE;
3340 }
3341
3342 #define LINE_BUFFER_SIZE 4096
3343 /* Max file limit of 128KB */
3344 #define MAX_FILE_SIZE 128 * 1024
3345 static char *
3346 get_file_content (FILE *stream)
3347 {
3348         char *buffer;
3349         ssize_t bytes_read;
3350         long filesize;
3351         int res, offset = 0;
3352
3353         res = fseek (stream, 0, SEEK_END);
3354         if (res < 0)
3355           return NULL;
3356
3357         filesize = ftell (stream);
3358         if (filesize < 0)
3359           return NULL;
3360
3361         res = fseek (stream, 0, SEEK_SET);
3362         if (res < 0)
3363           return NULL;
3364
3365         if (filesize > MAX_FILE_SIZE)
3366           return NULL;
3367
3368         buffer = (char *) g_malloc ((filesize + 1) * sizeof (char));
3369         while ((bytes_read = fread (buffer + offset, 1, LINE_BUFFER_SIZE, stream)) > 0)
3370                 offset += bytes_read;
3371
3372         /* NULL terminate our buffer */
3373         buffer[filesize] = '\0';
3374         return buffer;
3375 }
3376
3377 static char *
3378 get_next_line (char *contents, char **next_start)
3379 {
3380         char *p = contents;
3381
3382         if (p == NULL || *p == '\0') {
3383                 *next_start = NULL;
3384                 return NULL;
3385         }
3386
3387         while (*p != '\n' && *p != '\0')
3388                 p++;
3389
3390         if (*p == '\n') {
3391                 *p = '\0';
3392                 *next_start = p + 1;
3393         } else
3394                 *next_start = NULL;
3395
3396         return contents;
3397 }
3398
3399 static void
3400 init_suppressed_assemblies (void)
3401 {
3402         char *content;
3403         char *line;
3404         FILE *sa_file;
3405
3406         log_profiler.coverage_suppressed_assemblies = mono_conc_hashtable_new (g_str_hash, g_str_equal);
3407         sa_file = fopen (SUPPRESSION_DIR "/mono-profiler-log.suppression", "r");
3408         if (sa_file == NULL)
3409                 return;
3410
3411         /* Don't need to free @content as it is referred to by the lines stored in @suppressed_assemblies */
3412         content = get_file_content (sa_file);
3413         if (content == NULL)
3414                 g_error ("mono-profiler-log.suppression is greater than 128kb - aborting.");
3415
3416         while ((line = get_next_line (content, &content))) {
3417                 line = g_strchomp (g_strchug (line));
3418                 /* No locking needed as we're doing initialization */
3419                 mono_conc_hashtable_insert (log_profiler.coverage_suppressed_assemblies, line, line);
3420         }
3421
3422         fclose (sa_file);
3423 }
3424
3425 static void
3426 parse_cov_filter_file (GPtrArray *filters, const char *file)
3427 {
3428         FILE *filter_file = fopen (file, "r");
3429
3430         if (filter_file == NULL) {
3431                 mono_profiler_printf_err ("Could not open coverage filter file '%s'.", file);
3432                 return;
3433         }
3434
3435         /* Don't need to free content as it is referred to by the lines stored in @filters */
3436         char *content = get_file_content (filter_file);
3437
3438         if (content == NULL)
3439                 mono_profiler_printf_err ("Coverage filter file '%s' is larger than 128kb - ignoring.", file);
3440
3441         char *line;
3442
3443         while ((line = get_next_line (content, &content)))
3444                 g_ptr_array_add (filters, g_strchug (g_strchomp (line)));
3445
3446         fclose (filter_file);
3447 }
3448
3449 static void
3450 coverage_init (void)
3451 {
3452         mono_os_mutex_init (&log_profiler.coverage_mutex);
3453         log_profiler.coverage_methods = mono_conc_hashtable_new (NULL, NULL);
3454         log_profiler.coverage_assemblies = mono_conc_hashtable_new (NULL, NULL);
3455         log_profiler.coverage_classes = mono_conc_hashtable_new (NULL, NULL);
3456         log_profiler.coverage_filtered_classes = mono_conc_hashtable_new (NULL, NULL);
3457         log_profiler.coverage_image_to_methods = mono_conc_hashtable_new (NULL, NULL);
3458         init_suppressed_assemblies ();
3459 }
3460
3461 static void
3462 unref_coverage_assemblies (gpointer key, gpointer value, gpointer userdata)
3463 {
3464         MonoAssembly *assembly = (MonoAssembly *)value;
3465         mono_assembly_close (assembly);
3466 }
3467
3468 static void
3469 free_sample_hit (gpointer p)
3470 {
3471         mono_lock_free_free (p, SAMPLE_BLOCK_SIZE);
3472 }
3473
3474 static void
3475 cleanup_reusable_samples (void)
3476 {
3477         SampleHit *sample;
3478
3479         while ((sample = (SampleHit *) mono_lock_free_queue_dequeue (&log_profiler.sample_reuse_queue)))
3480                 mono_thread_hazardous_try_free (sample, free_sample_hit);
3481 }
3482
3483 static void
3484 log_shutdown (MonoProfiler *prof)
3485 {
3486         InterlockedWrite (&log_profiler.in_shutdown, 1);
3487
3488         if (ENABLED (PROFLOG_COUNTER_EVENTS))
3489                 counters_and_perfcounters_sample ();
3490
3491         if (log_config.collect_coverage)
3492                 dump_coverage ();
3493
3494         char c = 1;
3495
3496         if (write (prof->pipes [1], &c, 1) != 1) {
3497                 mono_profiler_printf_err ("Could not write to log profiler pipe: %s", strerror (errno));
3498                 exit (1);
3499         }
3500
3501         mono_native_thread_join (prof->helper_thread);
3502
3503         mono_os_mutex_destroy (&log_profiler.counters_mutex);
3504
3505         MonoCounterAgent *mc_next;
3506
3507         for (MonoCounterAgent *cur = log_profiler.counters; cur; cur = mc_next) {
3508                 mc_next = cur->next;
3509                 g_free (cur);
3510         }
3511
3512         PerfCounterAgent *pc_next;
3513
3514         for (PerfCounterAgent *cur = log_profiler.perfcounters; cur; cur = pc_next) {
3515                 pc_next = cur->next;
3516                 g_free (cur);
3517         }
3518
3519         /*
3520          * Ensure that we empty the LLS completely, even if some nodes are
3521          * not immediately removed upon calling mono_lls_remove (), by
3522          * iterating until the head is NULL.
3523          */
3524         while (log_profiler.profiler_thread_list.head) {
3525                 MONO_LLS_FOREACH_SAFE (&log_profiler.profiler_thread_list, MonoProfilerThread, thread) {
3526                         g_assert (thread->attached && "Why is a thread in the LLS not attached?");
3527
3528                         remove_thread (thread);
3529                 } MONO_LLS_FOREACH_SAFE_END
3530         }
3531
3532         /*
3533          * Ensure that all threads have been freed, so that we don't miss any
3534          * buffers when we shut down the writer thread below.
3535          */
3536         mono_thread_hazardous_try_free_all ();
3537
3538         InterlockedWrite (&prof->run_dumper_thread, 0);
3539         mono_os_sem_post (&prof->dumper_queue_sem);
3540         mono_native_thread_join (prof->dumper_thread);
3541         mono_os_sem_destroy (&prof->dumper_queue_sem);
3542
3543         InterlockedWrite (&prof->run_writer_thread, 0);
3544         mono_os_sem_post (&prof->writer_queue_sem);
3545         mono_native_thread_join (prof->writer_thread);
3546         mono_os_sem_destroy (&prof->writer_queue_sem);
3547
3548         /*
3549          * Free all writer queue entries, and ensure that all sample hits will be
3550          * added to the sample reuse queue.
3551          */
3552         mono_thread_hazardous_try_free_all ();
3553
3554         cleanup_reusable_samples ();
3555
3556         /*
3557          * Finally, make sure that all sample hits are freed. This should cover all
3558          * hazardous data from the profiler. We can now be sure that the runtime
3559          * won't later invoke free functions in the profiler library after it has
3560          * been unloaded.
3561          */
3562         mono_thread_hazardous_try_free_all ();
3563
3564         gint32 state = InterlockedRead (&log_profiler.buffer_lock_state);
3565
3566         g_assert (!(state & 0xFFFF) && "Why is the reader count still non-zero?");
3567         g_assert (!(state >> 16) && "Why is the exclusive lock still held?");
3568
3569 #if defined (HAVE_SYS_ZLIB)
3570         if (prof->gzfile)
3571                 gzclose (prof->gzfile);
3572 #endif
3573         if (prof->pipe_output)
3574                 pclose (prof->file);
3575         else
3576                 fclose (prof->file);
3577
3578         mono_conc_hashtable_destroy (prof->method_table);
3579         mono_os_mutex_destroy (&prof->method_table_mutex);
3580
3581         if (log_config.collect_coverage) {
3582                 mono_os_mutex_lock (&log_profiler.coverage_mutex);
3583                 mono_conc_hashtable_foreach (log_profiler.coverage_assemblies, unref_coverage_assemblies, NULL);
3584                 mono_os_mutex_unlock (&log_profiler.coverage_mutex);
3585
3586                 mono_conc_hashtable_destroy (log_profiler.coverage_methods);
3587                 mono_conc_hashtable_destroy (log_profiler.coverage_assemblies);
3588                 mono_conc_hashtable_destroy (log_profiler.coverage_classes);
3589                 mono_conc_hashtable_destroy (log_profiler.coverage_filtered_classes);
3590
3591                 mono_conc_hashtable_destroy (log_profiler.coverage_image_to_methods);
3592                 mono_conc_hashtable_destroy (log_profiler.coverage_suppressed_assemblies);
3593                 mono_os_mutex_destroy (&log_profiler.coverage_mutex);
3594         }
3595
3596         PROF_TLS_FREE ();
3597
3598         g_free (prof->args);
3599 }
3600
3601 static char*
3602 new_filename (const char* filename)
3603 {
3604         time_t t = time (NULL);
3605         int pid = process_id ();
3606         char pid_buf [16];
3607         char time_buf [16];
3608         char *res, *d;
3609         const char *p;
3610         int count_dates = 0;
3611         int count_pids = 0;
3612         int s_date, s_pid;
3613         struct tm *ts;
3614         for (p = filename; *p; p++) {
3615                 if (*p != '%')
3616                         continue;
3617                 p++;
3618                 if (*p == 't')
3619                         count_dates++;
3620                 else if (*p == 'p')
3621                         count_pids++;
3622                 else if (*p == 0)
3623                         break;
3624         }
3625         if (!count_dates && !count_pids)
3626                 return pstrdup (filename);
3627         snprintf (pid_buf, sizeof (pid_buf), "%d", pid);
3628         ts = gmtime (&t);
3629         snprintf (time_buf, sizeof (time_buf), "%d%02d%02d%02d%02d%02d",
3630                 1900 + ts->tm_year, 1 + ts->tm_mon, ts->tm_mday, ts->tm_hour, ts->tm_min, ts->tm_sec);
3631         s_date = strlen (time_buf);
3632         s_pid = strlen (pid_buf);
3633         d = res = (char *) g_malloc (strlen (filename) + s_date * count_dates + s_pid * count_pids);
3634         for (p = filename; *p; p++) {
3635                 if (*p != '%') {
3636                         *d++ = *p;
3637                         continue;
3638                 }
3639                 p++;
3640                 if (*p == 't') {
3641                         strcpy (d, time_buf);
3642                         d += s_date;
3643                         continue;
3644                 } else if (*p == 'p') {
3645                         strcpy (d, pid_buf);
3646                         d += s_pid;
3647                         continue;
3648                 } else if (*p == '%') {
3649                         *d++ = '%';
3650                         continue;
3651                 } else if (*p == 0)
3652                         break;
3653                 *d++ = '%';
3654                 *d++ = *p;
3655         }
3656         *d = 0;
3657         return res;
3658 }
3659
3660 static void
3661 add_to_fd_set (fd_set *set, int fd, int *max_fd)
3662 {
3663         /*
3664          * This should only trigger for the basic FDs (server socket, pipes) at
3665          * startup if for some mysterious reason they're too large. In this case,
3666          * the profiler really can't function, and we're better off printing an
3667          * error and exiting.
3668          */
3669         if (fd >= FD_SETSIZE) {
3670                 mono_profiler_printf_err ("File descriptor is out of bounds for fd_set: %d", fd);
3671                 exit (1);
3672         }
3673
3674         FD_SET (fd, set);
3675
3676         if (*max_fd < fd)
3677                 *max_fd = fd;
3678 }
3679
3680 static void *
3681 helper_thread (void *arg)
3682 {
3683         mono_threads_attach_tools_thread ();
3684         mono_native_thread_set_name (mono_native_thread_id_get (), "Profiler helper");
3685
3686         MonoProfilerThread *thread = init_thread (FALSE);
3687
3688         GArray *command_sockets = g_array_new (FALSE, FALSE, sizeof (int));
3689
3690         while (1) {
3691                 fd_set rfds;
3692                 int max_fd = -1;
3693
3694                 FD_ZERO (&rfds);
3695
3696                 add_to_fd_set (&rfds, log_profiler.server_socket, &max_fd);
3697                 add_to_fd_set (&rfds, log_profiler.pipes [0], &max_fd);
3698
3699                 for (gint i = 0; i < command_sockets->len; i++)
3700                         add_to_fd_set (&rfds, g_array_index (command_sockets, int, i), &max_fd);
3701
3702                 struct timeval tv = { .tv_sec = 1, .tv_usec = 0 };
3703
3704                 // Sleep for 1sec or until a file descriptor has data.
3705                 if (select (max_fd + 1, &rfds, NULL, NULL, &tv) == -1) {
3706                         if (errno == EINTR)
3707                                 continue;
3708
3709                         mono_profiler_printf_err ("Could not poll in log profiler helper thread: %s", strerror (errno));
3710                         exit (1);
3711                 }
3712
3713                 if (ENABLED (PROFLOG_COUNTER_EVENTS))
3714                         counters_and_perfcounters_sample ();
3715
3716                 buffer_lock_excl ();
3717
3718                 sync_point (SYNC_POINT_PERIODIC);
3719
3720                 buffer_unlock_excl ();
3721
3722                 // Are we shutting down?
3723                 if (FD_ISSET (log_profiler.pipes [0], &rfds)) {
3724                         char c;
3725                         read (log_profiler.pipes [0], &c, 1);
3726                         break;
3727                 }
3728
3729                 for (gint i = 0; i < command_sockets->len; i++) {
3730                         int fd = g_array_index (command_sockets, int, i);
3731
3732                         if (!FD_ISSET (fd, &rfds))
3733                                 continue;
3734
3735                         char buf [64];
3736                         int len = read (fd, buf, sizeof (buf) - 1);
3737
3738                         if (len == -1)
3739                                 continue;
3740
3741                         if (!len) {
3742                                 // The other end disconnected.
3743                                 g_array_remove_index (command_sockets, i);
3744                                 close (fd);
3745
3746                                 continue;
3747                         }
3748
3749                         buf [len] = 0;
3750
3751                         if (log_config.hs_mode == MONO_PROFILER_HEAPSHOT_ON_DEMAND && !strcmp (buf, "heapshot\n")) {
3752                                 // Rely on the finalization callback triggering a GC.
3753                                 InterlockedWrite (&log_profiler.heapshot_requested, 1);
3754                                 mono_gc_finalize_notify ();
3755                         }
3756                 }
3757
3758                 if (FD_ISSET (log_profiler.server_socket, &rfds)) {
3759                         int fd = accept (log_profiler.server_socket, NULL, NULL);
3760
3761                         if (fd != -1) {
3762                                 if (fd >= FD_SETSIZE)
3763                                         close (fd);
3764                                 else
3765                                         g_array_append_val (command_sockets, fd);
3766                         }
3767                 }
3768         }
3769
3770         for (gint i = 0; i < command_sockets->len; i++)
3771                 close (g_array_index (command_sockets, int, i));
3772
3773         g_array_free (command_sockets, TRUE);
3774
3775         send_log_unsafe (FALSE);
3776         deinit_thread (thread);
3777
3778         mono_thread_info_detach ();
3779
3780         return NULL;
3781 }
3782
3783 static void
3784 start_helper_thread (void)
3785 {
3786         if (pipe (log_profiler.pipes) == -1) {
3787                 mono_profiler_printf_err ("Could not create log profiler pipe: %s", strerror (errno));
3788                 exit (1);
3789         }
3790
3791         log_profiler.server_socket = socket (PF_INET, SOCK_STREAM, 0);
3792
3793         if (log_profiler.server_socket == -1) {
3794                 mono_profiler_printf_err ("Could not create log profiler server socket: %s", strerror (errno));
3795                 exit (1);
3796         }
3797
3798         struct sockaddr_in server_address;
3799
3800         memset (&server_address, 0, sizeof (server_address));
3801         server_address.sin_family = AF_INET;
3802         server_address.sin_addr.s_addr = INADDR_ANY;
3803         server_address.sin_port = htons (log_profiler.command_port);
3804
3805         if (bind (log_profiler.server_socket, (struct sockaddr *) &server_address, sizeof (server_address)) == -1) {
3806                 mono_profiler_printf_err ("Could not bind log profiler server socket on port %d: %s", log_profiler.command_port, strerror (errno));
3807                 close (log_profiler.server_socket);
3808                 exit (1);
3809         }
3810
3811         if (listen (log_profiler.server_socket, 1) == -1) {
3812                 mono_profiler_printf_err ("Could not listen on log profiler server socket: %s", strerror (errno));
3813                 close (log_profiler.server_socket);
3814                 exit (1);
3815         }
3816
3817         socklen_t slen = sizeof (server_address);
3818
3819         if (getsockname (log_profiler.server_socket, (struct sockaddr *) &server_address, &slen)) {
3820                 mono_profiler_printf_err ("Could not retrieve assigned port for log profiler server socket: %s", strerror (errno));
3821                 close (log_profiler.server_socket);
3822                 exit (1);
3823         }
3824
3825         log_profiler.command_port = ntohs (server_address.sin_port);
3826
3827         if (!mono_native_thread_create (&log_profiler.helper_thread, helper_thread, NULL)) {
3828                 mono_profiler_printf_err ("Could not start log profiler helper thread");
3829                 close (log_profiler.server_socket);
3830                 exit (1);
3831         }
3832 }
3833
3834 static void
3835 free_writer_entry (gpointer p)
3836 {
3837         mono_lock_free_free (p, WRITER_ENTRY_BLOCK_SIZE);
3838 }
3839
3840 static gboolean
3841 handle_writer_queue_entry (void)
3842 {
3843         WriterQueueEntry *entry;
3844
3845         if ((entry = (WriterQueueEntry *) mono_lock_free_queue_dequeue (&log_profiler.writer_queue))) {
3846                 if (!entry->methods)
3847                         goto no_methods;
3848
3849                 gboolean wrote_methods = FALSE;
3850
3851                 /*
3852                  * Encode the method events in a temporary log buffer that we
3853                  * flush to disk before the main buffer, ensuring that all
3854                  * methods have metadata emitted before they're referenced.
3855                  *
3856                  * We use a 'proper' thread-local buffer for this as opposed
3857                  * to allocating and freeing a buffer by hand because the call
3858                  * to mono_method_full_name () below may trigger class load
3859                  * events when it retrieves the signature of the method. So a
3860                  * thread-local buffer needs to exist when such events occur.
3861                  */
3862                 for (guint i = 0; i < entry->methods->len; i++) {
3863                         MethodInfo *info = (MethodInfo *) g_ptr_array_index (entry->methods, i);
3864
3865                         if (mono_conc_hashtable_lookup (log_profiler.method_table, info->method))
3866                                 goto free_info; // This method already has metadata emitted.
3867
3868                         /*
3869                          * Other threads use this hash table to get a general
3870                          * idea of whether a method has already been emitted to
3871                          * the stream. Due to the way we add to this table, it
3872                          * can easily happen that multiple threads queue up the
3873                          * same methods, but that's OK since eventually all
3874                          * methods will be in this table and the thread-local
3875                          * method lists will just be empty for the rest of the
3876                          * app's lifetime.
3877                          */
3878                         mono_os_mutex_lock (&log_profiler.method_table_mutex);
3879                         mono_conc_hashtable_insert (log_profiler.method_table, info->method, info->method);
3880                         mono_os_mutex_unlock (&log_profiler.method_table_mutex);
3881
3882                         char *name = mono_method_full_name (info->method, 1);
3883                         int nlen = strlen (name) + 1;
3884                         void *cstart = info->ji ? mono_jit_info_get_code_start (info->ji) : NULL;
3885                         int csize = info->ji ? mono_jit_info_get_code_size (info->ji) : 0;
3886
3887                         ENTER_LOG (&method_jits_ctr, logbuffer,
3888                                 EVENT_SIZE /* event */ +
3889                                 LEB128_SIZE /* method */ +
3890                                 LEB128_SIZE /* start */ +
3891                                 LEB128_SIZE /* size */ +
3892                                 nlen /* name */
3893                         );
3894
3895                         emit_event_time (logbuffer, TYPE_JIT | TYPE_METHOD, info->time);
3896                         emit_method_inner (logbuffer, info->method);
3897                         emit_ptr (logbuffer, cstart);
3898                         emit_value (logbuffer, csize);
3899
3900                         memcpy (logbuffer->cursor, name, nlen);
3901                         logbuffer->cursor += nlen;
3902
3903                         EXIT_LOG_EXPLICIT (NO_SEND);
3904
3905                         mono_free (name);
3906
3907                         wrote_methods = TRUE;
3908
3909                 free_info:
3910                         g_free (info);
3911                 }
3912
3913                 g_ptr_array_free (entry->methods, TRUE);
3914
3915                 if (wrote_methods) {
3916                         MonoProfilerThread *thread = PROF_TLS_GET ();
3917
3918                         dump_buffer_threadless (thread->buffer);
3919                         init_buffer_state (thread);
3920                 }
3921
3922         no_methods:
3923                 dump_buffer (entry->buffer);
3924
3925                 mono_thread_hazardous_try_free (entry, free_writer_entry);
3926
3927                 return TRUE;
3928         }
3929
3930         return FALSE;
3931 }
3932
3933 static void *
3934 writer_thread (void *arg)
3935 {
3936         mono_threads_attach_tools_thread ();
3937         mono_native_thread_set_name (mono_native_thread_id_get (), "Profiler writer");
3938
3939         dump_header ();
3940
3941         MonoProfilerThread *thread = init_thread (FALSE);
3942
3943         while (InterlockedRead (&log_profiler.run_writer_thread)) {
3944                 mono_os_sem_wait (&log_profiler.writer_queue_sem, MONO_SEM_FLAGS_NONE);
3945                 handle_writer_queue_entry ();
3946         }
3947
3948         /* Drain any remaining entries on shutdown. */
3949         while (handle_writer_queue_entry ());
3950
3951         free_buffer (thread->buffer, thread->buffer->size);
3952         deinit_thread (thread);
3953
3954         mono_thread_info_detach ();
3955
3956         return NULL;
3957 }
3958
3959 static void
3960 start_writer_thread (void)
3961 {
3962         InterlockedWrite (&log_profiler.run_writer_thread, 1);
3963
3964         if (!mono_native_thread_create (&log_profiler.writer_thread, writer_thread, NULL)) {
3965                 mono_profiler_printf_err ("Could not start log profiler writer thread");
3966                 exit (1);
3967         }
3968 }
3969
3970 static void
3971 reuse_sample_hit (gpointer p)
3972 {
3973         SampleHit *sample = p;
3974
3975         mono_lock_free_queue_node_unpoison (&sample->node);
3976         mono_lock_free_queue_enqueue (&log_profiler.sample_reuse_queue, &sample->node);
3977 }
3978
3979 static gboolean
3980 handle_dumper_queue_entry (void)
3981 {
3982         SampleHit *sample;
3983
3984         if ((sample = (SampleHit *) mono_lock_free_queue_dequeue (&log_profiler.dumper_queue))) {
3985                 for (int i = 0; i < sample->count; ++i) {
3986                         MonoMethod *method = sample->frames [i].method;
3987                         MonoDomain *domain = sample->frames [i].domain;
3988                         void *address = sample->frames [i].base_address;
3989
3990                         if (!method) {
3991                                 g_assert (domain && "What happened to the domain pointer?");
3992                                 g_assert (address && "What happened to the instruction pointer?");
3993
3994                                 MonoJitInfo *ji = mono_jit_info_table_find (domain, (char *) address);
3995
3996                                 if (ji)
3997                                         sample->frames [i].method = mono_jit_info_get_method (ji);
3998                         }
3999                 }
4000
4001                 ENTER_LOG (&sample_hits_ctr, logbuffer,
4002                         EVENT_SIZE /* event */ +
4003                         LEB128_SIZE /* tid */ +
4004                         LEB128_SIZE /* count */ +
4005                         1 * (
4006                                 LEB128_SIZE /* ip */
4007                         ) +
4008                         LEB128_SIZE /* managed count */ +
4009                         sample->count * (
4010                                 LEB128_SIZE /* method */
4011                         )
4012                 );
4013
4014                 emit_event_time (logbuffer, TYPE_SAMPLE | TYPE_SAMPLE_HIT, sample->time);
4015                 emit_ptr (logbuffer, (void *) sample->tid);
4016                 emit_value (logbuffer, 1);
4017
4018                 // TODO: Actual native unwinding.
4019                 for (int i = 0; i < 1; ++i) {
4020                         emit_ptr (logbuffer, sample->ip);
4021                         add_code_pointer ((uintptr_t) sample->ip);
4022                 }
4023
4024                 /* new in data version 6 */
4025                 emit_uvalue (logbuffer, sample->count);
4026
4027                 for (int i = 0; i < sample->count; ++i)
4028                         emit_method (logbuffer, sample->frames [i].method);
4029
4030                 EXIT_LOG;
4031
4032                 mono_thread_hazardous_try_free (sample, reuse_sample_hit);
4033
4034                 dump_unmanaged_coderefs ();
4035         }
4036
4037         return FALSE;
4038 }
4039
4040 static void *
4041 dumper_thread (void *arg)
4042 {
4043         mono_threads_attach_tools_thread ();
4044         mono_native_thread_set_name (mono_native_thread_id_get (), "Profiler dumper");
4045
4046         MonoProfilerThread *thread = init_thread (FALSE);
4047
4048         while (InterlockedRead (&log_profiler.run_dumper_thread)) {
4049                 /*
4050                  * Flush samples every second so it doesn't seem like the profiler is
4051                  * not working if the program is mostly idle.
4052                  */
4053                 if (mono_os_sem_timedwait (&log_profiler.dumper_queue_sem, 1000, MONO_SEM_FLAGS_NONE) == MONO_SEM_TIMEDWAIT_RET_TIMEDOUT)
4054                         send_log_unsafe (FALSE);
4055
4056                 handle_dumper_queue_entry ();
4057         }
4058
4059         /* Drain any remaining entries on shutdown. */
4060         while (handle_dumper_queue_entry ());
4061
4062         send_log_unsafe (FALSE);
4063         deinit_thread (thread);
4064
4065         mono_thread_info_detach ();
4066
4067         return NULL;
4068 }
4069
4070 static void
4071 start_dumper_thread (void)
4072 {
4073         InterlockedWrite (&log_profiler.run_dumper_thread, 1);
4074
4075         if (!mono_native_thread_create (&log_profiler.dumper_thread, dumper_thread, NULL)) {
4076                 mono_profiler_printf_err ("Could not start log profiler dumper thread");
4077                 exit (1);
4078         }
4079 }
4080
4081 static void
4082 register_counter (const char *name, gint32 *counter)
4083 {
4084         mono_counters_register (name, MONO_COUNTER_UINT | MONO_COUNTER_PROFILER | MONO_COUNTER_MONOTONIC, counter);
4085 }
4086
4087 static void
4088 runtime_initialized (MonoProfiler *profiler)
4089 {
4090         InterlockedWrite (&log_profiler.runtime_inited, 1);
4091
4092         register_counter ("Sample events allocated", &sample_allocations_ctr);
4093         register_counter ("Log buffers allocated", &buffer_allocations_ctr);
4094
4095         register_counter ("Event: Sync points", &sync_points_ctr);
4096         register_counter ("Event: Heap objects", &heap_objects_ctr);
4097         register_counter ("Event: Heap starts", &heap_starts_ctr);
4098         register_counter ("Event: Heap ends", &heap_ends_ctr);
4099         register_counter ("Event: Heap roots", &heap_roots_ctr);
4100         register_counter ("Event: GC events", &gc_events_ctr);
4101         register_counter ("Event: GC resizes", &gc_resizes_ctr);
4102         register_counter ("Event: GC allocations", &gc_allocs_ctr);
4103         register_counter ("Event: GC moves", &gc_moves_ctr);
4104         register_counter ("Event: GC handle creations", &gc_handle_creations_ctr);
4105         register_counter ("Event: GC handle deletions", &gc_handle_deletions_ctr);
4106         register_counter ("Event: GC finalize starts", &finalize_begins_ctr);
4107         register_counter ("Event: GC finalize ends", &finalize_ends_ctr);
4108         register_counter ("Event: GC finalize object starts", &finalize_object_begins_ctr);
4109         register_counter ("Event: GC finalize object ends", &finalize_object_ends_ctr);
4110         register_counter ("Event: Image loads", &image_loads_ctr);
4111         register_counter ("Event: Image unloads", &image_unloads_ctr);
4112         register_counter ("Event: Assembly loads", &assembly_loads_ctr);
4113         register_counter ("Event: Assembly unloads", &assembly_unloads_ctr);
4114         register_counter ("Event: Class loads", &class_loads_ctr);
4115         register_counter ("Event: Class unloads", &class_unloads_ctr);
4116         register_counter ("Event: Method entries", &method_entries_ctr);
4117         register_counter ("Event: Method exits", &method_exits_ctr);
4118         register_counter ("Event: Method exception leaves", &method_exception_exits_ctr);
4119         register_counter ("Event: Method JITs", &method_jits_ctr);
4120         register_counter ("Event: Code buffers", &code_buffers_ctr);
4121         register_counter ("Event: Exception throws", &exception_throws_ctr);
4122         register_counter ("Event: Exception clauses", &exception_clauses_ctr);
4123         register_counter ("Event: Monitor events", &monitor_events_ctr);
4124         register_counter ("Event: Thread starts", &thread_starts_ctr);
4125         register_counter ("Event: Thread ends", &thread_ends_ctr);
4126         register_counter ("Event: Thread names", &thread_names_ctr);
4127         register_counter ("Event: Domain loads", &domain_loads_ctr);
4128         register_counter ("Event: Domain unloads", &domain_unloads_ctr);
4129         register_counter ("Event: Domain names", &domain_names_ctr);
4130         register_counter ("Event: Context loads", &context_loads_ctr);
4131         register_counter ("Event: Context unloads", &context_unloads_ctr);
4132         register_counter ("Event: Sample binaries", &sample_ubins_ctr);
4133         register_counter ("Event: Sample symbols", &sample_usyms_ctr);
4134         register_counter ("Event: Sample hits", &sample_hits_ctr);
4135         register_counter ("Event: Counter descriptors", &counter_descriptors_ctr);
4136         register_counter ("Event: Counter samples", &counter_samples_ctr);
4137         register_counter ("Event: Performance counter descriptors", &perfcounter_descriptors_ctr);
4138         register_counter ("Event: Performance counter samples", &perfcounter_samples_ctr);
4139         register_counter ("Event: Coverage methods", &coverage_methods_ctr);
4140         register_counter ("Event: Coverage statements", &coverage_statements_ctr);
4141         register_counter ("Event: Coverage classes", &coverage_classes_ctr);
4142         register_counter ("Event: Coverage assemblies", &coverage_assemblies_ctr);
4143
4144         counters_init ();
4145
4146         /*
4147          * We must start the helper thread before the writer thread. This is
4148          * because the helper thread sets up the command port which is written to
4149          * the log header by the writer thread.
4150          */
4151         start_helper_thread ();
4152         start_writer_thread ();
4153         start_dumper_thread ();
4154 }
4155
4156 static void
4157 create_profiler (const char *args, const char *filename, GPtrArray *filters)
4158 {
4159         char *nf;
4160
4161         log_profiler.args = pstrdup (args);
4162         log_profiler.command_port = log_config.command_port;
4163
4164         //If filename begin with +, append the pid at the end
4165         if (filename && *filename == '+')
4166                 filename = g_strdup_printf ("%s.%d", filename + 1, getpid ());
4167
4168         if (!filename) {
4169                 if (log_config.do_report)
4170                         filename = "|mprof-report -";
4171                 else
4172                         filename = "output.mlpd";
4173                 nf = (char*)filename;
4174         } else {
4175                 nf = new_filename (filename);
4176                 if (log_config.do_report) {
4177                         int s = strlen (nf) + 32;
4178                         char *p = (char *) g_malloc (s);
4179                         snprintf (p, s, "|mprof-report '--out=%s' -", nf);
4180                         g_free (nf);
4181                         nf = p;
4182                 }
4183         }
4184         if (*nf == '|') {
4185                 log_profiler.file = popen (nf + 1, "w");
4186                 log_profiler.pipe_output = 1;
4187         } else if (*nf == '#') {
4188                 int fd = strtol (nf + 1, NULL, 10);
4189                 log_profiler.file = fdopen (fd, "a");
4190         } else
4191                 log_profiler.file = fopen (nf, "wb");
4192
4193         if (!log_profiler.file) {
4194                 mono_profiler_printf_err ("Could not create log profiler output file '%s'.", nf);
4195                 exit (1);
4196         }
4197
4198 #if defined (HAVE_SYS_ZLIB)
4199         if (log_config.use_zip)
4200                 log_profiler.gzfile = gzdopen (fileno (log_profiler.file), "wb");
4201 #endif
4202
4203         /*
4204          * If you hit this assert while increasing MAX_FRAMES, you need to increase
4205          * SAMPLE_BLOCK_SIZE as well.
4206          */
4207         g_assert (SAMPLE_SLOT_SIZE (MAX_FRAMES) * 2 < LOCK_FREE_ALLOC_SB_USABLE_SIZE (SAMPLE_BLOCK_SIZE));
4208
4209         // FIXME: We should free this stuff too.
4210         mono_lock_free_allocator_init_size_class (&log_profiler.sample_size_class, SAMPLE_SLOT_SIZE (log_config.num_frames), SAMPLE_BLOCK_SIZE);
4211         mono_lock_free_allocator_init_allocator (&log_profiler.sample_allocator, &log_profiler.sample_size_class, MONO_MEM_ACCOUNT_PROFILER);
4212
4213         mono_lock_free_queue_init (&log_profiler.sample_reuse_queue);
4214
4215         g_assert (sizeof (WriterQueueEntry) * 2 < LOCK_FREE_ALLOC_SB_USABLE_SIZE (WRITER_ENTRY_BLOCK_SIZE));
4216
4217         // FIXME: We should free this stuff too.
4218         mono_lock_free_allocator_init_size_class (&log_profiler.writer_entry_size_class, sizeof (WriterQueueEntry), WRITER_ENTRY_BLOCK_SIZE);
4219         mono_lock_free_allocator_init_allocator (&log_profiler.writer_entry_allocator, &log_profiler.writer_entry_size_class, MONO_MEM_ACCOUNT_PROFILER);
4220
4221         mono_lock_free_queue_init (&log_profiler.writer_queue);
4222         mono_os_sem_init (&log_profiler.writer_queue_sem, 0);
4223
4224         mono_lock_free_queue_init (&log_profiler.dumper_queue);
4225         mono_os_sem_init (&log_profiler.dumper_queue_sem, 0);
4226
4227         mono_os_mutex_init (&log_profiler.method_table_mutex);
4228         log_profiler.method_table = mono_conc_hashtable_new (NULL, NULL);
4229
4230         if (log_config.collect_coverage)
4231                 coverage_init ();
4232
4233         log_profiler.coverage_filters = filters;
4234
4235         log_profiler.startup_time = current_time ();
4236 }
4237
4238 /*
4239  * declaration to silence the compiler: this is the entry point that
4240  * mono will load from the shared library and call.
4241  */
4242 extern void
4243 mono_profiler_init (const char *desc);
4244
4245 extern void
4246 mono_profiler_init_log (const char *desc);
4247
4248 /*
4249  * this is the entry point that will be used when the profiler
4250  * is embedded inside the main executable.
4251  */
4252 void
4253 mono_profiler_init_log (const char *desc)
4254 {
4255         mono_profiler_init (desc);
4256 }
4257
4258 void
4259 mono_profiler_init (const char *desc)
4260 {
4261         GPtrArray *filters = NULL;
4262
4263         proflog_parse_args (&log_config, desc [3] == ':' ? desc + 4 : "");
4264
4265         if (log_config.cov_filter_files) {
4266                 filters = g_ptr_array_new ();
4267                 int i;
4268                 for (i = 0; i < log_config.cov_filter_files->len; ++i) {
4269                         const char *name = log_config.cov_filter_files->pdata [i];
4270                         parse_cov_filter_file (filters, name);
4271                 }
4272         }
4273
4274         init_time ();
4275
4276         PROF_TLS_INIT ();
4277
4278         create_profiler (desc, log_config.output_filename, filters);
4279
4280         mono_lls_init (&log_profiler.profiler_thread_list, NULL);
4281
4282         MonoProfilerHandle handle = log_profiler.handle = mono_profiler_install (&log_profiler);
4283
4284         /*
4285          * Required callbacks. These are either necessary for the profiler itself
4286          * to function, or provide metadata that's needed if other events (e.g.
4287          * allocations, exceptions) are dynamically enabled/disabled.
4288          */
4289
4290         mono_profiler_set_runtime_shutdown_end_callback (handle, log_shutdown);
4291         mono_profiler_set_runtime_initialized_callback (handle, runtime_initialized);
4292
4293         mono_profiler_set_gc_event_callback (handle, gc_event);
4294
4295         mono_profiler_set_thread_started_callback (handle, thread_start);
4296         mono_profiler_set_thread_stopped_callback (handle, thread_end);
4297         mono_profiler_set_thread_name_callback (handle, thread_name);
4298
4299         mono_profiler_set_domain_loaded_callback (handle, domain_loaded);
4300         mono_profiler_set_domain_unloading_callback (handle, domain_unloaded);
4301         mono_profiler_set_domain_name_callback (handle, domain_name);
4302
4303         mono_profiler_set_context_loaded_callback (handle, context_loaded);
4304         mono_profiler_set_context_unloaded_callback (handle, context_unloaded);
4305
4306         mono_profiler_set_assembly_loaded_callback (handle, assembly_loaded);
4307         mono_profiler_set_assembly_unloading_callback (handle, assembly_unloaded);
4308
4309         mono_profiler_set_image_loaded_callback (handle, image_loaded);
4310         mono_profiler_set_image_unloading_callback (handle, image_unloaded);
4311
4312         mono_profiler_set_class_loaded_callback (handle, class_loaded);
4313
4314         mono_profiler_set_jit_done_callback (handle, method_jitted);
4315
4316         if (ENABLED (PROFLOG_EXCEPTION_EVENTS)) {
4317                 mono_profiler_set_exception_throw_callback (handle, throw_exc);
4318                 mono_profiler_set_exception_clause_callback (handle, clause_exc);
4319         }
4320
4321         if (ENABLED (PROFLOG_MONITOR_EVENTS)) {
4322                 mono_profiler_set_monitor_contention_callback (handle, monitor_contention);
4323                 mono_profiler_set_monitor_acquired_callback (handle, monitor_acquired);
4324                 mono_profiler_set_monitor_failed_callback (handle, monitor_failed);
4325         }
4326
4327         if (ENABLED (PROFLOG_GC_EVENTS))
4328                 mono_profiler_set_gc_resize_callback (handle, gc_resize);
4329
4330         if (ENABLED (PROFLOG_GC_ALLOCATION_EVENTS)) {
4331                 mono_profiler_enable_allocations ();
4332                 mono_profiler_set_gc_allocation_callback (handle, gc_alloc);
4333         }
4334
4335         if (ENABLED (PROFLOG_GC_MOVE_EVENTS))
4336                 mono_profiler_set_gc_moves_callback (handle, gc_moves);
4337
4338         if (ENABLED (PROFLOG_GC_ROOT_EVENTS))
4339                 mono_profiler_set_gc_roots_callback (handle, gc_roots);
4340
4341         if (ENABLED (PROFLOG_GC_HANDLE_EVENTS)) {
4342                 mono_profiler_set_gc_handle_created_callback (handle, gc_handle_created);
4343                 mono_profiler_set_gc_handle_deleted_callback (handle, gc_handle_deleted);
4344         }
4345
4346         if (ENABLED (PROFLOG_FINALIZATION_EVENTS)) {
4347                 mono_profiler_set_gc_finalizing_callback (handle, finalize_begin);
4348                 mono_profiler_set_gc_finalized_callback (handle, finalize_end);
4349                 mono_profiler_set_gc_finalizing_object_callback (handle, finalize_object_begin);
4350                 mono_profiler_set_gc_finalized_object_callback (handle, finalize_object_end);
4351         } else if (log_config.hs_mode == MONO_PROFILER_HEAPSHOT_ON_DEMAND) {
4352                 //On Demand heapshot uses the finalizer thread to force a collection and thus a heapshot
4353                 mono_profiler_set_gc_finalized_callback (handle, finalize_end);
4354         }
4355
4356         if (ENABLED (PROFLOG_SAMPLE_EVENTS))
4357                 mono_profiler_set_sample_hit_callback (handle, mono_sample_hit);
4358
4359         if (ENABLED (PROFLOG_JIT_EVENTS))
4360                 mono_profiler_set_jit_code_buffer_callback (handle, code_buffer_new);
4361
4362         if (log_config.enter_leave) {
4363                 mono_profiler_set_call_instrumentation_filter_callback (handle, method_filter);
4364                 mono_profiler_set_method_enter_callback (handle, method_enter);
4365                 mono_profiler_set_method_leave_callback (handle, method_leave);
4366                 mono_profiler_set_method_exception_leave_callback (handle, method_exc_leave);
4367         }
4368
4369         if (log_config.collect_coverage)
4370                 mono_profiler_set_coverage_filter_callback (handle, coverage_filter);
4371
4372         mono_profiler_enable_sampling (handle);
4373
4374         /*
4375          * If no sample option was given by the user, this just leaves the sampling
4376          * thread in idle mode. We do this even if no option was given so that we
4377          * can warn if another profiler controls sampling parameters.
4378          */
4379         if (!mono_profiler_set_sample_mode (handle, log_config.sampling_mode, log_config.sample_freq))
4380                 mono_profiler_printf_err ("Another profiler controls sampling parameters; the log profiler will not be able to modify them.");
4381 }