JPA / Hibernate, duplicate pkey error when updating entity that is a subclass of a base class that uses IdClass for composite primary key #2767

cuipengfei · 2023-01-17T14:02:26Z

How to reproduce this issue

~~https://github.com/cuipengfei/Spikes/tree/master/jpa/ClassIdUpdateIssue~~

~~this code can reproduce the issue, just run the main method then the error will happen.~~

https://github.com/gregturn/spring-data-jpa-id-class-issues/tree/main/src/test/java/com/example/demo

Just make sure you have docker installed and run these 👆 unit tests.

The unit test with EmbeddedId will be ok.

But the one with IdClass will fail, while we expect it to be successful.

Issue Description

There is a base class like this:

@Entity
@Inheritance(strategy = InheritanceType.SINGLE_TABLE)
@DiscriminatorFormula("case when vip_number is not null then 'vip' else 'normal' end")
@DiscriminatorValue("normal")
@IdClass(CustomerPK.class)
public class CustomerWithIdClass implements Serializable {

    private String firstName;
    private String lastName;

    @Id
    private Long versionId;
    @Id
    private Long unitId;

    protected CustomerWithIdClass() {
    }

   // getter and setters ......
}

Its IdClass is like this:

@NoArgsConstructor
@EqualsAndHashCode
@Embeddable
public class CustomerPK implements Serializable {

    private Long unitId;

    private Long versionId;

    public void setUnitId(Long unitId) {
        this.unitId = unitId;
    }

    public void setVersionId(Long versionId) {
        this.versionId = versionId;
    }
}

Then it has a subclass:

@Entity
@DiscriminatorValue("vip")
public class VipCustomerWithIdClass extends CustomerWithIdClass {
    private String vipNumber;

    public VipCustomerWithIdClass() {
    }

    public VipCustomerWithIdClass(String firstName, String lastName, String vipNumber) {
        super(firstName, lastName);
        this.vipNumber = vipNumber;
    }

    public String getVipNumber() {
        return vipNumber;
    }

    public void setVipNumber(String vipNumber) {
        this.vipNumber = vipNumber;
    }
}

The subclass only adds one additional field, nothing else fancy.

Then when I try to persist an instance of the subclass like this:

        CustomerWithIdClass customer = new CustomerWithIdClass("a", "b");
        customer.setVersionId(123L);
        customer.setUnitId(456L);

        repository.save(customer);//save object of base class, ok

        customer.setFirstName("a2");
        repository.save(customer);//modify object of base class and save again, ok

        VipCustomerWithIdClass vipCustomer = new VipCustomerWithIdClass("a", "b", "888");
        vipCustomer.setVersionId(987L);
        vipCustomer.setUnitId(654L);

        repository.save(vipCustomer);//save object of subclass, ok

        vipCustomer.setVipNumber("999");
        repository.save(vipCustomer);//modify object of subclass and save again, NOT OK
        // ↑ THIS FAILS BECAUSE OF PRIMARY KEY CONFLICT. INSERT STATEMENT WAS USED INSTEAD OF UPDATE, WHY?
        // this failure only happens when:
        // 1. base class uses IdClass for composite primary key
        // 2. saving an instance of the subclass for the second time after modification

The Error

Then there will be an error of duplicate pkey when I try to save the instance of the subclass for the second time after some modification.

The error seems to be related with the @IdClass annotation, because I have tried using @EmbeddedId and @Embeddable for composite pkey, then the error does not happen.

The question

What is the root reason of this issue? Is @IdClass not supposed to be used for this scenario?

links

https://stackoverflow.com/questions/75147518/jpa-hibernate-duplicate-pkey-error-when-updating-entity-that-is-a-subclass-of

https://hibernate.atlassian.net/browse/HHH-16054

gregturn · 2023-01-17T18:04:40Z

Thanks @cuipengfei for the reproducer. Using it I have verified this issue exists. The first thing I noticed between the two scenarios, is that inserting the @IdClass-based VipCustomer entity doesn't result in a follow-up select. Hence, there is no updated copy of the entity signaling that an update is in order.

However, for the @EmbeddedId version, it does.

When running the @EmbeddedId variant, this is the output of storing the first VIP record:

2023-01-17 13:06:25.042 DEBUG 74994 --- [           main] org.hibernate.SQL                        : select vipcustome0_.unit_id as unit_id1_0_0_, vipcustome0_.version_id as version_2_0_0_, vipcustome0_.first_name as first_na3_0_0_, vipcustome0_.last_name as last_nam4_0_0_, vipcustome0_.vip_number as vip_numb5_0_0_ from customer_with_embedded_id vipcustome0_ where vipcustome0_.unit_id=? and vipcustome0_.version_id=? and case when vipcustome0_.vip_number is not null then 'vip' else 'normal' end='vip'
Hibernate: select vipcustome0_.unit_id as unit_id1_0_0_, vipcustome0_.version_id as version_2_0_0_, vipcustome0_.first_name as first_na3_0_0_, vipcustome0_.last_name as last_nam4_0_0_, vipcustome0_.vip_number as vip_numb5_0_0_ from customer_with_embedded_id vipcustome0_ where vipcustome0_.unit_id=? and vipcustome0_.version_id=? and case when vipcustome0_.vip_number is not null then 'vip' else 'normal' end='vip'
2023-01-17 13:06:25.042 TRACE 74994 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [BIGINT] - [654]
2023-01-17 13:06:25.042 TRACE 74994 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [2] as [BIGINT] - [987]
2023-01-17 13:06:25.051 DEBUG 74994 --- [           main] org.hibernate.SQL                        : insert into customer_with_embedded_id (first_name, last_name, vip_number, unit_id, version_id) values (?, ?, ?, ?, ?)
Hibernate: insert into customer_with_embedded_id (first_name, last_name, vip_number, unit_id, version_id) values (?, ?, ?, ?, ?)
2023-01-17 13:06:25.051 TRACE 74994 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [a]
2023-01-17 13:06:25.051 TRACE 74994 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [2] as [VARCHAR] - [b]
2023-01-17 13:06:25.051 TRACE 74994 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [3] as [VARCHAR] - [888]
2023-01-17 13:06:25.052 TRACE 74994 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [4] as [BIGINT] - [654]
2023-01-17 13:06:25.052 TRACE 74994 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [5] as [BIGINT] - [987]

But when running the @IdClass variant, this is the output:

2023-01-17 13:08:24.942 DEBUG 75260 --- [           main] org.hibernate.SQL                        : insert into customer_with_id_class (first_name, last_name, vip_number, unit_id, version_id) values (?, ?, ?, ?, ?)
Hibernate: insert into customer_with_id_class (first_name, last_name, vip_number, unit_id, version_id) values (?, ?, ?, ?, ?)
2023-01-17 13:08:24.942 TRACE 75260 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [a]
2023-01-17 13:08:24.942 TRACE 75260 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [2] as [VARCHAR] - [b]
2023-01-17 13:08:24.942 TRACE 75260 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [3] as [VARCHAR] - [888]
2023-01-17 13:08:24.942 TRACE 75260 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [4] as [BIGINT] - [654]
2023-01-17 13:08:24.943 TRACE 75260 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [5] as [BIGINT] - [987]

It's starting to look like a Hibernate-specific issue.

gregturn · 2023-01-17T19:47:35Z

I have taken your reproducer and turned things around such that each scenario is a different test case at https://github.com/gregturn/spring-data-jpa-id-class-issues.

gregturn · 2023-01-17T19:49:04Z

In both situations, it appears to perform a em.merge() on the VipCustomer objects. The embedded one does a proper JPA select/insert & select/update. But for the idclass one, it does NOT do a select. Without that, I can't see that the object already exists, and so it simply launches into insert, causing a key constraint violation when it tries a second time.

cuipengfei · 2023-01-18T01:40:51Z

In both situations, it appears to perform a em.merge() on the VipCustomer objects. The embedded one does a proper JPA select/insert & select/update. But for the idclass one, it does NOT do a select. Without that, I can't see that the object already exists, and so it simply launches into insert, causing a key constraint violation when it tries a second time.

Yes. I have noticed the same thing.

	Customer	VipCustomer
IdClass	select/insert and select/update	insert and insert, this is the problem
EmbeddedId	select/insert and select/update	select/insert and select/update

I just was not sure if it is a spring-data-jpa issue or a hibernate issue.

schauder · 2023-01-18T08:48:36Z

Not arguing with the analysis, but

repo.save(customer);//save object of base class, ok
customer.setFirstName("a2");

is problematic, since it mit loose generated information.
Instead the instance returned by save should be used:

customer = repo.save(customer);//save object of base class, ok
customer.setFirstName("a2");

This might even be a workaround for the issue.

gregturn · 2023-01-18T15:24:36Z

I'm going to try and reproduce the test cases using Hibernate only.

gregturn · 2023-01-18T15:37:32Z

@schauder I actually tested that, and it seemed to make no difference.

I created alternative variants of the test cases, instead using an injected EntityManager. They ONLY worked when I made the entire test class @Transactional. And then...both variants worked properly.

I went back and applied @Transactional to both variants of the Spring Data repository-based test cases...and suddenly the @IdClass one worked! So it looks like somehow, transactional state isn't being setup properly for the @IdClass scenario. I still can't see where this is happening exactly.

gregturn · 2023-01-18T17:36:11Z

I've pushed a few updates to my reproducer. This suggests that at a minimum, you can work around this by ensuring your service layer has @Transactional wrapped around it properly. I'm continuing to dig and find out where this inconsistency lies. But it does NOT appear to be Hibernate. (You may want to consider withdrawing the ticket opened against Hibernate).

gregturn · 2023-01-19T18:33:57Z

I turned up the logging flags and gathered this from the @IdClass test case that fails:

2023-01-19 12:31:25.468 TRACE 81625 --- [           main] toryAnnotationTransactionAttributeSource : Adding transactional method 'org.springframework.data.jpa.repository.support.SimpleJpaRepository.save' with attribute: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
2023-01-19 12:31:25.470 TRACE 81625 --- [           main] .i.SessionFactoryImpl$SessionBuilderImpl : Opening Hibernate Session.  tenant=null
2023-01-19 12:31:25.470 TRACE 81625 --- [           main] org.hibernate.internal.SessionImpl       : Opened Session [614d1a5f-5c9e-4a86-8f3f-21275c77118c] at timestamp: 1674153085470
2023-01-19 12:31:25.479 TRACE 81625 --- [           main] o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2023-01-19 12:31:25.484 DEBUG 81625 --- [           main] h.e.i.EntityCopyObserverFactoryInitiator : Configured EntityCopyObserver strategy: disallow
2023-01-19 12:31:25.487 TRACE 81625 --- [           main] o.hibernate.event.internal.EntityState   : Transient instance of: com.example.demo.IdClass.VipCustomerWithIdClass
2023-01-19 12:31:25.487 TRACE 81625 --- [           main] o.h.e.i.DefaultMergeEventListener        : Merging transient instance
2023-01-19 12:31:25.495 DEBUG 81625 --- [           main] o.h.e.i.AbstractSaveEventListener        : Generated identifier: component[unitId,versionId]{versionId=987, unitId=654}, using strategy: org.hibernate.id.CompositeNestedGeneratedValueGenerator
2023-01-19 12:31:25.496 TRACE 81625 --- [           main] o.h.e.i.AbstractSaveEventListener        : Saving [com.example.demo.IdClass.VipCustomerWithIdClass#component[unitId,versionId]{versionId=987, unitId=654}]
2023-01-19 12:31:25.500 TRACE 81625 --- [           main] o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2023-01-19 12:31:25.500 TRACE 81625 --- [           main] org.hibernate.internal.SessionImpl       : SessionImpl#beforeTransactionCompletion()
2023-01-19 12:31:25.500 TRACE 81625 --- [           main] org.hibernate.internal.SessionImpl       : Automatically flushing session
2023-01-19 12:31:25.500 TRACE 81625 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushing session
2023-01-19 12:31:25.500 DEBUG 81625 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Processing flush-time cascades
2023-01-19 12:31:25.501 DEBUG 81625 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Dirty checking collections
2023-01-19 12:31:25.501 TRACE 81625 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushing entities and processing referenced collections
2023-01-19 12:31:25.502 TRACE 81625 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Processing unreferenced collections
2023-01-19 12:31:25.502 TRACE 81625 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Scheduling collection removes/(re)creates/updates
2023-01-19 12:31:25.503 DEBUG 81625 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
2023-01-19 12:31:25.503 DEBUG 81625 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2023-01-19 12:31:25.503 DEBUG 81625 --- [           main] o.hibernate.internal.util.EntityPrinter  : Listing entities:
2023-01-19 12:31:25.503 DEBUG 81625 --- [           main] o.hibernate.internal.util.EntityPrinter  : com.example.demo.IdClass.VipCustomerWithIdClass{firstName=a, lastName=b, vipNumber=888}
2023-01-19 12:31:25.503 TRACE 81625 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Executing flush
2023-01-19 12:31:25.507 DEBUG 81625 --- [           main] org.hibernate.SQL                        : insert into customer_with_id_class (first_name, last_name, vip_number, unit_id, version_id) values (?, ?, ?, ?, ?)
Hibernate: insert into customer_with_id_class (first_name, last_name, vip_number, unit_id, version_id) values (?, ?, ?, ?, ?)
2023-01-19 12:31:25.509 TRACE 81625 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [a]
2023-01-19 12:31:25.509 TRACE 81625 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [2] as [VARCHAR] - [b]
2023-01-19 12:31:25.509 TRACE 81625 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [3] as [VARCHAR] - [888]
2023-01-19 12:31:25.509 TRACE 81625 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [4] as [BIGINT] - [654]
2023-01-19 12:31:25.510 TRACE 81625 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [5] as [BIGINT] - [987]
2023-01-19 12:31:25.520 TRACE 81625 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Post flush
2023-01-19 12:31:25.527 TRACE 81625 --- [           main] org.hibernate.internal.SessionImpl       : SessionImpl#afterTransactionCompletion(successful=true, delayed=false)
2023-01-19 12:31:25.527 TRACE 81625 --- [           main] org.hibernate.internal.SessionImpl       : Closing session [614d1a5f-5c9e-4a86-8f3f-21275c77118c]
2023-01-19 12:31:25.527 TRACE 81625 --- [           main] .i.SessionFactoryImpl$SessionBuilderImpl : Opening Hibernate Session.  tenant=null
2023-01-19 12:31:25.527 TRACE 81625 --- [           main] org.hibernate.internal.SessionImpl       : Opened Session [9ada37f0-bd57-4caa-92bb-8454fa9dd5a4] at timestamp: 1674153085527
2023-01-19 12:31:25.528 TRACE 81625 --- [           main] o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2023-01-19 12:31:25.528 TRACE 81625 --- [           main] o.hibernate.event.internal.EntityState   : Transient instance of: com.example.demo.IdClass.VipCustomerWithIdClass
2023-01-19 12:31:25.528 TRACE 81625 --- [           main] o.h.e.i.DefaultMergeEventListener        : Merging transient instance
2023-01-19 12:31:25.528 DEBUG 81625 --- [           main] o.h.e.i.AbstractSaveEventListener        : Generated identifier: component[unitId,versionId]{versionId=987, unitId=654}, using strategy: org.hibernate.id.CompositeNestedGeneratedValueGenerator
2023-01-19 12:31:25.528 TRACE 81625 --- [           main] o.h.e.i.AbstractSaveEventListener        : Saving [com.example.demo.IdClass.VipCustomerWithIdClass#component[unitId,versionId]{versionId=987, unitId=654}]
2023-01-19 12:31:25.528 TRACE 81625 --- [           main] o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2023-01-19 12:31:25.528 TRACE 81625 --- [           main] org.hibernate.internal.SessionImpl       : SessionImpl#beforeTransactionCompletion()
2023-01-19 12:31:25.528 TRACE 81625 --- [           main] org.hibernate.internal.SessionImpl       : Automatically flushing session
2023-01-19 12:31:25.528 TRACE 81625 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushing session
2023-01-19 12:31:25.528 DEBUG 81625 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Processing flush-time cascades
2023-01-19 12:31:25.528 DEBUG 81625 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Dirty checking collections
2023-01-19 12:31:25.528 TRACE 81625 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushing entities and processing referenced collections
2023-01-19 12:31:25.528 TRACE 81625 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Processing unreferenced collections
2023-01-19 12:31:25.528 TRACE 81625 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Scheduling collection removes/(re)creates/updates
2023-01-19 12:31:25.528 DEBUG 81625 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
2023-01-19 12:31:25.528 DEBUG 81625 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2023-01-19 12:31:25.528 DEBUG 81625 --- [           main] o.hibernate.internal.util.EntityPrinter  : Listing entities:
2023-01-19 12:31:25.528 DEBUG 81625 --- [           main] o.hibernate.internal.util.EntityPrinter  : com.example.demo.IdClass.VipCustomerWithIdClass{firstName=a, lastName=b, vipNumber=999}
2023-01-19 12:31:25.528 TRACE 81625 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Executing flush
2023-01-19 12:31:25.528 DEBUG 81625 --- [           main] org.hibernate.SQL                        : insert into customer_with_id_class (first_name, last_name, vip_number, unit_id, version_id) values (?, ?, ?, ?, ?)
Hibernate: insert into customer_with_id_class (first_name, last_name, vip_number, unit_id, version_id) values (?, ?, ?, ?, ?)
2023-01-19 12:31:25.528 TRACE 81625 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [a]
2023-01-19 12:31:25.529 TRACE 81625 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [2] as [VARCHAR] - [b]
2023-01-19 12:31:25.529 TRACE 81625 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [3] as [VARCHAR] - [999]
2023-01-19 12:31:25.529 TRACE 81625 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [4] as [BIGINT] - [654]
2023-01-19 12:31:25.529 TRACE 81625 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [5] as [BIGINT] - [987]
2023-01-19 12:31:25.537  WARN 81625 --- [           main] o.h.engine.jdbc.spi.SqlExceptionHelper   : SQL Error: 0, SQLState: 23505
2023-01-19 12:31:25.537 ERROR 81625 --- [           main] o.h.engine.jdbc.spi.SqlExceptionHelper   : ERROR: duplicate key value violates unique constraint "customer_with_id_class_pkey"
  Detail: Key (unit_id, version_id)=(654, 987) already exists.
2023-01-19 12:31:25.537  INFO 81625 --- [           main] o.h.e.j.b.internal.AbstractBatchImpl     : HHH000010: On release of batch it still contained JDBC statements
2023-01-19 12:31:25.545 TRACE 81625 --- [           main] org.hibernate.internal.SessionImpl       : SessionImpl#afterTransactionCompletion(successful=false, delayed=false)
2023-01-19 12:31:25.546 TRACE 81625 --- [           main] org.hibernate.internal.SessionImpl       : Closing session [9ada37f0-bd57-4caa-92bb-8454fa9dd5a4]

org.springframework.dao.DataIntegrityViolationException: could not execute statement; SQL [n/a]; constraint [customer_with_id_class_pkey]; nested exception is org.hibernate.exception.ConstraintViolationException: could not execute statement

	at org.springframework.orm.jpa.vendor.HibernateJpaDialect.convertHibernateAccessException(HibernateJpaDialect.java:276)
	at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:233)
	at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:566)
	at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:743)
	at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:711)
	at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:654)
	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:407)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
	at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:137)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
	at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:174)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
	at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)
	at com.sun.proxy.$Proxy127.save(Unknown Source)
	at com.example.demo.SpringDataIdClassTests.doStuff(SpringDataIdClassTests.java:75)
	at com.example.demo.SpringDataIdClassTests.idClassWithoutTransaction(SpringDataIdClassTests.java:44)
	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.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:725)
	at org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60)
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131)
	at org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:149)
	at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:140)
	at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:84)
	at org.junit.jupiter.engine.execution.ExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(ExecutableInvoker.java:115)
	at org.junit.jupiter.engine.execution.ExecutableInvoker.lambda$invoke$0(ExecutableInvoker.java:105)
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106)
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64)
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45)
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37)
	at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:104)
	at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:98)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$7(TestMethodTestDescriptor.java:214)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:210)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:135)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:66)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:151)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
	at java.util.ArrayList.forEach(ArrayList.java:1259)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:41)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:155)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
	at java.util.ArrayList.forEach(ArrayList.java:1259)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:41)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:155)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:35)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:54)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:107)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:88)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.lambda$execute$0(EngineExecutionOrchestrator.java:54)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.withInterceptedStreams(EngineExecutionOrchestrator.java:67)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:52)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:114)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:86)
	at org.junit.platform.launcher.core.DefaultLauncherSession$DelegatingLauncher.execute(DefaultLauncherSession.java:86)
	at org.junit.platform.launcher.core.SessionPerRequestLauncher.execute(SessionPerRequestLauncher.java:53)
	at com.intellij.junit5.JUnit5IdeaTestRunner.startRunnerWithArgs(JUnit5IdeaTestRunner.java:57)
	at com.intellij.rt.junit.IdeaTestRunner$Repeater$1.execute(IdeaTestRunner.java:38)
	at com.intellij.rt.execution.junit.TestsRepeater.repeat(TestsRepeater.java:11)
	at com.intellij.rt.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:35)
	at com.intellij.rt.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:235)
	at com.intellij.rt.junit.JUnitStarter.main(JUnitStarter.java:54)
