From b03f20d3b5dc401b3c40d2930d3e64a8b258c474 Mon Sep 17 00:00:00 2001 From: Nate Berkopec Date: Sat, 3 Jun 2017 10:33:20 -0600 Subject: [PATCH] SIGINFO prints thread backtraces Super basic server test Add tests for single/cluster Cleanup --- lib/puma/cluster.rb | 6 +++--- lib/puma/launcher.rb | 20 ++++++++++++++++++++ test/helpers/integration.rb | 2 +- test/test_integration_cluster.rb | 16 +++++++++++++++- test/test_integration_single.rb | 13 +++++++++++++ test/test_launcher.rb | 10 ++++++++++ test/test_puma_server.rb | 7 +------ 7 files changed, 63 insertions(+), 11 deletions(-) diff --git a/lib/puma/cluster.rb b/lib/puma/cluster.rb index d580b22a4e..5c6c610ffb 100644 --- a/lib/puma/cluster.rb +++ b/lib/puma/cluster.rb @@ -272,7 +272,7 @@ def worker(index, master) Signal.trap "SIGTERM" do server.stop end - + begin @worker_write << "b#{Process.pid}\n" rescue SystemCallError, IOError @@ -346,8 +346,8 @@ def reload_worker_directory log "+ Changing to #{dir}" Dir.chdir dir end - - # Inside of a child process, this will return all zeroes, as @workers is only populated in + + # Inside of a child process, this will return all zeroes, as @workers is only populated in # the master process. def stats old_worker_count = @workers.count { |w| w.phase != @phase } diff --git a/lib/puma/launcher.rb b/lib/puma/launcher.rb index 071035e764..2078a125b9 100644 --- a/lib/puma/launcher.rb +++ b/lib/puma/launcher.rb @@ -325,6 +325,17 @@ def graceful_stop log "- Goodbye!" end + def log_thread_status + Thread.list.each do |thread| + @events.log "Thread TID-#{thread.object_id.to_s(36)} #{thread['label']}" + if thread.backtrace + @events.log thread.backtrace.join("\n") + else + @events.log "" + end + end + end + def set_process_title Process.respond_to?(:setproctitle) ? Process.setproctitle(title) : $0 = title end @@ -441,6 +452,15 @@ def setup_signals rescue Exception log "*** SIGHUP not implemented, signal based logs reopening unavailable!" end + + begin + Signal.trap "SIGINFO" do + log_thread_status + end + rescue Exception + # Not going to log this one, as SIGINFO is *BSD only and would be pretty annoying + # to see this constantly on Linux. + end end def require_rubygems_min_version!(min_version, feature) diff --git a/test/helpers/integration.rb b/test/helpers/integration.rb index 9dd6067139..31608ef880 100644 --- a/test/helpers/integration.rb +++ b/test/helpers/integration.rb @@ -97,7 +97,7 @@ def read_body(connection) end # gets worker pids from @server output - def get_worker_pids(phase, size = WORKERS) + def get_worker_pids(phase = 0, size = WORKERS) pids = [] re = /pid: (\d+)\) booted, phase: #{phase}/ while pids.size < size diff --git a/test/test_integration_cluster.rb b/test/test_integration_cluster.rb index c2c9efcb0f..67e0bf3724 100644 --- a/test/test_integration_cluster.rb +++ b/test/test_integration_cluster.rb @@ -8,6 +8,20 @@ def setup super end + def test_siginfo_thread_print + skip_unless_signal_exist? :INFO + + cli_server("-w #{WORKERS} -q test/rackup/hello.ru") + worker_pids = get_worker_pids + output = [] + t = Thread.new { output << @server.readlines } + Process.kill(:INFO, worker_pids.first) + Process.kill(:INT, @server.pid) + t.join + + assert_match "Thread TID", output.join + end + def test_usr2_restart _, new_reply = restart_server_and_listen("-q -w #{WORKERS} test/rackup/hello.ru") assert_equal "Hello World", new_reply @@ -92,7 +106,7 @@ def test_term_worker_clean_exit pid = cli_server("-w #{WORKERS} test/rackup/hello.ru").pid # Get the PIDs of the child workers. - worker_pids = get_worker_pids 0 + worker_pids = get_worker_pids # Signal the workers to terminate, and wait for them to die. Process.kill :TERM, pid diff --git a/test/test_integration_single.rb b/test/test_integration_single.rb index 59fe811708..883974bb90 100644 --- a/test/test_integration_single.rb +++ b/test/test_integration_single.rb @@ -84,4 +84,17 @@ def test_int_signal_with_background_thread_in_jruby assert_raises(Errno::ECONNREFUSED) { TCPSocket.new(HOST, @tcp_port) } end + + def test_siginfo_thread_print + skip_unless_signal_exist? :INFO + + cli_server("test/rackup/hello.ru") + output = [] + t = Thread.new { output << @server.readlines } + Process.kill(:INFO, @server.pid) + Process.kill(:INT, @server.pid) + t.join + + assert_match "Thread TID", output.join + end end diff --git a/test/test_launcher.rb b/test/test_launcher.rb index 2ed5dd0796..e7ca5ebf7c 100644 --- a/test/test_launcher.rb +++ b/test/test_launcher.rb @@ -60,4 +60,14 @@ def test_puma_wild_location_is_an_absolute_path # assert no "/../" in path refute_match(%r{/\.\./}, puma_wild_location) end + + def test_prints_thread_traces + events = Puma::Events.strings + l = Puma::Launcher.new(Puma::Configuration.new, events: events) + + l.send(:log_thread_status) + events.stdout.rewind + + assert_match "Thread TID", events.stdout.read + end end diff --git a/test/test_puma_server.rb b/test/test_puma_server.rb index 42ed7b0685..a664b71103 100644 --- a/test/test_puma_server.rb +++ b/test/test_puma_server.rb @@ -9,7 +9,7 @@ def setup @app = lambda { |env| [200, {}, [env['rack.url_scheme']]] } - @events = Puma::Events.new STDOUT, STDERR + @events = Puma::Events.strings @server = Puma::Server.new @app, @events end @@ -280,9 +280,6 @@ def test_GET_with_no_body_has_sane_chunking end def test_doesnt_print_backtrace_in_production - @events = Puma::Events.strings - @server = Puma::Server.new @app, @events - @server.app = proc { |e| raise "don't leak me bro" } @server.leak_stack_on_error = false @server.add_tcp_listener @host, @port @@ -298,7 +295,6 @@ def test_doesnt_print_backtrace_in_production end def test_prints_custom_error - @events = Puma::Events.strings re = lambda { |err| [302, {'Content-Type' => 'text', 'Location' => 'foo.html'}, ['302 found']] } @server = Puma::Server.new @app, @events, {:lowlevel_error_handler => re} @@ -314,7 +310,6 @@ def test_prints_custom_error end def test_leh_gets_env_as_well - @events = Puma::Events.strings re = lambda { |err,env| env['REQUEST_PATH'] || raise("where is env?") [302, {'Content-Type' => 'text', 'Location' => 'foo.html'}, ['302 found']]