Error running storexml with latest dev 1.6

[David Just]

I got around to downloading and attepting a clean install of XNAT 1.6 today.  I got as far as attempting to store the base security.xml and ran into an error I have not seen before.  Has anybody else seen this:

2012-07-31 14:32:26,381 [main] INFO  org.nrg.xft.XFT - WARNING: Data Type:wrk:abstractExecutionEnvironment has no columns which uniquely identify it.
2012-07-31 14:32:26,383 [main] INFO  org.nrg.xft.XFT - WARNING: Data Type:wrk:xnatExecutionEnvironment has no columns which uniquely identify it.
2012-07-31 14:32:26,383 [main] INFO  org.nrg.xft.XFT - WARNING: Data Type:wrk:xnatExecutionEnvironment_notify has no columns which uniquely identify it.
2012-07-31 14:32:26,613 [main] INFO  org.nrg.xft.XFT - WARNING: Data Type:cat:catalog has no columns which uniquely identify it.
2012-07-31 14:32:26,614 [main] INFO  org.nrg.xft.XFT - WARNING: Data Type:cat:catalog_metaField has no columns which uniquely identify it.
2012-07-31 14:32:26,614 [main] INFO  org.nrg.xft.XFT - WARNING: Data Type:cat:catalog_tag has no columns which uniquely identify it.
2012-07-31 14:32:26,615 [main] INFO  org.nrg.xft.XFT - WARNING: Data Type:cat:entry has no columns which uniquely identify it.
2012-07-31 14:32:26,615 [main] INFO  org.nrg.xft.XFT - WARNING: Data Type:cat:entry_metaField has no columns which uniquely identify it.
2012-07-31 14:32:26,615 [main] INFO  org.nrg.xft.XFT - WARNING: Data Type:cat:entry_tag has no columns which uniquely identify it.
2012-07-31 14:32:26,616 [main] INFO  org.nrg.xft.XFT - WARNING: Data Type:cat:dcmEntry has no columns which uniquely identify it.
2012-07-31 14:32:26,616 [main] INFO  org.nrg.xft.XFT - WARNING: Data Type:cat:dcmCatalog has no columns which uniquely identify it.
2012-07-31 14:32:26,807 [main] INFO  org.nrg.xft.XFT - WARNING: Data Type:pipe:PipelineRepository has no columns which uniquely identify it.
2012-07-31 14:32:26,807 [main] INFO  org.nrg.xft.XFT - WARNING: Data Type:pipe:pipelineDetails_element has no columns which uniquely identify it.
2012-07-31 14:32:26,807 [main] INFO  org.nrg.xft.XFT - WARNING: Data Type:pipe:pipelineDetails_parameter has no columns which uniquely identify it.
2012-07-31 14:32:26,963 [main] INFO  org.nrg.xft.XFT - WARNING: Data Type:arc:project_pipeline has no columns which uniquely identify it.
2012-07-31 14:32:26,964 [main] INFO  org.nrg.xft.XFT - WARNING: Data Type:arc:pathInfo has no columns which uniquely identify it.
2012-07-31 14:32:27,251 [main] INFO  org.nrg.xft.XFT - WARNING: Data Type:val:additionalVal has no columns which uniquely identify it.
2012-07-31 14:32:27,419 [main] INFO  org.nrg.xft.XFT - WARNING: Data Type:xnat:statisticsData has no columns which uniquely identify it.
2012-07-31 14:32:27,419 [main] INFO  org.nrg.xft.XFT - WARNING: Data Type:xnat:abstractStatistics has no columns which uniquely identify it.
2012-07-31 14:32:27,421 [main] INFO  org.nrg.xft.XFT - WARNING: Data Type:xnat:contrastBolus has no columns which uniquely identify it.
2012-07-31 14:32:31,300 [main] INFO  org.nrg.xdat.XDAT - Initializing Display Manager
2012-07-31 14:32:31,555 [main] INFO  org.nrg.xdat.XDATTool - security/security.xml,null,true
2012-07-31 14:32:31,556 [main] INFO  org.nrg.xdat.XDATTool - Found Document:security/security.xml
2012-07-31 14:32:32,384 [main] INFO  org.nrg.xdat.XDATTool - Loaded XML Item:xdat:security
2012-07-31 14:32:32,583 [main] INFO  org.nrg.xdat.XDATTool - Validation: PASSED
2012-07-31 14:32:32,589 [main] ERROR org.nrg.xft.event.persist.PersistentWorkflowUtils -
java.lang.ClassNotFoundException: org.nrg.xnat.utils.WorkflowUtils
    at java.net.URLClassLoader$1.run(URLClassLoader.java:202)
    at java.security.AccessController.doPrivileged(Native Method)
    at java.net.URLClassLoader.findClass(URLClassLoader.java:190)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:306)
    at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:301)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:247)
    at java.lang.Class.forName0(Native Method)
    at java.lang.Class.forName(Class.java:169)
    at org.nrg.xft.event.persist.PersistentWorkflowUtils.getWorkflowBuilder(PersistentWorkflowUtils.java:30)
    at org.nrg.xft.event.persist.PersistentWorkflowUtils.buildOpenWorkflow(PersistentWorkflowUtils.java:64)
    at org.nrg.xft.event.persist.PersistentWorkflowUtils.buildOpenWorkflow(PersistentWorkflowUtils.java:111)
    at org.nrg.xft.event.persist.PersistentWorkflowUtils.buildAdminWorkflow(PersistentWorkflowUtils.java:138)
    at org.nrg.xdat.XDATTool.storeXML(XDATTool.java:198)
    at org.nrg.xdat.XDATTool.storeXML(XDATTool.java:127)
    at StoreXML.process(StoreXML.java:255)
    at org.nrg.xft.commandPrompt.CommandPromptTool._process(CommandPromptTool.java:205)
    at org.nrg.xft.commandPrompt.CommandPromptTool.run(CommandPromptTool.java:179)
    at org.nrg.xft.commandPrompt.CommandPromptTool.<init>(CommandPromptTool.java:77)
    at StoreXML.<init>(StoreXML.java:45)
    at StoreXML.main(StoreXML.java:49)
