reopen logs

.gitignore

@@ -16,3 +16,4 @@ Gemfile.lock
 /test/test_puma.state
 /test/test_server.sock
 /test/test_control.sock
+/vendor

lib/puma/dsl.rb

@@ -461,6 +461,10 @@ def shutdown_debug(val=true)
       @options[:shutdown_debug] = val
     end
 
+    def reopen_logs(val=true)
+      @options[:reopen_logs] = val
+    end
+
     # Control how the remote address of the connection is set. This
     # is configurable because to calculate the true socket peer address
     # a kernel syscall is required which for very fast rack handlers

lib/puma/launcher.rb

@@ -418,6 +418,11 @@ def setup_signals
       begin
         Signal.trap "SIGHUP" do
           if @runner.redirected_io?
+            begin
+              @runner.reopen_logs if @runner.reopen_logs?
+            rescue Exception => e
+              log "*** SIGHUP: unable to reopen logs: #{e.class.name}:#{e.message}#{e.backtrace.join("\n")}"
+            end
             @runner.redirect_io
           else
             stop

lib/puma/runner.rb

@@ -1,5 +1,6 @@
 require 'puma/server'
 require 'puma/const'
+require 'fcntl'
 
 module Puma
   # Generic class that is used by `Puma::Cluster` and `Puma::Single` to
@@ -104,6 +105,76 @@ def output_header(mode)
       end
     end
 
+    def should_reopen?(fd)
+      append_flags = File::WRONLY | File::APPEND
+
+      if fd.closed?
+        return false
+      end
+
+      is_append = (fd.fcntl(Fcntl::F_GETFL) & append_flags) == append_flags
+      if fd.stat.file? && fd.sync && is_append
+        return true
+      end
+      return false
+    rescue IOError, Errno::EBADF
+      false
+    end
+
+    def reopen_log(fd)
+      orig_stat = begin
+        fd.stat
+      rescue IOError, Errno::EBADF => e
+        STDOUT.puts "#{e.class.name} #{e.message} #{e.backtrace.join("\n")}"
+        return
+      end
+
+      # We only need files which were moved on disk
+      begin
+        new_stat = File.stat(fd.path)
+        if orig_stat.dev == new_stat.dev && orig_stat.ino == new_stat.ino
+          return
+        end
+      rescue Errno::ENOENT => e
+        STDOUT.puts "#{e.class.name} #{e.message} #{e.backtrace.join("\n")}"
+      end
+
+      STDOUT.puts "=== puma rotating log file #{fd.path} at #{Time.now} ==="
+
+      begin
+        fd.reopen(fd.path, "a")
+      rescue IOError, Errno::EBADF => e
+        STDOUT.puts "#{e.class.name} #{e.message} #{e.backtrace.join("\n")}"
+        return
+      end
+
+      # this is required to create the new file right away
+      fd.sync = true
+      fd.flush
+
+      new_stat = fd.stat
+
+      if orig_stat.uid != new_stat.uid || orig_stat.gid != new_stat.gid
+        fd.chown(orig_stat.uid, orig_stat.gid)
+      end
+    end
+
+    def reopen_logs?
+      @options[:reopen_logs]
+    end
+
+    def reopen_logs
+      fds = []
+
+      ObjectSpace.each_object(File) do |fd|
+        if should_reopen?(fd)
+          fds << fd
+        end
+      end
+
+      fds.each { |fd| reopen_log(fd) }
+    end
+
     def redirected_io?
       @options[:redirect_stdout] || @options[:redirect_stderr]
     end
@@ -120,7 +191,7 @@ def redirect_io
 
         STDOUT.reopen stdout, (append ? "a" : "w")
         STDOUT.sync = true
-        STDOUT.puts "=== puma startup: #{Time.now} ==="
+        STDOUT.puts "=== puma redirects stdout: #{Time.now} ==="
       end
 
       if stderr
@@ -130,7 +201,7 @@ def redirect_io
 
         STDERR.reopen stderr, (append ? "a" : "w")
         STDERR.sync = true
-        STDERR.puts "=== puma startup: #{Time.now} ==="
+        STDERR.puts "=== puma redirects stderr: #{Time.now} ==="
       end
     end
 

t4-pid

@@ -0,0 +1 @@
+21431

test/rackup/hello-logs.ru

@@ -0,0 +1,15 @@
+require 'logger'
+class AppWithLogger
+  def initialize
+    @logger = Logger.new('test/log.log')
+  end
+
+  def call(env)
+    puts "write to log"
+    @logger.info "hello"
+    #p @logger.instance_variable_get(:@logdev)
+    [200, {"Content-Type" => "text/plain"}, ["Hello World"]]
+  end
+end
+
+run AppWithLogger.new

test/shell/run.rb

@@ -1,4 +1,4 @@
-results = %w[t1 t2 t3].map do |test|
+results = %w[t1 t2 t3 t4].map do |test|
   system("ruby -rrubygems test/shell/#{test}.rb ") # > /dev/null 2>&1
 end
 

test/shell/t4.rb

@@ -0,0 +1,38 @@
+system "rm test/log.log*"
+
+system "ruby -rrubygems -Ilib bin/pumactl -F test/shell/t4_conf.rb start"
+sleep 5
+worker_pid = `ps aux | grep puma | grep worker`.split[1]
+
+system "curl http://localhost:10104"
+system "mv test/log.log test/log.log.1"
+system "ps aux | grep puma"
+system "kill -HUP `cat t4-pid`"
+sleep 8
+
+system "echo 'exec request 8s'"
+system "curl http://localhost:10104"
+sleep 1
+
+system "ruby -rrubygems -Ilib bin/pumactl -F test/shell/t4_conf.rb stop"
+
+def cleanup
+  system "rm test/log.log*"
+  system "rm t4-stdout"
+  system "rm t4-stderr"
+end
+
+if `ps aux | grep puma | grep worker`.split[1] != worker_pid
+  cleanup
+  puts "worker pid changed"
+  exit 1
+end
+
+if File.size("test/log.log") == 0
+  cleanup
+  puts "nothing written to reopened log file"
+  exit 1
+end
+
+cleanup
+exit 0

test/shell/t4_conf.rb

@@ -0,0 +1,7 @@
+pidfile "t4-pid"
+bind 'tcp://0.0.0.0:10104'
+rackup File.expand_path('../rackup/hello-logs.ru', File.dirname(__FILE__))
+reopen_logs
+stdout_redirect "t4-stdout", "t4-stderr", true
+daemonize
+workers 1