You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@qpid.apache.org by "Duong Quynh (FSU1.Z8.IP)" <Qu...@fsoft.com.vn> on 2014/07/04 09:05:05 UTC

Potential qpid cpp 0.28 bug

Hi everyone,

Today while coding a simple sender on qpid cpp 0.28 I encountered a problem where the program will not quit after completing its task. I am building using g++ 4.8.3, boost 1.49.0, proton 0.70 to name a  few. I put the program through gdb and it seems to jump around infitely after the std::cout << "2" << endl; line. My current guess is Sender class has issues since the receiver I wrote would quit gracefully.

Please see the code below:

//C++ producer code starts

#include <qpid/messaging/Connection.h>

#include <qpid/messaging/Message.h>

#include <qpid/messaging/Message_io.h>

#include <qpid/messaging/Sender.h>

#include <qpid/messaging/Session.h>

#include <iostream>

using namespace qpid::messaging;

int main(int argc, char** argv) {
    Connection connection;
    try
    {
        std::string url = argc > 1 ? argv[1] : "localhost:5672";
        std::string address = argc > 2 ? argv[2] : "'topic://usa.news'";

        std::string connectionOptions = argc > 3 ? argv[3] : "{username:guest,password:guest,sasl_mechanisms:PLAIN,protocol:amqp1.0}";

        connection = Connection(url, connectionOptions);
        connection.open();

        std::cout << "1" << std::endl;
        Session session = connection.createSession();
        Sender sender = session.createSender(address);

        int count = 10;

        for (int i = 0; i < count; i++)
        {
            sender.send(Message("Hello news!"));
            std::cout << "Sent - Hello news! " << i << std::endl;
        }

        std::cout << "2" << std::endl; // program seems to have problem after this point

        session.close();

        connection.close();

        return 0;
    } catch (const std::exception& error) {
        std::cout << "Error: " << error.what() << std::endl;
        connection.close();
    }
    return 1;
} //C++ code ends

Q

RE: Potential qpid cpp 0.28 bug

Posted by "Duong Quynh (FSU1.Z8.IP)" <Qu...@fsoft.com.vn>.
Deleted all qpid libs in /usr/lib64 (rm -rf *qpid*)
Deleted build folder
Recreated build folder
Cmake ..
Make
Make install
Rebuilt program
Result: same as before

./amq-producer 
2014-07-08 16:05:42 [Messaging] debug Driver started
2014-07-08 16:05:42 [Messaging] info Starting connection to amqp:tcp:localhost:5672
2014-07-08 16:05:42 [Messaging] info Connecting to tcp:localhost:5672
2014-07-08 16:05:42 [Messaging] debug tcp:localhost:5672 Connecting ...
2014-07-08 16:05:42 [System] info Connecting: [::1]:5672
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 1 || 0
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 1 || 0
2014-07-08 16:05:42 [Protocol] debug tcp:localhost:5672 writing protocol header: 1-0
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::encode(65535): 8
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Messaging] debug tcp:localhost:5672 Connected
2014-07-08 16:05:42 [Messaging] debug wakeupDriver()
2014-07-08 16:05:42 [Messaging] debug tcp:localhost:5672 Waiting to be authenticated...
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Protocol] debug tcp:localhost:5672 read protocol header: 1-0
2014-07-08 16:05:42 [Security] trace Reading SASL frame of size 34
2014-07-08 16:05:42 [Security] trace Reading SASL-MECHANISMS
2014-07-08 16:05:42 [Protocol] debug tcp:localhost:5672 Received SASL-MECHANISMS(ANONYMOUS PLAIN )
2014-07-08 16:05:42 [Security] debug CyrusSasl::start(PLAIN )
2014-07-08 16:05:42 [Security] debug min_ssf: 0, max_ssf: 256
2014-07-08 16:05:42 [Security] debug getUserFromSettings(): guest
2014-07-08 16:05:42 [Security] debug CyrusSasl::start(PLAIN ): selected PLAIN response: '\x00guest\x00guest'
2014-07-08 16:05:42 [Security] trace Completed encoding of frame of 52 bytes
2014-07-08 16:05:42 [Protocol] debug tcp:localhost:5672 Sent SASL-INIT(PLAIN, \x00guest\x00guest, localhost)
2014-07-08 16:05:42 [Messaging] debug wakeupDriver()
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::decode(42): 42
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 1
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 1
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::encode(65535): 52
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Security] trace Reading SASL frame of size 16
2014-07-08 16:05:42 [Security] trace Reading SASL-OUTCOME
2014-07-08 16:05:42 [Protocol] debug tcp:localhost:5672 Received SASL-OUTCOME(\x00)
2014-07-08 16:05:42 [Messaging] debug wakeupDriver()
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::decode(16): 16
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-08 16:05:42 [Protocol] trace [e0ecca2e-049e-402f-bd0f-575b8efba722]:   -> AMQP
2014-07-08 16:05:42 [Network] debug tcp:localhost:5672 encoded 8 bytes from 65535
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Messaging] trace tcp:localhost:5672 decode(8)
2014-07-08 16:05:42 [Protocol] trace [e0ecca2e-049e-402f-bd0f-575b8efba722]:   <- AMQP
2014-07-08 16:05:42 [Network] debug tcp:localhost:5672 decoded 8 bytes from 8
2014-07-08 16:05:42 [Messaging] debug tcp:localhost:5672 Authenticated
2014-07-08 16:05:42 [Messaging] debug tcp:localhost:5672 Opening...
2014-07-08 16:05:42 [Messaging] debug wakeupDriver()
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-08 16:05:42 [Protocol] trace [e0ecca2e-049e-402f-bd0f-575b8efba722]: 0 -> @open(16) [container-id="e0ecca2e-049e-402f-bd0f-575b8efba722", properties={:"qpid.client_process"="amq-producer", :"qpid.client_pid"=48301, :"qpid.client_ppid"=41102}]
2014-07-08 16:05:42 [Network] debug tcp:localhost:5672 encoded 155 bytes from 65535
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Messaging] trace tcp:localhost:5672 decode(23)
2014-07-08 16:05:42 [Protocol] trace [e0ecca2e-049e-402f-bd0f-575b8efba722]: 0 <- @open(16) [container-id="", hostname="", max-frame-size=1048576]
2014-07-08 16:05:42 [Network] debug tcp:localhost:5672 decoded 23 bytes from 23
2014-07-08 16:05:42 [Messaging] debug tcp:localhost:5672 Opened
2014-07-08 16:05:42 [Messaging] info Connected to tcp:localhost:5672
1
2014-07-08 16:05:42 [Messaging] debug wakeupDriver()
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-08 16:05:42 [Protocol] trace [e0ecca2e-049e-402f-bd0f-575b8efba722]: 0 -> @begin(17) [next-outgoing-id=0, incoming-window=2147483647, outgoing-window=0]
2014-07-08 16:05:42 [Network] debug tcp:localhost:5672 encoded 30 bytes from 65535
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Messaging] trace tcp:localhost:5672 decode(26)
2014-07-08 16:05:42 [Protocol] trace [e0ecca2e-049e-402f-bd0f-575b8efba722]: 0 <- @begin(17) [remote-channel=0, next-outgoing-id=1, incoming-window=0, outgoing-window=0, handle-max=1024]
2014-07-08 16:05:42 [Network] debug tcp:localhost:5672 decoded 26 bytes from 26
2014-07-08 16:05:42 [Messaging] debug Link attach sent for 0x1896ae0, state=10
2014-07-08 16:05:42 [Messaging] debug wakeupDriver()
2014-07-08 16:05:42 [Messaging] debug Waiting for confirmation of link attach for 0x1896ae0, state=10...
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-08 16:05:42 [Protocol] trace [e0ecca2e-049e-402f-bd0f-575b8efba722]: 0 -> @attach(18) [name="topic://usa.news_67222965-0d3d-4596-95ce-32f7f6e7528b", handle=0, role=false, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="topic://usa.news", durable=0, timeout=0, dynamic=false], target=@target(41) [address="topic://usa.news", durable=0, timeout=0, dynamic=false], initial-delivery-count=0]
2014-07-08 16:05:42 [Network] debug tcp:localhost:5672 encoded 166 bytes from 65535
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Messaging] trace tcp:localhost:5672 decode(147)
2014-07-08 16:05:42 [Protocol] trace [e0ecca2e-049e-402f-bd0f-575b8efba722]: 0 <- @attach(18) [name="topic://usa.news_67222965-0d3d-4596-95ce-32f7f6e7528b", handle=0, role=true, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="topic://usa.news"], target=@target(41) [address="topic://usa.news"]]
2014-07-08 16:05:42 [Protocol] trace [e0ecca2e-049e-402f-bd0f-575b8efba722]: 0 <- @flow(19) [next-incoming-id=0, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=0, link-credit=100]
2014-07-08 16:05:42 [Network] debug tcp:localhost:5672 decoded 147 bytes from 147
2014-07-08 16:05:42 [Messaging] debug Attach succeeded to topic://usa.news
2014-07-08 16:05:42 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-08 16:05:42 [Messaging] debug Trimming buffer from 59 to 31
2014-07-08 16:05:42 [Messaging] debug wakeupDriver()
Sent - Hello news! 0
2014-07-08 16:05:42 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-08 16:05:42 [Messaging] debug Trimming buffer from 59 to 31
2014-07-08 16:05:42 [Messaging] debug wakeupDriver()
Sent - Hello news! 1
2014-07-08 16:05:42 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-08 16:05:42 [Messaging] debug Trimming buffer from 59 to 31
2014-07-08 16:05:42 [Messaging] debug wakeupDriver()
Sent - Hello news! 2
2014-07-08 16:05:42 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-08 16:05:42 [Messaging] debug Trimming buffer from 59 to 31
2014-07-08 16:05:42 [Messaging] debug wakeupDriver()
Sent - Hello news! 3
2014-07-08 16:05:42 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-08 16:05:42 [Messaging] debug Trimming buffer from 59 to 31
2014-07-08 16:05:42 [Messaging] debug wakeupDriver()
Sent - Hello news! 4
2014-07-08 16:05:42 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-08 16:05:42 [Messaging] debug Trimming buffer from 59 to 31
2014-07-08 16:05:42 [Messaging] debug wakeupDriver()
Sent - Hello news! 5
2014-07-08 16:05:42 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-08 16:05:42 [Messaging] debug Trimming buffer from 59 to 31
2014-07-08 16:05:42 [Messaging] debug wakeupDriver()
Sent - Hello news! 6
2014-07-08 16:05:42 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-08 16:05:42 [Messaging] debug Trimming buffer from 59 to 31
2014-07-08 16:05:42 [Messaging] debug wakeupDriver()
Sent - Hello news! 7
2014-07-08 16:05:42 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-08 16:05:42 [Messaging] debug Trimming buffer from 59 to 31
2014-07-08 16:05:42 [Messaging] debug wakeupDriver()
Sent - Hello news! 8
2014-07-08 16:05:42 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-08 16:05:42 [Messaging] debug Trimming buffer from 59 to 31
2014-07-08 16:05:42 [Messaging] debug wakeupDriver()
Sent - Hello news! 9
2
2014-07-08 16:05:42 [Messaging] debug wakeupDriver()
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-08 16:05:42 [Protocol] trace [e0ecca2e-049e-402f-bd0f-575b8efba722]: 0 -> @transfer(20) [handle=0, delivery-id=0, delivery-tag=b"\x00\x00\x00\x00", message-format=0, settled=false, more=false] (31) "\x00Sp\xc0\x04\x02BP\x00\x00St\xc1\x01\x00\x00Su\xa0\x0bHello news!"
2014-07-08 16:05:42 [Network] debug tcp:localhost:5672 encoded 65 bytes from 65535
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-08 16:05:42 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 16:05:42 [Messaging] trace tcp:localhost:5672 decode(48)
2014-07-08 16:05:42 [Protocol] trace [e0ecca2e-049e-402f-bd0f-575b8efba722]: 0 <- @flow(19) [next-incoming-id=1, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=1, link-credit=100]
2014-07-08 16:05:42 [Protocol] trace [e0ecca2e-049e-402f-bd0f-575b8efba722]: 0 <- @disposition(21) [role=true, first=0, last=0, settled=true, state=@accepted(36) []]
2014-07-08 16:05:42 [Network] debug tcp:localhost:5672 decoded 48 bytes from 48

