You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@qpid.apache.org by lroloson <lr...@trmi.com> on 2009/08/04 20:34:57 UTC

Re: 0.5 C++ example listener hangs during testing

I turned on the additional logging as suggested - and ran some additional
tests today, using the 0.5 broker on Linux & the 0.5 listener on Windows
(which I modified to reconnect). When I tested again today the messages were
all delivered, however they were out of order. I have attached a snip from
the log, it appears the broker detected the disconnect. I have not tried the
broker built from the trunk yet.

.... log .....
....
2009-aug-04 12:45:09 trace SENT [127.0.0.1:36531]: Frame[BEbe; channel=2;
{SessionCompletedBody: commands={ [0,13] }; }]
2009-aug-04 12:45:10 trace RECV [127.0.0.1:36531]: Frame[Bbe; channel=2;
{MessageTransferBody: destination=amq.direct; accept-mode=1; acquire-mode=0;
}]
2009-aug-04 12:45:10 trace guest@QPID.1d5ba47a-8968-443d-97b2-1f535908db76:
recv cmd 14: {MessageTransferBody: destination=amq.direct; accept-mode=1;
acquire-mode=0; }
2009-aug-04 12:45:10 trace RECV [127.0.0.1:36531]: Frame[be; channel=2;
header (33 bytes); properties={{MessageProperties: content-length=38;
}{DeliveryProperties: delivery-mode=2; routing-key=aet_key; }}]
2009-aug-04 12:45:10 trace guest@QPID.1d5ba47a-8968-443d-97b2-1f535908db76:
recv cmd 14: header (33 bytes); properties={{MessageProperties:
content-length=38; }{DeliveryProperties: delivery-mode=2;
routing-key=aet_key; }}
2009-aug-04 12:45:10 trace RECV [127.0.0.1:36531]: Frame[Ebe; channel=2;
content (38 bytes) 15 Message : Tue...]
2009-aug-04 12:45:10 trace guest@QPID.1d5ba47a-8968-443d-97b2-1f535908db76:
recv cmd 14: content (38 bytes) 15 Message : Tue...
2009-aug-04 12:45:10 debug Message 0x1c3cea40 enqueued on aet_q[0x1c370ca0]
2009-aug-04 12:45:10 debug guest@QPID.1d5ba47a-8968-443d-97b2-1f535908db76:
receiver marked completed: 14 incomplete: { } unknown-completed: { [0,14] }
2009-aug-04 12:45:10 trace SENT [127.0.0.1:36531]: Frame[BEbe; channel=2;
{SessionCompletedBody: commands={ [0,14] }; }]
2009-aug-04 12:45:11 debug DISCONNECTED [127.0.0.1:36531]
2009-aug-04 12:45:11 debug guest@QPID.1d5ba47a-8968-443d-97b2-1f535908db76:
detached on broker.
2009-aug-04 12:47:46 debug RECV [192.168.230.229:49234] INIT(0-10)
2009-aug-04 12:47:46 debug min_ssf: 0, max_ssf: 256
2009-aug-04 12:47:46 info SASL: Mechanism list: LOGIN ANONYMOUS PLAIN
2009-aug-04 12:47:46 trace SENT 192.168.230.229:49234 INIT(0-10)
2009-aug-04 12:47:46 trace SENT [192.168.230.229:49234]: Frame[BEbe;
channel=0; {ConnectionStartBody:
server-properties={qpid.federation_tag:V2:36:str16(3b244fc7-dce1-404c-9c4c-586577edb814)};
mechanisms=str16{V2:5:str16(LOGIN), V2:9:str16(ANONYMOUS),
V2:5:str16(PLAIN)}; locales=str16{V2:5:str16(en_US)}; }]
2009-aug-04 12:47:46 trace RECV [192.168.230.229:49234]: Frame[BEbe;
channel=0; {ConnectionStartOkBody:
client-properties={qpid.client_pid:F4:int32(4080),qpid.client_ppid:F4:int32(0),qpid.client_process:V2:0:str16(),qpid.session_flow:F4:int32(1)};
mechanism=PLAIN; response=xxxxxx; locale=en_US; }]

....
....

-- 
View this message in context: http://n2.nabble.com/0.5-C%2B%2B-example-listener-hangs-during-testing-tp3344401p3386382.html
Sent from the Apache Qpid users mailing list archive at Nabble.com.

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


Re: 0.5 C++ example listener hangs during testing

Posted by Gordon Sim <gs...@redhat.com>.
lroloson wrote:
> The Broker built from trunk rev 80239 and the 3rd part persistence from rev
> 3353 seem to send the messages in order when the connection is broken and
> then reestablished. The problems I noticed with the 0.5 release seem to be
> resolved at this level. 

