Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Thread backtrace printing - additional features #1964

Closed
1 of 2 tasks
nateberkopec opened this issue Sep 12, 2019 · 3 comments
Closed
1 of 2 tasks

Thread backtrace printing - additional features #1964

nateberkopec opened this issue Sep 12, 2019 · 3 comments
Labels

Comments

@nateberkopec
Copy link
Member

nateberkopec commented Sep 12, 2019

#1320 adds a SIGINFO handler that prints all current thread backtraces.

  • If the master of a cluster receives SIGINFO, it should fan out that signal to all of its children.
  • Add a pumactl command that does this, so platforms without SIGINFO can use this feature.
@Fudoshiki
Copy link
Contributor

puma master

=> Booting Puma
=> Rails 6.1.0.alpha application starting in development 
=> Run `rails server --help` for more startup options
Puma starting in single mode...
* Version 4.1.1 (ruby 2.6.4-p104), codename: Fourth and One
* Min threads: 5, max threads: 5
* Environment: development
* Listening on tcp://0.0.0.0:3000
Use Ctrl-C to stop
#<Thread:0x00000001180f7990@/Users/sharevari/.rvm/gems/ruby-2.6.4@hospital40/bundler/gems/puma-7e704b553c73/lib/puma/plugin.rb:66 run> terminated with exception (report_on_exception is true):
Traceback (most recent call last):
/Users/sharevari/.rvm/gems/ruby-2.6.4@hospital40/bundler/gems/puma-7e704b553c73/lib/puma/plugin.rb:67:in `block (2 levels) in fire_background': undefined method `set_thread_name' for #<Puma::PluginRegistry:0x0000000117b8c668> (NoMethodError)
Did you mean?  set_trace_func

@dentarg
Copy link
Member

dentarg commented Sep 16, 2019

@Fudoshiki I think you should open up a new issue (or PR), I believe it comes from this change: https://github.com/puma/puma/pull/1968/files#diff-e897820765f1098c2b56bc7417b49cdd

(Nice catch though)

@nateberkopec nateberkopec added this to the 5.0.0 milestone Sep 23, 2019
composerinteralia added a commit to composerinteralia/puma that referenced this issue Oct 25, 2019
Completes 1 of 2 items from puma#1964

This commit adds an endpoint to the status app to print thread
backtraces, and control cli command to call that endpoint.
composerinteralia added a commit to composerinteralia/puma that referenced this issue Oct 25, 2019
Completes 1 of 2 items from puma#1964

This commit adds an endpoint to the status app to print thread
backtraces, and control cli command to call that endpoint.
composerinteralia added a commit to composerinteralia/puma that referenced this issue Oct 25, 2019
Completes 1 of 2 items from puma#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"
```
composerinteralia added a commit to composerinteralia/puma that referenced this issue Oct 25, 2019
Completes 1 of 2 items from puma#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"
```
composerinteralia added a commit to composerinteralia/puma that referenced this issue Oct 26, 2019
Completes 1 of 2 items from puma#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"
```
composerinteralia added a commit to composerinteralia/puma that referenced this issue Oct 26, 2019
Completes 1 of 2 items from puma#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"
```
composerinteralia added a commit to composerinteralia/puma that referenced this issue Nov 11, 2019
Completes 1 of 2 items from puma#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"
```
nateberkopec pushed a commit that referenced this issue Nov 11, 2019
* 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"
```

* 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.
@nateberkopec nateberkopec removed this from the 5.0.0 milestone Feb 27, 2020
@dentarg
Copy link
Member

dentarg commented Feb 6, 2021

@nateberkopec this looks done?

[ ] If the master of a cluster receives SIGINFO, it should fan out that signal to all of its children.

$ puma -C test/config/settings.rb test/rackup/hello.ru
Puma starting in single mode...
* Puma version: 5.2.1 (ruby 2.7.1-p83) ("Fettisdagsbulle")
*  Min threads: 3
*  Max threads: 5
*  Environment: development
*          PID: 31798
* Listening on http://0.0.0.0:3000
Use Ctrl-C to stop
<kill -SIGINFO 31798 in another terminal window>
Thread: TID-pk
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/launcher.rb:233:in `backtrace'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/launcher.rb:233:in `block in thread_status'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/launcher.rb:229:in `each'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/launcher.rb:229:in `thread_status'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/launcher.rb:505:in `block in setup_signals'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/single.rb:61:in `join'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/single.rb:61:in `run'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/launcher.rb:181:in `run'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/cli.rb:80:in `run'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/bin/puma:10:in `<top (required)>'
  /Users/dentarg/.gem/ruby/2.7.1/bin/puma:23:in `load'
  /Users/dentarg/.gem/ruby/2.7.1/bin/puma:23:in `<main>'
Thread: TID-q4 puma threadpool 001
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/thread_pool.rb:131:in `sleep'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/thread_pool.rb:131:in `wait'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/thread_pool.rb:131:in `block (2 levels) in spawn_thread'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/thread_pool.rb:116:in `synchronize'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/thread_pool.rb:116:in `block in spawn_thread'
Thread: TID-qo puma threadpool 002
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/thread_pool.rb:131:in `sleep'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/thread_pool.rb:131:in `wait'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/thread_pool.rb:131:in `block (2 levels) in spawn_thread'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/thread_pool.rb:116:in `synchronize'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/thread_pool.rb:116:in `block in spawn_thread'
Thread: TID-r8 puma threadpool 003
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/thread_pool.rb:131:in `sleep'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/thread_pool.rb:131:in `wait'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/thread_pool.rb:131:in `block (2 levels) in spawn_thread'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/thread_pool.rb:116:in `synchronize'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/thread_pool.rb:116:in `block in spawn_thread'
Thread: TID-rs puma reactor
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/reactor.rb:75:in `select'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/reactor.rb:75:in `select_loop'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/reactor.rb:39:in `block in run'
Thread: TID-sc puma threadpool reaper
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/thread_pool.rb:308:in `sleep'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/thread_pool.rb:308:in `block in start!'
Thread: TID-sw puma threadpool trimmer
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/thread_pool.rb:308:in `sleep'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/thread_pool.rb:308:in `block in start!'
Thread: TID-tg puma server
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/server.rb:324:in `select'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/server.rb:324:in `handle_servers'
  /Users/dentarg/.gem/ruby/2.7.1/gems/puma-5.2.1/lib/puma/server.rb:259:in `block in run'

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

3 participants