Multitenant configuration: StaleObjectStateException on Transaction (hibernate + spring-data-jpa)

i'm trying to setup a configuration for manage a multi-tenant enviroment with spring-boot, spring-data-jpa, hibernate and mysql (same schema, every tenant table has a tenant_code column). For dependencies the parent maven project is spring-boot-starter-parent (2.1.2.RELEASE).

On save entity hibernate throws this exception: org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect) :

The highlights steps are:

  1. Intercept "tenant code" with custom spring HandlerInterceptorAdapter (i read oauth2 token and extract custom attribute "tenant code");
  2. Save "tenant code" in a @RequestScope bean; 

  3. On Save
  4. Define an custom hibernate EmptyInterceptor to intercept onSave action and previously set the "tenant code" (taken on a @RequestScope bean) 

  5. On Read
  6. In abstract Entity (extended by all my entities) i define @Filter and set it via AOP

If in interceptor i override onSave method i get this exception:

org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect) : [com.test.module.api.domain.entity.User#22]
    at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:2522) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
    at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3355) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
    at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:3229) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
    at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3630) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
    at org.hibernate.action.internal.EntityUpdateAction.execute(EntityUpdateAction.java:146) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
    at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
    at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:478) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
    at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:356) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
    at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
    at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1454) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
    at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:511) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
    at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3283) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
    at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2479) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
    at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:473) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
    at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:178) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
    at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$300(JdbcResourceLocalTransactionCoordinatorImpl.java:39) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
    at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:271) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
    at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:98) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
    at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:532) ~[spring-orm-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:746) ~[spring-tx-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:714) ~[spring-tx-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:533) ~[spring-tx-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:304) ~[spring-tx-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98) ~[spring-tx-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688) ~[spring-aop-5.1.4.RELEASE.jar:5.1.4.RELEASE]
    at com.test.module.api.service.UserServiceImpl$$EnhancerBySpringCGLIB$$baf4f87e.updateUser(<generated>) ~[classes/:na]
    at com.test.module.api.web.UserController.updateUser(UserController.java:38) ~[classes/:na]


Here the code: 

Spring Interceptor from Request Header:

    @Component
    public class TokenInterceptor extends HandlerInterceptorAdapter {
        public final String TENANT_CODE = "tenant_code";
    @Autowired
    private CurrentUser currentUser;

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler)
            throws Exception {
        String tenantCode = ... extract tenant code from request...;
        currentUser.setTenantCode(tenantCode);        
        return true;
    }
}


Class to setup inteceptor in hibernate:

    @Component
public class TenantHibernateInterceptorCustomizer implements HibernatePropertiesCustomizer {

    @Autowired
    private TenantJpaInterceptor jpaInterceptor;

    @Override
    public void customize(Map&lt;String, Object&gt; hibernateProperties) {
        hibernateProperties.put("hibernate.session_factory.interceptor", jpaInterceptor);
    }

}


Hibernate custom interceptor:

    @Component
public class TenantJpaInterceptor extends EmptyInterceptor {
//Comment to test if problem is about spring context
//@Autowired
//private CurrentUser currentUser;

    @Override
    public boolean onSave(Object entity, Serializable id, Object[] state, String[] propertyNames, Type[] types) {
        if (entity instanceof TenantAuditable) {
            //((TenantAuditable&lt;?&gt;) entity).setTenandCode(currentUser.getTenantCode());
            //if i comment this line everythings works (without tenant code)
            ((TenantAuditable&lt;?&gt;) entity).setTenandCode("TEST");            
        }
        return false;
    }
}


Service layer:

    @Transactional
