Menu

#4084 HTTP Status 500 - javax.servlet.ServletException: org.springframework.orm.hibernate3.HibernateOptimisticLockingFailureException while saving encounter note

OSCAR Main Trunk
open
nobody
None
5
2015-09-07
2015-09-07
Tan
No

Using the old UI Echart + RELEASE_15_BETA on production

Two times last week, when saving the encounter note and I have the error below appears after pressing 'sign & save' the encounter note.
When I reopen the encounter note, the note is signed and saved but the draft note does reappear again.

This intermittent error can be reproduced more easily but not all the time by changing the autoSaveTimer (auto save of the encounter note) from 30000ms to 500ms.

The general log of MySQL on my test server give the rollback right after delete from casemgmt_tmpsave where id=229681
6 Query SET autocommit=0
6 Query select casemanage0_.id as id65_, casemanage0_.demographic_no as demograp2_65_, casemanage0_.note as note65_, casemanage0_.note_id as note4_65_, casemanage0_.program_id as program5_65_, casemanage0_.provider_no as provider6_65_, casemanage0_.update_date as update7_65_ from casemgmt_tmpsave casemanage0_ where casemanage0_.provider_no='123456' and casemanage0_.demographic_no=1 and casemanage0_.program_id=10016
6 Query delete from casemgmt_tmpsave where id=229681
6 Query commit
....
14 Query select casemanage0_.id as id65_, casemanage0_.demographic_no as demograp2_65_, casemanage0_.note as note65_, casemanage0_.note_id as note4_65_, casemanage0_.program_id as program5_65_, casemanage0_.provider_no as provider6_65_, casemanage0_.update_date as update7_65_ from casemgmt_tmpsave casemanage0_ where casemanage0_.provider_no='123456' and casemanage0_.demographic_no=1 and casemanage0_.program_id=10016
14 Query delete from casemgmt_tmpsave where id=229681
14 Query rollback
14 Query SET autocommit=1

I think this can happen due to multiple threads accessing/deleting the same objects at the same time.

Clearing the autoSaveTimer just before saving the note seems to resolve the error.

I will submit for review.


HTTP Status 500 - javax.servlet.ServletException: org.springframework.orm.hibernate3.HibernateOptimisticLockingFailureException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1; nested exception is org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1

type Exception report

message javax.servlet.ServletException: org.springframework.orm.hibernate3.HibernateOptimisticLockingFailureException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1; nested exception is org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1

description The server encountered an internal error that prevented it from fulfilling this request.

exception

javax.servlet.ServletException: javax.servlet.ServletException: org.springframework.orm.hibernate3.HibernateOptimisticLockingFailureException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1; nested exception is org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1
org.oscarehr.util.DbConnectionFilter.doFilter(DbConnectionFilter.java:69)
org.oscarehr.common.printing.PrivacyStatementAppendingFilter.doFilter(PrivacyStatementAppendingFilter.java:118)
org.oscarehr.util.ProblemCheckFilter.doFilter(ProblemCheckFilter.java:194)
org.oscarehr.util.ResponseDefaultsFilter.doFilter(ResponseDefaultsFilter.java:109)
net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:198)
net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:176)

root cause

javax.servlet.ServletException: org.springframework.orm.hibernate3.HibernateOptimisticLockingFailureException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1; nested exception is org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1
org.apache.struts.action.RequestProcessor.processException(RequestProcessor.java:523)
org.apache.struts.action.RequestProcessor.processActionPerform(RequestProcessor.java:421)
org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:224)
org.apache.struts.action.ActionServlet.process(ActionServlet.java:1194)
org.apache.struts.action.ActionServlet.doPost(ActionServlet.java:432)
javax.servlet.http.HttpServlet.service(HttpServlet.java:650)
javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:160)
oscar.oscarSecurity.LoginFilter.doFilter(LoginFilter.java:198)
net.sf.cookierevolver.servlet.CRFilterImpl.doFilter(CRFilterImpl.java:60)
org.displaytag.filter.ResponseOverrideFilter.doFilter(ResponseOverrideFilter.java:125)
org.oscarehr.util.LoggedInUserFilter.doFilter(LoggedInUserFilter.java:56)
org.oscarehr.util.DbConnectionFilter.doFilter(DbConnectionFilter.java:66)
org.oscarehr.common.printing.PrivacyStatementAppendingFilter.doFilter(PrivacyStatementAppendingFilter.java:118)
org.oscarehr.util.ProblemCheckFilter.doFilter(ProblemCheckFilter.java:194)
org.oscarehr.util.ResponseDefaultsFilter.doFilter(ResponseDefaultsFilter.java:109)
net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:198)
net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:176)

root cause

