Tomcat processes JRuby on Rails request before environment.rb is parsed
-----------------------------------------------------------------------
Key: JRUBY-5179
URL: http://jira.codehaus.org/browse/JRUBY-5179
Project: JRuby
Issue Type: Bug
Affects Versions: JRuby 1.5.2
Environment: SunOS ri-dev1 5.10 Generic_127112-08 i86pc i386 i86pc
Apache Tomcat Version 5.5.26
JRuby 1.5.2
Ruby on Rails 2.3.8
Reporter: Steve Finkelstein
Assignee: Thomas E Enebo
There is an edge case in our implementation of JRuby on Rails where Tomcat
allows processing requests to the application framework before environment.rb
is done parsing. I cannot verify for sure this is the case, however in our
environment.rb where this bug is reproduced consistently, we explicitly require
active_support. If Tomcat is stopped and restarted, we can call a service that
invokes ActiveSupport::TimeZone.all and that will come back nil. We noticed
this as an exception was being thrown and we collected the following backtrace
in our logs:
=== begin backtrace ===
-------------------------------
Backtrace:
-------------------------------
[RAILS_ROOT]/gems/gems/activesupport-2.3.8/lib/active_support/values/time_zone.rb:206:in
`<=>'
[RAILS_ROOT]/gems/gems/activesupport-2.3.8/lib/active_support/values/time_zone.rb:318:in
`sort'
[RAILS_ROOT]/gems/gems/activesupport-2.3.8/lib/active_support/values/time_zone.rb:318:in
`all'
[RAILS_ROOT]/app/controllers/geographies_controller.rb:16:in `timezones'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/base.rb:1331:in
`perform_action'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/filters.rb:617:in
`call_filters'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/filters.rb:638:in
`run_before_filters'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/filters.rb:206:in
`call'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/filters.rb:206:in
`around_proc'
[RAILS_ROOT]/gems/gems/activesupport-2.3.8/lib/active_support/callbacks.rb:182:in
`call'
[RAILS_ROOT]/gems/gems/activesupport-2.3.8/lib/active_support/callbacks.rb:182:in
`evaluate_method'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/filters.rb:184:in
`call'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/filters.rb:635:in
`run_before_filters'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/filters.rb:615:in
`call_filters'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/filters.rb:610:in
`perform_action_with_filters'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/benchmarking.rb:68:in
`perform_action_with_benchmark'
[RAILS_ROOT]/gems/gems/activesupport-2.3.8/lib/active_support/core_ext/benchmark.rb:17:in
`ms'
file:/reuters/coolstack/tomcat5/webapps/insider/WEB-INF/lib/jruby-complete-1.5.2.jar!/META-INF/jruby.home/lib/ruby/1.8/benchmark.rb:308:in
`realtime'
[RAILS_ROOT]/gems/gems/activesupport-2.3.8/lib/active_support/core_ext/benchmark.rb:17:in
`ms'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/benchmarking.rb:68:in
`perform_action_with_benchmark'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/rescue.rb:160:in
`perform_action_with_rescue'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/flash.rb:151:in
`perform_action_with_flash'
[RAILS_ROOT]/vendor/plugins/newrelic_rpm/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:255:in
`perform_action_with_newrelic_trace'
[RAILS_ROOT]/vendor/plugins/newrelic_rpm/lib/new_relic/agent/method_tracer.rb:141:in
`trace_execution_scoped'
[RAILS_ROOT]/vendor/plugins/newrelic_rpm/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:248:in
`perform_action_with_newrelic_trace'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/base.rb:532:in
`process'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/filters.rb:606:in
`process_with_filters'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/base.rb:391:in
`process'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/base.rb:386:in
`call'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/routing/route_set.rb:438:in
`call'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/dispatcher.rb:87:in
`dispatch'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/dispatcher.rb:121:in
`_call'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/dispatcher.rb:130:in
`build_middleware_stack'
[RAILS_ROOT]/app/middleware/flash_session_cookie_middleware.rb:29:in `call'
[RAILS_ROOT]/app/middleware/flash_session_cookie_middleware.rb:29:in `call'
[RAILS_ROOT]/app/middleware/set_cookie_domain.rb:16:in `call'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/string_coercion.rb:25:in
`call'
[RAILS_ROOT]/gems/gems/rack-1.1.0/lib/rack/head.rb:9:in `call'
[RAILS_ROOT]/lib/rack_method_override_patch.rb:24:in `call'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/params_parser.rb:15:in
`call'
[RAILS_ROOT]/gems/gems/rails-2.3.8/lib/rails/rack/metal.rb:47:in `call'
[RAILS_ROOT]/app/middleware/set_cookie_domain.rb:16:in `call'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/session/abstract_store.rb:128:in
`call'
[RAILS_ROOT]/app/middleware/flash_session_cookie_middleware.rb:29:in `call'
[RAILS_ROOT]/gems/gems/activerecord-2.3.8/lib/active_record/query_cache.rb:29:in
`call'
[RAILS_ROOT]/gems/gems/activerecord-2.3.8/lib/active_record/connection_adapters/abstract/query_cache.rb:34:in
`cache'
[RAILS_ROOT]/gems/gems/activerecord-2.3.8/lib/active_record/query_cache.rb:9:in
`cache'
[RAILS_ROOT]/gems/gems/activerecord-2.3.8/lib/active_record/query_cache.rb:28:in
`call'
[RAILS_ROOT]/gems/gems/activerecord-2.3.8/lib/active_record/connection_adapters/abstract/connection_pool.rb:361:in
`call'
[RAILS_ROOT]/gems/gems/activesupport-2.3.8/lib/active_support/cache/strategy/local_cache.rb:36:in
`call'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/failsafe.rb:26:in
`call'
[RAILS_ROOT]/gems/gems/actionpack-2.3.8/lib/action_controller/dispatcher.rb:106:in
`call'
file:/reuters/coolstack/tomcat5/webapps/insider/WEB-INF/lib/jruby-rack-0.9.5.jar!/rack/adapter/rails.rb:35:in
`serve_rails'
file:/reuters/coolstack/tomcat5/webapps/insider/WEB-INF/lib/jruby-rack-0.9.5.jar!/rack/adapter/rails.rb:40:in
`call'
file:/reuters/coolstack/tomcat5/webapps/insider/WEB-INF/lib/jruby-rack-0.9.5.jar!/jruby/rack/rails.rb:148:in
`call'
file:/reuters/coolstack/tomcat5/webapps/insider/WEB-INF/lib/jruby-rack-0.9.5.jar!/rack/handler/servlet.rb:18:in
`call'
:1
=== end backtrace ===
If you make subsequent requests, the invocation to the web service works fine,
because one can assume at that point ActiveSupport was loaded into memory and
can be accessed. The exception never gets thrown again, only reproduced when we
restart Tomcat.
some more relevant information from newrelic:
* action_controller.request.path_parameters :
controllergeographiesactiontimezonesformatxml
* action_controller.request.query_parameters :
* action_controller.request.request_parameters:
* action_controller.rescue.request :
#<ActionController::Request:0x384af712>
* action_controller.rescue.response :
#<ActionController::Response:0x41a2db9d>
* java.servlet_context :
org.jruby.rack.servlet.servletrackcont...@5492de02
* java.servlet_request :
org.apache.catalina.connector.requestfac...@145c38c1
* jruby.rack.dynamic.requests.only : true
* jruby.rack.jruby.version : 1.5.2
* jruby.rack.rack.release : 1.1
* jruby.rack.version : 0.9.5
* rack.errors :
#<JRuby::Rack::ServletLog:0x2b004215>
* rack.input :
#<JRuby::RackRewindableInput:0x1df286c1>
* rack.multiprocess : false
* rack.multithread : true
* rack.request.query_hash :
* rack.request.query_string :
* rack.run_once : false
* rack.session.record :
#<ActiveRecord::SessionStore::Session:0x13b2558e>
* rack.url_scheme : http
* rack.version : 11
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
http://jira.codehaus.org/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
To unsubscribe from this list, please visit:
http://xircles.codehaus.org/manage_email
