Correlated encoding/decoding log messages via hints

Issue: SPR-16966
This commit is contained in:
Rossen Stoyanchev
2018-07-03 20:54:19 -04:00
parent fd90b73748
commit 82310660fd
41 changed files with 293 additions and 152 deletions

View File

@@ -18,7 +18,6 @@ package org.springframework.core.codec;
import java.util.Arrays;
import java.util.List;
import java.util.Map;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
@@ -60,17 +59,4 @@ public abstract class AbstractEncoder<T> implements Encoder<T> {
return this.encodableMimeTypes.stream().anyMatch(candidate -> candidate.isCompatibleWith(mimeType));
}
/**
* Helper method to obtain the logger to use from the Map of hints, or fall
* back on the default logger. This may be used for example to override
* logging, e.g. for a multipart request where the full map of part values
* has already been logged.
* @param hints the hints passed to the encode method
* @return the logger to use
* @since 5.1
*/
protected Log getLogger(@Nullable Map<String, Object> hints) {
return hints != null ? ((Log) hints.getOrDefault(Log.class.getName(), logger)) : logger;
}
}

View File

@@ -54,7 +54,7 @@ public class ByteArrayDecoder extends AbstractDataBufferDecoder<byte[]> {
dataBuffer.read(result);
DataBufferUtils.release(dataBuffer);
if (logger.isDebugEnabled()) {
logger.debug("Read " + result.length + " bytes");
logger.debug(Hints.getLogPrefix(hints) + "Read " + result.length + " bytes");
}
return result;
}

View File

@@ -55,9 +55,10 @@ public class ByteArrayEncoder extends AbstractEncoder<byte[]> {
return Flux.from(inputStream).map(bytes -> {
DataBuffer dataBuffer = bufferFactory.wrap(bytes);
Log logger = getLogger(hints);
if (logger.isDebugEnabled()) {
logger.debug("Writing " + dataBuffer.readableByteCount() + " bytes");
Log theLogger = Hints.getLoggerOrDefault(hints, logger);
if (theLogger.isDebugEnabled()) {
theLogger.debug(Hints.getLogPrefix(hints) +
"Writing " + dataBuffer.readableByteCount() + " bytes");
}
return dataBuffer;
});

View File

@@ -58,7 +58,7 @@ public class ByteBufferDecoder extends AbstractDataBufferDecoder<ByteBuffer> {
copy.flip();
DataBufferUtils.release(dataBuffer);
if (logger.isDebugEnabled()) {
logger.debug("Read " + byteCount + " bytes");
logger.debug(Hints.getLogPrefix(hints) + "Read " + byteCount + " bytes");
}
return copy;
}

View File

@@ -56,9 +56,10 @@ public class ByteBufferEncoder extends AbstractEncoder<ByteBuffer> {
return Flux.from(inputStream).map(byteBuffer -> {
DataBuffer dataBuffer = bufferFactory.wrap(byteBuffer);
Log logger = getLogger(hints);
if (logger.isDebugEnabled()) {
logger.debug("Writing " + dataBuffer.readableByteCount() + " bytes");
Log theLogger = Hints.getLoggerOrDefault(hints, logger);
if (theLogger.isDebugEnabled()) {
theLogger.debug(Hints.getLogPrefix(hints) +
"Writing " + dataBuffer.readableByteCount() + " bytes");
}
return dataBuffer;
});

View File

@@ -69,9 +69,9 @@ public final class CharSequenceEncoder extends AbstractEncoder<CharSequence> {
Charset charset = getCharset(mimeType);
return Flux.from(inputStream).map(charSequence -> {
Log logger = getLogger(hints);
if (logger.isDebugEnabled()) {
logger.debug("Writing '" + charSequence + "'");
Log theLogger = Hints.getLoggerOrDefault(hints, logger);
if (theLogger.isDebugEnabled()) {
theLogger.debug(Hints.getLogPrefix(hints) + "Writing '" + charSequence + "'");
}
CharBuffer charBuffer = CharBuffer.wrap(charSequence);
ByteBuffer byteBuffer = charset.encode(charBuffer);

View File

@@ -63,7 +63,7 @@ public class DataBufferDecoder extends AbstractDataBufferDecoder<DataBuffer> {
@Nullable MimeType mimeType, @Nullable Map<String, Object> hints) {
if (logger.isDebugEnabled()) {
logger.debug("Read " + buffer.readableByteCount() + " bytes");
logger.debug(Hints.getLogPrefix(hints) + "Read " + buffer.readableByteCount() + " bytes");
}
return buffer;
}

View File

@@ -55,9 +55,11 @@ public class DataBufferEncoder extends AbstractEncoder<DataBuffer> {
Flux<DataBuffer> flux = Flux.from(inputStream);
Log logger = getLogger(hints);
if (logger.isDebugEnabled()) {
flux = flux.doOnNext(buffer -> logger.debug("Writing " + buffer.readableByteCount() + " bytes"));
Log theLogger = Hints.getLoggerOrDefault(hints, logger);
if (theLogger.isDebugEnabled()) {
flux = flux.doOnNext(buffer ->
theLogger.debug(Hints.getLogPrefix(hints) +
"Writing " + buffer.readableByteCount() + " bytes"));
}
return flux;

View File

@@ -0,0 +1,153 @@
/*
* Copyright 2002-2018 the original author or authors.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package org.springframework.core.codec;
import java.util.Collections;
import java.util.HashMap;
import java.util.Map;
import org.apache.commons.logging.Log;
import org.springframework.lang.Nullable;
/**
* Constants and convenience methods for working with hints.
*
* @author Rossen Stoyanchev
* @since 5.1
* @see ResourceRegionEncoder#BOUNDARY_STRING_HINT
*/
public abstract class Hints {
/**
* Name of hint exposing a prefix to use for correlating log messages.
* @since 5.1
*/
public static final String LOG_PREFIX_HINT = Log.class.getName() + ".PREFIX";
/**
* Name of hint for a preferred {@link Log logger} to use. This can be used
* by a composite encoder (e.g. multipart requests) to control or suppress
* logging by individual part encoders.
* @since 5.1
*/
public static final String LOGGER_HINT = Log.class.getName();
/**
* Create a map wit a single hint via {@link Collections#singletonMap}.
* @param hintName the hint name
* @param value the hint value
* @return the created map
*/
public static Map<String, Object> from(String hintName, Object value) {
return Collections.singletonMap(hintName, value);
}
/**
* Return an empty map of hints via {@link Collections#emptyMap()}.
* @return the empty map
*/
public static Map<String, Object> none() {
return Collections.emptyMap();
}
/**
* Obtain the value for a required hint.
* @param hints the hints map
* @param hintName the required hint name
* @param <T> the hint type to cast to
* @return the hint value
* @throws IllegalArgumentException if the hint is not found
*/
@SuppressWarnings("unchecked")
public static <T> T getRequiredHint(@Nullable Map<String, Object> hints, String hintName) {
if (hints == null) {
throw new IllegalArgumentException("No hints map for required hint '" + hintName + "'");
}
T hint = (T) hints.get(hintName);
if (hint == null) {
throw new IllegalArgumentException("Hints map must contain the hint '" + hintName + "'");
}
return hint;
}
/**
* Obtain the hint {@link #LOG_PREFIX_HINT}, if present, or an empty String.
* @param hints the hints passed to the encode method
* @return the log prefix
*/
public static String getLogPrefix(@Nullable Map<String, Object> hints) {
return hints != null ? (String) hints.getOrDefault(LOG_PREFIX_HINT, "") : "";
}
/**
* Obtain the hint {@link #LOGGER_HINT}, if present, or the given logger.
* @param hints the hints passed to the encode method
* @param defaultLogger the logger to return if a hint is not found
* @return the logger to use
*/
public static Log getLoggerOrDefault(@Nullable Map<String, Object> hints, Log defaultLogger) {
return hints != null ? (Log) hints.getOrDefault(LOGGER_HINT, defaultLogger) : defaultLogger;
}
/**
* Merge two maps of hints, creating and copying into a new map if both have
* values, or returning the non-empty map, or an empty map if both are empty.
* @param hints1 1st map of hints
* @param hints2 2nd map of hints
* @return a single map with hints from both
*/
public static Map<String, Object> merge(Map<String, Object> hints1, Map<String, Object> hints2) {
if (hints1.isEmpty() && hints2.isEmpty()) {
return Collections.emptyMap();
}
else if (hints2.isEmpty()) {
return hints1;
}
else if (hints1.isEmpty()) {
return hints2;
}
else {
Map<String, Object> result = new HashMap<>(hints1.size() + hints2.size());
result.putAll(hints1);
result.putAll(hints2);
return result;
}
}
/**
* Merge a single hint into a map of hints, possibly creating and copying
* all hints into a new map, or otherwise if the map of hints is empty,
* creating a new single entry map.
* @param hints a map of hints to be merge
* @param hintName the hint name to merge
* @param hintValue the hint value to merge
* @return a single map with all hints
*/
public static Map<String, Object> merge(Map<String, Object> hints, String hintName, Object hintValue) {
if (hints.isEmpty()) {
return Collections.singletonMap(hintName, hintValue);
}
else {
Map<String, Object> result = new HashMap<>(hints.size() + 1);
result.putAll(hints);
result.put(hintName, hintValue);
return result;
}
}
}

View File

@@ -73,7 +73,7 @@ public class ResourceDecoder extends AbstractDataBufferDecoder<Resource> {
Assert.state(clazz != null, "No resource class");
if (logger.isDebugEnabled()) {
logger.debug("Read " + bytes.length + " bytes");
logger.debug(Hints.getLogPrefix(hints) + "Read " + bytes.length + " bytes");
}
if (InputStreamResource.class == clazz) {

View File

@@ -69,9 +69,9 @@ public class ResourceEncoder extends AbstractSingleValueEncoder<Resource> {
protected Flux<DataBuffer> encode(Resource resource, DataBufferFactory dataBufferFactory,
ResolvableType type, @Nullable MimeType mimeType, @Nullable Map<String, Object> hints) {
Log logger = getLogger(hints);
if (logger.isDebugEnabled()) {
logger.debug("Writing [" + resource + "]");
Log theLogger = Hints.getLoggerOrDefault(hints, logger);
if (theLogger.isDebugEnabled()) {
theLogger.debug(Hints.getLogPrefix(hints) + "Writing [" + resource + "]");
}
return DataBufferUtils.read(resource, dataBufferFactory, this.bufferSize);

View File

@@ -91,10 +91,7 @@ public class ResourceRegionEncoder extends AbstractEncoder<ResourceRegion> {
.flatMapMany(region -> writeResourceRegion(region, bufferFactory, hints));
}
else {
Assert.notNull(hints, "'hints' must not be null");
Assert.isTrue(hints.containsKey(BOUNDARY_STRING_HINT), "'hints' must contain boundaryString hint");
final String boundaryString = (String) hints.get(BOUNDARY_STRING_HINT);
final String boundaryString = Hints.getRequiredHint(hints, BOUNDARY_STRING_HINT);
byte[] startBoundary = getAsciiBytes("\r\n--" + boundaryString + "\r\n");
byte[] contentType =
(mimeType != null ? getAsciiBytes("Content-Type: " + mimeType + "\r\n") : new byte[0]);
@@ -126,9 +123,10 @@ public class ResourceRegionEncoder extends AbstractEncoder<ResourceRegion> {
long position = region.getPosition();
long count = region.getCount();
Log logger = getLogger(hints);
if (logger.isDebugEnabled()) {
logger.debug("Writing region " + position + "-" + (position + count) + " of [" + resource + "]");
Log theLogger = Hints.getLoggerOrDefault(hints, logger);
if (theLogger.isDebugEnabled()) {
theLogger.debug(Hints.getLogPrefix(hints) +
"Writing region " + position + "-" + (position + count) + " of [" + resource + "]");
}
Flux<DataBuffer> in = DataBufferUtils.read(resource, position, bufferFactory, this.bufferSize);
@@ -149,7 +147,8 @@ public class ResourceRegionEncoder extends AbstractEncoder<ResourceRegion> {
long end = start + region.getCount() - 1;
OptionalLong contentLength = contentLength(region.getResource());
if (contentLength.isPresent()) {
return getAsciiBytes("Content-Range: bytes " + start + '-' + end + '/' + contentLength.getAsLong() + "\r\n\r\n");
long length = contentLength.getAsLong();
return getAsciiBytes("Content-Range: bytes " + start + '-' + end + '/' + length + "\r\n\r\n");
}
else {
return getAsciiBytes("Content-Range: bytes " + start + '-' + end + "\r\n\r\n");

View File

@@ -207,7 +207,7 @@ public final class StringDecoder extends AbstractDataBufferDecoder<String> {
DataBufferUtils.release(dataBuffer);
String value = charBuffer.toString();
if (logger.isDebugEnabled()) {
logger.debug("Decoded '" + value + "'");
logger.debug(Hints.getLogPrefix(hints) + "Decoded '" + value + "'");
}
return value;
}