search

spring-projects / spring-framework

Spring Framework
https://spring.io/projects/spring-framework
Apache License 2.0
56.67k stars 38.15k forks source link

Exception details lost when there is an exception while rolling back in `TransactionAspectSupport.invokeWithinTransaction()` #31615

Closed credmond-git closed 12 months ago

credmond-git commented 12 months ago

Affects: 6.0.13

I am using spanner with JPA, and when i am in a transaction where there is a bug and an exception is thrown I would expect the exception message to show the cause of the original bug with a callstack. However it is lost.

Inside TransactionAspectSupport.invokeWithinTransaction(...), we get to the invocation.proceedWithInvocation(), where an exception is thrown. 

Object retVal;
try {
    // This is an around advice: Invoke the next interceptor in the chain.
    // This will normally result in a target object being invoked.
    retVal = invocation.proceedWithInvocation();
}
catch (Throwable ex) {
    // target invocation exception
    completeTransactionAfterThrowing(txInfo, ex);
    throw ex;
}
finally {
    cleanupTransactionInfo(txInfo);
}

This causes the completeTransactionAfterThrowing(txInfo, ex); to be triggered.

which follows the call stack to doSetRollbackOnly:1207, AbstractPlatformTransactionManager:

doSetRollbackOnly:1207, AbstractPlatformTransactionManager (org.springframework.transaction.support)
processRollback:844, AbstractPlatformTransactionManager (org.springframework.transaction.support)
rollback:809, AbstractPlatformTransactionManager (org.springframework.transaction.support)
completeTransactionAfterThrowing:678, TransactionAspectSupport (org.springframework.transaction.interceptor)
invokeWithinTransaction:395, TransactionAspectSupport (org.springframework.transaction.interceptor)
invoke:119, TransactionInterceptor (org.springframework.transaction.interceptor)
proceed:184, ReflectiveMethodInvocation (org.springframework.aop.framework)
invoke:137, PersistenceExceptionTranslationInterceptor (org.springframework.dao.support)
proceed:184, ReflectiveMethodInvocation (org.springframework.aop.framework)
invoke:164, CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor (org.springframework.data.jpa.repository.support)
proceed:184, ReflectiveMethodInvocation (org.springframework.aop.framework)
invoke:97, ExposeInvocationInterceptor (org.springframework.aop.interceptor)
proceed:184, ReflectiveMethodInvocation (org.springframework.aop.framework)
invoke:94, MethodInvocationValidator (org.springframework.data.repository.core.support)
proceed:184, ReflectiveMethodInvocation (org.springframework.aop.framework)
invoke:244, JdkDynamicAopProxy (org.springframework.aop.framework)
save:-1, $Proxy213 (jdk.proxy3)
addProjectReason:109, ProjectServiceImpl (com.our.work)
invoke0:-1, NativeMethodAccessorImpl (jdk.internal.reflect)
invoke:77, NativeMethodAccessorImpl (jdk.internal.reflect)
invoke:43, DelegatingMethodAccessorImpl (jdk.internal.reflect)
invoke:568, Method (java.lang.reflect)
invokeJoinpointUsingReflection:343, AopUtils (org.springframework.aop.support)
invokeJoinpoint:196, ReflectiveMethodInvocation (org.springframework.aop.framework)
proceed:163, ReflectiveMethodInvocation (org.springframework.aop.framework)
proceed:751, CglibAopProxy$CglibMethodInvocation (org.springframework.aop.framework)
proceedWithInvocation:123, TransactionInterceptor$1 (org.springframework.transaction.interceptor)
invokeWithinTransaction:391, TransactionAspectSupport (org.springframework.transaction.interceptor)
invoke:119, TransactionInterceptor (org.springframework.transaction.interceptor)
proceed:184, ReflectiveMethodInvocation (org.springframework.aop.framework)
proceed:751, CglibAopProxy$CglibMethodInvocation (org.springframework.aop.framework)
intercept:703, CglibAopProxy$DynamicAdvisedInterceptor (org.springframework.aop.framework)
addProjectReason:-1, ProjectServiceImpl$$SpringCGLIB$$0 (com.our.work.project.service)
add project reason:83, ProjectsIntegrationTest (com.our.work.safety.moderation)
invoke0:-1, NativeMethodAccessorImpl (jdk.internal.reflect)
invoke:77, NativeMethodAccessorImpl (jdk.internal.reflect)
invoke:43, DelegatingMethodAccessorImpl (jdk.internal.reflect)
invoke:568, Method (java.lang.reflect)
invokeMethod:727, ReflectionUtils (org.junit.platform.commons.util)
proceed:60, MethodInvocation (org.junit.jupiter.engine.execution)
proceed:131, InvocationInterceptorChain$ValidatingInvocation (org.junit.jupiter.engine.execution)
intercept:156, TimeoutExtension (org.junit.jupiter.engine.extension)
interceptTestableMethod:147, TimeoutExtension (org.junit.jupiter.engine.extension)
interceptTestMethod:86, TimeoutExtension (org.junit.jupiter.engine.extension)
apply:-1, TestMethodTestDescriptor$$Lambda$233/0x00000284fc14ca00 (org.junit.jupiter.engine.descriptor)
lambda$ofVoidMethod$0:103, InterceptingExecutableInvoker$ReflectiveInterceptorCall (org.junit.jupiter.engine.execution)
apply:-1, InterceptingExecutableInvoker$ReflectiveInterceptorCall$$Lambda$234/0x00000284fc154000 (org.junit.jupiter.engine.execution)
lambda$invoke$0:93, InterceptingExecutableInvoker (org.junit.jupiter.engine.execution)
apply:-1, InterceptingExecutableInvoker$$Lambda$543/0x00000284fc2bb540 (org.junit.jupiter.engine.execution)
proceed:106, InvocationInterceptorChain$InterceptedInvocation (org.junit.jupiter.engine.execution)
proceed:64, InvocationInterceptorChain (org.junit.jupiter.engine.execution)
chainAndInvoke:45, InvocationInterceptorChain (org.junit.jupiter.engine.execution)
invoke:37, InvocationInterceptorChain (org.junit.jupiter.engine.execution)
invoke:92, InterceptingExecutableInvoker (org.junit.jupiter.engine.execution)
invoke:86, InterceptingExecutableInvoker (org.junit.jupiter.engine.execution)
lambda$invokeTestMethod$7:217, TestMethodTestDescriptor (org.junit.jupiter.engine.descriptor)
execute:-1, TestMethodTestDescriptor$$Lambda$3128/0x00000284fd30eba0 (org.junit.jupiter.engine.descriptor)
execute:73, ThrowableCollector (org.junit.platform.engine.support.hierarchical)
invokeTestMethod:213, TestMethodTestDescriptor (org.junit.jupiter.engine.descriptor)
execute:138, TestMethodTestDescriptor (org.junit.jupiter.engine.descriptor)
execute:68, TestMethodTestDescriptor (org.junit.jupiter.engine.descriptor)
lambda$executeRecursively$6:151, NodeTestTask (org.junit.platform.engine.support.hierarchical)
execute:-1, NodeTestTask$$Lambda$339/0x00000284fc16d0a0 (org.junit.platform.engine.support.hierarchical)
execute:73, ThrowableCollector (org.junit.platform.engine.support.hierarchical)
lambda$executeRecursively$8:141, NodeTestTask (org.junit.platform.engine.support.hierarchical)
invoke:-1, NodeTestTask$$Lambda$338/0x00000284fc16ce78 (org.junit.platform.engine.support.hierarchical)
around:137, Node (org.junit.platform.engine.support.hierarchical)
lambda$executeRecursively$9:139, NodeTestTask (org.junit.platform.engine.support.hierarchical)
execute:-1, NodeTestTask$$Lambda$337/0x00000284fc16ca50 (org.junit.platform.engine.support.hierarchical)
execute:73, ThrowableCollector (org.junit.platform.engine.support.hierarchical)
executeRecursively:138, NodeTestTask (org.junit.platform.engine.support.hierarchical)
execute:95, NodeTestTask (org.junit.platform.engine.support.hierarchical)
accept:-1, SameThreadHierarchicalTestExecutorService$$Lambda$343/0x00000284fc16dbb8 (org.junit.platform.engine.support.hierarchical)
forEach:1511, ArrayList (java.util)
invokeAll:41, SameThreadHierarchicalTestExecutorService (org.junit.platform.engine.support.hierarchical)
lambda$executeRecursively$6:155, NodeTestTask (org.junit.platform.engine.support.hierarchical)
execute:-1, NodeTestTask$$Lambda$339/0x00000284fc16d0a0 (org.junit.platform.engine.support.hierarchical)
execute:73, ThrowableCollector (org.junit.platform.engine.support.hierarchical)
lambda$executeRecursively$8:141, NodeTestTask (org.junit.platform.engine.support.hierarchical)
invoke:-1, NodeTestTask$$Lambda$338/0x00000284fc16ce78 (org.junit.platform.engine.support.hierarchical)
around:137, Node (org.junit.platform.engine.support.hierarchical)
lambda$executeRecursively$9:139, NodeTestTask (org.junit.platform.engine.support.hierarchical)
execute:-1, NodeTestTask$$Lambda$337/0x00000284fc16ca50 (org.junit.platform.engine.support.hierarchical)
execute:73, ThrowableCollector (org.junit.platform.engine.support.hierarchical)
executeRecursively:138, NodeTestTask (org.junit.platform.engine.support.hierarchical)
execute:95, NodeTestTask (org.junit.platform.engine.support.hierarchical)
accept:-1, SameThreadHierarchicalTestExecutorService$$Lambda$343/0x00000284fc16dbb8 (org.junit.platform.engine.support.hierarchical)
forEach:1511, ArrayList (java.util)
invokeAll:41, SameThreadHierarchicalTestExecutorService (org.junit.platform.engine.support.hierarchical)
lambda$executeRecursively$6:155, NodeTestTask (org.junit.platform.engine.support.hierarchical)
execute:-1, NodeTestTask$$Lambda$339/0x00000284fc16d0a0 (org.junit.platform.engine.support.hierarchical)
execute:73, ThrowableCollector (org.junit.platform.engine.support.hierarchical)
lambda$executeRecursively$8:141, NodeTestTask (org.junit.platform.engine.support.hierarchical)
invoke:-1, NodeTestTask$$Lambda$338/0x00000284fc16ce78 (org.junit.platform.engine.support.hierarchical)
around:137, Node (org.junit.platform.engine.support.hierarchical)
lambda$executeRecursively$9:139, NodeTestTask (org.junit.platform.engine.support.hierarchical)
execute:-1, NodeTestTask$$Lambda$337/0x00000284fc16ca50 (org.junit.platform.engine.support.hierarchical)
execute:73, ThrowableCollector (org.junit.platform.engine.support.hierarchical)
executeRecursively:138, NodeTestTask (org.junit.platform.engine.support.hierarchical)
execute:95, NodeTestTask (org.junit.platform.engine.support.hierarchical)
submit:35, SameThreadHierarchicalTestExecutorService (org.junit.platform.engine.support.hierarchical)
execute:57, HierarchicalTestExecutor (org.junit.platform.engine.support.hierarchical)
execute:54, HierarchicalTestEngine (org.junit.platform.engine.support.hierarchical)
execute:147, EngineExecutionOrchestrator (org.junit.platform.launcher.core)
execute:127, EngineExecutionOrchestrator (org.junit.platform.launcher.core)
execute:90, EngineExecutionOrchestrator (org.junit.platform.launcher.core)
lambda$execute$0:55, EngineExecutionOrchestrator (org.junit.platform.launcher.core)
accept:-1, EngineExecutionOrchestrator$$Lambda$291/0x00000284fc15b340 (org.junit.platform.launcher.core)
withInterceptedStreams:102, EngineExecutionOrchestrator (org.junit.platform.launcher.core)
execute:54, EngineExecutionOrchestrator (org.junit.platform.launcher.core)
execute:114, DefaultLauncher (org.junit.platform.launcher.core)
execute:86, DefaultLauncher (org.junit.platform.launcher.core)
execute:86, DefaultLauncherSession$DelegatingLauncher (org.junit.platform.launcher.core)
processAllTestClasses:119, JUnitPlatformTestClassProcessor$CollectAllTestClassesExecutor (org.gradle.api.internal.tasks.testing.junitplatform)
access$000:94, JUnitPlatformTestClassProcessor$CollectAllTestClassesExecutor (org.gradle.api.internal.tasks.testing.junitplatform)
stop:89, JUnitPlatformTestClassProcessor (org.gradle.api.internal.tasks.testing.junitplatform)
stop:62, SuiteTestClassProcessor (org.gradle.api.internal.tasks.testing)
invoke0:-1, NativeMethodAccessorImpl (jdk.internal.reflect)
invoke:77, NativeMethodAccessorImpl (jdk.internal.reflect)
invoke:43, DelegatingMethodAccessorImpl (jdk.internal.reflect)
invoke:568, Method (java.lang.reflect)
dispatch:36, ReflectionDispatch (org.gradle.internal.dispatch)
dispatch:24, ReflectionDispatch (org.gradle.internal.dispatch)
dispatch:33, ContextClassLoaderDispatch (org.gradle.internal.dispatch)
invoke:94, ProxyDispatchAdapter$DispatchingInvocationHandler (org.gradle.internal.dispatch)
stop:-1, $Proxy5 (jdk.proxy2)
run:193, TestWorker$3 (org.gradle.api.internal.tasks.testing.worker)
executeAndMaintainThreadName:129, TestWorker (org.gradle.api.internal.tasks.testing.worker)
execute:100, TestWorker (org.gradle.api.internal.tasks.testing.worker)
execute:60, TestWorker (org.gradle.api.internal.tasks.testing.worker)
execute:56, ActionExecutionWorker (org.gradle.process.internal.worker.child)
call:113, SystemApplicationClassLoaderWorker (org.gradle.process.internal.worker.child)
call:65, SystemApplicationClassLoaderWorker (org.gradle.process.internal.worker.child)
run:69, GradleWorkerMain (worker.org.gradle.process.internal.worker)
main:74, GradleWorkerMain (worker.org.gradle.process.internal.worker)

