dataverse
dataverse copied to clipboard
Small Tabular File Publish OptimisticLockException
To reproduce: Create and publish a dataset (no content was used in testing). After publish, then upload a small tabular file (csv was used). Then click publish from the dataset page. In some cases, the timing will be such that clicking publish will trigger no action for the user and in the back-end an optimistic lock exception will be thrown.
The timing on this has been a bit hard to nail down but seems to happen more often when auxdata/metadata is attached to the tabular file. For example, prov and file descriptions.
When this issue takes place, refreshing the page allows publish to happen as normal. No data is lost from the error.
Connects to #4731, where the issue was originally found.
An example of the OptimisticLockException
[2018-06-04T12:52:39.657-0400] [glassfish 4.1] [SEVERE] [] [javax.enterprise.resource.webcontainer.jsf.context] [tid: _ThreadID=31 _ThreadName=http-listener-1(4)] [timeMillis: 1528131159657] [levelValue: 1000] [[
javax.faces.el.EvaluationException: javax.ejb.EJBException
at javax.faces.component.MethodBindingMethodExpressionAdapter.invoke(MethodBindingMethodExpressionAdapter.java:101)
at com.sun.faces.application.ActionListenerImpl.processAction(ActionListenerImpl.java:102)
at javax.faces.component.UICommand.broadcast(UICommand.java:315)
at javax.faces.component.UIViewRoot.broadcastEvents(UIViewRoot.java:790)
at javax.faces.component.UIViewRoot.processDecodes(UIViewRoot.java:931)
at com.sun.faces.lifecycle.ApplyRequestValuesPhase.execute(ApplyRequestValuesPhase.java:78)
at com.sun.faces.lifecycle.Phase.doPhase(Phase.java:101)
at com.sun.faces.lifecycle.LifecycleImpl.execute(LifecycleImpl.java:198)
at javax.faces.webapp.FacesServlet.service(FacesServlet.java:646)
at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1682)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:344)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:214)
at org.glassfish.tyrus.servlet.TyrusServletFilter.doFilter(TyrusServletFilter.java:295)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:256)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:214)
at org.ocpsoft.rewrite.servlet.RewriteFilter.doFilter(RewriteFilter.java:226)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:256)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:214)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:316)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:160)
at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:734)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:673)
at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:99)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:174)
at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:415)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:282)
at com.sun.enterprise.v3.services.impl.ContainerMapper$HttpHandlerCallable.call(ContainerMapper.java:459)
at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:167)
at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:201)
at org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:175)
at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:235)
at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:284)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:201)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:133)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:112)
at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:561)
at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:112)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:117)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:56)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:137)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:565)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:545)
at java.lang.Thread.run(Thread.java:748)
Caused by: javax.ejb.EJBException
at com.sun.ejb.containers.EJBContainerTransactionManager.processSystemException(EJBContainerTransactionManager.java:748)
at com.sun.ejb.containers.EJBContainerTransactionManager.completeNewTx(EJBContainerTransactionManager.java:698)
at com.sun.ejb.containers.EJBContainerTransactionManager.postInvokeTx(EJBContainerTransactionManager.java:503)
at com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:4566)
at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:2074)
at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:2044)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:220)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:88)
at com.sun.proxy.$Proxy248.submit(Unknown Source)
at edu.harvard.iq.dataverse.__EJB31_Generated__EjbDataverseEngine__Intf____Bean__.submit(Unknown Source)
at edu.harvard.iq.dataverse.DatasetPage.releaseDataset(DatasetPage.java:1938)
at edu.harvard.iq.dataverse.DatasetPage.releaseMajor(DatasetPage.java:1783)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.sun.el.parser.AstValue.invoke(AstValue.java:289)
at com.sun.el.MethodExpressionImpl.invoke(MethodExpressionImpl.java:304)
at org.jboss.weld.util.el.ForwardingMethodExpression.invoke(ForwardingMethodExpression.java:40)
at org.jboss.weld.el.WeldMethodExpression.invoke(WeldMethodExpression.java:50)
at com.sun.faces.facelets.el.TagMethodExpression.invoke(TagMethodExpression.java:105)
at javax.faces.component.MethodBindingMethodExpressionAdapter.invoke(MethodBindingMethodExpressionAdapter.java:87)
... 44 more
Caused by: javax.persistence.OptimisticLockException: Exception [EclipseLink-5010] (Eclipse Persistence Services - 2.5.2.v20140319-9ad6abd): org.eclipse.persistence.exceptions.OptimisticLockException
Exception Description: The object [[DatasetVersion id:16]] cannot be merged because it has changed or been deleted since it was last read.
Class> edu.harvard.iq.dataverse.DatasetVersion
at org.eclipse.persistence.internal.jpa.EntityManagerImpl.mergeInternal(EntityManagerImpl.java:544)
at org.eclipse.persistence.internal.jpa.EntityManagerImpl.merge(EntityManagerImpl.java:519)
at com.sun.enterprise.container.common.impl.EntityManagerWrapper.merge(EntityManagerWrapper.java:305)
at edu.harvard.iq.dataverse.engine.command.impl.PublishDatasetCommand.execute(PublishDatasetCommand.java:92)
at edu.harvard.iq.dataverse.engine.command.impl.PublishDatasetCommand.execute(PublishDatasetCommand.java:31)
at edu.harvard.iq.dataverse.EjbDataverseEngine.submit(EjbDataverseEngine.java:223)
at sun.reflect.GeneratedMethodAccessor1253.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.glassfish.ejb.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1081)
at org.glassfish.ejb.security.application.EJBSecurityManager.invoke(EJBSecurityManager.java:1153)
at com.sun.ejb.containers.BaseContainer.invokeBeanMethod(BaseContainer.java:4786)
at com.sun.ejb.EjbInvocation.invokeBeanMethod(EjbInvocation.java:656)
at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:822)
at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:46)
at org.jboss.weld.ejb.SessionBeanInterceptor.aroundInvoke(SessionBeanInterceptor.java:52)
at sun.reflect.GeneratedMethodAccessor98.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:883)
at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:822)
at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.doCall(SystemInterceptorProxy.java:163)
at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.aroundInvoke(SystemInterceptorProxy.java:140)
at sun.reflect.GeneratedMethodAccessor101.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:883)
at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:822)
at com.sun.ejb.containers.interceptors.InterceptorManager.intercept(InterceptorManager.java:369)
at com.sun.ejb.containers.BaseContainer.__intercept(BaseContainer.java:4758)
at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:4746)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:212)
... 59 more
Caused by: Exception [EclipseLink-5010] (Eclipse Persistence Services - 2.5.2.v20140319-9ad6abd): org.eclipse.persistence.exceptions.OptimisticLockException
Exception Description: The object [[DatasetVersion id:16]] cannot be merged because it has changed or been deleted since it was last read.
Class> edu.harvard.iq.dataverse.DatasetVersion
at org.eclipse.persistence.exceptions.OptimisticLockException.objectChangedSinceLastMerge(OptimisticLockException.java:152)
at org.eclipse.persistence.internal.sessions.MergeManager.mergeChangesOfCloneIntoWorkingCopy(MergeManager.java:578)
at org.eclipse.persistence.internal.sessions.MergeManager.mergeChanges(MergeManager.java:313)
at org.eclipse.persistence.mappings.CollectionMapping.mergeIntoObject(CollectionMapping.java:1645)
at org.eclipse.persistence.internal.descriptors.ObjectBuilder.mergeIntoObject(ObjectBuilder.java:4132)
at org.eclipse.persistence.internal.sessions.MergeManager.mergeChangesOfCloneIntoWorkingCopy(MergeManager.java:594)
at org.eclipse.persistence.internal.sessions.MergeManager.mergeChanges(MergeManager.java:313)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.mergeCloneWithReferences(UnitOfWorkImpl.java:3521)
at org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.mergeCloneWithReferences(RepeatableWriteUnitOfWork.java:384)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.mergeCloneWithReferences(UnitOfWorkImpl.java:3481)
at org.eclipse.persistence.internal.jpa.EntityManagerImpl.mergeInternal(EntityManagerImpl.java:542)
... 92 more
]]
I'm going to close this one, as we've made some modifications (focused on locks releasing and other changes) to the locking code over the last year+ and I expect this has been fixed.
@matthew-a-dunlap if you're reading this I hope you're well! :)
Sadly, this issue is still occurring for us, with small CSVs. Backtrace excerpt:
ESC[36mdataverse |ESC[0m Exception Description: The object [[DatasetVersion id:2]] cannot be merged because it has changed or been deleted since it was last read.
ESC[36mdataverse |ESC[0m Class> edu.harvard.iq.dataverse.DatasetVersion
ESC[36mdataverse |ESC[0m at com.sun.ejb.containers.EJBContainerTransactionManager.processSystemException(EJBContainerTransactionManager.java:723)
ESC[36mdataverse |ESC[0m at com.sun.ejb.containers.EJBContainerTransactionManager.completeNewTx(EJBContainerTransactionManager.java:652)
ESC[36mdataverse |ESC[0m at com.sun.ejb.containers.EJBContainerTransactionManager.postInvokeTx(EJBContainerTransactionManager.java:482)
ESC[36mdataverse |ESC[0m at com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:4592)
ESC[36mdataverse |ESC[0m at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:2125)
ESC[36mdataverse |ESC[0m at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:2095)
ESC[36mdataverse |ESC[0m at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:220)
ESC[36mdataverse |ESC[0m at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:90)
ESC[36mdataverse |ESC[0m at com.sun.proxy.$Proxy362.submit(Unknown Source)
ESC[36mdataverse |ESC[0m at edu.harvard.iq.dataverse.__EJB31_Generated__EjbDataverseEngineInner__Intf____Bean__.submit(Unknown Source)
ESC[36mdataverse |ESC[0m at edu.harvard.iq.dataverse.EjbDataverseEngine.submit(EjbDataverseEngine.java:274)
ESC[36mdataverse |ESC[0m at jdk.internal.reflect.GeneratedMethodAccessor1214.invoke(Unknown Source)
ESC[36mdataverse |ESC[0m at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
ESC[36mdataverse |ESC[0m at java.base/java.lang.reflect.Method.invoke(Method.java:566)
ESC[36mdataverse |ESC[0m at org.glassfish.ejb.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:588)
ESC[36mdataverse |ESC[0m at org.glassfish.ejb.security.application.EJBSecurityManager.invoke(EJBSecurityManager.java:408)
ESC[36mdataverse |ESC[0m at com.sun.ejb.containers.BaseContainer.invokeBeanMethod(BaseContainer.java:4826)
ESC[36mdataverse |ESC[0m at com.sun.ejb.EjbInvocation.invokeBeanMethod(EjbInvocation.java:665)
ESC[36mdataverse |ESC[0m at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:834)
ESC[36mdataverse |ESC[0m at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:615)
ESC[36mdataverse |ESC[0m at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.doCall(SystemInterceptorProxy.java:163)
ESC[36mdataverse |ESC[0m at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.aroundInvoke(SystemInterceptorProxy.java:140)
ESC[36mdataverse |ESC[0m at jdk.internal.reflect.GeneratedMethodAccessor313.invoke(Unknown Source)
ESC[36mdataverse |ESC[0m at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
ESC[36mdataverse |ESC[0m at java.base/java.lang.reflect.Method.invoke(Method.java:566)
ESC[36mdataverse |ESC[0m at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:888)
ESC[36mdataverse |ESC[0m at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:833)
ESC[36mdataverse |ESC[0m at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:615)```
@vjorlikowski is testing Dataverse 5.8 using dataverse-docker.