Danse avec les reboots

A l’occasion des failles Spectre et Meltdown, des millions de serveurs vont être redémarrés. On m’a demandé à mon boulot, pourquoi certains serveurs rebootaient en 40s et d’autres en plus de 100s ?

Extinction puis démarrage

Un redémarrage (reboot) est composé de deux phases : l’extinction (shutdown) et le démarrage (boot). Peu de gens s’intéressent à l’extinction de leur pc, normal on arrête de l’utiliser. En revanche le temps de redémarrage d’un serveur est important, plus il sera long, plus longue sera la période d’indisponibilité des services fournis. Pour moi 60s c’est que dalle mais sur un serveur mutualisé avec disons 100 clients dessus, c’est 100 clients qui seront impactés pendant 1 minute. Cette minute devient très importante.

Pour réduire le temps de redémarrage, kexec (1, 2, 3) est l’outil le plus utilisé. Chez Ubuntu il y a Canonical Livepatch qui peut éviter d’avoir à redémarrer. Le démarrage est la partie visible de l’iceberg et la plus « simple ». On a en effet une session, nos outils, des logs, on peut déboguer. La base sera de jouer avec journalctl, dmesg -T | grep quelquechose, un petit journalctl -p err vous mettra sûrement sur la voie.

Déboguer l’extinction sera plus difficile. Le système s’éteint, on n’a plus de connexion réseau, pas la main sur un quelconque outil et ça dure une poignée de secondes. Pour « voir » une extinction, il faut avoir un écran branché sur le serveur ou utiliser certains outils basés sur IPMI (ipmitool), Dell iDRAC, HP iLO, KVM over IP. Évidemment c’est un peu mieux puisqu’on « voit » quelque chose cependant ça va très (trop) vite. Avec un peu de chance vous verrez « A stop job is running for… » mais on doit trouver plus exploitable.

journalctl

Si vous faites journalctl, vous afficherez les logs depuis le démarrage mais comment avoir les logs de l’extinction ? Dans un article précédent, j’avais souligné un choix par défaut discutable dans /etc/systemd/journald.conf. Faites un petit man journald.conf.

Storage=
           Controls where to store journal data. One of "volatile", "persistent", "auto" and "none". If "volatile", journal log data will be stored only in memory, i.e. below the /run/log/journal hierarchy
           (which is created if needed). If "persistent", data will be stored preferably on disk, i.e. below the /var/log/journal hierarchy (which is created if needed), with a fallback to /run/log/journal
           (which is created if needed), during early boot and if the disk is not writable.  "auto" is similar to "persistent" but the directory /var/log/journal is not created if needed, so that its
           existence controls where log data goes.  "none" turns off all storage, all log data received will be dropped. Forwarding to other targets, such as the console, the kernel log buffer, or a syslog
           socket will still work however. Defaults to "auto".

Par défaut Storage=auto, le journal est stocké dans /run/log/journal qui est perdu à chaque extinction puisque /run est un système de fichier temporaire (tmpfs). On a deux solutions pour avoir des logs de l’extinction, mettre Storage=persistent dans /etc/systemd/journald.conf ou simplement créer le dossier /var/log/journal (« so that its existence controls where log data goes », si /var/log/journal existe les logs seront envoyés dedans). Afin que la modification soit prise en compte sans rebooter (ha ha ha), on aura éventuellement besoin de faire systemctl restart systemd-journald. Faites journalctl --list-boots pour afficher les derniers boots, vous n’en aurez qu’un seul (le dernier). Maintenant si vous redémarrez votre pc/serveur puis que vous refaites journalctl --list-boots, vous en aurez deux. On va pouvoir regarder les logs de la précédente extinction

journalctl -p err sera encore utile mais perso je préfère journalctl -b -1 -n250 | grep 'timed out' # ou grep 'kill'. Cette seconde commande affiche les 250 dernières lignes (-n250) des logs du précédent boot (-b -1). C’est ainsi que j’ai trouvé mon fautif, j’ai confirmé en désactivant et stoppant le service systemctl disable --now servicerelou puis en rebootant : 40 secondes au lieu de 100.