2012-07-31 14:32:32,606 [main] ERROR org.nrg.xft.XFT -
java.lang.NullPointerException
    at org.nrg.xft.event.persist.PersistentWorkflowUtils.buildOpenWorkflow(PersistentWorkflowUtils.java:64)
    at org.nrg.xft.event.persist.PersistentWorkflowUtils.buildOpenWorkflow(PersistentWorkflowUtils.java:111)
    at org.nrg.xft.event.persist.PersistentWorkflowUtils.buildAdminWorkflow(PersistentWorkflowUtils.java:138)
    at org.nrg.xdat.XDATTool.storeXML(XDATTool.java:198)
    at org.nrg.xdat.XDATTool.storeXML(XDATTool.java:127)
    at StoreXML.process(StoreXML.java:255)
    at org.nrg.xft.commandPrompt.CommandPromptTool._process(CommandPromptTool.java:205)
    at org.nrg.xft.commandPrompt.CommandPromptTool.run(CommandPromptTool.java:179)
    at org.nrg.xft.commandPrompt.CommandPromptTool.<init>(CommandPromptTool.java:77)
    at StoreXML.<init>(StoreXML.java:45)
    at StoreXML.main(StoreXML.java:49)

[Jordan Woerndle]

We saw that this morning and just pushed a fix (90 seconds ago) to bit bucket. give it a try and let us know if you still have problems.

thank you,

jordan

--
You received this message because you are subscribed to the Google Groups "xnat_discussion" group.
To post to this group, send email to xnat_di...@googlegroups.com.
To unsubscribe from this group, send email to xnat_discussi...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/xnat_discussion?hl=en.

[dave J]

That got me past the StoreXML, but now once I log in for the first i'm I am presented the config screen with an error at the bottom: ERROR 500: Failed to load site information.

xdat.log has a nullpointer exception:

2012-07-31 16:19:03,888 [http-8080-6] ERROR org.nrg.xnat.turbine.utils.ArcSpecManager - 

java.lang.NullPointerException

at org.nrg.xnat.helpers.prearchive.PrearcDatabase.getPrearcPath(PrearcDatabase.java:117)

at org.nrg.xnat.helpers.prearchive.PrearcDatabase.initDatabase(PrearcDatabase.java:96)

at org.nrg.xnat.turbine.utils.ArcSpecManager.GetInstance(ArcSpecManager.java:227)

at org.nrg.xnat.turbine.utils.ArcSpecManager.GetInstance(ArcSpecManager.java:53)

at org.nrg.xnat.turbine.modules.screens.Configuration.doBuildTemplate(Configuration.java:14)

at org.nrg.xdat.turbine.modules.screens.SecureScreen.doBuildTemplate(SecureScreen.java:161)

at org.apache.turbine.modules.screens.TemplateScreen.doBuild(TemplateScreen.java:100)

at org.apache.turbine.modules.Screen.build(Screen.java:57)

at org.apache.turbine.modules.ScreenLoader.eval(ScreenLoader.java:104)

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859)

at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:588)

at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)

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

jordan

To post to this group, send email to xnat_discussion@googlegroups.com.
To unsubscribe from this group, send email to xnat_discussion+unsubscribe@googlegroups.com.

[Jordan Woerndle]

This might be similar to a problem we're seeing on one instance here.. Similar stack trace, but we get a 404 instead of a 500.

are your text boxes empty and disabled so that you can't enter data even if you wanted?

Jordan

To view this discussion on the web visit https://groups.google.com/d/msg/xnat_discussion/-/2jeK5UcI6qwJ.

To post to this group, send email to xnat_di...@googlegroups.com.
To unsubscribe from this group, send email to xnat_discussi...@googlegroups.com.

[David Just]

Yes, text boxes are completely disabled.

[Jordan Woerndle]

The xdat log is unrelated because when you install a new XNAT from the 1.6 release and start Tomcat, before logging in and initializing the system, you may see a number of errors in the xdat.log and sql.log files. These are caused by delayed initialization of some of the dependent tables and will stop occurring once you've logged in and initialized the system settings. This includes the one you copied, plus, potentially:

PrearcTableBuilder PSQLException

2012-03-29 14:41:18,764 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-2] ERROR org.nrg.xnat.helpers.prearchive.PrearcTableBuilder - 
org.postgresql.util.PSQLException: ERROR: relation "xdat_search.prearchive" does not exist
  Position: 15
[truncated]

DBAction PSQLException

2012-03-29 14:42:07,225 [http-8080-6] ERROR org.nrg.xft.db.DBAction - org.postgresql.util.PSQLException: ERROR: relation "xdat_meta_element_meta_data" does not exist
  Where: PL/pgSQL function "update_ls_xdat_meta_element" line 6 at FOR over SELECT rows

The message that may appear in sql.log relates to the meta-data table initialization. It doesn't appear as an error, but may be repeated enough to cause concern and looks similar to this:

2012-03-29 14:42:19,886 - SELECT update_ls_xdat_meta_element(573,NULL)

Do you see anything else in your logs besides those?

Can you open firebug (or equivalent) and see if the network traffic or console gives you any idea which calls are failing?

Thank you,

Jordan

--

You received this message because you are subscribed to the Google Groups "xnat_discussion" group.

[David Just]

Axis.log 16128 [main] ERROR org.apache.axis.configuration.EngineConfigurationFactoryServlet  - Unable to find config file.  Creating new servlet engine config file: /WEB-INF/server-config.wsdd


