Switch defaults and model for logging sensitive data

Issue: SPR-17029
This commit is contained in:
Rossen Stoyanchev 2018-07-10 16:18:31 -04:00
parent a40d25a760
commit 1b1bc7f5b5
34 changed files with 241 additions and 229 deletions

View File

@ -54,7 +54,7 @@ public class ByteArrayEncoder extends AbstractEncoder<byte[]> {
return Flux.from(inputStream).map(bytes -> {
DataBuffer dataBuffer = bufferFactory.wrap(bytes);
if (logger.isDebugEnabled() && !Hints.suppressLogging(hints)) {
if (logger.isDebugEnabled() && !Hints.isLoggingSuppressed(hints)) {
String logPrefix = Hints.getLogPrefix(hints);
logger.debug(logPrefix + "Writing " + dataBuffer.readableByteCount() + " bytes");
}

View File

@ -55,7 +55,7 @@ public class ByteBufferEncoder extends AbstractEncoder<ByteBuffer> {
return Flux.from(inputStream).map(byteBuffer -> {
DataBuffer dataBuffer = bufferFactory.wrap(byteBuffer);
if (logger.isDebugEnabled() && !Hints.suppressLogging(hints)) {
if (logger.isDebugEnabled() && !Hints.isLoggingSuppressed(hints)) {
String logPrefix = Hints.getLogPrefix(hints);
logger.debug(logPrefix + "Writing " + dataBuffer.readableByteCount() + " bytes");
}

View File

@ -68,7 +68,7 @@ public final class CharSequenceEncoder extends AbstractEncoder<CharSequence> {
Charset charset = getCharset(mimeType);
return Flux.from(inputStream).map(charSequence -> {
if (logger.isDebugEnabled() && !Hints.suppressLogging(hints)) {
if (logger.isDebugEnabled() && !Hints.isLoggingSuppressed(hints)) {
String logPrefix = Hints.getLogPrefix(hints);
logger.debug(logPrefix + "Writing '" + charSequence + "'");
}

View File

@ -54,7 +54,7 @@ public class DataBufferEncoder extends AbstractEncoder<DataBuffer> {
Flux<DataBuffer> flux = Flux.from(inputStream);
if (logger.isDebugEnabled() && !Hints.suppressLogging(hints)) {
if (logger.isDebugEnabled() && !Hints.isLoggingSuppressed(hints)) {
flux = flux.doOnNext(buffer -> {
String logPrefix = Hints.getLogPrefix(hints);
logger.debug(logPrefix + "Writing " + buffer.readableByteCount() + " bytes");

View File

@ -99,7 +99,7 @@ public abstract class Hints {
* @param hints the hints map
* @return whether logging of data is allowed
*/
public static boolean suppressLogging(@Nullable Map<String, Object> hints) {
public static boolean isLoggingSuppressed(@Nullable Map<String, Object> hints) {
return hints != null && (boolean) hints.getOrDefault(SUPPRESS_LOGGING_HINT, false);
}

View File

@ -68,7 +68,7 @@ public class ResourceEncoder extends AbstractSingleValueEncoder<Resource> {
protected Flux<DataBuffer> encode(Resource resource, DataBufferFactory dataBufferFactory,
ResolvableType type, @Nullable MimeType mimeType, @Nullable Map<String, Object> hints) {
if (logger.isDebugEnabled() && !Hints.suppressLogging(hints)) {
if (logger.isDebugEnabled() && !Hints.isLoggingSuppressed(hints)) {
String logPrefix = Hints.getLogPrefix(hints);
logger.debug(logPrefix + "Writing [" + resource + "]");
}

View File

@ -122,7 +122,7 @@ public class ResourceRegionEncoder extends AbstractEncoder<ResourceRegion> {
long position = region.getPosition();
long count = region.getCount();
if (logger.isDebugEnabled() && !Hints.suppressLogging(hints)) {
if (logger.isDebugEnabled() && !Hints.isLoggingSuppressed(hints)) {
logger.debug(Hints.getLogPrefix(hints) +
"Writing region " + position + "-" + (position + count) + " of [" + resource + "]");
}

View File

@ -111,19 +111,13 @@ public interface CodecConfigurer {
void jackson2JsonEncoder(Encoder<?> encoder);
/**
* Whether to disable logging of request details for form and multipart
* requests at any log level. By default such data is logged under
* {@code "org.springframework.http.codec"} but may contain sensitive
* information. Typically that's not an issue since DEBUG is used in
* development, but this option may be used to explicitly disable any
* logging of form and multipart data at any log level.
* <p>By default this is set to {@code false} in which case form and
* multipart data is logged at DEBUG or TRACE. When set to {@code true}
* values will not be logged at any level.
* @param disableLoggingRequestDetails whether to disable loggins
* Whether to log form data at DEBUG level, and headers at TRACE level.
* Both may contain sensitive information.
* <p>By default set to {@code false} so that request details are not shown.
* @param enable whether to enable or not
* @since 5.1
*/
void disableLoggingRequestDetails(boolean disableLoggingRequestDetails);
void enableLoggingRequestDetails(boolean enable);
}

View File

@ -108,8 +108,10 @@ public class FormHttpMessageReader extends LoggingCodecSupport
String body = charBuffer.toString();
DataBufferUtils.release(buffer);
MultiValueMap<String, String> formData = parseFormData(charset, body);
if (shouldLogRequestDetails()) {
logger.debug(Hints.getLogPrefix(hints) + "Decoded " + formData);
if (logger.isDebugEnabled()) {
String details = isEnableLoggingRequestDetails() ?
formData.toString() : "form fields " + formData.keySet() + " (content masked)";
logger.debug(Hints.getLogPrefix(hints) + "Read " + details);
}
return formData;
});

View File

@ -131,8 +131,10 @@ public class FormHttpMessageWriter extends LoggingCodecSupport
Assert.notNull(charset, "No charset"); // should never occur
return Mono.from(inputStream).flatMap(form -> {
if (shouldLogRequestDetails()) {
logger.debug(Hints.getLogPrefix(hints) + "Encoding " + form);
if (logger.isDebugEnabled()) {
String details = isEnableLoggingRequestDetails() ?
form.toString() : "form fields " + form.keySet() + " (content masked)";
logger.debug(Hints.getLogPrefix(hints) + "Writing " + details);
}
String value = serializeForm(form, charset);
ByteBuffer byteBuffer = charset.encode(value);

View File

@ -33,41 +33,26 @@ public class LoggingCodecSupport {
protected final Log logger = HttpLog.create(LogFactory.getLog(getClass()));
/** Do not log potentially sensitive information (params at DEBUG and headers at TRACE). */
private boolean disableLoggingRequestDetails = false;
/** Whether to log potentially sensitive info (form data at DEBUG and headers at TRACE). */
private boolean enableLoggingRequestDetails = false;
/**
* Whether to disable any logging of request details by this codec.
* By default values being encoded or decoded are logged at DEBUG and TRACE
* level under {@code "org.springframework.http.codec"} which may show
* sensitive data for form and multipart data. Typically that's not an issue
* since DEBUG and TRACE are intended for development, but this property may
* be used to explicitly disable any logging of such information regardless
* of the log level.
* <p>By default this is set to {@code false} in which case values encoded
* or decoded are logged at DEBUG level. When set to {@code true} values
* will not be logged at any level.
* @param disableLoggingRequestDetails whether to disable
* Whether to log form data at DEBUG level, and headers at TRACE level.
* Both may contain sensitive information.
* <p>By default set to {@code false} so that request details are not shown.
* @param enable whether to enable or not
*/
public void setDisableLoggingRequestDetails(boolean disableLoggingRequestDetails) {
this.disableLoggingRequestDetails = disableLoggingRequestDetails;
public void setEnableLoggingRequestDetails(boolean enable) {
this.enableLoggingRequestDetails = enable;
}
/**
* Whether any logging of values being encoded or decoded is explicitly
* disabled regardless of log level.
*/
public boolean isDisableLoggingRequestDetails() {
return this.disableLoggingRequestDetails;
}
/**
* Returns "true" if logger is at DEBUG level and the logging of values
* being encoded or decoded is not explicitly disabled.
*/
protected boolean shouldLogRequestDetails() {
return !this.disableLoggingRequestDetails && logger.isDebugEnabled();
public boolean isEnableLoggingRequestDetails() {
return this.enableLoggingRequestDetails;
}
}

View File

@ -145,7 +145,7 @@ public class ResourceHttpMessageWriter implements HttpMessageWriter<Resource> {
return mediaType;
}
mediaType = MediaTypeFactory.getMediaType(resource).orElse(MediaType.APPLICATION_OCTET_STREAM);
if (logger.isDebugEnabled()) {
if (logger.isDebugEnabled() && !Hints.isLoggingSuppressed(hints)) {
logger.debug(Hints.getLogPrefix(hints) + "Resource associated with '" + mediaType + "'");
}
return mediaType;

View File

@ -112,7 +112,7 @@ public abstract class AbstractJackson2Decoder extends Jackson2CodecSupport imple
return tokens.map(tokenBuffer -> {
try {
Object value = reader.readValue(tokenBuffer.asParser(getObjectMapper()));
if (logger.isDebugEnabled()) {
if (logger.isDebugEnabled() && !Hints.isLoggingSuppressed(hints)) {
logger.debug(Hints.getLogPrefix(hints) +"Decoded [" + value + "]");
}
return value;

View File

@ -141,7 +141,7 @@ 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.suppressLogging(hints)) {
if (logger.isDebugEnabled() && !Hints.isLoggingSuppressed(hints)) {
logger.debug(Hints.getLogPrefix(hints) + "Encoding [" + value + "]");
}

View File

@ -27,9 +27,11 @@ import reactor.core.publisher.Flux;
import reactor.core.publisher.Mono;
import org.springframework.core.ResolvableType;
import org.springframework.core.codec.Hints;
import org.springframework.http.MediaType;
import org.springframework.http.ReactiveHttpInputMessage;
import org.springframework.http.codec.HttpMessageReader;
import org.springframework.http.codec.LoggingCodecSupport;
import org.springframework.lang.Nullable;
import org.springframework.util.Assert;
import org.springframework.util.LinkedMultiValueMap;
@ -46,7 +48,8 @@ import org.springframework.util.MultiValueMap;
* @author Rossen Stoyanchev
* @since 5.0
*/
public class MultipartHttpMessageReader implements HttpMessageReader<MultiValueMap<String, Part>> {
public class MultipartHttpMessageReader extends LoggingCodecSupport
implements HttpMessageReader<MultiValueMap<String, Part>> {
private static final ResolvableType MULTIPART_VALUE_TYPE = ResolvableType.forClassWithGenerics(
MultiValueMap.class, String.class, Part.class);
@ -85,8 +88,19 @@ public class MultipartHttpMessageReader implements HttpMessageReader<MultiValueM
public Mono<MultiValueMap<String, Part>> readMono(ResolvableType elementType,
ReactiveHttpInputMessage inputMessage, Map<String, Object> hints) {
return this.partReader.read(elementType, inputMessage, hints)
.collectMultimap(Part::name).map(this::toMultiValueMap);
Map<String, Object> allHints = Hints.merge(hints, Hints.SUPPRESS_LOGGING_HINT, true);
return this.partReader.read(elementType, inputMessage, allHints)
.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);
}
})
.map(this::toMultiValueMap);
}
private LinkedMultiValueMap<String, Part> toMultiValueMap(Map<String, Collection<Part>> map) {

View File

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

View File

@ -95,8 +95,10 @@ 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 (shouldLogRequestDetails()) {
logger.debug(Hints.getLogPrefix(hints) + "Decoded [" + part + "]");
if (logger.isDebugEnabled() && !Hints.isLoggingSuppressed(hints)) {
String details = isEnableLoggingRequestDetails() ?
part.toString() : "parts '" + part.name() + "' (content masked)";
logger.debug(Hints.getLogPrefix(hints) + "Parsed " + details);
}
});
}

View File

@ -74,7 +74,7 @@ class BaseDefaultCodecs implements CodecConfigurer.DefaultCodecs {
@Nullable
private Encoder<?> jackson2JsonEncoder;
private boolean disableLoggingRequestDetails = false;
private boolean enableLoggingRequestDetails = false;
private boolean registerDefaults = true;
@ -90,12 +90,12 @@ class BaseDefaultCodecs implements CodecConfigurer.DefaultCodecs {
}
@Override
public void disableLoggingRequestDetails(boolean disableLoggingRequestDetails) {
this.disableLoggingRequestDetails = disableLoggingRequestDetails;
public void enableLoggingRequestDetails(boolean enable) {
this.enableLoggingRequestDetails = enable;
}
protected boolean isDisableLoggingRequestDetails() {
return this.disableLoggingRequestDetails;
protected boolean isEnableLoggingRequestDetails() {
return this.enableLoggingRequestDetails;
}
/**
@ -121,7 +121,7 @@ class BaseDefaultCodecs implements CodecConfigurer.DefaultCodecs {
readers.add(new DecoderHttpMessageReader<>(StringDecoder.textPlainOnly()));
FormHttpMessageReader formReader = new FormHttpMessageReader();
formReader.setDisableLoggingRequestDetails(this.disableLoggingRequestDetails);
formReader.setEnableLoggingRequestDetails(this.enableLoggingRequestDetails);
readers.add(formReader);
extendTypedReaders(readers);

View File

@ -88,10 +88,10 @@ class ClientDefaultCodecsImpl extends BaseDefaultCodecs implements ClientCodecCo
protected void extendTypedWriters(List<HttpMessageWriter<?>> typedWriters) {
FormHttpMessageWriter formWriter = new FormHttpMessageWriter();
formWriter.setDisableLoggingRequestDetails(isDisableLoggingRequestDetails());
formWriter.setEnableLoggingRequestDetails(isEnableLoggingRequestDetails());
MultipartHttpMessageWriter multipartWriter = new MultipartHttpMessageWriter(getPartWriters(), formWriter);
multipartWriter.setDisableLoggingRequestDetails(isDisableLoggingRequestDetails());
multipartWriter.setEnableLoggingRequestDetails(isEnableLoggingRequestDetails());
typedWriters.add(multipartWriter);
}

View File

@ -52,10 +52,15 @@ class ServerDefaultCodecsImpl extends BaseDefaultCodecs implements ServerCodecCo
@Override
protected void extendTypedReaders(List<HttpMessageReader<?>> typedReaders) {
if (synchronossMultipartPresent) {
boolean enable = isEnableLoggingRequestDetails();
SynchronossPartHttpMessageReader partReader = new SynchronossPartHttpMessageReader();
partReader.setDisableLoggingRequestDetails(isDisableLoggingRequestDetails());
partReader.setEnableLoggingRequestDetails(enable);
typedReaders.add(partReader);
typedReaders.add(new MultipartHttpMessageReader(partReader));
MultipartHttpMessageReader reader = new MultipartHttpMessageReader(partReader);
reader.setEnableLoggingRequestDetails(enable);
typedReaders.add(reader);
}
}

View File

@ -74,7 +74,7 @@ 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.suppressLogging(hints)) {
if (logger.isDebugEnabled() && !Hints.isLoggingSuppressed(hints)) {
logger.debug(Hints.getLogPrefix(hints) + "Encoding [" + value + "]");
}
DataBuffer buffer = dataBufferFactory.allocateBuffer(1024);

View File

@ -57,7 +57,7 @@ public class ReactorHttpHandlerAdapter implements BiFunction<HttpServerRequest,
NettyDataBufferFactory bufferFactory = new NettyDataBufferFactory(reactorResponse.alloc());
try {
ReactorServerHttpRequest request = new ReactorServerHttpRequest(reactorRequest, bufferFactory);
ServerHttpResponse response = new ReactorServerHttpResponse(reactorResponse, bufferFactory, request);
ServerHttpResponse response = new ReactorServerHttpResponse(reactorResponse, bufferFactory);
if (request.getMethod() == HttpMethod.HEAD) {
response = new HttpHeadResponseDecorator(response);

View File

@ -165,13 +165,7 @@ class ReactorServerHttpRequest extends AbstractServerHttpRequest {
@Override
public Flux<DataBuffer> getBody() {
return this.request.receive().retain()
.doOnNext(buffer -> {
if (logger.isTraceEnabled()) {
logger.trace(getLogPrefix() + "Read " + buffer.readableBytes() + " bytes");
}
})
.map(this.bufferFactory::wrap);
return this.request.receive().retain().map(this.bufferFactory::wrap);
}
@SuppressWarnings("unchecked")

View File

@ -45,16 +45,11 @@ class ReactorServerHttpResponse extends AbstractServerHttpResponse implements Ze
private final HttpServerResponse response;
private final ReactorServerHttpRequest request;
public ReactorServerHttpResponse(HttpServerResponse response, DataBufferFactory bufferFactory,
ReactorServerHttpRequest request) {
public ReactorServerHttpResponse(HttpServerResponse response, DataBufferFactory bufferFactory) {
super(bufferFactory);
Assert.notNull(response, "HttpServerResponse must not be null");
this.response = response;
this.request = request;
}
@ -119,12 +114,7 @@ class ReactorServerHttpResponse extends AbstractServerHttpResponse implements Ze
}
private Publisher<ByteBuf> toByteBufs(Publisher<? extends DataBuffer> dataBuffers) {
return Flux.from(dataBuffers).map(NettyDataBufferFactory::toByteBuf)
.doOnNext(byteBuf -> {
if (logger.isTraceEnabled()) {
logger.trace("Writing " + byteBuf.readableBytes() + " bytes");
}
});
return Flux.from(dataBuffers).map(NettyDataBufferFactory::toByteBuf);
}
}

View File

@ -199,15 +199,7 @@ class ServletServerHttpRequest extends AbstractServerHttpRequest {
@Nullable
DataBuffer readFromInputStream() throws IOException {
int read = this.request.getInputStream().read(this.buffer);
if (logger.isTraceEnabled()) {
logger.trace(getLogPrefix() + "Read " + read + (read != -1 ? " bytes" : ""));
}
else {
Log rsReadLogger = AbstractListenerReadPublisher.rsReadLogger;
if (rsReadLogger.isTraceEnabled()) {
rsReadLogger.trace(getLogPrefix() + "Read " + read + (read != -1 ? " bytes" : ""));
}
}
logBytesRead(read);
if (read > 0) {
DataBuffer dataBuffer = this.bufferFactory.allocateBuffer(read);
@ -222,6 +214,13 @@ class ServletServerHttpRequest extends AbstractServerHttpRequest {
return null;
}
protected final void logBytesRead(int read) {
Log rsReadLogger = AbstractListenerReadPublisher.rsReadLogger;
if (rsReadLogger.isTraceEnabled()) {
rsReadLogger.trace(getLogPrefix() + "Read " + read + (read != -1 ? " bytes" : ""));
}
}
@SuppressWarnings("unchecked")
@Override
public <T> T getNativeRequest() {

View File

@ -86,9 +86,7 @@ public class TomcatHttpHandlerAdapter extends ServletHttpHandlerAdapter {
ServletRequest request = getNativeRequest();
int read = ((CoyoteInputStream) request.getInputStream()).read(byteBuffer);
if (logger.isTraceEnabled()) {
logger.trace(getLogPrefix() + "read:" + read);
}
logBytesRead(read);
if (read > 0) {
dataBuffer.writePosition(read);

View File

@ -31,7 +31,6 @@ import io.undertow.connector.PooledByteBuffer;
import io.undertow.server.HttpServerExchange;
import io.undertow.server.handlers.Cookie;
import io.undertow.util.HeaderValues;
import org.apache.commons.logging.Log;
import org.xnio.channels.StreamSourceChannel;
import reactor.core.publisher.Flux;
@ -182,11 +181,7 @@ class UndertowServerHttpRequest extends AbstractServerHttpRequest {
ByteBuffer byteBuffer = pooledByteBuffer.getBuffer();
int read = this.channel.read(byteBuffer);
Log logger = UndertowServerHttpRequest.this.logger;
if (logger.isTraceEnabled()) {
logger.trace(getLogPrefix() + "Read " + read + (read != -1 ? " bytes" : ""));
}
else if (rsReadLogger.isTraceEnabled()) {
if (rsReadLogger.isTraceEnabled()) {
rsReadLogger.trace(getLogPrefix() + "Read " + read + (read != -1 ? " bytes" : ""));
}

View File

@ -121,18 +121,21 @@ public class DefaultServerWebExchange implements ServerWebExchange {
Assert.notNull(codecConfigurer, "'codecConfigurer' is required");
Assert.notNull(localeContextResolver, "'localeContextResolver' is required");
// Initialize before first call to getLogPrefix()
this.attributes.put(ServerWebExchange.LOG_ID_ATTRIBUTE, request.getId());
this.request = request;
this.response = response;
this.sessionMono = sessionManager.getSession(this).cache();
this.localeContextResolver = localeContextResolver;
this.formDataMono = initFormData(request, codecConfigurer);
this.multipartDataMono = initMultipartData(request, codecConfigurer);
this.formDataMono = initFormData(request, codecConfigurer, getLogPrefix());
this.multipartDataMono = initMultipartData(request, codecConfigurer, getLogPrefix());
this.applicationContext = applicationContext;
}
@SuppressWarnings("unchecked")
private static Mono<MultiValueMap<String, String>> initFormData(ServerHttpRequest request,
ServerCodecConfigurer configurer) {
ServerCodecConfigurer configurer, String logPrefix) {
try {
MediaType contentType = request.getHeaders().getContentType();
@ -141,7 +144,7 @@ public class DefaultServerWebExchange implements ServerWebExchange {
.filter(reader -> reader.canRead(FORM_DATA_TYPE, MediaType.APPLICATION_FORM_URLENCODED))
.findFirst()
.orElseThrow(() -> new IllegalStateException("No form data HttpMessageReader.")))
.readMono(FORM_DATA_TYPE, request, Hints.none())
.readMono(FORM_DATA_TYPE, request, Hints.from(Hints.LOG_PREFIX_HINT, logPrefix))
.switchIfEmpty(EMPTY_FORM_DATA)
.cache();
}
@ -154,7 +157,7 @@ public class DefaultServerWebExchange implements ServerWebExchange {
@SuppressWarnings("unchecked")
private static Mono<MultiValueMap<String, Part>> initMultipartData(ServerHttpRequest request,
ServerCodecConfigurer configurer) {
ServerCodecConfigurer configurer, String logPrefix) {
try {
MediaType contentType = request.getHeaders().getContentType();
@ -163,7 +166,7 @@ public class DefaultServerWebExchange implements ServerWebExchange {
.filter(reader -> reader.canRead(MULTIPART_DATA_TYPE, MediaType.MULTIPART_FORM_DATA))
.findFirst()
.orElseThrow(() -> new IllegalStateException("No multipart HttpMessageReader.")))
.readMono(MULTIPART_DATA_TYPE, request, Hints.none())
.readMono(MULTIPART_DATA_TYPE, request, Hints.from(Hints.LOG_PREFIX_HINT, logPrefix))
.switchIfEmpty(EMPTY_MULTIPART_DATA)
.cache();
}

View File

@ -26,6 +26,7 @@ import reactor.core.publisher.Mono;
import org.springframework.context.ApplicationContext;
import org.springframework.core.NestedExceptionUtils;
import org.springframework.http.HttpHeaders;
import org.springframework.http.HttpStatus;
import org.springframework.http.codec.LoggingCodecSupport;
import org.springframework.http.codec.ServerCodecConfigurer;
@ -94,8 +95,8 @@ public class HttpWebHandlerAdapter extends WebHandlerDecorator implements HttpHa
@Nullable
private ApplicationContext applicationContext;
/** Do not log potentially sensitive data (query/form at DEBUG, headers at TRACE). */
private boolean disableLoggingRequestDetails = false;
/** Whether to log potentially sensitive info (form data at DEBUG, headers at TRACE). */
private boolean enableLoggingRequestDetails = false;
public HttpWebHandlerAdapter(WebHandler delegate) {
@ -132,12 +133,12 @@ public class HttpWebHandlerAdapter extends WebHandlerDecorator implements HttpHa
Assert.notNull(codecConfigurer, "ServerCodecConfigurer is required");
this.codecConfigurer = codecConfigurer;
this.disableLoggingRequestDetails = false;
this.enableLoggingRequestDetails = false;
this.codecConfigurer.getReaders().stream()
.filter(LoggingCodecSupport.class::isInstance)
.forEach(reader -> {
if (((LoggingCodecSupport) reader).isDisableLoggingRequestDetails()) {
this.disableLoggingRequestDetails = true;
if (((LoggingCodecSupport) reader).isEnableLoggingRequestDetails()) {
this.enableLoggingRequestDetails = true;
}
});
}
@ -195,17 +196,11 @@ public class HttpWebHandlerAdapter extends WebHandlerDecorator implements HttpHa
*/
public void afterPropertiesSet() {
if (logger.isDebugEnabled()) {
if (this.disableLoggingRequestDetails) {
logger.debug("Logging query, form data, multipart data, and headers is OFF.");
}
else {
logger.warn("\n\n" +
"!!!!!!!!!!!!!!!!!!!\n" +
"Logging query, form and multipart data (DEBUG), and headers (TRACE) may show sensitive data.\n" +
"If not in development, set \"disableLoggingRequestDetails(true)\" on ServerCodecConfigurer,\n" +
"or lower the log level.\n" +
"!!!!!!!!!!!!!!!!!!!\n");
}
String value = this.enableLoggingRequestDetails ?
"shown which may lead to unsafe logging of potentially sensitive data" :
"masked to prevent unsafe logging of potentially sensitive data";
logger.debug("enableLoggingRequestDetails='" + this.enableLoggingRequestDetails +
"': form data and headers will be " + value);
}
}
@ -214,7 +209,6 @@ public class HttpWebHandlerAdapter extends WebHandlerDecorator implements HttpHa
public Mono<Void> handle(ServerHttpRequest request, ServerHttpResponse response) {
ServerWebExchange exchange = createExchange(request, response);
exchange.getAttributes().put(ServerWebExchange.LOG_ID_ATTRIBUTE, request.getId());
logExchange(exchange);
return getDelegate().handle(exchange)
@ -233,8 +227,7 @@ public class HttpWebHandlerAdapter extends WebHandlerDecorator implements HttpHa
String logPrefix = exchange.getLogPrefix();
ServerHttpRequest request = exchange.getRequest();
if (logger.isTraceEnabled()) {
String headers = this.disableLoggingRequestDetails ? "" : ", headers=" + request.getHeaders();
logger.trace(logPrefix + formatRequest(request) + headers);
logger.trace(logPrefix + formatRequest(request) + ", headers=" + formatHeaders(request.getHeaders()));
}
else {
logger.debug(logPrefix + formatRequest(request));
@ -243,11 +236,8 @@ public class HttpWebHandlerAdapter extends WebHandlerDecorator implements HttpHa
}
private String formatRequest(ServerHttpRequest request) {
String query = "";
if (!this.disableLoggingRequestDetails) {
String rawQuery = request.getURI().getRawQuery();
query = StringUtils.hasText(rawQuery) ? "?" + rawQuery : "";
}
String rawQuery = request.getURI().getRawQuery();
String query = StringUtils.hasText(rawQuery) ? "?" + rawQuery : "";
return "HTTP " + request.getMethod() + " \"" + request.getPath() + query + "\"";
}
@ -258,8 +248,7 @@ public class HttpWebHandlerAdapter extends WebHandlerDecorator implements HttpHa
HttpStatus status = response.getStatusCode();
String message = "Completed " + (status != null ? status : "200 OK");
if (logger.isTraceEnabled()) {
String headers = this.disableLoggingRequestDetails ? "" : ", headers=" + response.getHeaders();
logger.trace(logPrefix + message + headers);
logger.trace(logPrefix + message + ", headers=" + formatHeaders(response.getHeaders()));
}
else {
logger.debug(logPrefix + message);
@ -267,6 +256,11 @@ public class HttpWebHandlerAdapter extends WebHandlerDecorator implements HttpHa
}
}
private String formatHeaders(HttpHeaders responseHeaders) {
return this.enableLoggingRequestDetails ?
responseHeaders.toString() : responseHeaders.isEmpty() ? "{}" : "{masked}";
}
private Mono<Void> handleUnresolvedError(ServerWebExchange exchange, Throwable ex) {
ServerHttpRequest request = exchange.getRequest();

View File

@ -22,6 +22,7 @@ import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import reactor.core.publisher.Mono;
import org.springframework.http.HttpHeaders;
import org.springframework.http.HttpMethod;
import org.springframework.http.HttpStatus;
import org.springframework.http.client.reactive.ClientHttpConnector;
@ -71,7 +72,7 @@ public abstract class ExchangeFunctions {
private final ExchangeStrategies strategies;
private boolean disableLoggingRequestDetails;
private boolean enableLoggingRequestDetails;
public DefaultExchangeFunction(ClientHttpConnector connector, ExchangeStrategies strategies) {
@ -83,8 +84,8 @@ public abstract class ExchangeFunctions {
strategies.messageWriters().stream()
.filter(LoggingCodecSupport.class::isInstance)
.forEach(reader -> {
if (((LoggingCodecSupport) reader).isDisableLoggingRequestDetails()) {
this.disableLoggingRequestDetails = true;
if (((LoggingCodecSupport) reader).isEnableLoggingRequestDetails()) {
this.enableLoggingRequestDetails = true;
}
});
}
@ -109,12 +110,13 @@ public abstract class ExchangeFunctions {
private void logRequest(ClientRequest request) {
if (logger.isDebugEnabled()) {
String formatted = request.url().toString();
if (this.disableLoggingRequestDetails) {
int index = formatted.indexOf("?");
formatted = (index != -1 ? formatted.substring(0, index) : formatted);
String message = request.logPrefix() + "HTTP " + request.method() + " " + request.url();
if (logger.isTraceEnabled()) {
logger.trace(message + ", headers=" + formatHeaders(request.headers()));
}
else {
logger.debug(message);
}
logger.debug(request.logPrefix() + "HTTP " + request.method() + " " + formatted);
}
}
@ -122,16 +124,19 @@ public abstract class ExchangeFunctions {
if (logger.isDebugEnabled()) {
int code = response.getRawStatusCode();
HttpStatus status = HttpStatus.resolve(code);
String message = "Response " + (status != null ? status : code);
String message = logPrefix + "Response " + (status != null ? status : code);
if (logger.isTraceEnabled()) {
String headers = this.disableLoggingRequestDetails ? "" : ", headers=" + response.getHeaders();
logger.trace(logPrefix + message + headers);
logger.trace(message + ", headers=" + formatHeaders(response.getHeaders()));
}
else {
logger.debug(logPrefix + message);
logger.debug(message);
}
}
}
private String formatHeaders(HttpHeaders headers) {
return this.enableLoggingRequestDetails ? headers.toString() : headers.isEmpty() ? "{}" : "{masked}";
}
}
}

View File

@ -138,6 +138,9 @@ public class RequestPartMethodArgumentResolver extends AbstractMessageReaderArgu
return parts.flatMap(part -> {
ServerHttpRequest partRequest = new PartServerHttpRequest(exchange.getRequest(), part);
ServerWebExchange partExchange = exchange.mutate().request(partRequest).build();
if (logger.isDebugEnabled()) {
logger.debug(exchange.getLogPrefix() + "Decoding part '" + part.name() + "'");
}
return readBody(elementType, isRequired, bindingContext, partExchange);
});
}

View File

@ -208,7 +208,7 @@ public class MultipartIntegrationTests extends AbstractHttpHandlerIntegrationTes
}
private static Mono<String> partFluxDescription(Flux<? extends Part> partsFlux) {
return partsFlux.log().collectList().map(MultipartIntegrationTests::partListDescription);
return partsFlux.collectList().map(MultipartIntegrationTests::partListDescription);
}
private static String partListDescription(List<? extends Part> parts) {

View File

@ -309,9 +309,6 @@ public class DispatcherServlet extends FrameworkServlet {
/** Perform cleanup of request attributes after include request?. */
private boolean cleanupAfterInclude = true;
/** Do not log potentially sensitive information (params at DEBUG and headers at TRACE). */
private boolean disableLoggingRequestDetails = false;
/** MultipartResolver used by this servlet. */
@Nullable
private MultipartResolver multipartResolver;
@ -487,25 +484,6 @@ public class DispatcherServlet extends FrameworkServlet {
this.cleanupAfterInclude = cleanupAfterInclude;
}
/**
* Set whether the {@code DispatcherServlet} should not log request
* parameters and headers. By default request parameters are logged at DEBUG
* while headers are logged at TRACE under the log category
* {@code "org.springframework.web.servlet.DispatcherServlet"}. Those may
* contain sensitive information, however this is typically not a problem
* since DEBUG and TRACE are only expected to be enabled in development.
* This property may be used to explicitly disable logging of such
* information regardless of the log level.
* <p>By default this is set to {@code false} in which case request details
* are logged. If set to {@code true} request details will not be logged at
* any log level.
* @param disableLoggingRequestDetails whether to disable or not
* @since 5.1
*/
public void setDisableLoggingRequestDetails(boolean disableLoggingRequestDetails) {
this.disableLoggingRequestDetails = disableLoggingRequestDetails;
}
/**
* This implementation calls {@link #initStrategies}.
@ -529,20 +507,6 @@ public class DispatcherServlet extends FrameworkServlet {
initRequestToViewNameTranslator(context);
initViewResolvers(context);
initFlashMapManager(context);
if (logger.isDebugEnabled()) {
if (this.disableLoggingRequestDetails) {
logger.debug("Logging request parameters and headers is OFF.");
}
else {
logger.warn("\n\n" +
"!!!!!!!!!!!!!!!!!!!\n" +
"Logging request parameters (DEBUG) and headers (TRACE) may show sensitive data.\n" +
"If not in development, use the DispatcherServlet property \"disableLoggingRequestDetails=true\",\n" +
"or lower the log level.\n" +
"!!!!!!!!!!!!!!!!!!!\n");
}
}
}
/**
@ -990,26 +954,32 @@ public class DispatcherServlet extends FrameworkServlet {
private void logRequest(HttpServletRequest request) {
if (logger.isDebugEnabled()) {
String params = "";
if (!this.disableLoggingRequestDetails) {
String params;
if (isEnableLoggingRequestDetails()) {
params = request.getParameterMap().entrySet().stream()
.map(entry -> entry.getKey() + ":" + Arrays.toString(entry.getValue()))
.collect(Collectors.joining(", ", ", parameters={", "}"));
.collect(Collectors.joining(", "));
}
else {
params = request.getParameterMap().isEmpty() ? "" : "masked";
}
String query = StringUtils.isEmpty(request.getQueryString()) ? "" : "?" + request.getQueryString();
String dispatchType = !request.getDispatcherType().equals(DispatcherType.REQUEST) ?
"\"" + request.getDispatcherType().name() + "\" dispatch for " : "";
String message = dispatchType + request.getMethod() + " \"" + getRequestUri(request) + "\"" + params;
String message = dispatchType + request.getMethod() +
" \"" + getRequestUri(request) + query + "\", parameters={" + params + "}";
if (logger.isTraceEnabled()) {
String headers = "";
if (!this.disableLoggingRequestDetails) {
headers = Collections.list(request.getHeaderNames()).stream()
.map(name -> name + ":" + Collections.list(request.getHeaders(name)))
.collect(Collectors.joining(", ", ", headers={", "}"));
List<String> values = Collections.list(request.getHeaderNames());
String headers = values.size() > 0 ? "masked" : "";
if (isEnableLoggingRequestDetails()) {
headers = values.stream().map(name -> name + ":" + Collections.list(request.getHeaders(name)))
.collect(Collectors.joining(", "));
}
logger.trace(message + headers + " in DispatcherServlet '" + getServletName() + "'");
logger.trace(message + ", headers={" + headers + "} in DispatcherServlet '" + getServletName() + "'");
}
else {
logger.debug(message);

View File

@ -19,8 +19,10 @@ package org.springframework.web.servlet;
import java.io.IOException;
import java.security.Principal;
import java.util.ArrayList;
import java.util.Collection;
import java.util.List;
import java.util.concurrent.Callable;
import java.util.stream.Collectors;
import javax.servlet.DispatcherType;
import javax.servlet.ServletContext;
import javax.servlet.ServletException;
@ -217,6 +219,9 @@ public abstract class FrameworkServlet extends HttpServletBean implements Applic
/** Flag used to detect whether onRefresh has already been called. */
private boolean refreshEventReceived = false;
/** Whether to log potentially sensitive info (request params at DEBUG + headers at TRACE). */
private boolean enableLoggingRequestDetails = false;
/**
* Create a new {@code FrameworkServlet} that will create its own internal web
@ -467,6 +472,26 @@ public abstract class FrameworkServlet extends HttpServletBean implements Applic
this.dispatchTraceRequest = dispatchTraceRequest;
}
/**
* Whether to log request params at DEBUG level, and headers at TRACE level.
* Both may contain sensitive information.
* <p>By default set to {@code false} so that request details are not shown.
* @param enable whether to enable or not
* @since 5.1
*/
public void setEnableLoggingRequestDetails(boolean enable) {
this.enableLoggingRequestDetails = enable;
}
/**
* Whether logging of potentially sensitive, request details at DEBUG and
* TRACE level is allowed.
* @since 5.1
*/
public boolean isEnableLoggingRequestDetails() {
return this.enableLoggingRequestDetails;
}
/**
* Called by Spring via {@link ApplicationContextAware} to inject the current
* application context. This method allows FrameworkServlets to be registered as
@ -506,6 +531,14 @@ public abstract class FrameworkServlet extends HttpServletBean implements Applic
throw ex;
}
if (logger.isDebugEnabled()) {
String value = this.enableLoggingRequestDetails ?
"shown which may lead to unsafe logging of potentially sensitive data" :
"masked to prevent unsafe logging of potentially sensitive data";
logger.debug("enableLoggingRequestDetails='" + this.enableLoggingRequestDetails +
"': request parameters and headers will be " + value);
}
if (logger.isInfoEnabled()) {
long elapsedTime = System.currentTimeMillis() - startTime;
logger.info("FrameworkServlet '" + getServletName() + "': initialization completed in " +
@ -989,38 +1022,7 @@ public abstract class FrameworkServlet extends HttpServletBean implements Applic
if (requestAttributes != null) {
requestAttributes.requestCompleted();
}
if (logger.isDebugEnabled()) {
boolean isRequestDispatch = request.getDispatcherType().equals(DispatcherType.REQUEST);
String dispatchType = request.getDispatcherType().name();
if (failureCause != null) {
if (!isRequestDispatch) {
logger.debug("Unresolved failure from \"" + dispatchType + "\" dispatch: " + failureCause);
}
else if (logger.isTraceEnabled()) {
logger.trace("Failed to complete request", failureCause);
}
else {
logger.debug("Failed to complete request: " + failureCause);
}
}
else {
if (asyncManager.isConcurrentHandlingStarted()) {
logger.debug("Exiting but response remains open for further handling");
}
else {
int status = response.getStatus();
if (!isRequestDispatch) {
logger.debug("Exiting from \"" + dispatchType + "\" dispatch (status " + status + ")");
}
else {
HttpStatus httpStatus = HttpStatus.resolve(status);
logger.debug("Completed " + (httpStatus != null ? httpStatus : status));
}
}
}
}
logResult(request, response, failureCause, asyncManager);
publishRequestHandledEvent(request, response, startTime, failureCause);
}
}
@ -1084,6 +1086,59 @@ public abstract class FrameworkServlet extends HttpServletBean implements Applic
}
}
private void logResult(HttpServletRequest request, HttpServletResponse response,
@Nullable Throwable failureCause, WebAsyncManager asyncManager) {
if (!logger.isDebugEnabled()) {
return;
}
String dispatchType = request.getDispatcherType().name();
boolean initialDispatch = request.getDispatcherType().equals(DispatcherType.REQUEST);
if (failureCause != null) {
if (!initialDispatch) {
// FORWARD/ERROR/ASYNC: minimal message (there should be enough context already)
logger.debug("Unresolved failure from \"" + dispatchType + "\" dispatch: " + failureCause);
}
else if (logger.isTraceEnabled()) {
logger.trace("Failed to complete request", failureCause);
}
else {
logger.debug("Failed to complete request: " + failureCause);
}
return;
}
if (asyncManager.isConcurrentHandlingStarted()) {
logger.debug("Exiting but response remains open for further handling");
return;
}
int status = response.getStatus();
String headers = ""; // nothing below trace
if (logger.isTraceEnabled()) {
Collection<String> names = response.getHeaderNames();
if (this.enableLoggingRequestDetails) {
headers = names.stream().map(name -> name + ":" + response.getHeaders(name))
.collect(Collectors.joining(", "));
}
else {
headers = names.isEmpty() ? "" : "masked";
}
headers = ", headers={" + headers + "}";
}
if (!initialDispatch) {
logger.debug("Exiting from \"" + dispatchType + "\" dispatch, status " + status + headers);
}
else {
HttpStatus httpStatus = HttpStatus.resolve(status);
logger.debug("Completed " + (httpStatus != null ? httpStatus : status) + headers);
}
}
private void publishRequestHandledEvent(HttpServletRequest request, HttpServletResponse response,
long startTime, @Nullable Throwable failureCause) {