Log profiler: fixed timeout heapshot mode and sorted heapshots.
[mono.git] / mono / profiler / proflog.c
index d8c8e584359b42f5ae9f773c44b58d90ec3c1c4f..7ba7627d7456143c05bb638d6390d11787ed24a2 100644 (file)
@@ -13,9 +13,6 @@
 #include <mono/metadata/debug-helpers.h>
 #include <stdlib.h>
 #include <string.h>
-#if defined (HAVE_ZLIB)
-#include <zlib.h>
-#endif
 #include <assert.h>
 #ifdef HOST_WIN32
 #include <windows.h>
 #include "utils.c"
 #include "proflog.h"
 
+#ifdef HOST_WIN32
+#undef HAVE_ZLIB
+#endif
+#if defined (HAVE_ZLIB)
+#include <zlib.h>
+#endif
+
 #define BUFFER_SIZE (4096 * 16)
 static int nocalls = 0;
 static int notraces = 0;
@@ -129,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
@@ -141,12 +146,22 @@ 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
  * exinfo: flags: TYPE_LOAD_ERR
  * [time diff: uleb128] nanoseconds since last timing
- * [mtype: byte] metadata type, one of: TYPE_CLASS, TYPE_IMAGE, TYPE_ASSEMBLY, TYPE_DOMAIN
+ * [mtype: byte] metadata type, one of: TYPE_CLASS, TYPE_IMAGE, TYPE_ASSEMBLY, TYPE_DOMAIN,
+ * TYPE_THREAD
  * [pointer: sleb128] pointer of the metadata type depending on mtype
  * if mtype == TYPE_CLASS
  *     [image: sleb128] MonoImage* as a pointer difference from ptr_base
@@ -155,6 +170,9 @@ typedef struct _LogBuffer LogBuffer;
  * if mtype == TYPE_IMAGE
  *     [flags: uleb128] must be 0
  *     [name: string] image file name
+ * if mtype == TYPE_THREAD
+ *     [flags: uleb128] must be 0
+ *     [name: string] thread name
  *
  * type method format:
  * type: TYPE_METHOD
@@ -386,8 +404,8 @@ dump_header (MonoProfiler *profiler)
        *p++ = LOG_VERSION_MINOR;
        *p++ = LOG_DATA_VERSION;
        *p++ = sizeof (void*);
-       p = write_int64 (p, 0); /* startup time */
-       p = write_int32 (p, 0); /* timer overhead */
+       p = write_int64 (p, ((uint64_t)time (NULL)) * 1000); /* startup time */
+       p = write_int32 (p, get_timer_overhead ()); /* timer overhead */
        p = write_int32 (p, 0); /* flags */
        p = write_int32 (p, 0); /* pid */
        p = write_int32 (p, 0); /* opsystem */
@@ -460,6 +478,9 @@ gc_reference (MonoObject *obj, MonoClass *klass, uintptr_t size, uintptr_t num,
        emit_byte (logbuffer, TYPE_HEAP_OBJECT | TYPE_HEAP);
        emit_obj (logbuffer, obj);
        emit_ptr (logbuffer, klass);
+       /* account for object alignment in the heap */
+       size += 7;
+       size &= ~7;
        emit_value (logbuffer, size);
        emit_value (logbuffer, num);
        for (i = 0; i < num; ++i)
@@ -500,6 +521,7 @@ heap_walk (MonoProfiler *profiler)
        now = current_time ();
        emit_byte (logbuffer, TYPE_HEAP_END | TYPE_HEAP);
        emit_time (logbuffer, now);
+       last_hs_time = now;
 }
 
 static void
@@ -590,6 +612,9 @@ gc_alloc (MonoProfiler *prof, MonoObject *obj, MonoClass *klass)
        FrameData data;
        LogBuffer *logbuffer;
        len = mono_object_get_size (obj);
+       /* account for object alignment in the heap */
+       len += 7;
+       len &= ~7;
        if (do_bt)
                collect_bt (&data);
        logbuffer = ensure_logbuf (32 + MAX_FRAMES * 8);
@@ -621,6 +646,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)
 {
@@ -852,6 +896,23 @@ thread_end (MonoProfiler *prof, uintptr_t tid)
        TLS_SET (tlsbuffer, NULL);
 }
 
+static void
+thread_name (MonoProfiler *prof, uintptr_t tid, const char *name)
+{
+       int len = strlen (name) + 1;
+       uint64_t now;
+       LogBuffer *logbuffer;
+       logbuffer = ensure_logbuf (10 + len);
+       now = current_time ();
+       emit_byte (logbuffer, TYPE_METADATA);
+       emit_time (logbuffer, now);
+       emit_byte (logbuffer, TYPE_THREAD);
+       emit_ptr (logbuffer, (void*)tid);
+       emit_value (logbuffer, 0); /* flags */
+       memcpy (logbuffer->data, name, len);
+       logbuffer->data += len;
+}
+
 static void
 log_shutdown (MonoProfiler *prof)
 {
@@ -974,7 +1035,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))
@@ -1087,9 +1148,11 @@ 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);
+       mono_profiler_install_thread_name (thread_name);
        mono_profiler_install_enter_leave (method_enter, method_leave);
        mono_profiler_install_jit_end (method_jitted);
        mono_profiler_install_exception (throw_exc, method_exc_leave, clause_exc);