[squid-users] Seeking insight into zeros, negative values in log: 2.6.STABLE18 -- SOLVED

[Henry S. Thompson]

Amos Jeffries writes:

> On 6/08/2016 1:03 a.m., Henry S. Thompson wrote:
>> Amos wrote:
>>> HST wrote:
>> ...
>>>> Amos wrote:
>> ...
>>>>> HST wrote:
>>>>>>  3) I'm seeing very small numbers (1 in 100000) of negative durations, e.g.
...
>>>> 1000s of times a day?  Seems . . . unlikely.

Oops, my mistake -- that should have been (at most) 100s, not 1000s, per
day.

> ...
> So the Squid logs can contain negative duration under exactly four
> conditions:
> ...
>  4) NTP service adjusting the kernel clock backwards.
>
> Since you say this is happening noticably often then its #4 and there is
> something funky going on with NTP. The others are all at rare and
> predictable times.

On closer investigation, you are exactly right.  Here are the first two
columns (with the timestamp converted to human-readable form) for the
negative duration log lines starting at 0900 on the worst day on record,
3 years ago:

Tue 25 Jun 09:17:00 BST 2013 -281
Tue 25 Jun 09:17:00 BST 2013 -200
Tue 25 Jun 10:17:00 BST 2013 -644
Tue 25 Jun 10:17:00 BST 2013 -237
Tue 25 Jun 10:17:00 BST 2013 -388
Tue 25 Jun 10:17:00 BST 2013 -297
Tue 25 Jun 10:17:00 BST 2013 -259
Tue 25 Jun 11:16:59 BST 2013 -634
Tue 25 Jun 11:16:59 BST 2013 -644
Tue 25 Jun 11:16:59 BST 2013 -644
Tue 25 Jun 11:16:59 BST 2013 -871
Tue 25 Jun 11:16:59 BST 2013 -548
Tue 25 Jun 11:16:59 BST 2013 -901
Tue 25 Jun 11:16:59 BST 2013 -900
Tue 25 Jun 11:16:59 BST 2013 -905
Tue 25 Jun 11:16:59 BST 2013 -850
Tue 25 Jun 11:16:59 BST 2013 -865
Tue 25 Jun 11:16:59 BST 2013 -783
Tue 25 Jun 11:16:59 BST 2013 -858
Tue 25 Jun 11:16:59 BST 2013 -502
Tue 25 Jun 11:16:59 BST 2013 -378
Tue 25 Jun 11:16:59 BST 2013 -556
Tue 25 Jun 11:16:59 BST 2013 -61
Tue 25 Jun 11:17:00 BST 2013 -164
Tue 25 Jun 11:17:00 BST 2013 -179
Tue 25 Jun 11:17:00 BST 2013 -138
and so it goes on.

There's a cron job on the 4 cache machines that runs every hour, and we
now know at exactly what time :-).

Thanks again for your careful and detailed help,

ht
-- 
       Henry S. Thompson, School of Informatics, University of Edinburgh
      10 Crichton Street, Edinburgh EH8 9AB, SCOTLAND -- (44) 131 650-4440
                Fax (44) 131 650-4587, e-mail ht at inf.ed.ac.uk
                       URL http://www.ltg.ed.ac.uk/~ht/
 [mail from me _always_ has a .sig like this -- mail without it is forged spam]