Additional and adjusted logging for parallel minor GC. (mono/mono#17522)

* Additional and adjusted logging for parallel minor GC.

When running parallel minor GC we currently get incorrect timing
on several loggings and counters due to work being put on thread pool
and accumulated. This commit fix so that the logging is accurate
when running with and without parallelization. In parallel mode a new
logging is also added to show the accumulated split between major and los
remset scan jobs.

The counters time_minor_scan_remsets and time_minor_scan_roots are only
updated when not running parallel GC since they are not correct when
running parallel GC.

* Fix WASM build error.

Commit migrated from https://github.com/mono/mono/commit/c5edcd1ed443ae5b960d8f8972b0850b7999e44a

diff --git a/src/mono/mono/sgen/sgen-gc.c b/src/mono/mono/sgen/sgen-gc.c
index 7b5f7d8..9d41931 100644 (file)
--- a/src/mono/mono/sgen/sgen-gc.c
+++ b/src/mono/mono/sgen/sgen-gc.c
@@ -1777,13 +1777,18 @@ collect_nursery (const char *reason, gboolean is_overflow)
        sgen_client_pinning_end ();
 
        remset.start_scan_remsets ();
+       TV_GETTIME (btv);
 
-       enqueue_scan_remembered_set_jobs (&gc_thread_gray_queue, is_parallel ? NULL : object_ops_nopar, is_parallel);
+       SGEN_LOG (2, "Minor scan copy/clear remsets: %lld usecs", (long long)(TV_ELAPSED (atv, btv) / 10));
 
-       /* we don't have complete write barrier yet, so we scan all the old generation sections */
+       TV_GETTIME (atv);
+       enqueue_scan_remembered_set_jobs (&gc_thread_gray_queue, is_parallel ? NULL : object_ops_nopar, is_parallel);
        TV_GETTIME (btv);
-       time_minor_scan_remsets += TV_ELAPSED (atv, btv);
-       SGEN_LOG (2, "Old generation scan: %lld usecs", (long long)(TV_ELAPSED (atv, btv) / 10));
+
+       if (!is_parallel) {
+               time_minor_scan_remsets += TV_ELAPSED (atv, btv);
+               SGEN_LOG (2, "Minor scan remsets: %lld usecs", (long long)(TV_ELAPSED (atv, btv)/10));
+       }
 
        sgen_pin_stats_report ();
        sgen_gchandle_stats_report ();
@@ -1800,7 +1805,20 @@ collect_nursery (const char *reason, gboolean is_overflow)
        }
 
        TV_GETTIME (btv);
-       time_minor_scan_roots += TV_ELAPSED (atv, btv);
+       if (!is_parallel) {
+               time_minor_scan_roots += TV_ELAPSED (atv, btv);
+
+               SGEN_LOG (2, "Minor scan roots: %lld usecs",
+                       (long long)(TV_ELAPSED (atv, btv) / 10));
+       } else {
+               SGEN_LOG (2, "Minor scan remsets + roots: %lld usecs",
+                       (long long)(TV_ELAPSED (atv, btv) / 10));
+
+               SGEN_LOG (2, "Minor scan remsets: accumulated major scan=%lld usecs, accumulated los scan=%lld usecs, workers=%d",
+                       (long long)((time_minor_scan_major_blocks - major_scan_start) / 10),
+                       (long long)((time_minor_scan_los - los_scan_start) / 10),
+                       sgen_workers_get_active_worker_count (GENERATION_NURSERY));
+       }
 
        finish_gray_stack (GENERATION_NURSERY, ctx);
 

diff --git a/src/mono/mono/sgen/sgen-workers.c b/src/mono/mono/sgen/sgen-workers.c
index 292e117..a8897d9 100644 (file)
--- a/src/mono/mono/sgen/sgen-workers.c
+++ b/src/mono/mono/sgen/sgen-workers.c
@@ -593,6 +593,12 @@ sgen_workers_get_job_split_count (int generation)
        return (worker_contexts [generation].active_workers_num > 1) ? worker_contexts [generation].active_workers_num * 4 : 1;
 }
 
+int
+sgen_workers_get_active_worker_count (int generation)
+{
+       return (worker_contexts [generation].active_workers_num);
+}
+
 void
 sgen_workers_foreach (int generation, SgenWorkerCallback callback)
 {
@@ -651,6 +657,12 @@ sgen_workers_get_job_split_count (int generation)
        return 1;
 }
 
+int
+sgen_workers_get_active_worker_count (int generation)
+{
+       return 0;
+}
+
 gboolean
 sgen_workers_have_idle_work (int generation)
 {

diff --git a/src/mono/mono/sgen/sgen-workers.h b/src/mono/mono/sgen/sgen-workers.h
index e3147f0..14e68c9 100644 (file)
--- a/src/mono/mono/sgen/sgen-workers.h
+++ b/src/mono/mono/sgen/sgen-workers.h
@@ -87,6 +87,7 @@ void sgen_workers_assert_gray_queue_is_empty (int generation);
 void sgen_workers_take_from_queue (int generation, SgenGrayQueue *queue);
 SgenObjectOperations* sgen_workers_get_idle_func_object_ops (WorkerData *worker);
 int sgen_workers_get_job_split_count (int generation);
+int sgen_workers_get_active_worker_count (int generation);
 void sgen_workers_foreach (int generation, SgenWorkerCallback callback);
 gboolean sgen_workers_is_worker_thread (MonoNativeThreadId id);