Increasing logging verbosity of a Java application can be helpful in quick problem identification and resolution as error messages with default Tomcat logging settings can be quite vague.
Default logger in Tomcat 6 and 7 is java.util.logging logger. Previously Log4J was used. See an example how increased logging verbosity helps solving an issue. When deploying fresh Grails application all error messages we initially got were:
INFO: Deploying web application archive /home/grailswebapp/appservers/apache-tomcat-7.0.30/webapps/grailswebapp.war
Configuring Spring Security Core ...
... finished configuring Spring Security Core
Oct 12, 2012 4:00:37 PM org.apache.catalina.core.StandardContext startInternal
SEVERE: Error listenerStart
Oct 12, 2012 4:00:37 PM org.apache.catalina.core.StandardContext startInternal
SEVERE: Context [/tixomatic] startup failed due to previous errorsQuite unclear information, not leading straight to a reason and solution. Let's now stop the Tomcat and put logging.properties file into application's WEB-INF/classes with the following content:
org.apache.catalina.core.ContainerBase.[Catalina].level = INFO
org.apache.catalina.core.ContainerBase.[Catalina].handlers = java.util.logging.ConsoleHandlerClear catalina.out and start Tomcat. Now we get (scroll right to see Access denied for user message):
INFO: Deploying web application archive /home/grailswebapp/appservers/apache-tomcat-7.0.30/webapps/grailswebapp.war
Oct 12, 2012 4:13:37 PM org.apache.catalina.core.ApplicationContext log
INFO: No Spring WebApplicationInitializer types detected on classpath
Oct 12, 2012 4:13:38 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Configuring Spring Security Core ...
... finished configuring Spring Security Core
Oct 12, 2012 4:13:42 PM org.apache.catalina.core.StandardContext listenerStart
SEVERE: Exception sending context initialized event to listener instance of class org.codehaus.groovy.grails.web.context.GrailsContextLoaderListener
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'transactionManagerPostProcessor': Initialization of bean failed; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'transactionManager': Cannot resolve reference to bean 'sessionFactory' while setting bean property 'sessionFactory'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'sessionFactory': Cannot resolve reference to bean 'hibernateProperties' while setting bean property 'hibernateProperties'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'hibernateProperties': Cannot resolve reference to bean 'dialectDetector' while setting bean property 'properties' with key [hibernate.dialect]; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'dialectDetector': Invocation of init method failed; nested exception is org.springframework.jdbc.support.MetaDataAccessException: Error while extracting DatabaseMetaData; nested exception is org.apache.commons.dbcp.SQLNestedException: Cannot create PoolableConnectionFactory (Access denied for user 'grailswebapp_dbuser1'@'server.company.net' (using password: YES))
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:527)
at org.codehaus.groovy.grails.commons.spring.ReloadAwareAutowireCapableBeanFactory.doCreateBean(ReloadAwareAutowireCapableBeanFactory.java:126)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:456)
at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:294)
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:225)
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:291)
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
at org.springframework.context.support.AbstractApplicationContext.registerBeanPostProcessors(AbstractApplicationContext.java:707)
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:449)
at org.codehaus.groovy.grails.commons.spring.DefaultRuntimeSpringConfiguration.getApplicationContext(DefaultRuntimeSpringConfiguration.java:153)
at org.codehaus.groovy.grails.commons.spring.GrailsRuntimeConfigurator.configure(GrailsRuntimeConfigurator.java:170)
at org.codehaus.groovy.grails.commons.spring.GrailsRuntimeConfigurator.configure(GrailsRuntimeConfigurator.java:127)
at org.codehaus.groovy.grails.web.context.GrailsConfigUtils.configureWebApplicationContext(GrailsConfigUtils.java:121)
at org.codehaus.groovy.grails.web.context.GrailsContextLoader.initWebApplicationContext(GrailsContextLoader.java:104)
at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:111)
at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4791)
at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5285)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:901)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:877)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:618)
at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:963)
at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1600)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)and a few more related exceptions ending with
Oct 12, 2012 4:13:42 PM org.apache.catalina.core.StandardContext startInternal
SEVERE: Error listenerStart
Oct 12, 2012 4:13:42 PM org.apache.catalina.core.StandardContext startInternal
SEVERE: Context [/tixomatic] startup failed due to previous errorsIt means somewhere in the code the database host was referenced with a host name different from localhost while only localhost access is granted or database credentials are wrong. Just checking these 2 items made problem solved and logging.properties was removed to avoid excessive logging.
Similar issue where increased verbosity helped with quick resolution was one that produced
org.apache.catalina.core.StandardContext start SEVERE: Error listenerStart
org.apache.catalina.core.StandardContext start SEVERE: Context [/grailswebapp] startup failed due to previous errorsIn this case it was a ClassNotFoundException and problem has been solved after adding required class or jar.
Yet another example of unclear error message when JDK6 was used for application compiled with JDK7:
INFO: Deploying web application archive /home/tomcat/apache-tomcat-7.0.32/webapps/ROOT.war
Oct 13, 2012 8:03:33 AM org.apache.catalina.core.StandardContext startInternal
SEVERE: Error listenerStart
Oct 13, 2012 8:03:33 AM org.apache.catalina.core.StandardContext startInternal
SEVERE: Context [] startup failed due to previous errorsAnd after enabling verbose logging we know where we are (wrong JDK version used):
INFO: Deploying web application archive /home/tomcat/apache-tomcat-7.0.32/webapps/ROOT.war
Oct 13, 2012 8:05:19 AM org.apache.catalina.core.StandardContext listenerStart
SEVERE: Error configuring application listener of class website.web.MainAggregation
java.lang.UnsupportedClassVersionError: website/web/MainAggregation : Unsupported major.minor version 51.0 (unable to load class website.web.MainAggregation)Refer Tomcat 7 documentation for more on logging.
