つまらないポカで多大な時間を失った話

発生した問題と原因

すでにあるRailsで作ったWebアプリにRspecのテストを追加していたところ、自分でブラウザでいじっている場合には問題なく動いているが、「capybara-webkitで一部のテストがRoutingErrorで通らない」という問題が起きた。

結論だけ言うと、

サインインした後は、そのユーザのプロフィール画像を表示するようにしているが、FactoryGirlで生成していたUserのプロフィール画像がnilだった。そのためimgタグのsrcが空文字になっており、開いたページへもう一度GETリクエストが飛んでいた。

という本当に下らないミスだった。

思いっきり自分のポカで一般的な問題では無いので共有する意味もないかなと思いつつ、特定にあまりにも時間がかかってしまったので、反省のためにブログにする。

実際に踏んだプロセス

まず初めは
「一部のテストがRoutingErrorでテストが通らない」
という問題だった。

  1. とりあえず通ってないテストでpage.htmlを吐き出させてみると期待したHTMLは表示されているようであることを確認。混乱する。

  2. 実際に動く様子を見てみようとseleniumを入れてchromeで見てみるとテストが通ることを確認。更に混乱する。poltergeistでも試してみると通らない。

  3. webkitと何かの組み合わせが悪いのかと思い、同じ問題を再現するアプリを作ろうと試みる。gemを付け外ししたりconfigをいじったりするも再現せず。

  4. capybara-webkitにログを出力させることができるかを調てみるpage.driver.browser.enable_loggingでいけるようなのでログを見てみる。するとリクエストをだしたURLへもう一度GETでリクエストが飛んでいるのを確認。「一部のテスト」は、GET以外のメソッドでしか受け付けてないURLへリクエストするテストであることを確認。

  5. capybara-webkitを使っていることからもわかるように、JavaScriptを使っている部分だったので、想定していないイベントハンドラがバインドされていないか確認する。無い。

  6. ログをよく見てみると2度目のリクエストが送られるのは1度目のリクエストで200が返ってきた後であることがわかる。

  7. やはりJavaScript臭いなと思いページで読み込んたJavaScriptを全てコメントアウト。変わらない。メインのテンプレートでメインコンテンツをyieldしている部分もコメントアウト。しかし効果はない。

  8. いろいろな条件で試していくうちにどうやら2度めのリクエストが飛ぶのはサインインをした後のリクエストで、どのURLでもおきることを確認。サインインを再現するためにスタブしている部分が悪いのかとこのあたりを参考にしたりして変更してみるものの変わらない。実際にサインインのプロセスを踏ませると問題が起きないことを確認(OAuth認証で実際に存在するアカウントを使ったためプロフィール画像があった)。

  9. クマさんデバッグ

  10. やけくそになりつつもう一度メインのテンプレートを見てbody全部を取っ払ってみる。あれ?2度めのリクエストが飛ばない。少しずつコメントインしてみると問題はヘッダにあることを確認。

  11. ヘッダの内部でもコメントアウトしたりうんぬんかんぬんしているうちにユーザのプロフィール画像を表示しているimgタグが元凶であることを確認。

  12. factory.rbを見て解決した喜びと自分のアホさへの絶望の間で苦笑いする。

反省

リクエストが飛ぶ可能性のあるタグとしてimgが即座に出てこなかった

これが特にひどい。今回で強烈にインプットされたけど。

情報が少ないうちにした判断による思い込みに囚われすぎていた

判断をする前により多くの情報を集めるべきだった。
webkitと何かの組み合わせではないかという決め付け。JavaScriptではないかという決め付け。決めつけた後に「おかしい…こんなはずでは…」とかいってウダウダしてる時間があった。おかしいのは自分なのに。 まずcapybara-webkitのログをよく見て200の後にもう一度リクエストが飛んでいることまで特定するべきだった。

問題の切り分け方が良くなかった

最初はもっとざっくりと切り分けるべきだった。
200の後にリクエストが飛んでいることに気づいた後にそもそも一度bodyを空にしてみるべきだった。