Heroku logs FATAL SignalException: SIGTERM

ruby-on-rails heroku deployment sigterm
stecd picture stecd · Apr 23, 2014 · Viewed 15.9k times · Source

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)

Answer

Jon Mountjoy picture Jon Mountjoy · Apr 24, 2014

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.

Related questions

Heroku deployment error H10 (App crashed)

I have a RoR app working on my local computer, but when I send it to heroku, it crashes. The error log gives an error H10 & says: 2012-11-21T15:26:47+00:00 app[web.1]: from /app/vendor/bundle/ruby/1.9.1/gems/newrelic_…

Read More
Deploying Ruby on Rails - Is there a good alternative for Heroku?

I'm starting a new small venture, a POC if you would like, and I want to deploy my Rails application for free somewhere. I found that there is Heroku, are there another options?

Read More
Rails 3.1 Deployment to Heroku Error

I'm trying to deploy my app to Heroku, I've done this before on my Windows machine, and now I am currently using a mac. I'm trying to use Postgresql for the first time. I have the following in my Gemfile: …

Read More