Gestion des logs sur une plateforme web

GESTION DES LOGS SURUNE PLATEFORME WEB

AU MENULes logs , pourquoi faire ?Logger en java : comment, avec quoiCoté système : syslog and friendsCentralisation des logs : les outils récents

APPROCHE TRADITIONNELLE<barbu> @all, vous pouvez nettoyer les logs dans ~/tomcat/stuff/logs ?<barbu> on a une critical<dev> hmmk, je regarde

POURQUOI ON PARLE PEU DES LOGSPas exactement glamourDifficile à vendre aux clients, et donc au management

POURQUOI IL FAUDRAIT EN PARLERConnaissance de l'usage d'une applicationConnaissance de l'usage d'une plateformeDétection d'anomaliesEt bien sûr debuggage

CE QU'ON ATTEND D'UN SYSTÈME DE LOGSCollecte de messages issus de différentes sourcesNormalisation des messages issus de ces sourcesAccessibilité des messagesSimplification de la recherche d'information

CE QU'ON N'ATTEND PAS FORCÉMENT D'UNSYSTÈME DE LOGS

Archivage pour raison légalesStockage infini de fichiers

MAIS QU'EST-CE QU'UNE LOG ?Un message émis par une application (donc par undéveloppeur)Qui / Quand / Où / Quoi

LOGGER EN JAVA

AU COMMENCEMENT ÉTAIT LOG4JCréé par Ceki GülcüUtilisé depuis 1823

PUIS VINRENT...jdk-logging

Introduction d'un framework de logging dans le JDK 1.4Peu de succès : API limitée, log levels non standards

commons-loggingTentative de création d'une facade pour unifier desimplémentations différentesSuccès mitigé

POUR EN ARRIVER À SLF4J ET LOGBACKCréés par ... Ceki Gülcüslf4j

Successeur de commons-loggingBindings pour les autres frameworks

logbackSuccesseur de log4j

LES RAISONS DE CHOISIR SLF4JApproche "facade"Bindings pour une intégration facile

slf4j-api.jar # facadelogback-classic.jar # implementationlogback-core.jar # implementationjcl-over-slf4j.jar # remplace commons-logging.jarlog4j-over-slf4j.jar # remplace log4jjul-to-slf4j # bridge java.util.logging

LES RAISONS DE CHOISIR LOGBACKPlus performantSemble avoir une meilleure gestion de la concurrenceConfiguration similaire à log4jFormat des messages à la StringFormat

LES RAISONS DE CHOISIR LOGBACKReload des configurationsModularisation via des includes, des variables...Gestion des conditions (if, else)Gestion de la rotationGestion de la compression (bof)

LOGBACK : MODULARISATION DES CONFIGS<included> <jmxConfigurator/> <property name="pattern" value="${origin} %d{dd/MM/yyyy-HH:mm:ss.SSS} [%X{pid}] [%X{phpSessionId}] [%X{userId}] [%X{uniqueId}] [%X{functionalId}] [%thread] %level %C:%L - %msg%n" scope ="context"/> <include resource="logback-appender-console.xml"/> <include resource="logback-appender-graylog.xml"/> <include resource="logback-appender-file.xml"/> <include resource="logback-custom-loggers.xml"/> <include resource="logback-root.xml"/></included>

LOGBACK : GESTION DE CONDITIONS<included> <if condition="property("useFileLogger").equalsIgnoreCase("true")"> <then> <root level="INFO"> <appender-ref ref="FILE"> <appender-ref ref="GELF"> </appender-ref></appender-ref></root> </then> <else> <root level="INFO"> <appender-ref ref="STDOUT"> </appender-ref></root> </else> </if></included>

INTERLUDE

QUELQUES BONNES PRATIQUES

NIVEAU DE LOGCHOISIR LE BON LOG LEVEL N'EST PAS UNE OPTION

// true storylogger.debug("Somethin' very bad happened")

CONTENU DU MESSAGEDonner un maximum de contexte : identifiants, contenu desvariablesLe MDC est là pour automatiser ça

# filter or interceptor String userId = getUserIdSomehow();MDC.put("userId", userId);

