Add local decorating support for adding linking metadata when using Log4j2 JsonLayout

[jasonjkeller]

… to Log4j2 JsonLayout

Resolves #1467

This PR prototypes a few different approaches to support adding NR-LINKING metadata to the message when using JsonLayout with Log4j2.

OPTION 1: RECOMMENDED

TL;DR Recommended as it does not break other Log4j2 layouts, limits the scope of layouts it could alter to just Json/Yaml/Xml (though only modifies Json), and does not requires additional user config or splitting the instrumentation across multiple modules .

This approach weaves AbstractJacksonLayout.toSerializable and injects the NR-LINKING metadata into a JSON string (both pretty and compact formats) representing a LogEvent.

https://github.com/apache/logging-log4j2/blob/7e745b42bda9bf6f8ea681d38992d18036fc021e/log4j-core/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout.java#L282-L299

The result of this PR is that when logging using the JsonLayout and with local decorating enabled, the NR-LINKING metadata blob (NR-LINKING|entity.guid|hostname|trace.id|span.id|entity.name|) will be appended to the message string as shown below:

{
  "instant" : {
    "epochSecond" : 1694718968,
    "nanoOfSecond" : 371959000
  },
  "thread" : "http-nio-8081-exec-1",
  "level" : "WARN",
  "loggerName" : "org.springframework.samples.petclinic.system.WelcomeController",
  "message" : "This is a message being logged NR-LINKING|MTE4MjYy1234567890DM2OTExMDU1|zzzzzzv2mv0|5f90433333333298417f724|2670sssssa303e|PetClinic|",
  "endOfBatch" : true,
  "loggerFqcn" : "org.apache.logging.slf4j.Log4jLogger",
  "threadId" : 238,
  "threadPriority" : 5
}

OPTION 2: NOT RECOMMENDED

TL;DR Not recommended as it breaks other Log4j2 layouts and also requires splitting the instrumentation across two modules.

One option is to weave AbstractStringLayout.getBytes(final String s) and modify the string object which represents the JSON string that will be logged. This is the preferred option as it does not require any additional effort from customers.

https://github.com/apache/logging-log4j2/blob/7e745b42bda9bf6f8ea681d38992d18036fc021e/log4j-core/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout.java#L213-L222

This involves some string parsing and manipulation that could be costly when it comes to overhead. You have to find the "message", navigate to the end of that line, and then append the NR-LINKING metadata. Further complicating matters is that the NR-LINKING might already exist if the logged line passed through a different logging library that is already adding the NR-LINKING metadata, such as the JUL example below. This means that first we would have to check if NR-LINKING already exists. The overhead is likely acceptable.

	  {
		"instant" : {
		  "epochSecond" : 1693590220,
		  "nanoOfSecond" : 736537000
		},
		"thread" : "restartedMain",
		"level" : "INFO",
		"loggerName" : "org.apache.catalina.core.StandardService",
		"message" : "Starting service [Tomcat] NR-LINKING|MTE4MjYyMTV8QVBNfEFQUExJQ0FUSU9OfDM2OTExMDU1|pkxvhv2mv0|||DT-SBPetClinic-Caller-K2|",
		"endOfBatch" : false,
		"loggerFqcn" : "java.util.logging.Logger",
		"threadId" : 53,
		"threadPriority" : 5
	  }

Major Caveat: It seems that this approach will break as of 2.15.0 as they seem to have refactored AbstractStringLayout.getBytes. We would have to introduce another instrumentation module to support 2.15.0+, assuming a similar approach can be taken with those newer versions.

This caveat has been resolved with the most recent changes on this PR. There is now a apache-log4j-2 instrumentation module that supports versions 2.6 - 2.14 and a apache-log4j-2.15 instrumentation module that supports versions 2.15+.

---

OPTION 3: NOT RECOMMENDED

TL;DR Not recommended as it breaks backwards compatibly with Log4j2 versions below 2.10.0 and it also requires additional config from customers.

Another approach is to weave the constructor for AbstractJacksonLayout$LogEventWithAdditionalFields(final Object logEvent, final Map<String, String> additionalFields) and add the NR-LINKING metadata to the additionalFields map.

https://github.com/apache/logging-log4j2/blob/7e745b42bda9bf6f8ea681d38992d18036fc021e/log4j-core/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout.java#L359-L362

However the code that instantiates LogEventWithAdditionalFields will never be hit unless additionalFields.length > 0, which means that the customer will be required to have at least one additional field set in their JSON layout like shown below.

	  	<Console name="Console" target="SYSTEM_OUT">
			<JsonLayout complete="false" compact="false">
				<KeyValuePair key="ADD-NR-LINKING-METADATA" value="true" />
			</JsonLayout>
		</Console>

An example of what this instrumentation looks like can be seen here: 4645256#diff-9975c5b457f8a20647825bca0aaa786ec7180120a77f69d8d3f0c1ab8d046deb

Major Caveat: Our apache-log4j-2 currently supports versions 2.6+ but this approach would force us to drop support for versions 2.9.1 and below. Effectively, the instrumentation would support 2.10.0+. This is because AbstractJacksonLayout has been refactored over these versions and the LogEventWithAdditionalFields class that we would target to weave doesn't exist prior to 2.10.0.

It might be technically possible to for us to modify the logic via weave instrumentation so that additionalFields.length > 0 always evaluates to true so that it enters the first conditional statement and creates an instance of LogEventWithAdditionalFields but that feels dangerous as we would always force the logic to evaluate that way and it wouldn't be able to hit the other conditional branches after it.

https://github.com/apache/logging-log4j2/blob/7e745b42bda9bf6f8ea681d38992d18036fc021e/log4j-core/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout.java#L308-L321

  protected Object wrapLogEvent(final LogEvent event) {
        if (additionalFields.length > 0) {
            // Construct map for serialization - note that we are intentionally using original LogEvent
            final Map<String, String> additionalFieldsMap = resolveAdditionalFields(event);
            // This class combines LogEvent with AdditionalFields during serialization
            return new LogEventWithAdditionalFields(event, additionalFieldsMap);
        } else if (event instanceof Message) {
            // If the LogEvent implements the Messagee interface Jackson will not treat is as a LogEvent.
            return new ReadOnlyLogEventWrapper(event);
        } else {
            // No additional fields, return original object
            return event;
        }
    }

[codecov-commenter]

Codecov Report

Merging #1472 (97237cd) into main (cb363ea) will increase coverage by 0.01%.
Report is 10 commits behind head on main.
The diff coverage is 33.33%.

@@             Coverage Diff              @@
##               main    #1472      +/-   ##
============================================
+ Coverage     70.58%   70.59%   +0.01%     
- Complexity     9744     9747       +3     
============================================
  Files           813      813              
  Lines         39259    39269      +10     
  Branches       5961     5963       +2     
============================================
+ Hits          27711    27722      +11     
  Misses         8862     8862              
+ Partials       2686     2685       -1     

Files	Coverage Δ
...newrelic/agent/bridge/logging/AppLoggingUtils.java	87.80% <33.33%> (-2.20%)	⬇️

... and 7 files with indirect coverage changes

📣 We’re building smart automated test selection to slash your CI/CD build times. Learn more