org.springframework.orm.hibernate3.HibernateOptimisticLockingFailureException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1; nested exception is org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1
org.springframework.orm.hibernate3.SessionFactoryUtils.convertHibernateAccessException(SessionFactoryUtils.java:679)
org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:104)
org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:516)
org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:754)
org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:723)
org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:393)
org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:120)
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:622)
org.oscarehr.casemgmt.service.CaseManagementManager$$EnhancerByCGLIB$$e683822b.saveCaseManagementNote(<generated>)
org.oscarehr.casemgmt.web.CaseManagementEntryAction.noteSave(CaseManagementEntryAction.java:1425)
org.oscarehr.casemgmt.web.CaseManagementEntryAction.saveAndExit(CaseManagementEntryAction.java:1910)
sun.reflect.GeneratedMethodAccessor3318.invoke(Unknown Source)
java.lang.reflect.Method.invoke(Method.java:606)
org.apache.struts.actions.DispatchAction.dispatchMethod(DispatchAction.java:274)
org.apache.struts.actions.DispatchAction.execute(DispatchAction.java:194)
org.springframework.web.struts.DelegatingActionProxy.execute(DelegatingActionProxy.java:110)
org.apache.struts.action.RequestProcessor.processActionPerform(RequestProcessor.java:419)
org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:224)
org.apache.struts.action.ActionServlet.process(ActionServlet.java:1194)
org.apache.struts.action.ActionServlet.doPost(ActionServlet.java:432)
javax.servlet.http.HttpServlet.service(HttpServlet.java:650)
javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:160)
oscar.oscarSecurity.LoginFilter.doFilter(LoginFilter.java:198)
net.sf.cookierevolver.servlet.CRFilterImpl.doFilter(CRFilterImpl.java:60)
org.displaytag.filter.ResponseOverrideFilter.doFilter(ResponseOverrideFilter.java:125)
org.oscarehr.util.LoggedInUserFilter.doFilter(LoggedInUserFilter.java:56)
org.oscarehr.util.DbConnectionFilter.doFilter(DbConnectionFilter.java:66)
org.oscarehr.common.printing.PrivacyStatementAppendingFilter.doFilter(PrivacyStatementAppendingFilter.java:118)
org.oscarehr.util.ProblemCheckFilter.doFilter(ProblemCheckFilter.java:194)
org.oscarehr.util.ResponseDefaultsFilter.doFilter(ResponseDefaultsFilter.java:109)
net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:198)
net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:176)</generated>

root cause

org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1
org.hibernate.jdbc.Expectations$BasicExpectation.checkBatched(Expectations.java:85)
org.hibernate.jdbc.Expectations$BasicExpectation.verifyOutcome(Expectations.java:70)
org.hibernate.jdbc.BatchingBatcher.checkRowCounts(BatchingBatcher.java:90)
org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:70)
org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:268)
org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:266)
org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:172)
org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)
org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:50)
org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1027)
org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:365)
org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:137)
org.hibernate.ejb.TransactionImpl.commit(TransactionImpl.java:54)
org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:512)
org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:754)
org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:723)
org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:393)
org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:120)
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:622)
org.oscarehr.casemgmt.service.CaseManagementManager$$EnhancerByCGLIB$$e683822b.saveCaseManagementNote(<generated>)
org.oscarehr.casemgmt.web.CaseManagementEntryAction.noteSave(CaseManagementEntryAction.java:1425)
org.oscarehr.casemgmt.web.CaseManagementEntryAction.saveAndExit(CaseManagementEntryAction.java:1910)
sun.reflect.GeneratedMethodAccessor3318.invoke(Unknown Source)
java.lang.reflect.Method.invoke(Method.java:606)
org.apache.struts.actions.DispatchAction.dispatchMethod(DispatchAction.java:274)
org.apache.struts.actions.DispatchAction.execute(DispatchAction.java:194)
org.springframework.web.struts.DelegatingActionProxy.execute(DelegatingActionProxy.java:110)
org.apache.struts.action.RequestProcessor.processActionPerform(RequestProcessor.java:419)
org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:224)
org.apache.struts.action.ActionServlet.process(ActionServlet.java:1194)
org.apache.struts.action.ActionServlet.doPost(ActionServlet.java:432)
javax.servlet.http.HttpServlet.service(HttpServlet.java:650)
javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:160)
oscar.oscarSecurity.LoginFilter.doFilter(LoginFilter.java:198)
net.sf.cookierevolver.servlet.CRFilterImpl.doFilter(CRFilterImpl.java:60)
org.displaytag.filter.ResponseOverrideFilter.doFilter(ResponseOverrideFilter.java:125)
org.oscarehr.util.LoggedInUserFilter.doFilter(LoggedInUserFilter.java:56)
org.oscarehr.util.DbConnectionFilter.doFilter(DbConnectionFilter.java:66)
org.oscarehr.common.printing.PrivacyStatementAppendingFilter.doFilter(PrivacyStatementAppendingFilter.java:118)
org.oscarehr.util.ProblemCheckFilter.doFilter(ProblemCheckFilter.java:194)
org.oscarehr.util.ResponseDefaultsFilter.doFilter(ResponseDefaultsFilter.java:109)
net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:198)
net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:176)</generated>

Discussion

MongoDB Logo MongoDB