公開されるどこにも記録を残していないような気がするが、2016年の初めからとある事情により JavaScript のエラーをサーバに送りつけて監視サービスに送りつけてエラーの発生を知り、修正する、ということを地味にくり返していた。
そこに至る顛末と今後の分析の予定のお話。
背景
これまで扱ってきたものはそこまで JS ヘビーでないものが多く、また自分で書くものはできるだけユニットテストが動くように書いていた and そもそも監視サービスが入っていなかったので、エラーのログをサーバに送るとか監視するとか、そこまで手をかけていなかった。
しかし今回の案件は初期の設計では考えてもみなかった量のカウボーイスタイル JS がコミットされしまい、要するに非常にイキのいいフレッシュなレガシーコードがてんこ盛りで動いている状態になってしまった。
（あーはい、全部ぼくがコードレビューしてリジェクトすれば防げたんです、すいません。それをやったら別な角度からこっぴどく叱られたのでしょうけど。）
まずは静的解析
CI に乗せるまでも苦労したのだが、CI に乗せたのを機に eslint は動くようにしていた。
その段階ではほぼ致命的な問題は見つからなかったので、ちょっと安心していたのだけれど、やはり自動化されたテストのないコードが増えると厳しい。「なんかうまく動いていない感じがする」「再現性を確認できるレベルの報告は来ないが、何かは起きてるっぽい」という状態であり、またこの状態では積極的にはやりたくないが、どうしても変更はせざるを得ない。（完全無欠で変更不要なコードなんてあり得ない。）
cache busterできていない問題
そもそもの話なんだけど、件のサイトは AssetPipeline 的な仕組みが標準で入っていないので、当然のように JS がキャッシュされて、ブラウザによって動作がマチマチになってしまう問題を抱えていた。Rails 界隈では AssetPipeline 批判がすでに一周回り終わってしまっているが、世間にはまだそのような便利な仕組みがあることさえ知らずに素朴にキャッシュの効く生 JS を書くお仕事もあるわけです。はい。
が、なにせ量が多く、納得のいく形の cache buster まで持っていく時間を捻出できないので、そこは無視することにした。「cache の問題で意図した動作がユーザーの手元で再現できない場合がある」ことを記録するに留めることとした。
ガッデム。1
とにかくwindow.onerrorでサーバに送る
以前ならテストコードのないサーバサイドのアプリもエラーログで追い詰めつつ改修していくというのも割とよくやったが、最近はそういうやんちゃなコード扱ってないし、そもそも JS だとエラーログねーし…と思っていたが、「いや、何かで見たな」と思い返し、考え方を変えて、「まずはよく分からない状態を分かるようにする」ことにした。
大手Webサービスがクライアント側で発生したJavaScriptのエラーをどう収集しているのか まとめ - Qiita
を参考に、いちばんざっくり書けそうなのは
- window.onerror
- Ajax（サーバサイドアプリは単独ドメインなので）
の組み合わせで、サーバサイドに送ってサーバ側で NewRelic に送ることかなと考えた2。サーバサイドのエラーはすでに NewRelic に送ることができていたため、サーバ側に来てさえしまえばなんとかなると考えたのだ3。
NewRelic なら Error rate が基準（デフォルトでは 5.0%）以上になると通知してくれるので、何かが起きていることは可視化されやすいし、そこには
- URI
- ソース上のエラー発生箇所
- エラーメッセージ
といった基本的な情報が含まれているので、「分からないものが分かるようになる」段階としてはひとまず十分と言えるだろう。
びっくり仰天サーバサイドでJavaScriptリテラルを生成するコードの存在
上の記録をやり始めてから明確にエラーが減り（JS側の動作がおかしくてサーバ側にエラーが起きていたものも含む）、喜んでいたのもつかの間、いちばんショックなコードに出くわした。
ざっくり要約するとサーバ側のテンプレートで
var obj = val1 + {{$val2}};
みたいなことをやっているので、サーバ側で $val2 が null になると JavaScript 実行時には
var obj = val1 + ;
みたいなコードになってしまい、SyntaxError になるというもの。
こ れ は ひ ど い
2015年のコードでこれはないよ。値は HTTP か data-* で渡せよ。eslint 意味ねーだろ！！
サーバサイドでJSの変数直埋めするなよー。HTTPかDOMで渡せって。JSのlint意味ねーだろ。
— wtnabe (@wtnabe) November 22, 2016
泣く泣く
{{}}
の中に条件演算子を埋め込んで回りましたとさ…。
※ サーバサイドの View で JavaScript を書くのをそもそも禁止すれば少しはマシになりそうな気がするんだけど、これを静的解析で見つけることは可能なのかなぁ？ 人間がダメ出しすることはできても機械的に弾けないとやはり不安は残る。
無視すべきエラーとGoogle Analyticsへの記録
最近あった、ちょっと困ったパターン。
- Chrome 55 で実装された PointerEvents がバグっててエラー急増
- Babel を使って書いてる部分があって、IE 8 以下でエラーを吐く
- iOS の Google Search App が（恐らくZoomイベントに）バグを抱えていてエラーを吐く
こいつらはブラウザ側の問題でかつサポート外か、警告は出るが動作はするというものなので、無視する（サーバに送らない）ことにした。
※ Google Search App だとググってからでないとサイトを訪れることができないので、ほぼ production 環境以外ではデバッグできないわけだけど、みんなこんなもんどうやって相手してんの？
無視するだけだと怖いのでGoogle Analyticsに記録することにした
もしかしたら Chrome 56 で修正されるかもしれないし、闇雲に無視してしまうのは本来拾えるはずの情報を捨てることであり、なかなか怖い。ということでアプリが動いているサーバには送らないが Google Analytics には送ることとした。これなら通知はされないがあとで記録を見返すことはできる。
Google AnalyticsでJavaScriptエラーをトラッキングする
ただし、記録、閲覧できる情報量に不満があるので、もしかしたらイベントの方がよいかもしれない。
Google Analyticsを利用してクライアントサイドのエラーのレポーティングを行う - Thousand Years
とは言え、だいたい普通はイベントに関しては「何らかの効果の捕捉」に使うもので、利用回数に制限のあるイベントトラッキングを、何かの拍子に爆発しかねないエラーの記録に使うのはややリスキーだよね。
Google Analytics は分析目的の詳細な情報の記録ではなく、あくまで数の参考に留めておくのがよいのかもしれない。
まだ改善は続く
自分以外の人間が書くコードに対して、自分の得意なテストコードベースの手法だけを適用していこうとするのはやはり無理がある。一朝一夕には TDD はできるようにならないし、自社に十分な人数のデキるエンジニアが揃っていない場合は理想だけを追っても意味はない。
ということもあって、エラーログを単に「現在エラーが起きている」ことを知るためだけに使うのではなく、エラー発生率の変化など、指標として可視化してふり返りや分析にも利用できるようにしたらどうだろう、そしてたぶんこれは単独のサイトで考えるのではなく、会社全体としてログ分析基盤の一環として考えるべきなのではないかと思い始めている。
NewRelic以外のログ分析の基盤を用意したい
と考えると、単なる尻拭い案件ではなくなり、急に面白みが増してきた。
ERRORログが多すぎるWebアプリに出会ったら | GMOインターネット 次世代システム研究室
なんて話もあるが、現在我々には
Amazon Athena – サーバーレスのインタラクティブなクエリサービス – AWS
があるので、ログを S3 に放り込んで Athena で分析するのはアリだなと考えている。
NewRelic はエラーの通知とグラフィカルな可視化にはよいが、そもそも NewRelic のサイトの応答が重く、Error も Similar なもので畳まれて追いにくくなるので、もっと分析に特化したものは用意した方がよいように感じている。NewRelic はすぐに対応するにはよいが、長いスパンで見たい場合にはあまり向いていないなーと思っていたが、似たようなことを感じている人がいた。
※ export も自分で API を叩くコードを書かなきゃいけないし。
なぜ私たちはSumo Logicを捨ててBigQueryを選んだのか - tech.guitarrapc.cóm
この記事では BigQuery に入れることにしたようだが、自分には基盤整備の時間が十分にあるわけでもないので、「とにかくなんでも後回し」で考えると S3 + Athena かなという気がしている。幸い、ログを S3 に保存するのは自動化できている。
※ ところでバックトレースは複数行にまたがってしまうのに行に対して検索を掛ける SQL ベースの分析基盤はエラーログ分析には実は向いていないような気がしないでもないのですが、すでに基盤を構築済みの皆さんはどうしてるんですか？ トレースを改行のない状態に畳み込んでから記録してる？ そうするとロガーに手を加える必要がありますよね？
ログの情報量アップ
これまでは window.onerror に標準で渡ってくる情報を頼りに、トレースを取らずにそのままサーバに送っていたが、さすがにつらくなってきたので、
JavaScriptエラーログ収集に役立つツール・ライブラリ・手法まとめ - WPJ
を参考に
StackTrace.JS - Framework-agnostic, micro-library for getting stack traces in all web browsers
や
を使ってバックトレースは欲しいと思っているところ。
全体的な目標としては
JavaScript 祭で発表してきました - 若き JavaScripter の悩み
こんな感じですよね。よくまとまっていて分かりやすい資料をありがとうございます。
バグを防ぐ、デバッグという意味では本稼動してるアプリのログはやはり後手に回っているので、本来は前行程で防ぎたい。でも今は便利なツールが揃っているし、後手に回ったなら回ったなりにできることはいろいろあるし、これに慣れてくると、ちゃんとログ残したり監視できていないサイトはデプロイするの怖いという気もしてきそう。
エンジニアは怠惰で贅沢な生きものだもの。