2014-09-16 3 views
6

Мы используем Ruby 2.1.2, Rails 3.2.19 с JQuery 1.11, конвейер ресурса не используется (поэтому не используйте JQuery-ujs, но используете соответствующие rails.js явно). Для большинства пользователей JQuery и другие связанные общие плагины извлекаются из Google CDN (включая jquery.form 3.50). На веб-сервере влияют Ubuntu 14.04, Nginx 1.6 и Passenger 4.x.Rack throwing EOFError (плохой контент)

Около 10% пользователей на нашем сервере продукции (нагрузки, кажется, не имеет значения), мы получаем дамп стека, как это, в первую очередь для одного URL, но есть и другие:

/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" 

Перед тем, как обновление до JQuery 1.11 с 1.5 (!), эта ошибка не возникала (или, если это было так, это было очень редко). Мы до сих пор не смогли воспроизвести эту ошибку либо на нашем промежуточном сервере, либо в среде разработки. Один человек поддержки видел его на производстве один раз (я несколько раз пробовал), но не мог реплицироваться при постановке (это такая же среда, как и производство, хотя и меньшее количество ресурсов). Перенос JQuery не показывает никаких проблем при запуске, и, как я уже сказал, он работает для большинства пользователей; во время сеансов отладки ничего не кажется неправильным. Для OS/платформы или браузера нет видимой картины (они пытались воспроизвести несколько, и журналы не указывают на шаблон, хотя достаточно сложно просеять, чтобы быть уверенным). Основной URL-адрес связан с # новым действием на контроллере формы. У нас есть несколько других форм на платформе, и они не показывают никаких проблем.

Поскольку я не могу воспроизвести его, предоставление фрагмента кода невозможно - я не знаю, что именно точно определить.

Моя интерпретация ошибки до сих пор (на основе первой строки в стеке дампа) является одним из трех вещей:

  1. содержание в противном случае правильно, но не полностью сформирован как-то,
  2. содержание плохо формируются предполагая ошибку Ruby (хотя возможно JS)
  3. плохого кодирования (я использую form_for в Ruby, и даже бросил в «многочастный: правде», чтобы быть явными)

Я вижу, что Rack имеет дело с проблемой множественного EOFError в 4.x, но мы запускаем Rails 3.2.19, которая блокирует нас в более старой версии и обновление до Rails 4.x в настоящее время нецелесообразно. В качестве теста я попробовал JQuery до 1,7, но, похоже, не изменил его поведение (все было старше, и мне пришлось бы отбрасывать обновления кода, необходимые для JQuery 1.8+).

Поскольку код JQuery требовал внесения изменений в наш JS, я подозревал, что пропустил некоторые необходимые изменения JS, но ничего не кажется неправильным. Также были некоторые изменения CSS, но я не вижу, как это может повлиять на вещи (поскольку все проходило в разных тестовых средах, в развертывание также были включены другие изменения).

Я подозреваю, что вопросы JS в первую очередь, но некоторые ограниченные тесты на производство (я должен быть осторожным на реальном сервере, поэтому не могу быть слишком агрессивным) не обнаружил никаких подсказок или не вызвал ошибок, которые кажутся связанными ,

В качестве фона у меня есть опыт работы в течение года с Ruby и JS (хотя еще много лет на других платформах программирования), настолько возможно, что это то, с чем я не знаком.

У меня с трудом сужается, где сосредоточиться, чтобы получить ручку на этом. Любой совет, который нужно диагностировать или решать?

UPDATE (10/11/14) Я обезьяна заплата Rack::Multipart::Parser.fast_forward_to_first_boundary (спасибо, Исаак Betesh!), Чтобы добавить следы журнала и подтвердила, что содержание передается в анализатор пусто, когда он достигает эту функцию (то есть, StringIO, на который ссылается @env['rack.input'] при многократном разборе, не возвращает данные). Моя теория заключается в том, что она ошибочно ожидает многочастных данных, когда их нет. Опять же, это происходит только периодически и отлично разбирается во многих других вызовах этой же страницы. Поскольку мы работаем под Passenger 4.x и Nginx, я не исключил проблему буферизации.

+1

Если вы не можете обновить стойку, потому что Rails 3 блокирует версию, попробуйте обезвредить отдельный класс в файле в верхней части стека след. Вы не можете понять, почему это происходит, но это может быть эффективным решением. –

+0

Я мог бы, но беспокоился об изменении кода запаса на производстве (учитывая, что я действительно не могу его протестировать первым без воспроизведения), может дать мне ключ, хотя если он изменит поведение, и если это облегчит жизнь пользователям, это может стоит того. Благодарю. – rdnewman

+0

Кроме того, этот же код казался прекрасным до обновления до JQuery и связанных с ним изменений в JS (учитывая другие изменения в том же развёртывании этого теста). Поэтому изменение в JQuery должно было каким-то образом вызвать сбой в Rack, так же как и моя другая причина колебания. – rdnewman

ответ

8

Это было окончательно решено, и я публикую, что произошло, если оно полезно другим.

Резюме Исходный код содержал ajaxSubmit (через jquery.form плагин) в JS, которая представила форму (как POST) с кодированием многочастному/формы-данных (до сих пор так хорошо). Контроллер рельсов, обрабатывающий представление, обработал данные нормально, а затем перенаправил на второй href (как GET). Браузер (возможно, все еще обрабатывающий через плагин jquery.form перед возвратом в обработчик обратного вызова success) получил перенаправление и сохранил тип кодирования multipart/form-data. Когда стойка получила GET с многопрофильным кодированием, который все еще задан, он отклоняется, потому что для разбора не было многочастных данных.

Извините, многое из этого не было представлено в моем ОП. И мне непонятно, почему это работало в более старой версии JQuery и плагина JQuery.form или почему это иногда удавалось с помощью нового JQuery/JQuery.form.

Решение Refactored контроллер больше не перенаправлять, а возвращает URL (как текст визуализации) для обработчика success обратного вызова исходного ajaxSubmit. Затем обработчик success выполняет AJAX GET на возвращаемом URL-адресе, тем самым оставляя рабочий процесс неповрежденным, но избегая многопроцессорной кодировки в запросе GET.

Т.Л., д-р:

Перед тем как код был изменен когда-либо, у нас был путь с участием Jquery.форма, которая пошла что-то вроде этого (пример кода не означает быть исполняемым, но только в качестве иллюстрации):

Рубин зрения (в Haml для формы их представления):

= 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" 

Рубин контроллера:

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; 
}); 

Это был переработан следующим образом (опять же, просто иллюстрация):

Рубин вид (в Haml для формы их представления): неизменного

Рубин Контроллер:

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: (! Спасибо, Dan Axtman)

$(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; 
}); 

Это решение было найдено с некоторыми помощью с местным разработчиком и не без изрядного времени в обезьяннике-заплате лесозаготовок в стойке (спасибо, Исаак Бетеш!). По крайней мере, я кое-что узнал о том, что Rack и обезьяна исправлены в процессе ...