8386202: Genshen: Regulator thread reporting hiccup times proportional to safepoint times

Reviewed-by: wkemper, kdnilsen

Author: pf0n

src/hotspot/share/gc/shenandoah/shenandoahControlThread.cpp

@@ -221,22 +221,22 @@ void ShenandoahControlThread::run_service() {
     // Wait before performing the next action. If allocation happened during this wait,
     // we exit sooner, to let heuristics re-evaluate new conditions. If we are at idle,
     // back off exponentially.
-    const double before_sleep = most_recent_wake_time;
     if (heap->has_changed()) {
       sleep = ShenandoahControlIntervalMin;
-    } else if ((before_sleep - last_sleep_adjust_time) * 1000 > ShenandoahControlIntervalAdjustPeriod){
+    } else if ((most_recent_wake_time - last_sleep_adjust_time) * 1000 > ShenandoahControlIntervalAdjustPeriod){
       sleep = MIN2<int>(ShenandoahControlIntervalMax, MAX2(1, sleep * 2));
-      last_sleep_adjust_time = before_sleep;
+      last_sleep_adjust_time = most_recent_wake_time;
     }
     MonitorLocker ml(&_control_lock, Mutex::_no_safepoint_check_flag);
+    const double before_sleep_time = os::elapsedTime();
     ml.wait(sleep);
+    most_recent_wake_time = os::elapsedTime();
     // Record a conservative estimate of the longest anticipated sleep duration until we sample again.
     double planned_sleep_interval = MIN2<int>(ShenandoahControlIntervalMax, MAX2(1, sleep * 2)) / 1000.0;
-    most_recent_wake_time = os::elapsedTime();
     heuristics->update_should_start_query_times(most_recent_wake_time, planned_sleep_interval);
     if (LogTarget(Debug, gc, thread)::is_enabled()) {
-      double elapsed = most_recent_wake_time - before_sleep;
-      double hiccup = elapsed - double(sleep);
+      double elapsed = most_recent_wake_time - before_sleep_time;
+      double hiccup = elapsed - double(sleep) / 1000.0;
       if (hiccup > 0.001) {
         log_debug(gc, thread)("Control Thread hiccup time: %.3fs", hiccup);
       }

src/hotspot/share/gc/shenandoah/shenandoahRegulatorThread.cpp

@@ -116,23 +116,21 @@ void ShenandoahRegulatorThread::regulator_sleep() {
   // Wait before performing the next action. If allocation happened during this wait,
   // we exit sooner, to let heuristics re-evaluate new conditions. If we are at idle,
   // back off exponentially.
-  double before_sleep_time = _most_recent_wake_time;
   if (ShenandoahHeap::heap()->has_changed()) {
     _sleep = ShenandoahControlIntervalMin;
-  } else if ((before_sleep_time - _last_sleep_adjust_time) * 1000 > ShenandoahControlIntervalAdjustPeriod){
+  } else if ((_most_recent_wake_time - _last_sleep_adjust_time) * 1000 > ShenandoahControlIntervalAdjustPeriod){
     _sleep = MIN2<uint>(ShenandoahControlIntervalMax, MAX2(1u, _sleep * 2));
-    _last_sleep_adjust_time = before_sleep_time;
+    _last_sleep_adjust_time = _most_recent_wake_time;
   }
 
   SuspendibleThreadSetLeaver leaver;
+  const double before_sleep_time = os::elapsedTime();
   os::naked_short_sleep(_sleep);
-  double wake_time = os::elapsedTime();
-  _most_recent_period = wake_time - _most_recent_wake_time;
-  _most_recent_wake_time = wake_time;
+  _most_recent_wake_time = os::elapsedTime();
   _young_heuristics->update_should_start_query_times(_most_recent_wake_time, double(_sleep) / 1000.0);
   if (LogTarget(Debug, gc, thread)::is_enabled()) {
     double elapsed = _most_recent_wake_time - before_sleep_time;
-    double hiccup = elapsed - double(_sleep);
+    double hiccup = elapsed - double(_sleep) / 1000.0;
     if (hiccup > 0.001) {
       log_debug(gc, thread)("Regulator hiccup time: %.3fs", hiccup);
     }

src/hotspot/share/gc/shenandoah/shenandoahRegulatorThread.hpp

@@ -82,7 +82,6 @@ class ShenandoahRegulatorThread: public ConcurrentGCThread {
   // duration of planned regulator sleep period, in ms
   uint _sleep;
   double _most_recent_wake_time;
-  double _most_recent_period;
   double _last_sleep_adjust_time;
 };