<hangs here> 


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


RE: Potential qpid cpp 0.28 bug

Posted by "Duong Quynh (FSU1.Z8.IP)" <Qu...@fsoft.com.vn>.
The pleasure is all mine. Cheers.

Quynh

-----Original Message-----
From: Gordon Sim [mailto:gsim@redhat.com] 
Sent: Wednesday, July 09, 2014 3:38 PM
To: dev@qpid.apache.org
Subject: Re: Potential qpid cpp 0.28 bug

On 07/09/2014 04:02 AM, Duong Quynh (FSU1.Z8.IP) wrote:
> This patch seems to have fixed the infinite hang,

Great, thanks for confirming that and for your patience as we identified the issue!

> looks like it was indeed stuck in the detach because program would hang no matter whether you call sender.close() or not.

The detach would only be called in response to sender.close(). However the ending of the session would have caused something similar (that the first patch fixes).

With this one I tend to think that proton itself may want a fix. BUt at least we have a reasonable workaround for qpid::messaging in the meantime.

Thanks again for reporting the issue and working through it with us!

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org For additional commands, e-mail: dev-help@qpid.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


Re: Potential qpid cpp 0.28 bug

Posted by Gordon Sim <gs...@redhat.com>.
On 07/09/2014 04:02 AM, Duong Quynh (FSU1.Z8.IP) wrote:
> This patch seems to have fixed the infinite hang,

Great, thanks for confirming that and for your patience as we identified 
the issue!

> looks like it was indeed stuck in the detach because program would hang no matter whether you call sender.close() or not.

The detach would only be called in response to sender.close(). However 
the ending of the session would have caused something similar (that the 
first patch fixes).

With this one I tend to think that proton itself may want a fix. BUt at 
least we have a reasonable workaround for qpid::messaging in the meantime.

Thanks again for reporting the issue and working through it with us!

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


RE: Potential qpid cpp 0.28 bug

Posted by "Duong Quynh (FSU1.Z8.IP)" <Qu...@fsoft.com.vn>.
This patch seems to have fixed the infinite hang, looks like it was indeed stuck in the detach because program would hang no matter whether you call sender.close() or not.

