Heroku logs FATAL SignalException: SIGTERM
Asked Answered
S

2

9

I don't understand why I am getings this FATAL exception. It works just fine in localhost.

I understand that SIGTERM is simply a signal to terminate the program, and I don't believe the solution is to handle or ignore it.

When I look at the deployed website it displays as a white page. How can I fix this error so that my app can display normally?

Here are my Heroku logs:

2014-04-23T20:59:57.995734+00:00 app[web.1]:    /app/vendor/ruby-2.0.0/lib/ruby/2.0.0/webrick/server.rb:170:in `block in start'
2014-04-23T20:59:57.995789+00:00 app[web.1]:    /app/vendor/ruby-2.0.0/lib/ruby/2.0.0/webrick/server.rb:32:in `start'
2014-04-23T20:59:57.995875+00:00 app[web.1]:    /app/vendor/ruby-2.0.0/lib/ruby/2.0.0/webrick/server.rb:160:in `start'
2014-04-23T20:59:57.995933+00:00 app[web.1]:    /app/vendor/bundle/ruby/2.0.0/gems/rack-1.5.2/lib/rack/handler/webrick.rb:14:in `run'
2014-04-23T20:59:57.995988+00:00 app[web.1]:    /app/vendor/bundle/ruby/2.0.0/gems/rack-1.5.2/lib/rack/server.rb:264:in `start'
2014-04-23T20:59:57.996042+00:00 app[web.1]:    /app/vendor/bundle/ruby/2.0.0/gems/railties-4.0.4/lib/rails/commands/server.rb:84:in `start'
2014-04-23T20:59:57.996552+00:00 app[web.1]:    /app/vendor/bundle/ruby/2.0.0/gems/railties-4.0.4/lib/rails/commands.rb:71:in `<top (required)>'
2014-04-23T20:59:57.996843+00:00 app[web.1]: [2014-04-23 20:59:57] INFO  WEBrick::HTTPServer#start done.
2014-04-23T20:59:57.996932+00:00 app[web.1]: Exiting
2014-04-23T20:59:57.996466+00:00 app[web.1]:    /app/vendor/bundle/ruby/2.0.0/gems/railties-4.0.4/lib/rails/commands.rb:71:in `tap'
2014-04-23T20:59:57.996333+00:00 app[web.1]:    /app/vendor/bundle/ruby/2.0.0/gems/railties-4.0.4/lib/rails/commands.rb:76:in `block in <top (required)>'
2014-04-23T20:59:57.996777+00:00 app[web.1]: [2014-04-23 20:59:57] INFO  going to shutdown ...
2014-04-23T20:59:57.996607+00:00 app[web.1]:    bin/rails:4:in `require'
2014-04-23T20:59:57.996688+00:00 app[web.1]:    bin/rails:4:in `<main>'
2014-04-23T20:59:59.247265+00:00 heroku[web.1]: Process exited with status 143
2014-04-23T21:08:58.674758+00:00 heroku[web.1]: State changed from down to starting
2014-04-23T21:08:58.674486+00:00 heroku[web.1]: Unidling
2014-04-23T21:09:01.944699+00:00 heroku[web.1]: Starting process with command `bin/rails server -p 10144 -e production`
2014-04-23T21:09:04.904686+00:00 heroku[web.1]: State changed from starting to up
2014-04-23T21:09:05.944216+00:00 app[web.1]: => Booting WEBrick
2014-04-23T21:09:04.858787+00:00 app[web.1]: [2014-04-23 21:09:04] INFO  ruby 2.0.0 (2014-02-24) [x86_64-linux]
2014-04-23T21:09:04.859359+00:00 app[web.1]: [2014-04-23 21:09:04] INFO  WEBrick::HTTPServer#start: pid=2 port=10144
2014-04-23T21:09:04.858787+00:00 app[web.1]: [2014-04-23 21:09:04] INFO  WEBrick 1.3.1
2014-04-23T21:09:05.944216+00:00 app[web.1]: => Rails 4.0.4 application starting in production on http://0.0.0.0:10144
2014-04-23T21:09:05.944216+00:00 app[web.1]: => Run `rails server -h` for more startup options
2014-04-23T21:09:05.944216+00:00 app[web.1]: => Ctrl-C to shutdown server
2014-04-23T21:09:05.944216+00:00 app[web.1]: Started GET "/" for 67.169.92.237 at 2014-04-23 21:09:05 +0000
2014-04-23T21:09:05.944216+00:00 app[web.1]: Started GET "/" for 67.169.92.237 at 2014-04-23 21:09:05 +0000
2014-04-23T21:09:08.210054+00:00 app[web.1]: Processing by ApplicationController#index as HTML
2014-04-23T21:09:08.210054+00:00 app[web.1]: Processing by ApplicationController#index as HTML
2014-04-23T21:09:08.239227+00:00 app[web.1]:   Rendered application/index.html.erb within layouts/application (0.9ms)
2014-04-23T21:09:08.239227+00:00 app[web.1]:   Rendered application/index.html.erb within layouts/application (0.9ms)
2014-04-23T21:09:08.271897+00:00 heroku[router]: at=info method=GET path=/ host=artslot.herokuapp.com request_id=f5395cd5-4e00-4d9a-979d-6ad358b33a3a fwd="67.169.92.237" dyno=web.1 connect=6ms service=2367ms status=304 bytes=820
2014-04-23T21:09:08.432297+00:00 heroku[router]: at=info method=GET path=/assets/application-1c8ff196c2e39d33bb5c62b28dba7426.css host=artslot.herokuapp.com request_id=7f257454-b7d9-4c09-9ae1-133de79199e4 fwd="67.169.92.237" dyno=web.1 connect=0ms service=4ms status=304 bytes=133
2014-04-23T21:09:08.441339+00:00 heroku[router]: at=info method=GET path=/assets/application-7521f53a2cdda10ccbdb02603acc46e9.js host=artslot.herokuapp.com request_id=423e65eb-a3e8-41c3-b611-49f000601fd3 fwd="67.169.92.237" dyno=web.1 connect=1ms service=7ms status=304 bytes=133
2014-04-23T21:09:08.452496+00:00 heroku[router]: at=info method=GET path=/assets/vendor/modernizr-aee7c485b9900b5743cd0108ba6c4203.js host=artslot.herokuapp.com request_id=cad37bf0-a813-48dd-9dd5-8b1d57fb49d3 fwd="67.169.92.237" dyno=web.1 connect=6ms service=7ms status=304 bytes=133
2014-04-23T21:09:08.988730+00:00 heroku[router]: at=info method=GET path=/favicon.ico host=artslot.herokuapp.com request_id=bd9675a3-b338-4409-920a-605cfb34ab96 fwd="67.169.92.237" dyno=web.1 connect=1ms service=4ms status=304 bytes=133
2014-04-23T21:09:08.241372+00:00 app[web.1]: Completed 200 OK in 31ms (Views: 5.4ms | ActiveRecord: 0.0ms)
2014-04-23T21:09:08.241372+00:00 app[web.1]: Completed 200 OK in 31ms (Views: 5.4ms | ActiveRecord: 0.0ms)
2014-04-23T21:12:00.189756+00:00 heroku[api]: Starting process with command `bundle exec rake db:migrate` by [email protected]
2014-04-23T21:12:04.265328+00:00 heroku[run.3661]: Awaiting client
2014-04-23T21:12:04.342014+00:00 heroku[run.3661]: Starting process with command `bundle exec rake db:migrate`
2014-04-23T21:12:04.436971+00:00 heroku[run.3661]: State changed from starting to up
2014-04-23T21:12:23.595508+00:00 heroku[run.3661]: Process exited with status 0
2014-04-23T21:12:23.611644+00:00 heroku[run.3661]: State changed from up to complete
2014-04-23T21:12:42.205577+00:00 app[web.1]: Started GET "/" for 67.169.92.237 at 2014-04-23 21:12:42 +0000
2014-04-23T21:12:42.205577+00:00 app[web.1]: Started GET "/" for 67.169.92.237 at 2014-04-23 21:12:42 +0000
2014-04-23T21:12:42.217001+00:00 heroku[router]: at=info method=GET path=/ host=artslot.herokuapp.com request_id=74a0bfa8-fc4e-4743-bbcf-166e7854f087 fwd="67.169.92.237" dyno=web.1 connect=1ms service=10ms status=200 bytes=1771
2014-04-23T21:12:42.397848+00:00 heroku[router]: at=info method=GET path=/assets/vendor/modernizr-aee7c485b9900b5743cd0108ba6c4203.js host=artslot.herokuapp.com request_id=67050a5f-d2c6-4ed0-844c-e970b0d70e75 fwd="67.169.92.237" dyno=web.1 connect=1ms service=9ms status=200 bytes=11304
2014-04-23T21:12:42.400644+00:00 heroku[router]: at=info method=GET path=/assets/app
lication-1c8ff196c2e39d33bb5c62b28dba7426.css host=artslot.herokuapp.com request_id=0be05d98-f30d-49f6-a93f-28077b8466e2 fwd="67.169.92.237" dyno=web.1 connect=1ms service=14ms status=200 bytes=154145
2014-04-23T21:12:42.403702+00:00 heroku[router]: at=info method=GET path=/assets/application-7521f53a2cdda10ccbdb02603acc46e9.js host=artslot.herokuapp.com request_id=d11f58e8-56c4-4bb6-b4ec-1381cfee2689 fwd="67.169.92.237" dyno=web.1 connect=1ms service=15ms status=200 bytes=303416
2014-04-23T21:12:42.211004+00:00 app[web.1]: Completed 200 OK in 2ms (Views: 1.2ms | ActiveRecord: 0.0ms)
2014-04-23T21:12:42.211004+00:00 app[web.1]: Completed 200 OK in 2ms (Views: 1.2ms | ActiveRecord: 0.0ms)
2014-04-23T21:12:42.208919+00:00 app[web.1]: Processing by ApplicationController#index as HTML
2014-04-23T21:12:42.210188+00:00 app[web.1]:   Rendered application/index.html.erb within layouts/application (0.1ms)
2014-04-23T21:12:42.210188+00:00 app[web.1]:   Rendered application/index.html.erb within layouts/application (0.1ms)
2014-04-23T21:12:42.208919+00:00 app[web.1]: Processing by ApplicationController#index as HTML
2014-04-23T21:24:25+00:00 heroku[slug-compiler]: Slug compilation started
2014-04-23T21:24:47+00:00 heroku[slug-compiler]: Slug compilation finished
2014-04-23T21:24:47.431055+00:00 heroku[web.1]: State changed from up to starting
2014-04-23T21:24:47.151997+00:00 heroku[api]: Deploy 9b2229f by [email protected]
2014-04-23T21:24:47.152077+00:00 heroku[api]: Release v19 created by [email protected]
2014-04-23T21:24:49.977030+00:00 heroku[web.1]: Stopping all processes with SIGTERM
2014-04-23T21:24:50.541347+00:00 app[web.1]: [2014-04-23 21:24:50] FATAL SignalException: SIGTERM
2014-04-23T21:24:50.541347+00:00 app[web.1]:    /app/vendor/ruby-2.0.0/lib/ruby/2.0.0/webrick/server.rb:170:in `select'
2014-04-23T21:24:50.541347+00:00 app[web.1]:    /app/vendor/ruby-2.0.0/lib/ruby/2.0.0/webrick/server.rb:170:in `block in start'
2014-04-23T21:24:50.541600+00:00 app[web.1]:    /app/vendor/bundle/ruby/2.0.0/gems/railties-4.0.4/lib/rails/commands.rb:71:in `<top (required)>'
2014-04-23T21:24:50.541347+00:00 app[web.1]:    /app/vendor/ruby-2.0.0/lib/ruby/2.0.0/webrick/server.rb:32:in `start'
2014-04-23T21:24:50.541347+00:00 app[web.1]:    /app/vendor/ruby-2.0.0/lib/ruby/2.0.0/webrick/server.rb:160:in `start'
2014-04-23T21:24:50.541347+00:00 app[web.1]:    /app/vendor/bundle/ruby/2.0.0/gems/rack-1.5.2/lib/rack/handler/webrick.rb:14:in `run'
2014-04-23T21:24:50.541347+00:00 app[web.1]:    /app/vendor/bundle/ruby/2.0.0/gems/rack-1.5.2/lib/rack/server.rb:264:in `start'
2014-04-23T21:24:50.541347+00:00 app[web.1]:    /app/vendor/bundle/ruby/2.0.0/gems/railties-4.0.4/lib/rails/commands/server.rb:84:in `start'
2014-04-23T21:24:50.541347+00:00 app[web.1]:    /app/vendor/bundle/ruby/2.0.0/gems/railties-4.0.4/lib/rails/commands.rb:76:in `block in <top (required)>'
2014-04-23T21:24:50.541347+00:00 app[web.1]:    /app/vendor/bundle/ruby/2.0.0/gems/railties-4.0.4/lib/rails/commands.rb:71:in `tap'
2014-04-23T21:24:50.541600+00:00 app[web.1]:    bin/rails:4:in `require'
2014-04-23T21:24:50.541600+00:00 app[web.1]: [2014-04-23 21:24:50] INFO  going to shutdown ...
2014-04-23T21:24:50.541600+00:00 app[web.1]:    bin/rails:4:in `<main>'
2014-04-23T21:24:50.541600+00:00 app[web.1]: [2014-04-23 21:24:50] INFO  WEBrick::HTTPServer#start done.
2014-04-23T21:24:50.541600+00:00 app[web.1]: Exiting
2014-04-23T21:24:52.075006+00:00 heroku[web.1]: Starting process with command `bin/rails server -p 9064 -e production`
2014-04-23T21:24:51.773315+00:00 heroku[web.1]: Process exited with status 143
2014-04-23T21:24:57.244913+00:00 app[web.1]: [2014-04-23 21:24:57] INFO  WEBrick 1.3.1
2014-04-23T21:24:57.244913+00:00 app[web.1]: [2014-04-23 21:24:57] INFO  ruby 2.0.0 (2014-02-24) [x86_64-linux]
2014-04-23T21:24:57.244913+00:00 app[web.1]: [2014-04-23 21:24:57] INFO  WEBrick::HTTPServer#start: pid=2 port=9064
2014-04-23T21:24:57.702318+00:00 heroku[web.1]: State changed from starting to up
2014-04-23T21:29:13.588795+00:00 app[web.1]: => Booting WEBrick
2014-04-23T21:29:13.588795+00:00 app[web.1]: => Ctrl-C to shutdown server
2014-04-23T21:29:13.588795+00:00 app[web.1]: => Rails 4.0.4 application starting in production on http://0.0.0.0:9064
2014-04-23T21:29:13.588795+00:00 app[web.1]: => Run `rails server -h` for more startup options
2014-04-23T21:29:13.592113+00:00 app[web.1]: Started GET "/" for 67.169.92.237 at 2014-04-23 21:29:13 +0000
2014-04-23T21:29:13.588795+00:00 app[web.1]: Started GET "/" for 67.169.92.237 at 2014-04-23 21:29:13 +0000
2014-04-23T21:29:32.372120+00:00 app[web.1]: Processing by ApplicationController#index as HTML
2014-04-23T21:29:32.372120+00:00 app[web.1]: Processing by ApplicationController#index as HTML
2014-04-23T21:29:32.398081+00:00 app[web.1]:   Rendered application/index.html.erb within layouts/application (0.6ms)
2014-04-23T21:29:32.398081+00:00 app[web.1]:   Rendered application/index.html.erb within layouts/application (0.6ms)
2014-04-23T21:29:32.402368+00:00 heroku[router]: at=info method=GET path=/ host=artslot.herokuapp.com request_id=1992fcce-e969-4b96-94aa-8145b035c6ca fwd="67.169.92.237" dyno=web.1 connect=2ms service=18901ms status=200 bytes=1772
2014-04-23T21:29:32.628046+00:00 heroku[router]: at=info method=GET path=/assets/application-1c8ff196c2e39d33bb5c62b28dba7426.css host=artslot.herokuapp.com request_id=2d953064-ff85-497b-9c08-c15cb6ce570a fwd="67.169.92.237" dyno=web.1 connect=2ms service=27ms status=200 bytes=154145
2014-04-23T21:29:32.620125+00:00 heroku[router]: at=info method=GET path=/assets/vendor/modernizr-aee7c485b9900b5743cd0108ba6c4203.js host=artslot.herokuapp.com request_id=fc5617e3-e0f2-4fa0-adf0-739420a80ac8 fwd="67.169.92.237" dyno=web.1 connect=2ms service=10ms status=200 bytes=11304
2014-04-23T21:29:32.750051+00:00 heroku[router]: at=info method=GET path=/assets/application-7521f53a2cdda10ccbdb02603acc46e9.js host=artslot.herokuapp.com request_id=98e2156b-2650-4b06-a9d0-8c1817cf1009 fwd="67.169.92.237" dyno=web.1 connect=14ms service=38ms status=200 bytes=303416
2014-04-23T21:29:32.400007+00:00 app[web.1]: Completed 200 OK in 28ms (Views: 4.2ms | ActiveRecord: 0.0ms)
2014-04-23T21:29:32.400007+00:00 app[web.1]: Completed 200 OK in 28ms (Views: 4.2ms | ActiveRecord: 0.0ms)
Sonora answered 23/4, 2014 at 21:36 Comment(4)
possible duplicate of Understanding Heroku server status 143Dorsett
@MichaelSzyndel I see the similarity in the question, but I don't believe that It answers mine. I'm wondering what to do to fix it and not just what it means. I've been searching for a while but I'm not sure where to start making changes in my app or maybe even on heroku settings.Sonora
From what I see and my understanding how Heroku works this is totally normal behaviour. If you want to get rid of the error I would suggest using "real" web server, take a look at heroku docs devcenter.heroku.com/articles/…Dorsett
thank you for the suggestion @MichaelSzyndel. I have updated to unicorn, and now have no error, but nothing shows up on the browser either. Gonna spend some time on it.Sonora
C
20

When a dyno shuts down, for example as part of a daily restart or as part of sleeping or a new release (as you have in your example) then Heroku has to shut down the processes running in the dyno.

It does this by sending a SIGTERM to the processes.

The logs you show are consistent with this behavior.

Indeed, if I run a webrick server locally, and shut it down with SIGTERM (kill -SIGTERM <pid>), it behaves in exactly the same way.

ruby x.rb
[2014-04-24 09:34:46] INFO  WEBrick 1.3.1
[2014-04-24 09:34:46] INFO  ruby 2.0.0 (2013-06-27) [x86_64-darwin12.4.1]
[2014-04-24 09:34:46] INFO  WEBrick::HTTPServer#start: pid=66968 port=1234
[2014-04-24 09:35:04] FATAL SignalException: SIGTERM
    /Users/jonmountjoy/.rubies/2.0.0-p247/lib/ruby/2.0.0/webrick/server.rb:170:in `select'
    /Users/jonmountjoy/.rubies/2.0.0-p247/lib/ruby/2.0.0/webrick/server.rb:170:in `block in start'
    /Users/jonmountjoy/.rubies/2.0.0-p247/lib/ruby/2.0.0/webrick/server.rb:32:in `start'
    /Users/jonmountjoy/.rubies/2.0.0-p247/lib/ruby/2.0.0/webrick/server.rb:160:in `start'
    x.rb:5:in `<main>'
[2014-04-24 09:35:04] INFO  going to shutdown ...
[2014-04-24 09:35:04] INFO  WEBrick::HTTPServer#start done.
Cestoid answered 24/4, 2014 at 8:40 Comment(0)
A
5

I have solve same problem by this command

$ heroku restart worker.1

Restarting worker.1 dyno... done>

This command helps to restart a crashed worker instantly, without having to wait 10 minutes for the app to auto restart. heroku ps allows you to see if the web worker (dyno) was actually restarted.

Acclamation answered 21/10, 2015 at 13:33 Comment(2)
I get that this may solve the issue for some folks. But it would be good to have some information about why it works. Could someone, please, explain?Niko
I find that this issue isn't specific to Heroku and also that it can happen again and again all day long. So we can't expect someone can stay on the server 24/7 running commands to keep it up, but this command is useful for the given user perhaps if it only happens once, but I'm willing to bet it isn't just once or we won't have the post.Jenevajeni

© 2022 - 2024 — McMap. All rights reserved.