FAIL - Application at context path [/ODKAggregate] could not be started

Hi All

I am new to linux,and i have been trying to setup ODK aggregate on centOS 6.5.
I have installed postgresql 9.6, JDK8, JRE 8, tomcat 8.5 and ODK Aggregate 1.4.15.

I have managed to setup everything, except when i try to start ODKAggregate in tomcat Application manager i am getting the error

FAIL - Application at context path [/ODKAggregate] could not be started

Below is my Catalina Log.

29-Dec-2017 00:08:17.489 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/opt/apache-tomcat-8.5.24
29-Dec-2017 00:08:17.489 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/opt/apache-tomcat-8.5.24
29-Dec-2017 00:08:17.490 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/opt/apache-tomcat-8.5.24/temp
29-Dec-2017 00:08:17.490 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: [/usr/java/packages/lib/i386:/lib:/usr/lib]
29-Dec-2017 00:08:17.616 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
29-Dec-2017 00:08:17.628 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
29-Dec-2017 00:08:17.635 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["ajp-nio-8009"]
29-Dec-2017 00:08:17.636 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
29-Dec-2017 00:08:17.637 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 533 ms
29-Dec-2017 00:08:17.666 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
29-Dec-2017 00:08:17.666 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.5.24
29-Dec-2017 00:08:17.695 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive [/opt/apache-tomcat-8.5.24/webapps/ODKAggregate.war]
29-Dec-2017 00:08:19.409 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
29-Dec-2017 00:08:19.421 SEVERE [localhost-startStop-1] org.apache.catalina.core.StandardContext.startInternal Context [/ODKAggregate] startup failed due to previous errors
29-Dec-2017 00:08:19.434 WARNING [localhost-startStop-1] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesJdbc The web application [ODKAggregate] 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.
29-Dec-2017 00:08:19.438 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive [/opt/apache-tomcat-8.5.24/webapps/ODKAggregate.war] has finished in [1,743] ms
29-Dec-2017 00:08:19.439 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/apache-tomcat-8.5.24/webapps/manager]
29-Dec-2017 00:08:19.686 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/apache-tomcat-8.5.24/webapps/manager] has finished in [247] ms
29-Dec-2017 00:08:19.686 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/apache-tomcat-8.5.24/webapps/docs]
29-Dec-2017 00:08:19.745 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/apache-tomcat-8.5.24/webapps/docs] has finished in [58] ms
29-Dec-2017 00:08:19.745 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/apache-tomcat-8.5.24/webapps/examples]
29-Dec-2017 00:08:20.006 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/apache-tomcat-8.5.24/webapps/examples] has finished in [261] ms
29-Dec-2017 00:08:20.006 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/apache-tomcat-8.5.24/webapps/host-manager]
29-Dec-2017 00:08:20.079 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/apache-tomcat-8.5.24/webapps/host-manager] has finished in [73] ms
29-Dec-2017 00:08:20.079 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/opt/apache-tomcat-8.5.24/webapps/ROOT]
29-Dec-2017 00:08:20.156 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/opt/apache-tomcat-8.5.24/webapps/ROOT] has finished in [77] ms
29-Dec-2017 00:08:20.161 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
29-Dec-2017 00:08:20.169 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-nio-8009"]
29-Dec-2017 00:08:20.171 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 2534 ms
29-Dec-2017 00:10:35.416 SEVERE [http-nio-8080-exec-3] org.apache.catalina.core.StandardContext.startInternal One or more listeners failed to start. Full details will be found in the appropriate container log file
29-Dec-2017 00:10:35.417 SEVERE [http-nio-8080-exec-3] org.apache.catalina.core.StandardContext.startInternal Context [/ODKAggregate] startup failed due to previous errors
29-Dec-2017 00:10:35.432 WARNING [http-nio-8080-exec-3] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesJdbc The web application [ODKAggregate] 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.

I have read similar topics on this forum, however none seems to give an easy to follow suggestion for a biginer.

Will greatly appreciate your help.

