Newrelic Logs Integration: Unnest messages/named_tags, leverage nested objects, quick hacky Dockerfile

[rtizzy]

Issue # (if available)

https://github.com/reidmorrison/semantic_logger/issues/300

Changelog

Changelog updated appropriately.

Content below

- NR Integration: Ensures key/values are not nested under `messages`
- NR Integration: Ensures structures are built for all nested json (I.E build an actual object instead of doing `span.id` as the key)
- NR Integration: Named tags will instead be added directly to the JSON.  `named_tags` now adds key value pairs to object instead of nesting.  
- NR Integration: Conflicts between `named_tags` and existing tags are logged to `named_tag_conflicts` key.
- NR Integration: Adds a quick and hacky Dockerfile and Docker Compose file to allow for testing changes locally.

Description of changes

This PR fixes the NR Log Formatter so that keys are no longer erroneously nested under the message. key as mentioned in the linked issue.

This was initially commented on in the original PR but was simply missed.

• Ensures key/values are not nested under messages
• Ensures structures are built for all nested json (I.E build actual objects)
• Unnest named_tags.
  • Named tags will instead be added directly to the JSON.
  • Any conflicts with existing keys are logged to the named_tag_conflicts key so they are clearly visible and can be alerted on via NR.
• Adds a quick and hacky Dockerfile and Docker Compose file to allow for testing changes locally.
  • This can be expanded later to unify the local development environment and the CI environment for easier testing.

Screenshots

Before

After

Other details

Newrelic documentation is often incredibly contradictory with things spread all over the place.

Here they mention that the addition of a logtype value is required to utilize any log parsing rules in their best practices guide

https://docs.newrelic.com/docs/logs/get-started/logging-best-practices/

Add a logtype attribute to all the data you forward. The attribute is required to use our built-in parsing rules and can also be used to create custom parsing rules based on the data type. The logtype attribute is considered a well known attribute and is used in our quickstart dashboards for log summary information

They then contradict themselves in the Log Parsing docs saying that while this is suggested, it is not explicitly required.

https://docs.newrelic.com/docs/logs/ui-data/parsing/

To simplify the matching process, we recommend adding a logtype attribute to your logs. However, you are not limited to using logtype; one or more attributes can be used as matching criteria in the NRQL WHERE clause.

I can find no example for adding this via the Ruby APM Agent in their docs. I believe it may be possible to do so with the following configuration variable but I'm uncertain if this decoration will work with the SL gem.

https://docs.newrelic.com/docs/apm/agents/ruby-agent/configuration/ruby-agent-configuration/#application_logging-forwarding-custom_attributes

If we find that adding this at the APM level does not append this to the logs, another PR should likely be created to ensure it's possible to optionally set this value (Possibly with a default value like "logtype: semanticlogger" or similar).

By submitting this pull request, I confirm that my contribution is made under the terms of the Apache 2.0 license.

[rtizzy]

@reidmorrison

Hope you're gearing up for an excellent New Years!

If you have some time to review this, I'll be happy to do what's needed to get it across the finish line.

Thanks for your work on the project!

[jdelStrother]

Yes please, would love to avoid the extra nesting under message !

[rtizzy]

I just deployed this on my end and I believe this is now working as most will expect but additional testing is certainly appreciated!

One issue I'm still seeing:

It doesn't look like span.id or trace.is being included as expected (though that was also the case prior to my changes)

Is anyone else seeing that behavior?

[fabn]

@rtizzy I tested your PR in my project and it work like a charm 🚀

I'm eager to see this in production hope it will be merged soon.

Just one quick possible improvement, since NewRelic logs analysis dashboard expects a service_name attriubute it could be nice to add it (maybe renaming application)

[fabn]

@reidmorrison any chance to have this merged?

[rtizzy]

There still seem to be at least a few issues with this implementation.

See the following code as an example

      SemanticLogger.tagged('etl', 'daily', 'matview', failed_jobs: failed_jobs.map do |job|
        {
          source: job.source,
          action: job.action,
          status: job.status
        }
      end) do
        Rails.logger.error('EXAMPLE MESSAGE.')
      end

The intent is that should have a few unnamed tags nested under tags and then a few named tags for failed_jobs. Semantic logger docs seem to say that's how tagged should work.

What I'm actually seeing is that it continues to nest everything under the tags key, including what should be a named block.

If anyone has any suggestions for a fix, I'd appreciate it. Don't currently have the time to dig into it. :(

[fabn]

If anyone has any suggestions for a fix, I'd appreciate it. Don't currently have the time to dig into it. :(

I don't think that's your patch, but is the normal behavior of SemanticLogger, see this pry session (no JSON, no NewRelic):

[5] pry(main)> SemanticLogger.tagged(:foo, bar: :baz) { Rails.logger.info('bar') }
2025-01-29 17:50:44.947424 I [67067:9200 (pry):5] [foo] [{:bar=>:baz}] Rails -- bar

If you want to have both array tags and hash tags you need to perform two different calls as in:

[4] pry(main)> SemanticLogger.tagged(:foo) { SemanticLogger.tagged(bar: :baz) { Rails.logger.info('bar') } }
2025-01-29 17:50:32.840904 I [67067:9200 (pry):4] [foo] {bar: baz} Rails -- bar

With colors is better 😉

[rtizzy]

@kaylareopelle

Thanks for reaching out. Hope you're well.

What's the latest status on span_id, trace_id, entity_name, etc? Is the agent attaching them to the event?

Here is an example redacted log message that I'm receiving, some of these, like entity_name seem to be attached where others do not.

I would expect things like trace_id or span_id to only be associated if there is a Trace associated with the log message.

How does that associated happen and is there a good way to "force it" to check that it's working?

{
  "application": "Semantic Logger",
  "entity.guid": "INFOHERE",
  "entity.guids": "INFOHERE",
  "entity.name": "INFOHERE",
  "entity.type": "SERVICE",
  "environment": "INFOHERE",
  "hostname": "INFOHERE",
  "jid": "INFOHERE",
  "level": "INFO",
  "logger.name": "Rails",
  "message": "INFOHERE",
  "newrelic.logPattern": "nr.DID_NOT_MATCH",
  "newrelic.source": "logs.APM",
  "payload.adapter": "INFOHERE",
  "payload.arguments": "[$LISTOFARGSHERE]",
  "payload.event_name": "INFOHERE",
  "payload.job_class": "INFOHERE",
  "payload.job_id": "INFOHERE",
  "payload.provider_job_id": "INFOHERE",
  "payload.queue": "INFOHERE",
  "queue": "INFOHERE",
  "tags": "TAGSHERE]",
  "thread.name": "INFOHERE",
  "timestamp": 1737805749065
}

[jdelStrother]

I would expect things like trace_id or span_id to only be associated if there is a Trace associated with the log message.

How does that associated happen and is there a good way to "force it" to check that it's working?

You'll get trace_id & span_id if the agent has called something like NewRelic::Agent::Tracer.start_transaction(category: 'foo', name: 'test'), which happens automatically from NewRelic's instrumentation of Rails transactions, sidekiq jobs, etc, etc.

However, they're thread-local, so capturing them in SemanticLogger's async appender thread always returns nil, at least for me. I ended up doing something like this to capture them as soon as the Log object is created -

    module NewRelicMetadata
      def initialize(...)
        super
        @newrelic_attrs = {
          "trace.id": ::NewRelic::Agent::Tracer.current_trace_id,
          "span.id":  ::NewRelic::Agent::Tracer.current_span_id,
        }.compact
      end
      def newrelic_attrs = @newrelic_attrs
    end

    SemanticLogger::Log.prepend(NewRelicMetadata)

and then modifying NewRelicLogFormatter to merge in log.newrelic_attrs.

[rtizzy]

@reidmorrison

Thanks for getting things merged in.

@jdelStrother

Thanks for the detail there.

Is there any possibility you'd be able to create an PR for this? I'd certainly appreciate it!

[jdelStrother]

I'll try and submit something later this week