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.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.11/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 new file mode 100644 index 0000000000..91fe826e58 --- /dev/null +++ b/instrumentation/apache-log4j-2.11/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java @@ -0,0 +1,155 @@ +/* + * + * * 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.11"); + 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; + } + + /** + * 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/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.11/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 new file mode 100644 index 0000000000..4c86c4b000 --- /dev/null +++ b/instrumentation/apache-log4j-2.11/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.11/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 new file mode 100644 index 0000000000..f2ce9ae6d5 --- /dev/null +++ b/instrumentation/apache-log4j-2.11/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.11/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.11/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 new file mode 100644 index 0000000000..d24a77cb4a --- /dev/null +++ b/instrumentation/apache-log4j-2.11/src/main/java/org/apache/logging/log4j/core/layout/AbstractJacksonLayout_Instrumentation.java @@ -0,0 +1,66 @@ +/* + * + * * 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_Instrumentation; +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.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 abstract void toSerializable(final LogEvent_Instrumentation event, final Writer writer) throws IOException; + + public String toSerializable(final LogEvent_Instrumentation 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 + 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 writerString; + } catch (final IOException e) { + return Weaver.callOriginal(); + } + } + +} 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 71% 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 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.11/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/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/build.gradle b/instrumentation/apache-log4j-2.6/build.gradle similarity index 51% rename from instrumentation/apache-log4j-2/build.gradle rename to instrumentation/apache-log4j-2.6/build.gradle index 2042aee68b..dff4ad111b 100644 --- a/instrumentation/apache-log4j-2/build.gradle +++ b/instrumentation/apache-log4j-2.6/build.gradle @@ -1,15 +1,14 @@ jar { - manifest { attributes 'Implementation-Title': 'com.newrelic.instrumentation.apache-log4j-2' } + manifest { attributes 'Implementation-Title': 'com.newrelic.instrumentation.apache-log4j-2.6' } } dependencies { implementation(project(":agent-bridge")) - implementation("org.apache.logging.log4j:log4j-core:2.17.1") + implementation("org.apache.logging.log4j:log4j-core:2.10.0") } verifyInstrumentation { - passesOnly("org.apache.logging.log4j:log4j-core:[2.6,)") - excludeRegex '.*(alpha|beta|rc).*' + passesOnly("org.apache.logging.log4j:log4j-core:[2.6,2.11.0)") } site { diff --git a/instrumentation/apache-log4j-2/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 similarity index 83% rename from instrumentation/apache-log4j-2/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java rename to instrumentation/apache-log4j-2.6/src/main/java/com/nr/agent/instrumentation/log4j2/AgentUtil.java index df8761d0fc..f29566deba 100644 --- a/instrumentation/apache-log4j-2/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 @@ -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; @@ -47,7 +46,7 @@ public static void recordNewRelicLogEvent(LogEvent event) { if (shouldCreateLogEvent(message, throwable)) { Map contextData = event.getContextMap(); Map logEventMap = new HashMap<>(calculateInitialMapSize(contextData)); - logEventMap.put(INSTRUMENTATION, "apache-log4j-2"); + logEventMap.put(INSTRUMENTATION, "apache-log4j-2.6"); if (message != null) { String formattedMessage = message.getFormattedMessage(); if (formattedMessage != null && !formattedMessage.isEmpty()) { @@ -128,4 +127,28 @@ private static int calculateInitialMapSize(Map mdcPropertyMap) { ? 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/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 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.6/src/main/java/org/apache/logging/log4j/core/config/LoggerConfig_Instrumentation.java index 15f9df708c..6f710031f9 100644 --- a/instrumentation/apache-log4j-2/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.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..608571e764 --- /dev/null +++ b/instrumentation/apache-log4j-2.6/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() { + 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); + Configurator.setLevel(name, level); + } + + 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/settings.gradle b/settings.gradle index 6cc9301bd7..8e1eeda8d8 100644 --- a/settings.gradle +++ b/settings.gradle @@ -86,7 +86,8 @@ 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' +include 'instrumentation:apache-log4j-2.6' +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'