apache / apache/camel-quarkus

Mixed up MDC values

Open
#6,926 2 comments 0 reactions 0 assignees View on GitHub
bug
Dominant language
Java
Stars
302
Forks
232
Avg merge
1d 20h
Merged PRs (30d)
114

Description

### Bug description

Hello,

we are migrating a camel 2.23 application to camel quarkus 4 - concrete:
Quarkus 3.8.6.redhat-00004
Apache Camel 4.4.0.redhat-00041
(we already tested with version 3.15.2.redhat-00003 / Camel 4.8.0 and behaviour is the same)

Our application creates a MDCUnitOfWork to get some additional data logged - see source below.
Each route gets triggered by a message received from rabbitMQ using Spring RabbitMQ component.

Now it happens that MDC values do not get cleared/replaced properly
and the logs show values from a different route - See screenshot line 1 and 3.
Root cause may be an issue with jboss logmanager and VertxMDC.

dependencies for logging:

```

org.jboss.slf4j
slf4j-jboss-logmanager

io.quarkiverse.loggingjson
quarkus-logging-json
3.1.0

```

```
public class CustomMDCUnitOfWork extends MDCUnitOfWork {

static final String MDC_KEY_SERVICE_ID = "zoo.service";
static final String MDC_KEY_TRACING_ID = "zoo.tracing_id";
static final String MDC_KEY_COMPANY_ID = "zoo.company";
static final String MDC_KEY_ROUTE_ID = "zoo.route";

private final String originalServiceId;
private final String originalTracingId;
private final String originalCompanyId;
private final String originalRouteId;

public CustomMDCUnitOfWork(final Exchange exchange) {
super(exchange,
exchange.getContext().getInflightRepository(),
exchange.getContext().getMDCLoggingKeysPattern(),
exchange.getContext().isAllowUseOriginalMessage(),
exchange.getContext().isUseBreadcrumb());

this.originalServiceId = MDC.get(MDC_KEY_SERVICE_ID);
this.originalTracingId = MDC.get(MDC_KEY_TRACING_ID);
this.originalCompanyId = MDC.get(MDC_KEY_COMPANY_ID);
this.originalRouteId = MDC.get(MDC_KEY_ROUTE_ID);

putMDCValues(exchange);
}

//did not override prepareMDC of base class to prevent fragile base class issues
protected void putMDCValues(final Exchange exchange) {
MDC.put(MDC_KEY_SERVICE_ID, LoggingUtils.findServiceId(exchange));
MDC.put(MDC_KEY_TRACING_ID, LoggingUtils.findTracingId(exchange));
MDC.put(MDC_KEY_COMPANY_ID, LoggingUtils.findCompanyId(exchange));
MDC.put(MDC_KEY_ROUTE_ID, LoggingUtils.findRouteId(exchange));
}

@Override
public UnitOfWork newInstance(final Exchange exchange) {
return new CustomMDCUnitOfWork(exchange);
}

@Override
public AsyncCallback beforeProcess(final Processor processor, final Exchange exchange, final AsyncCallback callback) {
putMDCValues(exchange);
return super.beforeProcess(processor, exchange, new CustomMDCCallback(callback));
}

@Override
public void clear() {
super.clear();

if (this.originalServiceId != null) {
MDC.put(MDC_KEY_SERVICE_ID, this.originalServiceId);
} else {
MDC.remove(MDC_KEY_SERVICE_ID);
}

if (this.originalTracingId != null) {
MDC.put(MDC_KEY_TRACING_ID, this.originalTracingId);
} else {
MDC.remove(MDC_KEY_TRACING_ID);
}

if (this.originalCompanyId != null) {
MDC.put(MDC_KEY_COMPANY_ID, this.originalCompanyId);
} else {
MDC.remove(MDC_KEY_COMPANY_ID);
}

if (this.originalRouteId != null) {
MDC.put(MDC_KEY_ROUTE_ID, this.originalRouteId);
} else {
MDC.remove(MDC_KEY_ROUTE_ID);
}
}

private static final class CustomMDCCallback implements AsyncCallback {

private final AsyncCallback delegate;
private final String serviceId;
private final String tracingId;
private final String companyId;
private final String routeId;

private CustomMDCCallback(AsyncCallback delegate) {
this.delegate = delegate;
this.serviceId = MDC.get(MDC_KEY_SERVICE_ID);
this.tracingId = MDC.get(MDC_KEY_TRACING_ID);
this.companyId = MDC.get(MDC_KEY_COMPANY_ID);
this.routeId = MDC.get(MDC_KEY_ROUTE_ID);
}

public void done(boolean doneSync) {
try {
if (!doneSync) {
if (serviceId != null) {
MDC.put(MDC_KEY_SERVICE_ID, serviceId);
}
if (tracingId != null) {
MDC.put(MDC_KEY_TRACING_ID, tracingId);
}
if (companyId != null) {
MDC.put(MDC_KEY_COMPANY_ID, companyId);
}
if (routeId != null) {
MDC.put(MDC_KEY_ROUTE_ID, routeId);
}
}
} finally {
delegate.done(doneSync);
}
}

@Override
public String toString() {
return delegate.toString();
}
}
}
```

```
@ApplicationScoped
public class CustomMDCUnitOfWorkFactory implements UnitOfWorkFactory {

@Override
public UnitOfWork createUnitOfWork(final Exchange exchange) {
return new CustomMDCUnitOfWork(exchange);
}

@Override
public void afterPropertiesConfigured(final CamelContext camelContext) {
//nothing to do
}
}
```

```
@ApplicationScoped
public class LoggingObserver {

private static final List FILTERED_KEYS = List.of(AUTHORIZATION_HEADER, OLINGO_ENDPOINT_HTTP_HEADERS);

private final Logger logger;

@Inject
public LoggingObserver(final Logger logger) {
this.logger = logger;
}

public void onExchangeSendingEvent(@Observes ExchangeSendingEvent exchangeSendingEvent) {
logger.info("start request to endpoint {} with headers {}", getEndpointString(exchangeSendingEvent.getEndpoint()),
getFilteredHeaders(exchangeSendingEvent.getExchange()));
}

public void onExchangeSentEvent(@Observes ExchangeSentEvent exchangeSentEvent) {
logger.info("request to endpoint {} finished in {}ms", getEndpointString(exchangeSentEvent.getEndpoint()), exchangeSentEvent.getTimeTaken());
}

private String getEndpointString(final Endpoint endpoint) {
return endpoint.toString();
}

private Map getFilteredHeaders(final Exchange exchange) {
final ExtendedCamelContext context = exchange.getContext().getCamelContextExtension();
final Map result = context.getHeadersMapFactory().newMap();
for (Map.Entry entry : exchange.getIn().getHeaders().entrySet()) {
final Map.Entry mapEntry = mapEntry(entry);
result.put(mapEntry.getKey(), mapEntry.getValue());
}
return result;
}

private Map.Entry mapEntry(final Map.Entry entry) {
if (FILTERED_KEYS.contains(entry.getKey())) {
return new AbstractMap.SimpleEntry<>(entry.getKey(), "");
} else {
return entry;
}
}
}
```

![Image](https://github.com/user-attachments/assets/be6e9cef-b1b2-4d9b-8df3-6a70d9a16419)

Contributor guide

No contributing guide indexed for this repository

Research direction

Start by tracing CustomMDCUnitOfWorkFactory and CustomMDCUnitOfWork around beforeProcess, clear, and CustomMDCCallback.done, then reproduce the issue with concurrent Spring RabbitMQ-triggered routes and the listed logging dependencies. Done means MDC values remain associated with the correct route and are cleared or restored without appearing in another route's logs.

Written by the indexing model from the issue text.

Assessment

Tech stack
java, rabbitmq
Domain
backend, observability-sre
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
25/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.