Come tracciare l'esecuzione del programma utilizzando il comando Strace di Linux

Lo strace è un potente strumento da riga di comando per il monitoraggio dei processi, la diagnostica e i programmi di risoluzione dei problemi in Linux. Generalmente viene utilizzato per intercettare e registrare le chiamate di sistema ei segnali ricevuti da un processo. Puoi utilizzare strace per analizzare come un programma interagisce con il sistema per eseguire il debug di qualsiasi programma.

Questo strumento è molto utile se il programma si blocca continuamente o non si comporta come previsto. Fornisce una visione approfondita del funzionamento del sistema. Qualsiasi utente può tracciare i propri processi in esecuzione.

In questo tutorial, ti mostreremo come utilizzare lo strumento da riga di comando strace su Linux.

Installa Strace

Per impostazione predefinita, strace è disponibile nel repository predefinito di tutti i sistemi operativi Linux.

Sui sistemi operativi Debian e Ubuntu, installa lo strace con il seguente comando:

apt-get install strace -y

Sui sistemi operativi RHEL e CentOS, installa lo strace con il seguente comando:

dnf install strace -y

Dopo aver installato strace, puoi verificare la versione di strace utilizzando il seguente comando:

strace -V

Dovresti ottenere il seguente output:

strace -- version 4.8

Puoi stampare tutte le opzioni disponibili con il comando strace con il seguente comando:

strace -help

Output
usage: strace [-CdffhiqrtttTvVxxy] [-I n] [-e expr]...
              [-a column] [-o file] [-s strsize] [-P path]...
              -p pid... / [-D] [-E var=val]... [-u username] PROG [ARGS]
   or: strace -c[df] [-I n] [-e expr]... [-O overhead] [-S sortby]
              -p pid... / [-D] [-E var=val]... [-u username] PROG [ARGS]
-c -- count time, calls, and errors for each syscall and report summary
-C -- like -c but also print regular output
-d -- enable debug output to stderr
-D -- run tracer process as a detached grandchild, not as parent
-f -- follow forks, -ff -- with output into separate files
-i -- print instruction pointer at time of syscall
-q -- suppress messages about attaching, detaching, etc.
-r -- print relative timestamp, -t -- absolute timestamp, -tt -- with usecs
-T -- print time spent in each syscall
-v -- verbose mode: print unabbreviated argv, stat, termios, etc. args
-x -- print non-ascii strings in hex, -xx -- print all strings in hex
-y -- print paths associated with file descriptor arguments
-h -- print help message, -V -- print version
-a column -- alignment COLUMN for printing syscall results (default 40)
-b execve -- detach on this syscall
-e expr -- a qualifying expression: option=[!]all or option=[!]val1[,val2]...
   options: trace, abbrev, verbose, raw, signal, read, write
-I interruptible --
   1: no signals are blocked
   2: fatal signals are blocked while decoding syscall (default)
   3: fatal signals are always blocked (default if '-o FILE PROG')
   4: fatal signals and SIGTSTP (^Z) are always blocked
      (useful to make 'strace -o FILE PROG' not stop on ^Z)
-o file -- send trace output to FILE instead of stderr
-O overhead -- set overhead for tracing syscalls to OVERHEAD usecs
-p pid -- trace process with process id PID, may be repeated
-s strsize -- limit length of print strings to STRSIZE chars (default 32)
-S sortby -- sort syscall counts by: time, calls, name, nothing (default time)
-u username -- run command as username handling setuid and/or setgid
-E var=val -- put var=val in the environment for command
-E var -- remove var from the environment for command
-P path -- trace accesses to path

1. Traccia una chiamata di sistema

Se vuoi tracciare le chiamate di sistema del comando ls, esegui il comando seguente:

strace ls file1.txt

Output
execve("/bin/ls", ["ls", "file1.txt"], [/* 61 vars */]) = 0
brk(0)                                  = 0x1f2a000
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f4dd0d30000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=114633, ...}) = 0
mmap(NULL, 114633, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f4dd0d14000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libselinux.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0[\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=134296, ...}) = 0
mmap(NULL, 2238192, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f4dd08ed000
mprotect(0x7f4dd090d000, 2093056, PROT_NONE) = 0
mmap(0x7f4dd0b0c000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1f000) = 0x7f4dd0b0c000
mmap(0x7f4dd0b0e000, 5872, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f4dd0b0e000
NLY|O_CLOEXEC) = 3
MAP_DENYWRITE, 3, 0x2000) = 0x7f4dd00e0000
close(3)                                = 0
.......
.......
)             = 10
close(1)                                = 0
munmap(0x7f4dd0d2f000, 4096)            = 0
close(2)                                = 0
exit_group(0)                           = ?
+++ exited with 0 +++

