From cd914052f503556843b8d7fbfc8a65e92f7c1343 Mon Sep 17 00:00:00 2001 From: Daniel Colson Date: Fri, 25 Oct 2019 21:46:12 -0400 Subject: [PATCH] Add pumactl command to print thread backtraces Completes 1 of 2 items from #1964 This commit adds an endpoint to the status app to print thread backtraces, and control cli command to call that endpoint. I tried this locally by starting a server with: ```sh bundle exec bin/puma test/rackup/hello.ru \ --control-url="unix://test.sock" \ --control-token="token" ``` and then printing the backtraces with: ```sh bundle exec bin/pumactl thread-backtraces \ --control-url="unix://test.sock" \ --control-token="token" ``` --- History.md | 2 +- lib/puma/app/status.rb | 5 +++++ lib/puma/control_cli.rb | 5 +++-- lib/puma/launcher.rb | 32 ++++++++++++++++---------------- test/test_cli.rb | 24 ++++++++++++++++++++++++ test/test_launcher.rb | 2 +- 6 files changed, 50 insertions(+), 20 deletions(-) diff --git a/History.md b/History.md index ec0adbbfb5..7440540b99 100644 --- a/History.md +++ b/History.md @@ -1,7 +1,7 @@ ## Master * Features - * Your feature goes here (#Github Number) + * Add pumactl `thread-backtraces` command to print thread backtraces (#2053) * Bugfixes * Your bugfix goes here (#Github Number) diff --git a/lib/puma/app/status.rb b/lib/puma/app/status.rb index 2e4b4e4c3e..f4ef9f2eeb 100644 --- a/lib/puma/app/status.rb +++ b/lib/puma/app/status.rb @@ -55,6 +55,11 @@ def call(env) when /\/stats$/ rack_response(200, @cli.stats) + + when /\/thread-backtraces$/ + strings = Puma::Events.strings + @cli.log_thread_status(strings) + rack_response(200, strings.stdout.string) else rack_response 404, "Unsupported action", 'text/plain' end diff --git a/lib/puma/control_cli.rb b/lib/puma/control_cli.rb index 6d4118f062..53cbd978d4 100644 --- a/lib/puma/control_cli.rb +++ b/lib/puma/control_cli.rb @@ -11,7 +11,8 @@ module Puma class ControlCLI - COMMANDS = %w{halt restart phased-restart start stats status stop reload-worker-directory gc gc-stats} + COMMANDS = %w{halt restart phased-restart start stats status stop reload-worker-directory gc gc-stats thread-backtraces} + PRINTABLE_COMMANDS = %w{gc-stats stats thread-backtraces} def initialize(argv, stdout=STDOUT, stderr=STDERR) @state = nil @@ -187,7 +188,7 @@ def send_request end message "Command #{@command} sent success" - message response.last if @command == "stats" || @command == "gc-stats" + message response.last if PRINTABLE_COMMANDS.include?(@command) end ensure server.close if server && !server.closed? diff --git a/lib/puma/launcher.rb b/lib/puma/launcher.rb index 2a0cd9be39..0c93fb7663 100644 --- a/lib/puma/launcher.rb +++ b/lib/puma/launcher.rb @@ -205,6 +205,21 @@ def close_binder_listeners @binder.close_listeners end + def log_thread_status(events) + Thread.list.each do |thread| + events.log "Thread TID-#{thread.object_id.to_s(36)} #{thread['label']}" + logstr = "Thread: TID-#{thread.object_id.to_s(36)}" + logstr += " #{thread.name}" if thread.respond_to?(:name) + events.log logstr + + if thread.backtrace + events.log thread.backtrace.join("\n") + else + events.log "" + end + end + end + private # If configured, write the pid of the current process out @@ -323,21 +338,6 @@ def graceful_stop log "- Goodbye!" end - def log_thread_status - Thread.list.each do |thread| - log "Thread TID-#{thread.object_id.to_s(36)} #{thread['label']}" - logstr = "Thread: TID-#{thread.object_id.to_s(36)}" - logstr += " #{thread.name}" if thread.respond_to?(:name) - log logstr - - if thread.backtrace - log thread.backtrace.join("\n") - else - log "" - end - end - end - def set_process_title Process.respond_to?(:setproctitle) ? Process.setproctitle(title) : $0 = title end @@ -457,7 +457,7 @@ def setup_signals begin Signal.trap "SIGINFO" do - log_thread_status + log_thread_status(@events) end rescue Exception # Not going to log this one, as SIGINFO is *BSD only and would be pretty annoying diff --git a/test/test_cli.rb b/test/test_cli.rb index d49236246a..e2e55f7b2f 100644 --- a/test/test_cli.rb +++ b/test/test_cli.rb @@ -203,6 +203,30 @@ def test_control_stop t.join if UNIX_SKT_EXIST end + def test_control_thread_backtraces + skip UNIX_SKT_MSG unless UNIX_SKT_EXIST + url = "unix://#{@tmp_path}" + + cli = Puma::CLI.new ["-b", "unix://#{@tmp_path2}", + "--control-url", url, + "--control-token", "", + "test/rackup/lobster.ru"], @events + + t = Thread.new { cli.run } + + wait_booted + + s = UNIXSocket.new @tmp_path + s << "GET /thread-backtraces HTTP/1.0\r\n\r\n" + body = s.read + s.close + + assert_match %r{Thread: TID-}, body.split("\r\n").last + ensure + cli.launcher.stop if cli + t.join if UNIX_SKT_EXIST + end + def control_gc_stats(uri, cntl) cli = Puma::CLI.new ["-b", uri, "--control-url", cntl, diff --git a/test/test_launcher.rb b/test/test_launcher.rb index 9de31b9152..46b1f721ba 100644 --- a/test/test_launcher.rb +++ b/test/test_launcher.rb @@ -57,7 +57,7 @@ def test_puma_wild_location_is_an_absolute_path end def test_prints_thread_traces - launcher.send(:log_thread_status) + launcher.log_thread_status(events) events.stdout.rewind assert_match "Thread TID", events.stdout.read