Correct issue with request body already read.

- Store request body in request context
- Read it and write it in MDC for final log
- Add warning in comments of the annotation
- Move annotation to specific interface in tests
- Make sure to start appender in tests

src/main/java/com/chavaillaz/jakarta/rs/Logged.java

@@ -22,13 +22,20 @@
 
     /**
      * Indicates how the request body must be logged.
+     * <p>
+     * Do not activate it when expecting large payloads to avoid any performance or memory issue.
+     * <p>
+     * Note that for {@link LogType#MDC}, the request body will be stored in the request context
+     * in order to be retrieved and stored as MDC when logging the processing log line.
      *
      * @return The types of logging to be done
      */
     LogType[] requestBody() default {};
 
     /**
      * Indicates how the response body must be logged.
+     * <p>
+     * Do not activate it when expecting large payloads to avoid any performance or memory issue.
      *
      * @return The types of logging to be done
      */

src/main/java/com/chavaillaz/jakarta/rs/LoggedFilter.java

@@ -74,7 +74,12 @@ public class LoggedFilter implements ContainerRequestFilter, ContainerResponseFi
     /**
      * Name of the property stored in container context to compute the duration time.
      */
-    protected static final String REQUEST_TIME = "request-time";
+    protected static final String REQUEST_TIME_PROPERTY = "request-time";
+
+    /**
+     * Name of the property stored in container context to retrieve the request body after its processing.
+     */
+    protected static final String REQUEST_BODY_PROPERTY = "request-body";
 
     /**
      * Names of MDC fields to be used for all logged fields.
@@ -141,7 +146,7 @@ protected String getRequestId(ContainerRequestContext requestContext) {
 
     @Override
     public void filter(ContainerRequestContext requestContext) {
-        requestContext.setProperty(REQUEST_TIME, nanoTime());
+        requestContext.setProperty(REQUEST_TIME_PROPERTY, nanoTime());
 
         putMdc(REQUEST_ID, getRequestId(requestContext));
 
@@ -157,17 +162,23 @@ public void filter(ContainerRequestContext requestContext) {
                 .map(Method::getName)
                 .ifPresent(value -> putMdc(RESOURCE_METHOD, value));
 
-        if (requestBodyLogging().contains(LogType.LOG) && requestContext.hasEntity()) {
-            log.info("Received {} {}\n{}",
-                    requestContext.getMethod(),
-                    requestContext.getUriInfo().getPath(),
-                    getRequestBody(requestContext));
+        if (!requestBodyLogging().isEmpty() && requestContext.hasEntity()) {
+            String requestBody = getRequestBody(requestContext);
+            if (requestBodyLogging().contains(LogType.LOG)) {
+                log.info("Received {} {}\n{}",
+                        requestContext.getMethod(),
+                        requestContext.getUriInfo().getPath(),
+                        requestBody);
+            }
+            if (requestBodyLogging().contains(LogType.MDC)) {
+                requestContext.setProperty(REQUEST_BODY_PROPERTY, requestBody);
+            }
         }
     }
 
     @Override
     public void filter(ContainerRequestContext requestContext, ContainerResponseContext responseContext) {
-        long requestStartTime = Optional.ofNullable(requestContext.getProperty(REQUEST_TIME))
+        long requestStartTime = Optional.ofNullable(requestContext.getProperty(REQUEST_TIME_PROPERTY))
                 .map(Object::toString)
                 .map(Long::parseLong)
                 .orElse(nanoTime());
@@ -177,7 +188,7 @@ public void filter(ContainerRequestContext requestContext, ContainerResponseCont
         putMdc(RESPONSE_STATUS, valueOf(responseContext.getStatus()));
 
         if (requestBodyLogging().contains(LogType.MDC) && requestContext.hasEntity()) {
-            putMdc(REQUEST_BODY, getRequestBody(requestContext));
+            putMdc(REQUEST_BODY, (String) requestContext.getProperty(REQUEST_BODY_PROPERTY));
         }
 
         String responseBody = "";

src/test/java/com/chavaillaz/jakarta/rs/AbstractFilterTest.java

@@ -19,10 +19,11 @@ static void registerListAppender() {
         Configuration configuration = loggerContext.getConfiguration();
         LoggerConfig rootLoggerConfig = configuration.getLoggerConfig("");
         rootLoggerConfig.addAppender(listAppender, Level.ALL, null);
+        listAppender.start();
     }
 
     @BeforeEach
-    void setupTest() {
+    void setupTest() throws Exception {
         MDC.clear();
         listAppender.getMessages().clear();
         listAppender.start();

src/test/java/com/chavaillaz/jakarta/rs/LoggedFilterTest.java

@@ -49,8 +49,8 @@
 import org.mockito.junit.jupiter.MockitoExtension;
 import org.slf4j.MDC;
 
-@ExtendWith(MockitoExtension.class)
 @DisplayName("Original filter")
+@ExtendWith(MockitoExtension.class)
 class LoggedFilterTest extends AbstractFilterTest {
 
     private static final LogType[] NO_LOGGING = new LogType[]{};

src/test/java/com/chavaillaz/jakarta/rs/UserLoggedFilterTest.java

@@ -7,12 +7,14 @@
 import static org.junit.jupiter.api.Assertions.assertEquals;
 import static org.mockito.Mockito.doReturn;
 
+import java.lang.reflect.Method;
 import java.net.URISyntaxException;
 
 import com.chavaillaz.jakarta.rs.Logged.LogType;
 import jakarta.ws.rs.container.ResourceInfo;
 import org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext;
 import org.jboss.resteasy.mock.MockHttpRequest;
+import org.junit.jupiter.api.BeforeEach;
 import org.junit.jupiter.api.DisplayName;
 import org.junit.jupiter.api.Test;
 import org.junit.jupiter.api.extension.ExtendWith;
@@ -21,9 +23,8 @@
 import org.mockito.junit.jupiter.MockitoExtension;
 import org.slf4j.MDC;
 
-@ExtendWith(MockitoExtension.class)
 @DisplayName("Custom filter")
-@UserLogged(logging = @Logged(requestBody = {LogType.MDC}, responseBody = LogType.MDC), userAgent = true)
+@ExtendWith(MockitoExtension.class)
 class UserLoggedFilterTest extends AbstractFilterTest {
 
     @Mock
@@ -33,11 +34,13 @@ class UserLoggedFilterTest extends AbstractFilterTest {
     UserLoggedFilter requestLoggingFilter;
 
     @Override
-    void setupTest() {
+    @BeforeEach
+    void setupTest() throws Exception {
         super.setupTest();
-        // Returns this method and class as the resource matched by the queries in tests
-        doReturn(new Object() {}.getClass().getEnclosingMethod()).when(resourceInfo).getResourceMethod();
-        doReturn(this.getClass()).when(resourceInfo).getResourceClass();
+        Class<?> type = AnnotatedResource.class;
+        doReturn(type).when(resourceInfo).getResourceClass();
+        Method resourceMethod = type.getDeclaredMethod("inherit");
+        doReturn(resourceMethod).when(resourceInfo).getResourceMethod();
     }
 
     @Test
@@ -63,4 +66,11 @@ private PreMatchContainerRequestContext getRequestContext() throws URISyntaxExce
                         .contentType(TEXT_PLAIN_TYPE));
     }
 
+    @UserLogged(logging = @Logged(requestBody = {LogType.MDC}, responseBody = LogType.MDC), userAgent = true)
+    interface AnnotatedResource {
+
+        void inherit();
+
+    }
+
 }