12. Problèmes de débogage et de performance
Lorsque HAProxy est lancé avec l’option “-d”, il reste en premier plan et affiche une ligne par événement, tel qu’une connexion entrante, la fin d’une connexion, ou chaque ligne d’en-tête de requête ou de réponse observée. Cette sortie de débogage est émise avant le traitement des contenus, aussi ne tiennent-elles pas compte des modifications locales. Son usage principal consiste à afficher les requêtes et réponses sans avoir à exécuter un analyseur réseau. La lecture de la sortie devient moins aisée lorsque plusieurs connexions sont gérées en parallèle, mais les scripts “debug2ansi” et “debug2html” présents dans le répertoire examples/ aident certainement dans ce cas en colorant la sortie.
Si une requête ou une réponse HTTP/1.x est rejetée parce que HAProxy détecte qu’elle est mal formée, la meilleure action consiste à se connecter à l’interface CLI et à exécuter la commande « show errors », qui rapporte la dernière requête ou réponse HTTP/1.x incorrecte capturée pour chaque frontal et backend, accompagnée de toutes les informations nécessaires pour indiquer précisément le premier caractère du flux d’entrée rejeté. Cette information est parfois nécessaire pour prouver à des clients ou à des développeurs qu’une erreur est présente dans leur code. Dans ce cas, il est souvent possible de relâcher les vérifications (tout en conservant les captures) en utilisant l’option « option accept-unsafe-violations-in-http-request » ou son équivalent pour les réponses provenant du serveur « option accept-unsafe-violations-in-http-response ». Voir le manuel de configuration pour plus de détails.
Exemple :
La sortie de la commande « show info » en ligne de commande fournit plusieurs informations utiles concernant le débit maximal de connexions atteint, le débit maximal de clés SSL atteint, et, en général, toutes les informations pouvant aider à expliquer des problèmes temporaires liés à l’utilisation du CPU ou de la mémoire. Exemple :
Lorsqu’un problème semble apparaître de manière aléatoire sur une nouvelle version de HAProxy (par exemple, chaque deuxième requête est interrompue, crash occasionnel, etc.), il peut être utile d’activer le polluage mémoire afin que chaque appel à malloc() soit immédiatement suivi du remplissage de la zone mémoire avec un octet configurable. Par défaut, cet octet est 0x50 (caractère ‘P’ en ASCII), mais tout autre octet peut être utilisé, y compris zéro (ce qui aura le même effet qu’un calloc() et qui peut faire disparaître certains problèmes). Le polluage mémoire est activé en ligne de commande à l’aide de l’option “-dM”. Cela impacte légèrement les performances et n’est pas recommandé en production. Si un problème survient systématiquement avec cette option ou ne se produit jamais lorsque l’octet zéro est utilisé, cela indique clairement la présence d’un bug, que vous devez absolument signaler. Sinon, si aucun changement clair n’est observé, le problème n’est pas lié.
Lors du débogage de certains problèmes de latence, il est important d’utiliser à la fois strace et tcpdump sur la machine locale, ainsi qu’un autre tcpdump sur le système distant. La raison en est que des délais sont présents à chaque étape de la chaîne de traitement, et il est essentiel de déterminer celui qui cause la latence afin de savoir où intervenir. En pratique, le tcpdump local indiquera quand les données d’entrée arrivent. Strace indiquera quand haproxy reçoit ces données (via recv/recvfrom). Attention, openssl utilise des appels système read()/write() au lieu de recv()/send(). Strace indiquera également quand haproxy envoie les données, et tcpdump indiquera quand le système les envoie à l’interface. Ensuite, le tcpdump externe indiquera quand les données envoyées sont réellement reçues (puisqu’un tcpdump local ne montre que quand les paquets sont mis en file d’attente). L’avantage de capturer sur la machine locale est que strace et tcpdump utiliseront la même horloge de référence. Strace doit être utilisé avec “-tts200” pour obtenir des horodatages complets et rapporter des tronçons de données suffisamment grands pour être lus. Tcpdump doit être utilisé avec “-nvvttSs0” pour rapporter des paquets complets, des numéros de séquence réels et des horodatages complets.
En pratique, les données reçues sont presque toujours immédiatement prises en charge par HAProxy (sauf si le processeur est saturé ou si ces données sont invalides et non livrées). Si ces données sont reçues mais non envoyées, cela provient généralement d’un tampon de sortie saturé (c’est-à-dire que le destinataire ne consomme pas les données assez rapidement). Cela peut être confirmé en constatant que la surveillance ne signale pas la possibilité d’écrire sur le descripteur de fichier de sortie pendant un certain temps (il est souvent plus facile de repérer cela dans la sortie de strace lorsque les données finissent par partir, puis en remontant pour voir quand l’événement d’écriture a été signalé). Cela correspond généralement à un accusé de réception (ACK) reçu du destinataire, détecté par tcpdump. Une fois les données envoyées, elles peuvent passer un certain temps dans le système sans action. Là encore, la fenêtre de congestion TCP peut être limitée et empêcher ces données de sortir, en attendant un ACK pour ouvrir la fenêtre. Si le trafic est inactif et que les données mettent 40 ms ou 200 ms à sortir, il s’agit d’un autre problème (qui n’est pas un problème), à savoir que l’algorithme de Nagle empêche les paquets vides de sortir immédiatement, dans l’espoir qu’ils soient fusionnés avec des données ultérieures. HAProxy désactive automatiquement Nagle en mode TCP pur et dans les tunnels. Toutefois, il reste activé lors du transfert d’un corps HTTP (ce qui contribue à l’amélioration des performances en réduisant le nombre de paquets). Certains applications HTTP non conformes peuvent être sensibles à la latence lors de la livraison de messages de réponse HTTP incomplets. Dans ce cas, vous devrez activer « option http-no-delay » pour désactiver Nagle afin de contourner leur conception, tout en gardant à l’esprit que tout autre proxy de la chaîne peut être affecté de manière similaire. Si tcpdump indique que les données partent immédiatement mais que l’autre extrémité ne les voit pas rapidement, cela peut signifier qu’il y a une liaison WAN saturée, un LAN saturé avec le contrôle de flux activé empêchant les données de sortir, ou plus couramment que HAProxy fonctionne effectivement dans une machine virtuelle et que, pour une raison quelconque, l’hyperviseur a décidé que les données n’avaient pas besoin d’être envoyées immédiatement. Dans les environnements virtualisés, les problèmes de latence sont presque toujours dus à la couche de virtualisation, aussi vaut-il la peine, pour gagner du temps, de comparer tout d’abord les sorties tcpdump dans la machine virtuelle et sur les composants externes. Toute différence doit être attribuée à l’hyperviseur et à ses pilotes associés.
Lorsque des segments TCP SACK apparaissent dans les traces tcpdump (en utilisant -vv), cela signifie toujours que le côté émetteur dispose de la preuve de la perte d’un paquet. Le fait de ne pas les voir ne signifie pas qu’il n’y a pas de pertes, mais leur présence indique clairement que le réseau est sujet aux pertes. Les pertes sont normales sur un réseau, mais à un taux tel que les SACK ne sont pas perceptibles à l’œil nu. Si elles apparaissent fréquemment dans les traces, il est recommandé d’investiguer précisément ce qui se passe et où les paquets sont perdus. HTTP ne gère pas bien les pertes TCP, qui entraînent des latences importantes.
La commande « netstat -i » affiche les statistiques par interface. Une interface dont le compteur Rx-Ovr augmente indique que le système ne dispose pas de ressources suffisantes pour recevoir tous les paquets entrants, qui sont perdus avant d’être traités par le pilote réseau. Rx-Drp indique que certains paquets reçus ont été perdus dans la pile réseau parce que l’application ne les traite pas assez rapidement. Cela peut survenir également lors de certaines attaques. Tx-Drp signifie que les files de sortie étaient pleines et que des paquets ont dû être abandonnés. En utilisant TCP, cela devrait être très rare, mais peut indiquer une liaison sortante saturée.