Serialize values for debug output safely in AbstractMongoEventListener.

We now make sure that codec configuration will not cause an exception when debug logging is turned on.

Resolves: #3968
Original Pull Request: #3970

Author: christophstrobl

spring-data-mongodb/src/main/java/org/springframework/data/mongodb/core/mapping/event/AbstractMongoEventListener.java

@@ -20,6 +20,7 @@
 
 import org.springframework.context.ApplicationListener;
 import org.springframework.core.GenericTypeResolver;
+import org.springframework.data.mongodb.core.query.SerializationUtils;
 
 /**
  * Base class to implement domain class specific {@link ApplicationListener}s.
@@ -100,7 +101,7 @@ public void onApplicationEvent(MongoMappingEvent<?> event) {
 	public void onBeforeConvert(BeforeConvertEvent<E> event) {
 
 		if (LOG.isDebugEnabled()) {
-			LOG.debug(String.format("onBeforeConvert(%s)", event.getSource()));
+			LOG.debug(String.format("onBeforeConvert(%s)", SerializationUtils.serializeToJsonSafely(event.getSource())));
 		}
 	}
 
@@ -113,7 +114,7 @@ public void onBeforeConvert(BeforeConvertEvent<E> event) {
 	public void onBeforeSave(BeforeSaveEvent<E> event) {
 
 		if (LOG.isDebugEnabled()) {
-			LOG.debug(String.format("onBeforeSave(%s, %s)", event.getSource(), event.getDocument()));
+			LOG.debug(String.format("onBeforeSave(%s, %s)", SerializationUtils.serializeToJsonSafely(event.getSource()), SerializationUtils.serializeToJsonSafely(event.getDocument())));
 		}
 	}
 
@@ -126,7 +127,7 @@ public void onBeforeSave(BeforeSaveEvent<E> event) {
 	public void onAfterSave(AfterSaveEvent<E> event) {
 
 		if (LOG.isDebugEnabled()) {
-			LOG.debug(String.format("onAfterSave(%s, %s)", event.getSource(), event.getDocument()));
+			LOG.debug(String.format("onAfterSave(%s, %s)", SerializationUtils.serializeToJsonSafely(event.getSource()), SerializationUtils.serializeToJsonSafely(event.getDocument())));
 		}
 	}
 
@@ -139,7 +140,7 @@ public void onAfterSave(AfterSaveEvent<E> event) {
 	public void onAfterLoad(AfterLoadEvent<E> event) {
 
 		if (LOG.isDebugEnabled()) {
-			LOG.debug(String.format("onAfterLoad(%s)", event.getDocument()));
+			LOG.debug(String.format("onAfterLoad(%s)", SerializationUtils.serializeToJsonSafely(event.getDocument())));
 		}
 	}
 
@@ -152,7 +153,7 @@ public void onAfterLoad(AfterLoadEvent<E> event) {
 	public void onAfterConvert(AfterConvertEvent<E> event) {
 
 		if (LOG.isDebugEnabled()) {
-			LOG.debug(String.format("onAfterConvert(%s, %s)", event.getDocument(), event.getSource()));
+			LOG.debug(String.format("onAfterConvert(%s, %s)", SerializationUtils.serializeToJsonSafely(event.getDocument()), SerializationUtils.serializeToJsonSafely(event.getSource())));
 		}
 	}
 
@@ -165,7 +166,7 @@ public void onAfterConvert(AfterConvertEvent<E> event) {
 	public void onAfterDelete(AfterDeleteEvent<E> event) {
 
 		if (LOG.isDebugEnabled()) {
-			LOG.debug(String.format("onAfterDelete(%s)", event.getDocument()));
+			LOG.debug(String.format("onAfterDelete(%s)", SerializationUtils.serializeToJsonSafely(event.getDocument())));
 		}
 	}
 
@@ -178,7 +179,7 @@ public void onAfterDelete(AfterDeleteEvent<E> event) {
 	public void onBeforeDelete(BeforeDeleteEvent<E> event) {
 
 		if (LOG.isDebugEnabled()) {
-			LOG.debug(String.format("onBeforeDelete(%s)", event.getDocument()));
+			LOG.debug(String.format("onBeforeDelete(%s)", SerializationUtils.serializeToJsonSafely(event.getDocument())));
 		}
 	}
 }

spring-data-mongodb/src/test/java/org/springframework/data/mongodb/core/mapping/event/AbstractMongoEventListenerUnitTests.java

@@ -17,15 +17,18 @@
 
 import static org.assertj.core.api.Assertions.*;
 
+import java.time.Instant;
+
 import org.bson.Document;
 import org.junit.jupiter.api.Test;
-
 import org.springframework.context.support.AbstractApplicationContext;
 import org.springframework.context.support.ClassPathXmlApplicationContext;
 import org.springframework.data.mongodb.core.mapping.Account;
 import org.springframework.data.mongodb.repository.Contact;
 import org.springframework.data.mongodb.repository.Person;
 
+import com.mongodb.BasicDBObject;
+
 /**
  * Unit tests for {@link AbstractMongoEventListener}.
  *
@@ -154,6 +157,14 @@ public void donInvokePersonCallbackForUntypedEvent() {
 		assertThat(listener.invokedOnBeforeDelete).isFalse();
 	}
 
+	@Test // GH-3968
+	public void debugLogShouldNotFailMongoDBCodecError() {
+
+		MongoMappingEvent<BasicDBObject> event = new BeforeConvertEvent<>(new BasicDBObject("date", Instant.now()), "collection-1");
+		UntypedEventListener listener = new UntypedEventListener();
+		listener.onApplicationEvent(event);
+	}
+
 	class SamplePersonEventListener extends AbstractMongoEventListener<Person> {
 
 		boolean invokedOnBeforeConvert;

spring-data-mongodb/src/test/resources/logback.xml

@@ -7,11 +7,16 @@
 		</encoder>
 	</appender>
 
+	<appender name="no-op" class="ch.qos.logback.core.helpers.NOPAppender" />
+
 	<!--
 	<logger name="org.springframework" level="debug" />
 	 -->
 
 	<logger name="org.springframework.data.mongodb.core" level="error"/>
+	<logger name="org.springframework.data.mongodb.core.mapping.event.AbstractMongoEventListener" level="debug" additivity="false">
+		<appender-ref ref="no-op" />
+	</logger>
 	<logger name="org.springframework.data.mongodb.test.util" level="info"/>
 
 	<root level="error">