# ./amq-producer
2014-07-09 09:58:58 [Messaging] debug Driver started
2014-07-09 09:58:58 [Messaging] info Starting connection to amqp:tcp:localhost:5672
2014-07-09 09:58:58 [Messaging] info Connecting to tcp:localhost:5672
2014-07-09 09:58:58 [Messaging] debug tcp:localhost:5672 Connecting ...
2014-07-09 09:58:58 [System] info Connecting: [::1]:5672
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 1 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 1 || 0
2014-07-09 09:58:58 [Protocol] debug tcp:localhost:5672 writing protocol header: 1-0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::encode(65535): 8
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] debug tcp:localhost:5672 Connected
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Messaging] debug tcp:localhost:5672 Waiting to be authenticated...
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Protocol] debug tcp:localhost:5672 read protocol header: 1-0
2014-07-09 09:58:58 [Security] trace Reading SASL frame of size 34
2014-07-09 09:58:58 [Security] trace Reading SASL-MECHANISMS
2014-07-09 09:58:58 [Protocol] debug tcp:localhost:5672 Received SASL-MECHANISMS(ANONYMOUS PLAIN )
2014-07-09 09:58:58 [Security] debug CyrusSasl::start(PLAIN )
2014-07-09 09:58:58 [Security] debug min_ssf: 0, max_ssf: 256
2014-07-09 09:58:58 [Security] debug getUserFromSettings(): guest
2014-07-09 09:58:58 [Security] debug CyrusSasl::start(PLAIN ): selected PLAIN response: '\x00guest\x00guest'
2014-07-09 09:58:58 [Security] trace Completed encoding of frame of 52 bytes
2014-07-09 09:58:58 [Protocol] debug tcp:localhost:5672 Sent SASL-INIT(PLAIN, \x00guest\x00guest, localhost)
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::decode(42): 42
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 1
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 1
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::encode(65535): 52
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace Reading SASL frame of size 16
2014-07-09 09:58:58 [Security] trace Reading SASL-OUTCOME
2014-07-09 09:58:58 [Protocol] debug tcp:localhost:5672 Received SASL-OUTCOME(\x00)
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::decode(16): 16
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]:   -> AMQP
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 encoded 8 bytes from 65535
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 decode(8)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]:   <- AMQP
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 decoded 8 bytes from 8
2014-07-09 09:58:58 [Messaging] debug tcp:localhost:5672 Authenticated
2014-07-09 09:58:58 [Messaging] debug tcp:localhost:5672 Opening...
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 -> @open(16) [container-id="e9eea98e-d0d1-4bf7-b6d3-25748ed4b801", properties={:"qpid.client_process"="amq-producer", :"qpid.client_pid"=54885, :"qpid.client_ppid"=41102}]
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 encoded 155 bytes from 65535
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 decode(23)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @open(16) [container-id="", hostname="", max-frame-size=1048576]
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 decoded 23 bytes from 23
2014-07-09 09:58:58 [Messaging] debug tcp:localhost:5672 Opened
2014-07-09 09:58:58 [Messaging] info Connected to tcp:localhost:5672
1
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 -> @begin(17) [next-outgoing-id=0, incoming-window=2147483647, outgoing-window=0]
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 encoded 30 bytes from 65535
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 decode(26)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @begin(17) [remote-channel=0, next-outgoing-id=1, incoming-window=0, outgoing-window=0, handle-max=1024]
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 decoded 26 bytes from 26
2014-07-09 09:58:58 [Messaging] debug Link attach sent for 0x1949ae0, state=10
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Messaging] debug Waiting for confirmation of link attach for 0x1949ae0, state=10...
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 -> @attach(18) [name="topic://usa.news_0531249e-a5f9-4902-ac80-993cd1b3e4fe", handle=0, role=false, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="topic://usa.news", durable=0, timeout=0, dynamic=false], target=@target(41) [address="topic://usa.news", durable=0, timeout=0, dynamic=false], initial-delivery-count=0]
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 encoded 166 bytes from 65535
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 decode(147)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @attach(18) [name="topic://usa.news_0531249e-a5f9-4902-ac80-993cd1b3e4fe", handle=0, role=true, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="topic://usa.news"], target=@target(41) [address="topic://usa.news"]]
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @flow(19) [next-incoming-id=0, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=0, link-credit=100]
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 decoded 147 bytes from 147
2014-07-09 09:58:58 [Messaging] debug Attach succeeded to topic://usa.news
2014-07-09 09:58:58 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-09 09:58:58 [Messaging] debug Trimming buffer from 59 to 31
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
Sent - Hello news! 0
2014-07-09 09:58:58 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-09 09:58:58 [Messaging] debug Trimming buffer from 59 to 31
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
Sent - Hello news! 1
2014-07-09 09:58:58 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-09 09:58:58 [Messaging] debug Trimming buffer from 59 to 31
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
Sent - Hello news! 2
2014-07-09 09:58:58 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-09 09:58:58 [Messaging] debug Trimming buffer from 59 to 31
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
Sent - Hello news! 3
2014-07-09 09:58:58 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-09 09:58:58 [Messaging] debug Trimming buffer from 59 to 31
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
Sent - Hello news! 4
2014-07-09 09:58:58 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-09 09:58:58 [Messaging] debug Trimming buffer from 59 to 31
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
Sent - Hello news! 5
2014-07-09 09:58:58 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-09 09:58:58 [Messaging] debug Trimming buffer from 59 to 31
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
Sent - Hello news! 6
2014-07-09 09:58:58 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-09 09:58:58 [Messaging] debug Trimming buffer from 59 to 31
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
Sent - Hello news! 7
2014-07-09 09:58:58 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-09 09:58:58 [Messaging] debug Trimming buffer from 59 to 31
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
Sent - Hello news! 8
2014-07-09 09:58:58 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-09 09:58:58 [Messaging] debug Trimming buffer from 59 to 31
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 -> @transfer(20) [handle=0, delivery-id=0, delivery-tag=b"\x00\x00\x00\x00", message-format=0, settled=false, more=false] (31) "\x00Sp\xc0\x04\x02BP\x00\x00St\xc1\x01\x00\x00Su\xa0\x0bHello news!"
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 encoded 65 bytes from 65535
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
Sent - Hello news! 9
2
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 decode(48)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @flow(19) [next-incoming-id=1, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=1, link-credit=100]
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @disposition(21) [role=true, first=0, last=0, settled=true, state=@accepted(36) []]
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 decoded 48 bytes from 48
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 -> @transfer(20) [handle=0, delivery-id=1, delivery-tag=b"\x01\x00\x00\x00", message-format=0, settled=false, more=false] (31) "\x00Sp\xc0\x04\x02BP\x00\x00St\xc1\x01\x00\x00Su\xa0\x0bHello news!"
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 encoded 65 bytes from 65535
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 decode(50)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @flow(19) [next-incoming-id=2, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=2, link-credit=100]
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @disposition(21) [role=true, first=1, last=1, settled=true, state=@accepted(36) []]
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 decoded 50 bytes from 50
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 -> @transfer(20) [handle=0, delivery-id=2, delivery-tag=b"\x02\x00\x00\x00", message-format=0, settled=false, more=false] (31) "\x00Sp\xc0\x04\x02BP\x00\x00St\xc1\x01\x00\x00Su\xa0\x0bHello news!"
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 encoded 65 bytes from 65535
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 decode(50)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @flow(19) [next-incoming-id=3, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=3, link-credit=100]
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @disposition(21) [role=true, first=2, last=2, settled=true, state=@accepted(36) []]
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 decoded 50 bytes from 50
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 -> @transfer(20) [handle=0, delivery-id=3, delivery-tag=b"\x03\x00\x00\x00", message-format=0, settled=false, more=false] (31) "\x00Sp\xc0\x04\x02BP\x00\x00St\xc1\x01\x00\x00Su\xa0\x0bHello news!"
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 encoded 65 bytes from 65535
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 decode(50)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @flow(19) [next-incoming-id=4, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=4, link-credit=100]
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @disposition(21) [role=true, first=3, last=3, settled=true, state=@accepted(36) []]
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 decoded 50 bytes from 50
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 -> @transfer(20) [handle=0, delivery-id=4, delivery-tag=b"\x04\x00\x00\x00", message-format=0, settled=false, more=false] (31) "\x00Sp\xc0\x04\x02BP\x00\x00St\xc1\x01\x00\x00Su\xa0\x0bHello news!"
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 encoded 65 bytes from 65535
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 decode(50)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @flow(19) [next-incoming-id=5, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=5, link-credit=100]
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @disposition(21) [role=true, first=4, last=4, settled=true, state=@accepted(36) []]
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 decoded 50 bytes from 50
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 -> @transfer(20) [handle=0, delivery-id=5, delivery-tag=b"\x05\x00\x00\x00", message-format=0, settled=false, more=false] (31) "\x00Sp\xc0\x04\x02BP\x00\x00St\xc1\x01\x00\x00Su\xa0\x0bHello news!"
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 encoded 65 bytes from 65535
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 decode(50)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @flow(19) [next-incoming-id=6, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=6, link-credit=100]
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @disposition(21) [role=true, first=5, last=5, settled=true, state=@accepted(36) []]
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 decoded 50 bytes from 50
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 -> @transfer(20) [handle=0, delivery-id=6, delivery-tag=b"\x06\x00\x00\x00", message-format=0, settled=false, more=false] (31) "\x00Sp\xc0\x04\x02BP\x00\x00St\xc1\x01\x00\x00Su\xa0\x0bHello news!"
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 encoded 65 bytes from 65535
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 decode(50)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @flow(19) [next-incoming-id=7, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=7, link-credit=100]
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @disposition(21) [role=true, first=6, last=6, settled=true, state=@accepted(36) []]
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 decoded 50 bytes from 50
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 -> @transfer(20) [handle=0, delivery-id=7, delivery-tag=b"\x07\x00\x00\x00", message-format=0, settled=false, more=false] (31) "\x00Sp\xc0\x04\x02BP\x00\x00St\xc1\x01\x00\x00Su\xa0\x0bHello news!"
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 encoded 65 bytes from 65535
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 decode(50)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @flow(19) [next-incoming-id=8, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=8, link-credit=100]
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @disposition(21) [role=true, first=7, last=7, settled=true, state=@accepted(36) []]
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 decoded 50 bytes from 50
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 -> @transfer(20) [handle=0, delivery-id=8, delivery-tag=b"\x08\x00\x00\x00", message-format=0, settled=false, more=false] (31) "\x00Sp\xc0\x04\x02BP\x00\x00St\xc1\x01\x00\x00Su\xa0\x0bHello news!"
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 encoded 65 bytes from 65535
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 decode(50)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @flow(19) [next-incoming-id=9, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=9, link-credit=100]
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @disposition(21) [role=true, first=8, last=8, settled=true, state=@accepted(36) []]
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 decoded 50 bytes from 50
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 -> @transfer(20) [handle=0, delivery-id=9, delivery-tag=b"\x09\x00\x00\x00", message-format=0, settled=false, more=false] (31) "\x00Sp\xc0\x04\x02BP\x00\x00St\xc1\x01\x00\x00Su\xa0\x0bHello news!"
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 -> @detach(22) [handle=0, closed=true]
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 encoded 89 bytes from 65535
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 decode(50)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @flow(19) [next-incoming-id=10, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=10, link-credit=100]
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @disposition(21) [role=true, first=9, last=9, settled=true, state=@accepted(36) []]
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 decoded 50 bytes from 50
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 decode(16)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @detach(22) [handle=0, closed=true]
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 decoded 16 bytes from 16
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Messaging] debug wakeupDriver()
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 -> @end(23) []
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 -> @close(24) []
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 encoded 42 bytes from 65535
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]:   -> EOS
2014-07-09 09:58:58 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 decode(12)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @end(23) []
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 decoded 12 bytes from 12
2014-07-09 09:58:58 [Messaging] trace tcp:localhost:5672 decode(12)
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]: 0 <- @close(24) []
2014-07-09 09:58:58 [Protocol] trace [e9eea98e-d0d1-4bf7-b6d3-25748ed4b801]:   <- EOS
2014-07-09 09:58:58 [Network] debug tcp:localhost:5672 decoded 12 bytes from 12
2014-07-09 09:58:58 [Messaging] debug [[::1]:36066-localhost:5672] TcpTransport closing...
2014-07-09 09:58:58 [Messaging] debug [[::1]:36066-localhost:5672] Socket closed
2014-07-09 09:58:58 [Messaging] debug Driver stopped
#
<program exited successfully>

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


Re: Potential qpid cpp 0.28 bug

Posted by Gordon Sim <gs...@redhat.com>.
On 07/08/2014 10:11 AM, Duong Quynh (FSU1.Z8.IP) wrote:
> Here you go, it's waiting in Sender.close() as seen from the stack.

Ah, your example code must be a little different from what you sent at 
the beginning of the thread, as that did not call sender.close(). I was 
assuming it was blocked in session.close() as per the example.

On the face of it this looks like perhaps a proton bug. There should 
have been a detach emitted, but that seems not to be the case. I wonder 
if perhaps the session window is somehow preventing that.

Could you try this new patch and see if that has any effect?

RE: Potential qpid cpp 0.28 bug

Posted by "Duong Quynh (FSU1.Z8.IP)" <Qu...@fsoft.com.vn>.
Here you go, it's waiting in Sender.close() as seen from the stack.

[root@localhost ~]# ps aux | grep amq
root     48326  0.3  0.4 164584  7880 pts/0    Sl+  16:09   0:00 ./amq-producer
root     48347  0.0  0.0 103252   836 pts/2    S+   16:10   0:00 grep amq
[root@localhost ~]# pstack 48326
Thread 2 (Thread 0x7f77f570a700 (LWP 48327)):
#0  0x000000336d0e9153 in epoll_wait () from /lib64/libc.so.6
#1  0x00007f77f5df4ecc in qpid::sys::Poller::wait(qpid::sys::Duration) () from /usr/local/lib64/libqpidcommon.so.2
#2  0x00007f77f5df4af5 in qpid::sys::Poller::run() () from /usr/local/lib64/libqpidcommon.so.2
#3  0x00007f77f5de94cb in qpid::sys::(anonymous namespace)::runRunnable(void*) () from /usr/local/lib64/libqpidcommon.so.2
#4  0x000000336d4079d1 in start_thread () from /lib64/libpthread.so.0
#5  0x000000336d0e8b5d in clone () from /lib64/libc.so.6
Thread 1 (Thread 0x7f77f570e860 (LWP 48326)):
#0  0x000000336d40b5bc in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007f77f6728523 in qpid::sys::Condition::wait(qpid::sys::Mutex&) () from /usr/local/lib64/libqpidmessaging.so.2
#2  0x00007f77f672878f in qpid::sys::Monitor::wait() () from /usr/local/lib64/libqpidmessaging.so.2
#3  0x00007f77f6720ab6 in qpid::messaging::amqp::ConnectionContext::wait() () from /usr/local/lib64/libqpidmessaging.so.2
#4  0x00007f77f6720b19 in qpid::messaging::amqp::ConnectionContext::wait(boost::shared_ptr<qpid::messaging::amqp::SessionContext>) () from /usr/local/lib64/libqpidmessaging.so.2
#5  0x00007f77f671e7c4 in qpid::messaging::amqp::ConnectionContext::detach(boost::shared_ptr<qpid::messaging::amqp::SessionContext>, boost::shared_ptr<qpid::messaging::amqp::SenderContext>) () from /usr/local/lib64/libqpidmessaging.so.2
#6  0x00007f77f673c768 in qpid::messaging::amqp::SenderHandle::close() () from /usr/local/lib64/libqpidmessaging.so.2
#7  0x00007f77f6797965 in qpid::messaging::Sender::close() () from /usr/local/lib64/libqpidmessaging.so.2
#8  0x0000000000403738 in main (argc=1, argv=0x7fff0845f6b8) at ../amq-producer/main.cpp:43

