ログ、その時の為に。

自己紹介

佐藤太一
- ryushi@twitter
- taichi@github
- taichi#1881 @battle.net
Koshinuke
- Gitフロントエンド(実装済)
- ドキュメント管理(未実装)
- タスク管理(未実装)
Yuzen
- 静的コンテンツ生成エンジン
- Gradle プラグインとして実装したJekyll/Octopressクローン
- Thymeleafを使っている為、ブラウザでプレビュー可能なテンプレートが使えるのが特徴
- Koshinukeに統合予定

セキュリティレビューとかアーキテクチャレビューはしてるけども、
実運用されるアプリケーションの実装や運用を五年以上やってない。

ログとは何か

コンピュータの動作記録
- サーバログ
- トランザクションログ
人間の動作記録をコンピュータによって行うもの
- Weblog > Blog
- ライフログ
  - Twitter
  - Path
  - foursquare
人間がコンピュータに何をしたのか記録するもの
- アクセスログ
- 課金ログ
- 監査ログ
- ユーザオペレーションログ
対数
木材
地名
- ロシア
- スロベニア

今日の話題はサーバログ、かつアプリケーションにおけるログの話。

ログの受益者たる役割(ロール)

開発者
- 機能の追加やバグの修正の為コードを書く人
- ホワイトボックス的に障害解析をする人
  - 障害解析の結果、再現しない様にコードを修正する
  - 運用レベルで行うべき操作を定義する
運用者
- 定常的にサーバの保守運用する人
- ブラックボックス的に障害解析をする人
  - 再現しないように対策を開発者に依頼する
  - 再現したとしてもシステムを継続的に利用可能な状態にする
- 今日の話題の中心は開発者であるが、開発者は運用者というロールを想定するべき
分析者
- 次世代の仕様を検討したり、直接的な収益を得る為にログを分析する人
- 今日は基本的に話題の対象外とする
- そういう問題領域がある事を知ってはいるが太一に知識や経験が不足している為、議論出来ない

ログが果たすべき役割

正しく動作している範囲と、そうでない範囲を切り分ける
障害の原因となった可能性のある状態を適切に発見する
アプリケーションやフレームワークの動作を理解する

ログは問題が顕在化し易い場所とその原因となる場所で適切に出力されていなければならない。
障害を切り分け易い事と動作を理解し易い事は共通する部分もあるが厳密に一致している訳では無いので、
動作を理解し易いログの出し方については、これ以降話題にしない。

ログの出力制御について

出力がある程度制限された環境から得たログを元に、
開発環境では、その問題を調査する為に出力制御をするだろう。

その際のアプローチは凡そ以下の3つになる。

必要な情報が出る様にピンポイントでログが出力される様に制御する
- 問題はほぼ解決していて念の為確認すると言った色合いが強い
スタックトレース等を見て関連性のありそうなものを定性的な基準で選択する
TRACEやDEBUG等、全てのログがでる様にした上でフィルタしながら解析する

ほぼ障害が解決している状況を除くとログを何らかの形でフィルタリングしながら解析をしなければならない。
ログの出力制御を設定する作業者とログ出力コードの実装者の対象に対する理解が適切に合致していない場合、
名前空間のみをフィルタリングの基準として採用していると解決に必要な工数が大きくなりがちである。
そこで、名前空間やレベルに加えてログ解析の為に新たな項目を追加してはどうだろう？

問題が起こり易い場所について

開発者によるユニットテストでは洗い出されにくく、
結合テスト環境や本番環境と言った多くのモジュールが統合される環境で起きる問題。
もしくは、その様な環境に至るまでに問題が発見されなかったとしても、許容されるべき問題。

それがインターフェース（バウンダリ）に関する問題である。

ユーザインターフェース
ミドルウェアとのネットワークI/O
- データベース
- キャッシュサーバ
- メッセージキュー
ファイルI/O
- 設定ファイル
より粒度の大きいシステム間通信
- REST
- SOAP
粒度の大きなモジュール間結合
- フレームワークとアプリケーション
- プラグインシステムとプラグイン

経験則的な色合いが強いがこういった部分におけるログ出力を特別扱いしても良いのではないか？
プロジェクト固有の状況を鑑みれば、もっと他にもそういう場所はある筈。

ログの出力項目について

一般的には以下の様な項目をログとして出力する。

日付や時間等のタイムスタンプ
モジュールの名前空間
ログレベル
- TRACE
- DEBUG
- INFO
- WARN
- ERROR

加えて、今日は以下の様な項目を提案したい。

処理構造に基づくマーカ
- DESIGN
  - 設計判断を伴う処理に関連する項目
  - 粒度の大きなモジュール間の接合面になる部分で使う
  - アドインやプラグインに関連する部分など拡張性を意図して記述された部分で使う
- BOUNDARY
  - ファイルやネットワーク、他の依存ライブラリに対するインターフェースに関連する項目
  - 設定ファイルやデータベースの読み書きを行う際に使う
- LIFECYCLE
  - オブジェクトのライフサイクルに関連する項目
  - コンストラクタやinitialize,dispose,closeといったメソッドで使う
  - 入出力処理の前段階/後段階として実行される為、問題が起きた時どの様な状態であったのか捉え易くなる

本題とは余り関係無い、その他ログに関する雑多なTips

TRACEやDEBUGログは容赦なく出すべき
- 開発者規模の大きい開発では個々のプログラマに任せずとも一定水準以上のログが出る仕組みを用意する
- JavaならバイトコードエンハンスによるAOP等
運用環境に上手く適合するログローテーションを心がける
- ファイルのエントリ数に上限がある、もしくは著しく数が増えると適切に運用できないファイルシステムもあるよ
  - 数十万エントリ程度で、lsが返ってこなくなるext2, ext3 等
- ファイルオフセットが32bitな環境で2GB超のファイルを扱おうとするとトラブルが起きるケースが散見される
ログがシステムの動作に与えるコストはある程度負荷テストの中で計測する
- ログが無ければ障害解析出来ないがログが障害の原因になってしまってはいけない
開発中に計測しながら数年先のログ容量見積もり出来る体制を作る
- HDD はどんどん安くなってるから気にせず使うというアプローチもある
ログをいつどの様にして削除するのかをきちんと決める
- 最初に削除する理由と時期を少々不格好でも決めてしまい徐々にポリシーを更新する
- ログの曖昧な削除ポリシーはバックアップオペレーションを中心とした運用上の負荷を底上げする
ログを扱う為のミドルウェアの導入を検討する
- fluent
- scribe
RDBにログを取り込んでアドホックなSQLでフィルタリングすると大量のログを簡単に扱える
- Windows環境ならMS-Access使うと更に便利

まとめ

ログを出す目的を役割を基準に考えてみよう
解析し易いログを出力する為に出来る事を考えてみよう

ymotongpoo/log.md