Export: OAI-ORE stopped working in develop, throws server log error

[kcondon]

Some how this was missed and made its way into develop, even though all formats were tested in a recently merged branch updating export format.

Server log error:

[2019-08-16T15:01:14.003-0400] [glassfish 4.1] [SEVERE] [] [] [tid: _ThreadID=51 _ThreadName=Thread-9] [timeMillis: 1565982074003] [levelValue: 1000] [[
java.lang.NullPointerException
at edu.harvard.iq.dataverse.export.OAI_OREExporter.exportDataset(OAI_OREExporter.java:28)
at edu.harvard.iq.dataverse.export.ExportService.cacheExport(ExportService.java:270)
at edu.harvard.iq.dataverse.export.ExportService.exportAllFormats(ExportService.java:168)
at edu.harvard.iq.dataverse.engine.command.impl.FinalizeDatasetPublicationCommand.exportMetadata(FinalizeDatasetPublicationCommand.java:196)
at edu.harvard.iq.dataverse.engine.command.impl.FinalizeDatasetPublicationCommand.onSuccess(FinalizeDatasetPublicationCommand.java:184)
at edu.harvard.iq.dataverse.EjbDataverseEngine.completeCommand(EjbDataverseEngine.java:329)
at edu.harvard.iq.dataverse.EjbDataverseEngine.submit(EjbDataverseEngine.java:263)
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 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:64)
at org.jboss.weld.ejb.SessionBeanInterceptor.aroundInvoke(SessionBeanInterceptor.java:52)
at sun.reflect.GeneratedMethodAccessor116.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.GeneratedMethodAccessor115.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)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:88)
at com.sun.proxy.$Proxy507.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:2514)
at edu.harvard.iq.dataverse.DatasetPage.releaseDraft(DatasetPage.java:2349)
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)
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.processApplication(UIViewRoot.java:1282)
at com.sun.faces.lifecycle.InvokeApplicationPhase.execute(InvokeApplicationPhase.java:81)
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.core.StandardPipeline.doInvoke(StandardPipeline.java:734)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:673)
at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:412)
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.WorkerThreadI]]

[2019-08-16T15:01:14.003-0400] [glassfish 4.1] [SEVERE] [] [] [tid: _ThreadID=51 _ThreadName=Thread-9] [timeMillis: 1565982074003] [levelValue: 1000] [[
OStrategy$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)]]

[djbrooke]

Thanks for reporting @kcondon! I'll bring this into the sprint so that we can keep develop healthy. :)

cc: @qqmyers

[qqmyers]

A quick guess would be that the change in FinalizeDatasetPublicationCommand for onSuccess is now sending a ctxt with a null settings that is used to crete the ExportService. I'm away at present so I can't track that down further but that would be my guess given the error and the trail of recent changes.

[djbrooke]

Thanks @qqmyers, that's helpful!!

[kcondon]

Unfortunately we cannot reproduce this. I did nothing special, just went to metadata tab for a dataset and selected each of the formats for export. ORE resulted in a blank tab. In subsequent, repeated tests, this works. Will keep this in mind in future testing in case it is an edge case.

[pdurbin]

In the context of #4812 @scolapasta and I just saw these exceptions at https://jenkins.dataverse.org/job/IQSS-dataverse-develop/ws/conf/docker-aio/server.log

[kcondon]

This is happening again, consistently on publishing a dataset. Seems to happen after deploying a new branch. Create a dataset, upload a few files, one tabular, publish, error about OAI-ORE export in log, export shows blank file and 0 length file for ORE on filesystem. If remove that file and request export from UI, works. However, export ORE on publish continues to fail. This appeared to be unreproducible last evening on the same box so perhaps something gets initialized to make it work.

[pdurbin]

I can reproduce this in docker-aio running on my laptop as of e093c0f

[2019-08-22T20:41:53.443+0000] [glassfish 4.1] [SEVERE] [] [] [tid: _ThreadID=51 _ThreadName=Thread-9] [timeMillis: 1566506513443] [levelValue: 1000] [[
java.lang.NullPointerException
at edu.harvard.iq.dataverse.export.OAI_OREExporter.exportDataset(OAI_OREExporter.java:28)

Here's line 28:

dataverse/src/main/java/edu/harvard/iq/dataverse/export/OAI_OREExporter.java

Line 28 in e093c0f

new OREMap(version, ExportService.settingsService.isTrueForKey(SettingsServiceBean.Key.ExcludeEmailFromExport, false)).writeOREMap(outputStream);

When you run conf/docker-aio/prep_it.bash to stand up Dataverse in Docker, two datasets are created. Attempting to publish either dataset will result in the null pointer above.

[sekmiller]

The problem turned out to be that the HtmlCodeBookExporter was wiping out the settings service bean.