Some requests not getting logged

Hello,

I’ve noticed that some (seemingly random) requests get logged as 400 and
408
codes without 301 or 200 codes showing up in the logs.

This seems to occur a lot when redirecting people from http > https via
a
301 redirect, the 301 redirect will in many cases not appear at all in
the
logs but will instead show the following after some time has passed:

    • 24...* - - [17/Sep/2012:19:19:07 -0400] “-” 400 0 “-” “-” “-”
      “-”

I’ve also seen some https requests not show up in the logs at all as 200
codes, but will eventually display 408 codes:

TLSv1 ECDHE-RSA-RC4-SHA 213...** - - [17/Sep/2012:18:30:31 -0400]
“-”
408 0 “-” “-” “-” “-”

I’ve also been able to confirm that all of these requests are
successful, so
is this something wrong with the logging, or is this normal behavior?

To me it seems buggy how someone could make a 301 or 200 code request,
and
be completely hidden in the access logs other than the eventual
400/408s.

Posted at Nginx Forum:

I also met this problem with 1gb+ log increasing everyday…

Yours sincerely,
Christopher M.

Ambassador/Contributor of Fedora Project and many others.

http://mirrors.cicku.me

Hello!

On Mon, Sep 17, 2012 at 07:38:49PM -0400, eiji-gravion wrote:

be completely hidden in the access logs other than the eventual 400/408s.
Most likely this is a result of a cached response being used by a
browser, while in logs you see only a connection which was open by
the browser but no requests were sent in it.

Maxim D.

On 18 September 2012 07:46, Maxim D. [email protected] wrote:

I’ve also seen some https requests not show up in the logs at all as 200
codes, but will eventually display 408 codes:

TLSv1 ECDHE-RSA-RC4-SHA 213...** - - [17/Sep/2012:18:30:31 -0400] “-”
408 0 “-” “-” “-” “-”

Most likely this is a result of a cached response being used by a
browser, while in logs you see only a connection which was open by
the browser but no requests were sent in it.

I agree. I believe we already covered this here on the list a while
ago, didn’t we?

I seem to recall it’s caused by UAs optimistically opening (multiple?)
connections to origin servers, and then closing them after they go
unused. I.e. with no data transferred (i.e. 400/408 depending on
protocol).

I suspect you see these at HTTP->HTTPS redirection as that’s the point
at which the UA notices that it’s no longer accessing the HTTP://site/
, and closes the unused/cached/fallow optimistic HTTP connections it
had opened in /case/ the user continued browsing over HTTP.

My 2 cents,
Jonathan

Jonathan M.
Oxford, London, UK
http://www.jpluscplusm.com/contact.html