I have a lighttpd + Ruby on Rails via FCGI installation and I started to see 500 - Internal Server Error from lighttpd when I accessed my rails application.
2008-11-29 01:15:11: (log.c.75) server started
2008-11-29 01:15:22: (mod_fastcgi.c.1743) connect failed: Connection refused on unix:/tmp/ruby-railsapp.fastcgi-0
2008-11-29 01:15:22: (mod_fastcgi.c.2912) backend died; we'll disable it for 5 seconds and send the request to another backend instead: reconnects: 0 load: 1
2008-11-29 01:15:23: (mod_fastcgi.c.2471) unexpected end-of-file (perhaps the fastcgi process died): pid: 2068 socket: unix:/tmp/ruby-railsapp.fastcgi-0
2008-11-29 01:15:23: (mod_fastcgi.c.3234) child exited, pid: 2068 status: 1
2008-11-29 01:15:23: (mod_fastcgi.c.3281) response not received, request sent: 867 on socket: unix:/tmp/ruby-railsapp.fastcgi-0 for /dispatch.fcgi , closing connection
There's no error in
log/fastcgi.crash.log nor
log/development.log of my Rails installation.
It appeared that
public/dispatch.fcgi was called and failed. I put a bunch of fprintf-equivarent and found out that the line with
require File.dirname(__FILE__) + "/../config/environment".
was the line where it failed. I needed to know how it failed, and I put code to dump the stack trace:
begin
require File.dirname(__FILE__) + "/../config/environment"
rescue Exception => exception
File.open('/tmp/a.log', 'a') do |f|
f.puts exception.class.name + ":" + exception.message
f.puts exception.backtrace.join("\n")
end
end
and it gave me some clue:
SystemExit:exit
/Users/gaku/ror/iphone/public/../config/boot.rb:65:in `exit'
/Users/gaku/ror/iphone/public/../config/boot.rb:65:in `load_rails_gem'
/Users/gaku/ror/iphone/public/../config/boot.rb:53:in `load_initializer'
/Users/gaku/ror/iphone/public/../config/boot.rb:38:in `run'
/Users/gaku/ror/iphone/public/../config/boot.rb:11:in `boot!'
/Users/gaku/ror/iphone/public/../config/boot.rb:109
/Users/gaku/ror/iphone/public/../config/environment.rb:11:in `require'
/Users/gaku/ror/iphone/public/../config/environment.rb:11
/Users/gaku/ror/iphone/public/dispatch.fcgi:28:in `require'
/Users/gaku/ror/iphone/public/dispatch.fcgi:28
It failed in
load_rails_gem and there was an attempt to dump error message to stderr, but FCGI didn't spit the message anywhere. The message was:
$stderr.puts %(Missing the Rails #{version} gem. Please `gem install -v#{version} rails`, update your RAILS_GEM_VERSION settingin config/environment.rb for the Rails version you do have installed, or comment out RAILS_GEM_VERSION to use the latest version installed.)
I have rails 2.2.2 gem installed, and I updated
RAILS_GEM_VERSION variable in
config/environment.rb to 2.2.2. However, in fact, the code tried to run
gem 'rails', '2.2.2'
and threw
Gem::LoadError.
I need to dig deeper. I put another stack trace code to the
Gem::LoadError handler and it revealed another trace:
Gem::LoadError:Could not find RubyGem activesupport (= 2.2.2)
/opt/local/lib/ruby/site_ruby/1.8/rubygems.rb:636:in `report_activate_error'
/opt/local/lib/ruby/site_ruby/1.8/rubygems.rb:141:in `activate'
/opt/local/lib/ruby/site_ruby/1.8/rubygems.rb:165:in `activate'
/opt/local/lib/ruby/site_ruby/1.8/rubygems.rb:164:in `each'
/opt/local/lib/ruby/site_ruby/1.8/rubygems.rb:164:in `activate'
/opt/local/lib/ruby/site_ruby/1.8/rubygems.rb:49:in `gem'
/Users/gaku/ror/iphone/public/../config/boot.rb:62:in `load_rails_gem'
/Users/gaku/ror/iphone/public/../config/boot.rb:53:in `load_initializer'
/Users/gaku/ror/iphone/public/../config/boot.rb:38:in `run'
/Users/gaku/ror/iphone/public/../config/boot.rb:11:in `boot!'
/Users/gaku/ror/iphone/public/../config/boot.rb:123
/Users/gaku/ror/iphone/public/../config/environment.rb:11:in `require'
/Users/gaku/ror/iphone/public/../config/environment.rb:11
/Users/gaku/ror/iphone/public/dispatch.fcgi:28:in `require'
/Users/gaku/ror/iphone/public/dispatch.fcgi:28
It was not a failure to load rails 2.2.2 gem, but it failed to load underlying gem called activesupport. It says "Could not find RubyGem activesupport (= 2.2.2)".
It looked to me that I also have activesupport 2.2.2 according to my
gem list --local command. However, when I run
gem uninstall activesupport, there's an strange error:
kvant-2% sudo gem uninstall activesupport
ERROR: While executing gem ... (Gem::InstallError)
Unknown gem activesupport >= 0
So, I reinstalled activesupport anyway and this fixed the problem.
It looks like the cause of the problem was broken activesupport gem installation. It should have happened during my upgrade of Rails from 2.1 to 2.2. I don't know how it happen though
.
Lessons
- lighttpd's "child exited with status 1 /Users/gaku/ror/iphone/public/dispatch.fcgi" actually means Ruby fcgi script exit with status 1. Rails framework has such code.
- Stack trace is easy and informative in Ruby.
- gem installation could be broken. gem uninstall/install may help.
1 comment:
Just wanted to say thanks for the post, I spent hours tracking a problem down and with your code snippet, found + fixed inside of 5 minutes.. grrr internal server error 500!!
Post a Comment