qpid-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Robbie Gemmell <robbie.gemm...@gmail.com>
Subject Re: problems using cqpid with java broker
Date Tue, 14 Feb 2012 11:43:11 GMT
On 14 February 2012 06:44, Brandon Pedersen <bpedman@gmail.com> wrote:
> On Mon, Feb 13, 2012 at 3:20 PM, Robbie Gemmell
> <robbie.gemmell@gmail.com> wrote:
>> Thanks to Gordon for stepping in here and helping out with the C++
>> client/python bindings side of things, I had admittedly missed that
>> point and wouldn't have had much of a clue on that front :)
>>
>> On the below, it would appear that the commands you are using are
>> resulting in the client trying to declare an existing exchange (e.g.
>> amq.topic) with a different exchange type than it exists with already
>> (i.e not topic). I'm rather entrenched in JMS land and dont have that
>> good an idea of the Address Strings, but I guess I would maybe be
>> taking a look at the arguments you are feeding to Spout in that case.
>
> The format of the address string is correct (supposedly). If I use the
> same address with the python spout example, it works.
>
>> I have updated the message of the session execution exception the Java
>> broker emits when this occurs to list the exchange name and the two
>> conflicting exchange types in question. I forced an early build of the
>> nightly trunk Java release job, so you should now be able to get the
>> updated broker artifact here if you dont want to build your own:
>> https://builds.apache.org/view/M-R/view/Qpid/job/Qpid-Java-Artefact-Release/lastSuccessfulBuild/artifact/trunk/qpid/java/broker/release/
>

Updated again to log the types string name...knew I should have tried it ;)

> Thanks. I ran both the C++ and python spout examples again. The python
> spout works while the C++ one fails. It appears as though the C++
> client is running some sort of ExchangeBound query and the server
> responds that the queue and key is not found so it tries to create the
> exchange. The python spout on the other hand does an ExchangeQuery and
> it find the exchange (so it doesn't try to re-declare it).
>

My understanding of the Address syntax implementation is that the
clients query the broker to determine if a node is a queue or a topic
(implemented via an exchange and routing key combination), which is
what the python version below seems to be doing with its ExchangeQuery
to see if the test.topic exchange exists folloed by a QueueQuery to
see if the test.topic queue exists, with the broker replying that the
exchange does and the queue doesnt. The client then proceeded to
simply use the exchange and send the message, which wasnt delivered
because there was no queue bound to the exchange for the routing key
used.

The C++ client on the other hand is asking the broker via a
ExchangeBound command if there is a queue called test.topic which
happens to bound to an exchange called test.topic, and the broker is
replying that there isnt because there is no such queue. It didnt
indicate the exchange didnt exist, and thus implicitly confimed that
it did.  The client then decided to re-declare the exchange anyway
despite this, and in doing so seemed to neglect to send any exchange
type (or possibly the empty string), which the java broker interpreted
as an attempt to redeclare it with a different exchange type as it
doesnt match the existing one.

I cant really comment about the C++ client behaviour further than that
as I dont have any experience with it. Gordon, can you shed any light?

Robbie

> Here is the output with the C++ spout:
>
> 2012-02-13 21:48:14,072 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - SEND: [conn:4d811e2c] ch=0
> ConnectionOpenOk(knownHosts=[])
> 2012-02-13 21:48:14,072 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - FLUSH: [conn:4d811e2c]
> 2012-02-13 21:48:14,073 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - RECV: [conn:4d811e2c] ch=1
> SessionAttach(name=[B@47d978ea)
> 2012-02-13 21:48:14,073 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - SEND: [conn:4d811e2c] ch=1
> SessionAttached(name=[B@47d978ea)
> 2012-02-13 21:48:14,074 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - FLUSH: [conn:4d811e2c]
> 2012-02-13 21:48:14,074 INFO  [IoReceiver - /127.0.0.1:37964]
> logging.Log4jMessageLogger (Log4jMessageLogger.java:73) -
> [con:2(null@/127.0.0.1:37964/traacerlink)/ch:1] CHN-1001 : Create
> 2012-02-13 21:48:14,074 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - RECV: [conn:4d811e2c] ch=1
> SessionRequestTimeout(timeout=0)
> 2012-02-13 21:48:14,075 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - SEND: [conn:4d811e2c] ch=1
> SessionTimeout(timeout=0)
> 2012-02-13 21:48:14,075 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - FLUSH: [conn:4d811e2c]
> 2012-02-13 21:48:14,076 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - RECV: [conn:4d811e2c] ch=1
> SessionCommandPoint(commandId=0, commandOffset=0)
> 2012-02-13 21:48:14,076 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - RECV: [conn:4d811e2c] ch=1 [S]
> ExecutionSync()
> 2012-02-13 21:48:14,076 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - ID: [1] 0
> 2012-02-13 21:48:14,076 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) -
> ssn:"5e1ce183-f778-4e2b-8177-90fdbf617a21" synced to 0
> 2012-02-13 21:48:14,077 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) -
> ssn:"5e1ce183-f778-4e2b-8177-90fdbf617a21" processed([0,0]) 0 -1
> 2012-02-13 21:48:14,077 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - {}
> 2012-02-13 21:48:14,077 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - SEND: [conn:4d811e2c] ch=1
> SessionCompleted(commands={[0, 0]})
> 2012-02-13 21:48:14,078 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - FLUSH: [conn:4d811e2c]
> 2012-02-13 21:48:14,078 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - SEND: [conn:4d811e2c] ch=1
> SessionCompleted(commands={[0, 0]})
> 2012-02-13 21:48:14,078 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - FLUSH: [conn:4d811e2c]
> 2012-02-13 21:48:14,079 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - RECV: [conn:4d811e2c] ch=1 [S]
> ExchangeBound(exchange=test.topic, queue=test.topic, bindingKey=,
> arguments={})
> 2012-02-13 21:48:14,079 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - ID: [1] 1
> 2012-02-13 21:48:14,079 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - SEND: [conn:4d811e2c] ch=1
> SessionCommandPoint(commandId=0, commandOffset=0)
> 2012-02-13 21:48:14,080 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - FLUSH: [conn:4d811e2c]
> 2012-02-13 21:48:14,080 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - SEND: [conn:4d811e2c] ch=1 id=0
> ExecutionResult(commandId=1,
> value=ExchangeBoundResult(queueNotFound=true, keyNotMatched=true))
> 2012-02-13 21:48:14,080 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - FLUSH: [conn:4d811e2c]
> 2012-02-13 21:48:14,081 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - SEND: [conn:4d811e2c] ch=1
> SessionFlush(completed=true)
> 2012-02-13 21:48:14,081 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - FLUSH: [conn:4d811e2c]
> 2012-02-13 21:48:14,081 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) -
> ssn:"5e1ce183-f778-4e2b-8177-90fdbf617a21" processed([1,1]) 0 0
> 2012-02-13 21:48:14,082 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - {[0, 0]}
> 2012-02-13 21:48:14,082 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - SEND: [conn:4d811e2c] ch=1
> SessionCompleted(commands={[0, 1]})
> 2012-02-13 21:48:14,082 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - FLUSH: [conn:4d811e2c]
> 2012-02-13 21:48:14,083 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - RECV: [conn:4d811e2c] ch=1 [S]
> ExchangeDeclare(exchange=test.topic, type=, alternateExchange=,
> passive=true, arguments={})
> 2012-02-13 21:48:14,083 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - ID: [1] 2
> 2012-02-13 21:48:14,083 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - SEND: [conn:4d811e2c] ch=1 id=1
> ExecutionException(errorCode=NOT_ALLOWED, commandId=2,
> description=Attempt to redeclare exchange: test.topic of type
> org.apache.qpid.server.exchange.TopicExchange$1@3fcac3fa to .)
> 2012-02-13 21:48:14,083 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - FLUSH: [conn:4d811e2c]
> 2012-02-13 21:48:14,084 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - Closing
> [ssn:"5e1ce183-f778-4e2b-8177-90fdbf617a21"] in state [OPEN]
> 2012-02-13 21:48:14,084 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - SEND: [conn:4d811e2c] ch=1
> SessionRequestTimeout(timeout=0)
> 2012-02-13 21:48:14,084 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - FLUSH: [conn:4d811e2c]
> 2012-02-13 21:48:14,085 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - SEND: [conn:4d811e2c] ch=1
> SessionDetach(name=[B@262f4813)
> 2012-02-13 21:48:14,085 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - FLUSH: [conn:4d811e2c]
> 2012-02-13 21:48:14,086 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) -
> ssn:"5e1ce183-f778-4e2b-8177-90fdbf617a21" processed([2,2]) 1 1
> 2012-02-13 21:48:14,086 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - {[0, 1]}
> 2012-02-13 21:48:14,086 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - RECV: [conn:4d811e2c] ch=1
> SessionCompleted(commands=[0, 0], timelyReply=true)
> 2012-02-13 21:48:14,087 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) -
> ssn:"5e1ce183-f778-4e2b-8177-90fdbf617a21" complete(0, 0)
> 2012-02-13 21:48:14,087 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) -
> ssn:"5e1ce183-f778-4e2b-8177-90fdbf617a21"   commands remaining: 2
> 2012-02-13 21:48:14,087 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - SEND: [conn:4d811e2c] ch=1
> SessionKnownCompleted(commands=[0, 0])
> 2012-02-13 21:48:14,087 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - FLUSH: [conn:4d811e2c]
> 2012-02-13 21:48:14,088 DEBUG [IoReceiver - /127.0.0.1:37964]
> util.Logger (Logger.java:54) - RECV: [conn:4d811e2c] ch=0
> ConnectionClose(replyCode=NORMAL, replyText=OK)
>
> And the broker outputs the following with the python spout example:
>
> 2012-02-13 21:48:05,825 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - SEND: [conn:28294f62] ch=0
> ConnectionOpenOk(knownHosts=[])
> 2012-02-13 21:48:05,825 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - FLUSH: [conn:28294f62]
> 2012-02-13 21:48:05,827 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - RECV: [conn:28294f62] ch=0
> SessionAttach(name=[B@6d352447)
> 2012-02-13 21:48:05,827 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - SEND: [conn:28294f62] ch=0
> SessionAttached(name=[B@6d352447)
> 2012-02-13 21:48:05,828 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - FLUSH: [conn:28294f62]
> 2012-02-13 21:48:05,828 INFO  [IoReceiver - /127.0.0.1:37963]
> logging.Log4jMessageLogger (Log4jMessageLogger.java:73) -
> [con:1(null@/127.0.0.1:37963/traacerlink)/ch:0] CHN-1001 : Create
> 2012-02-13 21:48:05,829 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - RECV: [conn:28294f62] ch=0
> SessionCommandPoint(commandId=0, commandOffset=0)
> 2012-02-13 21:48:05,829 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - RECV: [conn:28294f62] ch=0 [S]
> ExchangeQuery(name=test.topic)
> 2012-02-13 21:48:05,829 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - ID: [0] 0
> 2012-02-13 21:48:05,830 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - SEND: [conn:28294f62] ch=0
> SessionCommandPoint(commandId=0, commandOffset=0)
> 2012-02-13 21:48:05,831 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - FLUSH: [conn:28294f62]
> 2012-02-13 21:48:05,831 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - SEND: [conn:28294f62] ch=0 id=0
> ExecutionResult(commandId=0, value=ExchangeQueryResult(type=topic))
> 2012-02-13 21:48:05,831 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - FLUSH: [conn:28294f62]
> 2012-02-13 21:48:05,832 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - SEND: [conn:28294f62] ch=0
> SessionFlush(completed=true)
> 2012-02-13 21:48:05,832 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - FLUSH: [conn:28294f62]
> 2012-02-13 21:48:05,832 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) -
> ssn:"e66d69f1-15dd-4b67-9af1-779bdf46a806:0" processed([0,0]) -1 -1
> 2012-02-13 21:48:05,832 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - {}
> 2012-02-13 21:48:05,833 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - SEND: [conn:28294f62] ch=0
> SessionCompleted(commands={[0, 0]})
> 2012-02-13 21:48:05,833 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - FLUSH: [conn:28294f62]
> 2012-02-13 21:48:05,834 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - RECV: [conn:28294f62] ch=0 [S]
> QueueQuery(queue=test.topic)
> 2012-02-13 21:48:05,834 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - ID: [0] 1
> 2012-02-13 21:48:05,835 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - SEND: [conn:28294f62] ch=0 id=1
> ExecutionResult(commandId=1, value=QueueQueryResult())
> 2012-02-13 21:48:05,835 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - FLUSH: [conn:28294f62]
> 2012-02-13 21:48:05,835 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) -
> ssn:"e66d69f1-15dd-4b67-9af1-779bdf46a806:0" processed([1,1]) 0 0
> 2012-02-13 21:48:05,835 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - {[0, 0]}
> 2012-02-13 21:48:05,836 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - SEND: [conn:28294f62] ch=0
> SessionCompleted(commands={[0, 1]})
> 2012-02-13 21:48:05,836 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - FLUSH: [conn:28294f62]
> 2012-02-13 21:48:05,836 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - RECV: [conn:28294f62] ch=0
> SessionCompleted(commands=[0, 0])
> 2012-02-13 21:48:05,837 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) -
> ssn:"e66d69f1-15dd-4b67-9af1-779bdf46a806:0" complete(0, 0)
> 2012-02-13 21:48:05,837 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) -
> ssn:"e66d69f1-15dd-4b67-9af1-779bdf46a806:0"   commands remaining: 2
> 2012-02-13 21:48:05,840 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - RECV: [conn:28294f62] ch=0 [S]
> MessageTransfer(destination=test.topic)
>  DeliveryProperties(routingKey=test)
>  MessageProperties(applicationHeaders={qpid.subject=test,
> spout-id=d9e8264e-887e-40b4-8215-663ca774123c:0})
> 2012-02-13 21:48:05,840 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - ID: [0] 2
> 2012-02-13 21:48:05,843 INFO  [IoReceiver - /127.0.0.1:37963]
> exchange.TopicExchange (TopicExchange.java:248) - Message routing key:
> test No routes.
> 2012-02-13 21:48:05,844 INFO  [IoReceiver - /127.0.0.1:37963]
> logging.Log4jMessageLogger (Log4jMessageLogger.java:73) -
> [con:1(null@/127.0.0.1:37963/traacerlink)/ch:0] EXH-1003 : Discarded
> Message : Name: test.topic Routing Key: test
> 2012-02-13 21:48:05,845 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) -
> ssn:"e66d69f1-15dd-4b67-9af1-779bdf46a806:0" processed([2,2]) 1 1
> 2012-02-13 21:48:05,845 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - {[0, 1]}
> 2012-02-13 21:48:05,846 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - SEND: [conn:28294f62] ch=0
> SessionCompleted(commands={[0, 2]})
> 2012-02-13 21:48:05,846 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - FLUSH: [conn:28294f62]
> 2012-02-13 21:48:05,847 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - RECV: [conn:28294f62] ch=0
> SessionDetach(name=[B@58ee21f5)
> 2012-02-13 21:48:05,848 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - SEND: [conn:28294f62] ch=0
> SessionDetached(name=[B@58ee21f5, code=NORMAL)
> 2012-02-13 21:48:05,849 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - FLUSH: [conn:28294f62]
> 2012-02-13 21:48:05,849 INFO  [IoReceiver - /127.0.0.1:37963]
> logging.Log4jMessageLogger (Log4jMessageLogger.java:73) -
> [con:1(null@/127.0.0.1:37963/traacerlink)/ch:0]
> [con:1(null@/127.0.0.1:37963/traacerlink)/ch:0] CHN-1003 : Close
> 2012-02-13 21:48:05,850 DEBUG [IoReceiver - /127.0.0.1:37963]
> util.Logger (Logger.java:54) - RECV: [conn:28294f62] ch=0
> ConnectionClose(replyCode=NORMAL)
>
> Thanks,
>
> -Brandon
>
>
>> Regards,
>> Robbie
>
> ---------------------------------------------------------------------
> Apache Qpid - AMQP Messaging Implementation
> Project:      http://qpid.apache.org
> Use/Interact: mailto:users-subscribe@qpid.apache.org
>

---------------------------------------------------------------------
Apache Qpid - AMQP Messaging Implementation
Project:      http://qpid.apache.org
Use/Interact: mailto:users-subscribe@qpid.apache.org


Mime
View raw message