Catalina.out:  
log4j:ERROR LogMananger.repositorySelector was null likely due to error in class reloading, using NOPLoggerRepository.
Jul 31, 2012 3:50:39 PM org.apache.catalina.loader.WebappClassLoader clearReferencesJdbc
SEVERE: The web application [] registered the JDBC driver [org.h2.Driver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
Jul 31, 2012 3:50:39 PM org.apache.catalina.loader.WebappClassLoader clearReferencesJdbc
SEVERE: The web application [] registered the JDBC driver [org.postgresql.Driver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
Jul 31, 2012 3:50:39 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [] appears to have started a thread named [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1] but has failed to stop it. This is very likely to create a memory leak.
Jul 31, 2012 3:50:39 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [] appears to have started a thread named [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-2] but has failed to stop it. This is very likely to create a memory leak.
Jul 31, 2012 3:50:39 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [] appears to have started a thread named [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-3] but has failed to stop it. This is very likely to create a memory leak.
Jul 31, 2012 3:50:39 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [] appears to have started a thread named [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-4] but has failed to stop it. This is very likely to create a memory leak.
Jul 31, 2012 3:50:39 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [] appears to have started a thread named [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-5] but has failed to stop it. This is very likely to create a memory leak.
Jul 31, 2012 3:50:39 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [] appears to have started a thread named [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] but has failed to stop it. This is very likely to create a memory leak.
Jul 31, 2012 3:50:39 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [] appears to have started a thread named [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-7] but has failed to stop it. This is very likely to create a memory leak.
Jul 31, 2012 3:50:39 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [] appears to have started a thread named [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-8] but has failed to stop it. This is very likely to create a memory leak.
Jul 31, 2012 3:50:39 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [] appears to have started a thread named [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-9] but has failed to stop it. This is very likely to create a memory leak.
Jul 31, 2012 3:50:39 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [] appears to have started a thread named [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-10] but has failed to stop it. This is very likely to create a memory leak.
Jul 31, 2012 3:50:39 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [] appears to have started a thread named [pool-1-thread-1] but has failed to stop it. This is very likely to create a memory leak.
Jul 31, 2012 3:50:39 PM org.apache.catalina.loader.WebappClassLoader clearThreadLocalMap
SEVERE: The web application [] created a ThreadLocal with key of type [org.apache.axis.utils.XMLUtils.ThreadLocalDocumentBuilder] (value [org.apache.axis.utils.XMLUtils$ThreadLocalDocumentBuilder@17be72ee]) and a value of type [org.apache.xerces.jaxp.DocumentBuilderImpl] (value [org.apache.xerces.jaxp.DocumentBuilderImpl@586b736f]) but failed to remove it when the web application was stopped. This is very likely to create a memory leak.
Jul 31, 2012 3:50:39 PM org.apache.catalina.loader.WebappClassLoader clearThreadLocalMap
SEVERE: The web application [] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@7667a9c2]) and a value of type [org.restlet.Context] (value [org.restlet.Context@fba3c49]) but failed to remove it when the web application was stopped. This is very likely to create a memory leak.
Jul 31, 2012 3:50:39 PM org.apache.catalina.loader.WebappClassLoader clearThreadLocalMap
SEVERE: The web application [] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@bcbe4b0]) and a value of type [org.restlet.data.Response] (value [org.restlet.data.Response@7712e4dc]) but failed to remove it when the web application was stopped. This is very likely to create a memory leak.
log4j:ERROR LogMananger.repositorySelector was null likely due to error in class reloading, using NOPLoggerRepository.
Jul 31, 2012 3:50:40 PM org.apache.coyote.http11.Http11Protocol destroy
INFO: Stopping Coyote HTTP/1.1 on http-8080
Listening for transport dt_socket at address: 8000
Jul 31, 2012 4:17:15 PM org.apache.catalina.startup.Embedded initDirs
SEVERE: Cannot find specified temporary folder at /Applications/Tomcat/temp
Jul 31, 2012 4:17:16 PM org.apache.catalina.core.AprLifecycleListener init
INFO: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: .:/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java
Jul 31, 2012 4:17:16 PM org.apache.coyote.http11.Http11Protocol init
INFO: Initializing Coyote HTTP/1.1 on http-8080
Jul 31, 2012 4:17:16 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 1071 ms
Jul 31, 2012 4:17:16 PM org.apache.catalina.core.StandardService start
INFO: Starting service Catalina
Jul 31, 2012 4:17:16 PM org.apache.catalina.core.StandardEngine start
INFO: Starting Servlet Engine: Apache Tomcat/6.0.32
WEBAPP:/adir_xnat
SOURCE: /Applications/Tomcat/webapps/adir_xnat/
log4j:WARN No such property [immediateFlush] in org.apache.log4j.jdbc.JDBCAppender.
log4j:WARN No such property [datePattern] in org.apache.log4j.jdbc.JDBCAppender.
log4j:WARN No such property [append] in org.apache.log4j.jdbc.JDBCAppender.
SLF4J: The requested version 1.5.8 by your slf4j binding is not compatible with [1.5.5, 1.5.6]
SLF4J: See http://www.slf4j.org/codes.html#version_mismatch for further details.
done
done
Hibernate: insert into xhbm_xdat_user_auth (created, disabled, enabled, timestamp, auth_method, auth_method_id, auth_user, failed_login_attempts, password_updated, xdat_username, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
Hibernate: insert into xhbm_xdat_user_auth (created, disabled, enabled, timestamp, auth_method, auth_method_id, auth_user, failed_login_attempts, password_updated, xdat_username, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
Hibernate: insert into xhbm_xdat_user_auth (created, disabled, enabled, timestamp, auth_method, auth_method_id, auth_user, failed_login_attempts, password_updated, xdat_username, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
Hibernate: select this_.id as id0_1_, this_.created as created0_1_, this_.disabled as disabled0_1_, this_.enabled as enabled0_1_, this_.timestamp as timestamp0_1_, this_.config_data as config8_4_1_, this_.path as path4_1_, this_.project as project4_1_, this_.reason as reason4_1_, this_.status as status4_1_, this_.tool as tool4_1_, this_.version as version4_1_, this_.xnat_user as xnat7_4_1_, configurat2_.id as id0_0_, configurat2_.created as created0_0_, configurat2_.disabled as disabled0_0_, configurat2_.enabled as enabled0_0_, configurat2_.timestamp as timestamp0_0_, configurat2_.contents as contents5_0_ from xhbm_configuration this_ left outer join xhbm_configuration_data configurat2_ on this_.config_data=configurat2_.id where this_.tool=? and this_.path=? and this_.project is null
Hibernate: select this_.id as id0_1_, this_.created as created0_1_, this_.disabled as disabled0_1_, this_.enabled as enabled0_1_, this_.timestamp as timestamp0_1_, this_.config_data as config8_4_1_, this_.path as path4_1_, this_.project as project4_1_, this_.reason as reason4_1_, this_.status as status4_1_, this_.tool as tool4_1_, this_.version as version4_1_, this_.xnat_user as xnat7_4_1_, configurat2_.id as id0_0_, configurat2_.created as created0_0_, configurat2_.disabled as disabled0_0_, configurat2_.enabled as enabled0_0_, configurat2_.timestamp as timestamp0_0_, configurat2_.contents as contents5_0_ from xhbm_configuration this_ left outer join xhbm_configuration_data configurat2_ on this_.config_data=configurat2_.id where this_.tool=? and this_.path=? and this_.project is null
Hibernate: insert into xhbm_configuration_data (created, disabled, enabled, timestamp, contents, id) values (?, ?, ?, ?, ?, ?)
Hibernate: insert into xhbm_configuration (created, disabled, enabled, timestamp, config_data, path, project, reason, status, tool, version, xnat_user, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
done
Jul 31, 2012 4:17:43 PM org.apache.catalina.startup.HostConfig deployDescriptor
INFO: Deploying configuration descriptor host-manager.xml
Jul 31, 2012 4:17:43 PM org.apache.catalina.startup.HostConfig deployDescriptor
INFO: Deploying configuration descriptor manager.xml
Jul 31, 2012 4:17:44 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory adir_xnat
WEBAPP:/adir_xnat
SOURCE: /Applications/Tomcat/webapps/adir_xnat/
log4j:WARN No such property [immediateFlush] in org.apache.log4j.jdbc.JDBCAppender.
log4j:WARN No such property [datePattern] in org.apache.log4j.jdbc.JDBCAppender.
log4j:WARN No such property [append] in org.apache.log4j.jdbc.JDBCAppender.
SLF4J: The requested version 1.5.8 by your slf4j binding is not compatible with [1.5.5, 1.5.6]
SLF4J: See http://www.slf4j.org/codes.html#version_mismatch for further details.
done
done
Hibernate: select this_.id as id0_1_, this_.created as created0_1_, this_.disabled as disabled0_1_, this_.enabled as enabled0_1_, this_.timestamp as timestamp0_1_, this_.config_data as config8_4_1_, this_.path as path4_1_, this_.project as project4_1_, this_.reason as reason4_1_, this_.status as status4_1_, this_.tool as tool4_1_, this_.version as version4_1_, this_.xnat_user as xnat7_4_1_, configurat2_.id as id0_0_, configurat2_.created as created0_0_, configurat2_.disabled as disabled0_0_, configurat2_.enabled as enabled0_0_, configurat2_.timestamp as timestamp0_0_, configurat2_.contents as contents5_0_ from xhbm_configuration this_ left outer join xhbm_configuration_data configurat2_ on this_.config_data=configurat2_.id where this_.tool=? and this_.path=? and this_.project is null
Hibernate: update xhbm_configuration_data set created=?, disabled=?, enabled=?, timestamp=?, contents=? where id=?
Hibernate: update xhbm_configuration set created=?, disabled=?, enabled=?, timestamp=?, config_data=?, path=?, project=?, reason=?, status=?, tool=?, version=?, xnat_user=? where id=?
done
Jul 31, 2012 4:18:16 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory docs
Jul 31, 2012 4:18:17 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory examples
Jul 31, 2012 4:18:17 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory oxygen
Jul 31, 2012 4:18:17 PM org.apache.coyote.http11.Http11Protocol start
INFO: Starting Coyote HTTP/1.1 on http-8080
done
done
done
done
Jul 31, 2012 4:18:17 PM org.apache.jk.common.ChannelSocket init
INFO: JK: ajp13 listening on /0.0.0.0:8009
Jul 31, 2012 4:18:17 PM org.apache.jk.server.JkMain start
INFO: Jk running ID=0 time=0/183  config=null
Jul 31, 2012 4:18:17 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 60976 ms
done
done
done
done
Hibernate: select this_.id as id0_1_, this_.created as created0_1_, this_.disabled as disabled0_1_, this_.enabled as enabled0_1_, this_.timestamp as timestamp0_1_, this_.config_data as config8_4_1_, this_.path as path4_1_, this_.project as project4_1_, this_.reason as reason4_1_, this_.status as status4_1_, this_.tool as tool4_1_, this_.version as version4_1_, this_.xnat_user as xnat7_4_1_, configurat2_.id as id0_0_, configurat2_.created as created0_0_, configurat2_.disabled as disabled0_0_, configurat2_.enabled as enabled0_0_, configurat2_.timestamp as timestamp0_0_, configurat2_.contents as contents5_0_ from xhbm_configuration this_ left outer join xhbm_configuration_data configurat2_ on this_.config_data=configurat2_.id where this_.tool=? and this_.path=? and this_.project is null
Hibernate: select this_.id as id0_1_, this_.created as created0_1_, this_.disabled as disabled0_1_, this_.enabled as enabled0_1_, this_.timestamp as timestamp0_1_, this_.config_data as config8_4_1_, this_.path as path4_1_, this_.project as project4_1_, this_.reason as reason4_1_, this_.status as status4_1_, this_.tool as tool4_1_, this_.version as version4_1_, this_.xnat_user as xnat7_4_1_, configurat2_.id as id0_0_, configurat2_.created as created0_0_, configurat2_.disabled as disabled0_0_, configurat2_.enabled as enabled0_0_, configurat2_.timestamp as timestamp0_0_, configurat2_.contents as contents5_0_ from xhbm_configuration this_ left outer join xhbm_configuration_data configurat2_ on this_.config_data=configurat2_.id where this_.tool=? and this_.path=? and this_.project is null
Hibernate: insert into xhbm_configuration_data (created, disabled, enabled, timestamp, contents, id) values (?, ?, ?, ?, ?, ?)
Hibernate: insert into xhbm_configuration (created, disabled, enabled, timestamp, config_data, path, project, reason, status, tool, version, xnat_user, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
done
Hibernate: select this_.id as id0_0_, this_.created as created0_0_, this_.disabled as disabled0_0_, this_.enabled as enabled0_0_, this_.timestamp as timestamp0_0_, this_.auth_method as auth1_3_0_, this_.auth_method_id as auth2_3_0_, this_.auth_user as auth3_3_0_, this_.failed_login_attempts as failed4_3_0_, this_.password_updated as password5_3_0_, this_.xdat_username as xdat6_3_0_ from xhbm_xdat_user_auth this_ where (this_.auth_method=? and this_.auth_user=?)
Hibernate: select this_.id as id0_0_, this_.created as created0_0_, this_.disabled as disabled0_0_, this_.enabled as enabled0_0_, this_.timestamp as timestamp0_0_, this_.auth_method as auth1_3_0_, this_.auth_method_id as auth2_3_0_, this_.auth_user as auth3_3_0_, this_.failed_login_attempts as failed4_3_0_, this_.password_updated as password5_3_0_, this_.xdat_username as xdat6_3_0_ from xhbm_xdat_user_auth this_ where (this_.auth_method=? and this_.auth_user=?)
Hibernate: select this_.id as id0_0_, this_.created as created0_0_, this_.disabled as disabled0_0_, this_.enabled as enabled0_0_, this_.timestamp as timestamp0_0_, this_.auth_method as auth1_3_0_, this_.auth_method_id as auth2_3_0_, this_.auth_user as auth3_3_0_, this_.failed_login_attempts as failed4_3_0_, this_.password_updated as password5_3_0_, this_.xdat_username as xdat6_3_0_ from xhbm_xdat_user_auth this_ where (this_.auth_method=? and this_.auth_user=?)
done
done
done
done
done
done
done
done
Hibernate: select this_.id as id0_1_, this_.created as created0_1_, this_.disabled as disabled0_1_, this_.enabled as enabled0_1_, this_.timestamp as timestamp0_1_, this_.config_data as config8_4_1_, this_.path as path4_1_, this_.project as project4_1_, this_.reason as reason4_1_, this_.status as status4_1_, this_.tool as tool4_1_, this_.version as version4_1_, this_.xnat_user as xnat7_4_1_, configurat2_.id as id0_0_, configurat2_.created as created0_0_, configurat2_.disabled as disabled0_0_, configurat2_.enabled as enabled0_0_, configurat2_.timestamp as timestamp0_0_, configurat2_.contents as contents5_0_ from xhbm_configuration this_ left outer join xhbm_configuration_data configurat2_ on this_.config_data=configurat2_.id where this_.tool=? and this_.path=? and this_.project is null
Hibernate: update xhbm_configuration_data set created=?, disabled=?, enabled=?, timestamp=?, contents=? where id=?
Hibernate: update xhbm_configuration set created=?, disabled=?, enabled=?, timestamp=?, config_data=?, path=?, project=?, reason=?, status=?, tool=?, version=?, xnat_user=? where id=?
done
done
Hibernate: select this_.id as id0_1_, this_.created as created0_1_, this_.disabled as disabled0_1_, this_.enabled as enabled0_1_, this_.timestamp as timestamp0_1_, this_.config_data as config8_4_1_, this_.path as path4_1_, this_.project as project4_1_, this_.reason as reason4_1_, this_.status as status4_1_, this_.tool as tool4_1_, this_.version as version4_1_, this_.xnat_user as xnat7_4_1_, configurat2_.id as id0_0_, configurat2_.created as created0_0_, configurat2_.disabled as disabled0_0_, configurat2_.enabled as enabled0_0_, configurat2_.timestamp as timestamp0_0_, configurat2_.contents as contents5_0_ from xhbm_configuration this_ left outer join xhbm_configuration_data configurat2_ on this_.config_data=configurat2_.id where this_.tool=? and this_.path=? and this_.project is null
Hibernate: select this_.id as id0_1_, this_.created as created0_1_, this_.disabled as disabled0_1_, this_.enabled as enabled0_1_, this_.timestamp as timestamp0_1_, this_.config_data as config8_4_1_, this_.path as path4_1_, this_.project as project4_1_, this_.reason as reason4_1_, this_.status as status4_1_, this_.tool as tool4_1_, this_.version as version4_1_, this_.xnat_user as xnat7_4_1_, configurat2_.id as id0_0_, configurat2_.created as created0_0_, configurat2_.disabled as disabled0_0_, configurat2_.enabled as enabled0_0_, configurat2_.timestamp as timestamp0_0_, configurat2_.contents as contents5_0_ from xhbm_configuration this_ left outer join xhbm_configuration_data configurat2_ on this_.config_data=configurat2_.id where this_.tool=? and this_.path=? and this_.project is null


That’s about it.

It appears that xnat is not picking up the settings from my build.properties file.

On 7/31/12 4:36 PM, "Jordan Woerndle" <jord...@gmail.com> wrote:

The xdat log is unrelated because when you install a new XNAT from the 1.6 release and start Tomcat, before logging in and initializing the system, you may see a number of errors in the xdat.log and sql.log files. These are caused by delayed initialization of some of the dependent tables and will stop occurring once you've logged in and initialized the system settings. This includes the one you copied, plus, potentially:

PrearcTableBuilder PSQLException

2012-03-29 14:41:18,764 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-2] ERROR org.nrg.xnat.helpers.prearchive.PrearcTableBuilder -
org.postgresql.util.PSQLException: ERROR: relation "xdat_search.prearchive" does not exist
  Position: 15
[truncated]
DBAction PSQLException

2012-03-29 14:42:07,225 [http-8080-6] ERROR org.nrg.xft.db.DBAction - org.postgresql.util.PSQLException: ERROR: relation "xdat_meta_element_meta_data" does not exist
  Where: PL/pgSQL function "update_ls_xdat_meta_element" line 6 at FOR over SELECT rows
The message that may appear in sql.log relates to the meta-data table initialization. It doesn't appear as an error, but may be repeated enough to cause concern and looks similar to this:

2012-03-29 14:42:19,886 - SELECT update_ls_xdat_meta_element(573,NULL)


Do you see anything else in your logs besides those?

Can you open firebug (or equivalent) and see if the network traffic or console gives you any idea which calls are failing?

Thank you,
Jordan

On Tue, Jul 31, 2012 at 4:31 PM, David Just <Just....@mayo.edu> wrote:

Yes, text boxes are completely disabled.


On 7/31/12 4:26 PM, "Jordan Woerndle" <jord...@gmail.com <http://jord...@gmail.com> > wrote:

This might be similar to a problem we're seeing on one instance here.. Similar stack trace, but we get a 404 instead of a 500.

are your text boxes empty and disabled so that you can't enter data even if you wanted?

Jordan

[Jordan Woerndle]

>It appears that xnat is not picking up the settings from my build.properties file. 

That's what we thought as well, but we can't pinpoint it on that one instance. Also, the 500 error makes me think it could be something different.

Can you hook a debugger up and step through the code? If so, set a few breakpoints in org.nrg.xnat.restlet.services.SettingsResetlet and let us know what you find.

Jordan

--

[Herrick, Rick]

David, most of those messages indicate anything in particular and really are just a herring shop:

 

·         The Axis message is a rather annoying message that we can’t seem to stomp out. It just means that we don’t have a wsdd configuration for Axis and that makes it rather grumpy. We don’t use Axis in the way that would require a wsdd configuration, so it pouts all the time.

·         Most of that hideous ERRORing going on in xdat.log consists of unclean teardown in the logging and scheduler frameworks. This is basically pointless: it won’t create a memory leak because it will soon be deceased and/or pining for the fjords. Again, something that shows up that we can’t get rid of in a non-trivial manner.

·         Things get interesting with the message: “INFO: The APR based Apache Tomcat Native…” This is where the restart happens. Everything after that is pretty normal initialization and bootstrapping of stuff in the database.

 

I’m not sure why you say: “It appears that xnat is not picking up the settings from my build.properties file.”

 

One thing to check is whether or not you have a build.properties file in your home folder (i.e. ~/build.properties). I just learned a valuable lesson around this particular item. Maven 1, in its wisdom, will look in your home folder and, if there is a build.properties file there, will use that in preference to the build.properties located right in the xnat_builder_1_6dev folder. Failure to know this simple fact results in plenty of frustration and cursing. At least, if you’re someone who reacts to such things with frustration and cursing and I assure you that I am. So if you’re seeing weird property settings, check on that possibility.

--

You received this message because you are subscribed to the Google Groups "xnat_discussion" group.
To post to this group, send email to xnat_di...@googlegroups.com.
To unsubscribe from this group, send email to xnat_discussi...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/xnat_discussion?hl=en.

---

The material in this message is private and may contain Protected Healthcare Information (PHI). 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.

[David Just]

I will have to get back to you.  I did not setup my eclipse for 1.6 so I still need to do that and I only had 1 day of time to work on it.  I will let you know if I can get back to it soon.   I didn’t see anything worthwhile in the logs ether but I forwarded them on just in case.

I do not have a build.properties file in my home directory.   During the build phase it correctly found and used the properties from my build file, but the values were not visible when I logged onto xnat.

[Herrick, Rick]

Ah, then what you’re seeing there is a failure of the settings restlet that drives the new configuration page. The values are most likely there, they’re just not making it from the server to your browser!

 

As of yesterday afternoon, I was getting through that portion of the build and installation process, so I think we’ve knocked that issue out. It was related to a code change over the weekend that started invoking the workflow engine before it was ready.

--

You received this message because you are subscribed to the Google Groups "xnat_discussion" group.
To post to this group, send email to xnat_di...@googlegroups.com.
To unsubscribe from this group, send email to xnat_discussi...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/xnat_discussion?hl=en.

[Jordan Woerndle]

David, 

I was under the assumption you had pulled the changes that should have fixed the restlet. Can you check which changeset you're running? The changes Rick spoke of are in 97ff709f0cd1 which I committed yesterday at 14:37 CST. That changeset  should have fixed issues with the settings restlet. Similar updates are in f19e3e933588 which I pushed at 14:58 yesterday. While the changes affect a similar bug, they aren't associated with settings.

Please let us know which commit you are using.

Thank you,

Jordan

[Haselgrove, Christian]

I just ran into the same problem ("500: Failed to load site information" and disabled text boxes) using the 1.6 release tarball.

Firebug reported the 500 in response to connection-min.js, with:

java.lang.IllegalStateException: Already listening - ServerSocket[unbound]
org.dcm4che2.net.NetworkConnection.bind(NetworkConnection.java:628)
org.dcm4che2.net.Device.startListening(Device.java:711)
org.nrg.dcm.DicomSCP.start(DicomSCP.java:170)

I had a 1.5.4 running as well, DICOM-listening on the port that 1.6 wanted. Changing the DICOM server port in WEB-INF/conf/dicom-import-context.xml did the trick for me.

c

--
Christian Haselgrove
christian....@umassmed.edu
508-856-5363
Fax: 508-856-8211