Skip to content

Commit ee3a9ce

Browse files
KarstenSchnitterKarstenSchnitter
committed
Improve Request Handling Without Request Logs
The RequestLoggingFilter serves two Use-Cases: * extract metadata from request headers and environment * collect and log request and response metrics There are scenarios where only the first use-case is required. In this case wrapping request and response, as well as request logging can be skipped altogether. This improves performance.
1 parent 90070f1 commit ee3a9ce

File tree

3 files changed

+70
-59
lines changed

3 files changed

+70
-59
lines changed

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

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,10 @@ public class RequestLogger {
2727
private HttpServletResponse httpResponse;
2828
private RequestRecord requestRecord;
2929

30+
public static final boolean isRequestLoggingEnabled() {
31+
return LOG.isInfoEnabled(Markers.REQUEST_MARKER);
32+
}
33+
3034
public RequestLogger(RequestRecord requestRecord, HttpServletRequest httpRequest,
3135
HttpServletResponse httpResponse) {
3236
this.requestRecord = requestRecord;

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

Lines changed: 17 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -101,6 +101,15 @@ private void doFilterRequest(HttpServletRequest httpRequest, HttpServletResponse
101101
httpResponse.setHeader(HttpHeaders.CORRELATION_ID.getName(), LogContext.getCorrelationId());
102102
}
103103

104+
/*
105+
* If request logging is disabled skip request instrumentation and continue the
106+
* filter chain immediately.
107+
*/
108+
if (!RequestLogger.isRequestLoggingEnabled()) {
109+
doFilter(chain, httpRequest, httpResponse);
110+
return;
111+
}
112+
104113
/*
105114
* -- we essentially do three things here: -- a) we create a log
106115
* record using our library and log it via STDOUT -- b) keep track
@@ -123,9 +132,7 @@ private void doFilterRequest(HttpServletRequest httpRequest, HttpServletResponse
123132

124133
/* -- start measuring right before calling up the filter chain -- */
125134
rr.start();
126-
if (chain != null) {
127-
chain.doFilter(httpRequest, httpResponse);
128-
}
135+
doFilter(chain, httpRequest, httpResponse);
129136

130137
if (!httpRequest.isAsyncStarted()) {
131138
loggingVisitor.logRequest();
@@ -141,4 +148,11 @@ private void doFilterRequest(HttpServletRequest httpRequest, HttpServletResponse
141148
}
142149
}
143150

151+
private void doFilter(FilterChain chain, HttpServletRequest httpRequest, HttpServletResponse httpResponse)
152+
throws IOException, ServletException {
153+
if (chain != null) {
154+
chain.doFilter(httpRequest, httpResponse);
155+
}
156+
}
157+
144158
}

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

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

3+
import static org.hamcrest.Matchers.empty;
34
import static org.hamcrest.Matchers.equalTo;
45
import static org.hamcrest.Matchers.hasEntry;
56
import static org.hamcrest.Matchers.is;
@@ -36,6 +37,9 @@
3637
import com.sap.hcp.cf.logging.common.request.HttpHeader;
3738
import com.sap.hcp.cf.logging.common.request.HttpHeaders;
3839

40+
import ch.qos.logback.classic.Level;
41+
import ch.qos.logback.classic.LoggerContext;
42+
3943
public class RequestLogTest {
4044

4145
private static final Logger LOG = LoggerFactory.getLogger(RequestLogTest.class);
@@ -73,115 +77,104 @@ public void tearDown() throws Exception {
7377
@Test
7478
public void logsCorrelationIdFromRequestHeader() throws Exception {
7579
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-
80+
HttpGet get = createRequestWithHeader(HttpHeaders.CORRELATION_ID.getName(), correlationId);
81+
try (CloseableHttpResponse response = client.execute(get)) {
8282
assertNull("No correlation_id should be generated.", getCorrelationIdGenerated());
8383

8484
assertThat("Application log without correlation id.", getRequestMessage(),
8585
hasEntry(Fields.CORRELATION_ID, correlationId));
8686
assertThat("Request log without correlation id.", getRequestLog(),
8787
hasEntry(Fields.CORRELATION_ID, correlationId));
88-
} finally {
89-
if (response != null) {
90-
response.close();
91-
}
9288
}
9389
}
9490

91+
private HttpGet createRequestWithHeader(String headerName, String headerValue) {
92+
HttpGet get = createRequest();
93+
get.setHeader(headerName, headerValue);
94+
return get;
95+
}
96+
97+
private HttpGet createRequest() {
98+
return new HttpGet(getBaseUrl() + "/test");
99+
}
100+
95101
@Test
96102
public void logsGeneratedCorrelationId() throws Exception {
97-
HttpGet get = new HttpGet(getBaseUrl() + "/test");
98-
CloseableHttpResponse response = null;
99-
try {
100-
response = client.execute(get);
101-
103+
try (CloseableHttpResponse response = client.execute(createRequest())) {
102104
String correlationId = getCorrelationIdGenerated();
103105

104106
assertThat("Application log without correlation id.", getRequestMessage(),
105107
hasEntry(Fields.CORRELATION_ID, correlationId));
106108
assertThat("Request log without correlation id.", getRequestLog(),
107109
hasEntry(Fields.CORRELATION_ID, correlationId));
108-
} finally {
109-
if (response != null) {
110-
response.close();
111-
}
112110
}
113111
}
114112

115113
@Test
116114
public void logsRequestIdFromRequestHeader() throws Exception {
117115
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-
116+
HttpGet get = createRequestWithHeader(HttpHeaders.X_VCAP_REQUEST_ID.getName(), requestId);
117+
try (CloseableHttpResponse response = client.execute(get)) {
124118
assertThat("Application log without request id.", getRequestMessage(),
125119
hasEntry(Fields.REQUEST_ID, requestId));
126120
assertThat("Request log without request id.", getRequestLog(),
127121
hasEntry(Fields.REQUEST_ID, requestId));
128-
} finally {
129-
if (response != null) {
130-
response.close();
131-
}
132122
}
133123
}
134124

135125
@Test
136126
public void logsTenantIdFromRequestHeader() throws Exception {
137127
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-
128+
HttpGet get = createRequestWithHeader(HttpHeaders.TENANT_ID.getName(), tenantId);
129+
try (CloseableHttpResponse response = client.execute(get)) {
144130
assertThat("Application log without tenant id.", getRequestMessage(),
145131
hasEntry(Fields.TENANT_ID, tenantId));
146132
assertThat("Request log without tenant id.", getRequestLog(), hasEntry(Fields.TENANT_ID, tenantId));
147-
} finally {
148-
if (response != null) {
149-
response.close();
150-
}
151133
}
152134
}
153135

154136
@Test
155137
public void writesCorrelationIdFromHeadersAsResponseHeader() throws Exception {
156138
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);
139+
HttpGet get = createRequestWithHeader(HttpHeaders.CORRELATION_ID.getName(), correlationId);
140+
try (CloseableHttpResponse response = client.execute(get)) {
162141
assertFirstHeaderValue(correlationId, response, HttpHeaders.CORRELATION_ID);
163-
} finally {
164-
if (response != null) {
165-
response.close();
166-
}
167142
}
168143
}
169144

170145
@Test
171146
public void writesGeneratedCorrelationIdAsResponseHeader() throws Exception {
172-
HttpGet get = new HttpGet(getBaseUrl() + "/test");
173-
CloseableHttpResponse response = null;
174-
try {
175-
response = client.execute(get);
176-
147+
try (CloseableHttpResponse response = client.execute(createRequest())) {
177148
assertFirstHeaderValue(getCorrelationIdGenerated(), response, HttpHeaders.CORRELATION_ID);
149+
}
150+
}
151+
152+
@Test
153+
public void writesNoRequestLogIfNotConfigured() throws Exception {
154+
setRequestLogLevel(Level.OFF);
155+
try (CloseableHttpResponse response = client.execute(createRequest())) {
156+
assertThat(getRequestLog().entrySet(), is(empty()));
157+
} finally {
158+
setRequestLogLevel(Level.INFO);
159+
}
160+
}
161+
162+
@Test
163+
public void logCorrelationIdFromHeaderEvenIfRequestLogNotConfigured() throws Exception {
164+
setRequestLogLevel(Level.OFF);
165+
String correlationId = UUID.randomUUID().toString();
166+
HttpGet get = createRequestWithHeader(HttpHeaders.CORRELATION_ID.getName(), correlationId);
167+
try (CloseableHttpResponse response = client.execute(get)) {
168+
assertThat("Application log without correlation id.", getRequestMessage(),
169+
hasEntry(Fields.CORRELATION_ID, correlationId));
178170
} finally {
179-
if (response != null) {
180-
response.close();
181-
}
171+
setRequestLogLevel(Level.INFO);
182172
}
183173
}
184174

175+
private void setRequestLogLevel(Level level) {
176+
((LoggerContext) LoggerFactory.getILoggerFactory()).getLogger(RequestLogger.class).setLevel(level);
177+
}
185178

186179
private String getBaseUrl() {
187180
int port = ((ServerConnector) server.getConnectors()[0]).getLocalPort();

0 commit comments

Comments
 (0)