Google ChromeでBad Requestが発生した件

概要

社内で運用しているWebアプリに、Google Chromeでアクセスした場合に「Bad Request」になるとの声があがっていました。

気になる点としては、
- 再現性が低いこと
- Cookieやローカルストレージを削除しても改善されないこと

事象が発生したブラウザではどうあがいても再発し、発生しないブラウザでは特に発生しない。そんな感じでした。
原因の切り分けに非常に時間を要したので、備忘録に記録しようと思います。

環境

AWSのEC2サービスで、下記の運用としています
- ALB
- EC2(Amazon Linux2) * 2
- httpdとtomcatをAJP連携

事象発生の操作

アクセスするとログイン画面が表示され、ログインを実行することにより、サービスが使用できる、というものなのですが、
ログインページアクセスのGETリクエストは問題無くでき、ログイン処理のPOSTリクエストでBad Request発生と言う、なんとも気持ち悪いものでした。

切り分けで確認したこと

• ログはどこまで届いているか
  • httpdのaccess_logに、400エラーの記録有り
    • httpd.confに「RemoteIPAddr X-Forwarded-For」の設定があるにも関わらず、400エラー発生時はクライアントIPがELBのIPで出力され、ヘッダの「X-Forwarded-For」にアクセス元IP情報が残っていた
  • tomcatのcatalina.outにはhttpアクセスログの記録無し
• ALBまわりでエラーは無いか
  • リクエストやレスポンスにスティッキーセッションで割り当てられるCookieが確認できた
    • このサービス設定面においては、特に問題は無さそう

このあたりで、不思議な点がいろいろ出てきてすごく混乱しました。笑
まずRequest Headerを成功時と失敗時で比較すると何かわかるかと思い、ChromeのDevelopper Tool機能でファイルダンプして比較してみたところ、差分が確認できました。
参考：https://smakoma.com/http-header-chrome.html

差分としては、失敗時のヘッダに「sec-ch-ua」「sec-ch-ua-mb」の2件がありました。なんやねんこいつら…
調べてみると、User-Agent Client Helper機能によるものだそう。
参考：https://qiita.com/nightyknite/items/257251b9692dff1b62be

試しに、成功する方のブラウザで機能をONにしたらそれらの情報がリクエストヘッダに載り、Bad Requestが再現しました。
しかしながら、Bad Request発生ブラウザを確認しても、その環境も当該機能はOFFだし、OFF→ON→OFFにしても変わらずリクエストヘッダには載る… なんでやねん。載らんでいらんねん。

とは言え、これらの有無の差分が今回の事象のネックだろうと。
ただ、User-Agent Client Helperまわりのリクエスト不具合をググっても何も出てこない。

土日挟んで今日の月曜も悩んでるところに、httpdの「LimitRequestFields」のブログ記事を見つけました。
リクエストヘッダ件数がこの値を上回った場合、エラーとなると。
これちゃうか、、、

試しに、失敗時のダンプからリクエストヘッダ件数を見ると21件。httpd側の設定値は20。
こいつかい〜〜

原因と解消法

• Google ChromeのUser-Agent Client Helper機能によって、リクエストヘッダ件数が2件増えていて、httpd側の制限を超過していた
  • httpd側の制限を拡張

所感

これに1週間くらい費やしました。。。
まだ、不明確な懸念点もいくつか残っていますが、取り急ぎBad Request表示は解決されました。
ただ、何故環境によってはUser-Agent Client Helper機能が強制有効なんでしょうか… これほんま謎。

しかし、困ったら成功パターンと失敗パターンで差分確認する。これやっぱ鉄則ですね。