Puzzling clock offset spikes

Sat Jun 30 01:27:30 UTC 2018

Standardized caveat: I'm devops/sysadmin, not dev.

I'm looking for any insights - 'have you thought about this', 'what 
about that', 'it could be this', 'can you check that', 'please provide 
this other data' - or, if I'm lucky, someone will chime in with "It's 
this phenomenon, <explication>". I'm starting here, but I'm also more 
than accepting of pointers to broader audiences/tighter focuses to blast 
this at. And thanks in advance if anyone has thoughts on this.

Raspberry Pi 3B+, Adafruit GPS hat., Raspbian Stretch, ntpsec 1.1.1, 
gpsd 3.18~dev.

Everything runs quite lovely, notwithstanding temperature variations, 
which I'm working on smoothing out.

*Except* that at regular intervals, there is a spike in clock offset, 
followed a smaller interval by another spike in offset. My early timings 
a couple of ago showed eleven minutes between events, and 90 seconds 
between first and second spike - however that has changed to 
approximately every nine minutes, followed approximately 74 seconds 
later by the second spike. I believe that shift may be thermally 
related, as ambient temps have been gradually rising the last few days, 
and overall offset follows.

Things I've checked:
It's not a cron job.
It's not an 'at' job.
It's not a recurring systemd job.
It's not a monitoring job.
It does not appear to be any kernel timers.
It does not appear to be any sort of RF or other recurring external 
signal burst; hard to verify, but nothing in the environment would seem 
to be a likely source of same.
It does not appear to be a function of the power supply.
It does not appear to be a function of network traffic either LAN or WAN.

I'm running netdata to get finer-grained/realtime graphs, and they show 
the spikes clearly - and they are somewhat similar in profile (see link 
below for screenshot). However, the graph doesn't seem to directly match 
to the raw data in the loopstats file (below are snippets of raw data 
for each spike). The issue predates installation of netdata.

I'm running nginx webserver on it, I will probably move that off to my 
separate Raspi that does ntpviz log processing. However, turning off 
nginx for extended periods makes no change.

I'm running the ntplogtemp and ntploggps scripts for ntpviz, and ntpheat 
to try to stabilize temperature. I'd be surprised if they are in some 
way responsible.

I've run extended 'ps -ecf' in a loop before, during, and after a spike, 
and sifted through to see if any new processes should pop up, but 
nothing has shown up.

I briefly latched onto this - 
http://www.ntp.org/ntpfaq/NTP-s-trbl-spec.htm - based on my earlier 
timings of eleven minutes, as the example within 8.3.1.1.2 suggested an 
eleven minute interval for RTC updates - but these later timings dash that.

Link to a few example ntpviz graphs, and the aforementioned netdata graph:
https://imgur.com/a/GFUU2kn

Some timings from the data below - beginning of event to beginning of 
event. Pattern is fairly evident.
1a to 1b is 74 seconds
1a to 2a is 572 seconds.
2a to 2b is 74 seconds.
2a to 3a is 494 seconds.
3a to 3b is  74 seconds.
3a to 4a is 570 seconds.
4a to 4b is 72 seconds.
4a to 5a is 568 seconds.
5a to 5b is 74 seconds.

1a.
58299 1727.181 0.000000288 -1.754883 0.000000460 0.003006 0
58299 1729.181 0.000000035 -1.754593 0.000000439 0.002813 0
58299 1731.181 -0.000004776 -1.791916 0.000001751 0.013456 0
58299 1733.181 -0.000006176 -1.840179 0.000001711 0.021204 0
58299 1735.181 -0.000000730 -1.845886 0.000002504 0.019936 0
58299 1737.181 0.000004460 -1.811035 0.000002976 0.022352 0
58299 1739.181 0.000004311 -1.777344 0.000002784 0.024063 0
58299 1741.181 0.000002386 -1.758698 0.000002691 0.023455 0
58299 1743.181 0.000000938 -1.751358 0.000002569 0.022093 0
58299 1745.181 -0.000000085 -1.752029 0.000002430 0.020667 0

1b.
58299 1801.181 -0.000000045 -1.761383 0.000000575 0.004406 0
58299 1803.181 -0.000000575 -1.765884 0.000000570 0.004418 0
58299 1805.181 -0.000006959 -1.820251 0.000002319 0.019661 0
58299 1807.181 -0.000003061 -1.844177 0.000002570 0.020243 0
58299 1809.181 0.000003505 -1.816788 0.000003343 0.021268 0
58299 1811.181 0.000004604 -1.780807 0.000003151 0.023614 0
58299 1813.181 0.000003447 -1.753876 0.000002976 0.024054 0
58299 1815.181 0.000001200 -1.744492 0.000002895 0.022743 0
58299 1817.181 -0.000000201 -1.746078 0.000002753 0.021282 0

2a.
58299 2295.181 0.000000543 -1.766388 0.000000370 0.002965 0
58299 2297.181 0.000000423 -1.763077 0.000000349 0.003010 0
58299 2299.181 -0.000004419 -1.797607 0.000001743 0.012529 0
58299 2301.181 -0.000006413 -1.847717 0.000001777 0.021242 0
58299 2303.181 -0.000000513 -1.851730 0.000002667 0.019921 0
58299 2305.181 0.000003329 -1.825714 0.000002841 0.020781 0
58299 2307.181 0.000004947 -1.787064 0.000002718 0.023761 0
58299 2309.181 0.000002720 -1.765808 0.000002662 0.023463 0
58299 2311.181 0.000000892 -1.758835 0.000002573 0.022085 0

