Associer vos logs Ruby à vos traces
Rapport de recherche Datadog : Bilan sur l'adoption de l'informatique sans serveur Rapport : Bilan sur l'adoption de l'informatique sans serveur

Associer vos logs Ruby à vos traces

Injection automatique d’ID de trace

Utilisez l’une des options suivantes pour injecter des informations de trace Ruby dans vos logs :

Après avoir configuré Lograge dans une application Rails, modifiez le bloc custom_options dans le fichier de configuration de votre environnement (p. ex., 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 à la sortie du log
    :dd => {
      :trace_id => correlation.trace_id,
      :span_id => correlation.span_id
    },
    :ddsource => ["ruby"],
    :params => event.payload[:params].reject { |k| %w(controller action).include? k }
  }
end

Les applications Rails qui sont configurées avec un logger ActiveSupport::TaggedLogging peuvent ajouter des ID de trace en tant que tags à la sortie du log. L’logger Rails par défaut applique cette journalisation avec des tags, ce qui simplifie l’ajout de tags de trace.

Dans le fichier de configuration de votre environnement Rails (p. ex., config/environments/production.rb), ajoutez le code suivant :

Rails.application.configure do
  config.log_tags = [proc { Datadog.tracer.active_correlation.to_s }]
end

Cela ajoute les tags de trace aux requêtes Web :

# [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.trace_id=7110975754844687674 dd.span_id=7518426836986654206] Processing by ArticlesController#index as */*
# [dd.trace_id=7110975754844687674 dd.span_id=7518426836986654206]   Article Load (0.5ms)  SELECT "articles".* FROM "articles"
# [dd.trace_id=7110975754844687674 dd.span_id=7518426836986654206] Completed 200 OK in 7ms (Views: 5.5ms | ActiveRecord: 0.5ms)

Injection manuelle d’ID de trace

Pour ajouter des ID de trace à votre propre enregistreur, ajoutez un formateur de log qui récupère les ID de trace avec Datadog.tracer.active_correlation, puis ajoutez les ID de trace au message.

Pour s’assurer du bon fonctionnement de la corrélation des logs, vérifiez que les éléments suivants sont inclus dans chaque message :

  • 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.trace_id=<ID_TRACE> dd.span_id=<ID_SPAN>.

Voici un exemple pour illustrer cela :

require 'ddtrace'
require 'logger'

logger = Logger.new(STDOUT)
logger.progname = 'mon_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('Cette opération n'est pas tracée.')
# [2019-01-16 18:38:41 +0000][my_app][WARN][dd.trace_id=0 dd.span_id=0] Cette opération n'est pas tracée.

# Lorsqu'une trace est active
Datadog.tracer.trace('my.operation') { logger.warn('Cette opération est tracée.') }
# [2019-01-16 18:38:41 +0000][my_app][WARN][dd.trace_id=8545847825299552251 dd.span_id=3711755234730770098] Cette opération est tracée.

Remarque : si vous n’utilisez pas une intégration de log de Datadog pour analyser vos logs, des règles de parsing de log personnalisées doivent s’assurer que dd.trace_id et dd.span_id sont analysés en tant que chaînes de caractères. Pour en savoir plus, consultez la FAQ à ce sujet.

Consultez la documentation relative à la journalisation Ruby pour vérifier que l’intégration de log Ruby est bien configurée et que vos logs Ruby sont automatiquement parsés.

Pour aller plus loin