自己紹介

佐藤太一

• ryushi@twitter
• taichi@github
• taichi#1881 @battle.net

セキュリティレビューとかアーキテクチャレビューはしてるけど

実運用されるアプリケーションの実装や運用を五年以上やってない

最近のコード

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

ログとは何か？

コンピュータの動作記録

• サーバログ
• トランザクションログ

人間の動作記録をコンピュータによって行うもの

• Weblog > Blog
• ライフログ
  • Twitter
  • Path
  • foursquare

人間がコンピュータに何をしたのか記録するもの

• アクセスログ
• 課金ログ
• 監査ログ
• ユーザオペレーションログ

他には？

• 対数
• 木材
• 地名
  • ロシア
  • スロベニア

ログの受益者たる役割

開発者

• 機能の追加やバグの修正の為コードを書く人
• ホワイトボックス的に障害解析をする人
  • 障害解析の結果、再現しない様にコードを修正する
  • 運用レベルで行うべき操作を定義する

運用者

• 定常的にサーバの保守運用する人
• ブラックボックス的に障害解析をする人
  • 再現しないように対策を開発者に依頼する
  • 再現してもシステムを継続的に利用可能な状態にする

話題の中心は開発者であるが

開発者は運用者というロールを想定するべき

分析者

• 次世代の仕様を検討したり、直接的な収益を得る為にログを分析する人
• 今日は基本的に話題の対象外とする

そういう問題領域がある事を知ってはいるが

太一に知識や経験が不足している為、議論出来ない

正直、余り興味も無い

ログが果たすべき役割

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

障害を切り分け易い事と動作を理解し易い事は共通する部分もあるが厳密に一致している訳では無いので、

動作を理解し易いログの出し方については

これ以降話題にしない

ログの出力制御について

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

ログ出力制御のアプローチ

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

ほぼ問題が解決している状況を除くとログを何らかの形でフィルタリングしながら解析をしなければならない

ログの出力制御を設定する作業者とログ出力コードの実装者の対象に対する理解が適切に合致していない場合、
名前空間のみをフィルタリングの基準として採用していると解決に必要な工数が大きくなりがち

そこで、名前空間やレベルに加えてログ解析の為に新たな項目を追加してはどうだろう？

問題が起こり易い場所

開発者によるユニットテストでは洗い出されにくく、

結合テスト環境や本番環境と言った多くのモジュールが統合される環境で起きる障害

もしくは、その様な環境に至るまでに発見されなかったとしても、許容されるべき問題

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

ユーザインターフェース

ミドルウェアとのネットワークI/O

• データベース
• キャッシュサーバ
• メッセージキュー

ファイルI/O

• 設定ファイル

粒度の大きいシステム間通信

• REST
• SOAP
• RMI, CORBA

粒度の大きいモジュール間結合

• フレームワークとアプリケーション
• プラグインシステムとプラグイン
• 在庫管理サブシステムと受注管理サブシステム

経験則的な色合いが強いがこういった部分におけるログ出力を特別扱いしても良いのではないか？

プロジェクト固有の状況を鑑みれば、もっと他にもそういう場所はある筈

ログの出力項目について

一般的な出力項目

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

新しい項目の提案

処理構造に基づくマーカ

出力項目の一部として固定的な文言を出力する事で解析し易くする

2012-05-20 15:34:35.431 INFO LIFECYCLE x.yy.zzz.contract.Aaaa initialized
2012-05-20 15:34:36.861 INFO x.yy.zzz.contract.Aaaa begining of transaction.
2012-05-20 15:34:37.971 DEBUG x.yy.zzz.impl.Bbbb main prcess.
2012-05-20 15:34:37.971 DEBUG BOUNDARY x.yy.zzz.impl.Cccc {"id":11122111,"name":"taichi"} entry data.
2012-05-20 15:34:38.851 DEBUG x.yy.zzz.impl.Dddd after process.
2012-05-20 15:34:39.851 INFO x.yy.zzz.contract.Aaaa end of transaction.
2012-05-20 15:34:40.241 INFO LIFECYCLE x.yy.zzz.contract.Aaaa disposed.

DESIGN

• 設計判断を伴う処理に関連する項目
• 粒度の大きなモジュール間の接合面になる部分で使う
• アドインやプラグインに関連する部分など拡張性を意図して記述された部分で使う

BOUNDARY

• ファイルやネットワーク、他の依存ライブラリに対するインターフェースに関連する項目
• 設定ファイルやデータベースの読み書きを行う際に使う

LIFECYCLE

• オブジェクトのライフサイクルに関連する項目
• コンストラクタやinitialize,dispose,closeといったメソッドで使う
• 入出力処理の前段階/後段階として実行される為、問題が起きた時どの様な状態であったのか捉え易くなる

ログに関する雑多なTips

TRACEやDEBUGログは容赦なく出すべき

• 開発者規模の大きい開発では個々のプログラマに任せずとも一定水準以上のログが出る仕組みを用意する
• JavaならバイトコードエンハンスによるAOP等

適切にログローテーションする

• ファイルのエントリ数に上限がある、もしくは著しく数が増えると適切に運用できないファイルシステムもある
  • 数十万エントリ程度でlsが返ってこなくなるext2, ext3
• ファイルオフセットが32bitな環境で2GB超のファイルを扱おうとするとトラブルが起きる

ログの動作コストを計測する

• 負荷テストの中で計測する
• ログが無ければ障害解析出来ないがログが障害の原因になってはいけない

ログの容量見積もりする

• 開発中に計測する
• 問題になるのは数年先なので後回しにしがち
• HDD はどんどん安くなってるから気にせず使うというアプローチもある

ログの削除ポリシーを決める

• 最初に削除する理由と時期を少々不格好でも決めてしまい徐々にポリシーを更新する
• いつ、どの様にして、誰が、誰の責任で削除するのか決める
• ログの曖昧な削除ポリシーはバックアップオペレーションを中心とした運用上の負荷を底上げする

ログ系ミドルウェアの導入を検討する

• fluent
• scribe

RDBにログを取り込む事を検討する

アドホックなSQLでフィルタリングすると大量のログを簡単に扱える

Windows環境ならMS-Access使うと更に便利