Application crashes with uninitialized Rack constant when run in Passenger #1478

Closed
rchady opened this Issue Apr 15, 2015 · 20 comments

Projects

None yet

6 participants

@rchady
rchady commented Apr 15, 2015

I've tried to google for this, tried everything I can think of to figure out why this is happening, but I am at a loss... so I'm asking here. Any idea why this happens with nginx+passenger, but not rackup? It is quite literally a "Hello world" sinatra app at this point in time.

App 23203 stderr: [ 2015-04-15 11:21:12.9206 23224/0x00000000c69850(Worker 1) utils.rb:85 ]: *** Exception NameError in Rack application object (uninitialized constant Rack::MethodOverride::REQUEST_METHOD) (process 23224, thread 0x00000000c69850(Worker 1)):
App 23203 stderr:       from /var/lib/gems/2.1.0/gems/rack-1.6.0/lib/rack/methodoverride.rb:14:in `call'
App 23203 stderr:       from /var/lib/gems/2.1.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:181:in `call'
App 23203 stderr:       from /var/lib/gems/2.1.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:2021:in `call'
App 23203 stderr:       from /var/lib/gems/2.1.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:1486:in `block in call'
App 23203 stderr:       from /var/lib/gems/2.1.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:1795:in `synchronize'
App 23203 stderr:       from /var/lib/gems/2.1.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:1486:in `call'
App 23203 stderr:       from /usr/lib/ruby/vendor_ruby/phusion_passenger/rack/thread_handler_extension.rb:85:in `process_request'
App 23203 stderr:       from /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler/thread_handler.rb:149:in `accept_and_process_next_request'
App 23203 stderr:       from /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler/thread_handler.rb:110:in `main_loop'
App 23203 stderr:       from /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler.rb:414:in `block (3 levels) in start_threads'
App 23203 stderr:       from /usr/lib/ruby/vendor_ruby/phusion_passenger/utils.rb:111:in `block in create_thread_and_abort_on_exception'
[ 2015-04-15 11:21:12.9209 23156/7fcb1c2cd700 age/Hel/Req/Utils.cpp:89 ]: [Client 1-1] Sending 502 response: application did not send a complete response
@FooBarWidget
Member

Can you post the app which reproduces the problem?

@rchady
rchady commented Apr 15, 2015

app.rb:

require 'sinatra'

get '/' do
    "Hello World!"
end

config.ru:

require 'sinatra'
require './app.rb'

run Sinatra::Application
@FooBarWidget
Member

Can you post everything? That includes your Gemfile and Gemfile.lock.

@rchady
rchady commented Apr 15, 2015

There is no Gemfile in this case. It quite literally is a directory with those 2 files in it and a vhost configured to point at it, enabling passenger.

Using the same setup with rackup works as expected. I ran in to this issue trying to set up geminabox, and then stickler, so I stripped it down to the bare minimum to try to help isolate the overall issue.

@rchady
rchady commented Apr 15, 2015

This is the location directive I"m using for it currently, though I've tried multiple setups now.

    location /gems {
      alias /srv/www/sites/gems/public;
      passenger_base_uri /gems;
      passenger_app_root /srv/www/sites/gems;
      passenger_document_root /srv/www/sites/gems/public;
      passenger_enabled on;
    }
@FooBarWidget
Member

I'm not able to reproduce this issue with Passenger 5.0.6, Ruby 2.2.0, and your exact same app code. Which exact Ruby version are you running? Which OS are you running? What happens if you run the app in Passenger Standalone?

@rchady
rchady commented Apr 15, 2015

Ruby: ruby 2.1.5p273 (2014-11-13) [x86_64-linux-gnu]
OS: Debian (wheezy)

I don't have the standalone runtime installed on this system. If it will help, I will get it set up.

Btw, thanks for the quick response(s) on this. I've spent hours trying to narrow this down and identify what could be going on.

@rchady
rchady commented Apr 15, 2015

If it helps any, here is my entire gem list from this system:

addressable (2.3.8)
bigdecimal (1.2.4)
builder (3.2.2)
bundler (1.9.4)
coderay (1.1.0)
crack (0.4.2)
domain_name (0.5.23)
excon (0.45.1)
faraday (0.9.1)
http-cookie (1.0.2)
httpclient (2.6.0.1)
io-console (0.4.2)
json (1.8.1)
little-plugger (1.1.3)
logging (1.8.2)
mechanize (2.7.3)
method_source (0.8.2)
mime-types (2.4.3)
mini_portile (0.6.2)
minitest (4.7.5)
multi_json (1.11.0)
multipart-post (2.0.0)
nesty (1.0.2)
net-http-digest_auth (1.4)
net-http-persistent (2.9.4)
nokogiri (1.6.6.2)
ntlm-http (0.1.1)
pry (0.10.1)
psych (2.0.5)
rack (1.6.0)
rack-protection (1.5.3)
rake (10.4.2, 10.1.0)
rdoc (4.1.0)
safe_yaml (1.0.4)
sinatra (1.4.6)
slop (3.6.0)
stickler (2.4.2)
test-unit (2.1.5.0)
tilt (2.0.1)
trollop (2.1.2)
unf (0.1.4)
unf_ext (0.0.6)
webrobots (0.1.1)
xpath (2.0.0)

@rchady
rchady commented Apr 15, 2015

If it helps any, here is an attempt of running it with passenger standalone:

App 6181 stdout:
App 6198 stdout:
App 6181 stderr: [ 2015-04-15 13:14:32.7962 6198/0x000000015c3ce8(Worker 1) utils.rb:85 ]: *** Exception NameError in Rack application object (uninitialized constant Rack::Request::SCRIPT_NAME) (process 6198, thread 0x000000015c3ce8(Worker 1)):
App 6181 stderr:    from /var/lib/gems/2.1.0/gems/rack-1.6.0/lib/rack/request.rb:21:in `script_name'
App 6181 stderr:    from /var/lib/gems/2.1.0/gems/rack-1.6.0/lib/rack/showexceptions.rb:69:in `pretty'
App 6181 stderr:    from /var/lib/gems/2.1.0/gems/sinatra-1.4.6/lib/sinatra/show_exceptions.rb:30:in `rescue in call'
App 6181 stderr:    from /var/lib/gems/2.1.0/gems/sinatra-1.4.6/lib/sinatra/show_exceptions.rb:21:in `call'
App 6181 stderr:    from /var/lib/gems/2.1.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:181:in `call'
App 6181 stderr:    from /var/lib/gems/2.1.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:2021:in `call'
App 6181 stderr:    from /var/lib/gems/2.1.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:1486:in `block in call'
App 6181 stderr:    from /var/lib/gems/2.1.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:1795:in `synchronize'
App 6181 stderr:    from /var/lib/gems/2.1.0/gems/sinatra-1.4.6/lib/sinatra/base.rb:1486:in `call'
App 6181 stderr:    from /var/lib/gems/2.1.0/gems/passenger-5.0.6/lib/phusion_passenger/rack/thread_handler_extension.rb:85:in `process_request'
App 6181 stderr:    from /var/lib/gems/2.1.0/gems/passenger-5.0.6/lib/phusion_passenger/request_handler/thread_handler.rb:155:in `accept_and_process_next_request'
App 6181 stderr:    from /var/lib/gems/2.1.0/gems/passenger-5.0.6/lib/phusion_passenger/request_handler/thread_handler.rb:110:in `main_loop'
App 6181 stderr:    from /var/lib/gems/2.1.0/gems/passenger-5.0.6/lib/phusion_passenger/request_handler.rb:414:in `block (3 levels) in start_threads'
App 6181 stderr:    from /var/lib/gems/2.1.0/gems/passenger-5.0.6/lib/phusion_passenger/utils.rb:111:in `block in create_thread_and_abort_on_exception'
[ 2015-04-15 13:14:32.7965 6148/7f0541b5c700 age/Hel/Req/Utils.cpp:89 ]: [Client 1-1] Sending 502 response: application did not send a complete response
^CStopping web server... done
@FooBarWidget
Member

@OnixGH I think I've seen someone else reporting this before, but I haven't been able to track down the issue. Can you try reproducing on the same OS and Ruby version as him?

@rchady
rchady commented Apr 15, 2015

A friend set up that simple application using the nginx .debs you provide and received the same error... whew, at least I'm not insane. :)

@OnixGH
Member
OnixGH commented Apr 16, 2015

The error is indeed reproducible, even with Ruby 2.2.0.

@FooBarWidget
Member

Maybe it's an OS X vs Linux thing. I'll take a look with you when I arrive at the office.

@FooBarWidget
Member

We've found the cause of the issue. It is not a Passenger bug.

Your system has two Rack versions installed. One is version 1.5.0, installed by APT, and is located in /usr/lib/ruby/vendor_ruby. The other one is version 1.6.0, installed by RubyGems, and is located in /var/lib/gems/2.1.0/gems/rack-1.6.0.

Before Passenger loads your app, Passenger calls require "rack". Because /usr/lib/ruby/vendor_ruby is in Ruby's $LOAD_PATH, Passenger loads the Rack 1.5.0 library installed by APT.

However Sinatra requires Rack 1.6.0 or later, so at some point it tries to load a file not found in Rack 1.5.0. At that point, RubyGems kicks in and loads rack/request.rb from /var/lib/gems/2.1.0/gems/rack-1.6.0. Now you've ended up with two conflicting versions of Rack loaded in the same Ruby process, and things break.

The solution is to use a Gemfile. This way, Bundler will ensure that /var/lib/gems/2.1.0/gems/rack-1.6.0 is in $LOAD_PATH first.

The reason why 'rackup' worked for you, is because the 'rackup' command that is first in your $PATH is the one installed by RubyGems, and not the one installed by APT. The 'rackup' command installed by RubyGems activates the rack 1.6.0 gem, and ensures that /var/lib/gems/2.1.0/gems/rack-1.6.0 is in $LOAD_PATH first. Thus, it happens to bypass the problem.

I am on OS X, so I don't have rack.rb installed in /usr/lib/ruby/vendor_ruby, and so I couldn't reproduce your problem.

@FooBarWidget FooBarWidget changed the title from Error with nginx+passenger-5.0.6 in rack app to Application crashes with uninitialized Rack constant when run in Passenger Apr 16, 2015
@rchady
rchady commented Apr 16, 2015

Aha, that makes perfect sense. Thank you for finding this for me. It also explains why it happens on Debian and not my other systems. Hopefully the log of this will help other people that get bit by this too.

@FooBarWidget FooBarWidget added a commit that referenced this issue Apr 17, 2015
@FooBarWidget FooBarWidget Prefer loading Rack and Bundler from RubyGems instead of 'vendor_ruby'
Closes GH-1478. Closes GH-1480.
4331c76
@borkabrak

Holy crap, thank you. I thought I was going crazy. You work is appreciated, ladies and/or gentlemen.

@isomorphisms

Thanks, I had the same problem and this explained / fixed it!

@michaeloboyle michaeloboyle referenced this issue in phusion/passenger-docker Feb 29, 2016
Closed

502 Gateway Timeout #131

@juanfer
juanfer commented May 24, 2016

I have the same problem, but couldn't fix it as suggested. I'm trying to install Locomotive Engine (https://github.com/locomotivecms/engine) in an Ubuntu 14.10 box with ruby 2.1.6, rails 4.2.6 (therefore there's a Gemfile where I explicitly added rack 1.6.0), and I have updated passenger to the last version 5.0.28 (which is supposed to prefer rack from the app), and had no luck with it, but looks like the same rack conflict mentioned here. Any ideas would be greatly appreciated.

App 18399 stderr: [ 2016-05-24 12:47:08.9948 18418/0x007f3b194134e8(Worker 1) utils.rb:87 ]: *** Exception NoMethodError in Rack application object (undefined method `path' for nil:NilClass) (process 18418, thread 0x007f3b194134e8(Worker 1)):
App 18399 stderr:   from /usr/local/lib/ruby/gems/2.1.0/gems/locomotivecms-3.1.1/lib/locomotive.rb:66:in `mounted_on'
App 18399 stderr:   from /usr/local/lib/ruby/gems/2.1.0/gems/locomotivecms-3.1.1/lib/locomotive/middlewares/image_thumbnail.rb:29:in `route'
App 18399 stderr:   from /usr/local/lib/ruby/gems/2.1.0/gems/locomotivecms-3.1.1/lib/locomotive/middlewares/image_thumbnail.rb:12:in `call'
App 18399 stderr:   from /usr/local/lib/ruby/gems/2.1.0/gems/dragonfly-1.0.12/lib/dragonfly/cookie_monster.rb:9:in `call'
App 18399 stderr:   from /usr/local/lib/ruby/gems/2.1.0/gems/rack-1.6.4/lib/rack/lock.rb:17:in `call'
App 18399 stderr:   from /usr/local/lib/ruby/gems/2.1.0/gems/actionpack-4.2.6/lib/action_dispatch/middleware/static.rb:120:in `call'
App 18399 stderr:   from /usr/local/lib/ruby/gems/2.1.0/gems/rack-1.6.4/lib/rack/sendfile.rb:113:in `call'
App 18399 stderr:   from /usr/local/lib/ruby/gems/2.1.0/gems/railties-4.2.6/lib/rails/engine.rb:518:in `call'
App 18399 stderr:   from /usr/local/lib/ruby/gems/2.1.0/gems/railties-4.2.6/lib/rails/application.rb:165:in `call'
App 18399 stderr:   from /usr/local/lib/ruby/gems/2.1.0/gems/passenger-5.0.28/src/ruby_supportlib/phusion_passenger/rack/thread_handler_extension.rb:97:in `process_request'
App 18399 stderr:   from /usr/local/lib/ruby/gems/2.1.0/gems/passenger-5.0.28/src/ruby_supportlib/phusion_passenger/request_handler/thread_handler.rb:152:in `accept_and_process_next_request'
App 18399 stderr:   from /usr/local/lib/ruby/gems/2.1.0/gems/passenger-5.0.28/src/ruby_supportlib/phusion_passenger/request_handler/thread_handler.rb:113:in `main_loop'
App 18399 stderr:   from /usr/local/lib/ruby/gems/2.1.0/gems/passenger-5.0.28/src/ruby_supportlib/phusion_passenger/request_handler.rb:416:in `block (3 levels) in start_threads'
App 18399 stderr:   from /usr/local/lib/ruby/gems/2.1.0/gems/passenger-5.0.28/src/ruby_supportlib/phusion_passenger/utils.rb:113:in `block in create_thread_and_abort_on_exception'
[ 2016-05-24 12:47:08.9953 18318/7feb25276700 age/Cor/Con/InternalUtils.cpp:112 ]: [Client 1-6] Sending 502 response: application did not send a complete response
@OnixGH
Member
OnixGH commented May 24, 2016

Your error message is different though? How do you know it's the same problem? Do you have multiple rack versions? Did you confirm that the error doesn't happen with rackup?

@juanfer
juanfer commented May 24, 2016

Yes, this are the rack versions installed:

/usr/local/lib/ruby/gems/2.1.0/gems/rack-1.6.0/
/usr/local/lib/ruby/gems/2.1.0/gems/rack-1.6.1/
/usr/local/lib/ruby/gems/2.1.0/gems/rack-1.6.4/

Errors are different, but they are rack related, therefore my assumption, but I have no experience with this issues, so might be mistaken of course.

Not sure how to run the application with rackup. I'll investigate.
Thanks for your answer.

@OnixGH OnixGH removed the SupportCentral label Jun 17, 2016
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment