Que font vos processus ? La commande strace
J’ai découvert une commande ulta utile, que ce soit pour la sécurité ou pour débuger : la commande strace.
Comme vous le savez, lorsque vous codez en C ou en tout autre langage le code est traduit en langage machine mais il peut aussi faire appel aux fameux “appels systèmes” gérés par l’OS (comme par exemple cloner des processus, accéder à un fichier, afficher quelque chose à l’écran…). Mais comment avoir la trace de toutes ces informations ? La commande strace fait tout cela.
Sur *BSD, vous pouvez utiliser de manière analogue truss(1).
Dans la pratique, strace permet de voir ce que fait un processus, on y accède en lui donnant le PID du processus (qu’on peut avoir avec la commande ps). Par exemple si je veux savoir ce que fait mon shell :
% ps
3982 pts/3 00:00:00 zsh
# Une fois qu'on a le pid on lance strace (dans un autre shell)
% strace -p3982
Regardons un peu ce qu’il se passe pour un simple ls :
# 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
(Là j’ai viré pas mal de lignes répétitives sur les signaux reçus par le processus)
Bon, vous voyez qu’il y a un tas d’appel système, et encore il a fait un fork(), c’est à dire qu’un nouveau processus a été crée… Pour suivre aussi les nouveaux processus il suffit d’un :
% strace -f -pPID
Attention, le log peut être très long, donc je vous conseille d’envoyer tout ça dans un fichier, pour donner un ordre d’idée, un simple chargement d’une page dans firefox donne plus de 59000 appels systèmes.
% strace -f -pPID > strace.log 2>&1
Avec ces informations vous pouvez faire du debugage (je me suis rendu compte que mon shell ne fermais pas ses fichiers quand il ne trouvais pas de complétion possible. C’est aussi grâce a ce genres de vérification qu’on s’est rendu compte que le charmant logiciel propriétaire skype ouvrait le fichier bookmaks.html (les favoris de firefox) et les envoyais à la maison mère… C’est une façon rapide de prouver qu’un logiciel propriétaire est malveillant.