Article sur les bugs

This commit is contained in:
Quentin Dufour 2016-04-19 14:55:09 -04:00
parent 21ff18ad9e
commit 594ee3df93
8 changed files with 262 additions and 81 deletions

View File

@ -1,3 +1,6 @@
source 'https://rubygems.org'
gem 'github-pages'
gem 'jekyll-sitemap'
gem 'jekyll'
gem 'jekyll-paginate'
gem 'rouge'

View File

@ -2,128 +2,131 @@ GEM
remote: https://rubygems.org/
specs:
RedCloth (4.2.9)
activesupport (4.2.3)
activesupport (4.2.6)
i18n (~> 0.7)
json (~> 1.7, >= 1.7.7)
minitest (~> 5.1)
thread_safe (~> 0.3, >= 0.3.4)
tzinfo (~> 1.1)
blankslate (2.1.2.4)
celluloid (0.16.0)
timers (~> 4.0.0)
classifier-reborn (2.0.3)
fast-stemmer (~> 1.0)
addressable (2.4.0)
coffee-script (2.4.1)
coffee-script-source
execjs
coffee-script-source (1.9.1.1)
coffee-script-source (1.10.0)
colorator (0.1)
execjs (2.5.2)
fast-stemmer (1.0.2)
ethon (0.8.1)
ffi (>= 1.3.0)
execjs (2.6.0)
faraday (0.9.2)
multipart-post (>= 1.2, < 3)
ffi (1.9.10)
gemoji (2.1.0)
github-pages (38)
github-pages (72)
RedCloth (= 4.2.9)
github-pages-health-check (~> 0.2)
jekyll (= 2.4.0)
github-pages-health-check (= 1.1.0)
jekyll (= 3.0.3)
jekyll-coffeescript (= 1.0.1)
jekyll-feed (= 0.3.0)
jekyll-mentions (= 0.2.1)
jekyll-redirect-from (= 0.8.0)
jekyll-sass-converter (= 1.2.0)
jekyll-sitemap (= 0.8.1)
jemoji (= 0.4.0)
kramdown (= 1.5.0)
liquid (= 2.6.2)
maruku (= 0.7.0)
jekyll-feed (= 0.5.1)
jekyll-gist (= 1.4.0)
jekyll-github-metadata (= 1.11.0)
jekyll-mentions (= 1.1.2)
jekyll-paginate (= 1.1.0)
jekyll-redirect-from (= 0.10.0)
jekyll-sass-converter (= 1.3.0)
jekyll-seo-tag (= 1.3.3)
jekyll-sitemap (= 0.10.0)
jekyll-textile-converter (= 0.1.0)
jemoji (= 0.6.2)
kramdown (= 1.10.0)
liquid (= 3.0.6)
mercenary (~> 0.3)
pygments.rb (= 0.6.3)
rdiscount (= 2.1.7)
redcarpet (= 3.3.1)
rdiscount (= 2.1.8)
redcarpet (= 3.3.3)
rouge (= 1.10.1)
terminal-table (~> 1.4)
github-pages-health-check (0.3.1)
net-dns (~> 0.6)
github-pages-health-check (1.1.0)
addressable (~> 2.3)
net-dns (~> 0.8)
octokit (~> 4.0)
public_suffix (~> 1.4)
hitimes (1.2.2)
html-pipeline (1.9.0)
activesupport (>= 2)
nokogiri (~> 1.4)
typhoeus (~> 0.7)
html-pipeline (2.4.0)
activesupport (>= 2, < 5)
nokogiri (>= 1.4)
i18n (0.7.0)
jekyll (2.4.0)
classifier-reborn (~> 2.0)
jekyll (3.0.3)
colorator (~> 0.1)
jekyll-coffeescript (~> 1.0)
jekyll-gist (~> 1.0)
jekyll-paginate (~> 1.0)
jekyll-sass-converter (~> 1.0)
jekyll-watch (~> 1.1)
kramdown (~> 1.3)
liquid (~> 2.6.1)
liquid (~> 3.0)
mercenary (~> 0.3.3)
pygments.rb (~> 0.6.0)
redcarpet (~> 3.1)
rouge (~> 1.7)
safe_yaml (~> 1.0)
toml (~> 0.1.0)
jekyll-coffeescript (1.0.1)
coffee-script (~> 2.2)
jekyll-feed (0.3.0)
jekyll-gist (1.2.1)
jekyll-mentions (0.2.1)
html-pipeline (~> 1.9.0)
jekyll (~> 2.0)
jekyll-feed (0.5.1)
jekyll-gist (1.4.0)
octokit (~> 4.2)
jekyll-github-metadata (1.11.0)
octokit (~> 4.0)
jekyll-mentions (1.1.2)
html-pipeline (~> 2.3)
jekyll (~> 3.0)
jekyll-paginate (1.1.0)
jekyll-redirect-from (0.8.0)
jekyll-redirect-from (0.10.0)
jekyll (>= 2.0)
jekyll-sass-converter (1.2.0)
jekyll-sass-converter (1.3.0)
sass (~> 3.2)
jekyll-sitemap (0.8.1)
jekyll-watch (1.2.1)
listen (~> 2.7)
jemoji (0.4.0)
jekyll-seo-tag (1.3.3)
jekyll (~> 3.0)
jekyll-sitemap (0.10.0)
jekyll-textile-converter (0.1.0)
RedCloth (~> 4.0)
jekyll-watch (1.3.1)
listen (~> 3.0)
jemoji (0.6.2)
gemoji (~> 2.0)
html-pipeline (~> 1.9)
jekyll (~> 2.0)
html-pipeline (~> 2.2)
jekyll (>= 3.0)
json (1.8.3)
kramdown (1.5.0)
liquid (2.6.2)
listen (2.10.1)
celluloid (~> 0.16.0)
kramdown (1.10.0)
liquid (3.0.6)
listen (3.0.6)
rb-fsevent (>= 0.9.3)
rb-inotify (>= 0.9)
maruku (0.7.0)
mercenary (0.3.5)
mini_portile (0.6.2)
minitest (5.7.0)
rb-inotify (>= 0.9.7)
mercenary (0.3.6)
minitest (5.8.4)
multipart-post (2.0.0)
net-dns (0.8.0)
nokogiri (1.6.6.2)
mini_portile (~> 0.6.0)
parslet (1.5.0)
blankslate (~> 2.0)
posix-spawn (0.3.11)
public_suffix (1.5.1)
pygments.rb (0.6.3)
posix-spawn (~> 0.3.6)
yajl-ruby (~> 1.2.0)
rb-fsevent (0.9.5)
rb-inotify (0.9.5)
nokogiri (1.6.7.2)
octokit (4.3.0)
sawyer (~> 0.7.0, >= 0.5.3)
public_suffix (1.5.3)
rb-fsevent (0.9.7)
rb-inotify (0.9.7)
ffi (>= 0.5.0)
rdiscount (2.1.7)
redcarpet (3.3.1)
rdiscount (2.1.8)
redcarpet (3.3.3)
rouge (1.10.1)
safe_yaml (1.0.4)
sass (3.4.16)
sass (3.4.22)
sawyer (0.7.0)
addressable (>= 2.3.5, < 2.5)
faraday (~> 0.8, < 0.10)
terminal-table (1.5.2)
thread_safe (0.3.5)
timers (4.0.1)
hitimes
toml (0.1.2)
parslet (~> 1.5.0)
typhoeus (0.8.0)
ethon (>= 0.8.0)
tzinfo (1.2.2)
thread_safe (~> 0.1)
yajl-ruby (1.2.1)
PLATFORMS
ruby
DEPENDENCIES
github-pages
jekyll
jekyll-paginate
jekyll-sitemap
rouge

