gihyo.jpサイトのロゴ

Ubuntu Weekly Recipe

第762回定番のデバッグ・調査ツールであるstraceでエラーインジェクション

2023-05-10

straceはユーザーランドアプリケーションの挙動の確認やデバッグに使える便利なツールです。どのシステムコールが、どのような引数で呼び出され、その結果どうなったのかをログとして残せます。不可解な挙動をするプログラムを調べる上で覚えておくと損はないツールです。今回はstraceの基本的な使い方に加えて、わざとシステムコールをエラー終了させる、エラーインジェクションについても紹介しましょう。

不可解なプログラムについて

この世にあるソフトウェアはすべて何らかの不具合を抱えています。もし不具合のないソフトウェアが存在するとしたら、その事実自体が不具合と言えるかもしれません。そのまま放置しておくと、きっと将来なにがしかの不具合が顕現することでしょう。よってソフトウェアエンジニアと呼ばれる人たちは、日々ソフトウェア様のご機嫌を伺い、こびりついた不具合を削ぎ落とし、場合によってはあえて不具合を埋め込みながら生活しているのです。

そんなわけで目の前で動いているアプリケーションやシステムは、たくさんのエンジニアによる多大な貢献と、ソフトウェア様のご機嫌によって成り立っているということを、心の片隅にでもとどめておいてください[1][2]。

初っ端から脇道にそれてしまいましたが、straceの話に戻りましょう。一般的にプログラムが意図しない挙動を見せた時は、さまざまな方法で原因を追求します。たとでばデバッガを使って実際の動作を追跡したり、ソースコードから挙動を読み解いたり、デバッグ用の出力を追加してトライアンドエラーを繰り返したり、毛むくじゃらのクマに話しかけたりとその方法は様々です。

Linuxの場合は、デバッグ時にstraceを使うと、次のような利点が得られます。

  • プログラムそのものに手を加える必要はない
  • ソースコードがなくてもある程度追跡可能
  • システムコールの実行の流れを把握できる
  • システムコール呼び出しの性能・統計情報が得られる
  • システムコールの戻り値を書き換えられる
  • 使うための準備がかんたん

「システムコール」は、Linuxカーネルとユーザーランドアプリの橋渡しをする部分です。たとえばファイルを読み書きするとかネットワークのデータを送受信するとか、そういうハードウェアが絡んでくる処理に関しては、ユーザーランドのプログラムはシステムコールを介してカーネルに処理を依頼することになります。よって、システムコールの状態を把握することで、そのプログラムが外とどんな風にデータをやりとりしているかが見えてきます。その結果、次のような動作の確認ができます。

  • 設定ファイルをどの順番で読み込んでいるか
  • メッセージ表示周辺のシステムコールの引数や戻り値はどうなっているのか
  • そもそもデータを送信しようとしているのか
  • どこかでタイムアウトやリトライが発生していないか
  • どのシステムコールの呼び出し周辺で時間がかかっているのか

また、straceは次のような調査には向いていません。

  • 特定の処理に対してデバッグログを追加したい
  • システムコール以外の関数の呼び出しや回数を確認したい
  • ソースコードの処理内容を変えたい
  • CPUのレジスタを確認したい
  • カーネルそのものをデバッグしたい

これらを実施したいのであればgdbやperf、eBPFといった他のツールや仕組みを使うことになるでしょう。

深夜はstraceするに限る

さて、実際にstraceを使ってみましょう。今回はUbuntu 22.04 LTSにインストールされている5.16を使うことにします。普通にUbuntuをインストールした環境であれば最初からインストールされているはずです。もし入っていなければ次のようにインストールしてください。

$ sudo apt install strace

試しに適当なプログラムを実行してみましょう。この場合、「⁠strace 対象のプログラムと引数」のように実行します。

