たまにはプログラムの話

めっちゃ長文になりました。
絵とか無いのでプログラム興味ない人はあんまり面白くないかもです。

不正落ち対策

初期のころのヴィータ大脱出は不正落ちすることが何度かあり、修正はしたものの、リリース後に不正落ちしたらどうしよう？　というかどうやって原因を特定しよう？　と悩んでおりました。
そこで、ゲームがユーザーの手に渡った後に不正落ちしても大丈夫（？）なように、不正落ちを自動的に検出してログを吐き出すという仕組みを入れることにしました。

ところで、不正落ちから原因箇所を特定するためには例外発生場所のアドレスが重要になりますが、普通に不正落ちしたときに出てくるWin32標準の例外ダイアログだと、その辺がよく分からないんですよね、アレ。あの情報からは元の個所を特定できる気がしません。

そんな時頼りになるのは、例外ダイアログではなくイベントビューアの方に記録されているアプリケーションのエラー情報です。これを見るとバッチリ例外発生アドレスが載っています。
これさえあれば、ビルド時に作った .map と .cod ファイルを使って、例外が発生した個所をソースコード上で特定できますね。

問題は、果たして不正落ちしたときにユーザーがイベントビューアを開いて膨大なリベントリストからヴィータ大脱出.EXEで発生したエラーのログを探し出してコピペしてくれるか？　ですが……まぁ無理ですね。なので、そこは自動で取得するように頑張りました。

ちなみに最初は間違った方向に頑張ったため、

ShellExecute(NULL, "open", "eventvwr.exe", "/c:Application", NULL, SW_SHOWNORMAL);

を実行して自動的にイベントヴューアを開いてアプリケーションログを表示し、あとはユーザに自力で検索してもらう、という実装になりかけました。

とりあえずログを取得する

プログラムでWindowsのイベントログを取得する方法は

EVENTLOGRECORD
OpenEventLog
ReadEventLog
CloseEventLog

あたりを検索するとすぐ見つかると思います。特に、

http://www.yuboo.net/~ybsystem/sys_build/win_client/evtlog_read.html
「イベントログの読み込み」

とか

http://plaza.rakuten.co.jp/u703331/diary/200608110000/
「Event Log」
http://plaza.rakuten.co.jp/u703331/diary/200608110001/
「Event Log その２」
http://plaza.rakuten.co.jp/u703331/diary/200608110002/
「Event Log その３」
http://plaza.rakuten.co.jp/u703331/diary/200608110003/
「Event Log その４」

には大変お世話になりました。

つぎに、膨大なログの中からヴィータ大脱出の不正落ちの記録だけをピンポイントで見つける方法です。
まともに検索するとすごく時間がかかります。たぶん何万件とかいったレベルでイベントがあるんじゃないかと思います。
Windowsイベントログを定期的に消してる人なんていないと思いますし。
幸いにもログは新しい順に取得できるので、検索対象は相当絞り込むことができます。例えば、

• 過去 5 分以内に発生したログだけを対象にする（それ以上古いログが出てきたら、そこで検索を打ち切る）

  EVENTLOGRECORD::TimeGenerated はそのまま time_t の値なので、これと現在時刻 time(NULL) の差をとり、
  	それが 5 * 60 [秒] 未満であるログだけ調べます
  

• エラーメッセージだけを対象にする

  EVENTLOGRECORD::EventType が EVENTLOG_ERROR_TYPE なやつだけを調べます
  

• ヴィータ大脱出の実行ファイル名を検索キーワードにする

  エラーメッセージの文字列パラメータは EVENTLOGRECORD の先頭を 0 バイト目としたときに、EVENTLOGRECORD::StringOffset バイト目以降に入っています。
  文字列パラメータが複数個ある場合はヌル文字で区切り、全部でNumString個の文字列があります。
  ちなみに EVENTLOGRECORD 構造体の直後にはソース文字列とコンピュータ名が同じくヌル文字区切りで入ってます。
  

イベントログのパラメータ文字列を得る

アドレスやら不正落ちした実行ファイル名やらの情報は、イベントの文字列パラメータという形で入っているので、これを取り出さないとどうしようもありません。これらの文字列を得るには、だいたいこんな感じにします。

#define MAX_EVENT_ARGS 32
#define OFFSET_PTR(p, off) (((uint8_t *)(p)) + (off)) // p の型に関係なく常に off バイトだけずらす
EVENTLOGRECORD *e = ...; // イベント
LPSTR SourceName = (LPSTR)OFFSET_PTR(e, sizeof(EVENTLOGRECORD)); // イベントソース
LPSTR ComputerName = SourceName + strlen(source) + 1; // コンピュータ名
LPSTR EventArgs[MAX_EVENT_ARGS]; // 文字列パラメータ数
LPSTR str = (LPSTR)OFFSET_PTR(e, e->StringOffset);
for (WORD i=0; i<e->NumStrings; i++) {
	EventArgs[i] = str; // i番目の文字列パラメータ（のアドレスだけ）
	str += strlen(str) + 1;
}

