Florilège de bugs

Publié le 19/04/2016

Ces derniers temps, j’ai fais face à une série noire de bugs sur mes serveurs. Il y a une théorie qui dit que dans le monde du logiciel libre, vous êtes toujours responsable quand une erreur arrive. L’objectif de cet article est donc de me servir d’aide mémoire, de réfléchir sur les solutions possibles et peut-être d’aider certaines personnes qui rencontreraient ce problème.

Fuite mémoire dans le noyau Linux

Le premier bug a touché mon serveur auto-hébergé suite à une coupure de courant. Étant à 6 000km de ce dernier, ce n’est pas facile de diagnostiquer d’où vient le problème. J’ai d’abord pensé à un problème sur le réseau. Quand au final, je me suis aussi aperçu que mes graphes munin en local étaient coupés.

Graphe d'utilisation de la mémoire vive Munin

Mais par contre rien ne semble suspicieux à première vue. Donc on constate que depuis la coupure électrique et donc le redémarrage, le serveur fonctionne pendant deux heures en moyenne et se coupe. Mais est toujours sous tension. Ca ressemble beaucoup à quelque chose comme un kernel panic.

L’étape suivante la plus logique est donc de se pencher sur les logs. Pour le coup, journalctl ne m’a pas été d’une grande aide. Il n’avait qu’un historique depuis le dernier démarrage. Par contre, j’ai quand même trouvé un fichier /var/log/syslog. Un point qui me fait dire que la gestion des logs peut-être très différente en fonction des distributions Linux et de la configuration de la stack systemd & co. Et donc on trouve entre autre des centaines de lignes comme celle là :

Apr 13 19:12:02 deuxfleurs kernel: [30185.865364] Out of memory: Kill process 20580 (munin-node) score 0 or sacrifice child
Apr 13 19:12:02 deuxfleurs kernel: [30185.873404] Killed process 20580 (munin-node) total-vm:6592kB, anon-rss:228kB, file-rss:2972kB

Comme quoi notre Linux n’aurait plus de RAM. Je pensais donc au début à un processus qui utiliserait toute la RAM. Ce qui n’est pas le cas après vérification de htop. Qui plus est, on vient de le voir, Linux tue les processus qui consomment trop de RAM quand cette dernière vient à manquer.

Ayant installé netdata pour avoir un meilleur suivi, je constate l’augmentation régulière de la RAM au fur et à mesure du temps :

Graphe d'utilisation de la mémoire vive NetData

Les graphes Munin n’étaient pas assez précis pour que je puisse constater cette augmentation.

Ne reste plus que le noyau. Et tout ce qui gravite autour, noyau monolithique oblige. La première commande qui m’est conseillé est slabtop :

Active / Total Objects (% used)    : 669706 / 851401 (78,7%)
Active / Total Slabs (% used)      : 37806 / 37811 (100,0%)
Active / Total Caches (% used)     : 67 / 103 (65,0%)
Active / Total Size (% used)       : 131870,09K / 152821,89K (86,3%)
Minimum / Average / Maximum Object : 0,02K / 0,18K / 4096,00K

OBJS ACTIVE  USE OBJ SIZE  SLABS OBJ/SLAB CACHE SIZE NAME                  
203091 202656  99%    0,19K   9671       21     38684K kmalloc-192
181973  82014  45%    0,05K   2563       71     10252K buffer_head
97824  88395  90%    0,12K   3057       32     12228K dentry
79680  63313  79%    0,65K  13280        6     53120K ext4_inode_cache
50204  27400  54%    0,02K    308      163      1232K Acpi-Namespace
46872  45239  96%    0,03K    378      124      1512K kmalloc-32
36580  17572  48%    0,03K    295      124      1180K jbd2_revoke_record_s
34619  31975  92%    0,30K   2663       13     10652K radix_tree_node
25536  25496  99%    0,07K    456       56      1824K kernfs_node_cache
18612  18599  99%    0,11K    517       36      2068K ext4_groupinfo_4k
14868  13350  89%    0,09K    354       42      1416K vm_area_struct
14289  13963  97%    0,34K   1299       11      5196K inode_cache
8820   7649  86%    0,06K    140       63       560K kmalloc-node
8715   7895  90%    0,05K    105       83       420K anon_vma

Le résultat ne m’a pas semblé aberrant. Mais peut-être qu’avec des connaissances plus poussées, il aurait été possible de détecter le problème depuis slabtop.

En parallèle de ces recherches, j’avais entrepris une grosse mise à jour du système. Une fois terminée, je redémarre sur le nouveau noyau. C’est une migration du noyau

Linux deuxfleurs.fr 4.3.0-1-686-pae #1 SMP Debian 4.3.5-1 (2016-02-06) i686 GNU/Linux

au

Linux deuxfleurs.fr 4.4.0-1-686-pae #1 SMP Debian 4.4.6-1 (2016-03-17) i686 GNU/Linux

Le problème est alors résolu, je savais que ça venait du noyau car la mémoire vive augmentait de manière continue sans qu’aucune application identifiée en soit la cause. Maintenant, il s’agit de savoir où et pourquoi.

Après quelques recherches, j’ai trouvé la réponse sur la mailing list lkml. C’est bien une fuite mémoire sur un pilote qui tourne dans le noyau. Plus exactement le pilote realtek, qui est utilisé par les dongles wifi USB.

Après vérification sur ma machine, en effet il était bien là :

Bus 004 Device 002: ID 0846:9041 NetGear, Inc. WNA1000M 802.11bgn [Realtek RTL8188CUS]

Le patch tient en 2 lignes, il manquait juste un free pour libérer la mémoire allouée.

