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

Uncaught SignalException SIGTERM #1438

Closed
wodka opened this issue Oct 11, 2017 · 14 comments
Closed

Uncaught SignalException SIGTERM #1438

wodka opened this issue Oct 11, 2017 · 14 comments

Comments

@wodka
Copy link

wodka commented Oct 11, 2017

Steps to reproduce

  1. setup heroku with puma

  2. restart app

  3. exception is thrown

screen shot 2017-10-11 at 10 02 11

this seems to be related to #1337 and can be reproduces without heroku (thx @dekellum)
#1337 (comment)

Expected behavior

no exception is thrown

Actual behavior

exception is thrown

System configuration

Ruby version: 2.2.5
Rails version: 4.2.9
Puma version: 3.10

@dekellum
Copy link
Contributor

Unless there are any objections or better ideas, I will attempt to open/link an issue and PR with bundler, to hopefully get the issue fixed there. Please reply here if anyone thinks my interpretation of this being a bundler issue is wrong.

cc: @shayonj @schneems

@shayonj
Copy link
Contributor

shayonj commented Oct 12, 2017

Nice one @dekellum! I was able to replicate the issue using bundle exec puma and sending a TERM signal to the server.

@dekellum
Copy link
Contributor

My fix and test for rubygems/bundler#6090 was merged to master and will presumably be released in the next bundler 1.16.x and possibly backported if they are still maintaining 1.15.x. In the interim, linked issue also gives details on two possible workarounds: using a bundle binstub, or setting bundle config disable_exec_load true

I would suggest that a puma committer can now close this issue. This could also be noted in puma release notes as a known issue, referencing the bundler issue.

@dekellum
Copy link
Contributor

cc: @nateberkopec

@nateberkopec
Copy link
Member

👋 Thanks.

@zquestz
Copy link

zquestz commented Dec 16, 2017

This thread saved me a lot of time. Thank you for the info and quick fix.

mrnugget added a commit to mrnugget/bugsnag-ruby that referenced this issue Jul 20, 2018
The previous behaviour resulted in applications reporting errors even
though they were gracefully and without any problems shut down. Example:
the puma webserver relies on `SIGTERM` to gracefully shut down its
workers and Bugsnag reported errors when it was normally shut down.

For more information on puma's behaviour, see here:

    puma/puma#1438

With the `at_exit` handler introduced in bugsnag#397, Bugsnag would catch
`SignalExceptions` on exit and report them as error, even though they
are none.

This PR changes the existing behaviour to add `SignalException` as a
special case in which the exception should not be passed to
`Bugsnag.notify`.

Due to the Ruby exiting when a `SignalException` is raised I had to
refactor the code to make the actual handling of the exit-exceptions
testable without the test suite quitting.
@burnettk
Copy link

From https://www.rubydoc.info/gems/puma/Puma%2FDSL:raise_exception_on_sigterm, documenting the puma config option "raise_exception_on_sigterm" that was added in puma version 4 in the context of #1690:

In environments where SIGTERM is something expected, instructing puma to shutdown gracefully ( for example in Kubernetes, where rolling restart is guaranteed usually on infrastructure level ) SignalException should not be raised for SIGTERM

When set to false, if puma process receives SIGTERM, it won't raise SignalException

@feliperaul
Copy link

I'm using Puma 4 and as far as I could understand for the systemd documentation, with socket activation you ARE going to kill workers with SIGTERM, because there's no ExecStop in the example service files (socket or service) telling to use USR2 or otherwise, right?

So, if one is using systemd with socket activation (a pretty standard deployment IMHO), we should either (1) just ignore this sigterm in our exception handling or (2) set raise_exception_on_sigterm false false in puma's config, but that can have unintended side effects.

Am I getting this right? Or my systemctl restart puma should not be sending SIGTERM ?

@AndrewSouthpaw
Copy link

I wanted to check in on this thread... @dekellum I'm running on bundler 2.1.4 which I believe should include your bundler fix. Yet we're still often getting SignalException errors to Rollbar from our dynos:

13:51:30.9 heroku web.1 - - Restarting
13:51:30.9 heroku web.1 - - State changed from up to starting
13:51:32.0 app web.1 - - [3] - Gracefully shutting down workers...
13:51:32.0 app web.1 - - agentmon: Got signal terminated. Shutting down.
13:51:32.1 heroku web.1 - - Stopping all processes with SIGTERM
13:51:32.5 app web.1 - - [3] worker status: pid 35 exit 0
13:51:32.5 app web.1 - - [3] worker status: pid 38 exit 0
13:51:32.5 app web.1 - - [3] worker shutdown time: 0.50
13:51:32.7 heroku web.1 - - Process exited with status 143

