You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@qpid.apache.org by Pekka Enberg <pe...@cs.helsinki.fi> on 2008/10/28 09:57:06 UTC

[PROBLEM] Protocol version mismatch in Qpid Java client/server?

Hi all,

When I run the following JMS example:

https://svn.apache.org/repos/asf/incubator/qpid/trunk/qpid/java/client/example/src/main/java/org/apache/qpid/example/jmsexample/direct/Producer.java

against the Java server implementation, I get the following error for each message:

penberg@penberg-laptop:~/tmp/qpid/qpid-incubating-M3$ qpid-server -c etc/config.xml 
Setting QPID_WORK to /home/penberg as default
System Properties set to -Damqj.logging.level=info -DQPID_HOME=/home/penberg/tmp/qpid/qpid-incubating-M3/ -DQPID_WORK=/home/penberg
Using QPID_CLASSPATH /home/penberg/tmp/qpid/qpid-incubating-M3//lib/qpid-incubating.jar:/home/penberg/tmp/qpid/qpid-incubating-M3//lib/bdbstore-launch.jar
Info: QPID_JAVA_GC not set. Defaulting to JAVA_GC -XX:+UseConcMarkSweepGC -XX:+HeapDumpOnOutOfMemoryError
Info: QPID_JAVA_MEM not set. Defaulting to JAVA_MEM -Xmx1024m
Using configuration file /home/penberg/tmp/qpid/qpid-incubating-M3/etc/config.xml
Configuring logger using configuration file /home/penberg/tmp/qpid/qpid-incubating-M3/etc/log4j.xml
2008-10-28 10:53:47,845 WARN  [main] management.AMQUserManagementMBean (AMQUserManagementMBean.java:387) - Access rights contains user 'admin' but there is no authentication data for that user
2008-10-28 10:53:47,848 WARN  [main] management.AMQUserManagementMBean (AMQUserManagementMBean.java:387) - Access rights contains user 'user' but there is no authentication data for that user
2008-10-28 10:53:48,063 WARN  [main] management.JMXManagedObjectRegistry (JMXManagedObjectRegistry.java:153) - JMX: Started JMXConnector server on port '8999' with security disabled
2008-10-28 10:53:48,142 WARN  [main] access.ACLManager (ACLManager.java:52) - No ACL Plugin specified. Using default ACL Plugin 'AllowAll' for VirtualHost:'localhost'
2008-10-28 10:53:48,190 WARN  [main] access.ACLManager (ACLManager.java:52) - No ACL Plugin specified. Using default ACL Plugin 'AllowAll' for VirtualHost:'development'
2008-10-28 10:53:48,200 WARN  [main] access.ACLManager (ACLManager.java:52) - No ACL Plugin specified. Using default ACL Plugin 'AllowAll' for VirtualHost:'test'
2008-10-28 10:53:48,208 INFO  [main] server.Main (Main.java:274) - Starting Qpid Broker incubating-M3 build: exported
2008-10-28 10:53:48,381 WARN  [main] transport.ConnectorConfiguration (ConnectorConfiguration.java:114) - Using Mina IO Processing
2008-10-28 10:53:48,435 INFO  [main] server.Main (Main.java:434) - Qpid.AMQP listening on non-SSL address 0.0.0.0/0.0.0.0:5672
2008-10-28 10:53:48,436 INFO  [main] server.Main (Main.java:456) - Qpid Broker Ready :incubating-M3 build: exported
2008-10-28 10:53:54,613 ERROR [pool-1-thread-1] protocol.AMQMinaProtocolSession (AMQMinaProtocolSession.java:275) - Received incorrect protocol initiation
org.apache.qpid.framing.AMQProtocolVersionException: Protocol version 0.10 not suppoerted by this version of the Qpid broker.
        at org.apache.qpid.framing.ProtocolInitiation.checkVersion(ProtocolInitiation.java:180)
        at org.apache.qpid.server.protocol.AMQMinaProtocolSession.protocolInitiationReceived(AMQMinaProtocolSession.java:256)
        at org.apache.qpid.server.protocol.AMQMinaProtocolSession.dataBlockReceived(AMQMinaProtocolSession.java:191)
        at org.apache.qpid.server.protocol.AMQPFastProtocolHandler.messageReceived(AMQPFastProtocolHandler.java:244)
        at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived(AbstractIoFilterChain.java:703)
        at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:362)
        at org.apache.mina.common.support.AbstractIoFilterChain.access$1200(AbstractIoFilterChain.java:54)
        at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:800)
        at org.apache.qpid.pool.PoolingFilter.messageReceived(PoolingFilter.java:334)
        at org.apache.mina.filter.ReferenceCountingIoFilter.messageReceived(ReferenceCountingIoFilter.java:96)
        at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:362)
        at org.apache.mina.common.support.AbstractIoFilterChain.access$1200(AbstractIoFilterChain.java:54)
        at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:800)
        at org.apache.mina.filter.codec.support.SimpleProtocolDecoderOutput.flush(SimpleProtocolDecoderOutput.java:60)
        at org.apache.mina.filter.codec.QpidProtocolCodecFilter.messageReceived(QpidProtocolCodecFilter.java:174)
        at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:362)
        at org.apache.mina.common.support.AbstractIoFilterChain.access$1200(AbstractIoFilterChain.java:54)
        at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:800)
        at org.apache.qpid.pool.Event$ReceivedEvent.process(Event.java:86)
        at org.apache.qpid.pool.Job.processAll(Job.java:114)
        at org.apache.qpid.pool.Job.run(Job.java:153)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
        at java.lang.Thread.run(Thread.java:619)