Allons plus loin

Tout d’abord pour mieux comprendre journald, man systemd-journald. On y trouvera notamment une explication plus claire du point précédent : « By default, the journal stores log data in /run/log/journal/. Since /run/ is volatile, log data is lost at reboot. To make the data persistent, it is sufficient to create /var/log/journal/ where systemd-journald will then store the data ».

A noter que le Storage=auto fait actuellement débat, Ubuntu est revenu dessus, les arguments avancés sont très intéressants à lire.

Si /var/log/journal existe ou si vous passez Storage=persistent, attention cela signifie que vous allez avoir rsyslog qui fera son boulot ET journald. Perso je crée le dossier /var/log/journal au besoin et une fois que j’ai fini de déboguer, je le supprime.

DefaultTimeoutStartSec et DefaultTimeoutStopSec

J’ai trouvé le service responsable mais j’ai dû déboguer, je n’ai évidemment pas fait cela sur des serveurs en prod. Peut-on réduire le temps de reboot en se passant de la phase de recherche/debug ?

Déjà afin de connaître le temps d’arrêt et de démarrage d’un service, on peut utiliser time systemctl stop servicerelou et time systemctl start servicerelou.

Je vous invite maintenant à lire ceci. Les options DefaultTimeoutStartSec= et DefaultTimeoutStopSec= permettent d’influer sur le timeout par défaut du démarrage/arrêt d’un service. Si vous modifiez ces valeurs dans le fichier /etc/systemd/system.conf, c’est le timeout par défaut de tous les services que vous modifiez.

Concrètement systemd attend 90s (par défaut) qu’un service s’arrête (stop), si au bout de ces 90s il n’est pas arrêté il va le tuer (kill). On comprend dès lors que si on met DefaultTimeoutStopSec=30s, systemd n’attendra au maximum que 30 secondes avant de tuer le service nous économisant de précieuses secondes. On peut donc au choix surcharger servicerelou (à l’aide des drop-ins) ou modifier le timeout par défaut pour tous les services (via /etc/systemd/system.conf).

Attention cependant ! Tuer un service peut provoquer une perte de données. Si votre service postgresql est éléphantesque, qu’il a besoin de 43 secondes pour s’arrêter et que vous avez mis DefaultTimeoutStopSec=30s, il sera tué au bout de 30s.

On en vient à se demander si la valeur par défaut (90s) est pertinente, est-elle juste ? Chacun se fera sa propre idée, on pourrait considérer qu’un service qui ne s’arrête pas en 60s ne s’arrêtera probablement pas davantage en 90s.

On peut ruser ainsi en mettant DefaultTimeoutStopSec=60s dans /etc/systemd/system.conf suivi d’un systemctl daemon-reexec, redémarrer le serveur puis remettre DefaultTimeoutStopSec=90s suivi d’un systemctl daemon-reexec. On sera d’accord pour dire que ce n’est pas propre mais les contraintes de la prod obligent parfois à utiliser des « trucs » et des rustines pour arrondir les angles.

Conclusion

Voilà c’est ce genre de « détails » que je traite dans mon nouveau job, vous aimez ?

Et puisqu’on parle de Spectre et Meltdown, OVH décrit sur cette page la disponibilité des patchs par système d’exploitation, un lien pratique mais aussi intéressant. Pour Windows Server 2008 et 2012, il faut upgrade to Windows Server 2008/2012 R2. Il y en a qui doivent l’avoir très mauvaise, il faut racheter des licences et migrer vers une autre version lol. Ça permet aussi de suivre les plus impactés et les plus rapides à patcher, par exemple Windows Server 2016 et SUSE Linux Enterprise Server sont intégralement patchés mais Debian n’a pour l’instant patché qu’une CVE sur 3.