Great! Thanks for the update. I believe this is due to the ability for 
the broker to detect the failed connection faster now that it tracks 
heartbeats as well as the client.

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


Re: 0.5 C++ example listener hangs during testing

Posted by lroloson <lr...@trmi.com>.
The Broker built from trunk rev 80239 and the 3rd part persistence from rev
3353 seem to send the messages in order when the connection is broken and
then reestablished. The problems I noticed with the 0.5 release seem to be
resolved at this level. 
-- 
View this message in context: http://n2.nabble.com/0.5-C%2B%2B-example-listener-hangs-during-testing-tp3344401p3460873.html
Sent from the Apache Qpid users mailing list archive at Nabble.com.

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


Re: 0.5 C++ example listener hangs during testing

Posted by Gordon Sim <gs...@redhat.com>.
lroloson wrote:
> I have Rev: 800555 built from the trunk, I am trying to build the persistence
> modules from the trunk as well. Rev: 3553 of the persistent trunk
> (http://anonsvn.jboss.org/repos/rhmessaging/store/trunk/cpp) fails when
> configured using the 800555 release;

Looks like the name of a method on the store interface was changed as of 
r801239[1] and the head of the trunk at the above url has already been 
modified for that. Try updating qpid trunk to 801239 or later.

--Gordon.

[1] http://svn.apache.org/viewvc?rev=801239&view=rev
> 
> ....
> ....
>  g++ -DHAVE_CONFIG_H -I. -I. -I.. -Werror -pedantic -Wall -Wextra
> -Wno-shadow -Wpointer-arith -Wcast-qual -Wcast-align -Wno-long-long
> -Wvolatile-register-var -Winvalid-pch -Wno-system-headers
> -I/root/Development/workspace/trunk/qpid/cpp/include
> -I/root/Development/workspace/trunk/qpid/cpp/src -I./gen -DRHM_CLEAN
> -pthread -g -O2 -MT StorePlugin.lo -MD -MP -MF .deps/StorePlugin.Tpo -c
> StorePlugin.cpp  -fPIC -DPIC -o .libs/StorePlugin.o
> StorePlugin.cpp: In member function 'virtual void
> qpid::broker::StorePlugin::earlyInitialize(qpid::Plugin::Target&)':
> StorePlugin.cpp:46: error: cannot allocate an object of abstract type
> 'mrg::msgstore::MessageStoreImpl'
> MessageStoreImpl.h:55: note:   because the following virtual functions are
> pure within 'mrg::msgstore::MessageStoreImpl':
> /root/Development/workspace/trunk/qpid/cpp/src/qpid/broker/MessageStore.h:66:
> note:     virtual void qpid::broker::MessageStore::discardInit(bool)
> make[3]: *** [StorePlugin.lo] Error 1
> make[3]: Leaving directory `/root/Development/workspace/persist/cpp/lib'
> make[2]: *** [all] Error 2
> make[2]: Leaving directory `/root/Development/workspace/persist/cpp/lib'
> make[1]: *** [all-recursive] Error 1
> make[1]: Leaving directory `/root/Development/workspace/persist/cpp'
> make: *** [all] Error 2
> ...
> ..
> Is there a different version of the persistent modules that builds with
> 800555?
> 


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


Re: 0.5 C++ example listener hangs during testing

Posted by lroloson <lr...@trmi.com>.
I have Rev: 800555 built from the trunk, I am trying to build the persistence
modules from the trunk as well. Rev: 3553 of the persistent trunk
(http://anonsvn.jboss.org/repos/rhmessaging/store/trunk/cpp) fails when
configured using the 800555 release;

....
....
 g++ -DHAVE_CONFIG_H -I. -I. -I.. -Werror -pedantic -Wall -Wextra
-Wno-shadow -Wpointer-arith -Wcast-qual -Wcast-align -Wno-long-long
-Wvolatile-register-var -Winvalid-pch -Wno-system-headers
-I/root/Development/workspace/trunk/qpid/cpp/include
-I/root/Development/workspace/trunk/qpid/cpp/src -I./gen -DRHM_CLEAN
-pthread -g -O2 -MT StorePlugin.lo -MD -MP -MF .deps/StorePlugin.Tpo -c
StorePlugin.cpp  -fPIC -DPIC -o .libs/StorePlugin.o
StorePlugin.cpp: In member function 'virtual void
qpid::broker::StorePlugin::earlyInitialize(qpid::Plugin::Target&)':
StorePlugin.cpp:46: error: cannot allocate an object of abstract type
'mrg::msgstore::MessageStoreImpl'
MessageStoreImpl.h:55: note:   because the following virtual functions are
pure within 'mrg::msgstore::MessageStoreImpl':
/root/Development/workspace/trunk/qpid/cpp/src/qpid/broker/MessageStore.h:66:
note:     virtual void qpid::broker::MessageStore::discardInit(bool)
make[3]: *** [StorePlugin.lo] Error 1
make[3]: Leaving directory `/root/Development/workspace/persist/cpp/lib'
make[2]: *** [all] Error 2
make[2]: Leaving directory `/root/Development/workspace/persist/cpp/lib'
make[1]: *** [all-recursive] Error 1
make[1]: Leaving directory `/root/Development/workspace/persist/cpp'
make: *** [all] Error 2
...
..
Is there a different version of the persistent modules that builds with
800555?

-- 
View this message in context: http://n2.nabble.com/0.5-C%2B%2B-example-listener-hangs-during-testing-tp3344401p3418124.html
Sent from the Apache Qpid users mailing list archive at Nabble.com.

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


Re: 0.5 C++ example listener hangs during testing

Posted by lroloson <lr...@trmi.com>.
I will work on getting the latest broker to build from the trunk, and I will
repeat the test. I will post the results here when completed. Thanks !
-- 
View this message in context: http://n2.nabble.com/0.5-C%2B%2B-example-listener-hangs-during-testing-tp3344401p3399777.html
Sent from the Apache Qpid users mailing list archive at Nabble.com.

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


Re: 0.5 C++ example listener hangs during testing

Posted by Gordon Sim <gs...@redhat.com>.
lroloson wrote:
> Carl, 
> 
> I tried you experiment this AM, and basically - if I unplug the cable on the
> linux end, and kill the listener on the other end (today I was using a linux
> listener on a separate machine), it works fine. When I plug the cable back
> in (a couple minutes later) & restart the listener, all the messages come in
> order. 
> 
> I repeated the same test without restarting the listener - I let it get in a
> loop where it tries to reconnect when the connection is broken. The
> connection is reestablished shortly after I plug the cable back in, and the
> messages are received out of order (same as before). Additionally - some of
> the messages do not get sent, I have to restart the client to get the
> missing messages ... they are all delivered, but it takes a reconnect and a
> restart to get them.

Looking at the '.reconnect' logs, the broker shows that messages 1 - 54 
were sent out on one connection of which the first 10 were acked; then 
55 - 200 were sent out on another connection; then 11 - 54 were sent on 
a third connection.

The broker logs the disconnection of the second of these connections 
just before the disconnection of the first connection which explains why 
messages 11-54 were not delivered to it - they were still 'locked' by 
the first connection. A third connection is then opened and it receives 
those messages, now requeued.

If you are able, I'd suggest trying the broker from trunk. The broker 
code has been modified since 0.5 such that it will detect the loss of 
the connection based on lack of heartbeats in the same way the client 
does and release the unacked messages.

With 0.5, if your client requests an exclusive subscription, then 
instead of getting messages delivered out of order in this case, you 
would get an error trying to resubscribe. That may (or may not!) be 
useful to you.

> 
> I have copies of my clients log, showing the messages with time stamps and
> sequence numbers, I also have copies of the qpidd.log (I started a new one
> prior to each test). There are 4 logs in a file located here
> http://files.me.com/lroloson/mkkv3w (that link should point to a file called
> BrokerOrder.tgz). Please let me know if you have problems getting the logs. 
> 
> thanks - Larry 


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


