Un bug pénible : l'échec de formation de cluster Elasticsearch

Cet article à pour but de vous présenter un “bug” qui m’a fait perdre pas mal de temps sur la formation d’un cluster Elasticsearch.

TL;DR : Docker et Elasticsearch peut poser certains problèmes. Il faut bien renseigner network.publish_host, transport.tcp.port et http.port.

Comment le cluster Elasticsearch fonctionne grossièrement ?

Un cluster Elasticsearch (abbrévié ES dans le reste de l’article) est consituté de plusieurs instances d’ES, des noeuds (ou nodes). Chacune de ces instances doit posséder quelques éléments de configurations en commun, comme la version principale (version 7 actuellement), la configuration cluster-name, etc.

Pour connecter les noeuds, il faut utiliser ce qu’Elastic appelle un plugin (ou module) mais qui en réalité est compris dans ES sans aucune opération à effectuer. Ce plugin s’appellait Zen Discovery dans les versions précédentes, mais à partir de la version 7, ce nom n’est plus usité, et seul Discovery est employé. Je ne m’étendrai pas plus sur le fonctionnement des version < 7.

Comment le configurer ?

La documentation est relativement claire sur comment mettre en place la détection des autres noeuds d’un cluster. Au démarrage d’un noeud, si certaines instructions de configuration n’existent pas, le noeud ne démarre tout simplement pas.

Voici les clés importantes à configurer :

  • cluster.name. Comme son nom l’indique, elle contient bien évidemment le nom du cluster. Ce nom doit être identique entre tous les noeuds d’un cluster.
  • node.name qui contient le nom du noeud, pour qu’il puisse être identifié au sein du cluster. Très utile de l’avoir.
  • discovery.seed_hosts qui est la liste des hosts (+ port éventuel) à ping pour trouver les autres noeuds. Il ne faut pas préciser de protocole (http ou https par exemple) car la communication se fait via le protocole de transport d’ES, et non pas via une API REST.
  • cluster.initial_master_nodes qui contient les noms des noeuds du cluster qui sont elligibles au rôle de master.

Si ces 4 informations sont correctement configurées, le cluster peut se former et devrait fonctionner correctement.

Il est intéressant de noter que pour les versions < 7 d’ES, il fallait absolument préciser l’options discovery.zen.minimum_master_nodes pour éviter les situations de split-brain (qui provoque des dégats au cluster). Depuis la version 7, la liste des noeuds elligible au rôle de master remplace indirectement cette information de configuration.

Les ennuis commencent

Et si ça ne fonctionne pas ?

Lors de mon apprentissage d’ES (qui a commencé sur les versions 5.x) et périodiquement par la suite, à chaque fois que j’ai eu à créer un cluster, j’ai du faire fâce à des problèmes de création de cluster. Il est fréquent de tomber sur ce genre de problème sur le forum d’Elasticsearch, mais je n’ai jamais vu de check-list ou similaire pour déterminer d’où peut provenir le problème. Je vais donc tenter d’en faire une (non-exhaustive j’en ai peur) des problèmes que j’ai pu rencontrer, ou dont j’ai la connaissance, et quelques pistes pour diagnostiquer :

Les noeuds ne peuvent pas communiquer entre eux.

Pour le diagnostique :

  • se SSH sur le noeud (ou docker exec -it) et tenter de joindre l’autre noeud avec netcat ou curl sur le port de transport (défaut à 9300).

Je précise que curl est mentionné même si le port de transport n’est pas du HTTP, car il permet tout de même de déterminer si l’autre noeud est contactable et répond correctement, et est installé dans l’image d’ES de base contrairement à netcat.

Dans les raisons potentielles :

  • network.host qui n’est pas sur une ip/interface autre que celles de loopback
  • iptables qui bloque les ports
  • pas de routes (ip route show) vers la machine
  • problème de DNS
  • etc…

Les noeuds sont joignables

Pour le diagnostique :

  • des informations dans les logs qui précisent des problèmes de compréhension entre deux noeuds
  • le test de réseau ci-dessus qui réussi dans les 2 sens

Dans les causes potentielles :

  • pas la même version d’ES d’un côté que de l’autre
  • pas le même cluster.name
  • un noeud qui porte le même nom qu’un noeud déjà dans le cluster
  • xpack security mal configuré (un noeud avec l’autre sans, problème de certif, etc)
  • la configuration ne précise pas le port particulier de transport à utiliser (si différent de 9300)

Le “bug” vicieux

La motivation qui m’a poussé à écrire cet article est pour vous faire part d’un problème de formation de cluster un peu vicieux que j’ai pu rencontrer dans une situation assez précisé.

Le cluster avant

Avant de rencontrer ce bug, notre cluster ES au CRI était composé de 3 noeuds, sur docker, sur la même machine. Les 3 noeuds étaient sur le même réseau docker, mais étaient configuré pour communiquer avec les autres noeuds via l’adresse publique de la machine hôte. On avait donc le noeud 1 configuré sur le port 9300 et il était bindé sur l’hôte sur le port 9300 également. Le node 2 écoutait sur 9300 également (vu qu’il était dans un autre conteneur), mais était bind sur le port 9301 de l’hôte. De même pour le noeud 3, en écoute sur 9300 bindé sur 9302.

La configuration du noeud 1 ressemblait à quelque chose comme ça :

cluster.name: "elastic-cluster"
node.name: "node-1"
network.host: 0.0.0.0
discovery.seed_hosts:
    - docker-host.internal:9301
    - docker-host.internal:9302
cluster.initial_master_nodes:
    - "node-1"
    - "node-2"
    - "node-3"

Et tout allait pour le mieux dans le meilleur des mondes.

Aggrandissement du cluster

Pour augmenter les performances mais aussi pour réduire les risques de SPOF (vu que tous nos noeuds sont sur le même host, il est facile de se rendre compte du problème que ça pose s’il meurt), j’ai décidé de rajouter 2 autres noeuds à ce cluster, situés sur 2 autres machines (2 noeuds pour toujours rester avec un nombre impair de noeuds dans le cluster pour le split-brain scenario).

Rien ne va plus

Avec ansible je rajoute les quelques variables nécéssaires au déploiement, je déploy, et les nouveaux noeuds ne rejoignent pas le cluster. J’investigue, je regarde les logs, et rien de concluant. J’effectue les tests présentés ci-dessus, et toujours rien de concluant. Les noeuds sont joignables les uns les autres, et pourtant ils ne forment pas de cluster. Seuls les 3 noeuds pré-existant fonctionnent. Je fouille sur internet, et tombe sur une indication sur un forum :

logger.org.elasticsearch.cluster.coordination.ClusterBootstrapService: TRACE
logger.org.elasticsearch.discovery: TRACE

Ces 2 instructions à mettre dans elasticsearch.yml permet d’incrémenter la verbosité des logs de Discovery. Parfait.

Je tombe enfin sur une ligne qui m’interpelle, depuis les logs du noeud 5 (IP partiellement rédigées):

{"type": "server", "timestamp": "2019-06-10T12:43:40,430+0000", "level": "TRACE", "component": "o.e.d.HandshakingTransportAddressConnector", "cluster.name": "elastic-cluster", "node.name": "node-5",  "message": "[connectToRemoteMasterNode[192.168.0.1:9300]] opened probe connection"  }
{"type": "server", "timestamp": "2019-06-10T12:43:40,435+0000", "level": "TRACE", "component": "o.e.d.HandshakingTransportAddressConnector", "cluster.name": "elastic-cluster", "node.name": "node-5",  "message": "[connectToRemoteMasterNode[192.168.0.1:9300]] handshake successful: {node-4}{MvLB9p9_SdyLf0abarfpOA}{MhR6SIJrT4eUAUaTyXcghg}{172.18.0.2}{172.18.0.2:9300}{ml.machine_memory=7338504192, ml.max_open_jobs=20, xpack.installed=true}"  }
{"type": "server", "timestamp": "2019-06-10T12:43:40,497+0000", "level": "DEBUG", "component": "o.e.d.PeerFinder", "cluster.name": "elastic-cluster", "node.name": "node-5",  "message": "Peer{transportAddress=192.168.0.1:9300, discoveryNode=null, peersRequestInFlight=false} connection failed" ,
"stacktrace": "org.elasticsearch.transport.ConnectTransportException: [node-4][172.18.0.2:9300] handshake failed. unexpected remote node {node-5}{jBNIv4t5T1m4iV5EC7sDLA}{2olLQth-TnG5AxNfnrcTDA}{172.18.0.2}{172.18.0.2:9300}{ml.machine_memory=7315435520, ml.max_open_jobs=20, xpack.installed=true}",
"at org.elasticsearch.transport.TransportService.lambda$connectionValidator$4(TransportService.java:352) ~[elasticsearch-7.0.1-SNAPSHOT.jar:7.0.1-SNAPSHOT]",
"at org.elasticsearch.transport.ConnectionManager.connectToNode(ConnectionManager.java:105) ~[elasticsearch-7.0.1-SNAPSHOT.jar:7.0.1-SNAPSHOT]",
"at org.elasticsearch.transport.TransportService.connectToNode(TransportService.java:344) ~[elasticsearch-7.0.1-SNAPSHOT.jar:7.0.1-SNAPSHOT]",
"at org.elasticsearch.transport.TransportService.connectToNode(TransportService.java:331) ~[elasticsearch-7.0.1-SNAPSHOT.jar:7.0.1-SNAPSHOT]",
"at org.elasticsearch.discovery.HandshakingTransportAddressConnector$1.doRun(HandshakingTransportAddressConnector.java:102) [elasticsearch-7.0.1-SNAPSHOT.jar:7.0.1-SNAPSHOT]",
"at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:751) [elasticsearch-7.0.1-SNAPSHOT.jar:7.0.1-SNAPSHOT]",
"at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-7.0.1-SNAPSHOT.jar:7.0.1-SNAPSHOT]",
"at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]",
"at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]",
"at java.lang.Thread.run(Thread.java:835) [?:?]"}

Analyse

De ce que j’en comprends :

  • l1 : Le noeud 5 établi la connection avec le 4
  • l2 : Le handshake se passe bien entre les noeuds 4 et 5
  • l3 : Rien ne va plus

Mais je remarque une loucherie : Si l’IP donnée aux lignes 1 et 2 correspondent bien à l’IP du noeud 4, je constate que le noeud 4 dans ses informations est lié à une autre IP, 172.18.0.2. Un oeil averti constate directement que cette IP est liée à Docker. Ainsi, même si je précise l’IP du hôte de node-4, ce dernier arrive avec sa propre IP lors de la connexion avec node-5 et fait échouer la connexion, emmpêchant la formation du cluster.

Comment pallier cette bizarrerie ?

Je fouille un peu plus la doc, dans la section réseau et tombe sur une configuration qui pourrait être utile : network.publish_host. De base, la valeur par défaut est _best_, qui correspond à un choix d’ES pour déterminer quelle semble être la meilleur IP à choisir pour l’annoncer aux autres noeuds. Ainsi, mes noeuds dans leur conteneur Docker récupèrent l’IP du conteneur, et l’annonce publiquement. A cause de ce fonctionnement, la connexion initiale peut se faire entre les deux noeuds, mais dès que l’un donne son publisher_host à l’autre qui correspond en réalité à l’IP du conteneur, rien ne va plus. Le conteneur tente d’établir une nouvelle connexion à cette IP, et tente en réalité de se connecter à lui même, ce qui échoue. Ce bug est relativement vicieux pour plusieurs raisons :

  • Il n’est pas documenté (ou mal documenté, car je ne suis pas tombé dessus en lisant la doc d’ES)
  • Il n’est pas loggué de base
  • Il ne se produit que dans une situation particulière
  • Il intervient dans une section un peu “mystique” du fonctionne d’ES
  • Il est facilement solvable, mais nécéssite de mettre des configurations qui ne sont pas nécéssaire et qui semblent “inutiles” de prime abord.

Pourquoi ça fonctionnait avant ?

Tout simplement car les 3 premiers noeuds sont sur le même hôte et dans le même réseau Docker ! Ainsi, la connexion initiale passait par l’hôte et de la même manière, un noeud arrivait avec son publisher_host auprès d’un autre, sauf que ce publisher_host était resolvable et pointait bien vers un autre conteneur du même réseau.

Le problème s’est manifesté dès qu’un noeud a été sorti du réseau Docker initial.

La partie 2 du bug

Une fois ce problème découvert, j’ai donc mis le publisher_host, et ai redéployé les 3 premiers noeuds. Sauf que là, plus rien n’allait, ils ne pouvaient pas se joindre mutuellement pour former un cluster.

Agaçant.

Je regarde donc les logs, et cette fois-ci arrive rapidement sur une ligne qui m’interpelle, indiquant que le noeud X communique avec le noeud X au lieu du noeud Y lors du handshake. Surprenant, sachant qu’ils n’ont pas été configurés pour fonctionner ainsi. Je découvre donc que de la même manière que pour l’IP précisée pour joindre les autres noeuds, le port qu’on y accole n’est pas suffisant une fois le handshake effectué. Pour bien comprendre, je vous fait un petit exemple, de ce que j’ai compris du fonctionnement de Discovery :

Soit 2 noeuds, X et Y, avec pour IP respective de conteneur 10.0.0.1 et 10.0.0.2. Ils sont tous les deux sur la même machine, 192.168.0.1. X et Y écoutent sur le même port 9300, mais X est bind à 9300 sur l’hôte tandis que Y est bind sur 9301. De plus, ils sont dans le même réseau Docker.

Lors de la formation du cluster, voilà ce qu’il se produit depuis le noeud X :

  1. Il regarde sa configuration, et cette dernière lui dit de trouver un noeud sur 192.168.0.1:9301
  2. Il s’y connecte, et effectue un handshake avec la personne derrière. Ce dernier présente avec un noeud qui ressemble à ça : Le noeud Y existe, son IP c'est 192.168.0.1 (précisé dans son fichier de config), son port c'est 9300 (c'est son port par défaut), et il a telle configuration : ....
  3. Le noeud X voit que Y est nouveau, et décide de l’ajouter dans un cluster qu’il tente de former. Pour cela, il va le joindre via l’IP indiquée, au port indiqué. Manque de bol, 192.168.0.1:9300, c’est X, et non Y.
  4. Il se rend compte qu’il discute avec lui même (ou avec un autre noeud qui s’appelle également X), et décide d’abort la connexion

Le problème vient ici du port qu’indique le noeud Y. S’il écoute bien sur le port 9300, ce n’est pas celui là qu’il est censé indiquer, car il est joignable en réalité sur le port 9301 depuis l’extérieur.

Pour résoudre ce deuxième problème, il faut préciser transport.tcp.port. J’ai donc modifié transport.tcp.port pour le mettre sur 9301 sur le noeud Y et ai modifié le bind de port de docker pour bind le port 9301 de l’hôte avec le port 9301 du conteneur (et oui, transport.tcp.port change le port et pas uniquement l’annonce).

J’en profite aussi pour le faire sur le port http via http.port.

Une fois toutes les modifications effectuées, je re-applique mon playbook ansible, et magie : mes 5 noeuds sont dans le cluster.

Extrait de la configuration finale

cluster.name: "elastic-cluster"
node.name: "node-2"
network.host: 0.0.0.0
network.publish_host: "docker-host.internal"
transport.tcp.port: 9301
http.port: 9201
discovery.seed_hosts:
    - docker-host.internal:9300
    - docker-host.internal:9302
    - elastic-node-4.internal:9300
    - elastic-node-5.internal:9300
cluster.initial_master_nodes:
    - "node-1"
    - "node-2"
    - "node-3"
    - "node-4"
    - "node-5"
Cyril `zarak` Duval
Cyril `zarak` Duval
Étudiant

Étudiant à EPITA de la promo 2020. Membre du CRI de janvier 2018 à janvier 2020. Root CRI + Assistant (YAKA / ACU) à EPITA.

Suivant
Précédent