6

I have been at this for a good few hours and I can not find a way to get around what seems to be JPARepository automatically starting/committing a transaction when I save entities inside an encapsulating transaction.

I create 3 entities in total. The first 2, ClientAdmin and CreditPot are to be made so when the third Institution entity is made, the entities can form relationships before being persisted.

When an Exception is thrown, I wanted it so that the created entities are NOT COMMITED (i.e. the entire process rolled back).

At the moment, I can see in the logs that the JPA Save method may start its own transaction (I don't fully understand the logs) which causes the entities that have called repo.save(entity) to be committed in their own transaction?

Any help would be greatly appreciated.

    @Transactional(propagation = Propagation.REQUIRED,rollbackFor = Exception.class)
public void createInstitution(InstitutionSignUpForm form) throws Exception {

    //Create Admin account.
    ClientAdmin clientAdmin = new ClientAdmin();
    clientAdmin.setRole(roleRepo.findOneByRole("SUPER_ADMIN").orElseThrow(() -> new Exception("Can not resolve role SUPER_ADMIN")));
    clientAdmin.setPassword(passwordEncoder.encode(form.getPassword()));
    clientAdmin.setUsername(form.getUsername());
    clientAdmin = clientAdminRepo.save(clientAdmin);

    //Create Credit Pot for institution.
    CreditPot creditPot = new CreditPot();
    creditPot.setIsPrimaryPot(true);
    creditPot.setName("Primary Credit Pot");
    creditPot.setCredits(300L);
    creditPot = creditPotRepo.save(creditPot);

    System.out.println("Throwing Exception.");
    if(1==1) throw new Exception("!!!", new Throwable("!!!"));

    //Create institution and assign relationships.
    Institution institution = new Institution();
    institution.setDiceCode(dicewareGenerator.generateRandomPassword(6));
    institution.setName(form.getInstitutionName());
    institution.setPrimaryCreditPot(creditPot);
    clientAdmin.setInstitution(institution);
    institutionRepo.saveAndFlush(institution);
}

The logs:

    2019-09-12 10:46:41.148 DEBUG 24621 --- [nio-5000-exec-6] o.j.s.OpenEntityManagerInViewInterceptor : Opening JPA EntityManager in OpenEntityManagerInViewInterceptor
2019-09-12 10:46:41.148 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Bound value [org.springframework.orm.jpa.EntityManagerHolder@5ed67928] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@70286b92] to thread [http-nio-5000-exec-6]
2019-09-12 10:46:41.149 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Retrieved value [org.springframework.orm.jpa.EntityManagerHolder@5ed67928] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@70286b92] bound to thread [http-nio-5000-exec-6]
2019-09-12 10:46:41.149 DEBUG 24621 --- [nio-5000-exec-6] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(652375272<open>)] for JPA transaction
2019-09-12 10:46:41.149 DEBUG 24621 --- [nio-5000-exec-6] o.s.orm.jpa.JpaTransactionManager        : Creating new transaction with name [com.j3den.edu.webserver.services.sigup.InstitutionSignUpService.createInstitution]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,-java.lang.Exception
2019-09-12 10:46:41.150 DEBUG 24621 --- [nio-5000-exec-6] o.s.orm.jpa.JpaTransactionManager        : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@74972cba]
2019-09-12 10:46:41.150 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Bound value [org.springframework.jdbc.datasource.ConnectionHolder@19e50439] for key [HikariDataSource (HikariPool-1)] to thread [http-nio-5000-exec-6]
2019-09-12 10:46:41.150 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Initializing transaction synchronization
2019-09-12 10:46:41.150 TRACE 24621 --- [nio-5000-exec-6] o.s.t.i.TransactionInterceptor           : Getting transaction for [com.j3den.edu.webserver.services.sigup.InstitutionSignUpService.createInstitution]
2019-09-12 10:46:41.150 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Bound value [org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$DefaultCrudMethodMetadata@304f1d77] for key [public abstract java.util.Optional com.j3den.edu.models.repos.RoleRepo.findOneByRole(java.lang.String)] to thread [http-nio-5000-exec-6]
2019-09-12 10:46:41.151 TRACE 24621 --- [nio-5000-exec-6] o.s.t.i.TransactionInterceptor           : No need to create transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findOneByRole]: This method is not transactional.
2019-09-12 10:46:41.151 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Retrieved value [org.springframework.orm.jpa.EntityManagerHolder@5ed67928] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@70286b92] bound to thread [http-nio-5000-exec-6]
2019-09-12 10:46:41.151 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Retrieved value [org.springframework.orm.jpa.EntityManagerHolder@5ed67928] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@70286b92] bound to thread [http-nio-5000-exec-6]
2019-09-12 10:46:41.153 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Removed value [org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$DefaultCrudMethodMetadata@304f1d77] for key [public abstract java.util.Optional com.j3den.edu.models.repos.RoleRepo.findOneByRole(java.lang.String)] from thread [http-nio-5000-exec-6]
2019-09-12 10:46:41.242 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Bound value [org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$DefaultCrudMethodMetadata@2d5257a2] for key [public abstract java.lang.Object org.springframework.data.repository.CrudRepository.save(java.lang.Object)] to thread [http-nio-5000-exec-6]
2019-09-12 10:46:41.242 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Retrieved value [org.springframework.orm.jpa.EntityManagerHolder@5ed67928] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@70286b92] bound to thread [http-nio-5000-exec-6]
2019-09-12 10:46:41.242 DEBUG 24621 --- [nio-5000-exec-6] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(652375272<open>)] for JPA transaction
2019-09-12 10:46:41.242 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Retrieved value [org.springframework.jdbc.datasource.ConnectionHolder@19e50439] for key [HikariDataSource (HikariPool-1)] bound to thread [http-nio-5000-exec-6]
2019-09-12 10:46:41.243 DEBUG 24621 --- [nio-5000-exec-6] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
2019-09-12 10:46:41.243 TRACE 24621 --- [nio-5000-exec-6] o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2019-09-12 10:46:41.243 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Retrieved value [org.springframework.orm.jpa.EntityManagerHolder@5ed67928] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@70286b92] bound to thread [http-nio-5000-exec-6]
2019-09-12 10:46:41.244 TRACE 24621 --- [nio-5000-exec-6] o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2019-09-12 10:46:41.245 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Removed value [org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$DefaultCrudMethodMetadata@2d5257a2] for key [public abstract java.lang.Object org.springframework.data.repository.CrudRepository.save(java.lang.Object)] from thread [http-nio-5000-exec-6]
2019-09-12 10:46:41.245 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Bound value [org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$DefaultCrudMethodMetadata@2d5257a2] for key [public abstract java.lang.Object org.springframework.data.repository.CrudRepository.save(java.lang.Object)] to thread [http-nio-5000-exec-6]
2019-09-12 10:46:41.245 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Retrieved value [org.springframework.orm.jpa.EntityManagerHolder@5ed67928] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@70286b92] bound to thread [http-nio-5000-exec-6]
2019-09-12 10:46:41.245 DEBUG 24621 --- [nio-5000-exec-6] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(652375272<open>)] for JPA transaction
2019-09-12 10:46:41.245 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Retrieved value [org.springframework.jdbc.datasource.ConnectionHolder@19e50439] for key [HikariDataSource (HikariPool-1)] bound to thread [http-nio-5000-exec-6]
2019-09-12 10:46:41.245 DEBUG 24621 --- [nio-5000-exec-6] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
2019-09-12 10:46:41.245 TRACE 24621 --- [nio-5000-exec-6] o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2019-09-12 10:46:41.245 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Retrieved value [org.springframework.orm.jpa.EntityManagerHolder@5ed67928] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@70286b92] bound to thread [http-nio-5000-exec-6]
2019-09-12 10:46:41.246 TRACE 24621 --- [nio-5000-exec-6] o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2019-09-12 10:46:41.247 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Removed value [org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$DefaultCrudMethodMetadata@2d5257a2] for key [public abstract java.lang.Object org.springframework.data.repository.CrudRepository.save(java.lang.Object)] from thread [http-nio-5000-exec-6]
Throwing Exception.
2019-09-12 10:46:41.247 TRACE 24621 --- [nio-5000-exec-6] o.s.t.i.TransactionInterceptor           : Completing transaction for [com.j3den.edu.webserver.services.sigup.InstitutionSignUpService.createInstitution] after exception: java.lang.Exception: !!!
2019-09-12 10:46:41.247 TRACE 24621 --- [nio-5000-exec-6] o.s.t.i.RuleBasedTransactionAttribute    : Applying rules to determine whether transaction should rollback on java.lang.Exception: !!!
2019-09-12 10:46:41.247 TRACE 24621 --- [nio-5000-exec-6] o.s.t.i.RuleBasedTransactionAttribute    : Winning rollback rule is: RollbackRuleAttribute with pattern [java.lang.Exception]
2019-09-12 10:46:41.247 DEBUG 24621 --- [nio-5000-exec-6] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction rollback
2019-09-12 10:46:41.247 DEBUG 24621 --- [nio-5000-exec-6] o.s.orm.jpa.JpaTransactionManager        : Rolling back JPA transaction on EntityManager [SessionImpl(652375272<open>)]
2019-09-12 10:46:41.248 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Clearing transaction synchronization
2019-09-12 10:46:41.248 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Removed value [org.springframework.jdbc.datasource.ConnectionHolder@19e50439] for key [HikariDataSource (HikariPool-1)] from thread [http-nio-5000-exec-6]
2019-09-12 10:46:41.248 DEBUG 24621 --- [nio-5000-exec-6] o.s.orm.jpa.JpaTransactionManager        : Not closing pre-bound JPA EntityManager after transaction
2019-09-12 10:46:41.248 TRACE 24621 --- [nio-5000-exec-6] .s.t.s.TransactionSynchronizationManager : Removed value [org.springframework.orm.jpa.EntityManagerHolder@5ed67928] for key [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean@70286b92] from thread [http-nio-5000-exec-6]
2019-09-12 10:46:41.248 DEBUG 24621 --- [nio-5000-exec-6] o.j.s.OpenEntityManagerInViewInterceptor : Closing JPA EntityManager in OpenEntityManagerInViewInterceptor
Jcov
  • 2,122
  • 2
  • 21
  • 32
  • The logs say that the transaction is rolled back due to the exception, and there's no indication that things aren't working exactly as they should. Are you claiming there's data in the database after the transaction is rolled back? – Kayaman Sep 12 '19 at 10:08
  • 1
    Yes. The ClientAdmin and CreditPot are both persisted (as I guess hibernate.save() has been called?) and are not rolled back once the Exception is thrown... – Jcov Sep 12 '19 at 10:14
  • Just to be sure, you haven't defined your own `save()` method in your repository classes, have you? Then again, it does say that both calls to `save()` are participating in an existing transaction, as they should. How are you checking that the values are inserted? Through code or by looking at the database with a tool? – Kayaman Sep 12 '19 at 10:29
  • Which database are you using? Also add your `persistence.xml` (if you have) and your `application.properties`. . – M. Deinum Sep 12 '19 at 10:29
  • @Kayaman I have not overridden any JpaRepo methods. – Jcov Sep 12 '19 at 10:40
  • @M.Deinum I am using MYSQL Server version: 5.7.27-0ubuntu0.18.04.1 (Ubuntu) Which now you mention it...maybe my mysql server doesn't play well with the version(s) of JPA/JDBC etc? I will try updating mysql to 8. – Jcov Sep 12 '19 at 10:41
  • It's most likely operator error. Saying "rollback is broken" is a pretty serious accusation, and the primary suspect is the developer (you). What if you print out the SQL generated by JPA? – Kayaman Sep 12 '19 at 10:42
  • Although maybe it's [an epidemic](https://stackoverflow.com/questions/57904945/rollback-not-performed-for-transactional-annotation) ;) – Kayaman Sep 12 '19 at 10:46
  • 2
    You using MySQL, depending on the dialect used it will either use MyISAM tables or InnoDB tables. MyISAM tables don't support transactions, and it looks like that is what you are running into. Make sure you confiugre JPA/Hibernate to use the proper table type for TX aka InnoDB tables. – M. Deinum Sep 12 '19 at 10:46
  • I know it is me. I am probably either not understanding how JPA and EntityManager works together and how @Transaction works but I can not figure out where I am going wrong. My properties for "datasource": spring.datasource.url=jdbc:mysql://127.0.0.1/mydb?createDatabaseIfNotExist=true spring.datasource.username=dev spring.datasource.password=password spring.datasource.driver-class-name=com.mysql.cj.jdbc.Driver spring.jpa.generate-ddl=true spring.jpa.hibernate.ddl-auto=update spring.jpa.database = MYSQL – Jcov Sep 12 '19 at 10:49
  • @M.Deinum Thank you very much! I am using MyISAM... I will try change the default to InnoDB and have another go. – Jcov Sep 12 '19 at 10:55

1 Answers1

5

MySQL historically by default created tables using the MyISAM engine, which didn't support transactions. Later InnoDB was added which did support transactions, however MyISAM remained the default for quite some time.

Hibernate with its dialects followed the same defaults and hence the default for the MySQL dialect is MyISAM (for backwards compatibility).

You have 2 ways to fix this, either select a specific dialect or toggle from MyISAM to InnoDB with a specific property.

To select a dialect use the spring.jpa.database-platform to specify the required dependency.

spring.jpa.database-platform=org.hibernate.dialect.MySQL57InnoDBDialect`

or to set the property use

spring.jpa.properties.hibernate.dialect.storage_engine=innodb

or a combination of both (as the MySQL57InnoDBDialect is deprecated now that there is the hibernate.dialect.storage_engine property).

spring.jpa.database-platform=org.hibernate.dialect.MySQL57Dialect
spring.jpa.properties.hibernate.dialect.storage_engine=innodb

See also: https://in.relation.to/2017/02/20/mysql-dialect-refactoring/

M. Deinum
  • 115,695
  • 22
  • 220
  • 224
  • Thank you so very much. I could have been scratching my head for days or having this little "gotcha" bite me hard later! – Jcov Sep 12 '19 at 11:08