Fuzzing Messages (was: NTP Performance)

ASSI Stromeko at nexgo.de
Sat Nov 30 08:23:59 UTC 2019


Richard Laager via devel writes:
> Also, what does this mean and is it a problem (it's an ERR level)? I'm
> seeing it on both servers.
>
> 2019-11-23T01:49:33.497786-06:00 ntp1 ntpd[28568]: CLOCK: ts_prev 1574495373 s + 497394102 ns, ts_min 1574495373 s + 497388500 ns
> 2019-11-23T01:49:33.497936-06:00 ntp1 ntpd[28568]: CLOCK: ts 1574495373 s + 497388500 ns
> 2019-11-23T01:49:33.498001-06:00 ntp1 ntpd[28568]: CLOCK: sys_fuzz 92 nsec, prior fuzz -0.000000043
> 2019-11-23T01:49:33.498073-06:00 ntp1 ntpd[28568]: CLOCK: this fuzz -0.000000020
> 2019-11-23T01:49:33.498129-06:00 ntp1 ntpd[28568]: CLOCK: prev get_systime 0xe183630d.7f564f2e is 0.000022246 later than 0xe183630d.7f54d9f6

> Aug  2 10:20:50 s2 ntpd[8263]: CLOCK: ts_prev 1564734050 s + 602281287 ns, ts_min 1564734050 s + 602280310 ns
> Aug  2 10:20:50 s2 ntpd[8263]: CLOCK: ts 1564734050 s + 602281287 ns
> Aug  2 10:20:50 s2 ntpd[8263]: CLOCK: sys_fuzz 2305 nsec, prior fuzz 0.000002107
> Aug  2 10:20:50 s2 ntpd[8263]: CLOCK: this fuzz -0.000001769
> Aug  2 10:20:50 s2 ntpd[8263]: CLOCK: prev get_systime 0xe0ee70e2.9a2f0787 is 0.000000593 later than 0xe0ee70e2.9a2efd93

Both you and Udo reported seeing this error with some frequency, while I
only saw it on my machines around the time ntpd starts up.  Now, looking
at my error message in detail:

2019-11-23T20:35:10 ntpd[3143]: CLOCK: ts_prev 1574537710 s + 453989656 ns, ts_min 1574537710 s + 453989656 ns
2019-11-23T20:35:10 ntpd[3143]: CLOCK: ts 1574537710 s + 453989656 ns
2019-11-23T20:35:10 ntpd[3143]: CLOCK: sys_fuzz 94 nsec, prior fuzz 0.000000086
2019-11-23T20:35:10 ntpd[3143]: CLOCK: this fuzz -0.000000072
2019-11-23T20:35:10 ntpd[3143]: CLOCK: prev get_systime 0xe184086e.7438aa64 is 0.000000064 later than 0xe184086e.7438a951

is… intriguing.  If you follow the code through the function, ts_min in
the log should always be ts_prev+sys_fuzz; these two values can't be
identical or differ by any other value, ts_min must strictly be greater
than ts_prev by sys_fuzz.  I notice that there is always a DNS operation
logged at the same time when I get these errors, so I am pretty sure
this is related to the DNS thread.  This would also explain why a server
that has many clients would see many more such errors.


Regards,
Achim.
-- 
+<[Q+ Matrix-12 WAVE#46+305 Neuron microQkb Andromeda XTk Blofeld]>+

SD adaptation for Waldorf Blofeld V1.15B11:
http://Synth.Stromeko.net/Downloads.html#WaldorfSDada


More information about the devel mailing list