Truncate logged encoded and decoded values if necessary

At DEBUG show up to 100 chars, at TRACE show full formatted value.

Note that the formatValue helper method is duplicated a number of times
in this commit. A utility method will likely be added in spring-core
through an extra commit.

Issue: SPR-17254
This commit is contained in:
Rossen Stoyanchev 2018-09-14 12:20:03 -04:00
parent 66c66baa8f
commit e62298eaad
16 changed files with 187 additions and 32 deletions

View File

@ -70,7 +70,13 @@ public final class CharSequenceEncoder extends AbstractEncoder<CharSequence> {
return Flux.from(inputStream).map(charSequence -> {
if (logger.isDebugEnabled() && !Hints.isLoggingSuppressed(hints)) {
String logPrefix = Hints.getLogPrefix(hints);
logger.debug(logPrefix + "Writing '" + charSequence + "'");
String s = logPrefix + "Writing " + formatValue(charSequence, logger.isTraceEnabled());
if (logger.isTraceEnabled()) {
logger.trace(s);
}
else {
logger.debug(s);
}
}
CharBuffer charBuffer = CharBuffer.wrap(charSequence);
ByteBuffer byteBuffer = charset.encode(charBuffer);
@ -89,6 +95,15 @@ public final class CharSequenceEncoder extends AbstractEncoder<CharSequence> {
return charset;
}
private 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)...";
}
/**
* Create a {@code CharSequenceEncoder} that supports only "text/plain".
*/

View File

@ -207,7 +207,13 @@ public final class StringDecoder extends AbstractDataBufferDecoder<String> {
DataBufferUtils.release(dataBuffer);
String value = charBuffer.toString();
if (logger.isDebugEnabled()) {
logger.debug(Hints.getLogPrefix(hints) + "Decoded '" + value + "'");
String s = Hints.getLogPrefix(hints) + "Decoded " + formatValue(value, logger.isTraceEnabled());
if (logger.isTraceEnabled()) {
logger.trace(s);
}
else {
logger.debug(s);
}
}
return value;
}
@ -221,6 +227,14 @@ public final class StringDecoder extends AbstractDataBufferDecoder<String> {
}
}
private 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)...";
}
/**
* Create a {@code StringDecoder} for {@code "text/plain"}.

View File

@ -108,15 +108,26 @@ public class FormHttpMessageReader extends LoggingCodecSupport
String body = charBuffer.toString();
DataBufferUtils.release(buffer);
MultiValueMap<String, String> formData = parseFormData(charset, body);
if (logger.isDebugEnabled()) {
String details = isEnableLoggingRequestDetails() ?
formData.toString() : "form fields " + formData.keySet() + " (content masked)";
logger.debug(Hints.getLogPrefix(hints) + "Read " + details);
}
logFormData(formData, hints);
return formData;
});
}
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);
}
}
}
private Charset getMediaTypeCharset(@Nullable MediaType mediaType) {
if (mediaType != null && mediaType.getCharset() != null) {
return mediaType.getCharset();

View File

@ -132,9 +132,15 @@ public class FormHttpMessageWriter extends LoggingCodecSupport
return Mono.from(inputStream).flatMap(form -> {
if (logger.isDebugEnabled()) {
String details = isEnableLoggingRequestDetails() ?
form.toString() : "form fields " + form.keySet() + " (content masked)";
logger.debug(Hints.getLogPrefix(hints) + "Writing " + details);
String s = Hints.getLogPrefix(hints) + "Writing " +
(isEnableLoggingRequestDetails() ?
form.toString() : "form fields " + form.keySet() + " (content masked)");
if (logger.isTraceEnabled()) {
logger.trace(s);
}
else {
logger.debug(s);
}
}
String value = serializeForm(form, charset);
ByteBuffer byteBuffer = charset.encode(value);

View File

@ -19,6 +19,7 @@ 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},
@ -55,4 +56,20 @@ 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)...";
}
}

View File

@ -116,7 +116,14 @@ public abstract class AbstractJackson2Decoder extends Jackson2CodecSupport imple
try {
Object value = reader.readValue(tokenBuffer.asParser(getObjectMapper()));
if (logger.isDebugEnabled() && !Hints.isLoggingSuppressed(hints)) {
logger.debug(Hints.getLogPrefix(hints) +"Decoded [" + value + "]");
boolean traceOn = logger.isTraceEnabled();
String s = Hints.getLogPrefix(hints) + "Decoded [" + formatValue(value, traceOn) + "]";
if (traceOn) {
logger.trace(s);
}
else {
logger.debug(s);
}
}
return value;
}

View File

@ -142,7 +142,14 @@ public abstract class AbstractJackson2Encoder extends Jackson2CodecSupport imple
ResolvableType elementType, @Nullable Map<String, Object> hints, JsonEncoding encoding) {
if (logger.isDebugEnabled() && !Hints.isLoggingSuppressed(hints)) {
logger.debug(Hints.getLogPrefix(hints) + "Encoding [" + value + "]");
boolean traceOn = logger.isTraceEnabled();
String s = Hints.getLogPrefix(hints) + "Encoding [" + formatValue(value, traceOn) + "]";
if (traceOn) {
logger.trace(s);
}
else {
logger.debug(s);
}
}
JavaType javaType = getJavaType(elementType.getType(), null);

View File

@ -125,4 +125,12 @@ 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)...";
}
}

View File

@ -95,9 +95,15 @@ public class MultipartHttpMessageReader extends LoggingCodecSupport
.collectMultimap(Part::name)
.doOnNext(map -> {
if (logger.isDebugEnabled()) {
String details = isEnableLoggingRequestDetails() ?
map.toString() : "parts " + map.keySet() + " (content masked)";
logger.debug(Hints.getLogPrefix(hints) + "Parsed " + details);
String s = Hints.getLogPrefix(hints) + "Parsed " +
(isEnableLoggingRequestDetails() ?
map.toString() : "parts " + map.keySet() + " (content masked)");
if (logger.isTraceEnabled()) {
logger.trace(s);
}
else {
logger.debug(s);
}
}
})
.map(this::toMultiValueMap);

View File

@ -226,9 +226,15 @@ public class MultipartHttpMessageWriter extends LoggingCodecSupport
outputMessage.getHeaders().setContentType(new MediaType(MediaType.MULTIPART_FORM_DATA, params));
if (logger.isDebugEnabled()) {
String details = isEnableLoggingRequestDetails() ?
map.toString() : "parts " + map.keySet() + " (content masked)";
logger.debug(Hints.getLogPrefix(hints) + "Encoding " + details);
String s = Hints.getLogPrefix(hints) + "Encoding " +
(isEnableLoggingRequestDetails() ?
map.toString() : "parts " + map.keySet() + " (content masked)");
if (logger.isTraceEnabled()) {
logger.trace(s);
}
else {
logger.debug(s);
}
}
Flux<DataBuffer> body = Flux.fromIterable(map.entrySet())

View File

@ -96,9 +96,14 @@ public class SynchronossPartHttpMessageReader extends LoggingCodecSupport implem
return Flux.create(new SynchronossPartGenerator(message, this.bufferFactory, this.streamStorageFactory))
.doOnNext(part -> {
if (logger.isDebugEnabled() && !Hints.isLoggingSuppressed(hints)) {
String details = isEnableLoggingRequestDetails() ?
part.toString() : "parts '" + part.name() + "' (content masked)";
logger.debug(Hints.getLogPrefix(hints) + "Parsed " + details);
String s = Hints.getLogPrefix(hints) + "Parsed " + (isEnableLoggingRequestDetails() ?
part.toString() : "parts '" + part.name() + "' (content masked)");
if (logger.isTraceEnabled()) {
logger.trace(s);
}
else {
logger.debug(s);
}
}
});
}

View File

@ -108,7 +108,14 @@ public class Jaxb2XmlDecoder extends AbstractDecoder<Object> {
return splitEvents.map(events -> {
Object value = unmarshal(events, outputClass);
if (logger.isDebugEnabled()) {
logger.debug(Hints.getLogPrefix(hints) + "Decoded [" + value + "]");
boolean traceOn = logger.isTraceEnabled();
String s = Hints.getLogPrefix(hints) + "Decoded [" + formatValue(value, traceOn) + "]";
if (traceOn) {
logger.trace(s);
}
else {
logger.debug(s);
}
}
return value;
});
@ -206,6 +213,14 @@ 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>>> {

View File

@ -79,7 +79,14 @@ public class Jaxb2XmlEncoder extends AbstractSingleValueEncoder<Object> {
ResolvableType type, @Nullable MimeType mimeType, @Nullable Map<String, Object> hints) {
try {
if (logger.isDebugEnabled() && !Hints.isLoggingSuppressed(hints)) {
logger.debug(Hints.getLogPrefix(hints) + "Encoding [" + value + "]");
boolean traceOn = logger.isTraceEnabled();
String s = Hints.getLogPrefix(hints) + "Encoding [" + formatValue(value, traceOn) + "]";
if (traceOn) {
logger.trace(s);
}
else {
logger.debug(s);
}
}
DataBuffer buffer = dataBufferFactory.allocateBuffer(1024);
OutputStream outputStream = buffer.asOutputStream();
@ -97,4 +104,12 @@ 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)...";
}
}

View File

@ -224,8 +224,15 @@ public abstract class AbstractMessageConverterMethodArgumentResolver implements
}
if (logger.isDebugEnabled()) {
logger.debug("Read \"" + contentType + "\" to " +
"[" + (body instanceof String ? "\"" + body + "\"" : body) + "]");
boolean traceOn = logger.isTraceEnabled();
String s = "Read \"" + contentType + "\" to [" +
RequestMappingHandlerAdapter.formatValue(body, traceOn) + "]";
if (traceOn) {
logger.trace(s);
}
else {
logger.debug(s);
}
}
return body;

View File

@ -281,7 +281,14 @@ public abstract class AbstractMessageConverterMethodProcessor extends AbstractMe
inputMessage, outputMessage);
if (body != null) {
if (logger.isDebugEnabled()) {
logger.debug("Writing [" + formatValue(body) + "]");
boolean traceOn = logger.isTraceEnabled();
String s = "Writing [" + RequestMappingHandlerAdapter.formatValue(body, traceOn) + "]";
if (traceOn) {
logger.trace(s);
}
else {
logger.debug(s);
}
}
addContentDispositionHeader(inputMessage, outputMessage);
if (genericConverter != null) {
@ -398,10 +405,6 @@ public abstract class AbstractMessageConverterMethodProcessor extends AbstractMe
return (MediaType.SPECIFICITY_COMPARATOR.compare(acceptType, produceTypeToUse) <= 0 ? acceptType : produceTypeToUse);
}
static String formatValue(Object body) {
return (body instanceof CharSequence ? "\"" + body + "\"" : body.toString());
}
/**
* Check if the path has a file extension and whether the extension is
* either {@link #WHITELISTED_EXTENSIONS whitelisted} or explicitly

View File

@ -885,8 +885,13 @@ public class RequestMappingHandlerAdapter extends AbstractHandlerMethodAdapter
mavContainer = (ModelAndViewContainer) asyncManager.getConcurrentResultContext()[0];
asyncManager.clearConcurrentResult();
if (logger.isDebugEnabled()) {
String formatted = AbstractMessageConverterMethodProcessor.formatValue(result);
logger.debug("Resume with async result [" + formatted + "]");
String s = "Resume with async result [" + formatValue(result, logger.isTraceEnabled()) + "]";
if (logger.isTraceEnabled()) {
logger.trace(s);
}
else {
logger.debug(s);
}
}
invocableMethod = invocableMethod.wrapConcurrentResult(result);
}
@ -1019,4 +1024,12 @@ public class RequestMappingHandlerAdapter extends AbstractHandlerMethodAdapter
return mav;
}
static String formatValue(@Nullable Object body, boolean logFullBody) {
if (body == null) {
return "";
}
String s = body instanceof CharSequence ? "\"" + body + "\"" : body.toString();
return logFullBody || s.length() < 100 ? s : s.substring(0, 100) + " (truncated)...";
}
}