Skip to content
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

Provide the ability to log MDC data in access_log #27006

Merged
merged 1 commit into from
Aug 9, 2022

Conversation

pilhuhn
Copy link
Contributor

@pilhuhn pilhuhn commented Jul 28, 2022

A config entry in application.properties like:

quarkus.http.access-log.pattern="%h %l %u %t \"%r\" %s %b traceId=%{X,traceId}"

would end up in

2022-07-28 17:46:56,512 INFO [access_log] (executor-thread-2) "127.0.0.1 - hrupp 28/Jul/2022:17:46:56 +0200 "GET /api/policies/v1.0/policies HTTP/1.1" 404 - traceId=797e67544634cff6b25a7d6ab429e67e"

This is similar to #26339

Unfortunately the %{X,..} syntax in access log patterns is different from the %X{..} syntax for console logs.

cc @brunobat

@pilhuhn pilhuhn changed the title Provide the ability to log MDC data in access_log. Provide the ability to log MDC data in access_log Jul 28, 2022
@quarkus-bot
Copy link

quarkus-bot bot commented Jul 28, 2022

Thanks for your pull request!

The title of your pull request does not follow our editorial rules. Could you have a look?

  • title should not end up with dot

This message is automatically generated by a bot.

@quarkus-bot

This comment has been minimized.

@Override
public String readAttribute(RoutingContext exchange) {
Map<String, Object> mdcMap = exchange.vertx().getOrCreateContext().getLocal("io.quarkus.vertx.core.runtime.VertxMDC");
return (String) mdcMap.getOrDefault(dataKey, null);
Copy link
Contributor

@brunobat brunobat Aug 1, 2022

Choose a reason for hiding this comment

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

They will be there only if the open telemetry extension is used... I wonder if this can be implemented on it.
The tests will never pass without it.
See: io.quarkus.opentelemetry.runtime.tracing.binders.vertx.EventBusInstrumenterVertxTracer

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 know this is tricky. I was thinking this could go into the open-telemetry extension, but then [ExchangeAttributeBuilder](https://github.com/quarkusio/quarkus/pull/27006#diff-287774a4f1c3b110b81bac31ef5eafa4372d24c820feb95563288be11238b421) can't list it and I don't think there is something like a ServiceLoader mechanism available. Perhaps @stuartwdouglas knows?

Copy link
Contributor

@brunobat brunobat Aug 2, 2022

Choose a reason for hiding this comment

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

The service loader is available but probably not needed.
We can try to bind this ExchangeAttribute like we do for the vert.x hooks. See:

VertxOptionsConsumerBuildItem vertxTracingMetricsOptions(TracerRecorder recorder) {

Copy link
Contributor

Choose a reason for hiding this comment

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

I think you should use VertxMDC.INSTANCE directly if you need to pass a Vert.x context , as it was done here https://github.com/quarkusio/quarkus/blob/main/extensions/opentelemetry/opentelemetry/runtime/src/main/java/io/quarkus/opentelemetry/runtime/OpenTelemetryUtil.java#L99 or call MDC.get(dataKey)); since VertxMDC will be always there, and you can log everything in the MDC not only Otel stuff

Copy link
Contributor

Choose a reason for hiding this comment

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

The thing is that only OTEL might be adding stuff to the MDC now, but the Vertx MDC implementation is in Vertx, and not in the OTEL extension, so I would really make this agnostic, and use the Vertx MDC instead of attaching it to OTEL

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 think you should use VertxMDC.INSTANCE directly

Great suggestion. I wasn't aware of it, but that makes life easier for everyone.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

The thing is that only OTEL might be adding stuff to the MDC now, but the Vertx MDC implementation is in Vertx, and not in the OTEL extension, so I would really make this agnostic, and use the Vertx MDC instead of attaching it to OTEL

You are right. I am renaming this and also update documentation.

Copy link
Contributor

Choose a reason for hiding this comment

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

The weird thing will be to see empty traceId and spanIds when the OTel extension is not used

Copy link
Contributor Author

Choose a reason for hiding this comment

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

But that is also true for the console.log.format pictured here:

https://quarkus.io/guides/opentelemetry#create-the-configuration

Copy link
Contributor

Choose a reason for hiding this comment

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

yeah... it can probably be improved

@pilhuhn pilhuhn requested a review from luneo7 August 3, 2022 19:09
@brunobat
Copy link
Contributor

brunobat commented Aug 4, 2022

@pilhuhn can you please add a test?

gsmet
gsmet previously requested changes Aug 5, 2022
Copy link
Member

@gsmet gsmet left a comment

Choose a reason for hiding this comment

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

Please squash the commits. Thanks!

@pilhuhn pilhuhn force-pushed the access_log_mdc_data branch from 8940bc9 to 979883d Compare August 8, 2022 10:54
@pilhuhn pilhuhn requested review from gsmet and removed request for luneo7 August 8, 2022 11:12
@gsmet gsmet dismissed their stale review August 9, 2022 21:09

Addressed

@gsmet gsmet merged commit 50ed212 into quarkusio:main Aug 9, 2022
@quarkus-bot quarkus-bot bot added this to the 2.12 - main milestone Aug 9, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants