php ロギング機構を作ってみた
はじめに
phpでデベロッパ向けアプリケーションログ機構をつくってみたのでその説明をしてみます。
一般的にプログラミングにおいてデベロッパ向けロギングというのはコンポーネントを横断する概念です。アプリケーション上ある機能 X があり、別の機能 Y があったとして、それをモジュール X、モジュール Y として実装するとします。その時 X と Y は(設計上いろいろ考えなければならないことはあるでしょうが)一般的に機能の直交性が高ければ独立して実装できるものです。
あるアプリケーションでデベロッパに何か情報を残したい要求があり、何らかのロギング機構を使用したとします。その場合、デベロッパが何を残したいかは具体的状況によって異なるため、ロギング機能をできるだけ細やかに使ってログを残したくなるのは当然です。(抽象化されたログにはあんまり意味が無い。)そうすると X, Y の両者がロギングの詳細に依存しまうことになり、概念的には何のつながりもないはずの X と Y に、ロギングというものを通した概念的つながりができてしまうわけです。
さらにプログラミング言語の特性によっては、そのログを出力するために必要な機能にも依存性が生じてしまいます。
そういう問題があるので、こういったオレオレライブラリによるロギング機構を使用することはおススメできません。もっと依存するに値する信頼性の高いライブラリの機能を使用しましょう。(似たようなことが例外機構にも言えます。)
また、単純に私は php について深く知りません。
私などが考えつくことは、有名なライブラリの作成者さんならば必ず考えて、もっとよい決断を下しているはずです。なので、こんなものは私が個人で使用していれば十分で、別の人に使ってもらえるレベルではないと考えています。
ですが、自分が何を考えたか、そういったことが何かの参考になる部分があるのではないかと思い、実装時に考えたことをちょっと説明をしてみようかとおもいました。
そういう意図なので、ソースコードはその時に考えたことをバラバラに記述しています。
物理的出力
ログの出力先は、汎用的なロギング機構を作成するのであれば、LogWriter のようなオブジェクトを作りそれに移譲させるべきです。
ですが、ここではディレクトリを指定し、その中に日付からつくったファイルを作成しそこに出力すれば良いということにしましょう。
調べてみたところ、ログ出力は error_log 関数を使えばいいようです。マジックナンバー 3 が気になりますが、まぁ二度と触れないのでいいとしましょう。
ファイル名を何度も作るのはちょっとやなカンジですが、キャッシュしても良いことはあまりなさそうなので、必要経費と考えることにします。
class Log { private static $directory = './'; public static function SetBaseDirectory( $dir ){ Log::$directory = $dir; if( Text::Right( Log::$directory, 1) != '/' ){ Log::$directory .= '/'; } } public static function GetActualLogFileName(){ $t = date('ymd'); return Log::$directory . $t . '.log'; } public static function WritePhysical( $text ){ @error_log( $text, 3, Log::GetActualLogFileName() ); } }
この時点ですでに Text::Right とか使ってますが、これは substr でつくった文字列の末尾を返す関数です。
php のエラー時の出力を何とかしたい
php は予め準備しておかないとエラーが起こった時その場でエラーメッセージを表示します。その挙動は非常に鬱陶しいと感じるわけですが、出力しようとしている画面そのものにエラーメッセージが出てくれるということ自体は結構便利ではあります。問題は節操無く出力されるところにあるので、一度バッファリングして出力したいところに出力できるようにしましょう。
Log::$entries という変数に一度蓄えておき、Log::DisplayLogs 関数でテーブルとして出力させます。
class Log { private static $entries = array(); private static $level_map = null; // php はスタティックイニシャライザって無いのかな? public static function InitStatic(){ Log::$level_map = array( E_ERROR => 'FATAL ', E_WARNING => 'WARN ', E_PARSE => 'PARSE ', E_NOTICE => 'NOTICE', E_CORE_ERROR => 'CORE ', E_CORE_WARNING => 'CORE_W', E_COMPILE_ERROR => 'C_ERR ', E_COMPILE_WARNING => 'C_WARN', E_USER_ERROR => 'fatal ', E_USER_WARNING => 'warn ', E_USER_NOTICE => 'notice', E_STRICT => 'STRICT', E_RECOVERABLE_ERROR => 'ERROR ', E_DEPRECATED => 'NOTICE', E_USER_DEPRECATED => 'notice' ); } private static function FomratLocate( $file, $line){ $file = basename($file); return " (in {$file}({$line}))"; } private static function GetCategoryString( $errno ){ if( isset(Log::$level_map[$errno])){ return Log::$level_map[$errno]; }else{ return "E($errno)"; } } // 出力、ファイルに書き出しつつ変数に蓄える。 public static function Write( $category, $message){ $msg = date( "ymd H:i:s"); $msg = "$msg $category $message\n"; Log::$entries[]= array( 'category' => $category, 'message' => $message); Log::WritePhysical($msg); } // HTMLとしてのログ出力 public static function DisplayLogs(){ if( XArray::Length(Log::$entries) == 0 ){ return; } $old_level = error_reporting(0); echo "<div class='log_display' id='log'><table>\n"; foreach (Log::$entries as $entry) { $c = Text::EscapeHTML($entry['category']); $m = Text::EscapeHTMLwithBreak($entry['message']); echo("<tr>"); echo("<td>{$c}</td><td>{$m}</td>"); echo("</tr>\n"); } echo "</table></div>\n"; error_reporting( $old_level ); } // エラーハンドラ public static function ErrorHandlerAdapter( $errno, $errstr, $errfile, $errline ){ $category = Log::GetCategoryString( $errno ); Log::Write($category, $errstr . Log::FormatLocate($errfile, $errline)); } } // 初期化 Log::InitStatic(); // エラーハンドラ function g_ErrorHandler( $errno, $errstr, $errfile, $errline ){ Log::ErrorHandlerAdapter( $errno, $errstr, $errfile, $errline); return TRUE; } set_error_handler('g_ErrorHandler'); error_reporting(E_ALL);
XArray とか、Text::EscapeHTML とかの内容は「お察し下さい」ということで。
で、地の文でどこかで
<?php Log::DisplayLogs(); ?>
とする必要が出てきましたが、本番ではすべきではないですし、忘れてもファイルには出力できるのでこれで良いものとします。
致命的エラー
これで良いかと思ったのですが、致命的エラーの場合は set_error_handler は無視され、いきなり落ちるようです。
いろいろ調べていくと register_shutdown_function という関数が使えそうなので、これで対応します。
function g_ShutdownHandler(){ $error = error_get_last(); if( ! $error ){ return; } switch($error['type']){ case E_ERROR: case E_PARSE: case E_CORE_ERROR: case E_CORE_WARNING: case E_COMPILE_ERROR: case E_COMPILE_WARNING: Log::ErrorHandlerAdapter( $error['type'], $error['message'], $error['file'], $error['line'] ); Log::DisplayLogs(); break; default: break; } return; } register_shutdown_function('g_ShutdownHandler');
これでいきなり落ちても一応ログは出力されるようです。
ログ出力関数
ここまでで set_error_handlerに対応しているので、trigger_error で E_USER_NOTICE とか E_USER_ERROR とかを挙げればログは出力できるようになってたりします。
trigger_error("こうやって notice ログが書ける。", E_USER_NOTICE);
ですが、これではあまりに非直感的なので Log::Debug という関数を作ります。
class Log{ public static function Debug( $msg ){ // ホントはここで出力レベル判定をやってるけど煩雑なので省略 // if( ... ) { return; } if( func_num_args() == 1 ){ Log::Write( 'debug', Cast::ToString($msg)); return; } $args = func_get_args(); $t = array(); foreach ( $args as $arg){ $t[] = Cast::ToString($arg); } Log::Write( 'debug', Text::Join($t, ", ")); } }
まず、ログは文字列を出力したいものですが、デベロッパが『ちょっとこの値を残しておきたい』と思ったときにそれが文字列であるかどうかはわからないものです。
かといって、デバッグ中に変数の内容をログ出力するとき、デベロッパは『変数なら変数を出力したい』のであって、『変数を文字列に変換してその結果を出力したい』とは考えません。『文字列に変換して・・・』というのは思考のオーバーヘッドでしかないのです。なので、どんな値でも受け付けることができるように Cast::ToString(内容はお察しください)をかましています。
次に func_get_args ですが、これは、実際の開発において複数の変数の値をとりあえず表示したい、ということが意外に多い(受けた引数をとりあえず表示、とか)ためこのような処理を入れています。
Log::Debug( "$a, $b" );
と書けば良いのですけど、
Log::Debug( $a, $b );
のほうが手軽です。
出力のフォーマットはいろいろ思うところはあるのですが、デバッグ用途なので、多少おかしかろうが出力できれば良いと考えてこうしました。
ここで注意しなければならないのは、デバッグログに関してはどこまででも詳細に情報が表示されれば良いということでもないことです。あまりに詳細な情報が勝手に出力されてしまうとログ出力が(実際に重いかどうかとはあまり関係なく)『心理的に重い行為』になってしまいますし、出力結果が多くの情報に埋もれて逆にみづらくなり、手軽に書くことを躊躇する意識が働きます。(print_r とか、 var_dump とかははっきりいってやり過ぎです。)
なので、Cast::ToString は入れ子配列を再帰しませんし、改行もしません。更に行番号を付加するようなこともしていません。そのような情報が欲しければ自分でそう書けば良い、とします。
で、エラーログ出力 Log::Error も作ります。(同様に Warn, Info もつくってあげます。)
class Log{ public static function Error( $msg ){ $entris = debug_backtrace(); if( XArray::Length($entris) == 0 ){ Log::Write( 'error', Cast::ToString($msg)); return; } $entry = $entris[1]; $file = $entry['file']; $line = $entry['line']; Log::WriteA('error', Cast::ToString($msg) . Log::FormatLocate($file, $line)); } }
こっちは出力するログの内容は十分吟味して呼ぶでしょうから、可変長引数に対応するようなことはしません。
あと、printf 形式の DebugF、var_dump の結果をログ出力する DumpVar などを作ってあげてロギング機構をしては一応の完成というところでしょうか。
PHP の strval が使いづらい。
PHP の strval 関数のマニュアルPHP: strval - Manualに
strval() は配列に対して使うことはできず、 __toString メソッドを実装していないオブジェクトに対しても使うことはできません。
という記述があるけれども、これはドキュメントとしておかしいと思う。
『使うことはできません』とかいったところで実際渡せてしまうのだから、書くべきなのは、どうなってしまうのか、あるいはその関数の実装側としてクライアントにどうしてほしいのかだと思う。
『配列、もしくは__toString メソッドを実装していないオブジェクトを strval に渡した結果は未定義とします。』
とか、
『strval はスカラー値を文字列化することを想定しているため、配列、もしくは__toString メソッドを実装していないオブジェクトを渡さないでください。』
とか、そういうふうに書かないとドキュメントとして体をなしてない。
で、
実際のところ渡すとどうなるかというと、配列を渡すと "Array" という文字列になり、__toString のないオブジェクトを渡すと実行時エラーが上がりつつ空文字列がかえってくる。
さらに TRUE を渡すと "1" が返ってきて、 FALSE を渡すと空文字列が返って来たりする・・・
・・・誰が得するんだこの仕様。
エラーが上がってくる可能性があるということは、この関数は実際のオブジェクトの型がわからない場合には使ってはいけないということになる。つまりこの関数のクライアントは渡した型を把握してなきゃいけない。で、渡した型が型がわかってるんだったら、配列が "Array" になっても何も嬉しくない。
配列が "Array" になるのであれば、文字列化できないオブジェクトは "Object" とでも返ってくればよかった、そうすれば少なくともエラーになることはないんだからテキトーに渡せる。
というか、私がほしい物作った。
自然に文字列にできるときは文字列にし、できないときは概略情報を文字列化する。
Class Text{ public static function ToString( $o ){ // NULL は空文字列、文字列はそのまま、数値っぽかったら strval // NULL は 'null' という文字列と悩んだが、空文字列が一番使い勝手が良いっぽい。 if( is_null($o)) return ''; if( is_string($o)) return $o; if( is_numeric($o)) return strval($o); // bool は true/false に if( is_bool($o)){ if( $o === TRUE ) return 'true'; if( $o === FALSE ) return 'false'; } // object は __toString の有無によって挙動を変える、 if (is_object($o)){ if( in_array( "__toString", get_class_methods($o))){ return strval($o->__toString()); }else{ return get_class($o) . ":" . spl_object_hash($o); } } // 配列は内容をトップレベルのみ表示 if( is_array( $o ) ){ // Text::ArrayToString は、再帰しない、改行しない print_r みたいな関数。(別に作った) return self::ArrayToString($o); } // リソースがここまで来るが、リソース ID が表示されるstrvalの挙動で良いので、 return strval($o); } }
lix::Failable
lix::Succession が失敗したときにエラーコードを返す、というだけのものであるのに対して、何らかの値を取得し、失敗時はエラーコードを返す、という場合に使用することを想定したクラステンプレートです。
// 何らかの文字列を引数で受けた string に格納して返す、失敗時は false を返し、その理由は GetLastError で取得できる。 bool GetSomeText( std::string& ret );
というシグネチャ(ここでは『失敗理由はGetLastErrorで』ということも意味的なシグネチャと捉えます。)が
lix::WinFailable<std::string> GetSomeText();
になります。Failable は boost::optional っぽい形式で内容にアクセスできます。
lix::WinFailable<std::string> GetText( int i ) { if( i < 0 ){ // ホントはなんか API を呼ぶ、その副作用で LastError が変わる。 SetLastError( ERROR_INVALID_PARAMETER ); return lix::Failed(GetLastError()); } return "てきすと"; } void sampleA(){ lix::WinFailable<std::string> r = GetText( 1 ); assert( r ); cout << r << endl; // これは内容が流れ、 "てきすと" と表示される。 std::string content = *r; // 値はこうやってとる。 content = r.Get(); // これでもいいけど . と -> の両方があるので、 // 混乱しそう。成功時はとっとと * したほうがいいと思う・ r = GetText(-1); // if( r.IsFailed()) でも同じ if( !r ){ // 失敗。 // エラーコードを返す。 DWORD err = r.GetErrorCode(); // メッセージを返す。 string message = r.GetErrorMessage(); // ストリームにも流せたりする。(これは内容ではなくエラーメッセージが流れる) cerr << r << endl; } r = GetText(-1); std::string x = r.GetValueOr("でふぉると"); // 成功してたら内容を、失敗してたら引数を返す。 cout << x << endl; // この表示は "でふぉると" }
lix::WinFailable
template< typename T, typename ErrorCodeType, typename ErrorCategory = ErrorCodeTraits<ErrorCodeType> > class FailableBase { ... }; // こう書きたいんだけどね・・・ // template <typename T> // using WinFailable = FailableBase<T, DWORD, Win32ErrorCategory >; // いまのところこうせざるをえない。 template< typename T> class WinFailable : public FailableBase<T, DWORD, Win32ErrorCategory> { ... };
ErrorCategory は lix::Succeesion と同じもので、エラーコードをどうやって文字列化するか、というポリシーです。errno版とGetLastError版が存在しています。
各エラー体系に合わせて ErrorCategory を作ってあげれば、エラーコードがどんなものであっても、
auto r = HogeHoge(); if( !r ){ // エラーハンドリング // return するか、 throw するか。 } // 改めて取り出す string s = *r;
というスタイルが使用できますし、boost::optional を使用してよくやるスタイル
if( auto r = HogeHoge() ){ string s = *r; // 正常時の処理をここに。 }else{ // 異常時の処理はここに。 }
を、エラー時の情報を殺すことなく行うことが出来ます。
lix::Succession
試しに公開してみた https://code.google.com/p/lix-failable/source/browse/ こいつですが、
例えばこういう関数を作るとして、
// 普通は失敗しない何かをする。失敗時は false を返す、失敗理由は(Win32の)GetLastError で。 BOOL DoSomething( int x);
この 『失敗理由は GetLastError()』 というのは、概念的にはその関数のシグネチャに含まれていますが、シンタックス的にはシグネチャではありません。
かといって、ここで『ErrorCodeを返す』ように変更してしまうと、エラーハンドリングの記述が直感的ではなくなる、という問題が発生してしまいます。
BOOL DoSomething( int x); // どこかで DWORD err = DoSomething( path ); if( err != NO_ERROR ){ // <- この if 文が直感的じゃない。 ... } if( err ) { // <- これ何が言いたいのかわからない、ミスか? ... }
なので、『成否を表しつつ否の場合はエラーコードを持たせることができるクラス』があれば、そのへんがすっきりするんじゃないかと。
で、作ってみたのが lix::Succession です。
これを使うと
lix::WinSuccession DoSomething( int x) { if( x < 0 ){ // ホントはなんか API を呼ぶ、その副作用で LastError が変わる。 SetLastError( ERROR_INVALID_PARAMETER ); // 失敗、 GetLastError を持たせるよ、という明示的記述。 return lix::Failed( GetLastError()); // こう書いても同じ return lix::FailedWithLastError(); // これでも同じ return lix::WinSuccession( false, GetLastError()); // これもコンパイル通っちゃうけど、 true を許しつつこれをやめさせる方法が思いつかなかった。 return false; } // 成功(boolからの変換コンストラクタがある。) // false 側を考えると、これは変換させないようにするか、ちょっと悩んだ。 return true; // どっちかっていうとこう書いてほしいな。 return lix::Succeeded(); } void sample1(){ lix::WinSuccession r = DoSomething( 1 ); assert( r.IsSucceeded()); r = DoSomething(-1); // if( r.IsFailed()) でも同じ if( !r ){ // 失敗。 // エラーコードを返す。 DWORD err = r.GetErrorCode(); // メッセージを返す。 wstring message = r.GetErrorMessage(); // ストリームにも流せたりする。(エラーメッセージが流れる) cerr << r << endl; } }
こんなふうにかけます。
lix::WinSuccession というクラステンプレートは2つのテンプレートパラメータをとり、第一パラメータがエラーコードの型、第二パラメータがそのエラーコードをどうやって文字列化するか、というポリシーです。
第二引数は lix::ErrorCodeTraits というテンプレートがデフォルトパラメータになっているため、指定しなくても構いません。
つまり lix::Succession は
template < typename ErrorCodeType, typename ErrorCategory = lix::ErrorCodeTraits<ErrorCodeType> > class Succession{ ... };
こうです。
で何度も出てきている lix::WinSuccession は DWORD と FormatMessagge をつかうポリシーでインスタンス化した lix::Succession
『俺のエラーコードは独自の emun だ!』とかいう場合もメッセージの取得さえ諦めればお手軽に、
enum CustomErrorCode { CUSTOM_OK = 0, CUSTOM_INVALID_ARG = 1, CUSTOM_SOMETHING_HAPPENS = 2 }; lix::Succession<CustomErrorCode> DoHogeHoge(int x) { if( x < 0) { return lix::Failed(CUSTOM_INVALID_ARG); } if( x > 100 ) { return lix::Failed(CUSTOM_SOMETHING_HAPPENS); } return lix::Succeeded(); } void sample2 { auto r = DoHogeHoge(1); assert( r.IsSucceeded()); r = DoHogeHoge( -1 ){ if( ! r ){ cerr << "失敗した。" << r.GetErrorCode() << endl. } }
こんなかんじで使えます。
そこで、エラーメッセージも対応するならば lix::ErrorCodeTraits
enum CustomErrorCode { CUSTOM_OK = 0, CUSTOM_INVALID_ARG = 1, CUSTOM_SOMETHING_HAPPENS = 2 }; // CustomErrorCode について lix::ErrorCodeTraits を特殊化。 namespace lix{ template<> class ErrorCodeTraits<CustomErrorCode> : public DefaultErrorCodeTraits<CustomErrorCode>{ public: static std::string GetText( code_type code){ if( code == CUSTOM_OK ) return "OK"; if( code == CUSTOM_INVALID_ARG ) return "ひきすうへんだよ?"; if( code == CUSTOM_SOMETHING_HAPPENS ) return "なんかおきた"; return "orz."; } }; } lix::Succession<CustomErrorCode> DoHogeHoge(int x) { if( x < 0) { return lix::Failed(CUSTOM_INVALID_ARG); } if( x > 100 ) { return lix::Failed(CUSTOM_SOMETHING_HAPPENS); } return lix::Succeeded(); } void sample3() { auto r = DoHogeHoge(1000 ); if( ! r ){ // これで、"なんかおきた" と表示される。 cerr << r << endl; } }
この CustomErrorCode のようにエラーコードの型からその扱いが一意に決まるならば、このような特殊化で対応可能ですが、現実的には int などの汎用の型を異なる体系のエラーコードとして使用していることがほとんどだと思います。
その場合は ErrorCategory 全体を作り、パラメータをすべて指定した typedef を通して使用することになるかと思います。
とりあえずサンプルとして Win32 の LastError 機構をつかう、
typedef Succession<DWORD, Win32ErrorCategory> WinSuccession;
と、 errno をつかう、
typedef Succession<errno_t, CRTErrorNoCategory> CRTSuccession;
を作ってみました。
winsock用とか HRESULT用とか、いろいろ ErrorCategory を作ってあげれば良い感じになるのではないかな、と。
Google Code に公開してみるてすと。
ちょっとしたコードの公開にgoogle code など使ってみる。
Google Code Archive - Long-term storage for Google Code Project Hosting.
よくわかんない。
趣味ライブラリの一部分だけを公開したいんだけど、どうすればいいのか。
マイクロソフトはインストーラーが何をしないといけないかちゃんと説明すべき
アプリケーションをつくって、誰かに使ってもらおうとするとインストーラーが必要になるわけだけど、世の中にはこれに関する情報が非常に少ない。
だからInstallShieldとかを使うわけだけど、やりたいことはアプリケーションを使ってもらいたいということであって、インストーラを作りたいわけじゃないのに、インストーラ作成ツールが一般的な開発環境よりも高いとか、どう考えても高すぎる。
で、wixとかを使うことになって、確かにちゃんと勉強すれば質の高いインストーラを作ることができるんだけど、ちょっと使ってもらいたい、というだけの用途にはどう考えてもオーバースペック。
じゃあ自分でつくろう、とか思うわけだけど、そうすると資料が全然たりなくて手探り状態。これでいいのかなぁとか、不安になりながら作ることになる。
Windows Installer はたしかに立派なもので、ちゃんとしたプロダクトを作って売るにはmsiを使用すべきというのはわからなくもないんだけど、ほとんどのデベロッパーにはバージョン間のファイルの共有とか、インストールのロールバックとか、修復インストールとか、そのへんはどうでもいい情報。(本当はどうでもいいとかいってちゃいけないのかもしれないけど気持ちとしてはどうでもいい。)
WixをつかってMSIをつくろうとすると、どうしてもそのへんの情報を正確に把握しとかなきゃいけないことになる。それなのに資料が全く足りない。書籍での資料はこれ The Definitive Guide to Windows Installer (Expert's Voice in Net) しかないし、http://msdn.microsoft.com/en-us/library/cc185688.aspx これもどうかと思う。マイクロソフトはインストーラーの挙動を統一したいのならもっとちゃんと情報を出すべきだと思う。
個人的には(いろいろ試してみた結果)インストーラーは素の exe として作成するのが一番楽という結論に至った。
InstallShield で設定するにせよ、Wix で XML を書くにせよ、その記述で何が起こるのかを正確に把握しておかないとちゃんとしてものは作れないわけで、何が起こるのか正確に把握できるのなら、そういう動作をするコードを C++ でかくのも別に難しいことじゃない。
いきなり exe を実行させるのは怖いような気もするけど、msiにしたって、正確にユーザーに的確な(msiexecの)コマンドラインオプションを指定させることができるのでなければいわゆるブートストラッパーexeを提供するのはさけられないことだし、msi 自体に dll を埋め込んでカスタムアクションで何でもさせられるのだから、セキュリティ上なにかが違うわけでもない。
カスタムリソースにcabでも仕込んでそれを展開させるようにすることと、 HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Uninstall あたりに正確な値を書きこむようにすることと、アンインストールを何とかすること、それらをちゃんと設計・実装するのと、WixなりInstallShieldなりに精通することとならば、前者のほうが楽だとしか思えない。
みんながみんなそう思うと、どんどんインストーラというものに統一性がなくなっていくわけだけど・・・