Merge pull request #10 from companieshouse/lp-170-add-logging-intereptor

LP-170 Add Logging Interceptor to log all requests to the api

Author: markpit

pom.xml

@@ -22,6 +22,7 @@
         <spring-boot-dependencies.version>3.3.4</spring-boot-dependencies.version>
         <spring-boot-maven-plugin.version>3.3.4</spring-boot-maven-plugin.version>
         <structured-logging.version>3.0.20</structured-logging.version>
+        <log4j.version>2.24.1</log4j.version>
         <jib-maven-plugin.version>3.4.2</jib-maven-plugin.version>
     </properties>
 
@@ -36,6 +37,13 @@
 
     <dependencyManagement>
         <dependencies>
+            <dependency>
+                <groupId>org.apache.logging.log4j</groupId>
+                <artifactId>log4j-bom</artifactId>
+                <version>${log4j.version}</version>
+                <scope>import</scope>
+                <type>pom</type>
+            </dependency>
             <dependency>
                 <groupId>org.springframework.boot</groupId>
                 <artifactId>spring-boot-dependencies</artifactId>
@@ -60,7 +68,6 @@
             <version>${structured-logging.version}</version>
         </dependency>
 
-
         <!-- Test dependencies -->
         <dependency>
             <groupId>org.springframework.boot</groupId>
@@ -74,6 +81,7 @@
             <scope>test</scope>
         </dependency>
     </dependencies>
+
     <build>
         <plugins>
             <plugin>

src/main/java/uk/gov/companieshouse/limitedpartnershipsapi/config/InterceptorConfig.java

@@ -0,0 +1,28 @@
+package uk.gov.companieshouse.limitedpartnershipsapi.config;
+
+import org.springframework.context.annotation.Configuration;
+import org.springframework.lang.NonNull;
+import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
+import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;
+import uk.gov.companieshouse.limitedpartnershipsapi.interceptor.LoggingInterceptor;
+
+
+@Configuration
+public class InterceptorConfig implements WebMvcConfigurer {
+
+    private final LoggingInterceptor loggingInterceptor;
+
+    public InterceptorConfig(LoggingInterceptor loggingInterceptor) {
+        this.loggingInterceptor = loggingInterceptor;
+    }
+
+    /**
+     * Set up the interceptors to run against endpoints when the endpoints are called
+     * Interceptors are executed in the order they are added to the registry
+     * @param registry The spring interceptor registry
+     */
+    @Override
+    public void addInterceptors(@NonNull InterceptorRegistry registry) {
+        registry.addInterceptor(loggingInterceptor);
+    }
+}

src/main/java/uk/gov/companieshouse/limitedpartnershipsapi/interceptor/LoggingInterceptor.java

@@ -0,0 +1,53 @@
+package uk.gov.companieshouse.limitedpartnershipsapi.interceptor;
+
+import jakarta.servlet.http.HttpServletRequest;
+import jakarta.servlet.http.HttpServletResponse;
+import org.springframework.lang.NonNull;
+import org.springframework.stereotype.Component;
+import org.springframework.web.servlet.HandlerInterceptor;
+import org.springframework.web.servlet.HandlerMapping;
+import uk.gov.companieshouse.limitedpartnershipsapi.utils.ApiLogger;
+
+import static uk.gov.companieshouse.limitedpartnershipsapi.utils.Constants.ERIC_REQUEST_ID_KEY;
+
+
+@Component
+public class LoggingInterceptor implements HandlerInterceptor {
+
+    private static final String START_TIME_KEY = "start-time";
+
+    @Override
+    public boolean preHandle(HttpServletRequest request, @NonNull HttpServletResponse response, @NonNull Object handler) {
+        Long startTime = System.currentTimeMillis();
+        request.setAttribute(START_TIME_KEY, startTime);
+
+        ApiLogger.infoContext(getRequestId(request), String.format("Start of request. Method: %s Path: %s",
+                getRequestMethod(request), getRequestPath(request)), null);
+        return true;
+    }
+
+    @Override
+    public void afterCompletion(HttpServletRequest request, @NonNull HttpServletResponse response, @NonNull Object handler, Exception ex) {
+        Long startTime = (Long) request.getAttribute(START_TIME_KEY);
+
+        if (startTime == null) {
+            ApiLogger.infoContext(getRequestId(request), "Start time not found in request attributes.", null);
+        } else {
+            long responseTime = System.currentTimeMillis() - startTime;
+            ApiLogger.infoContext(getRequestId(request), String.format("End of request. Method: %s Path: %s Duration: %sms Status: %s",
+                    getRequestMethod(request), getRequestPath(request), responseTime, response.getStatus()), null);
+        }
+    }
+
+    private String getRequestPath(HttpServletRequest request) {
+        return (String) request.getAttribute(HandlerMapping.BEST_MATCHING_PATTERN_ATTRIBUTE);
+    }
+
+    private String getRequestMethod(HttpServletRequest request) {
+        return request.getMethod();
+    }
+
+    private String getRequestId(HttpServletRequest request) {
+        return request.getHeader(ERIC_REQUEST_ID_KEY);
+    }
+}

src/main/java/uk/gov/companieshouse/limitedpartnershipsapi/utils/ApiLogger.java

@@ -9,6 +9,8 @@
 
 public class ApiLogger {
 
+    private ApiLogger() {}
+
     private static final Logger LOGGER =
             LoggerFactory.getLogger(LimitedPartnershipsApiApplication.APP_NAMESPACE);
 
@@ -32,6 +34,10 @@ public static void infoContext(String context, String message) {
         LOGGER.infoContext(context, message, null);
     }
 
+    public static void infoContext(String context, String message, Map<String, Object> dataMap) {
+        LOGGER.infoContext(context, message, cloneMapData(dataMap));
+    }
+
     public static void errorContext(String context, Exception e) {
         LOGGER.errorContext(context, e, null);
     }

src/main/java/uk/gov/companieshouse/limitedpartnershipsapi/utils/Constants.java

@@ -0,0 +1,9 @@
+package uk.gov.companieshouse.limitedpartnershipsapi.utils;
+
+public class Constants {
+
+    private Constants() { }
+
+    // Request header names
+    public static final String ERIC_REQUEST_ID_KEY = "X-Request-Id";
+}

src/test/java/uk/gov/companieshouse/limitedpartnershipsapi/config/InterceptorConfigTest.java

@@ -0,0 +1,47 @@
+package uk.gov.companieshouse.limitedpartnershipsapi.config;
+
+import org.junit.jupiter.api.Test;
+import org.junit.jupiter.api.extension.ExtendWith;
+import org.mockito.InOrder;
+import org.mockito.InjectMocks;
+import org.mockito.Mock;
+import org.mockito.junit.jupiter.MockitoExtension;
+import org.springframework.web.servlet.config.annotation.InterceptorRegistration;
+import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
+import uk.gov.companieshouse.limitedpartnershipsapi.interceptor.LoggingInterceptor;
+
+
+import static org.mockito.ArgumentMatchers.any;
+import static org.mockito.Mockito.inOrder;
+import static org.mockito.Mockito.times;
+import static org.mockito.Mockito.verify;
+import static org.mockito.Mockito.when;
+
+@ExtendWith(MockitoExtension.class)
+class InterceptorConfigTest {
+
+    @Mock
+    private InterceptorRegistry interceptorRegistry;
+
+    @Mock
+    private InterceptorRegistration interceptorRegistration;
+
+    @Mock
+    private LoggingInterceptor loggingInterceptor;
+
+
+    @InjectMocks
+    private InterceptorConfig interceptorConfig;
+
+    @Test
+    void addInterceptorsTest() {
+        when(interceptorRegistry.addInterceptor(any())).thenReturn(interceptorRegistration);
+
+        interceptorConfig.addInterceptors(interceptorRegistry);
+
+        InOrder inOrder = inOrder(interceptorRegistry, interceptorRegistration);
+        inOrder.verify(interceptorRegistry).addInterceptor(loggingInterceptor);
+
+        verify(interceptorRegistry, times(1)).addInterceptor(any());
+    }
+}

src/test/java/uk/gov/companieshouse/limitedpartnershipsapi/utils/ApiLoggerTest.java

@@ -8,7 +8,7 @@
 
 import static org.junit.jupiter.api.Assertions.assertEquals;
 
-public class ApiLoggerTest {
+class ApiLoggerTest {
 
     private static final String CONTEXT = "CONTEXT";
     private static final String TEST_MESSAGE = "TEST";
@@ -41,7 +41,7 @@ void testInfoLoggingDoesNotModifyLogMap() {
 
     @Test
     void testInfoContextLoggingDoesNotModifyLogMap() {
-        ApiLogger.infoContext(CONTEXT, TEST_MESSAGE);
+        ApiLogger.infoContext(CONTEXT, TEST_MESSAGE, logMap);
 
         assertEquals(1, logMap.size());
         assertEquals(LOG_MAP_VALUE, logMap.get(LOG_MAP_KEY));