search

MauroDataMapper / mdm-explorer

Apache License 2.0
0 stars 0 forks source link

Intermittent exception while browsing/selecting elements in Explorer #456

Closed joe-crawford closed 1 month ago

joe-crawford commented 1 month ago

Description

I've seen the following StaleStateException multiple times on an OpenID connect-related table when browsing and/or selecting elements in Explorer:

2024-09-25 13:31:05.121 ERROR --- [io-8080-exec-10] StackTrace                               : Full Stack Trace:

org.springframework.orm.hibernate5.HibernateOptimisticLockingFailureException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1; statement executed: update openidconnect.discovery_document set version=?, date_created=?, last_updated=?, path=?, token_endpoint=?, end_session_endpoint=?, userinfo_endpoint=?, created_by=?, authorization_endpoint=?, jwks_uri=?, issuer=? where id=? and version=?; nested exception is org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1; statement executed: update openidconnect.discovery_document set version=?, date_created=?, last_updated=?, path=?, token_endpoint=?, end_session_endpoint=?, userinfo_endpoint=?, created_by=?, authorization_endpoint=?, jwks_uri=?, issuer=? where id=? and version=?
    at org.springframework.orm.hibernate5.SessionFactoryUtils.convertHibernateAccessException(SessionFactoryUtils.java:254)
    at org.grails.orm.hibernate.GrailsHibernateTemplate.doExecute(GrailsHibernateTemplate.java:305)
    at org.grails.orm.hibernate.GrailsHibernateTemplate.execute(GrailsHibernateTemplate.java:241)
    at org.grails.orm.hibernate.GrailsHibernateTemplate.execute(GrailsHibernateTemplate.java:120)
    at org.grails.orm.hibernate.AbstractHibernateGormInstanceApi.performSave(AbstractHibernateGormInstanceApi.groovy:247)
    at org.grails.orm.hibernate.AbstractHibernateGormInstanceApi.save(AbstractHibernateGormInstanceApi.groovy:164)
    at org.grails.datastore.gorm.GormEntity$Trait$Helper.save(GormEntity.groovy:153)
    at uk.ac.ox.softeng.maurodatamapper.plugins.authentication.openid.connect.token.OpenidConnectTokenService.$tt__validateAndSave(OpenidConnectTokenService.groovy:69)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at grails.gorm.transactions.GrailsTransactionTemplate$2.doInTransaction(GrailsTransactionTemplate.groovy:94)
    at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140)
    at grails.gorm.transactions.GrailsTransactionTemplate.execute(GrailsTransactionTemplate.groovy:91)
    at uk.ac.ox.softeng.maurodatamapper.plugins.authentication.openid.connect.token.OpenidConnectTokenService.$tt__refreshToken(OpenidConnectTokenService.groovy:117)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at grails.gorm.transactions.GrailsTransactionTemplate$2.doInTransaction(GrailsTransactionTemplate.groovy:94)
    at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140)
    at grails.gorm.transactions.GrailsTransactionTemplate.execute(GrailsTransactionTemplate.groovy:91)
    at uk.ac.ox.softeng.maurodatamapper.plugins.authentication.openid.connect.token.OpenidConnectTokenService.$tt__refreshTokenBySessionId(OpenidConnectTokenService.groovy:84)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at grails.gorm.transactions.GrailsTransactionTemplate$2.doInTransaction(GrailsTransactionTemplate.groovy:94)
    at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140)
    at grails.gorm.transactions.GrailsTransactionTemplate.execute(GrailsTransactionTemplate.groovy:91)
    at uk.ac.ox.softeng.maurodatamapper.plugins.authentication.openid.connect.access.OpenidConnectAccessInterceptor.before(OpenidConnectAccessInterceptor.groovy:70)
    at org.grails.plugins.web.interceptors.GrailsInterceptorHandlerInterceptorAdapter.preHandle(GrailsInterceptorHandlerInterceptorAdapter.groovy:77)
    at org.springframework.web.servlet.HandlerExecutionChain.applyPreHandle(HandlerExecutionChain.java:148)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1066)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:964)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:909)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
    at org.grails.web.servlet.mvc.GrailsWebRequestFilter.doFilterInternal(GrailsWebRequestFilter.java:77)
    at org.grails.web.filters.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:67)
    at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1; statement executed: update openidconnect.discovery_document set version=?, date_created=?, last_updated=?, path=?, token_endpoint=?, end_session_endpoint=?, userinfo_endpoint=?, created_by=?, authorization_endpoint=?, jwks_uri=?, issuer=? where id=? and version=?
    at org.hibernate.jdbc.Expectations$BasicExpectation.checkBatched(Expectations.java:67)
    at org.hibernate.jdbc.Expectations$BasicExpectation.verifyOutcome(Expectations.java:54)
    at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.checkRowCounts(BatchingBatch.java:155)
    at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:130)
    at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.doExecuteBatch(BatchingBatch.java:110)
    at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.execute(AbstractBatchImpl.java:153)
    at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.getBatch(JdbcCoordinatorImpl.java:187)
    at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3513)
    at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:3438)
    at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3870)
    at org.hibernate.action.internal.EntityUpdateAction.execute(EntityUpdateAction.java:202)
    at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604)
    at org.hibernate.engine.spi.ActionQueue.lambda$executeActions$1(ActionQueue.java:478)
    at java.base/java.util.LinkedHashMap.forEach(LinkedHashMap.java:721)
    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.flush(SessionImpl.java:1394)
    at org.grails.orm.hibernate.AbstractHibernateGormInstanceApi.flushSession(AbstractHibernateGormInstanceApi.groovy:285)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at org.grails.orm.hibernate.AbstractHibernateGormInstanceApi$_performSave_closure3.doCall(AbstractHibernateGormInstanceApi.groovy:250)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at org.grails.orm.hibernate.GrailsHibernateTemplate.doExecute(GrailsHibernateTemplate.java:297)
    ... 34 common frames omitted

Expected behavior

We should investigate and debug and find a way to avoid StaleStateExceptions on OpenID Connect-authenticated requests.

Environment

latest develop of mdm-explorer, mdm-plugin-explorer

joe-crawford commented 1 month ago

Observation:

When selecting a new element and adding it to a request in Explorer, the version value on openidconnect.discovery_document increases by 1.

joe-crawford commented 1 month ago

Relevant message that appears near a StaleStateException:

2024-09-25 16:57:18.836 DEBUG --- [nio-8080-exec-3] p.a.o.c.a.OpenidConnectAccessInterceptor : Token has been refreshed and saved
joe-crawford commented 1 month ago

Added a PR at https://github.com/MauroDataMapper-Plugins/mdm-plugin-authentication-openid-connect/pull/27 which should resolve this.