Тест Rails не проходит, запросы не завершены за 60 секунд - PullRequest
0 голосов
/ 22 ноября 2018

После обновления rails с 4.2 до 5.2 мой тест зависает на запросе, пока он работает на сервере разработки. Я получаю следующую ошибку при запуске тестового набора.

Failures:

  1) cold end overview shows cold end stats
     Failure/Error: example.run

     RuntimeError:
       Requests did not finish in 60 seconds
     # /home/asnad/.rvm/gems/ruby-2.5.0/gems/capybara-2.18.0/lib/capybara/server.rb:94:in `rescue in wait_for_pending_requests'
     # /home/asnad/.rvm/gems/ruby-2.5.0/gems/capybara-2.18.0/lib/capybara/server.rb:91:in `wait_for_pending_requests'
     # /home/asnad/.rvm/gems/ruby-2.5.0/gems/capybara-2.18.0/lib/capybara/session.rb:130:in `reset!'
     # /home/asnad/.rvm/gems/ruby-2.5.0/gems/capybara-2.18.0/lib/capybara.rb:314:in `block in reset_sessions!'
     # /home/asnad/.rvm/gems/ruby-2.5.0/gems/capybara-2.18.0/lib/capybara.rb:314:in `reverse_each'
     # /home/asnad/.rvm/gems/ruby-2.5.0/gems/capybara-2.18.0/lib/capybara.rb:314:in `reset_sessions!'
     # /home/asnad/.rvm/gems/ruby-2.5.0/gems/capybara-2.18.0/lib/capybara/rspec.rb:22:in `block (2 levels) in <top (required)>'
     # ./spec/spec_helper.rb:43:in `block (3 levels) in <top (required)>'
     # /home/asnad/.rvm/gems/ruby-2.5.0/gems/database_cleaner-1.6.2/lib/database_cleaner/generic/base.rb:16:in `cleaning'
     # /home/asnad/.rvm/gems/ruby-2.5.0/gems/database_cleaner-1.6.2/lib/database_cleaner/base.rb:98:in `cleaning'
     # /home/asnad/.rvm/gems/ruby-2.5.0/gems/database_cleaner-1.6.2/lib/database_cleaner/configuration.rb:86:in `block (2 levels) in cleaning'
     # /home/asnad/.rvm/gems/ruby-2.5.0/gems/database_cleaner-1.6.2/lib/database_cleaner/configuration.rb:87:in `cleaning'
     # ./spec/spec_helper.rb:37:in `block (2 levels) in <top (required)>'
     # ------------------
     # --- Caused by: ---
     # Timeout::Error:
     #   execution expired
     #   /home/asnad/.rvm/gems/ruby-2.5.0/gems/capybara-2.18.0/lib/capybara/server.rb:92:in `sleep'

Top 1 slowest examples (62.59 seconds, 97.0% of total time):
  cold end overview shows cold end stats
    62.59 seconds ./spec/features/cold_end_overview_spec.rb:13

Finished in 1 minute 4.51 seconds (files took 4.15 seconds to load)
1 example, 1 failure

мой spec_helper.rb имеет конфигурации

RSpec.configure do |config|
  config.include FactoryBot::Syntax::Methods

  config.around(:each) do |example|
    DatabaseCleaner[:active_record].clean_with(:truncation)

    DatabaseCleaner.cleaning do
      if example.metadata.key?(:js) || example.metadata[:type] == :feature
        # VCR.configure { |c| c.ignore_localhost = true }
        WebMock.allow_net_connect!
        VCR.turn_off!
        VCR.eject_cassette
        example.run
      else
        # WebMock.disable_net_connect!
        VCR.turn_on!
        cassette_name = example.metadata[:full_description]
                               .split(/\s+/, 2)
                               .join('/')
                               .underscore.gsub(/[^\w\/]+/, '_')
        # VCR.configure { |c| c.ignore_localhost = false }
        VCR.use_cassette(cassette_name) { example.run }
        VCR.turn_off!
        WebMock.allow_net_connect!
      end
    end
  end

  config.expect_with :rspec do |expectations|
    expectations.include_chain_clauses_in_custom_matcher_descriptions = true
  end

  config.mock_with :rspec do |mocks|
    mocks.verify_partial_doubles = true
  end

  config.filter_run :focus
  config.run_all_when_everything_filtered = true

  config.example_status_persistence_file_path = "spec/examples.txt"

  if config.files_to_run.one?
    config.default_formatter = 'doc'
  end

  # Print the 10 slowest examples and example groups at the
  # end of the spec run, to help surface which specs are running
  # particularly slow.
  config.profile_examples = 10

  # Run specs in random order to surface order dependencies. If you find an
  # order dependency and want to debug it, you can fix the order by providing
  # the seed, which is printed after each run.
  #     --seed 1234
  config.order = :random

  # Seed global randomization in this process using the `--seed` CLI option.
  # Setting this allows you to use `--seed` to deterministically reproduce
  # test failures related to randomization by passing the same `--seed` value
  # as the one that triggered the failure.
  Kernel.srand config.seed
end