$ strace cat /etc/lsb-release
execve("/usr/bin/cat", ["cat", "/etc/lsb-release"], 0x7ffdac1fde48 /* 82 vars */) = 0
（中略）
openat(AT_FDCWD, "/etc/lsb-release", O_RDONLY) = 3
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=104, ...}, AT_EMPTY_PATH) = 0
fadvise64(3, 0, 0, POSIX_FADV_SEQUENTIAL) = 0
（中略）
read(3, "DISTRIB_ID=Ubuntu\nDISTRIB_RELEAS"..., 131072) = 104
write(1, "DISTRIB_ID=Ubuntu\nDISTRIB_RELEAS"..., 104DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=22.04
DISTRIB_CODENAME=jammy
DISTRIB_DESCRIPTION="Ubuntu 22.04.2 LTS"
) = 104
read(3, "", 131072)                     = 0
munmap(0x7f3a0dea8000, 139264)          = 0
close(3)                                = 0
close(1)                                = 0
close(2)                                = 0
exit_group(0)                           = ?
+++ exited with 0 +++

まず、execve()で実際に呼び出すプログラムを実行しています。その後、catを実行する際にさまざまなライブラリをロードする処理が走ったあとに「/etc/lsb-release」ファイルをopenat()で開いています。その戻り値である「3」は、開いたファイルのファイルディスクリプター（fd）です。これを、今度はread()で読み込み、その後に標準出力（fd=1）にwrite()しています。straceはトレース結果を標準エラー出力に出力しているため、catの実行結果と混ざって表示されています。最後に各種fdを閉じて、exit_group(0)して終了という流れです。

上記はシンプルな結果ですが、これだけでも使えることがわかるでしょう。たとえば「設定ファイルを変更したのに、なぜか実行結果には反映されない」なんて問題に遭遇した時、strace経由で実行すれば「open()が呼ばれたかどうか」で、その設定ファイルが実は使われていなかったなんてことが判明するわけです。もしくは「あとに読み込まれた他の設定ファイルで上書きされていた」なんてこともあるでしょう。

表示するシステムコールを限定する

特定のシステムコールだけに限定したいなら「-e システムコール名」という指定が可能です。たとえばopenat()とread()だけに限定したいなら次のように指定します。

$ strace -e openat,read cat /etc/lsb-release
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P\237\2\0\0\0\0\0"..., 832) = 832
openat(AT_FDCWD, "/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/etc/lsb-release", O_RDONLY) = 3
read(3, "DISTRIB_ID=Ubuntu\nDISTRIB_RELEAS"..., 131072) = 104
DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=22.04
DISTRIB_CODENAME=jammy
DISTRIB_DESCRIPTION="Ubuntu 22.04.2 LTS"
read(3, "", 131072)                     = 0
+++ exited with 0 +++

この「-e システムコール」は「-e trace=システムコール」の省略形です。「⁠-e」オプションには他にもいろいろ指定できるので詳細はstraceのmanページを参照してください。いくつか例をあげると、次のようなものがあります。

  • 「-e '!openat,read'⁠」⁠：openat()とread()以外
  • 「-e %file⁠」⁠：ファイル操作系のシステムコール一式のみ表示
  • 「-e %process⁠」⁠：exec()やexit()などのプロセス系のシステムコール一式のみ表示
  • 「-e %network⁠」⁠：ネットワーク系のシステムコール一式のみ表示
  • 「-e signal=SIGUSR1⁠」⁠：SIGUSR1シグナルの発生のみを表示

なお最初のケースで「!」を使う際は、この文字がシェルで展開されるために、エスケープするかシングルクォートでくくる必要があります。

出力先を変更する

straceは何もしないと標準エラー出力に出力します。よって「strace FOO 2> debug.log」のように実行すれば、出力結果を任意のファイルに保存できます。しかしながら、この場合は標準エラー出力がすべて保存されることになってしまいます。

straceの結果だけを保存したいのであれば、「⁠-o FILE」オプションを使いましょう。

$ strace -o debug.log cat /etc/lsb-release

これであとからじっくり実行結果を確認できます。

出力結果にタイムスタンプを付ける

出力結果にはタイムスタンプがあると便利です。straceにはいくつかのタイムスタンプのオプションが存在します。

  • -t：時計の時刻を秒単位で表示（例：22:39:13 read...）
  • -tt：時計の時刻をマイクロ秒単位で表示（例：22:39:44.314041 read...）
  • -ttt：Unix時間をマイクロ秒単位で表示（例：1683553208.654890 read...）