Hi @Iammash! I'm not super familiar with CentOS, but are there any other Tomcat logs that you could share? The logs you posted don't really have any hints about what is going wrong...

@yanokwa Thanks for your response, other than the log files in tomcat-installation/logs directory is there anywhere else i can find other tomcat logs? other than the catalina log file the others are empty or will very little info, most without an error.

I managed to spot out this line below from the log i posted above.
29-Dec-2017 00:08:19.409 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

Which was followed by
29-Dec-2017 00:08:19.421 SEVERE [localhost-startStop-1] org.apache.catalina.core.StandardContext.startInternal Context [/ODKAggregate] startup failed due to previous errors

Would you happen to know where the container log file being referred is located? maybe i can find something useful in it

I am really a newbie

If you are a newbie, starting with CentOS is a lot to take on! Is there any reason why you don't use ODK Aggregate on App Engine to start?

What file path are the logs now? Maybe try /var/log/tomcat to see if there are any other logs?

I am setting it up for a small community project i volunteer to , and they insisted on hosting on the server they have already setup with CentOS where they host their website. I am familiar with setting it up on windows and App Engine. But now i have been made to bend to this.

Those logs are in /opt/apache-tomcat/logs

Can't see anything tomcat related in /var/log/

@yanokwa Maybe this will have some useful information. Found the catalina.out log file

Dec 29, 2017 12:10:35 AM org.apache.catalina.core.StandardContext listenerStart
SEVERE: Exception sending context initialized event to listener instance of class [org.springframework.web.context.ContextLoaderListener]
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'hierarchicalRoleRelationships' defined in ServletContext resource [/WEB-INF/applicationContext-security.xml]: Invocation of init method failed; nested exception is org.opendatakit.common.persistence.exception.ODKDatastoreException: org.springframework.transaction.CannotCreateTransactionException: Could not open JDBC Connection for transaction; nested exception is java.sql.SQLException: Cannot create PoolableConnectionFactory (FATAL: Ident authentication failed for user "odk_user")
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1583)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:553)
	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:754)
	at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:866)
	at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:542)
	at org.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:444)
	at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:326)
	at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:107)
	at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4745)
	at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5207)
	at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
	at org.apache.catalina.manager.ManagerServlet.start(ManagerServlet.java:1309)
	at org.apache.catalina.manager.HTMLManagerServlet.start(HTMLManagerServlet.java:665)
	at org.apache.catalina.manager.HTMLManagerServlet.doPost(HTMLManagerServlet.java:211)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:661)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.catalina.filters.CsrfPreventionFilter.doFilter(CsrfPreventionFilter.java:136)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.catalina.filters.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:108)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:621)
	at org.apache.catalina.valves.RequestFilterValve.process(RequestFilterValve.java:348)
	at org.apache.catalina.valves.RemoteAddrValve.invoke(RemoteAddrValve.java:52)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81)
	at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:650)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:803)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:790)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1459)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Unknown Source)
Caused by: org.opendatakit.common.persistence.exception.ODKDatastoreException: org.springframework.transaction.CannotCreateTransactionException: Could not open JDBC Connection for transaction; nested exception is java.sql.SQLException: Cannot create PoolableConnectionFactory (FATAL: Ident authentication failed for user "odk_user")
	at org.opendatakit.common.persistence.engine.pgres.DatastoreImpl.assertRelation(DatastoreImpl.java:650)
	at org.opendatakit.common.security.spring.GrantedAuthorityHierarchyTable.assertRelation(GrantedAuthorityHierarchyTable.java:115)
	at org.opendatakit.common.security.spring.GrantedAuthorityHierarchyTable.getEntireGrantedAuthorityHierarchy(GrantedAuthorityHierarchyTable.java:186)
	at org.opendatakit.common.security.spring.RoleHierarchyImpl.buildRolesReachableInOneStepMap(RoleHierarchyImpl.java:465)
	at org.opendatakit.common.security.spring.RoleHierarchyImpl.refreshReachableGrantedAuthorities(RoleHierarchyImpl.java:282)
	at org.opendatakit.common.security.spring.RoleHierarchyImpl.afterPropertiesSet(RoleHierarchyImpl.java:132)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1642)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1579)
	... 50 more
