Skip to content

add initial logback-access-jetty-12 instrumentation #13927

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 11 commits into
base: main
Choose a base branch
from
Open
3 changes: 3 additions & 0 deletions .fossa.yml
Original file line number Diff line number Diff line change
Expand Up @@ -658,6 +658,9 @@ targets:
- type: gradle
path: ./
target: ':instrumentation:log4j:log4j-mdc-1.2:javaagent'
- type: gradle
path: ./
target: ':instrumentation:logback:logback-access-jetty-12.0:javaagent'
- type: gradle
path: ./
target: ':instrumentation:logback:logback-appender-1.0:javaagent'
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,47 @@
plugins {
id("otel.javaagent-instrumentation")
}

muzzle {
pass {
group.set("ch.qos.logback.access")
module.set("jetty12")
versions.set("[2.0.0,)")
assertInverse.set(true)
}
}

dependencies {
compileOnly("ch.qos.logback.access:jetty12") {
version {
strictly("2.0.0")
}
}
compileOnly("ch.qos.logback.access:logback-access-common:2.0.4")
compileOnly("org.slf4j:slf4j-api") {
version {
strictly("1.5.8")
}
}

if (findProperty("testLatestDeps") as Boolean) {
testImplementation("ch.qos.logback.access:jetty12:latest.release")
} else {
testImplementation("ch.qos.logback.access:jetty12") {
version {
strictly("2.0.0")
}
}
testImplementation("org.slf4j:slf4j-api") {
version {
strictly("1.7.36")
}
}
}

compileOnly(project(":javaagent-bootstrap"))
}

otelJava {
minJavaVersionSupported.set(JavaVersion.VERSION_17)
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,61 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/

package io.opentelemetry.javaagent.instrumentation.logback.access.jetty.v12_0;

import ch.qos.logback.access.common.spi.IAccessEvent;
import io.opentelemetry.api.logs.LogRecordBuilder;
import io.opentelemetry.api.logs.LoggerProvider;
import io.opentelemetry.api.logs.Severity;
import io.opentelemetry.semconv.ClientAttributes;
import io.opentelemetry.semconv.HttpAttributes;
import io.opentelemetry.semconv.ServerAttributes;
import io.opentelemetry.semconv.UrlAttributes;
import io.opentelemetry.semconv.UserAgentAttributes;
import java.net.URI;
import java.net.URISyntaxException;

public class AccessEventMapper {

public static final String ACCESS_EVENT_NAME = "access-event";

@SuppressWarnings({"MethodCanBeStatic", "EmptyCatch"})
// MethodCanBeStatic: This method should eventually refer to configs in this class. So it should
// not be static.
// EmptyCatch: for parsing URI, the input itself is actually one URI, so there is low chance the
// exception would be thrown. Even when it actually happened, there is not much we can do here.
private void mapLoggingEvent(LogRecordBuilder builder, IAccessEvent accessEvent) {
URI uri = null;
try {
uri = new URI(accessEvent.getRequest().getRequestURL().toString());
} catch (URISyntaxException ignored) {
}

builder
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'd imagine that setting the context with setContext(Context.current()) could also be useful here to allow for correlating traces and logs. Idk whether the context is available here.

.setSeverity(Severity.UNDEFINED_SEVERITY_NUMBER)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

undefined is the default, no need to explicitly set it

.setEventName(ACCESS_EVENT_NAME)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

does event name need to be speced?

.setAttribute(HttpAttributes.HTTP_REQUEST_METHOD, accessEvent.getMethod())
.setAttribute(
HttpAttributes.HTTP_RESPONSE_STATUS_CODE, Long.valueOf(accessEvent.getStatusCode()))
.setAttribute(ClientAttributes.CLIENT_ADDRESS, accessEvent.getRemoteAddr())
.setAttribute(ServerAttributes.SERVER_ADDRESS, accessEvent.getServerName())
.setAttribute(
UserAgentAttributes.USER_AGENT_ORIGINAL,
accessEvent.getRequestHeader("HTTP User-Agent"));
if (uri != null) {
builder
.setAttribute(UrlAttributes.URL_PATH, uri.getPath())
.setAttribute(UrlAttributes.URL_SCHEME, uri.getScheme());
}
Comment on lines +39 to +50
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Our convention is that by default we only emit attributes that have semantic conventions. Although these attributes are define in semantic conventions there are no conventions specifically for logs or access logs. @trask could you clarify whether such usage is ok or whether there should be a flag or whether this instrumentation should be disabled by default.
Assuming that using attributes from http server semantic conventions is acceptable here you should try to follow them. Have a look at HttpServerAttributesExtractor there are some nuances on how these attributes are filled. For example as defined in spec http.request.method should only contain know request methods and otherwise use _OTHER. Perhaps here we should also try to use HttpServerAttributesExtractor for collecting the attributes and implement the getter interfaces for extracting info from the logging event?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

there is an attempt to define access logs in semconv (open-telemetry/semantic-conventions#982), though I wouldn't follow the current draft state of it, and instead would follow @laurit's advice here to follow http semconv as much as possible

I suspect this should be disabled by default, since much of it is duplicative of the span data, and probably somewhat duplicative of the log data captured via the logback appender

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've been thinking about those comments for a while, and here are my two cents. Please feel free to correct me if I misunderstood anything.

I absolutely agree that we should aim to follow the semantic conventions as much as possible. However, I feel that strict adherence should mainly apply to the semantic convention names themselves. Since these are logs—not spans or metrics—the situation is a bit different. Only access logs are somewhat "structured," and they don’t have a true body, so we need to construct the log records from attributes.

If we adjust the attribute values to align too closely with the semantic conventions, I worry it might cause confusion. For example, take http.request.method: in the console, a method might be logged as XXX, and naturally, a user would search for XXX in the exported OpenTelemetry logs. But if they only see _OTHER instead, they may be confused—why doesn’t it match what was actually logged?

So my feeling is that we should treat the actual log content as the source of truth and avoid altering it too much just to conform to the semantic conventions.

Again, just my two cents—happy to be corrected if I'm off base. 🙇

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I absolutely agree that we should aim to follow the semantic conventions as much as possible. However, I feel that strict adherence should mainly apply to the semantic convention names themselves.

google defines the word semantic as relating to meaning in language or logic. They key part of semantic conventions is that besides a name they define a meaning for the attributes. To me assigning a different meaning to an attribute defined in the semantic conventions seems confusing.

If we adjust the attribute values to align too closely with the semantic conventions, I worry it might cause confusion. For example, take http.request.method: in the console, a method might be logged as XXX, and naturally, a user would search for XXX in the exported OpenTelemetry logs. But if they only see _OTHER instead, they may be confused—why doesn’t it match what was actually logged?

Semantic conventions define http.request.method_original for the original value of the request method.

So my feeling is that we should treat the actual log content as the source of truth and avoid altering it too much just to conform to the semantic conventions.

I think you should open a discussion in semantic conventions repo to get this clarified.

Copy link
Contributor Author

@cuichenli cuichenli Jun 10, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

google defines the word semantic as relating to meaning in language or logic. They key part of semantic conventions is that besides a name they define a meaning for the attributes. To me assigning a different meaning to an attribute defined in the semantic conventions seems confusing.

i think that makes sense. given we have attributes like http.request.method_original, do you think it is reasonable for this PR to start with some basic semantic convention attributes, which uses the original value would be sufficient? otherwise, the scope of this pr would be out of my expectation. thanks for your response

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

do you think it is reasonable for this PR to start with some basic semantic convention attributes

sure, though I'd still urge you to consider implementing HttpServerAttributesGetter and using HttpServerAttributesExtractor to do the attribute extraction. If that works you'd get the same attributes as the http server span.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'd still urge you to consider implementing HttpServerAttributesGetter and using HttpServerAttributesExtractor to do the attribute extraction.

Please feel free to correct me if I’m mistaken. My current understanding is that HttpServerAttributesGetter is tightly coupled with the Instrumenter class—so far, I haven't seen it used outside of that context. However, the Instrumenter class is specifically designed for spans (at least that is my understanding, still, it could be wrong), whereas we are dealing with logs. If we were to use it, it would result in new spans being created, which is not ideal, as they would duplicate the spans already generated by the jetty instrumentation.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

HttpServerAttributesGetter and HttpServerAttributesExtractor are not coupled with the Instrumenter and can be used without it. You could implement HttpServerAttributesGetter that extracts data and build a HttpServerAttributesExtractor with it. You can then call the onStart and onEnd methods on the extractor the same way Instrumenter does to get the attributes.

}

public void emit(LoggerProvider loggerProvider, IAccessEvent event) {
String instrumentationName = "ROOT";
LogRecordBuilder builder =
loggerProvider.loggerBuilder(instrumentationName).build().logRecordBuilder();
mapLoggingEvent(builder, event);
builder.emit();
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,58 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/

package io.opentelemetry.javaagent.instrumentation.logback.access.jetty.v12_0;

import static io.opentelemetry.javaagent.instrumentation.logback.access.jetty.v12_0.LogbackAccessSingletons.mapper;
import static net.bytebuddy.matcher.ElementMatchers.isMethod;
import static net.bytebuddy.matcher.ElementMatchers.isPublic;
import static net.bytebuddy.matcher.ElementMatchers.named;
import static net.bytebuddy.matcher.ElementMatchers.takesArguments;

import ch.qos.logback.access.common.spi.IAccessEvent;
import io.opentelemetry.api.GlobalOpenTelemetry;
import io.opentelemetry.api.logs.LoggerProvider;
import io.opentelemetry.javaagent.bootstrap.CallDepth;
import io.opentelemetry.javaagent.extension.instrumentation.TypeInstrumentation;
import io.opentelemetry.javaagent.extension.instrumentation.TypeTransformer;
import net.bytebuddy.asm.Advice;
import net.bytebuddy.description.type.TypeDescription;
import net.bytebuddy.matcher.ElementMatcher;

public class LogbackAccessInstrumentation implements TypeInstrumentation {
@Override
public ElementMatcher<TypeDescription> typeMatcher() {
return named("ch.qos.logback.core.spi.AppenderAttachableImpl");
}

@Override
public void transform(TypeTransformer transformer) {
transformer.applyAdviceToMethod(
isMethod().and(isPublic()).and(named("appendLoopOnAppenders")).and(takesArguments(1)),
LogbackAccessInstrumentation.class.getName() + "$CallAppendersAdvice");
}

@SuppressWarnings("unused")
public static class CallAppendersAdvice {

@Advice.OnMethodEnter(suppress = Throwable.class)
public static void methodEnter(
@Advice.Argument(0) Object o, @Advice.Local("otelCallDepth") CallDepth callDepth) {
if (o instanceof IAccessEvent event) {
// need to track call depth across all loggers in order to avoid double capture when one
// logging framework delegates to another
callDepth = CallDepth.forClass(LoggerProvider.class);
if (callDepth.getAndIncrement() == 0) {
mapper().emit(GlobalOpenTelemetry.get().getLogsBridge(), event);
}
}
}

@Advice.OnMethodExit(onThrowable = Throwable.class, suppress = Throwable.class)
public static void methodExit(@Advice.Local("otelCallDepth") CallDepth callDepth) {
callDepth.decrementAndGet();
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

there will be a NPE here when event isn't an instance of IAccessEvent

}
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,25 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/

package io.opentelemetry.javaagent.instrumentation.logback.access.jetty.v12_0;

import static java.util.Collections.singletonList;

import com.google.auto.service.AutoService;
import io.opentelemetry.javaagent.extension.instrumentation.InstrumentationModule;
import io.opentelemetry.javaagent.extension.instrumentation.TypeInstrumentation;
import java.util.List;

@AutoService(InstrumentationModule.class)
public class LogbackAccessInstrumentationModule extends InstrumentationModule {
public LogbackAccessInstrumentationModule() {
super("logback-access-jetty", "logback-access-jetty-12.0");
}

@Override
public List<TypeInstrumentation> typeInstrumentations() {
return singletonList(new LogbackAccessInstrumentation());
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,20 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/

package io.opentelemetry.javaagent.instrumentation.logback.access.jetty.v12_0;

public class LogbackAccessSingletons {
private static final AccessEventMapper mapper;

static {
mapper = new AccessEventMapper();
}

public static AccessEventMapper mapper() {
return mapper;
}

private LogbackAccessSingletons() {}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,77 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/

package io.opentelemetry.javaagent.instrumentation.logback.access.jetty.v12_0;

import ch.qos.logback.access.jetty.RequestLogImpl;
import java.nio.ByteBuffer;
import java.nio.charset.StandardCharsets;
import org.eclipse.jetty.http.HttpFields;
import org.eclipse.jetty.http.HttpHeader;
import org.eclipse.jetty.server.Handler;
import org.eclipse.jetty.server.Request;
import org.eclipse.jetty.server.Response;
import org.eclipse.jetty.server.Server;
import org.eclipse.jetty.util.Callback;

public class JettyServer {
protected final RequestLogImpl requestLogImpl;
protected Handler handler = new BasicHandler();
private final int port;
Server server;
protected String url;

public JettyServer(RequestLogImpl impl, int port) {
requestLogImpl = impl;
this.port = port;
url = "http://localhost:" + port + "/";
}

public String getName() {
return "Jetty Test Setup";
}

public String getUrl() {
return url;
}

public void start() throws Exception {
server = new Server(port);

server.setRequestLog(requestLogImpl);
configureRequestLogImpl();

server.setHandler(getRequestHandler());
server.start();
}

public void stop() throws Exception {
server.stop();
server = null;
}

protected void configureRequestLogImpl() {
requestLogImpl.start();
}

protected Handler getRequestHandler() {
return handler;
}

static class BasicHandler extends Handler.Wrapper {

@Override
public boolean handle(Request request, Response response, Callback callback) throws Exception {
HttpFields.Mutable responseHeaders = response.getHeaders();
responseHeaders.put(HttpHeader.CONTENT_TYPE, "text/plain; charset=UTF-8");

byte[] bytes = "hello world".getBytes(StandardCharsets.UTF_8);

ByteBuffer content = ByteBuffer.wrap(bytes);
response.write(true, content, callback);
return true;
}
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,82 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/

package io.opentelemetry.javaagent.instrumentation.logback.access.jetty.v12_0;

import static io.opentelemetry.javaagent.instrumentation.logback.access.jetty.v12_0.AccessEventMapper.ACCESS_EVENT_NAME;
import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.equalTo;
import static org.junit.jupiter.api.Assertions.assertEquals;

import ch.qos.logback.access.common.spi.Util;
import ch.qos.logback.access.jetty.RequestLogImpl;
import ch.qos.logback.core.testUtil.RandomUtil;
import io.opentelemetry.api.logs.Severity;
import io.opentelemetry.instrumentation.testing.junit.AgentInstrumentationExtension;
import io.opentelemetry.semconv.ClientAttributes;
import io.opentelemetry.semconv.HttpAttributes;
import io.opentelemetry.semconv.ServerAttributes;
import io.opentelemetry.semconv.UrlAttributes;
import io.opentelemetry.semconv.UserAgentAttributes;
import java.io.IOException;
import java.net.HttpURLConnection;
import java.net.URL;
import org.junit.jupiter.api.AfterEach;
import org.junit.jupiter.api.BeforeEach;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.extension.RegisterExtension;

class TestAccessLogWithJetty {

static RequestLogImpl requestLogImpl = new RequestLogImpl();
static JettyServer jettyFixture;
static String jettyFixtureUrlStr;

static final int RANDOM_SERVER_PORT = RandomUtil.getRandomServerPort();
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ideally you let the server bind to port 0 and later ask what was the actual port the os gave it. If that is not an option then use our PortUtils.findOpenPort(). RandomUtil.getRandomServerPort() just picks a random number, it may collide with a port that is used in some other test.


@BeforeEach
public void startServer() throws Exception {
requestLogImpl = new RequestLogImpl();
jettyFixture = new JettyServer(requestLogImpl, RANDOM_SERVER_PORT);
jettyFixture.start();
jettyFixtureUrlStr = jettyFixture.getUrl();
}

@AfterEach
public void stopServer() throws Exception {
if (jettyFixture != null) {
jettyFixture.stop();
}
}

@RegisterExtension
private static final AgentInstrumentationExtension testing =
AgentInstrumentationExtension.create();

@Test
void testT() throws IOException {
String path = "12312321";
URL url = new URL("http://localhost:" + RANDOM_SERVER_PORT + "/" + path);
HttpURLConnection connection = (HttpURLConnection) url.openConnection();
connection.setDoInput(true);

String result = Util.readToString(connection.getInputStream());

assertEquals("hello world", result);

testing.waitAndAssertLogRecords(
logRecord ->
logRecord
.hasEventName(ACCESS_EVENT_NAME)
.hasSeverity(Severity.UNDEFINED_SEVERITY_NUMBER)
.hasAttributesSatisfyingExactly(
equalTo(HttpAttributes.HTTP_REQUEST_METHOD, "GET"),
equalTo(HttpAttributes.HTTP_RESPONSE_STATUS_CODE, Long.valueOf(200)),
equalTo(ClientAttributes.CLIENT_ADDRESS, "127.0.0.1"),
equalTo(ServerAttributes.SERVER_ADDRESS, "localhost"),
equalTo(UserAgentAttributes.USER_AGENT_ORIGINAL, "-"),
equalTo(UrlAttributes.URL_PATH, "/" + path),
equalTo(UrlAttributes.URL_SCHEME, "http")));
}
}
1 change: 1 addition & 0 deletions settings.gradle.kts
Original file line number Diff line number Diff line change
Expand Up @@ -390,6 +390,7 @@ include(":instrumentation:log4j:log4j-context-data:log4j-context-data-2.17:javaa
include(":instrumentation:log4j:log4j-context-data:log4j-context-data-2.17:library-autoconfigure")
include(":instrumentation:log4j:log4j-context-data:log4j-context-data-common:testing")
include(":instrumentation:log4j:log4j-mdc-1.2:javaagent")
include(":instrumentation:logback:logback-access-jetty-12.0:javaagent")
include(":instrumentation:logback:logback-appender-1.0:javaagent")
include(":instrumentation:logback:logback-appender-1.0:library")
include(":instrumentation:logback:logback-mdc-1.0:javaagent")
Expand Down
Loading