Strace et Ltrace : tracez les appels systèmes et librairies

1 Introduction

strace est un outil de déboguage sous Linux pour surveiller les appels système utilisés par un programme, et tous les signaux qu'il reçoit, similaire à l'outil "truss" sur les autres systèmes Unix. Il a été rendu possible grâce à une fonctionnalité du noyau Linux appelée ptrace.

L'utilisation la plus courante est de lancer un programme en utilisant strace, qui affiche une liste des appels système faits par le programme. C'est utile lorsque le programme plante continuellement, ou ne se comporte pas comme souhaité. Par exemple, utiliser strace peut révéler que le programme tente d'accèder à un fichier qui n'existe pas ou qui ne peut pas être lu.

Une autre utilisation est d'utiliser l'option -p pour le rattacher à un programme lancé. 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 de faire une connexion réseau.

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

Dans cette documentation, je ne parlerais pas trop d'ltrace car son utilisation est à peu prêt similaire à strace.

2 Installation

2.1 Debian

Pour l'installer sur Debian :

aptitude

aptitude install strace ltrace

2.2 Red Hat

aptitude

yum install strace ltrace

3 Utilisation

Nous souhaitons par exemple débugger un problème sur un serveur apache :

strace

> strace -f /etc/init.d/httpd restart execve("/etc/init.d/httpd", ["/etc/init.d/httpd", "restart"], [/* 32 vars */]) = 0 brk(0) = 0x1c61000 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff218642000 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) open("/etc/ld.so.cache", O_RDONLY) = 3 fstat(3, {st_mode=S_IFREG|0644, st_size=31346, ...}) = 0 mmap(NULL, 31346, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7ff21863a000 close(3) = 0 open("/lib64/libtinfo.so.5", O_RDONLY) = 3 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@\310@\331=\0\0\0"..., 832) = 832 ...

L'option -f de strace trace les processus fils à mesure qu'ils sont créés par des processus actuellement tracés à la suite de l'appel système fork.

Il ne reste plus qu'à analyser les lignes et voir le soucis. C'est un peu fastidieux suivant le nombre de ligne, mais généralement il y a l'info sur votre problème ici.

3.1 Rediriger la sortie vers un fichier

Nous souhaitons rediriger toute la sortie d'strace (initialement sur la sortie d'erreur) dans un fichier à l'aide de l'option -o :

strace

strace -o apache -f /etc/init.d/httpd restart

3.2 Travailler sur la sortie standard

Comme vous le savez maintenant, strace travaille sur la sortie d'erreur, donc si on veut travailler dessus avec du grep ou autre commande à la volée (sans redirection dans un fichier), il va falloir utiliser une redirection :

strace

strace -f /etc/init.d/httpd restart 2>&1

3.3 Ne travailler que sur certains appels kernel

Si vous souhaitez par exemple ne récupérer que les appels de type open et access :

strace

strace -e open,access ls

Voici quelques exemples d'appels systèmes que vous pouvez tenter :

strace

strace -e trace=set strace -e trace=open strace -e trace=read strace -e trace=file strace -e trace=process strace -e trace=network strace -e trace=signal strace -e trace=ipc strace -e trace=desc //descriptors strace -e read=set

3.4 Augmenter le nombre de caractère à afficher

On peut augmenter la taille d'affichage il faut utiliser l'option -s suivit de la taille souhaitée (5000 par exemple) :

strace

strace -o apache -f -s 5000 /etc/init.d/httpd restart

3.5 Se raccrocher à un PID existant

Si nous souhaitons tracer un processus déjà en cours d'exécution c'est possible. Pour cela, il faut tout simplement utiliser l'argument -p :

strace

strace -f -s 5000 -p <PID>

3.6 Obtenir des statistiques

Si vous voulez obtenir des statistiques, nous allons utiliser l'option -c :

strace

> strace -c unameLinux % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- -nan 0.000000 0 1 read -nan 0.000000 0 1 write -nan 0.000000 0 3 open -nan 0.000000 0 5 close -nan 0.000000 0 4 fstat -nan 0.000000 0 10 mmap -nan 0.000000 0 3 mprotect -nan 0.000000 0 2 munmap -nan 0.000000 0 3 brk -nan 0.000000 0 1 1 access -nan 0.000000 0 1 execve -nan 0.000000 0 1 uname -nan 0.000000 0 1 arch_prctl ------ ----------- ----------- --------- --------- ---------------- 100.00 0.000000 36 1 total

