Closed
Description
Maxime Clement opened DATAMONGO-1645 and commented
If a document contains an @Id field that is serialized with a custom converter, a RuntimeException is thrown when the LoggingEventListener tries to log BeforeDeleteEvent and AfterDeleteEvent on document deletion :
SLF4J: Failed toString() invocation on an object of type [com.mongodb.BasicDBObject]
Reported exception:
java.lang.RuntimeException: json can't serialize type : class com.mclem.CustomId
at com.mongodb.util.ClassMapBasedObjectSerializer.serialize(ClassMapBasedObjectSerializer.java:79)
at com.mongodb.util.JSONSerializers$MapSerializer.serialize(JSONSerializers.java:328)
at com.mongodb.util.ClassMapBasedObjectSerializer.serialize(ClassMapBasedObjectSerializer.java:82)
at com.mongodb.util.JSON.serialize(JSON.java:53)
at com.mongodb.util.JSON.serialize(JSON.java:39)
at com.mongodb.BasicDBObject.toString(BasicDBObject.java:196)
at org.slf4j.helpers.MessageFormatter.safeObjectAppend(MessageFormatter.java:299)
at org.slf4j.helpers.MessageFormatter.deeplyAppendParameter(MessageFormatter.java:271)
at org.slf4j.helpers.MessageFormatter.arrayFormat(MessageFormatter.java:233)
at org.slf4j.helpers.MessageFormatter.arrayFormat(MessageFormatter.java:173)
at ch.qos.logback.classic.spi.LoggingEvent.getFormattedMessage(LoggingEvent.java:293)
at ch.qos.logback.classic.spi.LoggingEvent.prepareForDeferredProcessing(LoggingEvent.java:206)
at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:205)
at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:100)
at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84)
at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51)
at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270)
at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257)
at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:421)
at ch.qos.logback.classic.Logger.filterAndLog_1(Logger.java:398)
at ch.qos.logback.classic.Logger.info(Logger.java:583)
at org.springframework.data.mongodb.core.mapping.event.LoggingEventListener.onBeforeDelete(LoggingEventListener.java:93)
at org.springframework.data.mongodb.core.mapping.event.AbstractMongoEventListener.onApplicationEvent(AbstractMongoEventListener.java:67)
at org.springframework.data.mongodb.core.mapping.event.AbstractMongoEventListener.onApplicationEvent(AbstractMongoEventListener.java:31)
at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:167)
at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:139)
at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:383)
at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:337)
at org.springframework.data.mongodb.core.MongoTemplate.maybeEmitEvent(MongoTemplate.java:1688)
at org.springframework.data.mongodb.core.MongoTemplate$13.doInCollection(MongoTemplate.java:1336)
at org.springframework.data.mongodb.core.MongoTemplate$13.doInCollection(MongoTemplate.java:1333)
at org.springframework.data.mongodb.core.MongoTemplate.execute(MongoTemplate.java:479)
at org.springframework.data.mongodb.core.MongoTemplate.doRemove(MongoTemplate.java:1333)
at org.springframework.data.mongodb.core.MongoTemplate.remove(MongoTemplate.java:1319)
at org.springframework.data.mongodb.repository.support.SimpleMongoRepository.delete(SimpleMongoRepository.java:159)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.executeMethodOn(RepositoryFactorySupport.java:504)
at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.doInvoke(RepositoryFactorySupport.java:489)
at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.invoke(RepositoryFactorySupport.java:461)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.data.projection.DefaultMethodInvokingMethodInterceptor.invoke(DefaultMethodInvokingMethodInterceptor.java:61)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.data.repository.core.support.SurroundingTransactionDetectorMethodInterceptor.invoke(SurroundingTransactionDetectorMethodInterceptor.java:57)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213)
at com.sun.proxy.$Proxy69.delete(Unknown Source)
at com.mclem.PersonRepositoryTest.test_delete_DeletesTheDocument(PersonRepositoryTest.java:34)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
at org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:75)
at org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:86)
at org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:84)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:252)
at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:94)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.springframework.test.context.junit4.statements.RunBeforeTestClassCallbacks.evaluate(RunBeforeTestClassCallbacks.java:61)
at org.springframework.test.context.junit4.statements.RunAfterTestClassCallbacks.evaluate(RunAfterTestClassCallbacks.java:70)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.run(SpringJUnit4ClassRunner.java:191)
at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:68)
at com.intellij.rt.execution.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:51)
at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:237)
at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:70)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.intellij.rt.execution.application.AppMain.main(AppMain.java:147)
2017-03-14 08:34:33.420 INFO 29552 --- [ main] o.s.d.m.c.m.event.LoggingEventListener : onBeforeDelete: [FAILED toString()]The code at https://github.com/mclem/spring-data-mongodb-deleteevent can be used to reproduce the error with mvn test.
It looks like the intermediate object in method doRemove (https://github.com/spring-projects/spring-data-mongodb/blob/master/spring-data-mongodb/src/main/java/org/springframework/data/mongodb/core/MongoTemplate.java#L1330) should not be used and immediately replaced by the converted object (https://github.com/spring-projects/spring-data-mongodb/blob/master/spring-data-mongodb/src/main/java/org/springframework/data/mongodb/core/MongoTemplate.java#L1338), because the mongo driver cannot represent the custom class as a JSON object with the DBObject.toString method
Affects: 1.9.4 (Hopper SR4), 1.10.1 (Ingalls SR1)
Reference URL: https://github.com/mclem/spring-data-mongodb-deleteevent
Referenced from: pull request #450
Backported to: 1.10.2 (Ingalls SR2), 1.9.9 (Hopper SR9)