This doesn't seem to be fatal as messages are routed to any JMS
listeners but seems rather strange as both the client and the server
Jars are from incubating-M3 version.

		Pekka


Re: [PROBLEM] Protocol version mismatch in Qpid Java client/server?

Posted by Martin Ritchie <ri...@apache.org>.
2008/10/28 Pekka Enberg <pe...@cs.helsinki.fi>:
> Hi all,
>
> When I run the following JMS example:
>
> https://svn.apache.org/repos/asf/incubator/qpid/trunk/qpid/java/client/example/src/main/java/org/apache/qpid/example/jmsexample/direct/Producer.java
>
> against the Java server implementation, I get the following error for each message:
>
> penberg@penberg-laptop:~/tmp/qpid/qpid-incubating-M3$ qpid-server -c etc/config.xml
> Setting QPID_WORK to /home/penberg as default
> System Properties set to -Damqj.logging.level=info -DQPID_HOME=/home/penberg/tmp/qpid/qpid-incubating-M3/ -DQPID_WORK=/home/penberg
> Using QPID_CLASSPATH /home/penberg/tmp/qpid/qpid-incubating-M3//lib/qpid-incubating.jar:/home/penberg/tmp/qpid/qpid-incubating-M3//lib/bdbstore-launch.jar
> Info: QPID_JAVA_GC not set. Defaulting to JAVA_GC -XX:+UseConcMarkSweepGC -XX:+HeapDumpOnOutOfMemoryError
> Info: QPID_JAVA_MEM not set. Defaulting to JAVA_MEM -Xmx1024m
> Using configuration file /home/penberg/tmp/qpid/qpid-incubating-M3/etc/config.xml
> Configuring logger using configuration file /home/penberg/tmp/qpid/qpid-incubating-M3/etc/log4j.xml
> 2008-10-28 10:53:47,845 WARN  [main] management.AMQUserManagementMBean (AMQUserManagementMBean.java:387) - Access rights contains user 'admin' but there is no authentication data for that user
> 2008-10-28 10:53:47,848 WARN  [main] management.AMQUserManagementMBean (AMQUserManagementMBean.java:387) - Access rights contains user 'user' but there is no authentication data for that user
> 2008-10-28 10:53:48,063 WARN  [main] management.JMXManagedObjectRegistry (JMXManagedObjectRegistry.java:153) - JMX: Started JMXConnector server on port '8999' with security disabled
> 2008-10-28 10:53:48,142 WARN  [main] access.ACLManager (ACLManager.java:52) - No ACL Plugin specified. Using default ACL Plugin 'AllowAll' for VirtualHost:'localhost'
> 2008-10-28 10:53:48,190 WARN  [main] access.ACLManager (ACLManager.java:52) - No ACL Plugin specified. Using default ACL Plugin 'AllowAll' for VirtualHost:'development'
> 2008-10-28 10:53:48,200 WARN  [main] access.ACLManager (ACLManager.java:52) - No ACL Plugin specified. Using default ACL Plugin 'AllowAll' for VirtualHost:'test'
> 2008-10-28 10:53:48,208 INFO  [main] server.Main (Main.java:274) - Starting Qpid Broker incubating-M3 build: exported
> 2008-10-28 10:53:48,381 WARN  [main] transport.ConnectorConfiguration (ConnectorConfiguration.java:114) - Using Mina IO Processing
> 2008-10-28 10:53:48,435 INFO  [main] server.Main (Main.java:434) - Qpid.AMQP listening on non-SSL address 0.0.0.0/0.0.0.0:5672
> 2008-10-28 10:53:48,436 INFO  [main] server.Main (Main.java:456) - Qpid Broker Ready :incubating-M3 build: exported
> 2008-10-28 10:53:54,613 ERROR [pool-1-thread-1] protocol.AMQMinaProtocolSession (AMQMinaProtocolSession.java:275) - Received incorrect protocol initiation
> org.apache.qpid.framing.AMQProtocolVersionException: Protocol version 0.10 not suppoerted by this version of the Qpid broker.
>        at org.apache.qpid.framing.ProtocolInitiation.checkVersion(ProtocolInitiation.java:180)
>        at org.apache.qpid.server.protocol.AMQMinaProtocolSession.protocolInitiationReceived(AMQMinaProtocolSession.java:256)
>        at org.apache.qpid.server.protocol.AMQMinaProtocolSession.dataBlockReceived(AMQMinaProtocolSession.java:191)
>        at org.apache.qpid.server.protocol.AMQPFastProtocolHandler.messageReceived(AMQPFastProtocolHandler.java:244)
>        at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived(AbstractIoFilterChain.java:703)
>        at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:362)
>        at org.apache.mina.common.support.AbstractIoFilterChain.access$1200(AbstractIoFilterChain.java:54)
>        at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:800)
>        at org.apache.qpid.pool.PoolingFilter.messageReceived(PoolingFilter.java:334)
>        at org.apache.mina.filter.ReferenceCountingIoFilter.messageReceived(ReferenceCountingIoFilter.java:96)
>        at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:362)
>        at org.apache.mina.common.support.AbstractIoFilterChain.access$1200(AbstractIoFilterChain.java:54)
>        at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:800)
>        at org.apache.mina.filter.codec.support.SimpleProtocolDecoderOutput.flush(SimpleProtocolDecoderOutput.java:60)
>        at org.apache.mina.filter.codec.QpidProtocolCodecFilter.messageReceived(QpidProtocolCodecFilter.java:174)
>        at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:362)
>        at org.apache.mina.common.support.AbstractIoFilterChain.access$1200(AbstractIoFilterChain.java:54)
>        at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:800)
>        at org.apache.qpid.pool.Event$ReceivedEvent.process(Event.java:86)
>        at org.apache.qpid.pool.Job.processAll(Job.java:114)
>        at org.apache.qpid.pool.Job.run(Job.java:153)
>        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
>        at java.lang.Thread.run(Thread.java:619)
>
> This doesn't seem to be fatal as messages are routed to any JMS
> listeners but seems rather strange as both the client and the server
> Jars are from incubating-M3 version.
>
>                Pekka
>
>

Hi Pekka,

What you are seeing is a rather over zealous output as a result of
protocol negotication.

The Java M3 client will attempt to make a connection using AMQP 0-10
which the Java broker does not yet support. When the broker rejects
the connection the client will then connect to the Java broker with
the version it specifies.

If you are seeing this for every message you send then I would advise
that you do not create a new connection for every message you send. If
you are using mule or spring then they can be configured to pool the
connection rather than making a new one each time.

The exception stack trace has been removed for M4 which is just
entering its test phase. (Though the spelling error remains :()

Hope that helps

Martin
-- 
Martin Ritchie