Logs in wrong order

[Maxim Dounin]

Hello!

On Mon, May 09, 2011 at 06:52:28AM -0400, davidkazuhiro wrote:

> When I hit the nginx server with a very rapid succession of requests
> from multiple clients, the logs will be out of order. For example, the
> log times would appear like this:
> 
> ... 18:10:11 ...
> ... 18:10:11 ...
> ... 18:10:11 ...
> ... 18:10:12 ...
> ... 18:10:11 ...
> ... 18:10:12 ...
> ... 18:10:11 ...
> ... 18:10:12 ...
> ... 18:10:12 ...
> ... 18:10:12 ...
> 
> Why would this be?

Time in different nginx worker processes may be slightly different 
as nginx only updates time once per event loop iteration (or even 
less frequently if timer_resolution set).  This in turn results in 
out-of-order times in logs you see when requests from different 
workers are logged.

Similar effect may be also seen when using log buffering (though 
in this case you'll see blocks with successive times up to log 
buffer size, not individual lines).

Maxim Dounin