[profiler] Add GC finalization events to the format.

diff --git a/mono/profiler/decode.c b/mono/profiler/decode.c
index 61d39d530b96f836af906cbc9a93abf4df706173..355e4c95388770496902b501920f4d9b0fd8e959 100644 (file)
--- a/mono/profiler/decode.c
+++ b/mono/profiler/decode.c
@@ -2400,6 +2400,21 @@ decode_buffer (ProfContext *ctx)
                                        fprintf (outfile, "handle (%s) %u destroyed\n", get_handle_name (htype), handle);
                                if (frames != sframes)
                                        free (frames);
+                       } else if (subtype == TYPE_GC_FINALIZE_START) {
+                               // TODO: Generate a finalizer report based on these events.
+                               if (debug)
+                                       fprintf (outfile, "gc finalizer queue being processed at %llu\n", (unsigned long long) time_base);
+                       } else if (subtype == TYPE_GC_FINALIZE_END) {
+                               if (debug)
+                                       fprintf (outfile, "gc finalizer queue finished processing at %llu\n", (unsigned long long) time_base);
+                       } else if (subtype == TYPE_GC_FINALIZE_OBJECT_START) {
+                               intptr_t objdiff = decode_sleb128 (p, &p);
+                               if (debug)
+                                       fprintf (outfile, "gc finalizing object %p at %llu\n", (void *) OBJ_ADDR (objdiff), (unsigned long long) time_base);
+                       } else if (subtype == TYPE_GC_FINALIZE_OBJECT_END) {
+                               intptr_t objdiff = decode_sleb128 (p, &p);
+                               if (debug)
+                                       fprintf (outfile, "gc finalized object %p at %llu\n", (void *) OBJ_ADDR (objdiff), (unsigned long long) time_base);
                        }
                        break;
                }

diff --git a/mono/profiler/proflog.c b/mono/profiler/proflog.c
index 0c6f4c904c7e3b871cddfe6a68b4976466936e0d..529d5d675e57f4a545f5e1f5d67c9f6e0cab9f5b 100644 (file)
--- a/mono/profiler/proflog.c
+++ b/mono/profiler/proflog.c
@@ -231,7 +231,8 @@ static MonoLinkedListSet profiler_thread_list;
  * type GC format:
  * type: TYPE_GC
  * exinfo: one of TYPE_GC_EVENT, TYPE_GC_RESIZE, TYPE_GC_MOVE, TYPE_GC_HANDLE_CREATED[_BT],
- * TYPE_GC_HANDLE_DESTROYED[_BT]
+ * TYPE_GC_HANDLE_DESTROYED[_BT], TYPE_GC_FINALIZE_START, TYPE_GC_FINALIZE_END,
+ * TYPE_GC_FINALIZE_OBJECT_START, TYPE_GC_FINALIZE_OBJECT_END
  * [time diff: uleb128] nanoseconds since last timing
  * if exinfo == TYPE_GC_RESIZE
  *     [heap_size: uleb128] new heap size
@@ -254,6 +255,8 @@ static MonoLinkedListSet profiler_thread_list;
  *     upper bits reserved as flags
  *     [handle: uleb128] GC handle value
  *     If exinfo == TYPE_GC_HANDLE_DESTROYED_BT, a backtrace follows.
+ * if exinfo == TYPE_GC_FINALIZE_OBJECT_{START,END}
+ *     [object: sleb128] the object as a difference from obj_base
  *
  * type metadata format:
  * type: TYPE_METADATA
@@ -1619,6 +1622,74 @@ gc_handle (MonoProfiler *prof, int op, int type, uintptr_t handle, MonoObject *o
        process_requests (prof);
 }
 
