From e87d82db0a76b4c4cb7a804c88cb5042bde7abe8 Mon Sep 17 00:00:00 2001 From: Daniel Colson Date: Sun, 10 Nov 2019 22:46:04 -0500 Subject: [PATCH] Log threads as JSON in control app With this commit the status app sends the thread backtraces as an array of objects with `name` and `backtrace` keys, rather than as a string matching the SIGINFO output. While working on this I noticed that we logged the thread TID twice. This commit simplifies that so we only log the thread TID once, with both the label (I don't know when the label would get set) and name if they are available. --- lib/puma/app/status.rb | 9 ++++++--- lib/puma/launcher.rb | 21 ++++++++++----------- test/test_integration_cluster.rb | 2 +- test/test_integration_single.rb | 2 +- test/test_launcher.rb | 8 ++++---- 5 files changed, 22 insertions(+), 20 deletions(-) diff --git a/lib/puma/app/status.rb b/lib/puma/app/status.rb index f4ef9f2eeb..19f6d877de 100644 --- a/lib/puma/app/status.rb +++ b/lib/puma/app/status.rb @@ -57,9 +57,12 @@ def call(env) rack_response(200, @cli.stats) when /\/thread-backtraces$/ - strings = Puma::Events.strings - @cli.log_thread_status(strings) - rack_response(200, strings.stdout.string) + backtraces = [] + @cli.thread_status do |name, backtrace| + backtraces << { name: name, backtrace: backtrace } + end + + rack_response(200, backtraces.to_json) else rack_response 404, "Unsupported action", 'text/plain' end diff --git a/lib/puma/launcher.rb b/lib/puma/launcher.rb index 0c93fb7663..81ba457051 100644 --- a/lib/puma/launcher.rb +++ b/lib/puma/launcher.rb @@ -205,18 +205,14 @@ def close_binder_listeners @binder.close_listeners end - def log_thread_status(events) + def thread_status 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 + name = "Thread: TID-#{thread.object_id.to_s(36)}" + name += " #{thread['label']}" if thread['label'] + name += " #{thread.name}" if thread.respond_to?(:name) && thread.name + backtrace = thread.backtrace || [""] - if thread.backtrace - events.log thread.backtrace.join("\n") - else - events.log "" - end + yield name, backtrace end end @@ -457,7 +453,10 @@ def setup_signals begin Signal.trap "SIGINFO" do - log_thread_status(@events) + thread_status do |name, backtrace| + @events.log name + @events.log backtrace + end end rescue Exception # Not going to log this one, as SIGINFO is *BSD only and would be pretty annoying diff --git a/test/test_integration_cluster.rb b/test/test_integration_cluster.rb index 9679f274fb..a7f58f84ec 100644 --- a/test/test_integration_cluster.rb +++ b/test/test_integration_cluster.rb @@ -44,7 +44,7 @@ def test_siginfo_thread_print Process.kill :INT , @pid t.join - assert_match "Thread TID", output.join + assert_match "Thread: TID", output.join end def test_usr2_restart diff --git a/test/test_integration_single.rb b/test/test_integration_single.rb index 8325231f50..7f44fde5fb 100644 --- a/test/test_integration_single.rb +++ b/test/test_integration_single.rb @@ -99,6 +99,6 @@ def test_siginfo_thread_print Process.kill :INT , @pid t.join - assert_match "Thread TID", output.join + assert_match "Thread: TID", output.join end end diff --git a/test/test_launcher.rb b/test/test_launcher.rb index 46b1f721ba..421703e2f7 100644 --- a/test/test_launcher.rb +++ b/test/test_launcher.rb @@ -57,10 +57,10 @@ def test_puma_wild_location_is_an_absolute_path end def test_prints_thread_traces - launcher.log_thread_status(events) - events.stdout.rewind - - assert_match "Thread TID", events.stdout.read + launcher.thread_status do |name, backtrace| + assert_match "Thread: TID", name + refute_predicate backtrace, :empty? + end end def test_pid_file