8月9日、Michael Stapelbergが「Tracking down a Zsh history data loss bug 🐞」と題した記事を公開した。Zshのヒストリファイルが無言で切り詰められるバグをbpftraceと意図的クラッシュという手法で追跡し、根本原因を特定するまでの過程が詳しく記されている。
この問題はZsh 5.9.2(2026年7月12日リリース)で修正済みだ。しかし、デバッグのアプローチ——軽量な常時監視、コードを改変してクラッシュを誘発する手法——は再現困難なバグへの対処として実践的な参考になる。Zshユーザー以外にも読む意義がある内容だ。
「昨日打ったコマンドが消えている」——数年越しの怪現象
Zshユーザーであれば、Ctrl+Rでコマンド履歴を遡ったとき、確かに実行したはずのコマンドが見つからない経験があるかもしれない。Stapelbergは何年もの間、この現象に悩まされてきた。
症状は一貫していた。~/.zsh_historyを確認すると、ファイルは壊れていない(文字化けや不完全な行はない)。しかし、直近数年分のエントリが丸ごと消え、古いエントリだけが残っている。しかも残行数はそのつど異なる。最初はデイリーバックアップから復元してやり過ごしていたが、繰り返し発生するため、本格的に調査することにした。
調査ツールの選定——inotify、fatrace、そしてbpftrace
最初に試したのはLinuxの定番ファイル監視APIであるinotify(7)だ。~/.zsh_history単体を監視すると、ファイルが開かれ、読まれ、そしてDELETE_SELFイベントが発火する。なぜ削除なのか——ディレクトリごと監視すると全貌が見えた。
Zshは履歴保存時に.zsh_history.newを作成し、書き終えてからrenameで上書きするという「アトミック書き込み」パターンを採用している。DELETE_SELFはこのrename操作の副産物だった。
しかしinotifyではプロセスIDが取れない。fanotify(7)ベースのfsnotifywaitはカーネルからPIDを受け取れるが、ツール側が表示しない実装になっている。fatrace(8)を使うとプロセス名とPIDを確認できた。ただし「何バイト読み書きしたか」は依然わからない。
決め手になったのがbpftrace(8)だ。open(2)、read(2)、write(2)、lseek(2)などのシステムコールを横断的にフックし、読み書きのバイト数まで記録するスクリプトをsystemdユニットとして常駐させた。straceの常時適用と違い、bpftraceはカーネル内でフィルタリングするため、オーバーヘッドを抑えつつ長期監視が可能だ。
正常時のログはこうなる:
zsh(231222) openat: /home/michael/.zsh_history flags 0 mode 0
zsh(231222) read = 0 ← EOFまで読み切った証拠
zsh(231222) close 3 (reads: 52895744, writes: 0)
zsh(231222) close 3 (reads: 0, writes: 52888907)
zsh(231222) rename:/home/michael/.zsh_history.new -> /home/michael/.zsh_history
異常時のログはこうだ:
zsh(231233) openat: /home/michael/.zsh_history flags 0 mode 0
zsh(231233) lseek fd 3 offset 11572944 whence 0
zsh(231233) close 3 (reads: 11575296, writes: 0) ← EOFまで読んでいない
zsh(231233) close 3 (reads: 0, writes: 11572944)
zsh(231233) rename:/home/michael/.zsh_history.new -> /home/michael/.zsh_history
read = 0(EOFシグナル)がない。 つまりZshは履歴ファイルをEOFまで読み切らずに途中で打ち切り、その短い内容をそのまま.zsh_historyとして書き戻していた。
「クラッシュさせて、コアダンプを読む」という力技
犯人がZsh自身であることは確定した。次の問題は「なぜreadhistfileがファイルを途中までしか読まないのか」だ。Stapelbergが取った戦略は大胆なものだった。Zshのソースコードを改造して、短すぎる履歴ファイルを書こうとしたときに意図的にクラッシュさせるというものだ。
if (tmpfile && lines_written < 50000) {
char *crashptr = (char*)0x23;
*crashptr = 42; // セグフォルト発生
}
ポイントは「.zsh_historyを上書きする直前」でクラッシュさせることだ。これにより既存の履歴ファイルは書き換えられず、手元のデータを守ったままコアダンプだけが得られる。systemd-coredump(8)を設定しておけばクラッシュは自動収集され、数日後にcoredumpctl debugでGDBのバックトレースが得られた:
#0 savehistfile ... lines_written = 45546
#1 savehistfile ... xcurhist = 51183
xcurhist(メモリ上の履歴エントリ総数)は51,183なのに、実際に書かれた行数は45,546。savehistfileは正しく動いており、問題はreadhistfileがファイルを読み込む段階にあることが確定した。
なお、コアダンプにはシェル履歴が丸ごと含まれる。サードパーティのクラッシュ収集サービスにアップロードしないよう注意が必要だ。
根本原因:readhistfileの途中終了
ZshにはINC_APPEND_HISTORYというオプションがある(Zshオプション一覧)。このモードでは、コマンドを実行するたびに履歴をファイルに追記する。複数のシェルセッションを同時に使うユーザーが有効にしていることが多い設定だ。シェル終了時には全履歴を再度読み込んで重複排除などの処理をかけてから書き直すが、この再読み込みの際、特定の条件でファイルの途中までしか読まずに処理を終えてしまうコードパスが存在していた。コアダンプとソースコードの精査から、このreadhistfileの途中終了が今回の切り詰めの直接原因であることが判明した。
デバッグ手法のまとめ
今回の調査の流れをまとめると:
- inotify/fatrace でZsh自身が履歴を書き換えていることを特定
- bpftrace でEOFまで読んでいないことを観測
- Zshをパッチして意図的にクラッシュさせ、コアダンプで内部状態を確認
- ソースコードと照合して
readhistfileの途中終了を特定
straceの常時適用を避けbpftraceで軽量に監視し、再現困難なバグに対してはコードを改変してクラッシュを誘発するという手法は、日常的なデバッグの引き出しとして参考になる。Zsh 5.9.2以降へのアップデートで問題は解消される。
詳細はTracking down a Zsh history data loss bug 🐞を参照していただきたい。