Commit d5afd917 authored by Kishore Battula's avatar Kishore Battula
Browse files

Added transaction logging

parent 2430d823
package org.opengroup.osdu.azure.filters;
import org.opengroup.osdu.azure.logging.AzureLogger;
import org.opengroup.osdu.core.common.model.http.DpsHeaders;
import org.springframework.boot.autoconfigure.condition.ConditionalOnProperty;
import org.springframework.stereotype.Component;
import javax.inject.Inject;
import javax.servlet.Filter;
import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;
import java.util.Arrays;
import java.util.List;
import java.util.function.Function;
/**
* For logging start and end of request.
*/
@Component
@ConditionalOnProperty(value = "logging.transaction.enabled", havingValue = "true", matchIfMissing = false)
public final class TransactionLogFilter implements Filter {
private static final String LOGGER_NAME = "TxnLogger";
private static final List<String> WHITELIST_HEADERS = Arrays.asList(
DpsHeaders.CORRELATION_ID,
DpsHeaders.DATA_PARTITION_ID,
DpsHeaders.CONTENT_TYPE);
private static final String START_LOG_TEMPLATE = "Start Web-API %s %s %s";
private static final String END_LOG_TEMPLATE = "End Web-API %s %s %s timeTaken:%d";
@Inject
private AzureLogger azureLogger;
/**
* Filter logic.
* @param servletRequest Request object.
* @param servletResponse Response object.
* @param filterChain Filter Chain object.
* @throws IOException
* @throws ServletException
*/
@Override
public void doFilter(final ServletRequest servletRequest, final ServletResponse servletResponse,
final FilterChain filterChain) throws IOException, ServletException {
final HttpServletRequest httpRequest = (HttpServletRequest) servletRequest;
final HttpServletResponse httpResponse = (HttpServletResponse) servletResponse;
logTransactionStart(httpRequest);
final long start = System.currentTimeMillis();
filterChain.doFilter(servletRequest, servletResponse);
final long timeTaken = System.currentTimeMillis() - start;
logTransactionEnd(httpRequest, httpResponse, timeTaken);
}
/**
* Logs start of a request.
* @param request Request Object.
*/
private void logTransactionStart(final HttpServletRequest request) {
azureLogger.info(LOGGER_NAME, String.format(START_LOG_TEMPLATE, request.getMethod(), request.getServletPath(),
getRequestHeadersString(request)));
}
/**
* Logs end of a request.
* @param request Request object.
* @param response Response object.
* @param timeTaken timeTaken in ms taken for request to complete.
*/
private void logTransactionEnd(final HttpServletRequest request, final HttpServletResponse response,
final long timeTaken) {
azureLogger.info(LOGGER_NAME, String.format(END_LOG_TEMPLATE, request.getMethod(), request.getServletPath(),
getResponseHeadersString(response), timeTaken));
}
/**
* To construct string representation of request headers.
* @param request Request Object.
* @return String representation of request headers.
*/
private String getRequestHeadersString(final HttpServletRequest request) {
return getHeadersString(s -> request.getHeader(s));
}
/**
* To construct string representation of response headers.
* @param response Response Object.
* @return String representation of response headers.
*/
private String getResponseHeadersString(final HttpServletResponse response) {
return getHeadersString(s -> response.getHeader(s));
}
/**
* Construct string representation of headers.
* @param headerGetter Header value supplier
* @return String representation of headers
*/
private String getHeadersString(final Function<String, String> headerGetter) {
final StringBuilder headers = new StringBuilder();
for (String headerName: WHITELIST_HEADERS) {
if (headerGetter.apply(headerName) != null) {
headers.append(headerName);
headers.append(":");
headers.append(headerGetter.apply(headerName));
headers.append(",");
}
}
if (headers.length() != 0) {
headers.deleteCharAt(headers.length() - 1);
}
return String.format("Headers: {%s}", headers.toString());
}
}
package org.opengroup.osdu.azure.logging;
import org.opengroup.osdu.core.common.logging.JaxRsDpsLog;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.stereotype.Component;
/**
* A wrapper on {@link JaxRsDpsLog}.
*/
@Component
public class AzureLogger {
@Autowired
private JaxRsDpsLog jaxRsDpsLog;
/**
* To log info messages.
* @param loggerName Name of the logger. Generally Fully qualified class name is used. e.g className.class
* @param message Message to log
*/
public void info(final String loggerName, final String message) {
jaxRsDpsLog.info(message);
}
/**
* To log info messages.
* @param loggerName Name of the logger. Generally Fully qualified class name is used. e.g className.class
* @param message Message to log
*/
public void warn(final String loggerName, final String message) {
jaxRsDpsLog.warning(message);
}
/**
* To log info messages.
* @param loggerName Name of the logger. Generally Fully qualified class name is used. e.g className.class
* @param message Message to log
* @param e exception to log
*/
public void warn(final String loggerName, final String message, final Exception e) {
jaxRsDpsLog.warning(message, e);
}
/**
* To log info messages.
* @param loggerName Name of the logger. Generally Fully qualified class name is used. e.g className.class
* @param message Message to log
*/
public void error(final String loggerName, final String message) {
jaxRsDpsLog.error(message);
}
/**
* To log info messages.
* @param loggerName Name of the logger. Generally Fully qualified class name is used. e.g className.class
* @param message Message to log
* @param e exception to log
*/
public void error(final String loggerName, final String message, final Exception e) {
jaxRsDpsLog.error(message, e);
}
}
package org.opengroup.osdu.azure.filters;
import org.junit.jupiter.api.BeforeEach;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.extension.ExtendWith;
import org.mockito.ArgumentCaptor;
import org.mockito.InjectMocks;
import org.mockito.Mock;
import org.mockito.junit.jupiter.MockitoExtension;
import org.opengroup.osdu.azure.logging.AzureLogger;
import org.opengroup.osdu.core.common.model.http.DpsHeaders;
import javax.servlet.FilterChain;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import static org.junit.jupiter.api.Assertions.assertEquals;
import static org.mockito.ArgumentMatchers.eq;
import static org.mockito.Mockito.doNothing;
import static org.mockito.Mockito.times;
import static org.mockito.Mockito.verify;
import static org.mockito.Mockito.when;
/**
* Tests for {@link TransactionLogFilter}
*/
@ExtendWith(MockitoExtension.class)
public class TransactionLogFilterTest {
@Mock
private HttpServletRequest servletRequest;
@Mock
private HttpServletResponse servletResponse;
@Mock
private FilterChain filterChain;
@Mock
private AzureLogger azureLogger;
@InjectMocks
private TransactionLogFilter logFilter;
@BeforeEach
public void setup() {
}
@Test
public void testStartAndEndMessagesAreLoggedProperly() throws Exception {
final String startLogMessage = "Start Web-API PUT records Headers: {correlation-id:abc}";
final String endMessage = "End Web-API PUT records Headers: {correlation-id:abc} timeTaken:";
when(servletRequest.getMethod()).thenReturn("PUT");
when(servletRequest.getServletPath()).thenReturn("records");
when(servletRequest.getHeader(eq(DpsHeaders.CORRELATION_ID))).thenReturn("abc");
when(servletResponse.getHeader(eq(DpsHeaders.CORRELATION_ID))).thenReturn("abc");
final ArgumentCaptor<String> logMessageCaptor = ArgumentCaptor.forClass(String.class);
doNothing().when(azureLogger).info(eq("TxnLogger"), logMessageCaptor.capture());
this.logFilter.doFilter(servletRequest, servletResponse, filterChain);
verify(servletRequest, times(2)).getMethod();
verify(servletRequest, times(2)).getServletPath();
verify(servletRequest, times(2)).getHeader(eq(DpsHeaders.CORRELATION_ID));
verify(servletResponse, times(2)).getHeader(eq(DpsHeaders.CORRELATION_ID));
assertEquals(2, logMessageCaptor.getAllValues().size());
assertEquals(startLogMessage, logMessageCaptor.getAllValues().get(0));
assertEquals(true, logMessageCaptor.getAllValues().get(1).startsWith(endMessage));
}
@Test
public void testStartAndEndMessagesAreLoggedProperlyWithNoHeaders() throws Exception {
final String startLogMessage = "Start Web-API PUT records Headers: {}";
final String endMessage = "End Web-API PUT records Headers: {} timeTaken:";
when(servletRequest.getMethod()).thenReturn("PUT");
when(servletRequest.getServletPath()).thenReturn("records");
final ArgumentCaptor<String> logMessageCaptor = ArgumentCaptor.forClass(String.class);
doNothing().when(azureLogger).info(eq("TxnLogger"), logMessageCaptor.capture());
this.logFilter.doFilter(servletRequest, servletResponse, filterChain);
verify(servletRequest, times(2)).getMethod();
verify(servletRequest, times(2)).getServletPath();
assertEquals(2, logMessageCaptor.getAllValues().size());
assertEquals(startLogMessage, logMessageCaptor.getAllValues().get(0));
assertEquals(true, logMessageCaptor.getAllValues().get(1).startsWith(endMessage));
}
}
package org.opengroup.osdu.azure.logging;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.extension.ExtendWith;
import org.mockito.InjectMocks;
import org.mockito.Mock;
import org.mockito.junit.MockitoJUnitRunner;
import org.mockito.junit.jupiter.MockitoExtension;
import org.opengroup.osdu.core.common.logging.JaxRsDpsLog;
import static org.mockito.ArgumentMatchers.eq;
import static org.mockito.Mockito.doNothing;
import static org.mockito.Mockito.times;
import static org.mockito.Mockito.verify;
/**
* Tests for {@link AzureLogger}
*/
@ExtendWith(MockitoExtension.class)
public class AzureLoggerTest {
private static final String LOGGER_NAME = AzureLoggerTest.class.getName();
private static final String LOG_MESSAGE = "Hello world";
private static final Exception EXCEPTION = new Exception();
@Mock
private JaxRsDpsLog jaxRsDpsLog;
@InjectMocks
private AzureLogger azureLogger;
@Test
public void testInfo() {
doNothing().when(jaxRsDpsLog).info(eq(LOG_MESSAGE));
azureLogger.info(LOGGER_NAME, LOG_MESSAGE);
verify(jaxRsDpsLog, times(1)).info(eq(LOG_MESSAGE));
}
@Test
public void testWarn() {
doNothing().when(jaxRsDpsLog).warning(eq(LOG_MESSAGE));
azureLogger.warn(LOGGER_NAME, LOG_MESSAGE);
verify(jaxRsDpsLog, times(1)).warning(eq(LOG_MESSAGE));
}
@Test
public void testWarnWithException() {
doNothing().when(jaxRsDpsLog).warning(eq(LOG_MESSAGE), eq(EXCEPTION));
azureLogger.warn(LOGGER_NAME, LOG_MESSAGE, EXCEPTION);
verify(jaxRsDpsLog, times(1)).warning(eq(LOG_MESSAGE), eq(EXCEPTION));
}
@Test
public void testError() {
doNothing().when(jaxRsDpsLog).error(eq(LOG_MESSAGE));
azureLogger.error(LOGGER_NAME, LOG_MESSAGE);
verify(jaxRsDpsLog, times(1)).error(eq(LOG_MESSAGE));
}
@Test
public void testErrorWithException() {
doNothing().when(jaxRsDpsLog).error(eq(LOG_MESSAGE), eq(EXCEPTION));
azureLogger.error(LOGGER_NAME, LOG_MESSAGE, EXCEPTION);
verify(jaxRsDpsLog, times(1)).error(eq(LOG_MESSAGE), eq(EXCEPTION));
}
}
Supports Markdown
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment