How to avoid optimistic locking failure exception during ajax periodic calls in grails?

Question

I have a simple function in MessageController that is called by the mail compose page every 1 second using ajax call. It is a simple function to periodically save the message draft so that the message written by the user is not lost if something happens like crash or accidental redirect to other pages.

The method is as follows

def saveDraft(){

        if (request.xhr) {

            def event_only = params['event_only'].toBoolean()
            def event_id = params['event_id'].toLong()

            def event

            if(event_only) {
                event = CompositeEvent.get(event_id)
            }


            EventEmailDraft.withTransaction {


                def user = User.get(springSecurityService.principal.id)

                def draft

                if(event_only){
                    draft = EventEmailDraft.findByEvent(event)
                }
                else{
                    draft = MassEmailDraft.findByUser(user)
                }


                if(draft) {
                    draft.subject = params['subject']
                    draft.body = params['body']
                    draft.emails = params['add_emails']

                    draft.save()
                }

                render "ok"
            }

        }
        else{
            render "invalid"
        }


    }

In the logs once in a while I am seeing this error message. The pointed line for the error is Line 93 which is

    EventEmailDraft.withTransaction {

I don't know how to mitigate it since I cannot recreate it every time. It only appears sometimes in the logs. What can I try next?

I am using Grails 4.0.10 app.

2023-08-04 06:14:53.790 ERROR --- [io-8080-exec-12] StackTrace                               : Full Stack Trace:

org.springframework.orm.hibernate5.HibernateOptimisticLockingFailureException: Object of class [com.company.EventEmailDraft] with identifier [334]: optimistic locking failed; nested exception is org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect) : [com.company.EventEmailDraft#334]
    at org.springframework.orm.hibernate5.SessionFactoryUtils.convertHibernateAccessException(SessionFactoryUtils.java:284)
    at org.springframework.orm.hibernate5.HibernateTransactionManager.convertHibernateAccessException(HibernateTransactionManager.java:802)
    at org.springframework.orm.hibernate5.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:638)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:746)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:714)
    at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:152)
    at grails.gorm.transactions.GrailsTransactionTemplate.execute(GrailsTransactionTemplate.groovy:91)
    at org.grails.datastore.gorm.GormStaticApi.withTransaction(GormStaticApi.groovy:1014)
    at org.grails.datastore.gorm.GormStaticApi.withTransaction(GormStaticApi.groovy:877)
    at org.grails.datastore.gorm.GormEntity$Trait$Helper.withTransaction(GormEntity.groovy:941)
    at org.grails.datastore.gorm.GormEntity$Trait$Helper$withTransaction$2.call(Unknown Source)
    at com.company.EventEmailDraft.withTransaction(EventEmailDraft.groovy)
    at com.company.EventEmailDraft$withTransaction$0.call(Unknown Source)
    at com.company.MessageController.saveDraft(MessageController.groovy:93)
    at org.grails.core.DefaultGrailsControllerClass$MethodHandleInvoker.invoke(DefaultGrailsControllerClass.java:223)
    at org.grails.core.DefaultGrailsControllerClass.invoke(DefaultGrailsControllerClass.java:188)
    at org.grails.web.mapping.mvc.UrlMappingsInfoHandlerAdapter.handle(UrlMappingsInfoHandlerAdapter.groovy:90)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:909)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:652)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:733)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.boot.actuate.web.trace.servlet.HttpTraceFilter.doFilterInternal(HttpTraceFilter.java:88)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:320)
    at org.springframework.security.web.authentication.switchuser.SwitchUserFilter.doFilter(SwitchUserFilter.java:200)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:127)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:91)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:119)
    at grails.plugin.springsecurity.web.UpdateRequestContextHolderExceptionTranslationFilter.doFilter(UpdateRequestContextHolderExceptionTranslationFilter.groovy:64)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at grails.plugin.springsecurity.web.filter.GrailsAnonymousAuthenticationFilter.doFilter(GrailsAnonymousAuthenticationFilter.groovy:54)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.authentication.rememberme.RememberMeAuthenticationFilter.doFilter(RememberMeAuthenticationFilter.java:158)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:170)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:200)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    ... 
    at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:747)
    at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:690)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:374)
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1590)
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect) : [com.company.EventEmailDraft#334]
    at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:2604)
    at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3448)
    at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:3311)
    at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3723)
    at org.hibernate.action.internal.EntityUpdateAction.execute(EntityUpdateAction.java:201)
    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:684)
    at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:475)
    at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:348)
    at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:40)
    at org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:102)
    at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1360)
    at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:451)
    at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3210)
    at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2378)
    at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:447)
    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.hibernate5.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:626)
    ... 99 common frames omitted

