In modern applications, encountering errors is inevitable, and developers often rely on server logs to investigate and resolve issues. Unfortunately, crucial details are sometimes missing, making debugging more challenging. To address this, comprehensive logging is essential, especially for tracking user actions and system changes.
This article explores how you can enhance trace logging in a Spring Boot application, particularly when using the Axon Framework in an event-driven architecture. The Axon Framework allows you to integrate and manage event logs efficiently, providing deeper insights into application behavior.
Setting Up a Default Logging Configuration
The first step is to configure the Mapped Diagnostic Context (MDC), which adds contextual information, such as a unique request ID and the username, to your logs. This ensures that logs are traceable and relevant.
Here’s how you can implement MDC in a Spring Boot filter:
@Slf4j
@Component
public class FilterConfig implements Filter {
public static final String REQUEST_ID = "X-Request-Id";
public static final String USER_ID = "X-User-Id";
@Override
public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
// Define a unique request id to identify each request
MDC.put(REQUEST_ID, UUID.randomUUID().toString());
// Retrieve the current username
MDC.put(USER_ID, getCurrentUsername());
// pass the request
chain.doFilter(request, response);
}
}
Please note that the method getCurrentUsername depends on your implementation and should be created by yourself, where you return the current user id or name to identify the user in your system, normally by using the Spring Boot Security Context.
Customize Logging Patterns
To include MDC attributes in your logs, update the application.yml file as follows:
logging:
pattern:
console: "%clr(TS=){faint}%clr(%d{yyyy-MM-dd\'T\'HH:mm:ss.SSS\'Z\', UTC}){faint} [%t] %clr(APP=){faint}%clr(${spring.application.name:null}){yellow} %clr(LEVEL=){faint}%clr(${LOG_LEVEL_PATTERN:%p}) %clr(CLASS=){faint}%clr(%logger{26}){cyan} %clr(USERID=){faint}%clr(%X{X-User-Id:-null}) %clr(REQUESTID=){faint}%clr(%X{X-Request-Id:-null}){reverse} | %m%n%ex"
Intercepting and Logging HTTP Requests
To log HTTP traffic, we’ll use interceptors and advice adapters to capture incoming requests and outgoing responses.
LogInterceptor for GET Requests
Here’s an interceptor that logs all GET requests to endpoints prefixed with /api:
@Slf4j
@Component
public class LogInterceptor implements HandlerInterceptor {
LoggingService loggingService;
public LogInterceptor(LoggingService loggingService) {
this.loggingService = loggingService;
}
@Override
public boolean preHandle(HttpServletRequest request,
HttpServletResponse response,
Object handler) {
if (DispatcherType.REQUEST.name().equals(request.getDispatcherType().name())
&& request.getMethod().equals(HttpMethod.GET.name())
// Only log requests to our API
&& request.getRequestURI().contains("/api/")
) {
loggingService.logRequest(request, null);
}
return true;
}
}
Log POST Requests and Responses
Use advice adapters to capture POST requests and their responses:
- Request Body Logging:
@ControllerAdvice
@AllArgsConstructor
public class CustomResponseBodyAdviceAdapter implements ResponseBodyAdvice {
private LoggingService loggingService;
@Override
public boolean supports(MethodParameter methodParameter,
Class<? extends HttpMessageConverter> aClass) {
return true;
}
@Override
public Object beforeBodyWrite(Object o,
@NotNull MethodParameter methodParameter,
@NotNull MediaType mediaType,
@NotNull Class<? extends HttpMessageConverter> aClass,
@NotNull ServerHttpRequest serverHttpRequest,
@NotNull ServerHttpResponse serverHttpResponse) {
if (serverHttpRequest instanceof ServletServerHttpRequest
- Response Body Logging:
@ControllerAdvice
@AllArgsConstructor
public class CustomResponseBodyAdviceAdapter implements ResponseBodyAdvice {
private LoggingService loggingService;
@Override
public boolean supports(MethodParameter methodParameter,
Class<? extends HttpMessageConverter> aClass) {
return true;
}
@Override
public Object beforeBodyWrite(Object o,
@NotNull MethodParameter methodParameter,
@NotNull MediaType mediaType,
@NotNull Class<? extends HttpMessageConverter> aClass,
@NotNull ServerHttpRequest serverHttpRequest,
@NotNull ServerHttpResponse serverHttpResponse) {
if (serverHttpRequest instanceof ServletServerHttpRequest request &&
serverHttpResponse instanceof ServletServerHttpResponse response &&
request.getServletRequest().getRequestURI().contains("/api/")) {
loggingService.logResponse(
request.getServletRequest(),
response.getServletResponse(),
o
);
}
return o;
}
}
The LoggingService consolidates request and response logging logic, ensuring consistency across the application:
@Slf4j
@Service
public class LoggingService {
public void logRequest(HttpServletRequest httpServletRequest, Object body) {
StringBuilder stringBuilder = new StringBuilder();
Map parameters = buildParametersMap(httpServletRequest);
stringBuilder.append("REQUEST ");
stringBuilder.append("method=[").append(httpServletRequest.getMethod()).append("] ");
stringBuilder.append("path=[").append(httpServletRequest.getRequestURI()).append("] ");
if (!parameters.isEmpty()) {
stringBuilder.append("parameters=[").append(parameters).append("] ");
}
if (body != null) {
stringBuilder.append("body=[").append(body).append("]");
}
log.info(stringBuilder.toString());
}
public void logResponse(HttpServletRequest httpServletRequest, HttpServletResponse httpServletResponse, Object body) {
String stringBuilder = "RESPONSE " +
"method=[" + httpServletRequest.getMethod() + "] " +
"path=[" + httpServletRequest.getRequestURI() + "] " +
"responseBody=[" + body + "] ";
log.info(stringBuilder);
}
private Map buildParametersMap(HttpServletRequest httpServletRequest) {
Map resultMap = new HashMap();
Enumeration parameterNames = httpServletRequest.getParameterNames();
while (parameterNames.hasMoreElements()) {
String key = parameterNames.nextElement();
String value = httpServletRequest.getParameter(key);
resultMap.put(key, value);
}
return resultMap;
}
}
Register the Interceptor
Finally, integrate the LogInterceptor into your application using the WebMvcConfigurer class:
@Configuration
public class WebConfig implements WebMvcConfigurer {
LoggingService loggingService;
WebConfig(LoggingService loggingService) {
this.loggingService = loggingService;
}
@Override
public void addInterceptors(InterceptorRegistry registry) {
registry.addInterceptor(new LogInterceptor(loggingService));
}
}
Intercepting and Logging Axon Commands and Events
To ensure complete visibility into the flow of commands and events within an Axon-based application, we can extend logging to capture detailed information about dispatched messages. This section describes how to implement interceptors for commands and events, leveraging Axon's MessageDispatchInterceptor and MessageHandlerInterceptor.
Additionally, because the Axon framework doesn’t guarantee that commands and events execute within the same processing group, it’s possible for the Mapped Diagnostic Context (MDC) to lose traceability. To address this, we store contextual information, such as the request ID and username, in Axon’s MetaData.
Command Dispatch Interceptor
The CommandDispatchInterceptor enriches each dispatched command with metadata, including the current username and request ID, while logging the command details.
@Slf4j
public class CommandDispatchInterceptor implements MessageDispatchInterceptor<CommandMessage> {
@NotNull
@Override
public BiFunction<Integer, CommandMessage, CommandMessage> handle(@NotNull List<? extends CommandMessage> messages) {
return (index, command) -> {
// Enrich the command with additional metadata
var newCommand = command.andMetaData(
command.getMetaData()
.and("user", getCurrentUsername())
.and("requestId", MDC.get("X-Request-Id"))
);
log.info("Dispatching a command {}.", newCommand);
return newCommand;
};
}
}
Event Dispatch Interceptor
The EventDispatchInterceptor logs all events that are about to be published. It provides critical traceability for event publishing.
@Slf4j
public class EventDispatchInterceptor
implements MessageDispatchInterceptor<EventMessage> {
@Override
public BiFunction<Integer, EventMessage, EventMessage> handle(
List<? extends EventMessage> messages) {
return (index, event) -> {
log.info("Publishing event: [{}].", event);
return event;
};
}
}
Restoring MDC Context with Event Handler Interceptor
When processing events, we can restore the MDC context using metadata previously added during command or event dispatch. This ensures consistent traceability throughout the event-processing lifecycle.
@Slf4j
public class EventHandlerInterceptor
implements MessageHandlerInterceptor<EventMessage> {
@Override
public Object handle(UnitOfWork<? extends EventMessage> unitOfWork,
@NotNull InterceptorChain interceptorChain) throws Exception {
EventMessage event = unitOfWork.getMessage();
var metaData = event.getMetaData();
// Restore MDC attributes from metadata
var requestId = metaData.get("requestId");
if (requestId != null) {
MDC.put("requestId", requestId.toString());
}
var user = metaData.get("user");
if (user != null) {
MDC.put("user", user.toString());
}
return interceptorChain.proceed();
}
}
Registering Dispatch Interceptors
To activate the dispatch interceptors, define a configuration class. This registers the CommandDispatchInterceptor and EventDispatchInterceptor with the Axon framework.
@Configuration
public class AxonGatewayInterceptor {
private final CommandBus commandBus;
public AxonGatewayInterceptor(CommandBus commandBus, EventBus eventBus) {
this.commandBus = commandBus;
// Register the Event Dispatch Interceptor
eventBus.registerDispatchInterceptor(new EventDispatchInterceptor());
}
@PostConstruct
public void registerInterceptor() {
// Register the Command Dispatch Interceptor
commandBus.registerDispatchInterceptor(new CommandDispatchInterceptor());
}
}
Configuring Event Processing
To apply the EventHandlerInterceptor to a specific processing group, update the Axon configuration. This ensures the MDC context is restored during event handling.
@Configuration
public class AxonGatewayInterceptor {
private final CommandBus commandBus;
public AxonGatewayInterceptor(CommandBus commandBus, EventBus eventBus) {
this.commandBus = commandBus;
// Register the Event Dispatch Interceptor
eventBus.registerDispatchInterceptor(new EventDispatchInterceptor());
}
@PostConstruct
public void registerInterceptor() {
// Register the Command Dispatch Interceptor
commandBus.registerDispatchInterceptor(new CommandDispatchInterceptor());
}
}
By using Axon framework and the provided command and event dispatch interceptors, the application keeps contextual information across processing boundaries and can capture logs at critical points in the Axon command and event lifecycle. This enhanced logging setup empowers developers to diagnose and monitor applications with improved granularity, fostering a more reliable and maintainable system.