+static void
+finalize_begin (MonoProfiler *prof)
+{
+       ENTER_LOG;
+
+       LogBuffer *buf = ensure_logbuf (
+               EVENT_SIZE /* event */
+       );
+
+       emit_event (buf, TYPE_GC_FINALIZE_START | TYPE_GC);
+
+       EXIT_LOG;
+
+       process_requests (prof);
+}
+
+static void
+finalize_end (MonoProfiler *prof)
+{
+       ENTER_LOG;
+
+       LogBuffer *buf = ensure_logbuf (
+               EVENT_SIZE /* event */
+       );
+
+       emit_event (buf, TYPE_GC_FINALIZE_END | TYPE_GC);
+
+       EXIT_LOG;
+
+       process_requests (prof);
+}
+
+static void
+finalize_object_begin (MonoProfiler *prof, MonoObject *obj)
+{
+       ENTER_LOG;
+
+       LogBuffer *buf = ensure_logbuf (
+               EVENT_SIZE /* event */ +
+               LEB128_SIZE /* obj */
+       );
+
+       emit_event (buf, TYPE_GC_FINALIZE_OBJECT_START | TYPE_GC);
+       emit_obj (buf, obj);
+
+       EXIT_LOG;
+
+       process_requests (prof);
+}
+
+static void
+finalize_object_end (MonoProfiler *prof, MonoObject *obj)
+{
+       ENTER_LOG;
+
+       LogBuffer *buf = ensure_logbuf (
+               EVENT_SIZE /* event */ +
+               LEB128_SIZE /* obj */
+       );
+
+       emit_event (buf, TYPE_GC_FINALIZE_OBJECT_END | TYPE_GC);
+       emit_obj (buf, obj);
+
+       EXIT_LOG;
+
+       process_requests (prof);
+}
+
 static char*
 push_nesting (char *p, MonoClass *klass)
 {
@@ -5046,7 +5117,7 @@ mono_profiler_startup (const char *desc)
                MONO_PROFILE_ENTER_LEAVE|MONO_PROFILE_JIT_COMPILATION|MONO_PROFILE_EXCEPTIONS|
                MONO_PROFILE_MONITOR_EVENTS|MONO_PROFILE_MODULE_EVENTS|MONO_PROFILE_GC_ROOTS|
                MONO_PROFILE_INS_COVERAGE|MONO_PROFILE_APPDOMAIN_EVENTS|MONO_PROFILE_CONTEXT_EVENTS|
-               MONO_PROFILE_ASSEMBLY_EVENTS;
+               MONO_PROFILE_ASSEMBLY_EVENTS|MONO_PROFILE_GC_FINALIZATION;
 
        max_allocated_sample_hits = mono_cpu_count () * 1000;
 
@@ -5250,6 +5321,7 @@ mono_profiler_startup (const char *desc)
        mono_profiler_install_allocation (gc_alloc);
        mono_profiler_install_gc_moves (gc_moves);
        mono_profiler_install_gc_roots (gc_handle, gc_roots);
+       mono_profiler_install_gc_finalize (finalize_begin, finalize_object_begin, finalize_object_end, finalize_end);
        mono_profiler_install_appdomain (NULL, domain_loaded, domain_unloaded, NULL);
        mono_profiler_install_appdomain_name (domain_name);
        mono_profiler_install_context (context_loaded, context_unloaded);

diff --git a/mono/profiler/proflog.h b/mono/profiler/proflog.h
index a241bb383ed7d85e7621f60f04c92f0206e1cdcc..96f4fa958d657297e755b95908025ce6340571cb 100644 (file)
--- a/mono/profiler/proflog.h
+++ b/mono/profiler/proflog.h
@@ -52,6 +52,7 @@
                    TYPE_COVERAGE_ASSEMBLY
                moved the time field in TYPE_SAMPLE_HIT to right after the event byte, now encoded as a regular time field
                changed the time field in TYPE_SAMPLE_COUNTERS to be encoded as a regular time field (in nanoseconds)
+               added TYPE_GC_FINALIZE_{START,END,OBJECT_START,OBJECT_END}
  */
 
 enum {
@@ -89,6 +90,10 @@ enum {
        TYPE_GC_HANDLE_DESTROYED    = 5 << 4,
        TYPE_GC_HANDLE_CREATED_BT   = 6 << 4,
        TYPE_GC_HANDLE_DESTROYED_BT = 7 << 4,
+       TYPE_GC_FINALIZE_START = 8 << 4,
+       TYPE_GC_FINALIZE_END = 9 << 4,
+       TYPE_GC_FINALIZE_OBJECT_START = 10 << 4,
+       TYPE_GC_FINALIZE_OBJECT_END = 11 << 4,
        /* extended type for TYPE_METHOD */
        TYPE_LEAVE     = 1 << 4,
        TYPE_ENTER     = 2 << 4,