homenowpostsprojects(english version)

Une histoire de décharge

Durée de lecture estimée : 6 minutes

Il y a quelques semaines, j’étais chez un ami et, afin de contacter quelqu’un, j’ai démarré mon client IRC. Client IRC que j’ai moi-même écrit.

Au bout d’environ une heure, la batterie de mon ordinateur était presque à plat, j’ai pourtant l’habitude d’avoir plusieurs heures d’autonomie avec cet ordinateur portable !

Je vais rarement sur IRC quand je voyage avec mon ordinateur portable, c’est pourquoi j’ai pensé que quelque chose clochait dans mon client.

Pour enquêter sur le problème, j’ai utilisé l’outil powertop, dont voici une capture prise pendant que le client IRC était en train de tourner.

powertop montrant un grand nombre de réveils

D’après cette capture, nous pouvons observer que le processus pty irc-read -n +1 -f out réveille beaucoup le processeur (environ 600 fois par seconde). Ce qui empêche celui-ci de tomber dans des modes de sommeil plus profonds, et donc entraîne une consommation électrique générale plus élevée.

Ce petit programme est, bien entendu, une partie de mon client IRC. Vous pouvez voir son code source ici même.

Pour comprendre quel était exactement le problème, j’ai utilisé strace sur une instance de ce programme, et ai découvert que l’outil tail se comportait bizarrement.

stitch:~$ strace -p 4738
strace: Process 4738 attached
restart_syscall(<... resuming interrupted nanosleep ...>) = 0
fstat(3, {st_mode=S_IFREG|0644, st_size=589, ...}) = 0
lseek(3, 0, SEEK_CUR)                   = 589
read(3, "", 1024)                       = 0
nanosleep({tv_sec=1, tv_nsec=0}, 0x7ffe37c0ba60) = 0
fstat(3, {st_mode=S_IFREG|0644, st_size=589, ...}) = 0
lseek(3, 0, SEEK_CUR)                   = 589
read(3, "", 1024)                       = 0
nanosleep({tv_sec=1, tv_nsec=0}, 0x7ffe37c0ba60) = 0
fstat(3, {st_mode=S_IFREG|0644, st_size=589, ...}) = 0
lseek(3, 0, SEEK_CUR)                   = 589
read(3, "", 1024)                       = 0
nanosleep({tv_sec=1, tv_nsec=0}, 0x7ffe37c0ba60) = 0
…

Ce que cette trace révèle, c’est que tail -f opère en se déplaçant dans le fichier à la dernière position connue et en lisant les éventuelles nouvelles données. Et ce, chaque seconde (nanosleep avec tv_sec = 1 et tv_nsec = 0), réveillant effectivement le CPU une fois par seconde pour chaque canal IRC dans lequel je me trouve ; sachant qu’un processus irc-read est lancé pour chaque canal IRC.

Je n’étais pas content que tail -f vérifie les changements chaque seconde, sachant que de bien meilleures solutions existent. C’est pourquoi j’ai écrit ma propre version de tail -f, avec CHICKEN comme langage de programmation, et la bibliothèque inotify que wasamasa a écrite il y a quelques semaines.

Voici le code source de ma mise en œuvre :

;; tailf.scm
(use inotify utils)

(init!)
(on-exit clean-up!)

(define path (car (command-line-arguments)))
(add-watch! path '(modify))

(with-input-from-file path
  (lambda ()
    (let loop ()
      (display (read-all))
      (flush-output)
      (next-event!)
      (set-file-position! (current-input-port) 0 seek/cur)
      (loop))))

Comme vous pouvez le voir, c’est un programme très court. Ici j’utilise inotify pour réveiller le programme dès que le fichier observé est modifié. Je me déplace ensuite à la dernière position connue (pour éviter de lire l’ancienne fin de fichier) puis lis tout ce qui a été ajouté à partir de là.

Malheureusement ce ne fut pas suffisant, tail n’était qu’une diversion. Un autre processus était en train de réveiller le processeur, beaucoup plus souvent. Ce programme était pty, un petit utilitaire fourni avec l’éditeur de texte Ma, qui lui permet de se faire passer pour un émulateur de terminal.

Regardons sa trace d’appels système :

stitch:~$ strace -p 4668
strace: Process 4668 attached
restart_syscall(<... resuming interrupted nanosleep ...>) = 0
poll([{fd=0, events=POLLIN}, {fd=3, events=POLLOUT}], 2, 100) = 1 ([{fd=3, revents=POLLOUT}])
read(3, 0x7fff4a4f5290, 1023)           = -1 EAGAIN (Resource temporarily unavailable)
nanosleep({tv_sec=0, tv_nsec=10000000}, 0x7fff4a4f51c0) = 0
poll([{fd=0, events=POLLIN}, {fd=3, events=POLLOUT}], 2, 100) = 1 ([{fd=3, revents=POLLOUT}])
read(3, 0x7fff4a4f5290, 1023)           = -1 EAGAIN (Resource temporarily unavailable)
nanosleep({tv_sec=0, tv_nsec=10000000}, 0x7fff4a4f51c0) = 0
poll([{fd=0, events=POLLIN}, {fd=3, events=POLLOUT}], 2, 100) = 1 ([{fd=3, revents=POLLOUT}])
read(3, 0x7fff4a4f5290, 1023)           = -1 EAGAIN (Resource temporarily unavailable)
nanosleep({tv_sec=0, tv_nsec=10000000}, 0x7fff4a4f51c0) = 0
…

Ça semble familier, n’est-ce pas ? Cependant ce programme ci réveille le processeur toutes les 10 millisecondes ! (nanosleep avec tv_nsec = 10000000)

Il m’a fallu un petit moment avant de comprendre ce qui n’allait pas ici. Je ne comprenais pas pourquoi l’appel à poll() retournait un évènement pour le descripteur de fichier 3, et que lire depuis celui-ci retournait une erreur EAGAIN… Le problème était en fait un bug de l’outil pty ! En effet, il essaye de lire depuis un descripteur de fichier quand poll() informe le programme que le descripteur de fichier en question est prêt pour l’écriture !

J’ai donc écrit un petit patch pour réparer ce problème ainsi que faire fonctionner le programme sans descripteurs de fichier non bloquants, et maintenant tout va bien ! :D (voici le code source actuel)

powertop montrant un système calme