Merge pull request #1606 from alexanderkyte/debug-finalizers

[Runtime] Added logging around finalizers

diff --git a/man/mono.1 b/man/mono.1
index 07f7192b75d92f72a8ebaa6a23ee63af3dca2536..3c762c110416a888653a4623bf4ec1a4f24b25c9 100644 (file)
--- a/man/mono.1
+++ b/man/mono.1
@@ -1283,14 +1283,13 @@ work, Mono needs to be compiled with the BINARY_PROTOCOL define on
 sgen-gc.c.   You can then use this command to explore the output
 .nf
                 sgen-grep-binprot 0x1234 0x5678 < file
+.fi
 .TP
 \fBnursery-canaries\fR
 If set, objects allocated in the nursery are suffixed with a canary (guard)
 word, which is checked on each minor collection. Can be used to detect/debug
 heap corruption issues.
-.fi
-.ne
-.RE
+
 .TP
 \fBdo-not-finalize\fR
 If enabled, finalizers will not be run.  Everything else will be
@@ -1298,7 +1297,10 @@ unaffected: finalizable objects will still be put into the
 finalization queue where they survive until they're scheduled to
 finalize.  Once they're not in the queue anymore they will be
 collected regularly.
-.fi
+
+.TP
+\fBlog-finalizers\fR
+Log verbosely around the finalization process to aid debugging.
 .ne
 .RE
 .TP

diff --git a/mono/metadata/boehm-gc.c b/mono/metadata/boehm-gc.c
index b7f9b7c49538794e23c9a36e7e84a87afb432742..59ca03b80adfd38d3129480c03375bb59b19bbae 100644 (file)
--- a/mono/metadata/boehm-gc.c
+++ b/mono/metadata/boehm-gc.c
@@ -148,7 +148,22 @@ mono_gc_base_init (void)
        /* If GC_no_dls is set to true, GC_find_limit is not called. This causes a seg fault on Android. */
        GC_no_dls = TRUE;
 #endif
+       {
+               if ((env = g_getenv ("MONO_GC_DEBUG"))) {
+                       char **opts = g_strsplit (env, ",", -1);
+                       for (char **ptr = opts; ptr && *ptr; ptr ++) {
+                               char *opt = *ptr;
+                               if (!strcmp (opt, "do-not-finalize")) {
+                                       do_not_finalize = 1;
+                               } else if (!strcmp (opt, "log-finalizers")) {
+                                       log_finalizers = 1;
+                               }
+                       }
+               }
+       }
+
        GC_init ();
+
        GC_oom_fn = mono_gc_out_of_memory;
        GC_set_warn_proc (mono_gc_warning);
        GC_finalize_on_demand = 1;

diff --git a/mono/metadata/gc-internal.h b/mono/metadata/gc-internal.h
index de78a3093919d3a2e24c2e6cd939d60d9b1c1ad2..6e8c7351ce629398bc412c61a8718b4f78bdbb8a 100644 (file)
--- a/mono/metadata/gc-internal.h
+++ b/mono/metadata/gc-internal.h
@@ -390,5 +390,11 @@ guint mono_gc_get_vtable_bits (MonoClass *klass);
 
 void mono_gc_register_altstack (gpointer stack, gint32 stack_size, gpointer altstack, gint32 altstack_size);
 
+/* If set, print debugging messages around finalizers. */
+extern gboolean log_finalizers;
+
+/* If set, do not run finalizers. */
+extern gboolean do_not_finalize;
+
 #endif /* __MONO_METADATA_GC_INTERNAL_H__ */
 

diff --git a/mono/metadata/gc.c b/mono/metadata/gc.c
index b2f17354eaa9b53400ffc4aefbbd0ea2d4eb08b9..30179bd9fbaa61bd00f982b0db376fcd16b1ebbd 100644 (file)
--- a/mono/metadata/gc.c
+++ b/mono/metadata/gc.c
@@ -59,6 +59,9 @@ static gboolean gc_disabled = FALSE;
 
 static gboolean finalizing_root_domain = FALSE;
 
+gboolean log_finalizers = FALSE;
+gboolean do_not_finalize = FALSE;
+
 #define mono_finalizer_lock() mono_mutex_lock (&finalizer_mutex)
 #define mono_finalizer_unlock() mono_mutex_unlock (&finalizer_mutex)
 static mono_mutex_t finalizer_mutex;
