You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@activemq.apache.org by Richard Dunn <gn...@mac.com> on 2009/01/14 18:39:10 UTC

Re: Log4J ActiveMQ JMS Appender

I am also having this problem, but the problem only occurs in one scenario -
in my appfuse based spring web application. If I use the same versions of
activemq and log4j in my other web applications (older traditional
jsp/servlet webapps) everything works fine. I am currently using activemq
5.1, 5.2, 5.3 (beta versions) and log4j 1.2.15 and I get error listed in
just the spring application. The same versions of activemq and log4j work
fine with non-spring. I am wondering if this may be due to the introduction
of the slf4j as part of the spring.

This all is rather distressing for me as I see evidence of this problem on
many lists and see mention of this in
https://issues.apache.org/activemq/browse/AMQ-1473, but no resolutions.

Too much has been committed already in our JMSAppender based logging
infrastructure (which works well in all but spring) and our spring based
webapp to easily back out of either.

log4j:WARN No appenders could be found for logger
(org.apache.activemq.transport.WireFormatNegotiator).
log4j:WARN Please initialize the log4j system properly.
log4j:ERROR Error while activating options for appender named [jms].
javax.jms.JMSException: Wire format negotiation timeout: peer did not send
his wire format.
	at
org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:62)
	at
org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1206)
	at
org.apache.activemq.ActiveMQConnection.ensureConnectionInfoSent(ActiveMQConnection.java:1289)
	at
org.apache.activemq.ActiveMQConnection.createSession(ActiveMQConnection.java:295)
	at
org.apache.activemq.ActiveMQConnection.createTopicSession(ActiveMQConnection.java:998)
	at org.apache.log4j.net.JMSAppender.activateOptions(JMSAppender.java:217)
	at org.apache.log4j.config.PropertySetter.activate(PropertySetter.java:257)
	at
org.apache.log4j.config.PropertySetter.setProperties(PropertySetter.java:133)
	at
org.apache.log4j.config.PropertySetter.setProperties(PropertySetter.java:97)
	at
org.apache.log4j.PropertyConfigurator.parseAppender(PropertyConfigurator.java:689)
	at
org.apache.log4j.PropertyConfigurator.parseCategory(PropertyConfigurator.java:647)
	at
org.apache.log4j.PropertyConfigurator.configureRootCategory(PropertyConfigurator.java:544)
	at
org.apache.log4j.PropertyConfigurator.doConfigure(PropertyConfigurator.java:440)
	at
org.apache.log4j.PropertyConfigurator.doConfigure(PropertyConfigurator.java:476)
	at
org.apache.log4j.helpers.OptionConverter.selectAndConfigure(OptionConverter.java:471)
	at org.apache.log4j.LogManager.<clinit>(LogManager.java:125)
	at org.slf4j.impl.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:73)
	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:88)
	at
org.apache.commons.logging.impl.SLF4JLogFactory.getInstance(SLF4JLogFactory.java:155)
	at
org.apache.commons.logging.impl.SLF4JLogFactory.getInstance(SLF4JLogFactory.java:131)
	at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:645)

-- 
View this message in context: http://www.nabble.com/Log4J-ActiveMQ-JMS-Appender-tp18840199p21461090.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.


Re: Log4J ActiveMQ JMS Appender

Posted by Bruce Snyder <br...@gmail.com>.
On Wed, Jan 14, 2009 at 10:39 AM, Richard Dunn <gn...@mac.com> wrote:
>
> I am also having this problem, but the problem only occurs in one scenario -
> in my appfuse based spring web application. If I use the same versions of
> activemq and log4j in my other web applications (older traditional
> jsp/servlet webapps) everything works fine. I am currently using activemq
> 5.1, 5.2, 5.3 (beta versions) and log4j 1.2.15 and I get error listed in
> just the spring application. The same versions of activemq and log4j work
> fine with non-spring. I am wondering if this may be due to the introduction
> of the slf4j as part of the spring.
>
> This all is rather distressing for me as I see evidence of this problem on
> many lists and see mention of this in
> https://issues.apache.org/activemq/browse/AMQ-1473, but no resolutions.
>
> Too much has been committed already in our JMSAppender based logging
> infrastructure (which works well in all but spring) and our spring based
> webapp to easily back out of either.
>
> log4j:WARN No appenders could be found for logger
> (org.apache.activemq.transport.WireFormatNegotiator).
> log4j:WARN Please initialize the log4j system properly.
> log4j:ERROR Error while activating options for appender named [jms].
> javax.jms.JMSException: Wire format negotiation timeout: peer did not send
> his wire format.
>        at
> org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:62)
>        at
> org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1206)
>        at
> org.apache.activemq.ActiveMQConnection.ensureConnectionInfoSent(ActiveMQConnection.java:1289)
>        at
> org.apache.activemq.ActiveMQConnection.createSession(ActiveMQConnection.java:295)
>        at
> org.apache.activemq.ActiveMQConnection.createTopicSession(ActiveMQConnection.java:998)
>        at org.apache.log4j.net.JMSAppender.activateOptions(JMSAppender.java:217)