-----Original Message-----
From: Gordon Sim [mailto:gsim@redhat.com] 
Sent: Tuesday, July 08, 2014 4:09 PM
To: dev@qpid.apache.org
Subject: Re: Potential qpid cpp 0.28 bug

On 07/08/2014 09:40 AM, Duong Quynh (FSU1.Z8.IP) wrote:
> Yes I did, I make clean, deleted the CMake_Cache.txt, redid the whole process from "cmake .." if that doesn't work then something is wrong with the make process. I'll wipe out the build folder and retry.

That should certainly have done it. I just don't understand the log trace. Could you get a stack trace for all the threads (pstack <pid of producer process>), to be sure we know where it is waiting?

(The protocol trace shows the session window is set to one message by the broker. Therefore only one message can initially be sent. The broker then does move that window forwards by one, which should allow another transfer to be sent. QPID-5737 fixes a case where this doesn't happen if the application is already closing the session.)

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org For additional commands, e-mail: dev-help@qpid.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


Re: Potential qpid cpp 0.28 bug

Posted by Gordon Sim <gs...@redhat.com>.
On 07/08/2014 09:40 AM, Duong Quynh (FSU1.Z8.IP) wrote:
> Yes I did, I make clean, deleted the CMake_Cache.txt, redid the whole process from "cmake .." if that doesn't work then something is wrong with the make process. I'll wipe out the build folder and retry.

That should certainly have done it. I just don't understand the log 
trace. Could you get a stack trace for all the threads (pstack <pid of 
producer process>), to be sure we know where it is waiting?

(The protocol trace shows the session window is set to one message by 
the broker. Therefore only one message can initially be sent. The broker 
then does move that window forwards by one, which should allow another 
transfer to be sent. QPID-5737 fixes a case where this doesn't happen if 
the application is already closing the session.)

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


RE: Potential qpid cpp 0.28 bug

Posted by "Duong Quynh (FSU1.Z8.IP)" <Qu...@fsoft.com.vn>.
Yes I did, I make clean, deleted the CMake_Cache.txt, redid the whole process from "cmake .." if that doesn't work then something is wrong with the make process. I'll wipe out the build folder and retry.

Quynh

-----Original Message-----
From: Gordon Sim [mailto:gsim@redhat.com] 
Sent: Tuesday, July 08, 2014 3:38 PM
To: dev@qpid.apache.org
Subject: Re: Potential qpid cpp 0.28 bug

On 07/08/2014 05:08 AM, Duong Quynh (FSU1.Z8.IP) wrote:
> Here's your log Gordon.
>
[...]
> 2
> 2014-07-08 11:06:27 [Messaging] debug wakeupDriver()
> 2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 
> Sasl::canEncode(): 0 || 0
> 2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 
> Sasl::canEncode(): 0 || 0
> 2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 encode(65535)
> 2014-07-08 11:06:27 [Protocol] trace [4cc71475-8b5c-4127-b630-7d02c05da20b]: 0 -> @transfer(20) [handle=0, delivery-id=0, delivery-tag=b"\x00\x00\x00\x00", message-format=0, settled=false, more=false] (31) "\x00Sp\xc0\x04\x02BP\x00\x00St\xc1\x01\x00\x00Su\xa0\x0bHello news!"
> 2014-07-08 11:06:27 [Network] debug tcp:localhost:5672 encoded 65 
> bytes from 65535
> 2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 
> Sasl::canEncode(): 0 || 0
> 2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 
> Sasl::canEncode(): 0 || 0
> 2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 encode(65535)
> 2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 
> Sasl::canEncode(): 0 || 0
> 2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 decode(48)
> 2014-07-08 11:06:27 [Protocol] trace 
> [4cc71475-8b5c-4127-b630-7d02c05da20b]: 0 <- @flow(19) 
> [next-incoming-id=1, incoming-window=1, next-outgoing-id=1, 
> outgoing-window=0, handle=0, delivery-count=1, link-credit=100]
> 2014-07-08 11:06:27 [Protocol] trace 
> [4cc71475-8b5c-4127-b630-7d02c05da20b]: 0 <- @disposition(21) 
> [role=true, first=0, last=0, settled=true, state=@accepted(36) []]
> 2014-07-08 11:06:27 [Network] debug tcp:localhost:5672 decoded 48 
> bytes from 48

This looks like the change is not in effect. (I'd expect to see an additional log message here if it were). Is it possible that your newly patched and built library is not being picked up? Did you install the previous version yourself and into the same place?


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org For additional commands, e-mail: dev-help@qpid.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


Re: Potential qpid cpp 0.28 bug

Posted by Gordon Sim <gs...@redhat.com>.
On 07/08/2014 05:08 AM, Duong Quynh (FSU1.Z8.IP) wrote:
> Here's your log Gordon.
>
[...]
> 2
> 2014-07-08 11:06:27 [Messaging] debug wakeupDriver()
> 2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
> 2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
> 2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 encode(65535)
> 2014-07-08 11:06:27 [Protocol] trace [4cc71475-8b5c-4127-b630-7d02c05da20b]: 0 -> @transfer(20) [handle=0, delivery-id=0, delivery-tag=b"\x00\x00\x00\x00", message-format=0, settled=false, more=false] (31) "\x00Sp\xc0\x04\x02BP\x00\x00St\xc1\x01\x00\x00Su\xa0\x0bHello news!"
> 2014-07-08 11:06:27 [Network] debug tcp:localhost:5672 encoded 65 bytes from 65535
> 2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
> 2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
> 2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 encode(65535)
> 2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
> 2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 decode(48)
> 2014-07-08 11:06:27 [Protocol] trace [4cc71475-8b5c-4127-b630-7d02c05da20b]: 0 <- @flow(19) [next-incoming-id=1, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=1, link-credit=100]
> 2014-07-08 11:06:27 [Protocol] trace [4cc71475-8b5c-4127-b630-7d02c05da20b]: 0 <- @disposition(21) [role=true, first=0, last=0, settled=true, state=@accepted(36) []]
> 2014-07-08 11:06:27 [Network] debug tcp:localhost:5672 decoded 48 bytes from 48

This looks like the change is not in effect. (I'd expect to see an 
additional log message here if it were). Is it possible that your newly 
patched and built library is not being picked up? Did you install the 
previous version yourself and into the same place?


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


RE: Potential qpid cpp 0.28 bug

Posted by "Duong Quynh (FSU1.Z8.IP)" <Qu...@fsoft.com.vn>.
Here's your log Gordon.

./amq-producer 
2014-07-08 11:06:27 [Messaging] debug Driver started
2014-07-08 11:06:27 [Messaging] info Starting connection to amqp:tcp:localhost:5672
2014-07-08 11:06:27 [Messaging] info Connecting to tcp:localhost:5672
2014-07-08 11:06:27 [Messaging] debug tcp:localhost:5672 Connecting ...
2014-07-08 11:06:27 [System] info Connecting: [::1]:5672
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 1 || 0
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 1 || 0
2014-07-08 11:06:27 [Protocol] debug tcp:localhost:5672 writing protocol header: 1-0
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::encode(65535): 8
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Messaging] debug tcp:localhost:5672 Connected
2014-07-08 11:06:27 [Messaging] debug wakeupDriver()
2014-07-08 11:06:27 [Messaging] debug tcp:localhost:5672 Waiting to be authenticated...
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Protocol] debug tcp:localhost:5672 read protocol header: 1-0
2014-07-08 11:06:27 [Security] trace Reading SASL frame of size 34
2014-07-08 11:06:27 [Security] trace Reading SASL-MECHANISMS
2014-07-08 11:06:27 [Protocol] debug tcp:localhost:5672 Received SASL-MECHANISMS(ANONYMOUS PLAIN )
2014-07-08 11:06:27 [Security] debug CyrusSasl::start(PLAIN )
2014-07-08 11:06:27 [Security] debug min_ssf: 0, max_ssf: 256
2014-07-08 11:06:27 [Security] debug getUserFromSettings(): guest
2014-07-08 11:06:27 [Security] debug CyrusSasl::start(PLAIN ): selected PLAIN response: '\x00guest\x00guest'
2014-07-08 11:06:27 [Security] trace Completed encoding of frame of 52 bytes
2014-07-08 11:06:27 [Protocol] debug tcp:localhost:5672 Sent SASL-INIT(PLAIN, \x00guest\x00guest, localhost)
2014-07-08 11:06:27 [Messaging] debug wakeupDriver()
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::decode(42): 42
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 1
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 1
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::encode(65535): 52
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Security] trace Reading SASL frame of size 16
2014-07-08 11:06:27 [Security] trace Reading SASL-OUTCOME
2014-07-08 11:06:27 [Protocol] debug tcp:localhost:5672 Received SASL-OUTCOME(\x00)
2014-07-08 11:06:27 [Messaging] debug wakeupDriver()
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::decode(16): 16
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-08 11:06:27 [Protocol] trace [4cc71475-8b5c-4127-b630-7d02c05da20b]:   -> AMQP
2014-07-08 11:06:27 [Network] debug tcp:localhost:5672 encoded 8 bytes from 65535
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 decode(8)
2014-07-08 11:06:27 [Protocol] trace [4cc71475-8b5c-4127-b630-7d02c05da20b]:   <- AMQP
2014-07-08 11:06:27 [Network] debug tcp:localhost:5672 decoded 8 bytes from 8
2014-07-08 11:06:27 [Messaging] debug tcp:localhost:5672 Authenticated
2014-07-08 11:06:27 [Messaging] debug tcp:localhost:5672 Opening...
2014-07-08 11:06:27 [Messaging] debug wakeupDriver()
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-08 11:06:27 [Protocol] trace [4cc71475-8b5c-4127-b630-7d02c05da20b]: 0 -> @open(16) [container-id="4cc71475-8b5c-4127-b630-7d02c05da20b", properties={:"qpid.client_process"="amq-producer", :"qpid.client_pid"=32132, :"qpid.client_ppid"=20140}]
2014-07-08 11:06:27 [Network] debug tcp:localhost:5672 encoded 155 bytes from 65535
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 decode(23)
2014-07-08 11:06:27 [Protocol] trace [4cc71475-8b5c-4127-b630-7d02c05da20b]: 0 <- @open(16) [container-id="", hostname="", max-frame-size=1048576]
2014-07-08 11:06:27 [Network] debug tcp:localhost:5672 decoded 23 bytes from 23
2014-07-08 11:06:27 [Messaging] debug tcp:localhost:5672 Opened
2014-07-08 11:06:27 [Messaging] info Connected to tcp:localhost:5672
1
2014-07-08 11:06:27 [Messaging] debug wakeupDriver()
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-08 11:06:27 [Protocol] trace [4cc71475-8b5c-4127-b630-7d02c05da20b]: 0 -> @begin(17) [next-outgoing-id=0, incoming-window=2147483647, outgoing-window=0]
2014-07-08 11:06:27 [Network] debug tcp:localhost:5672 encoded 30 bytes from 65535
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 decode(26)
2014-07-08 11:06:27 [Protocol] trace [4cc71475-8b5c-4127-b630-7d02c05da20b]: 0 <- @begin(17) [remote-channel=0, next-outgoing-id=1, incoming-window=0, outgoing-window=0, handle-max=1024]
2014-07-08 11:06:27 [Network] debug tcp:localhost:5672 decoded 26 bytes from 26
2014-07-08 11:06:27 [Messaging] debug Link attach sent for 0x142eb00, state=10
2014-07-08 11:06:27 [Messaging] debug wakeupDriver()
2014-07-08 11:06:27 [Messaging] debug Waiting for confirmation of link attach for 0x142eb00, state=10...
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-08 11:06:27 [Protocol] trace [4cc71475-8b5c-4127-b630-7d02c05da20b]: 0 -> @attach(18) [name="topic://usa.news_9e51194a-fa15-4c62-8291-b4728877e2c3", handle=0, role=false, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="topic://usa.news", durable=0, timeout=0, dynamic=false], target=@target(41) [address="topic://usa.news", durable=0, timeout=0, dynamic=false], initial-delivery-count=0]
2014-07-08 11:06:27 [Network] debug tcp:localhost:5672 encoded 166 bytes from 65535
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 decode(147)
2014-07-08 11:06:27 [Protocol] trace [4cc71475-8b5c-4127-b630-7d02c05da20b]: 0 <- @attach(18) [name="topic://usa.news_9e51194a-fa15-4c62-8291-b4728877e2c3", handle=0, role=true, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="topic://usa.news"], target=@target(41) [address="topic://usa.news"]]
2014-07-08 11:06:27 [Protocol] trace [4cc71475-8b5c-4127-b630-7d02c05da20b]: 0 <- @flow(19) [next-incoming-id=0, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=0, link-credit=100]
2014-07-08 11:06:27 [Network] debug tcp:localhost:5672 decoded 147 bytes from 147
2014-07-08 11:06:27 [Messaging] debug Attach succeeded to topic://usa.news
2014-07-08 11:06:27 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-08 11:06:27 [Messaging] debug Trimming buffer from 59 to 31
2014-07-08 11:06:27 [Messaging] debug wakeupDriver()
Sent - Hello news! 0
2014-07-08 11:06:27 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-08 11:06:27 [Messaging] debug Trimming buffer from 59 to 31
2014-07-08 11:06:27 [Messaging] debug wakeupDriver()
Sent - Hello news! 1
2014-07-08 11:06:27 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-08 11:06:27 [Messaging] debug Trimming buffer from 59 to 31
2014-07-08 11:06:27 [Messaging] debug wakeupDriver()
Sent - Hello news! 2
2014-07-08 11:06:27 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-08 11:06:27 [Messaging] debug Trimming buffer from 59 to 31
2014-07-08 11:06:27 [Messaging] debug wakeupDriver()
Sent - Hello news! 3
2014-07-08 11:06:27 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-08 11:06:27 [Messaging] debug Trimming buffer from 59 to 31
2014-07-08 11:06:27 [Messaging] debug wakeupDriver()
Sent - Hello news! 4
2014-07-08 11:06:27 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-08 11:06:27 [Messaging] debug Trimming buffer from 59 to 31
2014-07-08 11:06:27 [Messaging] debug wakeupDriver()
Sent - Hello news! 5
2014-07-08 11:06:27 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-08 11:06:27 [Messaging] debug Trimming buffer from 59 to 31
2014-07-08 11:06:27 [Messaging] debug wakeupDriver()
Sent - Hello news! 6
2014-07-08 11:06:27 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-08 11:06:27 [Messaging] debug Trimming buffer from 59 to 31
2014-07-08 11:06:27 [Messaging] debug wakeupDriver()
Sent - Hello news! 7
2014-07-08 11:06:27 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-08 11:06:27 [Messaging] debug Trimming buffer from 59 to 31
2014-07-08 11:06:27 [Messaging] debug wakeupDriver()
Sent - Hello news! 8
2014-07-08 11:06:27 [Messaging] debug Sending message, buffer is 59 bytes
2014-07-08 11:06:27 [Messaging] debug Trimming buffer from 59 to 31
2014-07-08 11:06:27 [Messaging] debug wakeupDriver()
Sent - Hello news! 9
2
2014-07-08 11:06:27 [Messaging] debug wakeupDriver()
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-08 11:06:27 [Protocol] trace [4cc71475-8b5c-4127-b630-7d02c05da20b]: 0 -> @transfer(20) [handle=0, delivery-id=0, delivery-tag=b"\x00\x00\x00\x00", message-format=0, settled=false, more=false] (31) "\x00Sp\xc0\x04\x02BP\x00\x00St\xc1\x01\x00\x00Su\xa0\x0bHello news!"
2014-07-08 11:06:27 [Network] debug tcp:localhost:5672 encoded 65 bytes from 65535
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 encode(65535)
2014-07-08 11:06:27 [Security] trace tcp:localhost:5672 Sasl::canEncode(): 0 || 0
2014-07-08 11:06:27 [Messaging] trace tcp:localhost:5672 decode(48)
2014-07-08 11:06:27 [Protocol] trace [4cc71475-8b5c-4127-b630-7d02c05da20b]: 0 <- @flow(19) [next-incoming-id=1, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=1, link-credit=100]
2014-07-08 11:06:27 [Protocol] trace [4cc71475-8b5c-4127-b630-7d02c05da20b]: 0 <- @disposition(21) [role=true, first=0, last=0, settled=true, state=@accepted(36) []]
2014-07-08 11:06:27 [Network] debug tcp:localhost:5672 decoded 48 bytes from 48

