[ntp:questions] Popcorn on prefer takes out system clock

A C agcarver+ntp at acarver.net
Thu Mar 8 06:15:42 UTC 2012


On 3/7/2012 15:38, unruh wrote:
> On 2012-03-07, A C<agcarver+ntp at acarver.net>  wrote:
>> On 3/6/2012 20:34, Dave Hart wrote:
>>> On Wed, Mar 7, 2012 at 01:32,<Null at blacklist.anitech-systems.invalid>   wrote:
>>>> Dave Hart wrote:
>>>>> A C<agcarver+ntp at acarver.net>   wrote:
>>>>>> 130.207.165.28 944d 8d popcorn 2147483647.997598 s
>>>>>
>>>>> I assume you mean in the local ntpd log on your sparc box
>>>>>    referring to the IP address that used to be marked prefer.
>>>>> I realize not everyone is a programmer, but the number
>>>>>    above jumped out at me as suspiciously round in hex
>>>>>    and binary.  Sure enough, round it to whole seconds
>>>>>    and you have 2^31 or 0x80000000.  Incredible coincidence?
>>>>
>>>> -0.002402 ?
>>>
>>> Nope.  NTP's 32:32 l_fp is used for both unsigned timestamps and
>>> signed differences between timestamps (intervals or offsets).  In both
>>> cases the fractional part is unsigned and positive.  For offsets, the
>>> integer part is signed, so -0.002402 would be -1 seconds plus
>>> 0.997598, or in hex 0xffffffff.0xf.......  In this case we have an
>>> unambiguously positive value 0x7fffffff.0xf....... or just over +68
>>> years.
>>
>> Interestingly the same remote server just popcorned again but this time
>> the number was still huge though less than a full overflow:
>>
>>
>> 130.207.165.28 901d 8d popcorn 202238.338413 s
>
> Is it delivering a KOD packet? What is that server running? Do you have
> peers enabled and can you look at the output of the peers file when that
> weird measurement comes in? It would be nice if one could see all four
> times in the ntp packet for that situation, to see if it is your machine
> or the remote machine that is putting in absurd times into the packet
> (or if ntpd is misinterpreting something and causing the problem
> itself.) Unfortunately I do not think that there is any debug flag that
> can tell ntpd to report all four of those times on a bad packet. (I
> suppose you could hack the source to have it do that)


The peer records for that particular server.  Five polls prior to the 
major event (the popcorn 2147483647.997598 s), the event itself, and 
five polls after:

55992 28127.756 130.207.165.28  9014 -0.170051294  0.078942366 
7.937562104  0.000122070
55992 28129.677 130.207.165.28  9014 -0.179983358  0.077845506 
3.937600648  0.009932064
55992 28133.799 130.207.165.28  9014 -0.199691829  0.077621280 
0.937640806  0.021355778
55992 28408.122 130.207.165.28  9024 -0.006291682  0.078885845 
7.937562104  0.000122070
55992 28409.830 130.207.165.28  9024 -0.016024622  0.078550234 
3.937600653  0.009732940
55992 28411.834 130.207.165.28  9024 -0.026350192  0.077996043 
9225.801161582  0.015952448
55992 28413.833 130.207.165.28  9024 -0.036352381  0.078129313 
0.937637060  0.021732520
55992 28415.829 130.207.165.28  963a -0.041918036  0.077468683 
0.437644685  0.023521481
55992 28417.863 130.207.165.28  963a -0.041216188  0.077486681 
0.187648967  0.020491380
55992 28476.861 130.207.165.28  943a -0.011773862  0.078609389 
0.063072171  0.020977043
55992 28542.857 130.207.165.28  943a  0.000470710  0.079669255 
0.000839328  0.029465863

This is for the later event of 202238.338413 s popcorn

55993 28733.851 130.207.165.28  944d  0.001442344  0.077783855 
0.003718608  0.000174640
55993 29065.885 130.207.165.28  904d  0.001781094  0.077855594 
0.004514781  0.000271580
55993 29263.848 130.207.165.28  944d  0.001515211  0.077869762 
0.004768669  0.000225611
55993 29397.858 130.207.165.28  944d  0.001499231  0.077956490 
0.005274452  0.000200836
55993 29525.860 130.207.165.28  944d  0.001522830  0.077973892 
0.003356092  0.000185364
55993 29781.861 130.207.165.28  944d  202238.340010876  0.077839850 
1.518925725  202238.338406371
55993 30374.867 130.207.165.28  941d  0.001488131  0.078009916 
0.005926894  0.000356562
55993 30439.861 130.207.165.28  941d  0.001620819  0.078177454 
0.002953087  0.000259219
55993 30568.902 130.207.165.28  941d  0.001570695  0.077985387 
0.001762402  0.000288896
55993 30766.859 130.207.165.28  941d  0.001727346  0.077951527 
0.001585799  0.000266961
55993 30897.850 130.207.165.28  941d  0.001619869  0.077850728 
0.001662438  0.000143900

I happened to notice the time of day is close for each event, the events 
are almost 24 hours apart.  I'll see what happens later tonight (the 
clock only shows 22120 seconds right now)


More information about the questions mailing list