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

From Deimos.fr / Bloc Notes Informatique
Jump to: navigation, search

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 :

Command aptitude
aptitude install strace ltrace

2.2 Red Hat

Command aptitude
yum install strace ltrace

3 Utilisation

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

Command 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\[email protected]\[email protected]\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 :

Command 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 :

Command 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 :

Command strace
strace -e open,access ls

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

Command 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) :

Command 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 :

Command strace
strace -f -s 5000 -p <PID>

3.6 Obtenir des statistiques

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

Command 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 :

Command 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' :

Command 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;[email protected] ~\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