Index: Index all is failing and not clear why, need better error handling/reporting, skip over failures? #623

eaquigley · 2014-07-09T15:39:51Z

Author Name: Kevin Condon (@kcondon)
Original Redmine Issue: 4062, https://redmine.hmdc.harvard.edu/issues/4062
Original Date: 2014-06-02
Original Assignee: Kevin Condon

Attaching a db dump where index all fails, from 5/28

Phil:

I don't know what's going on with the data that was on dvn-build
(badindex.sql, attached). I can easily reproduce the exceptions
(javax.ejb.EJBTransactionRolledbackException
javax.ejb.TransactionRolledbackLocalException)

"index all" works fine if I comment out the sections of
IndexServiceBean that call the DataverseUserServiceBean methods
findByUserName and findAll.

Related issue(s): #702
Redmine related issue(s): 4160

eaquigley · 2014-07-09T15:39:51Z

Original Redmine Comment
Author Name: Philip Durbin (@pdurbin)
Original Date: 2014-06-20T20:45:47Z

We unfortunately saw the same problem on the demo site this afternoon and this was a quick fix:

swap order of methods within indexAll #4062 · 46ddb55 · IQSS/dataverse - 46ddb55

Kevin mentioned he'd be willing to comment so I'm passing this to him.

Also, please note that before I swapped the methods, I did a quick test of commenting out dataverseUserServiceBean.findAll() and that at least let the method finish without throwing a EJBTransactionRolledbackExcept and TransactionRolledbackLocalException.

eaquigley · 2014-07-09T15:39:51Z

Original Redmine Comment
Author Name: Philip Durbin (@pdurbin)
Original Date: 2014-06-23T13:34:48Z

Philip Durbin wrote:

We unfortunately saw the same problem on the demo site

I still have the data from demo loaded up locally and there's definitely still a bug here. During "index all", exceptions are being thrown when some datasets are indexed when the dataset's "subtree" is being determined. Strangely, if you later index the dataset individually, no exception is thrown.

I'm stealing this ticket back.

eaquigley · 2014-07-09T15:39:51Z

Original Redmine Comment
Author Name: Philip Durbin (@pdurbin)
Original Date: 2014-06-23T19:04:40Z

Philip Durbin wrote:

I still have the data from demo loaded up locally and there's definitely still a bug here. During "index all", exceptions are being thrown when some datasets are indexed when the dataset's "subtree" is being determined. Strangely, if you later index the dataset individually, no exception is thrown.

I just pushed this...

cache calls to dataverseService.findRootDataverse() #4062 · c9151d4 · IQSS/dataverse - c9151d4

... and it seems to prevent exceptions being throw during the "determine subtree" routine. Strangely, all I'm doing is reducing the number of calls to dataverseService.findRootDataverse() by caching the result (good for #3457 anyway). It prevents exceptions like this:


[2014-06-23T15:01:31.545-0400] [glassfish 4.0] [INFO] [] [edu.harvard.iq.dataverse.IndexServiceBean] [tid: _ThreadID=101 _ThreadName=http-listener-1(4)] [timeMillis: 1403550091545] [levelValue: 800] [[
  adding or updating Solr document for dataset id 433]]

[2014-06-23T15:01:31.545-0400] [glassfish 4.0] [WARNING] [ejb.system_exception] [javax.enterprise.system.container.ejb.com.sun.ejb.containers] [tid: _ThreadID=101 _ThreadName=http-listener-1(4)] [timeMillis: 1403550091545] [levelValue: 900] [[
  EJB5184:A system exception occurred during an invocation on EJB DataverseServiceBean, method: public edu.harvard.iq.dataverse.Dataverse edu.harvard.iq.dataverse.DataverseServiceBean.findRootDataverse()]]

[2014-06-23T15:01:31.545-0400] [glassfish 4.0] [WARNING] [] [javax.enterprise.system.container.ejb.com.sun.ejb.containers] [tid: _ThreadID=101 _ThreadName=http-listener-1(4)] [timeMillis: 1403550091545] [levelValue: 900] [[

javax.ejb.TransactionRolledbackLocalException: Client's transaction aborted
    at com.sun.ejb.containers.EJBContainerTransactionManager.useClientTx(EJBContainerTransactionManager.java:357)
    at com.sun.ejb.containers.EJBContainerTransactionManager.preInvokeTx(EJBContainerTransactionManager.java:251)
    at com.sun.ejb.containers.BaseContainer.preInvokeTx(BaseContainer.java:4433)
    at com.sun.ejb.containers.BaseContainer.preInvoke(BaseContainer.java:1921)
    at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:210)
    at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:88)
    at com.sun.proxy.$Proxy615.findRootDataverse(Unknown Source)
    at edu.harvard.iq.dataverse.__EJB31_Generated__DataverseServiceBean__Intf____Bean__.findRootDataverse(Unknown Source)
    at edu.harvard.iq.dataverse.IndexServiceBean.findPathSegments(IndexServiceBean.java:846)
    at edu.harvard.iq.dataverse.IndexServiceBean.addOrUpdateDataset(IndexServiceBean.java:355)
    at edu.harvard.iq.dataverse.IndexServiceBean.indexDataset(IndexServiceBean.java:304)
    at edu.harvard.iq.dataverse.IndexServiceBean.indexAll(IndexServiceBean.java:111)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    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:4695)
    at com.sun.ejb.EjbInvocation.invokeBeanMethod(EjbInvocation.java:630)
    at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:822)
    at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:582)
    at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:46)
    at sun.reflect.GeneratedMethodAccessor88.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    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:582)
    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.GeneratedMethodAccessor90.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    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:4667)
    at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:4655)
    at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:212)
    at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:88)
    at com.sun.proxy.$Proxy616.indexAll(Unknown Source)
    at edu.harvard.iq.dataverse.__EJB31_Generated__IndexServiceBean__Intf____Bean__.indexAll(Unknown Source)
    at edu.harvard.iq.dataverse.api.Index.indexAll(Index.java:33)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:125)
    at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$TypeOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:195)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:91)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:346)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:341)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:101)
    at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:224)
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:315)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:297)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:267)
    at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317)
    at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:198)
    at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:946)
    at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:323)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:372)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:335)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:218)
    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:253)
    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:357)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:260)
    at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:188)
    at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:191)
    at org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:168)
    at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:189)
    at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)
    at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:288)
    at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:206)
    at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:136)
    at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:114)
    at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
    at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:838)
    at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:113)
    at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:115)
    at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:55)
    at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:135)
    at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:564)
    at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:544)
    at java.lang.Thread.run(Thread.java:744)
]]

[2014-06-23T15:01:31.546-0400] [glassfish 4.0] [INFO] [] [edu.harvard.iq.dataverse.IndexServiceBean] [tid: _ThreadID=101 _ThreadName=http-listener-1(4)] [timeMillis: 1403550091546] [levelValue: 800] [[
  failed to find dataverseSegments for dataversePaths for subtree_ss: javax.ejb.EJBTransactionRolledbackException]]

In the middle of troubleshooting I found a related bug: #4142

Because of this bug (and because newer validation rules are apparently in place on dataverse-demo since data was added), we'll see this if you try an "index all":

{
"message":"javax.ejb.EJBException: Transaction aborted javax.transaction.RollbackException Transaction marked for rollback. javax.validation.ConstraintViolationException Bean Validation constraint(s) violated while executing Automatic Bean Validation on callback event:'preUpdate'. Please refer to embedded ConstraintViolations for details. (invalid value: <<<edu.harvard.iq.dataverse.DatasetFieldValueValue[ id=799 ]>>> for at edu.harvard.iq.dataverse.DatasetFieldValueValue[ id=799 ] - Contact E-mail is not a valid email address.)",
"documentation_url":"http://thedata.org"
}

eaquigley · 2014-07-09T15:39:52Z

Original Redmine Comment
Author Name: Philip Durbin (@pdurbin)
Original Date: 2014-06-24T12:30:29Z

Philip Durbin wrote:

I just pushed this...

cache calls to dataverseService.findRootDataverse() #4062 · c9151d4 · IQSS/dataverse - c9151d4

This commit has been deployed to dataverse-demo. Passing to QA.

eaquigley · 2014-07-09T15:39:52Z

Original Redmine Comment
Author Name: Kevin Condon (@kcondon)
Original Date: 2014-06-27T22:03:03Z

This was fixed. The broader feature of skipping failures and more debugging info is separate.

Closing ticket

eaquigley added this to the Dataverse 4.0: In Review milestone Jul 9, 2014

eaquigley assigned kcondon Jul 9, 2014

eaquigley closed this as completed Jul 9, 2014

This was referenced Jul 9, 2014

Solr: Index all performance is too slow with full production data. #50

Closed

dataset Contact E-mail does not allow dashes #692

Closed

scolapasta modified the milestones: Beta 1 - Dataverse 4.0, In Review - Dataverse 4.0 Jul 15, 2014

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Index: Index all is failing and not clear why, need better error handling/reporting, skip over failures? #623

Index: Index all is failing and not clear why, need better error handling/reporting, skip over failures? #623

eaquigley commented Jul 9, 2014

eaquigley commented Jul 9, 2014

eaquigley commented Jul 9, 2014

eaquigley commented Jul 9, 2014

eaquigley commented Jul 9, 2014

eaquigley commented Jul 9, 2014

Index: Index all is failing and not clear why, need better error handling/reporting, skip over failures? #623

Index: Index all is failing and not clear why, need better error handling/reporting, skip over failures? #623

Comments

eaquigley commented Jul 9, 2014

eaquigley commented Jul 9, 2014

eaquigley commented Jul 9, 2014

eaquigley commented Jul 9, 2014

eaquigley commented Jul 9, 2014

eaquigley commented Jul 9, 2014