javatomcatsakai

Sakai 11 - Binary installation is successful and its webapps deploy, but they fail to start


OS: Windows 10

Java Version: 1.8.0_121-b13

Server Version: Apache Tomcat/8.0.32

I'm very new at Sakai and I've been trying to use it as a part of a homework. At first, I've tried to install it from source. Unfortunately, it failed to build at samigo-services every time. So, I've decided to install its binary by this guide: https://confluence.sakaiproject.org/pages/viewpage.action?pageId=106792016

Java, Tomcat and Sakai-bin's installations were successful. But as I started the server by startup.bat, I've started to get all these exceptions since it has started extracting *.war files from sakai-bin. Tomcat server runs fine in the end, but these deployed webapps fail to start.

Excerpt from catalina.log:

31-Mar-2017 21:09:08.611 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive D:\opt\tomcat\webapps\access.war
31-Mar-2017 21:09:09.424 INFO [localhost-startStop-1] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
31-Mar-2017 21:09:33.408 SEVERE [localhost-startStop-1] org.apache.catalina.core.StandardContext.startInternal One or more Filters failed to start. Full details will be found in the appropriate container log file
31-Mar-2017 21:09:33.408 SEVERE [localhost-startStop-1] org.apache.catalina.core.StandardContext.startInternal Context [/access] startup failed due to previous errors
31-Mar-2017 21:09:33.439 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive D:\opt\tomcat\webapps\access.war has finished in 24,828 ms

Here's the full log of why access.war failed to start:

Excerpt from localhost.log:

31-Mar-2017 21:09:09.424 INFO [localhost-startStop-1] org.apache.catalina.core.ApplicationContext.log No Spring WebApplicationInitializer types detected on classpath
31-Mar-2017 21:09:33.408 SEVERE [localhost-startStop-1] org.apache.catalina.core.StandardContext.filterStart Exception starting filter sakai.request
 java.lang.NullPointerException
    at org.sakaiproject.util.RequestFilter.init(RequestFilter.java:649)
    at org.apache.catalina.core.ApplicationFilterConfig.initFilter(ApplicationFilterConfig.java:279)
    at org.apache.catalina.core.ApplicationFilterConfig.getFilter(ApplicationFilterConfig.java:260)
    at org.apache.catalina.core.ApplicationFilterConfig.<init>(ApplicationFilterConfig.java:105)
    at org.apache.catalina.core.StandardContext.filterStart(StandardContext.java:4659)
    at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5281)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147)
    at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:725)
    at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:701)
    at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:717)
    at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:939)
    at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1812)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

After these errors, it goes on with subsequent *.war files like this:

Excerpt from catalina.log:

31-Mar-2017 21:09:33.439 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive D:\opt\tomcat\webapps\accountvalidator.war
31-Mar-2017 21:09:35.346 SEVERE [localhost-startStop-1] org.apache.catalina.core.StandardContext.startInternal One or more listeners failed to start. Full details will be found in the appropriate container log file
31-Mar-2017 21:09:35.346 SEVERE [localhost-startStop-1] org.apache.catalina.core.StandardContext.startInternal Context [/accountvalidator] startup failed due to previous errors
31-Mar-2017 21:09:35.361 WARNING [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [accountvalidator] appears to have started a thread named [Sakai.SessionComponent.Maintenance] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 java.lang.Thread.sleep(Native Method)
 org.sakaiproject.tool.impl.SessionComponent$Maintenance.run(SessionComponent.java:601)
 java.lang.Thread.run(Thread.java:745)
31-Mar-2017 21:09:35.361 SEVERE [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [accountvalidator] created a ThreadLocal with key of type [uk.org.ponder.saxalizer.support.SAXalXMLProvider$1] (value [uk.org.ponder.saxalizer.support.SAXalXMLProvider$1@2d8b4438]) and a value of type [uk.org.ponder.saxalizer.SAXalizerHelper] (value [uk.org.ponder.saxalizer.SAXalizerHelper@5eda0219]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
31-Mar-2017 21:09:35.361 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive D:\opt\tomcat\webapps\accountvalidator.war has finished in 1,922 ms
31-Mar-2017 21:09:35.455 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive D:\opt\tomcat\webapps\adminsiteperms.war
31-Mar-2017 21:09:36.033 INFO [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading Illegal access: this web application instance has been stopped already. Could not load [org/sakaiproject/config/kernel.properties]. The following stack trace is thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access.
 java.lang.IllegalStateException: Illegal access: this web application instance has been stopped already. Could not load [org/sakaiproject/config/kernel.properties]. The following stack trace is thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access.
    at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading(WebappClassLoaderBase.java:1328)
    at org.apache.catalina.loader.WebappClassLoaderBase.getResourceAsStream(WebappClassLoaderBase.java:1063)
    at org.springframework.core.io.ClassPathResource.getInputStream(ClassPathResource.java:166)
    at org.sakaiproject.util.SakaiProperties$SakaiPropertiesFactoryBean.loadProperties(SakaiProperties.java:390)
    at org.sakaiproject.util.SakaiProperties$SakaiPropertiesFactoryBean.mergeProperties(SakaiProperties.java:366)
    at org.sakaiproject.util.SakaiProperties$SakaiPropertiesFactoryBean.createInstance(SakaiProperties.java:309)
    at org.sakaiproject.util.SakaiProperties$SakaiPropertiesFactoryBean.afterPropertiesSet(SakaiProperties.java:291)
    at org.sakaiproject.util.SakaiProperties.afterPropertiesSet(SakaiProperties.java:80)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1637)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1574)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:545)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
    at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:351)
    at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:108)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1481)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1226)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:543)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
    at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:351)
    at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:108)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1481)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1226)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:543)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
    at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:351)
    at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:108)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1481)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1226)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:543)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:275)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
    at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:351)
    at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:108)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1481)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1226)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:543)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:772)
    at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:839)
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:538)
    at org.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:444)
    at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:326)
    at org.sakaiproject.component.impl.SakaiContextLoader.initWebApplicationContext(SakaiContextLoader.java:69)
    at org.sakaiproject.util.SakaiContextLoaderListener.contextInitialized(SakaiContextLoaderListener.java:48)
    at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4812)
    at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5255)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147)
    at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:725)
    at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:701)
    at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:717)
    at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:939)
    at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1812)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

