Feature chat 100 remove double logs

backend-service/pom.xml

@@ -218,12 +218,11 @@
 				</executions>
 				<configuration>
 			        <configLocation>${project.basedir}/checkstyle.xml</configLocation>
-					<encoding>UTF-8</encoding>
 					<consoleOutput>true</consoleOutput>
 					<failsOnError>true</failsOnError>
 				</configuration>
 			</plugin>
         </plugins>
     </build>
 
-</project>
+</project>

backend-service/src/main/java/co/teamsphere/api/filters/FilterOrders.java

@@ -0,0 +1,8 @@
+package co.teamsphere.api.filters;
+
+import org.springframework.core.Ordered;
+
+public class FilterOrders {
+    public static final int GENERATE_REQUEST_ID_FILTER_ORDER = Ordered.HIGHEST_PRECEDENCE;
+    public static final int REQUEST_LOGGING_FILTER_ORDER = GENERATE_REQUEST_ID_FILTER_ORDER + 10;
+}

backend-service/src/main/java/co/teamsphere/api/filters/GenerateRequestIDFilter.java

@@ -0,0 +1,35 @@
+package co.teamsphere.api.filters;
+
+import jakarta.servlet.Filter;
+import jakarta.servlet.FilterChain;
+import jakarta.servlet.ServletException;
+import jakarta.servlet.ServletRequest;
+import jakarta.servlet.ServletResponse;
+import jakarta.servlet.http.HttpServletRequest;
+import org.apache.commons.lang3.StringUtils;
+import org.springframework.core.annotation.Order;
+import org.springframework.stereotype.Component;
+
+import java.io.IOException;
+import java.util.UUID;
+import java.util.function.Supplier;
+
+import static co.teamsphere.api.filters.FilterOrders.GENERATE_REQUEST_ID_FILTER_ORDER;
+
+@Component
+@Order(GENERATE_REQUEST_ID_FILTER_ORDER)
+public class GenerateRequestIDFilter implements Filter {
+    private final Supplier<String> requestIdGenerator = () -> UUID.randomUUID().toString();
+    @Override
+    public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse,
+                         FilterChain filterChain) throws IOException, ServletException {
+        if (servletRequest instanceof HttpServletRequest request){
+            String requestId = request.getHeader(RequestHeaders.X_REQUEST_ID.getHeader());
+
+            if (StringUtils.isBlank(requestId)){
+                request.setAttribute(RequestHeaders.X_REQUEST_ID.getHeader(), requestIdGenerator.get());
+            }
+        }
+        filterChain.doFilter(servletRequest, servletResponse);
+    }
+}

backend-service/src/main/java/co/teamsphere/api/filters/LoggingFilter.java

@@ -6,57 +6,44 @@
 import jakarta.servlet.ServletRequest;
 import jakarta.servlet.ServletResponse;
 import jakarta.servlet.http.HttpServletRequest;
-import lombok.extern.slf4j.Slf4j;
-import org.slf4j.MDC;
+import jakarta.servlet.http.HttpServletResponse;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+import org.springframework.core.annotation.Order;
 
 import java.io.IOException;
-import java.time.Instant;
-import java.util.UUID;
 
-@Slf4j
+import static co.teamsphere.api.filters.FilterOrders.REQUEST_LOGGING_FILTER_ORDER;
+
+@Order(REQUEST_LOGGING_FILTER_ORDER)
 public class LoggingFilter implements Filter {
+    private static final Logger LOG = LoggerFactory.getLogger(LoggingFilter.class);
+    private static final TimerThreadLocal TIMER = new TimerThreadLocal();
     @Override
     public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException {
-        HttpServletRequest httpRequest = (HttpServletRequest) servletRequest;
-
-        // Log request start
-        logRequestStart(httpRequest);
+        HttpServletRequest request = (HttpServletRequest) servletRequest;
+        HttpServletResponse response = (HttpServletResponse) servletResponse;
 
         try {
+            TIMER.start();
+            LOG.info("Start: {} {}", request.getMethod(), request.getRequestURI());
             filterChain.doFilter(servletRequest, servletResponse);
         } finally {
-            // Log request completion
-            logRequestCompletion();
+            long duration = TIMER.stop();
+            LOG.info("Took {}ms to {} {} | method={}, uri={}, duration={}, status={}",
+                duration, request.getMethod(), request.getRequestURI(), request.getMethod(),
+                request.getRequestURI(), duration,response.getStatus());
         }
     }
-
-    private void logRequestStart(HttpServletRequest request) {
-        Instant startTime = Instant.now();
-        MDC.put("startTime", startTime.toString());
-
-        String requestId = request.getHeader("X-Request-ID");
-        if (requestId == null) {
-            requestId = UUID.randomUUID().toString();
+    private static final class TimerThreadLocal extends ThreadLocal<Long>{
+        void start(){ set(System.currentTimeMillis());}
+        long stop(){
+            Long startTime = get();
+            remove();
+            if (startTime == null){
+                return -1;
+            }
+            return System.currentTimeMillis() - startTime;
         }
-        MDC.put("requestId", requestId);
-        MDC.put("httpMethod", request.getMethod());
-        MDC.put("httpRequestURI", request.getRequestURI());
-
-        log.info("Start {} uri={}", request.getMethod(), request.getRequestURI());
-    }
-
-    private void logRequestCompletion() {
-        String startTimeStr = MDC.get("startTime");
-        if (startTimeStr != null) {
-            Instant startTime = Instant.parse(startTimeStr); // Parse stored string to Instant
-            long duration = Instant.now().toEpochMilli() - startTime.toEpochMilli();
-
-            log.info("Took duration={}ms {} uri={}", duration, MDC.get("httpMethod"), MDC.get("httpRequestURI"));
-        } else {
-            log.warn("Unable to calculate duration for requestId={} method={} uri={}. Start time not found in MDC.", MDC.get("requestId"), MDC.get("httpMethod"), MDC.get("httpRequestURI"));
-        }
-
-        MDC.clear();
-
     }
 }

backend-service/src/main/java/co/teamsphere/api/filters/RequestHeaders.java

@@ -0,0 +1,14 @@
+package co.teamsphere.api.filters;
+
+public enum RequestHeaders {
+    X_REQUEST_ID("X-Request-ID");
+    private final String headerName;
+
+    RequestHeaders(String headerName) {
+        this.headerName = headerName;
+    }
+
+    public String getHeader() {
+        return headerName;
+    }
+}

backend-service/src/test/java/co/teamsphere/api/filters/GenerateRequestIDFilterTest.java

@@ -0,0 +1,84 @@
+package co.teamsphere.api.filters;
+
+import jakarta.servlet.FilterChain;
+import jakarta.servlet.ServletException;
+import jakarta.servlet.http.HttpServletRequest;
+import jakarta.servlet.http.HttpServletResponse;
+import org.junit.jupiter.api.BeforeEach;
+import org.junit.jupiter.api.Test;
+import org.junit.jupiter.api.extension.ExtendWith;
+import org.mockito.Mock;
+import org.mockito.junit.jupiter.MockitoExtension;
+
+import java.io.IOException;
+import java.util.function.Supplier;
+
+import static org.mockito.ArgumentMatchers.eq;
+import static org.mockito.Mockito.anyString;
+import static org.mockito.Mockito.mock;
+import static org.mockito.Mockito.never;
+import static org.mockito.Mockito.verify;
+import static org.mockito.Mockito.verifyNoInteractions;
+import static org.mockito.Mockito.when;
+
+@ExtendWith(MockitoExtension.class)
+class GenerateRequestIDFilterTest {
+
+    private GenerateRequestIDFilter generateRequestIDFilter;
+
+    @Mock
+    private HttpServletRequest mockHttpServletRequest;
+
+    @Mock
+    private HttpServletResponse mockHttpServletResponse;
+
+    @Mock
+    private FilterChain mockFilterChain;
+
+    @BeforeEach
+    void setUp() {
+        generateRequestIDFilter = new GenerateRequestIDFilter();
+        try {
+            java.lang.reflect.Field field = GenerateRequestIDFilter.class.getDeclaredField("requestIdGenerator");
+            field.setAccessible(true);
+            // We can set a predictable UUID for testing purposes
+            field.set(generateRequestIDFilter, (Supplier<String>) () -> "test-generated-uuid");
+        } catch (NoSuchFieldException | IllegalAccessException e) {
+            throw new RuntimeException(e);
+        }
+    }
+
+    @Test
+    void doFilter_HttpServletRequest_NoRequestIdHeader_GeneratesNewId() throws IOException, ServletException {
+        when(mockHttpServletRequest.getHeader(RequestHeaders.X_REQUEST_ID.getHeader())).thenReturn(null); // No existing header
+        generateRequestIDFilter.doFilter(mockHttpServletRequest, mockHttpServletResponse, mockFilterChain);
+        verify(mockHttpServletRequest).setAttribute(eq(RequestHeaders.X_REQUEST_ID.getHeader()), eq("test-generated-uuid"));
+        verify(mockFilterChain).doFilter(mockHttpServletRequest, mockHttpServletResponse);
+    }
+
+    @Test
+    void doFilter_HttpServletRequest_BlankRequestIdHeader_GeneratesNewId() throws IOException, ServletException {
+        when(mockHttpServletRequest.getHeader(RequestHeaders.X_REQUEST_ID.getHeader())).thenReturn(""); // Blank header
+        generateRequestIDFilter.doFilter(mockHttpServletRequest, mockHttpServletResponse, mockFilterChain);
+        verify(mockHttpServletRequest).setAttribute(eq(RequestHeaders.X_REQUEST_ID.getHeader()), eq("test-generated-uuid"));
+        verify(mockFilterChain).doFilter(mockHttpServletRequest, mockHttpServletResponse);
+    }
+
+    @Test
+    void doFilter_HttpServletRequest_ExistingRequestIdHeader_DoesNotGenerateNewId() throws IOException, ServletException {
+        String existingRequestId = "existing-request-id-123";
+        when(mockHttpServletRequest.getHeader(RequestHeaders.X_REQUEST_ID.getHeader())).thenReturn(existingRequestId);
+        generateRequestIDFilter.doFilter(mockHttpServletRequest, mockHttpServletResponse, mockFilterChain);
+        verify(mockHttpServletRequest, never()).setAttribute(eq(RequestHeaders.X_REQUEST_ID.getHeader()), anyString());
+        verify(mockFilterChain).doFilter(mockHttpServletRequest, mockHttpServletResponse);
+    }
+
+    @Test
+    void doFilter_NonHttpServletRequest_DoesNothingAndContinuesChain() throws IOException, ServletException {
+        jakarta.servlet.ServletRequest mockServletRequest = mock(jakarta.servlet.ServletRequest.class);
+        generateRequestIDFilter.doFilter(mockServletRequest, mockHttpServletResponse, mockFilterChain);
+        verifyNoInteractions(mockServletRequest);
+        verify(mockFilterChain).doFilter(mockServletRequest, mockHttpServletResponse);
+    }
+}
+

backend-service/src/test/java/co/teamsphere/api/filters/LoggingFilterTest.java

@@ -0,0 +1,93 @@
+package co.teamsphere.api.filters;
+
+import ch.qos.logback.classic.Level;
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import co.teamsphere.api.helpers.TestAppender;
+import jakarta.servlet.FilterChain;
+import jakarta.servlet.ServletException;
+import jakarta.servlet.http.HttpServletRequest;
+import jakarta.servlet.http.HttpServletResponse;
+import org.junit.jupiter.api.AfterEach;
+import org.junit.jupiter.api.BeforeEach;
+import org.junit.jupiter.api.Test;
+import org.junit.jupiter.api.extension.ExtendWith;
+import org.mockito.InjectMocks;
+import org.mockito.Mock;
+import org.mockito.MockitoAnnotations;
+import org.mockito.junit.jupiter.MockitoExtension;
+import ch.qos.logback.classic.Logger;
+
+import org.slf4j.LoggerFactory;
+
+import java.io.IOException;
+import java.util.List;
+
+import static org.assertj.core.api.Assertions.assertThat;
+import static org.mockito.Mockito.verify;
+import static org.mockito.Mockito.when;
+
+@ExtendWith(MockitoExtension.class)
+public class LoggingFilterTest {
+    @Mock
+    private HttpServletRequest request;
+    @Mock
+    private HttpServletResponse response;
+    @Mock
+    private FilterChain filterChain;
+    @InjectMocks
+    private LoggingFilter loggingFilter;
+    private TestAppender testAppender;
+    private final Logger logger = (Logger) LoggerFactory.getLogger(LoggingFilter.class);
+
+    @BeforeEach
+    void setUp() {
+        // Initialize mocks annotated with @Mock and inject them into @InjectMocks fields
+        MockitoAnnotations.openMocks(this);
+
+        // Configure and attach the custom Logback appender
+        testAppender = new TestAppender();
+        testAppender.start(); // Important: Start the appender
+        logger.addAppender(testAppender);
+        // Set logger level to DEBUG to capture both DEBUG (start) and INFO (end) logs
+        logger.setLevel(ch.qos.logback.classic.Level.DEBUG);
+    }
+
+    @AfterEach
+    void tearDown() {
+        logger.detachAppender(testAppender);
+        testAppender.stop();
+        testAppender.clearEvents();
+    }
+
+    @Test
+    void doFilter_logsRequestStartAndEndWithNoRequestId() throws IOException, ServletException {
+        // Arrange
+        when(request.getMethod()).thenReturn("GET");
+        when(request.getRequestURI()).thenReturn("/test-uri");
+        // Simulate no X-Request-ID header initially, so filter should log "N/A"
+        when(response.getStatus()).thenReturn(200);
+
+        // Act
+        loggingFilter.doFilter(request, response, filterChain);
+
+        // Assert
+        // Verify that the filter chain proceeded
+        verify(filterChain).doFilter(request, response);
+
+        // Verify log messages
+        List<ILoggingEvent> logEvents = testAppender.getLogEvents();
+        assertThat(logEvents).hasSize(2); // Expecting a DEBUG (start) and an INFO (end) log
+
+        // Verify start log (DEBUG) content
+        assertThat(logEvents.get(0).getLevel()).isEqualTo(Level.INFO);
+        assertThat(logEvents.get(0).getFormattedMessage())
+            .matches("Start: GET /test-uri");
+
+        // Verify end log (INFO) content
+        assertThat(logEvents.get(1).getLevel()).isEqualTo(ch.qos.logback.classic.Level.INFO);
+        assertThat(logEvents.get(1).getFormattedMessage())
+            .matches("Took \\d+ms to GET /test-uri \\| method=GET, uri=/test-uri, duration=\\d+, status=200");
+    }
+
+
+}

backend-service/src/test/java/co/teamsphere/api/helpers/TestAppender.java

@@ -0,0 +1,22 @@
+package co.teamsphere.api.helpers;
+
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import ch.qos.logback.core.AppenderBase;
+import lombok.Getter;
+
+import java.util.List;
+import java.util.concurrent.CopyOnWriteArrayList;
+
+@Getter
+public class TestAppender extends AppenderBase<ILoggingEvent> {
+    private final List<ILoggingEvent> logEvents = new CopyOnWriteArrayList<>();
+
+    @Override
+    protected void append(ILoggingEvent eventObject) {
+        logEvents.add(eventObject);
+    }
+
+    public void clearEvents() {
+        logEvents.clear();
+    }
+}