Merge pull request #5095 from kumpera/fix_fullaot
[mono.git] / mono / profiler / log.c
index 34cd7935f8f5fdbae1a37d24b1433709ba9ace20..d84ee526ca223d52314688d838b9f6cc6b1e1ed7 100644 (file)
@@ -258,7 +258,8 @@ static MonoLinkedListSet profiler_thread_list;
  *
  * type metadata format:
  * type: TYPE_METADATA
- * exinfo: one of: TYPE_END_LOAD, TYPE_END_UNLOAD (optional for TYPE_THREAD and TYPE_DOMAIN)
+ * exinfo: one of: TYPE_END_LOAD, TYPE_END_UNLOAD (optional for TYPE_THREAD and TYPE_DOMAIN,
+ * doesn't occur for TYPE_CLASS)
  * [mtype: byte] metadata type, one of: TYPE_CLASS, TYPE_IMAGE, TYPE_ASSEMBLY, TYPE_DOMAIN,
  * TYPE_THREAD, TYPE_CONTEXT
  * [pointer: sleb128] pointer of the metadata type depending on mtype
@@ -479,8 +480,42 @@ typedef struct {
 
        // Has this thread written a thread end event to `buffer`?
        gboolean ended;
+
+       // Stored in `buffer_lock_state` to take the exclusive lock.
+       int small_id;
 } MonoProfilerThread;
 
+// Do not use these TLS macros directly unless you know what you're doing.
+
+#ifdef HOST_WIN32
+
+#define PROF_TLS_SET(VAL) (TlsSetValue (profiler_tls, (VAL)))
+#define PROF_TLS_GET() ((MonoProfilerThread *) TlsGetValue (profiler_tls))
+#define PROF_TLS_INIT() (profiler_tls = TlsAlloc ())
+#define PROF_TLS_FREE() (TlsFree (profiler_tls))
+
+static DWORD profiler_tls;
+
+#elif HAVE_KW_THREAD
+
+#define PROF_TLS_SET(VAL) (profiler_tls = (VAL))
+#define PROF_TLS_GET() (profiler_tls)
+#define PROF_TLS_INIT()
+#define PROF_TLS_FREE()
+
+static __thread MonoProfilerThread *profiler_tls;
+
+#else
+
+#define PROF_TLS_SET(VAL) (pthread_setspecific (profiler_tls, (VAL)))
+#define PROF_TLS_GET() ((MonoProfilerThread *) pthread_getspecific (profiler_tls))
+#define PROF_TLS_INIT() (pthread_key_create (&profiler_tls, NULL))
+#define PROF_TLS_FREE() (pthread_key_delete (profiler_tls))
+
+static pthread_key_t profiler_tls;
+
+#endif
+
 static uintptr_t
 thread_id (void)
 {
@@ -595,84 +630,6 @@ init_time (void)
 
 #define EXIT_LOG EXIT_LOG_EXPLICIT (DO_SEND)
 
-static volatile gint32 buffer_rwlock_count;
-static volatile gpointer buffer_rwlock_exclusive;
-
-// Can be used recursively.
-static void
-buffer_lock (void)
-{
-       /*
-        * If the thread holding the exclusive lock tries to modify the
-        * reader count, just make it a no-op. This way, we also avoid
-        * invoking the GC safe point macros below, which could break if
-        * done from a thread that is currently the initiator of STW.
-        *
-        * In other words, we rely on the fact that the GC thread takes
-        * the exclusive lock in the gc_event () callback when the world
-        * is about to stop.
-        */
-       if (InterlockedReadPointer (&buffer_rwlock_exclusive) != (gpointer) thread_id ()) {
-               MONO_ENTER_GC_SAFE;
-
-               while (InterlockedReadPointer (&buffer_rwlock_exclusive))
-                       mono_thread_info_yield ();
-
-               InterlockedIncrement (&buffer_rwlock_count);
-
-               MONO_EXIT_GC_SAFE;
-       }
-
-       mono_memory_barrier ();
-}
-
-static void
-buffer_unlock (void)
-{
-       mono_memory_barrier ();
-
-       // See the comment in buffer_lock ().
-       if (InterlockedReadPointer (&buffer_rwlock_exclusive) == (gpointer) thread_id ())
-               return;
-
-       g_assert (InterlockedRead (&buffer_rwlock_count) && "Why are we trying to decrement a zero reader count?");
-
-       InterlockedDecrement (&buffer_rwlock_count);
-}
-
-// Cannot be used recursively.
-static void
-buffer_lock_excl (void)
-{
-       gpointer tid = (gpointer) thread_id ();
-
-       g_assert (InterlockedReadPointer (&buffer_rwlock_exclusive) != tid && "Why are we taking the exclusive lock twice?");
-
-       MONO_ENTER_GC_SAFE;
-
-       while (InterlockedCompareExchangePointer (&buffer_rwlock_exclusive, tid, 0))
-               mono_thread_info_yield ();
-
-       while (InterlockedRead (&buffer_rwlock_count))
-               mono_thread_info_yield ();
-
-       MONO_EXIT_GC_SAFE;
-
-       mono_memory_barrier ();
-}
-
-static void
-buffer_unlock_excl (void)
-{
-       mono_memory_barrier ();
-
-       g_assert (InterlockedReadPointer (&buffer_rwlock_exclusive) && "Why is the exclusive lock not held?");
-       g_assert (InterlockedReadPointer (&buffer_rwlock_exclusive) == (gpointer) thread_id () && "Why does another thread hold the exclusive lock?");
-       g_assert (!InterlockedRead (&buffer_rwlock_count) && "Why are there readers when the exclusive lock is held?");
-
-       InterlockedWritePointer (&buffer_rwlock_exclusive, NULL);
-}
-
 typedef struct _BinaryObject BinaryObject;
 struct _BinaryObject {
        BinaryObject *next;
@@ -727,37 +684,6 @@ typedef struct {
        uint64_t time;
 } MethodInfo;
 
-// Do not use these TLS macros directly unless you know what you're doing.
-
-#ifdef HOST_WIN32
-
-#define PROF_TLS_SET(VAL) (TlsSetValue (profiler_tls, (VAL)))
-#define PROF_TLS_GET() ((MonoProfilerThread *) TlsGetValue (profiler_tls))
-#define PROF_TLS_INIT() (profiler_tls = TlsAlloc ())
-#define PROF_TLS_FREE() (TlsFree (profiler_tls))
-
-static DWORD profiler_tls;
-
-#elif HAVE_KW_THREAD
-
-#define PROF_TLS_SET(VAL) (profiler_tls = (VAL))
-#define PROF_TLS_GET() (profiler_tls)
-#define PROF_TLS_INIT()
-#define PROF_TLS_FREE()
-
-static __thread MonoProfilerThread *profiler_tls;
-
-#else
-
-#define PROF_TLS_SET(VAL) (pthread_setspecific (profiler_tls, (VAL)))
-#define PROF_TLS_GET() ((MonoProfilerThread *) pthread_getspecific (profiler_tls))
-#define PROF_TLS_INIT() (pthread_key_create (&profiler_tls, NULL))
-#define PROF_TLS_FREE() (pthread_key_delete (profiler_tls))
-
-static pthread_key_t profiler_tls;
-
-#endif
-
 static char*
 pstrdup (const char *s)
 {
@@ -780,9 +706,9 @@ free_buffer (void *buf, int size)
 }
 
 static LogBuffer*
-create_buffer (uintptr_t tid)
+create_buffer (uintptr_t tid, int bytes)
 {
-       LogBuffer* buf = (LogBuffer *) alloc_buffer (BUFFER_SIZE);
+       LogBuffer* buf = (LogBuffer *) alloc_buffer (MAX (BUFFER_SIZE, bytes));
 
        InterlockedIncrement (&buffer_allocations_ctr);
 
@@ -805,7 +731,7 @@ create_buffer (uintptr_t tid)
 static void
 init_buffer_state (MonoProfilerThread *thread)
 {
-       thread->buffer = create_buffer (thread->node.key);
+       thread->buffer = create_buffer (thread->node.key, 0);
        thread->methods = NULL;
 }
 
@@ -846,6 +772,8 @@ init_thread (MonoProfiler *prof, gboolean add_to_lls)
 
        init_buffer_state (thread);
 
+       thread->small_id = mono_thread_info_register_small_id ();
+
        /*
         * Some internal profiler threads don't need to be cleaned up
         * by the main thread on shutdown.
@@ -883,16 +811,143 @@ ensure_logbuf_unsafe (MonoProfilerThread *thread, int bytes)
 {
        LogBuffer *old = thread->buffer;
 
-       if (old && old->cursor + bytes < old->buf_end)
+       if (old->cursor + bytes < old->buf_end)
                return old;
 
-       LogBuffer *new_ = create_buffer (thread->node.key);
+       LogBuffer *new_ = create_buffer (thread->node.key, bytes);
        new_->next = old;
        thread->buffer = new_;
 
        return new_;
 }
 
+/*
+ * This is a reader/writer spin lock of sorts used to protect log buffers.
+ * When a thread modifies its own log buffer, it increments the reader
+ * count. When a thread wants to access log buffers of other threads, it
+ * takes the exclusive lock.
+ *
+ * `buffer_lock_state` holds the reader count in its lower 16 bits, and
+ * the small ID of the thread currently holding the exclusive (writer)
+ * lock in its upper 16 bits. Both can be zero. It's important that the
+ * whole lock state is a single word that can be read/written atomically
+ * to avoid race conditions where there could end up being readers while
+ * the writer lock is held.
+ *
+ * The lock is writer-biased. When a thread wants to take the exclusive
+ * lock, it increments `buffer_lock_exclusive_intent` which will make new
+ * readers spin until it's back to zero, then takes the exclusive lock
+ * once the reader count has reached zero. After releasing the exclusive
+ * lock, it decrements `buffer_lock_exclusive_intent`, which, when it
+ * reaches zero again, allows readers to increment the reader count.
+ *
+ * The writer bias is necessary because we take the exclusive lock in
+ * `gc_event ()` during STW. If the writer bias was not there, and a
+ * program had a large number of threads, STW-induced pauses could be
+ * significantly longer than they have to be. Also, we emit periodic
+ * sync points from the helper thread, which requires taking the
+ * exclusive lock, and we need those to arrive with a reasonably
+ * consistent frequency so that readers don't have to queue up too many
+ * events between sync points.
+ *
+ * The lock does not support recursion.
+ */
+static volatile gint32 buffer_lock_state;
+static volatile gint32 buffer_lock_exclusive_intent;
+
+static void
+buffer_lock (void)
+{
+       /*
+        * If the thread holding the exclusive lock tries to modify the
+        * reader count, just make it a no-op. This way, we also avoid
+        * invoking the GC safe point macros below, which could break if
+        * done from a thread that is currently the initiator of STW.
+        *
+        * In other words, we rely on the fact that the GC thread takes
+        * the exclusive lock in the gc_event () callback when the world
+        * is about to stop.
+        */
+       if (InterlockedRead (&buffer_lock_state) != get_thread ()->small_id << 16) {
+               MONO_ENTER_GC_SAFE;
+
+               gint32 old, new_;
+
+               do {
+               restart:
+                       // Hold off if a thread wants to take the exclusive lock.
+                       while (InterlockedRead (&buffer_lock_exclusive_intent))
+                               mono_thread_info_yield ();
+
+                       old = InterlockedRead (&buffer_lock_state);
+
+                       // Is a thread holding the exclusive lock?
+                       if (old >> 16) {
+                               mono_thread_info_yield ();
+                               goto restart;
+                       }
+
+                       new_ = old + 1;
+               } while (InterlockedCompareExchange (&buffer_lock_state, new_, old) != old);
+
+               MONO_EXIT_GC_SAFE;
+       }
+
+       mono_memory_barrier ();
+}
+
+static void
+buffer_unlock (void)
+{
+       mono_memory_barrier ();
+
+       gint32 state = InterlockedRead (&buffer_lock_state);
+
+       // See the comment in buffer_lock ().
+       if (state == PROF_TLS_GET ()->small_id << 16)
+               return;
+
+       g_assert (state && "Why are we decrementing a zero reader count?");
+       g_assert (!(state >> 16) && "Why is the exclusive lock held?");
+
+       InterlockedDecrement (&buffer_lock_state);
+}
+
+static void
+buffer_lock_excl (void)
+{
+       gint32 new_ = get_thread ()->small_id << 16;
+
+       g_assert (InterlockedRead (&buffer_lock_state) != new_ && "Why are we taking the exclusive lock twice?");
+
+       InterlockedIncrement (&buffer_lock_exclusive_intent);
+
+       MONO_ENTER_GC_SAFE;
+
+       while (InterlockedCompareExchange (&buffer_lock_state, new_, 0))
+               mono_thread_info_yield ();
+
+       MONO_EXIT_GC_SAFE;
+
+       mono_memory_barrier ();
+}
+
+static void
+buffer_unlock_excl (void)
+{
+       mono_memory_barrier ();
+
+       gint32 state = InterlockedRead (&buffer_lock_state);
+       gint32 excl = state >> 16;
+
+       g_assert (excl && "Why is the exclusive lock not held?");
+       g_assert (excl == PROF_TLS_GET ()->small_id && "Why does another thread hold the exclusive lock?");
+       g_assert (!(state & 0xFFFF) && "Why are there readers when the exclusive lock is held?");
+
+       InterlockedWrite (&buffer_lock_state, 0);
+       InterlockedDecrement (&buffer_lock_exclusive_intent);
+}
+
 static void
 encode_uleb128 (uint64_t value, uint8_t *buf, uint8_t **endbuf)
 {
@@ -1026,6 +1081,7 @@ emit_method_inner (LogBuffer *logbuffer, void *method)
        g_assert (logbuffer->cursor <= logbuffer->buf_end && "Why are we writing past the buffer end?");
 }
 
+// The reader lock must be held.
 static void
 register_method_local (MonoMethod *method, MonoJitInfo *ji)
 {
@@ -1038,12 +1094,8 @@ register_method_local (MonoMethod *method, MonoJitInfo *ji)
                info->ji = ji;
                info->time = current_time ();
 
-               buffer_lock ();
-
                GPtrArray *arr = thread->methods ? thread->methods : (thread->methods = g_ptr_array_new ());
                g_ptr_array_add (arr, info);
-
-               buffer_unlock ();
        }
 }
 
@@ -1313,7 +1365,7 @@ send_log_unsafe (gboolean if_needed)
 static void
 sync_point_flush (void)
 {
-       g_assert (InterlockedReadPointer (&buffer_rwlock_exclusive) == (gpointer) thread_id () && "Why don't we hold the exclusive lock?");
+       g_assert (InterlockedRead (&buffer_lock_state) == PROF_TLS_GET ()->small_id << 16 && "Why don't we hold the exclusive lock?");
 
        MONO_LLS_FOREACH_SAFE (&profiler_thread_list, MonoProfilerThread, thread) {
                g_assert (thread->attached && "Why is a thread in the LLS not attached?");
@@ -1327,7 +1379,7 @@ sync_point_flush (void)
 static void
 sync_point_mark (MonoProfilerSyncPointType type)
 {
-       g_assert (InterlockedReadPointer (&buffer_rwlock_exclusive) == (gpointer) thread_id () && "Why don't we hold the exclusive lock?");
+       g_assert (InterlockedRead (&buffer_lock_state) == PROF_TLS_GET ()->small_id << 16 && "Why don't we hold the exclusive lock?");
 
        ENTER_LOG (&sync_points_ctr, logbuffer,
                EVENT_SIZE /* event */ +
@@ -1605,17 +1657,13 @@ collect_bt (FrameData *data)
 static void
 emit_bt (MonoProfiler *prof, LogBuffer *logbuffer, FrameData *data)
 {
-       /* FIXME: this is actually tons of data and we should
-        * just output it the first time and use an id the next
-        */
        if (data->count > num_frames)
                printf ("bad num frames: %d\n", data->count);
+
        emit_value (logbuffer, data->count);
-       //if (*p != data.count) {
-       //      printf ("bad num frames enc at %d: %d -> %d\n", count, data.count, *p); printf ("frames end: %p->%p\n", p, logbuffer->cursor); exit(0);}
-       while (data->count) {
+
+       while (data->count)
                emit_method (logbuffer, data->methods [--data->count]);
-       }
 }
 
 static void
@@ -1954,42 +2002,6 @@ class_loaded (MonoProfiler *prof, MonoClass *klass, int result)
                g_free (name);
 }
 
-static void
-class_unloaded (MonoProfiler *prof, MonoClass *klass)
-{
-       char *name;
-
-       if (InterlockedRead (&runtime_inited))
-               name = mono_type_get_name (mono_class_get_type (klass));
-       else
-               name = type_name (klass);
-
-       int nlen = strlen (name) + 1;
-       MonoImage *image = mono_class_get_image (klass);
-
-       ENTER_LOG (&class_unloads_ctr, logbuffer,
-               EVENT_SIZE /* event */ +
-               BYTE_SIZE /* type */ +
-               LEB128_SIZE /* klass */ +
-               LEB128_SIZE /* image */ +
-               nlen /* name */
-       );
-
-       emit_event (logbuffer, TYPE_END_UNLOAD | TYPE_METADATA);
-       emit_byte (logbuffer, TYPE_CLASS);
-       emit_ptr (logbuffer, klass);
-       emit_ptr (logbuffer, image);
-       memcpy (logbuffer->cursor, name, nlen);
-       logbuffer->cursor += nlen;
-
-       EXIT_LOG;
-
-       if (runtime_inited)
-               mono_free (name);
-       else
-               g_free (name);
-}
-
 static void process_method_enter_coverage (MonoProfiler *prof, MonoMethod *method);
 
 static void
@@ -2048,7 +2060,11 @@ method_jitted (MonoProfiler *prof, MonoMethod *method, MonoJitInfo *ji, int resu
        if (result != MONO_PROFILE_OK)
                return;
 
+       buffer_lock ();
+
        register_method_local (method, ji);
+
+       buffer_unlock ();
 }
 
 static void
@@ -3916,8 +3932,10 @@ log_shutdown (MonoProfiler *prof)
         */
        mono_thread_hazardous_try_free_all ();
 
-       g_assert (!InterlockedRead (&buffer_rwlock_count) && "Why is the reader count still non-zero?");
-       g_assert (!InterlockedReadPointer (&buffer_rwlock_exclusive) && "Why does someone still hold the exclusive lock?");
+       gint32 state = InterlockedRead (&buffer_lock_state);
+
+       g_assert (!(state & 0xFFFF) && "Why is the reader count still non-zero?");
+       g_assert (!(state >> 16) && "Why is the exclusive lock still held?");
 
 #if defined (HAVE_SYS_ZLIB)
        if (prof->gzfile)
@@ -4704,7 +4722,7 @@ mono_profiler_startup (const char *desc)
 
        if (config.effective_mask & PROFLOG_CLASS_EVENTS) {
                events |= MONO_PROFILE_CLASS_EVENTS;
-               mono_profiler_install_class (NULL, class_loaded, class_unloaded, NULL);
+               mono_profiler_install_class (NULL, class_loaded, NULL, NULL);
        }
 
        if (config.effective_mask & PROFLOG_JIT_COMPILATION_EVENTS) {