<hangs here>

-----Original Message-----
From: Gordon Sim [mailto:gsim@redhat.com] 
Sent: Monday, July 07, 2014 4:55 PM
To: dev@qpid.apache.org
Subject: Re: Potential qpid cpp 0.28 bug

On 07/07/2014 10:46 AM, Duong Quynh (FSU1.Z8.IP) wrote:
> Hi Gordon,
>
> I have made the changes to ConnectionContext.cpp file, make clean, make and make install again, deleted the executable binary, rebuilt, problem still persists:

Can you get a full log, QPID_LOG_ENABLE=trace+ (i.e. not just protocol)?


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org For additional commands, e-mail: dev-help@qpid.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


Re: Potential qpid cpp 0.28 bug

Posted by Gordon Sim <gs...@redhat.com>.
On 07/07/2014 10:46 AM, Duong Quynh (FSU1.Z8.IP) wrote:
> Hi Gordon,
>
> I have made the changes to ConnectionContext.cpp file, make clean, make and make install again, deleted the executable binary, rebuilt, problem still persists:

Can you get a full log, QPID_LOG_ENABLE=trace+ (i.e. not just protocol)?


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


RE: Potential qpid cpp 0.28 bug

Posted by "Duong Quynh (FSU1.Z8.IP)" <Qu...@fsoft.com.vn>.
Hi Gordon,

I have made the changes to ConnectionContext.cpp file, make clean, make and make install again, deleted the executable binary, rebuilt, problem still persists:


