On Debian : LogConfigurationException on Tomcat deploy

[liotier]

Hi, I am encountering this exception on the deployment of Alfresco by Tomcat :

Oct 27, 2006 6:56:42 PM org.apache.catalina.startup.HostConfig deployWAR
SEVERE: Error deploying web application archive alfresco.war
org.apache.commons.logging.LogConfigurationException: java.lang.ExceptionInInitializerError (Caused by java.lang.ExceptionInInitializerError)

I am very novice with Java. I have understood this may have something to do with Log4J but I do not know how to get any further.

I am using Debian with the following packages :

- Tomcat 5.5.20-1
- Liblog4j 1.2.13-1
- Alfresco Community war 1.4.0
- Sun Java 5 JRE & JDK 1.5.0-08-1

It seems they are fine versions that are supposed to work together…

Would anybody here have a clue about what might be failing ?


The full startup log follows :

Using CATALINA_BASE:   /var/lib/tomcat5.5
Using CATALINA_HOME:   /usr/share/tomcat5.5
Using CATALINA_TMPDIR: /var/lib/tomcat5.5/temp
Using JRE_HOME:       /usr/lib/jvm/java-1.5.0-sun
Using Security Manager
Oct 27, 2006 6:56:41 PM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFO: The Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: /usr/lib/jvm/java-1.5.0-sun-1.5.0.08/jre/lib/i386/client:/usr/lib/jvm/java-1.5.0-sun-1.5.0.08/jre/lib/i386:/usr/lib/jvm/java-1.5.0-sun-1.5.0.08/jre/../lib/i386
Oct 27, 2006 6:56:41 PM org.apache.coyote.http11.Http11BaseProtocol init
INFO: Initializing Coyote HTTP/1.1 on http-8180
Oct 27, 2006 6:56:41 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 940 ms
Oct 27, 2006 6:56:41 PM org.apache.catalina.core.StandardService start
INFO: Starting service Catalina
Oct 27, 2006 6:56:41 PM org.apache.catalina.core.StandardEngine start
INFO: Starting Servlet Engine: Apache Tomcat/5.5
Oct 27, 2006 6:56:41 PM org.apache.catalina.core.StandardHost start
INFO: XML validation disabled
Oct 27, 2006 6:56:42 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive alfresco.war
Oct 27, 2006 6:56:42 PM org.apache.catalina.startup.HostConfig deployWAR
SEVERE: Error deploying web application archive alfresco.war
org.apache.commons.logging.LogConfigurationException: java.lang.ExceptionInInitializerError (Caused by java.lang.ExceptionInInitializerError)
        at org.apache.commons.logging.impl.LogFactoryImpl.newInstance(LogFactoryImpl.java:538)
        at org.apache.commons.logging.impl.LogFactoryImpl.getInstance(LogFactoryImpl.java:235)
        at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:370)
        at org.apache.catalina.core.ContainerBase.getLogger(ContainerBase.java:380)
        at org.apache.catalina.core.StandardContext.start(StandardContext.java:4114)
        at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:759)
        at org.apache.catalina.core.ContainerBase.access$0(ContainerBase.java:743)
        at org.apache.catalina.core.ContainerBase$PrivilegedAddChild.run(ContainerBase.java:143)
        at java.security.AccessController.doPrivileged(Native Method)
        at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:737)
        at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:524)
        at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:809)
        at org.apache.catalina.startup.HostConfig.deployWARs(HostConfig.java:698)
        at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:472)
        at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1122)
        at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:310)
        at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:119)
        at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1021)
        at org.apache.catalina.core.StandardHost.start(StandardHost.java:718)
        at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1013)
        at org.apache.catalina.core.StandardEngine.start(StandardEngine.java:442)
        at org.apache.catalina.core.StandardService.start(StandardService.java:450)
        at org.apache.catalina.core.StandardServer.start(StandardServer.java:709)
        at org.apache.catalina.startup.Catalina.start(Catalina.java:551)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:294)
        at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:432)
Caused by: java.lang.ExceptionInInitializerError
        at org.apache.log4j.Logger.getLogger(Logger.java:85)
        at org.apache.commons.logging.impl.Log4JLogger.<init>(Log4JLogger.java:102)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:494)
        at org.apache.commons.logging.impl.LogFactoryImpl.newInstance(LogFactoryImpl.java:529)
        … 29 more
