# Log module question: does the buffer mess up the order of the log entries?

**URL:** <https://www.ruby-forum.com/t/log-module-question-does-the-buffer-mess-up-the-order-of-the-log-entries/236650>\
**Category:** NGINX\
**Created:** [September 23, 2013, 4:00am UTC](https://www.ruby-forum.com/t/log-module-question-does-the-buffer-mess-up-the-order-of-the-log-entries/236650 "2013-09-23T04:00:24Z")\
**Posts on this page:** 3\
**Page:** 1

<div class="post-metadata">

**Author:** ![alcina](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/a/a587f6/32.png) [@alcina](https://www.ruby-forum.com/u/alcina)\
**Post date:** [September 23, 2013, 4:00am UTC](https://www.ruby-forum.com/t/log-module-question-does-the-buffer-mess-up-the-order-of-the-log-entries/236650/1 "2013-09-23T04:00:24Z")

</div>

Hi experts,

I am reading the log module source code, there is something difficult to  
make sure, so I ask for your help.

Access log module use a buffer to buffer log entries before writing to  
the file system, the buffer is initialised before the worker processes  
are forked, so I guess after the fork(), each worker has a copy, this  
also explains why there is no lock-unlock operations while using the  
buffer. To be sure about that, I did a simple test:

1, configure nginx to use 16k access log buffer, use the default  
keep-alive time(65), work in master-workers mode with a few worker  
processes;  
2, open one browser, access nginx server, refresh a few times, no access  
log generated;  
3, open another browser, do the same thing as 2, until the access log  
was flushed;

I think there is a chance that the two browser was served by different  
worker processes, and log entries may be buffered in different buffers,  
which buffer get full first, which will be flush first. According that,  
the order of the log entries could be messed up. Unfortunately, I didn’t  
see that after testing for a few times.

My question is, Am I wrong about the log module behaviour, or I didn’t  
get the right way to test it?

---

<div class="post-metadata">

**Author:** ![SSSSSS\_S\_SSSSS\_SSS](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/s/b3f665/32.png) [@SSSSSS\_S\_SSSSS\_SSS](https://www.ruby-forum.com/u/SSSSSS_S_SSSSS_SSS)\
**Post date:** [September 23, 2013, 1:37pm UTC](https://www.ruby-forum.com/t/log-module-question-does-the-buffer-mess-up-the-order-of-the-log-entries/236650/2 "2013-09-23T13:37:09Z")

</div>

Hello!

On Mon, Sep 23, 2013 at 09:59:29AM +0800, 海峰 刘 wrote:

> that, I did a simple test:  
> different worker processes, and log entries may be buffered in  
> different buffers, which buffer get full first, which will be  
> flush first. According that, the order of the log entries could  
> be messed up. Unfortunately, I didn’t see that after testing for  
> a few times.
> 
> My question is, Am I wrong about the log module behaviour, or I  
> didn’t get the right way to test it?

Yes, with buffering used log entries may easely be out of order.  
(Moreover, even without buffering nothing is guaranteed, even  
within a single process - a request made and served later from  
client’s point of view, might end up being logged earlier. Mostly  
because logging happens once nginx thinks a request is complete,  
and this might disagree with client’s point of view.)

To somewhat limit possible log entries misorder with buffering  
there is the “flush” argument of the “access\_log” directive as  
introduced in nginx 1.3.10. It’s not normally needed on loaded  
servers as reasonably-sized buffers are filled in seconds, but may  
help in case of a varying load.

–  
Maxim D.  
[http://nginx.org/en/donation.html](http://nginx.org/en/donation.html)

---

<div class="post-metadata">

**Author:** ![SSSSSS\_S\_SSSSS\_SSS](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/s/b3f665/32.png) [@SSSSSS\_S\_SSSSS\_SSS](https://www.ruby-forum.com/u/SSSSSS_S_SSSSS_SSS)\
**Post date:** [September 23, 2013, 7:49pm UTC](https://www.ruby-forum.com/t/log-module-question-does-the-buffer-mess-up-the-order-of-the-log-entries/236650/3 "2013-09-23T19:49:29Z")

</div>

On Monday 23 September 2013 05:59:29 海峰 刘 wrote:

> see that after testing for a few times.
> 
> My question is, Am I wrong about the log module behaviour, or I didn’t get  
> the right way to test it?

The order of access log entries is undefined anyway if you have more  
than  
one worker processes.

wbr, Valentin V. Bartenev