# Selenium::WebDriver.logger.level = :debug
# Selenium::WebDriver.logger.output = 'selenium.log'
Capybara.register_driver :selenium_chrome_headless do |app|
  capabilities = Selenium::WebDriver::Remote::Capabilities.chrome(chromeOptions: { args: %w[headless no-sandbox disable-dev-shm-usage disable-gpu window-size=1200,1500] }, loggingPrefs: { browser: 'ALL' })
  Capybara::Selenium::Driver.new(app, browser: :chrome, desired_capabilities: capabilities)
end

Chromedriver.set_version '2.39'

Capybara.javascript_driver = :selenium_chrome_headless
Capybara::Screenshot.prune_strategy = :keep_last_run

в моей спецификации строка sign_in current_user отнимает слишком много времени, фактически она перенаправляет на страницу и не получает ответа даже долгое время, пока работает в среде разработки.что может быть причиной, если вам нужно что-то еще, пожалуйста, прокомментируйте.

1 Ответ

0 голосов
/ 15 июня 2019

Я только что прибыл сюда сам после обновления с 4.2 до 5.1 и сейчас 5.2, и я вижу то же самое в своем тестировании, когда я замораживаю тест в середине запроса с binding.pry, я получаюсообщение Requests did not finish in 60 seconds.Какая замечательная история, перейдите к концу для tl; dr (возможно, я понял это.)

Теперь я обновил все драгоценные камни постепенно, чтобы я мог сохранить способность делить пополам и наблюдать источникинтересных изменений, как этот.Я только заметил этот новый 60-секундный тайм-аут после перехода с chromedriver-helper, который сообщил, что он устарел к новому webdrivers гему, который вступает во владение, но это, похоже, не связано, поскольку я искал веб-драйверы для любого тайм-аута или значения 60 секунди обнаружил только ссылки на несвязанный запрос на извлечение № 60 (исправляет проблему № 59).

Я проверил каталог своего источника gem на наличие этого сообщения Requests did not finish in 60 seconds и обнаружил, что на самом деле это не старая версияКапибара, но она была поднята из версий, начиная с версии не ниже 3.9.0, и в самой последней версии 3.24.0 в lib/capybara/server.rb.

Используемый там объект есть Таймер, который вы можете найтиинтерфейс к нему здесь, в помощнике:

https://github.com/teamcapybara/capybara/blob/320ee96bb8f63ac9055f7522961a1e1cf8078a8a/lib/capybara/helpers.rb#L79

Это конкретное сообщение возникает из метода wait_for_pending_requests, который передает хард-60 в именованный параметр :expire_in,затем после отправляет любые ошибки, которые были обнаружены в потоке сервера.Это означает, что время не настраивается, вероятно, 60 секунд - это разумный промежуток времени для ожидания выполнения веб-запроса, хотя это немного неудобно для моего теста.

Этот метод вызывается только в одномместо, reset!, которое вы можете найти здесь, в capybara/session.rb: https://github.com/teamcapybara/capybara/blob/320ee96bb8f63ac9055f7522961a1e1cf8078a8a/lib/capybara/session.rb#L126

Сброс!Метод интересный, который поставляется с некоторой документацией о том, как он используется.@server&.wait_for_pending_requests похоже, что он может вызвать wait_for_pending_requests, если в запросе есть активный поток сервера, а затем повысить_сервер_еррор!который действует аналогично, только если @server&.error является правдивым.

Теперь мы находим этот сброс!поставляется с двумя псевдонимами, это сообщение reset! принимается всякий раз, когда Capybara вызывает cleanup! или reset_session!.На данный момент мы, вероятно, можем понять, что произошло, но это все еще немного загадочно, когда я использую тестирование chromedriver-helper и селен в течение нескольких лет, но никогда не вспоминаю, что видел этот 60-секундный тайм-аут раньше.Я не решаюсь указать пальцем на вебдрайвера, но у меня нет других ответов, почему этот тайм-аут является новым.На самом деле я не сделал ничего, что могло бы объяснить это, кроме обновления до этого драгоценного камня и любых других драгоценных камней, а также очистки предупреждений об устаревании.

Кажется возможным, что в Rails 5.1+ вызовы капибары сбрасываются!намного больше, может быть, больше, чем между тестовыми примерами.Особенно, когда вы читаете эту документацию по методу и думаете о том, какой фокус был на одной странице, и рассматриваете все то, что документация reset! говорит вам, что она не сбрасывается, очищает кеш браузера / HTML 5локальное хранилище / IndexedDB / база данных Web SQL / etc - или, может быть, я это представляю, и это не ново.Но я представляю, что есть много способов, которыми он может вызвать сброс!и не попадать в этот код тайм-аута, который, вероятно, зависит от драйвера.

Вы случайно не изменили на webdrivers gem, когда обновляли Rails?

Edit: Я вернулся к chromedriver-помощнику, чтобы быть уверенным, и это было не так.Что на самом деле происходит, так это то, что мой тест провалился в одном потоке, но сервер оставил сеанс binding.pry открытым.Capybara перешел к следующему тесту, и, таким образом, чтобы получить новый сеанс, он вызвал reset!, но через 60 секунд я все еще в моем сеансе pry, и сервер все еще не готов обслуживать корневой запрос.У меня такое ощущение, что поведение капибары в потоке изменилось, в моей памяти сеанс pry, открытый во время запроса к серверу, блокировал бы сбой теста до его возвращения.Но это, видимо, уже не то, что происходит.

Как вы сюда попали?К сожалению, я понятия не имею, но это точное описание того, что происходит при получении этого сообщения.

...