Log profiler: added support for GC handles tracking.

* proflog.c, proflog.h: added support for tracking GC handle creation
and destruction. Updated profiler version.
* decode.c: added support for GC handles in the GC report, including
backtraces.

diff --git a/mono/profiler/decode.c b/mono/profiler/decode.c
index 0a85d7032619f658ad8c93a78714896b94ebfc20..00b14c0a581cf5db3c029905c2d44e412148ef6f 100644 (file)
--- a/mono/profiler/decode.c
+++ b/mono/profiler/decode.c
@@ -640,6 +640,13 @@ static GCDesc gc_info [3];
 static uint64_t max_heap_size;
 static uint64_t gc_object_moves;
 static int gc_resizes;
+typedef struct {
+       uint64_t created;
+       uint64_t destroyed;
+       uint64_t max_live;
+       TraceDesc traces;
+} HandleInfo;
+static HandleInfo handle_info [4];
 
 static const char*
 gc_event_name (int ev)
@@ -720,6 +727,18 @@ monitor_ev_name (int ev)
        }
 }
 
+static const char*
+get_handle_name (int htype)
+{
+       switch (htype) {
+       case 0: return "weak";
+       case 1: return "weaktrack";
+       case 2: return "normal";
+       case 3: return "pinned";
+       default: return "unknown";
+       }
+}
+
 static MethodDesc**
 decode_bt (MethodDesc** sframes, int *size, unsigned char *p, unsigned char **endp, intptr_t ptr_base)
 {
@@ -758,6 +777,16 @@ tracked_creation (uintptr_t obj, ClassDesc *cd, uint64_t size, BackTrace *bt, ui
        }
 }
 
+static void
+track_handle (uintptr_t obj, int htype, uint32_t handle)
+{
+       int i;
+       for (i = 0; i < num_tracked_objects; ++i) {
+               if (tracked_objects [i] == obj)
+                       fprintf (outfile, "Object %p referenced from handle %u\n", (void*)obj, handle);
+       }
+}
+
 static void
 track_move (uintptr_t src, uintptr_t dst)
 {
@@ -877,6 +906,29 @@ decode_buffer (ProfContext *ctx)
                                                fprintf (outfile, "moved obj %p to %p\n", (void*)OBJ_ADDR (obj1diff), (void*)OBJ_ADDR (obj2diff));
                                        }
                                }
+                       } else if (subtype == TYPE_GC_HANDLE_CREATED) {
+                               int htype = decode_uleb128 (p, &p);
+                               uint32_t handle = decode_uleb128 (p, &p);
+                               intptr_t objdiff = decode_sleb128 (p, &p);
+                               if (htype > 3)
+                                       return 0;
+                               handle_info [htype].created++;
+                               add_trace_thread (thread, &handle_info [htype].traces, 1);
+                               /* FIXME: we don't take into account timing here */
+                               if (handle_info [htype].created > handle_info [htype].max_live)
+                                       handle_info [htype].max_live = handle_info [htype].created;
+                               if (num_tracked_objects)
+                                       track_handle (OBJ_ADDR (objdiff), htype, handle);
+                               if (debug)
+                                       fprintf (outfile, "handle (%s) %u created for object %p\n", get_handle_name (htype), handle, (void*)OBJ_ADDR (objdiff));
+                       } else if (subtype == TYPE_GC_HANDLE_DESTROYED) {
+                               int htype = decode_uleb128 (p, &p);
+                               uint32_t handle = decode_uleb128 (p, &p);
+                               if (htype > 3)
+                                       return 0;
+                               handle_info [htype].created--;
+                               if (debug)
+                                       fprintf (outfile, "handle (%s) %u destroyed\n", get_handle_name (htype), handle);
                        }
                        break;
                }
@@ -1319,6 +1371,13 @@ dump_gcs (void)
                        i, gc_info [i].count, gc_info [i].max_time / 1000, gc_info [i].total_time / 1000,
                        gc_info [i].total_time / gc_info [i].count / 1000);
        }
+       for (i = 0; i < 3; ++i) {
+               if (!handle_info [i].max_live)
+                       continue;
+               fprintf (outfile, "\tGC handles %s: created: %llu, destroyed: %llu, max: %llu\n",
+                       get_handle_name (i), handle_info [i].created, handle_info [i].destroyed, handle_info [i].max_live);
+               dump_traces (&handle_info [i].traces, "created");
+       }
 }
 
 static void

diff --git a/mono/profiler/proflog.c b/mono/profiler/proflog.c
index c669c1cd24903342a75ca56b76c12dd666bda1c2..34bb9ad120ef42e5e2dd66d1b5677b9bc63f5588 100644 (file)
--- a/mono/profiler/proflog.c
+++ b/mono/profiler/proflog.c
@@ -133,7 +133,8 @@ typedef struct _LogBuffer LogBuffer;
  *
  * type GC format:
  * type: TYPE_GC