Caused by: java.security.AccessControlException: access denied (java.io.FilePermission alfresco.log write)
        at java.security.AccessControlContext.checkPermission(AccessControlContext.java:264)
        at java.security.AccessController.checkPermission(AccessController.java:427)
        at java.lang.SecurityManager.checkPermission(SecurityManager.java:532)
        at java.lang.SecurityManager.checkWrite(SecurityManager.java:962)
        at java.io.FileOutputStream.<init>(FileOutputStream.java:169)
        at java.io.FileOutputStream.<init>(FileOutputStream.java:102)
        at org.apache.log4j.FileAppender.setFile(FileAppender.java:272)
        at org.apache.log4j.FileAppender.activateOptions(FileAppender.java:151)
        at org.apache.log4j.DailyRollingFileAppender.activateOptions(DailyRollingFileAppender.java:206)
        at org.apache.log4j.config.PropertySetter.activate(PropertySetter.java:247)
        at org.apache.log4j.config.PropertySetter.setProperties(PropertySetter.java:123)
        at org.apache.log4j.config.PropertySetter.setProperties(PropertySetter.java:87)
        at org.apache.log4j.PropertyConfigurator.parseAppender(PropertyConfigurator.java:645)
        at org.apache.log4j.PropertyConfigurator.parseCategory(PropertyConfigurator.java:603)
        at org.apache.log4j.PropertyConfigurator.configureRootCategory(PropertyConfigurator.java:500)
        at org.apache.log4j.PropertyConfigurator.doConfigure(PropertyConfigurator.java:406)
        at org.apache.log4j.PropertyConfigurator.doConfigure(PropertyConfigurator.java:432)
        at org.apache.log4j.helpers.OptionConverter.selectAndConfigure(OptionConverter.java:460)
        at org.apache.log4j.LogManager.<clinit>(LogManager.java:113)
        … 36 more
Oct 27, 2006 6:56:42 PM org.apache.coyote.http11.Http11BaseProtocol start
INFO: Starting Coyote HTTP/1.1 on http-8180
Oct 27, 2006 6:56:43 PM org.apache.jk.common.ChannelSocket init
INFO: JK: ajp13 listening on /0.0.0.0:8009
Oct 27, 2006 6:56:43 PM org.apache.jk.server.JkMain start
INFO: Jk running ID=0 time=0/28  config=null
Oct 27, 2006 6:56:43 PM org.apache.catalina.storeconfig.StoreLoader load
INFO: Find registry server-registry.xml at classpath resource
Oct 27, 2006 6:56:43 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 1860 ms

[liotier]

I just try with Alfresco 1.3 and I have exactly the same results.

[liotier]

Same thing with 1.2.1

I certainly have a Log4J problem but I don't understand it…

[liotier]

A french user noted the following line :

Caused by: java.security.AccessControlException: access denied (java.io.FilePermission alfresco.log write)‍

He hinted that it might be a stupid write permission problem and I tend to agree. I'll keep this thread posted.

[liotier]

Problem still not solved - but I won't give up. I'll keep this thread posted when I find a solution.

[marco]

My work-around is:

In /var/lib/tomcat5.5/webapps/alfresco/WEB-INF/classes/log4j.properties change:
    log4j.appender.File.File=/var/log/tomcat5.5/alfresco.log

Check that tomcat55 is the owner of the this log directory.

In /etc/default/tomtom5.5 change:
    TOMCAT5_SECURITY=no

The last point is the one which I don't like. Above all because I'm not aware of the implications. If you know please tell me!

Regards,
Marco

[marco]

How can I make an equivalent change in tomcat5.5/shared/classes/alfresco/extension/ instead of tomcat5.5/webapps/alfresco/WEB-INF/classes/?

I can't find where log4j.properties is imported.

/m

[liotier]

My work-around is:

In /var/lib/tomcat5.5/webapps/alfresco/WEB-INF/classes/log4j.properties change:
    log4j.appender.File.File=/var/log/tomcat5.5/alfresco.log

Check that tomcat55 is the owner of the this log directory.

In /etc/default/tomtom5.5 change:
    TOMCAT5_SECURITY=no

It sure did something positive as I have now moved on to a whole new 100 classes deep exception - looks like my database is not quite well configured…

Anyway thanks you for the help.

[liotier]

It sure did something positive as I have now moved on to a whole new 100 classes deep exception - looks like my database is not quite well configured…

Problem solved… For the first time Tomcat 5.5 launches with Alfresco 1.4 with no fatal exception apart from the ones complaining it can't bind on the FTP port nor the SMB one. And I still can't connect to it but I have to deal with strict firewalling so that shall probably be solved soon…

Feels good to be moving forward again…

[marco]

liotier,

How did you solve the permission conflict with the log file?

/m