Associer vos logs Ruby à vos traces
Mise en corrélation des traces
Dans de nombreux cas, par exemple pour le logging, il peut s’avérer utile de mettre en corrélation les ID de trace à d’autres événements ou flux de données afin de comparer ces différentes sources plus facilement.
Journalisation dans les applications Rails
Injection automatique
Pour les applications Rails qui utilisent le logger par défaut (ActiveSupport::TaggedLogging
) ou lograge
, vous pouvez activer automatiquement l’injection des informations de mise en corrélation des traces en définissant l’option de configuration de l’instrumentation rails
intitulée log_injection
sur true
ou en définissant la variable d’environnement DD_LOGS_INJECTION=true
:
# config/initializers/datadog.rb
require 'ddtrace'
Datadog.configure do |c|
c.use :rails, log_injection: true
end
Remarque : Rails charge les initialiseurs dans l’ordre alphabétique. Ainsi, pour les utilisateurs lograge
qui ont également défini lograge.custom_options
dans un fichier de configuration initializers/lograge.rb
, il est possible que la corrélation automatique des traces ne soit pas appliquée. En effet, initializers/datadog.rb
serait écrasé par l’initialiseur initializers/lograge.rb
. Pour activer la corrélation automatique des traces avec un paramètre lograge.custom_options
existant, utilisez la configuration manuelle de Lograge ci-dessous.
Injection manuelle
Lograge
Après avoir configuré Lograge dans une application Rails, modifiez manuellement le bloc custom_options
dans le fichier de configuration de votre environnement (par exemple, config/environments/production.rb
) pour ajouter les ID de trace.
config.lograge.custom_options = lambda do |event|
# Récupère les informations de trace pour le thread actuel
correlation = Datadog.tracer.active_correlation
{
# Ajoute les ID en tant que tags au log généré
:dd => {
# Pour maintenir le même niveau de précision durant la sérialisation JSON, utiliser des chaînes pour les grands nombres
:trace_id => correlation.trace_id.to_s,
:span_id => correlation.span_id.to_s,
:env => correlation.env.to_s,
:service => correlation.service.to_s,
:version => correlation.version.to_s
},
:ddsource => ["ruby"],
:params => event.payload[:params].reject { |k| %w(controller action).include? k }
}
end
ActiveSupport::TaggedLogging
Les applications Rails configurées avec le logger ActiveSupport::TaggedLogging
par défaut peuvent ajouter des ID de corrélation en tant que tags aux logs générés. Pour activer la mise en corrélation des traces avec ActiveSupport::TaggedLogging
, ajoutez ce qui suit dans le fichier de configuration de votre environnement Rails :
Rails.application.configure do
config.log_tags = [proc { Datadog.tracer.active_correlation.to_s }]
end
# Pour :
# DD_ENV = 'production' (Le nom de l'environnement dans lequel votre application est exécutée.)
# DD_SERVICE = 'billing-api' (Le nom de service par défaut de votre application.)
# DD_VERSION = '2.5.17' (La version de votre application.)
# Les requêtes Web vont générer :
# [dd.env=production dd.service=billing-api dd.version=2.5.17 dd.trace_id=7110975754844687674 dd.span_id=7518426836986654206] Started GET "/articles" for 172.22.0.1 at 2019-01-16 18:50:57 +0000
# [dd.env=production dd.service=billing-api dd.version=2.5.17 dd.trace_id=7110975754844687674 dd.span_id=7518426836986654206] Processing by ArticlesController#index as */*
# [dd.env=production dd.service=billing-api dd.version=2.5.17 dd.trace_id=7110975754844687674 dd.span_id=7518426836986654206] Article Load (0.5ms) SELECT "articles".* FROM "articles"
# [dd.env=production dd.service=billing-api dd.version=2.5.17 dd.trace_id=7110975754844687674 dd.span_id=7518426836986654206] Completed 200 OK in 7ms (Views: 5.5ms | ActiveRecord: 0.5ms)
Journalisation dans les applications Ruby
Pour ajouter des ID de corrélation à votre logger, ajoutez un formateur de log qui récupère les ID de corrélation avec Datadog.tracer.active_correlation
, puis ajoutez les ID au message.
Pour vous assurer que vos logs Datadog sont bien mis en corrélation, vérifiez que les éléments suivants sont inclus dans chaque message de log (l’ordre doit être le même) :
dd.env=<ENV>
: où <ENV>
correspond à Datadog.tracer.active_correlation.env
. N’incluez pas cet élément si aucun environnement n’est configuré.dd.service=<SERVICE>
: où <SERVICE>
correspond à Datadog.tracer.active_correlation.service
. N’incluez pas cet élément si aucun nom de service par défaut n’est configuré.dd.version=<VERSION>
: où <VERSION>
correspond à Datadog.tracer.active_correlation.version
. N’incluez pas cet élément si aucune version de l’application n’est configurée.dd.trace_id=<ID_TRACE>
: <ID_TRACE>
a pour valeur Datadog.tracer.active_correlation.trace_id
ou 0
en l’absence de trace active lors de la journalisation.dd.span_id=<ID_SPAN>
: <ID_SPAN>
a pour valeur Datadog.tracer.active_correlation.span_id
ou 0
en l’absence de trace active lors de la journalisation.
Par défaut, Datadog::Correlation::Identifier#to_s
renvoie dd.env=<ENV> dd.service=<SERVICE> dd.version=<VERSION> dd.trace_id=<ID_TRACE> dd.span_id=<ID_SPAN>
.
Si une trace n’est pas active et que ni l’environnement ni la version de l’application ne sont configurés, il renvoie dd.trace_id=0 dd.span_id=0 dd.env= dd.version=
.
Voici un exemple pour illustrer cela :
require 'ddtrace'
require 'logger'
ENV['DD_ENV'] = 'production'
ENV['DD_SERVICE'] = 'billing-api'
ENV['DD_VERSION'] = '2.5.17'
logger = Logger.new(STDOUT)
logger.progname = 'my_app'
logger.formatter = proc do |severity, datetime, progname, msg|
"[#{datetime}][#{progname}][#{severity}][#{Datadog.tracer.active_correlation}] #{msg}\n"
end
# Lorsqu'aucune trace n'est active
logger.warn('This is an untraced operation.')
# [2019-01-16 18:38:41 +0000][my_app][WARN][dd.env=production dd.service=billing-api dd.version=2.5.17 dd.trace_id=0 dd.span_id=0] This is an untraced operation.
# Lorsqu'une trace est active
Datadog.tracer.trace('my.operation') { logger.warn('This is a traced operation.') }
# [2019-01-16 18:38:41 +0000][my_app][WARN][dd.env=production dd.service=billing-api dd.version=2.5.17 dd.trace_id=8545847825299552251 dd.span_id=3711755234730770098] This is a traced operation.
Pour aller plus loin
Documentation, liens et articles supplémentaires utiles: