Skip to content

Commit 67b4c48

Browse files
weidongxu-microsoftweidongxu-microsoft
authored
mgmt, add a proper logging for debug, not to be released (Azure#20945)
1 parent eef4b16 commit 67b4c48

File tree

4 files changed

+272
-0
lines changed

4 files changed

+272
-0
lines changed

‎eng/code-quality-reports/src/main/resources/checkstyle/checkstyle-suppressions.xml‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -441,6 +441,7 @@ the main ServiceBusClientBuilder. -->
441441

442442
<!-- Checkstyle suppressions for resource manager package -->
443443
<suppress checks="com.azure.tools.checkstyle.checks.ServiceClientCheck" files="com.azure.resourcemanager.*"/>
444+
<suppress checks="com.azure.tools.checkstyle.checks.GoodLoggingCheck" files="com.azure.resourcemanager.test.policy.HttpDebugLoggingPolicy.java"/>
444445

445446
<!-- Checkstyle suppression for Event Hubs client APIs that use Flux instead of PagedFlux for methods that return a collection -->
446447
<suppress checks="com.azure.tools.checkstyle.checks.ServiceClientCheck" files="com.azure.messaging.eventhubs.EventHubConsumerClient.java"/>

‎sdk/resourcemanager/azure-resourcemanager-keyvault/pom.xml‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -180,6 +180,8 @@
180180
<artifactId>revapi-maven-plugin</artifactId>
181181
<version>0.11.2</version> <!-- {x-version-update;org.revapi:revapi-maven-plugin;external_dependency} -->
182182
<configuration>
183+
<skip>true</skip>
184+
183185
<analysisConfiguration>
184186
<revapi.ignore>
185187
<item>

‎sdk/resourcemanager/azure-resourcemanager-test/src/main/java/com/azure/resourcemanager/test/ResourceManagerTestBase.java‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,7 @@
2020
import com.azure.core.util.Configuration;
2121
import com.azure.core.util.logging.ClientLogger;
2222
import com.azure.identity.ClientSecretCredentialBuilder;
23+
import com.azure.resourcemanager.test.policy.HttpDebugLoggingPolicy;
2324
import com.azure.resourcemanager.test.policy.TextReplacementPolicy;
2425
import com.azure.resourcemanager.test.utils.AuthFile;
2526

@@ -243,6 +244,10 @@ protected void beforeTest() {
243244
if (!interceptorManager.isLiveMode() && !testContextManager.doNotRecordTest()) {
244245
policies.add(new TextReplacementPolicy(interceptorManager.getRecordedData(), textReplacementRules));
245246
}
247+
if (httpLogDetailLevel == HttpLogDetailLevel.BODY_AND_HEADERS) {
248+
policies.add(new HttpDebugLoggingPolicy());
249+
httpLogDetailLevel = HttpLogDetailLevel.NONE;
250+
}
246251
httpPipeline = buildHttpPipeline(
247252
credential,
248253
testProfile,

‎sdk/resourcemanager/azure-resourcemanager-test/src/main/java/com/azure/resourcemanager/test/policy/HttpDebugLoggingPolicy.java‎

Lines changed: 264 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,264 @@
1+
// Copyright (c) Microsoft Corporation. All rights reserved.
2+
// Licensed under the MIT License.
3+
4+
package com.azure.resourcemanager.test.policy;
5+
6+
import com.azure.core.http.ContentType;
7+
import com.azure.core.http.HttpHeader;
8+
import com.azure.core.http.HttpHeaders;
9+
import com.azure.core.http.HttpPipelineCallContext;
10+
import com.azure.core.http.HttpPipelineNextPolicy;
11+
import com.azure.core.http.HttpRequest;
12+
import com.azure.core.http.HttpResponse;
13+
import com.azure.core.http.policy.HttpLoggingPolicy;
14+
import com.azure.core.http.policy.HttpPipelinePolicy;
15+
import com.azure.core.util.CoreUtils;
16+
import com.fasterxml.jackson.databind.ObjectMapper;
17+
import com.fasterxml.jackson.databind.SerializationFeature;
18+
import org.slf4j.Logger;
19+
import org.slf4j.LoggerFactory;
20+
import reactor.core.publisher.Mono;
21+
22+
import java.io.ByteArrayOutputStream;
23+
import java.io.IOException;
24+
import java.io.UnsupportedEncodingException;
25+
import java.nio.ByteBuffer;
26+
import java.nio.channels.Channels;
27+
import java.nio.channels.WritableByteChannel;
28+
import java.nio.charset.StandardCharsets;
29+
import java.util.HashSet;
30+
import java.util.Locale;
31+
import java.util.Optional;
32+
import java.util.Set;
33+
import java.util.concurrent.TimeUnit;
34+
35+
/**
36+
* The pipeline policy that handles logging of HTTP requests and responses.
37+
*/
38+
public class HttpDebugLoggingPolicy implements HttpPipelinePolicy {
39+
40+
private static final ObjectMapper PRETTY_PRINTER = new ObjectMapper().enable(SerializationFeature.INDENT_OUTPUT);
41+
private static final String REDACTED_PLACEHOLDER = "REDACTED";
42+
private static final Set<String> DISALLOWED_HEADER_NAMES = new HashSet<>();
43+
private static final boolean PRETTY_PRINT_BODY = true;
44+
45+
/**
46+
* Creates an HttpDebugLoggingPolicy with the given log configurations.
47+
*/
48+
public HttpDebugLoggingPolicy() {
49+
DISALLOWED_HEADER_NAMES.add("authorization");
50+
}
51+
52+
@Override
53+
public Mono<HttpResponse> process(HttpPipelineCallContext context, HttpPipelineNextPolicy next) {
54+
final Logger logger = LoggerFactory.getLogger((String) context.getData("caller-method").orElse(""));
55+
final long startNs = System.nanoTime();
56+
57+
return logRequest(logger, context.getHttpRequest(), context.getData(HttpLoggingPolicy.RETRY_COUNT_CONTEXT))
58+
.then(next.process())
59+
.flatMap(response -> logResponse(logger, response, startNs))
60+
.doOnError(throwable -> logger.warn("<-- HTTP FAILED: ", throwable));
61+
}
62+
63+
private Mono<Void> logRequest(final Logger logger, final HttpRequest request,
64+
final Optional<Object> optionalRetryCount) {
65+
if (!logger.isInfoEnabled()) {
66+
return Mono.empty();
67+
}
68+
69+
StringBuilder requestLogMessage = new StringBuilder();
70+
requestLogMessage.append("--> ")
71+
.append(request.getHttpMethod())
72+
.append(" ")
73+
.append(request.getUrl())
74+
.append(System.lineSeparator());
75+
76+
optionalRetryCount.ifPresent(o -> requestLogMessage.append("Try count: ")
77+
.append(o)
78+
.append(System.lineSeparator()));
79+
80+
addHeadersToLogMessage(logger, request.getHeaders(), requestLogMessage);
81+
82+
if (request.getBody() == null) {
83+
requestLogMessage.append("(empty body)")
84+
.append(System.lineSeparator())
85+
.append("--> END ")
86+
.append(request.getHttpMethod())
87+
.append(System.lineSeparator());
88+
89+
return logAndReturn(logger, requestLogMessage, null);
90+
}
91+
92+
String contentType = request.getHeaders().getValue("Content-Type");
93+
long contentLength = getContentLength(logger, request.getHeaders());
94+
95+
if (shouldBodyBeLogged(contentType, contentLength)) {
96+
ByteArrayOutputStream outputStream = new ByteArrayOutputStream((int) contentLength);
97+
WritableByteChannel bodyContentChannel = Channels.newChannel(outputStream);
98+
99+
// Add non-mutating operators to the data stream.
100+
request.setBody(
101+
request.getBody()
102+
.flatMap(byteBuffer -> writeBufferToBodyStream(bodyContentChannel, byteBuffer))
103+
.doFinally(ignored -> {
104+
requestLogMessage.append(contentLength)
105+
.append("-byte body:")
106+
.append(System.lineSeparator())
107+
.append(prettyPrintIfNeeded(logger, contentType,
108+
convertStreamToString(outputStream, logger)))
109+
.append(System.lineSeparator())
110+
.append("--> END ")
111+
.append(request.getHttpMethod())
112+
.append(System.lineSeparator());
113+
114+
logger.info(requestLogMessage.toString());
115+
}));
116+
117+
return Mono.empty();
118+
} else {
119+
requestLogMessage.append(contentLength)
120+
.append("-byte body: (content not logged)")
121+
.append(System.lineSeparator())
122+
.append("--> END ")
123+
.append(request.getHttpMethod())
124+
.append(System.lineSeparator());
125+
126+
return logAndReturn(logger, requestLogMessage, null);
127+
}
128+
}
129+
130+
/*
131+
* Logs thr HTTP response.
132+
*
133+
* @param logger Logger used to log the response.
134+
* @param response HTTP response returned from Azure.
135+
* @param startNs Nanosecond representation of when the request was sent.
136+
* @return A Mono containing the HTTP response.
137+
*/
138+
private Mono<HttpResponse> logResponse(final Logger logger, final HttpResponse response, long startNs) {
139+
if (!logger.isInfoEnabled()) {
140+
return Mono.just(response);
141+
}
142+
143+
long tookMs = TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - startNs);
144+
145+
String contentLengthString = response.getHeaderValue("Content-Length");
146+
String bodySize = (CoreUtils.isNullOrEmpty(contentLengthString))
147+
? "unknown-length body"
148+
: contentLengthString + "-byte body";
149+
150+
StringBuilder responseLogMessage = new StringBuilder();
151+
responseLogMessage.append("<-- ")
152+
.append(response.getStatusCode())
153+
.append(" ")
154+
.append(response.getRequest().getUrl())
155+
.append(" (")
156+
.append(tookMs)
157+
.append(" ms, ")
158+
.append(bodySize)
159+
.append(")")
160+
.append(System.lineSeparator());
161+
162+
addHeadersToLogMessage(logger, response.getHeaders(), responseLogMessage);
163+
164+
String contentTypeHeader = response.getHeaderValue("Content-Type");
165+
long contentLength = getContentLength(logger, response.getHeaders());
166+
167+
if (shouldBodyBeLogged(contentTypeHeader, contentLength)) {
168+
HttpResponse bufferedResponse = response.buffer();
169+
ByteArrayOutputStream outputStream = new ByteArrayOutputStream((int) contentLength);
170+
WritableByteChannel bodyContentChannel = Channels.newChannel(outputStream);
171+
return bufferedResponse.getBody()
172+
.flatMap(byteBuffer -> writeBufferToBodyStream(bodyContentChannel, byteBuffer))
173+
.doFinally(ignored -> {
174+
responseLogMessage.append("Response body:")
175+
.append(System.lineSeparator())
176+
.append(prettyPrintIfNeeded(logger, contentTypeHeader,
177+
convertStreamToString(outputStream, logger)))
178+
.append(System.lineSeparator())
179+
.append("<-- END HTTP");
180+
181+
logger.info(responseLogMessage.toString());
182+
}).then(Mono.just(bufferedResponse));
183+
} else {
184+
responseLogMessage.append("(body content not logged)")
185+
.append(System.lineSeparator())
186+
.append("<-- END HTTP");
187+
188+
return logAndReturn(logger, responseLogMessage, response);
189+
}
190+
}
191+
192+
private <T> Mono<T> logAndReturn(Logger logger, StringBuilder logMessageBuilder, T data) {
193+
logger.info(logMessageBuilder.toString());
194+
return Mono.justOrEmpty(data);
195+
}
196+
197+
private void addHeadersToLogMessage(Logger logger, HttpHeaders headers, StringBuilder sb) {
198+
for (HttpHeader header : headers) {
199+
String headerName = header.getName();
200+
sb.append(headerName).append(":");
201+
if (!DISALLOWED_HEADER_NAMES.contains(headerName.toLowerCase(Locale.ROOT))) {
202+
sb.append(header.getValue());
203+
} else {
204+
sb.append(REDACTED_PLACEHOLDER);
205+
}
206+
sb.append(System.lineSeparator());
207+
}
208+
}
209+
210+
private String prettyPrintIfNeeded(Logger logger, String contentType, String body) {
211+
String result = body;
212+
if (PRETTY_PRINT_BODY && contentType != null
213+
&& (contentType.startsWith(ContentType.APPLICATION_JSON) || contentType.startsWith("text/json"))) {
214+
try {
215+
final Object deserialized = PRETTY_PRINTER.readTree(body);
216+
result = PRETTY_PRINTER.writeValueAsString(deserialized);
217+
} catch (Exception e) {
218+
logger.warn("Failed to pretty print JSON: {}", e.getMessage());
219+
}
220+
}
221+
return result;
222+
}
223+
224+
private long getContentLength(Logger logger, HttpHeaders headers) {
225+
long contentLength = 0;
226+
227+
String contentLengthString = headers.getValue("Content-Length");
228+
if (CoreUtils.isNullOrEmpty(contentLengthString)) {
229+
return contentLength;
230+
}
231+
232+
try {
233+
contentLength = Long.parseLong(contentLengthString);
234+
} catch (NumberFormatException | NullPointerException e) {
235+
logger.warn("Could not parse the HTTP header content-length: '{}'.",
236+
headers.getValue("content-length"), e);
237+
}
238+
239+
return contentLength;
240+
}
241+
242+
private boolean shouldBodyBeLogged(String contentTypeHeader, long contentLength) {
243+
return !ContentType.APPLICATION_OCTET_STREAM.equalsIgnoreCase(contentTypeHeader)
244+
&& contentLength != 0;
245+
}
246+
247+
private static String convertStreamToString(ByteArrayOutputStream stream, Logger logger) {
248+
try {
249+
return stream.toString(StandardCharsets.UTF_8.name());
250+
} catch (UnsupportedEncodingException ex) {
251+
logger.error(ex.toString());
252+
throw new RuntimeException(ex);
253+
}
254+
}
255+
256+
private static Mono<ByteBuffer> writeBufferToBodyStream(WritableByteChannel channel, ByteBuffer byteBuffer) {
257+
try {
258+
channel.write(byteBuffer.duplicate());
259+
return Mono.just(byteBuffer);
260+
} catch (IOException ex) {
261+
return Mono.error(ex);
262+
}
263+
}
264+
}

0 commit comments

Comments
 (0)