# logback pattern %X{userId}

CONTENU DU MESSAGEEviter les informations sensiblesEviter les codes d'erreur ésotériques

logger.error("Error 0004");

Ne pas oublier la stacktrace

logger.error("Error while doing stuff", e);# vslogger.error(e);

PERFORMANCEEviter les logs dans des bouclesConditionner les logs si construction de message complexe

if (logger.isDebugEnabled()) { logger.debug("Printing {}, {} and {}", value1, value2, value3);}

COMME TOUT CODE, LES LOGS SONT À REFACTORERAprès recette en devAprès passage en prod

LE DÉVELOPPEUR EST LE PREMIER RESPONSABLE DE LAQUALITÉ DES LOGS

LES LOGS SYSTÈMEMessages système avec syslogNettoyage avec logrotate

SYSLOGUn protocole créé dans les années 80 pour gérer les logssendmail, puis unixUtilisé pour écrire des logs sur disque, mais aussi pourenvoyer ces logs à d'autres machines

LES COMPOSANTES D'UN MESSAGE SYSLOGTimestampMessageHostnameFacility : le composant système qui a envoyé le message (0 :kernel, 2 : mail, 16: local0...). FigéSeverity : de 0 (Emergency) à 7 (Debug)PRI (8 * Facility + Severity = useless)Le pid du process

Limité à de l'ASCII sur 1024 bytes

EXEMPLE DE MESSAGE SYSLOG<78> CRON Oct 4 14:17:01 support-digi-dev2 13809 - - (root) CMD ( cd / && run-parts --

report /etc/cron.hourly)

SYSLOG AND FRIENDSLes limitations du syslog originel ont donné lieu à desimplémentations concurrentesD'abord syslog-ngPuis rsyslog

EXEMPLE DE CONFIGURATION RSYSLOG/etc/rsyslog.conf

$ModLoad imuxsock # provides support for local system logging$ModLoad imklog # provides kernel logging support (previously done by rklogd)#$ModLoad immark # provides --MARK-- message capability

# provides UDP syslog reception#$ModLoad imudp#$UDPServerRun 514

$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat

$IncludeConfig /etc/rsyslog.d/*.conf

EXEMPLE DE CONFIGURATION RSYSLOG/etc/rsyslog.d/50-default.conf

## First some standard log files. Log by facility.#auth,authpriv.* /var/log/auth.log*.*;auth,authpriv.none -/var/log/syslog#cron.* /var/log/cron.log#daemon.* -/var/log/daemon.logkern.* -/var/log/kern.log#lpr.* -/var/log/lpr.logmail.* -/var/log/mail.log#user.* -/var/log/user.log

EXEMPLE DE CONFIGURATION RSYSLOG/etc/rsyslog.d/99-graylog2.conf

$template Graylog2Output,"<%PRI%> %APP-NAME% %TIMESTAMP% %HOSTNAME% %PROCID% %MSGID% %STRUCTURED-DATA% %msg%\n"$ActionForwardDefaultTemplate Graylog2Output *.* @log-collector.mydomain.local:514

LOGROTATE

OBJECTIFS DE LOGROTATENe pas laisser les logs devenir trop volumineusesNe pas laisser s'accumuler les archives de logs

PRINCIPE DE LOGROTATELe script /etc/cron.daily/logrotate est exécutétous les joursEt traite par défaut toutes les configurations présentes dans/etc/logrotate.d

EXEMPLE DE CONFIGURATION/etc/logrotate.d/apache2

/var/www/*/logs/*.log /var/log/apache2/*log { daily missingok dateext rotate 10 maxage 10 compress ifempty create 644 root adm sharedscripts postrotate if [ -f /var/run/apache2.pid ]; then /etc/init.d/apache2 restart > /dev/null fi endscript}

LIMITES DE LOGROTATESystème de datation pas très souplePas le meilleur ami des applications java

LA CENTRALISATION DESLOGS

Récolter / transformer : logstashStocker / afficher : graylog2, kibana, elasticsearch

LOGSTASHUN PIPELINE DE TRAITEMENT D'ÉVÈNEMENTS COMPOSÉ :

d'inputs : file, syslog...de filtres et codecs : multiline, grok, mutate...d'outputs : graylog, elasticsearch, librato...

Cela donne un système extrêmement souple

LOGSTASH : EXEMPLE D'INPUTTail d'un fichier sur disque

file { type => "my-apache-access" path => ["/var/log/apache2/my-access.log"] exclude => ["*.gz"] debug => true tags => ['access']}

LOGSTASH : EXEMPLE DE FILTREStructuration d'un message avec grok

grok { tags => ['access'] # 172.19.0.24|-|[09/Oct/2012:06:48:09 +0200]|myserver.fr| # 443|POST /dp/ws/v2/gestionnaire HTTP/1.1|200|3148|547905|-|11224 pattern => "%{APACHE_ACCESS_PATTERN}" patterns_dir => "/data/etc/logstash/agent/patterns.d" }

Définition d'une pattern

APACHE_ACCESS_PATTERN %{CLOSE_BRACKET}%{PIPE}%{HOST:current_server}%{PIPE}%{INT:port}%{PIPE}%{WORD:verb} %{EXTENDEDURIPATHPARAM_OR_STAR:request}HTTP/%{NUMBER:httpversion}%{PIPE}%{DASH_OR_NUMBER:response}%{PIPE}%{DASH_OR_NUMBER:bytes}%{PIPE}%{DASH_OR_NUMBER:request_time}%{PIPE}%{DASH_OR_NUMBER:total_request_time}%{PIPE}%{DASH_OR_WORD:phpSessionId}%{PIPE}%{DASH_OR_WORD:pid}%{PIPE}%{UNIQUE_ID:uniqueId}

LOGSTASH : EXEMPLE DE FILTRESuppression d'un message avec grep

grep { tags => ['access'] negate => true match => [ "@message", "/images/" ]}

LOGSTASH : EXEMPLE DE FILTREModification d'un message avec mutate

mutate { tags => ['anon_sign'] gsub => [ "@message", "/my/url?sign=([0-9a-zA-Z]+)", "/my/url?sign=<PRIVATE>" ]}

LOGSTASH : EXEMPLE DE FILTRERecomposition d'une stacktrace avec multiline

multiline { type => "my-java-type" pattern => "̂\s" what => "previous"}

LOGSTASH : EXEMPLE D'OUTPUTEnvoi des logs vers graylog2 et vers la console

gelf { host => "my-log-collector.com" tags => ['access'] level => "info"}

stdout { debug => true }

LOGSTASH : LES LIMITESRefactoring fréquents, donc upgrades douloureuxConsommation CPU et mémoire

GRAYLOG2UN SYSTÈME EN DEUX PARTIES

graylog2-server, un collecteur écrit en javagraylog2-web, une webapp railsLe tout se base sur le format GELF

(attention gros changements à venir)

LE FORMAT GELFUNE VERSION ENRICHIE ET SOUPLE DU FORMAT SYSLOG{ "version": "1.0", "host": "www1", "short_message": "Short message", "full_message": "Backtrace here\n\nmore stuff", "timestamp": 1291899928.412, "level": 1, "facility": "payment-backend", "file": "/var/www/somefile.rb", "line": 356, "_user_id": 42, "_something_else": "foo"}

GRAYLOG2-SERVERUN AGENT JAVA QUI :

récolte les logs qui lui sont envoyées (par logstash, une applijava...)les stocke dans une instance elasticsearch

GRAYLOG2-WEBUNE WEBAPP QUI :

affiche tous les messagespermet une recherche multi-critèresdispose d'un mécanisme de permissionspermet d'explorer les données avec des requêtes libres

VU DE HAUT CA DONNE

© http://www.graylog2.org/

GRAYLOG2-WEB : LISTE DES MESSAGES

GRAYLOG2-WEB : DÉTAIL D'UN MESSAGE

GRAYLOG2-WEB : CONFIGURATION LOGBACK<appender name="GELF" class="me.moocar.logbackgelf.GelfAppender"> <facility>logback-gelf</facility> <graylog2serverhost>${graylogHost}</graylog2serverhost> <graylog2serverport>12201</graylog2serverport> <useloggername>true</useloggername> <usethreadname>true</usethreadname> <graylog2serverversion>0.9.6</graylog2serverversion> <chunkthreshold>1000</chunkthreshold> <messagepattern>%m%rEx</messagepattern> <additionalfield>pid:_pid</additionalfield> <additionalfield>origin:_origin</additionalfield> <additionalfield>userId:_userId</additionalfield> <additionalfield>uniqueId:_uniqueId</additionalfield> <additionalfield>phpSessionId:_phpSessionId</additionalfield> </appender>

GRAYLOG2-WEB : LES LIMITESPeu de problèmes applicatifs mais...Migrations infernalesChangements technologiques fréquentsRecherche textuelle parfois déroutante pour l'utilisateur

EXEMPLE D'APPLICATION : SUIVI D'UNEREQUÊTE

On veut pouvoir suivre une requête dans tous les systèmede l'applicationOn va donc générer un identifiant unique pour cetterequête, et le faire passer de couche en couche

RequestHeader set UNIQUE_ID %{UNIQUE_ID}e

172.23.101.120|172.24.0.111|[24/Oct/2013:09:05:20 +0200]|secure.digiposte.local|443|GET /js/routing?callback=fos.Router.setData HTTP/1.1|200|511|13467|13467|3h3buqge9hs3i7b9bvvgvebot1|25378|UmjGsKwYZWQAABI9RtcAAAAV

EXEMPLE D'APPLICATION : SUIVI D'UNEREQUÊTE

Coté applicatif java, il faut pouvoir recevoir cet id sousforme de header http, ou ampq

// AMQPMDC.put("UNIQUE_ID", message.getHeaders().get("UNIQUE_ID", String.class)); // ou// HTTPMDC.put(MDC_UNIQUE, request.getHeader("UNIQUE_ID"));

Mais aussi le faire passer sous forme de header

MessageProperties properties = new MessageProperties();properties.setHeader("UNIQUE_ID", MDC.get("UNIQUE_ID"));

digiposte-batch-indexer 24/10/2013-10:38:54.024 [32041] [u5dkkmk2s51vs12vhr3r02juo5][f2673dd7bfd7f8a398e550f3bdee2133] [UmjcnawYZWQAAHApDeIAAAAu] [6d516a02f78c40b892eb94277a3ca107] [SimpleAsyncTaskExecutor-1] INFO com.digiposte.batch.core.job launcher.NewRelicTracingJobLauncherDecorator:51 - Appending to NewRelic transaction the parameter = 32041

(TENTATIVE DE DÉMO GRAYLOG2)

CENTRALISATION DES LOGS : LES AUTRESOPTIONS

SAASSystèmes de collecteSystèmes de visualisation

SAAS : LES ACTEURSSplunkPapertrailLoggly

COLLECTE : FLUME“Flume is a distributed, reliable, and availableservice for efficiently collecting, aggregating,

and moving large amounts of log data. It has asimple and flexible architecture based on

streaming data flows. It is robust and faulttolerant with tunable reliability mechanismsand many failover and recovery mechanisms.

It uses a simple extensible data model thatallows for online analytic application.”

Créé chez Cloudera, donné à la fondation ApacheOrienté big dataBeaucoup plus souple que scribe

COLLECTE : FLUENTD“Fluentd is a fully free and fully open-source

log collector that instantly enables you to havea ‘Log Everything’ architecture with 125+

types of systems. Fluentd treats logs as JSON,a popular machine-readable format. It iswritten primarily in C with a thin-Ruby

wrapper that gives users flexibility.”

Créé chez TreasureDataAssez proche de logstashBeaucoup d'inputs / outputs, peu de filtres

VISUALISATION : KIBANAProjet indépendant, passé depuis sous l'ombrelleelasticsearchSe branche sur n'importe quel index elasticsearchUne option à suivre, malgré quelques lacunes de sécurité

QUESTIONS ?