8223961: ZGC: Unexpected behaviour due to ZMetronome::wait_for_tick() oversleeping
authorpliden
Fri, 17 May 2019 12:06:03 +0200
changeset 54922 185ffc45593c
parent 54921 be1cbfd81ea1
child 54923 23837d614c17
8223961: ZGC: Unexpected behaviour due to ZMetronome::wait_for_tick() oversleeping Reviewed-by: pliden, stefank Contributed-by: fujie@loongson.cn, per.liden@oracle.com
src/hotspot/share/gc/z/zMetronome.cpp
src/hotspot/share/gc/z/zMetronome.hpp
src/hotspot/share/gc/z/zStat.cpp
--- a/src/hotspot/share/gc/z/zMetronome.cpp	Fri May 17 11:44:44 2019 +0200
+++ b/src/hotspot/share/gc/z/zMetronome.cpp	Fri May 17 12:06:03 2019 +0200
@@ -34,10 +34,6 @@
     _nticks(0),
     _stopped(false) {}
 
-uint64_t ZMetronome::nticks() const {
-  return _nticks;
-}
-
 bool ZMetronome::wait_for_tick() {
   if (_nticks++ == 0) {
     // First tick, set start time
@@ -45,7 +41,9 @@
     _start_ms = TimeHelper::counter_to_millis(now.value());
   }
 
-  for (;;) {
+  MonitorLocker ml(&_monitor, Monitor::_no_safepoint_check_flag);
+
+  while (!_stopped) {
     // We might wake up spuriously from wait, so always recalculate
     // the timeout after a wakeup to see if we need to wait again.
     const Ticks now = Ticks::now();
@@ -53,15 +51,27 @@
     const uint64_t next_ms = _start_ms + (_interval_ms * _nticks);
     const int64_t timeout_ms = next_ms - now_ms;
 
-    MonitorLocker ml(&_monitor, Monitor::_no_safepoint_check_flag);
-    if (!_stopped && timeout_ms > 0) {
+    if (timeout_ms > 0) {
       // Wait
       ml.wait(timeout_ms);
     } else {
       // Tick
-      return !_stopped;
+      if (timeout_ms < 0) {
+        const uint64_t overslept = -timeout_ms;
+        if (overslept > _interval_ms) {
+          // Missed one or more ticks. Bump _nticks accordingly to
+          // avoid firing a string of immediate ticks to make up
+          // for the ones we missed.
+          _nticks += overslept / _interval_ms;
+        }
+      }
+
+      return true;
     }
   }
+
+  // Stopped
+  return false;
 }
 
 void ZMetronome::stop() {
--- a/src/hotspot/share/gc/z/zMetronome.hpp	Fri May 17 11:44:44 2019 +0200
+++ b/src/hotspot/share/gc/z/zMetronome.hpp	Fri May 17 12:06:03 2019 +0200
@@ -38,7 +38,6 @@
 public:
   ZMetronome(uint64_t hz);
 
-  uint64_t nticks() const;
   bool wait_for_tick();
   void stop();
 };
--- a/src/hotspot/share/gc/z/zStat.cpp	Fri May 17 11:44:44 2019 +0200
+++ b/src/hotspot/share/gc/z/zStat.cpp	Fri May 17 12:06:03 2019 +0200
@@ -850,7 +850,16 @@
 }
 
 bool ZStat::should_print(LogTargetHandle log) const {
-  return log.is_enabled() && (_metronome.nticks() % ZStatisticsInterval == 0);
+  static uint64_t print_at = ZStatisticsInterval;
+  const uint64_t now = os::elapsedTime();
+
+  if (now < print_at) {
+    return false;
+  }
+
+  print_at = ((now / ZStatisticsInterval) * ZStatisticsInterval) + ZStatisticsInterval;
+
+  return log.is_enabled();
 }
 
 void ZStat::print(LogTargetHandle log, const ZStatSamplerHistory* history) const {