Hi there,
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?
Example:
=> First, with config.autoflush_log set to false:
$ grep autoflush config/environments/production.rb
config.autoflush_log = false
$ script/unicorn upgrade
....
$ ps -ef | grep unicorn
10001 27332 1 79 16:28 ? 00:00:45 unicorn master -D -c
/path/to/app/current/config/unicorn.rb -E production
10001 27813 27332 9 16:29 ? 00:00:00 unicorn worker[0] -D -c
/path/to/app/current/config/unicorn.rb -E production
[...]
$ lsof -p 27332 | grep log
ruby 27332 app-user 1w REG 251,0 0 7106215
/path/to/app/shared/log/unicorn.stdout.log
ruby 27332 app-user 2w REG 251,0 2784 7105641
/path/to/app/shared/log/unicorn.stderr.log
ruby 27332 app-user 7w REG 251,0 76835 7110394
/path/to/app/shared/log/production.log
$ mv /path/to/app/shared/log/production.log
/path/to/app/shared/log/production.log.old
$ lsof -p 27332 | grep log
ruby 27332 app-user 1w REG 251,0 0 7106215
/path/to/app/shared/log/unicorn.stdout.log
ruby 27332 app-user 2w REG 251,0 2784 7105641
/path/to/app/shared/log/unicorn.stderr.log
ruby 27332 app-user 7w REG 251,0 76835 7110394
/path/to/app/shared/log/production.log.old
$ kill -USR1 27332
$ lsof -p 27332 | grep log
ruby 27332 app-user 1w REG 251,0 0 7106215
/path/to/app/shared/log/unicorn.stdout.log
ruby 27332 app-user 2w REG 251,0 3092 7105641
/path/to/app/shared/log/unicorn.stderr.log
ruby 27332 app-user 7w REG 251,0 76835 7110394
/path/to/app/shared/log/production.log.old
=> still writing on the old production.log.old file
=> Now, without config.autoflush_log:
$ grep autoflush config/environments/production.rb
#config.autoflush_log = false
$ script/unicorn upgrade
....
$ ps -ef | grep unicorn
10001 28621 1 85 16:31 ? 00:00:45 unicorn master -D -c
/path/to/app/current/config/unicorn.rb -E production
10001 29100 28621 18 16:31 ? 00:00:00 unicorn worker[0] -D -c
/path/to/app/current/config/unicorn.rb -E production
[...]
$ lsof -p 28621 | grep log
ruby 28621 app-user 1w REG 251,0 0 7106215
/path/to/app/shared/log/unicorn.stdout.log
ruby 28621 app-user 2w REG 251,0 3867 7105641
/path/to/app/shared/log/unicorn.stderr.log
ruby 28621 app-user 7w REG 251,0 1914 7105763
/path/to/app/shared/log/production.log
$ mv /path/to/app/shared/log/production.log
/path/to/app/shared/log/production.log.old
$ lsof -p 28621 | grep log
ruby 28621 app-user 1w REG 251,0 0 7106215
/path/to/app/shared/log/unicorn.stdout.log
ruby 28621 app-user 2w REG 251,0 4175 7105641
/path/to/app/shared/log/unicorn.stderr.log
ruby 28621 app-user 7w REG 251,0 1746 7110394
/path/to/app/shared/log/production.log.old
$ kill -USR1 28621
$ lsof -p 28621 | grep log
ruby 28621 app-user 1w REG 251,0 0 7106215
/path/to/app/shared/log/unicorn.stdout.log
ruby 28621 app-user 2w REG 251,0 4483 7105641
/path/to/app/shared/log/unicorn.stderr.log
ruby 28621 app-user 7w REG 251,0 0 7105763
/path/to/app/shared/log/production.log
=> now writing on newly reopened log
Thanks,
Cedric
