Linuxでのstraceコマンドの使い方まとめ

船井総研デジタルのよもぎたです。

[株式会社船井総研デジタル Advent Calendar 2022](https://qiita.com/advent-calendar/2022/fsdg)もよろしくお願いします。

# サマリ
いま、[「［試して理解］Linuxのしくみ ―実験と図解で学ぶOS、仮想マシン、コンテナの基礎知識【増補改訂版】」](https://gihyo.jp/book/2022/978-4-297-13148-7)という本を読んでいます。その第1章で取り上げられる``strace``コマンドについてもっと知りたいと思い、自分なりに使い方をまとめたのでシェアします。

``strace``コマンドは、トレース対象のプログラムが発行するシステムコールと受信したシグナルを出力するコマンドです。

# 前提条件
今回の記事は、Ubuntu 22.04.1 LTS上で検証しています。

```bash
$ cat /etc/os-release
PRETTY_NAME="Ubuntu 22.04.1 LTS"
NAME="Ubuntu"
VERSION_ID="22.04"
VERSION="22.04.1 LTS (Jammy Jellyfish)"
VERSION_CODENAME=jammy
ID=ubuntu
ID_LIKE=debian
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
UBUNTU_CODENAME=jammy
```

``uname``コマンドの結果は次の通りです。
```bash
$ uname -srvmpio
Linux 5.15.0-56-generic #62-Ubuntu SMP Tue Nov 22 19:54:14 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
```

``strace``コマンドのVersionは``5.16``です。
```bash
$ /usr/bin/strace --version
strace -- version 5.16
Copyright (c) 1991-2022 The strace developers <https://strace.io>.
This is free software; see the source for copying conditions.  There is NO
warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.

Optional features enabled: stack-trace=libunwind stack-demangle m32-mpers mx32-mpers
```

# manを眺めてみる

``man``コマンドで``strace``コマンドのオプションを調べてみます。かなりの数のオプションがあります。まとめは大変そうです。オプションの説明は、``General``、``Startup``等、用途ごとにまとめられているのが救いです。

```bash
$ man -S1 strace | head -16
STRACE(1)                   General Commands Manual                  STRACE(1)

NAME
       strace - trace system calls and signals

SYNOPSIS
       strace [-ACdffhikqqrtttTvVwxxyyzZ] [-I n] [-b execve] [-e expr]...
              [-O overhead] [-S sortby] [-U columns] [-a column] [-o file]
              [-s strsize] [-X format] [-P path]... [-p pid]...
              [--seccomp-bpf] { -p pid | [-DDD] [-E var[=val]]...
              [-u username] command [args] }

       strace -c [-dfwzZ] [-I n] [-b execve] [-e expr]... [-O overhead]
              [-S sortby] [-U columns] [-P path]... [-p pid]...
              [--seccomp-bpf] { -p pid | [-DDD] [-E var[=val]]...
              [-u username] command [args] }
```

# テスト用プログラムの準備
テスト用のプログラムをいくつか用意しました。

## テスト用プログラム１
何もせずに戻り値0を返すだけのプログラムです。
```C
int main(){
        return 0;
}
```
コンパイルして実行してみます。
```bash
$ gcc -o ret0 ret0.c
$ ./ret0
$ echo $?
0
$
```
なにも出力がありませんが、戻り値``0``が返されていることが分かります。

## テスト用プログラム２
定番のHello world.です。
```C
#include <stdio.h>

void main(){
        printf("Hello world.\n");
}
```

## テスト用プログラム３
``fork()``してPIDを出力するプログラムです。
```C
#include <unistd.h>
#include <stdio.h>

int main(){

        int pid;

        pid=fork();
        printf("%d\n",pid);
        return pid;

}
```
コンパイルして実行してみます。
```bash
$ ./fork_example
5686
0
```
子プロセスのPIDと0が出力されます。

# 実際に``strace``を実行してみる
一番簡単な``strace``コマンドの使い方は、何もオプションを付けずに``strace <command>``と実行することです。そこで、上記のテスト用プログラムを実行してみます。

```bash
$ strace ./ret0
execve("./ret0", ["./ret0"], 0x7ffc272ce2c0 /* 24 vars */) = 0
brk(NULL)                               = 0x55a31009d000
arch_prctl(0x3001 /* ARCH_??? */, 0x7ffd785cbae0) = -1 EINVAL (Invalid argument)
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0063a67000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=36015, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 36015, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f0063a5e000
close(3)                                = 0
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
pread64(3, "\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"..., 784, 64) = 784
pread64(3, "\4\0\0\0 \0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0"..., 48, 848) = 48
pread64(3, "\4\0\0\0\24\0\0\0\3\0\0\0GNU\0i8\235HZ\227\223\333\350s\360\352,\223\340."..., 68, 896) = 68
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=2216304, ...}, AT_EMPTY_PATH) = 0
pread64(3, "\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"..., 784, 64) = 784
mmap(NULL, 2260560, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f0063836000
mmap(0x7f006385e000, 1658880, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x28000) = 0x7f006385e000
mmap(0x7f00639f3000, 360448, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1bd000) = 0x7f00639f3000
mmap(0x7f0063a4b000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x214000) = 0x7f0063a4b000
mmap(0x7f0063a51000, 52816, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f0063a51000
close(3)                                = 0
mmap(NULL, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0063833000
arch_prctl(ARCH_SET_FS, 0x7f0063833740) = 0
set_tid_address(0x7f0063833a10)         = 1839
set_robust_list(0x7f0063833a20, 24)     = 0
rseq(0x7f00638340e0, 0x20, 0, 0x53053053) = 0
mprotect(0x7f0063a4b000, 16384, PROT_READ) = 0
mprotect(0x55a30edd6000, 4096, PROT_READ) = 0
mprotect(0x7f0063aa1000, 8192, PROT_READ) = 0
prlimit64(0, RLIMIT_STACK, NULL, {rlim_cur=8192*1024, rlim_max=RLIM64_INFINITY}) = 0
munmap(0x7f0063a5e000, 36015)           = 0
exit_group(0)                           = ?
+++ exited with 0 +++
```

``0``を返すだけのプログラムでも、これだけのシステムコールが発行されていることが分かります。多いですね。これには、シェルがプログラムを実行したり、リンクされているライブラリを読み込んだりといった処理のためのシステムコールも含まれているためです。

``helloworld``も実行してみます。
```bash
$ strace ./helloworld
---snip---
write(1, "Hello world.\n", 13Hello world.
)          = 13
exit_group(13)                          = ?
+++ exited with 13 +++
```

``write``システムコールの後に、``./hellowrold``が出力した文字列が出力されています。そこで、``>/dev/null``を付けて実行してみます。
```bash
$ strace ./helloworld >/dev/null
---snip---
write(1, "Hello world.\n", 13)          = 13
exit_group(13)                          = ?
+++ exited with 13 +++
```
今度は、``./helloworld``が出力する文字列が``/dev/null``にリダイレクトされて、``strace``コマンドの結果だけが出力されました。

ここで一つ想定されることは、``strace``コマンドの出力は標準エラー出力に出力されているのではないか、ということです。そこで、``man``を``stderr``で検索したところ、次のような記載が見つかりました。

```bash
$ man strace
       -o filename
       --output=filename
                   Write the trace output to the file filename rather than to stderr.
```
というわけで、やはり``strace``の出力は標準エラー出力に出力されていました。

実際、標準エラー出力を``/dev/null``にリダイレクトすると、次のようになります。
```bash
$ strace ./helloworld 2>/dev/null
Hello world.
$
```

# ``strace``コマンドの使い方まとめ
ようやくというか、いよいよ本題です。

## ``strace``の出力をファイルに記録する
``-o <filename>``オプションで、``strace``の出力をファイルに記録することができます。追跡対象のプロセスが標準エラー出力にも出力する場合に便利です。

```bash
$ strace -o strace_ret0.log ./ret0
$ head -3 strace_ret0.log
execve("./ret0", ["./ret0"], 0x7ffca8217860 /* 24 vars */) = 0
brk(NULL)                               = 0x55fbcd2c4000
arch_prctl(0x3001 /* ARCH_??? */, 0x7ffea0340340) = -1 EINVAL (Invalid argument)
```

## 特定のシステムコールだけ追跡する

### 指定したシステムコールだけ追跡する
``-e <systemcall>``オプションで、指定したシステムコールだけ追跡することができます。

```bash
$ strace -e write ./helloworld >/dev/null
write(1, "Hello world.\n", 13)          = 13
+++ exited with 13 +++
$
```

### 複数の指定したシステムコールだけ追跡する
``-e <systemcall1>,<systemcall2>...``とすることで、複数のシステムコールを追跡するすることもできます。
```bash
$ strace -e write,execve ./helloworld >/dev/null
execve("./helloworld", ["./helloworld"], 0x7ffc227df340 /* 24 vars */) = 0
write(1, "Hello world.\n", 13)          = 13
+++ exited with 13 +++
$
```

### 特定のファイルにアクセスするシステムコールだけ追跡する

``-P </path/to/file>`` オプションで、特定のファイルにアクセスするシステムコールだけ追跡することができます。
```bash
$ strace -P /etc/passwd cat /etc/passwd >/dev/null
openat(AT_FDCWD, "/etc/passwd", O_RDONLY) = 3
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=2138, ...}, AT_EMPTY_PATH) = 0
fadvise64(3, 0, 0, POSIX_FADV_SEQUENTIAL) = 0
read(3, "root:x:0:0:root:/root:/bin/bash\n"..., 131072) = 2138
read(3, "", 131072)                     = 0
close(3)                                = 0
+++ exited with 0 +++
```

### ファイルにアクセスするシステムコールだけ追跡する
``-e trace=%file``オプションで、ファイルにアクセスするシステムコールだけ追跡することができます。
```bash
$ strace -e trace=%file cat ./ret0.c >/dev/null
execve("/usr/bin/cat", ["cat", "./ret0.c"], 0x7fff6d3abb58 /* 24 vars */) = 0
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=36015, ...}, AT_EMPTY_PATH) = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=2216304, ...}, AT_EMPTY_PATH) = 0
newfstatat(1, "", {st_mode=S_IFCHR|0666, st_rdev=makedev(0x1, 0x3), ...}, AT_EMPTY_PATH) = 0
openat(AT_FDCWD, "./ret0.c", O_RDONLY)  = 3
newfstatat(3, "", {st_mode=S_IFREG|0664, st_size=25, ...}, AT_EMPTY_PATH) = 0
+++ exited with 0 +++
```

### ネットワークに関するシステムコールだけ追跡する
``-e trace=%net``オプションで、ネットワークに関するシステムコールだけ追跡することができます。
```bash
$ strace -e trace=%net ping -c 1 8.8.8.8 >/dev/null
socket(AF_INET, SOCK_DGRAM, IPPROTO_ICMP) = 3
socket(AF_INET6, SOCK_DGRAM, IPPROTO_ICMPV6) = 4
socket(AF_INET, SOCK_DGRAM, IPPROTO_IP) = 5
connect(5, {sa_family=AF_INET, sin_port=htons(1025), sin_addr=inet_addr("8.8.8.8")}, 16) = 0
getsockname(5, {sa_family=AF_INET, sin_port=htons(54235), sin_addr=inet_addr("192.168.7.11")}, [16]) = 0
setsockopt(3, SOL_IP, IP_RECVERR, [1], 4) = 0
setsockopt(3, SOL_IP, IP_RECVTTL, [1], 4) = 0
setsockopt(3, SOL_IP, IP_RETOPTS, [1], 4) = 0
setsockopt(3, SOL_SOCKET, SO_SNDBUF, [324], 4) = 0
setsockopt(3, SOL_SOCKET, SO_RCVBUF, [65536], 4) = 0
getsockopt(3, SOL_SOCKET, SO_RCVBUF, [131072], [4]) = 0
setsockopt(3, SOL_SOCKET, SO_TIMESTAMP_OLD, [1], 4) = 0
setsockopt(3, SOL_SOCKET, SO_SNDTIMEO_OLD, "\1\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 16) = 0
setsockopt(3, SOL_SOCKET, SO_RCVTIMEO_OLD, "\1\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 16) = 0
sendto(3, "\10\0\250\244\0\0\0\1\213t\244c\0\0\0\0T\257\f\0\0\0\0\0\20\21\22\23\24\25\26\27"..., 64, 0, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("8.8.8.8")}, 16) = 64
recvmsg(3, {msg_name={sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("8.8.8.8")}, msg_namelen=128 => 16, msg_iov=[{iov_base="\0\0\260\237\0\5\0\1\213t\244c\0\0\0\0T\257\f\0\0\0\0\0\20\21\22\23\24\25\26\27"..., iov_len=192}], msg_iovlen=1, msg_control=[{cmsg_len=32, cmsg_level=SOL_SOCKET, cmsg_type=SO_TIMESTAMP_OLD, cmsg_data={tv_sec=1671722123, tv_usec=901628}}, {cmsg_len=20, cmsg_level=SOL_IP, cmsg_type=IP_TTL, cmsg_data=[109]}], msg_controllen=56, msg_flags=0}, 0) = 64
+++ exited with 0 +++
```

### ファイルデスクリプタに関するシステムコールだけ追跡する
``-e trace=%desc``とすることで、ファイルデスクリプタに関するシステムコールだけ追跡することができます。
```bash
$ strace -e trace=%desc ./helloworld >/dev/null
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f89d2f18000
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=36015, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 36015, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f89d2f0f000
close(3)                                = 0
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
pread64(3, "\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"..., 784, 64) = 784
pread64(3, "\4\0\0\0 \0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0"..., 48, 848) = 48
pread64(3, "\4\0\0\0\24\0\0\0\3\0\0\0GNU\0i8\235HZ\227\223\333\350s\360\352,\223\340."..., 68, 896) = 68
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=2216304, ...}, AT_EMPTY_PATH) = 0
pread64(3, "\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"..., 784, 64) = 784
mmap(NULL, 2260560, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f89d2ce7000
mmap(0x7f89d2d0f000, 1658880, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x28000) = 0x7f89d2d0f000
mmap(0x7f89d2ea4000, 360448, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1bd000) = 0x7f89d2ea4000
mmap(0x7f89d2efc000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x214000) = 0x7f89d2efc000
mmap(0x7f89d2f02000, 52816, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f89d2f02000
close(3)                                = 0
mmap(NULL, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f89d2ce4000
newfstatat(1, "", {st_mode=S_IFCHR|0666, st_rdev=makedev(0x1, 0x3), ...}, AT_EMPTY_PATH) = 0
ioctl(1, TCGETS, 0x7fff8915ae60)        = -1 ENOTTY (Inappropriate ioctl for device)
write(1, "Hello world.\n", 13)          = 13
+++ exited with 13 +++
```

## ユーザーを指定して実行したコマンドのシステムコールを追跡する

この操作は、root権限が必要です。
```bash
$ strace -u nobody ./ret0
strace: You must be root to use the -u/--username option
```

まず``-u``オプション無しで``id``コマンドを実行します。
```bash
$ strace id -u 2>/dev/null
1000
```
当たり前の結果が返ってきました。

つづいて、``-u``オプションを指定して``id``コマンドを実行します。
```bash
$ sudo strace -u root id -u 2>/dev/null
0
```
``id``コマンドがrootユーザで実行されたことが分かります。

## 実行中のプロセスのシステムコールを追跡する

``-p <PID>``オプションで、実行中のプロセスのシステムコールを追跡できます。

この操作を実行するには、カーネルパラメータ``kernel.yama.ptrace_scope``が関係してきます。
この値が``0``の場合、自分の権限で実行中のプロセスのシステムコールを追跡できます。今回の環境ではこの値は1で、``/etc/sysctl.d/10-ptrace.conf``にセキュリティ上の配慮である旨が記載されていました。
root権限で``strace``を実行すると、このパラメータの値に関係なく実行中のプロセスのシステムコールを追跡できます。

今回はroot権限で``strace``を実行した例をご確認ください。

```bash
$ sleep 16 &
[1] 5458
$ sudo strace -p 5458
strace: Process 5458 attached
restart_syscall(<... resuming interrupted read ...>) = 0
close(1)                                = 0
close(2)                                = 0
exit_group(0)                           = ?
+++ exited with 0 +++
[1]+  Done                    sleep 16
```
## 環境変数を操作してコマンドを実行してシステムコールを追跡する

-E オプションを使うことで、一時的に環境変数を設定してコマンドを実行させたり、逆に設定されている環境変数を無視してコマンドを実行させることができます。

一時的に環境変数を設定してコマンドを実行するには``-E env=val``オプションを指定して``strace``コマンドを実行します。
```bash
$ env | grep TODAY
$
$ strace -E TODAY="2022/12/25" env 2>/dev/null | grep TODAY
TODAY=2022/12/25
$
```


設定されている環境変数を無視してコマンドを実行するには、``-E env``オプションを指定して``strace``コマンドを実行します。
```bash
$ export TODAY="2022/12/25"
$ env | grep TODAY
TODAY=2022/12/25
$ strace -E TODAY env 2>/dev/null | grep TODAY
$
```

## ``fork``した子プロセスのシステムコールも追跡する

テスト用プログラム３の出番です。

まず、何もオプションを付けないで実行すると、親プロセスのシステムコールだけ追跡されることが分かります。
```bash
$ strace -e write ./fork_example >/dev/null
write(1, "5724\n", 5)                   = 5
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=5724, si_uid=1000, si_status=0, si_utime=0, si_stime=0} ---
+++ exited with 92 +++
```

``-f``オプションを付けて``strace``コマンドを実行すると、fork()した子プロセスのシステムコールも追跡できます。
```bash
$ strace -f -e write ./fork_example >/dev/null
strace: Process 5729 attached
[pid  5728] write(1, "5729\n", 5)       = 5
[pid  5728] +++ exited with 97 +++
write(1, "0\n", 2)                      = 2
+++ exited with 0 +++
```

## 成功/失敗したシステムコールだけ追跡する

``-z``オプションで、成功したシステムコールだけ追跡することができます。

``-Z``オプションで、失敗した（＝エラーコードで終了した）システムコールだけ追跡することができます。

```bash
$ strace -Z -o strace_cat_nosuchfile.log cat /no/such/file
cat: /no/such/file: No such file or directory
$ cat ./strace_cat_nosuchfile.log
arch_prctl(0x3001 /* ARCH_??? */, 0x7fff00a44e20) = -1 EINVAL (Invalid argument)
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/no/such/file", O_RDONLY) = -1 ENOENT (No such file or directory)
+++ exited with 1 +++
```

## タイムスタンプ付きでシステムコールを追跡する

``-t``、``-tt``、``-ttt``の各オプションで、各システムコールが開始されたタイムスタンプを出力させることができます。

```bash
$ strace -t ./ret0 2>&1 | head -5
00:00:00 execve("./ret0", ["./ret0"], 0x7ffce1adfc18 /* 24 vars */) = 0
00:00:00 brk(NULL)                      = 0x5651a3829000
00:00:00 arch_prctl(0x3001 /* ARCH_??? */, 0x7fff584f79e0) = -1 EINVAL (Invalid argument)
00:00:00 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fedede20000
00:00:00 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
$
$ strace -tt ./ret0 2>&1 | head -5
00:00:00.965791 execve("./ret0", ["./ret0"], 0x7fff50139f28 /* 24 vars */) = 0
00:00:00.966937 brk(NULL)               = 0x5604b0cec000
00:00:00.967106 arch_prctl(0x3001 /* ARCH_??? */, 0x7ffc31001a10) = -1 EINVAL (Invalid argument)
00:00:00.967493 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f072ecab000
00:00:00.967585 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
$
$ strace -ttt ./ret0 2>&1 | head -5
1671926400.778421 execve("./ret0", ["./ret0"], 0x7ffdeaadd978 /* 24 vars */) = 0
1671926400.779446 brk(NULL)             = 0x55ecb7a8a000
1671926400.779641 arch_prctl(0x3001 /* ARCH_??? */, 0x7ffdd2e44080) = -1 EINVAL (Invalid argument)
1671926400.780112 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f31785f7000
1671926400.780255 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
```

## 統計情報を表示する
``-c``オプションで統計を、``-C``オプションで通常の出力と統計を表示できます。

```bash
$ strace -c tar xf ./httpd-2.4.54.tar.bz2
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 39.59    0.074551          10      7097           write
 24.24    0.045639          14      3158        12 openat
 17.46    0.032885           3      8985           read
  6.40    0.012044       12044         1           wait4
  5.66    0.010661           3      3257           utimensat
  4.11    0.007733           2      3159           close
  1.95    0.003678          25       142           mkdirat
  0.19    0.000367          13        27           mmap
  0.07    0.000127          14         9           mprotect
  0.07    0.000125           4        29           newfstatat
  0.03    0.000062          62         1           clone
  0.03    0.000060          10         6         4 connect
  0.02    0.000042           7         6           socket
  0.02    0.000041          13         3           munmap
  0.02    0.000034           3        11           epoll_ctl
  0.02    0.000033          16         2         2 statfs
  0.02    0.000030           7         4           pread64
  0.01    0.000025          12         2         2 access
  0.01    0.000021           5         4           brk
  0.01    0.000018           2         8           epoll_wait
  0.01    0.000011           5         2           sendto
  0.00    0.000009           4         2           recvfrom
  0.00    0.000009           9         1           getrandom
  0.00    0.000008           8         1           prlimit64
  0.00    0.000007           3         2         1 arch_prctl
  0.00    0.000007           3         2           getdents64
  0.00    0.000007           3         2           timerfd_create
  0.00    0.000006           2         3           fcntl
  0.00    0.000006           6         1           set_tid_address
  0.00    0.000006           6         1           set_robust_list
  0.00    0.000006           6         1           pipe2
  0.00    0.000006           6         1           rseq
  0.00    0.000005           2         2           lseek
  0.00    0.000005           2         2           rt_sigprocmask
  0.00    0.000005           2         2           futex
  0.00    0.000005           5         1           epoll_create1
  0.00    0.000004           2         2           umask
  0.00    0.000004           4         1           readlinkat
  0.00    0.000003           3         1           rt_sigaction
  0.00    0.000003           3         1           timerfd_settime
  0.00    0.000002           2         1           getpid
  0.00    0.000002           2         1           geteuid
  0.00    0.000001           1         1           gettid
  0.00    0.000000           0         1           execve
------ ----------- ----------- --------- --------- ----------------
100.00    0.188303           7     25946        21 total
```

# まとめ
それなりのボリュームになってしまったので、ここで一段落とさせてください。ご紹介したオプションにも、さらに細かい指定ができるものが多くあります。アタッチしたプロセスにシステムコールをインジェクションする機能もあるのですが、そちらには全く手が回りませんでした。うまく使いこなせるようになって、ご紹介できればと思います。

最後までお読みいただきありがとうございました。