RFR: 8223961: ZGC: Unexpected behaviour was observed caused by the incorrect update of _nticks in ZMetronome::wait_for_tick()

[Per Liden]

A slight refinement and also removing ZMetronome::nticks() as it's not 
very useful anymore.

http://cr.openjdk.java.net/~pliden/8223961/webrev.0

/Per

On 5/17/19 8:14 AM, Per Liden wrote:
> Let's wait for a second Reviewer to give thumbs up, then I'll go ahead 
> and sponsor/push this.
> 
> cheers,
> Per
> 
> On 5/16/19 11:21 AM, Jie Fu wrote:
>> It's much clearer and more reasonable.
>> I like your patch.
>> Thanks Per.
>>
>> On 2019/5/16 下午4:40, Per Liden wrote:
>>> On 05/16/2019 08:25 AM, Per Liden wrote:
>>>> Hi,
>>>>
>>>> There is code in ZStat that assumes ZMetronome::ntick() never skips 
>>>> over ticks. That would need to be addressed if we do something like 
>>>> this. Otherwise we risk not getting statistics print outs just 
>>>> because the metronome overslept. I'll take a look at it.
>>>
>>> I was thinking something like this:
>>>
>>> diff --git a/src/hotspot/share/gc/z/zMetronome.cpp 
>>> b/src/hotspot/share/gc/z/zMetronome.cpp
>>> --- a/src/hotspot/share/gc/z/zMetronome.cpp
>>> +++ b/src/hotspot/share/gc/z/zMetronome.cpp
>>> @@ -45,7 +45,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 +55,24 @@
>>>      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 < -_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 += -timeout_ms / _interval_ms;
>>> +      }
>>> +
>>> +      return true;
>>>      }
>>>    }
>>> +
>>> +  // Stopped
>>> +  return false;
>>>  }
>>>
>>>  void ZMetronome::stop() {
>>> diff --git a/src/hotspot/share/gc/z/zMetronome.hpp 
>>> b/src/hotspot/share/gc/z/zMetronome.hpp
>>> --- a/src/hotspot/share/gc/z/zMetronome.hpp
>>> +++ b/src/hotspot/share/gc/z/zMetronome.hpp
>>> @@ -29,11 +29,11 @@
>>>
>>>  class ZMetronome : public StackObj {
>>>  private:
>>> -  Monitor        _monitor;
>>> -  const uint64_t _interval_ms;
>>> -  uint64_t       _start_ms;
>>> -  uint64_t       _nticks;
>>> -  bool           _stopped;
>>> +  Monitor       _monitor;
>>> +  const int64_t _interval_ms;
>>> +  uint64_t      _start_ms;
>>> +  uint64_t      _nticks;
>>> +  bool          _stopped;
>>>
>>>  public:
>>>    ZMetronome(uint64_t hz);
>>> diff --git a/src/hotspot/share/gc/z/zStat.cpp 
>>> b/src/hotspot/share/gc/z/zStat.cpp
>>> --- a/src/hotspot/share/gc/z/zStat.cpp
>>> +++ b/src/hotspot/share/gc/z/zStat.cpp
>>> @@ -850,7 +850,16 @@
>>>  }
>>>
>>>  bool ZStat::should_print(LogTargetHandle log) const {
>>> -  return log.is_enabled() && (_metronome.nticks() % 
>>> ZStatisticsInterval == 0);
>>> +  static uint64_t print_at_nticks = ZStatisticsInterval;
>>> +  uint64_t nticks = _metronome.nticks();
>>> +
>>> +  if (nticks < print_at_nticks) {
>>> +    return false;
>>> +  }
>>> +
>>> +  print_at_nticks = ((nticks / ZStatisticsInterval) * 
>>> ZStatisticsInterval) + ZStatisticsInterval;
>>> +
>>> +  return log.is_enabled();
>>>  }
>>>
>>>  void ZStat::print(LogTargetHandle log, const ZStatSamplerHistory* 
>>> history) const {
>>>
>>>
>>> cheers,
>>> Per
>>>
>>>>
>>>> cheers,
>>>> Per
>>>>
>>>> On 05/15/2019 04:33 PM, Jie Fu wrote:
>>>>> Hi all,
>>>>>
>>>>> JBS: https://bugs.openjdk.java.net/browse/JDK-8223961
>>>>>
>>>>> Please review the following patch which fixes the update of 
>>>>> "_nticks" in ZMetronome::wait_for_tick()
>>>>> -----------------------------------
>>>>> diff -r b0b20413d853 src/hotspot/share/gc/z/zMetronome.cpp
>>>>> --- a/src/hotspot/share/gc/z/zMetronome.cpp     Wed May 15 11:53:47 
>>>>> 2019 +0200
>>>>> +++ b/src/hotspot/share/gc/z/zMetronome.cpp     Wed May 15 20:15:39 
>>>>> 2019 +0800
>>>>> @@ -57,6 +57,8 @@
>>>>>       if (!_stopped && timeout_ms > 0) {
>>>>>         // Wait
>>>>>         ml.wait(timeout_ms);
>>>>> +    } else if (timeout_ms < -1 * (int64_t)_interval_ms) {
>>>>> +      _nticks += -timeout_ms / _interval_ms;
>>>>>       } else {
>>>>>         // Tick
>>>>>         return !_stopped;
>>>>> -----------------------------------
>>>>> For more info, please see the JBS.
>>>>>
>>>>> Testing:
>>>>>    - make test TEST="hotspot_gc" CONF=release
>>>>>
>>>>> Thanks a lot.
>>>>> Best regards,
>>>>> Jie
>>>>>
>>>>>
>>