Logs in wrong order

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?

Posted at Nginx Forum:

Hello!

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

… 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 D.

Oh I see, tricky. How is an event loop defined? Is there a value
definable in nginx.conf which can shorten the event loop? Or can I just
increase timer resolution to a really high number to make the log times
more accurate?

Posted at Nginx Forum: