Weird "Failed to create search results" error

[Simon Doran]

Hi All,

  I have been transferring my XNAT production systems to a new platform and am basing them on 1.7.2 VMs running under VirtualBox. After a little bit of tweaking, *almost* everything is now working. The webapp spins up correctly and the site configuration section and the prearchive do exactly what I expect.

  However, I am getting a weird "Failed to create search results" error when navigating to a project from the home page (see below). The full traces from xdat.log and restlet.log are below. However, the significant lines seem to be:

access.log

2017-05-12 19:20:29,072 - admin 192.168.242.4 POST https://xx.xx.ac.uk:8443/SITE_NAME/REST/search?XNAT_CSRF=d0dd8ec1-d1fb-49c7-9192-a9d0143a4ce7&format=json&cache=true&refresh=true

-05-12 19:20:29,102 [http-bio-8443-exec-8] ERROR org.nrg.xnat.restlet.resources.search.SearchResource -

org.xml.sax.SAXParseException; Premature end of file.

        at org.apache.xerces.parsers.AbstractSAXParser.parse(Unknown Source)

        at org.apache.xerces.jaxp.SAXParserImpl$JAXPSAXParser.parse(Unknown Source)

        at org.apache.xerces.jaxp.SAXParserImpl.parse(Unknown Source)

        at org.nrg.xft.schema.Wrappers.XMLWrapper.SAXReader.parse(SAXReader.java:135)

        at org.nrg.xnat.restlet.resources.search.SearchResource.handlePost(SearchResource.java:136)

2017-05-12 19:20:25,014 [http-bio-8443-exec-9] ERROR org.nrg.xdat.security.PermissionsServiceImpl -

org.nrg.xft.exception.ElementNotFoundException: Element not found: 'subjectData/project'

        at org.nrg.xft.meta.XFTMetaManager.FindElement(XFTMetaManager.java:189)

  Any help that anyone could give would be much appreciated, as this is a complete roadblock at the moment.

  Best wishes,

Simon

xdat.log

======

2017-05-12 19:20:25,014 [http-bio-8443-exec-9] ERROR org.nrg.xdat.security.PermissionsServiceImpl -

org.nrg.xft.exception.ElementNotFoundException: Element not found: 'subjectData/project'

        at org.nrg.xft.meta.XFTMetaManager.FindElement(XFTMetaManager.java:189)

        at org.nrg.xft.meta.XFTMetaManager.FindElement(XFTMetaManager.java:228)

        at org.nrg.xft.meta.XFTMetaManager.FindElement(XFTMetaManager.java:183)

        at org.nrg.xft.meta.XFTMetaManager.GetWrappedElementByName(XFTMetaManager.java:319)

        at org.nrg.xft.schema.Wrappers.GenericWrapper.GenericWrapperElement.GetElement(GenericWrapperElement.java:145)

        at org.nrg.xdat.schema.SchemaElement.GetElement(SchemaElement.java:121)

        at org.nrg.xdat.security.PermissionsServiceImpl.getAllowedValues(PermissionsServiceImpl.java:423)

        at org.nrg.xdat.security.PermissionsServiceImpl.canAny(PermissionsServiceImpl.java:448)

        at org.nrg.xdat.security.helpers.Permissions.canAny(Permissions.java:399)

        at org.nrg.xdat.security.services.UserHelperServiceI.canCreate(UserHelperServiceI.java:69)

        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.apache.velocity.util.introspection.UberspectImpl$VelMethodImpl.doInvoke(UberspectImpl.java:395)

        at org.apache.velocity.util.introspection.UberspectImpl$VelMethodImpl.invoke(UberspectImpl.java:384)

        at org.apache.velocity.runtime.parser.node.ASTMethod.execute(ASTMethod.java:173)

        at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:280)

        at org.apache.velocity.runtime.parser.node.ASTReference.evaluate(ASTReference.java:530)

        at org.apache.velocity.runtime.parser.node.ASTOrNode.evaluate(ASTOrNode.java:105)

        at org.apache.velocity.runtime.parser.node.ASTExpression.evaluate(ASTExpression.java:62)

        at org.apache.velocity.runtime.parser.node.ASTIfStatement.render(ASTIfStatement.java:85)

        at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:342)

        at org.apache.velocity.runtime.directive.Parse.render(Parse.java:260)

        at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:207)

        at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)

        at org.apache.velocity.runtime.parser.node.ASTElseIfStatement.render(ASTElseIfStatement.java:92)

        at org.apache.velocity.runtime.parser.node.ASTIfStatement.render(ASTIfStatement.java:106)

        at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)

        at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:420)

        at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:207)

        at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)

        at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:216)

        at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:311)

        at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:230)

        at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:207)

        at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:342)

        at org.apache.velocity.runtime.directive.Parse.render(Parse.java:260)

        at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:207)

        at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)

        at org.apache.velocity.runtime.parser.node.ASTElseIfStatement.render(ASTElseIfStatement.java:92)

        at org.apache.velocity.runtime.parser.node.ASTIfStatement.render(ASTIfStatement.java:106)

        at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)

        at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:420)

        at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:207)

        at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)

        at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:216)

        at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:311)

        at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:230)

        at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:207)

        at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:342)

        at org.apache.velocity.Template.merge(Template.java:356)

        at org.apache.velocity.Template.merge(Template.java:260)

        at org.apache.velocity.app.Velocity.mergeTemplate(Velocity.java:339)

        at org.apache.turbine.services.velocity.TurbineVelocityService.executeRequest(TurbineVelocityService.java:412)

        at org.apache.turbine.services.velocity.TurbineVelocityService.handleRequest(TurbineVelocityService.java:284)

        at org.apache.turbine.services.velocity.TurbineVelocity.handleRequest(TurbineVelocity.java:74)

        at org.apache.turbine.modules.navigations.VelocityNavigation.buildTemplate(VelocityNavigation.java:95)

        at org.apache.turbine.modules.navigations.TemplateNavigation.doBuild(TemplateNavigation.java:69)

        t org.apache.turbine.modules.Navigation.build(Navigation.java:60)

        at org.apache.turbine.modules.NavigationLoader.eval(NavigationLoader.java:110)

        at org.apache.turbine.util.template.TemplateNavigation.toString(TemplateNavigation.java:109)

        at org.apache.velocity.runtime.parser.node.ASTReference.render(ASTReference.java:430)

        at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:342)

        at org.apache.velocity.Template.merge(Template.java:356)

        at org.apache.velocity.Template.merge(Template.java:260)

        at org.apache.velocity.app.Velocity.mergeTemplate(Velocity.java:339)

        at org.apache.turbine.services.velocity.TurbineVelocityService.executeRequest(TurbineVelocityService.java:412)

        at org.apache.turbine.services.velocity.TurbineVelocityService.handleRequest(TurbineVelocityService.java:284)

        at org.apache.turbine.services.velocity.TurbineVelocity.handleRequest(TurbineVelocity.java:74)

        at org.apache.turbine.modules.layouts.VelocityOnlyLayout.doBuild(VelocityOnlyLayout.java:119)

        at org.apache.turbine.modules.Layout.build(Layout.java:56)

        at org.apache.turbine.modules.LayoutLoader.exec(LayoutLoader.java:104)

        at org.apache.turbine.modules.pages.DefaultPage.doBuild(DefaultPage.java:149)

        at org.apache.turbine.modules.Page.build(Page.java:56)

        at org.apache.turbine.modules.PageLoader.exec(PageLoader.java:104)

        at org.apache.turbine.Turbine.doGet(Turbine.java:796)

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

        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 net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:200)

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

        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:37)

        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:316)

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

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

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

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

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

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

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

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

        at org.nrg.xnat.security.XnatInitCheckFilter.doFilter(XnatInitCheckFilter.java:51)

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

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

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

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

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

        at org.nrg.xnat.security.XnatBasicAuthenticationFilter.doFilterInternal(XnatBasicAuthenticationFilter.java:143)

        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)

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

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

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

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

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

        at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:64)

        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)

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

        at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:53)

        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)

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

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

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

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

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

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

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

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

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

        at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:213)

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

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

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

        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:170)

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

        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:1041)

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

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

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

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

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

restlet.log

=======

017-05-12 19:20:29,102 [http-bio-8443-exec-8] ERROR org.nrg.xnat.restlet.resources.search.SearchResource -