Excerpt from localhost.log:

31-Mar-2017 21:09:34.064 INFO [localhost-startStop-1] org.apache.catalina.core.ApplicationContext.log No Spring WebApplicationInitializer types detected on classpath
31-Mar-2017 21:09:34.080 INFO [localhost-startStop-1] org.apache.catalina.core.ApplicationContext.log Initializing Spring root WebApplicationContext
31-Mar-2017 21:09:35.346 SEVERE [localhost-startStop-1] org.apache.catalina.core.StandardContext.listenerStart Exception sending context initialized event to listener instance of class org.sakaiproject.util.SakaiContextLoaderListener
 org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'sakai-PermissionChecker' defined in class path resource [conf/sakai-applicationContext.xml]: Cannot resolve reference to bean 'org.sakaiproject.authz.api.SecurityService' while setting bean property 'securityService'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'org.sakaiproject.authz.api.SecurityService' defined in file [D:\opt\tomcat\components\sakai-kernel-component\WEB-INF\authz-components.xml]: Invocation of init method failed; nested exception is java.lang.NullPointerException
    at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:359)
    at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:108)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1481)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1226)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:543)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:772)
    at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:839)
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:538)
    at org.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:444)
    at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:326)
    at org.sakaiproject.component.impl.SakaiContextLoader.initWebApplicationContext(SakaiContextLoader.java:69)
    at org.sakaiproject.util.SakaiContextLoaderListener.contextInitialized(SakaiContextLoaderListener.java:48)
    at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4812)
    at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5255)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147)
    at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:725)
    at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:701)
    at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:717)
    at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:939)
    at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1812)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'org.sakaiproject.authz.api.SecurityService' defined in file [D:\opt\tomcat\components\sakai-kernel-component\WEB-INF\authz-components.xml]: Invocation of init method failed; nested exception is java.lang.NullPointerException
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1578)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:545)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:275)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
    at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:351)
    ... 29 more
Caused by: java.lang.NullPointerException
    at org.sakaiproject.authz.impl.SakaiSecurity.init(SakaiSecurity.java:151)
    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.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeCustomInitMethod(AbstractAutowireCapableBeanFactory.java:1706)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1645)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1574)
    ... 38 more

I'm mostly clueless about these logs but, I'm suspecting that these logs indicate why these deployed webapps simply don't start.

How can I fix these errors and make these webapps start successfully?

Thanks.


Solution

  • These look like the errors discussed recently on the sakai-dev thread here. The solution was

    1. The sakai.properties file I downloaded had UNIX line endings. Changed those to Windows LF.
    2. I missed renaming the apache-tomcat-8.0.32 folder to tomcat (not sure why this is necessary, as %CATALINA_HOME% points to location of tomcat

    For Sakai 11.3 you should use tomcat 8.0.32, for Sakai 11.4 you can use tomcat 8.0.43. Very little testing is done on Windows and if all else fails installing Tomcat and Sakai in a Linux Virtualbox should eliminate most possible problems.