Cómo rastrear la ejecución del programa usando el comando Strace de Linux

El strace es una poderosa herramienta de línea de comandos para programas de monitoreo, diagnóstico y solució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 usar 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ías 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 llamadas al sistema

Si desea rastrear las llamadas al sistema del comando ls, ejecute el siguiente comando:

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 +++

En el resultado anterior, puede ver la llamada al sistema y el resultado de la llamada del comando ls. También debería ver que el estado de salida es 0. Eso significa que no hubo ningún error.

Un uso de strace (excepto para depurar algún problema) es que puede averiguar qué archivos de configuración se leen por un programa.

Por ejemplo:

strace php 2>&1 | grep php.ini

2. Filtrar llamadas específicas del sistema

Por defecto, strace muestra todas las llamadas al sistema para el ejecutable dado. Si desea mostrar solo una llamada de sistema específica, puede usar la opción strace -e.

Por ejemplo, para mostrar solo la llamada del sistema de escritura del comando ls, ejecute el siguiente comando:

strace -e write ls file1.txt file2.txt

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

Para mostrar solo la llamada al sistema abierto del comando ls, ejecute el siguiente comando:

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 +++

Si desea mostrar archivos abiertos por un proceso específico como SSH, ejecute el siguiente comando:

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

Para rastrear las llamadas al sistema relacionadas con la red, ejecute el siguiente comando:

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. 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:\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

Este comando mostrará continuamente las llamadas al sistema realizadas por el proceso. Puede presionar CTRL+C para detenerlo.

donde:

5315 es un ID de proceso del proceso en ejecución.

4. Redirigir la salida de rastreo a un archivo

Puede usar el indicador -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. Imprimir el tiempo dedicado a las llamadas del sistema

Para imprimir la marca de tiempo relativa de cada llamada, use el indicador -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, "\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 +++

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.txt\n", 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. Muestra el puntero de instrucciones de la llamada al sistema

Puede usar el indicador -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.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. Generar un informe de llamadas del sistema

Puede usar el indicador -c para obtener el informe estadístico útil para el seguimiento de la 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" indicaba 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 el indicador -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. Seguimiento de 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 la 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 las llamadas al sistema relacionadas con el proceso, 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 administradores de sistemas y programadores para depurar y solucionar problemas de cualquier programa.