On 11/30/19 6:17 AM, ASSI via devel wrote: > ASSI via devel writes: >> 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.
That was the case for me _at startup_, but not after that. (See the attached logs.) >> This would also explain why a server >> that has many clients would see many more such errors. Why's that? What DNS lookups is ntpd doing for clients? > While I have not yet identified the code path that is involved (likely > something in NTS, I think), you might want to try the following monkey > patch: > > Let me know if makes a difference on your system. The error crops up > too sparingly on mine to really tell if it helps or not. Attached is what I have right away, filtered for DNS|CLOCK. -- Richard
2019-12-01T02:04:28.211306-06:00 ntp2 ntpd[29868]: DNS: dns_probe: ntp1.wiktel.com, cast_flags:1, flags:21901 2019-12-01T02:04:28.211433-06:00 ntp2 ntpd[29868]: CLOCK: we were blocked for 0.000046718 s while waiting for another thread 2019-12-01T02:04:28.219010-06:00 ntp2 ntpd[29868]: DNS: dns_check: processing ntp1.wiktel.com, 1, 21901 2019-12-01T02:04:28.219046-06:00 ntp2 ntpd[29868]: DNS: Server taking: 2600:2600::99 2019-12-01T02:04:28.219078-06:00 ntp2 ntpd[29868]: DNS: Server poking hole in restrictions for: 2600:2600::99 2019-12-01T02:04:28.219110-06:00 ntp2 ntpd[29868]: DNS: dns_take_status: ntp1.wiktel.com=>good, 0 2019-12-01T02:04:29.211262-06:00 ntp2 ntpd[29868]: DNS: dns_probe: time.cloudflare.com:1234, cast_flags:1, flags:21901 2019-12-01T02:04:29.211404-06:00 ntp2 ntpd[29868]: CLOCK: we were blocked for 0.000027831 s while waiting for another thread 2019-12-01T02:04:29.211444-06:00 ntp2 ntpd[29868]: CLOCK: we were blocked for 0.000008658 s while waiting for another thread 2019-12-01T02:04:29.303891-06:00 ntp2 ntpd[29868]: DNS: dns_check: processing time.cloudflare.com:1234, 1, 21901 2019-12-01T02:04:29.303925-06:00 ntp2 ntpd[29868]: DNS: Server taking: 2606:4700:f1::123 2019-12-01T02:04:29.304008-06:00 ntp2 ntpd[29868]: DNS: Server poking hole in restrictions for: 2606:4700:f1::123 2019-12-01T02:04:29.304055-06:00 ntp2 ntpd[29868]: DNS: dns_take_status: time.cloudflare.com:1234=>good, 0 2019-12-01T02:04:49.271159-06:00 ntp2 ntpd[29868]: CLOCK: we were blocked for 0.000015647 s while waiting for another thread 2019-12-01T02:05:10.364817-06:00 ntp2 ntpd[29868]: CLOCK: we were blocked for 0.000008022 s while waiting for another thread 2019-12-01T02:05:37.990619-06:00 ntp2 ntpd[29868]: CLOCK: we were blocked for 0.000051095 s while waiting for another thread 2019-12-01T02:06:04.152914-06:00 ntp2 ntpd[29868]: CLOCK: we were blocked for 0.000000160 s while waiting for another thread 2019-12-01T02:06:04.152954-06:00 ntp2 ntpd[29868]: CLOCK: we were blocked for 0.000001035 s while waiting for another thread 2019-12-01T02:06:20.372082-06:00 ntp2 ntpd[29868]: CLOCK: we were blocked for 0.000003552 s while waiting for another thread 2019-12-01T02:06:47.079607-06:00 ntp2 ntpd[29868]: CLOCK: we were blocked for 0.000001632 s while waiting for another thread 2019-12-01T02:06:52.489707-06:00 ntp2 ntpd[29868]: CLOCK: we were blocked for 0.000024759 s while waiting for another thread 2019-12-01T02:09:59.817856-06:00 ntp2 ntpd[29868]: CLOCK: we were blocked for 0.000019769 s while waiting for another thread 2019-12-01T02:10:28.192124-06:00 ntp2 ntpd[29868]: CLOCK: we were blocked for 0.000007581 s while waiting for another thread 2019-12-01T02:10:28.192234-06:00 ntp2 ntpd[29868]: CLOCK: we were blocked for 0.000022856 s while waiting for another thread 2019-12-01T02:10:41.854610-06:00 ntp2 ntpd[29868]: CLOCK: we were blocked for 0.000028176 s while waiting for another thread 2019-12-01T02:10:45.901016-06:00 ntp2 ntpd[29868]: CLOCK: we were blocked for 0.000048026 s while waiting for another thread 2019-12-01T02:10:45.901134-06:00 ntp2 ntpd[29868]: CLOCK: we were blocked for 0.000003723 s while waiting for another thread 2019-12-01T02:11:22.081163-06:00 ntp2 ntpd[29868]: CLOCK: we were blocked for 0.000009447 s while waiting for another thread 2019-12-01T02:11:22.081203-06:00 ntp2 ntpd[29868]: CLOCK: we were blocked for 0.000009033 s while waiting for another thread
signature.asc
Description: OpenPGP digital signature
_______________________________________________ devel mailing list devel@ntpsec.org http://lists.ntpsec.org/mailman/listinfo/devel
