机架抛出EOFError(错误的内容主体) [英] Rack throwing EOFError (bad content body)
问题描述
我们正在将Ruby 2.1.2，Rails 3.2.19与JQuery 1.11结合使用，未使用资产管道(因此，未使用JQuery-ujs，而是显式使用了相关的rails.js).对于大多数用户而言，JQuery和其他相关的通用插件已从Google CDN中提取(包括jquery.form 3.50).受影响的Web服务器是Ubuntu 14.04，Nginx 1.6和Passenger 4.x.
We're using Ruby 2.1.2, Rails 3.2.19 with JQuery 1.11, asset pipeline is not being used (so not using JQuery-ujs, but are using relevant rails.js explicitly). For most users, JQuery and other related common plugins are being pulled from Google CDN (including jquery.form 3.50). The web server affected is Ubuntu 14.04, Nginx 1.6, and Passenger 4.x.
对于我们生产服务器上约10％的用户(负载似乎无关紧要)，我们会得到这样的堆栈转储，主要是针对一个URL，但还有其他URL:
For about 10% of users on our production server (loads seem to not matter), we're getting a stack dump like this, primarily for one URL but there are others:
/gems/rack-1.4.5/lib/rack/multipart/parser.rb:74 in "block in fast_forward_to_first_boundary"
/gems/rack-1.4.5/lib/rack/multipart/parser.rb:72 in "loop"
/gems/rack-1.4.5/lib/rack/multipart/parser.rb:72 in "fast_forward_to_first_boundary"
/gems/rack-1.4.5/lib/rack/multipart/parser.rb:15 in "parse"
/gems/rack-1.4.5/lib/rack/multipart.rb:25 in "parse_multipart"
/gems/rack-1.4.5/lib/rack/request.rb:336 in "parse_multipart"
/gems/rack-1.4.5/lib/rack/request.rb:201 in "POST"
/gems/actionpack-3.2.19/lib/action_dispatch/http/request.rb:237 in "POST"
/gems/actionpack-3.2.19/lib/action_dispatch/http/parameters.rb:10 in "parameters"
/gems/actionpack-3.2.19/lib/action_dispatch/http/filter_parameters.rb:31 in "filtered_parameters"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/rails3/action_controller.rb:31 in "process_action"
/gems/actionpack-3.2.19/lib/abstract_controller/base.rb:121 in "process"
/gems/actionpack-3.2.19/lib/abstract_controller/rendering.rb:45 in "process"
/gems/actionpack-3.2.19/lib/action_controller/metal.rb:203 in "dispatch"
/gems/actionpack-3.2.19/lib/action_controller/metal/rack_delegation.rb:14 in "dispatch"
/gems/actionpack-3.2.19/lib/action_controller/metal.rb:246 in "block in action"
/gems/actionpack-3.2.19/lib/action_dispatch/routing/route_set.rb:73 in "call"
/gems/actionpack-3.2.19/lib/action_dispatch/routing/route_set.rb:73 in "dispatch"
/gems/actionpack-3.2.19/lib/action_dispatch/routing/route_set.rb:36 in "call"
/gems/journey-1.0.4/lib/journey/router.rb:68 in "block in call"
/gems/journey-1.0.4/lib/journey/router.rb:56 in "each"
/gems/journey-1.0.4/lib/journey/router.rb:56 in "call"
/gems/actionpack-3.2.19/lib/action_dispatch/routing/route_set.rb:608 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/rack/error_collector.rb:50 in "traced_call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:55 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/rack/agent_hooks.rb:26 in "traced_call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:55 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/rack/browser_monitoring.rb:23 in "traced_call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:55 in "call"
/gems/oink-0.10.1/lib/oink/middleware.rb:17 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/warden-1.2.3/lib/warden/manager.rb:35 in "block in call"
/gems/warden-1.2.3/lib/warden/manager.rb:34 in "catch"
/gems/warden-1.2.3/lib/warden/manager.rb:34 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/actionpack-3.2.19/lib/action_dispatch/middleware/best_standards_support.rb:17 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/rack-1.4.5/lib/rack/etag.rb:23 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/rack-1.4.5/lib/rack/conditionalget.rb:25 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/actionpack-3.2.19/lib/action_dispatch/middleware/head.rb:14 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/actionpack-3.2.19/lib/action_dispatch/middleware/params_parser.rb:21 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/actionpack-3.2.19/lib/action_dispatch/middleware/flash.rb:242 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/rack-1.4.5/lib/rack/session/abstract/id.rb:210 in "context"
/gems/rack-1.4.5/lib/rack/session/abstract/id.rb:205 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/actionpack-3.2.19/lib/action_dispatch/middleware/cookies.rb:341 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/activerecord-3.2.19/lib/active_record/query_cache.rb:64 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/activerecord-3.2.19/lib/active_record/connection_adapters/abstract/connection_pool.rb:479 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/actionpack-3.2.19/lib/action_dispatch/middleware/callbacks.rb:28 in "block in call"
/gems/activesupport-3.2.19/lib/active_support/callbacks.rb:405 in "_run__3807242266783802268__call__1942732928323145202__callbacks"
/gems/activesupport-3.2.19/lib/active_support/callbacks.rb:405 in "__run_callback"
/gems/activesupport-3.2.19/lib/active_support/callbacks.rb:385 in "_run_call_callbacks"
/gems/activesupport-3.2.19/lib/active_support/callbacks.rb:81 in "run_callbacks"
/gems/actionpack-3.2.19/lib/action_dispatch/middleware/callbacks.rb:27 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/rack-1.4.5/lib/rack/sendfile.rb:102 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/actionpack-3.2.19/lib/action_dispatch/middleware/remote_ip.rb:31 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/actionpack-3.2.19/lib/action_dispatch/middleware/debug_exceptions.rb:16 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/actionpack-3.2.19/lib/action_dispatch/middleware/show_exceptions.rb:56 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/railties-3.2.19/lib/rails/rack/logger.rb:32 in "call_app"
/gems/railties-3.2.19/lib/rails/rack/logger.rb:18 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/actionpack-3.2.19/lib/action_dispatch/middleware/request_id.rb:22 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/rack-1.4.5/lib/rack/methodoverride.rb:21 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/rack-1.4.5/lib/rack/runtime.rb:17 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/activesupport-3.2.19/lib/active_support/cache/strategy/local_cache.rb:72 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/rack-1.4.5/lib/rack/lock.rb:15 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/rack-cache-1.2/lib/rack/cache/context.rb:136 in "forward"
/gems/rack-cache-1.2/lib/rack/cache/context.rb:245 in "fetch"
/gems/rack-cache-1.2/lib/rack/cache/context.rb:185 in "lookup"
/gems/rack-cache-1.2/lib/rack/cache/context.rb:66 in "call!"
/gems/rack-cache-1.2/lib/rack/cache/context.rb:51 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/railties-3.2.19/lib/rails/engine.rb:484 in "call"
/gems/railties-3.2.19/lib/rails/application.rb:231 in "call"
/gems/railties-3.2.19/lib/rails/railtie/configurable.rb:30 in "method_missing"
/gems/rack-1.4.5/lib/rack/urlmap.rb:64 in "block in call"
/gems/rack-1.4.5/lib/rack/urlmap.rb:49 in "each"
/gems/rack-1.4.5/lib/rack/urlmap.rb:49 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/gems/sass-3.2.19/lib/sass/plugin/rack.rb:54 in "call"
/gems/newrelic_rpm-3.9.3.241/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in "call"
/var/www/.rvm/gems/ruby-2.1.2/gems/passenger-4.0.45/lib/phusion_passenger/rack/thread_handler_extension.rb:74 in "process_request"
/var/www/.rvm/gems/ruby-2.1.2/gems/passenger-4.0.45/lib/phusion_passenger/request_handler/thread_handler.rb:141 in "accept_and_process_next_request"
/var/www/.rvm/gems/ruby-2.1.2/gems/passenger-4.0.45/lib/phusion_passenger/request_handler/thread_handler.rb:109 in "main_loop"
/var/www/.rvm/gems/ruby-2.1.2/gems/passenger-4.0.45/lib/phusion_passenger/request_handler.rb:448 in "block (3 levels) in start_threads"
在从1.5(！)升级到JQuery 1.11之前，未发生此错误(或者，如果确实如此，则非常罕见).到目前为止，无论是在我们的登台服务器上还是在开发环境中，我们都无法重现此错误.一个支持人员曾经在生产中看到过它(我已经尝试了几次)，但是无法在登台上复制(这与生产环境相同，尽管资源较少). JQuery迁移在运行时没有显示任何问题，正如我所说，它似乎对大多数用户都有效.在调试会话期间，似乎没有任何毛病. OS/平台或浏览器没有明显的模式(试图在多个平台上重现，并且日志虽然很难筛选以确保不能显示出这种模式).涉及的主要URL用于在表单控制器上执行#new操作.平台中还有其他几种形式，它们没有显示任何问题.
Before an upgrade to JQuery 1.11 from 1.5(!), this error didn't occur (or if it did, it was very rare). We so far have been unable to reproduce this error either on our staging server or in a development environment. A support person saw it on production once (I've tried several times), but couldn't replicate on staging (which is same environment as production, though smaller resourcing). JQuery migrate is not showing any issues when it runs and, as I said, it seems to work for most users; during debug sessions nothing seems amiss. There is no apparent pattern to OS/platform or browser (tried to reproduce on several and logs don't indicate a pattern though hard to sift enough to be sure). The primary URL involved is for a #new action on a form controller. We have several other forms in the platform and they do not show any issues.
由于我无法复制它，因此无法提供代码段－我不知道该找些什么.
Since I can't reproduce it, giving a code snippet is not possible -- I wouldn't know what to pinpoint.
到目前为止，我对错误的解释(基于堆栈转储的第一行)是三件事之一:
My interpretation of the error so far (based on first line in stack dump) is one of the three things:
- 该内容在其他方面是正确的，但由于某种原因并未完全形成，
- 内容格式不正确，表明存在Ruby错误(尽管 也许是JS)
- 编码错误(我在Ruby中甚至使用了form_for 明确地输入"multipart:true")
- the content is otherwise correct, but not fully formed somehow,
- the content is poorly formed suggesting a Ruby bug (though perhaps JS)
- bad encoding (I'm using form_for in Ruby and even threw in "multipart: true" to be explicit)
我看到Rack在4.x中处理了一个相关的多部分EOFError问题，但是我们正在运行Rails 3.2.19，它将我们锁定在较旧的版本，并且此时升级到Rails 4.x不切实际.作为测试，我已经尝试将JQuery降低到1.7，但似乎并没有改变其行为(任何较旧的版本，我都必须放弃JQuery 1.8+所需的代码更新).
I see Rack has dealt with a related multipart EOFError issue in 4.x, but we're running Rails 3.2.19 which locks us at an older version and upgrading to Rails 4.x is not practical at this time. As a test, I've tried JQuery back to as low as 1.7 but didn't seem to change the behavior (any older and I'd have to drop code updates needed for JQuery 1.8+).
由于JQuery代码需要对我们的JS进行更改，因此我怀疑我错过了一些必要的JS更改，但似乎没有任何不妥之处.附近也有一些CSS更改，但是我不知道这会如何影响事情(由于一切都在我们的各种测试环境中通过，因此其他更改也包含在部署中).
Since the JQuery code necessitated changes to our JS, I suspected I missed some necessary JS changes, but nothing seems amiss. There were also some CSS changes nearby, but I don't see how that could affect things (since everything was passing in our various test environments, other changes were also included in the deploy).
我主要是在怀疑JS问题，但是在生产中进行了一些有限的测试(我必须在实时服务器上小心，以免过于激进)没有显示出任何线索或引发任何看起来相关的错误.
I've been suspecting JS issues primarily, but some limited tests on production (I have to be careful on the live server so can't get too aggressive) haven't shown any clues or thrown any errors that seem related.
作为背景，我在Ruby和JS方面有大约一年的经验(尽管在其他编程平台上有很多年)，因此完全有可能是我不熟悉的基本知识.
As background, I have about a year's experience with Ruby and JS (though many more years on other programming platforms) so entirely possible it's something basic I'm unfamiliar with.
我很难确定要集中精力解决问题的地方.对诊断或解决有什么建议吗?
I'm having a hard time with narrowing down where to focus to get a handle on this. Any advice either to diagnose or solve?
更新(14/11/14)，我猴子修补了Rack::Multipart::Parser.fast_forward_to_first_boundary(感谢Isaac Betesh！)以添加日志跟踪，并确认传递到解析器的内容在达到该值时为空.函数(即，在多部分分析期间由@env['rack.input']引用的StringIO不返回任何数据).我现在的理论是，当没有多部分数据时，它会错误地期望多部分数据.同样，这只是间歇性地发生，并且对于同一页面的许多其他调用也可以很好地解析.由于我们是在Passenger 4.x和Nginx下运行的，因此我不排除存在缓冲问题.
UPDATE (10/11/14) I monkey patched Rack::Multipart::Parser.fast_forward_to_first_boundary (thanks, Isaac Betesh!) to add log traces and confirmed that the content passed to the parser is empty when it reaches that function (that is, the StringIO referred to by @env['rack.input'] during multipart parsing returns no data). My theory now is that it erroneously expects multipart data when there is there is none. Again, this only happens intermittently and parses fine for many other invocations of this same page. Since we're running under Passenger 4.x and Nginx, I haven't ruled out a buffering issue.
推荐答案
终于解决了这个问题，我将发布发生的情况，以防对他人有所帮助.
This was finally solved and I'm posting what happened in case it's helpful to others.
摘要原始代码在JS中包含一个ajaxSubmit(通过jquery.form插件)，该jaxSubmit提交了具有multipart/form-data编码的表单(作为POST)(到目前为止非常好).处理提交的Rails控制器通常会处理数据，然后重定向到另一个href(作为GET).浏览器(可能仍在通过jquery.form插件进行处理，然后返回其success回调处理程序)接收到重定向并保留的multipart/form-data编码类型.当机架收到仍指定多部分编码的GET时，由于没有要分析的多部分数据而被拒绝.
Summary The original code contained an ajaxSubmit (via jquery.form plugin) in the JS which submitted a form (as a POST) with multipart/form-data encoding (so far so good). The rails controller handling the submission processed the data normally and then redirected to a second href (as a GET). The browser (perhaps still processing through the jquery.form plugin before returning to it's success callback handler) received the redirect and retained the multipart/form-data encoding type. When rack received the GET with multipart encoding still specified, it balked because there was no multipart data to parse.
很抱歉，我的OP中并未提供很多证据.而且我还不清楚为什么它在旧版本的JQuery和JQuery.form插件下可以工作，或者为什么有时在新的JQuery/JQuery.form下可以成功.
Sorry, much of this wasn't in evidence in my OP. And it's not clear to me why this worked under an older version of JQuery and the JQuery.form plugin or why it sometimes succeeded under the new JQuery/JQuery.form.
解决方案，将控制器重构为不再重定向，而是返回原始ajaxSubmit的success回调处理程序的URL(作为文本呈现).现在，success处理程序对返回的URL进行AJAX GET，从而使工作流保持完整，但避免对GET请求进行任何多部分编码.
Solution Refactored the controller to no longer redirect, but rather return a URL (as a text render) for the success callback handler of the original ajaxSubmit. The success handler now then does an AJAX GET on the returned URL thereby leaving the workflow intact but avoiding any multipart encoding on the GET request.
tl; dr :
在更改代码之前，我们有一条涉及Jquery.form的路径，其内容如下所示(代码示例并不意味着可以执行，而只是为了说明):
Before the code was ever changed, we had a path involving Jquery.form that went something like this (code example is not meant to be executable, but just as an illustration):
Ruby视图(在HAML中用于提交表单):
Ruby view (in HAML for form being submitted):
= form_for @someObject, html: {:multipart => true, :class => "someformclass"} do |f|
= f.error_messages
= hidden_field_tag :submitted, true
=# some more fields
%p.submits
= f.submit "Submit", class: "submit"
Ruby控制器:
class OurController < ApplicationController
layout false
before_filter :authenticate_user!
# some other actions
def create
# some processing
someObject.save
redirect_to new_feedback_path, :method => :get, :notice => "notice text", status: 303
end
# some other actions
end
JS :
$(document).on('click', '.someformclass .submit', function() {
...
$(this).parents('form').ajaxSubmit({ // uses jquery.form
...
beforeSubmit: function(someargs) {
... blah blah
},
success: function(responseText) {
// ... code to display flash message
if (typeof(window.history.pushState) == 'function') {
window.history.pushState('html', 'sometext', $.cookie('current_url'));
matchFiltersClass(window.location.pathname);
} else {
window.location.hash = '#!' + $.cookie('current_path');
matchFiltersClass($.cookie('current_path'));
}
$('#main_content').html(responseText);
}
});
return false;
});
重构如下(再次只是一个例子):
This was refactored as follows (again, just an illustration):
Ruby视图(在HAML中用于提交表单):未更改
Ruby view (in HAML for form being submitted): unchanged
Ruby控制器:
class OurController < ApplicationController
layout false
before_filter :authenticate_user!
# some other actions
def create
# some processing
someObject.save
flash[:notice] = 'notice text' # NEW LINE
render text: new_feedback path, status: accepted #CHANGED LINE
end
# some other actions
end
JS :
$(document).on('click', '.someformclass .submit', function() {
...
$(this).parents('form').ajaxSubmit({ // uses jquery.form
...
beforeSubmit: function(someargs) {
... blah blah
},
success: function(responseText) {
// ... code to display flash message
$.get(responseText, function(data) { // NEW LINE
if (typeof(window.history.pushState) == 'function') {
window.history.pushState('html', 'sometext', $.cookie('current_url'));
matchFiltersClass(window.location.pathname);
} else {
window.location.hash = '#!' + $.cookie('current_path');
matchFiltersClass($.cookie('current_path'));
}
$('#main_content').html(responseText);
}); // NEW LINE
}
});
return false;
});
此解决方案是在本地开发人员的帮助下找到的(感谢Dan Axtman！)，并且在Rack的猴子补丁日志记录中花费了大量的时间(感谢Isaac Betesh！).至少我在此过程中学到了有关机架和猴子修补的知识...
This solution was found with some help with a local developer (thanks, Dan Axtman!) and not without a fair amount of time in monkey-patched logging in Rack (thanks, Isaac Betesh!). At least I learned something about Rack and monkey patching in the process...
这篇关于机架抛出EOFError(错误的内容主体)的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！