Re: 0.5 C++ example listener hangs during testing

Posted by lroloson <lr...@trmi.com>.
Carl, 

I tried you experiment this AM, and basically - if I unplug the cable on the
linux end, and kill the listener on the other end (today I was using a linux
listener on a separate machine), it works fine. When I plug the cable back
in (a couple minutes later) & restart the listener, all the messages come in
order. 

I repeated the same test without restarting the listener - I let it get in a
loop where it tries to reconnect when the connection is broken. The
connection is reestablished shortly after I plug the cable back in, and the
messages are received out of order (same as before). Additionally - some of
the messages do not get sent, I have to restart the client to get the
missing messages ... they are all delivered, but it takes a reconnect and a
restart to get them.

I have copies of my clients log, showing the messages with time stamps and
sequence numbers, I also have copies of the qpidd.log (I started a new one
prior to each test). There are 4 logs in a file located here
http://files.me.com/lroloson/mkkv3w (that link should point to a file called
BrokerOrder.tgz). Please let me know if you have problems getting the logs. 

thanks - Larry 
-- 
View this message in context: http://n2.nabble.com/0.5-C%2B%2B-example-listener-hangs-during-testing-tp3344401p3398863.html
Sent from the Apache Qpid users mailing list archive at Nabble.com.

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


Re: 0.5 C++ example listener hangs during testing