@@ -101,6 +104,9 @@ static gboolean suspend_finalizers = FALSE;
 void
 mono_gc_run_finalize (void *obj, void *data)
 {
+       if (do_not_finalize)
+               return;
+
        MonoObject *exc = NULL;
        MonoObject *o;
 #ifndef HAVE_SGEN_GC
@@ -113,6 +119,9 @@ mono_gc_run_finalize (void *obj, void *data)
 
        o = (MonoObject*)((char*)obj + GPOINTER_TO_UINT (data));
 
+       if (log_finalizers)
+               g_log ("mono-gc-finalizers", G_LOG_LEVEL_DEBUG, "<%s at %p> Starting finalizer checks.", o->vtable->klass->name, o);
+
        if (suspend_finalizers)
                return;
 
@@ -133,6 +142,9 @@ mono_gc_run_finalize (void *obj, void *data)
        /* make sure the finalizer is not called again if the object is resurrected */
        object_register_finalizer (obj, NULL);
 
+       if (log_finalizers)
+               g_log ("mono-gc-finalizers", G_LOG_LEVEL_MESSAGE, "<%s at %p> Registered finalizer as processed.", o->vtable->klass->name, o);
+
        if (o->vtable->klass == mono_defaults.internal_thread_class) {
                MonoInternalThread *t = (MonoInternalThread*)o;
 
@@ -201,6 +213,9 @@ mono_gc_run_finalize (void *obj, void *data)
         * create and precompile a wrapper which calls the finalize method using
         * a CALLVIRT.
         */
+       if (log_finalizers)
+               g_log ("mono-gc-finalizers", G_LOG_LEVEL_MESSAGE, "<%s at %p> Compiling finalizer.", o->vtable->klass->name, o);
+
        if (!domain->finalize_runtime_invoke) {
                MonoMethod *invoke = mono_marshal_get_runtime_invoke (mono_class_get_method_from_name_flags (mono_defaults.object_class, "Finalize", 0, 0), TRUE);
 
@@ -216,8 +231,14 @@ mono_gc_run_finalize (void *obj, void *data)
                                o->vtable->klass->name_space, o->vtable->klass->name);
        }
 
+       if (log_finalizers)
+               g_log ("mono-gc-finalizers", G_LOG_LEVEL_MESSAGE, "<%s at %p> Calling finalizer.", o->vtable->klass->name, o);
+
        runtime_invoke (o, NULL, &exc, NULL);
 
+       if (log_finalizers)
+               g_log ("mono-gc-finalizers", G_LOG_LEVEL_MESSAGE, "<%s at %p> Returned from finalizer.", o->vtable->klass->name, o);
+
        if (exc)
                mono_internal_thread_unhandled_exception (exc);
 

diff --git a/mono/metadata/sgen-gc.c b/mono/metadata/sgen-gc.c
index a080e9fcf1dc4fb80edbb370421bee736fa57edc..6db0c4e79ea13fa086aed215e694ab08a732e695 100644 (file)
--- a/mono/metadata/sgen-gc.c
+++ b/mono/metadata/sgen-gc.c
@@ -278,8 +278,6 @@ static gboolean conservative_stack_mark = FALSE;
 /* If set, do a plausibility check on the scan_starts before and after
    each collection */
 static gboolean do_scan_starts_check = FALSE;
-/* If set, do not run finalizers. */
-static gboolean do_not_finalize = FALSE;
 
 /*
  * If the major collector is concurrent and this is FALSE, we will
@@ -3682,8 +3680,7 @@ mono_gc_invoke_finalizers (void)
                count++;
                /* the object is on the stack so it is pinned */
                /*g_print ("Calling finalizer for object: %p (%s)\n", entry->object, safe_name (entry->object));*/
-               if (!do_not_finalize)
-                       mono_gc_run_finalize (obj, NULL);
+               mono_gc_run_finalize (obj, NULL);
        }
        g_assert (!entry);
        return count;
@@ -5063,6 +5060,8 @@ mono_gc_base_init (void)
                                enable_nursery_canaries = TRUE;
                        } else if (!strcmp (opt, "do-not-finalize")) {
                                do_not_finalize = TRUE;
+                       } else if (!strcmp (opt, "log-finalizers")) {
+                               log_finalizers = TRUE;
                        } else if (!sgen_bridge_handle_gc_debug (opt)) {
                                sgen_env_var_error (MONO_GC_DEBUG_NAME, "Ignoring.", "Unknown option `%s`.", opt);
 
@@ -5094,6 +5093,7 @@ mono_gc_base_init (void)
                                fprintf (stderr, "  binary-protocol=<filename>[:<file-size-limit>]\n");
                                fprintf (stderr, "  nursery-canaries\n");
                                fprintf (stderr, "  do-not-finalize\n");
+                               fprintf (stderr, "  log-finalizers\n");
                                sgen_bridge_print_gc_debug_usage ();
                                fprintf (stderr, "\n");