Hi Eric,
Thanks for your answer (and update to the FAQ ;) ).
I'm playing with autoflush_log = true and see if I find a performance
impact (I'm logging approx 20KB per sec).
sys.vm.dirty* sysctls are already changed, but with low ratios as those
systems are also writing large files (and I don't want those pages in
memory for too long).
If a performance impact can be measured, I believe that I will turn
autoflush_log to false again and modify Unicorn::Util#is_log? to accept
!fp.sync ;) (I'm willing to accept occasional log lines corruption esp
during rotation)... or just restart unicorn after rotation instead.
Or, thinking out loud... keep autoflush_log to false and have unicorn
flush logs itself regularly, outside the HTTP request path (and when
reopening logs), to avoid blocking on IO during a log flush in the
middle of a request? (I need to refresh myself on the sizes of the ruby
& system IO buffers though, not sure if it's worth the pain).
Cedric
On Thu, Jul 03, 2014 at 05:24:10PM +0000, Eric Wong wrote:
>
> Cedric Maion <[email protected]> wrote:
> > On a Rails 4.0 app with 'config.autoflush_log = false', it seems to me
> > that telling unicorn to reopen log files fails (e.g., after a log
> > rotation and USR1 signal, Rails/unicorn still writes to the old rotated
> > file instead of reopening a new one).
> >
> > Without this config option, logs does properly get reopened.
> >
> > Is this something known?
>
> Yes, log buffering via File#sync=true is incompatible with reopening in
> multiprocess servers. File#sync=true does not guarantee writes are
> atomic on line boundaries, so it's dangerous to assume they're logs.
>
> Even without reopening, enabling this option on a multiprocess server
> might corrupt logs (depending on the buffering implementation)
> because the synchronization is within each process rather for the
> entire OS.
>
> Looking at the rails source:
> ==> railties/lib/rails/application/bootstrap.rb <==
> f = File.open path, 'a'
> f.binmode
> f.sync = config.autoflush_log # if true make sure every write
> flushes
>
> You're not likely to notice any performance difference unless you're
> logging excessively. Keep in mind the Linux kernel also does buffering
> and you can tune that via the sys.vm.dirty_* sysctls.