./amq-producer 
2014-07-07 16:41:12 [Protocol] debug tcp:localhost:5672 writing protocol header: 1-0
2014-07-07 16:41:12 [Protocol] debug tcp:localhost:5672 read protocol header: 1-0
2014-07-07 16:41:12 [Protocol] debug tcp:localhost:5672 Received SASL-MECHANISMS(ANONYMOUS PLAIN )
2014-07-07 16:41:12 [Protocol] debug tcp:localhost:5672 Sent SASL-INIT(PLAIN, \x00guest\x00guest, localhost)
2014-07-07 16:41:12 [Protocol] debug tcp:localhost:5672 Received SASL-OUTCOME(\x00)
2014-07-07 16:41:12 [Protocol] trace [9d2c3b99-3dd9-452c-af0e-206991e5237f]:   -> AMQP
2014-07-07 16:41:12 [Protocol] trace [9d2c3b99-3dd9-452c-af0e-206991e5237f]:   <- AMQP
2014-07-07 16:41:12 [Protocol] trace [9d2c3b99-3dd9-452c-af0e-206991e5237f]: 0 -> @open(16) [container-id="9d2c3b99-3dd9-452c-af0e-206991e5237f", properties={:"qpid.client_process"="amq-producer", :"qpid.client_pid"=25518, :"qpid.client_ppid"=20140}]
2014-07-07 16:41:12 [Protocol] trace [9d2c3b99-3dd9-452c-af0e-206991e5237f]: 0 <- @open(16) [container-id="", hostname="", max-frame-size=1048576]
1
2014-07-07 16:41:12 [Protocol] trace [9d2c3b99-3dd9-452c-af0e-206991e5237f]: 0 -> @begin(17) [next-outgoing-id=0, incoming-window=2147483647, outgoing-window=0]
2014-07-07 16:41:12 [Protocol] trace [9d2c3b99-3dd9-452c-af0e-206991e5237f]: 0 <- @begin(17) [remote-channel=0, next-outgoing-id=1, incoming-window=0, outgoing-window=0, handle-max=1024]
2014-07-07 16:41:12 [Protocol] trace [9d2c3b99-3dd9-452c-af0e-206991e5237f]: 0 -> @attach(18) [name="topic://usa.news_9a89c322-d271-449f-a9d6-2b32573c7863", handle=0, role=false, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="topic://usa.news", durable=0, timeout=0, dynamic=false], target=@target(41) [address="topic://usa.news", durable=0, timeout=0, dynamic=false], initial-delivery-count=0]
2014-07-07 16:41:12 [Protocol] trace [9d2c3b99-3dd9-452c-af0e-206991e5237f]: 0 <- @attach(18) [name="topic://usa.news_9a89c322-d271-449f-a9d6-2b32573c7863", handle=0, role=true, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="topic://usa.news"], target=@target(41) [address="topic://usa.news"]]
2014-07-07 16:41:12 [Protocol] trace [9d2c3b99-3dd9-452c-af0e-206991e5237f]: 0 <- @flow(19) [next-incoming-id=0, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=0, link-credit=100]
Sent - Hello news! 0
Sent - Hello news! 1
Sent - Hello news! 2
Sent - Hello news! 3
Sent - Hello news! 4
Sent - Hello news! 5
Sent - Hello news! 6
Sent - Hello news! 7
Sent - Hello news! 8
Sent - Hello news! 9
2
2014-07-07 16:41:12 [Protocol] trace [9d2c3b99-3dd9-452c-af0e-206991e5237f]: 0 -> @transfer(20) [handle=0, delivery-id=0, delivery-tag=b"\x00\x00\x00\x00", message-format=0, settled=false, more=false] (31) "\x00Sp\xc0\x04\x02BP\x00\x00St\xc1\x01\x00\x00Su\xa0\x0bHello news!"
2014-07-07 16:41:12 [Protocol] trace [9d2c3b99-3dd9-452c-af0e-206991e5237f]: 0 <- @flow(19) [next-incoming-id=1, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=1, link-credit=100]
2014-07-07 16:41:12 [Protocol] trace [9d2c3b99-3dd9-452c-af0e-206991e5237f]: 0 <- @disposition(21) [role=true, first=0, last=0, settled=true, state=@accepted(36) []]

<still hangs here>

-----Original Message-----
From: Gordon Sim [mailto:gsim@redhat.com] 
Sent: Monday, July 07, 2014 3:29 PM
To: dev@qpid.apache.org
Subject: Re: Potential qpid cpp 0.28 bug

Yes, rebuild the 0.28 libs and that should fix the issue.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


Re: Potential qpid cpp 0.28 bug

Posted by Gordon Sim <gs...@redhat.com>.
On 07/07/2014 09:27 AM, Duong Quynh (FSU1.Z8.IP) wrote:
> Got it, all I need is apply the patch and rebuild the libs, right?

Yes, rebuild the 0.28 libs and that should fix the issue.

> -----Original Message-----
> From: Gordon Sim [mailto:gsim@redhat.com]
> Sent: Monday, July 07, 2014 3:25 PM
> To: dev@qpid.apache.org
> Subject: Re: Potential qpid cpp 0.28 bug
>
> That looks like QPID-5737[1], where an expansion to the incoming session window is not handled if it comes when the program is already closing down. This is fixed on trunk but not in 0.28. If you want, you can apply the change[2], which is very simple, to the 0.28 code and check whether it resolves the issue.
>
> [1] https://issues.apache.org/jira/browse/QPID-5737
> [2]
> https://svn.apache.org/viewvc/qpid/trunk/qpid/cpp/src/qpid/messaging/amqp/ConnectionContext.cpp?r1=1591470&r2=1591469&pathrev=1591470
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
> For additional commands, e-mail: dev-help@qpid.apache.org
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
> For additional commands, e-mail: dev-help@qpid.apache.org
>


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


RE: Potential qpid cpp 0.28 bug

Posted by "Duong Quynh (FSU1.Z8.IP)" <Qu...@fsoft.com.vn>.
Got it, all I need is apply the patch and rebuild the libs, right?

-----Original Message-----
From: Gordon Sim [mailto:gsim@redhat.com] 
Sent: Monday, July 07, 2014 3:25 PM
To: dev@qpid.apache.org
Subject: Re: Potential qpid cpp 0.28 bug

That looks like QPID-5737[1], where an expansion to the incoming session window is not handled if it comes when the program is already closing down. This is fixed on trunk but not in 0.28. If you want, you can apply the change[2], which is very simple, to the 0.28 code and check whether it resolves the issue.

[1] https://issues.apache.org/jira/browse/QPID-5737
[2]
https://svn.apache.org/viewvc/qpid/trunk/qpid/cpp/src/qpid/messaging/amqp/ConnectionContext.cpp?r1=1591470&r2=1591469&pathrev=1591470


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


Re: Potential qpid cpp 0.28 bug

Posted by Gordon Sim <gs...@redhat.com>.
On 07/07/2014 02:43 AM, Duong Quynh (FSU1.Z8.IP) wrote:
> I rebuilt the program again and run it a second time, it didn't complete again as logged below:
>
> ./amq-producer
> 2014-07-07 08:41:30 [Protocol] debug tcp:localhost:5672 writing protocol header: 1-0
> 2014-07-07 08:41:30 [Protocol] debug tcp:localhost:5672 read protocol header: 1-0
> 2014-07-07 08:41:30 [Protocol] debug tcp:localhost:5672 Received SASL-MECHANISMS(ANONYMOUS PLAIN )
> 2014-07-07 08:41:30 [Protocol] debug tcp:localhost:5672 Sent SASL-INIT(PLAIN, \x00guest\x00guest, localhost)
> 2014-07-07 08:41:30 [Protocol] debug tcp:localhost:5672 Received SASL-OUTCOME(\x00)
> 2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]:   -> AMQP
> 2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]:   <- AMQP
> 2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]: 0 -> @open(16) [container-id="ed70edd1-1d03-47c2-bd73-b0227ff93716", properties={:"qpid.client_process"="amq-producer", :"qpid.client_pid"=16745, :"qpid.client_ppid"=14398}]
> 2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]: 0 <- @open(16) [container-id="", hostname="", max-frame-size=1048576]
> 1
> 2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]: 0 -> @begin(17) [next-outgoing-id=0, incoming-window=2147483647, outgoing-window=0]
> 2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]: 0 <- @begin(17) [remote-channel=0, next-outgoing-id=1, incoming-window=0, outgoing-window=0, handle-max=1024]
> 2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]: 0 -> @attach(18) [name="topic://usa.news_cf7c7459-54cd-42c9-8f73-b3434f68711b", handle=0, role=false, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="topic://usa.news", durable=0, timeout=0, dynamic=false], target=@target(41) [address="topic://usa.news", durable=0, timeout=0, dynamic=false], initial-delivery-count=0]
> 2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]: 0 <- @attach(18) [name="topic://usa.news_cf7c7459-54cd-42c9-8f73-b3434f68711b", handle=0, role=true, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="topic://usa.news"], target=@target(41) [address="topic://usa.news"]]
> 2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]: 0 <- @flow(19) [next-incoming-id=0, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=0, link-credit=100]
> Sent - Hello news! 0
> Sent - Hello news! 1
> Sent - Hello news! 2
> Sent - Hello news! 3
> Sent - Hello news! 4
> Sent - Hello news! 5
> Sent - Hello news! 6
> Sent - Hello news! 7
> Sent - Hello news! 8
> Sent - Hello news! 9
> 2
> 2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]: 0 -> @transfer(20) [handle=0, delivery-id=0, delivery-tag=b"\x00\x00\x00\x00", message-format=0, settled=false, more=false] (31) "\x00Sp\xc0\x04\x02BP\x00\x00St\xc1\x01\x00\x00Su\xa0\x0bHello news!"
> 2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]: 0 <- @flow(19) [next-incoming-id=1, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=1, link-credit=100]
> 2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]: 0 <- @disposition(21) [role=true, first=0, last=0, settled=true, state=@accepted(36) []]

That looks like QPID-5737[1], where an expansion to the incoming session 
window is not handled if it comes when the program is already closing 
down. This is fixed on trunk but not in 0.28. If you want, you can apply 
the change[2], which is very simple, to the 0.28 code and check whether 
it resolves the issue.

[1] https://issues.apache.org/jira/browse/QPID-5737
[2] 
https://svn.apache.org/viewvc/qpid/trunk/qpid/cpp/src/qpid/messaging/amqp/ConnectionContext.cpp?r1=1591470&r2=1591469&pathrev=1591470


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


RE: Potential qpid cpp 0.28 bug

Posted by "Duong Quynh (FSU1.Z8.IP)" <Qu...@fsoft.com.vn>.
I rebuilt the program again and run it a second time, it didn't complete again as logged below:

