プログラマー探偵の事件簿：突然、リリース版が起動できなくなる安易な修正

2022年3月6日 07:17

やっとソフトウェアをリリースできると思った瞬間に突然やってくる致命的問題の顛末である。

事件の始まり

今年の元日から開発しているログ分析ツール（TWLogAIAN)の最初のリリース版を公開しようとした時に話である。最終段階の細々したバグを修正しWailsパッケージも最新に更新してリリース版を作成した。Windows版を最終版候補のインストーラーからインストールして起動してみた。何と起動できない。何も表示されない。これまで沢山のソフトを開発してきた私にとっては何度も経験したリリース版が動作しないという悪夢である。調査に時間がかかったという悪い思い出がよみがる。

Mac版で手がかりを見つけた

最初はWindows版の問題かと思った。Windowsのデバック版プログラムを作って試してみた。ちゃんと起動できる。しかし、リリース版に戻すと起動できない。何日か前にリリース版を試した時には問題は発生しなかった。なんとなく助手の猫が天から「Mac版のリリース版を試してみたら」と言ったような気がした。Mac版のリリース版を起動してみた。

2022/03/01 06:45:37 cannot call 'github.com/wailsapp/wails/v2/pkg/runtime.LogDebug': An invalid context was passed. This method requires the specific context given in the lifecycle hooks:
https://wails.io/docs/reference/runtime/intro

のログがでて停止した。なんとリリース版だけにある問題だった。

Wailsのソースコードを調べる

Mac版が停止した時のログから原因を調べることにした。幸いなことにオープンソースのパッケージはソースコードを調べられる。問題のログは

の４１行目で出力していることがわかった。

func getLogger(ctx context.Context) *logger.Logger {
	if ctx == nil {
		pc, _, _, _ := goruntime.Caller(1)
		funcName := goruntime.FuncForPC(pc).Name()
		log.Fatalf("cannot call '%s': context is nil", funcName)
	}
	result := ctx.Value("logger")
	if result != nil {
		return result.(*logger.Logger)
	}
	pc, _, _, _ := goruntime.Caller(1)
	funcName := goruntime.FuncForPC(pc).Name()
	log.Fatalf("cannot call '%s': %s", funcName, contextError)　// ここです。
	return nil
}

どうやらloggerが設定されていないとエラー終了することがわかった。
ソースコードの履歴をみて、この部分は２ヶ月前から変わっていないこともわかった。つまり、その日に更新したwailsでは変わっていないということである。問題なのはloggerを設定しているところのようなので、その部分を探した。

のCreateApp関数で設定していた。ソースコードをよく見ると問題が発生していた3/1時点ではリリース版ではloggerが設定されない処理になっていた。
そして履歴をみると

の問題で修正したことによりloggerを設定する処理がなくなったこともわかった。それが私がリリース版を作るためにWailsを更新する２日前であった。偶然にも地雷を踏んでしまった。

自前のログ出力に変更して逃げた

リリース版が起動しない原因はわかった。たぶんwailsのバグである。報告しようかとも思ったが、リリースできなくてモチベーションも下がって、その日は忘れることにした。
その後、前々からwailsのデバッグログの出力が気に入らなかったので、自前でデバッグログを出力することにした。

DEB | [DesktopAssetServer] Loading file: assets/images/appicon.png
2022/03/05 15:29:53 GetConfig

１行目がWailsのデバックログ出力、レベルはあるけどタイムスタンプがない。２行目が自前のデバックログ出力、GO言語標準である。
大量にあるデバックログ出力を全部書き換えた。

これで問題は回避できた。リリース版できた

やはりWailsのバグだった

ログ分析ツールの開発を次の段階に進める前に、今朝この問題がwailsでどうなったか調べてみた。

案の定、ちゃんと報告した人がいて２日前に修正されていた。

ログ分析ツールの最初のリリースが前後に１週間ずれていたら、この事件に遭遇することもなかったようである。最初のバグを組み込んだ原因はリリース版では不要なログを出さないようにするという思いやりであったと思うが、修正の仕方がログ出力の処理自体をなくすという安易な方法だったことが問題であった。その修正が起動できないという災いになるとは気づかないものである。

「安易な修正は災いを呼ぶ」と助手の猫が天から言っているような気がする。私も気をつけよう。

開発のための諸経費（機材、Appleの開発者、サーバー運用）に利用します。ソフトウェアのマニュアルをnoteの記事で提供しています。サポートによりnoteの運営にも貢献できるのでよろしくお願います。