Depuis que je me suis mis sur docker swarm, ma plus grosse problématique a été la gestion des logs. Cette architecture qui répartie les services entre plusieurs machines répartie également les logs. Pour peu qu'un service redémarre ou qu'un problème survienne, on risque de perdre une partie des logs et ne plus pouvoir inspecter les erreurs d'une application.

Un peu de prospection

J'ai rapidement cherché une solution pour centraliser les logs de mes applications et j'ai souvent été ramené vers Elastic Search et la populaire stack ELK^[1]. Ma contrainte étant la gratuité et la maitrise de mes données cela semblait être une bonne option.
Cependant, le problème de cette stack, de mon point de vue, c'est sa grosse consommation de ressources, et sa configuration pénible à implémenter. De plus je n'ai pas trouvé que logstash soit assez flexible sur le formattage des logs.

Photo by Štefan Štefančík / Unsplash

J'ai également testé une autre stack à base d'Elastic Search mais cette fois avec Fluentd^[2] à la place de Logstash. Dans la configuration que j'ai pu rencontrer il fallait configurer les driver de log sur chacun des services que je souhaitais surveiller. Au final ce n'était pas pratique car la moindre défaillance au niveau de fluentd faisait planter tous les services qui l'utilisaient.

Vers une solution partielle

Du moment ou j'ai commencé à m'intéresser au sujet de centralisation des logs à aujourd'hui, il s'est passé un an. Sur toutes les solutions que j'ai pu observer, Elastic Search et Kibana en étaient très souvent des composants. Par chance, ces deux projets ont également évolué pendant cette période pour être plus faciles d'accès.
Je me suis donc retrouvé avec une solution partielle pour stocker et visualiser mes données. Il ne me restait plus qu'à trouver de quoi collecter et traiter mes logs.

Création d'un outil de collecte

Finalement je me suis retourné vers mes propres compétences en développement pour mettre en place une solution qui corresponde à mon besoin ... et peut-etre à celui d'autres.
J'ai alors développé LogPycker, un petit projet python qui se connecte au daemon docker pour aller lire les logs de chacun des conteneurs déployés. De base, il effectue un parsing sommaire afin de construire un message structuré, au mieux, de la manière suivante :

{
    "date": "August 4th 2018, 10:32:31.384",
    "project": "my-project",
    "service": "my-service",
    "task": "my-task-id",
    "message": "content of my message"
}

Certains attributs du message peuvent ne pas être présent notamment lorsque le conteneur est lancé tout seul. En effet, les attributs project, service et task ne sont disponibles que si le conteneur est lancé par le biais d'une stack (compose ou swarm).

Photo by Oskars Sylwan / Unsplash

Utilisation de Log Pycker

Comme je l'ai dit plus tôt, mon objectif premier était de disposer d'un aggrégateur de log simple à mettre en place. Outre la configuration du point daccès vers Elastic Search , s'il n'y a rien à configurer de particulier pour récupérer des logs, on ne peut que mieux se porter.

Je me suis donc basé sur la stack ELK^[1:1] afin de mettre en place mon outil. Cela m'a faut aboutir à la stack suivante (en mode compose) :

version: "3.2"

networks:
  logger-net:
  docker-net:
    external: true

services:
  elastic:
    environment:
      discovery.type: single-node
    image: docker.elastic.co/elasticsearch/elasticsearch:6.3.1
    networks:
      - logger-net
    restart: always

  pycker:
    depends_on:
      - elastic
    environment:
      elastic.url: http://elastic
    image: xylphid/log-pycker:latest
    links:
      - elastic
    networks:
      - logger-net
    volumes:
      - /var/run/docker.sock:/var/run/docker.sock

  kibana:
    depends_on:
      - elastic
    environment:
      ELASTICSEARCH_URL: http://elastic:9200
    image: docker.elastic.co/kibana/kibana:6.3.1
    labels:
      traefik.enable: "true"
      traefik.backend: "Monitor"
      traefik.docker.network: "docker-net"
      traefik.frontend.headers.SSLRedirect: "true"
      traefik.frontend.rule: "Host: monitor.docker"
      traefik.port: "5601"
    links:
      - elastic
    networks:
      - docker-net
      - logger-net

Note : J'utilise Traefik^[3] afin de pouvoir accéder à kibana via l'adresse http://monitor.docker (domaine local)

Comme on peut le voir, le service pycker est relativement facile à configurer. Il n'a besoin que de connaitre l'adresse d'Elastic Search et d'avoir accès, par le biais du volume, au daemon docker.

Pour aller un peu plus loin

Le besoin d'analyse des logs pouvant être différent selon les services que l'on souhaite surveiller, j'ai souhaité mettre en place un mécanisme qui permette, depuis chaque conteneur, de spécifier un format d'extraction des données.
Pour cela, il suffit de définir un label de conteneur avec une expression régulière spécifiant le pattern d'extraction.
Voici un exemple de ce que j'utilise pour extraire le niveau de log d'un projet Play Framework! :

version: "3.2"
services:
  web-app:
    image: my-web-app-play
    labels:
      log.pycker.pattern: "(?P<level>(?:[[])?(?:INFO|DEBUG|ERROR)(?:[]])?)\\s*"
    restart: always

Comment cela fonctionne ?
Assez simplement au final. L'expression régulière utilise des groupes nommés qui serviront à définir les attributs complémentaires de notre objet message. Si le message match un des groupes il sera extrait et nettoyé.

Voici un message avant traitement :

{
    "message": "INFO ~ [LogManager][before] Requested URI : GET:/"
}

Et voici le même message après avoir été analysé avec le pattern :

{
    "level": "INFO",
    "message": "~ [LogManager][before] Requested URI : GET:/"
}

Il est également possible de détecter automatiquement les messages multiligne. Pour cela, il faut activer l'option via un label de conteneur.
Dans cette première version de l'application, cette option est très fortement liée à la présence de la date. Ainsi un message avec une date sera systématiquement considéré comme un nouveau message alors qu'un message n'ayant pas cette information sera rattaché au précédent.

Si l'on reprend notre stack précédente, nous avons modifié la définition comme suit :

version: "3.2"
services:
  web-app:
    image: my-web-app-play
    labels:
      log.pycker.pattern: "(?P<level>(?:[[])?(?:INFO|DEBUG|ERROR)(?:[]])?)\\s*"
      log.pycker.multiline.enabled: "true"
    restart: always

Ces deux options permettent d'améliorer la qualité des informations récupérées par l'outil de collecte et, pour peu que l'on manipule correctement les expressions régulières, d'avoir un détail relativement fin dans le découpage des logs.

Amélioration à venir

Voici les quelques évolutions que j'envisage de mettre en place à ce jour afin d'améliorer les performances de l'application :

• Utiliser une message queue pour stocker les messages en cas d'erreur réseau (avec un fallback en local)
• Récupérer tout l'historique de log d'un conteneur.

Remonter un bug ou contribuer

Le projet est actuellement en phase de test sur une petite architecture qui héberge une vingtaine de services.
Vous pouvez, si vous le souhaitez, le tester sur votre propre infrastructure et remonter vos bugs via github.