Strace pour dépanner

strace est un outil de débugage permettant de tracer/surveiller les appels systèmes utilisés par un programme, similaire à l’outil « truss » sur les autres systèmes Unix.
Les appels systèmes sont les interfaces fondamentales entre les applications et le noyau.
Généralement, ils ne sont pas appelés directement, mais via des wrappers de la glibc.

L’utilisation la plus courante de strace est de lancer un programme en l’utilisant. Il affichera une liste des appels système faits par le programme. C’est utile lorsqu’un programme plante continuellement, ou ne se comporte pas comme on l’aurait souhaité. Cela peut par exemple, révéler que le programme tente d’accéder à un dossier qui n’existe pas ou qui ne peut pas être traversé.

Une autre utilisation est d’utiliser l’option -p pour le rattacher à un PID. C’est utile lorsqu’un programme ne répond plus, et peut révéler, par exemple, que le processus est bloqué car il attend une connexion réseau.

Comme strace ne détaille que les appels système, il ne peut pas être utilisé comme un débugueur de code, tel que Gdb. Il reste cependant plus simple à utiliser qu’un débugueur de code, et est un outil extrêmement utile pour les administrateurs système.

Par exemples « fstat, mmap, open et close » lors d’un strace sur la commande ls:

strace ls


....
open("/usr/lib/x86_64-linux-gnu/gconv/gconv-modules.cache", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=26258, ...}) = 0
mmap(NULL, 26258, PROT_READ, MAP_SHARED, 3, 0) = 0x7f70143ad000
close(3)
...  

Utilisation basique de strace (strace+commande):

strace ifconfig eth0

execve("/sbin/ifconfig", ["ifconfig", "eth0"], [/* 60 vars */]) = 0
brk(0)                                  = 0x24c2000
........
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libc.so.6", 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\320\37\2\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1840928, ...}) = 0
mmap(NULL, 3949248, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f7f6bcb2000
mprotect(0x7f7f6be6d000, 2093056, PROT_NONE) = 0
..........
uname({sys="Linux", node="starmate", ...}) = 0
access("/proc/net", R_OK)               = 0
access("/proc/net/unix", R_OK)          = 0
socket(PF_LOCAL, SOCK_DGRAM, 0)         = 3
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 4
..........
write(1, "          inet adr:192.168.0.10 "..., 75
inet adr:192.168.0.10  Bcast:192.168.0.255  Masque:255.255.255.0
) = 75
open("/proc/net/if_inet6", O_RDONLY)    = 6
........
close(5)                                = 0
exit_group(0)                           = ?
+++ exited with 0 +++ 

Pour faire un grep, il faut enregistrer la sortie de strace dans un fichier:

strace -o /tmp/starmate/test.txt ifconfig eth0

Pour faire un rapport des appels systèmes:

strace -c ifconfig eth0

eth0      Link encap:Ethernet  HWaddr 90:e6:ba:00:a5:cc
inet adr:192.168.0.10  Bcast:192.168.0.255  Masque:255.255.255.0
adr inet6: fe80::92e6:baff:fe00:a5cc/64 Scope:Lien
UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
Packets reçus:798982 erreurs:0 :0 overruns:0 frame:0
TX packets:465336 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 lg file transmission:1000
Octets reçus:1141244545 (1.1 GB) Octets transmis:47180143 (47.1 MB)
Interruption:18

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
23.71    0.000170          12        14        11 access
16.04    0.000115          16         7           read
14.37    0.000103           7        14           mmap
 13.67    0.000098           9        11         3 open
5.86    0.000042          14         3           brk
5.72    0.000041          41         1           execve
4.04    0.000029           3        10           write
3.63    0.000026           3         9           close
3.07    0.000022           2         9           fstat
2.93    0.000021           5         4           mprotect
2.79    0.000020           5         4           munmap
2.09    0.000015           1        11           ioctl
1.53    0.000011           4         3           socket
0.28    0.000002           2         1           uname
0.28    0.000002           2         1           arch_prctl
------ ----------- ----------- --------- --------- ----------------
100.00    0.000717                   102        14 total 

Ici, l’appel système open génère 3 erreurs.

Pour tracer un appel système spécifique (fstat, mmap, open, close, etc):

strace -e open ifconfig eth0

open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
open("/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3
open("/proc/net/dev", O_RDONLY)         = 6
open("/usr/share/locale/locale.alias", O_RDONLY|O_CLOEXEC) = 6
open("/usr/share/locale/fr_FR/LC_MESSAGES/net-tools.mo", O_RDONLY) = -1 ENOENT
(No such file or directory)
open("/usr/share/locale/fr/LC_MESSAGES/net-tools.mo", O_RDONLY) = -1 ENOENT
(No such file or directory)
open("/usr/share/locale-langpack/fr_FR/LC_MESSAGES/net-tools.mo", O_RDONLY) = -1 ENOENT
(No such file or directory)
open("/usr/share/locale-langpack/fr/LC_MESSAGES/net-tools.mo", O_RDONLY) = 6
open("/usr/lib/x86_64-linux-gnu/gconv/gconv-modules.cache", O_RDONLY) = 6
eth0      Link encap:Ethernet  HWaddr 90:e6:ba:00:a5:cc
inet adr:192.168.0.10  Bcast:192.168.0.255  Masque:255.255.255.0
open("/proc/net/if_inet6", O_RDONLY)    = 6
adr inet6: fe80::92e6:baff:fe00:a5cc/64 Scope:Lien
UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
Packets reçus:799386 erreurs:0 :0 overruns:0 frame:0
TX packets:465734 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 lg file transmission:1000
Octets reçus:1141290153 (1.1 GB) Octets transmis:47434995 (47.4 MB)
Interruption:18

+++ exited with 0 +++ 

On voit que ifconfig essaye d’ouvrir des fichiers absents.

Pour les compter:

strace -e open ifconfig eth0 2>&1 | grep "No such file or directory" | wc -l

3 

3! Exactement comme dans le rapport d’appels systèmes.

Pour tracer plusieurs appels systèmes spécifique (fstat, mmap, open, close, etc):

strace -e trace=mprotect,close ifconfig eth0

close(3)                                = 0
mprotect(0x7fdc160b6000, 2093056, PROT_NONE) = 0
close(3)                                = 0
mprotect(0x7fdc162b5000, 16384, PROT_READ) = 0
mprotect(0x60e000, 4096, PROT_READ)     = 0
mprotect(0x7fdc164e2000, 4096, PROT_READ) = 0
close(3)                                = 0
close(6)                                = 0
close(6)                                = 0
close(6)                                = 0
close(6)                                = 0
eth0      Link encap:Ethernet  HWaddr 90:e6:ba:00:a5:cc
inet adr:192.168.0.10  Bcast:192.168.0.255  Masque:255.255.255.0
adr inet6: fe80::92e6:baff:fe00:a5cc/64 Scope:Lien
close(6)                                = 0
UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
Packets reçus:799874 erreurs:0 :0 overruns:0 frame:0
TX packets:466198 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 lg file transmission:1000
Octets reçus:1141346643 (1.1 GB) Octets transmis:47736756 (47.7 MB)
Interruption:18
close(5)                                = 0

+++ exited with 0 +++ 

Pour tracer une catégorie spécifique d’appels Système ( ici ceux des processus « process »):

strace -e trace=process ifconfig eth0
execve("/sbin/ifconfig", ["ifconfig", "eth0"], [/* 60 vars */]) = 0
arch_prctl(ARCH_SET_FS, 0x7fccbe552740) = 0
eth0 Link encap:Ethernet HWaddr 90:e6:ba:00:a5:cc 
 inet adr:192.168.0.10 Bcast:192.168.0.255 Masque:255.255.255.0
 adr inet6: fe80::92e6:baff:fe00:a5cc/64 Scope:Lien
 UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
 Packets reçus:800160 erreurs:0 :0 overruns:0 frame:0
 TX packets:466500 errors:0 dropped:0 overruns:0 carrier:0
 collisions:0 lg file transmission:1000 
 Octets reçus:1141433090 (1.1 GB) Octets transmis:47829311 (47.8 MB)
 Interruption:18 

exit_group(0) = ?
+++ exited with 0 +++

Les autres catégories:

-e trace=network         Trace tous les appels systèmes de type réseau.
-e trace=signal             Trace tous les appels systèmes de type signal.
-e trace=ipc                   Trace tous les appels systèmes IPC.
-e trace=desc               Trace tous les appels systèmes liés aux descripteurs.
-e trace=set                  Trace tous les appels systèmes SET
-e trace=memory        Trace tous les appels systèmes liés à la mémoire. 

 

Il peut être utile d’afficher horodatage des appels systèmes et leur timestamp:

strace -r     Timestamp relatif - temps passé pour un appel système
strace -t     Préfixer chaque ligne par la date du jour
strace -tt     Préfixer chaque ligne par la date du jour à la microseconde près
strace -ttt     Préfixer chaque ligne par la date du jour à la microseconde près depuis 01/01/1970.
 

Pour attacher strace à un processus existant :

trace -p n°_PID

Strace est un outil très puissant, ne pas oublier man strace !!!

Derniers Articles