[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 5c847572e8d7f7a61a502567fe0f08bf62763450..46acfc67f0aa8a6cca23bd42c3b281e6ac14a766 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 0bd1d21ffc7f2de711898196563ad2023da2306a..5b05310625a7c79b4d62f5bf634c9e730ac4094f 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) MONO_INTERNAL;
 
 void mono_gc_register_altstack (gpointer stack, gint32 stack_size, gpointer altstack, gint32 altstack_size) MONO_INTERNAL;
 
+/* 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 4c5d5967181011a620f17d16f47d85dab18f2bad..84a673d47db2bb02d18c5fcbe0dad309974bb8ca 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 10a0a142bd8afd5c01391ebd3eeae80bfeec03a8..b586cff4607f51a3cd74b9707ff09fc9a94ae2e9 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
@@ -3692,8 +3690,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;
@@ -5075,6 +5072,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);
 
@@ -5106,6 +5105,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");