af83

Scruter ses processus avec strace

strace est un outil, utilisable en ligne de commande, qui affiche les appels systèmes effectués par un processus et ses enfants. Ces appels systèmes sont le seul contact du processus avec l'extérieur : pas de lecture de fichier, de réseau ou d'affichage sans passer par des appels au noyau. L'affichage de ces appels permet de débugger et d'étudier le comportement du processus en laissant de coté la logique du code pour s'attacher uniquement à ses interactions.

strace s'utilise simplement en lui passant une commande à exécuter :

$ strace ls
[...]
open(".", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 3
getdents(3, /* 5 entries */, 32768)     = 144
getdents(3, /* 0 entries */, 32768)     = 0
close(3)                                = 0
fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 4), ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f1119e93000
write(1, "brownies  cookies  cupcakes\n", 28) = 28
close(1)                                = 0
munmap(0x7f1119e93000, 4096)            = 0
close                                = 0
exit_group(0)                           = ?

Cet exemple permet de décortiquer le fonctionnement de la commande ls. On peut y voir l'ouverture du répertoire . avec open, son parcours avec getdents ainsi que l'écriture du résultat sur la sortie standard avec write. Ces appels système disposent généralement d'une page de man qui décrit leur différents paramètres et la valeur renvoyée (section 2 des pages de man).

Ces appels peuvent être séparés en plusieurs catégories :

  • les appels dédiés à la communication avec l'extérieur : il s'agit notamment des appels open, read, write, close et par extension tous les appels qui manipulent des descripteurs de fichier. Dans l'exemple précédent, la fonction open qui ouvre le répertoire . renvoie le descripteur de fichier 3, ce descripteur sera utilisé par getdents pour récupérer le contenu du répertoire avant d'être fermé par close. D'autres appels renvoient des descripteurs, notamment accept qui ouvre un descripteur pour la communication avec un client (généralement en TCP) ou connect pour la communication avec un serveur ;
  • les appels dédiés à la gestion de la mémoire : mmap, munmap, brk et sbrk permettent d'allouer et de libérer des portions de la mémoire. L'exemple précédent montre un appel à mmap pour allouer un buffer de 4096 octets, ce buffer sera utilisé pour copier la sortie (le nom des fichiers) avant l'écriture sur la sortie standard puis sera désalloué avec munmap. Notons que mmap est aussi utilisé pour mapper des fichiers en mémoire.

D'autres appels, qui ne sont pas présents dans l'exemple de ls, sont aussi très courants :

  • les multiplexeurs : généralement poll, select, epoll_wait ou kqueue. Ces appels servent généralement de point central à un processus, ils permettent de gérer les différents canaux de communication d'un processus en regroupant l'attente des évènements en un seul appel. Ces appels sont bloquants et ne retournent que lorsqu'un évènement arrive sur un descripteur de fichier ou que leur timeout est atteint ;
  • les appels dédiés au temps : souvent gettimeofday ou clock_gettime qui permettent de retourner différentes interprétation du temps ;
  • les appels dédiés aux threads : généralement tous ceux qui commencent par pthread_ ;
  • les appels dédiés aux signaux : kill et signal sont les plus connus mais Posix en compte un certain nombre.

Quelques explications sur les options de strace

Quelques options de strace méritent un peu plus d'attention :

  • -p : permet de s'attacher à un processus qui est déjà en train de s'exécuter, en utilisant son pid. Notons que comme strace utilise l'API ptrace il n'est pas possible de tracer plus d'une fois le même processus ou de tracer un processus qui se trace lui même ;
  • -f : permet de suivre les forks d'un processus en affichant à la fois les appels du parents et des enfants ;
  • -o : enregistrer la sortie dans un fichier ;
  • -c : afficher des statistiques sur le temps passé et le nombre d'appels.

Identifier les problèmes

Les fuites de mémoires

Deux comportements peuvent caractériser une fuite de mémoire :

  • de nombreux appels à brk avec un paramètre qui augmente constamment ;
  • de nombreux appels à mmap sans appel à munmap.

Le programme suivant génère une fuite de mémoire :

int main() {
  for (;;)
    malloc(4096);
}

Le résultat avec strace :