./amq-producer 
2014-07-07 08:41:30 [Protocol] debug tcp:localhost:5672 writing protocol header: 1-0
2014-07-07 08:41:30 [Protocol] debug tcp:localhost:5672 read protocol header: 1-0
2014-07-07 08:41:30 [Protocol] debug tcp:localhost:5672 Received SASL-MECHANISMS(ANONYMOUS PLAIN )
2014-07-07 08:41:30 [Protocol] debug tcp:localhost:5672 Sent SASL-INIT(PLAIN, \x00guest\x00guest, localhost)
2014-07-07 08:41:30 [Protocol] debug tcp:localhost:5672 Received SASL-OUTCOME(\x00)
2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]:   -> AMQP
2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]:   <- AMQP
2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]: 0 -> @open(16) [container-id="ed70edd1-1d03-47c2-bd73-b0227ff93716", properties={:"qpid.client_process"="amq-producer", :"qpid.client_pid"=16745, :"qpid.client_ppid"=14398}]
2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]: 0 <- @open(16) [container-id="", hostname="", max-frame-size=1048576]
1
2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]: 0 -> @begin(17) [next-outgoing-id=0, incoming-window=2147483647, outgoing-window=0]
2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]: 0 <- @begin(17) [remote-channel=0, next-outgoing-id=1, incoming-window=0, outgoing-window=0, handle-max=1024]
2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]: 0 -> @attach(18) [name="topic://usa.news_cf7c7459-54cd-42c9-8f73-b3434f68711b", handle=0, role=false, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="topic://usa.news", durable=0, timeout=0, dynamic=false], target=@target(41) [address="topic://usa.news", durable=0, timeout=0, dynamic=false], initial-delivery-count=0]
2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]: 0 <- @attach(18) [name="topic://usa.news_cf7c7459-54cd-42c9-8f73-b3434f68711b", handle=0, role=true, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="topic://usa.news"], target=@target(41) [address="topic://usa.news"]]
2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]: 0 <- @flow(19) [next-incoming-id=0, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=0, link-credit=100]
Sent - Hello news! 0
Sent - Hello news! 1
Sent - Hello news! 2
Sent - Hello news! 3
Sent - Hello news! 4
Sent - Hello news! 5
Sent - Hello news! 6
Sent - Hello news! 7
Sent - Hello news! 8
Sent - Hello news! 9
2
2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]: 0 -> @transfer(20) [handle=0, delivery-id=0, delivery-tag=b"\x00\x00\x00\x00", message-format=0, settled=false, more=false] (31) "\x00Sp\xc0\x04\x02BP\x00\x00St\xc1\x01\x00\x00Su\xa0\x0bHello news!"
2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]: 0 <- @flow(19) [next-incoming-id=1, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=1, link-credit=100]
2014-07-07 08:41:30 [Protocol] trace [ed70edd1-1d03-47c2-bd73-b0227ff93716]: 0 <- @disposition(21) [role=true, first=0, last=0, settled=true, state=@accepted(36) []]

<program idled here>

-----Original Message-----
From: Gordon Sim [mailto:gsim@redhat.com]
Sent: Friday, July 04, 2014 10:07 PM
To: dev@qpid.apache.org
Subject: Re: Potential qpid cpp 0.28 bug

On 07/04/2014 04:00 PM, Duong Quynh (FSU1.Z8.IP) wrote:
> Like I said in a different thread, I was using JBOSS A-MQ.

Which is based on ActiveMQ.

However the point is that its some compatibility issue, and a protocol trace will help establish what that is.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


RE: Potential qpid cpp 0.28 bug

Posted by "Duong Quynh (FSU1.Z8.IP)" <Qu...@fsoft.com.vn>.
Here's your core dump:

./amq-producer 
2014-07-07 08:31:19 [Protocol] debug tcp:localhost:5672 writing protocol header: 1-0
2014-07-07 08:31:19 [Protocol] debug tcp:localhost:5672 read protocol header: 1-0
2014-07-07 08:31:19 [Protocol] debug tcp:localhost:5672 Received SASL-MECHANISMS(ANONYMOUS PLAIN )
2014-07-07 08:31:19 [Protocol] debug tcp:localhost:5672 Sent SASL-INIT(PLAIN, \x00guest\x00guest, localhost)
2014-07-07 08:31:19 [Protocol] debug tcp:localhost:5672 Received SASL-OUTCOME(\x00)
2014-07-07 08:31:19 [Protocol] trace [abc35b30-8eae-4211-834a-fe22e3f7d498]:   -> AMQP
2014-07-07 08:31:19 [Protocol] trace [abc35b30-8eae-4211-834a-fe22e3f7d498]:   <- AMQP
2014-07-07 08:31:19 [Protocol] trace [abc35b30-8eae-4211-834a-fe22e3f7d498]: 0 -> @open(16) [container-id="abc35b30-8eae-4211-834a-fe22e3f7d498", properties={:"qpid.client_process"="amq-producer", :"qpid.client_pid"=16662, :"qpid.client_ppid"=14398}]
2014-07-07 08:31:19 [Protocol] trace [abc35b30-8eae-4211-834a-fe22e3f7d498]: 0 <- @open(16) [container-id="", hostname="", max-frame-size=1048576]
1
2014-07-07 08:31:19 [Protocol] trace [abc35b30-8eae-4211-834a-fe22e3f7d498]: 0 -> @begin(17) [next-outgoing-id=0, incoming-window=2147483647, outgoing-window=0]
2014-07-07 08:31:19 [Protocol] trace [abc35b30-8eae-4211-834a-fe22e3f7d498]: 0 <- @begin(17) [remote-channel=0, next-outgoing-id=1, incoming-window=0, outgoing-window=0, handle-max=1024]
2014-07-07 08:31:19 [Protocol] trace [abc35b30-8eae-4211-834a-fe22e3f7d498]: 0 -> @attach(18) [name="topic://usa.news_c09a31be-7169-42f5-857a-b76eac3002a7", handle=0, role=false, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="topic://usa.news", durable=0, timeout=0, dynamic=false], target=@target(41) [address="topic://usa.news", durable=0, timeout=0, dynamic=false], initial-delivery-count=0]
2014-07-07 08:31:19 [Protocol] trace [abc35b30-8eae-4211-834a-fe22e3f7d498]: 0 <- @attach(18) [name="topic://usa.news_c09a31be-7169-42f5-857a-b76eac3002a7", handle=0, role=true, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="topic://usa.news"], target=@target(41) [address="topic://usa.news"]]
2014-07-07 08:31:19 [Protocol] trace [abc35b30-8eae-4211-834a-fe22e3f7d498]: 0 <- @flow(19) [next-incoming-id=0, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=0, link-credit=100]
Sent - Hello news! 0
Sent - Hello news! 1
Sent - Hello news! 2
Sent - Hello news! 3
Sent - Hello news! 4
Sent - Hello news! 5
Sent - Hello news! 6
Sent - Hello news! 7
Sent - Hello news! 8
Sent - Hello news! 9
2
*** glibc detected *** ./amq-producer: double free or corruption (out): 0x00007fff10ea0070 ***
2014-07-07 08:31:19 [Protocol] trace [abc35b30-8eae-4211-834a-fe22e3f7d498]: 0 -> @transfer(20) [handle=0, delivery-id=0, delivery-tag=b"\x00\x00\x00\x00", message-format=0, settled=false, more=false] (31) "\x00Sp\xc0\x04\x02BP\x00\x00St\xc1\x01\x00\x00Su\xa0\x0bHello news!"
2014-07-07 08:31:19 [Protocol] trace [abc35b30-8eae-4211-834a-fe22e3f7d498]: 0 <- @flow(19) [next-incoming-id=1, incoming-window=1, next-outgoing-id=1, outgoing-window=0, handle=0, delivery-count=1, link-credit=100]
2014-07-07 08:31:19 [Protocol] trace [abc35b30-8eae-4211-834a-fe22e3f7d498]: 0 <- @disposition(21) [role=true, first=0, last=0, settled=true, state=@accepted(36) []]
======= Backtrace: =========
/lib64/libc.so.6[0x336d076166]
/lib64/libc.so.6[0x336d078ca3]
./amq-producer[0x4036e7]
/lib64/libc.so.6(__libc_start_main+0xfd)[0x336d01ed1d]
./amq-producer[0x403329]
======= Memory map: ========
00400000-0040a000 r-xp 00000000 08:03 1987179                            /root/workspace/build-amq-producer-Desktop_Qt_5_3_0_GCC_64bit-Debug/amq-producer
00609000-0060a000 rw-p 00009000 08:03 1987179                            /root/workspace/build-amq-producer-Desktop_Qt_5_3_0_GCC_64bit-Debug/amq-producer
019e3000-01a6e000 rw-p 00000000 00:00 0                                  [heap]
336cc00000-336cc20000 r-xp 00000000 08:03 2093080                        /lib64/ld-2.12.so
336ce1f000-336ce20000 r--p 0001f000 08:03 2093080                        /lib64/ld-2.12.so
336ce20000-336ce21000 rw-p 00020000 08:03 2093080                        /lib64/ld-2.12.so
336ce21000-336ce22000 rw-p 00000000 00:00 0 
336d000000-336d18b000 r-xp 00000000 08:03 2093084                        /lib64/libc-2.12.so
336d18b000-336d38a000 ---p 0018b000 08:03 2093084                        /lib64/libc-2.12.so
336d38a000-336d38e000 r--p 0018a000 08:03 2093084                        /lib64/libc-2.12.so
336d38e000-336d38f000 rw-p 0018e000 08:03 2093084                        /lib64/libc-2.12.so
336d38f000-336d394000 rw-p 00000000 00:00 0 
336d400000-336d417000 r-xp 00000000 08:03 2093094                        /lib64/libpthread-2.12.so
336d417000-336d617000 ---p 00017000 08:03 2093094                        /lib64/libpthread-2.12.so
336d617000-336d618000 r--p 00017000 08:03 2093094                        /lib64/libpthread-2.12.so
336d618000-336d619000 rw-p 00018000 08:03 2093094                        /lib64/libpthread-2.12.so
336d619000-336d61d000 rw-p 00000000 00:00 0 
336d800000-336d802000 r-xp 00000000 08:03 2093102                        /lib64/libdl-2.12.so
336d802000-336da02000 ---p 00002000 08:03 2093102                        /lib64/libdl-2.12.so
336da02000-336da03000 r--p 00002000 08:03 2093102                        /lib64/libdl-2.12.so
336da03000-336da04000 rw-p 00003000 08:03 2093102                        /lib64/libdl-2.12.so
336dc00000-336dc07000 r-xp 00000000 08:03 2093096                        /lib64/librt-2.12.so
336dc07000-336de06000 ---p 00007000 08:03 2093096                        /lib64/librt-2.12.so
336de06000-336de07000 r--p 00006000 08:03 2093096                        /lib64/librt-2.12.so
336de07000-336de08000 rw-p 00007000 08:03 2093096                        /lib64/librt-2.12.so
336e000000-336e083000 r-xp 00000000 08:03 2093131                        /lib64/libm-2.12.so
336e083000-336e282000 ---p 00083000 08:03 2093131                        /lib64/libm-2.12.so
336e282000-336e283000 r--p 00082000 08:03 2093131                        /lib64/libm-2.12.so
336e283000-336e284000 rw-p 00083000 08:03 2093131                        /lib64/libm-2.12.so
336e400000-336e415000 r-xp 00000000 08:03 2093114                        /lib64/libz.so.1.2.3
336e415000-336e614000 ---p 00015000 08:03 2093114                        /lib64/libz.so.1.2.3
336e614000-336e615000 r--p 00014000 08:03 2093114                        /lib64/libz.so.1.2.3
336e615000-336e616000 rw-p 00015000 08:03 2093114                        /lib64/libz.so.1.2.3
336ec00000-336ec1d000 r-xp 00000000 08:03 2093128                        /lib64/libselinux.so.1
336ec1d000-336ee1c000 ---p 0001d000 08:03 2093128                        /lib64/libselinux.so.1
336ee1c000-336ee1d000 r--p 0001c000 08:03 2093128                        /lib64/libselinux.so.1
336ee1d000-336ee1e000 rw-p 0001d000 08:03 2093128                        /lib64/libselinux.so.1
336ee1e000-336ee1f000 rw-p 00000000 00:00 0 
336fc00000-336fc16000 r-xp 00000000 08:03 2093127                        /lib64/libresolv-2.12.so
336fc16000-336fe16000 ---p 00016000 08:03 2093127                        /lib64/libresolv-2.12.so
336fe16000-336fe17000 r--p 00016000 08:03 2093127                        /lib64/libresolv-2.12.so
336fe17000-336fe18000 rw-p 00017000 08:03 2093127                        /lib64/libresolv-2.12.so
336fe18000-336fe1a000 rw-p 00000000 00:00 0 
3378000000-3378004000 r-xp 00000000 08:03 2093120                        /lib64/libuuid.so.1.3.0
3378004000-3378203000 ---p 00004000 08:03 2093120                        /lib64/libuuid.so.1.3.0
3378203000-3378204000 rw-p 00003000 08:03 2093120                        /lib64/libuuid.so.1.3.0
3378400000-3378416000 r-xp 00000000 08:03 2093117                        /lib64/libgcc_s-4.4.7-20120601.so.1
3378416000-3378615000 ---p 00016000 08:03 2093117                        /lib64/libgcc_s-4.4.7-20120601.so.1
3378615000-3378616000 rw-p 00015000 08:03 2093117                        /lib64/libgcc_s-4.4.7-20120601.so.1
3379c00000-3379d6f000 r-xp 00000000 08:03 2093150                        /lib64/libdb-4.7.so
3379d6f000-3379f6e000 ---p 0016f000 08:03 2093150                        /lib64/libdb-4.7.so
3379f6e000-3379f74000 rw-p 0016e000 08:03 2093150                        /lib64/libdb-4.7.so
337a800000-337a80a000 r-xp 00000000 08:03 2093171                        /lib64/libkrb5support.so.0.1
337a80a000-337aa09000 ---p 0000a000 08:03 2093171                        /lib64/libkrb5support.so.0.1
337aa09000-337aa0a000 r--p 00009000 08:03 2093171                        /lib64/libkrb5support.so.0.1
337aa0a000-337aa0b000 rw-p 0000a000 08:03 2093171                        /lib64/libkrb5support.so.0.1
337ac00000-337ac29000 r-xp 00000000 08:03 2093177                        /lib64/libk5crypto.so.3.1
337ac29000-337ae29000 ---p 00029000 08:03 2093177                        /lib64/libk5crypto.so.3.1
337ae29000-337ae2a000 r--p 00029000 08:03 2093177                        /lib64/libk5crypto.so.3.1
337ae2a000-337ae2b000 rw-p 0002a000 08:03 2093177                        /lib64/libk5crypto.so.3.1
337ae2b000-337ae2c000 rw-p 00000000 00:00 0 
337b800000-337b802000 r-xp 00000000 08:03 2093168                        /lib64/libkeyutils.so.1.3
337b802000-337ba01000 ---p 00002000 08:03 2093168                        /lib64/libkeyutils.so.1.3
337ba01000-337ba02000 r--p 00001000 08:03 2093168                        /lib64/libkeyutils.so.1.3Aborted (core dumped)

-----Original Message-----
From: Gordon Sim [mailto:gsim@redhat.com] 
Sent: Friday, July 04, 2014 10:07 PM
To: dev@qpid.apache.org
Subject: Re: Potential qpid cpp 0.28 bug

On 07/04/2014 04:00 PM, Duong Quynh (FSU1.Z8.IP) wrote:
> Like I said in a different thread, I was using JBOSS A-MQ.

Which is based on ActiveMQ.

However the point is that its some compatibility issue, and a protocol trace will help establish what that is.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


Re: Potential qpid cpp 0.28 bug

Posted by Gordon Sim <gs...@redhat.com>.
On 07/04/2014 04:00 PM, Duong Quynh (FSU1.Z8.IP) wrote:
> Like I said in a different thread, I was using JBOSS A-MQ.

Which is based on ActiveMQ.

However the point is that its some compatibility issue, and a protocol 
trace will help establish what that is.
__________________________________
> From: Gordon Sim [gsim@redhat.com]
> Sent: Friday, July 04, 2014 6:41 PM
> To: dev@qpid.apache.org
> Subject: Re: Potential qpid cpp 0.28 bug
>
> On 07/04/2014 10:31 AM, Duong Quynh (FSU1.Z8.IP) wrote:
>> I will get down to the log later when I have time, however, I don't see this problem happening with the JAVA client, the Producer just exits with identical logic.
>
> The c++ sender example you posted works fine for me against ActiveMQ 5.9
> when using the 0.28 release.


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


RE: Potential qpid cpp 0.28 bug

Posted by "Duong Quynh (FSU1.Z8.IP)" <Qu...@fsoft.com.vn>.
Like I said in a different thread, I was using JBOSS A-MQ.

Cheers.
________________________________________
From: Gordon Sim [gsim@redhat.com]
Sent: Friday, July 04, 2014 6:41 PM
To: dev@qpid.apache.org
Subject: Re: Potential qpid cpp 0.28 bug

On 07/04/2014 10:31 AM, Duong Quynh (FSU1.Z8.IP) wrote:
> I will get down to the log later when I have time, however, I don't see this problem happening with the JAVA client, the Producer just exits with identical logic.

The c++ sender example you posted works fine for me against ActiveMQ 5.9
when using the 0.28 release.


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


Re: Potential qpid cpp 0.28 bug

Posted by Gordon Sim <gs...@redhat.com>.
On 07/04/2014 10:31 AM, Duong Quynh (FSU1.Z8.IP) wrote:
> I will get down to the log later when I have time, however, I don't see this problem happening with the JAVA client, the Producer just exits with identical logic.

The c++ sender example you posted works fine for me against ActiveMQ 5.9 
when using the 0.28 release.


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


RE: Potential qpid cpp 0.28 bug

Posted by "Duong Quynh (FSU1.Z8.IP)" <Qu...@fsoft.com.vn>.
I will get down to the log later when I have time, however, I don't see this problem happening with the JAVA client, the Producer just exits with identical logic.

> Not sure what you mean by that... do you mean that the subsequent call, i.e. session.close() does not return?

> The most likely reason for that is around the settlement of messages. If you can enable some more detailed logging it should be able to spot the issue. > E.g. QPID_LOG_ENABLE=trace+:Protocol

>The session.close() will wait for all sent messages to be settled before closing. I suspect that is where it is blocked. The protocol trace should help.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org For additional commands, e-mail: dev-help@qpid.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


Re: Potential qpid cpp 0.28 bug

Posted by Gordon Sim <gs...@redhat.com>.
On 07/04/2014 08:05 AM, Duong Quynh (FSU1.Z8.IP) wrote:
> Hi everyone,
>
> Today while coding a simple sender on qpid cpp 0.28 I encountered a
> problem where the program will not quit after completing its task. I
> am building using g++ 4.8.3, boost 1.49.0, proton 0.70 to name a
> few. I put the program through gdb and it seems to jump around
> infitely after the std::cout << "2" << endl; line.

Not sure what you mean by that... do you mean that the subsequent call, 
i.e. session.close() does not return?

The most likely reason for that is around the settlement of messages. If 
you can enable some more detailed logging it should be able to spot the 
issue. E.g. QPID_LOG_ENABLE=trace+:Protocol

> My current guess
> is Sender class has issues since the receiver I wrote would quit
> gracefully.

The session.close() will wait for all sent messages to be settled before 
closing. I suspect that is where it is blocked. The protocol trace 
should help.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org