open-telemetry
/
opentelemetry-java-instrumentation
mirror of https://github.com/open-telemetry/opentelemetry-java-instrumentation.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

Redo log capture instrumentation (#212) 

Make it clear that this is experimental option, as the specifics of log
capture will definitely change sometime in the future once there is an
agreed on OpenTelemetry spec for this.

Capture logs as spans, to avoid the limitations of current
implementation that captures them as events (no log capture when no
current span, and limited number of events per span).

Change the log instrumentation module names to just reflect the
underlying logger, e.g. "log4j-1.1" instead of "log4j-spans-1.1". This
way we don't end up with an entirely deprecated artifact once the
logging spec is worked out. The spans instrumentation now shares modules
with the MDC instrumentation, which I think is reasonable, as you pick
which one you want via configuration.
This commit is contained in:
Trask Stalnaker 2020-03-06 13:05:44 -08:00 committed by GitHub
parent 6b8edd52a3
commit ea74337c10
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
31 changed files with 272 additions and 251 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

30
agent-bootstrap/src/main/java/io/opentelemetry/auto/config/Config.java
View File

@ -71,8 +71,9 @@ public class Config {
public static final String RUNTIME_CONTEXT_FIELD_INJECTION =
"trace.runtime.context.field.injection";
public static final String LOGS_INJECTION_ENABLED = "logs.injection.enabled";
public static final String LOGS_EVENTS_THRESHOLD = "logs.events.threshold";
public static final String LOG_INJECTION_ENABLED = "log.injection.enabled";
public static final String EXPERIMENTAL_LOG_CAPTURE_THRESHOLD =
"experimental.log.capture.threshold";
private static final boolean DEFAULT_TRACE_ENABLED = true;
public static final boolean DEFAULT_INTEGRATIONS_ENABLED = true;
@ -89,7 +90,8 @@ public class Config {
private static final boolean DEFAULT_DB_CLIENT_HOST_SPLIT_BY_INSTANCE = false;
private static final int DEFAULT_SCOPE_DEPTH_LIMIT = 100;
public static final boolean DEFAULT_LOGS_INJECTION_ENABLED = false;
public static final boolean DEFAULT_LOG_INJECTION_ENABLED = false;
public static final String DEFAULT_EXPERIMENTAL_LOG_CAPTURE_THRESHOLD = null;
private static final String SPLIT_BY_SPACE_OR_COMMA_REGEX = "[,\\s]+";
@ -112,7 +114,7 @@ public class Config {
@Getter private final Integer scopeDepthLimit;
@Getter private final boolean runtimeContextFieldInjection;
@Getter private final boolean logsInjectionEnabled;
@Getter private final boolean logInjectionEnabled;
// mapping of threshold values to different logging frameworks:
//
@ -128,7 +130,7 @@ public class Config {
// | FINER | FINER | DEBUG | DEBUG |
// | TRACE/FINEST | FINEST | TRACE | TRACE |
// | ALL | ALL | ALL | ALL |
@Getter private final String logsEventsThreshold;
@Getter private final String experimentalLogCaptureThreshold;
@Getter private final String traceAnnotations;
@ -184,10 +186,12 @@ public class Config {
getBooleanSettingFromEnvironment(
RUNTIME_CONTEXT_FIELD_INJECTION, DEFAULT_RUNTIME_CONTEXT_FIELD_INJECTION);
logsInjectionEnabled =
getBooleanSettingFromEnvironment(LOGS_INJECTION_ENABLED, DEFAULT_LOGS_INJECTION_ENABLED);
logInjectionEnabled =
getBooleanSettingFromEnvironment(LOG_INJECTION_ENABLED, DEFAULT_LOG_INJECTION_ENABLED);
logsEventsThreshold = getSettingFromEnvironment(LOGS_EVENTS_THRESHOLD, null);
experimentalLogCaptureThreshold =
getSettingFromEnvironment(
EXPERIMENTAL_LOG_CAPTURE_THRESHOLD, DEFAULT_EXPERIMENTAL_LOG_CAPTURE_THRESHOLD);
traceAnnotations = getSettingFromEnvironment(TRACE_ANNOTATIONS, DEFAULT_TRACE_ANNOTATIONS);
@ -244,10 +248,12 @@ public class Config {
getPropertyBooleanValue(
properties, RUNTIME_CONTEXT_FIELD_INJECTION, parent.runtimeContextFieldInjection);
logsInjectionEnabled =
getPropertyBooleanValue(properties, LOGS_INJECTION_ENABLED, parent.logsInjectionEnabled);
logInjectionEnabled =
getPropertyBooleanValue(properties, LOG_INJECTION_ENABLED, parent.logInjectionEnabled);
logsEventsThreshold = properties.getProperty(LOGS_EVENTS_THRESHOLD, parent.logsEventsThreshold);
experimentalLogCaptureThreshold =
properties.getProperty(
EXPERIMENTAL_LOG_CAPTURE_THRESHOLD, parent.experimentalLogCaptureThreshold);
traceAnnotations = properties.getProperty(TRACE_ANNOTATIONS, parent.traceAnnotations);
@ -635,7 +641,7 @@ public class Config {
if (fileReader != null) {
try {
fileReader.close();
} catch (IOException ioe) {
} catch (final IOException ioe) {
log.error("Configuration file '{}' was not closed correctly.", configurationFilePath);
}
}

4
instrumentation/instrumentation.gradle
View File

@ -90,7 +90,7 @@ configurations {
}
// need to perform shading in two steps in order to avoid shading java.util.logging.Logger
// in the java-util-logging-events instrumentation since that instrumentation needs to
// in the java-util-logging instrumentation since that instrumentation needs to
// reference unshaded java.util.logging.Logger
// (java.util.logging.Logger shading is not needed in any of the instrumentation modules,
// but it is needed for the dependencies, e.g. guava, which use java.util.logging.Logger)
@ -102,7 +102,7 @@ task shadowJarStep1(type: com.github.jengelman.gradle.plugins.shadow.tasks.Shado
configurations = [project.configurations.runtime]
dependencies {
exclude(project(':instrumentation:java-util-logging-events'))
exclude(project(':instrumentation:java-util-logging'))
}
// rewrite dependencies calling Logger.getLogger

0
instrumentation/java-util-logging-events/java-util-logging-events.gradle → instrumentation/java-util-logging/java-util-logging.gradle
View File

25
instrumentation/java-util-logging-events/src/main/java/io/opentelemetry/auto/instrumentation/jul/JavaUtilLoggingEvents.java → instrumentation/java-util-logging/src/main/java/io/opentelemetry/auto/instrumentation/jul/JavaUtilLoggingSpans.java
View File

@ -22,8 +22,6 @@ import io.opentelemetry.trace.Span;
import io.opentelemetry.trace.Tracer;
import java.io.PrintWriter;
import java.io.StringWriter;
import java.util.HashMap;
import java.util.Map;
import java.util.logging.Formatter;
import java.util.logging.Level;
import java.util.logging.LogRecord;
@ -31,10 +29,10 @@ import java.util.logging.Logger;
import lombok.extern.slf4j.Slf4j;
@Slf4j
public class JavaUtilLoggingEvents {
public class JavaUtilLoggingSpans {
private static final Tracer TRACER =
OpenTelemetry.getTracerFactory().get("io.opentelemetry.auto.java-util-logging-events");
OpenTelemetry.getTracerFactory().get("io.opentelemetry.auto.java-util-logging");
private static final Formatter FORMATTER = new AccessibleFormatter();
@ -48,19 +46,16 @@ public class JavaUtilLoggingEvents {
if (level.intValue() < getThreshold().intValue()) {
return;
}
final Span currentSpan = TRACER.getCurrentSpan();
if (!currentSpan.getContext().isValid()) {
return;
}
final Throwable t = logRecord.getThrown();
final Map<String, AttributeValue> attributes = new HashMap<>(t == null ? 2 : 3);
attributes.put("level", newAttributeValue(level.getName()));
attributes.put("loggerName", newAttributeValue(logger.getName()));
final Span span = TRACER.spanBuilder("log.message").startSpan();
span.setAttribute("message", FORMATTER.formatMessage(logRecord));
span.setAttribute("level", level.getName());
span.setAttribute("loggerName", logger.getName());
if (t != null) {
attributes.put("error.stack", newAttributeValue(toString(t)));
span.setAttribute("error.stack", toString(t));
}
currentSpan.addEvent(FORMATTER.formatMessage(logRecord), attributes);
span.end();
}
private static AttributeValue newAttributeValue(final String stringValue) {
@ -74,7 +69,7 @@ public class JavaUtilLoggingEvents {
}
private static Level getThreshold() {
final String level = Config.get().getLogsEventsThreshold();
final String level = Config.get().getExperimentalLogCaptureThreshold();
if (level == null) {
return Level.OFF;
}
@ -103,7 +98,7 @@ public class JavaUtilLoggingEvents {
case "ALL":
return Level.ALL;
default:
log.error("unexpected value for {}: {}", Config.LOGS_EVENTS_THRESHOLD, level);
log.error("unexpected value for {}: {}", Config.EXPERIMENTAL_LOG_CAPTURE_THRESHOLD, level);
return Level.OFF;
}
}

14
instrumentation/java-util-logging-events/src/main/java/io/opentelemetry/auto/instrumentation/jul/JavaUtilLoggingEventInstrumentation.java → instrumentation/java-util-logging/src/main/java/io/opentelemetry/auto/instrumentation/jul/JavaUtilLoggingSpansInstrumentation.java
View File

@ -34,9 +34,9 @@ import net.bytebuddy.description.type.TypeDescription;
import net.bytebuddy.matcher.ElementMatcher;
@AutoService(Instrumenter.class)
public class JavaUtilLoggingEventInstrumentation extends Instrumenter.Default {
public JavaUtilLoggingEventInstrumentation() {
super("java-util-logging-events");
public class JavaUtilLoggingSpansInstrumentation extends Instrumenter.Default {
public JavaUtilLoggingSpansInstrumentation() {
super("java-util-logging");
}
@Override
@ -47,8 +47,8 @@ public class JavaUtilLoggingEventInstrumentation extends Instrumenter.Default {
@Override
public String[] helperClassNames() {
return new String[] {
packageName + ".JavaUtilLoggingEvents",
packageName + ".JavaUtilLoggingEvents$AccessibleFormatter"
packageName + ".JavaUtilLoggingSpans",
packageName + ".JavaUtilLoggingSpans$AccessibleFormatter"
};
}
@ -61,7 +61,7 @@ public class JavaUtilLoggingEventInstrumentation extends Instrumenter.Default {
.and(named("log"))
.and(takesArguments(1))
.and(takesArgument(0, named("java.util.logging.LogRecord"))),
JavaUtilLoggingEventInstrumentation.class.getName() + "$LogMessageAdvice");
JavaUtilLoggingSpansInstrumentation.class.getName() + "$LogMessageAdvice");
return transformers;
}
@ -70,7 +70,7 @@ public class JavaUtilLoggingEventInstrumentation extends Instrumenter.Default {
@Advice.OnMethodEnter(suppress = Throwable.class)
public static void methodEnter(
@Advice.This final Logger logger, @Advice.Argument(0) final LogRecord logRecord) {
JavaUtilLoggingEvents.capture(logger, logRecord);
JavaUtilLoggingSpans.capture(logger, logRecord);
}
}
}

2
instrumentation/java-util-logging-events/src/test/groovy/JavaUtilLoggingEventTest.groovy → instrumentation/java-util-logging/src/test/groovy/JavaUtilLoggingSpansTest.groovy
View File

@ -17,7 +17,7 @@ import io.opentelemetry.auto.test.log.events.LogEventsTestBase
import java.util.logging.Logger
class JavaUtilLoggingEventTest extends LogEventsTestBase {
class JavaUtilLoggingSpansTest extends LogEventsTestBase {
@Override
Object createLogger(String name) {

0
instrumentation/log4j-events-1.1/log4j-events-1.1.gradle → instrumentation/log4j-1.1/log4j-1.1.gradle
View File

44
instrumentation/log4j1/src/main/java/io/opentelemetry/auto/instrumentation/log4j1/Log4j1MDCInstrumentation.java → instrumentation/log4j-1.1/src/main/java/io/opentelemetry/auto/instrumentation/log4j/v1_1/Log4jMDCInstrumentation.java
View File

@ -1,12 +1,25 @@
package io.opentelemetry.auto.instrumentation.log4j1;
/*
* Copyright 2020, OpenTelemetry Authors
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package io.opentelemetry.auto.instrumentation.log4j.v1_1;
import static java.util.Collections.singletonMap;
import static net.bytebuddy.matcher.ElementMatchers.isConstructor;
import static net.bytebuddy.matcher.ElementMatchers.named;
import com.google.auto.service.AutoService;
import io.opentelemetry.auto.api.Config;
import io.opentelemetry.auto.api.GlobalTracer;
import io.opentelemetry.auto.config.Config;
import io.opentelemetry.auto.tooling.Instrumenter;
import io.opentelemetry.auto.tooling.log.LogContextScopeListener;
import java.lang.reflect.Method;
@ -16,17 +29,16 @@ import net.bytebuddy.description.method.MethodDescription;
import net.bytebuddy.description.type.TypeDescription;
import net.bytebuddy.matcher.ElementMatcher;
@AutoService(Instrumenter.class)
public class Log4j1MDCInstrumentation extends Instrumenter.Default {
public static final String MDC_INSTRUMENTATION_NAME = "log4j1";
public Log4j1MDCInstrumentation() {
super(MDC_INSTRUMENTATION_NAME);
// FIXME this instrumentation relied on scope listener
// @AutoService(Instrumenter.class)
public class Log4jMDCInstrumentation extends Instrumenter.Default {
public Log4jMDCInstrumentation() {
super("log4j");
}
@Override
protected boolean defaultEnabled() {
return Config.get().isLogsInjectionEnabled();
return Config.get().isLogInjectionEnabled();
}
@Override
@ -37,7 +49,7 @@ public class Log4j1MDCInstrumentation extends Instrumenter.Default {
@Override
public Map<? extends ElementMatcher<? super MethodDescription>, String> transformers() {
return singletonMap(
isConstructor(), Log4j1MDCInstrumentation.class.getName() + "$MDCContextAdvice");
isConstructor(), Log4jMDCInstrumentation.class.getName() + "$MDCContextAdvice");
}
@Override
@ -47,16 +59,18 @@ public class Log4j1MDCInstrumentation extends Instrumenter.Default {
public static class MDCContextAdvice {
@Advice.OnMethodExit(suppress = Throwable.class)
public static void mdcClassInitialized(@Advice.This Object instance) {
public static void mdcClassInitialized(@Advice.This final Object instance) {
if (instance == null) {
return;
}
try {
Class<?> mdcClass = instance.getClass();
final Class<?> mdcClass = instance.getClass();
final Method putMethod = mdcClass.getMethod("put", String.class, Object.class);
final Method removeMethod = mdcClass.getMethod("remove", String.class);
GlobalTracer.get().addScopeListener(new LogContextScopeListener(putMethod, removeMethod));
// FIXME this instrumentation relied on scope listener
// GlobalTracer.get().addScopeListener(new LogContextScopeListener(putMethod,
// removeMethod));
} catch (final NoSuchMethodException e) {
org.slf4j.LoggerFactory.getLogger(instance.getClass())
.debug("Failed to add log4j ThreadContext span listener", e);

27
instrumentation/log4j-events-1.1/src/main/java/io/opentelemetry/auto/instrumentation/log4jevents/Log4jEvents.java → instrumentation/log4j-1.1/src/main/java/io/opentelemetry/auto/instrumentation/log4j/v1_1/Log4jSpans.java
View File

@ -13,7 +13,7 @@
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package io.opentelemetry.auto.instrumentation.log4jevents;
package io.opentelemetry.auto.instrumentation.log4j.v1_1;
import io.opentelemetry.OpenTelemetry;
import io.opentelemetry.auto.config.Config;
@ -22,17 +22,15 @@ import io.opentelemetry.trace.Span;
import io.opentelemetry.trace.Tracer;
import java.io.PrintWriter;
import java.io.StringWriter;
import java.util.HashMap;
import java.util.Map;
import lombok.extern.slf4j.Slf4j;
import org.apache.log4j.Category;
import org.apache.log4j.Priority;
@Slf4j
public class Log4jEvents {
public class Log4jSpans {
private static final Tracer TRACER =
OpenTelemetry.getTracerFactory().get("io.opentelemetry.auto.log4j-events-1.1");
OpenTelemetry.getTracerFactory().get("io.opentelemetry.auto.log4j-1.1");
// these constants are copied from org.apache.log4j.Priority and org.apache.log4j.Level because
// Level was only introduced in 1.2, and then Level.TRACE was only introduced in 1.2.12
@ -51,18 +49,15 @@ public class Log4jEvents {
if (level.toInt() < getThreshold()) {
return;
}
final Span currentSpan = TRACER.getCurrentSpan();
if (!currentSpan.getContext().isValid()) {
return;
}
final Map<String, AttributeValue> attributes = new HashMap<>(t == null ? 2 : 3);
attributes.put("level", newAttributeValue(level.toString()));
attributes.put("loggerName", newAttributeValue(logger.getName()));
final Span span = TRACER.spanBuilder("log.message").startSpan();
span.setAttribute("message", String.valueOf(message));
span.setAttribute("level", level.toString());
span.setAttribute("loggerName", logger.getName());
if (t != null) {
attributes.put("error.stack", newAttributeValue(toString(t)));
span.setAttribute("error.stack", toString(t));
}
currentSpan.addEvent(String.valueOf(message), attributes);
span.end();
}
private static AttributeValue newAttributeValue(final String stringValue) {
@ -76,7 +71,7 @@ public class Log4jEvents {
}
private static int getThreshold() {
final String level = Config.get().getLogsEventsThreshold();
final String level = Config.get().getExperimentalLogCaptureThreshold();
if (level == null) {
return OFF_INT;
}
@ -104,7 +99,7 @@ public class Log4jEvents {
case "ALL":
return ALL_INT;
default:
log.error("unexpected value for {}: {}", Config.LOGS_EVENTS_THRESHOLD, level);
log.error("unexpected value for {}: {}", Config.EXPERIMENTAL_LOG_CAPTURE_THRESHOLD, level);
return OFF_INT;
}
}

14
instrumentation/log4j-events-1.1/src/main/java/io/opentelemetry/auto/instrumentation/log4jevents/Log4jEventInstrumentation.java → instrumentation/log4j-1.1/src/main/java/io/opentelemetry/auto/instrumentation/log4j/v1_1/Log4jSpansInstrumentation.java
View File

@ -13,7 +13,7 @@
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package io.opentelemetry.auto.instrumentation.log4jevents;
package io.opentelemetry.auto.instrumentation.log4j.v1_1;
import static net.bytebuddy.matcher.ElementMatchers.isMethod;
import static net.bytebuddy.matcher.ElementMatchers.isProtected;
@ -33,9 +33,9 @@ import org.apache.log4j.Category;
import org.apache.log4j.Priority;
@AutoService(Instrumenter.class)
public class Log4jEventInstrumentation extends Instrumenter.Default {
public Log4jEventInstrumentation() {
super("log4j-events");
public class Log4jSpansInstrumentation extends Instrumenter.Default {
public Log4jSpansInstrumentation() {
super("log4j");
}
@Override
@ -45,7 +45,7 @@ public class Log4jEventInstrumentation extends Instrumenter.Default {
@Override
public String[] helperClassNames() {
return new String[] {packageName + ".Log4jEvents"};
return new String[] {packageName + ".Log4jSpans"};
}
@Override
@ -60,7 +60,7 @@ public class Log4jEventInstrumentation extends Instrumenter.Default {
.and(takesArgument(1, named("org.apache.log4j.Priority")))
.and(takesArgument(2, named("java.lang.Object")))
.and(takesArgument(3, named("java.lang.Throwable"))),
Log4jEventInstrumentation.class.getName() + "$ForcedLogAdvice");
Log4jSpansInstrumentation.class.getName() + "$ForcedLogAdvice");
return transformers;
}
@ -72,7 +72,7 @@ public class Log4jEventInstrumentation extends Instrumenter.Default {
@Advice.Argument(1) final Priority level,
@Advice.Argument(2) final Object message,
@Advice.Argument(3) final Throwable t) {
Log4jEvents.capture(logger, level, message, t);
Log4jSpans.capture(logger, level, message, t);
}
}
}

40
instrumentation/log4j-1.1/src/test/groovy/Log4jMDCTest.groovy Normal file
View File

@ -0,0 +1,40 @@
/*
* Copyright 2020, OpenTelemetry Authors
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
import io.opentelemetry.auto.test.log.injection.LogContextInjectionTestBase
import org.apache.log4j.MDC
import org.junit.Ignore
import spock.lang.Requires
/**
It looks like log4j1 is broken for any java version that doesn't have '.' in version number
- it thinks it runs on ancient version. For example this happens for java13.
See {@link org.apache.log4j.helpers.Loader}.
*/
// FIXME this instrumentation relied on scope listener
@Ignore
@Requires({ System.getProperty("java.version").contains(".") })
class Log4jMDCTest extends LogContextInjectionTestBase {
@Override
def put(String key, Object value) {
return MDC.put(key, value)
}
@Override
def get(String key) {
return MDC.get(key)
}
}

2
instrumentation/log4j-events-1.1/src/test/groovy/Log4jEventTest.groovy → instrumentation/log4j-1.1/src/test/groovy/Log4jSpansTest.groovy
View File

@ -16,7 +16,7 @@
import io.opentelemetry.auto.test.log.events.LogEventsTestBase
import org.apache.log4j.Logger
class Log4jEventTest extends LogEventsTestBase {
class Log4jSpansTest extends LogEventsTestBase {
@Override
Object createLogger(String name) {

0
instrumentation/log4j-events-1.1/src/test/resources/log4j.properties → instrumentation/log4j-1.1/src/test/resources/log4j.properties
View File

0
instrumentation/log4j-events-2.0/log4j-events-2.0.gradle → instrumentation/log4j-2.0/log4j-2.0.gradle
View File

27
instrumentation/log4j-events-2.0/src/main/java/io/opentelemetry/auto/instrumentation/log4jevents/v2_0/Log4jEvents.java → instrumentation/log4j-2.0/src/main/java/io/opentelemetry/auto/instrumentation/log4j/v2_0/Log4jSpans.java
View File

@ -13,7 +13,7 @@
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package io.opentelemetry.auto.instrumentation.log4jevents.v2_0;
package io.opentelemetry.auto.instrumentation.log4j.v2_0;
import io.opentelemetry.OpenTelemetry;
import io.opentelemetry.auto.config.Config;
@ -22,18 +22,16 @@ import io.opentelemetry.trace.Span;
import io.opentelemetry.trace.Tracer;
import java.io.PrintWriter;
import java.io.StringWriter;
import java.util.HashMap;
import java.util.Map;
import lombok.extern.slf4j.Slf4j;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.message.Message;
@Slf4j
public class Log4jEvents {
public class Log4jSpans {
private static final Tracer TRACER =
OpenTelemetry.getTracerFactory().get("io.opentelemetry.auto.log4j-events-2.0");
OpenTelemetry.getTracerFactory().get("io.opentelemetry.auto.log4j-2.0");
public static void capture(
final Logger logger, final Level level, final Message message, final Throwable t) {
@ -41,18 +39,15 @@ public class Log4jEvents {
if (level.intLevel() > getThreshold().intLevel()) {
return;
}
final Span currentSpan = TRACER.getCurrentSpan();
if (!currentSpan.getContext().isValid()) {
return;
}
final Map<String, AttributeValue> attributes = new HashMap<>(t == null ? 2 : 3);
attributes.put("level", newAttributeValue(level.toString()));
attributes.put("loggerName", newAttributeValue(logger.getName()));
final Span span = TRACER.spanBuilder("log.message").startSpan();
span.setAttribute("message", message.getFormattedMessage());
span.setAttribute("level", level.toString());
span.setAttribute("loggerName", logger.getName());
if (t != null) {
attributes.put("error.stack", newAttributeValue(toString(t)));
span.setAttribute("error.stack", toString(t));
}
currentSpan.addEvent(message.getFormattedMessage(), attributes);
span.end();
}
private static AttributeValue newAttributeValue(final String stringValue) {
@ -66,7 +61,7 @@ public class Log4jEvents {
}
private static Level getThreshold() {
final String level = Config.get().getLogsEventsThreshold();
final String level = Config.get().getExperimentalLogCaptureThreshold();
if (level == null) {
return Level.OFF;
}
@ -94,7 +89,7 @@ public class Log4jEvents {
case "ALL":
return Level.ALL;
default:
log.error("unexpected value for {}: {}", Config.LOGS_EVENTS_THRESHOLD, level);
log.error("unexpected value for {}: {}", Config.EXPERIMENTAL_LOG_CAPTURE_THRESHOLD, level);
return Level.OFF;
}
}

18
instrumentation/log4j-events-2.0/src/main/java/io/opentelemetry/auto/instrumentation/log4jevents/v2_0/Log4jEventInstrumentation.java → instrumentation/log4j-2.0/src/main/java/io/opentelemetry/auto/instrumentation/log4j/v2_0/Log4jSpansInstrumentation.java
View File

@ -13,7 +13,7 @@
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package io.opentelemetry.auto.instrumentation.log4jevents.v2_0;
package io.opentelemetry.auto.instrumentation.log4j.v2_0;
import static io.opentelemetry.auto.tooling.bytebuddy.matcher.AgentElementMatchers.extendsClass;
import static net.bytebuddy.matcher.ElementMatchers.isMethod;
@ -36,9 +36,9 @@ import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.message.Message;
@AutoService(Instrumenter.class)
public class Log4jEventInstrumentation extends Instrumenter.Default {
public Log4jEventInstrumentation() {
super("log4j-events");
public class Log4jSpansInstrumentation extends Instrumenter.Default {
public Log4jSpansInstrumentation() {
super("log4j");
}
@Override
@ -48,7 +48,7 @@ public class Log4jEventInstrumentation extends Instrumenter.Default {
@Override
public String[] helperClassNames() {
return new String[] {packageName + ".Log4jEvents"};
return new String[] {packageName + ".Log4jSpans"};
}
@Override
@ -64,7 +64,7 @@ public class Log4jEventInstrumentation extends Instrumenter.Default {
.and(takesArgument(2, named("org.apache.logging.log4j.Marker")))
.and(takesArgument(3, named("org.apache.logging.log4j.message.Message")))
.and(takesArgument(4, named("java.lang.Throwable"))),
Log4jEventInstrumentation.class.getName() + "$LogMessageAdvice");
Log4jSpansInstrumentation.class.getName() + "$LogMessageAdvice");
// log4j 2.12.1 introduced and started using this new log() method
transformers.put(
isMethod()
@ -77,7 +77,7 @@ public class Log4jEventInstrumentation extends Instrumenter.Default {
.and(takesArgument(3, named("java.lang.StackTraceElement")))
.and(takesArgument(4, named("org.apache.logging.log4j.message.Message")))
.and(takesArgument(5, named("java.lang.Throwable"))),
Log4jEventInstrumentation.class.getName() + "$LogAdvice");
Log4jSpansInstrumentation.class.getName() + "$LogAdvice");
return transformers;
}
@ -89,7 +89,7 @@ public class Log4jEventInstrumentation extends Instrumenter.Default {
@Advice.Argument(1) final Level level,
@Advice.Argument(3) final Message message,
@Advice.Argument(4) final Throwable t) {
Log4jEvents.capture(logger, level, message, t);
Log4jSpans.capture(logger, level, message, t);
}
}
@ -101,7 +101,7 @@ public class Log4jEventInstrumentation extends Instrumenter.Default {
@Advice.Argument(0) final Level level,
@Advice.Argument(4) final Message message,
@Advice.Argument(5) final Throwable t) {
Log4jEvents.capture(logger, level, message, t);
Log4jSpans.capture(logger, level, message, t);
}
}
}

30
instrumentation/log4j2/src/main/java/io/opentelemetry/auto/instrumentation/log4j2/ThreadContextInstrumentation.java → instrumentation/log4j-2.0/src/main/java/io/opentelemetry/auto/instrumentation/log4j/v2_0/ThreadContextInstrumentation.java
View File

@ -1,12 +1,25 @@
package io.opentelemetry.auto.instrumentation.log4j2;
/*
* Copyright 2020, OpenTelemetry Authors
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package io.opentelemetry.auto.instrumentation.log4j.v2_0;
import static java.util.Collections.singletonMap;
import static net.bytebuddy.matcher.ElementMatchers.isTypeInitializer;
import static net.bytebuddy.matcher.ElementMatchers.named;
import com.google.auto.service.AutoService;
import io.opentelemetry.auto.api.Config;
import io.opentelemetry.auto.api.GlobalTracer;
import io.opentelemetry.auto.config.Config;
import io.opentelemetry.auto.tooling.Instrumenter;
import io.opentelemetry.auto.tooling.log.LogContextScopeListener;
import java.lang.reflect.Method;
@ -16,7 +29,8 @@ import net.bytebuddy.description.method.MethodDescription;
import net.bytebuddy.description.type.TypeDescription;
import net.bytebuddy.matcher.ElementMatcher;
@AutoService(Instrumenter.class)
// FIXME this instrumentation relied on scope listener
// @AutoService(Instrumenter.class)
public class ThreadContextInstrumentation extends Instrumenter.Default {
public static final String MDC_INSTRUMENTATION_NAME = "log4j";
@ -26,7 +40,7 @@ public class ThreadContextInstrumentation extends Instrumenter.Default {
@Override
protected boolean defaultEnabled() {
return Config.get().isLogsInjectionEnabled();
return Config.get().isLogInjectionEnabled();
}
@Override
@ -51,7 +65,9 @@ public class ThreadContextInstrumentation extends Instrumenter.Default {
try {
final Method putMethod = threadClass.getMethod("put", String.class, String.class);
final Method removeMethod = threadClass.getMethod("remove", String.class);
GlobalTracer.get().addScopeListener(new LogContextScopeListener(putMethod, removeMethod));
// FIXME this instrumentation relied on scope listener
// GlobalTracer.get().addScopeListener(new LogContextScopeListener(putMethod,
// removeMethod));
} catch (final NoSuchMethodException e) {
org.slf4j.LoggerFactory.getLogger(threadClass)
.debug("Failed to add log4j ThreadContext span listener", e);

4
instrumentation/log4j-events-2.0/src/test/groovy/Log4jEventTest.groovy → instrumentation/log4j-2.0/src/test/groovy/Log4jSpansTest.groovy
View File

@ -16,12 +16,12 @@
import io.opentelemetry.auto.test.log.events.LogEventsTestBase
import org.apache.logging.log4j.LogManager
class Log4jEventTest extends LogEventsTestBase {
class Log4jSpansTest extends LogEventsTestBase {
static {
// need to initialize logger before tests to flush out init warning message:
// "Unable to instantiate org.fusesource.jansi.WindowsAnsiOutputStream"
LogManager.getLogger(Log4jEventTest)
LogManager.getLogger(Log4jSpansTest)
}
@Override

33
instrumentation/log4j-2.0/src/test/groovy/Log4jThreadContextTest.groovy Normal file
View File

@ -0,0 +1,33 @@
/*
* Copyright 2020, OpenTelemetry Authors
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
import io.opentelemetry.auto.test.log.injection.LogContextInjectionTestBase
import org.apache.logging.log4j.ThreadContext
import org.junit.Ignore
// FIXME this instrumentation relied on scope listener
@Ignore
class Log4jThreadContextTest extends LogContextInjectionTestBase {
@Override
def put(String key, Object value) {
return ThreadContext.put(key, value as String)
}
@Override
def get(String key) {
return ThreadContext.get(key)
}
}

0
instrumentation/log4j-events-2.0/src/test/resources/log4j2.xml → instrumentation/log4j-2.0/src/test/resources/log4j2.xml
View File

27
instrumentation/log4j1/log4j1.gradle
View File

@ -1,27 +0,0 @@
apply from: "${rootDir}/gradle/java.gradle"
ext {
log4jVersion = '1.2.17'
}
muzzle {
pass {
group = 'log4j'
module = 'log4j'
versions = '(,)'
}
}
configurations {
// In order to test the real log4j library we need to remove the log4j transitive
// dependency 'log4j-over-slf4j' brought in by :testing which would shadow
// the log4j module under test using a proxy to slf4j instead.
testCompile.exclude group: 'org.slf4j', module: 'log4j-over-slf4j'
// See: https://stackoverflow.com/a/9047963/2749853
testCompile.exclude group: 'javax.jms', module: 'jms'
}
dependencies {
testCompile group: 'log4j', name: 'log4j', version: log4jVersion
}

22
instrumentation/log4j1/src/test/groovy/Log4j1MDCTest.groovy
View File

@ -1,22 +0,0 @@
import io.opentelemetry.auto.test.log.injection.LogContextInjectionTestBase
import org.apache.log4j.MDC
import spock.lang.Requires
/**
It looks like log4j1 is broken for any java version that doesn't have '.' in version number
- it thinks it runs on ancient version. For example this happens for java13.
See {@link org.apache.log4j.helpers.Loader}.
*/
@Requires({ System.getProperty("java.version").contains(".") })
class Log4j1MDCTest extends LogContextInjectionTestBase {
@Override
def put(String key, Object value) {
return MDC.put(key, value)
}
@Override
def get(String key) {
return MDC.get(key)
}
}

31
instrumentation/log4j2/log4j2.gradle
View File

@ -1,31 +0,0 @@
apply from: "${rootDir}/gradle/java.gradle"
ext {
log4jVersion = '2.11.2'
}
configurations {
// In order to test the real log4j library we need to remove the log4j transitive
// dependency 'log4j-over-slf4j' brought in by :testing which would shadow
// the log4j module under test using a proxy to slf4j instead.
testCompile.exclude group: 'org.slf4j', module: 'log4j-over-slf4j'
}
muzzle {
pass {
group = 'org.apache.logging.log4j'
module = 'log4j-core'
versions = '(,)'
}
pass {
group = 'org.apache.logging.log4j'
module = 'log4j-api'
versions = '(,)'
}
}
dependencies {
testCompile group: 'org.apache.logging.log4j', name: 'log4j-core', version: log4jVersion
testCompile group: 'org.apache.logging.log4j', name: 'log4j-api', version: log4jVersion
}

15
instrumentation/log4j2/src/test/groovy/Log4jThreadContextTest.groovy
View File

@ -1,15 +0,0 @@
import io.opentelemetry.auto.test.log.injection.LogContextInjectionTestBase
import org.apache.logging.log4j.ThreadContext
class Log4jThreadContextTest extends LogContextInjectionTestBase {
@Override
def put(String key, Object value) {
return ThreadContext.put(key, value as String)
}
@Override
def get(String key) {
return ThreadContext.get(key)
}
}

0
instrumentation/logback-events-1.0/logback-events-1.0.gradle → instrumentation/logback-1.0/logback-1.0.gradle
View File

24
instrumentation/logback-events-1.0/src/main/java/io/opentelemetry/auto/instrumentation/logbackevents/LogbackEvents.java → instrumentation/logback-1.0/src/main/java/io/opentelemetry/auto/instrumentation/logback/LogbackSpans.java
View File

@ -13,7 +13,7 @@
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package io.opentelemetry.auto.instrumentation.logbackevents;
package io.opentelemetry.auto.instrumentation.logback;
import io.opentelemetry.OpenTelemetry;
import io.opentelemetry.auto.config.Config;
@ -22,15 +22,13 @@ import io.opentelemetry.trace.Span;
import io.opentelemetry.trace.Tracer;
import java.io.PrintWriter;
import java.io.StringWriter;
import java.util.HashMap;
import java.util.Map;
import lombok.extern.slf4j.Slf4j;
import unshaded.ch.qos.logback.classic.Level;
import unshaded.ch.qos.logback.classic.spi.ILoggingEvent;
import unshaded.ch.qos.logback.classic.spi.ThrowableProxy;
@Slf4j
public class LogbackEvents {
public class LogbackSpans {
private static final Tracer TRACER =
OpenTelemetry.getTracerFactory().get("io.opentelemetry.auto");
@ -43,9 +41,6 @@ public class LogbackEvents {
return;
}
final Span currentSpan = TRACER.getCurrentSpan();
if (!currentSpan.getContext().isValid()) {
return;
}
final Object throwableProxy = event.getThrowableProxy();
Throwable t = null;
@ -55,13 +50,14 @@ public class LogbackEvents {
t = ((ThrowableProxy) throwableProxy).getThrowable();
}
final Map<String, AttributeValue> attributes = new HashMap<>(t == null ? 2 : 3);
attributes.put("level", newAttributeValue(level.toString()));
attributes.put("loggerName", newAttributeValue(event.getLoggerName()));
final Span span = TRACER.spanBuilder("log.message").startSpan();
span.setAttribute("message", event.getFormattedMessage());
span.setAttribute("level", level.toString());
span.setAttribute("loggerName", event.getLoggerName());
if (t != null) {
attributes.put("error.stack", newAttributeValue(toString(t)));
span.setAttribute("error.stack", toString(t));
}
currentSpan.addEvent(event.getFormattedMessage(), attributes);
span.end();
}
private static AttributeValue newAttributeValue(final String stringValue) {
@ -75,7 +71,7 @@ public class LogbackEvents {
}
private static Level getThreshold() {
final String level = Config.get().getLogsEventsThreshold();
final String level = Config.get().getExperimentalLogCaptureThreshold();
if (level == null) {
return Level.OFF;
}
@ -102,7 +98,7 @@ public class LogbackEvents {
case "ALL":
return Level.ALL;
default:
log.error("unexpected value for {}: {}", Config.LOGS_EVENTS_THRESHOLD, level);
log.error("unexpected value for {}: {}", Config.EXPERIMENTAL_LOG_CAPTURE_THRESHOLD, level);
return Level.OFF;
}
}

14
instrumentation/logback-events-1.0/src/main/java/io/opentelemetry/auto/instrumentation/logbackevents/LogbackEventInstrumentation.java → instrumentation/logback-1.0/src/main/java/io/opentelemetry/auto/instrumentation/logback/LogbackSpansInstrumentation.java
View File

@ -13,7 +13,7 @@
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package io.opentelemetry.auto.instrumentation.logbackevents;
package io.opentelemetry.auto.instrumentation.logback;
import static net.bytebuddy.matcher.ElementMatchers.isMethod;
import static net.bytebuddy.matcher.ElementMatchers.isPublic;
@ -32,9 +32,9 @@ import net.bytebuddy.matcher.ElementMatcher;
import unshaded.ch.qos.logback.classic.spi.ILoggingEvent;
@AutoService(Instrumenter.class)
public class LogbackEventInstrumentation extends Instrumenter.Default {
public LogbackEventInstrumentation() {
super("logback-events");
public class LogbackSpansInstrumentation extends Instrumenter.Default {
public LogbackSpansInstrumentation() {
super("logback");
}
@Override
@ -44,7 +44,7 @@ public class LogbackEventInstrumentation extends Instrumenter.Default {
@Override
public String[] helperClassNames() {
return new String[] {packageName + ".LogbackEvents"};
return new String[] {packageName + ".LogbackSpans"};
}
@Override
@ -56,7 +56,7 @@ public class LogbackEventInstrumentation extends Instrumenter.Default {
.and(named("callAppenders"))
.and(takesArguments(1))
.and(takesArgument(0, named("unshaded.ch.qos.logback.classic.spi.ILoggingEvent"))),
LogbackEventInstrumentation.class.getName() + "$CallAppendersAdvice");
LogbackSpansInstrumentation.class.getName() + "$CallAppendersAdvice");
return transformers;
}
@ -64,7 +64,7 @@ public class LogbackEventInstrumentation extends Instrumenter.Default {
@Advice.OnMethodEnter(suppress = Throwable.class)
public static void methodEnter(@Advice.Argument(0) final ILoggingEvent event) {
LogbackEvents.capture(event);
LogbackSpans.capture(event);
}
}
}

2
instrumentation/logback-events-1.0/src/test/groovy/LogbackEventTest.groovy → instrumentation/logback-1.0/src/test/groovy/LogbackSpansTest.groovy
View File

@ -16,7 +16,7 @@
import io.opentelemetry.auto.test.log.events.LogEventsTestBase
import unshaded.ch.qos.logback.classic.LoggerContext
class LogbackEventTest extends LogEventsTestBase {
class LogbackSpansTest extends LogEventsTestBase {
@Override
Object createLogger(String name) {

2
instrumentation/slf4j-mdc/src/main/java/io/opentelemetry/auto/instrumentation/slf4j/mdc/MDCInjectionInstrumentation.java
View File

@ -32,7 +32,7 @@ public class MDCInjectionInstrumentation extends Instrumenter.Default {
@Override
protected boolean defaultEnabled() {
return Config.get().isLogsInjectionEnabled();
return Config.get().isLogInjectionEnabled();
}
@Override

12
settings.gradle
View File

@ -82,7 +82,7 @@ include ':instrumentation:java-concurrent:kotlin-testing'
include ':instrumentation:java-concurrent:scala-testing'
include ':instrumentation:java-concurrent:akka-testing'
include ':instrumentation:java-concurrent:akka-2.5-testing'
include ':instrumentation:java-util-logging-events'
include ':instrumentation:java-util-logging'
include ':instrumentation:jaxrs-1.0'
include ':instrumentation:jaxrs-2.0'
include ':instrumentation:jaxrs-2.0:jaxrs-2.0-jersey-2.0'
@ -101,13 +101,9 @@ include ':instrumentation:jsp-2.3'
include ':instrumentation:kafka-clients-0.11'
include ':instrumentation:kafka-streams-0.11'
include ':instrumentation:lettuce-5.0'
include ':instrumentation:log4j-events-1.1'
// FIXME this instrumentation relied on scope listener
// include ':instrumentation:log4j1'
include ':instrumentation:log4j-events-2.0'
// FIXME this instrumentation relied on scope listener
// include ':instrumentation:log4j2'
include ':instrumentation:logback-events-1.0'
include ':instrumentation:log4j-1.1'
include ':instrumentation:log4j-2.0'
include ':instrumentation:logback-1.0'
include ':instrumentation:mongo-3.1'
include ':instrumentation:mongo-3.7'
include ':instrumentation:mongo-async-3.3'

60
testing/src/main/groovy/io/opentelemetry/auto/test/log/events/LogEventsTestBase.groovy
View File

@ -15,10 +15,9 @@
*/
package io.opentelemetry.auto.test.log.events
import io.opentelemetry.OpenTelemetry
import io.opentelemetry.auto.config.Config
import io.opentelemetry.auto.test.AgentTestRunner
import io.opentelemetry.trace.Tracer
import spock.lang.Unroll
import static io.opentelemetry.auto.test.utils.ConfigUtils.withConfigOverride
@ -31,8 +30,6 @@ import static io.opentelemetry.auto.test.utils.TraceUtils.runUnderTrace
@Unroll
abstract class LogEventsTestBase extends AgentTestRunner {
final Tracer tracer = OpenTelemetry.getTracerFactory().get("io.opentelemetry.auto.test")
abstract Object createLogger(String name)
String warn() {
@ -47,27 +44,26 @@ abstract class LogEventsTestBase extends AgentTestRunner {
setup:
runUnderTrace("test") {
def logger = createLogger("abc")
withConfigOverride(Config.LOGS_EVENTS_THRESHOLD, "WARN") {
withConfigOverride(Config.EXPERIMENTAL_LOG_CAPTURE_THRESHOLD, "WARN") {
logger."$testMethod"("xyz")
}
}
expect:
assertTraces(1) {
trace(0, 1) {
trace(0, capture ? 2 : 1) {
span(0) {
operationName "test"
if (capture) {
event(0) {
eventName "xyz"
attributes {
"level" testMethod.toUpperCase()
"loggerName" "abc"
}
}
if (capture) {
span(1) {
operationName "log.message"
tags {
"message" "xyz"
"level" testMethod.toUpperCase()
"loggerName" "abc"
}
}
tags {
}
}
}
}
@ -78,4 +74,38 @@ abstract class LogEventsTestBase extends AgentTestRunner {
warn() | true
error() | true
}
def "capture #testMethod (#capture) as span when no current span"() {
when:
def logger = createLogger("abc")
withConfigOverride(Config.EXPERIMENTAL_LOG_CAPTURE_THRESHOLD, "WARN") {
logger."$testMethod"("xyz")
}
then:
if (capture) {
assertTraces(1) {
trace(0, 1) {
span(0) {
operationName "log.message"
tags {
"message" "xyz"
"level" testMethod.toUpperCase()
"loggerName" "abc"
}
}
}
}
} else {
Thread.sleep(500) // sleep a bit just to make sure no span is captured
assertTraces(0) {
}
}
where:
testMethod | capture
"info" | false
warn() | true
error() | true
}
}