public UpsertResponse<UserDto> updateUser(UserDto userDto) {
UpsertResponse<UserDto> validationResult = CommonValidators.validateUserDto(userDto);
if(!validationResult.isValidated()) {
return validationResult;

    SpUser user = userRepo.findById(userDto.getUserId()).orElse(new SpUser());
    userMapper.mapUserDtoToEntity(userDto, user);
    try {
        SpUser savedUser = userRepo.save(user);
        validationResult.setEntity(userMapper.mapUserDtoFromEntity(savedUser));
        validationResult.setValidated(true);
    }catch(Exception e) {
        e.printStackTrace();
        validationResult.setValidated(false);
        validationResult.setGlobalMessage(e.getLocalizedMessage());

    }
    return validationResult;
}

I expected a insert/update sql query with filled tenant_code field.


Here complete log

2019-01-22 01:10:57.521  INFO 14304 — [nio-8090-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet ‘dispatcherServlet’
2019-01-22 01:10:57.523 INFO 14304 — [nio-8090-exec-1] o.s.web.servlet.DispatcherServlet : Initializing Servlet ‘dispatcherServlet’
2019-01-22 01:10:57.550 INFO 14304 — [nio-8090-exec-1] o.s.web.servlet.DispatcherServlet : Completed initialization in 27 ms
Hibernate:
select
spuser0_.user_id as user_id1_0_0_,
spuser0_.created_by as created_2_0_0_,
spuser0_.created_date as created_3_0_0_,
spuser0_.last_modified_by as last_mod4_0_0_,
spuser0_.last_modified_date as last_mod5_0_0_,
spuser0_.tenant_code as tenant_c6_0_0_,
spuser0_.buyer_id as buyer_id7_0_0_,
spuser0_.email as email8_0_0_,
spuser0_.family_name as family_n9_0_0_,
spuser0_.given_name as given_n10_0_0_,
spuser0_.middle_name as middle_11_0_0_,
spuser0_.user_name as user_na12_0_0_
from
sp_user spuser0_
where
spuser0_.user_id=?
2019-01-22 01:11:10.689 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [1] as [BIGINT] - [2]
Hibernate:
select
spuser0_.user_id as user_id1_0_0_,
spuser0_.created_by as created_2_0_0_,
spuser0_.created_date as created_3_0_0_,
spuser0_.last_modified_by as last_mod4_0_0_,
spuser0_.last_modified_date as last_mod5_0_0_,
spuser0_.tenant_code as tenant_c6_0_0_,
spuser0_.buyer_id as buyer_id7_0_0_,
spuser0_.email as email8_0_0_,
spuser0_.family_name as family_n9_0_0_,
spuser0_.given_name as given_n10_0_0_,
spuser0_.middle_name as middle_11_0_0_,
spuser0_.user_name as user_na12_0_0_
from
sp_user spuser0_
where
spuser0_.user_id=?
2019-01-22 01:11:14.414 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [1] as [BIGINT] - [2]
Hibernate:
insert
into
sp_user
(created_by, created_date, last_modified_by, last_modified_date, tenant_code, buyer_id, email, family_name, given_name, middle_name, user_name)
values
(?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
2019-01-22 01:11:23.137 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [1] as [VARCHAR] - [3bf38f12-5d17-47e4-9504-ad0705289d10]
2019-01-22 01:11:23.138 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [2] as [TIMESTAMP] - [Tue Jan 22 01:11:14 CET 2019]
2019-01-22 01:11:23.140 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [3] as [VARCHAR] - [3bf38f12-5d17-47e4-9504-ad0705289d10]
2019-01-22 01:11:23.140 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [4] as [TIMESTAMP] - [Tue Jan 22 01:11:14 CET 2019]
2019-01-22 01:11:23.140 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [5] as [VARCHAR] - [null]
2019-01-22 01:11:23.140 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [6] as [VARCHAR] - [1]
2019-01-22 01:11:23.140 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [7] as [VARCHAR] - [gabriele.muscas@gmail.comx]
2019-01-22 01:11:23.140 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [8] as [VARCHAR] - [Muscas]
2019-01-22 01:11:23.140 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [9] as [VARCHAR] - [Gabrielex]
2019-01-22 01:11:23.141 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [10] as [VARCHAR] - [Giuseppe Pippo]
2019-01-22 01:11:23.141 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [11] as [VARCHAR] - [gabriele.muscas]
Hibernate:
update
sp_user
set
created_by=?,
created_date=?,
last_modified_by=?,
last_modified_date=?,
tenant_code=?,
buyer_id=?,
email=?,
family_name=?,
given_name=?,
middle_name=?,
user_name=?
where
user_id=?
2019-01-22 01:11:24.912 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [1] as [VARCHAR] - [3bf38f12-5d17-47e4-9504-ad0705289d10]
2019-01-22 01:11:24.912 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [2] as [TIMESTAMP] - [Tue Jan 22 01:11:14 CET 2019]
2019-01-22 01:11:24.913 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [3] as [VARCHAR] - [3bf38f12-5d17-47e4-9504-ad0705289d10]
2019-01-22 01:11:24.913 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [4] as [TIMESTAMP] - [Tue Jan 22 01:11:24 CET 2019]
2019-01-22 01:11:24.913 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [5] as [VARCHAR] - [PIPPO]
2019-01-22 01:11:24.913 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [6] as [VARCHAR] - [1]
2019-01-22 01:11:24.914 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [7] as [VARCHAR] - [gabriele.muscas@gmail.comx]
2019-01-22 01:11:24.914 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [8] as [VARCHAR] - [Muscas]
2019-01-22 01:11:24.914 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [9] as [VARCHAR] - [Gabrielex]
2019-01-22 01:11:24.915 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [10] as [VARCHAR] - [Giuseppe Pippo]
2019-01-22 01:11:24.915 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [11] as [VARCHAR] - [gabriele.muscas]
2019-01-22 01:11:24.915 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [12] as [BIGINT] - [23]
2019-01-22 01:11:24.918 ERROR 14304 — [nio-8090-exec-2] o.h.i.ExceptionMapperStandardImpl : HHH000346: Error during managed flush [Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect) : [com.supplhi.buyer.api.domain.entity.SpUser#23]]
Hibernate:
select
spuser0_.user_id as user_id1_0_0_,
spuser0_.created_by as created_2_0_0_,
spuser0_.created_date as created_3_0_0_,
spuser0_.last_modified_by as last_mod4_0_0_,
spuser0_.last_modified_date as last_mod5_0_0_,
spuser0_.tenant_code as tenant_c6_0_0_,
spuser0_.buyer_id as buyer_id7_0_0_,
spuser0_.email as email8_0_0_,
spuser0_.family_name as family_n9_0_0_,
spuser0_.given_name as given_n10_0_0_,
spuser0_.middle_name as middle_11_0_0_,
spuser0_.user_name as user_na12_0_0_
from
sp_user spuser0_
where
spuser0_.user_id=?
2019-01-22 01:11:24.928 TRACE 14304 — [nio-8090-exec-2] o.h.type.descriptor.sql.BasicBinder : binding parameter [1] as [BIGINT] - [23]
2019-01-22 01:11:24.940 ERROR 14304 — [nio-8090-exec-2] o.a.c.c.C.[.[.[/].[dispatcherServlet] : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is org.springframework.orm.ObjectOptimisticLockingFailureException: Object of class [com.supplhi.buyer.api.domain.entity.SpUser] with identifier [23]: optimistic locking failed; nested exception is org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect) : [com.supplhi.buyer.api.domain.entity.SpUser#23]] with root cause

org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect) : [com.supplhi.buyer.api.domain.entity.SpUser#23]
at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:2522) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3355) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:3229) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3630) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
at org.hibernate.action.internal.EntityUpdateAction.execute(EntityUpdateAction.java:146) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:478) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:356) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1454) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:511) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3283) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2479) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:473) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:178) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$300(JdbcResourceLocalTransactionCoordinatorImpl.java:39) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:271) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:98) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final]
at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:532) ~[spring-orm-5.1.4.RELEASE.jar:5.1.4.RELEASE]
at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:746) ~[spring-tx-5.1.4.RELEASE.jar:5.1.4.RELEASE]
at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:714) ~[spring-tx-5.1.4.RELEASE.jar:5.1.4.RELEASE]
at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:533) ~[spring-tx-5.1.4.RELEASE.jar:5.1.4.RELEASE]
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:304) ~[spring-tx-5.1.4.RELEASE.jar:5.1.4.RELEASE]
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98) ~[spring-tx-5.1.4.RELEASE.jar:5.1.4.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.1.4.RELEASE.jar:5.1.4.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688) ~[spring-aop-5.1.4.RELEASE.jar:5.1.4.RELEASE]
at com.supplhi.buyer.api.service.UserServiceImpl$$EnhancerBySpringCGLIB$$baf4f87e.updateUser(<generated>) ~[classes/:na]
at com.supplhi.buyer.api.web.UserController.updateUser(UserController.java:38) ~[classes/:na]

A little help, s’ll vous plaît. Thanks

#java #spring #hibernate #jpa

3 Likes33.45 GEEK