ちなみに、イベントビューアで見られるようなイベントメッセージをそっくりそのまま再現するためには、レジストリの

"SYSTEM\\CurrentControlSet\\Services\\EventLog\\Application"

を見てメッセージフォーマットが定義されているファイルを調べ、それをロードして FormatMessage するとかいう複雑怪奇な手順が必要ですが、目的のエラーを探すだけだったら文字列パラメータを見ればよいだけなので、面倒な作業は完全に不要です。
が、一応載せておきますと、だいたい↓みたいな感じです。

EVENTLOGRECORD *e = ...; // イベント
CHAR szExpandModuleName[MAX_PATH] = {0};
{
	HKEY hAppKey = NULL;
	HKEY hSrcKey = NULL;
	WCHAR moduleName[MAX_PATH] = {0};
	DWORD moduleNameBytes = sizeof(moduleName);
	RegOpenKeyEx(HKEY_LOCAL_MACHINE, "SYSTEM\\CurrentControlSet\\Services\\EventLog\\Application", 0, KEY_READ, &hAppKey);
	RegOpenKeyEx(hAppKey, SourceName, 0, KEY_READ, &hSrcKey);
	RegQueryValueEx(hSrcKey, "EventMessageFile", NULL, NULL, (LPBYTE)moduleName, &moduleNameBytes);
	ExpandEnvironmentStrings(moduleName, szExpandModuleName, MAX_PATH);
	RegCloseKey(hSrcKey);
	RegCloseKey(hAppKey);
}
void *pMessage = NULL;
HMODULE hModule = LoadLibraryEx(szExpandModuleName, NULL, DONT_RESOLVE_DLL_REFERENCES|LOAD_LIBRARY_AS_DATAFILE);
FormatMessage(
	FORMAT_MESSAGE_ALLOCATE_BUFFER|FORMAT_MESSAGE_FROM_HMODULE|FORMAT_MESSAGE_ARGUMENT_ARRAY,
	hModule,
	e->EventID, // ←イベントIDを指定
	MAKELANGID(LANG_JAPANESE,SUBLANG_JAPANESE_JAPAN), // ←日本語で取得するなら、こう
	 (LPSTR)&pMessage, 0, (va_list *)&EventArgs);
MessageDialog(NULL, (LPSTR)pMessage, "", 0);
LocalFree(pMessage);

めんどくさいですね～～～

目的のエラーログかどうかを調べる

エラーイベントのメッセージパラメータ（↑のコードでいうとEventArgsのどれか）には必ずエラーが発生した実行ファイルのファイル名が入ってますから、その名前で検索をかけてやるわけです。なお、フルパスではなく、ファイル名だけで比較しないと引っかかりません。

自分が不正落ちしたかどうかを調べ、不正落ちした形跡が見つかったらダイアログメッセージを出す

そもそもの目的はコレです。本当は例外発生に引っ掛けて、その時点でアドレスが分かればよいのですが例外フック（SetUnhandledExceptionFilter）で得られる情報は例外ダイアログのものと同じで、エラー発生個所の特定にはあまり役に立たなそうに見えます。
じゃあフックしたときにエラーログを見るか？とも思いましたが、残念ながらフックした段階ではまだエラーイベントは生成されていません。
実行ファイルがが例外で完全に終了して、やっとイベントが生成されるみたいです。

なので例外フックには頼るのはボツにしました。
その代わりに、ゲーム起動時に１５分前までのイベントログを調べ、ヴィータ大脱出で発生したエラーイベントが見つかった場合は、前回起動時に不正終了したとみなし、イベントの内容を情報をテキストファイルに保存してダイアログメッセージを出す、というふうにしました。

ちなみに１５分と長めに設定したのは、

ヴィータ大脱出をフルスクリーンで実行中に不正落ち
↓
フルスクリーン状態で止まっているのでデスクトップが操作できない
↓
仕方なくCtrl+Alt+Deleteでウィンドウを出すも、ゲームウィンドウの裏側に表示されてしまいまともに操作できない
↓
どうにかキーボード操作でログアウトする
↓
再起動

みたいな流れになって、復旧に手間取った場合を想定したからです。

テスト

テストです。適当なところに

int *a=0; *a=0; 

とか書いておいて実行してみます。ちなみに VisualStudio から実行してもダメです。
デバッガが起動してしまい、エラーログが追加されません。普通にエクスプローラから EXE を実行して確認します。
・
・
・
どうやらうまくいったようです。これでリリース後に不正落ちしても安心ですね！

ちなみに

リリース後、不正終了の報告はありませんでした……。