- * exinfo: one of TYPE_GC_EVENT, TYPE_GC_RESIZE, TYPE_GC_MOVE
+ * exinfo: one of TYPE_GC_EVENT, TYPE_GC_RESIZE, TYPE_GC_MOVE, TYPE_GC_HANDLE_CREATED,
+ * TYPE_GC_HANDLE_DESTROYED
  * [time diff: uleb128] nanoseconds since last timing
  * if exinfo == TYPE_GC_RESIZE
  *     [heap_size: uleb128] new heap size
@@ -145,6 +146,15 @@ typedef struct _LogBuffer LogBuffer;
  *     [objaddr: sleb128]+ num_objects object pointer differences from obj_base
  *     num is always an even number: the even items are the old
  *     addresses, the odd numbers are the respective new object addresses
+ * if exinfo == TYPE_GC_HANDLE_CREATED
+ *     [handle_type: uleb128] GC handle type (System.Runtime.InteropServices.GCHandleType)
+ *     upper bits reserved as flags
+ *     [handle: uleb128] GC handle value
+ *     [objaddr: sleb128] object pointer differences from obj_base
+ * if exinfo == TYPE_GC_HANDLE_DESTROYED
+ *     [handle_type: uleb128] GC handle type (System.Runtime.InteropServices.GCHandleType)
+ *     upper bits reserved as flags
+ *     [handle: uleb128] GC handle value
  *
  * type metadata format:
  * type: TYPE_METADATA
@@ -631,6 +641,25 @@ gc_moves (MonoProfiler *prof, void **objects, int num)
        //printf ("gc moved %d objects\n", num/2);
 }
 
+static void
+gc_handle (MonoProfiler *prof, int op, int type, uintptr_t handle, MonoObject *obj)
+{
+       uint64_t now;
+       LogBuffer *logbuffer = ensure_logbuf (16);
+       now = current_time ();
+       if (op == MONO_PROFILER_GC_HANDLE_CREATED)
+               emit_byte (logbuffer, TYPE_GC_HANDLE_CREATED | TYPE_GC);
+       else if (op == MONO_PROFILER_GC_HANDLE_DESTROYED)
+               emit_byte (logbuffer, TYPE_GC_HANDLE_DESTROYED | TYPE_GC);
+       else
+               return;
+       emit_time (logbuffer, now);
+       emit_value (logbuffer, type);
+       emit_value (logbuffer, handle);
+       if (op == MONO_PROFILER_GC_HANDLE_CREATED)
+               emit_obj (logbuffer, obj);
+}
+
 static char*
 push_nesting (char *p, MonoClass *klass)
 {
@@ -984,7 +1013,7 @@ mono_profiler_startup (const char *desc)
        int events = MONO_PROFILE_GC|MONO_PROFILE_ALLOCATIONS|
                MONO_PROFILE_GC_MOVES|MONO_PROFILE_CLASS_EVENTS|MONO_PROFILE_THREADS|
                MONO_PROFILE_ENTER_LEAVE|MONO_PROFILE_JIT_COMPILATION|MONO_PROFILE_EXCEPTIONS|
-               MONO_PROFILE_MONITOR_EVENTS|MONO_PROFILE_MODULE_EVENTS;
+               MONO_PROFILE_MONITOR_EVENTS|MONO_PROFILE_MODULE_EVENTS|MONO_PROFILE_GC_ROOTS;
 
        p = desc;
        if (strncmp (p, "log", 3))
@@ -1097,6 +1126,7 @@ mono_profiler_startup (const char *desc)
        mono_profiler_install_gc (gc_event, gc_resize);
        mono_profiler_install_allocation (gc_alloc);
        mono_profiler_install_gc_moves (gc_moves);
+       mono_profiler_install_gc_roots (gc_handle);
        mono_profiler_install_class (NULL, class_loaded, NULL, NULL);
        mono_profiler_install_module (NULL, image_loaded, NULL, NULL);
        mono_profiler_install_thread (thread_start, thread_end);

diff --git a/mono/profiler/proflog.h b/mono/profiler/proflog.h
index c9e7f443b6a5c3f969fb2e1eb745c51a17588e3c..0a4769d86341a828bb4ab8310d8e52d61a49fba1 100644 (file)
--- a/mono/profiler/proflog.h
+++ b/mono/profiler/proflog.h
@@ -4,7 +4,7 @@
 #define BUF_ID 0x4D504C01
 #define LOG_HEADER_ID 0x4D505A01
 #define LOG_VERSION_MAJOR 0
-#define LOG_VERSION_MINOR 1
+#define LOG_VERSION_MINOR 2
 #define LOG_DATA_VERSION 1
 
 enum {
@@ -34,6 +34,8 @@ enum {
        TYPE_GC_EVENT  = 1 << 4,
        TYPE_GC_RESIZE = 2 << 4,
        TYPE_GC_MOVE   = 3 << 4,
+       TYPE_GC_HANDLE_CREATED   = 4 << 4,
+       TYPE_GC_HANDLE_DESTROYED = 5 << 4,
        /* extended type for TYPE_METHOD */
        TYPE_LEAVE     = 1 << 4,
        TYPE_ENTER     = 2 << 4,