Do you have a configuration with a logger that makes use of the
org.apache.log4j.net.JMSAppender as noted above? Based on the output
above, it looks like the logger's name is 'jms'.

Bruce
-- 
perl -e 'print unpack("u30","D0G)U8V4\@4VYY9&5R\"F)R=6-E+G-N>61E<D\!G;6%I;\"YC;VT*"
);'

Apache ActiveMQ - http://activemq.org/
Apache Camel - http://activemq.org/camel/
Apache ServiceMix - http://servicemix.org/

Blog: http://bruceblog.org/

Re: Log4J ActiveMQ JMS Appender

Posted by Richard Dunn <gn...@mac.com>.

> can you run with -Dlog4j.debug (set the system property) to see where
> the log4j configuration is coming from?

The following is the debug output - other webapps (not spring) started up
normally, with the same
settings from the log4j.properties.

log4j: Using URL
[file:/usr/local/apache-tomcat-6.0.18/webapps/Utilities/WEB-INF/classes/log4j.properties]
for automatic log4j configuration.
log4j: Reading configuration from URL
file:/usr/local/apache-tomcat-6.0.18/webapps/Utilities/WEB-INF/classes/log4j.properties
log4j: Parsing for [root] with value=[debug, jms].
log4j: Level token is [debug].
log4j: Category root set to DEBUG
log4j: Parsing appender named "jms".
log4j: Setting property [password] to [*******].
log4j: Setting property [userName] to [*******].
log4j: Setting property [topicConnectionFactoryBindingName] to
[ConnectionFactory].
log4j: Setting property [topicBindingName] to [dynamicTopics/locallogging].
log4j: Setting property [providerURL] to [tcp://jmsserver:61616].
log4j: Setting property [initialContextFactoryName] to
[org.apache.activemq.jndi.ActiveMQInitialContextFactory].
log4j: Getting initial context.
log4j: Looking up [ConnectionFactory]
log4j: About to create TopicConnection.
log4j:WARN No appenders could be found for logger
(org.apache.activemq.transport.WireFormatNegotiator).
log4j:WARN Please initialize the log4j system properly.
log4j: Creating TopicSession, non-transactional, in AUTO_ACKNOWLEDGE mode.
log4j:ERROR Error while activating options for appender named [jms].
javax.jms.JMSException: Wire format negotiation timeout: peer did not send
his wire format.
	at
org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:62)
	at
org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1206)
	at
org.apache.activemq.ActiveMQConnection.ensureConnectionInfoSent(ActiveMQConnection.java:1289)
	at
org.apache.activemq.ActiveMQConnection.createSession(ActiveMQConnection.java:295)
	at
org.apache.activemq.ActiveMQConnection.createTopicSession(ActiveMQConnection.java:998)
	at org.apache.log4j.net.JMSAppender.activateOptions(JMSAppender.java:217)
	at org.apache.log4j.config.PropertySetter.activate(PropertySetter.java:257)
	at
org.apache.log4j.config.PropertySetter.setProperties(PropertySetter.java:133)
	at
org.apache.log4j.config.PropertySetter.setProperties(PropertySetter.java:97)
	at
org.apache.log4j.PropertyConfigurator.parseAppender(PropertyConfigurator.java:689)
	at
org.apache.log4j.PropertyConfigurator.parseCategory(PropertyConfigurator.java:647)
	at
org.apache.log4j.PropertyConfigurator.configureRootCategory(PropertyConfigurator.java:544)
	at
org.apache.log4j.PropertyConfigurator.doConfigure(PropertyConfigurator.java:440)
	at
org.apache.log4j.PropertyConfigurator.doConfigure(PropertyConfigurator.java:476)
	at
