Recently got an interesting SR which worth sharing.
An application which uses Spring and uses log4j to log debug information. log4j.properties is configured for both application code and Spring code:
log4j.logger.com.company.customerCode=DEBUG
log4j.logger.org.springframework.core=DEBUG
The logging works perfectly on a base weblogic domain, which both application and spring debug messages are printed to specified log file.
However, when the application is deployed to a JRF/SOA enabled domain, we see only application debug messages, not Spring ones. Why??
When diagnosing this problem, 2 debug flags helped:
1) -Dlog4j.debug
we can see the sample output here:
log4j: Using URL [zip:D:/bea/WLS1036/user_projects/domains/TestDevDomain/servers/AdminServer/tmp/_WL_user/_appsdir_aif-sm_ear_1.0.0-dev-b57/mpc1b8/war/WEB-INF/log4j.properties] for automatic log4j configuration.
log4j: Reading configuration from URL zip:D:/bea/WLS1036/user_projects/domains/TestDevDomain/servers/AdminServer/tmp/_WL_user/_appsdir_aif-sm_ear_1.0.0-dev-b57/mpc1b8/war/WEB-INF/log4j.properties
log4j: Parsing for [root] with value=[WARN, logfile].
log4j: Level token is [WARN].
log4j: Category root set to WARN
log4j: Parsing appender named "logfile".
log4j: Parsing layout options for "logfile".
log4j: Setting property [conversionPattern] to [%x %d %p [%c] - %m%n].
log4j: End of parsing for "logfile".
log4j: Setting property [file] to [aif-common.log].
log4j: setFile called: aif-common.log, true
log4j: setFile ended
log4j: Parsed "logfile" options.
log4j: Parsing for [com.company.customerCode] with value=[DEBUG].
log4j: Level token is [DEBUG].
log4j: Category com.company.customerCode set to DEBUG
log4j: Handling log4j.com.company.customerCode=[null]
log4j: Parsing for [org.springframework] with value=[DEBUG].
log4j: Level token is [DEBUG].
log4j: Category org.springframework set to DEBUG
log4j: Handling log4j.additivity.org.springframework=[null]
log4j: Finished configuring.
the output tells us that log4j configuration is correct. the log4j properties files are loaded and configurations are set.
2) -Dorg.apache.commons.logging.diagnostics.dest=d:\test\jcl.log
this output tells us how JCL loads it's configurations.
Here's sample output snippet from a base domain:
[LogFactoryImpl@15531576 from weblogic.utils.classloaders.ChangeAwareClassLoader@14877755] Trying to get log class from attribute 'org.apache.commons.logging.Log'
[LogFactoryImpl@15531576 from weblogic.utils.classloaders.ChangeAwareClassLoader@14877755] Trying to get log class from attribute 'org.apache.commons.logging.log'
[LogFactoryImpl@15531576 from weblogic.utils.classloaders.ChangeAwareClassLoader@14877755] Trying to get log class from system property 'org.apache.commons.logging.Log'
[LogFactoryImpl@15531576 from weblogic.utils.classloaders.ChangeAwareClassLoader@14877755] Trying to get log class from system property 'org.apache.commons.logging.log'
[LogFactoryImpl@15531576 from weblogic.utils.classloaders.ChangeAwareClassLoader@14877755] No user-specified Log implementation; performing discovery using the standard supported logging implementations...
[LogFactoryImpl@15531576 from weblogic.utils.classloaders.ChangeAwareClassLoader@14877755] Attempting to instantiate 'org.apache.commons.logging.impl.Log4JLogger'
here's sample output sinippet from a JRF/SOA enabled domain:
[LogFactoryImpl@8199388 from weblogic.utils.classloaders.ChangeAwareClassLoader@1666116] Trying to get log class from attribute 'org.apache.commons.logging.Log'
[LogFactoryImpl@8199388 from weblogic.utils.classloaders.ChangeAwareClassLoader@1666116] Trying to get log class from attribute 'org.apache.commons.logging.log'
[LogFactoryImpl@8199388 from weblogic.utils.classloaders.ChangeAwareClassLoader@1666116] Trying to get log class from system property 'org.apache.commons.logging.Log'
[LogFactoryImpl@8199388 from weblogic.utils.classloaders.ChangeAwareClassLoader@1666116] Attempting to load user-specified log class 'org.apache.commons.logging.impl.Jdk14Logger'...
Seems there is a system property set for org.apache.commons.logging.Log
I checked JRF domain, it indeed has that:
org.apache.commons.logging.Log = org.apache.commons.logging.impl.Jdk14Logger
it's configured in setDomainEnv.cmd:
set EXTRA_JAVA_PROPERTIES=-Dcommon.components.home=%COMMON_COMPONENTS_HOME% -Djrf.version=11.1.1 -Dorg.apache.commons.logging.Log=org.apache.commons.logging.impl.Jdk14Logger -Ddomain.home=%DOMAIN_HOME% -Djrockit.optfile=%COMMON_COMPONENTS_HOME%\modules\oracle.jrf_11.1.1\jrocket_optfile.txt -Doracle.server.config.dir=%ORACLE_DOMAIN_CONFIG_DIR%\servers\%SERVER_NAME% -Doracle.domain.config.dir=%ORACLE_DOMAIN_CONFIG_DIR% -Digf.arisidbeans.carmlloc=%ORACLE_DOMAIN_CONFIG_DIR%\carml -Digf.arisidstack.home=%ORACLE_DOMAIN_CONFIG_DIR%\arisidprovider -Doracle.security.jps.config=%DOMAIN_HOME%\config\fmwconfig\jps-config.xml -Doracle.deployed.app.dir=%DOMAIN_HOME%\servers\%SERVER_NAME%\tmp\_WL_user -Doracle.deployed.app.ext=\- -Dweblogic.alternateTypesDirectory=%ALT_TYPES_DIR% -Djava.protocol.handler.pkgs=%PROTOCOL_HANDLERS% %WLS_JDBC_REMOTE_ENABLED% %EXTRA_JAVA_PROPERTIES%
Then we found the problem. :)
There are 2 solutions for this problem:
1) modify the system level properties
from
-Dorg.apache.commons.logging.Log=org.apache.commons.logging.impl.Jdk14Logger
to
-Dorg.apache.commons.logging.Log=org.apache.commons.logging.impl.Log4JLogger
2) modify(or add one if not exist) the commons-logging.properties file under application's war file's WEB-INF\classes directory to contain the following content:
org.apache.commons.logging.Log=org.apache.commons.logging.impl.Log4JLogger
priority=1