[JIRA] (HHH-13926) StaleStateException message should not contain SQL parameters
by Mickaël TRICOT (JIRA)
Mickaël TRICOT ( https://hibernate.atlassian.net/secure/ViewProfile.jspa?accountId=557058%... ) *updated* an issue
Hibernate ORM ( https://hibernate.atlassian.net/browse/HHH?atlOrigin=eyJpIjoiZjUxNmZlZTcy... ) / Bug ( https://hibernate.atlassian.net/browse/HHH-13926?atlOrigin=eyJpIjoiZjUxNm... ) HHH-13926 ( https://hibernate.atlassian.net/browse/HHH-13926?atlOrigin=eyJpIjoiZjUxNm... ) StaleStateException message should not contain SQL parameters ( https://hibernate.atlassian.net/browse/HHH-13926?atlOrigin=eyJpIjoiZjUxNm... )
Change By: Mickaël TRICOT ( https://hibernate.atlassian.net/secure/ViewProfile.jspa?accountId=557058%... )
When a StaleStateException is raised, SQL parameters are always added to the exception message. As a result, sensible data may leak in the logs, without any option to turn it off (apart from hiding the exceptions, which does not sound like a good option)
{noformat}13:52:46.834 [ForkJoinPool.commonPool-worker-3] ERROR o.h.e.j.batch.internal.BatchingBatch - HHH000315: Exception executing batch [org.hibernate.StaleStateException: Batch update returned unexpected row count from update [1]; actual row count: 0; expected: 1; statement executed: HikariProxyPreparedStatement@1522577332 wrapping update patient set city='Gotham', country='US', line='Manoir Wayne', postal_code='12000', birth_date='1964-03-12 +00', email='batman(a)goth.com', family_name_official='Wayne', family_name_usual=NULL, first_name='Bruce', gender='male', last_crm_update='2020-04-03 13:52:21.638307+00', last_modified='2020-04-03 13:42:06.158879+00', phone='06 01 01 01 05', version=2 where id='749863f8-f148-4f3b-90eb-35841a26e12f'::uuid and version=1], SQL: update patient set city=?, country=?, line=?, postal_code=?, birth_date=?, email=?, family_name_official=?, family_name_usual=?, first_name=?, gender=?, last_crm_update=?, last_modified=?, phone=?, version=? where id=? and version=?
13:52:46.847 [ForkJoinPool.commonPool-worker-3] ERROR c.s.s.backend.infra.job.JobDecorator - Job failed: AutoUpdateCrmAppointments
[1] org.springframework.orm.ObjectOptimisticLockingFailureException: Batch update returned unexpected row count from update [1]; actual row count: 0; expected: 1; statement executed: HikariProxyPreparedStatement@1522577332 wrapping update patient set city='Gotham', country='US', line='Manoir Wayne', postal_code='12000', birth_date='1964-03-12 +00', email='batman(a)goth.com', family_name_official='Wayne', family_name_usual=NULL, first_name='Bruce', gender='male', last_crm_update='2020-04-03 13:52:21.638307+00', last_modified='2020-04-03 13:42:06.158879+00', phone='06 01 01 01 05', version=2 where id='749863f8-f148-4f3b-90eb-35841a26e12f'::uuid and version=1; nested exception is org.hibernate.StaleStateException: Batch update returned unexpected row count from update [1]; actual row count: 0; expected: 1; statement executed: HikariProxyPreparedStatement@1522577332 wrapping update patient set city='Gotham', country='US', line='Manoir Wayne', postal_code='12000', birth_date='1964-03-12 +00', email='batman(a)goth.com', family_name_official='Wayne', family_name_usual=NULL, first_name='Bruce', gender='male', last_crm_update='2020-04-03 13:52:21.638307+00', last_modified='2020-04-03 13:42:06.158879+00', phone='06 01 01 01 05', version=2 where id='749863f8-f148-4f3b-90eb-35841a26e12f'::uuid and version=1
[1] at org.springframework.orm.jpa.vendor.HibernateJpaDialect.convertHibernateAccessException(HibernateJpaDialect.java:340)
[1] at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:255)
[1] at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:538)
[1] at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:743)
[1] at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:711)
[1] at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:631)
[1] at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:385)
[1] at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:118)
[1] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
[1] at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749)
[1] at net.javacrumbs.shedlock.core.DefaultLockingTaskExecutor.executeWithLock(DefaultLockingTaskExecutor.java:73)
[1] at net.javacrumbs.shedlock.spring.aop.MethodProxyScheduledLockAdvisor$LockingInterceptor.invoke(MethodProxyScheduledLockAdvisor.java:85)
[1] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
[1] at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749)
[1] at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:691)
[1] at c.s.s.backend.use_cases.crm.AutoUpdateCrmAppointments$$EnhancerBySpringCGLIB$$3cbc2df0.perform(<generated>)
[1] at c.s.s.backend.infra.job.JobDecorator.run(JobDecorator.java:35)
[1] at c.s.s.backend.infra.job.RunAsyncJob.lambda$perform$0(RunAsyncJob.java:13)
[1] at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1800)
[1] at java.base/java.util.concurrent.CompletableFuture$AsyncRun.exec(CompletableFuture.java:1792)
[1] at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290)
[1] at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1016)
[1] at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1665)
[1] at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1598)
[1] at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:177)
[1] Caused by: org.hibernate.StaleStateException: Batch update returned unexpected row count from update [1]; actual row count: 0; expected: 1; statement executed: HikariProxyPreparedStatement@1522577332 wrapping update patient set city='Gotham', country='US', line='Manoir Wayne', postal_code='12000', birth_date='1964-03-12 +00', email='batman(a)goth.com', family_name_official='Wayne', family_name_usual=NULL, first_name='Bruce', gender='male', last_crm_update='2020-04-03 13:52:21.638307+00', last_modified='2020-04-03 13:42:06.158879+00', phone='06 01 01 01 05', version=2 where id='749863f8-f148-4f3b-90eb-35841a26e12f'::uuid and version=1
[1] at org.hibernate.jdbc.Expectations$BasicExpectation.checkBatched(Expectations.java:67)
[1] at org.hibernate.jdbc.Expectations$BasicExpectation.verifyOutcome(Expectations.java:54)
[1] at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.checkRowCounts(BatchingBatch.java:149)
[1] at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:124)
[1] at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.doExecuteBatch(BatchingBatch.java:105)
[1] at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.execute(AbstractBatchImpl.java:148)
[1] at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.executeBatch(JdbcCoordinatorImpl.java:198)
[1] at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:633)
[1] at org.hibernate.engine.spi.ActionQueue.lambda$executeActions$1(ActionQueue.java:478)
[1] at java.base/java.util.LinkedHashMap.forEach(LinkedHashMap.java:723)
[1] at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:475)
[1] at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:348)
[1] at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:40)
[1] at org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:102)
[1] at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1352)
[1] at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:443)
[1] at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3202)
[1] at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2370)
[1] at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:447)
[1] at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:183)
[1] at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$300(JdbcResourceLocalTransactionCoordinatorImpl.java:40)
[1] at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:281)
[1] at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:101)
[1] at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:534)
[1] ... 22 common frames omitted{noformat}
Also see:
* [HHH-11082]
* [HHH-12878]
* [https://github.com/pgjdbc/pgjdbc/issues/1829|https://github.com/pgjdbc/pg...]
( https://hibernate.atlassian.net/browse/HHH-13926#add-comment?atlOrigin=ey... ) Add Comment ( https://hibernate.atlassian.net/browse/HHH-13926#add-comment?atlOrigin=ey... )
Get Jira notifications on your phone! Download the Jira Cloud app for Android ( https://play.google.com/store/apps/details?id=com.atlassian.android.jira.... ) or iOS ( https://itunes.apple.com/app/apple-store/id1006972087?pt=696495&ct=EmailN... ) This message was sent by Atlassian Jira (v1001.0.0-SNAPSHOT#100133- sha1:8ba02c9 )
3 years, 11 months
[JIRA] (HHH-13926) StaleStateException message should not contain SQL parameters
by Mickaël TRICOT (JIRA)
Mickaël TRICOT ( https://hibernate.atlassian.net/secure/ViewProfile.jspa?accountId=557058%... ) *updated* an issue
Hibernate ORM ( https://hibernate.atlassian.net/browse/HHH?atlOrigin=eyJpIjoiYTliZDI4ZTNj... ) / Bug ( https://hibernate.atlassian.net/browse/HHH-13926?atlOrigin=eyJpIjoiYTliZD... ) HHH-13926 ( https://hibernate.atlassian.net/browse/HHH-13926?atlOrigin=eyJpIjoiYTliZD... ) StaleStateException message should not contain SQL parameters ( https://hibernate.atlassian.net/browse/HHH-13926?atlOrigin=eyJpIjoiYTliZD... )
Change By: Mickaël TRICOT ( https://hibernate.atlassian.net/secure/ViewProfile.jspa?accountId=557058%... )
When a StaleStateException is raised, SQL parameters are always added to the exception message. As a result, sensible data may leak in the logs, without any option to turn it off (apart from hiding the exceptions, which does not sound like a good option)
{noformat}13:52:46.834 [ForkJoinPool.commonPool-worker-3] ERROR o.h.e.j.batch.internal.BatchingBatch - HHH000315: Exception executing batch [org.hibernate.StaleStateException: Batch update returned unexpected row count from update [1]; actual row count: 0; expected: 1; statement executed: HikariProxyPreparedStatement@1522577332 wrapping update patient set city='Gotham', country='US', line='Manoir Wayne', postal_code='12000', birth_date='1964-03-12 +00', email='batman(a)goth.com', family_name_official='Wayne', family_name_usual=NULL, first_name='Bruce', gender='male', last_crm_update='2020-04-03 13:52:21.638307+00', last_modified='2020-04-03 13:42:06.158879+00', phone='06 01 01 01 05', version=2 where id='749863f8-f148-4f3b-90eb-35841a26e12f'::uuid and version=1], SQL: update patient set city=?, country=?, line=?, postal_code=?, birth_date=?, email=?, family_name_official=?, family_name_usual=?, first_name=?, gender=?, last_crm_update=?, last_modified=?, phone=?, version=? where id=? and version=?
13:52:46.847 [ForkJoinPool.commonPool-worker-3] ERROR c.s.s.backend.infra.job.JobDecorator - Job failed: AutoUpdateCrmAppointments
[1] org.springframework.orm.ObjectOptimisticLockingFailureException: Batch update returned unexpected row count from update [1]; actual row count: 0; expected: 1; statement executed: HikariProxyPreparedStatement@1522577332 wrapping update patient set city='Gotham', country='US', line='Manoir Wayne', postal_code='12000', birth_date='1964-03-12 +00', email='batman(a)goth.com', family_name_official='Wayne', family_name_usual=NULL, first_name='Bruce', gender='male', last_crm_update='2020-04-03 13:52:21.638307+00', last_modified='2020-04-03 13:42:06.158879+00', phone='06 01 01 01 05', version=2 where id='749863f8-f148-4f3b-90eb-35841a26e12f'::uuid and version=1; nested exception is org.hibernate.StaleStateException: Batch update returned unexpected row count from update [1]; actual row count: 0; expected: 1; statement executed: HikariProxyPreparedStatement@1522577332 wrapping update patient set city='Gotham', country='US', line='Manoir Wayne', postal_code='12000', birth_date='1964-03-12 +00', email='batman(a)goth.com', family_name_official='Wayne', family_name_usual=NULL, first_name='Bruce', gender='male', last_crm_update='2020-04-03 13:52:21.638307+00', last_modified='2020-04-03 13:42:06.158879+00', phone='06 01 01 01 05', version=2 where id='749863f8-f148-4f3b-90eb-35841a26e12f'::uuid and version=1
[1] at org.springframework.orm.jpa.vendor.HibernateJpaDialect.convertHibernateAccessException(HibernateJpaDialect.java:340)
[1] at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:255)
[1] at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:538)
[1] at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:743)
[1] at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:711)
[1] at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:631)
[1] at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:385)
[1] at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:118)
[1] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
[1] at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749)
[1] at net.javacrumbs.shedlock.core.DefaultLockingTaskExecutor.executeWithLock(DefaultLockingTaskExecutor.java:73)
[1] at net.javacrumbs.shedlock.spring.aop.MethodProxyScheduledLockAdvisor$LockingInterceptor.invoke(MethodProxyScheduledLockAdvisor.java:85)
[1] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
[1] at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749)
[1] at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:691)
[1] at c.s.s.backend.use_cases.crm.AutoUpdateCrmAppointments$$EnhancerBySpringCGLIB$$3cbc2df0.perform(<generated>)
[1] at c.s.s. smc. backend.infra.job.JobDecorator.run(JobDecorator.java:35)
[1] at c.s.s.backend.infra.job.RunAsyncJob.lambda$perform$0(RunAsyncJob.java:13)
[1] at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1800)
[1] at java.base/java.util.concurrent.CompletableFuture$AsyncRun.exec(CompletableFuture.java:1792)
[1] at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290)
[1] at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1016)
[1] at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1665)
[1] at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1598)
[1] at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:177)
[1] Caused by: org.hibernate.StaleStateException: Batch update returned unexpected row count from update [1]; actual row count: 0; expected: 1; statement executed: HikariProxyPreparedStatement@1522577332 wrapping update patient set city='Gotham', country='US', line='Manoir Wayne', postal_code='12000', birth_date='1964-03-12 +00', email='batman(a)goth.com', family_name_official='Wayne', family_name_usual=NULL, first_name='Bruce', gender='male', last_crm_update='2020-04-03 13:52:21.638307+00', last_modified='2020-04-03 13:42:06.158879+00', phone='06 01 01 01 05', version=2 where id='749863f8-f148-4f3b-90eb-35841a26e12f'::uuid and version=1
[1] at org.hibernate.jdbc.Expectations$BasicExpectation.checkBatched(Expectations.java:67)
[1] at org.hibernate.jdbc.Expectations$BasicExpectation.verifyOutcome(Expectations.java:54)
[1] at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.checkRowCounts(BatchingBatch.java:149)
[1] at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:124)
[1] at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.doExecuteBatch(BatchingBatch.java:105)
[1] at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.execute(AbstractBatchImpl.java:148)
[1] at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.executeBatch(JdbcCoordinatorImpl.java:198)
[1] at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:633)
[1] at org.hibernate.engine.spi.ActionQueue.lambda$executeActions$1(ActionQueue.java:478)
[1] at java.base/java.util.LinkedHashMap.forEach(LinkedHashMap.java:723)
[1] at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:475)
[1] at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:348)
[1] at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:40)
[1] at org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:102)
[1] at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1352)
[1] at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:443)
[1] at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3202)
[1] at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2370)
[1] at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:447)
[1] at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:183)
[1] at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$300(JdbcResourceLocalTransactionCoordinatorImpl.java:40)
[1] at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:281)
[1] at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:101)
[1] at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:534)
[1] ... 22 common frames omitted{noformat}
Also see: [HHH-11082] [HHH-12878]
( https://hibernate.atlassian.net/browse/HHH-13926#add-comment?atlOrigin=ey... ) Add Comment ( https://hibernate.atlassian.net/browse/HHH-13926#add-comment?atlOrigin=ey... )
Get Jira notifications on your phone! Download the Jira Cloud app for Android ( https://play.google.com/store/apps/details?id=com.atlassian.android.jira.... ) or iOS ( https://itunes.apple.com/app/apple-store/id1006972087?pt=696495&ct=EmailN... ) This message was sent by Atlassian Jira (v1001.0.0-SNAPSHOT#100133- sha1:8ba02c9 )
3 years, 11 months