Reputation: 639
This is the transactional service defining the method I use to create a UserCommit and explicitly persisting it (this part works), and in the meantime updating the lastCommit field of the already existent parent entity User. This update doesn't get flushed.
@Transactional
@Service
public class UserCommitService {
@Autowired
private UserService userService;
@Autowired
private UserCommitRepository ucRepo;
public UserCommit createFrom(User user, Integer prodId, String ucType, String stage) {
UserCommit uc = new UserCommit();
uc.setUser(userService.findUserById(user.getId()));
uc.getUser().addUserCommit(uc);
uc.setTime(LocalDateTime.now());
uc.getUser().setLastCommit(uc.getTime());
ucRepo.save(uc);
return uc;
}
}
Here you can read the tracing log:
EDIT
Why CrudRepository.save
creates a new transaction instead of joining the existing one?
2020-05-31 12:52:36.405 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Retrieved value [org.springframework.orm.jpa.EntityManagerHolder@296e6024] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@1826475] bound to thread [http-nio-192.168.1.10-8080-exec-6]
2020-05-31 12:52:36.406 DEBUG 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Found thread-bound EntityManager [SessionImpl(461939992<open>)] for JPA transaction
2020-05-31 12:52:36.406 DEBUG 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Creating new transaction with name [petmenu.services.users.UserCommitService.createFrom]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
2020-05-31 12:52:36.407 DEBUG 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@5ac66b8d]
2020-05-31 12:52:36.407 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Bound value [org.springframework.jdbc.datasource.ConnectionHolder@4905e3e7] for key [HikariDataSource (HikariPool-1)] to thread [http-nio-192.168.1.10-8080-exec-6]
2020-05-31 12:52:36.407 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Initializing transaction synchronization
2020-05-31 12:52:36.407 TRACE 7194 --- [.10-8080-exec-6] o.s.t.i.TransactionInterceptor : Getting transaction for [petmenu.services.users.UserCommitService.createFrom]
2020-05-31 12:53:24.212 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Retrieved value [org.springframework.orm.jpa.EntityManagerHolder@296e6024] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@1826475] bound to thread [http-nio-192.168.1.10-8080-exec-6]
2020-05-31 12:53:24.217 DEBUG 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Found thread-bound EntityManager [SessionImpl(461939992<open>)] for JPA transaction
2020-05-31 12:53:24.221 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Retrieved value [org.springframework.jdbc.datasource.ConnectionHolder@4905e3e7] for key [HikariDataSource (HikariPool-1)] bound to thread [http-nio-192.168.1.10-8080-exec-6]
2020-05-31 12:53:24.228 DEBUG 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Participating in existing transaction
2020-05-31 12:53:24.232 TRACE 7194 --- [.10-8080-exec-6] o.s.t.i.TransactionInterceptor : Getting transaction for [petmenu.services.users.UserService.findUserById]
2020-05-31 12:53:24.256 TRACE 7194 --- [.10-8080-exec-6] o.s.t.i.TransactionInterceptor : No need to create transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findUserById]: This method is not transactional.
2020-05-31 12:53:24.265 DEBUG 7194 --- [.10-8080-exec-6] o.s.orm.jpa.EntityManagerFactoryUtils : Opening JPA EntityManager
2020-05-31 12:53:24.271 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Bound value [org.springframework.orm.jpa.EntityManagerHolder@75c27c80] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@6c8672b9] to thread [http-nio-192.168.1.10-8080-exec-6]
2020-05-31 12:53:24.279 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Retrieved value [org.springframework.orm.jpa.EntityManagerHolder@75c27c80] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@6c8672b9] bound to thread [http-nio-192.168.1.10-8080-exec-6]
2020-05-31 12:53:24.288 DEBUG 7194 --- [.10-8080-exec-6] org.hibernate.SQL : select user0_.id as id1_0_, user0_.kc_id as kc_id2_0_, user0_.last_commit as last_com3_0_, user0_.name as name4_0_ from user user0_ where user0_.id=?
2020-05-31 12:53:24.298 TRACE 7194 --- [.10-8080-exec-6] o.h.type.descriptor.sql.BasicBinder : binding parameter [1] as [INTEGER] - [6]
2020-05-31 12:53:24.309 TRACE 7194 --- [.10-8080-exec-6] o.h.type.descriptor.sql.BasicExtractor : extracted value ([id1_0_] : [INTEGER]) - [6]
2020-05-31 12:53:24.317 TRACE 7194 --- [.10-8080-exec-6] o.h.type.descriptor.sql.BasicExtractor : extracted value ([kc_id2_0_] : [VARCHAR]) - [80a3b4b1-00d1-4062-a7e5-1927b938c203]
2020-05-31 12:53:24.325 TRACE 7194 --- [.10-8080-exec-6] o.h.type.descriptor.sql.BasicExtractor : extracted value ([last_com3_0_] : [TIMESTAMP]) - [null]
2020-05-31 12:53:24.332 TRACE 7194 --- [.10-8080-exec-6] o.h.type.descriptor.sql.BasicExtractor : extracted value ([name4_0_] : [VARCHAR]) - [user1]
2020-05-31 12:53:24.342 TRACE 7194 --- [.10-8080-exec-6] o.s.t.i.TransactionInterceptor : Completing transaction for [petmenu.services.users.UserService.findUserById]
2020-05-31 12:55:07.918 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Bound value [org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$DefaultCrudMethodMetadata@326a9afb] for key [public abstract java.lang.Object org.springframework.data.repository.CrudRepository.save(java.lang.Object)] to thread [http-nio-192.168.1.10-8080-exec-6]
2020-05-31 12:55:07.957 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Retrieved value [org.springframework.orm.jpa.EntityManagerHolder@75c27c80] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@6c8672b9] bound to thread [http-nio-192.168.1.10-8080-exec-6]
2020-05-31 12:55:07.961 DEBUG 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Found thread-bound EntityManager [SessionImpl(1373582834<open>)] for JPA transaction
2020-05-31 12:55:07.966 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Removed value [org.springframework.orm.jpa.EntityManagerHolder@75c27c80] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@6c8672b9] from thread [http-nio-192.168.1.10-8080-exec-6]
2020-05-31 12:55:07.970 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Clearing transaction synchronization
2020-05-31 12:55:07.975 DEBUG 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Creating new transaction with name [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
2020-05-31 12:55:07.980 DEBUG 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Opened new EntityManager [SessionImpl(756005269<open>)] for JPA transaction
2020-05-31 12:55:07.987 DEBUG 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@6860e795]
2020-05-31 12:55:07.992 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Bound value [org.springframework.jdbc.datasource.ConnectionHolder@6374741f] for key [HikariDataSource (HikariPool-2)] to thread [http-nio-192.168.1.10-8080-exec-6]
2020-05-31 12:55:07.998 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Bound value [org.springframework.orm.jpa.EntityManagerHolder@4b2cad26] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@6c8672b9] to thread [http-nio-192.168.1.10-8080-exec-6]
2020-05-31 12:55:08.002 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Initializing transaction synchronization
2020-05-31 12:55:08.006 TRACE 7194 --- [.10-8080-exec-6] o.s.t.i.TransactionInterceptor : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2020-05-31 12:55:08.226 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Retrieved value [org.springframework.orm.jpa.EntityManagerHolder@4b2cad26] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@6c8672b9] bound to thread [http-nio-192.168.1.10-8080-exec-6]
2020-05-31 12:55:08.392 DEBUG 7194 --- [.10-8080-exec-6] org.hibernate.SQL : select nextval(hibernate_sequence)
2020-05-31 12:55:08.783 TRACE 7194 --- [.10-8080-exec-6] o.s.t.i.TransactionInterceptor : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2020-05-31 12:55:08.787 TRACE 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Triggering beforeCommit synchronization
2020-05-31 12:55:08.791 TRACE 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Triggering beforeCompletion synchronization
2020-05-31 12:55:08.796 DEBUG 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Initiating transaction commit
2020-05-31 12:55:08.800 DEBUG 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Committing JPA transaction on EntityManager [SessionImpl(756005269<open>)]
2020-05-31 12:55:08.824 DEBUG 7194 --- [.10-8080-exec-6] org.hibernate.SQL : insert into user_commit (uctype, prod_id, stage, time, user, id) values (?, ?, ?, ?, ?, ?)
2020-05-31 12:55:08.832 TRACE 7194 --- [.10-8080-exec-6] o.h.type.descriptor.sql.BasicBinder : binding parameter [1] as [INTEGER] - [1]
2020-05-31 12:55:08.838 TRACE 7194 --- [.10-8080-exec-6] o.h.type.descriptor.sql.BasicBinder : binding parameter [2] as [INTEGER] - [3]
2020-05-31 12:55:08.845 TRACE 7194 --- [.10-8080-exec-6] o.h.type.descriptor.sql.BasicBinder : binding parameter [3] as [INTEGER] - [0]
2020-05-31 12:55:08.884 TRACE 7194 --- [.10-8080-exec-6] o.h.type.descriptor.sql.BasicBinder : binding parameter [4] as [TIMESTAMP] - [2020-05-31T12:54:58.518530]
2020-05-31 12:55:08.922 TRACE 7194 --- [.10-8080-exec-6] o.h.type.descriptor.sql.BasicBinder : binding parameter [5] as [INTEGER] - [6]
2020-05-31 12:55:08.929 TRACE 7194 --- [.10-8080-exec-6] o.h.type.descriptor.sql.BasicBinder : binding parameter [6] as [INTEGER] - [3003]
2020-05-31 12:55:09.043 TRACE 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Triggering afterCommit synchronization
2020-05-31 12:55:09.048 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Clearing transaction synchronization
2020-05-31 12:55:09.052 TRACE 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Triggering afterCompletion synchronization
2020-05-31 12:55:09.056 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Removed value [org.springframework.orm.jpa.EntityManagerHolder@4b2cad26] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@6c8672b9] from thread [http-nio-192.168.1.10-8080-exec-6]
2020-05-31 12:55:09.062 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Removed value [org.springframework.jdbc.datasource.ConnectionHolder@6374741f] for key [HikariDataSource (HikariPool-2)] from thread [http-nio-192.168.1.10-8080-exec-6]
2020-05-31 12:55:09.066 DEBUG 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Closing JPA EntityManager [SessionImpl(756005269<open>)] after transaction
2020-05-31 12:55:09.070 DEBUG 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Resuming suspended transaction after completion of inner transaction
2020-05-31 12:55:09.075 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Initializing transaction synchronization
2020-05-31 12:55:09.080 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Bound value [org.springframework.orm.jpa.EntityManagerHolder@75c27c80] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@6c8672b9] to thread [http-nio-192.168.1.10-8080-exec-6]
2020-05-31 12:55:09.085 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Removed value [org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$DefaultCrudMethodMetadata@326a9afb] for key [public abstract java.lang.Object org.springframework.data.repository.CrudRepository.save(java.lang.Object)] from thread [http-nio-192.168.1.10-8080-exec-6]
2020-05-31 12:58:18.989 TRACE 7194 --- [.10-8080-exec-6] o.s.t.i.TransactionInterceptor : Completing transaction for [petmenu.services.users.UserCommitService.createFrom]
2020-05-31 12:58:18.997 TRACE 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Triggering beforeCommit synchronization
2020-05-31 12:58:19.001 TRACE 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Triggering beforeCompletion synchronization
2020-05-31 12:58:19.006 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Removed value [org.springframework.orm.jpa.EntityManagerHolder@75c27c80] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@6c8672b9] from thread [http-nio-192.168.1.10-8080-exec-6]
2020-05-31 12:58:19.071 INFO 7194 --- [.10-8080-exec-6] o.h.c.i.AbstractPersistentCollection : HHH000496: Detaching an uninitialized collection with queued operations from a session: [petmenu.entities.users.User.userCommitList#6]
2020-05-31 12:58:19.075 DEBUG 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Initiating transaction commit
2020-05-31 12:58:19.081 DEBUG 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Committing JPA transaction on EntityManager [SessionImpl(461939992<open>)]
2020-05-31 12:58:19.095 TRACE 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Triggering afterCommit synchronization
2020-05-31 12:58:19.099 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Clearing transaction synchronization
2020-05-31 12:58:19.104 TRACE 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Triggering afterCompletion synchronization
2020-05-31 12:58:19.109 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Removed value [org.springframework.jdbc.datasource.ConnectionHolder@4905e3e7] for key [HikariDataSource (HikariPool-1)] from thread [http-nio-192.168.1.10-8080-exec-6]
2020-05-31 12:58:19.113 DEBUG 7194 --- [.10-8080-exec-6] o.s.orm.jpa.JpaTransactionManager : Not closing pre-bound JPA EntityManager after transaction
2020-05-31 12:59:07.063 TRACE 7194 --- [.10-8080-exec-6] .s.t.s.TransactionSynchronizationManager : Removed value [org.springframework.orm.jpa.EntityManagerHolder@296e6024] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@1826475] from thread [http-nio-192.168.1.10-8080-exec-6]
EDIT2
I tried to remove the CrudRepository.save call, because it behaves strangely, creating a new transaction on its own, and seems responsible for previous one closing. The log becomes a little more logic, but still User.lastCommit new value doesn't get flushed.
2020-06-01 11:39:10.518 TRACE 26420 --- [.10-8080-exec-2] .s.t.s.TransactionSynchronizationManager : Retrieved value [org.springframework.orm.jpa.EntityManagerHolder@5f0cca8f] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@27bbe773] bound to thread [http-nio-192.168.1.10-8080-exec-2]
2020-06-01 11:39:10.518 DEBUG 26420 --- [.10-8080-exec-2] o.s.orm.jpa.JpaTransactionManager : Found thread-bound EntityManager [SessionImpl(2096513672<open>)] for JPA transaction
2020-06-01 11:39:10.518 DEBUG 26420 --- [.10-8080-exec-2] o.s.orm.jpa.JpaTransactionManager : Creating new transaction with name [petmenu.services.users.UserCommitService.createFrom]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
2020-06-01 11:39:10.518 DEBUG 26420 --- [.10-8080-exec-2] o.s.orm.jpa.JpaTransactionManager : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@62cbdd03]
2020-06-01 11:39:10.519 TRACE 26420 --- [.10-8080-exec-2] .s.t.s.TransactionSynchronizationManager : Bound value [org.springframework.jdbc.datasource.ConnectionHolder@4b988820] for key [HikariDataSource (HikariPool-1)] to thread [http-nio-192.168.1.10-8080-exec-2]
2020-06-01 11:39:10.519 TRACE 26420 --- [.10-8080-exec-2] .s.t.s.TransactionSynchronizationManager : Initializing transaction synchronization
2020-06-01 11:39:10.519 TRACE 26420 --- [.10-8080-exec-2] o.s.t.i.TransactionInterceptor : Getting transaction for [petmenu.services.users.UserCommitService.createFrom]
2020-06-01 11:39:16.678 TRACE 26420 --- [.10-8080-exec-2] .s.t.s.TransactionSynchronizationManager : Retrieved value [org.springframework.orm.jpa.EntityManagerHolder@5f0cca8f] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@27bbe773] bound to thread [http-nio-192.168.1.10-8080-exec-2]
2020-06-01 11:39:16.683 DEBUG 26420 --- [.10-8080-exec-2] o.s.orm.jpa.JpaTransactionManager : Found thread-bound EntityManager [SessionImpl(2096513672<open>)] for JPA transaction
2020-06-01 11:39:16.688 TRACE 26420 --- [.10-8080-exec-2] .s.t.s.TransactionSynchronizationManager : Retrieved value [org.springframework.jdbc.datasource.ConnectionHolder@4b988820] for key [HikariDataSource (HikariPool-1)] bound to thread [http-nio-192.168.1.10-8080-exec-2]
2020-06-01 11:39:16.693 DEBUG 26420 --- [.10-8080-exec-2] o.s.orm.jpa.JpaTransactionManager : Participating in existing transaction
2020-06-01 11:39:16.697 TRACE 26420 --- [.10-8080-exec-2] o.s.t.i.TransactionInterceptor : Getting transaction for [petmenu.services.users.UserService.findUserById]
2020-06-01 11:39:16.720 TRACE 26420 --- [.10-8080-exec-2] o.s.t.i.TransactionInterceptor : No need to create transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findUserById]: This method is not transactional.
2020-06-01 11:39:16.727 DEBUG 26420 --- [.10-8080-exec-2] o.s.orm.jpa.EntityManagerFactoryUtils : Opening JPA EntityManager
2020-06-01 11:39:16.733 TRACE 26420 --- [.10-8080-exec-2] .s.t.s.TransactionSynchronizationManager : Bound value [org.springframework.orm.jpa.EntityManagerHolder@ca14c2f] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@161c9468] to thread [http-nio-192.168.1.10-8080-exec-2]
2020-06-01 11:39:16.738 TRACE 26420 --- [.10-8080-exec-2] .s.t.s.TransactionSynchronizationManager : Retrieved value [org.springframework.orm.jpa.EntityManagerHolder@ca14c2f] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@161c9468] bound to thread [http-nio-192.168.1.10-8080-exec-2]
2020-06-01 11:39:16.747 DEBUG 26420 --- [.10-8080-exec-2] org.hibernate.SQL : select user0_.id as id1_0_, user0_.kc_id as kc_id2_0_, user0_.last_commit as last_com3_0_, user0_.name as name4_0_ from user user0_ where user0_.id=?
2020-06-01 11:39:16.754 TRACE 26420 --- [.10-8080-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [1] as [INTEGER] - [6]
2020-06-01 11:39:16.763 TRACE 26420 --- [.10-8080-exec-2] o.h.type.descriptor.sql.BasicExtractor : extracted value ([id1_0_] : [INTEGER]) - [6]
2020-06-01 11:39:16.772 TRACE 26420 --- [.10-8080-exec-2] o.h.type.descriptor.sql.BasicExtractor : extracted value ([kc_id2_0_] : [VARCHAR]) - [80a3b4b1-00d1-4062-a7e5-1927b938c203]
2020-06-01 11:39:16.779 TRACE 26420 --- [.10-8080-exec-2] o.h.type.descriptor.sql.BasicExtractor : extracted value ([last_com3_0_] : [TIMESTAMP]) - [null]
2020-06-01 11:39:16.787 TRACE 26420 --- [.10-8080-exec-2] o.h.type.descriptor.sql.BasicExtractor : extracted value ([name4_0_] : [VARCHAR]) - [user1]
2020-06-01 11:39:16.795 TRACE 26420 --- [.10-8080-exec-2] o.s.t.i.TransactionInterceptor : Completing transaction for [petmenu.services.users.UserService.findUserById]
2020-06-01 11:39:48.779 TRACE 26420 --- [.10-8080-exec-2] o.s.t.i.TransactionInterceptor : Completing transaction for [petmenu.services.users.UserCommitService.createFrom]
2020-06-01 11:39:48.780 TRACE 26420 --- [.10-8080-exec-2] o.s.orm.jpa.JpaTransactionManager : Triggering beforeCommit synchronization
2020-06-01 11:39:48.780 TRACE 26420 --- [.10-8080-exec-2] o.s.orm.jpa.JpaTransactionManager : Triggering beforeCompletion synchronization
2020-06-01 11:39:48.780 TRACE 26420 --- [.10-8080-exec-2] .s.t.s.TransactionSynchronizationManager : Removed value [org.springframework.orm.jpa.EntityManagerHolder@ca14c2f] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@161c9468] from thread [http-nio-192.168.1.10-8080-exec-2]
2020-06-01 11:39:48.782 INFO 26420 --- [.10-8080-exec-2] o.h.c.i.AbstractPersistentCollection : HHH000496: Detaching an uninitialized collection with queued operations from a session: [petmenu.entities.users.User.userCommitList#6]
2020-06-01 11:39:48.782 DEBUG 26420 --- [.10-8080-exec-2] o.s.orm.jpa.JpaTransactionManager : Initiating transaction commit
2020-06-01 11:39:48.782 DEBUG 26420 --- [.10-8080-exec-2] o.s.orm.jpa.JpaTransactionManager : Committing JPA transaction on EntityManager [SessionImpl(2096513672<open>)]
2020-06-01 11:39:48.787 TRACE 26420 --- [.10-8080-exec-2] o.s.orm.jpa.JpaTransactionManager : Triggering afterCommit synchronization
2020-06-01 11:39:48.787 TRACE 26420 --- [.10-8080-exec-2] .s.t.s.TransactionSynchronizationManager : Clearing transaction synchronization
2020-06-01 11:39:48.787 TRACE 26420 --- [.10-8080-exec-2] o.s.orm.jpa.JpaTransactionManager : Triggering afterCompletion synchronization
2020-06-01 11:39:48.787 TRACE 26420 --- [.10-8080-exec-2] .s.t.s.TransactionSynchronizationManager : Removed value [org.springframework.jdbc.datasource.ConnectionHolder@4b988820] for key [HikariDataSource (HikariPool-1)] from thread [http-nio-192.168.1.10-8080-exec-2]
2020-06-01 11:39:48.787 DEBUG 26420 --- [.10-8080-exec-2] o.s.orm.jpa.JpaTransactionManager : Not closing pre-bound JPA EntityManager after transaction
Upvotes: 1
Views: 2943
Reputation: 639
I spent just 4 days to realize the what the problem was. Awesome...(To be honest, I took advantage of all the stuff I had to read about JPA and Hibernate to get rid completely of OSIV).
When I defined my two datasources (Products and Users) configs, I annotated all the classes inside ProductsDataSourceConfiguration
as @Primary
, making them the default values when called without explicitly setting a name.
The problem was with PlatformTransactionManager
in it, that was called as transaction manager for both my datasources, while actually being crafted just for Products one.
To solve the issue I had to specify the secondary transaction manager name on @Transactional
annotation used on methods referring to secondary (Users) datasource:
@Transactional("usersTransactionManager")
@Service
public class UserCommitService {
...
Upvotes: 1