Skip to content

Commit 709947e

Browse files
KarstenSchnitterKarstenSchnitter
committed
Fix correlation_id if generated and add as response header
Signed-off-by: Karsten Schnitter <[email protected]>
1 parent 780e104 commit 709947e

File tree

6 files changed

+289
-7
lines changed

6 files changed

+289
-7
lines changed

‎cf-java-logging-support-servlet/pom.xml

Lines changed: 28 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -5,13 +5,13 @@
55
<artifactId>cf-java-logging-support-servlet</artifactId>
66
<packaging>jar</packaging>
77

8-
<name>cf-java-logging-support-servlet</name>
9-
<parent>
10-
<groupId>com.sap.hcp.cf.logging</groupId>
11-
<artifactId>cf-java-logging-support-parent</artifactId>
12-
<version>3.0.2</version>
13-
<relativePath>../pom.xml</relativePath>
14-
</parent>
8+
<name>cf-java-logging-support-servlet</name>
9+
<parent>
10+
<groupId>com.sap.hcp.cf.logging</groupId>
11+
<artifactId>cf-java-logging-support-parent</artifactId>
12+
<version>3.0.2</version>
13+
<relativePath>../pom.xml</relativePath>
14+
</parent>
1515

1616
<properties>
1717
<servlet.api.version>3.0.1</servlet.api.version>
@@ -69,5 +69,26 @@
6969
<artifactId>jackson-databind</artifactId>
7070
<version>2.9.9.1</version>
7171
</dependency>
72+
73+
<!-- testing -->
74+
<dependency>
75+
<groupId>org.eclipse.jetty</groupId>
76+
<artifactId>jetty-server</artifactId>
77+
<version>9.4.19.v20190610</version>
78+
<scope>test</scope>
79+
</dependency>
80+
<dependency>
81+
<groupId>org.eclipse.jetty</groupId>
82+
<artifactId>jetty-servlet</artifactId>
83+
<version>9.4.19.v20190610</version>
84+
<scope>test</scope>
85+
</dependency>
86+
<dependency>
87+
<groupId>org.apache.httpcomponents</groupId>
88+
<artifactId>httpclient</artifactId>
89+
<version>4.5.9</version>
90+
<scope>test</scope>
91+
</dependency>
92+
7293
</dependencies>
7394
</project>

‎cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/HttpHeaderUtilities.java

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@
33
import javax.servlet.http.HttpServletRequest;
44
import javax.servlet.http.HttpServletResponse;
55

6+
import com.sap.hcp.cf.logging.common.LogContext;
67
import com.sap.hcp.cf.logging.common.request.HttpHeader;
78

89
public final class HttpHeaderUtilities {
@@ -25,14 +26,26 @@ public static String getHeaderValue(HttpServletRequest httpRequest, HttpHeader h
2526
return value;
2627
}
2728
}
29+
String contextFieldValue = getLogContextFieldValue(header);
30+
if (contextFieldValue != null) {
31+
return contextFieldValue;
32+
}
2833
return defaultValue;
2934
}
3035

36+
3137
private static String getHeaderValueInternal(HttpServletRequest httpRequest, HttpHeader header) {
3238
String headerName = header.getName();
3339
return httpRequest.getHeader(headerName);
3440
}
3541

42+
private static String getLogContextFieldValue(HttpHeader header) {
43+
if (header.getField() == null) {
44+
return null;
45+
}
46+
return LogContext.get(header.getField());
47+
}
48+
3649
public static String getHeaderValue(HttpServletResponse httpResponse, HttpHeader header) {
3750
return getHeaderValue(httpResponse, header, null);
3851
}

