Skip to content

Commit

Permalink
Remove side-effect in RequestRecordFactory (#117)
Browse files Browse the repository at this point in the history
* Remove side-effect in RequestRecordFactory

This change removes the http header propagation to log fields in the RequestRecordFactory.
This feature was refactored to the AddHttpHeadersToLogContextFilter. The change include
several test to ensure correct behaviour.
  • Loading branch information
KarstenSchnitter authored Jul 23, 2021
1 parent 671d10b commit 2f192a1
Show file tree
Hide file tree
Showing 5 changed files with 175 additions and 27 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -36,9 +36,6 @@ public RequestRecord create(HttpServletRequest request) {
getHeader(request, HttpHeaders.X_FORWARDED_FOR))
.addOptionalTag(isLogRemoteUserField, Fields.REMOTE_USER, getValue(request.getRemoteUser()))
.addOptionalTag(isLogRefererField, Fields.REFERER, getHeader(request, HttpHeaders.REFERER));
for (HttpHeader header : HttpHeaders.propagated()) {
rrb.addContextTag(header.getField(), getHeaderValue(request, header, null));
}
return rrb.build();
}

Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,143 @@
package com.sap.hcp.cf.logging.servlet.filter;

import static org.hamcrest.MatcherAssert.assertThat;
import static org.hamcrest.Matchers.equalTo;
import static org.hamcrest.Matchers.hasEntry;
import static org.hamcrest.Matchers.is;

import java.util.EnumSet;

import javax.servlet.DispatcherType;
import javax.servlet.Filter;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

import org.apache.http.client.methods.CloseableHttpResponse;
import org.apache.http.client.methods.HttpGet;
import org.apache.http.impl.client.CloseableHttpClient;
import org.apache.http.impl.client.HttpClientBuilder;
import org.eclipse.jetty.server.Server;
import org.eclipse.jetty.server.ServerConnector;
import org.eclipse.jetty.servlet.FilterHolder;
import org.eclipse.jetty.servlet.ServletContextHandler;
import org.junit.Rule;
import org.junit.Test;
import org.slf4j.MDC;

import com.sap.hcp.cf.logging.common.Fields;
import com.sap.hcp.cf.logging.common.request.HttpHeaders;

public class CustomFilterTest {

@Rule
public SystemOutRule systemOutRule = new SystemOutRule();

@Test
public void setsFixedTenantId() throws Exception {
Server jetty = initJetty(constantTenantId("my_tenant"));
try (CloseableHttpClient client = HttpClientBuilder.create().build()) {
jetty.start();
try (CloseableHttpResponse response = client.execute(createBasicGetRequest(jetty))) {
assertThat(response.getStatusLine().getStatusCode(), is(equalTo(200)));
assertThat(systemOutRule.findLineAsMapWith(Fields.MSG, LoggingTestServlet.LOG_MESSAGE), hasEntry(
Fields.TENANT_ID,
"my_tenant"));
}
} finally {
jetty.stop();
}
}

/**
* This test case addresses
* <a href="https://github.com/SAP/cf-java-logging-support/issues/111">
* Github issue #111</a>, by ensuring the elimination of a side-effect in
* {@link RequestRecordFactory}, which used to overwrite custom set log
* fields with values extracted from http headers.
*
* @throws Exception
*/
@Test
public void usesCustomTenantIdInRequestLog() throws Exception {
Filter filter = new CompositeFilter(constantTenantId("custom_tenant"), new GenerateRequestLogFilter());
Server jetty = initJetty(filter);
try (CloseableHttpClient client = HttpClientBuilder.create().build()) {
jetty.start();
HttpGet request = createBasicGetRequest(jetty);
request.addHeader(HttpHeaders.TENANT_ID.getName(), "other_tenant");
try (CloseableHttpResponse response = client.execute(request)) {
assertThat(response.getStatusLine().getStatusCode(), is(equalTo(200)));
assertThat(systemOutRule.findLineAsMapWith(Fields.MSG, LoggingTestServlet.LOG_MESSAGE), hasEntry(
Fields.TENANT_ID,
"custom_tenant"));
assertThat(systemOutRule.findLineAsMapWith(Fields.LAYER, "[SERVLET]"), hasEntry(Fields.TENANT_ID,
"custom_tenant"));
}
} finally {
jetty.stop();
}
}

@Test
public void canOverwriteGeneratedCorrelationId() throws Exception {
Filter filter = new CompositeFilter(new CorrelationIdFilter(), constantCorrelationId("my_correlation"),
new GenerateRequestLogFilter());
Server jetty = initJetty(filter);
try (CloseableHttpClient client = HttpClientBuilder.create().build()) {
jetty.start();
try (CloseableHttpResponse response = client.execute(createBasicGetRequest(jetty))) {
assertThat(response.getStatusLine().getStatusCode(), is(equalTo(200)));
assertThat(systemOutRule.findLineAsMapWith(Fields.MSG, LoggingTestServlet.LOG_MESSAGE), hasEntry(
Fields.CORRELATION_ID,
"my_correlation"));
assertThat(systemOutRule.findLineAsMapWith(Fields.LAYER, "[SERVLET]"), hasEntry(Fields.CORRELATION_ID,
"my_correlation"));
}
} finally {
jetty.stop();
}
}

private Server initJetty(Filter filter) {
Server jetty = new Server(0);
ServletContextHandler contextHandler = new ServletContextHandler(jetty, null);
EnumSet<DispatcherType> dispatches = EnumSet.of(DispatcherType.INCLUDE, DispatcherType.REQUEST,
DispatcherType.ERROR, DispatcherType.FORWARD,
DispatcherType.ASYNC);
contextHandler.addFilter(new FilterHolder(filter), "/*", dispatches);
contextHandler.addServlet(LoggingTestServlet.class, "/test");
return jetty;
}

private HttpGet createBasicGetRequest(Server jetty) {
return new HttpGet(getBaseUrl(jetty) + "/test");
}

private String getBaseUrl(Server server) {
int port = ((ServerConnector) server.getConnectors()[0]).getLocalPort();
return "http://localhost:" + port;
}

private static Filter constantTenantId(String tenantId) {
return constantField(Fields.TENANT_ID, tenantId);
}

private static Filter constantCorrelationId(String correlationId) {
return constantField(Fields.CORRELATION_ID, correlationId);
}

private static Filter constantField(String field, String value) {
return new AbstractLoggingFilter() {
@Override
protected void beforeFilter(HttpServletRequest request, HttpServletResponse response) {
MDC.put(field, value);
}

@Override
protected void cleanup(HttpServletRequest request, HttpServletResponse response) {
MDC.remove(field);
}
};
}

}
Original file line number Diff line number Diff line change
@@ -0,0 +1,25 @@
package com.sap.hcp.cf.logging.servlet.filter;