---
drivers/net/wireless/realtek/rtlwifi/usb.c | 2 ++
1 file changed, 2 insertions(+)

diff --git a/drivers/net/wireless/realtek/rtlwifi/usb.c b/drivers/net/wireless/realtek/rtlwifi/usb.c
index 2721cf8..aac1ed3 100644
--- a/drivers/net/wireless/realtek/rtlwifi/usb.c
+++ b/drivers/net/wireless/realtek/rtlwifi/usb.c
@@ -531,6 +531,8 @@ static void _rtl_usb_rx_process_noagg(struct ieee80211_hw *hw,
       ieee80211_rx(hw, skb);
     else
       dev_kfree_skb_any(skb);
+  } else {
+    dev_kfree_skb_any(skb);
   }
 }

Cet épisode fut l’occasion pour moi de découvrir comment un serveur se comporte en l’absence de mémoire vive libre, comment est géré la mémoire vive dans le noyau. J’ai eu beaucoup de chance que le bug soit déjà corrigé.

Il semble qu’un outil nommé kmemleak a été créé dans l’objectif de découvrir ce genre de bugs. La question que tout le monde se pose : est ce que ça aurait pu arriver sur Windows ? Je ne sais pas, mais Microsoft propose aussi des outils pour vérifier ses pilotes, nommés Driver Verifier.

Docker

Après plus de 200 jours d’uptime sur un CoreOS, j’ai commencé à rencontrer quelques problèmes. Mais avant de vous en faire part, je profite de ce billet pour attirer votre attention sur l’importance des fichiers .dockerignore.

En effet, lorsque vous allez lancer un docker build, ce dernier va envoyer votre contexte au daemon Docker. Le contexte, de ce que j’en ai compris est l’ensemble des fichiers dans votre répertoire courant.

Il se trouve que dans mon répertoire courant se trouve aussi les données que je veux garder (persister). Et que ces derniers peuvent faire plusieurs gigaoctets. Ces données seront alors envoyé à chaque build au daemon docker, monopolisant des ressources pour rien, et surtout ça prend du temps. Le fichier .dockerignore permet donc de préciser quels dossiers et fichiers ne pas envoyer au daemon, comme un .gitignore.

Mais revenons à nos moutons. Au bout de ces 200 jours, lorsque je relançais un conteneur, ce dernier n’avait plus accès à internet.

En relançant ce conteneur un certains nombre de fois, il a fini par fonctionner. Ce qui est vraiment bizarre. De ce que j’ai pu lire sur internet, d’autres personnes ont rencontré ce problème plus ou moins ici et .

La solution proposée est en général d’arrêter Docker, de supprimer le bridge, puis de le redémarrer. Ayant une version assez vieille, j’en ai profité pour mettre Docker à jour.

Au redémarrage, tout se passe bien, sauf qu’un container ne veut plus se lancer. L’erreur est pour le moins cryptique :

Error response from daemon: Could not find container for entity id 20d3aad...

Il me semble que cette erreur était provoquée par :

/usr/bin/docker rm php1

Encore une fois, c’est un bug connu. De ce que j’ai compris, Docker possède une base de donnée sqlite, dans lequel il stocke les id des containers, et probablement des informations à leur sujet. Il semble qu’une entrée dans cette base de donnée pointe vers un dossier n’existant plus. Il est typique de la mise à jour de docker 1.8 vers docker 1.9. La solution proposée est la suppresion de la base de données et des containers existants.

Je me suis personnellement contenté de ne plus utiliser l’identifiant php1, que j’ai remplacé par php-01. En sachant que dans ma base de donnée, cet identifiant restera un fantôme à tout jamais… ou jusqu’à que je le supprime manuellement.

Les DNS de Google

J’ai aussi un serveur VPN, partagé avec quelques amis, permettant de s’affranchir de certaines restrictions imposés par un pare feu un peu récalcitrant.

Ce dernier est configuré afin de fournir des serveurs DNS au client. Afin de me simplifier la vie, j’avais alors fourni ceux de google, les très célèbres 8.8.8.8 et 8.8.4.4.

Mon service VPN fonctionnait très bien, jusqu’au jour où plus de connexion internet. En remontant, je finis bien par découvrir que le problème vient de la résolution DNS. La commande ping fonctionne très bien mais impossible de résoudre un nom de domaine.

Mais le problème est dur à identifier, car parfois la résolution fonctionne. Ca peut être dû à plusieurs facteurs différents, mais sachez que Windows n’hésite pas à faire des requêtes sur les serveurs DNS de tous les réseaux de la machine, pouvant au passage révéler les sites que vous voulez consulter.

Depuis OpenVPN 2.3.9, il existe une option de configuration nommée block-outside-dns qui permet de résoudre ce problème sous Windows. Pour plus d’information, voici le bug report.

En passant sur le serveur, le ping fonctionne très bien. Par contre, au moment de réaliser une requête avec dig, le serveur DNS de google ne répondait plus. Finalement, j’ai décidé de tenter un autre serveur DNS, celui de mon hébergeur. Cette fois-ci ça a marché.

dig

Après avoir laissé un ticket chez mon hébergeur, voici leur réponse :

Il arrive de temps en temps que Google bloque les requêtes venant de certaines IPs ou certaines plages d’IP pour diverses raisons, je ne pourrais donc que vous inviter à utiliser d’autres serveurs DNS que les leurs.

Vous voilà donc prévenu ! Les serveurs DNS de Google c’est bien pour utilisation domestique, c’est tout !

En somme ces quelques bugs m’ont permis de découvrir beaucoup de choses - et ont aussi mis à l’épreuve mon calme légendaire…