‎cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggingFilter.java

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -96,6 +96,10 @@ private void doFilterRequest(HttpServletRequest httpRequest, HttpServletResponse
9696

9797
RequestRecord rr = requestRecordFactory.create(httpRequest);
9898
httpRequest.setAttribute(MDC.class.getName(), MDC.getCopyOfContextMap());
99+
100+
if (!httpResponse.isCommitted() && httpResponse.getHeader(HttpHeaders.CORRELATION_ID.getName()) == null) {
101+
httpResponse.setHeader(HttpHeaders.CORRELATION_ID.getName(), LogContext.getCorrelationId());
102+
}
99103

100104
/*
101105
* -- we essentially do three things here: -- a) we create a log
@@ -133,6 +137,7 @@ private void doFilterRequest(HttpServletRequest httpRequest, HttpServletResponse
133137
if (dynamicLogLevelProcessor != null) {
134138
dynamicLogLevelProcessor.removeDynamicLogLevelFromMDC();
135139
}
140+
LogContext.resetContextFields();
136141
}
137142
}
138143

‎cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/RequestLogTest.java

Lines changed: 221 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,221 @@
1+
package com.sap.hcp.cf.logging.servlet.filter;
2+
3+
import static org.hamcrest.Matchers.equalTo;
4+
import static org.hamcrest.Matchers.hasEntry;
5+
import static org.hamcrest.Matchers.is;
6+
import static org.junit.Assert.assertNull;
7+
import static org.junit.Assert.assertThat;
8+
9+
import java.io.IOException;
10+
import java.util.EnumSet;
11+
import java.util.Map;
12+
import java.util.UUID;
13+
14+
import javax.servlet.DispatcherType;
15+
import javax.servlet.ServletException;
16+
import javax.servlet.http.HttpServlet;
17+
import javax.servlet.http.HttpServletRequest;
18+
import javax.servlet.http.HttpServletResponse;
19+
20+
import org.apache.http.client.methods.CloseableHttpResponse;
21+
import org.apache.http.client.methods.HttpGet;
22+
import org.apache.http.impl.client.CloseableHttpClient;
23+
import org.apache.http.impl.client.HttpClientBuilder;
24+
import org.eclipse.jetty.server.Server;
25+
import org.eclipse.jetty.server.ServerConnector;
26+
import org.eclipse.jetty.servlet.ServletContextHandler;
27+
import org.junit.After;
28+
import org.junit.Before;
29+
import org.junit.Rule;
30+
import org.junit.Test;
31+
import org.slf4j.Logger;
32+
import org.slf4j.LoggerFactory;
33+
34+
import com.sap.hcp.cf.logging.common.Fields;
35+
import com.sap.hcp.cf.logging.common.LogContext;
36+
import com.sap.hcp.cf.logging.common.request.HttpHeader;
37+
import com.sap.hcp.cf.logging.common.request.HttpHeaders;
38+
39+
public class RequestLogTest {
40+
41+
private static final Logger LOG = LoggerFactory.getLogger(RequestLogTest.class);
42+
private static final String REQUEST_RECEIVED = "Request received";
43+
44+
@Rule
45+
public SystemOutRule systemOut = new SystemOutRule();
46+
47+
private Server server;
48+
private CloseableHttpClient client;
49+
50+
@Before
51+
public void setUp() throws Exception {
52+
this.server = initJetty();
53+
this.client = HttpClientBuilder.create().build();
54+
55+
}
56+
57+
private Server initJetty() throws Exception {
58+
Server server = new Server(0);
59+
ServletContextHandler handler = new ServletContextHandler(server, null);
60+
handler.addFilter(RequestLoggingFilter.class, "/*", EnumSet.of(DispatcherType.INCLUDE, DispatcherType.REQUEST,
61+
DispatcherType.ERROR, DispatcherType.FORWARD, DispatcherType.ASYNC));
62+
handler.addServlet(TestServlet.class, "/test");
63+
server.start();
64+
return server;
65+
}
66+
67+
@After
68+
public void tearDown() throws Exception {
69+
client.close();
70+
server.stop();
71+
}
72+
73+
@Test
74+
public void logsCorrelationIdFromRequestHeader() throws Exception {
75+
String correlationId = UUID.randomUUID().toString();
76+
HttpGet get = new HttpGet(getBaseUrl() + "/test");
77+
get.setHeader(HttpHeaders.CORRELATION_ID.getName(), correlationId);
78+
CloseableHttpResponse response = null;
79+
try {
80+
response = client.execute(get);
81+
82+
assertNull("No correlation_id should be generated.", getCorrelationIdGenerated());
83+
84+
assertThat("Application log without correlation id.", getRequestMessage(),
85+
hasEntry(Fields.CORRELATION_ID, correlationId));
86+
assertThat("Request log without correlation id.", getRequestLog(),
87+
hasEntry(Fields.CORRELATION_ID, correlationId));
88+
} finally {
89+
if (response != null) {
90+
response.close();
91+
}
92+
}
93+
}
94+
95+
@Test
96+
public void logsGeneratedCorrelationId() throws Exception {
97+
HttpGet get = new HttpGet(getBaseUrl() + "/test");
98+
CloseableHttpResponse response = null;
99+
try {
100+
response = client.execute(get);
101+
102+
String correlationId = getCorrelationIdGenerated();
103+
104+
assertThat("Application log without correlation id.", getRequestMessage(),
105+
hasEntry(Fields.CORRELATION_ID, correlationId));
106+
assertThat("Request log without correlation id.", getRequestLog(),
107+
hasEntry(Fields.CORRELATION_ID, correlationId));
108+
} finally {
109+
if (response != null) {
110+
response.close();
111+
}
112+
}
113+
}
114+
115+
@Test
116+
public void logsRequestIdFromRequestHeader() throws Exception {
117+
String requestId = UUID.randomUUID().toString();
118+
HttpGet get = new HttpGet(getBaseUrl() + "/test");
119+
get.setHeader(HttpHeaders.X_VCAP_REQUEST_ID.getName(), requestId);
120+
CloseableHttpResponse response = null;
121+
try {
122+
response = client.execute(get);
123+
124+
assertThat("Application log without request id.", getRequestMessage(),
125+
hasEntry(Fields.REQUEST_ID, requestId));
126+
assertThat("Request log without request id.", getRequestLog(),
127+
hasEntry(Fields.REQUEST_ID, requestId));
128+
} finally {
129+
if (response != null) {
130+
response.close();
131+
}
132+
}
133+
}
134+
135+
@Test
136+
public void logsTenantIdFromRequestHeader() throws Exception {
137+
String tenantId = UUID.randomUUID().toString();
138+
HttpGet get = new HttpGet(getBaseUrl() + "/test");
139+
get.setHeader(HttpHeaders.TENANT_ID.getName(), tenantId);
140+
CloseableHttpResponse response = null;
141+
try {
142+
response = client.execute(get);
143+
144+
assertThat("Application log without tenant id.", getRequestMessage(),
145+
hasEntry(Fields.TENANT_ID, tenantId));
146+
assertThat("Request log without tenant id.", getRequestLog(), hasEntry(Fields.TENANT_ID, tenantId));
147+
} finally {
148+
if (response != null) {
149+
response.close();
150+
}
151+
}
152+
}
153+
154+
@Test
155+
public void writesCorrelationIdFromHeadersAsResponseHeader() throws Exception {
156+
String correlationId = UUID.randomUUID().toString();
157+
HttpGet get = new HttpGet(getBaseUrl() + "/test");
158+
get.setHeader(HttpHeaders.CORRELATION_ID.getName(), correlationId);
159+
CloseableHttpResponse response = null;
160+
try {
161+
response = client.execute(get);
162+
assertFirstHeaderValue(correlationId, response, HttpHeaders.CORRELATION_ID);
163+
} finally {
164+
if (response != null) {
165+
response.close();
166+
}
167+
}
168+
}
169+
170+
@Test
171+
public void writesGeneratedCorrelationIdAsResponseHeader() throws Exception {
172+
HttpGet get = new HttpGet(getBaseUrl() + "/test");
173+
CloseableHttpResponse response = null;
174+
try {
175+
response = client.execute(get);
176+
177+
assertFirstHeaderValue(getCorrelationIdGenerated(), response, HttpHeaders.CORRELATION_ID);
178+
} finally {
179+
if (response != null) {
180+
response.close();
181+
}
182+
}
183+
}
184+
185+
186+
private String getBaseUrl() {
187+
int port = ((ServerConnector) server.getConnectors()[0]).getLocalPort();
188+
return "http://localhost:" + port;
189+
}
190+
191+
private String getCorrelationIdGenerated() throws IOException {
192+
Map<Object, Object> generationLog = systemOut.fineLineAsMapWith("logger", LogContext.class.getName());
193+
if (generationLog == null) {
194+
return null;
195+
}
196+
return generationLog.get(Fields.CORRELATION_ID) == null ? null
197+
: generationLog.get(Fields.CORRELATION_ID).toString();
198+
}
199+
200+
private Map<Object, Object> getRequestMessage() throws IOException {
201+
return systemOut.fineLineAsMapWith("msg", REQUEST_RECEIVED);
202+
}
203+
204+
private Map<Object, Object> getRequestLog() throws IOException {
205+
return systemOut.fineLineAsMapWith("layer", "[SERVLET]");
206+
}
207+
208+
private static void assertFirstHeaderValue(String expected, CloseableHttpResponse response, HttpHeader header) {
209+
String headerValue = response.getFirstHeader(header.getName()).getValue();
210+
assertThat(headerValue, is(equalTo(expected)));
211+
}
212+
213+
@SuppressWarnings("serial")
214+
public static class TestServlet extends HttpServlet {
215+
216+
@Override
217+
protected void doGet(HttpServletRequest req, HttpServletResponse resp) throws ServletException, IOException {
218+
LOG.info(REQUEST_RECEIVED);
219+
}
220+
}
221+
}

‎cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggingFilterTest.java

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -62,6 +62,7 @@ public class RequestLoggingFilterTest {
6262

6363
@Before
6464
public void initMocks() throws IOException {
65+
Mockito.reset(mockReq, mockResp, mockWriter);
6566
when(mockResp.getWriter()).thenReturn(mockWriter);
6667

6768
Map<String, String> contextMap = new HashMap<>();

‎cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/SystemOutRule.java

Lines changed: 21 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,11 +1,16 @@
11
package com.sap.hcp.cf.logging.servlet.filter;
22

33
import java.io.ByteArrayOutputStream;
4+
import java.io.IOException;
45
import java.io.OutputStream;
56
import java.io.PrintStream;
7+
import java.util.Collections;
8+
import java.util.Map;
69

710
import org.junit.rules.ExternalResource;
811

12+
import com.fasterxml.jackson.jr.ob.JSON;
13+
914
public class SystemOutRule extends ExternalResource {
1015

1116
private PrintStream originalOut;
@@ -27,4 +32,20 @@ protected void after() {
2732
public String toString() {
2833
return output.toString();
2934
}
35+
36+
public Map<Object, Object> fineLineAsMapWith(String key, String expected) throws IOException {
37+
for (String line : output.toString().split("\n")) {
38+
Map<Object, Object> map = JSON.std.mapFrom(line);
39+
if (expected.equals(getAsString(map, key))) {
40+
return map;
41+
}
42+
}
43+
return Collections.emptyMap();
44+
}
45+
46+
private String getAsString(Map<Object, Object> map, String key) {
47+
Object value = map.get(key);
48+
return value != null ? value.toString() : null;
49+
}
50+
3051
}

0 commit comments

Comments
 (0)