Hi all, Log4J has all of a sudden started printing all log messages under the [STDERR] label. All these messages were earlier [INFO] etc. I am running the app on JBoss. The problem starts right after a Quartz message(included the console output below), not sure if it is Quartz that is the problem.
my jBoss-log4j.xml: <?xml version="1.0" encoding="UTF-8"?> <!DOCTYPE log4j:configuration SYSTEM "log4j.dtd"> <log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/"; debug="false"> <!-- A time/date based rolling appender --> <appender name="FILE" class="org.jboss.logging.appender.DailyRollingFileAppender"> <param name="Threshold" value="INFO"/> <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/> <param name="File" value="${jboss.server.log.dir}/server.log"/> <param name="Append" value="false"/> <!-- Rollover at midnight each day --> <param name="DatePattern" value="'.'yyyy-MM-dd"/> <layout class="org.apache.log4j.PatternLayout"> <!-- The default pattern: Date Priority [Category] Message\n --> <param name="ConversionPattern" value="%d %-5p [%c] %m%n"/> <!-- The full pattern: Date MS Priority [Category] (Thread:NDC) Message\n <param name="ConversionPattern" value="%d %-5r %-5p [%c] (%t:%x) %m%n"/> --> </layout> </appender> <!-- ============================== --> <!-- Append messages to the console --> <!-- ============================== --> <appender name="CONSOLE" class="org.apache.log4j.ConsoleAppender"> <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/> <param name="Target" value="System.out"/> <param name="Threshold" value="INFO"/> <layout class="org.apache.log4j.PatternLayout"> <!-- The default pattern: Date Priority [Category] Message\n --> <param name="ConversionPattern" value="%d{ABSOLUTE} %-5p [%c{1}] %m%n"/> </layout> </appender> <!-- ================ --> <!-- Limit categories --> <!-- ================ --> <!-- Limit the org.apache category to INFO as its DEBUG is verbose --> <category name="org.apache"> <priority value="ERROR"/> </category> <!-- Limit the jacorb category to WARN as its INFO is verbose --> <category name="jacob"> <priority value="ERROR"/> </category> <!-- Limit the org.jgroups category to WARN as its INFO is verbose --> <category name="org.jgroups"> <priority value="ERROR"/> </category> <!-- Limit the org.quartz category to INFO as its DEBUG is verbose --> <category name="org.quartz"> <priority value="ERROR"/> </category> <!-- Limit JSF logging to DEBUG. FINER and FINEST will not be logged --> <category name="javax.enterprise.resource.webcontainer.jsf"> <priority value="ERROR" /> </category> <!-- Limit the JSR77 categories --> <category name="org.jboss.management"> <priority value="ERROR"/> </category> <!-- Limit the org.jboss.serial (jboss-serialization) to INFO as its DEBUG is verbose --> <category name="org.jboss.serial"> <priority value="ERROR"/> </category> <appender name="EMAIL" class="org.apache.log4j.net.SMTPAppender"> <param name="SMTPHost" value="192.168.3.25"/> <param name="To" value="[email protected]<mailto:[email protected]>"/> <param name="From" value="[email protected]<mailto:[email protected]>"/> <layout class="org.apache.log4j.PatternLayout"> <param name="ConversionPattern" value="%d %-5p %c - %m%n"/> </layout> </appender> <!-- ======================= --> <!-- Setup the Root category --> <!-- ======================= --> <root> <appender-ref ref="CONSOLE"/> <appender-ref ref="FILE"/> </root> </log4j:configuration> This the console output of JBoss, the log messages change to STDERR after "start quartz!!!". CONSOLE OUTPUT: =============================================================================== JBoss Bootstrap Environment JBOSS_HOME: D:\Vinay\JBoss JAVA: C:\Java\bin\java JAVA_OPTS: -Xdebug -Xrunjdwp:transport=dt_socket,address=8787,server=y,suspend=n -Dprogram.name=run.bat -server -Xms512m - 24m -XX:PermSize=128M -XX:MaxPermSize=256M -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000 CLASSPATH: C:\Java\lib\tools.jar;D:\Vinay\JBoss\bin\run.jar =============================================================================== Listening for transport dt_socket at address: 8787 12:22:03,712 INFO [Server] Starting JBoss (MX MicroKernel)... 12:22:03,712 INFO [Server] Release ID: JBoss [Trinity] 4.2.3.GA (build: SVNTag=JBoss_4_2_3_GA date=200807181417) 12:22:03,727 INFO [Server] Home Dir: D:\Vinay\JBoss 12:22:03,727 INFO [Server] Home URL: file:/D:/Vinay/JBoss/ 12:22:03,727 INFO [Server] Patch URL: null 12:22:03,727 INFO [Server] Server Name: default 12:22:03,727 INFO [Server] Server Home Dir: D:\Vinay\JBoss\server\default 12:22:03,727 INFO [Server] Server Home URL: file:/D:/Vinay/JBoss/server/default/ 12:22:03,727 INFO [Server] Server Log Dir: D:\Vinay\JBoss\server\default\log 12:22:03,727 INFO [Server] Server Temp Dir: D:\Vinay\JBoss\server\default\tmp 12:22:03,727 INFO [Server] Root Deployment Filename: jboss-service.xml 12:22:03,993 INFO [ServerInfo] Java version: 1.6.0_10,Sun Microsystems Inc. 12:22:03,993 INFO [ServerInfo] Java VM: Java HotSpot(TM) Server VM 11.0-b15,Sun Microsystems Inc. 12:22:03,993 INFO [ServerInfo] OS-System: Windows XP 5.1,x86 12:22:04,462 INFO [Server] Core system initialized 12:22:13,883 INFO [WebService] Using RMI server codebase: http://127.0.0.1:8083/ 12:22:13,899 INFO [Log4jService$URLWatchTimerTask] Configuring from URL: resource:jboss-log4j.xml log4j:WARN Continuable parsing error 103 and column 23 log4j:WARN The content of element type "log4j:configuration" must match "(renderer*,appender*,(category|logger)*,root?,catego tory?)". 12:22:16,399 INFO [TransactionManagerService] JBossTS Transaction Service (JTA version) - JBoss Inc. 12:22:16,399 INFO [TransactionManagerService] Setting up property manager MBean and JMX layer 12:22:16,586 INFO [TransactionManagerService] Starting recovery manager 12:22:16,696 INFO [TransactionManagerService] Recovery manager started 12:22:16,696 INFO [TransactionManagerService] Binding TransactionManager JNDI Reference 12:22:19,540 INFO [EJB3Deployer] Starting java:comp multiplexer 12:22:21,774 INFO [NativeServerConfig] JBoss Web Services - Native 12:22:21,774 INFO [NativeServerConfig] jbossws-3.0.1-native-2.0.4.GA (build=200803312044) 12:22:23,711 INFO [TomcatDeployer] deploy, ctxPath=/, warUrl=.../deploy/jboss-web.deployer/ROOT.war/ 12:22:24,305 INFO [TomcatDeployer] deploy, ctxPath=/invoker, warUrl=.../deploy/http-invoker.sar/invoker.war/ 12:22:24,446 INFO [TomcatDeployer] deploy, ctxPath=/jbossws, warUrl=.../deploy/jbossws.sar/jbossws-context.war/ 12:22:24,555 INFO [TomcatDeployer] deploy, ctxPath=/jbossmq-httpil, warUrl=.../deploy/jms/jbossmq-httpil.sar/jbossmq-httpil. 12:22:25,477 INFO [TomcatDeployer] deploy, ctxPath=/web-console, warUrl=.../deploy/management/console-mgr.sar/web-console.wa 12:22:25,993 INFO [MailService] Mail Service bound to java:/Mail 12:22:26,164 INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jboss-ha-local-jdbc.rar 12:22:26,211 INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jboss-ha-xa-jdbc.rar 12:22:26,243 INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jboss-local-jdbc.rar 12:22:26,274 INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jboss-xa-jdbc.rar 12:22:26,321 INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jms/jms-ra.rar 12:22:26,352 INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/mail-ra.rar 12:22:26,399 INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/quartz-ra.rar 12:22:26,414 INFO [QuartzResourceAdapter] start quartz!!! 12:22:26,493 ERROR [STDERR] Aug 18, 2010 12:22:26 PM org.quartz.simpl.SimpleThreadPool initialize INFO: Job execution threads will use class loader of thread: main 12:22:26,649 ERROR [STDERR] Aug 18, 2010 12:22:26 PM org.quartz.core.SchedulerSignalerImpl <init> INFO: Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl 12:22:26,774 ERROR [STDERR] Aug 18, 2010 12:22:26 PM org.quartz.core.QuartzScheduler <init> INFO: Quartz Scheduler v.1.6.1 created. 12:22:26,899 ERROR [STDERR] Aug 18, 2010 12:22:26 PM org.quartz.simpl.RAMJobStore initialize INFO: RAMJobStore initialized. 12:22:27,024 ERROR [STDERR] Aug 18, 2010 12:22:27 PM org.quartz.impl.StdSchedulerFactory instantiate INFO: Quartz scheduler 'DefaultQuartzScheduler' initialized from default resource file in Quartz package: 'quartz.properties' 12:22:27,133 ERROR [STDERR] Aug 18, 2010 12:22:27 PM org.quartz.impl.StdSchedulerFactory instantiate INFO: Quartz scheduler version: 1.6.1 12:22:27,258 ERROR [STDERR] Aug 18, 2010 12:22:27 PM org.quartz.core.QuartzScheduler start INFO: Scheduler DefaultQuartzScheduler_$_NON_CLUSTERED started. 12:22:28,055 INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:service=DataSourceBinding,name=Defaul to JNDI name 'java:DefaultDS' 12:22:28,477 INFO [A] Bound to JNDI name: queue/A 12:22:28,539 INFO [B] Bound to JNDI name: queue/B 12:23:08,367 INFO [C] Bound to JNDI name: queue/C 12:23:08,367 INFO [D] Bound to JNDI name: queue/D 12:23:08,367 INFO [ex] Bound to JNDI name: queue/ex 12:23:08,383 INFO [testTopic] Bound to JNDI name: topic/testTopic 12:23:08,399 INFO [securedTopic] Bound to JNDI name: topic/securedTopic 12:23:08,399 INFO [testDurableTopic] Bound to JNDI name: topic/testDurableTopic 12:23:08,461 INFO [testQueue] Bound to JNDI name: queue/testQueue 12:23:08,570 INFO [UILServerILService] JBossMQ UIL service available at : /127.0.0.1:8093 12:23:08,664 INFO [DLQ] Bound to JNDI name: queue/DLQ 12:23:08,930 INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:service=ConnectionFactoryBinding,name A' to JNDI name 'java:JmsXA' 12:23:09,102 INFO [TomcatDeployer] deploy, ctxPath=/assets-vwr, warUrl=.../deploy/assets-vwr.war/ 12:23:09,305 INFO [TomcatDeployer] deploy, ctxPath=/assets, warUrl=.../deploy/assets.war/ 12:23:09,524 INFO [TomcatDeployer] deploy, ctxPath=/, warUrl=.../deploy/consumer.war/ 12:23:09,945 ERROR [STDERR] Aug 18, 2010 12:23:09 PM org.springframework.web.context.ContextLoader initWebApplicationContext INFO: Root WebApplicationContext: initialization started 12:23:10,149 ERROR [STDERR] Aug 18, 2010 12:23:10 PM org.springframework.context.support.AbstractApplicationContext prepareRe INFO: Refreshing org.springframework.context.support.classpathxmlapplicationcont...@607cd0<mailto:org.springframework.context.support.classpathxmlapplicationcont...@607cd0>: display name [org.springframework ext.support.classpathxmlapplicationcont...@607cd0<mailto:ext.support.classpathxmlapplicationcont...@607cd0>]; startup date [Wed Aug 18 12:23:10 IST 2010]; root of context hierarchy 12:23:10,539 ERROR [STDERR] Aug 18, 2010 12:23:10 PM org.springframework.beans.factory.xml.XmlBeanDefinitionReader loadBeanDe ions INFO: Loading XML bean definitions from URL [jar:file:/D:/Vinay/JBoss/server/default/lib//allviant/carepass-service-1.0-SNAPS ar!/spring/beanRefFactory.xml] 12:23:10,867 ERROR [STDERR] Aug 18, 2010 12:23:10 PM org.springframework.context.support.AbstractApplicationContext obtainFre nFactory INFO: Bean factory for application context [org.springframework.context.support.classpathxmlapplicationcont...@607cd0]: org.s framework.beans.factory.support.defaultlistablebeanfact...@18d042a<mailto:framework.beans.factory.support.defaultlistablebeanfact...@18d042a> 12:23:11,164 ERROR [STDERR] Aug 18, 2010 12:23:11 PM org.springframework.beans.factory.support.DefaultListableBeanFactory pre ntiateSingletons INFO: Pre-instantiating singletons in org.springframework.beans.factory.support.defaultlistablebeanfact...@18d042a<mailto:org.springframework.beans.factory.support.defaultlistablebeanfact...@18d042a>: defining [ear.context]; root of factory hierarchy 12:23:11,524 ERROR [STDERR] Aug 18, 2010 12:23:11 PM org.springframework.context.support.AbstractApplicationContext prepareRe INFO: Refreshing org.springframework.context.support.classpathxmlapplicationcont...@1efb1c0<mailto:org.springframework.context.support.classpathxmlapplicationcont...@1efb1c0>: display name [org.springframewor text.support.classpathxmlapplicationcont...@1efb1c0<mailto:text.support.classpathxmlapplicationcont...@1efb1c0>]; startup date [Wed Aug 18 12:23:11 IST 2010]; root of context hierarchy 12:23:11,774 ERROR [STDERR] Aug 18, 2010 12:23:11 PM org.springframework.beans.factory.xml.XmlBeanDefinitionReader loadBeanDe ions INFO: Loading XML bean definitions from class path resource [spring/identity-context.xml] 12:23:12,039 ERROR [STDERR] Aug 18, 2010 12:23:12 PM org.springframework.beans.factory.xml.XmlBeanDefinitionReader loadBeanDe ions INFO: Loading XML bean definitions from class path resource [spring/dao-context.xml] 12:23:12,289 ERROR [STDERR] Aug 18, 2010 12:23:12 PM org.springframework.beans.factory.xml.XmlBeanDefinitionReader loadBeanDe ions INFO: Loading XML bean definitions from class path resource [spring/service-context.xml] 12:23:12,633 ERROR [STDERR] Aug 18, 2010 12:23:12 PM org.springframework.beans.factory.xml.XmlBeanDefinitionReader loadBeanDe ions INFO: Loading XML bean definitions from class path resource [spring/cms-api-context.xml] 12:23:12,867 ERROR [STDERR] Aug 18, 2010 12:23:12 PM org.springframework.beans.factory.xml.XmlBeanDefinitionReader loadBeanDe ions INFO: Loading XML bean definitions from class path resource [spring/scheduler-context.xml] 12:23:13,070 ERROR [STDERR] Aug 18, 2010 12:23:13 PM org.springframework.beans.factory.xml.XmlBeanDefinitionReader loadBeanDe ions INFO: Loading XML bean definitions from class path resource [spring/search-context.xml] 12:23:13,336 INFO [Server] Runtime shutdown hook called, forceHalt: true 12:23:13,414 INFO [Server] JBoss SHUTDOWN: Undeploying all packages 12:23:15,992 INFO [MLog] MLog clients using log4j logging. 12:23:16,242 INFO [C3P0Registry] Initializing c3p0-0.9.1 [built 16-January-2007 14:46:42; debug? true; trace: 10] 12:23:20,008 INFO [AbstractPoolBackedDataSource] Initializing c3p0 pool... com.mchange.v2.c3p0.ComboPooledDataSource [ acqui rement -> 3, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, b fterAcquireFailure -> false, checkoutTimeout -> 60000, connectionCustomizerClassName -> null, connectionTesterClassName -> co ange.v2.c3p0.impl.DefaultConnectionTester, dataSourceName -> 1hge11g8a10m8qv8xoxx5y|3d7f99, debugUnreturnedConnectionStackTra > true, description -> null, driverClass -> com.mysql.jdbc.Driver, > factoryClassLocation -> null, forceIgnoreUnresolvedTransac -> false, identityToken -> 1hge11g8a10m8qv8xoxx5y|3d7f99, idleConnectionTestPeriod -> 600, initialPoolSize -> 3, jdbcUrl -> mysql://localhost:3306/carepass, lastAcquisitionFailureDefaultUser -> null, maxAdministrativeTaskTime -> 0, maxConnectionAge maxIdleTime -> 0, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 40, maxStatements -> 0, maxStatementsPerConnection -> 20 PoolSize -> 3, numHelperThreads -> 3, numThreadsAwaitingCheckoutDefaultUser -> 0, preferredTestQuery -> Select top 1 * from u properties -> {user=******, password=******}, propertyCycle -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout alse, unreturnedConnectionTimeout -> 600, usesTraditionalReflectiveProxies -> false ] 12:23:32,602 INFO [STDOUT] Got the URL jar:file:/D:/Vinay/JBoss/server/default/lib//allviant/carepass-common-1.0-SNAPSHOT.ja rorMessage.properties 12:23:36,945 INFO [TomcatDeployer] undeploy, ctxPath=/, warUrl=.../deploy/consumer.war/ 12:23:38,273 INFO [TomcatDeployer] undeploy, ctxPath=/assets, warUrl=.../deploy/assets.war/ 12:23:38,273 INFO [TomcatDeployer] deploy, ctxPath=/employer, warUrl=.../deploy/employer.war/ 12:23:42,398 INFO [AbstractPoolBackedDataSource] Initializing c3p0 pool... com.mchange.v2.c3p0.ComboPooledDataSource [ acqui rement -> 3, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, b fterAcquireFailure -> false, checkoutTimeout -> 60000, connectionCustomizerClassName -> null, connectionTesterClassName -> co ange.v2.c3p0.impl.DefaultConnectionTester, dataSourceName -> 1hge11g8a10m8qv8xoxx5y|6b834a, debugUnreturnedConnectionStackTra > true, description -> null, driverClass -> com.mysql.jdbc.Driver, > factoryClassLocation -> null, forceIgnoreUnresolvedTransac -> false, identityToken -> 1hge11g8a10m8qv8xoxx5y|6b834a, idleConnectionTestPeriod -> 600, initialPoolSize -> 3, jdbcUrl -> mysql://localhost:3306/carepass, lastAcquisitionFailureDefaultUser -> null, maxAdministrativeTaskTime -> 0, maxConnectionAge maxIdleTime -> 0, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 40, maxStatements -> 0, maxStatementsPerConnection -> 20 PoolSize -> 3, numHelperThreads -> 3, numThreadsAwaitingCheckoutDefaultUser -> 0, preferredTestQuery -> Select top 1 * from u properties -> {user=******, password=******}, propertyCycle -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout alse, unreturnedConnectionTimeout -> 600, usesTraditionalReflectiveProxies -> false ] Thanks a ton for your time! Vinay.