Caused by: org.springframework.transaction.CannotCreateTransactionException: Could not open JDBC Connection for transaction; nested exception is java.sql.SQLException: Cannot create PoolableConnectionFactory (FATAL: Ident authentication failed for user "odk_user")
	at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:252)
	at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373)
	at org.opendatakit.common.persistence.engine.pgres.DatastoreImpl.assertRelation(DatastoreImpl.java:506)
	... 57 more
Caused by: java.sql.SQLException: Cannot create PoolableConnectionFactory (FATAL: Ident authentication failed for user "odk_user")
	at org.apache.commons.dbcp2.BasicDataSource.createPoolableConnectionFactory(BasicDataSource.java:2294)
	at org.apache.commons.dbcp2.BasicDataSource.createDataSource(BasicDataSource.java:2039)
	at org.apache.commons.dbcp2.BasicDataSource.getConnection(BasicDataSource.java:1533)
	at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:211)
	... 59 more
Caused by: org.postgresql.util.PSQLException: FATAL: Ident authentication failed for user "odk_user"
	at org.postgresql.core.v3.ConnectionFactoryImpl.doAuthentication(ConnectionFactoryImpl.java:446)
	at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:220)
	at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:54)
	at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:218)
	at org.postgresql.Driver.makeConnection(Driver.java:407)
	at org.postgresql.Driver.connect(Driver.java:275)
	at org.apache.commons.dbcp2.DriverConnectionFactory.createConnection(DriverConnectionFactory.java:39)
	at org.apache.commons.dbcp2.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:256)
	at org.apache.commons.dbcp2.BasicDataSource.validateConnectionFactory(BasicDataSource.java:2304)
	at org.apache.commons.dbcp2.BasicDataSource.createPoolableConnectionFactory(BasicDataSource.java:2290)
	... 62 more

29-Dec-2017 00:10:35.416 SEVERE [http-nio-8080-exec-3] org.apache.catalina.core.StandardContext.startInternal One or more listeners failed to start. Full details will be found in the appropriate container log file
29-Dec-2017 00:10:35.417 SEVERE [http-nio-8080-exec-3] org.apache.catalina.core.StandardContext.startInternal Context [/ODKAggregate] startup failed due to previous errors
Dec 29, 2017 12:10:35 AM org.apache.catalina.core.ApplicationContext log
INFO: Closing Spring root WebApplicationContext
29-Dec-2017 00:10:35.432 WARNING [http-nio-8080-exec-3] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesJdbc The web application [ODKAggregate] 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.
29-Dec-2017 00:35:23.104 INFO [http-nio-8080-exec-12] org.apache.coyote.http11.Http11Processor.service Error parsing HTTP request header
 Note: further occurrences of HTTP header parsing errors will be logged at DEBUG level.
 java.lang.IllegalArgumentException: Invalid character found in method name. HTTP method names must be tokens
	at org.apache.coyote.http11.Http11InputBuffer.parseRequestLine(Http11InputBuffer.java:426)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:687)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:790)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1459)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Unknown Source)

These logs are more useful!

The error is: Ident authentication failed for user "odk_user". Did you follow the installer instructions on creating the PostgreSQL database? You would have to run commands like these...

CREATE USER "odk_unit" WITH UNENCRYPTED PASSWORD 'test';
CREATE DATABASE odk_db WITH OWNER odk_unit;
GRANT ALL PRIVILEGES ON DATABASE odk_db TO odk_unit;
\connect odk_db;
CREATE SCHEMA odk_db;
GRANT ALL PRIVILEGES ON SCHEMA odk_db TO odk_unit;

Thanks @yanokwa. After granting the user privileges it now works fine.

2 Likes

hello Iammash. I have the same problem with the user odk_user, also I am new in linux. As you give privileges to user_odk? I already did it from pgadmin but the same error keeps coming up