Nagios is triggered with: CRITICAL: offset is out of range (nan) - must be between -0.050000 and 0.050000 about ntpmon HOT 3 CLOSED

juju run-action ntp/18 diagnostics --wait
unit-ntp-18:
id: cc6fdaab-b40d-4952-8c14-44330192ef84
results:
kernel:
clocksource0:
available: tsc hpet acpi_pm
current: tsc
release: 4.15.0-47-generic
ntp:
implementation: chrony
log:
measurements: |-
2019-09-05 06:34:59 216.228.192.52 N 2 111 111 1111 10 10 0.66 -3.572e-03 6.332e-02 1.038e-06 3.204e-04 7.339e-03 D8E4C035 4B K K
2019-09-05 06:35:23 69.41.163.31 N 2 111 111 1111 6 6 0.77 1.338e-03 8.176e-03 1.966e-07 7.584e-03 1.221e-02 8B4E6180 4B K K
2019-09-05 06:35:43 10.20.113.20 N 4 111 111 1111 7 7 0.70 5.124e-03 1.158e-04 3.144e-07 1.237e-01 1.387e-01 0AE0A002 4B K K
2019-09-05 06:36:27 69.41.163.31 N 2 111 111 1111 6 6 0.89 1.452e-03 7.918e-03 1.966e-07 7.584e-03 1.317e-02 8B4E6180 4B K K
2019-09-05 06:36:35 98.191.213.7 N 1 111 111 1111 10 10 1.00 -1.597e-03 5.436e-02 1.030e-06 0.000e+00 4.120e-04 47505300 4B K K
2019-09-05 06:37:01 91.189.94.4 N 2 111 111 1111 10 10 0.85 1.251e-03 1.080e-01 2.296e-07 8.545e-03 3.369e-02 11FD6CFD 4B K K
2019-09-05 06:37:32 69.41.163.31 N 2 111 111 1111 7 6 0.03 1.475e-03 8.002e-03 1.969e-07 7.584e-03 1.414e-02 8B4E6180 4B K K
2019-09-05 06:37:39 198.58.105.63 N 2 111 111 1111 8 8 0.31 2.813e-03 8.384e-03 1.983e-07 3.146e-02 4.491e-02 8E42650D 4B K K
2019-09-05 06:37:44 204.11.201.12 N 2 111 111 1111 10 10 1.00 7.346e-04 6.594e-02 1.367e-07 2.174e-02 3.551e-02 D8DAFECA 4B K K
2019-09-05 06:37:53 10.20.113.20 N 4 111 111 1111 7 7 0.26 5.194e-03 6.119e-05 3.144e-07 1.237e-01 1.406e-01 0AE0A002 4B K K
statistics: |-
2019-09-05 06:34:59 216.228.192.52 4.274e-05 2.123e-03 2.825e-05 1.032e-07 7.204e-08 2.0e-01 7 0 5 0.50
2019-09-05 06:35:23 69.41.163.31 4.474e-05 -1.538e-03 1.965e-05 -6.804e-08 1.726e-07 1.6e-01 15 0 11 0.50
2019-09-05 06:35:43 10.20.113.20 8.703e-06 -5.121e-03 6.026e-06 -1.363e-07 4.761e-08 3.1e-02 10 0 7 0.00
2019-09-05 06:36:27 69.41.163.31 6.058e-05 -1.541e-03 2.480e-05 5.031e-09 2.043e-07 4.7e-01 16 0 9 0.50
2019-09-05 06:36:35 98.191.213.7 2.443e-04 -7.790e-04 7.511e-05 1.933e-09 1.430e-08 2.9e-02 32 0 16 0.47
2019-09-05 06:37:01 91.189.94.4 2.827e-04 -1.432e-03 3.164e-04 3.310e-08 3.765e-07 4.4e-01 7 1 3 0.00
2019-09-05 06:37:32 69.41.163.31 5.847e-05 -1.541e-03 2.339e-05 1.379e-08 1.803e-07 5.9e-02 17 0 9 0.50
2019-09-05 06:37:39 198.58.105.63 8.152e-05 -2.773e-03 5.726e-05 5.651e-07 3.002e-07 3.4e-02 8 0 5 0.00
2019-09-05 06:37:44 204.11.201.12 3.902e-04 -2.160e-03 1.231e-04 -1.760e-08 1.625e-08 2.6e-02 45 0 23 0.41
2019-09-05 06:37:53 10.20.113.20 1.413e-05 -5.180e-03 8.011e-06 -1.784e-07 6.378e-08 8.0e-01 11 1 7 0.00
tracking: |-
2019-09-05 06:27:50 69.41.163.31 3 -14.936 0.007 4.525e-05 N 10 2.457e-03 -1.627e-04 1.586e-02 1.110e-02 1.928e-02
2019-09-05 06:28:55 69.41.163.31 3 -14.936 0.007 -2.544e-06 N 10 2.473e-03 -1.963e-04 1.586e-02 1.104e-02 1.931e-02
2019-09-05 06:29:59 69.41.163.31 3 -14.934 0.008 7.532e-06 N 10 2.448e-03 -1.837e-04 1.586e-02 1.104e-02 1.922e-02
2019-09-05 06:31:03 69.41.163.31 3 -14.934 0.007 -2.497e-06 N 10 2.464e-03 -1.813e-04 1.586e-02 1.099e-02 1.922e-02
2019-09-05 06:32:09 69.41.163.31 3 -14.934 0.007 1.470e-06 N 10 2.467e-03 -1.700e-04 1.586e-02 1.099e-02 1.917e-02
2019-09-05 06:33:14 69.41.163.31 3 -14.934 0.006 -8.165e-06 N 10 2.451e-03 -1.635e-04 1.553e-02 1.027e-02 1.915e-02
2019-09-05 06:34:19 69.41.163.31 3 -14.934 0.007 3.765e-06 N 10 2.464e-03 -1.488e-04 1.553e-02 1.028e-02 1.826e-02
2019-09-05 06:35:23 69.41.163.31 3 -14.926 0.011 3.529e-05 N 10 2.465e-03 -1.464e-04 1.553e-02 1.029e-02 1.826e-02
2019-09-05 06:36:27 69.41.163.31 3 -14.923 0.008 8.981e-06 N 10 2.444e-03 -1.727e-04 1.553e-02 1.031e-02 1.830e-02
2019-09-05 06:37:32 69.41.163.31 3 -14.922 0.007 3.750e-06 N 10 2.439e-03 -1.726e-04 1.553e-02 1.032e-02 1.832e-02
sources: "210 Number of sources = 21\nMS Name/IP address Stratum Poll
Reach LastRx Last sample \n===============================================================================\n^-
10.20.113.20 4 7 377 10 -5194us[-5194us] +/- 203ms\n^+
74.117.214.3 1 10 377 38m -1256us[-1082us] +/- 39ms\n^-
204.11.201.12 2 10 377 19 -735us[ -735us] +/- 79ms\n^+
69.89.207.199 2 10 377 343 +2109us[+2150us] +/- 77ms\n^-
199.223.248.100 2 10 377 497 -3941us[-3895us] +/- 109ms\n^+
72.30.35.88 2 10 377 663 +2142us[+2229us] +/- 26ms\n^-
69.164.202.202 3 9 377 519 -1558us[-1512us] +/- 91ms\n^-
74.117.214.2 2 10 377 33m -1096us[ -807us] +/- 70ms\n^+
98.191.213.7 1 10 377 88 +1594us[+1597us] +/- 28ms\n^-
4.53.160.75 2 10 377 776 +2696us[+2808us] +/- 52ms\n^+
216.228.192.52 2 10 377 184 +3525us[+3572us] +/- 39ms\n^+
66.228.42.59 3 9 377 205 -2410us[-2363us] +/- 45ms\n^+
198.58.105.63 2 8 377 24 -2813us[-2813us] +/- 65ms\n^+
74.6.168.73 2 10 377 240 +4116us[+4167us] +/- 35ms\n^*
69.41.163.31 2 7 377 31 -1479us[-1475us] +/- 22ms\n^+
204.11.201.10 2 10 377 769 +1462us[+1574us] +/- 46ms\n^-
195.21.137.209 2 9 377 241 +236us[ +286us] +/- 78ms\n^-
91.189.91.157 2 10 377 387 +598us[ +641us] +/- 91ms\n^-
91.189.94.4 2 10 175 62 -1255us[-1251us] +/- 92ms\n^-
91.189.89.199 2 10 377 614 -1275us[-1188us] +/- 88ms\n^-
91.189.89.198 2 10 265 29m -1432us[-1194us] +/- 99ms"
tracking: |-
Reference ID : 4529A31F (69.41.163.31)
Stratum : 3
Ref time (UTC) : Thu Sep 05 06:37:31 2019
System time : 0.000172272 seconds fast of NTP time
Last offset : +0.000003750 seconds
RMS offset : 0.000032249 seconds
Frequency : 14.922 ppm slow
Residual freq : +0.000 ppm
Skew : 0.007 ppm
Root delay : 0.015531355 seconds
Root dispersion : 0.010348102 seconds
Update interval : 64.6 seconds
Leap status : Normal
status: completed
timing:
completed: 2019-09-05 06:38:04 +0000 UTC
enqueued: 2019-09-05 06:37:57 +0000 UTC
started: 2019-09-05 06:38:04 +0000 UTC
unit: ntp/18

from ntpmon.

@woutervb Apologies for the delay on this. I'm just looking at the problem again along with the patch from @rodrigogansobarbieri and I'm a little surprised that this condition ever occurs. In the logs you've sent, the system seems to be tracking along pretty well - I can't see anything obviously problematic in the figures. I'll test out the patch shortly, but if you have any more recent examples of this and could gather any relevant log entries from either chronyd itself, the ntp charm, or ntpmon/check_ntpmon (I don't think there'll be much in the way of this unless they're producing python tracebacks), that would be much appreciated.

from ntpmon.

@rodrigogansobarbieri has provided the debug output of a system experiencing this issue. For posterity, the cause was a case where all peers suddenly and unexpectedly went into falseticker state. PR #10 was committed to avoid this case.

from ntpmon.