8. Journalisation
L’un des points forts d’HAProxy réside certainement dans ses journaux précis. Il fournit probablement le niveau d’information le plus poussé disponible pour un tel produit, ce qui est essentiel pour le dépannage des environnements complexes. Les informations standard fournies dans les journaux incluent les ports clients, les compteurs d’état TCP/HTTP, l’état précis du flux à la terminaison et la cause précise de la terminaison, des informations sur les décisions visant à acheminer le trafic vers un serveur, ainsi que, bien entendu, la capacité à capturer des en-têtes arbitraires.
Afin d’améliorer la réactivité des administrateurs, il offre une grande transparence concernant les problèmes rencontrés, qu’ils soient internes ou externes, et il est possible d’envoyer les journaux vers différentes sources simultanément, avec des filtres de niveau différents :
- journaux au niveau du processus global (erreurs système, démarrage/arrêt, etc.)
- erreurs système et internes par instance (manque de ressources, bugs, …)
- problèmes externes par instance (serveurs actifs/inactifs, nombre maximal de connexions)
- activité par instance (connexions clients), soit à l’établissement, soit à la fermeture.
- contrôle du niveau de journalisation par requête, par exemple http-request set-log-level silent si sensitive_request
La possibilité de distribuer différents niveaux de journaux vers des serveurs de journaux distincts permet à plusieurs équipes de production d’interagir et de résoudre leurs problèmes aussi rapidement que possible. Par exemple, l’équipe système peut surveiller les erreurs à l’échelle du système, tandis que l’équipe application peut surveiller en temps réel l’état actif/inactif de leurs serveurs, et l’équipe sécurité peut analyser les journaux d’activité avec un délai d’une heure.
8.1. Niveaux de journalisation
Les connexions TCP et HTTP peuvent être journalisées avec des informations telles que la date, l’heure, l’adresse IP source, l’adresse de destination, la durée de la connexion, les temps de réponse, la requête HTTP, le code de retour HTTP, le nombre d’octets transmis, les conditions d’arrêt du flux, ainsi que les valeurs des cookies échangés. Par exemple, suivre les problèmes d’un utilisateur particulier. Tous les messages peuvent être envoyés à jusqu’à deux serveurs syslog. Consultez le mot-clé « log » dans la section 4.2 pour plus d’informations sur les installations de journalisation.
8.2. Formats de journalisation
HAProxy prend en charge 5 formats de journalisation. Plusieurs champs sont communs à ces formats et seront détaillés dans les sections suivantes. Certains de ces champs peuvent varier légèrement selon la configuration, en raison d’indicateurs propres à certaines options. Les formats pris en charge sont les suivants :
le format par défaut, très basique et très rarement utilisé. Il ne fournit que des informations très élémentaires sur la connexion entrante au moment où elle est acceptée : adresse IP source:port, adresse IP destination:port et nom du frontal. Ce mode sera progressivement supprimé, aussi ne sera-t-il pas décrit en détail.
le format TCP, qui est plus avancé. Ce format est activé lorsque « option tcplog » est configuré sur le frontal. HAProxy attend alors généralement la fermeture de la connexion avant d’effectuer la journalisation. Ce format fournit des informations bien plus riches, telles que les compteurs de temps, le nombre de connexions, la taille de la file d’attente, etc. Ce format est recommandé pour les proxies TCP purs.
le format HTTP, le plus avancé pour le proxy HTTP. Ce format est activé lorsque « option httplog » est définie sur le frontal. Il fournit les mêmes informations que le format TCP, complétées par des champs spécifiques à HTTP tels que la requête, le code d’état, ainsi que les captures d’en-têtes et de cookies. Ce format est recommandé pour les proxies HTTP.
le format CLF HTTP, qui est équivalent au format HTTP, mais avec les champs disposés dans le même ordre que le format CLF. En ce mode, tous les compteurs, captures, indicateurs, etc. apparaissent un par champ après la fin des champs communs, dans le même ordre qu’ils apparaissent dans le format HTTP standard.
le format de journal personnalisé, vous permet de définir votre propre ligne de journal.
Les sections suivantes approfondiront les détails relatifs à chacun de ces formats. La spécification du format sera effectuée au niveau de chaque « champ ». À moins d’indication contraire, un champ correspond à une portion de texte délimitée par un nombre quelconque d’espaces. Étant donné que les serveurs syslog peuvent insérer des champs au début d’une ligne, il est toujours supposé que le premier champ contient le nom du processus et son identifiant.
Note : Étant donné que les lignes de journalisation peuvent être assez longues, les exemples de journaux présentés dans les sections suivantes peuvent être divisés en plusieurs lignes. Les lignes d’exemple de journalisation seront précédées de trois chevrons fermants (’>>>’) et, chaque fois qu’une ligne de journalisation est divisée en plusieurs lignes, chaque ligne non finale se terminera par une barre oblique inverse (’\’) et la ligne suivante commencera indentée de deux caractères.
8.2.1. Format de journal par défaut
Ce format est utilisé lorsque aucune option spécifique n’est définie. Le journal est émis dès l’acceptation de la connexion. Il convient de noter qu’il s’agit actuellement du seul format qui enregistre l’adresse IP et les ports de destination de la requête.
Exemple :
Champ Format Extraits de l’exemple ci-dessus 1 process_name ‘[’ pid ‘]:’ HAProxy[14385]: 2 ‘Connect from’ Connect from 3 source_ip ‘:’ source_port 10.0.1.2:33312 4 ’to’ to 5 destination_ip ‘:’ destination_port 10.0.3.31:8012 6 ‘(’ frontend_name ‘/’ mode ‘)’ (www/HTTP)
Description détaillée des champs :
- “source_ip” est l’adresse IP du client ayant initié la connexion.
- “source_port” est le port TCP du client ayant initié la connexion.
- “destination_ip” est l’adresse IP vers laquelle le client s’est connecté.
- “destination_port” est le port TCP vers lequel le client s’est connecté.
- “frontend_name” est le nom du frontal (ou écouteur) qui a reçu et traité la connexion.
- “mode est le mode d’opération du frontal (TCP ou HTTP).
En cas de socket UNIX, les adresses source et destination sont marquées par « unix: » et les ports correspondent à l’identifiant interne du socket ayant accepté la connexion (identifiant identique à celui rapporté dans les statistiques).
Il est recommandé de ne pas utiliser ce format obsolète pour les nouvelles installations, car il disparaîtra tôt ou tard.
8.2.2. Format de journalisation TCP
Le format TCP est utilisé lorsque l’option « option tcplog » est spécifiée dans le frontal, et constitue le format recommandé pour les proxies TCP purs. Il fournit une quantité d’informations précieuses pour le dépannage. Étant donné que ce format inclut des compteurs de temps et de bytes, le journal est normalement émis à la fin de la session. Il peut être émis plus tôt si l’option « option logasap » est spécifiée, ce qui est pertinent dans la plupart des environnements présentant des sessions longues, comme les terminaux distants. Les sessions correspondant aux règles « monitor » ne sont jamais journalisées. Il est également possible de ne pas émettre de journal pour les sessions durant lesquelles aucune donnée n’a été échangée entre le client et le serveur, en spécifiant « option dontlognull » dans le frontal. Les connexions réussies ne seront pas journalisées si l’option « option dontlog-normal » est spécifiée dans le frontal.
Le format de journalisation TCP est déclaré internement comme un format de journalisation personnalisé basé sur la chaîne exacte suivante, qui peut également servir de base à l’extension du format si nécessaire. En outre, la variable HAPROXY_TCP_LOG_FMT peut être utilisée à la place. Reportez-vous à la section 8.2.6 « Format de journalisation personnalisé » pour savoir comment l’utiliser :
Et le format de journal CLF est déclaré internement comme un format de journal personnalisé basé sur cette chaîne exacte :
Quelques champs peuvent légèrement varier en fonction de certaines options de configuration ; ceux-ci sont marqués d’une étoile (’*’) après leur nom ci-dessous.
Exemple :
| Champ | Format | Extraction à partir de l’exemple ci-dessus |
|---|---|---|
| 1 | process_name ‘[’ pid ‘]:’ | HAProxy[14387]: |
| 2 | client_ip ‘:’ client_port | 10.0.1.2:33313 |
| 3 | ‘[’ accept_date ‘]’ | [06/Feb/2009:12:12:51.443] |
| 4 | frontend_name | fnt |
| 5 | backend_name ‘/’ server_name | bck/srv1 |
| 6 | Tw ‘/’ Tc ‘/’ Tt* | 0/0/5007 |
| 7 | bytes_read* | 212 |
| 8 | termination_state | – |
| 9 | actconn ‘/’ feconn ‘/’ beconn ‘/’ srv_conn ‘/’ retries* | 0/0/0/0/3 |
| 10 | srv_queue ‘/’ backend_queue | 0/0 |
Description détaillée des champs :
“client_ip” est l’adresse IP du client ayant initié la connexion TCP vers HAProxy. Si la connexion a été acceptée sur une socket UNIX, l’adresse IP est remplacée par le mot « unix ». Notez que lorsque la connexion est acceptée sur une socket configurée avec « accept-proxy » et que le protocole PROXY est correctement utilisé, ou avec « accept-netscaler-cip » et que le protocole d’insertion de l’IP client NetScaler est correctement utilisé, les journaux reflètent alors les informations de la connexion transférée.
“client_port” est le port TCP du client ayant initié la connexion. Si la connexion a été acceptée via une socket UNIX, le port est remplacé par l’identifiant de la socket d’acceptation, qui est également rapporté dans l’interface de statistiques.
“accept_date” est la date exacte à laquelle la connexion a été reçue par HAProxy (qui peut différer légèrement de la date observée sur le réseau en cas de mise en file d’attente dans la file de connexion du système). Cette date correspond généralement à celle qui peut apparaître dans les journaux de tout pare-feu en amont. En mode HTTP, le champ accept_date est réinitialisé au moment où la connexion est prête à recevoir une nouvelle requête (fin de la réponse précédente pour HTTP/1, immédiatement après la requête précédente pour HTTP/2).
“frontend_name” est le nom du frontal (ou de l’écouteur) qui a reçu et traité la connexion.
“backend_name” est le nom du backend (ou de l’écouteur) qui a été sélectionné pour gérer la connexion au serveur. Ce nom est identique à celui du frontal si aucune règle de commutation n’a été appliquée, ce qui est courant pour les applications TCP.
“server_name” est le nom du dernier serveur vers lequel la connexion a été envoyée, qui peut différer du premier si des erreurs de connexion ont eu lieu et qu’une redistribution a été effectuée. Notez que ce serveur appartient au backend qui a traité la requête. Si la connexion a été interrompue avant d’atteindre un serveur, “
<NOSRV>” est indiqué à la place du nom du serveur.“Tw” correspond au temps total, en millisecondes, passé en attente dans les différentes files d’attente. Il peut prendre la valeur “-1” si la connexion a été interrompue avant d’atteindre la file d’attente. Voir « Horloges » ci-dessous pour plus de détails.
« Tc » est le temps total, en millisecondes, passé en attente de l’établissement de la connexion avec le serveur final, y compris les tentatives de reconnexion. Il peut être “-1” si la connexion a été interrompue avant qu’une connexion ne puisse être établie. Voir « Horloges » ci-dessous pour plus de détails.
« Tt » est le temps total, en millisecondes, écoulé entre l’acceptation et la fermeture finale. Il couvre toutes les étapes de traitement possibles. Une exception existe : si l’option « option logasap » est spécifiée, le comptage du temps s’arrête au moment de l’émission du journal. Dans ce cas, un signe « + » est ajouté avant la valeur, indiquant que la valeur finale sera plus élevée. Voir « Chronomètres » ci-dessous pour plus de détails.
“bytes_read” est le nombre total d’octets transmis du serveur vers le client au moment de l’émission du journal. Si l’option logasap est spécifiée, cette valeur sera précédée du signe ‘+’ pour indiquer que la valeur finale peut être plus élevée. Veuillez noter que cette valeur est un compteur 64 bits, les outils d’analyse des journaux doivent donc être capables de la gérer sans débordement.
“termination_state” est l’état dans lequel la session se trouvait lors de sa fermeture. Cela indique l’état de la session, le côté ayant provoqué la fermeture, ainsi que la raison (délai d’expiration, erreur, …). Les indicateurs normaux doivent être “–”, ce qui signifie que la session a été fermée par l’une ou l’autre extrémité sans données restantes dans les tampons. Voir ci-dessous « État du flux à la déconnexion » pour plus de détails.
“actconn” correspond au nombre total de connexions simultanées sur le processus au moment où la session a été journalisée. Cette information est utile pour détecter lorsque certains plafonds système par processus ont été atteints. Par exemple, si “actconn” est proche de 512 lorsqu’apparaissent plusieurs erreurs de connexion, il est fort probable que le système limite le processus à un maximum de 1024 descripteurs de fichiers, et que tous soient utilisés. Voir section 3 “Section globale” pour savoir comment ajuster le système.
« feconn » est le nombre total de connexions simultanées sur le frontal au moment où la session a été journalisée. Cette information est utile pour estimer les ressources nécessaires afin de supporter des charges élevées, et pour détecter lorsque la limite « maxconn » du frontal a été atteinte. En général, une augmentation brutale de cette valeur indique une congestion sur les serveurs backend, mais elle peut aussi être due à une attaque par déni de service.
« beconn » correspond au nombre total de connexions simultanées gérées par le backend au moment où la session a été journalisée. Il inclut le nombre total de connexions simultanées actives sur les serveurs ainsi que le nombre de connexions en attente dans les files d’attente. Cette information est utile pour estimer le nombre de serveurs supplémentaires nécessaires afin de supporter des charges élevées pour une application donnée. En général, lorsque cette valeur augmente brusquement, cela indique une congestion sur les serveurs backend, mais cela peut aussi être dû à une attaque par déni de service.
“srv_conn” est le nombre total de connexions simultanées encore actives sur le serveur au moment où la session a été journalisée. Il ne peut jamais dépasser le paramètre configuré « maxconn » du serveur. Si cette valeur est très souvent proche ou égale à « maxconn » du serveur, cela signifie que la régulation du trafic est très fréquente, ce qui indique soit que la valeur « maxconn » du serveur est trop faible, soit qu’il n’y a pas assez de serveurs pour traiter la charge avec un temps de réponse optimal. Lorsqu’un seul des serveurs “srv_conn” est élevé, cela signifie généralement que ce serveur rencontre des difficultés entraînant un traitement des connexions plus lent que sur les autres serveurs.
“retries” correspond au nombre de tentatives de connexion effectuées par cette session lors de la tentative de connexion au serveur. Il doit normalement être égal à zéro, sauf si le serveur est arrêté au moment précis où la connexion est tentée. Un nombre élevé de tentatives indique généralement un problème réseau entre HAProxy et le serveur, ou une file d’attente de connexion mal configurée sur le serveur empêchant les nouvelles connexions d’être mises en file. Ce champ peut éventuellement être précédé du signe ‘+’ pour indiquer que la session a été réacheminée après avoir atteint le nombre maximal de tentatives sur le serveur initial. Dans ce cas, le nom du serveur apparaissant dans le journal est celui vers lequel la connexion a été réacheminée, et non celui du premier serveur, bien que les deux puissent parfois être identiques, par exemple en cas de hachage. En règle générale, lorsqu’un ‘+’ est présent devant le nombre de tentatives, ce nombre ne doit pas être attribué au serveur indiqué dans le journal.
“srv_queue” est le nombre total de requêtes traitées avant celle-ci dans la file du serveur. Il vaut zéro lorsque la requête n’a pas traversé la file du serveur. Il permet d’estimer le temps de réponse approximatif du serveur en divisant le temps passé en file par le nombre de requêtes dans la file. Il convient de noter qu’en cas de réacheminement, si une session traverse deux files du serveur, leurs positions s’additionnent. Une requête ne doit pas traverser à la fois la file du serveur et la file du backend, sauf en cas de réacheminement.
“backend_queue” est le nombre total de requêtes traitées avant celle-ci dans la file d’attente globale du backend. Il vaut zéro lorsque la requête n’a pas traversé la file d’attente globale. Ce chiffre permet d’estimer la longueur moyenne de la file, qui se traduit aisément en nombre de serveurs manquants lorsqu’elle est divisée par le paramètre “maxconn” d’un serveur. Il convient de noter qu’en cas de redirigabilité d’une session, une requête peut passer deux fois par la file du backend, et les deux positions seront alors cumulées. Une requête ne doit pas traverser à la fois la file du serveur et la file du backend, sauf en cas de redirigabilité.
8.2.3. Format de journalisation HTTP
Le format HTTP est le plus complet et le mieux adapté aux proxies HTTP. Il est activé lorsque « option httplog » est spécifié dans le frontal. Il fournit le même niveau d’information que le format TCP, avec des fonctionnalités supplémentaires propres au protocole HTTP. Tout comme le format TCP, la journalisation a généralement lieu à la fin du flux, sauf si « option logasap » est spécifiée, ce qui n’a généralement de sens que pour les sites de téléchargement. Les flux correspondant aux règles « monitor » ne sont jamais journalisés. Il est également possible de ne pas journaliser les flux pour lesquels le client n’a envoyé aucune donnée en spécifiant « option dontlognull » dans le frontal. Les connexions réussies ne sont pas journalisées si « option dontlog-normal » est spécifié dans le frontal.
Le format de journalisation HTTP est déclaré internement comme un format de journalisation personnalisé basé sur la chaîne exacte suivante, qui peut également servir de base pour étendre le format si nécessaire. En outre, la variable HAPROXY_HTTP_LOG_FMT peut être utilisée à la place. Reportez-vous à la section 8.2.6 « Format de journalisation personnalisé » pour savoir comment l’utiliser :
Et le format de journal CLF est déclaré internement comme un format de journal personnalisé basé sur cette chaîne exacte :
La plupart des champs sont communs au journal TCP, certains étant différents. Quelques champs peuvent légèrement varier selon certaines options de configuration. Ceux-ci sont marqués d’une étoile (’*’) après leur nom ci-dessous.
Exemple :
Champ Format Extraire de l’exemple ci-dessus 1 process_name ‘[’ pid ‘]:’ HAProxy[14389]: 2 client_ip ‘:’ client_port 10.0.1.2:33317 3 ‘[’ request_date ‘]’ [06/Feb/2009:12:14:14.655] 4 frontend_name http-in 5 backend_name ‘/’ server_name static/srv1 6 TR ‘/’ Tw ‘/’ Tc ‘/’ Tr ‘/’ Ta* 10/0/30/69/109 7 status_code 200 8 bytes_read* 2750 9 captured_request_cookie - 10 captured_response_cookie - 11 termination_state —- 12 actconn ‘/’ feconn ‘/’ beconn ‘/’ srv_conn ‘/’ retries* 1/1/1/1/0 13 srv_queue ‘/’ backend_queue 0/0 14 ‘{’ captured_request_headers* ‘}’ {HAProxy.1wt.eu} 15 ‘{’ captured_response_headers* ‘}’ {} 16 ‘”’ http_request ‘"’ “GET /index.html HTTP/1.1”
Description détaillée des champs :
“client_ip” est l’adresse IP du client ayant initié la connexion TCP vers HAProxy. Si la connexion a été acceptée sur une socket UNIX, l’adresse IP est remplacée par le mot « unix ». Notez que lorsque la connexion est acceptée sur une socket configurée avec « accept-proxy » et que le protocole PROXY est correctement utilisé, ou avec « accept-netscaler-cip » et que le protocole d’insertion de l’IP client NetScaler est correctement utilisé, les journaux reflètent alors les informations de la connexion transférée.
“client_port” est le port TCP du client ayant initié la connexion. Si la connexion a été acceptée via une socket UNIX, le port est remplacé par l’identifiant de la socket d’acceptation, qui est également rapporté dans l’interface de statistiques.
“request_date” est la date exacte à laquelle le premier octet de la requête HTTP a été reçu par HAProxy (champ de journalisation %tr).
“frontend_name” est le nom du frontal (ou de l’écouteur) qui a reçu et traité la connexion.
“backend_name” est le nom du backend (ou de l’écouteur) qui a été sélectionné pour gérer la connexion au serveur. Ce nom est identique à celui du frontal si aucune règle de commutation n’a été appliquée.
“server_name” est le nom du dernier serveur vers lequel la connexion a été envoyée, qui peut différer du premier si des erreurs de connexion ont entraîné une redistribution. Notez que ce serveur appartient au backend ayant traité la requête. Si la requête a été interrompue avant d’atteindre un serveur, “
<NOSRV>” est indiqué à la place du nom du serveur. Si la requête a été interceptée par le sous-système de statistiques, “<STATS>” est indiqué à la place.“TR” correspond au temps total, en millisecondes, passé à attendre la réception complète d’une requête HTTP depuis le client (sans compter le corps) après la réception du premier octet. Il peut prendre la valeur “-1” si la connexion a été interrompue avant la réception d’une requête complète ou si une requête invalide a été reçue. Ce temps doit toujours être très faible, car une requête s’inscrit généralement dans un seul paquet. Des valeurs élevées indiquent généralement des problèmes réseau entre le client et HAProxy ou des requêtes saisies manuellement. Voir section 8.4 « Événements de temporisation » pour plus de détails.
« Tw » est le temps total, en millisecondes, passé en attente dans les différentes files d’attente. Il peut être “-1” si la connexion a été interrompue avant d’atteindre la file d’attente. Voir section 8.4 « Événements de temporisation » pour plus de détails.
« Tc » est le temps total, en millisecondes, passé en attente de l’établissement de la connexion avec le serveur final, y compris les tentatives de reconnexion. Il peut être “-1” si la requête a été interrompue avant qu’une connexion ne puisse être établie. Voir section 8.4 « Événements de temporisation » pour plus de détails.
« Tr » est le temps total, en millisecondes, passé à attendre que le serveur envoie une réponse HTTP complète, sans compter les données. Il peut valoir “-1” si la requête a été interrompue avant qu’une réponse complète ne puisse être reçue. Il correspond généralement au temps de traitement du serveur pour la requête, bien qu’il puisse être modifié par la quantité de données envoyées par le client au serveur. Des temps élevés pour les requêtes « GET » indiquent généralement un serveur surchargé. Voir section 8.4 « Événements de temporisation » pour plus de détails.
« Ta » est le temps pendant lequel la requête est restée active dans HAProxy, soit le temps total en millisecondes écoulé entre la réception du premier octet de la requête et l’envoi du dernier octet de la réponse. Il englobe toutes les phases de traitement possibles, à l’exception de l’échange d’handshake (voir Th) et du temps d’inactivité (voir Ti). Une exception existe : si l’option « option logasap » est spécifiée, alors le comptage du temps s’arrête au moment de l’émission du journal. Dans ce cas, un signe « + » est ajouté en préfixe de la valeur, indiquant que la valeur finale sera plus élevée. Voir section 8.4 « Événements de temporisation » pour plus de détails.
“status_code” est le code d’état HTTP renvoyé au client. Ce code est généralement défini par le serveur, mais peut également être défini par HAProxy lorsque le serveur n’est pas accessible ou lorsque sa réponse est bloquée par HAProxy.
“bytes_read” est le nombre total d’octets transmis au client au moment de l’émission du journal. Cette valeur inclut les en-têtes HTTP. Si l’option « option logasap » est spécifiée, cette valeur est précédée d’un signe « + », indiquant que la valeur finale peut être plus élevée. Veuillez noter que cette valeur est un compteur 64 bits, les outils d’analyse des journaux doivent donc être capables de la gérer sans débordement.
“captured_request_cookie” est une entrée facultative au format « nom=valeur » indiquant que le client avait ce cookie dans la requête. Le nom du cookie et sa longueur maximale sont définis par l’instruction « capture cookie » dans la configuration du frontal. Ce champ est une simple tiret (’-’) lorsque l’option n’est pas définie. Un seul cookie peut être capturé, ce qui est généralement utilisé pour suivre les échanges d’ID de session entre un client et un serveur afin de détecter les chevauchements de session entre clients dus à des bugs applicatifs. Pour plus de détails, veuillez consulter la section « Capturer des en-têtes et des cookies HTTP » ci-dessous.
“captured_response_cookie” est une entrée facultative au format « nom=valeur », indiquant que le serveur a renvoyé un cookie dans sa réponse. Le nom du cookie et sa longueur maximale sont définis par l’instruction « capture cookie » dans la configuration du frontal. Ce champ est un trait d’union unique (’-’) lorsque l’option n’est pas activée. Un seul cookie peut être capturé, ce qui est généralement utilisé pour suivre les échanges d’identifiants de session entre un client et un serveur afin de détecter les chevauchements de session entre clients dus à des bugs applicatifs. Pour plus de détails, veuillez consulter la section « Capturer les en-têtes HTTP et les cookies » ci-dessous.
“termination_state” est l’état du flux lorsqu’il s’est terminé. Cela indique l’état du flux, le côté ayant provoqué la fin du flux, la raison (délai d’expiration, erreur, …), de la même manière que dans les journaux TCP, ainsi que des informations sur les opérations de persistance des cookies dans les deux derniers caractères. Les indicateurs normaux doivent commencer par “–”, ce qui signifie que le flux a été fermé par l’une ou l’autre extrémité sans données restantes dans les tampons. Voir ci-dessous « État du flux à la déconnexion » pour plus de détails.
“actconn” correspond au nombre total de connexions simultanées sur le processus au moment où le flux a été journalisé. Il est utile pour détecter lorsque certains plafonds système par processus ont été atteints. Par exemple, si actconn est proche de 512 ou 1024 lorsqu’une erreur de connexion multiple survient, il est très probable que le système limite le processus à un maximum de 1024 descripteurs de fichiers, et que tous soient utilisés. Voir section 3 “Section globale” pour savoir comment ajuster le système.
« feconn » est le nombre total de connexions simultanées sur le frontal au moment où le flux a été journalisé. Il est utile pour estimer la quantité de ressources nécessaires pour supporter des charges élevées, et pour détecter lorsque la limite « maxconn » du frontal a été atteinte. En général, lorsque cette valeur augmente brusquement, cela indique une congestion sur les serveurs backend, mais cela peut aussi être dû à une attaque par déni de service.
« beconn » est le nombre total de connexions simultanées gérées par le backend au moment où le flux a été journalisé. Il inclut le nombre total de connexions simultanées actives sur les serveurs ainsi que le nombre de connexions en attente dans les files d’attente. Cette information est utile pour estimer le nombre de serveurs supplémentaires nécessaires afin de supporter des charges élevées pour une application donnée. En général, lorsque cette valeur augmente brusquement, cela indique une congestion sur les serveurs backend, mais cela peut aussi être dû à une attaque par déni de service.
“srv_conn” est le nombre total de connexions simultanées encore actives sur le serveur au moment où le flux a été journalisé. Cette valeur ne peut jamais dépasser le paramètre configuré « maxconn » du serveur. Si cette valeur est très souvent proche ou égale à « maxconn » du serveur, cela signifie que la régulation du trafic est très fréquente, ce qui indique soit que la valeur maxconn du serveur est trop faible, soit qu’il n’y a pas assez de serveurs pour traiter la charge avec un temps de réponse optimal. Lorsqu’un seul des serveurs “srv_conn” est élevé, cela signifie généralement que ce serveur rencontre des difficultés entraînant un traitement plus lent des requêtes par rapport aux autres serveurs.
“retries” correspond au nombre de tentatives de connexion effectuées par ce flux lors de la tentative de connexion au serveur. Il doit normalement être égal à zéro, sauf si un serveur est arrêté au moment précis où la connexion est tentée. Des tentatives fréquentes indiquent généralement un problème réseau entre HAProxy et le serveur, ou une configuration incorrecte de la file d’attente de connexion sur le serveur empêchant les nouvelles connexions d’être enregistrées. Ce champ peut éventuellement être précédé du signe ‘+’ pour indiquer qu’une rediffusion a eu lieu après avoir atteint le nombre maximal de tentatives sur le serveur initial. Dans ce cas, le nom du serveur apparaissant dans le journal est celui vers lequel la connexion a été rediffusée, et non celui initial, bien que les deux puissent parfois être identiques, par exemple en cas de hachage. En règle générale, lorsqu’un ‘+’ est présent devant le nombre de tentatives, ce dernier ne doit pas être attribué au serveur indiqué dans le journal.
“srv_queue” est le nombre total de requêtes traitées avant celle-ci dans la file d’attente du serveur. Il vaut zéro lorsque la requête n’a pas traversé la file d’attente du serveur. Il permet d’estimer approximativement le temps de réponse du serveur en divisant le temps passé en file par le nombre de requêtes dans la file. Il convient de noter qu’en cas de réacheminement, si un flux traverse deux files d’attente du serveur, leurs positions s’additionnent. Une requête ne doit pas traverser à la fois la file d’attente du serveur et la file d’attente du backend, sauf en cas de réacheminement.
“backend_queue” est le nombre total de requêtes traitées avant celle-ci dans la file d’attente globale du backend. Il vaut zéro lorsque la requête n’a pas traversé la file d’attente globale. Ce chiffre permet d’estimer la longueur moyenne de la file, qui se traduit aisément en nombre de serveurs manquants lorsqu’elle est divisée par le paramètre “maxconn” d’un serveur. Il convient de noter qu’une requête pouvant subir une redirigabilité, elle peut passer deux fois par la file du backend, et les deux positions seront alors cumulées. Une requête ne doit pas passer à la fois par la file du serveur et par la file du backend, sauf en cas de redirigabilité.
“captured_request_headers” est une liste d’en-têtes capturés dans la requête en raison de la présence de l’instruction « capture en-tête requête » dans le frontal. Plusieurs en-têtes peuvent être capturés, ils seront séparés par un trait vertical (’|’). Lorsqu’aucune capture n’est activée, les accolades ne s’affichent pas, ce qui provoque un décalage des champs restants. Il est important de noter que ce champ peut contenir des espaces, et son utilisation nécessite un analyseur de journaux plus performant qu’en l’absence de capture. Veuillez consulter la section « Capturer des en-têtes HTTP et des cookies » ci-dessous pour plus de détails.
“captured_response_headers” est une liste d’en-têtes capturés dans la réponse en raison de la présence de l’instruction « capturer l’en-tête de réponse » dans le frontal. Plusieurs en-têtes peuvent être capturés ; ils seront séparés par un trait vertical (’|’). Lorsqu’aucune capture n’est activée, les accolades ne s’affichent pas, ce qui provoque un décalage des champs restants. Il est important de noter que ce champ peut contenir des espaces, et son utilisation nécessite un analyseur de journaux plus performant que lorsqu’il n’est pas utilisé. Veuillez consulter la section « Capturer les en-têtes HTTP et les cookies » ci-dessous pour plus de détails.
“http_request” est la ligne de requête HTTP complète, comprenant la méthode, la requête et la version HTTP. Les caractères non imprimables sont encodés (voir ci-dessous la section « Caractères non imprimables »). Ce champ est toujours le dernier, toujours délimité par des guillemets, et le seul à pouvoir contenir des guillemets. Si de nouveaux champs sont ajoutés au format de journalisation, ils seront insérés avant ce champ. Ce champ peut être tronqué si la requête est trop volumineuse pour tenir dans le tampon standard syslog (1024 caractères). C’est la raison pour laquelle ce champ doit toujours rester le dernier.
8.2.4. Format de journalisation HTTPS
Le format HTTPS est le plus adapté aux connexions HTTP sur SSL. Il s’agit d’une extension du format HTTP (voir section 8.2.3 ) à laquelle sont ajoutées des informations relatives à SSL. Il est activé lorsque l’option « option httpslog » est spécifiée dans le frontal. Tout comme les formats TCP et HTTP, la journalisation a lieu généralement à la fin du flux, sauf si l’option « option logasap » est indiquée. Un flux correspondant aux règles « monitor » ne sera jamais journalisé. Il est également possible de ne pas journaliser les flux pour lesquels le client n’a envoyé aucune donnée en spécifiant « option dontlognull » dans le frontal. Les connexions réussies ne seront pas journalisées si l’option « option dontlog-normal » est spécifiée dans le frontal.
Le format de journalisation HTTPS est déclaré internement comme un format de journalisation personnalisé basé sur la chaîne exacte suivante, qui peut également servir de base pour étendre le format si nécessaire. En outre, la variable HAPROXY_HTTPS_LOG_FMT peut être utilisée à la place. Reportez-vous à la section 8.2.6 « Format de journalisation personnalisé » pour savoir comment l’utiliser :
Ce format est fondamentalement celui de HTTP (voir section 8.2.3 ) avec des champs supplémentaires ajoutés. Les nouveaux champs (lignes 17 et 18) seront détaillés ici. Pour les champs HTTP, se référer à la section HTTP.
Exemple :
Champ Format Extraire de l’exemple ci-dessus 1 process_name ‘[’ pid ‘]:’ HAProxy[14389]: 2 client_ip ‘:’ client_port 10.0.1.2:33317 3 ‘[’ request_date ‘]’ [06/Feb/2009:12:14:14.655] 4 frontend_name https-in 5 backend_name ‘/’ server_name static/srv1 6 TR ‘/’ Tw ‘/’ Tc ‘/’ Tr ‘/’ Ta* 10/0/30/69/109 7 status_code 200 8 bytes_read* 2750 9 captured_request_cookie - 10 captured_response_cookie - 11 termination_state —- 12 actconn ‘/’ feconn ‘/’ beconn ‘/’ srv_conn ‘/’ retries* 1/1/1/1/0 13 srv_queue ‘/’ backend_queue 0/0 14 ‘{’ captured_request_headers* ‘}’ {HAProxy.1wt.eu} 15 ‘{’ captured_response_headers* ‘}’ {} 16 ‘"’ http_request ‘"’ “GET /index.html HTTP/1.1” 17 fc_err ‘/’ ssl_fc_err ‘/’ ssl_c_err ‘/’ ssl_c_ca_err ‘/’ ssl_fc_is_resumed 0/0/0/0/0 18 ssl_fc_sni ‘/’ ssl_version ‘/’ ssl_ciphers 1wt.eu/TLSv1.3/TLS_AES_256_GCM_SHA384
Description détaillée des champs :
“fc_err” est l’état de la connexion du côté frontal. Il correspond à l’extraction d’échantillon “fc_err”. Pour plus d’informations, consultez les fonctions d’extraction d’échantillon “fc_err” et “fc_err_str”.
“ssl_fc_err” est la dernière erreur de la première pile d’erreurs SSL levée depuis la perspective du frontal. Elle peut être utilisée, par exemple, pour détecter les erreurs d’établissement de main-handshake SSL. Elle vaut 0 si tout s’est déroulé normalement. Pour plus d’informations, consulter la description de l’extraction d’échantillon “ssl_fc_err”.
“ssl_c_err” est l’état du processus de vérification du certificat client. La négociation peut réussir tout en ayant un code d’erreur de vérification non nul si cette erreur est ignorée. Voir l’extraction d’échantillon “ssl_c_err” et l’option “crt-ignore-err”.
“ssl_c_ca_err” est l’état du processus de vérification de la chaîne de certificat du client. La négociation peut réussir tout en ayant un code d’erreur de vérification non nul si cette erreur est ignorée. Voir l’extraction d’échantillon “ssl_c_ca_err” et l’option “ca-ignore-err”.
“ssl_fc_is_resumed” est true si la session TLS entrante a été rétablie à partir de la mémoire tampon étatique ou d’un jeton sans état. N’oubliez pas qu’une session TLS peut être partagée par plusieurs requêtes.
“ssl_fc_sni” est l’indication de nom de serveur (SNI) présentée par le client pour sélectionner le certificat à utiliser. Elle correspond généralement au nom d’hôte de la première requête d’une connexion. L’absence de ce champ peut indiquer que le client n’a pas envoyé de SNI, ce qui amène HAProxy à utiliser le certificat par défaut, ou à rejeter la connexion en cas de mode strict-sni.
“ssl_version” est la version SSL du frontal.
“ssl_ciphers” est le chiffrement SSL utilisé pour la connexion.
8.2.5. Format du journal d’erreurs
Lorsqu’une connexion entrante échoue en raison d’une négociation SSL ou d’un en-tête PROXY invalide, HAProxy journalise l’événement à l’aide d’un format de ligne plus court et fixe, sauf si un format de journalisation d’erreur dédié est défini via une ligne « error-log-format ». Par défaut, les journaux sont émis au niveau LOG_INFO, sauf si l’option « log-separate-errors » est définie dans le backend, auquel cas le niveau LOG_ERR sera utilisé. Les connexions sur lesquelles aucune donnée n’est échangée (par exemple, les sondes) ne sont pas journalisées si l’option « dontlognull » est activée.
Le format par défaut a cette apparence :
Ces champs ne fournissent que des informations minimales afin d’aider au débogage des échecs de connexion.
En utilisant la directive « error-log-format », le format d’historique hérité décrit ci-dessus ne sera plus utilisé, et toutes les lignes de journal d’erreur suivront le format défini.
Un exemple de format d’erreur suffisamment complet est présenté ci-dessous. Il rapporte l’adresse source et le port, la date d’acceptation de la connexion, le nom du frontend, le nombre de connexions actives sur le processus et sur ce frontend, l’identifiant interne d’erreur d’HAProxy sur la connexion frontale, le numéro d’erreur OpenSSL au format hexadécimal (pouvant être copié-collé dans « OpenSSL errstr » pour une décodage complet), l’état d’extraction du certificat client (0 indique aucune erreur), l’état de validation du certificat client par la CA (0 indique aucune erreur), une valeur booléenne indiquant si la connexion est nouvelle ou a été rétablie, l’indication éventuelle du nom de serveur (SNI) fournie par le client, le nom de la version SSL et les chiffres SSL utilisés sur la connexion, le cas échéant. Notez que les erreurs de connexion backend ne sont jamais rapportées ici, car pour qu’une connexion backend échoue, elle aurait dû passer par un flux réussi, et sera donc disponible sous forme de journal de trafic régulier (voir l’option httplog ou l’option httpslog).
8.2.6. Format de journal personnalisé
Historiquement, les formats de journalisation personnalisés n’étaient utilisés que pour produire des journaux. Mais leur commodité lorsqu’ils servent à générer une chaîne en assemblant plusieurs expressions complexes a conduit à leur adoption par de nombreuses directives qui n’acceptaient auparavant que des chaînes en argument et qui peuvent désormais également accepter une définition de format de journalisation personnalisé. Ces arguments, généralement désignés par “<fmt>” dans ce document, sont définis exactement de la même manière que l’argument de la directive « log-format », décrite ici.
Lorsqu’il s’agit des journaux et que les formats de journalisation par défaut ne sont pas suffisants, il est possible de définir de nouveaux formats avec une grande précision. Comme la création d’un format de journalisation depuis zéro n’est pas toujours une tâche aisée, il est fortement recommandé de consulter en premier lieu les formats existants (“option tcplog”, “option httplog”, “option httpslog”), de choisir celui qui correspond le plus à l’attente, de copier sa chaîne équivalente “log-format” et de l’ajuster.
Une définition de format de journal personnalisé est un argument unique du point de vue de la configuration. Cela signifie qu’elle ne peut pas contenir d’espaces (blancs ou tabulations), sauf si ces espaces sont échappés à l’aide du caractère barre oblique inversée (’\’), ou si toute la définition est enclose entre guillemets (ce qui est la méthode recommandée pour les utiliser). L’utilisation de chaînes de format non encloses entre guillemets n’est plus recommandée, car l’histoire a montré qu’elle était très sujette aux erreurs, une simple barre oblique inversée manquante pouvant entraîner une troncation silencieuse du format. De telles configurations sont encore fréquemment rencontrées en raison de l’adoption massive des formats de journal après la version 1.5-dev9, soit trois ans avant que les guillemets soient disponibles, mais il est recommandé de les convertir en chaînes entre guillemets et de supprimer les barres obliques inversées.
Une définition de format de journal est composée d’un nombre quelconque d’éléments de format de journal séparés par du texte et des espaces. Un élément de format de journal commence par le caractère ‘%’. Pour émettre un ‘%’ littéral, il doit être précédé d’un autre ‘%’ donnant ‘%%’.
Les éléments de logformat peuvent être soit des alias, soit des expressions d’échantillonnage :
Si un élément est nommé entre crochets (’[’ .. ‘]’), il est utilisé comme une expression d’exemple règle (voir section 7.3 ). Cela est utile pour ajouter certaines informations moins courantes, telles que le DN du certificat SSL du client, ou pour journaliser la clé qui serait utilisée pour stocker une entrée dans une table de persistance. Il est également couramment utilisé avec des actions non loggées (manipulation d’en-têtes, variables, etc.).
Sinon, si l’élément est nommé à l’aide d’un nom alphanumérique, il s’agit d’un alias. (Voir le tableau ci-dessous pour la liste des alias disponibles)
Les éléments peuvent accepter des arguments entre accolades (’{}’), et plusieurs arguments sont séparés par des virgules à l’intérieur des accolades. Les indicateurs peuvent être ajoutés ou supprimés en les préfixant d’un signe ‘+’ ou ‘-’ (voir ci-dessous la liste des indicateurs disponibles).
L’alias spécial “%o” peut être utilisé pour propager ses indicateurs à tous les autres éléments de formatage dans la même chaîne de format. Cela est particulièrement pratique avec les formats de chaîne entre guillemets (“Q”) et les chaînes échappées (“E”).
Alias spécial “%OG” peut être utilisé pour récupérer l’origine du journal (lieu de génération du journal) sous une forme lisible par l’humain. Il est particulièrement utile avec “option logasap” car certaines variables de journal ou extraits d’échantillon pourraient rapporter des valeurs incomplètes ou se comporter différemment selon le moment ou le lieu d’évaluation de l’expression logformat. Les valeurs possibles sont :
- “sess_error” : le journal a été généré lors du traitement d’une erreur de session
- “sess_killed” : le journal a été généré lors de l’abandon de session (session embryonnaire interrompue)
- “txn_accept” : le journal a été généré juste après l’acceptation de la connexion frontale
- “txn_request” : le journal a été généré après réception de la requête client
- “txn_connect” : le journal a été généré après établissement de la connexion backend
- “txn_response” : le journal a été généré lors du traitement de la réponse serveur
- “txn_close” : le journal a été généré à l’étape finale de la transaction, avant la fermeture
- “unspec” : inconnu ou non spécifié “%OG” est pertinent uniquement dans un contexte de journalisation.
Les éléments peuvent éventuellement être nommés à l’aide de parenthèses (’()’). Le nom doit être fourni immédiatement après ‘%’ (avant les arguments). Il sera automatiquement utilisé comme nom de clé lorsque le drapeau d’encodage tel que « json » ou « cbor » est défini. Lorsqu’aucun drapeau d’encodage n’est spécifié (par défaut), le nom de l’élément sera ignoré. Il est également possible de forcer le type de sortie de l’élément en ajoutant ‘:type’ après le nom, comme ceci : %(itemname:itemtype)aliasname ou %(itemname:itemtype)[expr], où itemtype peut être ‘str’, ‘sint’ ou ‘bool’. La spécification du type n’est pertinente que lorsqu’une méthode d’encodage est utilisée. Il est également possible de fournir un nom vide afin de forcer le type de sortie sur un élément anonyme : %(:itemtype), par exemple lorsque l’encodage n’est pas défini globalement, voir les définitions des drapeaux ci-dessous pour plus d’informations.
En raison de l’objectif initial des formats de journalisation personnalisés, qui est d’être utilisés uniquement pour la journalisation, une règle spéciale est appliquée aux caractères non imprimables et non sûrs (ceux situés en dehors des codes ASCII 32 à 126, ainsi que quelques autres) selon leur contexte d’utilisation. Section 8.6 décrit précisément ce qui est fait pour les journaux afin de garantir qu’aucun code non sûr n’est envoyé, ce qui pourrait altérer la lisibilité de la sortie dans un terminal. Lorsqu’ils sont utilisés pour former des champs d’en-tête, des contrôles d’état ou des réponses de charge utile, les règles sont moins strictes, et seuls les caractères interdits dans les champs d’en-tête HTTP sont remplacés par leur encodage hexadécimal précédé du caractère ‘%’. Cela ne pose normalement pas de problème, mais cela peut affecter la sortie lorsque le caractère était censé être reproduit tel quel (par exemple, lors de la construction d’une page d’erreur ou d’une charge utile complète de réponse, où les sauts de ligne pourraient apparaître sous la forme “%0A”).
Note : dans les directives de configuration « log-format », « log-format-sd » et « unique-id-format », les espaces sont considérés comme des délimiteurs et sont fusionnés.
Note : lors de l’utilisation du format de message syslog RFC5424, les caractères ‘"’, ‘\’ et ‘]’ figurant dans PARAM-VALUE doivent être échappés en les préfixant par ‘\’ (voir https://tools.ietf.org/html/rfc5424#section-6.3.3 pour plus de détails). Dans de tels cas, l’utilisation du drapeau “E” doit être prise en compte.
Les indicateurs d’éléments pris en charge sont (peuvent être activés/désactivés via les arguments de l’élément) :
- Q : insérer une chaîne entre guillemets
- X : représentation hexadécimale (adresses IP, ports, %Ts, %rt, %pid)
- E : échapper les caractères ‘"’, ‘\’ et ‘]’ dans une chaîne avec ‘\’ comme préfixe (destiné à être utilisé avec les formats de journalisation structurés RFC5424)
- bin : essayer de préserver les données binaires, ce qui peut être utile avec des expressions d’échantillonnage produisant des données binaires afin de conserver les données d’origine. Faites attention toutefois, car cela peut évidemment générer des caractères non imprimables, y compris des octets NULL, que la plupart des terminaux syslog n’attendent pas. Cette option est donc principalement destinée à être utilisée avec set-var-fmt, les anneaux et les terminaux de journalisation capables de traiter les données binaires. Cette option ne peut être définie qu’au niveau global (avec %o), elle sera ignorée si elle est définie sur les options d’un élément individuel.
- json : encoder automatiquement la valeur au format JSON (lorsqu’elle est définie au niveau global, seules les entrées de format de journal nommées sont prises en compte). Les valeurs numériques incomplètes (par exemple : ‘%B’ lorsqu’on utilise logasap), qui sont normalement précédées de ‘+’ sans encodage, seront encodées telles quelles. De plus, l’option ‘+E’ sera ignorée.
- cbor : encoder automatiquement la valeur au format CBOR (lorsqu’il est défini globalement, seuls les éléments de format de journal nommés sont pris en compte). Par défaut, les données encodées en CBOR sont représentées sous forme hexadécimale afin de rester lisibles sur stdout et pouvant être utilisées avec des terminaux syslog classiques. Comme pour l’encodage JSON, les valeurs numériques incomplètes seront encodées telles quelles et l’option ‘+E’ sera ignorée. Lorsqu’elle est combinée avec l’option ‘+bin’, elle génère directement un payload CBOR binaire brut. Attention, cela produit évidemment des caractères non imprimables, aussi cette option est-elle principalement destinée à être utilisée avec set-var-fmt, les files d’attente et les terminaux de journalisation capables de traiter les données binaires.
Exemple :
Veuillez vous référer au tableau ci-dessous pour les alias actuellement définis :
R = Restrictions: H = mode http only; S = SSL only; L = log only
8.3. Options avancées de journalisation
Certaines options avancées de journalisation sont fréquemment recherchées, mais ne sont pas faciles à identifier en examinant uniquement les différentes options. Voici un point d’entrée pour les quelques options permettant une meilleure journalisation. Reportez-vous à la référence des mots-clés pour plus d’informations sur leur utilisation.
8.3.1. Désactivation de la journalisation des tests externes
Il est fréquent de voir des outils de surveillance effectuer des contrôles d’état sur HAProxy. Parfois, il s’agit d’un équilibreur de charge au niveau 3, comme LVS ou tout équilibreur de charge commercial, et parfois d’un système de surveillance plus complet, comme Nagios. Lorsque ces tests sont très fréquents, les utilisateurs demandent souvent comment désactiver la journalisation de ces contrôles. Trois possibilités existent :
Si les connexions proviennent de partout et ne sont que des sondes TCP, il est souvent souhaitable de désactiver simplement la journalisation des connexions sans échange de données, en définissant « option dontlognull » dans le frontal. Cela désactive également la journalisation des scans de port, ce qui peut ou non être souhaitable.
il est possible d’utiliser l’action « http-request set-log-level silent » avec diverses conditions (source réseau, chemins, user-agents, etc.).
si les tests sont effectués sur une URI connue, utilisez « monitor-uri » pour déclarer cette URI comme dédiée au suivi. Tout hôte envoyant cette requête ne recevra que le résultat d’un contrôle de santé, et la requête ne sera pas journalisée.
8.3.2. Journalisation avant d’attendre la fin du flux
Le problème lié à la journalisation à la fin de la connexion est qu’il n’est pas possible de savoir ce qui se passe pendant des flux très longs, comme les sessions de terminal distant ou les téléchargements de fichiers volumineux. Ce problème peut être contourné en spécifiant « option logasap » dans le frontal. HAProxy journalisera alors dès que possible, juste avant le début du transfert de données. Cela signifie qu’en cas de TCP, il journalisera encore l’état de la connexion vers le serveur, et en cas de HTTP, il journalisera juste après le traitement des en-têtes serveur. Dans ce cas, le nombre d’octets rapporté correspond au nombre d’octets d’en-tête envoyés au client. Pour éviter toute confusion avec les journaux normaux, les champs temps total et nombre d’octets sont précédés d’un signe « + », ce qui indique que les valeurs réelles sont certainement plus élevées.
8.3.3. Augmenter le niveau de journalisation en cas d’erreur
Parfois, il est plus pratique de séparer le trafic normal des journaux d’erreurs, par exemple pour faciliter la surveillance des erreurs à partir des fichiers journaux. Lorsque l’option « log-separate-errors » est utilisée, les connexions qui rencontrent des erreurs, des délais d’expiration, des tentatives de reconnexion, des redirigements ou des codes d’état HTTP 5xx verront leur niveau syslog passé de « info » à « err ». Cela permet à un démon syslog de stocker le journal dans un fichier distinct. Il est très important de conserver les erreurs dans le fichier de journal du trafic normal afin de ne pas altérer l’ordre des journaux. Vous devez également faire attention si vous avez déjà configuré votre démon syslog pour stocker tous les journaux de niveau supérieur à « notice » dans un fichier « admin », car le niveau « err » est supérieur à « notice ».
8.3.4. Désactivation de la journalisation des connexions réussies
Bien que cela puisse sembler étrange au premier abord, certains grands sites doivent gérer des milliers de journaux par seconde et éprouvent des difficultés à les conserver intégraux sur une longue période ou à détecter des erreurs au sein d’entre eux. Si l’option « dontlog-normal » est définie sur le frontal, toutes les connexions normales ne seront pas journalisées. Une connexion normale est définie comme une connexion sans erreur, délai d’expiration, tentative de reconnexion ni redirigement. En HTTP, le code de statut est également vérifié, et une réponse avec un statut 5xx n’est pas considérée comme normale et sera journalisée également. Bien entendu, cette pratique est fortement déconseillée, car elle supprime la majeure partie des informations utiles des journaux. Procédez ainsi uniquement si aucune autre alternative n’est disponible.
8.3.5. Profils de journalisation
Bien que certaines directives telles que « log-format », « log-format-sd », « error-log-format » ou « log-tag » permettent de configurer le format des journaux de manière globale ou au niveau du proxy, il peut être pertinent de configurer ces paramètres aussi près que possible des destinations de journalisation, c’est-à-dire par directive « log ».
C’est ici que la section « log-profile » entre en jeu : la section « log-profile » peut être définie n’importe où dans la configuration. Cette section accepte un ensemble de mots-clés différents, utilisés pour décrire la manière dont les journaux émis pour une directive log donnée doivent être construits.
À partir d’une directive « log », il est possible de choisir un profil de journalisation spécifique par son nom. Ce même profil peut être utilisé à partir de plusieurs directives « log ».
log-profile <name> Crée un nouveau profil de journalisation identifié par <name>
log-tag <string> Remplacer l’étiquette de journalisation syslog définie globalement ou par proxy à l’aide de la directive « log-tag ».
sur <step> [drop] [format <fmt>] [sd <sd_fmt>] Remplace la chaîne de format de journalisation utilisée par défaut pour construire la ligne de journal au stade de journalisation <step>. <fmt> permet de remplacer les chaînes “log-format” ou “error-log-format” (selon le <step>), tandis que <sd_fmt> permet de remplacer la chaîne “log-format-sd” (les deux peuvent être combinés).
Mot-clé spécial drop peut être utilisé pour indiquer qu’aucun journal ne doit être émis pour le <step> donné.
Il a priorité sur format et sd s’ils ont été définis précédemment.
Valeurs possibles pour <step> sont :
- “accept” : remplacer log-format si le journal est généré juste après l’acceptation de la connexion frontale
- “request” : remplacer log-format si le journal est généré après la réception de la requête client
- “connect” : remplacer log-format si le journal est généré après l’établissement de la connexion backend
- “response” : remplacer log-format si le journal est généré pendant le traitement de la réponse serveur
- “close” : remplacer log-format si le journal est généré à l’étape finale de la transaction (txn)
- “error” : remplacer error-log-format si le journal est généré suite à une erreur de transaction
- “any” : remplacer à la fois log-format et error-log-format pour toutes les étapes de journalisation, sauf si une substitution plus précise est déclarée.
Voir l’action « do-log » pour les valeurs <step> supplémentaires pertinentes.
Ce paramètre n’est pertinent que pour les directives « log » utilisées dans des contextes où l’utilisation de la directive « log-format » a un sens (par exemple : proxys HTTP et TCP). Dans les autres cas, il sera simplement ignoré.
Exemple :
8.4. Événements de temporisation
Les compteurs aident grandement au dépannage des problèmes réseau. Toutes les valeurs sont exprimées en millisecondes (ms). Ces compteurs doivent être utilisés conjointement avec les indicateurs de terminaison de flux. En mode TCP avec l’option « option tcplog » activée sur le frontal, trois points de contrôle sont rapportés sous la forme « Tw/Tc/Tt », et en mode HTTP, cinq points de contrôle sont rapportés sous la forme « TR/Tw/Tc/Tr/Ta ». En outre, trois autres mesures sont fournies : « Th », « Ti » et « Tq ».
Événements de temporisation en mode HTTP :
Événements de temporisation en mode TCP :
- Th : temps total nécessaire pour accepter la connexion TCP et exécuter les échanges de protocoles de bas niveau. Actuellement, ces protocoles sont proxy-protocol et SSL. Cet événement ne peut se produire qu’une seule fois au cours de la durée de vie de la connexion. Un temps élevé ici peut indiquer que le client a établi la connexion uniquement sans échanger de données, qu’il rencontre des problèmes réseau empêchant la réalisation d’un échange dans un délai raisonnable (par exemple, des problèmes de MTU), ou qu’une négociation SSL a été particulièrement coûteuse à calculer. Veuillez noter que ce temps n’est rapporté qu’avant la première requête, il est donc sans danger de le moyenniser sur toutes les requêtes afin d’obtenir sa valeur amortie. Les requêtes suivantes rapporteront toujours zéro ici.
Ce minuteur est nommé %Th en tant qu’alias de format de journalisation, et fc.timer.handshake en tant qu’extraction d’échantillon.
- Ti : est le délai d’inactivité avant la requête HTTP (mode HTTP uniquement). Ce minuteur s’active entre la fin des échanges d’handshake et la réception du premier octet de la requête HTTP. En cas de deuxième requête en mode keep-alive, il démarre après la fin de l’envoi de la réponse précédente. Lorsqu’un protocole multiplexé tel qu’HTTP/2 est utilisé, il démarre immédiatement après la requête précédente. Certains navigateurs établissent des connexions préalables à un serveur afin de réduire la latence d’une requête future, et les maintiennent en attente jusqu’à leur utilisation. Ce délai sera comptabilisé comme temps d’inactivité. Une valeur de -1 indique qu’aucune donnée n’a été reçue sur la connexion.
Ce minuteur est nommé %Ti en tant qu’alias de format de journalisation, et req.timer.idle en tant qu’extraction d’échantillon.
- TR : temps total pour obtenir la requête client (mode HTTP uniquement). Il s’agit du temps écoulé entre les premiers octets reçus et le moment où le proxy a reçu la ligne vide marquant la fin des en-têtes HTTP. La valeur “-1” indique que la fin des en-têtes n’a jamais été observée. Cela se produit lorsque le client se ferme prématurément ou expiré. Ce temps est généralement très court, car la plupart des requêtes tiennent dans un seul paquet. Un temps élevé peut indiquer une requête saisie manuellement lors d’un test.
Ce minuteur est nommé %TR en tant qu’alias de format de journalisation, et req.timer.hdr en tant qu’extraction d’échantillon.
- Tq : temps total pour obtenir la requête client à partir de la date d’acceptation ou depuis l’émission du dernier octet de la réponse précédente (mode HTTP uniquement). Il est exactement égal à Th + Ti + TR, sauf si l’un de ces éléments est -1, auquel cas il retourne également -1. Ce chronomètre était autrefois très utile avant l’arrivée de la réutilisation de connexion HTTP et de la fonction de pré-connexion des navigateurs. Il est recommandé de l’abandonner au profit de TR, car le temps d’attente ajoute beaucoup de bruit aux rapports.
Ce minuteur est nommé %Tq en tant qu’alias de format de journalisation, et req.timer.tq en tant qu’extraction d’échantillon.
- Tw : temps total passé dans les files d’attente en attente d’une slot de connexion. Il tient compte à la fois de la file d’attente du backend et des files d’attente du serveur, et dépend de la taille de la file d’attente ainsi que du temps nécessaire au serveur pour terminer les requêtes précédentes. La valeur “-1” signifie que la requête a été interrompue avant d’atteindre la file d’attente, ce qui se produit généralement pour les requêtes non valides ou refusées.
Ce minuteur est nommé %Tw en tant qu’alias de format de journalisation, et req.timer.queue en tant qu’extraction d’échantillon.
- Tc : temps total nécessaire à l’établissement de la connexion TCP au serveur. Il correspond au temps écoulé entre l’instant où le proxy a envoyé la requête de connexion et l’instant où celle-ci a été reconnue par le serveur, ou entre l’envoi du paquet TCP SYN et la réception du paquet SYN/ACK correspondant. La valeur “-1” signifie que la connexion n’a pas pu être établie.
Ce minuteur est nommé %Tc en tant qu’alias de format de journalisation, et bc.timer.connect en tant qu’extraction d’échantillon.
- Tr : temps de réponse du serveur (mode HTTP uniquement). Il s’agit du délai écoulé entre l’instant où la connexion TCP a été établie avec le serveur et l’instant où le serveur a envoyé l’intégralité de ses en-têtes de réponse. Il indique uniquement le temps de traitement de la requête, sans tenir compte de la surcharge réseau due à la transmission des données. Il convient de noter qu’en cas d’envoi de données par le client au serveur, par exemple lors d’une requête POST, le délai est déjà en cours, ce qui peut fausser le temps de réponse apparent. Pour cette raison, il est généralement préférable de ne pas trop se fier à ce champ pour les requêtes POST initiées depuis des clients situés derrière un réseau non fiable. Une valeur de “-1” signifie ici que la dernière en-tête de réponse (ligne vide) n’a jamais été vue, probablement parce que le délai d’expiration du serveur s’est déclenché avant que le serveur n’ait pu traiter la requête ou parce que le serveur a renvoyé une réponse invalide.
Ce minuteur est nommé %Tr en tant qu’alias de format de journalisation, et res.timer.hdr en tant qu’extraction d’échantillon.
- Td : c’est le temps total de transfert du contenu de la réponse jusqu’à l’envoi du dernier octet au client. En HTTP, il commence après le dernier en-tête de réponse (après Tr).
Les données envoyées ne sont pas garanties d’être reçues par le client ; elles peuvent rester bloquées dans le noyau ou le réseau.
Ce minuteur est nommé %Td en tant qu’alias de format de journalisation, et res.timer.data en tant qu’extraction d’échantillon.
- Ta : temps d’activité total pour la requête HTTP, compris entre le moment où le proxy a reçu le premier octet de l’en-tête de la requête et l’émission du dernier octet du corps de la réponse. L’exception est lorsque l’option « logasap » est spécifiée. Dans ce cas, il ne correspond qu’à (TR+Tw+Tc+Tr) et est précédé du signe « + ». À partir de ce champ, on peut déduire « Td », le temps de transmission des données, en soustrayant les autres compteurs lorsque ceux-ci sont valides :
Les compteurs dont les valeurs sont "-1" doivent être exclus de cette équation. Notez qu'« Ta » ne peut jamais être négatif.
Ce minuteur est nommé %Ta en tant qu'alias de format de journalisation, et txn.timer.total en tant qu'extraction d'échantillon.
- Tt : durée totale du flux, entre le moment où le proxy l’a accepté et celui où les deux extrémités ont été fermées. L’exception concerne l’option « logasap ». Dans ce cas, elle ne correspond qu’à (Th+Ti+TR+Tw+Tc+Tr), et est précédée d’un signe « + ». À partir de ce champ, on peut déduire « Td », le temps de transmission des données, en soustrayant les autres temporisateurs lorsque ceux-ci sont valides :
Les compteurs ayant une valeur "-1" doivent être exclus de cette équation. En mode TCP, les valeurs "Ti", "Tq" et "Tr" doivent également être exclus. Notez que "Tt" ne peut jamais être négatif, et que pour HTTP, Tt est simplement égal à (Th+Ti+Ta).
Ce minuteur est nommé %Tt en tant qu'alias de format de journalisation, et fc.timer.total en tant qu'extraction d'échantillon.
- Tu : temps estimé total perçu par le client, entre l’instant où le proxy l’a accepté et l’instant où les deux extrémités ont été fermées, sans temps d’inactivité. Cela permet de mesurer grossièrement le temps de bout en bout tel qu’un utilisateur le perçoit, sans la pollution due aux périodes d’inactivité dues à la réutilisation de connexions persistantes entre les requêtes. Ce chronomètre n’est qu’une estimation du temps perçu par l’utilisateur, car il suppose que la latence réseau est identique dans les deux sens. L’exception se produit lorsque l’option « logasap » est spécifiée. Dans ce cas, il ne correspond qu’à (Th+TR+Tw+Tc+Tr) et est précédé du signe « + ».
Ce minuteur est nommé %Tu as un alias de format de journal, et txn.timer.user comme extraction d’échantillon.
Ces délais d’expiration fournissent des indications précieuses sur les causes des problèmes. Étant donné que le protocole TCP définit des délais de retransmission de 3, 6, 12… secondes, on peut affirmer avec certitude que des délais proches des multiples de 3 s sont presque toujours liés à la perte de paquets due à des problèmes réseau (câblage, négociation, congestion). En outre, si « Ta » ou « Tt » est proche d’une valeur de délai d’expiration définie dans la configuration, cela signifie souvent qu’un flux a été interrompu en raison d’un délai d’expiration.
Cas les plus fréquents :
Si “Th” ou “Ti” sont proches de 3000, un paquet a probablement été perdu entre le client et le proxy. Cela est très rare sur les réseaux locaux, mais peut survenir lorsque les clients sont situés sur des réseaux distants et envoient des requêtes importantes. Il peut arriver que des valeurs plus élevées que la normale apparaissent ici sans cause réseau. Parfois, lors d’une attaque ou juste après la fin d’une saturation des ressources, HAProxy peut accepter des milliers de connexions en quelques millisecondes. Le temps passé à accepter ces connexions retardera inévitablement légèrement le traitement des autres connexions, et il peut arriver que des temps de requête de l’ordre de quelques dizaines de millisecondes soient mesurés après qu’un nombre de milliers de nouvelles connexions ait été accepté en même temps. L’utilisation d’un mode keep-alive peut faire apparaître des temps d’inactivité plus élevés, car “Ti” mesure le temps passé en attente de requêtes supplémentaires.
Si « Tc » est proche de 3000, un paquet a probablement été perdu entre le serveur et le proxy pendant la phase de connexion du serveur. Cette valeur doit toujours être très faible, par exemple de l’ordre de 1 ms sur les réseaux locaux et inférieure à quelques dizaines de ms sur les réseaux distants.
Si « Tr » est presque toujours inférieur à 3000, sauf pour certaines valeurs rares qui semblent être la moyenne majorée de 3000, il y a probablement des paquets perdus entre le proxy et le serveur.
Si « Ta » est élevé même pour de faibles volumes d’octets, cela est généralement dû au fait que ni le client ni le serveur ne décident de fermer la connexion pendant que HAProxy fonctionne en mode tunnel, et que les deux ont convenu d’un mode de connexion persistante. Pour résoudre ce problème, il faudra spécifier l’une des options HTTP afin de manipuler les options de maintien de connexion ou de fermeture, soit au niveau du frontal, soit au niveau du backend. Il est important de réduire au minimum la valeur de « Ta » ou de « Tt » lorsqu’une régulation des connexions est utilisée avec l’option « maxconn » sur les serveurs, car aucune nouvelle connexion ne sera envoyée au serveur tant qu’une autre n’aura pas été libérée.
Autres cas de journalisation HTTP notables (‘xx’ signifie toute valeur à ignorer) :
8.5. État du flux à la déconnexion
Les journaux TCP et HTTP fournissent un indicateur de terminaison de flux dans le champ “termination_state”, juste avant le nombre de connexions actives. Il est composé de 2 caractères en mode TCP, et étendu à 4 caractères en mode HTTP, chacun ayant une signification particulière :
- Sur le premier caractère, un code indiquant l’événement initial ayant provoqué la fin du flux :
- sur le deuxième caractère, l’état du flux TCP ou HTTP au moment de sa fermeture :
- le troisième caractère indique si le cookie de persistance a été fourni par le client (uniquement en mode HTTP) :
- le dernier caractère indique les opérations effectuées sur le cookie de persistance renvoyé par le serveur (uniquement en mode HTTP) :
La combinaison des deux premiers indicateurs fournit de nombreuses informations sur ce qui s’est produit lors de la fermeture du flux ou de la session, ainsi que sur la raison de cette fermeture. Elle peut aider à détecter une saturation du serveur, des problèmes réseau, une pénurie de ressources système locales, des attaques, etc…
Les combinaisons de drapeaux de terminaison les plus courantes sont indiquées ci-dessous. Elles sont triées par ordre alphabétique, avec l’ensemble minuscule placé immédiatement après l’ensemble majuscule pour faciliter la recherche et la compréhension.
Drapeaux Raison
-- Normal termination.
CC Le client a interrompu la connexion avant qu'elle ne puisse être établie avec le serveur. Cela peut se produire lorsque HAProxy tente de se connecter à un serveur récemment tombé en panne (ou non vérifié), et que le client interrompt la connexion pendant que HAProxy attend la réponse du serveur ou l'expiration du délai de connexion.
CD Le client a interrompu inopinément la transmission de données. Cela peut être dû à une panne du navigateur, à un équipement intermédiaire entre le client et HAProxy qui a décidé de rompre activement la connexion, à des problèmes de routage réseau entre le client et HAProxy, ou à une connexion en continu (keep-alive) entre le serveur et le client qui a été fermée en premier par le client.
cD Le client n'a ni envoyé ni reconnu de données pendant une durée égale au délai « timeout client ». Cela est souvent dû à une panne réseau côté client, ou au fait que le client quitte le réseau de manière non propre.
CH Le client a interrompu la requête pendant l'attente de la réponse du serveur.
Cela peut être dû au délai de réponse du serveur ou au client cliquant trop rapidement sur le bouton « Arrêter ».
cH Le délai d'expiration « client » pendant l'attente des données du client lors d'une requête POST. Cela peut être dû à des valeurs TCP MSS trop élevées sur les réseaux PPPoE, incapables de transmettre des paquets de taille maximale. Cela peut également se produire lorsque le délai d'expiration du client est inférieur à celui du serveur et que ce dernier met trop de temps à répondre.
CQ Le client a interrompu la connexion alors que son flux était en attente dans la file d'attente, en attendant un serveur disposant de suffisamment de slots libres pour l'accepter. Cela peut être dû au fait que tous les serveurs étaient saturés ou que le serveur assigné mettait trop de temps à répondre.
CR Le client a interrompu la transmission d'une requête HTTP complète. Il s'agit probablement d'une requête saisie manuellement à l'aide d'un client telnet, interrompue trop tôt. Le code d'état HTTP est probablement 400. Dans certains cas, cela peut également être dû à un IDS qui interrompt la connexion entre HAProxy et le client. L'option « http-ignore-probes » peut être utilisée pour ignorer les connexions sans transfert de données.
cR Le délai d'expiration « timeout http-request » est déclenché avant que le client n'ait envoyé une requête HTTP complète. Cela peut être dû à des valeurs TCP MSS trop élevées côté client sur des réseaux PPPoE incapables de transmettre des paquets de taille maximale, ou à des clients qui envoient des requêtes manuellement sans taper assez vite, ou en oubliant d'entrer la ligne vide à la fin de la requête. Le code d'état HTTP est probablement 408 ici. Note : récemment, certains navigateurs ont commencé à implémenter une fonctionnalité de « pré-connexion », qui consiste à établir une connexion en avance avec certains sites web récemment visités, au cas où l'utilisateur souhaiterait les visiter. Cela entraîne de nombreuses connexions établies vers des sites web, qui aboutissent à un délai d'expiration 408 si le délai d'expiration est déclenché en premier, ou à une requête 400 Bad Request lorsque le navigateur décide de les fermer en premier. Ces connexions polluent les journaux et alimentent les compteurs d'erreurs. Certains navigateurs ont même été signalés pour afficher directement le code d'erreur. Il est possible de contourner les effets indésirables de ce comportement en ajoutant « option http-ignore-probes » dans le frontal, ce qui fait ignorer entièrement les connexions n'ayant aucune transmission de données. Cela masquera certainement les erreurs des utilisateurs rencontrant des problèmes de connectivité.
CT Le client a interrompu la requête pendant qu'elle était soumise à un tarpit. Il est important de vérifier si cela se produit sur des requêtes valides, afin de s'assurer qu'aucune règle de tarpit incorrecte n'a été configurée. Si un grand nombre d'occurrences sont observées, il peut être pertinent de réduire la valeur du « timeout tarpit » afin de la rapprocher de la valeur moyenne du chronomètre « Tw », afin de ne pas consommer de ressources pour quelques attaquants seulement.
LC La requête a été interceptée et traitée localement par HAProxy. La requête n'a pas été envoyée au serveur. Cela ne se produit que lors d'une redirection due à un paramètre « redir » sur la ligne du serveur.
LR La requête a été interceptée et traitée localement par HAProxy. La requête
n'a pas été envoyée au serveur. Cela signifie généralement qu'une redirection
a été renvoyée, une instruction HTTP return a été traitée ou que la requête
a été gérée par un applet (statistiques, cache, export Prometheus, applet Lua...).
LH La réponse a été interceptée et gérée localement par HAProxy. Cela signifie généralement qu'une redirection a été renvoyée ou qu'une instruction HTTP return a été traitée.
SC Le serveur ou un équipement situé entre celui-ci et HAProxy a explicitement refusé la connexion TCP (le proxy a reçu un message TCP RST ou un message ICMP en retour). Dans certaines circonstances, cela peut également provenir de la pile réseau qui informe le proxy que le serveur est injoignable (par exemple, absence de route ou absence de réponse ARP sur le réseau local). Lorsqu'une telle situation se produit en mode HTTP, le code de statut est probablement un 502 ou un 503.
sC Le délai d'expiration « connect » est déclenché avant la finalisation de la connexion au serveur. Lorsqu'il se produit en mode HTTP, le code de statut est probablement 503 ou 504.
SD La connexion au serveur s'est interrompue avec une erreur pendant le transfert de données. Cela signifie généralement que HAProxy a reçu un RST du serveur ou un message ICMP d'un équipement intermédiaire pendant l'échange de données avec le serveur. Cela peut être dû à un plantage du serveur ou à une panne réseau sur un équipement intermédiaire.
sD Le serveur n'a ni envoyé ni reconnu de données pendant une durée égale au paramètre « timeout server » durant la phase de données. Cela est souvent dû à des délais d'expiration trop courts sur l'équipement L4 situé avant le serveur (pare-feux, équilibreurs de charge, ...), ainsi qu'à l'expiration des sessions keep-alive entre le client et le serveur, qui se produit avant HAProxy.
SH Le serveur a interrompu l'envoi de ses en-têtes de réponse HTTP complets, ou il s'est arrêté de manière anormale pendant le traitement de la requête. Étant donné qu'une interruption du serveur à ce stade est très rare, il est recommandé d'examiner les journaux du serveur afin de vérifier s'il s'est arrêté de manière anormale et pourquoi. La requête journalisée peut indiquer un petit ensemble de requêtes défectueuses, révélant des bogues dans l'application. Parfois, cela peut également être dû à un système de détection d'intrusions (IDS) qui a interrompu la connexion entre HAProxy et le serveur.
sH Le délai d'expiration « server » a été atteint avant que le serveur ne puisse renvoyer ses en-têtes de réponse. Il s'agit de l'anomalie la plus fréquente, indiquant des transactions trop longues, probablement causées par une saturation du serveur ou de la base de données. La solution de contournement immédiate consiste à augmenter le paramètre « timeout server », mais il est important de garder à l'esprit que l'expérience utilisateur sera affectée par ces temps de réponse longs. La seule solution à long terme consiste à corriger l'application.
sQ Le flux a passé trop de temps dans la file d'attente et a expiré. Consultez les paramètres « timeout queue » et « timeout connect » pour savoir comment résoudre ce problème s'il se produit trop fréquemment. Si cela se produit régulièrement et massivement sur de courtes périodes, cela peut indiquer des problèmes généraux sur les serveurs concernés dus à une congestion d'E/S ou de base de données, ou à une saturation causée par des attaques externes.
PC Le proxy a refusé d'établir une connexion avec le serveur car la limite de sockets du processus a été atteinte lors de la tentative de connexion. Le paramètre global « maxconn » peut être augmenté dans la configuration afin d'éviter que cela ne se reproduise. Ce statut est très rare et peut survenir lorsque le paramètre global « ulimit-n » est fixé manuellement.
PD Le proxy a bloqué un message encodé en tronçons mal formaté dans une requête ou une réponse, après que le serveur a émis ses en-têtes. Dans la plupart des cas, cela indique un message invalide émis par le serveur vers le client. HAProxy prend en charge des tailles de tronçons allant jusqu'à 2 Go - 1 (2147483647 octets). Toute taille supérieure sera considérée comme une erreur.
PH Le proxy a bloqué la réponse du serveur, car elle était invalide, incomplète, dangereuse (contrôle de mise en cache) ou correspondait à un filtre de sécurité. Dans tous les cas, une erreur HTTP 502 est renvoyée au client. Une cause possible de cette erreur est une syntaxe incorrecte dans un nom d’en-tête HTTP contenant des caractères non autorisés. Il est également possible, bien que peu probable, que le proxy ait bloqué une requête codée en chunked depuis le client en raison d'une syntaxe invalide, avant que le serveur ne réponde. Dans ce cas, une erreur HTTP 400 est renvoyée au client et signalée dans les journaux. Enfin, cela peut être dû à un échec de réécriture d’en-tête HTTP dans la réponse. Dans ce cas, une erreur HTTP 500 est renvoyée (voir "tune.maxrewrite" et « http-response strict-mode » pour plus d’informations).
PR Le proxy a bloqué la requête HTTP du client, soit en raison d'une syntaxe HTTP invalide, auquel cas il a renvoyé une erreur HTTP 400 au client, soit en raison d'un filtre de refus correspondant, auquel cas il a renvoyé une erreur HTTP 403. Il peut également s'agir d'une erreur de réécriture d'en-tête HTTP sur la requête. Dans ce cas, une erreur HTTP 500 est envoyée (voir "tune.maxrewrite" et « http-request strict-mode » pour plus d'informations).
PT Le proxy a bloqué la requête du client et a appliqué une tarpitation à la connexion avant de la renvoyer avec une erreur serveur 500. Aucune donnée n'a été envoyée au serveur. La connexion est restée ouverte aussi longtemps que l'indique le champ du minuteur "Tw".
RC Une ressource locale a été épuisée (mémoire, sockets, ports sources),
empêchant la connexion au serveur d'être établie. Les journaux d'erreurs
indiqueront précisément quelle ressource manquait. Ce cas est très rare
et ne peut être résolu que par une adaptation appropriée du système.
La combinaison des deux derniers indicateurs fournit de nombreuses informations sur la manière dont la persistance a été gérée par le client, le serveur et HAProxy. Cela est très important pour diagnostiquer les déconnexions lorsque les utilisateurs déclarent devoir se réauthentifier. Les indicateurs couramment rencontrés sont :
8.6. Caractères non imprimables
Afin d’éviter tout problème avec les outils d’analyse de journaux ou les terminaux lors de la consultation des logs, les caractères non imprimables ne sont pas envoyés tels quels dans les fichiers de journal, mais convertis en représentation hexadécimale sur deux chiffres de leur code ASCII, préfixés par le caractère ‘#’. Les seuls caractères pouvant être journalisés sans échappement sont ceux dont la valeur ASCII se situe entre 32 et 126 (inclus). Évidemment, le caractère d’échappement ‘#’ lui-même est également encodé afin d’éviter toute ambiguïté ("#23"). Il en va de même pour le caractère ‘"’, qui devient “#22”, ainsi que pour ‘{’, ‘|’ et ‘}’ lors de la journalisation des en-têtes.
Notez que le caractère espace (’ ‘) n’est pas encodé dans les en-têtes, ce qui peut poser problème pour les outils s’appuyant sur le décompte des espaces pour localiser les champs. Un en-tête typique contenant des espaces est « User-Agent ».
Enfin, il a été observé que certains démons syslog, tels que syslog-ng, échappent la guillemet (« " ») par une barre oblique inverse (« \ »). L’opération inverse peut être effectuée en toute sécurité, car aucune guillemet ne peut apparaître ailleurs dans les journaux.
8.7. Capture de cookies HTTP
La capture de cookie simplifie le suivi d’une session utilisateur complète. Cela peut être réalisé à l’aide de l’instruction « capture cookie » dans le frontal. Voir section 4.2 pour plus de détails. Une seule cookie peut être capturée, et la même cookie est simultanément vérifiée dans la requête (en-tête « Cookie: ») et dans la réponse (en-tête « Set-Cookie: »). Les valeurs correspondantes seront reportées dans les journaux HTTP aux emplacements “captured_request_cookie” et “captured_response_cookie” (voir section 8.2.3 sur le format des journaux HTTP). Lorsqu’une des cookies n’est pas présente, une tiret (’-’) remplace sa valeur. Ainsi, il est facile de détecter quand un utilisateur passe à une nouvelle session, par exemple, car le serveur lui attribue une nouvelle cookie. Il est également possible de détecter si un serveur définit par erreur une cookie incorrecte pour un client, entraînant une croisement de session.
Exemples :
Il est possible d’effectuer des captures plus avancées à l’aide des règles « http-request » et « http-response » afin d’attribuer des cookies à des variables de portée « txn ». Les valeurs des cookies peuvent ensuite être extraites à partir de la requête ou de la réponse à l’aide des fonctions d’extraction d’échantillon “req.cook” et “res.cook” (voir section 7.3.6 ) et attribuées à une variable à l’aide des actions « set-var » ou « set-var-fmt » (voir section 4.3 ). Un format de journalisation personnalisé permettra alors de présenter ces variables là où souhaité (voir section 8.2.6 ).
8.8. Capture d’en-têtes HTTP (version ancienne)
Les captures d’en-têtes sont utiles pour suivre des identifiants uniques de requête définis par un proxy supérieur, des noms de virtual host, des user-agents, la longueur du contenu POST, les référents, etc. Dans la réponse, on peut rechercher des informations sur la longueur de la réponse, la manière dont le serveur a demandé au cache de se comporter, ou l’emplacement d’un objet lors d’une redirection.
Il existe deux façons de capturer des en-têtes. La méthode moderne consiste à définir des variables à partir des en-têtes à capturer, ou à partir d’échantillons composés retournés par “req.hdr_names”, “req.hdrs”, “res.hdr_names”, “res.hdrs” (voir section 7.3.6 ) pour toutes les possibilités. Ces variables peuvent être affectées à des variables de portée « txn » à l’aide des actions « set-var » et « set-var-fmt » des règlesets « http-request » et « http-response » (voir section 4.3 ), puis référencées dans des formats de journalisation personnalisés (voir section 8.2.6 ). Cette méthode est recommandée pour capturer les en-têtes HTTP.
Il existe également la méthode héritée, antérieure aux règles et aux variables http-request, qui ne nécessite pas de modifier le format de journalisation et qui a longtemps été utilisée à la fois pour la journalisation et comme moyen artificiel de transmettre des informations sur une requête tout au long de la transaction HTTP, à l’aide des anciens jeux de règles « capture ». C’est ce qui est décrit dans cette section.
Les captures d’en-têtes héritées sont effectuées à l’aide des instructions « capture request header » et « capture response header » dans le frontal. Veuillez consulter leur définition dans la section 4.2 pour plus de détails.
Il est possible d’inclure à la fois des en-têtes de requête et des en-têtes de réponse en même temps. Les en-têtes inexistants sont enregistrés sous forme de chaînes vides, et si un en-tête apparaît plus d’une fois, seul son dernier occurrence est enregistrée. Les en-têtes de requête sont regroupés entre accolades ‘{’ et ‘}’ dans le même ordre que leur déclaration, et séparés par une barre verticale ‘|’ sans espace. Les en-têtes de réponse suivent la même représentation, mais sont affichés après un espace suivant le bloc d’en-têtes de requête. Ces blocs sont affichés juste avant la requête HTTP dans les journaux.
En tant que cas particulier, il est possible de spécifier la capture d’un en-tête HTTP dans un frontend TCP. Le but est d’autoriser la journalisation des en-têtes qui seront analysés dans un backend HTTP si la requête est ensuite acheminée vers ce backend HTTP.
Exemple :
8.9. Exemples de journaux
Voici des exemples concrets de journaux accompagnés d’une explication. Certains ont été créés manuellement. La partie syslog a été supprimée pour faciliter la lecture. Leur unique objectif est d’expliquer comment les décoder.
>>> haproxy[674]: 127.0.0.1:33318 [15/Oct/2003:08:31:57.130] px-http \
px-http/srv1 6559/0/7/147/6723 200 243 - - ---- 5/3/3/1/0 0/0 \
"HEAD / HTTP/1.0"
=> requête longue (6,5 s) entrée manuellement via « telnet ». Le serveur a répondu en 147 ms, et la session s'est terminée normalement ('----')
>>> haproxy[674]: 127.0.0.1:33319 [15/Oct/2003:08:31:57.149] px-http \
px-http/srv1 6559/1230/7/147/6870 200 243 - - ---- 324/239/239/99/0 \
0/9 "HEAD / HTTP/1.0"
=> Idem, mais la requête a été placée en file d'attente dans la file globale derrière 9 autres requêtes, puis a attendu pendant 1230 ms.
=> requête pour un transfert de données long. L'option « logasap » a été spécifiée, donc le journal a été généré juste avant le transfert des données. Le serveur a répondu en 14 ms, 243 octets d'en-têtes ont été envoyés au client, et le temps total depuis l'acceptation jusqu'à la première octet de données est de 30 ms.
>>> haproxy[674]: 127.0.0.1:33320 [15/Oct/2003:08:32:17.925] px-http \
px-http/srv1 9/0/7/14/30 502 243 - - PH-- 3/2/2/0/0 0/0 \
"GET /cgi-bin/bug.cgi? HTTP/1.0"
=> le proxy a bloqué une réponse serveur soit en raison d'une règle « http-response deny », soit parce que la réponse était mal formatée et non conforme au protocole HTTP, soit parce qu'elle contenait des informations sensibles susceptibles d'être mises en cache. Dans ce cas, la réponse est remplacée par un « 502 mauvais passerelle ». Les indicateurs ("PH--") indiquent que c'est HAProxy qui a décidé de renvoyer le code 502 et non le serveur.
>>> haproxy[18113] : 127.0.0.1:34548 [15/Oct/2003:15:18:55.798] px-http \
px-http/`<NOSRV>` -1/-1/-1/-1/8490 -1 0 - - CR-- 2/2/2/0/0 0/0 ""
=> le client n’a pas terminé sa requête et s’est interrompu lui-même ("C---") après 8,5 s, pendant que le proxy attendait les en-têtes de requête ("-R--"). Aucune donnée n’a été envoyée à aucun serveur.
>>> haproxy[18113]: 127.0.0.1:34549 [15/Oct/2003:15:19:06.103] px-http \
px-http/`<NOSRV>` -1/-1/-1/-1/50001 408 0 - - cR-- 2/2/2/0/0 0/0 ""
Le client n’a pas terminé sa requête, qui a été interrompue par le délai d’attente ("c---") après 50 s, pendant que le proxy attendait les en-têtes de la requête ("-R--"). Aucune donnée n’a été envoyée à aucun serveur, mais le proxy a pu renvoyer un code de réponse 408 au client.
>>> haproxy[18989]: 127.0.0.1:34550 [15/Oct/2003:15:24:28.312] px-tcp \
px-tcp/srv1 0/0/5007 0 cD 0/0/0/0/0 0/0
=> Ce journal a été généré avec l'option tcplog. Le client a expiré après 5 secondes ("c----").
>>> haproxy[18989] : 10.0.0.1:34552 [15/Oct/2003:15:26:31.462] px-http \
px-http/srv1 3183/-1/-1/-1/11215 503 0 - - SC-- 205/202/202/115/3 \
0/0 "HEAD / HTTP/1.0"
La requête a pris 3 s pour s’achever (probablement un problème réseau), et la connexion au serveur a échoué ('SC--') après 4 tentatives de 2 s chacune (la configuration indique 'retries 3'), sans réacheminement (sinon, nous aurions vu "/+3"). Le code d’état 503 a été renvoyé au client. Il y avait 115 connexions sur ce serveur, 202 connexions sur ce proxy et 205 au niveau du processus global. Il est possible que le serveur ait refusé la connexion en raison d’un nombre trop élevé de connexions déjà établies.