Details
-
Type:
Bug
-
Status:
Resolved
-
Priority:
Major
-
Resolution: Incomplete
-
Affects Version/s: JRuby 1.5.2
-
Fix Version/s: None
-
Component/s: None
-
Labels:None
-
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
-
Number of attachments :
Description
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.ServletRackContext@5492de02
- java.servlet_request : org.apache.catalina.connector.RequestFacade@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
Activity
| Field | Original Value | New Value |
|---|---|---|
| Status | Open [ 1 ] | Resolved [ 5 ] |
| Assignee | Thomas E Enebo [ enebo ] | Charles Oliver Nutter [ headius ] |
| Resolution | Incomplete [ 4 ] |