org.xml.sax.SAXParseException; Premature end of file.

        at org.apache.xerces.parsers.AbstractSAXParser.parse(Unknown Source)

        at org.apache.xerces.jaxp.SAXParserImpl$JAXPSAXParser.parse(Unknown Source)

        at org.apache.xerces.jaxp.SAXParserImpl.parse(Unknown Source)

        at org.nrg.xft.schema.Wrappers.XMLWrapper.SAXReader.parse(SAXReader.java:135)

        at org.nrg.xnat.restlet.resources.search.SearchResource.handlePost(SearchResource.java:136)

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

        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 net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:200)

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

        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:37)

        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:316)

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

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

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

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

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

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

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

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

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

        at org.nrg.xnat.security.XnatInitCheckFilter.doFilter(XnatInitCheckFilter.java:51)

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

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

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

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

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

        at org.nrg.xnat.security.XnatBasicAuthenticationFilter.doFilterInternal(XnatBasicAuthenticationFilter.java:143)

        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)

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

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

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

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

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

        at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:64)

        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)

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

        at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:53)

        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)

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

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

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

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

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

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

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

        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:170)

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

        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:1041)

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

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

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

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

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

                                                                                                     

[Simon Doran]

... and here's the image.

[Simon Doran]

Initially, I thought this was a duplicate of https://groups.google.com/forum/#!searchin/xnat_discussion/failed$20to$20create%7Csort:relevance/xnat_discussion/0FdEJpCIPok/mBZWHsVgGwAJ

However, I have checked the solution in that post (i.e., to leave the security setting as "any") and this is what is already in the Postgres database.

Further information:

* http://VM_IP:8080 always redirects to 8443 (not sure why)

* When I don't set Tomcat's server.xml up with an 8443 connector port, then nothing connects.

* When I uncomment the entry for 8443 in server.xml, then I get the following: 

https://VM_IP:8443 works exactly as planned, but in order to get Tomcat to startup correctly on 8443, I needed a self-signed certificate on the VM, as the bona fide certificate that I have is for the VM's host.

http://VM_IP:8080 redirects to https://VM_IP:8443 and this works as above. 

https://VM_HOST_IP (my desired URL for access) is redirected by the organisation WAP server to https://VM_IP:8443 but, although the webapp is displayed, this gives the "Failed to create search results" error. Note that the WAP server has installed on it the SSL certificate generated for the VM host.

  I'm sure that this is indeed an SSL problem, but I don't know enough to work out what to do?

  Best wishes,

Simon

[Simon Doran]

UPDATE

This error is now getting very concerning, as it is completely blocking our proposed deployment with our institutional proxy server.

We have successfully installed all the necessary SSL certificates for our VM-based XNAT servers to run in the following configuration:

* Internal user can access the VM directly on port 8443, i.e., https://internalVmName.icr.ac.uk:8443/XNAT_INSTALLATION_NAME

* External user access the VM via the "public address" https://publicServer.icr.ac.uk/XNAT_INSTALLATION_NAME and this URL is routed by our WAP server to the internal URL above.

With the internal route, explicitly accessing the VM on port 8443, everything works perfectly.

Via the external route, at first sight, everything also seems to works as normal. I can log on and the home page lists all my projects correctly. If I click on a the session name from one of the recent uploads on the right, I can view that session. I can download images via Manage Files and I can user the image viewer. I can administer the site and create new users. In short, I can do anything I want, it seems, except list the subjects in a project when I click on the project from the home screen. The images below show what I get:

Internal route: report successfully displayed

External route: report generation fails.

As described in the previous post, the error flagged up restlet.log is this one: 

2017-05-24 21:36:18,318 [http-bio-8443-exec-1] ERROR org.nrg.xnat.restlet.resources.search.SearchResource -

org.xml.sax.SAXParseException; lineNumber: 1; columnNumber: 1; Premature end of file.

        at org.apache.xerces.parsers.AbstractSAXParser.parse(Unknown Source)

        at javax.xml.parsers.SAXParser.parse(SAXParser.java:392)

        at org.nrg.xft.schema.Wrappers.XMLWrapper.SAXReader.parse(SAXReader.java:135)

        at org.nrg.xnat.restlet.resources.search.SearchResource.handlePost(SearchResource.java:136)

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

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

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

.

.

.

and the most recent search listed in access.log is:

2017-05-24 21:36:18,303 - admin 192.168.242.4 POST https://internalVmName.icr.ac.uk:8443/XNAT_INSTALLATION_NAME/REST/search?XNAT_CSRF=a9f4db53-4bce-49b9-9972-801f2ddde074&format=json&cache=true&refresh=true

  Any ideas on how to go about tracking this down would be greatly appreciated.

  Best wishes,

Simon

[Herrick, Rick]

There are two ways to find out what’s getting POSTed to the server:

 

·         The best way is to use a proxy debugger like Charles Proxy (https://www.charlesproxy.com, only on OSX, costs US$50 for a license but has a 30-day trial license; it’s awesome enough that I paid for a license) and monitor the traffic between the browser and the server.

·         The cheaper way is to open the network monitor in your browser’s developer tools. I think that’s Firefox you’re using so go to Tools->Web Developer->Network). You can limit the calls that appear in the network window to just REST calls by clicking XHR at the top of the listing:

 

 

 

In either case, search for the failing request, in this case /REST/search, and select that. That will let you look at the request and response headers, cookies, etc., including the request body that was posted to the server. This is one of the areas of functionality where I prefer Charles over the browser tools, because the formatted info is much more readable:

 

You can even copy the request as a curl command, which lets you test what’s going on in isolation from other things happening on the page. So, for reference, here’s the curl command for the request shown above (with some stuff removed because it’s mostly irrelevant):

 

curl -H 'Content-Type: application/x-www-form-urlencoded; charset=UTF-8' \

     -H 'Cookie: JSESSIONID=F9BCB78B1CAE0F2CED236E6A45914596;' \

     --data-binary '<XML PAYLOAD IN HERE>’

     --compressed 'http://xnat-dev05.nrg.mir/REST/search?XNAT_CSRF=xxx&format=json&cache=true&refresh=true'

 

I’m sure that this is related to the proxy situation you have, so you might try running the curl command two separate ways:

 

·         With the public server URL, so https://publicServer.icr.ac.uk/XNAT_INSTALLATION_NAME/REST/search

·         With the internal server URL, so https://internalVmName.icr.ac.uk:8443/XNAT_INSTALLATION_NAME/REST/search

 

What makes this a more difficult nut to crack is the URL rewriting going on between the proxy and Tomcat. The entries that I’m getting in the XNAT access.log look like this:

 

2017-05-25 01:41:56,596 - xxx 10.28.17.101 POST http://xnat-dev05.nrg.mir/REST/search?XNAT_CSRF=a893285b-4ec3-411d-a728-29496db43def&format=json&cache=true&refresh=true

 

That server address is the same as the request made by the browser, even though it’s going through Apache HTTPD. I suspect that the big difference between our configuration here and yours is the configuration of the connection between the two. We’re using mod_jk with Apache mapped to localhost and port 8009, but there’s no reason to think that it wouldn’t work fine if this wasn’t to localhost, as long as port 8009 is open between the servers hosting the proxy and Tomcat instances. Introducing SSL at that level is somewhat complicating, but since it seems like the cert is good (because you have no issues accessing the server through the internal address), I doubt that’s an issue.

 

What I’m really wondering is if there’s some sort of security measure on the proxy that’s kneecapping the request, specifically maybe blocking XML from being POSTed? Maybe you could try a couple of test operations that use XML POSTs to see if they’ll get blocked as well. I’ve attached a simple XML that you can use to create projects with a command like this:

 

curl -u user:pass -X POST https://publicServer.icr.ac.UK/XNAT/REST/projects -H 'Content-Type: text/xml' --data-ascii @XML_Create.xml

 

You can replace “-u user:pass” with “-H ‘JSESSIONID=xxx’” by scraping a valid JSESSIONID from your network monitor or proxy debugger, which helps avoid creating a new session for each request.

 

If you’re using Charles or another proxy debugger, you can insert that into the call to monitor the traffic with curl’s --proxy parameter. With the proxy running on the machine from which you’re issuing commands, you’d just add “--proxy localhost:8888” to the curl command.

 

Give that a try and see what happens. Also, would it be possible to find out how the proxy is configured to handle the routing to your Tomcat server? Specifically, it would be good to know which mod is being used (nowadays, it’s almost always mod_jk, but just in case it’s something else…) and how it’s configured (specifically the mod_jk.conf and worker properties).

 

-- 

Rick Herrick

Sr. Programmer/Analyst

Neuroinformatics Research Group

Washington University School of Medicine

--
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 https://groups.google.com/group/xnat_discussion.
For more options, visit https://groups.google.com/d/optout.

 

---

The materials in this message are private and may contain Protected Healthcare Information or other information of a sensitive nature. If you are not the intended recipient, be advised that any unauthorized use, disclosure, copying or the taking of any action in reliance on the contents of this information is strictly prohibited. If you have received this email in error, please immediately notify the sender via telephone or return mail.

[Simon Doran]

Hi Rick,

  Thanks so much for taking the trouble to write such a detailed post on this.

  I'll give these various tests a go and then get back to you with what I find.

  Best wishes,