org.apache.log4j.helpers.OptionConverter.selectAndConfigure(OptionConverter.java:471)
	at org.apache.log4j.LogManager.<clinit>(LogManager.java:125)
	at org.slf4j.impl.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:73)
	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:88)
	at
org.apache.commons.logging.impl.SLF4JLogFactory.getInstance(SLF4JLogFactory.java:155)
	at
org.apache.commons.logging.impl.SLF4JLogFactory.getInstance(SLF4JLogFactory.java:131)
	at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:645)
	at
org.springframework.web.context.request.RequestContextListener.<init>(RequestContextListener.java:55)
	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:513)
	at java.lang.Class.newInstance0(Class.java:355)
	at java.lang.Class.newInstance(Class.java:308)
	at
org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:3787)
	at
org.apache.catalina.core.StandardContext.start(StandardContext.java:4342)
	at
org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:791)
	at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:771)
	at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:525)
	at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:830)
	at org.apache.catalina.startup.HostConfig.deployWARs(HostConfig.java:719)
	at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:490)
	at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1149)
	at
org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:311)
	at
org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:117)
	at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1053)
	at org.apache.catalina.core.StandardHost.start(StandardHost.java:719)
	at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1045)
	at org.apache.catalina.core.StandardEngine.start(StandardEngine.java:443)
	at org.apache.catalina.core.StandardService.start(StandardService.java:516)
	at org.apache.catalina.core.StandardServer.start(StandardServer.java:710)
	at org.apache.catalina.startup.Catalina.start(Catalina.java:578)
	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:597)
	at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:288)
	at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:413)
Caused by: java.io.IOException: Wire format negotiation timeout: peer did
not send his wire format.
	at
org.apache.activemq.transport.WireFormatNegotiator.oneway(WireFormatNegotiator.java:94)
	at
org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:40)
	at
org.apache.activemq.transport.ResponseCorrelator.asyncRequest(ResponseCorrelator.java:74)
	at
org.apache.activemq.transport.ResponseCorrelator.request(ResponseCorrelator.java:79)
	at
org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1195)
	... 50 more
log4j: Parsed "jms" options.
log4j: Parsing for [org.springframework] with value=[debug, jms].
log4j: Level token is [debug].
log4j: Category org.springframework set to DEBUG
log4j: Parsing appender named "jms".
log4j: Appender "jms" was already parsed.
log4j: Handling log4j.additivity.org.springframework=[null]
log4j: Parsing for [org.apache.activemq.ActiveMQConnection] with
value=[info, stdout].
log4j: Level token is [info].
log4j: Category org.apache.activemq.ActiveMQConnection set to INFO
log4j: Parsing appender named "stdout".
log4j: Parsing layout options for "stdout".
log4j: Setting property [conversionPattern] to [%d %-5p %c - %m%n].
log4j: End of parsing for "stdout".
log4j: Parsed "stdout" options.
log4j: Handling
log4j.additivity.org.apache.activemq.ActiveMQConnection=[null]
log4j: Parsing for [com.contentwatch] with value=[debug, jms].
log4j: Level token is [debug].
log4j: Category com.contentwatch set to DEBUG
log4j: Parsing appender named "jms".
log4j: Appender "jms" was already parsed.
log4j: Handling log4j.additivity.com.contentwatch=[null]
log4j: Finished configuring.

My log4j.properties file:

### Set root logger level and appenders
log4j.rootLogger=debug, jms

### Set logger level and appender for ContentWatch classes
log4j.logger.com.contentwatch=debug, jms

# set logger for jms to stdout in case of problems with the jms
log4j.logger.org.apache.activemq.ActiveMQConnection=info, stdout
log4j.logger.org.springframework=debug, jms

### stdout appender defined
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d %-5p %c - %m%n

### file appender defined
log4j.appender.file=org.apache.log4j.RollingFileAppender
log4j.appender.file.File=${catalina.home}/logs/contentwatch_${hostname}.log
log4j.appender.file.File.Append=true
log4j.appender.file.File.MaxFileSize=1000KB
log4j.appender.file.File.MaxBackupIndex=1
log4j.appender.file.layout=org.apache.log4j.PatternLayout
log4j.appender.file.layout.ConversionPattern=%d %-5p %c - %m%n

