Multiple Entries in Log File

[Igor Sysoev]

On Wed, Dec 02, 2009 at 04:14:41PM -0500, cpriest wrote:

> Okay, I've got some more details on this event.  I've changed the query params to zzzz=1 to secure my customers data but otherwise these are unmodified.
> 
> So based on this I *think* they are sending a second request through right?

Yes, the client send request twice.

> Also, is 180140 a sequential connection number?

Yes. It's usually used to search particular connection in huge debug logs.

>  What's the 4388#0 designator?

4388 is a proces number, 0 is a thread number (0 means there are no threads).

> Lastly which of these lines indicates a "new request" and also which means "new connection"?

The log is not complete, probably, because you have other error_log directives.

> 2009/12/02 08:06:49  4388#0: *180140 http close request
> 2009/12/02 08:06:49  4388#0: *180140 http log handler
> 2009/12/02 08:06:49  4388#0: *180140 hc free: 00000000 0
> 2009/12/02 08:06:49  4388#0: *180140 hc busy: 00000000 0
> 2009/12/02 08:06:49  4388#0: *180140 http keepalive handler
> 2009/12/02 08:06:49  4388#0: *180140 http empty handler

Here is a new request:

> 2009/12/02 08:06:49  4388#0: *180140 http keepalive handler

But some lines are missed.

> 2009/12/02 08:06:49  4388#0: *180140 http cl:-1 max:536870912
> 2009/12/02 08:06:49  4388#0: *180140 generic phase: 3
> 2009/12/02 08:06:49  4388#0: *180140 post rewrite phase: 4
> 2009/12/02 08:06:49  4388#0: *180140 generic phase: 5
> 2009/12/02 08:06:49  4388#0: *180140 generic phase: 6
> 2009/12/02 08:06:49  4388#0: *180140 generic phase: 7
> 2009/12/02 08:06:49  4388#0: *180140 access phase: 8
> 2009/12/02 08:06:49  4388#0: *180140 access phase: 9
> 2009/12/02 08:06:49  4388#0: *180140 post access phase: 10


-- 
Igor Sysoev
http://sysoev.ru/en/