Simon

[Simon Doran]

Hi Rick,

  Thanks again for the advice. When you know what you are looking for and how to look, the immediate cause of the problem is not hard to find!

  Attached are the POST request for the search that works and the corresponding request for the one that doesn't. Your hunch was correct and no XML seems to have been transferred when POSTing from the public server via the web proxy.

  Further digging shows that I was over-optimistic when I said that the REST calls worked equally well from both places. GET seems to be fine, but POSTs definitely don't always do the same thing. For example:

curl -u user:password -X POST https://internalVmName.icr.ac.uk:8443/XNAT_INSTALLATION//REST/JSESSION
responds with
7B33E1109294EBB86CBEB56389EA5DBE

but

curl -u user:password -X POST https://publicServer.icr.ac.uk/XNAT_INSTALLATION//REST/JSESSION
gives
<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN""http://www.w3.org/TR/html4/strict.dtd">
<HTML><HEAD><TITLE>Length Required</TITLE>
<META HTTP-EQUIV="Content-Type" Content="text/html; charset=us-ascii"></HEAD>
<BODY><h2>Length Required</h2>
<hr><p>HTTP Error 411. The request must be chunked or have a content length.</p>
</BODY></HTML>

By contrast, when I issued the project-creation XML that you attached from the command line, it did work in both cases. So this is clearly a little bit more subtle than simply saying that no POST queries work.

  Now that it seems clear that it is definitely a proxying and not an XNAT issue, I'll take this back to our institute's networking team and report back.

  Thanks again for your timely help. Much appreciated.

  Best wishes,

Simon

[Simon Doran]

Hi Rick,

  A quick update:

1. The POST above to get a JSESSION id *does* work, but only if we add an extra parameter, viz:

 curl -u user:password -d "" -X POST https://publicServer.icr.ac.uk/XNAT_INSTALLATION/REST/JSESSION

  Good that it does work, but the fact that it doesn't work the same is concerning.

2. I tried both your project-creation XML and a typical search XML and both of these *do* work from the command line, so it is clear that things are definitely not as simple as the proxy failing to pass request content.

  As of now, I think that we are in a ping-pong situation where our networking team will say it is an error in the web app and the development team might reasonably claim it is a problem with the proxy. Is there anything for it other than simply to work line-by-line through the source of the web page and find the origin of the call that fails?

 

  Best wishes,

Simon

  

[John Flavin]

My two cents: The failure you got says that you have to set the Content-length header. Since XNAT clearly doesn't care about that header (because you can make the request directly to XNAT without setting the Content-length header and it goes fine), it seems that the proxy server is insisting that the Content-length header be present. Ask your network team if that is correct, and, if so, if they can remove that restriction.

To explain why the '-d ""' flag makes things work again: I would guess that curl is setting the Content-length header on your behalf whenever you are POSTing data, either from a file or from a -d "" empty body. You can check the headers on your requests in the same way that you are checking the query params; "Headers" is another column in the network inspector. That would allow you to verify when the Content-length header is or is not set.

Flavin

[John Flavin]

Oh, and another thing you could try to get around the error is to explicitly set the Content-length header yourself. In curl you would use the flag

-H 'Content-length: 0'

I imagine that should work equally as well as posting an empty body (-d "").

[Simon Doran]

Phew! Finally sorted.

One of my networking colleagues, David Silva dug this gem out, no doubt after much Googling.

Thank you all for your help over the last couple of weeks. I was getting a bit desperate.  I am a happy man.

Hi Simon,

 

You’ll be very happy to hear that I’ve managed to find a fix for this (literally) J

 

Microsoft had a hidden hotfix at the “bottom” of the Internet, which is at the same time one of the worst detailed hotfixes I’ve come across.

It’s a hotfix from 2015, which hasn’t been made available via standard OS updates and it’s only available “on-request”.

https://support.microsoft.com/en-us/help/3042127/-http-400---bad-request-error-when-you-open-a-shared-mailbox-through-wap-in-windows-server-2012-r2

As you can see it doesn’t sound remotely relevant, until I read this: http://bit.ly/2siUg6V and this http://bit.ly/2qDj5JD

 

The hotfix has now been applied to the WAP server and xnatcruk projects link tested successfully.

Curious we haven’t come across this before on the other web applications we have published via the WAP.

 

Anyway, hopefully this puts an end to this saga J

 

Regards,

David