[...]
brk(0)                                  = 0x1f7e000
brk(0x1fa0000)                          = 0x1fa0000
brk(0x1fc1000)                          = 0x1fc1000
brk(0x1fe2000)                          = 0x1fe2000
[...]
brk(0x1fd7c000)                         = 0x1fd7c000
brk(0x1fd9d000)                         = 0x1fd9d000
brk(0x1fdbe000)                         = 0x1fdbe000
[...]

Les fuites de descripteurs de fichier

Les descripteurs de fichier servent d'identifiants pour les fichiers, les connexions, les pipes (dont l'entrée et la sortie standard) et pour un certain nombre d'autres interfaces. Tout comme la mémoire, ceux-ci doivent être libérés pour ne pas atteindre les limites imposés par le système.

Les descripteurs de fichier sont des entiers qui se suivent, si l'un d'eux est libéré il sera immédiatement recyclé pour servir d'identifiant à une autre ressource. Il est donc assez facile d'identifier les fuites en observant le numéro des descripteurs : si ceux-ci sont de plus en plus élevés sans raison apparente c'est qu'ils ne sont pas fermés correctement.

Le programme suivant ouvre tous les fichiers d'un répertoire sans jamais les fermer :

int main() {
  DIR * dir;
  struct dirent * entry;

  dir = opendir (".");
  while (entry = readdir (dir))
    open (entry->d_name, O_RDONLY);
}

Le résultat avec strace :

[...]
open(".", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 3
getdents(3, /* 128 entries */, 32768)   = 4240
open(".dbus", O_RDONLY)                 = 4
open(".cache", O_RDONLY)                = 5
open(".gvfs", O_RDONLY)                 = 6
[...]
open(".profile", O_RDONLY)              = 431
open(".bash_logout", O_RDONLY)          = 432
open(".gegl-0.0", O_RDONLY)             = 433
[...]

Autres comportements anormaux

Un processus qui fait un minimum d'entrée/sorties dans le temps utilisera, presque toujours, un multiplexeur (généralement poll, select, epoll_wait ou kqueue) qui lui permettra de suivre simultanément tous les évènements susceptibles de le réveiller, tout en bloquant sans consommer de CPU quand aucune tâche n'est en cours.

Un serveur HTTP en bonne santé fournira plus ou moins la trace suivante. À la réception d'une requête, la fonction epoll_wait retourne, le serveur traite la demande puis bloque à nouveau dans epoll_wait en attendant une nouvelle requête.

$ strace -p [pid]
epoll_wait(16, }, 512, 4294967295) = 1
accept(13, {sa_family=AF_INET, sin_port=htons(39824),
           sin_addr=inet_addr("127.0.0.1")}, [16]) = 3
recvfrom(3, "GET / HTTP/1.1\r\nHost: localhost\r"..., 1024, 0, NULL, NULL) = 376
write(3, "HTTP/1.1 404 Not Found\r\nServer: "..., 387) = 387
close(3)
epoll_wait(16, 

Imaginons maintenant que ce serveur HTTP ne réponde plus malgré le fait que son processus soit toujours présent. On peut diagnostiquer le problème en s'attachant directement au processus :

  • si il n'y a aucun retour de strace, le serveur est très certainement bloqué dans une boucle entièrement logique (sans appels systèmes) ;
  • si le serveur est bloqué sur un autre appel que le multiplexeur, il peut s'agir d'un I/O sur une ressource particulièrement lente, dans le cas d'appels à read, write ou leurs dérivés, ou d'un deadlock, notamment si le serveur bloque sur un appel à pthread_mutex_lock ;
  • si le serveur passe toujours par son multiplexeur mais retourne directement, il s'agit généralement de la notification d'un évènement demandant une lecture ou une écriture qui ne serait pas ensuite exécutée par le serveur ;
  • si le serveur reste bloqué sur le multiplexeur malgré les requêtes qui lui sont envoyées : il se peut que la socket du serveur soit fermée ou qu'elle ne soit pas en écoute sur le port ou l'interface réseau attendu.

Beyond strace, d'autres outils utiles

  • lsof permet de lister toutes les ressources ouvertes par les processus, il est très utile pour savoir à quoi correspond un descripteur de fichier affiché dans la sortie de strace ;
  • valgrind et toute sa suite d'outils permettent d'observer la consommation mémoire, les problèmes de multi-threading, l'accès au cache et comportement anormaux d'un processus ;
  • ltrace est le petit frère de strace, permettant de suivre non pas les appels systèmes mais les appels à des bibliothèques dynamiques.

blog comments powered by Disqus