Spring/spring-framework
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

Add LogFormatUtils

Browse Source 
1. Helper method to eliminate duplication in formatting (de-)serialized
   values for logging introduced with prior commit #e62298.

2. Helper method for TRACE vs DEBUG logging with different details.

Issue: SPR-17254
This commit is contained in:
Rossen Stoyanchev
2018-09-14 14:38:11 -04:00
parent 41d4cb5cbf
commit db8e9eafb2
24 changed files with 212 additions and 289 deletions
Download Patch File Download Diff File Expand all files Collapse all files

17
spring-web/src/main/java/org/springframework/http/codec/FormHttpMessageReader.java
View File

@@ -31,6 +31,7 @@ import reactor.core.publisher.Mono;
import org.springframework.core.ResolvableType;
import org.springframework.core.codec.Hints;
import org.springframework.core.io.buffer.DataBufferUtils;
import org.springframework.core.log.LogFormatUtils;
import org.springframework.http.MediaType;
import org.springframework.http.ReactiveHttpInputMessage;
import org.springframework.lang.Nullable;
@@ -114,18 +115,10 @@ public class FormHttpMessageReader extends LoggingCodecSupport
}
private void logFormData(MultiValueMap<String, String> formData, Map<String, Object> hints) {
if (logger.isDebugEnabled()) {
String s = Hints.getLogPrefix(hints) + "Read " +
(isEnableLoggingRequestDetails() ?
formatValue(formData, logger.isTraceEnabled()) :
"form fields " + formData.keySet() + " (content masked)");
if (logger.isTraceEnabled()) {
logger.trace(s);
}
else {
logger.debug(s);
}
}
LogFormatUtils.traceDebug(logger, traceOn -> Hints.getLogPrefix(hints) + "Read " +
(isEnableLoggingRequestDetails() ?
LogFormatUtils.formatValue(formData, !traceOn) :
"form fields " + formData.keySet() + " (content masked)"));
}
private Charset getMediaTypeCharset(@Nullable MediaType mediaType) {

21
spring-web/src/main/java/org/springframework/http/codec/FormHttpMessageWriter.java
View File

@@ -31,6 +31,7 @@ import reactor.core.publisher.Mono;
import org.springframework.core.ResolvableType;
import org.springframework.core.codec.Hints;
import org.springframework.core.io.buffer.DataBuffer;
import org.springframework.core.log.LogFormatUtils;
import org.springframework.http.MediaType;
import org.springframework.http.ReactiveHttpOutputMessage;
import org.springframework.lang.Nullable;
@@ -131,18 +132,7 @@ public class FormHttpMessageWriter extends LoggingCodecSupport
Assert.notNull(charset, "No charset"); // should never occur
return Mono.from(inputStream).flatMap(form -> {
if (logger.isDebugEnabled()) {
String s = Hints.getLogPrefix(hints) + "Writing " +
(isEnableLoggingRequestDetails() ?
formatValue(form, logger.isTraceEnabled()) :
"form fields " + form.keySet() + " (content masked)");
if (logger.isTraceEnabled()) {
logger.trace(s);
}
else {
logger.debug(s);
}
}
logFormData(form, hints);
String value = serializeForm(form, charset);
ByteBuffer byteBuffer = charset.encode(value);
DataBuffer buffer = message.bufferFactory().wrap(byteBuffer);
@@ -163,6 +153,13 @@ public class FormHttpMessageWriter extends LoggingCodecSupport
}
}
private void logFormData(MultiValueMap<String, String> form, Map<String, Object> hints) {
LogFormatUtils.traceDebug(logger, traceOn -> Hints.getLogPrefix(hints) + "Writing " +
(isEnableLoggingRequestDetails() ?
LogFormatUtils.formatValue(form, !traceOn) :
"form fields " + form.keySet() + " (content masked)"));
}
protected String serializeForm(MultiValueMap<String, String> formData, Charset charset) {
StringBuilder builder = new StringBuilder();
formData.forEach((name, values) ->

17
spring-web/src/main/java/org/springframework/http/codec/LoggingCodecSupport.java
View File

@@ -19,7 +19,6 @@ package org.springframework.http.codec;
import org.apache.commons.logging.Log;
import org.springframework.http.HttpLogging;
import org.springframework.lang.Nullable;
/**
* Base class for {@link org.springframework.core.codec.Encoder},
@@ -56,20 +55,4 @@ public class LoggingCodecSupport {
return this.enableLoggingRequestDetails;
}
/**
* Format the given value via {{toString()}}, either in full or truncated
* if it has 100 or more characters.
* @param value the value to format
* @param logFullValue whether to log in full or truncate if necessary
* @return the formatted value
* @since 5.1
*/
protected String formatValue(@Nullable Object value, boolean logFullValue) {
if (value == null) {
return "";
}
String s = value instanceof CharSequence ? "\"" + value + "\"" : value.toString();
return logFullValue || s.length() < 100 ? s : s.substring(0, 100) + " (truncated)...";
}
}

15
spring-web/src/main/java/org/springframework/http/codec/json/AbstractJackson2Decoder.java
View File

@@ -38,6 +38,7 @@ import org.springframework.core.codec.CodecException;
import org.springframework.core.codec.DecodingException;
import org.springframework.core.codec.Hints;
import org.springframework.core.io.buffer.DataBuffer;
import org.springframework.core.log.LogFormatUtils;
import org.springframework.http.codec.HttpMessageDecoder;
import org.springframework.http.server.reactive.ServerHttpRequest;
import org.springframework.http.server.reactive.ServerHttpResponse;
@@ -115,15 +116,11 @@ public abstract class AbstractJackson2Decoder extends Jackson2CodecSupport imple
return tokens.map(tokenBuffer -> {
try {
Object value = reader.readValue(tokenBuffer.asParser(getObjectMapper()));
if (logger.isDebugEnabled() && !Hints.isLoggingSuppressed(hints)) {
boolean traceOn = logger.isTraceEnabled();
String s = Hints.getLogPrefix(hints) + "Decoded [" + formatValue(value, traceOn) + "]";
if (traceOn) {
logger.trace(s);
}
else {
logger.debug(s);
}
if (!Hints.isLoggingSuppressed(hints)) {
LogFormatUtils.traceDebug(logger, traceOn -> {
String formatted = LogFormatUtils.formatValue(value, !traceOn);
return Hints.getLogPrefix(hints) + "Decoded [" + formatted + "]";
});
}
return value;
}

15
spring-web/src/main/java/org/springframework/http/codec/json/AbstractJackson2Encoder.java
View File

@@ -44,6 +44,7 @@ import org.springframework.core.codec.EncodingException;
import org.springframework.core.codec.Hints;
import org.springframework.core.io.buffer.DataBuffer;
import org.springframework.core.io.buffer.DataBufferFactory;
import org.springframework.core.log.LogFormatUtils;
import org.springframework.http.MediaType;
import org.springframework.http.codec.HttpMessageEncoder;
import org.springframework.http.server.reactive.ServerHttpRequest;
@@ -141,15 +142,11 @@ public abstract class AbstractJackson2Encoder extends Jackson2CodecSupport imple
private DataBuffer encodeValue(Object value, @Nullable MimeType mimeType, DataBufferFactory bufferFactory,
ResolvableType elementType, @Nullable Map<String, Object> hints, JsonEncoding encoding) {
if (logger.isDebugEnabled() && !Hints.isLoggingSuppressed(hints)) {
boolean traceOn = logger.isTraceEnabled();
String s = Hints.getLogPrefix(hints) + "Encoding [" + formatValue(value, traceOn) + "]";
if (traceOn) {
logger.trace(s);
}
else {
logger.debug(s);
}
if (!Hints.isLoggingSuppressed(hints)) {
LogFormatUtils.traceDebug(logger, traceOn -> {
String formatted = LogFormatUtils.formatValue(value, !traceOn);
return Hints.getLogPrefix(hints) + "Encoding [" + formatted + "]";
});
}
JavaType javaType = getJavaType(elementType.getType(), null);

8
spring-web/src/main/java/org/springframework/http/codec/json/Jackson2CodecSupport.java
View File

@@ -125,12 +125,4 @@ public abstract class Jackson2CodecSupport {
@Nullable
protected abstract <A extends Annotation> A getAnnotation(MethodParameter parameter, Class<A> annotType);
String formatValue(@Nullable Object value, boolean logFullValue) {
if (value == null) {
return "";
}
String s = value instanceof CharSequence ? "\"" + value + "\"" : value.toString();
return logFullValue || s.length() < 100 ? s : s.substring(0, 100) + " (truncated)...";
}
}

17
spring-web/src/main/java/org/springframework/http/codec/multipart/MultipartHttpMessageReader.java
View File

@@ -28,6 +28,7 @@ import reactor.core.publisher.Mono;
import org.springframework.core.ResolvableType;
import org.springframework.core.codec.Hints;
import org.springframework.core.log.LogFormatUtils;
import org.springframework.http.MediaType;
import org.springframework.http.ReactiveHttpInputMessage;
import org.springframework.http.codec.HttpMessageReader;
@@ -94,18 +95,10 @@ public class MultipartHttpMessageReader extends LoggingCodecSupport
return this.partReader.read(elementType, inputMessage, allHints)
.collectMultimap(Part::name)
.doOnNext(map -> {
if (logger.isDebugEnabled()) {
String s = Hints.getLogPrefix(hints) + "Parsed " +
(isEnableLoggingRequestDetails() ?
formatValue(map, logger.isTraceEnabled()) :
"parts " + map.keySet() + " (content masked)");
if (logger.isTraceEnabled()) {
logger.trace(s);
}
else {
logger.debug(s);
}
}
LogFormatUtils.traceDebug(logger, traceOn -> Hints.getLogPrefix(hints) + "Parsed " +
(isEnableLoggingRequestDetails() ?
LogFormatUtils.formatValue(map, !traceOn) :
"parts " + map.keySet() + " (content masked)"));
})
.map(this::toMultiValueMap);
}

17
spring-web/src/main/java/org/springframework/http/codec/multipart/MultipartHttpMessageWriter.java
View File

@@ -41,6 +41,7 @@ import org.springframework.core.io.Resource;
import org.springframework.core.io.buffer.DataBuffer;
import org.springframework.core.io.buffer.DataBufferFactory;
import org.springframework.core.io.buffer.DefaultDataBufferFactory;
import org.springframework.core.log.LogFormatUtils;
import org.springframework.http.HttpEntity;
import org.springframework.http.HttpHeaders;
import org.springframework.http.MediaType;
@@ -225,18 +226,10 @@ public class MultipartHttpMessageWriter extends LoggingCodecSupport
outputMessage.getHeaders().setContentType(new MediaType(MediaType.MULTIPART_FORM_DATA, params));
if (logger.isDebugEnabled()) {
String s = Hints.getLogPrefix(hints) + "Encoding " +
(isEnableLoggingRequestDetails() ?
formatValue(map, logger.isTraceEnabled()) :
"parts " + map.keySet() + " (content masked)");
if (logger.isTraceEnabled()) {
logger.trace(s);
}
else {
logger.debug(s);
}
}
LogFormatUtils.traceDebug(logger, traceOn -> Hints.getLogPrefix(hints) + "Encoding " +
(isEnableLoggingRequestDetails() ?
LogFormatUtils.formatValue(map, !traceOn) :
"parts " + map.keySet() + " (content masked)"));
Flux<DataBuffer> body = Flux.fromIterable(map.entrySet())
.concatMap(entry -> encodePartValues(boundary, entry.getKey(), entry.getValue()))

15
spring-web/src/main/java/org/springframework/http/codec/multipart/SynchronossPartHttpMessageReader.java
View File

@@ -50,6 +50,7 @@ import org.springframework.core.io.buffer.DataBuffer;
import org.springframework.core.io.buffer.DataBufferFactory;
import org.springframework.core.io.buffer.DataBufferUtils;
import org.springframework.core.io.buffer.DefaultDataBufferFactory;
import org.springframework.core.log.LogFormatUtils;
import org.springframework.http.HttpHeaders;
import org.springframework.http.MediaType;
import org.springframework.http.ReactiveHttpInputMessage;
@@ -95,17 +96,11 @@ public class SynchronossPartHttpMessageReader extends LoggingCodecSupport implem
public Flux<Part> read(ResolvableType elementType, ReactiveHttpInputMessage message, Map<String, Object> hints) {
return Flux.create(new SynchronossPartGenerator(message, this.bufferFactory, this.streamStorageFactory))
.doOnNext(part -> {
if (logger.isDebugEnabled() && !Hints.isLoggingSuppressed(hints)) {
String s = Hints.getLogPrefix(hints) + "Parsed " +
if (!Hints.isLoggingSuppressed(hints)) {
LogFormatUtils.traceDebug(logger, traceOn -> Hints.getLogPrefix(hints) + "Parsed " +
(isEnableLoggingRequestDetails() ?
formatValue(part, logger.isTraceEnabled()) :
"parts '" + part.name() + "' (content masked)");
if (logger.isTraceEnabled()) {
logger.trace(s);
}
else {
logger.debug(s);
}
LogFormatUtils.formatValue(part, !traceOn) :
"parts '" + part.name() + "' (content masked)"));
}
});
}

23
spring-web/src/main/java/org/springframework/http/codec/xml/Jaxb2XmlDecoder.java
View File

@@ -42,6 +42,7 @@ import org.springframework.core.codec.CodecException;
import org.springframework.core.codec.DecodingException;
import org.springframework.core.codec.Hints;
import org.springframework.core.io.buffer.DataBuffer;
import org.springframework.core.log.LogFormatUtils;
import org.springframework.lang.Nullable;
import org.springframework.util.Assert;
import org.springframework.util.ClassUtils;
@@ -107,16 +108,10 @@ public class Jaxb2XmlDecoder extends AbstractDecoder<Object> {
return splitEvents.map(events -> {
Object value = unmarshal(events, outputClass);
if (logger.isDebugEnabled()) {
boolean traceOn = logger.isTraceEnabled();
String s = Hints.getLogPrefix(hints) + "Decoded [" + formatValue(value, traceOn) + "]";
if (traceOn) {
logger.trace(s);
}
else {
logger.debug(s);
}
}
LogFormatUtils.traceDebug(logger, traceOn -> {
String formatted = LogFormatUtils.formatValue(value, !traceOn);
return Hints.getLogPrefix(hints) + "Decoded [" + formatted + "]";
});
return value;
});
}
@@ -213,14 +208,6 @@ public class Jaxb2XmlDecoder extends AbstractDecoder<Object> {
return xmlEventFlux.flatMap(new SplitFunction(desiredName));
}
String formatValue(@Nullable Object value, boolean logFullValue) {
if (value == null) {
return "";
}
String s = value instanceof CharSequence ? "\"" + value + "\"" : value.toString();
return logFullValue || s.length() < 100 ? s : s.substring(0, 100) + " (truncated)...";
}
private static class SplitFunction implements Function<XMLEvent, Publisher<? extends List<XMLEvent>>> {

23
spring-web/src/main/java/org/springframework/http/codec/xml/Jaxb2XmlEncoder.java
View File

@@ -34,6 +34,7 @@ import org.springframework.core.codec.EncodingException;
import org.springframework.core.codec.Hints;
import org.springframework.core.io.buffer.DataBuffer;
import org.springframework.core.io.buffer.DataBufferFactory;
import org.springframework.core.log.LogFormatUtils;
import org.springframework.lang.Nullable;
import org.springframework.util.ClassUtils;
import org.springframework.util.MimeType;
@@ -78,15 +79,11 @@ public class Jaxb2XmlEncoder extends AbstractSingleValueEncoder<Object> {
protected Flux<DataBuffer> encode(Object value, DataBufferFactory dataBufferFactory,
ResolvableType type, @Nullable MimeType mimeType, @Nullable Map<String, Object> hints) {
try {
if (logger.isDebugEnabled() && !Hints.isLoggingSuppressed(hints)) {
boolean traceOn = logger.isTraceEnabled();
String s = Hints.getLogPrefix(hints) + "Encoding [" + formatValue(value, traceOn) + "]";
if (traceOn) {
logger.trace(s);
}
else {
logger.debug(s);
}
if (!Hints.isLoggingSuppressed(hints)) {
LogFormatUtils.traceDebug(logger, traceOn -> {
String formatted = LogFormatUtils.formatValue(value, !traceOn);
return Hints.getLogPrefix(hints) + "Encoding [" + formatted + "]";
});
}
DataBuffer buffer = dataBufferFactory.allocateBuffer(1024);
OutputStream outputStream = buffer.asOutputStream();
@@ -104,12 +101,4 @@ public class Jaxb2XmlEncoder extends AbstractSingleValueEncoder<Object> {
}
}
String formatValue(@Nullable Object value, boolean logFullValue) {
if (value == null) {
return "";
}
String s = value instanceof CharSequence ? "\"" + value + "\"" : value.toString();
return logFullValue || s.length() < 100 ? s : s.substring(0, 100) + " (truncated)...";
}
}

3
spring-web/src/main/java/org/springframework/http/server/reactive/AbstractListenerWriteFlushProcessor.java
View File

@@ -49,7 +49,8 @@ public abstract class AbstractListenerWriteFlushProcessor<T> implements Processo
* @see AbstractListenerWriteProcessor#rsWriteLogger
* @see WriteResultPublisher#rsWriteResultLogger
*/
protected static final Log rsWriteFlushLogger = LogDelegateFactory.getHiddenLog(AbstractListenerWriteFlushProcessor.class);
protected static final Log rsWriteFlushLogger =
LogDelegateFactory.getHiddenLog(AbstractListenerWriteFlushProcessor.class);
private final AtomicReference<State> state = new AtomicReference<>(State.UNSUBSCRIBED);

30
spring-web/src/main/java/org/springframework/web/multipart/commons/CommonsFileUploadSupport.java
View File

@@ -31,6 +31,7 @@ import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.springframework.core.io.Resource;
import org.springframework.core.log.LogFormatUtils;
import org.springframework.http.MediaType;
import org.springframework.lang.Nullable;
import org.springframework.util.LinkedMultiValueMap;
@@ -281,16 +282,11 @@ public abstract class CommonsFileUploadSupport {
// multipart file field
CommonsMultipartFile file = createMultipartFile(fileItem);
multipartFiles.add(file.getName(), file);
if (logger.isDebugEnabled()) {
String message = "Part '" + file.getName() + "', " +
"size " + file.getSize() + " bytes, filename='" + file.getOriginalFilename() + "'";
if (logger.isTraceEnabled()) {
logger.trace(message + ", storage=" + file.getStorageDescription());
}
else {
logger.debug(message);
}
}
LogFormatUtils.traceDebug(logger, traceOn ->
"Part '" + file.getName() + "', size " + file.getSize() +
" bytes, filename='" + file.getOriginalFilename() + "'" +
(traceOn ? ", storage=" + file.getStorageDescription() : "")
);
}
}
return new MultipartParsingResult(multipartFiles, multipartParameters, multipartParameterContentTypes);
@@ -323,16 +319,10 @@ public abstract class CommonsFileUploadSupport {
if (file instanceof CommonsMultipartFile) {
CommonsMultipartFile cmf = (CommonsMultipartFile) file;
cmf.getFileItem().delete();
if (logger.isDebugEnabled()) {
String filename = cmf.getOriginalFilename();
String message = "Cleaning up part '" + cmf.getName() + "', filename '" + filename + "'";
if (logger.isTraceEnabled()) {
logger.trace(message + ", stored " + cmf.getStorageDescription());
}
else {
logger.debug(message);
}
}
LogFormatUtils.traceDebug(logger, traceOn ->
"Cleaning up part '" + cmf.getName() +
"', filename '" + cmf.getOriginalFilename() + "'" +
(traceOn ? ", stored " + cmf.getStorageDescription() : ""));
}
}
}

16
spring-web/src/main/java/org/springframework/web/multipart/commons/CommonsMultipartFile.java
View File

@@ -29,6 +29,7 @@ import org.apache.commons.fileupload.disk.DiskFileItem;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.springframework.core.log.LogFormatUtils;
import org.springframework.util.FileCopyUtils;
import org.springframework.util.StreamUtils;
import org.springframework.web.multipart.MultipartFile;
@@ -165,20 +166,15 @@ public class CommonsMultipartFile implements MultipartFile, Serializable {
try {
this.fileItem.write(dest);
if (logger.isDebugEnabled()) {
LogFormatUtils.traceDebug(logger, traceOn -> {
String action = "transferred";
if (!this.fileItem.isInMemory()) {
action = (isAvailable() ? "copied" : "moved");
}
String message = "Part '" + getName() + "', filename '" + getOriginalFilename() + "'";
if (logger.isTraceEnabled()) {
logger.trace(message + ", stored " + getStorageDescription() + ": " + action +
" to [" + dest.getAbsolutePath() + "]");
}
else {
logger.debug(message + ": " + action + " to [" + dest.getAbsolutePath() + "]");
}
}
return "Part '" + getName() + "', filename '" + getOriginalFilename() + "'" +
(traceOn ? ", stored " + getStorageDescription() : "") +
": " + action + " to [" + dest.getAbsolutePath() + "]";
});
}
catch (FileUploadException ex) {
throw new IllegalStateException(ex.getMessage(), ex);

36
spring-web/src/main/java/org/springframework/web/server/adapter/HttpWebHandlerAdapter.java
View File

@@ -26,6 +26,7 @@ import reactor.core.publisher.Mono;
import org.springframework.context.ApplicationContext;
import org.springframework.core.NestedExceptionUtils;
import org.springframework.core.log.LogFormatUtils;
import org.springframework.http.HttpHeaders;
import org.springframework.http.HttpStatus;
import org.springframework.http.codec.LoggingCodecSupport;
@@ -237,7 +238,10 @@ public class HttpWebHandlerAdapter extends WebHandlerDecorator implements HttpHa
}
ServerWebExchange exchange = createExchange(request, response);
logExchange(exchange);
LogFormatUtils.traceDebug(logger, traceOn ->
exchange.getLogPrefix() + formatRequest(exchange.getRequest()) +
(traceOn ? ", headers=" + formatHeaders(exchange.getRequest().getHeaders()) : ""));
return getDelegate().handle(exchange)
.doOnSuccess(aVoid -> logResponse(exchange))
@@ -250,19 +254,6 @@ public class HttpWebHandlerAdapter extends WebHandlerDecorator implements HttpHa
getCodecConfigurer(), getLocaleContextResolver(), this.applicationContext);
}
private void logExchange(ServerWebExchange exchange) {
if (logger.isDebugEnabled()) {
String logPrefix = exchange.getLogPrefix();
ServerHttpRequest request = exchange.getRequest();
if (logger.isTraceEnabled()) {
logger.trace(logPrefix + formatRequest(request) + ", headers=" + formatHeaders(request.getHeaders()));
}
else {
logger.debug(logPrefix + formatRequest(request));
}
}
}
private String formatRequest(ServerHttpRequest request) {
String rawQuery = request.getURI().getRawQuery();
String query = StringUtils.hasText(rawQuery) ? "?" + rawQuery : "";
@@ -270,18 +261,11 @@ public class HttpWebHandlerAdapter extends WebHandlerDecorator implements HttpHa
}
private void logResponse(ServerWebExchange exchange) {
if (logger.isDebugEnabled()) {
String logPrefix = exchange.getLogPrefix();
ServerHttpResponse response = exchange.getResponse();
HttpStatus status = response.getStatusCode();
String message = "Completed " + (status != null ? status : "200 OK");
if (logger.isTraceEnabled()) {
logger.trace(logPrefix + message + ", headers=" + formatHeaders(response.getHeaders()));
}
else {
logger.debug(logPrefix + message);
}
}
LogFormatUtils.traceDebug(logger, traceOn -> {
HttpStatus status = exchange.getResponse().getStatusCode();
return exchange.getLogPrefix() + "Completed " + (status != null ? status : "200 OK") +
(traceOn ? ", headers=" + formatHeaders(exchange.getResponse().getHeaders()) : "");
});
}
private String formatHeaders(HttpHeaders responseHeaders) {