Trying to track down an issue in a performance based load test.. using Rails 2.2.2

rubyonrails-talk
1

I am trying to debug an issue with Rails 2.2.2... I am running a load test where I am logging in and out 20 users, and I am occasionally seeing this error, in my logs: (see stack trace below) it appears that the body of some of my requests are null... I'm trying to figure out if a) it's a rails issue, b) is it a jruby/rack issue or c) is it an issue with caching (which is turned on but I wouldn't think should be an issue on a login/logout scenario). any one have any thoughts on where I Could check to see why the body is null? I'm off to try and turn off caching to see what happens but this issue is a pretty big issue and we need to resolve it asap. We see it in normal usage of our website too. It appears to be timing related but I'm not sure why or how yet.

I'm not necessarily looking for THE answer but any general help of "check xxx" would be great.

Thanks! Jay

[#|2008-12-11T16:14:13.299-0500|INFO|sun-appserver9.1| javax.enterprise.system.container.web| _ThreadID=16;_ThreadName=httpWorkerThread-8081-1;|PWC1412: WebModule ServletContext.log():/!\ FAILSAFE /!\ Thu Dec 11 16:14:13 -0500 2008   Status: 500 Internal Server Error   undefined method `' for nil:NilClass     /Applications/NetBeans/glassfish-v2ur2/domains/domain1/ applications/j2ee-modules/WebSite/WEB-INF/gems/gems/actionpack-2.2.2/ lib/action_controller/request.rb:597:in `clean_up_ajax_request_body!'     /Applications/NetBeans/glassfish-v2ur2/domains/domain1/ applications/j2ee-modules/WebSite/WEB-INF/gems/gems/actionpack-2.2.2/ lib/action_controller/request.rb:508:in `parse_formatted_request_parameters'     /Applications/NetBeans/glassfish-v2ur2/domains/domain1/ applications/j2ee-modules/WebSite/WEB-INF/gems/gems/actionpack-2.2.2/ lib/action_controller/request.rb:441:in `request_parameters'     /Applications/NetBeans/glassfish-v2ur2/domains/domain1/ applications/j2ee-modules/WebSite/WEB-INF/gems/gems/actionpack-2.2.2/ lib/action_controller/request.rb:392:in `parameters'     /Applications/NetBeans/glassfish-v2ur2/domains/domain1/ applications/j2ee-modules/WebSite/WEB-INF/gems/gems/actionpack-2.2.2/ lib/action_controller/request.rb:30:in `request_method'     /Applications/NetBeans/glassfish-v2ur2/domains/domain1/ applications/j2ee-modules/WebSite/WEB-INF/gems/gems/ activesupport-2.2.2/lib/active_support/memoizable.rb:86:in `request_method'     /Applications/NetBeans/glassfish-v2ur2/domains/domain1/ applications/j2ee-modules/WebSite/WEB-INF/gems/gems/actionpack-2.2.2/ lib/action_controller/request.rb:40:in `method'     /Applications/NetBeans/glassfish-v2ur2/domains/domain1/ applications/j2ee-modules/WebSite/WEB-INF/gems/gems/actionpack-2.2.2/ lib/action_controller/routing/route_set.rb:433:in `extract_request_environment'     /Applications/NetBeans/glassfish-v2ur2/domains/domain1/ applications/j2ee-modules/WebSite/WEB-INF/gems/gems/actionpack-2.2.2/ lib/action_controller/routing/route_set.rb:386:in `recognize'     /Applications/NetBeans/glassfish-v2ur2/domains/domain1/ applications/j2ee-modules/WebSite/WEB-INF/gems/gems/actionpack-2.2.2/ lib/action_controller/dispatcher.rb:182:in `handle_request'     /Applications/NetBeans/glassfish-v2ur2/domains/domain1/ applications/j2ee-modules/WebSite/WEB-INF/gems/gems/actionpack-2.2.2/ lib/action_controller/dispatcher.rb:110:in `dispatch_unlocked'     /Applications/NetBeans/glassfish-v2ur2/domains/domain1/ applications/j2ee-modules/WebSite/WEB-INF/gems/gems/actionpack-2.2.2/ lib/action_controller/dispatcher.rb:120:in `dispatch'     /Applications/NetBeans/glassfish-v2ur2/domains/domain1/ applications/j2ee-modules/WebSite/WEB-INF/gems/gems/actionpack-2.2.2/ lib/action_controller/dispatcher.rb:132:in `dispatch_cgi'     /Applications/NetBeans/glassfish-v2ur2/domains/domain1/ applications/j2ee-modules/WebSite/WEB-INF/gems/gems/actionpack-2.2.2/ lib/action_controller/dispatcher.rb:39:in `dispatch'     /Applications/NetBeans/glassfish-v2ur2/domains/domain1/generated/ jsp/j2ee-modules/WebSite/loader/rack/adapter/rails.rb:37:in `serve_rails'     /Applications/NetBeans/glassfish-v2ur2/domains/domain1/generated/ jsp/j2ee-modules/WebSite/loader/rack/adapter/rails.rb:44:in `call'     /Applications/NetBeans/glassfish-v2ur2/domains/domain1/generated/ jsp/j2ee-modules/WebSite/loader/jruby/rack/rails.rb:145:in `call'     /Applications/NetBeans/glassfish-v2ur2/domains/domain1/generated/ jsp/j2ee-modules/WebSite/loader/rack/handler/servlet.rb:17:in `call':1

2

Here's a thought: If it's Ajax and your are POSTing from jQuery, check
to see you have params. Some clients are sketchy about filling in a
body of a POST by themselves.

3

I think it's more multithreaded... we aren't using JQuery just prototype.

Most of the time things work but we are seeing errors where it appears the body just disappears.

Jay

4

Are you open to putting some code in rack? If so, I'd try inserting a
mutex as early in the request request cycle as possible and see
whether you can repro the problem with the threading reduced as close
to single-threaded as possible. If its a threading issue, you've got
some real detective work ahead of you, but it sounds like you already
know that.

Sorry not to be encouraging. We're using MRI and Mongrel -- but this
is, I agree, an important problem.

5

no… Thank you for responding! It’s good just to be able to talk with someone about it. I think I will be putting code into rack… Or rather with JRuby I think if I set it up to have multiple runtimes a mutex is inserted. I’m goign to keep on pluggin :slight_smile:

Jay