Posted by Carl Trieloff <cc...@redhat.com>.
lroloson wrote:
> Carl,
>
> I have the 0.5 broker and direct_producer running on Linux, and a slightly
> modified 0.5 direct_listener running on windows. When the connection is
> established, I receive all of the messages, in order from the Linux broker.
> Everything appears to be fine. 
>
> I am now testing some fault recovery scenarios, such as a broken ethernet
> connection between the linux broker and the windows consumer. When I
> intentionally disconnect the cable from the linux machine, the producer
> continues, the messages and the queue are persistent, all of the messages
> are saved. The windows producer detects the broken connection and retries to
> establish the connection (I modified direct_listener to do that). When I
> plug the cable back in, the client reconnects, and the messages are
> delivered again, albeit out of order. (see my previous posts in this
> thread). 
>
> I am looking for a way to get the broker to send the messages in order, when
> the connection is reestablished. 

got it,  can we do a quick experiment. pull the cable. then kill the 
client, and start a new one when
the link is re-connected and check the order across the two clients. 
This will tell us if it is in the
client or client's local queue for example.

Carl.

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


Re: 0.5 C++ example listener hangs during testing

Posted by lroloson <lr...@trmi.com>.
Carl,

I have the 0.5 broker and direct_producer running on Linux, and a slightly
modified 0.5 direct_listener running on windows. When the connection is
established, I receive all of the messages, in order from the Linux broker.
Everything appears to be fine. 

I am now testing some fault recovery scenarios, such as a broken ethernet
connection between the linux broker and the windows consumer. When I
intentionally disconnect the cable from the linux machine, the producer
continues, the messages and the queue are persistent, all of the messages
are saved. The windows producer detects the broken connection and retries to
establish the connection (I modified direct_listener to do that). When I
plug the cable back in, the client reconnects, and the messages are
delivered again, albeit out of order. (see my previous posts in this
thread). 

I am looking for a way to get the broker to send the messages in order, when
the connection is reestablished. 
-- 
View this message in context: http://n2.nabble.com/0.5-C%2B%2B-example-listener-hangs-during-testing-tp3344401p3394382.html
Sent from the Apache Qpid users mailing list archive at Nabble.com.

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


Re: 0.5 C++ example listener hangs during testing

Posted by Carl Trieloff <cc...@redhat.com>.
lroloson wrote:
> I have tried the client on linux, with the same results. All of the messages
> are delivered - but they are out of order if the connection is broken. My
> application requires delivery in chronological order - and when the
> connection is intact all of the messages are delivered in order. When the
> connection is broken, and then reestablished, the messages are out of order. 
>
> Am I missing something in the broker configuration? Is there a way to reject
> the messages that are out of order?
>   


To understand,

- you have 1 consumer, it is consuming messages, but not all the 
messages are acknowledged.
- you kill the consumer, which will requeue the messages to the broker 
that are not acknowledged.
- you then consume with a new consumer and they are out of order ? --- 
This should not be happening.

Do I understand the case correctly?

If you just want to drop the messages, and not requeue them then set 
acquire-mode to pre-acquire, and
don't worry about the acks.

Carl.

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


Re: 0.5 C++ example listener hangs during testing

Posted by lroloson <lr...@trmi.com>.
I have tried the client on linux, with the same results. All of the messages
are delivered - but they are out of order if the connection is broken. My
application requires delivery in chronological order - and when the
connection is intact all of the messages are delivered in order. When the
connection is broken, and then reestablished, the messages are out of order. 

Am I missing something in the broker configuration? Is there a way to reject
the messages that are out of order?
-- 
View this message in context: http://n2.nabble.com/0.5-C%2B%2B-example-listener-hangs-during-testing-tp3344401p3394145.html
Sent from the Apache Qpid users mailing list archive at Nabble.com.

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


Re: 0.5 C++ example listener hangs during testing