# log to JMS
log4j.appender.jms=org.apache.log4j.net.JMSAppender
log4j.appender.jms.InitialContextFactoryName=org.apache.activemq.jndi.ActiveMQInitialContextFactory
log4j.appender.jms.ProviderURL=tcp://jmsserver:61616
log4j.appender.jms.TopicBindingName=dynamicTopics/locallogging
log4j.appender.jms.TopicConnectionFactoryBindingName=ConnectionFactory
log4j.appender.jms.UserName=*********
log4j.appender.jms.Password=*********

-- 
View this message in context: http://www.nabble.com/Log4J-ActiveMQ-JMS-Appender-tp18840199p21464605.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.


Re: Log4J ActiveMQ JMS Appender

Posted by Gary Tully <ga...@gmail.com>.
can you run with -Dlog4j.debug (set the system property) to see where
the log4j configuration is coming from?

It may be that the wireFormatNegotiator is trying to log a message
which is trying to start a jms connection which uses
wireFormatNegotiator etc. Chicken and egg.
logging for activemq needs to be disabled if it is used as a default appender.
Possibly you have this configured but your log4j configuration is not
being picked up.

-Dlog4j.debug should help diagnose this as it will use System.err to
output what it is up to while it gets initialised.

2009/1/14 Richard Dunn <gn...@mac.com>:
>
> I am also having this problem, but the problem only occurs in one scenario -
> in my appfuse based spring web application. If I use the same versions of
> activemq and log4j in my other web applications (older traditional
> jsp/servlet webapps) everything works fine. I am currently using activemq
> 5.1, 5.2, 5.3 (beta versions) and log4j 1.2.15 and I get error listed in
> just the spring application. The same versions of activemq and log4j work
> fine with non-spring. I am wondering if this may be due to the introduction
> of the slf4j as part of the spring.
>
> This all is rather distressing for me as I see evidence of this problem on
> many lists and see mention of this in
> https://issues.apache.org/activemq/browse/AMQ-1473, but no resolutions.
>
> Too much has been committed already in our JMSAppender based logging
> infrastructure (which works well in all but spring) and our spring based
> webapp to easily back out of either.
>
> log4j:WARN No appenders could be found for logger
> (org.apache.activemq.transport.WireFormatNegotiator).
> log4j:WARN Please initialize the log4j system properly.
> log4j:ERROR Error while activating options for appender named [jms].
> javax.jms.JMSException: Wire format negotiation timeout: peer did not send
> his wire format.
>        at
> org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:62)
>        at
> org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1206)
>        at
> org.apache.activemq.ActiveMQConnection.ensureConnectionInfoSent(ActiveMQConnection.java:1289)
>        at
> org.apache.activemq.ActiveMQConnection.createSession(ActiveMQConnection.java:295)
>        at
> org.apache.activemq.ActiveMQConnection.createTopicSession(ActiveMQConnection.java:998)
>        at org.apache.log4j.net.JMSAppender.activateOptions(JMSAppender.java:217)
>        at org.apache.log4j.config.PropertySetter.activate(PropertySetter.java:257)
>        at
> org.apache.log4j.config.PropertySetter.setProperties(PropertySetter.java:133)
>        at
> org.apache.log4j.config.PropertySetter.setProperties(PropertySetter.java:97)
>        at
> org.apache.log4j.PropertyConfigurator.parseAppender(PropertyConfigurator.java:689)
>        at
> org.apache.log4j.PropertyConfigurator.parseCategory(PropertyConfigurator.java:647)
>        at
> org.apache.log4j.PropertyConfigurator.configureRootCategory(PropertyConfigurator.java:544)
>        at
> org.apache.log4j.PropertyConfigurator.doConfigure(PropertyConfigurator.java:440)
>        at
> org.apache.log4j.PropertyConfigurator.doConfigure(PropertyConfigurator.java:476)
>        at
> org.apache.log4j.helpers.OptionConverter.selectAndConfigure(OptionConverter.java:471)
>        at org.apache.log4j.LogManager.<clinit>(LogManager.java:125)
>        at org.slf4j.impl.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:73)
>        at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:88)
>        at
> org.apache.commons.logging.impl.SLF4JLogFactory.getInstance(SLF4JLogFactory.java:155)
>        at
> org.apache.commons.logging.impl.SLF4JLogFactory.getInstance(SLF4JLogFactory.java:131)
>        at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:645)
>
> --
> View this message in context: http://www.nabble.com/Log4J-ActiveMQ-JMS-Appender-tp18840199p21461090.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>
>



-- 
http://blog.garytully.com

Open Source SOA
http://FUSESource.com