Data upload problem / odd error messages

[Simon Doran]

Hi,

  Is there anyone who can help me with this. I have several users who are finding difficulty uploading data to one of my production XNAT systems. The only information the user is receiving is an error flag in the prearchive.

  When I look in the logs, I find a large number of similar errors in both xdat.log and catalina.out. It is difficult to tell whether these are related to the problem, but they certainly look odd.

  Interestingly, in the catalina.out errors may be a red herring. The highlighted file and directory are completely non-existent and the session name in the directory title does not match what the user specified. I think these may refer to a different session unrelated to the failed upload in the prearchive (different session for same subject). The file in question does actually seem to have been uploaded under a different name, which does not seem to correspond to the expected nomenclature.

  File that does not exist is:

127.MR.Vaccinia.23.52.20120410.160651.qkv1zn.dcm

where the MR.Vaccinia.23.52.20120410.160651 correctly label the modality, project, scan no., data and time.

By contrast, I do have lots that match the form

1.3.12.2.1107.5.99.2.2137.30000012041118584576500004902-23-9-sks4dj.dcm

  Any ideas where these errors are coming from and if they are connected to failures to upload data?

  Best wishes,

Simon

xdat.log

======  

2015-03-25 17:00:45,234 [http-bio-8443-exec-17067] ERROR org.nrg.xdat.security.helpers.Features - Un-registered group feature: classic_viewer

2015-03-25 17:00:45,237 [http-bio-8443-exec-17067] ERROR org.nrg.xdat.security.helpers.Features - Un-registered group feature: upload_scans

2015-03-25 17:00:45,239 [http-bio-8443-exec-17067] ERROR org.nrg.xdat.security.helpers.Features - Un-registered group feature: tagged_upload

2015-03-25 17:00:45,242 [http-bio-8443-exec-17067] ERROR org.nrg.xdat.security.helpers.Features - Un-registered group feature: manage_files

2015-03-25 17:07:55,218 [org.springframework.jms.listener.DefaultMessageListenerContainer#0-1] ERROR org.nrg.xnat.archive.XNATSessionBuilder -

java.lang.ArrayIndexOutOfBoundsException: 16

        at org.hsqldb.store.BaseHashMap.addOrRemove(Unknown Source)

        at org.hsqldb.lib.IntKeyHashMap.put(Unknown Source)

        at org.hsqldb.DatabaseManager.getDatabaseObject(Unknown Source)

        at org.hsqldb.DatabaseManager.getDatabase(Unknown Source)

        at org.hsqldb.DatabaseManager.newSession(Unknown Source)

        at org.hsqldb.jdbc.jdbcConnection.<init>(Unknown Source)

        at org.hsqldb.jdbcDriver.getConnection(Unknown Source)

        at org.hsqldb.jdbc.jdbcDataSource.getConnection(Unknown Source)

        at org.hsqldb.jdbc.jdbcDataSource.getConnection(Unknown Source)

        at org.nrg.dcm.EnumeratedMetadataStore.<init>(EnumeratedMetadataStore.java:226)

        at org.nrg.dcm.EnumeratedMetadataStore.createHSQLDBBacked(EnumeratedMetadataStore.java:172)

        at org.nrg.dcm.EnumeratedMetadataStore.createHSQLDBBacked(EnumeratedMetadataStore.java:188)

        at org.nrg.dcm.xnat.DICOMSessionBuilder.createStore(DICOMSessionBuilder.java:294)

        at org.nrg.dcm.xnat.DICOMSessionBuilder.getStore(DICOMSessionBuilder.java:299)

        at org.nrg.dcm.xnat.DICOMSessionBuilder.<init>(DICOMSessionBuilder.java:236)

        at org.nrg.dcm.xnat.DICOMSessionBuilder.<init>(DICOMSessionBuilder.java:256)

        at org.nrg.xnat.archive.XNATSessionBuilder.call(XNATSessionBuilder.java:211)

        at org.nrg.xnat.helpers.prearchive.PrearcDatabase$12.extSync(PrearcDatabase.java:718)

        at org.nrg.xnat.helpers.prearchive.PrearcDatabase$12.extSync(PrearcDatabase.java:691)

        at org.nrg.xnat.helpers.prearchive.PrearcDatabase$LockAndSync.run(PrearcDatabase.java:1241)

        at org.nrg.xnat.helpers.prearchive.PrearcDatabase.buildSession(PrearcDatabase.java:691)

        at org.nrg.xnat.helpers.prearchive.SessionXmlRebuilderRequestListener.onSessionXmlRebuilderRequest(SessionXmlRebuilderRequestListener.java:40)

        at sun.reflect.GeneratedMethodAccessor516.invoke(Unknown Source)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

        at java.lang.reflect.Method.invoke(Method.java:606)

.

.

.

catalina.out

=========

java.io.FileNotFoundException: Source '/home/xnat/XNAT/Home/archive/VACCINIA/arc001/02_20120410_160651/SCANS/23/DICOM/127.MR.Vaccinia.23.52.20120410.160651.qkv1zn.dcm' does not exist

at org.apache.commons.io.FileUtils.moveFile(FileUtils.java:2819)

at org.nrg.xft.utils.FileUtils.MoveFile(FileUtils.java:737)

at org.nrg.xft.utils.FileUtils.MoveFile(FileUtils.java:753)

at org.nrg.xft.utils.FileUtils.MoveToCache(FileUtils.java:1024)

at org.nrg.xdat.om.base.BaseXnatAbstractresource.deleteFromFileSystem(BaseXnatAbstractresource.java:172)

at org.nrg.xdat.om.base.BaseXnatResourcecatalog.deleteFromFileSystem(BaseXnatResourcecatalog.java:177)

at org.nrg.xdat.om.base.BaseXnatResourcecatalog.deleteWithBackup(BaseXnatResourcecatalog.java:173)

at org.nrg.xdat.om.base.BaseXnatImagesessiondata.deleteFiles(BaseXnatImagesessiondata.java:2967)

at org.nrg.xdat.om.base.BaseXnatExperimentdata.delete(BaseXnatExperimentdata.java:601)

at org.nrg.xnat.restlet.resources.SubjAssessmentResource.handleDelete(SubjAssessmentResource.java:667)

at org.restlet.Finder.handle(Finder.java:361)

at org.restlet.Filter.doHandle(Filter.java:150)

at org.restlet.Filter.handle(Filter.java:195)

at org.restlet.Router.handle(Router.java:504)

at org.restlet.Filter.doHandle(Filter.java:150)

at org.restlet.Filter.handle(Filter.java:195)

at org.restlet.Filter.doHandle(Filter.java:150)

at org.restlet.Filter.handle(Filter.java:195)

at org.restlet.Router.handle(Router.java:504)

at org.restlet.Filter.doHandle(Filter.java:150)

at org.restlet.Filter.handle(Filter.java:195)

at org.restlet.Filter.doHandle(Filter.java:150)

at org.restlet.Filter.handle(Filter.java:195)

at org.restlet.Filter.doHandle(Filter.java:150)

at com.noelios.restlet.StatusFilter.doHandle(StatusFilter.java:130)

at org.restlet.Filter.handle(Filter.java:195)

at org.restlet.Filter.doHandle(Filter.java:150)

at org.restlet.Filter.handle(Filter.java:195)

at com.noelios.restlet.ChainHelper.handle(ChainHelper.java:124)

at com.noelios.restlet.application.ApplicationHelper.handle(ApplicationHelper.java:112)

at org.restlet.Application.handle(Application.java:341)

at org.restlet.Filter.doHandle(Filter.java:150)

at org.restlet.Filter.handle(Filter.java:195)

at org.restlet.Router.handle(Router.java:504)

at org.restlet.Filter.doHandle(Filter.java:150)

at org.restlet.Filter.handle(Filter.java:195)

at org.restlet.Router.handle(Router.java:504)

at org.restlet.Filter.doHandle(Filter.java:150)

at com.noelios.restlet.StatusFilter.doHandle(StatusFilter.java:130)

at org.restlet.Filter.handle(Filter.java:195)

at org.restlet.Filter.doHandle(Filter.java:150)

at org.restlet.Filter.handle(Filter.java:195)

at com.noelios.restlet.ChainHelper.handle(ChainHelper.java:124)

at org.restlet.Component.handle(Component.java:673)

at org.restlet.Server.handle(Server.java:331)

at com.noelios.restlet.ServerHelper.handle(ServerHelper.java:68)

at com.noelios.restlet.http.HttpServerHelper.handle(HttpServerHelper.java:147)

at com.noelios.restlet.ext.servlet.ServerServlet.service(ServerServlet.java:881)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)