Nell'output sopra, puoi vedere la chiamata di sistema e il risultato del comando call of ls. Dovresti anche vedere che lo stato di uscita è 0. Ciò significa che non si è verificato alcun errore.

Un uso di strace (tranne il debug di alcuni problemi) è che puoi scoprire quali file di configurazione vengono letti da un programma.

Ad esempio:

strace php 2>&1 | grep php.ini

2. Filtra chiamate di sistema specifiche

Per impostazione predefinita, strace visualizza tutte le chiamate di sistema per l'eseguibile specificato. Se desideri visualizzare solo una specifica chiamata di sistema, puoi utilizzare l'opzione strace -e.

Ad esempio, per visualizzare solo la chiamata di sistema di scrittura del comando ls, eseguire il comando seguente:

strace -e write ls file1.txt file2.txt

Output
write(1, "file1.txt  file2.txt\n", 21file1.txt  file2.txt
)  = 21
+++ exited with 0 +++

Per visualizzare solo la chiamata di sistema aperta del comando ls, eseguire il comando seguente:

strace -e open ls file1.txt file2.txt

Output
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
open("/lib/x86_64-linux-gnu/libselinux.so.1", O_RDONLY|O_CLOEXEC) = 3
open("/lib/x86_64-linux-gnu/libacl.so.1", O_RDONLY|O_CLOEXEC) = 3
open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
open("/lib/x86_64-linux-gnu/libpcre.so.3", O_RDONLY|O_CLOEXEC) = 3
open("/lib/x86_64-linux-gnu/libdl.so.2", O_RDONLY|O_CLOEXEC) = 3
open("/lib/x86_64-linux-gnu/libattr.so.1", O_RDONLY|O_CLOEXEC) = 3
open("/proc/filesystems", O_RDONLY)     = 3
open("/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3
file1.txt  file2.txt
+++ exited with 0 +++

Se desideri visualizzare i file aperti da un processo specifico come SSH, esegui il comando seguente:

strace -f -e open /usr/sbin/sshd 2>&1 | grep ssh

Output
open("/etc/ssh/sshd_config", O_RDONLY)  = 3
open("/etc/ssh/ssh_host_rsa_key", O_RDONLY) = -1 EACCES (Permission denied)
open("/etc/ssh/ssh_host_rsa_key", O_RDONLY) = -1 EACCES (Permission denied)
open("/etc/ssh/ssh_host_ecdsa_key.pub", O_RDONLY) = 3
Could not load host key: /etc/ssh/ssh_host_ecdsa_key
open("/etc/ssh/ssh_host_ed25519_key.pub", O_RDONLY) = 3
Could not load host key: /etc/ssh/ssh_host_ed25519_key

Per tracciare le chiamate di sistema relative alla rete, esegui il comando seguente:

strace -e network nc -v -n 127.0.0.1 80

Output
socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
connect(3, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
connect(3, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
connect(3, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 EINPROGRESS (Operation now in progress)
getsockopt(3, SOL_SOCKET, SO_ERROR, [0], [4]) = 0
Connection to 127.0.0.1 80 port [tcp/*] succeeded!

3. Allega al processo già in esecuzione

Se un processo è già in esecuzione, puoi tracciarlo utilizzando il suo PID come mostrato di seguito:

strace -p 5315

Output
Process 5315 attached
restart_syscall(<... resuming interrupted call ...>) = -1 ETIMEDOUT (Connection timed out)
futex(0x7ffdc25fd048, FUTEX_WAKE_PRIVATE, 1) = 0
lseek(31, 0, SEEK_SET)                  = 0
read(31, "1185755 22902 18214 39954 0 1079"..., 4095) = 38
lseek(32, 0, SEEK_SET)                  = 0
read(32, "Name:\tchrome\nState:\tR (running)\n"..., 4095) = 1020
futex(0x7ffdc25fd074, FUTEX_WAIT_BITSET_PRIVATE, 1, {3799, 9175}, ffffffff) = -1 ETIMEDOUT (Connection timed out)
futex(0x7ffdc25fd048, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x7ffdc25fd074, FUTEX_WAIT_BITSET_PRIVATE, 1, {3802, 10202}, ffffffff^CProcess 5315 detached

Questo comando mostrerà continuamente le chiamate di sistema effettuate dal processo. Puoi premere CTRL+C per interromperlo.

dove:

5315 è un ID processo del processo in esecuzione.

4. Reindirizza l'output di traccia su un file

Puoi usare -o flag con il comando strace per salvare l'output di strace nel file specificato.

strace -o file_out.txt ls file1.txt

È ora possibile visualizzare il contenuto del file file_out.txt con il seguente comando:

cat file_out.txt

5. Stampa il tempo speso per le chiamate di sistema

Per stampare il timestamp relativo di ogni chiamata, usa il flag -r come mostrato di seguito.

strace -r ls file1.txt

Output
     0.000000 execve("/bin/ls", ["ls", "file1.txt"], [/* 61 vars */]) = 0
     0.000947 brk(0)                    = 0xaf3000
     0.000450 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
     0.000706 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f01b1ccb000
     0.000319 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
     0.000093 close(1)                  = 0
     0.000069 munmap(0x7f01b1cca000, 4096) = 0
     0.000078 close(2)                  = 0
     0.000104 exit_group(0)             = ?
     0.000184 +++ exited with 0 +++

Per visualizzare la differenza di tempo tra l'inizio e la fine di ogni chiamata di sistema effettuata dal comando ls, utilizzare l'opzione -T.

strace -T ls file1.txt

Output
execve("/bin/ls", ["ls", "file1.txt"], [/* 61 vars */]) = 0 <0.000908>
brk(0)                                  = 0x1d72000 <0.000050>
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory) <0.000066>
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fc895610000 <0.000059>
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory) <0.000060>
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 <0.000072>
fstat(3, {st_mode=S_IFREG|0644, st_size=114633, ...}) = 0 <0.000052>
mmap(NULL, 114633, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fc8955f4000 <0.000062>
close(3)                                = 0 <0.000050>
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory) <0.000059>
open("/lib/x86_64-linux-gnu/libselinux.so.1", O_RDONLY|O_CLOEXEC) = 3 <0.000068>
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0[\0\0\0\0\0\0"..., 832) = 832 <0.000057>
fstat(3, {st_mode=S_IFREG|0644, st_size=134296, ...}) = 0 <0.000052>
mmap(NULL, 2238192, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fc8951cd000 <0.000064>
mprotect(0x7fc8951ed000, 2093056, PROT_NONE) = 0 <0.000085>
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fc89560f000 <0.000026>
write(1, "file1.txt\n", 10file1.txt
)             = 10 <0.000029>
close(1)                                = 0 <0.000021>
munmap(0x7fc89560f000, 4096)            = 0 <0.000029>
close(2)                                = 0 <0.000022>
exit_group(0)                           = ?
+++ exited with 0 +++

Per stampare l'ora dell'orologio da parete di ogni chiamata di sistema, eseguire il comando seguente:

strace -t ls file1.txt

Output
10:58:25 execve("/bin/ls", ["ls", "file1.txt"], [/* 61 vars */]) = 0
10:58:25 brk(0)                         = 0xc30000
10:58:25 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
10:58:25 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fd4db396000
10:58:25 write(1, "file1.txt\n", 10file1.txt
)    = 10
10:58:25 close(1)                       = 0
10:58:25 exit_group(0)                  = ?
10:58:25 +++ exited with 0 +++

L'opzione -tt mostra il timestamp seguito da microsecondi.

strace -tt ls file1.txt

6. Visualizza il puntatore di istruzioni della chiamata di sistema

Puoi usare -i flag con il comando strace per stampare il puntatore all'istruzione al momento di ogni chiamata di sistema effettuata dal comando:

strace -i ls file1.txt

Output
[00007efd8cfeb337] execve("/bin/ls", ["ls", "file1.txt"], [/* 61 vars */]) = 0
[00007f5ab611e18c] brk(0)               = 0x239e000
[00007f5ab611f537] access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
[00007f5ab611f65a] mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5ab6326000
[00007f5ab5a01870] write(1, "file1.txt\n", 10file1.txt
) = 10
[00007f5ab5a01f60] close(1)             = 0
[00007f5ab5a0a9f7] munmap(0x7f5ab6325000, 4096) = 0
[00007f5ab5a01f60] close(2)             = 0
[00007f5ab59d7309] exit_group(0)        = ?
[????????????????] +++ exited with 0 +++

7. Genera un rapporto sulle chiamate di sistema

Puoi utilizzare il flag -c per ottenere il report statistico utile per la traccia di esecuzione.

strace -c ls /var/www/html

Output
index.html
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
  0.00    0.000000           0         8           read
  0.00    0.000000           0         1           write
  0.00    0.000000           0         9           open
  0.00    0.000000           0        12           close
  0.00    0.000000           0         1           stat
  0.00    0.000000           0        10           fstat
  0.00    0.000000           0        23           mmap
  0.00    0.000000           0        14           mprotect
  0.00    0.000000           0         3           munmap
  0.00    0.000000           0         3           brk
  0.00    0.000000           0         2           ioctl
  0.00    0.000000           0         8         8 access
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         2           getdents
  0.00    0.000000           0         2         2 statfs
  0.00    0.000000           0         1           arch_prctl
  0.00    0.000000           0         1           openat
------ ----------- ----------- --------- --------- ----------------
100.00    0.000000                   101        10 total

Nell'output precedente, la colonna "chiamate" indicava quante volte è stata eseguita quella particolare chiamata di sistema.

8. Stampa Debug Output di strace

Per stampare le informazioni di debug per il comando strace, usa il flag -d come mostrato di seguito:

strace -d ls file1.txt

Output
ptrace_setoptions = 0x11
new tcb for pid 6453, active tcbs:1
 [wait(0x80137f) = 6453] ?? (128),PTRACE_EVENT_?? (128)
pid 6453 has TCB_STARTUP, initializing it
setting opts 11 on pid 6453
 [wait(0x80057f) = 6453] ?? (128),PTRACE_EVENT_?? (128)
 [wait(0x127f) = 6453] WIFSTOPPED,sig=SIGCONT
 [wait(0x857f) = 6453] WIFSTOPPED,sig=133
execve("/bin/ls", ["ls", "file1.txt"], [/* 61 vars */] [wait(0x4057f) = 6453] WIFSTOPPED,sig=SIGTRAP,PTRACE_EVENT_EXEC
 [wait(0x857f) = 6453] WIFSTOPPED,sig=133
) = 0
 [wait(0x857f) = 6453] WIFSTOPPED,sig=133
brk(0 [wait(0x857f) = 6453] WIFSTOPPED,sig=133
)                                  = 0x25bc000
 [wait(0x857f) = 6453] WIFSTOPPED,sig=133
exit_group(0)                           = ?
 [wait(0x0000) = 6453] WIFEXITED,exitcode=0
+++ exited with 0 +++
dropped tcb for pid 6453, 0 remain

9. Traccia le chiamate di sistema in base a una determinata condizione

Puoi anche tracciare le chiamate di sistema in base alla condizione specifica. Ad esempio, traccia tutte le chiamate di sistema relative alla gestione della memoria, esegui il comando seguente:

strace -q -e memory ls file1.txt

Output
brk(0)                                  = 0x248d000
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f68e9ac4000
mmap(NULL, 114633, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f68e9aa8000
mmap(NULL, 2238192, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f68e9681000
mprotect(0x7f68e96a1000, 2093056, PROT_NONE) = 0
mmap(0x7f68e98a0000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1f000) = 0x7f68e98a0000
mmap(0x7f68e98a2000, 5872, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f68e98a2000
mmap(NULL, 2126336, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f68e9479000
mmap(0x7f68e8e74000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7f68e8e74000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f68e9aa6000
mmap(NULL, 2113760, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f68e8a6d000
mprotect(0x7f68e8a71000, 2093056, PROT_NONE) = 0
mmap(0x7f68e8c70000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3000) = 0x7f68e8c70000
brk(0)                                  = 0x248d000
brk(0x24ae000)                          = 0x24ae000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f68e9ac3000
munmap(0x7f68e9ac3000, 4096)            = 0
mmap(NULL, 7216688, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f68e838b000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f68e9ac3000
file1.txt
munmap(0x7f68e9ac3000, 4096)            = 0
+++ exited with 0 +++

Per tracciare le chiamate di sistema realted del segnale, eseguire il comando seguente:

strace -e signal ls file1.txt

Output
file1.txt
+++ exited with 0 +++

Per tracciare le chiamate di sistema reali del processo, eseguire il comando seguente:

strace -e process ls file1.txt

Output
execve("/bin/ls", ["ls", "file1.txt"], [/* 61 vars */]) = 0
arch_prctl(ARCH_SET_FS, 0x7fb8196a8840) = 0
file1.txt
exit_group(0)                           = ?
+++ exited with 0 +++

Conclusione

Nella guida sopra, hai imparato come usare il comando strace con diversi esempi. Questo strumento è molto utile per gli amministratori di sistema e i programmatori per eseguire il debug e risolvere i problemi di qualsiasi programma.