chubbsondubs · Accepted Answer · 2023-08-16T22:19:10.267

I think it might be a multi-threading issue where 2 threads are trying to run this method at the same time. Because you have such a small period of 1 second if one thread lags a little bit it could cause the browser to run 2 saves at the same time.

If you get into a situation where the 1st thread loads the email, and the 2nd thread loads the email, then the 1st thread saves it. That will cause the 2nd thread to blow up with this. Some very careful logging statements would help you identify if you had that situation. Add logging statements after the email is loaded, and after the save. Then if you have your log4j configuration setup to log the thread name you can check the logs after reproducing it and see if you see 2 threads running at the same time.

If you have multiple servers running you might have to check timestamps to know if they are running at the same time.

The simplest fix might be to turn down your period to something less frequent thus lowering your chance of encountering concurrency issues.
The other option is to just trap the error and move on. If you encounter an optimistic locking it just means someone else has already updated it to the latest version. So just give up. It's saved.
Make the front end smarter, while you can check frequently (say 1s) you don't have to call the server if nothing has changed. Set a flag for when someone changes the email. In your timer check to see if the flag is set to true then only send the request to the server then. Clear the flag before you send the request just in case the user is typing and changing things while your server request is running.
Consider removing the poll, and replacing it with a de-bounced event handler. So in this case if someone modifies something you set a single run timer for 500ms, 1s, etc in the future. If you receive new events (say from someone typing fast) destroy any open timer and restart it. When the timer event handler runs send your server request to save. This helps eliminate sending hundreds of requests in response to user events which will be out of date from someone modifying it. Essentially it waits until someone pauses before it sends the save event and it won't cause things to back up. You also know that you are only saving what needs to be saved rather than potentially writing over and over even though nothing has changed.

This suggestions aren't mutually exclusive either. So you might choose to implement #2 and #4. #2 recovers for when two threads try to save the object simultaneous, and #4 to make that possibility less likely.

score 1 · Answer 2 · answered Aug 14 '23 at 16:22

All of the suggestions from @chubbsondubs are good ones, and probably more than sufficient for this situation. In case you run into this in a more complex situation, I'd suggest option 5: synchronization.

You can use a pattern like this to ensure a single thread at a time is accessing your object:

synchronized (someObject) {
    EventEmailDraft.withTransaction {
         // all of your code
    }
|

In this case, someObject might be event_id.intern() or something similar that will be (1) different for different uses (don't want a bottleneck preventing different people from working on different objects) but also (2) always the same object for the same use (not just the same String, but the actual same, in-memory, object).

Note that interning a string may be a naive approach here since that can eventually lead to too much memory consumption. Depending on your load you may need a more efficient approach.

You can also move the synchronization out into a service and call it with a closure if you are performing similar activity that all needs to be synchronized across multiple controllers/actions.

I had considered good old synchronization, BUT it only works if the threads are on the same box. If he had multiple servers then synchronization won't help; you'd be locking in separate VMs against different objects. That's why it's more scalable to skip synchronization altogether if you can help it. — chubbsondubs, Aug 16 '23 at 01:39
Definitely agree, it's not the first tool to use! But if it's necessary, FYI it's pretty simple to tie into hazelcast or redis locks (if you're using redisson, at least, not sure about other implementations) to scale horizontally. All that said...yeah I'd avoid it if at all possible! — Daniel, Aug 16 '23 at 14:42

How to avoid optimistic locking failure exception during ajax periodic calls in grails?

2 Answers2