「--timestamp=time:ns」のように、フォーマットや精度の調整もできます。また、「⁠-T」を指定すると、システムコールにかかった時間も末尾に表示してくれます。

22:41:50.730704 read(3, "DISTRIB_ID=Ubuntu\nDISTRIB_RELEAS"..., 131072) = 104 <0.000033>

上記の例だと、行末の「0.000033」が、read()にかかった時間です（33マイクロ秒⁠）⁠。

ターゲットから起動したプロセスも調査対象に入れる

あるプログラムが別のプログラムを起動することもよくあります。この場合、straceが調べるのはstraceの引数に渡したプログラムだけです。たとえばshコマンド経由でcatを呼び出してみましょう。

$ strace -e openat,read,execve,%process sh -c "cat /etc/lsb-release"
execve("/usr/bin/sh", ["sh", "-c", "cat /etc/lsb-release"], 0x7ffd05f72500 /* 82 vars */) = 0
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P\237\2\0\0\0\0\0"..., 832) = 832
vfork()                                 = 2871878
wait4(-1, DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=22.04
DISTRIB_CODENAME=jammy
DISTRIB_DESCRIPTION="Ubuntu 22.04.2 LTS"
[{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 2871878
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=2871878, si_uid=1000, si_status=0, si_utime=0, si_stime=0} ---
wait4(-1, 0x7ffe7b65f9ec, WNOHANG, NULL) = -1 ECHILD (子プロセスがありません)
exit_group(0)                           = ?
+++ exited with 0 +++

「/etc/lsb-release」を開いたり読んだりしている箇所が見つかりませんね。その代わり「vfork()」を呼び出して「wait4()」を実行しているようです。これはshコマンドが引数に渡したプログラムを実行し、その終了を待っている部分になります。

「-f」を付けると、プログラムから起動したプロセスも追跡してくれます。

$ strace -f -e openat,read,execve,%process sh -c "cat /etc/lsb-release"
execve("/usr/bin/sh", ["sh", "-c", "cat /etc/lsb-release"], 0x7fffd5dfea38 /* 82 vars */) = 0
（中略）
vfork(strace: Process 2873473 attached
 <unfinished ...>
[pid 2873473] execve("/usr/bin/cat", ["cat", "/etc/lsb-release"], 0x556212d323f8 /* 82 vars */ <unfinished ...>
（中略）
[pid 2873473] openat(AT_FDCWD, "/etc/lsb-release", O_RDONLY) = 3
[pid 2873473] read(3, "DISTRIB_ID=Ubuntu\nDISTRIB_RELEAS"..., 131072) = 104

今度はshコマンドだけでなく、そこから起動したcatコマンドも追跡してくれました。これはマルチスレッドなプログラムを検査したい場合にも有効です。

ちなみに「-Y」オプションを指定すると、PID（Process ID）に該当するプログラム名も付けて表示してくれます。複数のプログラムを動かすケースだとこちらのほうが読みやすいかもしれません。

$ strace -Y -ff -e openat,read,execve,%process sh -c "cat /etc/lsb-release"
execve("/usr/bin/sh", ["sh", "-c", "cat /etc/lsb-release"], 0x7fff3a037350 /* 82 vars */) = 0
（中略）
[pid 2876104<sh>] execve("/usr/bin/cat", ["cat", "/etc/lsb-release"], 0x55b1b8dcd3f8 /* 82 vars */ <unfinished ...>
（中略）
[pid 2876104<cat>] openat(AT_FDCWD, "/etc/lsb-release", O_RDONLY) = 3

「-o ファイル名」でファイルに出力する場合、「⁠-ff」と指定することでPIDごとに出力ファイルを変えてくれます。具体的には「元のファイル名.PID」のようなファイル名になります。

ファイル名、構造体や文字列の展開

「-yy」を指定するとファイルディスクリプターの横に、ファイル名を展開表示してくれます。

$ strace -yy -e openat,read cat /etc/lsb-release
（中略）
openat(AT_FDCWD</home/shibata>, "/etc/lsb-release", O_RDONLY) = 3</etc/lsb-release>
read(3</etc/lsb-release>, "DISTRIB_ID=Ubuntu\nDISTRIB_RELEAS"..., 131072) = 104

「-v」を指定すると構造体を展開表示してくれます。

$ strace -yy -v -e newfstatat cat /etc/lsb-release
（中略）
newfstatat(3</etc/lsb-release>, "", {st_dev=makedev(0x103, 0x2), st_ino=1840137, st_mode=S_IFREG|0644,
st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=8, st_size=104, st_atime=1683550922
/* 2023-05-08T22:02:02.942255967+0900 */, st_atime_nsec=942255967, st_mtime=1676563352
/* 2023-02-17T01:02:32+0900 */, st_mtime_nsec=0, st_ctime=1676700937 /* 2023-02-18T15:15:37.548645620+0900 */,
st_ctime_nsec=548645620}, AT_EMPTY_PATH) = 0

この「-v」は「-e abbrev=none」の省略形です。「⁠-e 'abbrev=!foo,bar'」などと指定することで、特定のシステムコールだけ展開する方法もあります。展開するシステムコールに「!」を付ける点に注意してください。

straceは自動で文字列を32文字までは展開してくれますが、この文字数は「-s 文字数」で変更可能です。また通常はASCII文字のうち表示可能な文字だけ表示し、残りは八進数表記となります。もし十六進数表記にしたければ「-x」オプションを付けてください。「⁠-xx」オプションにするとASCII文字も含めて十六進数表記になります。

通常の表示：八進数表記となる
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P\237\2\0\0\0\0\0"..., 832) = 832

「-x」付き：ASCII文字以外も含まれる文字列は十六進数表記となる
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\x7f\x45\x4c\x46\x02\x01\x01\x03\x00\x00\x00\x00\x00\x00\x00\x00\x03\x00\x3e\x00\x01\x00\x00\x00\x50\x9f\x02\x00\x00\x00\x00\x00"..., 832) = 832

「-xx」付き：ASCII文字が含まれるかどうかに関係なく十六進数表記となる
openat(AT_FDCWD, "\x2f\x6c\x69\x62\x2f\x78\x38\x36\x5f\x36\x34\x2d\x6c\x69\x6e\x75\x78\x2d\x67\x6e\x75\x2f\x6c\x69\x62\x63\x2e\x73\x6f\x2e\x36", O_RDONLY|O_CLOEXEC) = 3
read(3, "\x7f\x45\x4c\x46\x02\x01\x01\x03\x00\x00\x00\x00\x00\x00\x00\x00\x03\x00\x3e\x00\x01\x00\x00\x00\x50\x9f\x02\x00\x00\x00\x00\x00"..., 832) = 832

情報の表示オプションについてまとめると「strace -fvttTyyY -o ファイル名」というオプションを常に付けておけば、大抵の情報は手に入ります。

さらに工夫せるstrace

定番の表示オプション以外にも、組み合わせたり単体で使うと便利なオプションがいくつか存在します。

特定のファイル関連の処理のみ表示する

「-P ファイル」オプションを指定すると、特定のファイルに関連する処理だけ表示してくれます。

$ strace -P /etc/lsb-release cat /etc/lsb-release
openat(AT_FDCWD, "/etc/lsb-release", O_RDONLY) = 3
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=104, ...}, AT_EMPTY_PATH) = 0
fadvise64(3, 0, 0, POSIX_FADV_SEQUENTIAL) = 0
read(3, "DISTRIB_ID=Ubuntu\nDISTRIB_RELEAS"..., 131072) = 104
DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=22.04
DISTRIB_CODENAME=jammy
DISTRIB_DESCRIPTION="Ubuntu 22.04.2 LTS"
read(3, "", 131072)                     = 0
close(3)                                = 0
+++ exited with 0 +++

ここでは「-P」オプションで指定したファイルを開いたあと、そのファイルディスクリプターを使って呼び出すシステムコールも一緒に表示してくれているわけです。また、他のファイル関連システムコールやそれ以外のシステムコールは表示しません。特定のファイルに絞って追跡したい場合に便利です。

実行中のプロセスをチェックする

ここまではプログラムの起動時にstraceを実行する方法でした。「⁠-p」オプションを使用すると、実行中のプロセスに対してもstraceコマンドを実行できます。

$ strace -p <pid>,<pid>,...

複数のプロセスの指定が可能です。Ctrl-Cを入力することで、straceによる調査を終了します。

統計情報の表示

「-c」オプションを指定すると、各システムコールの呼び出し回数などの統計情報を表示してくれます。

$ strace -c cat /etc/lsb-release
DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=22.04
DISTRIB_CODENAME=jammy
DISTRIB_DESCRIPTION="Ubuntu 22.04.2 LTS"
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 20.46    0.000089           8        10           mmap
 16.78    0.000073          36         2           munmap
 11.72    0.000051          17         3           mprotect
  8.97    0.000039           6         6           close
  8.97    0.000039           9         4           openat
  6.90    0.000030           6         5           newfstatat
  5.29    0.000023           7         3           read
  4.60    0.000020          20         1           write
  4.14    0.000018           6         3           brk
  2.30    0.000010          10         1           getrandom
  1.84    0.000008           8         1           fadvise64
  1.84    0.000008           8         1           prlimit64
  1.61    0.000007           3         2         1 arch_prctl
  1.61    0.000007           7         1           set_robust_list
  1.61    0.000007           7         1           rseq
  1.38    0.000006           6         1           set_tid_address
  0.00    0.000000           0         4           pread64
  0.00    0.000000           0         1         1 access
  0.00    0.000000           0         1           execve
------ ----------- ----------- --------- --------- ----------------
100.00    0.000435           8        51         2 total

「-S ソート対象」とセットで実行すると、呼び出し回数が多いシステムコールや時間のかかっているシステムコールを見つけやすくなります。

システムコールよエラーになれ

straceはシステムコールを呼び出すポイントと戻るポイントに対して処理を行います。さらにこのポイントで指定した操作を行うことも可能です。その最たる例がエラーインジェクションでしょう。システムコールが戻るときにエラーを返すようにすることで、プログラムのテストでも難しいエラー系の処理を通すことができます。

システムコールをエラーにする

具体的な例を見ていきましょう。まず単純にこれまでの例でファイルを開いたときにエラーになるようにしてみます。「⁠-e fault=システムコール」と指定すると指定したシステムコールがエラー扱いになります。ファイルを開くのは今回のコマンドだとopenat()だったのでこれを指定します。

$ strace -e fault=openat cat /etc/lsb-release
execve("/usr/bin/cat", ["cat", "/etc/lsb-release"], 0x7fff744bfc88 /* 83 vars */) = 0
brk(NULL)                               = 0x564ef3b4d000
arch_prctl(0x3001 /* ARCH_??? */, 0x7ffc78c33370) = -1 EINVAL (無効な引数です)
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0b4cad9000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (そのようなファイルやディレクトリはありません)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = -1 ENOSYS (関数は実装されていません) (INJECTED)

実はopenat()はライブラリのロードでも使われているため、catコマンドの最初のほうでエラーになってしまいます。今回は「/etc/lsb-release」を開く時にエラーにしたいので、「⁠-P /etc/lsb-release」も追加してみましょう。

$ strace -P /etc/lsb-release -e fault=openat cat /etc/lsb-release
openat(AT_FDCWD, "/etc/lsb-release", O_RDONLY) = -1 ENOSYS (関数は実装されていません) (INJECTED)
cat: /etc/lsb-release: 関数は実装されていません
+++ exited with 1 +++

うまくエラーになりましたね。

エラー番号を変更する

先ほどまでのエラーは戻り値が「-1」ですが、エラー番号が「ENOSYS」になっています。これはfault指定のデフォルト値です。先ほどのオプションに続けて「error=エラー名」を指定することで、置き換えられます。

$ strace -P /etc/lsb-release -e fault=openat:error=EINVAL cat /etc/lsb-release
openat(AT_FDCWD, "/etc/lsb-release", O_RDONLY) = -1 EINVAL (無効な引数です) (INJECTED)
cat: /etc/lsb-release: 無効な引数です
+++ exited with 1 +++

エラー番号については、個々のシステムコールのmanページを見るとわかります。また、moreutilsパッケージのerrnoコマンドを使うと「errno -l」のようにシステムにインストールされているヘッダーファイルのエラー番号とそのメッセージの一覧が得られます。

エラーのタイミングを調整する

「when=N」を付けると、「⁠N番目のシステムコール呼び出し時のみ、エラーにする」ことが可能になります。次の例だと、4回同じファイルを表示していますが、このうち2回目のopenat()だけエラーになっています。

$ strace -P /etc/lsb-release -e openat -e fault=openat:error=EINVAL:when=2 cat /etc/lsb-release{,}{,} >/dev/null
openat(AT_FDCWD, "/etc/lsb-release", O_RDONLY) = 3
openat(AT_FDCWD, "/etc/lsb-release", O_RDONLY) = -1 EINVAL (無効な引数です) (INJECTED)
cat: /etc/lsb-release: 無効な引数です
openat(AT_FDCWD, "/etc/lsb-release", O_RDONLY) = 3
openat(AT_FDCWD, "/etc/lsb-release", O_RDONLY) = 3
+++ exited with 1 +++

この「when=」は「first[..last][+step]]」といったフォーマットを持っていて、より細かいエラー発生タイミングを調整できます。

  • when=M+：M回目以降をすべてエラーにする
  • when=M..N：M回目からN回目までをエラーにする
  • when=M+S：M回目からS回ごとにエラーにする（＝「M + S x n」回目をエラーにする）
  • when=M..N+S：M回目からN回目までのうち、M回目からS回ごとにエラーにする

システムコールの戻り値を置き換える

ここまで利用した「-e fault=」は「-e inject=」の省略形です。「⁠-e inject=」を使うとさらに詳細に設定できます。たとえば「retval=」で戻り値を任意の数字に変更できます。

$ strace -P /etc/lsb-release -e openat -e inject=openat:retval=-2 cat /etc/lsb-release
strace: Inadvertent injection of error 2 is possible for retval=18446744073709551614
openat(AT_FDCWD, "/etc/lsb-release", O_RDONLY) = -2 (INJECTED)
cat: /etc/lsb-release: そのようなファイルやディレクトリはありません
+++ exited with 1 +++

openat()の場合は、APIの使用上「-1」のみがエラー扱いであるため、実装によってはそれ以外の負の数は成功扱いになってしまう可能性があります。そのため1行目でstraceが警告を出しています。たとえば0や1にすると、標準入力や標準出力として、後ろの処理が動作します。

シグナルを発生させる

「signal=シグナル」を付けるとシグナルを発生させられます。

$ strace -P /etc/lsb-release -e openat -e inject=openat:signal=INT cat /etc/lsb-release
openat(AT_FDCWD, "/etc/lsb-release", O_RDONLY) = 3
--- SIGINT {si_signo=SIGINT, si_code=SI_KERNEL} ---
+++ killed by SIGINT +++

遅延時間を挿入する

「delay_entery=時間」や「delay_exit=時間」で、システムコールに入る時と抜ける時を遅延させることができます。下記の例だと、入る時に1秒、出る時に2秒の計3秒の遅延が発生しています。

$ strace -tt -P /etc/lsb-release -e openat -e inject=openat:delay_enter=1s:delay_exit=2s cat /etc/lsb-release >/dev/null
00:55:20.180126 openat(AT_FDCWD, "/etc/lsb-release", O_RDONLY) = 3 (DELAYED)
00:55:23.182622 +++ exited with 0 +++

時刻のサフィックスは「s（秒⁠）⁠」⁠「⁠ms（ミリ秒⁠）⁠」⁠「⁠us（マイクロ秒⁠）⁠」⁠「⁠ns（ナノ秒⁠）⁠」があります。未指定だとマイクロ秒です。

このように、straceのエラーインジェクション機能を使うと、様々なタイミングで任意のエラーを発生させられます。システムコールが想定外のエラーを返した時にソフトウェア様がへそを曲げてしまわないためにも、きちんとエラー処理を書いておいて、テストすることを心がけましょう。

おすすめ記事

記事・ニュース一覧