Railsをお仕事で使っている方はみんなE2Eのテストで時々失敗するやつに苦労しているんじゃないかなと思います。
@mtsmfmさんの発表スライドが詳しいので基本的にはこれで大体のケースには対応できるはず。
スライド読むのがめんどくさい人向けに、一部抜粋かつ要約すると
なんらかの要因(CSSアニメーションや画像のロード)でDOM要素が移動する場合にクリックをミスしてしまってテストが失敗するケースが「時々失敗するテスト」の大多数を占める
という話になります。これを防ぐためにはCSSのアニメーションをオフにしたり、↓のようなメソッドを利用して画像が完全にロードするまで待ってからクリックする、という方法があります。
def wait_for_image_loading
Timeout.timeout(Capybara.default_max_wait_time) do
sleep 0.5 until evaluate_script(<<~JS)
Array.prototype.every.call(
document.querySelectorAll('img'),
(e) => e.complete
)
JS
end
end
で、僕も同様のやり方を採用していたのですがそれでも時々テストが失敗します。そこでいい加減原因を究明しないとなーと思ったので計測の方法を調べました。
前提
- Rails
- rspec
- capybara
- selenium
- headless chrome
です。バージョンはどれも現時点での最新安定版です
どこをクリックしているのか調べる
seleniumやchrome driverはそれぞれログ出力するオプションを持っていますが、僕が調べた限りではあまり有用な情報は取れませんでした(一番最後にログの取得方法を書いておきます)
seleniumには、クリックや画面遷移やjsの実行などの前後にコールバックメソッドを実行する仕組みが用意されています。
Class: Selenium::WebDriver::Support::AbstractEventListener — Documentation for selenium-webdriver (3.142.2)
これを継承した次のようなクラスを作ります。
class NavigationListener < Selenium::WebDriver::Support::AbstractEventListener
def initialize(logger)
@logger = logger
end
def after_find(by, what, driver)
logger.info "finded #{by}, #{what}"
end
def before_click(element, driver)
logger.info "clicking location: #{element.location}"
if element.tag_name == 'a'
href = element.attribute('href')
logger.info "before click to: #{href}"
end
end
def after_navigate_to(url, driver)
logger.info "after navigate to: #{url}"
end
private
attr_reader :logger
end
rails_helper.rbで次のようなcapybara用のdriverを作ります
logger = Logger.new(Rails.root.join('log', 'selenium_hooks.log'))
listener = NavigationListener.new(logger)
Capybara.register_driver :selenium_chrome_headless do |app|
browser_options = Selenium::WebDriver::Chrome::Options.new
browser_options.args << '--headless'
browser_options.args << '--disable-gpu'
browser_options.args << '--no-sandbox'
Capybara::Selenium::Driver.new(
app, browser: :chrome, options: browser_options, listener: listener
).tap do |driver|
driver.browser.manage.window.size = Selenium::WebDriver::Dimension.new(
1920, 1080
)
end
end
これで、どこをクリックしようとしたのかログに残すことができます。次に、失敗を再現させてみましょう。たまにコケるテストを1000回ほど実行してみます。
1000.times do
it '送信したメッセージが表示されていること' do
expect(page).to have_content(message.body)
end
end
このとき、rails_helper.rbで次のように最初にテストがコケたタイミングでテスト全体が終了するようにしておくと便利です。
config.fail_fast = 1
無事テストが失敗したら、失敗したときのクリック座標と成功したときのクリック座標とを比べてみたり、log/test.logでリクエストが正しく送られてきているかを確認します。僕は↓のような結果になりました。test.logを確認してもリクエストが送られていないので、これはクリックミスしている疑いが濃厚ですね…。
失敗しているとき
clicking location : #<struct Selenium::WebDriver::Point x=413.5, y=381.375>
成功しているとき
clicking location: #<struct Selenium::WebDriver::Point x=413.5, y=551.765625>
最終的に、僕の今回のケースではturbolinksを利用しているのが原因で、wait_for_image_loadingが遷移前のページに対して実行されてしまい有効に動いていなかったのが原因である、という結論になりました。次のページへの遷移を待ってからwait_for_image_loadingを実行することで解決。
seleniumとchrome driverのログを取得する方法
他にハマって時間を取られる人が減るように記録に残しておきます。seleniumのログは次のようにするととれます。
Selenium::WebDriver.logger.level = :debug
Selenium::WebDriver.logger.output = 'selenium.log'
Ruby Bindings · SeleniumHQ/selenium Wiki
chromedriverのログは次のように、新しくdriverを定義する中のdriver_opts
オプションを利用します。
Capybara.register_driver :selenium_chrome_headless do |app|
browser_options = Selenium::WebDriver::Chrome::Options.new
browser_options.args << '--headless'
browser_options.args << '--disable-gpu'
browser_options.args << '--no-sandbox'
Capybara::Selenium::Driver.new(
app, browser: :chrome, options: browser_options, driver_opts: '--verbose'
).tap do |driver|
driver.browser.manage.window.size = Selenium::WebDriver::Dimension.new(
1920, 1080
)
end
end
driver_optsオプションで指定した文字列がchromedriverの起動オプションとして渡されます。(driver_optsオプションを利用すると、seleniumにdeprecatedだと怒られるのですがいったんこれでOKとしています)。
Logging - ChromeDriver - WebDriver for Chrome
(2023/08/29追記)今はdriver_optsオプションは使えません。次のようにserviceオプションを利用します。
Capybara.register_driver :selenium_chrome_headless do |app|
options = Selenium::WebDriver::Chrome::Options.new
options.args << '--headless'
options.args << '--disable-gpu'
options.args << '--no-sandbox'
service = Selenium::WebDriver::Service.chrome
service.args << '--verbose'
Capybara::Selenium::Driver.new(
app, browser: :chrome, timeout: 600, options:, service:
)
end
(追記ここまで)
ここで注意したいのが、chromedriverのログを取得するとき、seleniumのログ設定がないとログを取得することができないということです。どうやら、selenium側でchromedriverの標準エラー出力をseleniumのログ出力と同じにしている模様(かつ、chromedriver側がそれを尊重しているっぽい(未確認))。
selenium/service.rb at abf2219b575bea98e4093fb13843f487da7edb51 · SeleniumHQ/selenium
consoleを見る方法
おまけ。↓のようにするとconsoleの出力が確認できるみたいです(今回は特に活躍することがなかった)
logger.debug(page.driver.browser.manage.logs.get(:browser))