Thanks for your patience with this, but still not quite getting it.
I thought there were two cases:
1) Client drops the connection before the interaction is complete ==
log shows HTTP result code 000, almost always size 0 as well;
2) Interaction completed successfully == HTTP result code as from
cache or remote, size as sent to client.
See below how I can't make that fit with your reply
Amos Jeffries writes:
>>>> 2) Leaving aside those cases, I see a modest handful (1 in 7000) of 0
>>>> values in the size field, e.g.
>>>>
>>>> 1402741879.726 114 ... TCP_MISS/200 0 GET http://... DIRECT/... image/gif
>>>> 1402771557.693 176 ... TCP_HIT/200 0 GET http://... NONE/- image/gif
>>>>
>>>> How should these be understood?
>>>
>>> A response with no body payload. It happens. Usually with "web bug" type
>>> images used for tracking.
>>> Or maybe the image was something like a captcha and the script producing
>>> it crashed with no data sent.
>>
>> But documentation claims size field includes headers, and clearly
>> (image/gif) at least a Content-type header was sent...
>
> Nope. The reply message header (maybe more, or not) was received from
> the server but not sent to the client. The second case it only got as
> far as loading from disk and not yet sending.
>
> At the lowest level it was likely the attempt to write(2) those reply
> details to the client that detected the connection was closed/aborted
> already by the other end.
So the simple story I added at the top is wrong, and I should instead
understand that
1') Log shows size 0 means client dropped the connection before the
interaction was complete (HTTP result code 000 vs. something else is
just a question of when the drop was detected);
2) Interaction completed successfully == HTTP result code as from
cache or remote, size as sent to client. 0 size can _never_ mean
all is well, server result was empty, because if all is well at
least some header info will have been sent.
>>>> 3) I'm seeing very small numbers (1 in 100000) of negative durations, e.g.
>>>>
>>>> 1402744620.389 -70 ... TCP_MISS/200 1882 GET http://... DIRECT/... text/xml
>>>>
>>>> How should these be understood?
>>>
>>> The system clock on your machine went backwards between the request
>>> arriving and the response being completely sent. Check for issues in
>>> your NTP setup.
>>
>> 1000s of times a day? Seems . . . unlikely. But I'll try to get the
>> sys admin people responsible to investigate.
>
> Squid's simply doing a time fetch from the kernel and subtracting
> Start-time from End-time to get a negative.
> Note that its on the scale of ~100 milliseconds.
Sorry but I still don't see how two successive fetchs could result in a
decrement (w/o an NTP intervention).
The negative numbers I'm seeing range up into the low 1000s (of msec,
right? That's what the squid documentation says, IIRC).
Did you really mean "~100 _milliseconds_"? My understanding was that
kernel time differences were typically accurate to ~100 _nanoseconds_.
If you can easily tell me where to look in the source, obviously that's
what I should do....
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@xxxxxxxxxxxx
URL: http://www.ltg.ed.ac.uk/~ht/
[mail from me _always_ has a .sig like this -- mail without it is forged spam]
_______________________________________________
squid-users mailing list
squid-users@xxxxxxxxxxxxxxxxxxxxx
http://lists.squid-cache.org/listinfo/squid-users
