Posted at

エラーの可視化を捗らせよう

More than 3 years have passed since last update.

こんにちは。TDアドベントカレンダーも12日目になりました。

主にアプリケーション周りでのTDの使い方に関して記載している私の記事ですが、今日はエラーの可視化について書いてみようと思います。


前振り

アプリケーションのエラー可視化はみなさん行っていますか?自分たちのサービスでどれくらいエラーがでているか、どれくらいの影響がでるのか、といったことをチームのメンバーで把握できていますか?

例えば大まかなMySQLへのエラーの確率とか、そういった所まで把握できていれば理想だと思います。

こういったエラーログの収集は直接的な収益に繋がるわけではありませんが、お客様の問題の調査に役立ったり、複雑なアプリケーションの実装における問題の発見、トラッキングなどに役立つのでとても重要な項目です。

この事から、エラー関連のログも上手に収集してアプリケーション運用を楽に出来るように構築しておきましょう。


エラーの発生要因

そもそもエラーとはどういったことで起きるのでしょうか?おおまかに2つに分けるとすると私ならば下記のように分類します。


  • A) ユーザーが行うアクションの選択によっては起きるエラー

例えば、カードゲームを作っている場合にユーザーが規定枚数のカードを持っていて再度同じアクションを取ろうとした時に発生するエラーなどがあります。主に処理の前段のValidationの段階で発生するものが大半です。

Validation失敗が多ければ何かしら前ページに問題があるのではないか?という推測がたてられます


  • B) バックエンドのシステム状況によっては問題が発生してしまうエラー

代表的なものとしてはnetworkの不調により該当サーバーへの接続が行えなかった、など環境に要因されるエラーなどのことです。例えば、バックエンドのサーバーに対してshardingをしている時に特定のuser_idだけ問題が起こっているならば、sharding周りがなにかおかしい、等の状況が推測出来るようになります。

アプリケーションの運用時にはどちらも重要な情報です。Aのスコアを改善できれば、少なくともValidationエラーでの無駄な画面遷移が少なくなる為サービスを快適に使っていただけているという事にもなりますし、Bのスコアを改善できれば安定して運用できているとことになります。


エラーのロギングに必要な情報とは

エラーのハンドリングをするときに必要なエラーのログに必要な情報とは何でしょうか?一つ重要な事は、かならず問題解決の糸口に繋がる情報を残す、ということです。

おおまかにではありますがこのような情報が揃っていれば十分かと思われます。


  • どの時間帯に発生した問題なのか

  • どのページで起こった問題なのか

  • どの機能分類の問題なのか

  • どのユーザーの問題なのか

  • 問題の原因は何なのか

よくあるだとExceptionをthrowした所までは良いのですが、情報が不完全な場合結局何が問題なのか分からずexeptionに渡すパラメーターを直して次のエラーがでるまで待つ、なんてこともは場合によってはあるでしょう。また、使っているフレームワークによってはStack Traceだけでは分かりづらい事もありますので、過不足ない情報を自分で渡すのが大事です。

参考例として、テーブルは下記のように作っておけば良いと思います。

name
description

action
pageのurlや正規化したコントローラーメソッド等

category
エラーの種類。mysql系であればmysql.updateとかでデータを入れとく

user_id
対象のuser_id

time
発生時間

info
ドリルダウンの際に必要なデータだけを突っ込んでおく。

また、別途categoryやactionが一覧出来るような分類表を作っておいてクエリを作成するときに参考に出来るようにしておくと便利です。

こうして、エラー系のログを書き込むことでアプリケーションの健康状況が定量的に分かるようになるので、この問題のユーザー影響は低く、発生件数もn件/日と影響度は小さいので後で新規メンバーに依頼する、等の判断が行い易くなります。


コード例

例えば特定のデータを保存する擬似コードとして下記のようなものがあるとします。

try {

$my->execute($object);
} catch (NancharaException $e) {
return $controller->showErrorPage($e->getMessage());
}

このエラーは先ほど定義した分類だとBで、いまのコードでは問題があった場合のページ表示は行えていますが、ログを落としていないので運用側からはそもそも起こったのか起こってないのかがわからない状態にあります。

try {

$my->execute($object);
} catch (NancharaException $e) {
$logger->log("error", "mysql.query", $user_id, $e->toArray());
return $controller->showErrorPage($e->getMessage());
}

これでエラー情報をログに落とすことが出来ます。

ここで大事な事は、 「必ず問題解決や判断ができる情報を盛り込む」 ということです。それがないと、ログを出したはいいけど調査をし直すところから始めないといけません。

loggerの実装はプロジェクトに依ってまちまちだと思いますのでそれに併せておきましょう。


エラーの可視化

可視化をする理由としては、グラフを見れば、だれでも同じようにエラーの量に対して判断できる感覚を養い為です。

ログとして落としているだけでは人によって感覚の精度がまちまちになってしまいますし(最悪、そもそもエラーログ見てない、とかいう人も出るでしょう)、能動的に2〜3ステップ踏めないと見れないのではすぐに続かなくなってしまいます。

では具体的にどうやって可視化をしていけば良いのでしょうか?ここで、categoryやactionの情報を持たせていたことが役立ちます。

ではさっそくsql

select 

time,
sum(mysql) as mysql,
sum(mysql_connect) as mysql_connect,
sum(mysql_query) as mysql_query,
sum(battle_fault) as battle_fault,
sum(seek_error) as seek_error
from (
select
time,
sum(case category when 'mysql' then 1 else 0 end) as mysql,
sum(case category when 'mysql.connect' then 1 else 0 end) as mysql_connect,
sum(case category when 'mysql.query' then 1 else 0 end) as mysql_query,
sum(case category when 'battle.fault' then 1 else 0 end) as battle_fault,
sum(case category when 'seek.error' then 1 else 0 end) as seek_error
from mysql.p.error
where
TD_TIME_RANGE(time, '2014-12-1 00:00:00', '2014-12-4 :59:59', 'JST')
group by time
) group by time;

だいたいこんなクエリを生成しておけばグラフを作るのは簡単です。

この手のクエリは手で書くのが面倒くさいのですが、分類表を作っておけば簡単にプログラムから生成出来ます。こういったクエリやテーブル設計はとりあえずなにも考えずに生成できるように多少アホっぽい設計でもいいので実用重視でつくるの大事です。

◇ ◇ ◇ ◇

下記のグラフはdummyデータで可視化したものです。参考までに

平時はなんとなく眺められる、必要な時はドリルダウンできるという2つの要素をうまーく保持することで使えるエラーテーブルを作ることが出来ます。


まとめ


  • エラーの可視化するとチーム内でのコンテキスト共有が捗るうえに、Priorityをつける目安にもできます

  • 取りうる値を列記した分類表は必ず作っておきましょう。クエリの自動生成に便利です。

  • 必要があればドリルダウンできるように作っておきましょう

さほど考えずにTDに突っ込んでいけるテーブルを作っておいてクエリを汎用化させる、というのが実用上大事なポイントです。

それではー