Cómo rastrear la ejecución del programa usando el comando Strace de Linux
Strace es una poderosa herramienta de línea de comandos para programas de monitoreo, diagnóstico y resolución de problemas de procesos en Linux. Generalmente, se utiliza para interceptar y registrar las llamadas al sistema y las señales recibidas por un proceso. Puede utilizar strace para analizar cómo un programa interactúa con el sistema para depurar cualquier programa.
Esta herramienta es muy útil si el programa falla continuamente o no se comporta como se esperaba. Proporciona una visión profunda de cómo funciona el sistema. Cualquier usuario puede rastrear sus propios procesos en ejecución.
En este tutorial, le mostraremos cómo usar la herramienta de línea de comandos strace en Linux.
Instalar Strace
De forma predeterminada, strace está disponible en el repositorio predeterminado de todos los sistemas operativos Linux.
En los sistemas operativos Debian y Ubuntu, instale strace con el siguiente comando:
apt-get install strace -y
En los sistemas operativos RHEL y CentOS, instale strace con el siguiente comando:
dnf install strace -y
Después de instalar strace, puede verificar la versión de strace usando el siguiente comando:
strace -V
Debería obtener el siguiente resultado:
strace -- version 4.8
Puede imprimir todas las opciones disponibles con el comando strace con el siguiente 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. Rastrear las llamadas del sistema
Si desea rastrear las llamadas al sistema del comando ls, ejecute el siguiente comando:
strace ls file1.txt
Ejecución de salida ("/ bin / ls", ["ls", "file1.txt"], [/* 61 vars */]) = 0 brk (0) = 0x1f2a000 access ("/ etc / ld.so.nohwcap", F_OK) = -1 ENOENT (No existe tal archivo o directorio) mmap (NULL, 8192, PROT_READ | PROT_WRITE, MAP_PRIVATE | MAP_ANONYMOUS, - 1, 0) = 0x7f4dd0d30000 acceso ("/ etc / ld.so.preload", R_OK) = -1 ENOENT (No existe tal archivo o directorio) 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 acceso ("/ etc /ld.so.nohwcap ", F_OK) = -1 ENOENT (No existe tal archivo o directorio) 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[ "..., 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 +++
In the above output, you can see the system call and result of the call of ls command. You should also see that exit status is 0. That means there was no error.
One use of strace (Except debugging some problem) is that you can find out which configuration files are read by a program.
For example:
strace php 2>&1 | grep php.ini
2. Filter Specific System Calls
Be default, strace displays all system calls for the given executable. If you want to display only a specific system call, you can use strace -e option.
For example, to displays only the write system call of the ls command run the following command:
strace -e write ls file1.txt file2.txt
Output write(1, "file1.txt file2.txtn", 21file1.txt file2.txt ) = 21 +++ exited with 0 +++
To displays only the open system call of the ls command run the following command:
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 +++
If you want to display files opened by a specific process like SSH, run the following command:
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
To trace network-related system calls, run the following command:
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 Conexión al puerto 127.0.0.1 80 [tcp/*] logrado!
3. Adjuntar a un proceso que ya se está ejecutando
Si un proceso ya se está ejecutando, puede rastrearlo usando su PID como se muestra a continuación:
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:tchromenState: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
Este comando mostrará continuamente las llamadas al sistema realizadas por el proceso. Puede presionar CTRL + C para detenerlo.
dónde:
5315 es un ID de proceso del proceso en ejecución.
4. Redirigir la salida de seguimiento a un archivo
Puede usar la bandera -o con el comando strace para guardar la salida de strace en el archivo especificado.
strace -o file_out.txt ls file1.txt
Ahora puede mostrar el contenido del archivo file_out.txt con el siguiente comando:
cat file_out.txt
5. Imprima el tiempo dedicado a las llamadas al sistema
Para imprimir la marca de tiempo relativa de cada llamada, use la marca -r como se muestra a continuación.
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 +++
Para mostrar la diferencia de tiempo entre el inicio y el final de cada llamada al sistema realizada por el comando ls, use la opción -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, "177ELF211 3 > 1 [ "..., 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.txtn", 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 +++
Para imprimir la hora del reloj de pared de cada llamada al sistema, ejecute el siguiente comando:
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.txtn", 10file1.txt
) = 10
10:58:25 close(1) = 0
10:58:25 exit_group(0) = ?
10:58:25 +++ exited with 0 +++
La opción -tt muestra la marca de tiempo seguida de microsegundos.
strace -tt ls file1.txt
6. Mostrar el puntero de instrucción de la llamada al sistema
Puede usar la bandera -i con el comando strace para imprimir el puntero de instrucción en el momento de cada llamada al sistema realizada por el 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.txtn", 10file1.txt
) = 10
[00007f5ab5a01f60] close(1) = 0
[00007f5ab5a0a9f7] munmap(0x7f5ab6325000, 4096) = 0
[00007f5ab5a01f60] close(2) = 0
[00007f5ab59d7309] exit_group(0) = ?
[????????????????] +++ exited with 0 +++
7. Genere un informe de llamadas al sistema
Puede utilizar la marca -c para obtener el informe estadístico útil para el seguimiento de ejecución.
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
En el resultado anterior, la columna «llamadas» indica cuántas veces se ejecutó esa llamada al sistema en particular.
8. Imprimir salida de depuración de strace
Para imprimir información de depuración para el comando strace, use la marca -d como se muestra a continuación:
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. Rastrear llamadas al sistema en función de una determinada condición
También puede rastrear las llamadas al sistema según la condición específica. Por ejemplo, rastree todas las llamadas al sistema relacionadas con la administración de memoria ejecute el siguiente comando:
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 +++
Para rastrear las llamadas al sistema relacionadas con la señal, ejecute el siguiente comando:
strace -e signal ls file1.txt
Output file1.txt +++ exited with 0 +++
Para rastrear el proceso de llamadas al sistema relacionadas, ejecute el siguiente comando:
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 +++
Conclusión
En la guía anterior, aprendió a usar el comando strace con varios ejemplos. Esta herramienta es muy útil para los administradores de sistemas y programadores para depurar y solucionar problemas de cualquier programa.