Posted inLinux

straceを使ったLinuxアプリケーションのデバッグ入門：システムコールの追跡とエラー原因の特定

Linux tutorial - IT technology blog
Linux tutorial - IT technology blog

straceが本当に必要になる場面とは

金曜日の夕方、サービスが突然ダウンしているのにログには何も出ていない、そんな経験はないだろうか。再起動すると復活するが、5分後にまた落ちる。dmesgにも何も出ず、journalctlも沈黙したまま。そんなときに筆者が開くのがstraceだ。

会社の古いCentOS 7サーバーでは、通常のログレベルでは拾えない問題を突き止めるためにstraceをかなり活用してきた。デプロイ後に狂ったファイルパーミッション、ulimitによってブロックされたソケット、symlinkを新しい場所に張り直したにもかかわらず古いパスのconfigを読もうとし続けるバイナリ——そういった問題を解決してきた。

straceは、プロセスが実行するすべてのシステムコール——ファイルのオープン、読み書き、ネットワーク接続、子プロセスの生成など、アプリケーションとカーネル間のあらゆるやり取り——を「盗み聞き」できるツールだ。ソースコードもリコンパイルも不要で、実行中のPIDにアタッチするだけでいい。

ログを読む場合（開発者がprint出力を許可した情報しか見えない）と違い、straceはプロセスがカーネルレベルで実際に何をしているかをすべて見せてくれる。より深いレベルでのログ分析には、journalctlとdmesgによる詳細ガイドも合わせて参照すると理解が深まる。

straceのインストール

ほとんどのディストリビューションの公式リポジトリにstraceが含まれている：

# Ubuntu / Debian
sudo apt install strace

# CentOS / RHEL / AlmaLinux
sudo yum install strace
# 新しいバージョンはdnfを使用
sudo dnf install strace

# Arch Linux
sudo pacman -S strace

# バージョンを確認
strace --version

追加設定は不要だ。straceはカーネルのptrace()システムコールを利用して動作する——プロセスにアタッチできる十分な権限（通常はrootまたは同一ユーザー）さえあれば使える。権限管理に不安がある場合は、sudoとsudoersファイルの設定ガイドを確認しておくといい。

straceの実践的な使い方

コマンドを直接straceで実行する

最もシンプルな方法——straceがコマンドを実行しながらすべてのシステムコールを出力する：

strace ls /tmp

出力量が膨大になる。実際にはフィルタリングするかファイルに書き出したほうがいい：

# 後で分析するためにファイルへ書き出す
strace -o /tmp/strace_ls.log ls /tmp

# タイムスタンプ付き（非常に便利）
strace -t -o /tmp/strace_ls.log ls /tmp

# マイクロ秒単位の精密なタイムスタンプ
strace -tt -o /tmp/strace_ls.log ls /tmp

実行中のプロセスにアタッチする

最も現実的なケース——サービスが動いているがエラーが出ていて、再起動できない状況：

# まずPIDを調べる
pgrep -a nginx
# または
ps aux | grep myapp

# プロセスにアタッチ
sudo strace -p 12345

# すべてのスレッドにアタッチ（マルチスレッドアプリでは重要）
sudo strace -p 12345 -f

-fフラグ（follow forks）は、マルチスレッドアプリや子プロセスをspawnするアプリで非常に重要だ。-fがないと、子スレッドのシステムコールをすべて見逃す可能性がある。プロセス管理の基礎についてはsystemdでLinuxプロセスを管理する完全ガイドも参考になる。

必要なシステムコールだけをフィルタリングする

-e trace=でノイズを減らす——筆者が最もよく使う方法だ：

# ファイル関連のシステムコールのみ表示
strace -e trace=file ls /tmp

# ネットワーク関連のコールのみ
strace -p 12345 -e trace=network

# open、read、writeのみ
strace -e trace=open,read,write -p 12345

# エラーになったコールのみ（-1を返したもの）
strace -e trace=all -e status=failed -p 12345

-e status=failedオプションは非常に強力で、失敗したシステムコールだけを表示し、成功したものはすべて省略する。パーミッションエラーやファイルが見つからない問題を素早く特定するのに最適だ。

各システムコールの時間を計測する

# -T: 各システムコールにかかった時間を表示
strace -T -p 12345 -e trace=file

# -c: 統計サマリーを表示（ボトルネック分析に非常に便利）
strace -c ls /tmp

-cの出力はこのようになる：

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 52.13    0.000423          42        10           mmap
 23.41    0.000190          19        10           read
 12.50    0.000102          12         8         1 openat
  5.10    0.000041           5         8           fstat
  ...

