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