import java.io.IOException;

import javax.servlet.ServletException;
import javax.servlet.http.HttpServlet;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class LoggingTestServlet extends HttpServlet {

public static final String LOG_MESSAGE = "request received";

private static final long serialVersionUID = -4594560302550583354L;
private static final Logger LOG = LoggerFactory.getLogger(LoggingTestServlet.class);

@Override
protected void doGet(HttpServletRequest req, HttpServletResponse resp) throws ServletException, IOException {
LOG.info(LOG_MESSAGE);
}

}
Original file line number Diff line number Diff line change
Expand Up @@ -13,10 +13,6 @@
import java.util.UUID;

import javax.servlet.DispatcherType;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServlet;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

import org.apache.http.client.methods.CloseableHttpResponse;
import org.apache.http.client.methods.HttpGet;
Expand All @@ -29,7 +25,6 @@
import org.junit.Before;
import org.junit.Rule;
import org.junit.Test;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import com.sap.hcp.cf.logging.common.Fields;
Expand All @@ -41,10 +36,7 @@

public class RequestLogTest {

private static final Logger LOG = LoggerFactory.getLogger(RequestLogTest.class);
private static final String REQUEST_RECEIVED = "Request received";

@Rule
@Rule
public SystemOutRule systemOut = new SystemOutRule();

private Server server;
Expand All @@ -65,7 +57,7 @@ private Server initJetty() throws Exception {
handler.addFilter(RequestLoggingFilter.class, "/*", EnumSet.of(DispatcherType.INCLUDE,
DispatcherType.REQUEST,
DispatcherType.ERROR, DispatcherType.FORWARD, DispatcherType.ASYNC));
handler.addServlet(TestServlet.class, "/test");
handler.addServlet(LoggingTestServlet.class, "/test");
server.start();
return server;
}
Expand Down Expand Up @@ -196,7 +188,7 @@ private String getBaseUrl() {
}

private String getCorrelationIdGenerated() throws IOException {
Map<String, Object> generationLog = systemOut.fineLineAsMapWith("logger", CorrelationIdFilter.class.getName());
Map<String, Object> generationLog = systemOut.findLineAsMapWith("logger", CorrelationIdFilter.class.getName());
if (generationLog == null) {
return null;
}
Expand All @@ -205,24 +197,15 @@ private String getCorrelationIdGenerated() throws IOException {
}

private Map<String, Object> getRequestMessage() throws IOException {
return systemOut.fineLineAsMapWith("msg", REQUEST_RECEIVED);
return systemOut.findLineAsMapWith("msg", LoggingTestServlet.LOG_MESSAGE);
}

private Map<String, Object> getRequestLog() throws IOException {
return systemOut.fineLineAsMapWith("layer", "[SERVLET]");
private Map<String, Object> getRequestLog() throws IOException {
return systemOut.findLineAsMapWith("layer", "[SERVLET]");
}

private static void assertFirstHeaderValue(String expected, CloseableHttpResponse response, HttpHeader header) {
String headerValue = response.getFirstHeader(header.getName()).getValue();
assertThat(headerValue, is(equalTo(expected)));
}

@SuppressWarnings("serial")
public static class TestServlet extends HttpServlet {

@Override
protected void doGet(HttpServletRequest req, HttpServletResponse resp) throws ServletException, IOException {
LOG.info(REQUEST_RECEIVED);
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -33,7 +33,7 @@ public String toString() {
return output.toString();
}

public Map<String, Object> fineLineAsMapWith(String key, String expected) throws IOException {
public Map<String, Object> findLineAsMapWith(String key, String expected) throws IOException {
for (String line : output.toString().split("\n")) {
Map<String, Object> map = JSON.std.mapFrom(line);
if (expected.equals(getAsString(map, key))) {
Expand Down

0 comments on commit 2f192a1

Please sign in to comment.