Same thing happens for our worker dynos.

I'm wondering if a logtrace like this one indicates that we actually do have your fix, and it's something else that's fiddly with Heroku that's sending errors off to Rollbar?

I've come across the switch for turning off raising SignalException on SIGTERM from puma, but I'm concerned that would have unexpected downstream effects.

Are other people encountering these issues at all?

@shanthakumarf22
Copy link

@AndrewSouthpaw +1. got this in our ECS servers with no relevant change in application code.

@MSP-Greg
Copy link
Member

I've been working on a re-write of the test suite, and added a few 'shutdown' related tests. I'm still trying to sort out what's happening in terms of single/cluster, halt/stop/graceful-stop, etc.

One of the failures was a bad exit code, another was a unix bind path that wasn't being unlinked...

@AndrewSouthpaw
Copy link

Thanks for the feedback!

For our case, I narrowed it down to an issue where an unhandled SignalException is emitted when a worker spins up and immediately is told to turn off before it can finish booting. (We had an autoscaling system that was sometimes telling workers to turn off/on within the same second.)

When we changed the logic so that a boot/shutdown would only be initialized once per minute, our errors went away.

Hope that maybe helps others in their investigation!

@okuramasafumi
Copy link
Contributor

We've been having the same issue on Heroku with Puma 5.3.2 and Bundler 2.2.21. It emits lots of exceptions to our error tracking system.
It's interesting that the app with similar setup doesn't have this issue. The only difference is that it doesn't call preload_app!.
Is Heroku "environments where SIGTERM is something expected"? If so, I'll send a PR to mention Heroku in the comment.

@rgaufman
Copy link

rgaufman commented Jan 6, 2022

We get the same, when we push a new version and restart the server, we get:

SignalException:  SIGTERM
/gems/bootsnap-1.9.3/lib/bootsnap/compile_cache/iseq.rb:24 in compile_file
/gems/bootsnap-1.9.3/lib/bootsnap/compile_cache/iseq.rb:24 in input_to_storage
/gems/bootsnap-1.9.3/lib/bootsnap/compile_cache/iseq.rb:55 in fetch
/gems/bootsnap-1.9.3/lib/bootsnap/compile_cache/iseq.rb:55 in fetch
/gems/bootsnap-1.9.3/lib/bootsnap/compile_cache/iseq.rb:80 in load_iseq
/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:23 in require
/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:23 in block in require_with_bootsnap_lfi
/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/loaded_features_index.rb:100 in register
/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:22 in require_with_bootsnap_lfi
/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:31 in require
/gems/activesupport-6.1.4.4/lib/active_support/dependencies.rb:332 in block in require
/gems/activesupport-6.1.4.4/lib/active_support/dependencies.rb:299 in load_dependency
/gems/activesupport-6.1.4.4/lib/active_support/dependencies.rb:332 in require
/gems/actionmailer-6.1.4.4/lib/action_mailer/base.rb:10 in <main>
/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:23 in require
/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:23 in block in require_with_bootsnap_lfi
/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/loaded_features_index.rb:100 in register
/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:22 in require_with_bootsnap_lfi
/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:31 in require
/gems/activesupport-6.1.4.4/lib/active_support/dependencies.rb:332 in block in require
/gems/activesupport-6.1.4.4/lib/active_support/dependencies.rb:299 in load_dependency
/gems/activesupport-6.1.4.4/lib/active_support/dependencies.rb:332 in require
/gems/actionmailer-6.1.4.4/lib/action_mailer/railtie.rb:73 in block (2 levels) in <class:Railtie>
/gems/activesupport-6.1.4.4/lib/active_support/lazy_load_hooks.rb:73 in instance_eval
/gems/activesupport-6.1.4.4/lib/active_support/lazy_load_hooks.rb:73 in block in execute_hook
/gems/activesupport-6.1.4.4/lib/active_support/lazy_load_hooks.rb:61 in with_execution_control
/gems/activesupport-6.1.4.4/lib/active_support/lazy_load_hooks.rb:66 in execute_hook
/gems/activesupport-6.1.4.4/lib/active_support/lazy_load_hooks.rb:52 in block in run_load_hooks
/gems/activesupport-6.1.4.4/lib/active_support/lazy_load_hooks.rb:51 in each
/gems/activesupport-6.1.4.4/lib/active_support/lazy_load_hooks.rb:51 in run_load_hooks
/gems/railties-6.1.4.4/lib/rails/application/finisher.rb:140 in block in <module:Finisher>
/gems/railties-6.1.4.4/lib/rails/initializable.rb:32 in instance_exec
/gems/railties-6.1.4.4/lib/rails/initializable.rb:32 in run
/gems/railties-6.1.4.4/lib/rails/initializable.rb:61 in block in run_initializers
/usr/local/lib/ruby/3.0.0/tsort.rb:228 in block in tsort_each
/usr/local/lib/ruby/3.0.0/tsort.rb:350 in block (2 levels) in each_strongly_connected_component
/usr/local/lib/ruby/3.0.0/tsort.rb:431 in each_strongly_connected_component_from
/usr/local/lib/ruby/3.0.0/tsort.rb:349 in block in each_strongly_connected_component
/usr/local/lib/ruby/3.0.0/tsort.rb:347 in each
/usr/local/lib/ruby/3.0.0/tsort.rb:347 in call
/usr/local/lib/ruby/3.0.0/tsort.rb:347 in each_strongly_connected_component
/usr/local/lib/ruby/3.0.0/tsort.rb:226 in tsort_each
/usr/local/lib/ruby/3.0.0/tsort.rb:205 in tsort_each
/gems/railties-6.1.4.4/lib/rails/initializable.rb:60 in run_initializers
/gems/railties-6.1.4.4/lib/rails/application.rb:391 in initialize!
config/environment.rb:7 in <top (required)>
/gems/activesupport-6.1.4.4/lib/active_support/dependencies.rb:332 in require
/gems/activesupport-6.1.4.4/lib/active_support/dependencies.rb:332 in block in require
/gems/activesupport-6.1.4.4/lib/active_support/dependencies.rb:299 in load_dependency
/gems/activesupport-6.1.4.4/lib/active_support/dependencies.rb:332 in require
/gems/sidekiq-6.3.1/lib/sidekiq/cli.rb:273 in boot_application
/gems/sidekiq-6.3.1/lib/sidekiq/cli.rb:37 in run
/gems/sidekiq-6.3.1/bin/sidekiq:31 in <top (required)>
/bin/sidekiq:25 in load
/bin/sidekiq:25 in <top (required)>
/usr/local/lib/ruby/3.0.0/bundler/cli/exec.rb:58 in load
/usr/local/lib/ruby/3.0.0/bundler/cli/exec.rb:58 in kernel_load
/usr/local/lib/ruby/3.0.0/bundler/cli/exec.rb:23 in run
/usr/local/lib/ruby/3.0.0/bundler/cli.rb:478 in exec
/usr/local/lib/ruby/3.0.0/bundler/vendor/thor/lib/thor/command.rb:27 in run
/usr/local/lib/ruby/3.0.0/bundler/vendor/thor/lib/thor/invocation.rb:127 in invoke_command
/usr/local/lib/ruby/3.0.0/bundler/vendor/thor/lib/thor.rb:392 in dispatch
/usr/local/lib/ruby/3.0.0/bundler/cli.rb:31 in dispatch
/usr/local/lib/ruby/3.0.0/bundler/vendor/thor/lib/thor/base.rb:485 in start
/usr/local/lib/ruby/3.0.0/bundler/cli.rb:25 in start
/usr/local/lib/ruby/gems/3.0.0/gems/bundler-2.2.32/libexec/bundle:49 in block in <top (required)>
/usr/local/lib/ruby/3.0.0/bundler/friendly_errors.rb:103 in with_friendly_errors
/usr/local/lib/ruby/gems/3.0.0/gems/bundler-2.2.32/libexec/bundle:37 in <top (required)>
/usr/local/bin/bundle:23 in load
/usr/local/bin/bundle:23 in <main>

Any solution to this?

gnclmorais added a commit to gnclmorais/planner that referenced this issue Oct 16, 2022
Looking at our Rollbar quota, the large majority of the errors we get
there come from, I believe, the recurring Heroku restart that happens.
I see no reason to report these to Rollbar, since they are expected
and, at least while using Heroku, necessary.

Luckily, looks like [Puma has an option for this][0], so it makes sense
to me to turn it on (or rather off, since we’re setting it to `false`).
[Found it][1] while doing some research on this subject, since I’ve had
a feeling I’ve seen it before.

[0]: https://www.rubydoc.info/gems/puma/Puma%2FDSL:raise_exception_on_sigterm
[1]: puma/puma#1438
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests