What Went Wrong with MDC-Based Logging in Grafana (and How We Fixed It)
Introduction
The purpose of this article is to demostrate how we reached our goal at adjusting our app logging with MDC (Mapped Diagnostic Context) to increase value when querying by custom fields in Grafana. This guide explores a robust implementation of MDC usage, a Filter class and an MDC interceptor to inject high-value metadata, such as trace.id, trace.user, and endpoint—into every log entry, We adjusted MDC-based log enrichment so that custom context fields are consistently available as queryable metadata in Loki when viewed through Grafana.
I'll dive into a critical edge case: handling unhandled runtime exceptions without duplicating logs. By excluding Error Dispatcher types and specific HTTP statuses, we ensure error context is preserved without the noise of redundant MVC redirects.
Additionally, we applied:
- JSON layouts for seamless log ingestion
- Threshold and level filters to separate INFO and DEBUG streams
-
A custom PostmarkAppender using markers
(e.g.
NOTIFY_DEV)
Whether you’re handling a standard NotFoundException via @ControllerAdvice or a silent runtime exception, this setup
ensures logs are structured, unique, and actionable.
Why MDC for logging enrichment
MDC (Mapped Diagnostic Context) is a thread-local key-value store provided by Logback that retains such data and makes them available for logging frameworks at any point.
We can add any useful key, such as trace.id or endpoint. The advantage here is structured logging. We can later trace any key-value and watch it as request is running./p> It's better to add "MDC.put("orderId", "99B-Z")" in a log like "logger.info("Order processed")", because we can make a query by orderId and get only related logs in Grafana, Kibana or other.
Note that MDC logging isn't the same as distributed tracing, it's related onlye to a specific thread. That's also why we must clear MDC content at request end. If not, the same thread may be used by another user causing unpredictable behaviour. Additionally MDC is only for small data, not e.g. full request bodies, and surely not for sensitive data like user's email, credit card numbers, session ids, jwt tokens.
Stages of MDC enrichment
Meaningful enrichment would require acting on pre-request and post-request phases. We can gather various information types, like user id, endpoint, errorCode, etc.
Servlet Filter for User info
First, we add a Servlet filter that enriches every incoming HTTP request with request-scoped diagnostic metadata using SLF4J’s MDC. The goal here is simple: Ensure every log line emitted during request processing can be correlated by user info. The earlier we setup MDC, the more coverage we achieve.
Remember that at this phase we haven't even reached Spring's DispatcherServlet, no request has been processed yet from our controllers. Filters run on Servlet container's environment, before we reach Spring MVC.
@Component
@Order(1)
@Slf4j
public class MdcRequestFilter implements Filter
{
@Override
public void init(FilterConfig filterConfig) throws ServletException
{
log.info("Initializing filter; {}", getClass().getSimpleName());
}
@Override
public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain)
throws IOException, ServletException
{
MDC.put("trace.id", UUID.randomUUID().toString());
Optional.ofNullable(SecurityContextHolder.getContext())
.map(SecurityContext::getAuthentication)
.map(Authentication::getName)
.ifPresent(user -> MDC.put("trace.user", user));
filterChain.doFilter(servletRequest, servletResponse);
}
@Override
public void destroy()
{
log.warn("Destructing filter; {}", this);
}
}
HandlerInterceptor for endpoint, request, happy/error case info
A new HandlerInteceptor can intercept requests before and after, so that we add more stuff to MDC.
- Before request is handled by controllers, we add endpoint information (preHandle method)
- After request is done, we add information like errorName, errorStatus, errorStackTrace, logType, responseStatus (afterCompletion method) ---> Or someone would expect so
@RequiredArgsConstructor
@Slf4j
@Component
public class MdcInterceptor implements HandlerInterceptor
{
@Override
public boolean preHandle(HttpServletRequest request,
HttpServletResponse response,
Object handler) throws Exception
{
MDC.put("endpoint", request.getMethod() + " " + request.getRequestURI());
return true;
}
@Override
public void afterCompletion(HttpServletRequest request,
HttpServletResponse response,
Object handler,
Exception ex) throws Exception
{
try
{
// Add info like error stuff, codes, statuses, etc - What seems normal to do:
MDC.put("errorName", ex.getClass().getSimpleName());
MDC.put("errorStackTrace", Arrays.toString( ex.getStackTrace()));
// ....
}
finally
{
MDC.clear();
}
}
}
Of course, we have to add it to our web config:
@Configuration
public class WebConfig implements WebMvcConfigurer
{
private final MdcInterceptor mdcInterceptor;
public WebConfig(MdcInterceptor mdcInterceptor) {
this.mdcInterceptor = mdcInterceptor;
}
@Override
public void addInterceptors(InterceptorRegistry registry) {
registry.addInterceptor(mdcInterceptor);
}
}
A simple helper to create our MDC information:
@Slf4j
@Component
public class MdcUtils
{
public void enrichErrorMDCAndLog(Exception exception, HttpStatus httpStatus)
{
MDC.put("errorName", exception.getClass().getSimpleName());
MDC.put("errorStatus", httpStatus.toString());
MDC.put("errorStackTrace", Arrays.toString( exception.getStackTrace()));
MDC.put("logType", "Issue");
log.error("");
MDC.clear();
}
}
The problem: Duplicate logs
As you have been hinted, adding logging in afterCompletion isn't straightforward. Specifically, it produces unexpectedly duplicated logs in some cases.
We now dive into a critical edge case: handling unhandled runtime exceptions without duplicating logs. By excluding Error Dispatcher types and specific HTTP statuses, we ensure error context is preserved without the noise of redundant MVC redirects.
Spring MVC error redirects
When a request is processed normally, Spring MVC uses DispatcherServlet to handle it. The request goes through handler mappings, interceptors, and the controller, and the response is returned. If an exception occurs, DispatcherServlet first attempts to handle it internally using registered HandlerExceptionResolvers (for example, @ExceptionHandler in @ControllerAdvice). If the exception is handled, no error dispatch occurs. Only when the exception is not handled does the servlet container trigger an ERROR dispatch, which results in a second invocation of DispatcherServlet with DispatcherType.ERROR, typically mapped to /error and handled by an ErrorController. In this case, interceptors and filters may be invoked again, depending on their configuration.
Centralized exception handling (ControllerAdvice)
Our ControllerAdvice handles only business exceptions:
@ControllerAdvice
public class ExceptionControllerAdvice {
@ExceptionHandler(BusinessException.class)
public ResponseEntity handle(BusinessException ex) {
ErrorResponse error = new ErrorResponse(
ex.getErrorCode(),
ex.getMessage()
);
enrichErrorMDCAndLog(ex, HttpStatus.BAD_REQUEST);
return new ResponseEntity<>(error, HttpStatus.BAD_REQUEST);
}
We've decided to not handle Exception or RuntimeException class for various reasons, mostly because of hiding real bugs.
So we don't handle every error possible, and thus DispatcherServlet doesn't delegate to ControllerAdvice but ErrorDispatcher. This leads to again triggering our Interceptor and error log is duplicated.
Additionally, after ControllerAdvice runs, Interceptors are still executed. But we already do MDC logging from inside our ControllerAdvice, so we can't allow our Interceptor to log again same error.
Solution
We added this for afterCompletion method:
@Override
public void afterCompletion(HttpServletRequest request,
HttpServletResponse response,
Object handler,
Exception ex) throws Exception
{
try
{
// In case of unhandled exception: Exclude Error Dispatcher to avoid duplicate logging (exception info already exists in response)
if (request.getDispatcherType().toString().equalsIgnoreCase(DispatcherType.REQUEST.toString())
&& response.getStatus() == HttpStatus.OK.value())
{
// If exception is not handled in ControllerAdvice, return 500 as general runtime exception
MDC.put("responseStatus", String.valueOf((ex != null) ? 500 : response.getStatus()));
if (ex != null)
{
mdcUtils.enrichErrorMDCAndLog(ex, HttpStatus.INTERNAL_SERVER_ERROR);
}
else
{
MDC.put("logType", "Activity");
log.info("");
}
}
}
finally
{
MDC.clear();
}
}
First, we have a guardian condition:
if (request.getDispatcherType().toString().equalsIgnoreCase(DispatcherType.REQUEST.toString())
&& response.getStatus() == HttpStatus.OK.value())
We don't let ErrorDispatcher and ERROR Dispatcher type, thrown by unhandled error.
We also allow only OK HttpStatus. If we allowed error statuses, then ControllerAdvice would send errors here, duplicating them. Remember, we already use enrichErrorMDCAndLog in ControllerAdvice to uniquely log business errors.
And how we log the unhandled error?
We use "Exception ex" information for REQUEST Dispatcher type.
Flow is: REQUEST type runs --> produces some exception --> ERROR type runs.
In REQUEST phase, we already can extract error info. We don't need to reach the ERROR phase. So, this line runs and we choose a generic message:
mdcUtils.enrichErrorMDCAndLog(ex, HttpStatus.INTERNAL_SERVER_ERROR);
In case of handled error, ex is null (because DispatcherServlet has already delegated to ControllerAdvice, doesn't care to create exceptions), so we just add some more MDC info.
To summarize
I've analyzed a not-so edge case we faced when we tried to apply MDC logging for Grafana. All were fine until we faced unexpected duplicate logs. Central exception handling also has a role in this - avoiding catching all exceptions creates our issue. The solution was to "hack" Spring Dispatchers' flows and afterCompletion method:
After Completion: Why we exclude Error Dispatcher types and error Http statuses?
Error Http Statuses: These are only thrown by ControllerAdvice. There we already handle (throw and log) business exceptions. If we include these in interceptor, we would have duplicate logs.
Error Dispatcher Type: This takes places only in unhandled exceptions, that we don’t handle (and shouldn’t) in ControllerAdvice, like some NPE or other. When such error appears, original flow returns with error, and MVC additionally decides to redirect error to an Error Dispatcher. The last thing would cause duplicate logs if we included it in interceptor. And how do we log the exception/error? We take advantage of original flow that carries error information. We just stop the additional Error Dispatcher interception that would duplicate the error log.