From 3fc5cf1c503df91de1ea165f660ba8b08613ffd5 Mon Sep 17 00:00:00 2001 From: jasonjkeller Date: Fri, 20 Oct 2023 08:57:19 -0700 Subject: [PATCH 01/14] Split log4j2 into two modules --- instrumentation/apache-log4j-2.6/build.gradle | 17 + .../instrumentation/log4j2/AgentUtil.java | 154 +++++ .../instrumentation/log4j2/ExceptionUtil.java | 49 ++ .../log4j/core/LogEvent_Instrumentation.java | 77 +++ .../config/LoggerConfig_Instrumentation.java | 66 ++ ...AbstractJacksonLayout_Instrumentation.java | 57 ++ .../StringBuilderEncoder_Instrumentation.java | 45 ++ .../logging/log4j/core/time/Instant.java | 7 + .../log4j2/ContextDataTest.java | 63 ++ .../log4j2/ExceptionUtilTest.java | 61 ++ .../LoggerConfig_InstrumentationTest.java | 626 ++++++++++++++++++ ...plication_logging_context_data_enabled.yml | 12 + .../resources/application_logging_enabled.yml | 10 + instrumentation/apache-log4j-2/build.gradle | 2 +- .../instrumentation/log4j2/AgentUtil.java | 7 +- settings.gradle | 1 + 16 files changed, 1250 insertions(+), 4 deletions(-) create mode 100644 instrumentation/apache-log4j-2.6/build.gradle create mode 100644 instrumentation/apache-log4j-2.6/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java create mode 100644 instrumentation/apache-log4j-2.6/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java create mode 100644 instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/LogEvent_Instrumentation.java create mode 100644 instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java create mode 100644 instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java create mode 100644 instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java create mode 100644 instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/time/Instant.java create mode 100644 instrumentation/apache-log4j-2.6/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java create mode 100644 instrumentation/apache-log4j-2.6/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java create mode 100644 instrumentation/apache-log4j-2.6/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java create mode 100644 instrumentation/apache-log4j-2.6/src/test/resources/application_logging_context_data_enabled.yml create mode 100644 instrumentation/apache-log4j-2.6/src/test/resources/application_logging_enabled.yml diff --git a/instrumentation/apache-log4j-2.6/build.gradle b/instrumentation/apache-log4j-2.6/build.gradle new file mode 100644 index 0000000000..dff4ad111b --- /dev/null +++ b/instrumentation/apache-log4j-2.6/build.gradle @@ -0,0 +1,17 @@ +jar { + manifest { attributes 'Implementation-Title': 'com.newrelic.instrumentation.apache-log4j-2.6' } +} + +dependencies { + implementation(project(":agent-bridge")) + implementation("org.apache.logging.log4j:log4j-core:2.10.0") +} + +verifyInstrumentation { + passesOnly("org.apache.logging.log4j:log4j-core:[2.6,2.11.0)") +} + +site { + title 'Log4j2' + type 'Framework' +} diff --git a/instrumentation/apache-log4j-2.6/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java b/instrumentation/apache-log4j-2.6/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java new file mode 100644 index 0000000000..f29566deba --- /dev/null +++ b/instrumentation/apache-log4j-2.6/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java @@ -0,0 +1,154 @@ +/* + * + * * Copyright 2022 New Relic Corporation. All rights reserved. + * * SPDX-License-Identifier: Apache-2.0 + * + */ + +package com.nr.agent.instrumentation.log4j2; + +import com.newrelic.agent.bridge.AgentBridge; +import com.newrelic.agent.bridge.logging.AppLoggingUtils; +import com.newrelic.agent.bridge.logging.LogAttributeKey; +import com.newrelic.agent.bridge.logging.LogAttributeType; +import org.apache.logging.log4j.Level; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.message.Message; + +import java.util.HashMap; +import java.util.Map; + +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.DEFAULT_NUM_OF_LOG_EVENT_ATTRIBUTES; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.ERROR_CLASS; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.ERROR_MESSAGE; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.ERROR_STACK; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.INSTRUMENTATION; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.LEVEL; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.LOGGER_FQCN; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.LOGGER_NAME; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.MESSAGE; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.THREAD_ID; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.THREAD_NAME; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.TIMESTAMP; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.UNKNOWN; + +public class AgentUtil { + /** + * Record a LogEvent to be sent to New Relic. + * + * @param event to parse + */ + public static void recordNewRelicLogEvent(LogEvent event) { + if (event != null) { + Message message = event.getMessage(); + Throwable throwable = event.getThrown(); + + if (shouldCreateLogEvent(message, throwable)) { + Map contextData = event.getContextMap(); + Map logEventMap = new HashMap<>(calculateInitialMapSize(contextData)); + logEventMap.put(INSTRUMENTATION, "apache-log4j-2.6"); + if (message != null) { + String formattedMessage = message.getFormattedMessage(); + if (formattedMessage != null && !formattedMessage.isEmpty()) { + logEventMap.put(MESSAGE, formattedMessage); + } + } + logEventMap.put(TIMESTAMP, event.getTimeMillis()); + + if (AppLoggingUtils.isAppLoggingContextDataEnabled() && contextData != null) { + for (Map.Entry entry : contextData.entrySet()) { + String key = entry.getKey(); + String value = entry.getValue(); + LogAttributeKey logAttrKey = new LogAttributeKey(key, LogAttributeType.CONTEXT); + logEventMap.put(logAttrKey, value); + } + } + + Level level = event.getLevel(); + if (level != null) { + String levelName = level.name(); + if (levelName.isEmpty()) { + logEventMap.put(LEVEL, UNKNOWN); + } else { + logEventMap.put(LEVEL, levelName); + } + } + + String errorStack = ExceptionUtil.getErrorStack(throwable); + if (errorStack != null) { + logEventMap.put(ERROR_STACK, errorStack); + } + + String errorMessage = ExceptionUtil.getErrorMessage(throwable); + if (errorMessage != null) { + logEventMap.put(ERROR_MESSAGE, errorMessage); + } + + String errorClass = ExceptionUtil.getErrorClass(throwable); + if (errorClass != null) { + logEventMap.put(ERROR_CLASS, errorClass); + } + + String threadName = event.getThreadName(); + if (threadName != null) { + logEventMap.put(THREAD_NAME, threadName); + } + + logEventMap.put(THREAD_ID, event.getThreadId()); + + String loggerName = event.getLoggerName(); + if (loggerName != null) { + logEventMap.put(LOGGER_NAME, loggerName); + } + + String loggerFqcn = event.getLoggerFqcn(); + if (loggerFqcn != null) { + logEventMap.put(LOGGER_FQCN, loggerFqcn); + } + + AgentBridge.getAgent().getLogSender().recordLogEvent(logEventMap); + } + } + } + + /** + * A LogEvent MUST NOT be reported if neither a log message nor an error is logged. If either is present report the LogEvent. + * + * @param message Message to validate + * @param throwable Throwable to validate + * @return true if a LogEvent should be created, otherwise false + */ + private static boolean shouldCreateLogEvent(Message message, Throwable throwable) { + return (message != null) || !ExceptionUtil.isThrowableNull(throwable); + } + + private static int calculateInitialMapSize(Map mdcPropertyMap) { + return AppLoggingUtils.isAppLoggingContextDataEnabled() && mdcPropertyMap != null + ? mdcPropertyMap.size() + DEFAULT_NUM_OF_LOG_EVENT_ATTRIBUTES + : DEFAULT_NUM_OF_LOG_EVENT_ATTRIBUTES; + } + + /** + * Checks pretty or compact JSON layout strings for a series of characters and returns the index of + * the characters or -1 if they were not found. This is used to find the log "message" substring + * so that the NR-LINKING metadata blob can be inserted when using local decorating with JsonLayout. + * + * @param writerString String representing JSON formatted log event + * @return positive int if index was found, else -1 + */ + public static int getIndexToModifyJson(String writerString) { + return writerString.indexOf("\",", writerString.indexOf("message")); + } + + /** + * Check if a valid match was found when calling String.indexOf. + * If index value is -1 then no valid match was found, a positive integer represents a valid index. + * + * @param indexToModifyJson int representing index returned by indexOf + * @return true if a valid index was found, else false + */ + public static boolean foundIndexToInsertLinkingMetadata(int indexToModifyJson) { + return indexToModifyJson != -1; + } + +} diff --git a/instrumentation/apache-log4j-2.6/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java b/instrumentation/apache-log4j-2.6/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java new file mode 100644 index 0000000000..a0f650906a --- /dev/null +++ b/instrumentation/apache-log4j-2.6/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java @@ -0,0 +1,49 @@ +package com.nr.agent.instrumentation.log4j2; + +public class ExceptionUtil { + public static final int MAX_STACK_SIZE = 300; + + public static boolean isThrowableNull(Throwable throwable) { + return throwable == null; + } + + public static String getErrorStack(Throwable throwable) { + if (isThrowableNull(throwable)) { + return null; + } + + StackTraceElement[] stack = throwable.getStackTrace(); + return getErrorStack(stack); + } + + public static String getErrorStack(StackTraceElement[] stack) { + return getErrorStack(stack, MAX_STACK_SIZE); + } + + public static String getErrorStack(StackTraceElement[] stack, Integer maxStackSize) { + if (stack == null || stack.length == 0) { + return null; + } + + StringBuilder stackBuilder = new StringBuilder(); + int stackSizeLimit = Math.min(maxStackSize, stack.length); + for (int i = 0; i < stackSizeLimit; i++) { + stackBuilder.append(" at ").append(stack[i].toString()).append("\n"); + } + return stackBuilder.toString(); + } + + public static String getErrorMessage(Throwable throwable) { + if (isThrowableNull(throwable)) { + return null; + } + return throwable.getMessage(); + } + + public static String getErrorClass(Throwable throwable) { + if (isThrowableNull(throwable)) { + return null; + } + return throwable.getClass().getName(); + } +} diff --git a/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/LogEvent_Instrumentation.java b/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/LogEvent_Instrumentation.java new file mode 100644 index 0000000000..1c7d34a44a --- /dev/null +++ b/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/LogEvent_Instrumentation.java @@ -0,0 +1,77 @@ +///* +// * +// * * Copyright 2023 New Relic Corporation. All rights reserved. +// * * SPDX-License-Identifier: Apache-2.0 +// * +// */ +// +//package org.apache.logging.log4j.core; +// +//import com.newrelic.api.agent.NewRelic; +//import com.newrelic.api.agent.weaver.MatchType; +//import com.newrelic.api.agent.weaver.NewField; +//import com.newrelic.api.agent.weaver.Weave; +//import org.apache.logging.log4j.Level; +//import org.apache.logging.log4j.Marker; +//import org.apache.logging.log4j.ThreadContext; +//import org.apache.logging.log4j.core.impl.ThrowableProxy; +//import org.apache.logging.log4j.message.Message; +//import org.apache.logging.log4j.util.ReadOnlyStringMap; +// +//import java.util.Map; +// +//import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingLocalDecoratingEnabled; +// +//@Weave(originalName = "org.apache.logging.log4j.core.LogEvent", type = MatchType.Interface) +//public abstract class LogEvent_Instrumentation { +// +// /* +// * In cases where the LogEvent is sent to an AsyncAppender, getLinkingMetadata would get called on a new thread and the trace.id and span.id +// * would be missing. To work around this we save the linking metadata on the LogEvent on the thread where it was created and use it later. +// */ +// @NewField +// public Map agentLinkingMetadata = isApplicationLoggingLocalDecoratingEnabled() ? NewRelic.getAgent().getLinkingMetadata() : null; +// +// public abstract LogEvent toImmutable(); +// +// @Deprecated +// public abstract Map getContextMap(); +// +// public abstract ReadOnlyStringMap getContextData(); +// +// public abstract ThreadContext.ContextStack getContextStack(); +// +// public abstract String getLoggerFqcn(); +// +// public abstract Level getLevel(); +// +// public abstract String getLoggerName(); +// +// public abstract Marker getMarker(); +// +// public abstract Message getMessage(); +// +// public abstract long getTimeMillis(); +// +// public abstract StackTraceElement getSource(); +// +// public abstract String getThreadName(); +// +// public abstract long getThreadId(); +// +// public abstract int getThreadPriority(); +// +// public abstract Throwable getThrown(); +// +// public abstract ThrowableProxy getThrownProxy(); +// +// public abstract boolean isEndOfBatch(); +// +// public abstract boolean isIncludeLocation(); +// +// public abstract void setEndOfBatch(boolean endOfBatch); +// +// public abstract void setIncludeLocation(boolean locationRequired); +// +// public abstract long getNanoTime(); +//} diff --git a/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java b/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java new file mode 100644 index 0000000000..15f9df708c --- /dev/null +++ b/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java @@ -0,0 +1,66 @@ +/* + * + * * Copyright 2022 New Relic Corporation. All rights reserved. + * * SPDX-License-Identifier: Apache-2.0 + * + */ + +package org.apache.logging.log4j.core.config; + +import com.newrelic.api.agent.NewRelic; +import com.newrelic.api.agent.weaver.MatchType; +import com.newrelic.api.agent.weaver.NewField; +import com.newrelic.api.agent.weaver.Weave; +import com.newrelic.api.agent.weaver.WeaveAllConstructors; +import com.newrelic.api.agent.weaver.Weaver; +import org.apache.logging.log4j.core.LogEvent; + +import java.util.concurrent.atomic.AtomicBoolean; + +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingEnabled; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingForwardingEnabled; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingMetricsEnabled; +import static com.nr.agent.instrumentation.log4j2.AgentUtil.recordNewRelicLogEvent; + +@Weave(originalName = "org.apache.logging.log4j.core.config.LoggerConfig", type = MatchType.ExactClass) +public class LoggerConfig_Instrumentation { + @NewField + public static AtomicBoolean instrumented = new AtomicBoolean(false); + + @WeaveAllConstructors + public LoggerConfig_Instrumentation() { + // Generate the instrumentation module supportability metric only once + if (!instrumented.getAndSet(true)) { + NewRelic.incrementCounter("Supportability/Logging/Java/Log4j2/enabled"); + } + } + + protected void callAppenders(LogEvent event) { + // Do nothing if application_logging.enabled: false + if (isApplicationLoggingEnabled()) { + // Do nothing if logger has parents and isAdditive is set to true to avoid duplicated counters and logs + if (getParent() == null || !isAdditive()) { + if (isApplicationLoggingMetricsEnabled()) { + // Generate log level metrics + NewRelic.incrementCounter("Logging/lines"); + NewRelic.incrementCounter("Logging/lines/" + event.getLevel().toString()); + } + + if (isApplicationLoggingForwardingEnabled()) { + // Record and send LogEvent to New Relic + recordNewRelicLogEvent(event); + } + } + } + Weaver.callOriginal(); + } + + public LoggerConfig getParent() { + return Weaver.callOriginal(); + } + + public boolean isAdditive() { + return Weaver.callOriginal(); + } + +} diff --git a/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java b/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java new file mode 100644 index 0000000000..dc2cc47bf2 --- /dev/null +++ b/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java @@ -0,0 +1,57 @@ +/* + * + * * Copyright 2023 New Relic Corporation. All rights reserved. + * * SPDX-License-Identifier: Apache-2.0 + * + */ + +package org.apache.logging.log4j.core.layout; + +import com.newrelic.api.agent.weaver.MatchType; +import com.newrelic.api.agent.weaver.Weave; +import com.newrelic.api.agent.weaver.Weaver; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.util.StringBuilderWriter; + +import java.io.IOException; +import java.io.Writer; + +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.BLOB_PREFIX; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.getLinkingMetadataBlob; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingEnabled; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingLocalDecoratingEnabled; +import static com.nr.agent.instrumentation.log4j2.AgentUtil.foundIndexToInsertLinkingMetadata; +import static com.nr.agent.instrumentation.log4j2.AgentUtil.getIndexToModifyJson; + +@Weave(originalName = "org.apache.logging.log4j.core.layout.AbstractJacksonLayout", type = MatchType.ExactClass) +abstract class AbstractJacksonLayout_Instrumentation { + + public abstract void toSerializable(final LogEvent event, final Writer writer) throws IOException; + + public String toSerializable(final LogEvent event) { + final StringBuilderWriter writer = new StringBuilderWriter(); + try { + toSerializable(event, writer); + String writerString = writer.toString(); + String modified = writerString; + + // Append linking metadata to the log message if local decorating is enabled + if (isApplicationLoggingEnabled() && isApplicationLoggingLocalDecoratingEnabled()) { + // It is possible that the log might already have NR-LINKING metadata from JUL instrumentation + if (!writerString.contains(BLOB_PREFIX)) { + int indexToModifyJson = getIndexToModifyJson(writerString); + if (foundIndexToInsertLinkingMetadata(indexToModifyJson)) { + // Replace the JSON string with modified version that includes NR-LINKING metadata + modified = new StringBuilder(writerString).insert(indexToModifyJson, getLinkingMetadataBlob()).toString(); + } + } + return modified; + } + + return writerString; + } catch (final IOException e) { + return Weaver.callOriginal(); + } + } + +} diff --git a/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java b/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java new file mode 100644 index 0000000000..ef3469d0d7 --- /dev/null +++ b/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java @@ -0,0 +1,45 @@ +/* + * + * * Copyright 2022 New Relic Corporation. All rights reserved. + * * SPDX-License-Identifier: Apache-2.0 + * + */ + +package org.apache.logging.log4j.core.layout; + +import com.newrelic.api.agent.weaver.MatchType; +import com.newrelic.api.agent.weaver.Weave; +import com.newrelic.api.agent.weaver.Weaver; + +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.BLOB_PREFIX; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.getLinkingMetadataBlob; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingEnabled; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingLocalDecoratingEnabled; + +@Weave(originalName = "org.apache.logging.log4j.core.layout.StringBuilderEncoder", type = MatchType.BaseClass) +public class StringBuilderEncoder_Instrumentation { + + public void encode(final StringBuilder source, final ByteBufferDestination destination) { + // Do nothing if application_logging.enabled: false + if (isApplicationLoggingEnabled()) { + if (isApplicationLoggingLocalDecoratingEnabled()) { + // Append New Relic linking metadata from agent to log message + appendAgentMetadata(source); + } + } + Weaver.callOriginal(); + } + + private void appendAgentMetadata(StringBuilder source) { + String sourceString = source.toString(); + // It is possible that the log might already have NR-LINKING metadata from JUL instrumentation + if (!sourceString.contains(BLOB_PREFIX)) { + int breakLine = sourceString.lastIndexOf("\n"); + if (breakLine != -1) { + source.replace(breakLine, breakLine + 1, ""); + } + source.append(getLinkingMetadataBlob()).append("\n"); + } + } + +} diff --git a/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/time/Instant.java b/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/time/Instant.java new file mode 100644 index 0000000000..067802fae0 --- /dev/null +++ b/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/time/Instant.java @@ -0,0 +1,7 @@ +package org.apache.logging.log4j.core.time; + +import com.newrelic.api.agent.weaver.SkipIfPresent; + +@SkipIfPresent(originalName = "org.apache.logging.log4j.core.time.Instant") +public abstract class Instant { +} diff --git a/instrumentation/apache-log4j-2.6/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java b/instrumentation/apache-log4j-2.6/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java new file mode 100644 index 0000000000..c6643259de --- /dev/null +++ b/instrumentation/apache-log4j-2.6/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java @@ -0,0 +1,63 @@ +/* + * + * * Copyright 2022 New Relic Corporation. All rights reserved. + * * SPDX-License-Identifier: Apache-2.0 + * + */ +package com.nr.agent.instrumentation.log4j2; + +import com.newrelic.agent.introspec.InstrumentationTestConfig; +import com.newrelic.agent.introspec.InstrumentationTestRunner; +import com.newrelic.agent.introspec.Introspector; +import com.newrelic.agent.model.LogEvent; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.ThreadContext; +import org.apache.logging.log4j.core.config.Configurator; +import org.junit.Before; +import org.junit.Test; +import org.junit.runner.RunWith; + +import java.util.Collection; +import java.util.Map; + +import static org.junit.Assert.*; + +@RunWith(InstrumentationTestRunner.class) +@InstrumentationTestConfig(includePrefixes = { "org.apache.logging.log4j.core" }, configName = "application_logging_context_data_enabled.yml") +public class ContextDataTest { + + private final Introspector introspector = InstrumentationTestRunner.getIntrospector(); + + @Before + public void reset() { + introspector.clearLogEvents(); + } + + @Test + public void testAttributes() { + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + String attrKey1 = "key"; + String attrKey2 = "anotherKey"; + String val1 = "42"; + String val2 = "panic"; + + ThreadContext.put(attrKey1, val1); + ThreadContext.put(attrKey2, val2); + logger.error("message"); + + Collection logEvents = introspector.getLogEvents(); + assertEquals(1, logEvents.size()); + + LogEvent logEvent = logEvents.iterator().next(); + Map attributes = logEvent.getUserAttributesCopy(); + long contextAttrCount = attributes.keySet().stream() + .filter(key -> key.startsWith("context.")) + .count(); + // MDC data is filtered later in the process + assertEquals(2L, contextAttrCount); + assertEquals(val1, attributes.get("context." + attrKey1)); + assertEquals(val2, attributes.get("context." + attrKey2)); + } + +} diff --git a/instrumentation/apache-log4j-2.6/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java b/instrumentation/apache-log4j-2.6/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java new file mode 100644 index 0000000000..85545ba746 --- /dev/null +++ b/instrumentation/apache-log4j-2.6/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java @@ -0,0 +1,61 @@ +package com.nr.agent.instrumentation.log4j2; + +import org.junit.Test; + +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertFalse; +import static org.junit.Assert.assertNull; +import static org.junit.Assert.assertTrue; + +public class ExceptionUtilTest { + + @Test + public void testIsThrowableNull() { + Throwable nullThrowable = null; + Throwable nonNullThrowable = new Throwable("Hi"); + + assertTrue(ExceptionUtil.isThrowableNull(nullThrowable)); + assertFalse(ExceptionUtil.isThrowableNull(nonNullThrowable)); + } + + @Test + public void testGetErrorStack() { + int maxStackSize = 3; + StackTraceElement stackTraceElement1 = new StackTraceElement("Class1", "method1", "File1", 1); + StackTraceElement stackTraceElement2 = new StackTraceElement("Class2", "method2", "File2", 2); + StackTraceElement stackTraceElement3 = new StackTraceElement("Class3", "method3", "File3", 3); + StackTraceElement stackTraceElement4 = new StackTraceElement("Class4", "method4", "File4", 4); + StackTraceElement stackTraceElement5 = new StackTraceElement("Class5", "method5", "File5", 5); + StackTraceElement[] stack = new StackTraceElement[] { stackTraceElement1, stackTraceElement2, stackTraceElement3, stackTraceElement4, + stackTraceElement5 }; + String errorStack = ExceptionUtil.getErrorStack(stack, maxStackSize); + + // Processed stack should be limited to only the first three lines + assertTrue(errorStack.contains(stackTraceElement1.toString())); + assertTrue(errorStack.contains(stackTraceElement2.toString())); + assertTrue(errorStack.contains(stackTraceElement3.toString())); + // Processed stack should omit the last two lines + assertFalse(errorStack.contains(stackTraceElement4.toString())); + assertFalse(errorStack.contains(stackTraceElement5.toString())); + } + + @Test + public void testGetErrorMessage() { + String expectedMessage = "Hi"; + Throwable nullThrowable = null; + Throwable nonNullThrowable = new Throwable(expectedMessage); + + assertNull(ExceptionUtil.getErrorMessage(nullThrowable)); + assertEquals(expectedMessage, ExceptionUtil.getErrorMessage(nonNullThrowable)); + } + + @Test + public void testGetErrorClass() { + String expectedExceptionClass = "java.lang.RuntimeException"; + Throwable nullThrowable = null; + RuntimeException runtimeException = new RuntimeException("Hi"); + + assertNull(ExceptionUtil.getErrorClass(nullThrowable)); + assertEquals(expectedExceptionClass, ExceptionUtil.getErrorClass(runtimeException)); + } +} diff --git a/instrumentation/apache-log4j-2.6/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java b/instrumentation/apache-log4j-2.6/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java new file mode 100644 index 0000000000..5198ef3150 --- /dev/null +++ b/instrumentation/apache-log4j-2.6/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java @@ -0,0 +1,626 @@ +package com.nr.agent.instrumentation.log4j2; + +import com.newrelic.agent.introspec.InstrumentationTestConfig; +import com.newrelic.agent.introspec.InstrumentationTestRunner; +import com.newrelic.agent.introspec.Introspector; +import com.newrelic.agent.introspec.MetricsHelper; +import com.newrelic.agent.model.LogEvent; +import junit.framework.TestCase; +import org.apache.logging.log4j.Level; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.ThreadContext; +import org.apache.logging.log4j.core.Appender; +import org.apache.logging.log4j.core.Layout; +import org.apache.logging.log4j.core.LoggerContext; +import org.apache.logging.log4j.core.appender.ConsoleAppender; +import org.apache.logging.log4j.core.config.AppenderRef; +import org.apache.logging.log4j.core.config.Configuration; +import org.apache.logging.log4j.core.config.Configurator; +import org.apache.logging.log4j.core.config.LoggerConfig; +import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilder; +import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilderFactory; +import org.apache.logging.log4j.core.config.builder.impl.BuiltConfiguration; +import org.apache.logging.log4j.core.impl.Log4jContextFactory; +import org.apache.logging.log4j.core.layout.PatternLayout; +import org.apache.logging.log4j.spi.LoggerContextFactory; +import org.junit.Assert; +import org.junit.Before; +import org.junit.Test; +import org.junit.runner.RunWith; + +import java.util.Collection; +import java.util.List; +import java.util.Map; +import java.util.stream.Collectors; + +@RunWith(InstrumentationTestRunner.class) +@InstrumentationTestConfig(includePrefixes = { "org.apache.logging.log4j.core" }, configName = "application_logging_enabled.yml") +public class LoggerConfig_InstrumentationTest extends TestCase { + + private static final String CAPTURED = "This log message should be captured"; + private static final String NOT_CAPTURED = "This message should NOT be captured"; + private final Introspector introspector = InstrumentationTestRunner.getIntrospector(); + + @Before + public void reset() { + introspector.clearLogEvents(); + } + + @Test + public void testLogEventsAllLevel() { + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + // Log at ALL level + setLoggerLevel(Level.ALL); + + int expectedTotalEventsCapturedAtFatal = 1; + logger.fatal(CAPTURED); + + int expectedTotalEventsCapturedAtError = 2; + logger.error(CAPTURED); + logger.error(CAPTURED); + + int expectedTotalEventsCapturedAtWarn = 3; + logger.warn(CAPTURED); + logger.warn(CAPTURED); + logger.warn(CAPTURED); + + int expectedTotalEventsCapturedAtInfo = 4; + logger.info(CAPTURED); + logger.info(CAPTURED); + logger.info(CAPTURED); + logger.info(CAPTURED); + + int expectedTotalEventsCapturedAtDebug = 5; + logger.debug(CAPTURED); + logger.debug(CAPTURED); + logger.debug(CAPTURED); + logger.debug(CAPTURED); + logger.debug(CAPTURED); + + int expectedTotalEventsCapturedAtTrace = 6; + logger.trace(CAPTURED); + logger.trace(CAPTURED); + logger.trace(CAPTURED); + logger.trace(CAPTURED); + logger.trace(CAPTURED); + logger.trace(CAPTURED); + + int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + + expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + + expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + + expectedTotalEventsCapturedAtTrace; + + Collection logEvents = introspector.getLogEvents(); + + assertEquals(expectedTotalEventsCaptured, logEvents.size()); + + List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); + List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); + List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); + List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); + List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); + List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); + + assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); + } + + @Test + public void testLogEventsOffLevel() { + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + // Logging is OFF at all levels + setLoggerLevel(Level.OFF); + + int expectedTotalEventsCapturedAtFatal = 0; + logger.fatal(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtError = 0; + logger.error(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtWarn = 0; + logger.warn(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtInfo = 0; + logger.info(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtDebug = 0; + logger.debug(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtTrace = 0; + logger.trace(NOT_CAPTURED); + + int expectedTotalEventsCaptured = 0; + + Collection logEvents = introspector.getLogEvents(); + + assertEquals(expectedTotalEventsCaptured, logEvents.size()); + + List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); + List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); + List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); + List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); + List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); + List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); + + assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); + } + + @Test + public void testLogEventsFatalLevel() { + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + // Log at FATAL level + setLoggerLevel(Level.FATAL); + + int expectedTotalEventsCapturedAtFatal = 1; + logger.fatal(CAPTURED); + + int expectedTotalEventsCapturedAtError = 0; + logger.error(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtWarn = 0; + logger.warn(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtInfo = 0; + logger.info(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtDebug = 0; + logger.debug(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtTrace = 0; + logger.trace(NOT_CAPTURED); + + int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + + expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + + expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + + expectedTotalEventsCapturedAtTrace; + + Collection logEvents = introspector.getLogEvents(); + + assertEquals(expectedTotalEventsCaptured, logEvents.size()); + + List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); + List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); + List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); + List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); + List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); + List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); + + assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); + } + + @Test + public void testLogEventsErrorLevel() { + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + // Log at ERROR level + setLoggerLevel(Level.ERROR); + + int expectedTotalEventsCapturedAtFatal = 1; + logger.fatal(CAPTURED); + + int expectedTotalEventsCapturedAtError = 1; + logger.error(CAPTURED); + + int expectedTotalEventsCapturedAtWarn = 0; + logger.warn(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtInfo = 0; + logger.info(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtDebug = 0; + logger.debug(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtTrace = 0; + logger.trace(NOT_CAPTURED); + + int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + + expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + + expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + + expectedTotalEventsCapturedAtTrace; + + Collection logEvents = introspector.getLogEvents(); + + assertEquals(expectedTotalEventsCaptured, logEvents.size()); + + List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); + List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); + List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); + List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); + List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); + List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); + + assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); + } + + @Test + public void testLogEventsWarnLevel() { + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + // Log at WARN level + setLoggerLevel(Level.WARN); + + int expectedTotalEventsCapturedAtFatal = 1; + logger.fatal(CAPTURED); + + int expectedTotalEventsCapturedAtError = 1; + logger.error(CAPTURED); + + int expectedTotalEventsCapturedAtWarn = 1; + logger.warn(CAPTURED); + + int expectedTotalEventsCapturedAtInfo = 0; + logger.info(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtDebug = 0; + logger.debug(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtTrace = 0; + logger.trace(NOT_CAPTURED); + + int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + + expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + + expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + + expectedTotalEventsCapturedAtTrace; + + Collection logEvents = introspector.getLogEvents(); + + assertEquals(expectedTotalEventsCaptured, logEvents.size()); + + List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); + List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); + List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); + List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); + List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); + List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); + + assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); + } + + @Test + public void testLogEventsInfoLevel() { + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + // Log at INFO level + setLoggerLevel(Level.INFO); + + int expectedTotalEventsCapturedAtFatal = 1; + logger.fatal(CAPTURED); + + int expectedTotalEventsCapturedAtError = 1; + logger.error(CAPTURED); + + int expectedTotalEventsCapturedAtWarn = 1; + logger.warn(CAPTURED); + + int expectedTotalEventsCapturedAtInfo = 1; + logger.info(CAPTURED); + + int expectedTotalEventsCapturedAtDebug = 0; + logger.debug(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtTrace = 0; + logger.trace(NOT_CAPTURED); + + int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + + expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + + expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + + expectedTotalEventsCapturedAtTrace; + + Collection logEvents = introspector.getLogEvents(); + + assertEquals(expectedTotalEventsCaptured, logEvents.size()); + + List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); + List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); + List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); + List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); + List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); + List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); + + assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); + } + + @Test + public void testLogEventsDebugLevel() { + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + // Log at DEBUG level + setLoggerLevel(Level.DEBUG); + + int expectedTotalEventsCapturedAtFatal = 1; + logger.fatal(CAPTURED); + + int expectedTotalEventsCapturedAtError = 1; + logger.error(CAPTURED); + + int expectedTotalEventsCapturedAtWarn = 1; + logger.warn(CAPTURED); + + int expectedTotalEventsCapturedAtInfo = 1; + logger.info(CAPTURED); + + int expectedTotalEventsCapturedAtDebug = 1; + logger.debug(CAPTURED); + + int expectedTotalEventsCapturedAtTrace = 0; + logger.trace(NOT_CAPTURED); + + int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + + expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + + expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + + expectedTotalEventsCapturedAtTrace; + + Collection logEvents = introspector.getLogEvents(); + + assertEquals(expectedTotalEventsCaptured, logEvents.size()); + + List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); + List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); + List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); + List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); + List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); + List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); + + assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); + } + + @Test + public void testLogEventsTraceLevel() { + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + // Log at TRACE level + setLoggerLevel(Level.TRACE); + + int expectedTotalEventsCapturedAtFatal = 1; + logger.fatal(CAPTURED); + + int expectedTotalEventsCapturedAtError = 1; + logger.error(CAPTURED); + + int expectedTotalEventsCapturedAtWarn = 1; + logger.warn(CAPTURED); + + int expectedTotalEventsCapturedAtInfo = 1; + logger.info(CAPTURED); + + int expectedTotalEventsCapturedAtDebug = 1; + logger.debug(CAPTURED); + + int expectedTotalEventsCapturedAtTrace = 1; + logger.trace(CAPTURED); + + int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + + expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + + expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + + expectedTotalEventsCapturedAtTrace; + + Collection logEvents = introspector.getLogEvents(); + + assertEquals(expectedTotalEventsCaptured, logEvents.size()); + + List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); + List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); + List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); + List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); + List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); + List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); + + assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); + } + + private List getTraceLevelLogEvents(Collection logEvents) { + return logEvents.stream() + .filter(logEvent -> logEvent.getUserAttributesCopy().containsValue(Level.TRACE.toString())) + .collect(Collectors.toList()); + } + + private List getDebugLevelLogEvents(Collection logEvents) { + return logEvents.stream() + .filter(logEvent -> logEvent.getUserAttributesCopy().containsValue(Level.DEBUG.toString())) + .collect(Collectors.toList()); + } + + private List getInfoLevelLogEvents(Collection logEvents) { + return logEvents.stream() + .filter(logEvent -> logEvent.getUserAttributesCopy().containsValue(Level.INFO.toString())) + .collect(Collectors.toList()); + } + + private List getWarnLevelLogEvents(Collection logEvents) { + return logEvents.stream() + .filter(logEvent -> logEvent.getUserAttributesCopy().containsValue(Level.WARN.toString())) + .collect(Collectors.toList()); + } + + private List getErrorLevelLogEvents(Collection logEvents) { + return logEvents.stream() + .filter(logEvent -> logEvent.getUserAttributesCopy().containsValue(Level.ERROR.toString())) + .collect(Collectors.toList()); + } + + private List getFatalLevelLogEvents(Collection logEvents) { + return logEvents.stream() + .filter(logEvent -> logEvent.getUserAttributesCopy().containsValue(Level.FATAL.toString())) + .collect(Collectors.toList()); + } + + @Test + public void shouldIncrementEmittedLogsCountersIndependentlyIfLogLevelEnabled() { + // Given + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + setLoggerLevel(Level.INFO); + + // When + logger.trace(NOT_CAPTURED); + logger.debug(NOT_CAPTURED); + logger.info(CAPTURED); + logger.info(CAPTURED); + logger.info(CAPTURED); + logger.warn(CAPTURED); + logger.warn(CAPTURED); + logger.warn(CAPTURED); + logger.warn(CAPTURED); + logger.error(CAPTURED); + + // Then + Assert.assertEquals(8, MetricsHelper.getUnscopedMetricCount("Logging/lines")); + Assert.assertEquals(0, MetricsHelper.getUnscopedMetricCount("Logging/lines/TRACE")); + Assert.assertEquals(0, MetricsHelper.getUnscopedMetricCount("Logging/lines/DEBUG")); + Assert.assertEquals(3, MetricsHelper.getUnscopedMetricCount("Logging/lines/INFO")); + Assert.assertEquals(4, MetricsHelper.getUnscopedMetricCount("Logging/lines/WARN")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/ERROR")); + } + + @Test + public void shouldIncrementAllEmittedLogCountersIfLogLevelIsSetToTrace() { + // Given + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + setLoggerLevel(Level.TRACE); + + // When + logger.trace(CAPTURED); + logger.debug(CAPTURED); + logger.info(CAPTURED); + logger.warn(CAPTURED); + logger.error(CAPTURED); + + // Then + Assert.assertEquals(5, MetricsHelper.getUnscopedMetricCount("Logging/lines")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/TRACE")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/DEBUG")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/INFO")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/WARN")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/ERROR")); + } + + @Test + public void shouldIncrementAllEmittedLogCountersOnlyOnceWhenMultipleLoggersAreSet() { + // Given + createLogger("A_SPECIAL_LOGGER", createAppender("ConsoleAppender"), Level.TRACE, true); + final Logger logger = LogManager.getLogger("A_SPECIAL_LOGGER"); + setLoggerLevel(Level.TRACE); + + // When + logger.trace(CAPTURED); + logger.debug(CAPTURED); + logger.info(CAPTURED); + logger.warn(CAPTURED); + logger.error(CAPTURED); + + // Then + Assert.assertEquals(5, MetricsHelper.getUnscopedMetricCount("Logging/lines")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/TRACE")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/DEBUG")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/INFO")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/WARN")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/ERROR")); + } + + @Test + public void shouldIncrementAllEmittedLogCountersRespectingLevelFromOriginalLogger() { + // Given + createLogger("A_SPECIAL_LOGGER", createAppender("ConsoleAppender"), Level.INFO, true); + final Logger logger = LogManager.getLogger("A_SPECIAL_LOGGER"); + setLoggerLevel(Level.ERROR); + + // When + logger.trace(NOT_CAPTURED); + logger.debug(NOT_CAPTURED); + logger.info(CAPTURED); + logger.warn(CAPTURED); + logger.error(CAPTURED); + + // Then + Assert.assertEquals(3, MetricsHelper.getUnscopedMetricCount("Logging/lines")); + Assert.assertEquals(0, MetricsHelper.getUnscopedMetricCount("Logging/lines/TRACE")); + Assert.assertEquals(0, MetricsHelper.getUnscopedMetricCount("Logging/lines/DEBUG")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/INFO")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/WARN")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/ERROR")); + } + + private void createLogger(String name, Appender appender, Level level, boolean additivity) { + final LoggerContext ctx = (LoggerContext) LogManager.getContext(false); + final Configuration config = ctx.getConfiguration(); + AppenderRef ref = AppenderRef.createAppenderRef("File", null, null); + AppenderRef[] refs = new AppenderRef[] { ref }; + LoggerConfig loggerConfig = LoggerConfig.createLogger(additivity, level, name, "true", refs, null, config, null); + loggerConfig.addAppender(appender, level, null); + config.addLogger(name, loggerConfig); + } + + private Appender createAppender(String name) { + Layout layout = PatternLayout.newBuilder() + .withPattern(PatternLayout.SIMPLE_CONVERSION_PATTERN) + .build(); + Appender appender = ConsoleAppender.newBuilder() + .withName(name) + .withLayout(layout) + .build(); + appender.start(); + return appender; + } + + private void setLoggerLevel(Level level) { + final LoggerContext context = (LoggerContext) LogManager.getContext(false); + final Configuration configuration = context.getConfiguration(); + final LoggerConfig rootConfig = configuration.getLoggerConfig(LogManager.ROOT_LOGGER_NAME); + rootConfig.setLevel(level); + context.updateLoggers(); + } + + @Test + public void contextDataDisabledTest() { + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + ThreadContext.put("include", "42"); + ThreadContext.put("exclude", "panic"); + + logger.error("message"); + + Collection logEvents = introspector.getLogEvents(); + assertEquals(1, logEvents.size()); + + // verify no context attrs + Map attributes = logEvents.iterator().next().getUserAttributesCopy(); + long contextAttrCount = attributes.keySet().stream() + .filter(key -> key.startsWith("context.")) + .count(); + assertEquals(0L, contextAttrCount); + } + +} diff --git a/instrumentation/apache-log4j-2.6/src/test/resources/application_logging_context_data_enabled.yml b/instrumentation/apache-log4j-2.6/src/test/resources/application_logging_context_data_enabled.yml new file mode 100644 index 0000000000..1212edc2e9 --- /dev/null +++ b/instrumentation/apache-log4j-2.6/src/test/resources/application_logging_context_data_enabled.yml @@ -0,0 +1,12 @@ +common: &default_settings + application_logging: + enabled: true + forwarding: + enabled: true + max_samples_stored: 10000 + context_data: + enabled: true + metrics: + enabled: true + local_decorating: + enabled: false diff --git a/instrumentation/apache-log4j-2.6/src/test/resources/application_logging_enabled.yml b/instrumentation/apache-log4j-2.6/src/test/resources/application_logging_enabled.yml new file mode 100644 index 0000000000..583ffd2bba --- /dev/null +++ b/instrumentation/apache-log4j-2.6/src/test/resources/application_logging_enabled.yml @@ -0,0 +1,10 @@ +common: &default_settings + application_logging: + enabled: true + forwarding: + enabled: true + max_samples_stored: 10000 + metrics: + enabled: true + local_decorating: + enabled: false diff --git a/instrumentation/apache-log4j-2/build.gradle b/instrumentation/apache-log4j-2/build.gradle index 2083af1595..c9ae274c15 100644 --- a/instrumentation/apache-log4j-2/build.gradle +++ b/instrumentation/apache-log4j-2/build.gradle @@ -8,7 +8,7 @@ dependencies { } verifyInstrumentation { - passesOnly("org.apache.logging.log4j:log4j-core:[2.6,3.0.0-alpha1)") + passesOnly("org.apache.logging.log4j:log4j-core:[2.11.0,3.0.0-alpha1)") } site { diff --git a/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java b/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java index 8b8ffdcef3..d288e4efec 100644 --- a/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java +++ b/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java @@ -14,6 +14,7 @@ import org.apache.logging.log4j.Level; import org.apache.logging.log4j.core.LogEvent; import org.apache.logging.log4j.message.Message; +import org.apache.logging.log4j.util.ReadOnlyStringMap; import java.util.HashMap; import java.util.Map; @@ -44,7 +45,7 @@ public static void recordNewRelicLogEvent(LogEvent event) { Throwable throwable = event.getThrown(); if (shouldCreateLogEvent(message, throwable)) { - Map contextData = event.getContextMap(); + ReadOnlyStringMap contextData = event.getContextData(); Map logEventMap = new HashMap<>(calculateInitialMapSize(contextData)); logEventMap.put(INSTRUMENTATION, "apache-log4j-2"); if (message != null) { @@ -56,7 +57,7 @@ public static void recordNewRelicLogEvent(LogEvent event) { logEventMap.put(TIMESTAMP, event.getTimeMillis()); if (AppLoggingUtils.isAppLoggingContextDataEnabled() && contextData != null) { - for (Map.Entry entry : contextData.entrySet()) { + for (Map.Entry entry : contextData.toMap().entrySet()) { String key = entry.getKey(); String value = entry.getValue(); LogAttributeKey logAttrKey = new LogAttributeKey(key, LogAttributeType.CONTEXT); @@ -122,7 +123,7 @@ private static boolean shouldCreateLogEvent(Message message, Throwable throwable return (message != null) || !ExceptionUtil.isThrowableNull(throwable); } - private static int calculateInitialMapSize(Map mdcPropertyMap) { + private static int calculateInitialMapSize(ReadOnlyStringMap mdcPropertyMap) { return AppLoggingUtils.isAppLoggingContextDataEnabled() && mdcPropertyMap != null ? mdcPropertyMap.size() + DEFAULT_NUM_OF_LOG_EVENT_ATTRIBUTES : DEFAULT_NUM_OF_LOG_EVENT_ATTRIBUTES; diff --git a/settings.gradle b/settings.gradle index b221ac20f7..6a211fffe5 100644 --- a/settings.gradle +++ b/settings.gradle @@ -86,6 +86,7 @@ include 'instrumentation:akka-http-core-2.13_10.2.0' include 'instrumentation:akka-http-core-10.0' include 'instrumentation:akka-http-core-10.2.0' include 'instrumentation:apache-log4j-1' +include 'instrumentation:apache-log4j-2.6' include 'instrumentation:apache-log4j-2' include 'instrumentation:apache-struts-2.0' include 'instrumentation:async-http-client-2.0.0' From e2af13d1e3087848de6b0038886557f88357677e Mon Sep 17 00:00:00 2001 From: jasonjkeller Date: Fri, 20 Oct 2023 16:12:36 -0700 Subject: [PATCH 02/14] Cleanup and fix test --- .../log4j/core/LogEvent_Instrumentation.java | 77 ------------------- .../LoggerConfig_InstrumentationTest.java | 6 +- instrumentation/apache-log4j-2/build.gradle | 3 +- 3 files changed, 3 insertions(+), 83 deletions(-) delete mode 100644 instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/LogEvent_Instrumentation.java diff --git a/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/LogEvent_Instrumentation.java b/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/LogEvent_Instrumentation.java deleted file mode 100644 index 1c7d34a44a..0000000000 --- a/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/LogEvent_Instrumentation.java +++ /dev/null @@ -1,77 +0,0 @@ -///* -// * -// * * Copyright 2023 New Relic Corporation. All rights reserved. -// * * SPDX-License-Identifier: Apache-2.0 -// * -// */ -// -//package org.apache.logging.log4j.core; -// -//import com.newrelic.api.agent.NewRelic; -//import com.newrelic.api.agent.weaver.MatchType; -//import com.newrelic.api.agent.weaver.NewField; -//import com.newrelic.api.agent.weaver.Weave; -//import org.apache.logging.log4j.Level; -//import org.apache.logging.log4j.Marker; -//import org.apache.logging.log4j.ThreadContext; -//import org.apache.logging.log4j.core.impl.ThrowableProxy; -//import org.apache.logging.log4j.message.Message; -//import org.apache.logging.log4j.util.ReadOnlyStringMap; -// -//import java.util.Map; -// -//import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingLocalDecoratingEnabled; -// -//@Weave(originalName = "org.apache.logging.log4j.core.LogEvent", type = MatchType.Interface) -//public abstract class LogEvent_Instrumentation { -// -// /* -// * In cases where the LogEvent is sent to an AsyncAppender, getLinkingMetadata would get called on a new thread and the trace.id and span.id -// * would be missing. To work around this we save the linking metadata on the LogEvent on the thread where it was created and use it later. -// */ -// @NewField -// public Map agentLinkingMetadata = isApplicationLoggingLocalDecoratingEnabled() ? NewRelic.getAgent().getLinkingMetadata() : null; -// -// public abstract LogEvent toImmutable(); -// -// @Deprecated -// public abstract Map getContextMap(); -// -// public abstract ReadOnlyStringMap getContextData(); -// -// public abstract ThreadContext.ContextStack getContextStack(); -// -// public abstract String getLoggerFqcn(); -// -// public abstract Level getLevel(); -// -// public abstract String getLoggerName(); -// -// public abstract Marker getMarker(); -// -// public abstract Message getMessage(); -// -// public abstract long getTimeMillis(); -// -// public abstract StackTraceElement getSource(); -// -// public abstract String getThreadName(); -// -// public abstract long getThreadId(); -// -// public abstract int getThreadPriority(); -// -// public abstract Throwable getThrown(); -// -// public abstract ThrowableProxy getThrownProxy(); -// -// public abstract boolean isEndOfBatch(); -// -// public abstract boolean isIncludeLocation(); -// -// public abstract void setEndOfBatch(boolean endOfBatch); -// -// public abstract void setIncludeLocation(boolean locationRequired); -// -// public abstract long getNanoTime(); -//} diff --git a/instrumentation/apache-log4j-2.6/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java b/instrumentation/apache-log4j-2.6/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java index 5198ef3150..608571e764 100644 --- a/instrumentation/apache-log4j-2.6/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java +++ b/instrumentation/apache-log4j-2.6/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java @@ -18,12 +18,7 @@ import org.apache.logging.log4j.core.config.Configuration; import org.apache.logging.log4j.core.config.Configurator; import org.apache.logging.log4j.core.config.LoggerConfig; -import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilder; -import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilderFactory; -import org.apache.logging.log4j.core.config.builder.impl.BuiltConfiguration; -import org.apache.logging.log4j.core.impl.Log4jContextFactory; import org.apache.logging.log4j.core.layout.PatternLayout; -import org.apache.logging.log4j.spi.LoggerContextFactory; import org.junit.Assert; import org.junit.Before; import org.junit.Test; @@ -582,6 +577,7 @@ private void createLogger(String name, Appender appender, Level level, boolean a LoggerConfig loggerConfig = LoggerConfig.createLogger(additivity, level, name, "true", refs, null, config, null); loggerConfig.addAppender(appender, level, null); config.addLogger(name, loggerConfig); + Configurator.setLevel(name, level); } private Appender createAppender(String name) { diff --git a/instrumentation/apache-log4j-2/build.gradle b/instrumentation/apache-log4j-2/build.gradle index c9ae274c15..1ead670f8d 100644 --- a/instrumentation/apache-log4j-2/build.gradle +++ b/instrumentation/apache-log4j-2/build.gradle @@ -8,7 +8,8 @@ dependencies { } verifyInstrumentation { - passesOnly("org.apache.logging.log4j:log4j-core:[2.11.0,3.0.0-alpha1)") + passesOnly("org.apache.logging.log4j:log4j-core:[2.11.0,)") + excludeRegex '.*(alpha|beta|rc).*' } site { From 924efffc90221e43dbbe0aa332ae3d0b537eb61f Mon Sep 17 00:00:00 2001 From: jasonjkeller Date: Fri, 1 Sep 2023 15:40:32 -0700 Subject: [PATCH 03/14] Prototype two potential approaches to support adding linking metadata to Log4j2 JsonLayout --- ...AbstractJacksonLayout_Instrumentation.java | 45 +++++++++++++++++++ .../AbstractStringLayout_Instrumentation.java | 44 ++++++++++++++++++ 2 files changed, 89 insertions(+) create mode 100644 instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java create mode 100644 instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java diff --git a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java new file mode 100644 index 0000000000..409f3a9ac5 --- /dev/null +++ b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java @@ -0,0 +1,45 @@ +/* + * + * * Copyright 2023 New Relic Corporation. All rights reserved. + * * SPDX-License-Identifier: Apache-2.0 + * + */ + +package org.apache.logging.log4j.core.layout; + +import com.newrelic.api.agent.weaver.MatchType; +import com.newrelic.api.agent.weaver.Weave; +import com.newrelic.api.agent.weaver.Weaver; + +import java.util.Map; + +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.getLinkingMetadataBlob; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingEnabled; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingLocalDecoratingEnabled; + +abstract class AbstractJacksonLayout_Instrumentation { + + @Weave(originalName = "org.apache.logging.log4j.core.layout.AbstractJacksonLayout$LogEventWithAdditionalFields", type = MatchType.ExactClass) + public static class LogEventWithAdditionalFields_Instrumentation { + + private final Object logEvent; + private final Map additionalFields; + + public LogEventWithAdditionalFields_Instrumentation(final Object logEvent, final Map additionalFields) { + // This will only ever work if at least one additional field is set in the JsonLayout, doesn't matter what it is + // + // + // + + this.logEvent = Weaver.callOriginal(); + if (isApplicationLoggingEnabled()) { + if (isApplicationLoggingLocalDecoratingEnabled()) { + // Append New Relic linking metadata from agent to log message + additionalFields.put("In NR", getLinkingMetadataBlob()); + } + } + this.additionalFields = Weaver.callOriginal(); + } + } + +} diff --git a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java new file mode 100644 index 0000000000..9d57018e47 --- /dev/null +++ b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java @@ -0,0 +1,44 @@ +/* + * + * * Copyright 2023 New Relic Corporation. All rights reserved. + * * SPDX-License-Identifier: Apache-2.0 + * + */ + +package org.apache.logging.log4j.core.layout; + +import com.newrelic.api.agent.weaver.MatchType; +import com.newrelic.api.agent.weaver.Weave; +import com.newrelic.api.agent.weaver.Weaver; +import org.apache.logging.log4j.core.util.StringEncoder; + +import java.io.UnsupportedEncodingException; +import java.nio.charset.Charset; + +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.getLinkingMetadataBlob; + +@Weave(originalName = "org.apache.logging.log4j.core.layout.AbstractStringLayout", type = MatchType.ExactClass) +public abstract class AbstractStringLayout_Instrumentation { + + private transient Charset charset = Weaver.callOriginal(); + private final String charsetName = Weaver.callOriginal(); + private final boolean useCustomEncoding = Weaver.callOriginal(); + + protected byte[] getBytes(final String s) { + String modified = s; + if (!s.contains("NR-LINKING")) { + int indexToInsertNrLinkingMetadata = s.indexOf("\n", s.indexOf("message")) - 1; + // Replace the JSON string with modified version + modified = new StringBuilder(s).insert(indexToInsertNrLinkingMetadata, getLinkingMetadataBlob()).toString(); + } + if (useCustomEncoding) { + return StringEncoder.encodeSingleByteChars(modified); + } + try { + return modified.getBytes(charsetName); + } catch (final UnsupportedEncodingException e) { + return modified.getBytes(charset); + } + } + +} From 9dde58e964c273aad9fdc0a9b94a576d57923038 Mon Sep 17 00:00:00 2001 From: jasonjkeller Date: Tue, 5 Sep 2023 11:19:23 -0700 Subject: [PATCH 04/14] Remove AbstractJacksonLayout instrumentation. Split instrumentation into two modules to support log4j 2.6-2.14 and 2.15+ --- .../apache-log4j-2.15/build.gradle | 18 + .../instrumentation/log4j2/AgentUtil.java | 131 ++++ .../instrumentation/log4j2/ExceptionUtil.java | 49 ++ .../config/LoggerConfig_Instrumentation.java | 66 ++ .../AbstractStringLayout_Instrumentation.java | 33 + .../StringBuilderEncoder_Instrumentation.java | 40 ++ .../log4j2/ContextDataTest.java | 64 ++ .../log4j2/ExceptionUtilTest.java | 61 ++ .../LoggerConfig_InstrumentationTest.java | 622 ++++++++++++++++++ ...plication_logging_context_data_enabled.yml | 12 + .../resources/application_logging_enabled.yml | 10 + instrumentation/apache-log4j-2/build.gradle | 2 +- ...AbstractJacksonLayout_Instrumentation.java | 45 -- 13 files changed, 1107 insertions(+), 46 deletions(-) create mode 100644 instrumentation/apache-log4j-2.15/build.gradle create mode 100644 instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java create mode 100644 instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java create mode 100644 instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java create mode 100644 instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java create mode 100644 instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java create mode 100644 instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java create mode 100644 instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java create mode 100644 instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java create mode 100644 instrumentation/apache-log4j-2.15/src/test/resources/application_logging_context_data_enabled.yml create mode 100644 instrumentation/apache-log4j-2.15/src/test/resources/application_logging_enabled.yml delete mode 100644 instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java diff --git a/instrumentation/apache-log4j-2.15/build.gradle b/instrumentation/apache-log4j-2.15/build.gradle new file mode 100644 index 0000000000..109a0ea164 --- /dev/null +++ b/instrumentation/apache-log4j-2.15/build.gradle @@ -0,0 +1,18 @@ +jar { + manifest { attributes 'Implementation-Title': 'com.newrelic.instrumentation.apache-log4j-2.15' } +} + +dependencies { + implementation(project(":agent-bridge")) + implementation("org.apache.logging.log4j:log4j-core:2.20.0") +} + +verifyInstrumentation { + passesOnly("org.apache.logging.log4j:log4j-core:[2.15.0,)") + excludeRegex '.*(alpha|beta|rc).*' +} + +site { + title 'Log4j2' + type 'Framework' +} diff --git a/instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java b/instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java new file mode 100644 index 0000000000..05ac051504 --- /dev/null +++ b/instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java @@ -0,0 +1,131 @@ +/* + * + * * Copyright 2022 New Relic Corporation. All rights reserved. + * * SPDX-License-Identifier: Apache-2.0 + * + */ + +package com.nr.agent.instrumentation.log4j2; + +import com.newrelic.agent.bridge.AgentBridge; +import com.newrelic.agent.bridge.logging.AppLoggingUtils; +import com.newrelic.agent.bridge.logging.LogAttributeKey; +import com.newrelic.agent.bridge.logging.LogAttributeType; +import org.apache.logging.log4j.Level; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.message.Message; +import org.apache.logging.log4j.util.ReadOnlyStringMap; + +import java.util.HashMap; +import java.util.Map; + +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.DEFAULT_NUM_OF_LOG_EVENT_ATTRIBUTES; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.ERROR_CLASS; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.ERROR_MESSAGE; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.ERROR_STACK; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.INSTRUMENTATION; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.LEVEL; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.LOGGER_FQCN; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.LOGGER_NAME; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.MESSAGE; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.THREAD_ID; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.THREAD_NAME; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.TIMESTAMP; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.UNKNOWN; + +public class AgentUtil { + /** + * Record a LogEvent to be sent to New Relic. + * + * @param event to parse + */ + public static void recordNewRelicLogEvent(LogEvent event) { + if (event != null) { + Message message = event.getMessage(); + Throwable throwable = event.getThrown(); + + if (shouldCreateLogEvent(message, throwable)) { + ReadOnlyStringMap contextData = event.getContextData(); + Map logEventMap = new HashMap<>(calculateInitialMapSize(contextData)); + logEventMap.put(INSTRUMENTATION, "apache-log4j-2.15"); + if (message != null) { + String formattedMessage = message.getFormattedMessage(); + if (formattedMessage != null && !formattedMessage.isEmpty()) { + logEventMap.put(MESSAGE, formattedMessage); + } + } + logEventMap.put(TIMESTAMP, event.getTimeMillis()); + + if (AppLoggingUtils.isAppLoggingContextDataEnabled() && contextData != null) { + for (Map.Entry entry : contextData.toMap().entrySet()) { + String key = entry.getKey(); + String value = entry.getValue(); + LogAttributeKey logAttrKey = new LogAttributeKey(key, LogAttributeType.CONTEXT); + logEventMap.put(logAttrKey, value); + } + } + + Level level = event.getLevel(); + if (level != null) { + String levelName = level.name(); + if (levelName.isEmpty()) { + logEventMap.put(LEVEL, UNKNOWN); + } else { + logEventMap.put(LEVEL, levelName); + } + } + + String errorStack = ExceptionUtil.getErrorStack(throwable); + if (errorStack != null) { + logEventMap.put(ERROR_STACK, errorStack); + } + + String errorMessage = ExceptionUtil.getErrorMessage(throwable); + if (errorMessage != null) { + logEventMap.put(ERROR_MESSAGE, errorMessage); + } + + String errorClass = ExceptionUtil.getErrorClass(throwable); + if (errorClass != null) { + logEventMap.put(ERROR_CLASS, errorClass); + } + + String threadName = event.getThreadName(); + if (threadName != null) { + logEventMap.put(THREAD_NAME, threadName); + } + + logEventMap.put(THREAD_ID, event.getThreadId()); + + String loggerName = event.getLoggerName(); + if (loggerName != null) { + logEventMap.put(LOGGER_NAME, loggerName); + } + + String loggerFqcn = event.getLoggerFqcn(); + if (loggerFqcn != null) { + logEventMap.put(LOGGER_FQCN, loggerFqcn); + } + + AgentBridge.getAgent().getLogSender().recordLogEvent(logEventMap); + } + } + } + + /** + * A LogEvent MUST NOT be reported if neither a log message nor an error is logged. If either is present report the LogEvent. + * + * @param message Message to validate + * @param throwable Throwable to validate + * @return true if a LogEvent should be created, otherwise false + */ + private static boolean shouldCreateLogEvent(Message message, Throwable throwable) { + return (message != null) || !ExceptionUtil.isThrowableNull(throwable); + } + + private static int calculateInitialMapSize(ReadOnlyStringMap mdcPropertyMap) { + return AppLoggingUtils.isAppLoggingContextDataEnabled() && mdcPropertyMap != null + ? mdcPropertyMap.size() + DEFAULT_NUM_OF_LOG_EVENT_ATTRIBUTES + : DEFAULT_NUM_OF_LOG_EVENT_ATTRIBUTES; + } +} diff --git a/instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java b/instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java new file mode 100644 index 0000000000..a0f650906a --- /dev/null +++ b/instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java @@ -0,0 +1,49 @@ +package com.nr.agent.instrumentation.log4j2; + +public class ExceptionUtil { + public static final int MAX_STACK_SIZE = 300; + + public static boolean isThrowableNull(Throwable throwable) { + return throwable == null; + } + + public static String getErrorStack(Throwable throwable) { + if (isThrowableNull(throwable)) { + return null; + } + + StackTraceElement[] stack = throwable.getStackTrace(); + return getErrorStack(stack); + } + + public static String getErrorStack(StackTraceElement[] stack) { + return getErrorStack(stack, MAX_STACK_SIZE); + } + + public static String getErrorStack(StackTraceElement[] stack, Integer maxStackSize) { + if (stack == null || stack.length == 0) { + return null; + } + + StringBuilder stackBuilder = new StringBuilder(); + int stackSizeLimit = Math.min(maxStackSize, stack.length); + for (int i = 0; i < stackSizeLimit; i++) { + stackBuilder.append(" at ").append(stack[i].toString()).append("\n"); + } + return stackBuilder.toString(); + } + + public static String getErrorMessage(Throwable throwable) { + if (isThrowableNull(throwable)) { + return null; + } + return throwable.getMessage(); + } + + public static String getErrorClass(Throwable throwable) { + if (isThrowableNull(throwable)) { + return null; + } + return throwable.getClass().getName(); + } +} diff --git a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java new file mode 100644 index 0000000000..15f9df708c --- /dev/null +++ b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java @@ -0,0 +1,66 @@ +/* + * + * * Copyright 2022 New Relic Corporation. All rights reserved. + * * SPDX-License-Identifier: Apache-2.0 + * + */ + +package org.apache.logging.log4j.core.config; + +import com.newrelic.api.agent.NewRelic; +import com.newrelic.api.agent.weaver.MatchType; +import com.newrelic.api.agent.weaver.NewField; +import com.newrelic.api.agent.weaver.Weave; +import com.newrelic.api.agent.weaver.WeaveAllConstructors; +import com.newrelic.api.agent.weaver.Weaver; +import org.apache.logging.log4j.core.LogEvent; + +import java.util.concurrent.atomic.AtomicBoolean; + +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingEnabled; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingForwardingEnabled; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingMetricsEnabled; +import static com.nr.agent.instrumentation.log4j2.AgentUtil.recordNewRelicLogEvent; + +@Weave(originalName = "org.apache.logging.log4j.core.config.LoggerConfig", type = MatchType.ExactClass) +public class LoggerConfig_Instrumentation { + @NewField + public static AtomicBoolean instrumented = new AtomicBoolean(false); + + @WeaveAllConstructors + public LoggerConfig_Instrumentation() { + // Generate the instrumentation module supportability metric only once + if (!instrumented.getAndSet(true)) { + NewRelic.incrementCounter("Supportability/Logging/Java/Log4j2/enabled"); + } + } + + protected void callAppenders(LogEvent event) { + // Do nothing if application_logging.enabled: false + if (isApplicationLoggingEnabled()) { + // Do nothing if logger has parents and isAdditive is set to true to avoid duplicated counters and logs + if (getParent() == null || !isAdditive()) { + if (isApplicationLoggingMetricsEnabled()) { + // Generate log level metrics + NewRelic.incrementCounter("Logging/lines"); + NewRelic.incrementCounter("Logging/lines/" + event.getLevel().toString()); + } + + if (isApplicationLoggingForwardingEnabled()) { + // Record and send LogEvent to New Relic + recordNewRelicLogEvent(event); + } + } + } + Weaver.callOriginal(); + } + + public LoggerConfig getParent() { + return Weaver.callOriginal(); + } + + public boolean isAdditive() { + return Weaver.callOriginal(); + } + +} diff --git a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java new file mode 100644 index 0000000000..5c5c42038a --- /dev/null +++ b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java @@ -0,0 +1,33 @@ +/* + * + * * Copyright 2023 New Relic Corporation. All rights reserved. + * * SPDX-License-Identifier: Apache-2.0 + * + */ + +package org.apache.logging.log4j.core.layout; + +import com.newrelic.api.agent.weaver.MatchType; +import com.newrelic.api.agent.weaver.Weave; +import com.newrelic.api.agent.weaver.Weaver; + +import java.nio.charset.Charset; + +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.getLinkingMetadataBlob; + +@Weave(originalName = "org.apache.logging.log4j.core.layout.AbstractStringLayout", type = MatchType.ExactClass) +public abstract class AbstractStringLayout_Instrumentation { + + private final Charset charset = Weaver.callOriginal(); + + protected byte[] getBytes(final String s) { + String modified = s; + if (!s.contains("NR-LINKING")) { + int indexToInsertNrLinkingMetadata = s.indexOf("\n", s.indexOf("message")) - 1; + // Replace the JSON string with modified version + modified = new StringBuilder(s).insert(indexToInsertNrLinkingMetadata, getLinkingMetadataBlob()).toString(); + } + return modified.getBytes(charset); + } + +} diff --git a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java new file mode 100644 index 0000000000..e09c3e19a5 --- /dev/null +++ b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java @@ -0,0 +1,40 @@ +/* + * + * * Copyright 2022 New Relic Corporation. All rights reserved. + * * SPDX-License-Identifier: Apache-2.0 + * + */ + +package org.apache.logging.log4j.core.layout; + +import com.newrelic.api.agent.weaver.MatchType; +import com.newrelic.api.agent.weaver.Weave; +import com.newrelic.api.agent.weaver.Weaver; + +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.getLinkingMetadataBlob; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingEnabled; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingLocalDecoratingEnabled; + +@Weave(originalName = "org.apache.logging.log4j.core.layout.StringBuilderEncoder", type = MatchType.BaseClass) +public class StringBuilderEncoder_Instrumentation { + + public void encode(final StringBuilder source, final ByteBufferDestination destination) { + // Do nothing if application_logging.enabled: false + if (isApplicationLoggingEnabled()) { + if (isApplicationLoggingLocalDecoratingEnabled()) { + // Append New Relic linking metadata from agent to log message + appendAgentMetadata(source); + } + } + Weaver.callOriginal(); + } + + private void appendAgentMetadata(StringBuilder source) { + int breakLine = source.toString().lastIndexOf("\n"); + if (breakLine != -1) { + source.replace(breakLine, breakLine + 1, ""); + } + source.append(getLinkingMetadataBlob()).append("\n"); + } + +} \ No newline at end of file diff --git a/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java b/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java new file mode 100644 index 0000000000..09b8893aec --- /dev/null +++ b/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java @@ -0,0 +1,64 @@ +/* + * + * * Copyright 2022 New Relic Corporation. All rights reserved. + * * SPDX-License-Identifier: Apache-2.0 + * + */ +package com.nr.agent.instrumentation.log4j2; + +import com.newrelic.agent.introspec.InstrumentationTestConfig; +import com.newrelic.agent.introspec.InstrumentationTestRunner; +import com.newrelic.agent.introspec.Introspector; +import com.newrelic.agent.model.LogEvent; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.ThreadContext; +import org.apache.logging.log4j.core.config.Configurator; +import org.junit.Before; +import org.junit.Test; +import org.junit.runner.RunWith; + +import java.util.Collection; +import java.util.Map; + +import static org.junit.Assert.*; + +@RunWith(InstrumentationTestRunner.class) +@InstrumentationTestConfig(includePrefixes = { "org.apache.logging.log4j.core" }, configName = "application_logging_context_data_enabled.yml") +public class ContextDataTest { + + private final Introspector introspector = InstrumentationTestRunner.getIntrospector(); + + @Before + public void reset() { + Configurator.reconfigure(); + introspector.clearLogEvents(); + } + + @Test + public void testAttributes() { + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + String attrKey1 = "key"; + String attrKey2 = "anotherKey"; + String val1 = "42"; + String val2 = "panic"; + + ThreadContext.put(attrKey1, val1); + ThreadContext.put(attrKey2, val2); + logger.error("message"); + + Collection logEvents = introspector.getLogEvents(); + assertEquals(1, logEvents.size()); + + LogEvent logEvent = logEvents.iterator().next(); + Map attributes = logEvent.getUserAttributesCopy(); + long contextAttrCount = attributes.keySet().stream() + .filter(key -> key.startsWith("context.")) + .count(); + // MDC data is filtered later in the process + assertEquals(2L, contextAttrCount); + assertEquals(val1, attributes.get("context." + attrKey1)); + assertEquals(val2, attributes.get("context." + attrKey2)); + } + +} diff --git a/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java b/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java new file mode 100644 index 0000000000..85545ba746 --- /dev/null +++ b/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java @@ -0,0 +1,61 @@ +package com.nr.agent.instrumentation.log4j2; + +import org.junit.Test; + +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertFalse; +import static org.junit.Assert.assertNull; +import static org.junit.Assert.assertTrue; + +public class ExceptionUtilTest { + + @Test + public void testIsThrowableNull() { + Throwable nullThrowable = null; + Throwable nonNullThrowable = new Throwable("Hi"); + + assertTrue(ExceptionUtil.isThrowableNull(nullThrowable)); + assertFalse(ExceptionUtil.isThrowableNull(nonNullThrowable)); + } + + @Test + public void testGetErrorStack() { + int maxStackSize = 3; + StackTraceElement stackTraceElement1 = new StackTraceElement("Class1", "method1", "File1", 1); + StackTraceElement stackTraceElement2 = new StackTraceElement("Class2", "method2", "File2", 2); + StackTraceElement stackTraceElement3 = new StackTraceElement("Class3", "method3", "File3", 3); + StackTraceElement stackTraceElement4 = new StackTraceElement("Class4", "method4", "File4", 4); + StackTraceElement stackTraceElement5 = new StackTraceElement("Class5", "method5", "File5", 5); + StackTraceElement[] stack = new StackTraceElement[] { stackTraceElement1, stackTraceElement2, stackTraceElement3, stackTraceElement4, + stackTraceElement5 }; + String errorStack = ExceptionUtil.getErrorStack(stack, maxStackSize); + + // Processed stack should be limited to only the first three lines + assertTrue(errorStack.contains(stackTraceElement1.toString())); + assertTrue(errorStack.contains(stackTraceElement2.toString())); + assertTrue(errorStack.contains(stackTraceElement3.toString())); + // Processed stack should omit the last two lines + assertFalse(errorStack.contains(stackTraceElement4.toString())); + assertFalse(errorStack.contains(stackTraceElement5.toString())); + } + + @Test + public void testGetErrorMessage() { + String expectedMessage = "Hi"; + Throwable nullThrowable = null; + Throwable nonNullThrowable = new Throwable(expectedMessage); + + assertNull(ExceptionUtil.getErrorMessage(nullThrowable)); + assertEquals(expectedMessage, ExceptionUtil.getErrorMessage(nonNullThrowable)); + } + + @Test + public void testGetErrorClass() { + String expectedExceptionClass = "java.lang.RuntimeException"; + Throwable nullThrowable = null; + RuntimeException runtimeException = new RuntimeException("Hi"); + + assertNull(ExceptionUtil.getErrorClass(nullThrowable)); + assertEquals(expectedExceptionClass, ExceptionUtil.getErrorClass(runtimeException)); + } +} diff --git a/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java b/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java new file mode 100644 index 0000000000..5fc7516329 --- /dev/null +++ b/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java @@ -0,0 +1,622 @@ +package com.nr.agent.instrumentation.log4j2; + +import com.newrelic.agent.introspec.InstrumentationTestConfig; +import com.newrelic.agent.introspec.InstrumentationTestRunner; +import com.newrelic.agent.introspec.Introspector; +import com.newrelic.agent.introspec.MetricsHelper; +import com.newrelic.agent.model.LogEvent; +import junit.framework.TestCase; +import org.apache.logging.log4j.Level; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.ThreadContext; +import org.apache.logging.log4j.core.Appender; +import org.apache.logging.log4j.core.Layout; +import org.apache.logging.log4j.core.LoggerContext; +import org.apache.logging.log4j.core.appender.ConsoleAppender; +import org.apache.logging.log4j.core.config.AppenderRef; +import org.apache.logging.log4j.core.config.Configuration; +import org.apache.logging.log4j.core.config.Configurator; +import org.apache.logging.log4j.core.config.LoggerConfig; +import org.apache.logging.log4j.core.layout.PatternLayout; +import org.junit.Assert; +import org.junit.Before; +import org.junit.Test; +import org.junit.runner.RunWith; + +import java.util.Collection; +import java.util.List; +import java.util.Map; +import java.util.stream.Collectors; + +@RunWith(InstrumentationTestRunner.class) +@InstrumentationTestConfig(includePrefixes = { "org.apache.logging.log4j.core" }, configName = "application_logging_enabled.yml") +public class LoggerConfig_InstrumentationTest extends TestCase { + + private static final String CAPTURED = "This log message should be captured"; + private static final String NOT_CAPTURED = "This message should NOT be captured"; + private final Introspector introspector = InstrumentationTestRunner.getIntrospector(); + + @Before + public void reset() { + Configurator.reconfigure(); + introspector.clearLogEvents(); + } + + @Test + public void testLogEventsAllLevel() { + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + // Log at ALL level + setLoggerLevel(Level.ALL); + + int expectedTotalEventsCapturedAtFatal = 1; + logger.fatal(CAPTURED); + + int expectedTotalEventsCapturedAtError = 2; + logger.error(CAPTURED); + logger.error(CAPTURED); + + int expectedTotalEventsCapturedAtWarn = 3; + logger.warn(CAPTURED); + logger.warn(CAPTURED); + logger.warn(CAPTURED); + + int expectedTotalEventsCapturedAtInfo = 4; + logger.info(CAPTURED); + logger.info(CAPTURED); + logger.info(CAPTURED); + logger.info(CAPTURED); + + int expectedTotalEventsCapturedAtDebug = 5; + logger.debug(CAPTURED); + logger.debug(CAPTURED); + logger.debug(CAPTURED); + logger.debug(CAPTURED); + logger.debug(CAPTURED); + + int expectedTotalEventsCapturedAtTrace = 6; + logger.trace(CAPTURED); + logger.trace(CAPTURED); + logger.trace(CAPTURED); + logger.trace(CAPTURED); + logger.trace(CAPTURED); + logger.trace(CAPTURED); + + int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + + expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + + expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + + expectedTotalEventsCapturedAtTrace; + + Collection logEvents = introspector.getLogEvents(); + + assertEquals(expectedTotalEventsCaptured, logEvents.size()); + + List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); + List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); + List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); + List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); + List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); + List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); + + assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); + } + + @Test + public void testLogEventsOffLevel() { + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + // Logging is OFF at all levels + setLoggerLevel(Level.OFF); + + int expectedTotalEventsCapturedAtFatal = 0; + logger.fatal(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtError = 0; + logger.error(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtWarn = 0; + logger.warn(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtInfo = 0; + logger.info(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtDebug = 0; + logger.debug(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtTrace = 0; + logger.trace(NOT_CAPTURED); + + int expectedTotalEventsCaptured = 0; + + Collection logEvents = introspector.getLogEvents(); + + assertEquals(expectedTotalEventsCaptured, logEvents.size()); + + List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); + List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); + List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); + List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); + List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); + List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); + + assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); + } + + @Test + public void testLogEventsFatalLevel() { + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + // Log at FATAL level + setLoggerLevel(Level.FATAL); + + int expectedTotalEventsCapturedAtFatal = 1; + logger.fatal(CAPTURED); + + int expectedTotalEventsCapturedAtError = 0; + logger.error(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtWarn = 0; + logger.warn(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtInfo = 0; + logger.info(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtDebug = 0; + logger.debug(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtTrace = 0; + logger.trace(NOT_CAPTURED); + + int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + + expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + + expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + + expectedTotalEventsCapturedAtTrace; + + Collection logEvents = introspector.getLogEvents(); + + assertEquals(expectedTotalEventsCaptured, logEvents.size()); + + List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); + List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); + List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); + List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); + List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); + List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); + + assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); + } + + @Test + public void testLogEventsErrorLevel() { + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + // Log at ERROR level + setLoggerLevel(Level.ERROR); + + int expectedTotalEventsCapturedAtFatal = 1; + logger.fatal(CAPTURED); + + int expectedTotalEventsCapturedAtError = 1; + logger.error(CAPTURED); + + int expectedTotalEventsCapturedAtWarn = 0; + logger.warn(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtInfo = 0; + logger.info(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtDebug = 0; + logger.debug(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtTrace = 0; + logger.trace(NOT_CAPTURED); + + int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + + expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + + expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + + expectedTotalEventsCapturedAtTrace; + + Collection logEvents = introspector.getLogEvents(); + + assertEquals(expectedTotalEventsCaptured, logEvents.size()); + + List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); + List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); + List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); + List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); + List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); + List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); + + assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); + } + + @Test + public void testLogEventsWarnLevel() { + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + // Log at WARN level + setLoggerLevel(Level.WARN); + + int expectedTotalEventsCapturedAtFatal = 1; + logger.fatal(CAPTURED); + + int expectedTotalEventsCapturedAtError = 1; + logger.error(CAPTURED); + + int expectedTotalEventsCapturedAtWarn = 1; + logger.warn(CAPTURED); + + int expectedTotalEventsCapturedAtInfo = 0; + logger.info(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtDebug = 0; + logger.debug(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtTrace = 0; + logger.trace(NOT_CAPTURED); + + int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + + expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + + expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + + expectedTotalEventsCapturedAtTrace; + + Collection logEvents = introspector.getLogEvents(); + + assertEquals(expectedTotalEventsCaptured, logEvents.size()); + + List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); + List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); + List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); + List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); + List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); + List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); + + assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); + } + + @Test + public void testLogEventsInfoLevel() { + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + // Log at INFO level + setLoggerLevel(Level.INFO); + + int expectedTotalEventsCapturedAtFatal = 1; + logger.fatal(CAPTURED); + + int expectedTotalEventsCapturedAtError = 1; + logger.error(CAPTURED); + + int expectedTotalEventsCapturedAtWarn = 1; + logger.warn(CAPTURED); + + int expectedTotalEventsCapturedAtInfo = 1; + logger.info(CAPTURED); + + int expectedTotalEventsCapturedAtDebug = 0; + logger.debug(NOT_CAPTURED); + + int expectedTotalEventsCapturedAtTrace = 0; + logger.trace(NOT_CAPTURED); + + int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + + expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + + expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + + expectedTotalEventsCapturedAtTrace; + + Collection logEvents = introspector.getLogEvents(); + + assertEquals(expectedTotalEventsCaptured, logEvents.size()); + + List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); + List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); + List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); + List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); + List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); + List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); + + assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); + } + + @Test + public void testLogEventsDebugLevel() { + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + // Log at DEBUG level + setLoggerLevel(Level.DEBUG); + + int expectedTotalEventsCapturedAtFatal = 1; + logger.fatal(CAPTURED); + + int expectedTotalEventsCapturedAtError = 1; + logger.error(CAPTURED); + + int expectedTotalEventsCapturedAtWarn = 1; + logger.warn(CAPTURED); + + int expectedTotalEventsCapturedAtInfo = 1; + logger.info(CAPTURED); + + int expectedTotalEventsCapturedAtDebug = 1; + logger.debug(CAPTURED); + + int expectedTotalEventsCapturedAtTrace = 0; + logger.trace(NOT_CAPTURED); + + int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + + expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + + expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + + expectedTotalEventsCapturedAtTrace; + + Collection logEvents = introspector.getLogEvents(); + + assertEquals(expectedTotalEventsCaptured, logEvents.size()); + + List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); + List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); + List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); + List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); + List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); + List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); + + assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); + } + + @Test + public void testLogEventsTraceLevel() { + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + // Log at TRACE level + setLoggerLevel(Level.TRACE); + + int expectedTotalEventsCapturedAtFatal = 1; + logger.fatal(CAPTURED); + + int expectedTotalEventsCapturedAtError = 1; + logger.error(CAPTURED); + + int expectedTotalEventsCapturedAtWarn = 1; + logger.warn(CAPTURED); + + int expectedTotalEventsCapturedAtInfo = 1; + logger.info(CAPTURED); + + int expectedTotalEventsCapturedAtDebug = 1; + logger.debug(CAPTURED); + + int expectedTotalEventsCapturedAtTrace = 1; + logger.trace(CAPTURED); + + int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + + expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + + expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + + expectedTotalEventsCapturedAtTrace; + + Collection logEvents = introspector.getLogEvents(); + + assertEquals(expectedTotalEventsCaptured, logEvents.size()); + + List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); + List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); + List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); + List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); + List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); + List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); + + assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); + assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); + } + + private List getTraceLevelLogEvents(Collection logEvents) { + return logEvents.stream() + .filter(logEvent -> logEvent.getUserAttributesCopy().containsValue(Level.TRACE.toString())) + .collect(Collectors.toList()); + } + + private List getDebugLevelLogEvents(Collection logEvents) { + return logEvents.stream() + .filter(logEvent -> logEvent.getUserAttributesCopy().containsValue(Level.DEBUG.toString())) + .collect(Collectors.toList()); + } + + private List getInfoLevelLogEvents(Collection logEvents) { + return logEvents.stream() + .filter(logEvent -> logEvent.getUserAttributesCopy().containsValue(Level.INFO.toString())) + .collect(Collectors.toList()); + } + + private List getWarnLevelLogEvents(Collection logEvents) { + return logEvents.stream() + .filter(logEvent -> logEvent.getUserAttributesCopy().containsValue(Level.WARN.toString())) + .collect(Collectors.toList()); + } + + private List getErrorLevelLogEvents(Collection logEvents) { + return logEvents.stream() + .filter(logEvent -> logEvent.getUserAttributesCopy().containsValue(Level.ERROR.toString())) + .collect(Collectors.toList()); + } + + private List getFatalLevelLogEvents(Collection logEvents) { + return logEvents.stream() + .filter(logEvent -> logEvent.getUserAttributesCopy().containsValue(Level.FATAL.toString())) + .collect(Collectors.toList()); + } + + @Test + public void shouldIncrementEmittedLogsCountersIndependentlyIfLogLevelEnabled() { + // Given + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + setLoggerLevel(Level.INFO); + + // When + logger.trace(NOT_CAPTURED); + logger.debug(NOT_CAPTURED); + logger.info(CAPTURED); + logger.info(CAPTURED); + logger.info(CAPTURED); + logger.warn(CAPTURED); + logger.warn(CAPTURED); + logger.warn(CAPTURED); + logger.warn(CAPTURED); + logger.error(CAPTURED); + + // Then + Assert.assertEquals(8, MetricsHelper.getUnscopedMetricCount("Logging/lines")); + Assert.assertEquals(0, MetricsHelper.getUnscopedMetricCount("Logging/lines/TRACE")); + Assert.assertEquals(0, MetricsHelper.getUnscopedMetricCount("Logging/lines/DEBUG")); + Assert.assertEquals(3, MetricsHelper.getUnscopedMetricCount("Logging/lines/INFO")); + Assert.assertEquals(4, MetricsHelper.getUnscopedMetricCount("Logging/lines/WARN")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/ERROR")); + } + + @Test + public void shouldIncrementAllEmittedLogCountersIfLogLevelIsSetToTrace() { + // Given + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + setLoggerLevel(Level.TRACE); + + // When + logger.trace(CAPTURED); + logger.debug(CAPTURED); + logger.info(CAPTURED); + logger.warn(CAPTURED); + logger.error(CAPTURED); + + // Then + Assert.assertEquals(5, MetricsHelper.getUnscopedMetricCount("Logging/lines")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/TRACE")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/DEBUG")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/INFO")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/WARN")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/ERROR")); + } + + @Test + public void shouldIncrementAllEmittedLogCountersOnlyOnceWhenMultipleLoggersAreSet() { + // Given + createLogger("A_SPECIAL_LOGGER", createAppender("ConsoleAppender"), Level.TRACE, true); + final Logger logger = LogManager.getLogger("A_SPECIAL_LOGGER"); + setLoggerLevel(Level.TRACE); + + // When + logger.trace(CAPTURED); + logger.debug(CAPTURED); + logger.info(CAPTURED); + logger.warn(CAPTURED); + logger.error(CAPTURED); + + // Then + Assert.assertEquals(5, MetricsHelper.getUnscopedMetricCount("Logging/lines")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/TRACE")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/DEBUG")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/INFO")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/WARN")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/ERROR")); + } + + @Test + public void shouldIncrementAllEmittedLogCountersRespectingLevelFromOriginalLogger() { + // Given + createLogger("A_SPECIAL_LOGGER", createAppender("ConsoleAppender"), Level.INFO, true); + final Logger logger = LogManager.getLogger("A_SPECIAL_LOGGER"); + setLoggerLevel(Level.ERROR); + + // When + logger.trace(NOT_CAPTURED); + logger.debug(NOT_CAPTURED); + logger.info(CAPTURED); + logger.warn(CAPTURED); + logger.error(CAPTURED); + + // Then + Assert.assertEquals(3, MetricsHelper.getUnscopedMetricCount("Logging/lines")); + Assert.assertEquals(0, MetricsHelper.getUnscopedMetricCount("Logging/lines/TRACE")); + Assert.assertEquals(0, MetricsHelper.getUnscopedMetricCount("Logging/lines/DEBUG")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/INFO")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/WARN")); + Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/ERROR")); + } + + private void createLogger(String name, Appender appender, Level level, boolean additivity) { + final LoggerContext ctx = (LoggerContext) LogManager.getContext(false); + final Configuration config = ctx.getConfiguration(); + AppenderRef ref = AppenderRef.createAppenderRef("File", null, null); + AppenderRef[] refs = new AppenderRef[] { ref }; + LoggerConfig loggerConfig = LoggerConfig.createLogger(additivity, level, name, "true", refs, null, config, null); + loggerConfig.addAppender(appender, level, null); + config.addLogger(name, loggerConfig); + } + + private Appender createAppender(String name) { + Layout layout = PatternLayout.newBuilder() + .withPattern(PatternLayout.SIMPLE_CONVERSION_PATTERN) + .build(); + Appender appender = ConsoleAppender.newBuilder() + .setName(name) + .setLayout(layout) + .build(); + appender.start(); + return appender; + } + + private void setLoggerLevel(Level level) { + final LoggerContext context = (LoggerContext) LogManager.getContext(false); + final Configuration configuration = context.getConfiguration(); + final LoggerConfig rootConfig = configuration.getLoggerConfig(LogManager.ROOT_LOGGER_NAME); + rootConfig.setLevel(level); + context.updateLoggers(); + } + + @Test + public void contextDataDisabledTest() { + final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); + ThreadContext.put("include", "42"); + ThreadContext.put("exclude", "panic"); + + logger.error("message"); + + Collection logEvents = introspector.getLogEvents(); + assertEquals(1, logEvents.size()); + + // verify no context attrs + Map attributes = logEvents.iterator().next().getUserAttributesCopy(); + long contextAttrCount = attributes.keySet().stream() + .filter(key -> key.startsWith("context.")) + .count(); + assertEquals(0L, contextAttrCount); + } + +} diff --git a/instrumentation/apache-log4j-2.15/src/test/resources/application_logging_context_data_enabled.yml b/instrumentation/apache-log4j-2.15/src/test/resources/application_logging_context_data_enabled.yml new file mode 100644 index 0000000000..1212edc2e9 --- /dev/null +++ b/instrumentation/apache-log4j-2.15/src/test/resources/application_logging_context_data_enabled.yml @@ -0,0 +1,12 @@ +common: &default_settings + application_logging: + enabled: true + forwarding: + enabled: true + max_samples_stored: 10000 + context_data: + enabled: true + metrics: + enabled: true + local_decorating: + enabled: false diff --git a/instrumentation/apache-log4j-2.15/src/test/resources/application_logging_enabled.yml b/instrumentation/apache-log4j-2.15/src/test/resources/application_logging_enabled.yml new file mode 100644 index 0000000000..583ffd2bba --- /dev/null +++ b/instrumentation/apache-log4j-2.15/src/test/resources/application_logging_enabled.yml @@ -0,0 +1,10 @@ +common: &default_settings + application_logging: + enabled: true + forwarding: + enabled: true + max_samples_stored: 10000 + metrics: + enabled: true + local_decorating: + enabled: false diff --git a/instrumentation/apache-log4j-2/build.gradle b/instrumentation/apache-log4j-2/build.gradle index 81cb3eb978..2042aee68b 100644 --- a/instrumentation/apache-log4j-2/build.gradle +++ b/instrumentation/apache-log4j-2/build.gradle @@ -8,7 +8,7 @@ dependencies { } verifyInstrumentation { - passesOnly("org.apache.logging.log4j:log4j-core:[2.11.0,)") + passesOnly("org.apache.logging.log4j:log4j-core:[2.6,)") excludeRegex '.*(alpha|beta|rc).*' } diff --git a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java deleted file mode 100644 index 409f3a9ac5..0000000000 --- a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java +++ /dev/null @@ -1,45 +0,0 @@ -/* - * - * * Copyright 2023 New Relic Corporation. All rights reserved. - * * SPDX-License-Identifier: Apache-2.0 - * - */ - -package org.apache.logging.log4j.core.layout; - -import com.newrelic.api.agent.weaver.MatchType; -import com.newrelic.api.agent.weaver.Weave; -import com.newrelic.api.agent.weaver.Weaver; - -import java.util.Map; - -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.getLinkingMetadataBlob; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingEnabled; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingLocalDecoratingEnabled; - -abstract class AbstractJacksonLayout_Instrumentation { - - @Weave(originalName = "org.apache.logging.log4j.core.layout.AbstractJacksonLayout$LogEventWithAdditionalFields", type = MatchType.ExactClass) - public static class LogEventWithAdditionalFields_Instrumentation { - - private final Object logEvent; - private final Map additionalFields; - - public LogEventWithAdditionalFields_Instrumentation(final Object logEvent, final Map additionalFields) { - // This will only ever work if at least one additional field is set in the JsonLayout, doesn't matter what it is - // - // - // - - this.logEvent = Weaver.callOriginal(); - if (isApplicationLoggingEnabled()) { - if (isApplicationLoggingLocalDecoratingEnabled()) { - // Append New Relic linking metadata from agent to log message - additionalFields.put("In NR", getLinkingMetadataBlob()); - } - } - this.additionalFields = Weaver.callOriginal(); - } - } - -} From 2f06bceb4d705ef1575355c59f8bd29c75067241 Mon Sep 17 00:00:00 2001 From: jasonjkeller Date: Tue, 5 Sep 2023 11:24:32 -0700 Subject: [PATCH 05/14] Update copyright headers --- .../com/nr/agent/instrumentation/log4j2/AgentUtil.java | 2 +- .../com/nr/agent/instrumentation/log4j2/ExceptionUtil.java | 7 +++++++ .../log4j/core/config/LoggerConfig_Instrumentation.java | 2 +- .../core/layout/StringBuilderEncoder_Instrumentation.java | 2 +- .../nr/agent/instrumentation/log4j2/ContextDataTest.java | 2 +- .../nr/agent/instrumentation/log4j2/ExceptionUtilTest.java | 7 +++++++ .../log4j2/LoggerConfig_InstrumentationTest.java | 7 +++++++ 7 files changed, 25 insertions(+), 4 deletions(-) diff --git a/instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java b/instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java index 05ac051504..0ef59817a8 100644 --- a/instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java +++ b/instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java @@ -1,6 +1,6 @@ /* * - * * Copyright 2022 New Relic Corporation. All rights reserved. + * * Copyright 2023 New Relic Corporation. All rights reserved. * * SPDX-License-Identifier: Apache-2.0 * */ diff --git a/instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java b/instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java index a0f650906a..fe87219561 100644 --- a/instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java +++ b/instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java @@ -1,3 +1,10 @@ +/* + * + * * Copyright 2023 New Relic Corporation. All rights reserved. + * * SPDX-License-Identifier: Apache-2.0 + * + */ + package com.nr.agent.instrumentation.log4j2; public class ExceptionUtil { diff --git a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java index 15f9df708c..cc33972047 100644 --- a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java +++ b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java @@ -1,6 +1,6 @@ /* * - * * Copyright 2022 New Relic Corporation. All rights reserved. + * * Copyright 2023 New Relic Corporation. All rights reserved. * * SPDX-License-Identifier: Apache-2.0 * */ diff --git a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java index e09c3e19a5..121cbdfdaf 100644 --- a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java +++ b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java @@ -1,6 +1,6 @@ /* * - * * Copyright 2022 New Relic Corporation. All rights reserved. + * * Copyright 2023 New Relic Corporation. All rights reserved. * * SPDX-License-Identifier: Apache-2.0 * */ diff --git a/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java b/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java index 09b8893aec..1ab8a4d5d5 100644 --- a/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java +++ b/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java @@ -1,6 +1,6 @@ /* * - * * Copyright 2022 New Relic Corporation. All rights reserved. + * * Copyright 2023 New Relic Corporation. All rights reserved. * * SPDX-License-Identifier: Apache-2.0 * */ diff --git a/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java b/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java index 85545ba746..9ebc9ca804 100644 --- a/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java +++ b/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java @@ -1,3 +1,10 @@ +/* + * + * * Copyright 2023 New Relic Corporation. All rights reserved. + * * SPDX-License-Identifier: Apache-2.0 + * + */ + package com.nr.agent.instrumentation.log4j2; import org.junit.Test; diff --git a/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java b/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java index 5fc7516329..2d16b08b34 100644 --- a/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java +++ b/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java @@ -1,3 +1,10 @@ +/* + * + * * Copyright 2023 New Relic Corporation. All rights reserved. + * * SPDX-License-Identifier: Apache-2.0 + * + */ + package com.nr.agent.instrumentation.log4j2; import com.newrelic.agent.introspec.InstrumentationTestConfig; From 418cb192f59da2d40a7091ce1757d66fa388af16 Mon Sep 17 00:00:00 2001 From: jasonjkeller Date: Tue, 5 Sep 2023 11:29:51 -0700 Subject: [PATCH 06/14] Add comments --- .../core/layout/AbstractStringLayout_Instrumentation.java | 3 ++- .../core/layout/AbstractStringLayout_Instrumentation.java | 3 ++- 2 files changed, 4 insertions(+), 2 deletions(-) diff --git a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java index 5c5c42038a..1af85ae231 100644 --- a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java +++ b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java @@ -22,9 +22,10 @@ public abstract class AbstractStringLayout_Instrumentation { protected byte[] getBytes(final String s) { String modified = s; + // It is possible that the log being formatted into JSON might already have NR-LINKING metadata from JUL instrumentation if (!s.contains("NR-LINKING")) { int indexToInsertNrLinkingMetadata = s.indexOf("\n", s.indexOf("message")) - 1; - // Replace the JSON string with modified version + // Replace the JSON string with modified version that includes NR-LINKING metadata modified = new StringBuilder(s).insert(indexToInsertNrLinkingMetadata, getLinkingMetadataBlob()).toString(); } return modified.getBytes(charset); diff --git a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java index 9d57018e47..79c0bc487c 100644 --- a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java +++ b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java @@ -26,9 +26,10 @@ public abstract class AbstractStringLayout_Instrumentation { protected byte[] getBytes(final String s) { String modified = s; + // It is possible that the log being formatted into JSON might already have NR-LINKING metadata from JUL instrumentation if (!s.contains("NR-LINKING")) { int indexToInsertNrLinkingMetadata = s.indexOf("\n", s.indexOf("message")) - 1; - // Replace the JSON string with modified version + // Replace the JSON string with modified version that includes NR-LINKING metadata modified = new StringBuilder(s).insert(indexToInsertNrLinkingMetadata, getLinkingMetadataBlob()).toString(); } if (useCustomEncoding) { From f1307cf71d9e3580e5eec67b5c6027d4d4bdf4bb Mon Sep 17 00:00:00 2001 From: jasonjkeller Date: Tue, 5 Sep 2023 12:07:02 -0700 Subject: [PATCH 07/14] Prevent log4j2 instrumentation from adding NR-LINKING metadata if it was already added by other logger instrumentation (e.g. JUL). --- .../AbstractStringLayout_Instrumentation.java | 3 ++- .../StringBuilderEncoder_Instrumentation.java | 15 ++++++++++----- .../AbstractStringLayout_Instrumentation.java | 3 ++- .../StringBuilderEncoder_Instrumentation.java | 15 ++++++++++----- 4 files changed, 24 insertions(+), 12 deletions(-) diff --git a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java index 1af85ae231..4f448da82b 100644 --- a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java +++ b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java @@ -13,6 +13,7 @@ import java.nio.charset.Charset; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.BLOB_PREFIX; import static com.newrelic.agent.bridge.logging.AppLoggingUtils.getLinkingMetadataBlob; @Weave(originalName = "org.apache.logging.log4j.core.layout.AbstractStringLayout", type = MatchType.ExactClass) @@ -23,7 +24,7 @@ public abstract class AbstractStringLayout_Instrumentation { protected byte[] getBytes(final String s) { String modified = s; // It is possible that the log being formatted into JSON might already have NR-LINKING metadata from JUL instrumentation - if (!s.contains("NR-LINKING")) { + if (!s.contains(BLOB_PREFIX)) { int indexToInsertNrLinkingMetadata = s.indexOf("\n", s.indexOf("message")) - 1; // Replace the JSON string with modified version that includes NR-LINKING metadata modified = new StringBuilder(s).insert(indexToInsertNrLinkingMetadata, getLinkingMetadataBlob()).toString(); diff --git a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java index 121cbdfdaf..e87d757bd3 100644 --- a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java +++ b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java @@ -11,6 +11,7 @@ import com.newrelic.api.agent.weaver.Weave; import com.newrelic.api.agent.weaver.Weaver; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.BLOB_PREFIX; import static com.newrelic.agent.bridge.logging.AppLoggingUtils.getLinkingMetadataBlob; import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingEnabled; import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingLocalDecoratingEnabled; @@ -30,11 +31,15 @@ public void encode(final StringBuilder source, final ByteBufferDestination desti } private void appendAgentMetadata(StringBuilder source) { - int breakLine = source.toString().lastIndexOf("\n"); - if (breakLine != -1) { - source.replace(breakLine, breakLine + 1, ""); + String sourceString = source.toString(); + // It is possible that the log might already have NR-LINKING metadata from JUL instrumentation + if (!sourceString.contains(BLOB_PREFIX)) { + int breakLine = sourceString.lastIndexOf("\n"); + if (breakLine != -1) { + source.replace(breakLine, breakLine + 1, ""); + } + source.append(getLinkingMetadataBlob()).append("\n"); } - source.append(getLinkingMetadataBlob()).append("\n"); } -} \ No newline at end of file +} diff --git a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java index 79c0bc487c..ac9c3a7b5f 100644 --- a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java +++ b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java @@ -15,6 +15,7 @@ import java.io.UnsupportedEncodingException; import java.nio.charset.Charset; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.BLOB_PREFIX; import static com.newrelic.agent.bridge.logging.AppLoggingUtils.getLinkingMetadataBlob; @Weave(originalName = "org.apache.logging.log4j.core.layout.AbstractStringLayout", type = MatchType.ExactClass) @@ -27,7 +28,7 @@ public abstract class AbstractStringLayout_Instrumentation { protected byte[] getBytes(final String s) { String modified = s; // It is possible that the log being formatted into JSON might already have NR-LINKING metadata from JUL instrumentation - if (!s.contains("NR-LINKING")) { + if (!s.contains(BLOB_PREFIX)) { int indexToInsertNrLinkingMetadata = s.indexOf("\n", s.indexOf("message")) - 1; // Replace the JSON string with modified version that includes NR-LINKING metadata modified = new StringBuilder(s).insert(indexToInsertNrLinkingMetadata, getLinkingMetadataBlob()).toString(); diff --git a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java index e09c3e19a5..ef3469d0d7 100644 --- a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java +++ b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java @@ -11,6 +11,7 @@ import com.newrelic.api.agent.weaver.Weave; import com.newrelic.api.agent.weaver.Weaver; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.BLOB_PREFIX; import static com.newrelic.agent.bridge.logging.AppLoggingUtils.getLinkingMetadataBlob; import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingEnabled; import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingLocalDecoratingEnabled; @@ -30,11 +31,15 @@ public void encode(final StringBuilder source, final ByteBufferDestination desti } private void appendAgentMetadata(StringBuilder source) { - int breakLine = source.toString().lastIndexOf("\n"); - if (breakLine != -1) { - source.replace(breakLine, breakLine + 1, ""); + String sourceString = source.toString(); + // It is possible that the log might already have NR-LINKING metadata from JUL instrumentation + if (!sourceString.contains(BLOB_PREFIX)) { + int breakLine = sourceString.lastIndexOf("\n"); + if (breakLine != -1) { + source.replace(breakLine, breakLine + 1, ""); + } + source.append(getLinkingMetadataBlob()).append("\n"); } - source.append(getLinkingMetadataBlob()).append("\n"); } -} \ No newline at end of file +} From e6139d2452835cf9e5c5c95e7234191c4694acfc Mon Sep 17 00:00:00 2001 From: jasonjkeller Date: Tue, 5 Sep 2023 14:48:42 -0700 Subject: [PATCH 08/14] Insert NR-LINKING metadata within closing parenthesis --- .../core/layout/AbstractStringLayout_Instrumentation.java | 6 ++++-- .../core/layout/AbstractStringLayout_Instrumentation.java | 6 ++++-- 2 files changed, 8 insertions(+), 4 deletions(-) diff --git a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java index 4f448da82b..c4db3b4fba 100644 --- a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java +++ b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java @@ -23,9 +23,11 @@ public abstract class AbstractStringLayout_Instrumentation { protected byte[] getBytes(final String s) { String modified = s; - // It is possible that the log being formatted into JSON might already have NR-LINKING metadata from JUL instrumentation + // It is possible that the log might already have NR-LINKING metadata from JUL instrumentation if (!s.contains(BLOB_PREFIX)) { - int indexToInsertNrLinkingMetadata = s.indexOf("\n", s.indexOf("message")) - 1; + // Finds the index of the closing parenthesis for a substring that begins with "message" and ends with the sequence ",\n + // Example JSON substring: "message":"Tomcat initialized",\n + int indexToInsertNrLinkingMetadata = s.indexOf("\",\n", s.indexOf("message")); // Replace the JSON string with modified version that includes NR-LINKING metadata modified = new StringBuilder(s).insert(indexToInsertNrLinkingMetadata, getLinkingMetadataBlob()).toString(); } diff --git a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java index ac9c3a7b5f..16034ca258 100644 --- a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java +++ b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java @@ -27,9 +27,11 @@ public abstract class AbstractStringLayout_Instrumentation { protected byte[] getBytes(final String s) { String modified = s; - // It is possible that the log being formatted into JSON might already have NR-LINKING metadata from JUL instrumentation + // It is possible that the log might already have NR-LINKING metadata from JUL instrumentation if (!s.contains(BLOB_PREFIX)) { - int indexToInsertNrLinkingMetadata = s.indexOf("\n", s.indexOf("message")) - 1; + // Finds the index of the closing parenthesis for a substring that begins with "message" and ends with the sequence ",\n + // Example JSON substring: "message":"Tomcat initialized",\n + int indexToInsertNrLinkingMetadata = s.indexOf("\",\n", s.indexOf("message")); // Replace the JSON string with modified version that includes NR-LINKING metadata modified = new StringBuilder(s).insert(indexToInsertNrLinkingMetadata, getLinkingMetadataBlob()).toString(); } From 95403668959a0fbbfb5d551fc794e99a2715077e Mon Sep 17 00:00:00 2001 From: jasonjkeller Date: Wed, 6 Sep 2023 16:34:34 -0700 Subject: [PATCH 09/14] Refactor to use new approach with AbstractJacksonLayout --- .../apache-log4j-2.15/build.gradle | 18 - .../instrumentation/log4j2/AgentUtil.java | 131 ---- .../instrumentation/log4j2/ExceptionUtil.java | 56 -- .../config/LoggerConfig_Instrumentation.java | 66 -- .../AbstractStringLayout_Instrumentation.java | 37 -- .../StringBuilderEncoder_Instrumentation.java | 45 -- .../log4j2/ContextDataTest.java | 64 -- .../log4j2/ExceptionUtilTest.java | 68 -- .../LoggerConfig_InstrumentationTest.java | 629 ------------------ ...plication_logging_context_data_enabled.yml | 12 - .../resources/application_logging_enabled.yml | 10 - instrumentation/apache-log4j-2/build.gradle | 2 +- .../instrumentation/log4j2/AgentUtil.java | 32 +- ...AbstractJacksonLayout_Instrumentation.java | 51 ++ .../AbstractStringLayout_Instrumentation.java | 48 -- 15 files changed, 83 insertions(+), 1186 deletions(-) delete mode 100644 instrumentation/apache-log4j-2.15/build.gradle delete mode 100644 instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java delete mode 100644 instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java delete mode 100644 instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java delete mode 100644 instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java delete mode 100644 instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java delete mode 100644 instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java delete mode 100644 instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java delete mode 100644 instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java delete mode 100644 instrumentation/apache-log4j-2.15/src/test/resources/application_logging_context_data_enabled.yml delete mode 100644 instrumentation/apache-log4j-2.15/src/test/resources/application_logging_enabled.yml create mode 100644 instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java delete mode 100644 instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java diff --git a/instrumentation/apache-log4j-2.15/build.gradle b/instrumentation/apache-log4j-2.15/build.gradle deleted file mode 100644 index 109a0ea164..0000000000 --- a/instrumentation/apache-log4j-2.15/build.gradle +++ /dev/null @@ -1,18 +0,0 @@ -jar { - manifest { attributes 'Implementation-Title': 'com.newrelic.instrumentation.apache-log4j-2.15' } -} - -dependencies { - implementation(project(":agent-bridge")) - implementation("org.apache.logging.log4j:log4j-core:2.20.0") -} - -verifyInstrumentation { - passesOnly("org.apache.logging.log4j:log4j-core:[2.15.0,)") - excludeRegex '.*(alpha|beta|rc).*' -} - -site { - title 'Log4j2' - type 'Framework' -} diff --git a/instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java b/instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java deleted file mode 100644 index 0ef59817a8..0000000000 --- a/instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java +++ /dev/null @@ -1,131 +0,0 @@ -/* - * - * * Copyright 2023 New Relic Corporation. All rights reserved. - * * SPDX-License-Identifier: Apache-2.0 - * - */ - -package com.nr.agent.instrumentation.log4j2; - -import com.newrelic.agent.bridge.AgentBridge; -import com.newrelic.agent.bridge.logging.AppLoggingUtils; -import com.newrelic.agent.bridge.logging.LogAttributeKey; -import com.newrelic.agent.bridge.logging.LogAttributeType; -import org.apache.logging.log4j.Level; -import org.apache.logging.log4j.core.LogEvent; -import org.apache.logging.log4j.message.Message; -import org.apache.logging.log4j.util.ReadOnlyStringMap; - -import java.util.HashMap; -import java.util.Map; - -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.DEFAULT_NUM_OF_LOG_EVENT_ATTRIBUTES; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.ERROR_CLASS; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.ERROR_MESSAGE; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.ERROR_STACK; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.INSTRUMENTATION; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.LEVEL; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.LOGGER_FQCN; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.LOGGER_NAME; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.MESSAGE; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.THREAD_ID; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.THREAD_NAME; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.TIMESTAMP; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.UNKNOWN; - -public class AgentUtil { - /** - * Record a LogEvent to be sent to New Relic. - * - * @param event to parse - */ - public static void recordNewRelicLogEvent(LogEvent event) { - if (event != null) { - Message message = event.getMessage(); - Throwable throwable = event.getThrown(); - - if (shouldCreateLogEvent(message, throwable)) { - ReadOnlyStringMap contextData = event.getContextData(); - Map logEventMap = new HashMap<>(calculateInitialMapSize(contextData)); - logEventMap.put(INSTRUMENTATION, "apache-log4j-2.15"); - if (message != null) { - String formattedMessage = message.getFormattedMessage(); - if (formattedMessage != null && !formattedMessage.isEmpty()) { - logEventMap.put(MESSAGE, formattedMessage); - } - } - logEventMap.put(TIMESTAMP, event.getTimeMillis()); - - if (AppLoggingUtils.isAppLoggingContextDataEnabled() && contextData != null) { - for (Map.Entry entry : contextData.toMap().entrySet()) { - String key = entry.getKey(); - String value = entry.getValue(); - LogAttributeKey logAttrKey = new LogAttributeKey(key, LogAttributeType.CONTEXT); - logEventMap.put(logAttrKey, value); - } - } - - Level level = event.getLevel(); - if (level != null) { - String levelName = level.name(); - if (levelName.isEmpty()) { - logEventMap.put(LEVEL, UNKNOWN); - } else { - logEventMap.put(LEVEL, levelName); - } - } - - String errorStack = ExceptionUtil.getErrorStack(throwable); - if (errorStack != null) { - logEventMap.put(ERROR_STACK, errorStack); - } - - String errorMessage = ExceptionUtil.getErrorMessage(throwable); - if (errorMessage != null) { - logEventMap.put(ERROR_MESSAGE, errorMessage); - } - - String errorClass = ExceptionUtil.getErrorClass(throwable); - if (errorClass != null) { - logEventMap.put(ERROR_CLASS, errorClass); - } - - String threadName = event.getThreadName(); - if (threadName != null) { - logEventMap.put(THREAD_NAME, threadName); - } - - logEventMap.put(THREAD_ID, event.getThreadId()); - - String loggerName = event.getLoggerName(); - if (loggerName != null) { - logEventMap.put(LOGGER_NAME, loggerName); - } - - String loggerFqcn = event.getLoggerFqcn(); - if (loggerFqcn != null) { - logEventMap.put(LOGGER_FQCN, loggerFqcn); - } - - AgentBridge.getAgent().getLogSender().recordLogEvent(logEventMap); - } - } - } - - /** - * A LogEvent MUST NOT be reported if neither a log message nor an error is logged. If either is present report the LogEvent. - * - * @param message Message to validate - * @param throwable Throwable to validate - * @return true if a LogEvent should be created, otherwise false - */ - private static boolean shouldCreateLogEvent(Message message, Throwable throwable) { - return (message != null) || !ExceptionUtil.isThrowableNull(throwable); - } - - private static int calculateInitialMapSize(ReadOnlyStringMap mdcPropertyMap) { - return AppLoggingUtils.isAppLoggingContextDataEnabled() && mdcPropertyMap != null - ? mdcPropertyMap.size() + DEFAULT_NUM_OF_LOG_EVENT_ATTRIBUTES - : DEFAULT_NUM_OF_LOG_EVENT_ATTRIBUTES; - } -} diff --git a/instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java b/instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java deleted file mode 100644 index fe87219561..0000000000 --- a/instrumentation/apache-log4j-2.15/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java +++ /dev/null @@ -1,56 +0,0 @@ -/* - * - * * Copyright 2023 New Relic Corporation. All rights reserved. - * * SPDX-License-Identifier: Apache-2.0 - * - */ - -package com.nr.agent.instrumentation.log4j2; - -public class ExceptionUtil { - public static final int MAX_STACK_SIZE = 300; - - public static boolean isThrowableNull(Throwable throwable) { - return throwable == null; - } - - public static String getErrorStack(Throwable throwable) { - if (isThrowableNull(throwable)) { - return null; - } - - StackTraceElement[] stack = throwable.getStackTrace(); - return getErrorStack(stack); - } - - public static String getErrorStack(StackTraceElement[] stack) { - return getErrorStack(stack, MAX_STACK_SIZE); - } - - public static String getErrorStack(StackTraceElement[] stack, Integer maxStackSize) { - if (stack == null || stack.length == 0) { - return null; - } - - StringBuilder stackBuilder = new StringBuilder(); - int stackSizeLimit = Math.min(maxStackSize, stack.length); - for (int i = 0; i < stackSizeLimit; i++) { - stackBuilder.append(" at ").append(stack[i].toString()).append("\n"); - } - return stackBuilder.toString(); - } - - public static String getErrorMessage(Throwable throwable) { - if (isThrowableNull(throwable)) { - return null; - } - return throwable.getMessage(); - } - - public static String getErrorClass(Throwable throwable) { - if (isThrowableNull(throwable)) { - return null; - } - return throwable.getClass().getName(); - } -} diff --git a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java deleted file mode 100644 index cc33972047..0000000000 --- a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java +++ /dev/null @@ -1,66 +0,0 @@ -/* - * - * * Copyright 2023 New Relic Corporation. All rights reserved. - * * SPDX-License-Identifier: Apache-2.0 - * - */ - -package org.apache.logging.log4j.core.config; - -import com.newrelic.api.agent.NewRelic; -import com.newrelic.api.agent.weaver.MatchType; -import com.newrelic.api.agent.weaver.NewField; -import com.newrelic.api.agent.weaver.Weave; -import com.newrelic.api.agent.weaver.WeaveAllConstructors; -import com.newrelic.api.agent.weaver.Weaver; -import org.apache.logging.log4j.core.LogEvent; - -import java.util.concurrent.atomic.AtomicBoolean; - -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingEnabled; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingForwardingEnabled; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingMetricsEnabled; -import static com.nr.agent.instrumentation.log4j2.AgentUtil.recordNewRelicLogEvent; - -@Weave(originalName = "org.apache.logging.log4j.core.config.LoggerConfig", type = MatchType.ExactClass) -public class LoggerConfig_Instrumentation { - @NewField - public static AtomicBoolean instrumented = new AtomicBoolean(false); - - @WeaveAllConstructors - public LoggerConfig_Instrumentation() { - // Generate the instrumentation module supportability metric only once - if (!instrumented.getAndSet(true)) { - NewRelic.incrementCounter("Supportability/Logging/Java/Log4j2/enabled"); - } - } - - protected void callAppenders(LogEvent event) { - // Do nothing if application_logging.enabled: false - if (isApplicationLoggingEnabled()) { - // Do nothing if logger has parents and isAdditive is set to true to avoid duplicated counters and logs - if (getParent() == null || !isAdditive()) { - if (isApplicationLoggingMetricsEnabled()) { - // Generate log level metrics - NewRelic.incrementCounter("Logging/lines"); - NewRelic.incrementCounter("Logging/lines/" + event.getLevel().toString()); - } - - if (isApplicationLoggingForwardingEnabled()) { - // Record and send LogEvent to New Relic - recordNewRelicLogEvent(event); - } - } - } - Weaver.callOriginal(); - } - - public LoggerConfig getParent() { - return Weaver.callOriginal(); - } - - public boolean isAdditive() { - return Weaver.callOriginal(); - } - -} diff --git a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java deleted file mode 100644 index c4db3b4fba..0000000000 --- a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java +++ /dev/null @@ -1,37 +0,0 @@ -/* - * - * * Copyright 2023 New Relic Corporation. All rights reserved. - * * SPDX-License-Identifier: Apache-2.0 - * - */ - -package org.apache.logging.log4j.core.layout; - -import com.newrelic.api.agent.weaver.MatchType; -import com.newrelic.api.agent.weaver.Weave; -import com.newrelic.api.agent.weaver.Weaver; - -import java.nio.charset.Charset; - -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.BLOB_PREFIX; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.getLinkingMetadataBlob; - -@Weave(originalName = "org.apache.logging.log4j.core.layout.AbstractStringLayout", type = MatchType.ExactClass) -public abstract class AbstractStringLayout_Instrumentation { - - private final Charset charset = Weaver.callOriginal(); - - protected byte[] getBytes(final String s) { - String modified = s; - // It is possible that the log might already have NR-LINKING metadata from JUL instrumentation - if (!s.contains(BLOB_PREFIX)) { - // Finds the index of the closing parenthesis for a substring that begins with "message" and ends with the sequence ",\n - // Example JSON substring: "message":"Tomcat initialized",\n - int indexToInsertNrLinkingMetadata = s.indexOf("\",\n", s.indexOf("message")); - // Replace the JSON string with modified version that includes NR-LINKING metadata - modified = new StringBuilder(s).insert(indexToInsertNrLinkingMetadata, getLinkingMetadataBlob()).toString(); - } - return modified.getBytes(charset); - } - -} diff --git a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java b/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java deleted file mode 100644 index e87d757bd3..0000000000 --- a/instrumentation/apache-log4j-2.15/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java +++ /dev/null @@ -1,45 +0,0 @@ -/* - * - * * Copyright 2023 New Relic Corporation. All rights reserved. - * * SPDX-License-Identifier: Apache-2.0 - * - */ - -package org.apache.logging.log4j.core.layout; - -import com.newrelic.api.agent.weaver.MatchType; -import com.newrelic.api.agent.weaver.Weave; -import com.newrelic.api.agent.weaver.Weaver; - -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.BLOB_PREFIX; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.getLinkingMetadataBlob; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingEnabled; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingLocalDecoratingEnabled; - -@Weave(originalName = "org.apache.logging.log4j.core.layout.StringBuilderEncoder", type = MatchType.BaseClass) -public class StringBuilderEncoder_Instrumentation { - - public void encode(final StringBuilder source, final ByteBufferDestination destination) { - // Do nothing if application_logging.enabled: false - if (isApplicationLoggingEnabled()) { - if (isApplicationLoggingLocalDecoratingEnabled()) { - // Append New Relic linking metadata from agent to log message - appendAgentMetadata(source); - } - } - Weaver.callOriginal(); - } - - private void appendAgentMetadata(StringBuilder source) { - String sourceString = source.toString(); - // It is possible that the log might already have NR-LINKING metadata from JUL instrumentation - if (!sourceString.contains(BLOB_PREFIX)) { - int breakLine = sourceString.lastIndexOf("\n"); - if (breakLine != -1) { - source.replace(breakLine, breakLine + 1, ""); - } - source.append(getLinkingMetadataBlob()).append("\n"); - } - } - -} diff --git a/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java b/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java deleted file mode 100644 index 1ab8a4d5d5..0000000000 --- a/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java +++ /dev/null @@ -1,64 +0,0 @@ -/* - * - * * Copyright 2023 New Relic Corporation. All rights reserved. - * * SPDX-License-Identifier: Apache-2.0 - * - */ -package com.nr.agent.instrumentation.log4j2; - -import com.newrelic.agent.introspec.InstrumentationTestConfig; -import com.newrelic.agent.introspec.InstrumentationTestRunner; -import com.newrelic.agent.introspec.Introspector; -import com.newrelic.agent.model.LogEvent; -import org.apache.logging.log4j.LogManager; -import org.apache.logging.log4j.Logger; -import org.apache.logging.log4j.ThreadContext; -import org.apache.logging.log4j.core.config.Configurator; -import org.junit.Before; -import org.junit.Test; -import org.junit.runner.RunWith; - -import java.util.Collection; -import java.util.Map; - -import static org.junit.Assert.*; - -@RunWith(InstrumentationTestRunner.class) -@InstrumentationTestConfig(includePrefixes = { "org.apache.logging.log4j.core" }, configName = "application_logging_context_data_enabled.yml") -public class ContextDataTest { - - private final Introspector introspector = InstrumentationTestRunner.getIntrospector(); - - @Before - public void reset() { - Configurator.reconfigure(); - introspector.clearLogEvents(); - } - - @Test - public void testAttributes() { - final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); - String attrKey1 = "key"; - String attrKey2 = "anotherKey"; - String val1 = "42"; - String val2 = "panic"; - - ThreadContext.put(attrKey1, val1); - ThreadContext.put(attrKey2, val2); - logger.error("message"); - - Collection logEvents = introspector.getLogEvents(); - assertEquals(1, logEvents.size()); - - LogEvent logEvent = logEvents.iterator().next(); - Map attributes = logEvent.getUserAttributesCopy(); - long contextAttrCount = attributes.keySet().stream() - .filter(key -> key.startsWith("context.")) - .count(); - // MDC data is filtered later in the process - assertEquals(2L, contextAttrCount); - assertEquals(val1, attributes.get("context." + attrKey1)); - assertEquals(val2, attributes.get("context." + attrKey2)); - } - -} diff --git a/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java b/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java deleted file mode 100644 index 9ebc9ca804..0000000000 --- a/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java +++ /dev/null @@ -1,68 +0,0 @@ -/* - * - * * Copyright 2023 New Relic Corporation. All rights reserved. - * * SPDX-License-Identifier: Apache-2.0 - * - */ - -package com.nr.agent.instrumentation.log4j2; - -import org.junit.Test; - -import static org.junit.Assert.assertEquals; -import static org.junit.Assert.assertFalse; -import static org.junit.Assert.assertNull; -import static org.junit.Assert.assertTrue; - -public class ExceptionUtilTest { - - @Test - public void testIsThrowableNull() { - Throwable nullThrowable = null; - Throwable nonNullThrowable = new Throwable("Hi"); - - assertTrue(ExceptionUtil.isThrowableNull(nullThrowable)); - assertFalse(ExceptionUtil.isThrowableNull(nonNullThrowable)); - } - - @Test - public void testGetErrorStack() { - int maxStackSize = 3; - StackTraceElement stackTraceElement1 = new StackTraceElement("Class1", "method1", "File1", 1); - StackTraceElement stackTraceElement2 = new StackTraceElement("Class2", "method2", "File2", 2); - StackTraceElement stackTraceElement3 = new StackTraceElement("Class3", "method3", "File3", 3); - StackTraceElement stackTraceElement4 = new StackTraceElement("Class4", "method4", "File4", 4); - StackTraceElement stackTraceElement5 = new StackTraceElement("Class5", "method5", "File5", 5); - StackTraceElement[] stack = new StackTraceElement[] { stackTraceElement1, stackTraceElement2, stackTraceElement3, stackTraceElement4, - stackTraceElement5 }; - String errorStack = ExceptionUtil.getErrorStack(stack, maxStackSize); - - // Processed stack should be limited to only the first three lines - assertTrue(errorStack.contains(stackTraceElement1.toString())); - assertTrue(errorStack.contains(stackTraceElement2.toString())); - assertTrue(errorStack.contains(stackTraceElement3.toString())); - // Processed stack should omit the last two lines - assertFalse(errorStack.contains(stackTraceElement4.toString())); - assertFalse(errorStack.contains(stackTraceElement5.toString())); - } - - @Test - public void testGetErrorMessage() { - String expectedMessage = "Hi"; - Throwable nullThrowable = null; - Throwable nonNullThrowable = new Throwable(expectedMessage); - - assertNull(ExceptionUtil.getErrorMessage(nullThrowable)); - assertEquals(expectedMessage, ExceptionUtil.getErrorMessage(nonNullThrowable)); - } - - @Test - public void testGetErrorClass() { - String expectedExceptionClass = "java.lang.RuntimeException"; - Throwable nullThrowable = null; - RuntimeException runtimeException = new RuntimeException("Hi"); - - assertNull(ExceptionUtil.getErrorClass(nullThrowable)); - assertEquals(expectedExceptionClass, ExceptionUtil.getErrorClass(runtimeException)); - } -} diff --git a/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java b/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java deleted file mode 100644 index 2d16b08b34..0000000000 --- a/instrumentation/apache-log4j-2.15/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java +++ /dev/null @@ -1,629 +0,0 @@ -/* - * - * * Copyright 2023 New Relic Corporation. All rights reserved. - * * SPDX-License-Identifier: Apache-2.0 - * - */ - -package com.nr.agent.instrumentation.log4j2; - -import com.newrelic.agent.introspec.InstrumentationTestConfig; -import com.newrelic.agent.introspec.InstrumentationTestRunner; -import com.newrelic.agent.introspec.Introspector; -import com.newrelic.agent.introspec.MetricsHelper; -import com.newrelic.agent.model.LogEvent; -import junit.framework.TestCase; -import org.apache.logging.log4j.Level; -import org.apache.logging.log4j.LogManager; -import org.apache.logging.log4j.Logger; -import org.apache.logging.log4j.ThreadContext; -import org.apache.logging.log4j.core.Appender; -import org.apache.logging.log4j.core.Layout; -import org.apache.logging.log4j.core.LoggerContext; -import org.apache.logging.log4j.core.appender.ConsoleAppender; -import org.apache.logging.log4j.core.config.AppenderRef; -import org.apache.logging.log4j.core.config.Configuration; -import org.apache.logging.log4j.core.config.Configurator; -import org.apache.logging.log4j.core.config.LoggerConfig; -import org.apache.logging.log4j.core.layout.PatternLayout; -import org.junit.Assert; -import org.junit.Before; -import org.junit.Test; -import org.junit.runner.RunWith; - -import java.util.Collection; -import java.util.List; -import java.util.Map; -import java.util.stream.Collectors; - -@RunWith(InstrumentationTestRunner.class) -@InstrumentationTestConfig(includePrefixes = { "org.apache.logging.log4j.core" }, configName = "application_logging_enabled.yml") -public class LoggerConfig_InstrumentationTest extends TestCase { - - private static final String CAPTURED = "This log message should be captured"; - private static final String NOT_CAPTURED = "This message should NOT be captured"; - private final Introspector introspector = InstrumentationTestRunner.getIntrospector(); - - @Before - public void reset() { - Configurator.reconfigure(); - introspector.clearLogEvents(); - } - - @Test - public void testLogEventsAllLevel() { - final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); - // Log at ALL level - setLoggerLevel(Level.ALL); - - int expectedTotalEventsCapturedAtFatal = 1; - logger.fatal(CAPTURED); - - int expectedTotalEventsCapturedAtError = 2; - logger.error(CAPTURED); - logger.error(CAPTURED); - - int expectedTotalEventsCapturedAtWarn = 3; - logger.warn(CAPTURED); - logger.warn(CAPTURED); - logger.warn(CAPTURED); - - int expectedTotalEventsCapturedAtInfo = 4; - logger.info(CAPTURED); - logger.info(CAPTURED); - logger.info(CAPTURED); - logger.info(CAPTURED); - - int expectedTotalEventsCapturedAtDebug = 5; - logger.debug(CAPTURED); - logger.debug(CAPTURED); - logger.debug(CAPTURED); - logger.debug(CAPTURED); - logger.debug(CAPTURED); - - int expectedTotalEventsCapturedAtTrace = 6; - logger.trace(CAPTURED); - logger.trace(CAPTURED); - logger.trace(CAPTURED); - logger.trace(CAPTURED); - logger.trace(CAPTURED); - logger.trace(CAPTURED); - - int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + - expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + - expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + - expectedTotalEventsCapturedAtTrace; - - Collection logEvents = introspector.getLogEvents(); - - assertEquals(expectedTotalEventsCaptured, logEvents.size()); - - List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); - List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); - List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); - List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); - List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); - List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); - - assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); - } - - @Test - public void testLogEventsOffLevel() { - final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); - // Logging is OFF at all levels - setLoggerLevel(Level.OFF); - - int expectedTotalEventsCapturedAtFatal = 0; - logger.fatal(NOT_CAPTURED); - - int expectedTotalEventsCapturedAtError = 0; - logger.error(NOT_CAPTURED); - - int expectedTotalEventsCapturedAtWarn = 0; - logger.warn(NOT_CAPTURED); - - int expectedTotalEventsCapturedAtInfo = 0; - logger.info(NOT_CAPTURED); - - int expectedTotalEventsCapturedAtDebug = 0; - logger.debug(NOT_CAPTURED); - - int expectedTotalEventsCapturedAtTrace = 0; - logger.trace(NOT_CAPTURED); - - int expectedTotalEventsCaptured = 0; - - Collection logEvents = introspector.getLogEvents(); - - assertEquals(expectedTotalEventsCaptured, logEvents.size()); - - List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); - List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); - List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); - List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); - List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); - List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); - - assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); - } - - @Test - public void testLogEventsFatalLevel() { - final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); - // Log at FATAL level - setLoggerLevel(Level.FATAL); - - int expectedTotalEventsCapturedAtFatal = 1; - logger.fatal(CAPTURED); - - int expectedTotalEventsCapturedAtError = 0; - logger.error(NOT_CAPTURED); - - int expectedTotalEventsCapturedAtWarn = 0; - logger.warn(NOT_CAPTURED); - - int expectedTotalEventsCapturedAtInfo = 0; - logger.info(NOT_CAPTURED); - - int expectedTotalEventsCapturedAtDebug = 0; - logger.debug(NOT_CAPTURED); - - int expectedTotalEventsCapturedAtTrace = 0; - logger.trace(NOT_CAPTURED); - - int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + - expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + - expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + - expectedTotalEventsCapturedAtTrace; - - Collection logEvents = introspector.getLogEvents(); - - assertEquals(expectedTotalEventsCaptured, logEvents.size()); - - List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); - List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); - List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); - List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); - List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); - List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); - - assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); - } - - @Test - public void testLogEventsErrorLevel() { - final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); - // Log at ERROR level - setLoggerLevel(Level.ERROR); - - int expectedTotalEventsCapturedAtFatal = 1; - logger.fatal(CAPTURED); - - int expectedTotalEventsCapturedAtError = 1; - logger.error(CAPTURED); - - int expectedTotalEventsCapturedAtWarn = 0; - logger.warn(NOT_CAPTURED); - - int expectedTotalEventsCapturedAtInfo = 0; - logger.info(NOT_CAPTURED); - - int expectedTotalEventsCapturedAtDebug = 0; - logger.debug(NOT_CAPTURED); - - int expectedTotalEventsCapturedAtTrace = 0; - logger.trace(NOT_CAPTURED); - - int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + - expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + - expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + - expectedTotalEventsCapturedAtTrace; - - Collection logEvents = introspector.getLogEvents(); - - assertEquals(expectedTotalEventsCaptured, logEvents.size()); - - List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); - List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); - List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); - List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); - List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); - List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); - - assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); - } - - @Test - public void testLogEventsWarnLevel() { - final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); - // Log at WARN level - setLoggerLevel(Level.WARN); - - int expectedTotalEventsCapturedAtFatal = 1; - logger.fatal(CAPTURED); - - int expectedTotalEventsCapturedAtError = 1; - logger.error(CAPTURED); - - int expectedTotalEventsCapturedAtWarn = 1; - logger.warn(CAPTURED); - - int expectedTotalEventsCapturedAtInfo = 0; - logger.info(NOT_CAPTURED); - - int expectedTotalEventsCapturedAtDebug = 0; - logger.debug(NOT_CAPTURED); - - int expectedTotalEventsCapturedAtTrace = 0; - logger.trace(NOT_CAPTURED); - - int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + - expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + - expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + - expectedTotalEventsCapturedAtTrace; - - Collection logEvents = introspector.getLogEvents(); - - assertEquals(expectedTotalEventsCaptured, logEvents.size()); - - List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); - List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); - List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); - List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); - List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); - List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); - - assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); - } - - @Test - public void testLogEventsInfoLevel() { - final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); - // Log at INFO level - setLoggerLevel(Level.INFO); - - int expectedTotalEventsCapturedAtFatal = 1; - logger.fatal(CAPTURED); - - int expectedTotalEventsCapturedAtError = 1; - logger.error(CAPTURED); - - int expectedTotalEventsCapturedAtWarn = 1; - logger.warn(CAPTURED); - - int expectedTotalEventsCapturedAtInfo = 1; - logger.info(CAPTURED); - - int expectedTotalEventsCapturedAtDebug = 0; - logger.debug(NOT_CAPTURED); - - int expectedTotalEventsCapturedAtTrace = 0; - logger.trace(NOT_CAPTURED); - - int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + - expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + - expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + - expectedTotalEventsCapturedAtTrace; - - Collection logEvents = introspector.getLogEvents(); - - assertEquals(expectedTotalEventsCaptured, logEvents.size()); - - List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); - List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); - List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); - List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); - List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); - List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); - - assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); - } - - @Test - public void testLogEventsDebugLevel() { - final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); - // Log at DEBUG level - setLoggerLevel(Level.DEBUG); - - int expectedTotalEventsCapturedAtFatal = 1; - logger.fatal(CAPTURED); - - int expectedTotalEventsCapturedAtError = 1; - logger.error(CAPTURED); - - int expectedTotalEventsCapturedAtWarn = 1; - logger.warn(CAPTURED); - - int expectedTotalEventsCapturedAtInfo = 1; - logger.info(CAPTURED); - - int expectedTotalEventsCapturedAtDebug = 1; - logger.debug(CAPTURED); - - int expectedTotalEventsCapturedAtTrace = 0; - logger.trace(NOT_CAPTURED); - - int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + - expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + - expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + - expectedTotalEventsCapturedAtTrace; - - Collection logEvents = introspector.getLogEvents(); - - assertEquals(expectedTotalEventsCaptured, logEvents.size()); - - List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); - List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); - List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); - List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); - List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); - List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); - - assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); - } - - @Test - public void testLogEventsTraceLevel() { - final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); - // Log at TRACE level - setLoggerLevel(Level.TRACE); - - int expectedTotalEventsCapturedAtFatal = 1; - logger.fatal(CAPTURED); - - int expectedTotalEventsCapturedAtError = 1; - logger.error(CAPTURED); - - int expectedTotalEventsCapturedAtWarn = 1; - logger.warn(CAPTURED); - - int expectedTotalEventsCapturedAtInfo = 1; - logger.info(CAPTURED); - - int expectedTotalEventsCapturedAtDebug = 1; - logger.debug(CAPTURED); - - int expectedTotalEventsCapturedAtTrace = 1; - logger.trace(CAPTURED); - - int expectedTotalEventsCaptured = expectedTotalEventsCapturedAtFatal + - expectedTotalEventsCapturedAtError + expectedTotalEventsCapturedAtWarn + - expectedTotalEventsCapturedAtInfo + expectedTotalEventsCapturedAtDebug + - expectedTotalEventsCapturedAtTrace; - - Collection logEvents = introspector.getLogEvents(); - - assertEquals(expectedTotalEventsCaptured, logEvents.size()); - - List fatalLevelLogEvents = getFatalLevelLogEvents(logEvents); - List errorLevelLogEvents = getErrorLevelLogEvents(logEvents); - List warnLevelLogEvents = getWarnLevelLogEvents(logEvents); - List infoLevelLogEvents = getInfoLevelLogEvents(logEvents); - List debugLevelLogEvents = getDebugLevelLogEvents(logEvents); - List traceLevelLogEvents = getTraceLevelLogEvents(logEvents); - - assertEquals(expectedTotalEventsCapturedAtFatal, fatalLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtError, errorLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtWarn, warnLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtInfo, infoLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtDebug, debugLevelLogEvents.size()); - assertEquals(expectedTotalEventsCapturedAtTrace, traceLevelLogEvents.size()); - } - - private List getTraceLevelLogEvents(Collection logEvents) { - return logEvents.stream() - .filter(logEvent -> logEvent.getUserAttributesCopy().containsValue(Level.TRACE.toString())) - .collect(Collectors.toList()); - } - - private List getDebugLevelLogEvents(Collection logEvents) { - return logEvents.stream() - .filter(logEvent -> logEvent.getUserAttributesCopy().containsValue(Level.DEBUG.toString())) - .collect(Collectors.toList()); - } - - private List getInfoLevelLogEvents(Collection logEvents) { - return logEvents.stream() - .filter(logEvent -> logEvent.getUserAttributesCopy().containsValue(Level.INFO.toString())) - .collect(Collectors.toList()); - } - - private List getWarnLevelLogEvents(Collection logEvents) { - return logEvents.stream() - .filter(logEvent -> logEvent.getUserAttributesCopy().containsValue(Level.WARN.toString())) - .collect(Collectors.toList()); - } - - private List getErrorLevelLogEvents(Collection logEvents) { - return logEvents.stream() - .filter(logEvent -> logEvent.getUserAttributesCopy().containsValue(Level.ERROR.toString())) - .collect(Collectors.toList()); - } - - private List getFatalLevelLogEvents(Collection logEvents) { - return logEvents.stream() - .filter(logEvent -> logEvent.getUserAttributesCopy().containsValue(Level.FATAL.toString())) - .collect(Collectors.toList()); - } - - @Test - public void shouldIncrementEmittedLogsCountersIndependentlyIfLogLevelEnabled() { - // Given - final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); - setLoggerLevel(Level.INFO); - - // When - logger.trace(NOT_CAPTURED); - logger.debug(NOT_CAPTURED); - logger.info(CAPTURED); - logger.info(CAPTURED); - logger.info(CAPTURED); - logger.warn(CAPTURED); - logger.warn(CAPTURED); - logger.warn(CAPTURED); - logger.warn(CAPTURED); - logger.error(CAPTURED); - - // Then - Assert.assertEquals(8, MetricsHelper.getUnscopedMetricCount("Logging/lines")); - Assert.assertEquals(0, MetricsHelper.getUnscopedMetricCount("Logging/lines/TRACE")); - Assert.assertEquals(0, MetricsHelper.getUnscopedMetricCount("Logging/lines/DEBUG")); - Assert.assertEquals(3, MetricsHelper.getUnscopedMetricCount("Logging/lines/INFO")); - Assert.assertEquals(4, MetricsHelper.getUnscopedMetricCount("Logging/lines/WARN")); - Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/ERROR")); - } - - @Test - public void shouldIncrementAllEmittedLogCountersIfLogLevelIsSetToTrace() { - // Given - final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); - setLoggerLevel(Level.TRACE); - - // When - logger.trace(CAPTURED); - logger.debug(CAPTURED); - logger.info(CAPTURED); - logger.warn(CAPTURED); - logger.error(CAPTURED); - - // Then - Assert.assertEquals(5, MetricsHelper.getUnscopedMetricCount("Logging/lines")); - Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/TRACE")); - Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/DEBUG")); - Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/INFO")); - Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/WARN")); - Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/ERROR")); - } - - @Test - public void shouldIncrementAllEmittedLogCountersOnlyOnceWhenMultipleLoggersAreSet() { - // Given - createLogger("A_SPECIAL_LOGGER", createAppender("ConsoleAppender"), Level.TRACE, true); - final Logger logger = LogManager.getLogger("A_SPECIAL_LOGGER"); - setLoggerLevel(Level.TRACE); - - // When - logger.trace(CAPTURED); - logger.debug(CAPTURED); - logger.info(CAPTURED); - logger.warn(CAPTURED); - logger.error(CAPTURED); - - // Then - Assert.assertEquals(5, MetricsHelper.getUnscopedMetricCount("Logging/lines")); - Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/TRACE")); - Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/DEBUG")); - Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/INFO")); - Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/WARN")); - Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/ERROR")); - } - - @Test - public void shouldIncrementAllEmittedLogCountersRespectingLevelFromOriginalLogger() { - // Given - createLogger("A_SPECIAL_LOGGER", createAppender("ConsoleAppender"), Level.INFO, true); - final Logger logger = LogManager.getLogger("A_SPECIAL_LOGGER"); - setLoggerLevel(Level.ERROR); - - // When - logger.trace(NOT_CAPTURED); - logger.debug(NOT_CAPTURED); - logger.info(CAPTURED); - logger.warn(CAPTURED); - logger.error(CAPTURED); - - // Then - Assert.assertEquals(3, MetricsHelper.getUnscopedMetricCount("Logging/lines")); - Assert.assertEquals(0, MetricsHelper.getUnscopedMetricCount("Logging/lines/TRACE")); - Assert.assertEquals(0, MetricsHelper.getUnscopedMetricCount("Logging/lines/DEBUG")); - Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/INFO")); - Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/WARN")); - Assert.assertEquals(1, MetricsHelper.getUnscopedMetricCount("Logging/lines/ERROR")); - } - - private void createLogger(String name, Appender appender, Level level, boolean additivity) { - final LoggerContext ctx = (LoggerContext) LogManager.getContext(false); - final Configuration config = ctx.getConfiguration(); - AppenderRef ref = AppenderRef.createAppenderRef("File", null, null); - AppenderRef[] refs = new AppenderRef[] { ref }; - LoggerConfig loggerConfig = LoggerConfig.createLogger(additivity, level, name, "true", refs, null, config, null); - loggerConfig.addAppender(appender, level, null); - config.addLogger(name, loggerConfig); - } - - private Appender createAppender(String name) { - Layout layout = PatternLayout.newBuilder() - .withPattern(PatternLayout.SIMPLE_CONVERSION_PATTERN) - .build(); - Appender appender = ConsoleAppender.newBuilder() - .setName(name) - .setLayout(layout) - .build(); - appender.start(); - return appender; - } - - private void setLoggerLevel(Level level) { - final LoggerContext context = (LoggerContext) LogManager.getContext(false); - final Configuration configuration = context.getConfiguration(); - final LoggerConfig rootConfig = configuration.getLoggerConfig(LogManager.ROOT_LOGGER_NAME); - rootConfig.setLevel(level); - context.updateLoggers(); - } - - @Test - public void contextDataDisabledTest() { - final Logger logger = LogManager.getLogger(LoggerConfig_InstrumentationTest.class); - ThreadContext.put("include", "42"); - ThreadContext.put("exclude", "panic"); - - logger.error("message"); - - Collection logEvents = introspector.getLogEvents(); - assertEquals(1, logEvents.size()); - - // verify no context attrs - Map attributes = logEvents.iterator().next().getUserAttributesCopy(); - long contextAttrCount = attributes.keySet().stream() - .filter(key -> key.startsWith("context.")) - .count(); - assertEquals(0L, contextAttrCount); - } - -} diff --git a/instrumentation/apache-log4j-2.15/src/test/resources/application_logging_context_data_enabled.yml b/instrumentation/apache-log4j-2.15/src/test/resources/application_logging_context_data_enabled.yml deleted file mode 100644 index 1212edc2e9..0000000000 --- a/instrumentation/apache-log4j-2.15/src/test/resources/application_logging_context_data_enabled.yml +++ /dev/null @@ -1,12 +0,0 @@ -common: &default_settings - application_logging: - enabled: true - forwarding: - enabled: true - max_samples_stored: 10000 - context_data: - enabled: true - metrics: - enabled: true - local_decorating: - enabled: false diff --git a/instrumentation/apache-log4j-2.15/src/test/resources/application_logging_enabled.yml b/instrumentation/apache-log4j-2.15/src/test/resources/application_logging_enabled.yml deleted file mode 100644 index 583ffd2bba..0000000000 --- a/instrumentation/apache-log4j-2.15/src/test/resources/application_logging_enabled.yml +++ /dev/null @@ -1,10 +0,0 @@ -common: &default_settings - application_logging: - enabled: true - forwarding: - enabled: true - max_samples_stored: 10000 - metrics: - enabled: true - local_decorating: - enabled: false diff --git a/instrumentation/apache-log4j-2/build.gradle b/instrumentation/apache-log4j-2/build.gradle index 2042aee68b..31449fbb0e 100644 --- a/instrumentation/apache-log4j-2/build.gradle +++ b/instrumentation/apache-log4j-2/build.gradle @@ -4,7 +4,7 @@ jar { dependencies { implementation(project(":agent-bridge")) - implementation("org.apache.logging.log4j:log4j-core:2.17.1") + implementation("org.apache.logging.log4j:log4j-core:2.20.0") } verifyInstrumentation { diff --git a/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java b/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java index adcef6a0b2..8bc9061d6b 100644 --- a/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java +++ b/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java @@ -14,7 +14,6 @@ import org.apache.logging.log4j.Level; import org.apache.logging.log4j.core.LogEvent; import org.apache.logging.log4j.message.Message; -import org.apache.logging.log4j.util.ReadOnlyStringMap; import java.util.HashMap; import java.util.Map; @@ -128,4 +127,35 @@ private static int calculateInitialMapSize(ReadOnlyStringMap mdcPropertyMap) { ? mdcPropertyMap.size() + DEFAULT_NUM_OF_LOG_EVENT_ATTRIBUTES : DEFAULT_NUM_OF_LOG_EVENT_ATTRIBUTES; } + + /** + * Checks a pretty and compact JSON strings for a series of characters and returns the index of + * the characters or -1 if they were not found. This is used to find the log "message" substring + * so that the NR-LINKING metadata blob can be inserted when using local decorating with JsonLayout. + * + * @param writerString String representing JSON formatted log event + * @return positive int if index was found, else -1 + */ + public static int getIndexToModifyJson(String writerString) { + int indexOfMessage = writerString.indexOf("message"); + // Pretty JSON format + int indexToModifyJson = writerString.indexOf("\",\n", indexOfMessage); + if (!foundIndexToInsertLinkingMetadata(indexToModifyJson)) { + // Compact JSON format + indexToModifyJson = writerString.indexOf("\",", indexOfMessage); + } + return indexToModifyJson; + } + + /** + * Check if a valid match was found when calling String.indexOf. + * If index value is -1 then no valid match was found, a positive integer represents a valid index. + * + * @param indexToModifyJson int representing index returned by indexOf + * @return true if a valid index was found, else false + */ + public static boolean foundIndexToInsertLinkingMetadata(int indexToModifyJson) { + return indexToModifyJson != -1; + } + } diff --git a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java new file mode 100644 index 0000000000..d6c696b45f --- /dev/null +++ b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java @@ -0,0 +1,51 @@ +/* + * + * * Copyright 2023 New Relic Corporation. All rights reserved. + * * SPDX-License-Identifier: Apache-2.0 + * + */ + +package org.apache.logging.log4j.core.layout; + +import com.newrelic.api.agent.weaver.MatchType; +import com.newrelic.api.agent.weaver.Weave; +import com.newrelic.api.agent.weaver.Weaver; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.util.StringBuilderWriter; + +import java.io.IOException; +import java.io.Writer; + +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.BLOB_PREFIX; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.getLinkingMetadataBlob; +import static com.nr.agent.instrumentation.log4j2.AgentUtil.foundIndexToInsertLinkingMetadata; +import static com.nr.agent.instrumentation.log4j2.AgentUtil.getIndexToModifyJson; + +@Weave(originalName = "org.apache.logging.log4j.core.layout.AbstractJacksonLayout", type = MatchType.ExactClass) +abstract class AbstractJacksonLayout_Instrumentation { + + public void toSerializable(final LogEvent event, final Writer writer) throws IOException { + Weaver.callOriginal(); + } + + public String toSerializable(final LogEvent event) { + final StringBuilderWriter writer = new StringBuilderWriter(); + try { + toSerializable(event, writer); + String writerString = writer.toString(); + String modified = writerString; + // It is possible that the log might already have NR-LINKING metadata from JUL instrumentation + if (!writerString.contains(BLOB_PREFIX)) { + int indexToModifyJson = getIndexToModifyJson(writerString); + if (foundIndexToInsertLinkingMetadata(indexToModifyJson)) { + // Replace the JSON string with modified version that includes NR-LINKING metadata + modified = new StringBuilder(writerString).insert(indexToModifyJson, getLinkingMetadataBlob()).toString(); + } + } + return modified; + } catch (final IOException e) { + return Weaver.callOriginal(); + } + } + +} diff --git a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java deleted file mode 100644 index 16034ca258..0000000000 --- a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractStringLayout_Instrumentation.java +++ /dev/null @@ -1,48 +0,0 @@ -/* - * - * * Copyright 2023 New Relic Corporation. All rights reserved. - * * SPDX-License-Identifier: Apache-2.0 - * - */ - -package org.apache.logging.log4j.core.layout; - -import com.newrelic.api.agent.weaver.MatchType; -import com.newrelic.api.agent.weaver.Weave; -import com.newrelic.api.agent.weaver.Weaver; -import org.apache.logging.log4j.core.util.StringEncoder; - -import java.io.UnsupportedEncodingException; -import java.nio.charset.Charset; - -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.BLOB_PREFIX; -import static com.newrelic.agent.bridge.logging.AppLoggingUtils.getLinkingMetadataBlob; - -@Weave(originalName = "org.apache.logging.log4j.core.layout.AbstractStringLayout", type = MatchType.ExactClass) -public abstract class AbstractStringLayout_Instrumentation { - - private transient Charset charset = Weaver.callOriginal(); - private final String charsetName = Weaver.callOriginal(); - private final boolean useCustomEncoding = Weaver.callOriginal(); - - protected byte[] getBytes(final String s) { - String modified = s; - // It is possible that the log might already have NR-LINKING metadata from JUL instrumentation - if (!s.contains(BLOB_PREFIX)) { - // Finds the index of the closing parenthesis for a substring that begins with "message" and ends with the sequence ",\n - // Example JSON substring: "message":"Tomcat initialized",\n - int indexToInsertNrLinkingMetadata = s.indexOf("\",\n", s.indexOf("message")); - // Replace the JSON string with modified version that includes NR-LINKING metadata - modified = new StringBuilder(s).insert(indexToInsertNrLinkingMetadata, getLinkingMetadataBlob()).toString(); - } - if (useCustomEncoding) { - return StringEncoder.encodeSingleByteChars(modified); - } - try { - return modified.getBytes(charsetName); - } catch (final UnsupportedEncodingException e) { - return modified.getBytes(charset); - } - } - -} From 4ebba2a0d16f8c96714bedde085fcde18756aab1 Mon Sep 17 00:00:00 2001 From: jasonjkeller Date: Thu, 14 Sep 2023 12:21:28 -0700 Subject: [PATCH 10/14] Add support for local decorating when using log4j2 async appenders --- .../agent/bridge/logging/AppLoggingUtils.java | 27 ++++++- .../log4j/core/LogEvent_Instrumentation.java | 80 +++++++++++++++++++ ...AbstractJacksonLayout_Instrumentation.java | 37 ++++++--- 3 files changed, 130 insertions(+), 14 deletions(-) create mode 100644 instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/LogEvent_Instrumentation.java diff --git a/agent-bridge/src/main/java/com/newrelic/agent/bridge/logging/AppLoggingUtils.java b/agent-bridge/src/main/java/com/newrelic/agent/bridge/logging/AppLoggingUtils.java index d5cbf0f474..271f651134 100644 --- a/agent-bridge/src/main/java/com/newrelic/agent/bridge/logging/AppLoggingUtils.java +++ b/agent-bridge/src/main/java/com/newrelic/agent/bridge/logging/AppLoggingUtils.java @@ -6,8 +6,6 @@ */ package com.newrelic.agent.bridge.logging; -import com.newrelic.agent.bridge.logging.LogAttributeKey; -import com.newrelic.agent.bridge.logging.LogAttributeType; import com.newrelic.api.agent.NewRelic; import java.io.UnsupportedEncodingException; @@ -54,11 +52,32 @@ public class AppLoggingUtils { * @return agent linking metadata string blob */ public static String getLinkingMetadataBlob() { - Map agentLinkingMetadata = NewRelic.getAgent().getLinkingMetadata(); + return constructLinkingMetadataBlob(NewRelic.getAgent().getLinkingMetadata()); + } + + /** + * Gets a String representing the agent linking metadata in blob format: + * NR-LINKING|entity.guid|hostname|trace.id|span.id|entity.name| + * + * @param agentLinkingMetadata map of linking metadata + * @return agent linking metadata string blob + */ + public static String getLinkingMetadataBlobFromMap(Map agentLinkingMetadata) { + return constructLinkingMetadataBlob(agentLinkingMetadata); + } + + /** + * Constructs a String representing the agent linking metadata in blob format: + * NR-LINKING|entity.guid|hostname|trace.id|span.id|entity.name| + * + * @param agentLinkingMetadata map of linking metadata + * @return agent linking metadata string blob + */ + private static String constructLinkingMetadataBlob(Map agentLinkingMetadata) { StringBuilder blob = new StringBuilder(); blob.append(" ").append(BLOB_PREFIX).append(BLOB_DELIMITER); - if (agentLinkingMetadata != null && agentLinkingMetadata.size() > 0) { + if (agentLinkingMetadata != null && !agentLinkingMetadata.isEmpty()) { appendAttributeToBlob(agentLinkingMetadata.get(ENTITY_GUID), blob); appendAttributeToBlob(agentLinkingMetadata.get(HOSTNAME), blob); appendAttributeToBlob(agentLinkingMetadata.get(TRACE_ID), blob); diff --git a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/LogEvent_Instrumentation.java b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/LogEvent_Instrumentation.java new file mode 100644 index 0000000000..4c86c4b000 --- /dev/null +++ b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/LogEvent_Instrumentation.java @@ -0,0 +1,80 @@ +/* + * + * * Copyright 2023 New Relic Corporation. All rights reserved. + * * SPDX-License-Identifier: Apache-2.0 + * + */ + +package org.apache.logging.log4j.core; + +import com.newrelic.api.agent.NewRelic; +import com.newrelic.api.agent.weaver.MatchType; +import com.newrelic.api.agent.weaver.NewField; +import com.newrelic.api.agent.weaver.Weave; +import org.apache.logging.log4j.Level; +import org.apache.logging.log4j.Marker; +import org.apache.logging.log4j.ThreadContext; +import org.apache.logging.log4j.core.impl.ThrowableProxy; +import org.apache.logging.log4j.core.time.Instant; +import org.apache.logging.log4j.message.Message; +import org.apache.logging.log4j.util.ReadOnlyStringMap; + +import java.util.Map; + +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingLocalDecoratingEnabled; + +@Weave(originalName = "org.apache.logging.log4j.core.LogEvent", type = MatchType.Interface) +public abstract class LogEvent_Instrumentation { + + /* + * In cases where the LogEvent is sent to an AsyncAppender, getLinkingMetadata would get called on a new thread and the trace.id and span.id + * would be missing. To work around this we save the linking metadata on the LogEvent on the thread where it was created and use it later. + */ + @NewField + public Map agentLinkingMetadata = isApplicationLoggingLocalDecoratingEnabled() ? NewRelic.getAgent().getLinkingMetadata() : null; + + public abstract LogEvent toImmutable(); + + @Deprecated + public abstract Map getContextMap(); + + public abstract ReadOnlyStringMap getContextData(); + + public abstract ThreadContext.ContextStack getContextStack(); + + public abstract String getLoggerFqcn(); + + public abstract Level getLevel(); + + public abstract String getLoggerName(); + + public abstract Marker getMarker(); + + public abstract Message getMessage(); + + public abstract long getTimeMillis(); + + public abstract Instant getInstant(); + + public abstract StackTraceElement getSource(); + + public abstract String getThreadName(); + + public abstract long getThreadId(); + + public abstract int getThreadPriority(); + + public abstract Throwable getThrown(); + + public abstract ThrowableProxy getThrownProxy(); + + public abstract boolean isEndOfBatch(); + + public abstract boolean isIncludeLocation(); + + public abstract void setEndOfBatch(boolean endOfBatch); + + public abstract void setIncludeLocation(boolean locationRequired); + + public abstract long getNanoTime(); +} diff --git a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java index d6c696b45f..0eaacfecd9 100644 --- a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java +++ b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java @@ -10,7 +10,7 @@ import com.newrelic.api.agent.weaver.MatchType; import com.newrelic.api.agent.weaver.Weave; import com.newrelic.api.agent.weaver.Weaver; -import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.LogEvent_Instrumentation; import org.apache.logging.log4j.core.util.StringBuilderWriter; import java.io.IOException; @@ -18,31 +18,48 @@ import static com.newrelic.agent.bridge.logging.AppLoggingUtils.BLOB_PREFIX; import static com.newrelic.agent.bridge.logging.AppLoggingUtils.getLinkingMetadataBlob; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.getLinkingMetadataBlobFromMap; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingEnabled; +import static com.newrelic.agent.bridge.logging.AppLoggingUtils.isApplicationLoggingLocalDecoratingEnabled; import static com.nr.agent.instrumentation.log4j2.AgentUtil.foundIndexToInsertLinkingMetadata; import static com.nr.agent.instrumentation.log4j2.AgentUtil.getIndexToModifyJson; @Weave(originalName = "org.apache.logging.log4j.core.layout.AbstractJacksonLayout", type = MatchType.ExactClass) abstract class AbstractJacksonLayout_Instrumentation { - public void toSerializable(final LogEvent event, final Writer writer) throws IOException { + public void toSerializable(final LogEvent_Instrumentation event, final Writer writer) throws IOException { Weaver.callOriginal(); } - public String toSerializable(final LogEvent event) { + public String toSerializable(final LogEvent_Instrumentation event) { final StringBuilderWriter writer = new StringBuilderWriter(); try { toSerializable(event, writer); String writerString = writer.toString(); String modified = writerString; - // It is possible that the log might already have NR-LINKING metadata from JUL instrumentation - if (!writerString.contains(BLOB_PREFIX)) { - int indexToModifyJson = getIndexToModifyJson(writerString); - if (foundIndexToInsertLinkingMetadata(indexToModifyJson)) { - // Replace the JSON string with modified version that includes NR-LINKING metadata - modified = new StringBuilder(writerString).insert(indexToModifyJson, getLinkingMetadataBlob()).toString(); + + // Append linking metadata to the log message if local decorating is enabled + if (isApplicationLoggingEnabled() && isApplicationLoggingLocalDecoratingEnabled()) { + // It is possible that the log might already have NR-LINKING metadata from JUL instrumentation + if (!writerString.contains(BLOB_PREFIX)) { + int indexToModifyJson = getIndexToModifyJson(writerString); + if (foundIndexToInsertLinkingMetadata(indexToModifyJson)) { + // Replace the JSON string with modified version that includes NR-LINKING metadata + if (event != null && event.agentLinkingMetadata != null && (!event.agentLinkingMetadata.isEmpty())) { + // Get linking metadata stored on LogEvent if available. This ensures that + // the trace.id and span.id will be available when using an async appender. + modified = new StringBuilder(writerString).insert(indexToModifyJson, getLinkingMetadataBlobFromMap(event.agentLinkingMetadata)) + .toString(); + } else { + // Get linking metadata from current thread if it is not available on LogEvent. + modified = new StringBuilder(writerString).insert(indexToModifyJson, getLinkingMetadataBlob()).toString(); + } + } } + return modified; } - return modified; + + return writerString; } catch (final IOException e) { return Weaver.callOriginal(); } From 2dfa0f0b89e39a7892c74aa088647edbbb32578f Mon Sep 17 00:00:00 2001 From: jasonjkeller Date: Thu, 14 Sep 2023 12:23:40 -0700 Subject: [PATCH 11/14] Fix comment --- .../java/com/nr/agent/instrumentation/log4j2/AgentUtil.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java b/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java index 8bc9061d6b..66f1316c4b 100644 --- a/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java +++ b/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java @@ -129,7 +129,7 @@ private static int calculateInitialMapSize(ReadOnlyStringMap mdcPropertyMap) { } /** - * Checks a pretty and compact JSON strings for a series of characters and returns the index of + * Checks pretty or compact JSON layout strings for a series of characters and returns the index of * the characters or -1 if they were not found. This is used to find the log "message" substring * so that the NR-LINKING metadata blob can be inserted when using local decorating with JsonLayout. * From d82dc8dcd302a9c23beee8b28b597650efe3a872 Mon Sep 17 00:00:00 2001 From: jasonjkeller Date: Mon, 25 Sep 2023 16:28:59 -0700 Subject: [PATCH 12/14] Address PR feedback --- .../com/nr/agent/instrumentation/log4j2/AgentUtil.java | 9 +-------- .../layout/AbstractJacksonLayout_Instrumentation.java | 4 +--- 2 files changed, 2 insertions(+), 11 deletions(-) diff --git a/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java b/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java index 66f1316c4b..3ec612a9d7 100644 --- a/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java +++ b/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java @@ -137,14 +137,7 @@ private static int calculateInitialMapSize(ReadOnlyStringMap mdcPropertyMap) { * @return positive int if index was found, else -1 */ public static int getIndexToModifyJson(String writerString) { - int indexOfMessage = writerString.indexOf("message"); - // Pretty JSON format - int indexToModifyJson = writerString.indexOf("\",\n", indexOfMessage); - if (!foundIndexToInsertLinkingMetadata(indexToModifyJson)) { - // Compact JSON format - indexToModifyJson = writerString.indexOf("\",", indexOfMessage); - } - return indexToModifyJson; + return writerString.indexOf("\",", writerString.indexOf("message")); } /** diff --git a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java index 0eaacfecd9..d24a77cb4a 100644 --- a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java +++ b/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java @@ -27,9 +27,7 @@ @Weave(originalName = "org.apache.logging.log4j.core.layout.AbstractJacksonLayout", type = MatchType.ExactClass) abstract class AbstractJacksonLayout_Instrumentation { - public void toSerializable(final LogEvent_Instrumentation event, final Writer writer) throws IOException { - Weaver.callOriginal(); - } + public abstract void toSerializable(final LogEvent_Instrumentation event, final Writer writer) throws IOException; public String toSerializable(final LogEvent_Instrumentation event) { final StringBuilderWriter writer = new StringBuilderWriter(); From 2ea3563f20aba8486b782d781eb6140332826333 Mon Sep 17 00:00:00 2001 From: jasonjkeller Date: Fri, 20 Oct 2023 17:10:22 -0700 Subject: [PATCH 13/14] Fix some things --- instrumentation/apache-log4j-2/build.gradle | 2 +- .../java/com/nr/agent/instrumentation/log4j2/AgentUtil.java | 1 + 2 files changed, 2 insertions(+), 1 deletion(-) diff --git a/instrumentation/apache-log4j-2/build.gradle b/instrumentation/apache-log4j-2/build.gradle index 31449fbb0e..1ead670f8d 100644 --- a/instrumentation/apache-log4j-2/build.gradle +++ b/instrumentation/apache-log4j-2/build.gradle @@ -8,7 +8,7 @@ dependencies { } verifyInstrumentation { - passesOnly("org.apache.logging.log4j:log4j-core:[2.6,)") + passesOnly("org.apache.logging.log4j:log4j-core:[2.11.0,)") excludeRegex '.*(alpha|beta|rc).*' } diff --git a/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java b/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java index 3ec612a9d7..d288e4efec 100644 --- a/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java +++ b/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java @@ -14,6 +14,7 @@ import org.apache.logging.log4j.Level; import org.apache.logging.log4j.core.LogEvent; import org.apache.logging.log4j.message.Message; +import org.apache.logging.log4j.util.ReadOnlyStringMap; import java.util.HashMap; import java.util.Map; From 02f5527e09f905121b754b023d85539d13f3025f Mon Sep 17 00:00:00 2001 From: jasonjkeller Date: Tue, 31 Oct 2023 09:55:49 -0700 Subject: [PATCH 14/14] Rename apache-log4j-2 module to apache-log4j-2.11 --- .../apache-log4j-2.11/build.gradle | 23 +++++++++++++++++++ .../instrumentation/log4j2/AgentUtil.java | 2 +- .../instrumentation/log4j2/ExceptionUtil.java | 0 .../log4j/core/LogEvent_Instrumentation.java | 0 .../config/LoggerConfig_Instrumentation.java | 2 +- ...AbstractJacksonLayout_Instrumentation.java | 0 .../StringBuilderEncoder_Instrumentation.java | 0 .../log4j2/ContextDataTest.java | 0 .../log4j2/ExceptionUtilTest.java | 0 .../LoggerConfig_InstrumentationTest.java | 0 ...plication_logging_context_data_enabled.yml | 0 .../resources/application_logging_enabled.yml | 0 .../config/LoggerConfig_Instrumentation.java | 2 +- instrumentation/apache-log4j-2/build.gradle | 18 --------------- settings.gradle | 2 +- 15 files changed, 27 insertions(+), 22 deletions(-) create mode 100644 instrumentation/apache-log4j-2.11/build.gradle rename instrumentation/{apache-log4j-2 => apache-log4j-2.11}/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java (99%) rename instrumentation/{apache-log4j-2 => apache-log4j-2.11}/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java (100%) rename instrumentation/{apache-log4j-2 => apache-log4j-2.11}/src/main/java/org/apache/logging/log4j/core/LogEvent_Instrumentation.java (100%) rename instrumentation/{apache-log4j-2 => apache-log4j-2.11}/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java (99%) rename instrumentation/{apache-log4j-2 => apache-log4j-2.11}/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java (100%) rename instrumentation/{apache-log4j-2 => apache-log4j-2.11}/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java (100%) rename instrumentation/{apache-log4j-2 => apache-log4j-2.11}/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java (100%) rename instrumentation/{apache-log4j-2 => apache-log4j-2.11}/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java (100%) rename instrumentation/{apache-log4j-2 => apache-log4j-2.11}/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java (100%) rename instrumentation/{apache-log4j-2 => apache-log4j-2.11}/src/test/resources/application_logging_context_data_enabled.yml (100%) rename instrumentation/{apache-log4j-2 => apache-log4j-2.11}/src/test/resources/application_logging_enabled.yml (100%) delete mode 100644 instrumentation/apache-log4j-2/build.gradle diff --git a/instrumentation/apache-log4j-2.11/build.gradle b/instrumentation/apache-log4j-2.11/build.gradle new file mode 100644 index 0000000000..e84eff7c3d --- /dev/null +++ b/instrumentation/apache-log4j-2.11/build.gradle @@ -0,0 +1,23 @@ +jar { + manifest { + attributes 'Implementation-Title': 'com.newrelic.instrumentation.apache-log4j-2.11', + // The module was renamed to its current name from the name below. The alias exists so the instrumentation + // is still excluded/included for customers who have the old name in their configuration. + 'Implementation-Title-Alias': 'com.newrelic.instrumentation.apache-log4j-2' + } +} + +dependencies { + implementation(project(":agent-bridge")) + implementation("org.apache.logging.log4j:log4j-core:2.20.0") +} + +verifyInstrumentation { + passesOnly("org.apache.logging.log4j:log4j-core:[2.11.0,)") + excludeRegex '.*(alpha|beta|rc).*' +} + +site { + title 'Log4j2' + type 'Framework' +} diff --git a/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java b/instrumentation/apache-log4j-2.11/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java similarity index 99% rename from instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java rename to instrumentation/apache-log4j-2.11/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java index d288e4efec..91fe826e58 100644 --- a/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java +++ b/instrumentation/apache-log4j-2.11/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java @@ -47,7 +47,7 @@ public static void recordNewRelicLogEvent(LogEvent event) { if (shouldCreateLogEvent(message, throwable)) { ReadOnlyStringMap contextData = event.getContextData(); Map logEventMap = new HashMap<>(calculateInitialMapSize(contextData)); - logEventMap.put(INSTRUMENTATION, "apache-log4j-2"); + logEventMap.put(INSTRUMENTATION, "apache-log4j-2.11"); if (message != null) { String formattedMessage = message.getFormattedMessage(); if (formattedMessage != null && !formattedMessage.isEmpty()) { diff --git a/instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java b/instrumentation/apache-log4j-2.11/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java similarity index 100% rename from instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java rename to instrumentation/apache-log4j-2.11/src/main/java/com/nr/agent/instrumentation/log4j2/ExceptionUtil.java diff --git a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/LogEvent_Instrumentation.java b/instrumentation/apache-log4j-2.11/src/main/java/org/apache/logging/log4j/core/LogEvent_Instrumentation.java similarity index 100% rename from instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/LogEvent_Instrumentation.java rename to instrumentation/apache-log4j-2.11/src/main/java/org/apache/logging/log4j/core/LogEvent_Instrumentation.java diff --git a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java b/instrumentation/apache-log4j-2.11/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java similarity index 99% rename from instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java rename to instrumentation/apache-log4j-2.11/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java index 15f9df708c..f2ce9ae6d5 100644 --- a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java +++ b/instrumentation/apache-log4j-2.11/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java @@ -31,7 +31,7 @@ public class LoggerConfig_Instrumentation { public LoggerConfig_Instrumentation() { // Generate the instrumentation module supportability metric only once if (!instrumented.getAndSet(true)) { - NewRelic.incrementCounter("Supportability/Logging/Java/Log4j2/enabled"); + NewRelic.incrementCounter("Supportability/Logging/Java/Log4j2.11/enabled"); } } diff --git a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java b/instrumentation/apache-log4j-2.11/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java similarity index 100% rename from instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java rename to instrumentation/apache-log4j-2.11/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java diff --git a/instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java b/instrumentation/apache-log4j-2.11/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java similarity index 100% rename from instrumentation/apache-log4j-2/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java rename to instrumentation/apache-log4j-2.11/src/main/java/org/apache/logging/log4j/core/layout/StringBuilderEncoder_Instrumentation.java diff --git a/instrumentation/apache-log4j-2/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java b/instrumentation/apache-log4j-2.11/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java similarity index 100% rename from instrumentation/apache-log4j-2/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java rename to instrumentation/apache-log4j-2.11/src/test/java/com/nr/agent/instrumentation/log4j2/ContextDataTest.java diff --git a/instrumentation/apache-log4j-2/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java b/instrumentation/apache-log4j-2.11/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java similarity index 100% rename from instrumentation/apache-log4j-2/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java rename to instrumentation/apache-log4j-2.11/src/test/java/com/nr/agent/instrumentation/log4j2/ExceptionUtilTest.java diff --git a/instrumentation/apache-log4j-2/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java b/instrumentation/apache-log4j-2.11/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java similarity index 100% rename from instrumentation/apache-log4j-2/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java rename to instrumentation/apache-log4j-2.11/src/test/java/com/nr/agent/instrumentation/log4j2/LoggerConfig_InstrumentationTest.java diff --git a/instrumentation/apache-log4j-2/src/test/resources/application_logging_context_data_enabled.yml b/instrumentation/apache-log4j-2.11/src/test/resources/application_logging_context_data_enabled.yml similarity index 100% rename from instrumentation/apache-log4j-2/src/test/resources/application_logging_context_data_enabled.yml rename to instrumentation/apache-log4j-2.11/src/test/resources/application_logging_context_data_enabled.yml diff --git a/instrumentation/apache-log4j-2/src/test/resources/application_logging_enabled.yml b/instrumentation/apache-log4j-2.11/src/test/resources/application_logging_enabled.yml similarity index 100% rename from instrumentation/apache-log4j-2/src/test/resources/application_logging_enabled.yml rename to instrumentation/apache-log4j-2.11/src/test/resources/application_logging_enabled.yml diff --git a/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java b/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java index 15f9df708c..6f710031f9 100644 --- a/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java +++ b/instrumentation/apache-log4j-2.6/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java @@ -31,7 +31,7 @@ public class LoggerConfig_Instrumentation { public LoggerConfig_Instrumentation() { // Generate the instrumentation module supportability metric only once if (!instrumented.getAndSet(true)) { - NewRelic.incrementCounter("Supportability/Logging/Java/Log4j2/enabled"); + NewRelic.incrementCounter("Supportability/Logging/Java/Log4j2.6/enabled"); } } diff --git a/instrumentation/apache-log4j-2/build.gradle b/instrumentation/apache-log4j-2/build.gradle deleted file mode 100644 index 1ead670f8d..0000000000 --- a/instrumentation/apache-log4j-2/build.gradle +++ /dev/null @@ -1,18 +0,0 @@ -jar { - manifest { attributes 'Implementation-Title': 'com.newrelic.instrumentation.apache-log4j-2' } -} - -dependencies { - implementation(project(":agent-bridge")) - implementation("org.apache.logging.log4j:log4j-core:2.20.0") -} - -verifyInstrumentation { - passesOnly("org.apache.logging.log4j:log4j-core:[2.11.0,)") - excludeRegex '.*(alpha|beta|rc).*' -} - -site { - title 'Log4j2' - type 'Framework' -} diff --git a/settings.gradle b/settings.gradle index 8cfad13fb7..a8296a4664 100644 --- a/settings.gradle +++ b/settings.gradle @@ -87,7 +87,7 @@ include 'instrumentation:akka-http-core-10.0' include 'instrumentation:akka-http-core-10.2.0' include 'instrumentation:apache-log4j-1' include 'instrumentation:apache-log4j-2.6' -include 'instrumentation:apache-log4j-2' +include 'instrumentation:apache-log4j-2.11' include 'instrumentation:apache-struts-2.0' include 'instrumentation:async-http-client-2.0.0' include 'instrumentation:async-http-client-2.1.0'