Rsyslog
Rsyslog est un proche de Logstash permettant d’écouter ou de recevoir des logs de nombreuses entrées différentes pour les filtrer et les mettre en forme avant de les renvoyer à un autre endroit. Il est par ailleurs nativement installé sur un certain nombre de distributions GNU/lLinux dont nos distributions Debian à la base de nos images Docker.
Dans l’idée de ne pas faire crasher nos conteneurs Docker quand l’instance de monitoring tombe et d’avoir encore accès aux logs Docker via la commande docker logs
, nous avons choisi de transférer les logs via le démon journald
de Docker de telle sorte que ceux-ci arrivent directement sur la machine. Rsyslog permet de récupérer ces logs et de les envoyer à notre instance Logstash. Pour cela, il suffit d’ajouter un fichier de configuration /etc/rsyslog.d/docker.conf
:
if ($programname == 'dockerd') then { # on cherche les logs envoyés par le démon docker @@localhost:1234 # on les transmet en TCP à l'adresse de notre logstash }
Problème
Les logs étant maintenant tous envoyés par le démon Docker, seul celui-ci est enregistré dans le message de log, on perd donc l’information relative au service qui a envoyé le log.
message:<3>May 26 17:10:23 dockerd[550]: 2017-05-26T15:10:23.238973Z 0 [Note] mysqld: Shutdown complete
Cependant, la commande journalctl CONTAINER_NAME=monContainer
nous permet bien de récupérer seulement les logs du container mysql
et en effet, la documentation docker nous indique qu’ils rajoutent des méta-données au message, les champs :
CONTAINERID
*
CONTAINERIDFULL*
CONTAINERNAMECONTAINERTAG
*
CONTAINERPARTIAL_MESSAGE
Recherches effectuées
Rsyslog permettant de filtrer et modifier les logs, l’idée est donc de récupérer une de ces métadonnées et de la concaténer au message. Pour cela, il faut rajouter des règles soit dans le fichier /etc/rsyslog.d/docker.conf
(mieux) ou directement dans le fichier /etc/rsyslog.conf
en suivant la syntaxe suivante :
# création d'une variable set tag-service = $CONTAINER_TAG # definition d'un template pour le formatage du message # on concatene les différentes variables qu'on veut avoir qu'on entoure du signe % # la syntaxe est très capricieuse : # le caractère spécial \n fonctionne mais \t ne semble pas fonctionner $template templateperso,"%CONTAINER_TAG%\\%rawmsg%\n" # template qu'on aimerait utiliser if ($programname == 'dockerd') then { @@localhost:1234;templateperso # envoi du message via TCP en suivant le formalisme du template défini précedement $ActionExecOnlyWhenPreviousIsSuspended on # en cas d'échec d'envoi TCP & /DATA/logs/service.log;templateperso # envoi vers un fichier local $ActionExecOnlyWhenPreviousIsSuspended off & ~ # arrête le filtrage des logs n'ayant pas validé la condition précédente
Le problème est que nous n’arrivons pas à récupérer les metadata du message, toutes les informations que nous récupérons actuellement sont disponible sur ce template :
$template testProp, "message:%rawmsg%\nhostname:%HOSTNAME%\nfromhost:%FROMHOST%\nsyslogtag:%syslogtag%\npri-text:%PRI-text%\nsyslog$logfacility-text%\nstructured-Data:%STRUCTURED-DATA%\napp-name:%APP-NAME%\nEND\n"
Pourtant, la sortie verbose
de journalctl
nous montre bien que les données sont présentes :
journalctl -o verbose CONTAINER_TAG=mysqld
:
mar. 2017-05-23 18:18:59.177228 CEST [s=c049a5b6ff8e4c3caef8d1f64c689844;i= _UID=0 _GID=0 _CAP_EFFECTIVE=3fffffffff _SYSTEMD_SLICE=system.slice _BOOT_ID=d007332a987843d6ac35db9ea6e6c8c0 _MACHINE_ID=c93a4702101142bd9b6f0cce62b74590 _HOSTNAME=pica01-test PRIORITY=3 _TRANSPORT=journal _PID=550 _COMM=dockerd _EXE=/usr/bin/dockerd _CMDLINE=/usr/bin/dockerd -H fd:// _SYSTEMD_CGROUP=/system.slice/docker.service _SYSTEMD_UNIT=docker.service CONTAINER_NAME=mysql CONTAINER_TAG=mysql CONTAINER_ID=fb104951880d CONTAINER_ID_FULL=fb104951880d8d0fef051a4ab49bdb68a11dee540f7df431856d3 MESSAGE=2017-05-23T16:18:58.936255Z 0 [Warning] TIMESTAMP with implicit _SOURCE_REALTIME_TIMESTAMP=1495556339177228