From ece497a2385cb9a4e247896a7a8102a5a01782d9 Mon Sep 17 00:00:00 2001 From: Christoph Strobl Date: Wed, 15 Mar 2017 15:20:44 +0100 Subject: [PATCH 1/3] DATAMONGO-1645 - RuntimeException when logging BeforeDeleteEvent and AfterDeleteEvent. Prepare issue branch. --- pom.xml | 2 +- spring-data-mongodb-cross-store/pom.xml | 4 ++-- spring-data-mongodb-distribution/pom.xml | 2 +- spring-data-mongodb-log4j/pom.xml | 2 +- spring-data-mongodb/pom.xml | 2 +- 5 files changed, 6 insertions(+), 6 deletions(-) diff --git a/pom.xml b/pom.xml index 75fa63795e..7a6dd6cfb8 100644 --- a/pom.xml +++ b/pom.xml @@ -5,7 +5,7 @@ org.springframework.data spring-data-mongodb-parent - 1.11.0.BUILD-SNAPSHOT + 1.11.0.DATAMONGO-1645-SNAPSHOT pom Spring Data MongoDB diff --git a/spring-data-mongodb-cross-store/pom.xml b/spring-data-mongodb-cross-store/pom.xml index dc5a04a7ad..8eff179af4 100644 --- a/spring-data-mongodb-cross-store/pom.xml +++ b/spring-data-mongodb-cross-store/pom.xml @@ -6,7 +6,7 @@ org.springframework.data spring-data-mongodb-parent - 1.11.0.BUILD-SNAPSHOT + 1.11.0.DATAMONGO-1645-SNAPSHOT ../pom.xml @@ -48,7 +48,7 @@ org.springframework.data spring-data-mongodb - 1.11.0.BUILD-SNAPSHOT + 1.11.0.DATAMONGO-1645-SNAPSHOT diff --git a/spring-data-mongodb-distribution/pom.xml b/spring-data-mongodb-distribution/pom.xml index 9876e11ee3..7e3bddd74b 100644 --- a/spring-data-mongodb-distribution/pom.xml +++ b/spring-data-mongodb-distribution/pom.xml @@ -13,7 +13,7 @@ org.springframework.data spring-data-mongodb-parent - 1.11.0.BUILD-SNAPSHOT + 1.11.0.DATAMONGO-1645-SNAPSHOT ../pom.xml diff --git a/spring-data-mongodb-log4j/pom.xml b/spring-data-mongodb-log4j/pom.xml index c0436bac90..67583ab814 100644 --- a/spring-data-mongodb-log4j/pom.xml +++ b/spring-data-mongodb-log4j/pom.xml @@ -5,7 +5,7 @@ org.springframework.data spring-data-mongodb-parent - 1.11.0.BUILD-SNAPSHOT + 1.11.0.DATAMONGO-1645-SNAPSHOT ../pom.xml diff --git a/spring-data-mongodb/pom.xml b/spring-data-mongodb/pom.xml index ea1b594b99..08740f2d34 100644 --- a/spring-data-mongodb/pom.xml +++ b/spring-data-mongodb/pom.xml @@ -11,7 +11,7 @@ org.springframework.data spring-data-mongodb-parent - 1.11.0.BUILD-SNAPSHOT + 1.11.0.DATAMONGO-1645-SNAPSHOT ../pom.xml From ae283dac409e6580ed13a61702d357684c198a86 Mon Sep 17 00:00:00 2001 From: Christoph Strobl Date: Thu, 16 Mar 2017 16:14:32 +0100 Subject: [PATCH 2/3] DATAMONGO-1645 - Safely serialize JSON output for log message in LoggingEventListener. We now make sure to safely serialize JSON output for mapped documents. This prevents the logger from rendering false exception messages to log appender. --- .../mapping/event/LoggingEventListener.java | 17 +-- .../event/LoggingEventListenerTests.java | 102 ++++++++++++++++++ 2 files changed, 112 insertions(+), 7 deletions(-) create mode 100644 spring-data-mongodb/src/test/java/org/springframework/data/mongodb/core/mapping/event/LoggingEventListenerTests.java diff --git a/spring-data-mongodb/src/main/java/org/springframework/data/mongodb/core/mapping/event/LoggingEventListener.java b/spring-data-mongodb/src/main/java/org/springframework/data/mongodb/core/mapping/event/LoggingEventListener.java index 2e27551a83..06a329393e 100644 --- a/spring-data-mongodb/src/main/java/org/springframework/data/mongodb/core/mapping/event/LoggingEventListener.java +++ b/spring-data-mongodb/src/main/java/org/springframework/data/mongodb/core/mapping/event/LoggingEventListener.java @@ -1,5 +1,5 @@ /* - * Copyright 2011-2016 the original author or authors. + * Copyright 2011-2017 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. @@ -15,6 +15,8 @@ */ package org.springframework.data.mongodb.core.mapping.event; +import static org.springframework.data.mongodb.core.query.SerializationUtils.*; + import org.slf4j.Logger; import org.slf4j.LoggerFactory; import org.springframework.context.ApplicationListener; @@ -25,6 +27,7 @@ * @author Jon Brisbin * @author Martin Baumgartner * @author Oliver Gierke + * @author Christoph Strobl */ public class LoggingEventListener extends AbstractMongoEventListener { @@ -45,7 +48,7 @@ public void onBeforeConvert(BeforeConvertEvent event) { */ @Override public void onBeforeSave(BeforeSaveEvent event) { - LOGGER.info("onBeforeSave: {}, {}", event.getSource(), event.getDBObject()); + LOGGER.info("onBeforeSave: {}, {}", event.getSource(), serializeToJsonSafely(event.getDBObject())); } /* @@ -54,7 +57,7 @@ public void onBeforeSave(BeforeSaveEvent event) { */ @Override public void onAfterSave(AfterSaveEvent event) { - LOGGER.info("onAfterSave: {}, {}", event.getSource(), event.getDBObject()); + LOGGER.info("onAfterSave: {}, {}", event.getSource(), serializeToJsonSafely(event.getDBObject())); } /* @@ -63,7 +66,7 @@ public void onAfterSave(AfterSaveEvent event) { */ @Override public void onAfterLoad(AfterLoadEvent event) { - LOGGER.info("onAfterLoad: {}", event.getDBObject()); + LOGGER.info("onAfterLoad: {}", serializeToJsonSafely(event.getDBObject())); } /* @@ -72,7 +75,7 @@ public void onAfterLoad(AfterLoadEvent event) { */ @Override public void onAfterConvert(AfterConvertEvent event) { - LOGGER.info("onAfterConvert: {}, {}", event.getDBObject(), event.getSource()); + LOGGER.info("onAfterConvert: {}, {}", serializeToJsonSafely(event.getDBObject()), event.getSource()); } /* @@ -81,7 +84,7 @@ public void onAfterConvert(AfterConvertEvent event) { */ @Override public void onAfterDelete(AfterDeleteEvent event) { - LOGGER.info("onAfterDelete: {}", event.getDBObject()); + LOGGER.info("onAfterDelete: {}", serializeToJsonSafely(event.getDBObject())); } /* @@ -90,6 +93,6 @@ public void onAfterDelete(AfterDeleteEvent event) { */ @Override public void onBeforeDelete(BeforeDeleteEvent event) { - LOGGER.info("onBeforeDelete: {}", event.getDBObject()); + LOGGER.info("onBeforeDelete: {}", serializeToJsonSafely(event.getDBObject())); } } diff --git a/spring-data-mongodb/src/test/java/org/springframework/data/mongodb/core/mapping/event/LoggingEventListenerTests.java b/spring-data-mongodb/src/test/java/org/springframework/data/mongodb/core/mapping/event/LoggingEventListenerTests.java new file mode 100644 index 0000000000..fa29363229 --- /dev/null +++ b/spring-data-mongodb/src/test/java/org/springframework/data/mongodb/core/mapping/event/LoggingEventListenerTests.java @@ -0,0 +1,102 @@ +/* + * Copyright 2017 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.data.mongodb.core.mapping.event; + +import static org.hamcrest.core.StringStartsWith.*; +import static org.junit.Assert.*; + +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.core.read.ListAppender; + +import org.junit.Before; +import org.junit.Test; +import org.slf4j.LoggerFactory; + +import com.mongodb.BasicDBObject; + +/** + * @author Christoph Strobl + */ +public class LoggingEventListenerTests { + + LoggingEventListener listener; + ListAppender appender; + + @Before + public void setUp() { + + // set log level for LoggingEventListener to "info" and set up an appender capturing events. + ch.qos.logback.classic.Logger logger = (ch.qos.logback.classic.Logger) LoggerFactory + .getLogger(LoggingEventListener.class); + logger.setLevel(Level.toLevel("info")); + + appender = new ListAppender(); + logger.addAppender(appender); + appender.start(); + + listener = new LoggingEventListener(); + } + + @Test // DATAMONGO-1645 + public void shouldSerializeAfterConvertEventCorrectly() { + + listener.onAfterConvert(new AfterConvertEvent(new BasicDBObject("foo", new Foo()), this, "collection")); + + assertThat(appender.list.get(0).getFormattedMessage(), startsWith("onAfterConvert: { \"foo\"")); + } + + @Test // DATAMONGO-1645 + public void shouldSerializeBeforeSaveEventEventCorrectly() { + + listener.onBeforeSave(new BeforeSaveEvent(new Foo(), new BasicDBObject("foo", new Foo()), "collection")); + + assertThat(appender.list.get(0).getFormattedMessage(), + startsWith("onBeforeSave: org.springframework.data.mongodb.core.")); + } + + @Test // DATAMONGO-1645 + public void shouldSerializeAfterSaveEventEventCorrectly() { + + listener.onAfterSave(new AfterSaveEvent(new Foo(), new BasicDBObject("foo", new Foo()), "collection")); + + assertThat(appender.list.get(0).getFormattedMessage(), + startsWith("onAfterSave: org.springframework.data.mongodb.core.")); + } + + @Test // DATAMONGO-1645 + public void shouldSerializeBeforeDeleteEventEventCorrectly() { + + listener + .onBeforeDelete(new BeforeDeleteEvent(new BasicDBObject("foo", new Foo()), Object.class, "collection")); + + assertThat(appender.list.get(0).getFormattedMessage(), startsWith("onBeforeDelete: { \"foo\"")); + } + + @Test // DATAMONGO-1645 + public void shouldSerializeAfterDeleteEventEventCorrectly() { + + listener + .onAfterDelete(new AfterDeleteEvent(new BasicDBObject("foo", new Foo()), Object.class, "collection")); + + assertThat(appender.list.get(0).getFormattedMessage(), startsWith("onAfterDelete: { \"foo\"")); + } + + static class Foo { + + } + +} From 116a90b706cb540bb796b9d2669ede495f65f937 Mon Sep 17 00:00:00 2001 From: Mark Paluch Date: Tue, 21 Mar 2017 10:23:17 +0100 Subject: [PATCH 3/3] DATAMONGO-1645 - Polishing. Clean up appender and log level after test run. --- .../event/LoggingEventListenerTests.java | 26 ++++++++++++++----- 1 file changed, 20 insertions(+), 6 deletions(-) diff --git a/spring-data-mongodb/src/test/java/org/springframework/data/mongodb/core/mapping/event/LoggingEventListenerTests.java b/spring-data-mongodb/src/test/java/org/springframework/data/mongodb/core/mapping/event/LoggingEventListenerTests.java index fa29363229..d92c231522 100644 --- a/spring-data-mongodb/src/test/java/org/springframework/data/mongodb/core/mapping/event/LoggingEventListenerTests.java +++ b/spring-data-mongodb/src/test/java/org/springframework/data/mongodb/core/mapping/event/LoggingEventListenerTests.java @@ -22,6 +22,7 @@ import ch.qos.logback.classic.spi.ILoggingEvent; import ch.qos.logback.core.read.ListAppender; +import org.junit.After; import org.junit.Before; import org.junit.Test; import org.slf4j.LoggerFactory; @@ -29,28 +30,42 @@ import com.mongodb.BasicDBObject; /** + * Tests for {@link LoggingEventListener}. + * * @author Christoph Strobl + * @author Mark Paluch */ public class LoggingEventListenerTests { LoggingEventListener listener; - ListAppender appender; + ch.qos.logback.classic.Logger logger; + ListAppender appender = new ListAppender(); @Before public void setUp() { // set log level for LoggingEventListener to "info" and set up an appender capturing events. - ch.qos.logback.classic.Logger logger = (ch.qos.logback.classic.Logger) LoggerFactory - .getLogger(LoggingEventListener.class); - logger.setLevel(Level.toLevel("info")); + logger = (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(LoggingEventListener.class); + logger.setLevel(Level.INFO); - appender = new ListAppender(); logger.addAppender(appender); appender.start(); listener = new LoggingEventListener(); } + @After + public void tearDown() { + + // cleanup + if (logger != null) { + logger.detachAppender(appender); + logger.setLevel(null); + } + + appender.stop(); + } + @Test // DATAMONGO-1645 public void shouldSerializeAfterConvertEventCorrectly() { @@ -98,5 +113,4 @@ public void shouldSerializeAfterDeleteEventEventCorrectly() { static class Foo { } - }