Page 1 of 1

Unable to restart Subsonic on NAS cleanly

PostPosted: Wed Jan 04, 2017 9:20 pm
by billraff
Hello all

Looking for some thoughts on whether this is an issue with the code or something unique to my setup.
The issue is that I have to restart my NAS in order to restart Subsonic.

Details:

Version 6.0 (build a7857c) – April 30, 2016
Server Apache Tomcat/7.0.73, java 1.8.0_91, Linux (100.3 MB / 119.9 MB)
Synology DS416j running DSM 6.0.2-8451 Update 7


So I am running Subsonic as an app under Tomcat 7. If I have a reason to restart Subsonic (NAS update, Tomcat update, etc) Tomcat cannot shut down
Subsonic completely. In the log I see:


INFO: A valid shutdown command was received via the shutdown port. Stopping the Server instance.
Jan 04, 2017 2:21:01 PM org.apache.coyote.AbstractProtocol pause
INFO: Pausing ProtocolHandler ["http-bio-7070"]
Jan 04, 2017 2:21:01 PM org.apache.coyote.AbstractProtocol pause
INFO: Pausing ProtocolHandler ["ajp-bio-8009"]
Jan 04, 2017 2:21:01 PM org.apache.catalina.core.StandardService stopInternal
INFO: Stopping service Catalina
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesJdbc
SEVERE: The web application [/subsonic] registered the JDBC driver [org.hsqldb.jdbcDriver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] appears to have started a thread named [HSQLDB Timer @9cdf1e] but has failed to stop it. This is very likely to create a memory leak.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] 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.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] appears to have started a thread named [Timer-0] but has failed to stop it. This is very likely to create a memory leak.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] appears to have started a thread named [pool-2-thread-1] but has failed to stop it. This is very likely to create a memory leak.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] appears to have started a thread named [pool-2-thread-2] but has failed to stop it. This is very likely to create a memory leak.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] appears to have started a thread named [cling-1] but has failed to stop it. This is very likely to create a memory leak.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] appears to have started a thread named [cling-2] but has failed to stop it. This is very likely to create a memory leak.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] appears to have started a thread named [cling-3] but has failed to stop it. This is very likely to create a memory leak.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] appears to have started a thread named [cling-4] but has failed to stop it. This is very likely to create a memory leak.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] appears to have started a thread named [pool-4-thread-1] but has failed to stop it. This is very likely to create a memory leak.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] appears to have started a thread named [Thread-8] but has failed to stop it. This is very likely to create a memory leak.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] appears to have started a thread named [pool-5-thread-1] but has failed to stop it. This is very likely to create a memory leak.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] appears to have started a thread named [pool-6-thread-1] but has failed to stop it. This is very likely to create a memory leak.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] appears to have started a thread named [AudioScrobbler Registration] but has failed to stop it. This is very likely to create a memory leak.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] appears to have started a thread named [cling-7583] but has failed to stop it. This is very likely to create a memory leak.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] appears to have started a thread named [cling-7588] but has failed to stop it. This is very likely to create a memory leak.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] appears to have started a thread named [cling-7593] but has failed to stop it. This is very likely to create a memory leak.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] appears to have started a thread named [cling-7594] but has failed to stop it. This is very likely to create a memory leak.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] appears to have started a thread named [cling-7595] but has failed to stop it. This is very likely to create a memory leak.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] appears to have started a thread named [cling-7596] but has failed to stop it. This is very likely to create a memory leak.
Jan 04, 2017 2:21:04 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [/subsonic] appears to have started a thread named [cling-7597] but has failed to stop it. This is very likely to create a memory leak.


Eventually it appears Tomcat just pulls the rug out and shuts down but it can't start Subsonic up again when it restarts because:

[2017-01-04 14:22:15,753] WARN org.springframework.beans.factory.support.DisposableBeanAdapter - Invocation of destroy method 'shutdown' failed on bean with name 'cxf': org.springframework.beans.factory.BeanCreationNotAllowedException: Error creating bean with name 'ajaxTagServiceSecure': Singleton bean creation not allowed while the singletons of this factory are in destruction (Do not request a bean from a BeanFactory in a destroy method implementation!)
[2017-01-04 14:22:15,756] ERROR org.springframework.web.context.ContextLoader - Context initialization failed
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'mediaFileService' defined in ServletContext resource [/WEB-INF/applicationContext-service.xml]: Cannot resolve reference to bean 'metaDataParserFactory' while setting bean property 'metaDataParserFactory'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'metaDataParserFactory' defined in ServletContext resource [/WEB-INF/applicationContext-service.xml]: Cannot create inner bean 'net.sourceforge.subsonic.service.metadata.FFmpegParser#6e20ab' of type [net.sourceforge.subsonic.service.metadata.FFmpegParser] while setting bean property 'parsers' with key [1]; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'net.sourceforge.subsonic.service.metadata.FFmpegParser#6e20ab' defined in ServletContext resource [/WEB-INF/applicationContext-service.xml]: Cannot resolve reference to bean 'transcodingService' while setting bean property 'transcodingService'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'transcodingService' defined in ServletContext resource [/WEB-INF/applicationContext-service.xml]: Cannot resolve reference to bean 'playerService' while setting bean property 'playerService'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'playerService' defined in ServletContext resource [/WEB-INF/applicationContext-service.xml]: Invocation of init method failed; nested exception is org.springframework.jdbc.CannotGetJdbcConnectionException: Could not get JDBC Connection; nested exception is java.sql.SQLException: The database is already in use by another process: org.hsqldb.persist.NIOLockFile@2d6451a6[file =/var/subsonic/db/subsonic.lck, exists=true, locked=false, valid=false, fl =null]: java.lang.Exception: checkHeartbeat(): lock file [/var/subsonic/db/subsonic.lck] is presumably locked by another process.
at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:275)
at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:104)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1245)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1010)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:472)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory$1.run(AbstractAutowireCapableBeanFactory.java:409)
at java.security.AccessController.doPrivileged(Native Method)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:380)
at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:264)
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222)
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:261)
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:185)
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:164)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:429)
at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:728)
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:380)
at org.springframework.web.context.ContextLoader.createWebApplicationContext(ContextLoader.java:255)
at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:199)
at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:45)
at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:5118)
at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5634)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:145)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:899)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:875)

I'd really like to not have to recycle the NAS to get the Subsonic application to shutdown and start up again. Inside the Tomcat admin if I
stop Subsonic it shows as shut down but you can't start it without restarting the NAS.
Anyone seen a situation like this before? Any thoughts/help appreciated.
Thanks in advance
-billraff