GC measurement feature

* `GC.measure_total_time = true` enables total time measurement (default: true)
* `GC.measure_total_time` returns current flag.
* `GC.total_time` returns measured total time in nano seconds.
* `GC.stat(:time)` (and Hash) returns measured total time in milli seconds.

1 files changed, 60 insertions, 37 deletions

diff --git a/gc.c b/gc.c
index 1029306cfd..0bb44d24ae 100644
--- a/gc.c
+++ b/gc.c
@@ -732,6 +732,7 @@ typedef struct rb_objspace {
 #if GC_ENABLE_INCREMENTAL_MARK
 	unsigned int during_incremental_marking : 1;
 #endif
+        unsigned int measure_gc : 1;
     } flags;
 
     rb_event_flag_t hook_events;
@@ -807,7 +808,7 @@ typedef struct rb_objspace {
 	size_t total_freed_objects;
 	size_t total_allocated_pages;
 	size_t total_freed_pages;
-        size_t total_time_ns;
+        uint64_t total_time_ns;
         struct timespec start_time;
     } profile;
     struct gc_list *global_list;
@@ -1718,6 +1719,7 @@ rb_objspace_t *
 rb_objspace_alloc(void)
 {
     rb_objspace_t *objspace = calloc1(sizeof(rb_objspace_t));
+    objspace->flags.measure_gc = 1;
     malloc_limit = gc_params.malloc_limit_min;
 
     for (int i = 0; i < SIZE_POOL_COUNT; i++) {
@@ -9165,10 +9167,12 @@ gc_enter_count(enum gc_enter_event event)
     }
 }
 
-#define MEASURE_GC 1
+#ifndef MEASURE_GC
+#define MEASURE_GC (objspace->flags.measure_gc)
+#endif
 
 static bool
-gc_enter_event_measure_p(enum gc_enter_event event)
+gc_enter_event_measure_p(rb_objspace_t *objspace, enum gc_enter_event event)
 {
     if (!MEASURE_GC) return false;
 
@@ -9178,33 +9182,47 @@ gc_enter_event_measure_p(enum gc_enter_event event)
       case gc_enter_event_sweep_continue:
       case gc_enter_event_rest:
         return true;
-      case gc_enter_event_finalizer:
-      case gc_enter_event_rb_memerror:
+
+      default:
+        // case gc_enter_event_finalizer:
+        // case gc_enter_event_rb_memerror:
         return false;
     }
 }
 
+static bool current_process_time(struct timespec *ts);
+
 static void
 gc_enter_clock(rb_objspace_t *objspace, enum gc_enter_event event)
 {
-    if (gc_enter_event_measure_p(event)) {
-        clock_gettime(CLOCK_MONOTONIC, &objspace->profile.start_time);
+    if (gc_enter_event_measure_p(objspace, event)) {
+        if (!current_process_time(&objspace->profile.start_time)) {
+            objspace->profile.start_time.tv_sec = 0;
+            objspace->profile.start_time.tv_nsec = 0;
+        }
     }
 }
 
 static void
 gc_exit_clock(rb_objspace_t *objspace, enum gc_enter_event event)
 {
-    if (gc_enter_event_measure_p(event)) {
+    if (gc_enter_event_measure_p(objspace, event)) {
         struct timespec end_time;
 
-        clock_gettime(CLOCK_MONOTONIC, &end_time);
-        if (end_time.tv_sec < objspace->profile.start_time.tv_sec) {
-            return; // ignore
-        }
-        size_t ns = (end_time.tv_sec - objspace->profile.start_time.tv_sec) * 1000 * 1000 * 1000 + end_time.tv_nsec - objspace->profile.start_time.tv_nsec;
+        if ((objspace->profile.start_time.tv_sec > 0 ||
+             objspace->profile.start_time.tv_nsec > 0) &&
+            current_process_time(&end_time)) {
 
-        objspace->profile.total_time_ns += ns;
+            if (end_time.tv_sec < objspace->profile.start_time.tv_sec) {
+                return; // ignore
+            }
+            else {
+                uint64_t ns =
+                  (uint64_t)(end_time.tv_sec - objspace->profile.start_time.tv_sec) * (1000 * 1000 * 1000) +
+                            (end_time.tv_nsec - objspace->profile.start_time.tv_nsec);
+                objspace->profile.total_time_ns += ns;
+            }
+        }
     }
 }
 
@@ -12411,16 +12429,14 @@ wmap_size(VALUE self)
 
 #define GC_PROFILE_RECORD_DEFAULT_SIZE 100
 
-/* return sec in user time */
-static double
-getrusage_time(void)
+static bool
+current_process_time(struct timespec *ts)
 {
 #if defined(HAVE_CLOCK_GETTIME) && defined(CLOCK_PROCESS_CPUTIME_ID)
     {
         static int try_clock_gettime = 1;
-        struct timespec ts;
-        if (try_clock_gettime && clock_gettime(CLOCK_PROCESS_CPUTIME_ID, &ts) == 0) {
-            return ts.tv_sec + ts.tv_nsec * 1e-9;
+        if (try_clock_gettime && clock_gettime(CLOCK_PROCESS_CPUTIME_ID, ts) == 0) {
+            return true;
         }
         else {
             try_clock_gettime = 0;
@@ -12434,7 +12450,9 @@ getrusage_time(void)
         struct timeval time;
         if (getrusage(RUSAGE_SELF, &usage) == 0) {
             time = usage.ru_utime;
-            return time.tv_sec + time.tv_usec * 1e-6;
+            ts->tv_sec = time.tv_sec;
+            ts->tv_nsec = time.tv_usec * 1000;
+            return true;
         }
     }
 #endif
@@ -12442,30 +12460,35 @@ getrusage_time(void)
 #ifdef _WIN32
     {
 	FILETIME creation_time, exit_time, kernel_time, user_time;
-	ULARGE_INTEGER ui;
-	LONG_LONG q;
-	double t;
+        ULARGE_INTEGER ui;
 
-	if (GetProcessTimes(GetCurrentProcess(),
+        if (GetProcessTimes(GetCurrentProcess(),
 			    &creation_time, &exit_time, &kernel_time, &user_time) != 0) {
-	    memcpy(&ui, &user_time, sizeof(FILETIME));
-	    q = ui.QuadPart / 10L;
-	    t = (DWORD)(q % 1000000L) * 1e-6;
-	    q /= 1000000L;
-#ifdef __GNUC__
-	    t += q;
-#else
-	    t += (double)(DWORD)(q >> 16) * (1 << 16);
-	    t += (DWORD)q & ~(~0 << 16);
-#endif
-	    return t;
+            memcpy(&ui, &user_time, sizeof(FILETIME));
+#define PER100NSEC (uint64_t)(1000 * 1000 * 10)
+            ts->tv_nsec = (long)(ui.QuadPart % PER100NSEC);
+            ts->tv_sec  = (time_t)(ui.QuadPart / PER100NSEC);
+            return true;
 	}
     }
 #endif
 
-    return 0.0;
+    return false;
+}
+
+static double
+getrusage_time(void)
+{
+    struct timespec ts;
+    if (current_process_time(&ts)) {
+        return ts.tv_sec + ts.tv_nsec * 1e-9;
+    }
+    else {
+        return 0.0;
+    }
 }
 
+
 static inline void
 gc_prof_setup_new_record(rb_objspace_t *objspace, unsigned int reason)
 {