at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)

at net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:163)

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)

at net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:206)

at net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:179)

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)

at org.nrg.xnat.restlet.util.UpdateExpirationCookie.doFilter(UpdateExpirationCookie.java:38)

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:369)

at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:109)

at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:83)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)

at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:97)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)

at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:100)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)

at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:78)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)

at org.nrg.xnat.security.XnatArcSpecFilter.doFilter(XnatArcSpecFilter.java:40)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)

at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:54)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)

at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:35)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)

at org.nrg.xnat.security.XnatBasicAuthenticationFilter.doFilter(XnatBasicAuthenticationFilter.java:138)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)

at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:187)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)

at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:105)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)

at org.springframework.security.web.session.ConcurrentSessionFilter.doFilter(ConcurrentSessionFilter.java:109)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)

at org.nrg.xnat.security.XnatExpiredPasswordFilter.doFilter(XnatExpiredPasswordFilter.java:232)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)

at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:79)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)

at org.springframework.security.web.access.channel.ChannelProcessingFilter.doFilter(ChannelProcessingFilter.java:109)

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)

at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:168)

at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:237)

at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:167)

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)

at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)

at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)

at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:501)

at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)

at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)

at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:950)

at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)

at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)

at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1070)

at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:611)

at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)

at java.lang.Thread.run(Thread.java:745)

[Tim Olsen]

I think the missing file errors are red herrings.  I’ve seen those for years, but haven’t been able to identify the cause.  I’d love to eliminate those, if we could track down the cause.  But, historically they never actually broke anything.

 

I suspect the pertinent log is the xdat.log entry.  That looks like an exception in the internals of HSQL (an in-memory database) which is used in Kevin’s DICOM anaylsis code.  If that breaks, then you would definitely have things left in an error state.  As to why its happening, that I’m not sure about

 

I assume this is only happening to some of the data being uploaded to the server.  Is there something different or unique about this data?  Is it particularly large in size or file count.  If you attempt to upload that data to one of your other XNAT servers, do you get the same exception?

 

Tim

--
You received this message because you are subscribed to the Google Groups "xnat_discussion" group.
To unsubscribe from this group and stop receiving emails from it, send an email to xnat_discussi...@googlegroups.com.
To post to this group, send email to xnat_di...@googlegroups.com.
Visit this group at http://groups.google.com/group/xnat_discussion.
For more options, visit https://groups.google.com/d/optout.

[Simon Doran]

Hi Tim,

  Thanks for your response. I haven't had time to follow this up yet, but will let you know if it turns into a widespread problem.

  Best wishes,

Simon