Posted by Gordon Sim <gs...@redhat.com>.
lroloson wrote:
> I turned on the additional logging as suggested - and ran some additional
> tests today, using the 0.5 broker on Linux & the 0.5 listener on Windows
> (which I modified to reconnect). When I tested again today the messages were
> all delivered, however they were out of order. I have attached a snip from
> the log, it appears the broker detected the disconnect. I have not tried the
> broker built from the trunk yet.
> 
> .... log .....
> ....
> 2009-aug-04 12:45:09 trace SENT [127.0.0.1:36531]: Frame[BEbe; channel=2;
> {SessionCompletedBody: commands={ [0,13] }; }]
> 2009-aug-04 12:45:10 trace RECV [127.0.0.1:36531]: Frame[Bbe; channel=2;
> {MessageTransferBody: destination=amq.direct; accept-mode=1; acquire-mode=0;
> }]
> 2009-aug-04 12:45:10 trace guest@QPID.1d5ba47a-8968-443d-97b2-1f535908db76:
> recv cmd 14: {MessageTransferBody: destination=amq.direct; accept-mode=1;
> acquire-mode=0; }
> 2009-aug-04 12:45:10 trace RECV [127.0.0.1:36531]: Frame[be; channel=2;
> header (33 bytes); properties={{MessageProperties: content-length=38;
> }{DeliveryProperties: delivery-mode=2; routing-key=aet_key; }}]
> 2009-aug-04 12:45:10 trace guest@QPID.1d5ba47a-8968-443d-97b2-1f535908db76:
> recv cmd 14: header (33 bytes); properties={{MessageProperties:
> content-length=38; }{DeliveryProperties: delivery-mode=2;
> routing-key=aet_key; }}
> 2009-aug-04 12:45:10 trace RECV [127.0.0.1:36531]: Frame[Ebe; channel=2;
> content (38 bytes) 15 Message : Tue...]
> 2009-aug-04 12:45:10 trace guest@QPID.1d5ba47a-8968-443d-97b2-1f535908db76:
> recv cmd 14: content (38 bytes) 15 Message : Tue...
> 2009-aug-04 12:45:10 debug Message 0x1c3cea40 enqueued on aet_q[0x1c370ca0]
> 2009-aug-04 12:45:10 debug guest@QPID.1d5ba47a-8968-443d-97b2-1f535908db76:
> receiver marked completed: 14 incomplete: { } unknown-completed: { [0,14] }
> 2009-aug-04 12:45:10 trace SENT [127.0.0.1:36531]: Frame[BEbe; channel=2;
> {SessionCompletedBody: commands={ [0,14] }; }]
> 2009-aug-04 12:45:11 debug DISCONNECTED [127.0.0.1:36531]
> 2009-aug-04 12:45:11 debug guest@QPID.1d5ba47a-8968-443d-97b2-1f535908db76:
> detached on broker.

I believe the disconnection here is of the publisher(?), certainly the 
session involved had just sent a message to the broker (content starting 
'15 Message : Tue'...

Would it be possible to send the whole log, or better still attach it to 
a Jira?

My speculative hypothesis earlier was that the new session and 
subscription were created before the messages 'locked' by the previous 
session were freed (which happens when the broker detects the loss of 
the connection).

If you modify your listener to request an exclusive subscription (set 
SubcriptionSettings::exclusive to true), that might help confirm the 
above (as would the log I hope). This is not foolproof as messages are 
requeued after the subscription for a failed connection is cancelled. 
However that is a much smaller window. If on making this change you get 
an error on subscribe, then we would at least know what the issue was.

> 2009-aug-04 12:47:46 debug RECV [192.168.230.229:49234] INIT(0-10)
> 2009-aug-04 12:47:46 debug min_ssf: 0, max_ssf: 256
> 2009-aug-04 12:47:46 info SASL: Mechanism list: LOGIN ANONYMOUS PLAIN
> 2009-aug-04 12:47:46 trace SENT 192.168.230.229:49234 INIT(0-10)
> 2009-aug-04 12:47:46 trace SENT [192.168.230.229:49234]: Frame[BEbe;
> channel=0; {ConnectionStartBody:
> server-properties={qpid.federation_tag:V2:36:str16(3b244fc7-dce1-404c-9c4c-586577edb814)};
> mechanisms=str16{V2:5:str16(LOGIN), V2:9:str16(ANONYMOUS),
> V2:5:str16(PLAIN)}; locales=str16{V2:5:str16(en_US)}; }]
> 2009-aug-04 12:47:46 trace RECV [192.168.230.229:49234]: Frame[BEbe;
> channel=0; {ConnectionStartOkBody:
> client-properties={qpid.client_pid:F4:int32(4080),qpid.client_ppid:F4:int32(0),qpid.client_process:V2:0:str16(),qpid.session_flow:F4:int32(1)};
> mechanism=PLAIN; response=xxxxxx; locale=en_US; }]
> 
> ....
> ....
> 


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