errors列はどのシステムコールが失敗しているかを示す。% time列は何がCPUを最も消費しているかを示す。

実際の問題をデバッグする

ケース1：アプリがconfigファイルを見つけられない

典型的な状況：アプリがエラーを出しているが、ログには「config not found」とだけ書かれている。

# ファイル関連のシステムコールをフィルタリングしてエラーのみ取得
strace -e trace=openat,open -e status=failed ./myapp 2>&1 | grep ENOENT

アプリが読もうとして見つからなかったファイルが一目でわかる：

openat(AT_FDCWD, "/etc/myapp/config.yaml", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/local/etc/myapp.conf", O_RDONLY) = -1 ENOENT (No such file or directory)

コードにドキュメントがなくても、アプリがどこでconfigを探しているかがすぐにわかる。

ケース2：謎のPermission denied

strace -e trace=file -e status=failed sudo -u appuser ./myapp 2>&1 | grep EACCES

会社のCentOS 7サーバーで、「Permission denied」でサービスが落ちているのにls -laでファイルパーミッションを確認すると明らかに問題ないように見えるケースがあった。straceで調べてみると、SELinuxがブロックしていることが判明——システムコールはEACCESを返していたが、エラーメッセージにはSELinuxへの言及が一切なかった。LinuxのユーザーとPermission管理の基礎を押さえておくと、こうした問題の切り分けがさらにスムーズになる。

ケース3：サービスがハングして何を待っているかわからない

sudo strace -p $(pgrep myservice) -e trace=network,ipc

プロセスが次のような状態でスタックしているのが見えたら：

epoll_wait(5, [], 1, 30000)             = 0  # ネットワークを待機中、30秒タイムアウト
# または
futex(0x7f..., FUTEX_WAIT, ...)         # ロックを待機中

すぐにわかる：前者はネットワーク接続待ち（バックエンドのタイムアウトの可能性）、後者はmutexロック待ち（デッドロックの可能性）だ。

ケース4：I/Oボトルネックを特定する

# 30秒間の統計を集計
sudo timeout 30 strace -c -f -p $(pgrep myapp) 2>&1

readやwriteが50%以上のtimeを占め、usecs/callが高い場合——それはI/Oが遅いサインだ。ディスクやNFSマウントを確認する必要がある。

straceによる検査とモニタリング

筆者の実践的なデバッグワークフロー

  1. -cで最初に全体像を把握する：どのシステムコールが最も多く呼ばれているか、どれが失敗しているかを確認する。
  2. ステップ1の結果に基づいて特定のシステムコールをフィルタリングする——生の出力は量が多すぎるので、最初から見ないこと。
  3. 正確なタイミングが必要なときは-tt -Tを使う——異常に長い時間間隔を探す。
  4. エラーコードでgrepする：ENOENT（ファイルが見つからない）、EACCES（パーミッション）、ECONNREFUSED（ネットワーク）、ETIMEDOUT（タイムアウト）。

straceログを分析する際に便利なgrepコマンド

# 正常にオープンされたすべてのファイルを表示
grep 'openat.*O_RDONLY' strace.log | grep -v '= -1'

# ネットワーク接続を探す
grep 'connect(' strace.log

# stderr（fd=2）への書き込みを探す
grep 'write(2,' strace.log

オーバーヘッドについての注意

straceはptrace()を使用するため、各システムコールでプロセスを停止してカーネルに報告させる必要がある。ワークロードによって2倍から10倍のオーバーヘッドが発生する可能性がある。高負荷の本番環境では使用しないこと——デバッグ中のみ使用するか、リアルタイム出力の代わりに-cで統計サマリーを取得するにとどめること。

本番環境でより低いオーバーヘッドでトレーシングが必要な場合、perf traceやbpftraceのほうが適しているが、straceはシンプルで事前準備が不要なため、筆者が最初に手を伸ばすツールであることに変わりはない。本番環境全体のパフォーマンス改善についてはLinuxサーバーのパフォーマンス最適化（本番環境向け）も参照してほしい。

まとめ

straceは日常的に使うツールではないが、ログでは説明がつかない問題——特にパーミッションエラー、ファイルが見つからない、ネットワークタイムアウト、デッドロック——をデバッグする際に、ソースコードを読んだりprint文を追加してリデプロイしたりするよりもはるかに時間を節約できる。

straceでデバッグする際の優先順位：まず-e status=failedでエラーを確認し、次に-cでボトルネックを把握し、それから必要であれば詳細を確認する。最初から生の出力を見ようとすると、情報量に圧倒されてしまう。

Share:
Tags: