diff --git a/backend-service/pom.xml b/backend-service/pom.xml index d3bbcb6..675356a 100644 --- a/backend-service/pom.xml +++ b/backend-service/pom.xml @@ -218,7 +218,6 @@ ${project.basedir}/checkstyle.xml - UTF-8 true true @@ -226,4 +225,4 @@ - \ No newline at end of file + diff --git a/backend-service/src/main/java/co/teamsphere/api/filters/FilterOrders.java b/backend-service/src/main/java/co/teamsphere/api/filters/FilterOrders.java new file mode 100644 index 0000000..4bb41b2 --- /dev/null +++ b/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; +} diff --git a/backend-service/src/main/java/co/teamsphere/api/filters/GenerateRequestIDFilter.java b/backend-service/src/main/java/co/teamsphere/api/filters/GenerateRequestIDFilter.java new file mode 100644 index 0000000..3fcd3b7 --- /dev/null +++ b/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 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); + } +} diff --git a/backend-service/src/main/java/co/teamsphere/api/filters/LoggingFilter.java b/backend-service/src/main/java/co/teamsphere/api/filters/LoggingFilter.java index 52b8b99..09aff51 100644 --- a/backend-service/src/main/java/co/teamsphere/api/filters/LoggingFilter.java +++ b/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{ + 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(); - } } diff --git a/backend-service/src/main/java/co/teamsphere/api/filters/RequestHeaders.java b/backend-service/src/main/java/co/teamsphere/api/filters/RequestHeaders.java new file mode 100644 index 0000000..0093e51 --- /dev/null +++ b/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; + } +} diff --git a/backend-service/src/test/java/co/teamsphere/api/filters/GenerateRequestIDFilterTest.java b/backend-service/src/test/java/co/teamsphere/api/filters/GenerateRequestIDFilterTest.java new file mode 100644 index 0000000..8dff012 --- /dev/null +++ b/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) () -> "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); + } +} + diff --git a/backend-service/src/test/java/co/teamsphere/api/filters/LoggingFilterTest.java b/backend-service/src/test/java/co/teamsphere/api/filters/LoggingFilterTest.java new file mode 100644 index 0000000..37187a1 --- /dev/null +++ b/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 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"); + } + + +} diff --git a/backend-service/src/test/java/co/teamsphere/api/helpers/TestAppender.java b/backend-service/src/test/java/co/teamsphere/api/helpers/TestAppender.java new file mode 100644 index 0000000..e5b8b1d --- /dev/null +++ b/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 { + private final List logEvents = new CopyOnWriteArrayList<>(); + + @Override + protected void append(ILoggingEvent eventObject) { + logEvents.add(eventObject); + } + + public void clearEvents() { + logEvents.clear(); + } +}