large object ... does not exist
66 views
Skip to first unread message
Daniel Drucker
Jul 31, 2025, 10:42:13 AMJul 31
to xnat_discussion
When I click on "View Images", I get "Unexpected end of JSON input", and in the logs from postgres, "ERROR: large object 437977 does not exist". (Or some other number.)
What can I do?
Daniel Drucker
Daniel Drucker
Jul 31, 2025, 10:58:29 AMJul 31
to xnat_discussion
It looks like all of my OHIF cache got removed by postgres somehow!
I can fix this for a session with e.g. POST /xapi/viewer/projects/{projectId}/experiments/{experimentId} but it's slow and I have 22k+ sessions.
Is there a way to tell XNAT it's wrong about it being cached, so people clicking View Image will get a delay while the cache is regenerated, rather than an error?
Daniel Drucker
Jul 31, 2025, 12:08:54 PMJul 31
to xnat_discussion
What apparently happened, by the way, is that someone (who is having their access re-examined) decided it would be a great idea to run 'vacuumlo' on the xnat database.
That said, why and how does XNAT create unreferenced large objects that it then actually uses? vacuumlo should never have an effect on the database's user unless something is being done very wrong, AFAIK.
In any event, how can I fix XNAT's belief that it has all of these cached?
Timothy Olsen
Jul 31, 2025, 1:31:01 PMJul 31
to xnat_di...@googlegroups.com
Daniel,
What version of XNAT and OHIF are you running? I thought the newest version of OHIF stored the json on disk instead of in the database (because it was blowing up the database size and didn't need to be queried across sessions). And I thought the newest version would automatically recreate it if it was missing.
Tim
Tim
Timothy R Olsen
Founder, President
--
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 view this discussion visit https://groups.google.com/d/msgid/xnat_discussion/f5c481d1-4ab8-4d7f-b09a-14236e738213n%40googlegroups.com.
Daniel Drucker
Jul 31, 2025, 1:49:18 PMJul 31
to xnat_discussion
XNAT 1.9.1.2, OHIF 3.7.0.
Daniel Drucker
Jul 31, 2025, 2:19:14 PMJul 31
to xnat_discussion
> That said, why and how does XNAT create unreferenced large objects that it then actually uses? vacuumlo should never have an effect on the database's user unless something is being done very wrong, AFAIK.
The answer to that is it's not storing the oid references in oid-typed columns, which is a very bad idea for exactly this reason.
Timothy Olsen
Jul 31, 2025, 6:35:10 PMJul 31
to xnat_di...@googlegroups.com
Daniel,
Is there a full stack trace in the logs when this issue occurs?
Tim
Is there a full stack trace in the logs when this issue occurs?
Tim
Timothy R Olsen
Founder, President
--
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 view this discussion visit https://groups.google.com/d/msgid/xnat_discussion/73daa4a6-e788-476f-9723-3ea105fa0f78n%40googlegroups.com.
Daniel Drucker
Jul 31, 2025, 6:42:23 PMJul 31
to xnat_discussion
Here you go:
==> access.log <==
2025-07-31 22:41:32,790 - ddrucker 172.29.158.193 GET http://iris.mclean.harvard.edu/xapi/viewer/projects/clancy/experiments/Iris_E05346/exists "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.6 Safari/605.1.15"
2025-07-31 22:41:32,889 - ddrucker 172.29.158.193 GET http://iris.mclean.harvard.edu/xapi/viewer/projects/clancy/experiments/Iris_E05346 "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.6 Safari/605.1.15"
==> ohifviewer.log <==
2025-07-31 22:41:32,791 [http-nio-8080-exec-2] DEBUG org.nrg.xnatx.plugin.Security - Permission check - User: ddrucker, Permission: Read, Element: xnat:projectData/ID, Value: clancy
2025-07-31 22:41:32,793 [http-nio-8080-exec-2] DEBUG org.nrg.xnatx.plugin.Security - Project visible to user ddrucker: clancy
2025-07-31 22:41:32,793 [http-nio-8080-exec-2] DEBUG org.nrg.xnatx.plugin.Security - Permission check - User: ddrucker, Permission: Read, Element: xnat:imageSessionData/ID, Value: Iris_E05346
2025-07-31 22:41:32,817 [http-nio-8080-exec-2] DEBUG org.nrg.xnatx.plugin.Security - Session visible to user ddrucker: Iris_E05346
2025-07-31 22:41:32,826 [http-nio-8080-exec-2] DEBUG org.nrg.xnatx.plugin.Security - Permission check - User: ddrucker, Permission: Read, Element: xnat:mrSessionData/project, Value: clancy
2025-07-31 22:41:32,828 [http-nio-8080-exec-2] INFO org.nrg.xnatx.plugin.PluginUtils - Experiment Iris_E05346 belongs to project clancy
2025-07-31 22:41:32,829 [http-nio-8080-exec-2] DEBUG org.nrg.xnatx.ohifviewer.inputcreator.JsonMetadataHandler - Stored JSON revision: 2
2025-07-31 22:41:32,889 [http-nio-8080-exec-3] DEBUG org.nrg.xnatx.plugin.Security - Permission check - User: ddrucker, Permission: Read, Element: xnat:projectData/ID, Value: clancy
2025-07-31 22:41:32,891 [http-nio-8080-exec-3] DEBUG org.nrg.xnatx.plugin.Security - Project visible to user ddrucker: clancy
2025-07-31 22:41:32,892 [http-nio-8080-exec-3] DEBUG org.nrg.xnatx.plugin.Security - Permission check - User: ddrucker, Permission: Read, Element: xnat:imageSessionData/ID, Value: Iris_E05346
2025-07-31 22:41:32,902 [http-nio-8080-exec-3] DEBUG org.nrg.xnatx.plugin.Security - Session visible to user ddrucker: Iris_E05346
2025-07-31 22:41:32,911 [http-nio-8080-exec-3] DEBUG org.nrg.xnatx.plugin.Security - Permission check - User: ddrucker, Permission: Read, Element: xnat:mrSessionData/project, Value: clancy
2025-07-31 22:41:32,913 [http-nio-8080-exec-3] INFO org.nrg.xnatx.plugin.PluginUtils - Experiment Iris_E05346 belongs to project clancy
2025-07-31 22:41:32,914 [http-nio-8080-exec-3] DEBUG org.nrg.xnatx.ohifviewer.inputcreator.JsonMetadataHandler - Stored JSON revision: 2
2025-07-31 22:41:32,914 [http-nio-8080-exec-3] DEBUG org.nrg.xnatx.ohifviewer.service.HibernateOhifSessionDataService - Fetching session JSON for sessionId=Iris_E05346
2025-07-31 22:41:32,918 [http-nio-8080-exec-3] ERROR org.nrg.xnatx.ohifviewer.xapi.OhifViewerControllerAdvice - Error executing request - Failed to obtain stream - Cause: ERROR: large object 438334 does not exist
org.nrg.xnatx.plugin.PluginException: Failed to obtain stream
at org.nrg.xnatx.ohifviewer.service.HibernateOhifSessionDataService.getSessionJsonReader(HibernateOhifSessionDataService.java:117)
at org.nrg.xnatx.ohifviewer.service.HibernateOhifSessionDataService.transferSessionJson(HibernateOhifSessionDataService.java:94)
at org.nrg.xnatx.ohifviewer.service.HibernateOhifSessionDataService$$FastClassBySpringCGLIB$$ed840c12.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:792)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:762)
at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:123)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:388)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:762)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:707)
at org.nrg.xnatx.ohifviewer.service.HibernateOhifSessionDataService$$EnhancerBySpringCGLIB$$ef6f922d.transferSessionJson(<generated>)
at org.nrg.xnatx.ohifviewer.xapi.OhifViewerApi.getExperimentJson(OhifViewerApi.java:198)
at org.nrg.xnatx.ohifviewer.xapi.OhifViewerApi$$FastClassBySpringCGLIB$$73803578.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:792)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:762)
at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:89)
at org.nrg.xapi.rest.aspects.XapiRequestMappingAspect.processXapiRequest(XapiRequestMappingAspect.java:89)
at sun.reflect.GeneratedMethodAccessor306.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:634)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:624)
at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:72)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:762)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:762)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:707)
at org.nrg.xnatx.ohifviewer.xapi.OhifViewerApi$$EnhancerBySpringCGLIB$$f797e1f4.getExperimentJson(<generated>)
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.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205)
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:150)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:117)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:903)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:809)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1072)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:965)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:655)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:764)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:239)
at net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:215)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:337)
at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:115)
at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:81)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:122)
at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:116)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:126)
at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:81)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:109)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.nrg.xnat.security.XnatInitCheckFilter.doFilterInternal(XnatInitCheckFilter.java:41)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:149)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.nrg.xnat.security.XnatExpiredPasswordFilter.doFilterInternal(XnatExpiredPasswordFilter.java:109)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.nrg.xnat.security.XnatBasicAuthenticationFilter.doFilterInternal(XnatBasicAuthenticationFilter.java:117)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.session.ConcurrentSessionFilter.doFilter(ConcurrentSessionFilter.java:147)
at org.springframework.security.web.session.ConcurrentSessionFilter.doFilter(ConcurrentSessionFilter.java:125)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:223)
at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:217)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:223)
at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:217)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:103)
at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:89)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.header.HeaderWriterFilter.doHeadersAfter(HeaderWriterFilter.java:90)
at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:75)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:112)
at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:82)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:55)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.access.channel.ChannelProcessingFilter.doFilter(ChannelProcessingFilter.java:133)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.session.DisableEncodeUrlFilter.doFilterInternal(DisableEncodeUrlFilter.java:42)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:221)
at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:186)
at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:354)
at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:267)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:197)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:687)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:360)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:399)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:890)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1789)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:750)
Caused by: org.postgresql.util.PSQLException: ERROR: large object 438334 does not exist
at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2725)
at org.postgresql.core.v3.QueryExecutorImpl.receiveFastpathResult(QueryExecutorImpl.java:888)
at org.postgresql.core.v3.QueryExecutorImpl.fastpathCall(QueryExecutorImpl.java:668)
at org.postgresql.fastpath.Fastpath.fastpath(Fastpath.java:110)
at org.postgresql.fastpath.Fastpath.fastpath(Fastpath.java:152)
at org.postgresql.fastpath.Fastpath.getInteger(Fastpath.java:164)
at org.postgresql.largeobject.LargeObject.<init>(LargeObject.java:107)
at org.postgresql.largeobject.LargeObjectManager.open(LargeObjectManager.java:247)
at org.postgresql.largeobject.LargeObjectManager.open(LargeObjectManager.java:230)
at org.postgresql.jdbc.AbstractBlobClob.getLo(AbstractBlobClob.java:288)
at org.postgresql.jdbc.AbstractBlobClob.getBinaryStream(AbstractBlobClob.java:127)
at org.postgresql.jdbc.PgClob.getCharacterStream(PgClob.java:76)
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.hibernate.engine.jdbc.SerializableClobProxy.invoke(SerializableClobProxy.java:60)
at com.sun.proxy.$Proxy358.getCharacterStream(Unknown Source)
at org.nrg.xnatx.ohifviewer.service.HibernateOhifSessionDataService.getSessionJsonReader(HibernateOhifSessionDataService.java:115)
... 138 common frames omitted
==> turbine.log <==
2025-07-31 22:41:32,975 [http-nio-8080-exec-3] ERROR org.apache.turbine.Turbine - Turbine.handleException:
java.lang.IllegalStateException: getOutputStream() has already been called for this response
at org.apache.catalina.connector.Response.getWriter(Response.java:584)
at org.apache.catalina.connector.ResponseFacade.getWriter(ResponseFacade.java:227)
at javax.servlet.ServletResponseWrapper.getWriter(ServletResponseWrapper.java:114)
at org.apache.turbine.services.rundata.DefaultTurbineRunData.getOut(DefaultTurbineRunData.java:928)
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:655)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:764)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:711)
at org.apache.catalina.core.ApplicationDispatcher.doInclude(ApplicationDispatcher.java:578)
at org.apache.catalina.core.ApplicationDispatcher.include(ApplicationDispatcher.java:517)
at org.apache.catalina.core.StandardHostValve.custom(StandardHostValve.java:384)
at org.apache.catalina.core.StandardHostValve.throwable(StandardHostValve.java:327)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:687)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:360)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:399)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:890)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1789)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:750)
2025-07-31 22:41:32,998 [http-nio-8080-exec-3] ERROR org.apache.turbine.Turbine - getOutputStream() has already been called for this response
java.lang.IllegalStateException: getOutputStream() has already been called for this response
at org.apache.catalina.connector.Response.getWriter(Response.java:584)
at org.apache.catalina.connector.ResponseFacade.getWriter(ResponseFacade.java:227)
at javax.servlet.ServletResponseWrapper.getWriter(ServletResponseWrapper.java:114)
at org.apache.turbine.services.rundata.DefaultTurbineRunData.getOut(DefaultTurbineRunData.java:928)
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.handleException(Turbine.java:1008)
at org.apache.turbine.Turbine.doGet(Turbine.java:867)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:655)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:764)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:711)
at org.apache.catalina.core.ApplicationDispatcher.doInclude(ApplicationDispatcher.java:578)
at org.apache.catalina.core.ApplicationDispatcher.include(ApplicationDispatcher.java:517)
at org.apache.catalina.core.StandardHostValve.custom(StandardHostValve.java:384)
at org.apache.catalina.core.StandardHostValve.throwable(StandardHostValve.java:327)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:687)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:360)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:399)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:890)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1789)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:750)
2025-07-31 22:41:32,790 - ddrucker 172.29.158.193 GET http://iris.mclean.harvard.edu/xapi/viewer/projects/clancy/experiments/Iris_E05346/exists "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.6 Safari/605.1.15"
2025-07-31 22:41:32,889 - ddrucker 172.29.158.193 GET http://iris.mclean.harvard.edu/xapi/viewer/projects/clancy/experiments/Iris_E05346 "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.6 Safari/605.1.15"
==> ohifviewer.log <==
2025-07-31 22:41:32,791 [http-nio-8080-exec-2] DEBUG org.nrg.xnatx.plugin.Security - Permission check - User: ddrucker, Permission: Read, Element: xnat:projectData/ID, Value: clancy
2025-07-31 22:41:32,793 [http-nio-8080-exec-2] DEBUG org.nrg.xnatx.plugin.Security - Project visible to user ddrucker: clancy
2025-07-31 22:41:32,793 [http-nio-8080-exec-2] DEBUG org.nrg.xnatx.plugin.Security - Permission check - User: ddrucker, Permission: Read, Element: xnat:imageSessionData/ID, Value: Iris_E05346
2025-07-31 22:41:32,817 [http-nio-8080-exec-2] DEBUG org.nrg.xnatx.plugin.Security - Session visible to user ddrucker: Iris_E05346
2025-07-31 22:41:32,826 [http-nio-8080-exec-2] DEBUG org.nrg.xnatx.plugin.Security - Permission check - User: ddrucker, Permission: Read, Element: xnat:mrSessionData/project, Value: clancy
2025-07-31 22:41:32,828 [http-nio-8080-exec-2] INFO org.nrg.xnatx.plugin.PluginUtils - Experiment Iris_E05346 belongs to project clancy
2025-07-31 22:41:32,829 [http-nio-8080-exec-2] DEBUG org.nrg.xnatx.ohifviewer.inputcreator.JsonMetadataHandler - Stored JSON revision: 2
2025-07-31 22:41:32,889 [http-nio-8080-exec-3] DEBUG org.nrg.xnatx.plugin.Security - Permission check - User: ddrucker, Permission: Read, Element: xnat:projectData/ID, Value: clancy
2025-07-31 22:41:32,891 [http-nio-8080-exec-3] DEBUG org.nrg.xnatx.plugin.Security - Project visible to user ddrucker: clancy
2025-07-31 22:41:32,892 [http-nio-8080-exec-3] DEBUG org.nrg.xnatx.plugin.Security - Permission check - User: ddrucker, Permission: Read, Element: xnat:imageSessionData/ID, Value: Iris_E05346
2025-07-31 22:41:32,902 [http-nio-8080-exec-3] DEBUG org.nrg.xnatx.plugin.Security - Session visible to user ddrucker: Iris_E05346
2025-07-31 22:41:32,911 [http-nio-8080-exec-3] DEBUG org.nrg.xnatx.plugin.Security - Permission check - User: ddrucker, Permission: Read, Element: xnat:mrSessionData/project, Value: clancy
2025-07-31 22:41:32,913 [http-nio-8080-exec-3] INFO org.nrg.xnatx.plugin.PluginUtils - Experiment Iris_E05346 belongs to project clancy
2025-07-31 22:41:32,914 [http-nio-8080-exec-3] DEBUG org.nrg.xnatx.ohifviewer.inputcreator.JsonMetadataHandler - Stored JSON revision: 2
2025-07-31 22:41:32,914 [http-nio-8080-exec-3] DEBUG org.nrg.xnatx.ohifviewer.service.HibernateOhifSessionDataService - Fetching session JSON for sessionId=Iris_E05346
2025-07-31 22:41:32,918 [http-nio-8080-exec-3] ERROR org.nrg.xnatx.ohifviewer.xapi.OhifViewerControllerAdvice - Error executing request - Failed to obtain stream - Cause: ERROR: large object 438334 does not exist
org.nrg.xnatx.plugin.PluginException: Failed to obtain stream
at org.nrg.xnatx.ohifviewer.service.HibernateOhifSessionDataService.getSessionJsonReader(HibernateOhifSessionDataService.java:117)
at org.nrg.xnatx.ohifviewer.service.HibernateOhifSessionDataService.transferSessionJson(HibernateOhifSessionDataService.java:94)
at org.nrg.xnatx.ohifviewer.service.HibernateOhifSessionDataService$$FastClassBySpringCGLIB$$ed840c12.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:792)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:762)
at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:123)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:388)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:762)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:707)
at org.nrg.xnatx.ohifviewer.service.HibernateOhifSessionDataService$$EnhancerBySpringCGLIB$$ef6f922d.transferSessionJson(<generated>)
at org.nrg.xnatx.ohifviewer.xapi.OhifViewerApi.getExperimentJson(OhifViewerApi.java:198)
at org.nrg.xnatx.ohifviewer.xapi.OhifViewerApi$$FastClassBySpringCGLIB$$73803578.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:792)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:762)
at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:89)
at org.nrg.xapi.rest.aspects.XapiRequestMappingAspect.processXapiRequest(XapiRequestMappingAspect.java:89)
at sun.reflect.GeneratedMethodAccessor306.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:634)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:624)
at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:72)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:762)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:762)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:707)
at org.nrg.xnatx.ohifviewer.xapi.OhifViewerApi$$EnhancerBySpringCGLIB$$f797e1f4.getExperimentJson(<generated>)
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.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205)
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:150)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:117)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:903)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:809)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1072)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:965)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:655)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:764)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:239)
at net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:215)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:337)
at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:115)
at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:81)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:122)
at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:116)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:126)
at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:81)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:109)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.nrg.xnat.security.XnatInitCheckFilter.doFilterInternal(XnatInitCheckFilter.java:41)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:149)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.nrg.xnat.security.XnatExpiredPasswordFilter.doFilterInternal(XnatExpiredPasswordFilter.java:109)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.nrg.xnat.security.XnatBasicAuthenticationFilter.doFilterInternal(XnatBasicAuthenticationFilter.java:117)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.session.ConcurrentSessionFilter.doFilter(ConcurrentSessionFilter.java:147)
at org.springframework.security.web.session.ConcurrentSessionFilter.doFilter(ConcurrentSessionFilter.java:125)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:223)
at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:217)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:223)
at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:217)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:103)
at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:89)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.header.HeaderWriterFilter.doHeadersAfter(HeaderWriterFilter.java:90)
at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:75)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:112)
at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:82)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:55)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.access.channel.ChannelProcessingFilter.doFilter(ChannelProcessingFilter.java:133)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.session.DisableEncodeUrlFilter.doFilterInternal(DisableEncodeUrlFilter.java:42)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:346)
at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:221)
at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:186)
at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:354)
at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:267)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:197)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:687)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:360)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:399)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:890)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1789)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:750)
Caused by: org.postgresql.util.PSQLException: ERROR: large object 438334 does not exist
at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2725)
at org.postgresql.core.v3.QueryExecutorImpl.receiveFastpathResult(QueryExecutorImpl.java:888)
at org.postgresql.core.v3.QueryExecutorImpl.fastpathCall(QueryExecutorImpl.java:668)
at org.postgresql.fastpath.Fastpath.fastpath(Fastpath.java:110)
at org.postgresql.fastpath.Fastpath.fastpath(Fastpath.java:152)
at org.postgresql.fastpath.Fastpath.getInteger(Fastpath.java:164)
at org.postgresql.largeobject.LargeObject.<init>(LargeObject.java:107)
at org.postgresql.largeobject.LargeObjectManager.open(LargeObjectManager.java:247)
at org.postgresql.largeobject.LargeObjectManager.open(LargeObjectManager.java:230)
at org.postgresql.jdbc.AbstractBlobClob.getLo(AbstractBlobClob.java:288)
at org.postgresql.jdbc.AbstractBlobClob.getBinaryStream(AbstractBlobClob.java:127)
at org.postgresql.jdbc.PgClob.getCharacterStream(PgClob.java:76)
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.hibernate.engine.jdbc.SerializableClobProxy.invoke(SerializableClobProxy.java:60)
at com.sun.proxy.$Proxy358.getCharacterStream(Unknown Source)
at org.nrg.xnatx.ohifviewer.service.HibernateOhifSessionDataService.getSessionJsonReader(HibernateOhifSessionDataService.java:115)
... 138 common frames omitted
==> turbine.log <==
2025-07-31 22:41:32,975 [http-nio-8080-exec-3] ERROR org.apache.turbine.Turbine - Turbine.handleException:
java.lang.IllegalStateException: getOutputStream() has already been called for this response
at org.apache.catalina.connector.Response.getWriter(Response.java:584)
at org.apache.catalina.connector.ResponseFacade.getWriter(ResponseFacade.java:227)
at javax.servlet.ServletResponseWrapper.getWriter(ServletResponseWrapper.java:114)
at org.apache.turbine.services.rundata.DefaultTurbineRunData.getOut(DefaultTurbineRunData.java:928)
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:655)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:764)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:711)
at org.apache.catalina.core.ApplicationDispatcher.doInclude(ApplicationDispatcher.java:578)
at org.apache.catalina.core.ApplicationDispatcher.include(ApplicationDispatcher.java:517)
at org.apache.catalina.core.StandardHostValve.custom(StandardHostValve.java:384)
at org.apache.catalina.core.StandardHostValve.throwable(StandardHostValve.java:327)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:687)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:360)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:399)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:890)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1789)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:750)
2025-07-31 22:41:32,998 [http-nio-8080-exec-3] ERROR org.apache.turbine.Turbine - getOutputStream() has already been called for this response
java.lang.IllegalStateException: getOutputStream() has already been called for this response
at org.apache.catalina.connector.Response.getWriter(Response.java:584)
at org.apache.catalina.connector.ResponseFacade.getWriter(ResponseFacade.java:227)
at javax.servlet.ServletResponseWrapper.getWriter(ServletResponseWrapper.java:114)
at org.apache.turbine.services.rundata.DefaultTurbineRunData.getOut(DefaultTurbineRunData.java:928)
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.handleException(Turbine.java:1008)
at org.apache.turbine.Turbine.doGet(Turbine.java:867)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:655)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:764)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:711)
at org.apache.catalina.core.ApplicationDispatcher.doInclude(ApplicationDispatcher.java:578)
at org.apache.catalina.core.ApplicationDispatcher.include(ApplicationDispatcher.java:517)
at org.apache.catalina.core.StandardHostValve.custom(StandardHostValve.java:384)
at org.apache.catalina.core.StandardHostValve.throwable(StandardHostValve.java:327)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:687)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:360)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:399)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:890)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1789)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:750)
Timothy Olsen
Jul 31, 2025, 7:28:21 PMJul 31
to xnat_di...@googlegroups.com
I think if you were able to delete the corresponding rows from the 'xhbm_ohif_session_data' table, then the viewer would regenerate the missing content.
To view this discussion visit https://groups.google.com/d/msgid/xnat_discussion/36bdb491-c9fc-4311-a18f-326b657e108bn%40googlegroups.com.
Daniel Drucker
Jul 31, 2025, 7:53:55 PMJul 31
to xnat_discussion
Could you give me a hint? I'm real leery of touching stuff like this.
xnat=# select * from xhbm_ohif_session_data limit 5;
id | created | disabled | enabled | timestamp | revision | session_id | session_json
----+-------------------------+---------------------+---------+-------------------------+----------+-------------+--------------
1 | 2023-03-14 02:07:29.983 | 1970-01-01 00:00:00 | t | 2023-03-14 02:07:29.983 | 2 | Iris_E01721 | 242879
2 | 2023-03-14 13:39:11.872 | 1970-01-01 00:00:00 | t | 2023-03-14 14:02:54.127 | 2 | Iris_E01756 | 242889
3 | 2023-03-15 11:40:12.751 | 1970-01-01 00:00:00 | t | 2023-03-15 11:40:12.751 | 2 | Iris_E01757 | 242988
4 | 2023-03-15 13:59:13.179 | 1970-01-01 00:00:00 | t | 2023-03-15 13:59:13.179 | 2 | Iris_E01758 | 243003
6 | 2023-03-15 19:05:07.015 | 1970-01-01 00:00:00 | t | 2023-03-15 19:05:07.015 | 2 | Iris_E01626 | 243174
(5 rows)
xnat=# select count(*) from xhbm_ohif_session_data limit 5;
count
-------
3609
(1 row)
id | created | disabled | enabled | timestamp | revision | session_id | session_json
----+-------------------------+---------------------+---------+-------------------------+----------+-------------+--------------
1 | 2023-03-14 02:07:29.983 | 1970-01-01 00:00:00 | t | 2023-03-14 02:07:29.983 | 2 | Iris_E01721 | 242879
2 | 2023-03-14 13:39:11.872 | 1970-01-01 00:00:00 | t | 2023-03-14 14:02:54.127 | 2 | Iris_E01756 | 242889
3 | 2023-03-15 11:40:12.751 | 1970-01-01 00:00:00 | t | 2023-03-15 11:40:12.751 | 2 | Iris_E01757 | 242988
4 | 2023-03-15 13:59:13.179 | 1970-01-01 00:00:00 | t | 2023-03-15 13:59:13.179 | 2 | Iris_E01758 | 243003
6 | 2023-03-15 19:05:07.015 | 1970-01-01 00:00:00 | t | 2023-03-15 19:05:07.015 | 2 | Iris_E01626 | 243174
(5 rows)
xnat=# select count(*) from xhbm_ohif_session_data limit 5;
count
-------
3609
(1 row)
Should I literally just DELETE FROM `xhbm_ohif_session_data`?
Daniel Drucker
Jul 31, 2025, 8:00:48 PMJul 31
to xnat_discussion
Ok, yeah, I tested that with a single row, and it does work. So I guess I'll just blow those away.
Is there any way to have it auto-generate these - at least for newly added sessions, not old ones - BEFORE the first view? I feel like I've asked this before and gotten a positive answer but now I can't find it.
Timothy Olsen
Jul 31, 2025, 8:08:07 PMJul 31
to xnat_di...@googlegroups.com
You could dump the table out to csv before deleting the contents if you want to be safe.
The swagger docs say you should be able to do this:
POST/viewer/projects/{projectId}/experiments/{experimentId}
If you haven't deleted the rows from the table yet, then you could join from the ohif table to the experiment table to get the list of expected experiments. Write that out to a csv. Then AI can easily generate a script that takes that in and issues that POST command.
SELECT expt.project, expt.id FROM xhbm_ohif_session_data ohif LEFT JOIN xnat_experimentData expt ON ohif.session_id=expt.id;
The swagger docs say you should be able to do this:
POST/viewer/projects/{projectId}/experiments/{experimentId}
Generates the session JSON for the specified experiment ID.
If you haven't deleted the rows from the table yet, then you could join from the ohif table to the experiment table to get the list of expected experiments. Write that out to a csv. Then AI can easily generate a script that takes that in and issues that POST command.
SELECT expt.project, expt.id FROM xhbm_ohif_session_data ohif LEFT JOIN xnat_experimentData expt ON ohif.session_id=expt.id;
To view this discussion visit https://groups.google.com/d/msgid/xnat_discussion/0595d913-5965-4dec-998e-cbeadd02e571n%40googlegroups.com.
Daniel Drucker
Jul 31, 2025, 8:18:10 PMJul 31
to xnat_discussion
I deleted the rows, and it worked just fine - everything works now, it's just slightly slow (not awful, like 15-30s the first time).
It does look like newly added sessions get the OHIF cache auto-generated when they are received. I'm not sure what the mechanism of that is, but it does seem to happen, so that's great.
Thanks! And BTW ... whatever is responsible for making those large objects, they really should be storing the OID in an oid field so postgres is aware of it!
Daniel
Daniel Drucker
Jul 31, 2025, 8:18:26 PMJul 31
to xnat_discussion
(and maybe it shouldn't be happening in the database, like you said...)
Daniel Drucker
Aug 1, 2025, 10:58:54 PMAug 1
to xnat_discussion
I'm almost there, I think!
I am running XNAT 1.9.2.1 now with postgres 16.9, having done a dump from 12 into 16.
I can log in, see images, download images... all but one thing, which is if I go to e.g.:
I get a resultset like the below, but if I try to retrieve e.g.:
/data/experiments/Iris3_E02450/scans/1/resources/97178/
or
/data/experiments/Iris3_E02450/scans/1/resources/97178/files/1.2.840.113837.1889284432.1581541425.0-1-7-alp9hi.dcm
... the request just hangs forever. I think there's maybe some other table that got messed up. Can you please help me fix that?
The data's clearly all still there - I can download stuff - individual files or entire studies, and view it in OHIF, but access with that syntax fails.
{
"ResultSet": {
"Result": [
{
"file_count": "2",
"xnat_abstractresource_id": "435035",
"cat_desc": "localizer",
"cat_id": "1",
"format": "GIF",
"label": "SNAPSHOTS",
"category": "scans",
"element_name": "xnat:resourceCatalog",
"file_size": "135141",
"content": "SNAPSHOTS",
"tags": ""
},
{
"file_count": "7",
"xnat_abstractresource_id": "97178",
"cat_desc": "localizer",
"cat_id": "1",
"format": "DICOM",
"label": "DICOM",
"category": "scans",
"element_name": "xnat:resourceCatalog",
"file_size": "4737372",
"content": "RAW",
"tags": ""
}
],
"totalRecords": "2",
"title": "Resources"
}
}
"ResultSet": {
"Result": [
{
"file_count": "2",
"xnat_abstractresource_id": "435035",
"cat_desc": "localizer",
"cat_id": "1",
"format": "GIF",
"label": "SNAPSHOTS",
"category": "scans",
"element_name": "xnat:resourceCatalog",
"file_size": "135141",
"content": "SNAPSHOTS",
"tags": ""
},
{
"file_count": "7",
"xnat_abstractresource_id": "97178",
"cat_desc": "localizer",
"cat_id": "1",
"format": "DICOM",
"label": "DICOM",
"category": "scans",
"element_name": "xnat:resourceCatalog",
"file_size": "4737372",
"content": "RAW",
"tags": ""
}
],
"totalRecords": "2",
"title": "Resources"
}
}
Daniel Drucker
Aug 1, 2025, 11:01:40 PMAug 1
to xnat_discussion
And it looks like while it's sitting there spinning there's a postgres SELECT taking 100% CPU.
Daniel Drucker
Aug 2, 2025, 7:00:22 AMAug 2
to xnat_discussion
Absolutely nothing appears in any of the logs when this happens other than the GET in the access.log.
Daniel Drucker
Aug 2, 2025, 7:07:35 AMAug 2
to xnat_discussion
Sorry for so many messages. One more clue: Using a syntax that does not involve the xnat_abstractresource_id does work, e.g.:
/data/experiments/Iris_E05368/scans/localizer/files?format=zip
works just fine. It's just this format:
/data/experiments/Iris3_E02450/scans/1/resources/97178/
that hangs.
Daniel Drucker
Aug 2, 2025, 5:03:43 PMAug 2
to xnat_discussion
FIXED!!!!!
I ran ANALYZE which ran for about 10 seconds, and after that, the problem has gone away!
Timothy Olsen
Aug 2, 2025, 5:07:30 PMAug 2
to xnat_di...@googlegroups.com
Awesome!!!
For the records, did you run it database wide or just on one table? Was it with a VACUUM call?
To view this discussion visit https://groups.google.com/d/msgid/xnat_discussion/d270e782-c0a9-4d9f-b96f-356ea82a1704n%40googlegroups.com.
Daniel Drucker
Aug 2, 2025, 5:13:43 PMAug 2
to xnat_discussion
All I did was run ANALYZE.
xnat=> ANALYZE;
WARNING: permission denied to analyze "pg_authid", skipping it
WARNING: permission denied to analyze "pg_subscription", skipping it
WARNING: permission denied to analyze "pg_database", skipping it
WARNING: permission denied to analyze "pg_db_role_setting", skipping it
WARNING: permission denied to analyze "pg_tablespace", skipping it
WARNING: permission denied to analyze "pg_auth_members", skipping it
WARNING: permission denied to analyze "pg_shdepend", skipping it
WARNING: permission denied to analyze "pg_shdescription", skipping it
WARNING: permission denied to analyze "pg_replication_origin", skipping it
WARNING: permission denied to analyze "pg_shseclabel", skipping it
WARNING: permission denied to analyze "pg_parameter_acl", skipping it
ANALYZE
xnat=>
WARNING: permission denied to analyze "pg_authid", skipping it
WARNING: permission denied to analyze "pg_subscription", skipping it
WARNING: permission denied to analyze "pg_database", skipping it
WARNING: permission denied to analyze "pg_db_role_setting", skipping it
WARNING: permission denied to analyze "pg_tablespace", skipping it
WARNING: permission denied to analyze "pg_auth_members", skipping it
WARNING: permission denied to analyze "pg_shdepend", skipping it
WARNING: permission denied to analyze "pg_shdescription", skipping it
WARNING: permission denied to analyze "pg_replication_origin", skipping it
WARNING: permission denied to analyze "pg_shseclabel", skipping it
WARNING: permission denied to analyze "pg_parameter_acl", skipping it
ANALYZE
xnat=>
This btw after a very long conversation with Claude Code; I am extremely impressed. I'll let it speak for itself:
> Write a concise description of the debugging steps we went through today, suitable for posting on a mailing list so the developers understand what happened here.
XNAT Resource Access Hanging After PostgreSQL 12→16 Migration
Problem: After migrating from PostgreSQL 12 to 16 using pg_dump/restore, URLs like
/data/experiments/{ID}/scans/{ID}/resources/{ID}/ began hanging indefinitely, while simpler URLs like
/data/experiments/{ID}/scans/{ID}/files continued working normally.
Debugging Steps:
1. Confirmed database connectivity - Direct SQL queries on resource tables worked fine
2. Used jstack thread dump - Showed Java thread stuck in XNATCatalogTemplate.<init>() at line 62, waiting for
PostgreSQL response
3. Checked pg_stat_activity - Found the complex security query from XNATCatalogTemplate.java:183-238 running for 3+
minutes
4. Examined the hanging query - The QUERY_FIND_RESOURCE_SECURE_OBJECTS query with multiple LEFT JOINs and
data_type_fns_can_action_entity() calls
Root Cause: PostgreSQL 16's query planner was making poor execution plan choices due to missing table statistics
after the migration. The pg_dump/restore process preserved data and schema but not the query planner statistics that
PostgreSQL 12 had accumulated.
Solution: Running ANALYZE; immediately fixed the issue by updating table statistics, allowing PostgreSQL 16's
planner to choose efficient execution plans.
Key Insight: The complex resource security query in XNATCatalogTemplate is particularly sensitive to planner
statistics. Consider documenting that ANALYZE should be run after any PostgreSQL major version migration.
Thread dump location: The hang occurs specifically in the XNATCatalogTemplate constructor when executing the named
parameter query for resource security validation, not in catalog file processing as initially suspected.
Problem: After migrating from PostgreSQL 12 to 16 using pg_dump/restore, URLs like
/data/experiments/{ID}/scans/{ID}/resources/{ID}/ began hanging indefinitely, while simpler URLs like
/data/experiments/{ID}/scans/{ID}/files continued working normally.
Debugging Steps:
1. Confirmed database connectivity - Direct SQL queries on resource tables worked fine
2. Used jstack thread dump - Showed Java thread stuck in XNATCatalogTemplate.<init>() at line 62, waiting for
PostgreSQL response
3. Checked pg_stat_activity - Found the complex security query from XNATCatalogTemplate.java:183-238 running for 3+
minutes
4. Examined the hanging query - The QUERY_FIND_RESOURCE_SECURE_OBJECTS query with multiple LEFT JOINs and
data_type_fns_can_action_entity() calls
Root Cause: PostgreSQL 16's query planner was making poor execution plan choices due to missing table statistics
after the migration. The pg_dump/restore process preserved data and schema but not the query planner statistics that
PostgreSQL 12 had accumulated.
Solution: Running ANALYZE; immediately fixed the issue by updating table statistics, allowing PostgreSQL 16's
planner to choose efficient execution plans.
Key Insight: The complex resource security query in XNATCatalogTemplate is particularly sensitive to planner
statistics. Consider documenting that ANALYZE should be run after any PostgreSQL major version migration.
Thread dump location: The hang occurs specifically in the XNATCatalogTemplate constructor when executing the named
parameter query for resource security validation, not in catalog file processing as initially suspected.
Daniel Drucker
Aug 2, 2025, 7:24:38 PMAug 2
to xnat_discussion
In retrospect, I should have known this - you're always supposed to ANALYZE after a postgres dump/restore.
Reply all
Reply to author
Forward
0 new messages