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

[Per Liden]

Thanks Stefan!

/Per

On 5/17/19 10:05 AM, Stefan Karlsson wrote:
> Looks good.
> 
> StefanK
> 
> On 2019-05-17 10:03, Per Liden wrote:
>> 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
>>>>>>>
>>>>>>>
>>>>