プログラマ探偵の事件簿：厄介なWindows

思わぬところに動作環境の違いによる問題が潜んでいることがある。Linux/Mac OSの上で問題なく動作していたものがWindowsだけ違う動きをすることに悩まされた話である。助手の猫は、面白い問題だから早く調べろと夜中の２時半から大騒ぎして私を起こした。

事件の始まり

３ヶ月コツコツと開発してきたTWSNMP　FCを、いよいよリリースしようと念の為Windows環境でテストしていた時のことである。自動発見やマップの操作には問題はない。試してにIPから位置情報を取得するデータベースファイルの登録をやってみた。登録失敗！！！　他のOSでは何の問題もないのに不思議だった。見つかったのはこの問題だけなので一先ずリリースはすることにした。後でじっくり調査することにした。

エラーログが出ないのは何故か？

TWSNMP　FCをリリースした翌日、猫に言われたので調べ始めた。ログをみるとデータベースの登録を行うリクエストの応答が４００（バッドリクエスト）になっていたが、その前に何もエラーログが記録されていない。

2021-04-18T06:16:22.791 POST 400 /api/conf/geoip 127.0.0.1 61914739 26 711.5099ms

問題のデータベース登録処理を行うソースコードを順番に調べていくと、たしかにエラーログを出力していない部分が見つかった。その前の処理はエラーログを出力するようになっている。逆にログの出力を忘れたこの場所が原因ということがわかった。

ファイルのリネームのOSによる違い

エラーログを出力するように修正して調べてみた。

2021-04-18T06:16:22.629 postGeoIP err=rename datastore\geoio.uplaod datastore\geoip.mmdb: The process cannot access the file because it is being used by another process.
2021-04-18T06:16:22.791 POST 400 /api/conf/geoip 127.0.0.1 61914739 26 711.5099ms

ファイルをリネームする時にリネームするファイルを他のプロセスが使っているというエラーである。登録する処理にはリネームがある。

// UpdateGeoIP : GeoIP DBを更新する
func UpdateGeoIP(path string) error {
	DeleteGeoIP()
	dst := filepath.Join(dspath, "geoip.mmdb")
	if err := os.Rename(path, dst); err != nil {
		return err
	}
	return openGeoIP(dst)
}

この処理を呼び出す元のソースコードを見直すとたしかにファイルをクローズする前にリネームされる。

deferの中でクローズしているので関数が終了するまでクローズされない。

しかし、他のOSでは、なぜクローズしていないファイルをリネームできるのか不思議だ。もしかするとオープンしているプロセスが自分なら許してくれるのかもしれない。

クローズしてからリネーム

WIndowsでも問題なくIP位置情報データベースを登録できるように修正して一件落着。

教訓

たぶん、Windowsのようにクローズしていないファイルをリネームした時にエラーになることが厳密には正解なのだと思う。LinuxやMac OSの優しさは時には混乱の元になるように思う。よの中には、そんな優しさで問題なく動作しているプログラムがどれだけあるのだろるか！
助手の猫曰く「カリカリを全部食べないとレトルトの美味しいスープはもらえないのと同じ」とのこと。ピントがずれているが、彼のおかげで、問題を解決できた。