which throws the error

throw new IllegalTransactionStateException(
  "Participating in existing transactions is not supported - when 'isExistingTransaction' " +
  "returns true, appropriate 'doSetRollbackOnly' behavior must be provided");

Now instead of rethrowing the exception i am interested in that was caught in 

catch (Throwable ex) {
// target invocation exception
completeTransactionAfterThrowing(txInfo, ex);
throw ex;
}

i lose that exception and get the IllegalTransactionStateException with all the exception details lost.

I probably have a bug in my code that is causing the IllegalTransactionStateException to happen, but either way we should preserve the causing exception. We could catch the IllegalTransactionStateException and log it then the causing Throwable ex as well as the IllegalTransactionStateException or vise versa.

sbrannen commented 12 months ago

which throws the error

throw new IllegalTransactionStateException(
  "Participating in existing transactions is not supported - when 'isExistingTransaction' " +
  "returns true, appropriate 'doSetRollbackOnly' behavior must be provided");

What concrete AbstractPlatformTransactionManager sub-type are you using?

As far as I know, all concrete implementations in the core Spring Framework override doSetRollbackOnly(), meaning that particular exception will not be thrown.

credmond-git commented 12 months ago

I am using SpannerTransactionManager it looks like there was a ticket previously but it was closed without fixing. Never mind that was for Datastore not Spanner. Do you have any details i could provide for google to open a new issue?

snicoll commented 12 months ago

@credmond-git report this against the Google Cloud project and we can assist them if they have any question. Make sure to add a link to this issue so that they can follow along.