EntityManager#merge() inside nested Transactions hangs indefinitely

[woezelmann]

When executing multiple calls to EntityManager#merge() inside a @transactional(REQUIRES_NEW) block, which itself runs inside a @transactional block, the merge hangs indefinitely.

The setup looks like this:

@Service
public class OuterService {

		@Autowired
		private InnerService innerService;

		@Transactional
		public void runWithTransaction() {
				String callId = UUID.randomUUID().toString();
				String externalCallId = UUID.randomUUID().toString();

				innerService.save(new ExternalServiceCall(callId, externalCallId));

				innerService.load(callId)
						.ifPresent(externalServiceCall -> {
								externalServiceCall.setExternalCallId(UUID.randomUUID().toString());
								innerService.update(externalServiceCall);
						});

				innerService.load(callId)
						.ifPresent(externalServiceCall -> {
								externalServiceCall.setExternalCallId(UUID.randomUUID().toString());
								innerService.update(externalServiceCall);
						});
		}
}

@Repository
public class InnerService {

		private static final String QUERY_WITH_CALLID = "ExternalServiceCalls.findByCallId";

		@PersistenceContext
		private EntityManager em;

		@Transactional(REQUIRES_NEW)
		public ExternalServiceCall save(ExternalServiceCall externalServiceCall) {
				em.persist(externalServiceCall);
				return externalServiceCall;
		}

		@Transactional(REQUIRES_NEW)
		public ExternalServiceCall update(ExternalServiceCall externalServiceCall) {
				em.merge(externalServiceCall);
				return externalServiceCall;
		}

		public Optional<ExternalServiceCall> load(String callId) {
				List<ExternalServiceCall> externalServiceCalls = em.createNamedQuery(QUERY_WITH_CALLID, ExternalServiceCall.class)
						.setParameter("callId", callId)
						.getResultList();
				if (externalServiceCalls.isEmpty()) {
						return Optional.empty();
				}
				return Optional.of(externalServiceCalls.get(0));
		}
}

@Entity(name = "externalservicecalls")
@Table(name = "externalservicecalls")
@Inheritance(strategy = InheritanceType.JOINED)
@NamedQueries({
		@NamedQuery(name = "ExternalServiceCalls.findByCallId",
				query = "SELECT e FROM externalservicecalls e WHERE e.callId = :callId")
})
public class ExternalServiceCall {

		@Id
		private String callId;

		@Basic
		@Column(nullable = false)
		private String externalCallId;

		public ExternalServiceCall() {
		}

		public ExternalServiceCall(String callId, String externalCallId) {
				this.callId = callId;
				this.externalCallId = externalCallId;
		}

		public void setExternalCallId(String externalCallId) {
				this.externalCallId = externalCallId;
		}
}

Calling OuterService#runWithTransactions hangs on the 2nd InnerService#update(), the ThreadDump looks like this:

"main" #1 [5123] prio=5 os_prio=31 cpu=3397.67ms elapsed=12.11s tid=0x000000010152f460 nid=5123 runnable  [0x000000016f43d000]
   java.lang.Thread.State: RUNNABLE
	at sun.nio.ch.Net.poll(java.base@21.0.7/Native Method)
	at sun.nio.ch.NioSocketImpl.park(java.base@21.0.7/NioSocketImpl.java:191)
	at sun.nio.ch.NioSocketImpl.park(java.base@21.0.7/NioSocketImpl.java:201)
	at sun.nio.ch.NioSocketImpl.implRead(java.base@21.0.7/NioSocketImpl.java:309)
	at sun.nio.ch.NioSocketImpl.read(java.base@21.0.7/NioSocketImpl.java:346)
	at sun.nio.ch.NioSocketImpl$1.read(java.base@21.0.7/NioSocketImpl.java:796)
	at java.net.Socket$SocketInputStream.read(java.base@21.0.7/Socket.java:1099)
	at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:192)
	at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:159)
	at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:144)
	at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:76)
	at org.postgresql.core.PGStream.receiveChar(PGStream.java:477)
	at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2175)
	at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:372)
	at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:525)
	at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:435)
	at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:196)
	at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java:157)
	at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61)
	at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java)
	at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:194)
	at org.hibernate.engine.jdbc.mutation.internal.AbstractMutationExecutor.performNonBatchedMutation(AbstractMutationExecutor.java:134)
	at org.hibernate.engine.jdbc.mutation.internal.MutationExecutorSingleNonBatched.performNonBatchedOperations(MutationExecutorSingleNonBatched.java:55)
	at org.hibernate.engine.jdbc.mutation.internal.AbstractMutationExecutor.execute(AbstractMutationExecutor.java:55)
	at org.hibernate.persister.entity.mutation.UpdateCoordinatorStandard.doStaticUpdate(UpdateCoordinatorStandard.java:781)
	at org.hibernate.persister.entity.mutation.UpdateCoordinatorStandard.performUpdate(UpdateCoordinatorStandard.java:328)
	at org.hibernate.persister.entity.mutation.UpdateCoordinatorStandard.update(UpdateCoordinatorStandard.java:245)
	at org.hibernate.action.internal.EntityUpdateAction.execute(EntityUpdateAction.java:169)
	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:644)
	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:511)
	at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:414)
	at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:41)
	at org.hibernate.internal.SessionImpl$$Lambda/0x000000a0019aca28.accept(Unknown Source)
	at org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:127)
	at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1429)
	at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:491)
	at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:2354)
	at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:1978)
	at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:439)
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:169)
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:267)
	at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:101)
	at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:563)
	at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:795)
	at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:758)
	at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:698)
	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:416)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
	at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:728)
	at de.woezelmann.nested.transaction.InnerService$$SpringCGLIB$$0.update(<generated>)
	at de.woezelmann.nested.transaction.OuterService.lambda$runWithTransaction$1(OuterService.java:31)
	at de.woezelmann.nested.transaction.OuterService$$Lambda/0x000000a0019fc1f8.accept(Unknown Source)
	at java.util.Optional.ifPresent(java.base@21.0.7/Optional.java:178)
	at de.woezelmann.nested.transaction.OuterService.runWithTransaction(OuterService.java:29)

I've created a small test project, that reproduces this behavior with Postgresql and Mysql: https://github.com/woezelmann/spring-nested-transactions

[mp911de]

This is expected behavior and is not really related to Spring at all.

The outer service starts a transaction on a JDBC connection, performs some activity (leading to a transactional lock on the first connection).

Then, another (nested) transaction is being started (indicated by REQUIRES_NEW propagation). Interacting with an EntityManager requires a JDBC connection that is being created within the new transactional context. Operating on a new connection with the same table as being locked in the first transaction causes the database to wait until the lock is being released.

To avoid these sorts of circular locks you need to complete the first transaction before starting a new one. Likely it would be the most straightforward approach to design your service calls side by side so that inner service and outer service don't have that inner-outer relationship, but rather a third, orchestrator service invokes first what is now OuterService (using REQUIRES_NEW propagation) and then what is InnerService. Make sure to avoid any JPA resource usage in those code paths prior to InnerService and OuterService calls.

[woezelmann]

Hi @mp911de

thank you very much for your answer.

The way you describe it, I would assume that the first call to innerService.update() would hang, but it is working fine and only the second call hangs.

Also the outside transaction is not writing anything to the table, so I wonder why it is creating a lock.

[mp911de]

That's not exactly what's happening here. innerService.load(callId) loads an entity that is attached to the OuterService transaction context. By setting a value in the ifPresent(…) lambda, you're updating an object that is contained in the outer session. Additionally, the entity is being saved (EntityManager.merge(…)) in a new transaction.

The second call to load issues an automatic flush to reflect prior made changes to your object.

Running load() in its own transaction (or detaching the object after querying it) will resolve the issue.

FWIW, you might want to enable SQL logging to trace that kind of issues.