3.7 Détecter des problèmes réseaux

Si par exemple vous souhaitez uniquement travailler sur une couche réseaux, voici la solution :

strace

strace -e poll,select,connect,recvfrom,sendto nc www.deimos.fr 80

4 Exemple

Voici un exemple de cette commande avec quelques explications pour mieux vous aider à débuter sur une commande 'ls' :

strace

# Lecture d'un l au clavier read(10, "l"..., 1) = 1 # écriture du l a l'écran (celui qu'il vient de lire write(10, "l"..., 1) = 1 # Lecture du s read(10, "s"..., 1) = 1 # ecriture du s write(10, "\10ls"..., 3) = 3 # lecture de la touche enter (en C) read(10, " "..., 1) = 1 write(10, " "..., 2) = 2 alarm(0) = 0 ioctl(10, SNDCTL_TMR_STOP or TCSETSW, {B38400 opost isig icanon echo ...}) = 0 time(NULL) = 1229629587 pipe([3, 4]) = 0 gettimeofday({1229629587, 864550}, {0, 0}) = 0 # clone ----> un nouveau processus est crée en fait fork() execute l'appel système clone, le nouveau pid est 4024 clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xb7ddd998) = 4024 close(4) = 0 read(3, ""..., 1) = 0 close(3) = 0 rt_sigprocmask(SIG_BLOCK, [CHLD], [CHLD], 8) = 0 rt_sigsuspend([]) = ? ERESTARTNOHAND (To be restarted) --- SIGCHLD (Child exited) @ 0 (0) --- rt_sigprocmask(SIG_BLOCK, ~[RTMIN RT_1], [CHLD], 8) = 0 rt_sigprocmask(SIG_SETMASK, [CHLD], ~[KILL STOP RTMIN RT_1], 8) = 0 # La fin du processus fils (4024) wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WNOHANG|WSTOPPED, {ru_utime={0, 0}, ru_stime={0, 0}, ...}) = 4024 gettimeofday({1229629587, 867012}, {0, 0}) = 0 ioctl(10, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0 ioctl(10, TIOCGPGRP, [4024]) = 0 ioctl(10, TIOCSPGRP, [3982]) = 0 ioctl(10, TIOCGWINSZ, {ws_row=38, ws_col=127, ws_xpixel=1270, ws_ypixel=758}) = 0 wait4(-1, 0xbfe3f48c, WNOHANG|WSTOPPED, 0xbfe3f434) = -1 ECHILD (No child processes) # Il se demande quelle heure est il :-) time(NULL) = 1229629587 ioctl(10, TIOCSPGRP, [3982]) = 0 fstat64(0, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 3), ...}) = 0 fcntl64(0, F_GETFL) = 0x2 (flags O_RDWR) # Il se demande sous quel UID il tourne getuid32() = 1000 # Il reécris le prompt write(1, "\33]0;phil@philpep.ath.cx ~\7"..., 26) = 26 rt_sigprocmask(SIG_BLOCK, [CHLD], [CHLD], 8) = 0 # Il se redemande quelle heure il est time(NULL) = 1229629587 rt_sigaction(SIGINT, {0x80a8fd0, [], SA_INTERRUPT}, NULL, 8) = 0 write(10, "\33[1m\33[3m%\33[23m\33[1m\33[0m "..., 149) = 149 time(NULL) = 1229629587 # Il ouvre le fichier /etc/localtime stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2945, ...}) = 0 ioctl(10, FIONREAD, [0]) = 0 ioctl(10, TIOCSPGRP, [3982]) = 0 ioctl(10, SNDCTL_TMR_STOP or TCSETSW, {B38400 opost isig -icanon -echo ...}) = 0 write(10, " \33[0m\33[23m\33[24m\33[J\33[01;30m[\33[01;3"..., 105) = 105 write(10, "\33[K\33[81C \33[01;30m18/12/08 20:46:"..., 46) = 46 # Il attend une nouvelle saisie read(10, Process 3982 detached

5 Ressources

http://blog.philpep.org/post/Que-font-vos-processus---La-commande-strace
http://www.hokstad.com/5-simple-ways-to-troubleshoot-using-strace.html