Dd-trace-rb: Setup log injection with Rails Semantic Logger

[truongnmt]

I'm using rails (6.0.3.4), ddtrace (0.40.0) and rails_semantic_logger (4.4.4). Recently Datadog releases "Trace correlation" feature and I'm trying to set it up to work.

https://github.com/DataDog/dd-trace-rb/blob/master/docs/GettingStarted.md#trace-correlation

As written in the documentation, I tried the "Automatic" way which is either by adding configuration in Rails instrumentation log_injection: true or DD_LOGS_INJECTION=true. However, either didn't work. A quick look in the code base, add_log method only adds the additional log tag in the case of logger is lograge or ActiveSupport::TaggedLogging type. In my case which is SemanticLogger, it prints the following warning:

W, [2020-11-18T19:13:21.688997 #87523] WARN -- ddtrace: [ddtrace] Unabe to enable Datadog Trace context, Logger #SemanticLogger::Logger:0x00007ff0d1340598 is not supported

Which means, I can't setup in "Automatic" way. So I tried with manual way in the section For logging in Ruby applications.

In SemanticLogger there is Name Tags feature which add a set of hash log value in every request.

So I setup as below:

config.log_tags = {
  host: -> request { request.host },
  remote_ip: -> request { request.remote_ip },
  request_id: -> request { request.uuid },
  session: -> request { ... },
  user_agent: -> request { request.headers["User-Agent"] },
  dd: -> _request {
    correlation = Datadog.tracer.active_correlation
    {
      env: correlation.env.to_s,
      service: correlation.service.to_s,
      version: correlation.version.to_s,
      trace_id: correlation.trace_id.to_s,
      span_id: correlation.span_id.to_s
    }
  }
}

The additional tag is sent along with the log as below screenshot. But why I can't see the related traces? In the log it said "No Trace associated with this Log"

In the APM, it still said:

No logs found
To correlate logs with traces, inject trace_id and span_id

May I ask in which format should I include the tags for the Trace correlation feature to works? Thanks!

[ericmustin]

Hey there, thanks for reaching out. So support for "automatic" patching of rocketjob/semantic_logger is indeed not supported at the moment, and would currently be a feature request. I can speak with the team internally on where this would line up on our roadmap, I think we want to continue improving our trace/log injection support and this would help that, but it probably won't be available "automatically" in the short term.

So in the meantime, the approach you've taken, setting this up manually, is correct. I believe what's happening here from the screenshot you provided is that you're sending these tags to datadog logs intake in the format of, named_tags.dd.trace_id, but our logs ingestion pipelines are expecting them in the format of just dd.trace_id, not nested within named_tags. It's possible to adjust your logs intake for a differently named trace_id attribute in the Datadog though, I believe if you follow the guide here, all you would need to do is add named_tags.dd.trace_id as a reserved attribute. Example of where this would get added below:

Can you give that a shot and let us know if that unblocks you here? If that doesn't work (it should), there's probably some other issue related to your logs pipeline, so then i'd suggest you contact support and get a ticket opened and we can work through the specifics of your account setup. Feel free to reference this Issue on the support request if it gets to that point.

Cheers

[gingerlime]

We had a similar issue (also using Semantic Logger with DD), and we used a similar config + added remappers to Datadog log parsing

HTH

[truongnmt]

Thanks so much for your helps! Using remapper does work! 🎉 🎉 🎉