Reopen logs working with renaming of the log file

[AnatolyShirykalov]

Reopen logs of rack application after renaming log file

[olleolleolle]

Is this debugging which you want to keep in the test file?

[AnatolyShirykalov]

removed

[nateberkopec]

Linking #1527 #880 #561

[nateberkopec]

Please ask to re-open if you feel this is still needed in Puma.

However, this PR as stands currently reimplements log rotation via SIGHUP without a) removing the old code path or b) providing a use case as to why this way is better.

[jeremy]

I was reminded of this recently when switching from Unicorn to Puma. Unicorn reopens all loggish-looking File objects on USR1, so any Logger.new(path) you have floating around your app (debug stuff, plugins/engines, gems?) that get log-rotated (a common route is a wildcard rule that catches an unanticipated logfile) will Just Work if you have logrotate kill -USR1 /path/to/unicorn.pid, because most log files don't need special handling and are simple to detect. Relying on this is convenient because the opposite is not: painstaking, error-prone, order-dependent, infuriating Signal.trap management.

Which suggests an alternative! Offer some kind of on_reload/HUP so apps can enlist their own behavior. Trigger a config refresh, reopen logfiles, freshen up, whatever. If someone wants, Unicorn-style log reopening, then on_HUP { Unicorn::Util.reopen_logs }

Anyway, back to the beginning:

providing a use case as to why this way is better

Filing this as a data point that while "better" is arguable, "easier to reliably migrate" from Unicorn is certain!

[nateberkopec]

Signal.trap wrangling definitely sucks. on_HUP sounds like a good alternative - are you suggesting that instead of the Unicorn behavior because it isn't a breaking change?

[jeremy]

are you suggesting that instead of the Unicorn behavior because it isn't a breaking change?

Yep! Not everyone's a fan of the clever Unicorn behavior, either. 😈

I think it's possible to provide as a Puma plugin too though. I'll give that a shot to demonstrate.

[jeremy]

Here's what I set up, if you're looking for a quick way to get logrotate signaling Puma to reopen logfiles in your app.

Caveats

• You must redirect stderr or stdout to a file in Puma config. Otherwise, the default Puma HUP behavior is to non-gracefully terminate the process—the opposite of what we want.

# Gracefully reopen logfiles on HUP using Unicorn's reopener. Chains to
# Puma's HUP handler which signals its workers and reopens stdout/stderr.
module LogReopener
  extend self

  def trap(signal)
    require "unicorn"
    require "benchmark"

    # Funky construction here: Signal.trap returns the previous trap, so we
    # can refer to our own return value to chain handlers. (Puma's default
    # handler broadcasts HUP to workers and reopens stdout/stderr in each.)
    previous = Signal.trap(signal) do
      yield reopen_logs
      previous.call
    end
  end

  def reopen_logs
    timed { Unicorn::Util.reopen_logs }
  end

  private
    def timed
      result = nil
      ms = 1000 * Benchmark.realtime { result = yield }
      return result, ms
    end
end

# Install the HUP handler as early as we can, before the whole app boots.
# Mimic Puma-esque log output indicating logfile reopens and delays.
LogReopener.trap "SIGHUP" do |count, elapsed|
  puts "[#{Process.pid}] ! SIGHUP: reopened #{count} logfiles in #{elapsed.round}ms"
end