2b.
58299 2369.181 -0.000000626 -1.762268 0.000000564 0.004718 0
58299 2371.181 -0.000000354 -1.765045 0.000000536 0.004522 0
58299 2373.181 -0.000007680 -1.825043 0.000002638 0.021630 0
58299 2375.181 -0.000002766 -1.846664 0.000003018 0.021629 0
58299 2377.181 0.000003865 -1.816467 0.000003670 0.022876 0
58299 2379.181 0.000004563 -1.780807 0.000003442 0.024837 0
58299 2381.181 0.000003585 -1.752792 0.000003238 0.025256 0
58299 2383.181 0.000001564 -1.740570 0.000003112 0.024017 0
58299 2385.181 0.000000171 -1.739227 0.000002952 0.022470 0

3a.
58299 2863.181 -0.000000094 -1.761185 0.000000594 0.003366 0
58299 2865.181 0.000000303 -1.758804 0.000000574 0.003259 0
58299 2867.181 -0.000004647 -1.795120 0.000001831 0.013197 0
58299 2869.181 -0.000008013 -1.857727 0.000002086 0.025344 0
58299 2871.181 -0.000000036 -1.858017 0.000003430 0.023708 0
58299 2873.181 0.000005298 -1.816620 0.000003722 0.026571 0
58299 2875.181 0.000004557 -1.781006 0.000003491 0.027862 0
58299 2877.181 0.000002611 -1.760605 0.000003337 0.027042 0
58299 2879.181 0.000001660 -1.747635 0.000003140 0.025708 0
58299 2881.181 -0.000000126 -1.748627 0.000003004 0.024050 0

3b.
58299 2937.181 -0.000001048 -1.769531 0.000000679 0.006295 0
58299 2939.181 -0.000000344 -1.772232 0.000000682 0.005966 0
58299 2941.181 -0.000002575 -1.792343 0.000001014 0.009039 0
58299 2943.181 -0.000003913 -1.822922 0.000001060 0.013725 0
58299 2945.181 0.000001626 -1.810211 0.000002196 0.013602 0
58299 2947.181 0.000004089 -1.778259 0.000002231 0.017015 0
58299 2949.181 0.000003423 -1.751511 0.000002100 0.018514 0
58299 2951.181 0.000001775 -1.737640 0.000002049 0.017999 0
58299 2953.181 0.000000375 -1.734695 0.000001980 0.016868 0

4a.
58299 3431.181 0.000000090 -1.765152 0.000000378 0.002660 0
58299 3433.181 -0.000000423 -1.768463 0.000000398 0.002749 0
58299 3435.181 -0.000000301 -1.770828 0.000000375 0.002704 0
58299 3437.181 -0.000009220 -1.842865 0.000003173 0.025594 0
58299 3439.181 -0.000002659 -1.863647 0.000003767 0.025043 0
58299 3441.181 0.000003693 -1.834778 0.000004179 0.025553 0
58299 3443.181 0.000006439 -1.784470 0.000004028 0.029794 0
58299 3445.181 0.000004265 -1.751144 0.000003845 0.030258 0
58299 3447.181 0.000001470 -1.739655 0.000003730 0.028594 0

4b.
58299 3503.181 -0.000000532 -1.760254 0.000000709 0.005446 0
58299 3505.181 -0.000001300 -1.770416 0.000000717 0.006234 0
58299 3507.181 -0.000000980 -1.778076 0.000000680 0.006429 0
58299 3509.181 -0.000003905 -1.808594 0.000001214 0.012353 0
58299 3511.181 -0.000004439 -1.843277 0.000001151 0.016849 0
58299 3513.181 0.000001046 -1.835098 0.000002219 0.016024 0
58299 3515.181 0.000004529 -1.799713 0.000002413 0.019524 0
58299 3517.181 0.000003523 -1.772186 0.000002285 0.020694 0
58299 3519.181 0.000002604 -1.751831 0.000002162 0.020652 0

5a.
58299 4001.181 -0.000000605 -1.766434 0.000000382 0.003381 0
58299 4003.181 -0.000000297 -1.768768 0.000000373 0.003268 0
58299 4005.181 -0.000004164 -1.801300 0.000001411 0.011901 0
58299 4007.181 -0.000004872 -1.839371 0.000001343 0.017467 0
58299 4009.181 0.000000398 -1.836258 0.000002248 0.016376 0
58299 4011.181 0.000004405 -1.801834 0.000002535 0.019565 0
58299 4013.181 0.000004611 -1.765808 0.000002373 0.022297 0

5b.
58299 4077.181 0.000000363 -1.761673 0.000000711 0.004804 0
58299 4079.181 -0.000007144 -1.817490 0.000002737 0.020239 0
58299 4081.181 -0.000002646 -1.838181 0.000003014 0.020296 0
58299 4083.181 0.000003860 -1.808014 0.000003639 0.021776 0
58299 4085.181 0.000005223 -1.767197 0.000003438 0.024964 0
58299 4087.181 0.000002925 -1.744339 0.000003317 0.024710 0

-- 
Paul Theodoropoulos
www.anastrophe.com

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.ntpsec.org/pipermail/users/attachments/20180629/db7d36b9/attachment.html>