Caused by: org.hibernate.exception.ConstraintViolationException: could not execute statement
	at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:109)
	at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:37)
	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113)
	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99)
	at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:200)
	at org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:46)
	at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3375)
	at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3937)
	at org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:107)
	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604)
	at org.hibernate.engine.spi.ActionQueue.lambda$executeActions$1(ActionQueue.java:478)
	at java.util.LinkedHashMap.forEach(LinkedHashMap.java:684)
	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:475)
	at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:344)
	at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:40)
	at org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:107)
	at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1407)
	at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:489)
	at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3303)
	at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2438)
	at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:449)
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:183)
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$300(JdbcResourceLocalTransactionCoordinatorImpl.java:40)
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:281)
	at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:101)
	at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:562)
	... 85 more
Caused by: org.postgresql.util.PSQLException: ERROR: duplicate key value violates unique constraint "customer_with_id_class_pkey"
  Detail: Key (unit_id, version_id)=(654, 987) already exists.
	at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2675)
	at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2365)
	at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:355)
	at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:490)
	at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:408)
	at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:167)
	at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java:135)
	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:197)
	... 106 more

gregturn · 2023-01-19T18:35:07Z

This is the @EmbeddedId test case that runs just fine, with the same log levels applied:

2023-01-19 12:34:16.834 TRACE 82130 --- [           main] toryAnnotationTransactionAttributeSource : Adding transactional method 'org.springframework.data.jpa.repository.support.SimpleJpaRepository.save' with attribute: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
2023-01-19 12:34:16.835 TRACE 82130 --- [           main] .i.SessionFactoryImpl$SessionBuilderImpl : Opening Hibernate Session.  tenant=null
2023-01-19 12:34:16.835 TRACE 82130 --- [           main] org.hibernate.internal.SessionImpl       : Opened Session [a8b92ca7-04d3-42f2-b4f0-b8d5ca2e39ff] at timestamp: 1674153256835
2023-01-19 12:34:16.845 TRACE 82130 --- [           main] o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2023-01-19 12:34:16.848 DEBUG 82130 --- [           main] h.e.i.EntityCopyObserverFactoryInitiator : Configured EntityCopyObserver strategy: disallow
2023-01-19 12:34:16.851 TRACE 82130 --- [           main] o.hibernate.event.internal.EntityState   : Detached instance of: com.example.demo.EmbeddedId.VipCustomerWithEmbedId
2023-01-19 12:34:16.851 TRACE 82130 --- [           main] o.h.e.i.DefaultMergeEventListener        : Merging detached instance
2023-01-19 12:34:16.853 TRACE 82130 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Loading entity: [com.example.demo.EmbeddedId.VipCustomerWithEmbedId#component[unitId,versionId]{versionId=987, unitId=654}]
2023-01-19 12:34:16.853 TRACE 82130 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Attempting to resolve: [com.example.demo.EmbeddedId.VipCustomerWithEmbedId#component[unitId,versionId]{versionId=987, unitId=654}]
2023-01-19 12:34:16.854 TRACE 82130 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Object not resolved in any cache: [com.example.demo.EmbeddedId.VipCustomerWithEmbedId#component[unitId,versionId]{versionId=987, unitId=654}]
2023-01-19 12:34:16.862 DEBUG 82130 --- [           main] org.hibernate.SQL                        : select vipcustome0_.unit_id as unit_id1_0_0_, vipcustome0_.version_id as version_2_0_0_, vipcustome0_.first_name as first_na3_0_0_, vipcustome0_.last_name as last_nam4_0_0_, vipcustome0_.vip_number as vip_numb5_0_0_ from customer_with_embedded_id vipcustome0_ where vipcustome0_.unit_id=? and vipcustome0_.version_id=? and case when vipcustome0_.vip_number is not null then 'vip' else 'normal' end='vip'
Hibernate: select vipcustome0_.unit_id as unit_id1_0_0_, vipcustome0_.version_id as version_2_0_0_, vipcustome0_.first_name as first_na3_0_0_, vipcustome0_.last_name as last_nam4_0_0_, vipcustome0_.vip_number as vip_numb5_0_0_ from customer_with_embedded_id vipcustome0_ where vipcustome0_.unit_id=? and vipcustome0_.version_id=? and case when vipcustome0_.vip_number is not null then 'vip' else 'normal' end='vip'
2023-01-19 12:34:16.865 TRACE 82130 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [BIGINT] - [654]
2023-01-19 12:34:16.865 TRACE 82130 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [2] as [BIGINT] - [987]
2023-01-19 12:34:16.871 TRACE 82130 --- [           main] o.h.e.i.DefaultMergeEventListener        : Merging transient instance
2023-01-19 12:34:16.874 DEBUG 82130 --- [           main] o.h.e.i.AbstractSaveEventListener        : Generated identifier: component[unitId,versionId]{versionId=987, unitId=654}, using strategy: org.hibernate.id.CompositeNestedGeneratedValueGenerator
2023-01-19 12:34:16.874 TRACE 82130 --- [           main] o.h.e.i.AbstractSaveEventListener        : Saving [com.example.demo.EmbeddedId.VipCustomerWithEmbedId#component[unitId,versionId]{versionId=987, unitId=654}]
2023-01-19 12:34:16.878 TRACE 82130 --- [           main] o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2023-01-19 12:34:16.878 TRACE 82130 --- [           main] org.hibernate.internal.SessionImpl       : SessionImpl#beforeTransactionCompletion()
2023-01-19 12:34:16.878 TRACE 82130 --- [           main] org.hibernate.internal.SessionImpl       : Automatically flushing session
2023-01-19 12:34:16.879 TRACE 82130 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushing session
2023-01-19 12:34:16.879 DEBUG 82130 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Processing flush-time cascades
2023-01-19 12:34:16.879 DEBUG 82130 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Dirty checking collections
2023-01-19 12:34:16.879 TRACE 82130 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushing entities and processing referenced collections
2023-01-19 12:34:16.880 TRACE 82130 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Processing unreferenced collections
2023-01-19 12:34:16.880 TRACE 82130 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Scheduling collection removes/(re)creates/updates
2023-01-19 12:34:16.881 DEBUG 82130 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
2023-01-19 12:34:16.881 DEBUG 82130 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2023-01-19 12:34:16.881 DEBUG 82130 --- [           main] o.hibernate.internal.util.EntityPrinter  : Listing entities:
2023-01-19 12:34:16.881 DEBUG 82130 --- [           main] o.hibernate.internal.util.EntityPrinter  : com.example.demo.EmbeddedId.VipCustomerWithEmbedId{firstName=a, lastName=b, customerPK=component[unitId,versionId]{versionId=987, unitId=654}, vipNumber=888}
2023-01-19 12:34:16.881 TRACE 82130 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Executing flush
2023-01-19 12:34:16.884 DEBUG 82130 --- [           main] org.hibernate.SQL                        : insert into customer_with_embedded_id (first_name, last_name, vip_number, unit_id, version_id) values (?, ?, ?, ?, ?)
Hibernate: insert into customer_with_embedded_id (first_name, last_name, vip_number, unit_id, version_id) values (?, ?, ?, ?, ?)
2023-01-19 12:34:16.884 TRACE 82130 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [a]
2023-01-19 12:34:16.884 TRACE 82130 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [2] as [VARCHAR] - [b]
2023-01-19 12:34:16.884 TRACE 82130 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [3] as [VARCHAR] - [888]
2023-01-19 12:34:16.885 TRACE 82130 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [4] as [BIGINT] - [654]
2023-01-19 12:34:16.885 TRACE 82130 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [5] as [BIGINT] - [987]
2023-01-19 12:34:16.890 TRACE 82130 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Post flush
2023-01-19 12:34:16.894 TRACE 82130 --- [           main] org.hibernate.internal.SessionImpl       : SessionImpl#afterTransactionCompletion(successful=true, delayed=false)
2023-01-19 12:34:16.894 TRACE 82130 --- [           main] org.hibernate.internal.SessionImpl       : Closing session [a8b92ca7-04d3-42f2-b4f0-b8d5ca2e39ff]
2023-01-19 12:34:16.894 TRACE 82130 --- [           main] .i.SessionFactoryImpl$SessionBuilderImpl : Opening Hibernate Session.  tenant=null
2023-01-19 12:34:16.894 TRACE 82130 --- [           main] org.hibernate.internal.SessionImpl       : Opened Session [6211a808-9faa-4f5f-9c05-7c59c946bb27] at timestamp: 1674153256894
2023-01-19 12:34:16.894 TRACE 82130 --- [           main] o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2023-01-19 12:34:16.894 TRACE 82130 --- [           main] o.hibernate.event.internal.EntityState   : Detached instance of: com.example.demo.EmbeddedId.VipCustomerWithEmbedId
2023-01-19 12:34:16.894 TRACE 82130 --- [           main] o.h.e.i.DefaultMergeEventListener        : Merging detached instance
2023-01-19 12:34:16.894 TRACE 82130 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Loading entity: [com.example.demo.EmbeddedId.VipCustomerWithEmbedId#component[unitId,versionId]{versionId=987, unitId=654}]
2023-01-19 12:34:16.895 TRACE 82130 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Attempting to resolve: [com.example.demo.EmbeddedId.VipCustomerWithEmbedId#component[unitId,versionId]{versionId=987, unitId=654}]
2023-01-19 12:34:16.895 TRACE 82130 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Object not resolved in any cache: [com.example.demo.EmbeddedId.VipCustomerWithEmbedId#component[unitId,versionId]{versionId=987, unitId=654}]
2023-01-19 12:34:16.895 DEBUG 82130 --- [           main] org.hibernate.SQL                        : select vipcustome0_.unit_id as unit_id1_0_0_, vipcustome0_.version_id as version_2_0_0_, vipcustome0_.first_name as first_na3_0_0_, vipcustome0_.last_name as last_nam4_0_0_, vipcustome0_.vip_number as vip_numb5_0_0_ from customer_with_embedded_id vipcustome0_ where vipcustome0_.unit_id=? and vipcustome0_.version_id=? and case when vipcustome0_.vip_number is not null then 'vip' else 'normal' end='vip'
Hibernate: select vipcustome0_.unit_id as unit_id1_0_0_, vipcustome0_.version_id as version_2_0_0_, vipcustome0_.first_name as first_na3_0_0_, vipcustome0_.last_name as last_nam4_0_0_, vipcustome0_.vip_number as vip_numb5_0_0_ from customer_with_embedded_id vipcustome0_ where vipcustome0_.unit_id=? and vipcustome0_.version_id=? and case when vipcustome0_.vip_number is not null then 'vip' else 'normal' end='vip'
2023-01-19 12:34:16.895 TRACE 82130 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [BIGINT] - [654]
2023-01-19 12:34:16.895 TRACE 82130 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [2] as [BIGINT] - [987]
2023-01-19 12:34:16.899 TRACE 82130 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([first_na3_0_0_] : [VARCHAR]) - [a]
2023-01-19 12:34:16.899 TRACE 82130 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([last_nam4_0_0_] : [VARCHAR]) - [b]
2023-01-19 12:34:16.899 TRACE 82130 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([vip_numb5_0_0_] : [VARCHAR]) - [888]
2023-01-19 12:34:16.899 TRACE 82130 --- [           main] o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2023-01-19 12:34:16.899 TRACE 82130 --- [           main] org.hibernate.internal.SessionImpl       : SessionImpl#beforeTransactionCompletion()
2023-01-19 12:34:16.899 TRACE 82130 --- [           main] org.hibernate.internal.SessionImpl       : Automatically flushing session
2023-01-19 12:34:16.900 TRACE 82130 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushing session
2023-01-19 12:34:16.900 DEBUG 82130 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Processing flush-time cascades
2023-01-19 12:34:16.900 DEBUG 82130 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Dirty checking collections
2023-01-19 12:34:16.900 TRACE 82130 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushing entities and processing referenced collections
2023-01-19 12:34:16.900 TRACE 82130 --- [           main] o.h.e.i.DefaultFlushEntityEventListener  : Found dirty properties [[com.example.demo.EmbeddedId.VipCustomerWithEmbedId#CustomerPK(unitId=654, versionId=987)]] : [vipNumber]
2023-01-19 12:34:16.900 TRACE 82130 --- [           main] o.h.e.i.DefaultFlushEntityEventListener  : Updating entity: [com.example.demo.EmbeddedId.VipCustomerWithEmbedId#component[unitId,versionId]{versionId=987, unitId=654}]
2023-01-19 12:34:16.900 TRACE 82130 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Processing unreferenced collections
2023-01-19 12:34:16.900 TRACE 82130 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Scheduling collection removes/(re)creates/updates
2023-01-19 12:34:16.900 DEBUG 82130 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushed: 0 insertions, 1 updates, 0 deletions to 1 objects
2023-01-19 12:34:16.900 DEBUG 82130 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2023-01-19 12:34:16.900 DEBUG 82130 --- [           main] o.hibernate.internal.util.EntityPrinter  : Listing entities:
2023-01-19 12:34:16.900 DEBUG 82130 --- [           main] o.hibernate.internal.util.EntityPrinter  : com.example.demo.EmbeddedId.VipCustomerWithEmbedId{firstName=a, lastName=b, customerPK=component[unitId,versionId]{versionId=987, unitId=654}, vipNumber=999}
2023-01-19 12:34:16.900 TRACE 82130 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Executing flush
2023-01-19 12:34:16.900 DEBUG 82130 --- [           main] org.hibernate.SQL                        : update customer_with_embedded_id set first_name=?, last_name=?, vip_number=? where unit_id=? and version_id=?
Hibernate: update customer_with_embedded_id set first_name=?, last_name=?, vip_number=? where unit_id=? and version_id=?
2023-01-19 12:34:16.900 TRACE 82130 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [a]
2023-01-19 12:34:16.900 TRACE 82130 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [2] as [VARCHAR] - [b]
2023-01-19 12:34:16.900 TRACE 82130 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [3] as [VARCHAR] - [999]
2023-01-19 12:34:16.900 TRACE 82130 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [4] as [BIGINT] - [654]
2023-01-19 12:34:16.900 TRACE 82130 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [5] as [BIGINT] - [987]
2023-01-19 12:34:16.911 TRACE 82130 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Post flush
2023-01-19 12:34:16.917 TRACE 82130 --- [           main] org.hibernate.internal.SessionImpl       : SessionImpl#afterTransactionCompletion(successful=true, delayed=false)
2023-01-19 12:34:16.919 TRACE 82130 --- [           main] org.hibernate.internal.SessionImpl       : Closing session [6211a808-9faa-4f5f-9c05-7c59c946bb27]

ThomHurks · 2023-01-23T03:17:09Z

I seem to also have this issue, or a very similar one. I'm using Spring Boot 2.7.6 and its respective Spring Data JPA/Hibernate versions. I replicated exactly the blogpost by Vlad Mihalcea on using @EmbeddedId and @Embedded to create a compound primary key on a many-to-many table entity, and it gives me the following exception when calling postRepository.save():
"org.springframework.dao.DataIntegrityViolationException: A different object with the same identifier value was already associated with the session : [PostTag#PostTagId[postId=47,tagId=5]];"

Vlad's blogpost with the code is here: https://vladmihalcea.com/the-best-way-to-map-a-many-to-many-association-with-extra-columns-when-using-jpa-and-hibernate/

I thought I was going crazy as I double-checked if the code was identical a thousand times and could not figure out why it didn't work. It seems it may be a Spring Data JPA bug then.

If I can assist with replicating the bug, I'll gladly help!

The workaround I found for now is to remove one side of the many-to-many relationship, so only have it present on Post, for example, but not on Tag. That seems to prevent the exception, but is not ideal in case you would like to use the relation from both entities.

schauder · 2023-01-24T08:34:15Z

@ThomHurks When the many-to-many relationship is essential for your issue, it seem to be a different issue, since the original has no such relationship.

Please create a separate issue and provide a reproducer.

ThomHurks · 2023-01-24T09:25:55Z

@schauder Okay, will do.

schauder · 2023-01-24T09:36:10Z

I took a look at the reproducer.
Nice work.
But I get a different conclusion than @gregturn

Did you notice there are different exceptions thrown?

When running without transactions in Hibernate we get javax.persistence.TransactionRequiredException: No EntityManager with actual transaction available for current thread - cannot reliably process 'merge' call which I guess is to be expected.
The Spring Data variant never really runs without transaction since the individual repository call is always wrapped in a transaction. I call this "inner transaction".

These inner transactions trigger the error.

Interestingly Hibernate shows the same behaviour with the "Handrolled" transaction, i.e. a transaction implemented using the JPA API.

So currently we don't really reproduce the same scenario with Hibernate, since we have no tests with "inner transaction", but since we see the same behaviour with the handrolled transaction I'm still thinking this is a Hibernate issue.

I put the test results in a spread sheet:
https://docs.google.com/spreadsheets/d/1h9icBwPhjHSzimxw-KRvv722NzvE_73dyUazNGiGMvM/edit?usp=sharing

schauder · 2023-01-24T10:20:31Z

Ok, the duplicate key with hand rolled transaction was due to stuff left in the database from previous tests.
Still we don't test with inner transactions.

I created a PR with inner transactions: gregturn/spring-data-jpa-id-class-issues#1

With these the Hibernate behaviour matches that of Spring Data.
I therefore consider this a Hibernate issue.

Therefore closing this issue.

ThomHurks · 2023-01-24T11:16:10Z

@schauder I created an issue and reproduction case for my issue here: #2776

matera-jhb · 2024-10-21T11:58:38Z

Hi everyone,

I made some tests using the repo with Spring 3.x and the bug does not appear.

For someone that needs a composite IdClass and persistence with more than one transaction aspect, mabe is alternative.

spring-projects-issues added the status: waiting-for-triage An issue we've not yet triaged label Jan 17, 2023

mp911de assigned schauder Jan 23, 2023

schauder closed this as not planned Won't fix, can't repro, duplicate, stale Jan 24, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

JPA / Hibernate, duplicate pkey error when updating entity that is a subclass of a base class that uses IdClass for composite primary key #2767

JPA / Hibernate, duplicate pkey error when updating entity that is a subclass of a base class that uses IdClass for composite primary key #2767

cuipengfei commented Jan 17, 2023 •

edited

Loading

gregturn commented Jan 17, 2023 •

edited

Loading

gregturn commented Jan 17, 2023

gregturn commented Jan 17, 2023

cuipengfei commented Jan 18, 2023

schauder commented Jan 18, 2023

gregturn commented Jan 18, 2023

gregturn commented Jan 18, 2023 •

edited

Loading

gregturn commented Jan 18, 2023

gregturn commented Jan 19, 2023

gregturn commented Jan 19, 2023

ThomHurks commented Jan 23, 2023 •

edited

Loading

schauder commented Jan 24, 2023

ThomHurks commented Jan 24, 2023

schauder commented Jan 24, 2023

schauder commented Jan 24, 2023

ThomHurks commented Jan 24, 2023

matera-jhb commented Oct 21, 2024

JPA / Hibernate, duplicate pkey error when updating entity that is a subclass of a base class that uses IdClass for composite primary key #2767

JPA / Hibernate, duplicate pkey error when updating entity that is a subclass of a base class that uses IdClass for composite primary key #2767

Comments

cuipengfei commented Jan 17, 2023 • edited Loading

How to reproduce this issue

Issue Description

The Error

The question

links

gregturn commented Jan 17, 2023 • edited Loading

gregturn commented Jan 17, 2023

gregturn commented Jan 17, 2023

cuipengfei commented Jan 18, 2023

schauder commented Jan 18, 2023

gregturn commented Jan 18, 2023

gregturn commented Jan 18, 2023 • edited Loading

gregturn commented Jan 18, 2023

gregturn commented Jan 19, 2023

gregturn commented Jan 19, 2023

ThomHurks commented Jan 23, 2023 • edited Loading

schauder commented Jan 24, 2023

ThomHurks commented Jan 24, 2023

schauder commented Jan 24, 2023

schauder commented Jan 24, 2023

ThomHurks commented Jan 24, 2023

matera-jhb commented Oct 21, 2024

cuipengfei commented Jan 17, 2023 •

edited

Loading

gregturn commented Jan 17, 2023 •

edited

Loading

gregturn commented Jan 18, 2023 •

edited

Loading

ThomHurks commented Jan 23, 2023 •

edited

Loading