View File

@ -5,7 +5,7 @@ meta_description: "Quentin Dufour. Let's hack !"
aboutPage: true
markdown: redcarpet
highlighter: pygments
highlighter: rouge
paginate: 20
domain_name: 'http://quentin.dufour.io'
@ -35,3 +35,4 @@ defaults:
gems:
- jekyll-sitemap
- jekyll-paginate

View File

@ -0,0 +1,174 @@
---
layout: post
slug: quelques-bugs-etonnants
status: published
title: Quelques bugs étonnants
description: Et l'histoire qui va avec !
categories: linux
tags:
---
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](http://munin-monitoring.org/) en local étaient coupés.
![Graphe d'utilisation de la mémoire vive Munin](/assets/images/posts/bugs-munin-1.png)
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](https://github.com/firehol/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](/assets/images/posts/bugs-netdata-1.png)
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
```none
Linux deuxfleurs.fr 4.3.0-1-686-pae #1 SMP Debian 4.3.5-1 (2016-02-06) i686 GNU/Linux
```
au
```none
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](https://lkml.org/lkml/2015/12/6/113). 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à :
```none
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.
```diff
---
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 comme 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](https://www.kernel.org/doc/Documentation/kmemleak.txt) 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](https://msdn.microsoft.com/en-us/library/windows/hardware/ff545448(VS.85).aspx).
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](https://bugs.launchpad.net/ubuntu/+source/docker.io/+bug/1509867) et [](https://github.com/docker/docker/issues/866#issuecomment-19218300).
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 :
```none
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](https://github.com/docker/docker/issues/17691). 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](https://community.openvpn.net/openvpn/ticket/605).
Afin de trouver pourquoi la résolution ne fonctionnait pas, j'ai quand même vérifié si 8.8.8.8 était accessible en le pingant. Tout fonctionnait 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, ceux de mon hébergeur. Cette fois-ci ça a marché.
![dig](/assets/images/posts/bugs-dns-2.png)
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 3-4 bugs assez intéressants, qui m'ont permis de découvrir beaucoup de choses mais qui ont aussi mis à l'épreuve mon calme légendaire...

Binary file not shown.

After

Width:  |  Height:  |  Size: 64 KiB

Binary file not shown.

After

Width:  |  Height:  |  Size: 30 KiB

Binary file not shown.

After

Width:  |  Height:  |  Size: 58 KiB

Binary file not shown.

After

Width:  |  Height:  |  Size: 29 KiB