You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@qpid.apache.org by "Darryl L. Pierce" <dp...@redhat.com> on 2012/07/02 18:09:12 UTC
[Proton] ERROR amqp:connection:framing-error connection aborted
I keep hitting this issue and I'm not quite sure the problem. In writing
the Ruby version of mailserver, post and fetch, I see this come up when
post sends its last message to the mail server.
The combination that I'm using is the Python server
(examples/mailbox/server) and the Ruby post.rb application. The output I
see from server is, at the end:
I/O processing start.
Process delivery post-deliver-5.
Msg Received 5
Mailbox foo contains: ['test0', 'test1', 'test2', 'test3']
Msg Accepted.
remote disposition for post-deliver-5: 0
Driver sleep...
...Driver wakeup.
Process Connector
I/O processing start.
Driver sleep...
...Driver wakeup.
Process Connector
ERROR amqp:connection:framing-error connection aborted
error in process_input: PN_ERR
I/O processing start.
Driver sleep...
...Driver wakeup.
Process Connector
I/O processing start.
Closing connector
Driver sleep...
In this case I sent five messages:
test0 test1 test2 test3 test4
If I drop or add any messages, it always sends through the very last
message but then the server gives the same message after message n-1.
--
Darryl L. Pierce, Sr. Software Engineer @ Red Hat, Inc.
Delivering value year after year.
Red Hat ranks #1 in value among software vendors.
http://www.redhat.com/promo/vendor/
Re: [Proton] ERROR amqp:connection:framing-error connection aborted
Posted by "Darryl L. Pierce" <dp...@redhat.com>.
On Thu, Jul 05, 2012 at 05:51:05PM -0400, Rafael Schloming wrote:
> According to the log output you posted, the body of the loop is never
> running. Can you log the value that pn_connection_state is returning and
> verify that the test is working as expected? I don't recall offhand how
> exactly bitwise operators work in Ruby.
They work the same as in other languages, where:
while !(Cproton::pn_connection_state(sender.conn) & Cproton::PN_REMOTE_CLOSED)
should only return a true value if the bits expressed by
Cproton::PN_REMOTE_CLOSED are not all set in
Cproton::pn_connection_state(sender.conn).
The output you requested is:
mcpierce@mcpierce-laptop:ruby (Ruby-bindings) $ ruby -I
../../cmake/bindings/ruby/ post.rb test1 test2 test3 test4 test5 -m farkle
Cproton::pn_unsettled returns 0
Closing the connection.
Cproton::pn_connection_state(#<SWIG::TYPE_p_pn_connection_t:0x0000000066d028>)==20
So the connection state is 20 which is
#define PN_LOCAL_CLOSED (4) /**< local endpoint is closed */
#define PN_REMOTE_ACTIVE (16) /**< remote endpoint is active */
/me plays in IRB
And I learned something new about Ruby: !0 != true, but !!0 == true. I
replaced the previous call with:
while ((Cproton::pn_connection_state(sender.conn) & Cproton::PN_REMOTE_CLOSED) != Cproton::PN_REMOTE_CLOSED)
(which is pretty ugly and verbose) and the transaction doesn't exhibit
the previous errors.
--
Darryl L. Pierce, Sr. Software Engineer @ Red Hat, Inc.
Delivering value year after year.
Red Hat ranks #1 in value among software vendors.
http://www.redhat.com/promo/vendor/
Re: [Proton] ERROR amqp:connection:framing-error connection aborted
Posted by Rafael Schloming <ra...@redhat.com>.
According to the log output you posted, the body of the loop is never
running. Can you log the value that pn_connection_state is returning and
verify that the test is working as expected? I don't recall offhand how
exactly bitwise operators work in Ruby.
--Rafael
On Thu, 2012-07-05 at 16:20 -0400, Darryl L. Pierce wrote:
> On Tue, Jul 03, 2012 at 05:13:17PM -0400, Rafael Schloming wrote:
> > Can you post the ruby code you're using? I took a look at the original
> > python example you're transcoding and based on the trace it's likely
> > something is messed up around this part:
> >
> > # we're done, close and wait for the remote to close also
> > pn_connection_close(sender.conn)
> > while not (pn_connection_state(sender.conn) & PN_REMOTE_CLOSED):
> > sender.wait()
>
> Sure, you can see all that I've done so far up in my Github repo:
>
> https://github.com/mcpierce/proton/tree/Ruby-bindings
>
> What I did in the Ruby was to line-by-line copy the above with:
>
> puts "Closing the connection."
> Cproton::pn_connection_close sender.conn
> while !(Cproton::pn_connection_state(sender.conn) & Cproton::PN_REMOTE_CLOSED)
> log "Waiting for things to become closed..."
> sender.wait
> end
>
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org
Re: [Proton] ERROR amqp:connection:framing-error connection aborted
Posted by "Darryl L. Pierce" <mc...@fedoraproject.org>.
On Tue, Jul 03, 2012 at 05:13:17PM -0400, Rafael Schloming wrote:
> Can you post the ruby code you're using? I took a look at the original
> python example you're transcoding and based on the trace it's likely
> something is messed up around this part:
>
> # we're done, close and wait for the remote to close also
> pn_connection_close(sender.conn)
> while not (pn_connection_state(sender.conn) & PN_REMOTE_CLOSED):
> sender.wait()
Sure, you can see all that I've done so far up in my Github repo:
https://github.com/mcpierce/proton/tree/Ruby-bindings
What I did in the Ruby was to line-by-line copy the above with:
puts "Closing the connection."
Cproton::pn_connection_close sender.conn
while !(Cproton::pn_connection_state(sender.conn) & Cproton::PN_REMOTE_CLOSED)
log "Waiting for things to become closed..."
sender.wait
end
--
Darryl L. Pierce, Sr. Software Engineer @ Red Hat, Inc.
Delivering value year after year.
Red Hat ranks #1 in value among software vendors.
http://www.redhat.com/promo/vendor/
Re: [Proton] ERROR amqp:connection:framing-error connection aborted
Posted by Rafael Schloming <ra...@redhat.com>.
Can you post the ruby code you're using? I took a look at the original
python example you're transcoding and based on the trace it's likely
something is messed up around this part:
# we're done, close and wait for the remote to close also
pn_connection_close(sender.conn)
while not (pn_connection_state(sender.conn) & PN_REMOTE_CLOSED):
sender.wait()
--Rafael
On Tue, 2012-07-03 at 08:51 -0400, Darryl L. Pierce wrote:
> On Mon, Jul 02, 2012 at 04:07:53PM -0400, Rafael Schloming wrote:
> > That most likely means the TCP connection is being terminated without
> > waiting for the proper protocol close handshake to occur. To debug this
> > try setting the environment variable PN_TRACE_FRM to 1 when you run the
> > client and/or server. That will let you see exactly what frames are
> > being exchanged. If you post the output here I can give you a better
> > idea of what is going on.
>
> Grabbed the output from both sides. Again, this is the Python server app
> and the Ruby post.rb app for the mailbox example.
>
> Here is the client side:
>
> mcpierce@mcpierce-laptop:cmake (Ruby-bindings) $ PN_TRACE_FRM=1 ruby -I bindings/ruby/ ../examples/ruby/post.rb -m foo test0 test1 test2 test3 test4
> Connected to 0.0.0.0:5672
> -> AMQP SASL 1.0
> [0] -> SASL-INIT @65 [:ANONYMOUS, null]
> <- AMQP SASL 1.0
> [0] <- SASL-MECHANISMS @64 [@PN_SYMBOL[:ANONYMOUS]]
> [0] <- SASL-OUTCOME @68 [0]
> <- AMQP 1.0
> -> AMQP 1.0
> [0] -> OPEN @16 [null, null]
> [1] -> BEGIN @17 [null, 0, 1024, 1024]
> [1] -> ATTACH @18 ["sender", 1, false, null, null, null, @41 ["foo"], null, null, 0]
> [0] <- OPEN @16 [null, null]
> [1] <- BEGIN @17 [1, 0, 1024, 1024]
> [1] <- ATTACH @18 ["sender", 1, true, null, null, null, @41 ["foo"], null, null, 0]
> [1] <- FLOW @19 [0, 1024, 0, 1024, 1, 0, 1, null, false]
> [1] -> TRANSFER @20 [1, 0, b"post-deliver-4", 0, true, false] (5) "test0"
> [1] -> DISPOSITION @21 [false, 0, 0, true, null]
> [1] <- FLOW @19 [1, 1023, 0, 1024, 1, 1, 1, null, false]
> [1] -> TRANSFER @20 [1, 1, b"post-deliver-3", 0, true, false] (5) "test1"
> [1] -> DISPOSITION @21 [false, 1, 1, true, null]
> [1] <- FLOW @19 [2, 1023, 0, 1024, 1, 2, 1, null, false]
> [1] -> TRANSFER @20 [1, 2, b"post-deliver-2", 0, true, false] (5) "test2"
> [1] -> DISPOSITION @21 [false, 2, 2, true, null]
> [1] <- FLOW @19 [3, 1023, 0, 1024, 1, 3, 1, null, false]
> [1] -> TRANSFER @20 [1, 3, b"post-deliver-1", 0, true, false] (5) "test3"
> [1] -> DISPOSITION @21 [false, 3, 3, true, null]
> [1] <- FLOW @19 [4, 1023, 0, 1024, 1, 4, 1, null, false]
> Cproton::pn_unsettled returns 0
> Closing the connection.
>
> And here is the server side:
>
> mcpierce@mcpierce-laptop:cmake (Ruby-bindings) $ PN_TRACE_FRM=1 PYTHONPATH=bindings/python/ ../examples/mailbox/server
> Server started, listening on 0.0.0.0:5672
> Listening on 0.0.0.0:5672
> Driver sleep...
> ...Driver wakeup.
> Accepting Connection.
> accepted from mcpierce-laptop:60728
> Driver sleep...
> ...Driver wakeup.
> Process Connector
> <- AMQP SASL 1.0
> [0] <- SASL-INIT @65 [:ANONYMOUS, null]
> -> AMQP SASL 1.0
> Authenticating...
> Authenticating-CONF...
> Authenticating-STEP...
> Authentication-PASSED
> [0] -> SASL-MECHANISMS @64 [@PN_SYMBOL[:ANONYMOUS]]
> [0] -> SASL-OUTCOME @68 [0]
> -> AMQP 1.0
> Driver sleep...
> ...Driver wakeup.
> Process Connector
> I/O processing start.
> Connection Opened.
> [0] -> OPEN @16 [null, null]
> Driver sleep...
> ...Driver wakeup.
> Process Connector
> I/O processing start.
> Driver sleep...
> ...Driver wakeup.
> Process Connector
> <- AMQP 1.0
> [0] <- OPEN @16 [null, null]
> [1] <- BEGIN @17 [null, 0, 1024, 1024]
> [1] <- ATTACH @18 ["sender", 1, false, null, null, null, @41 ["foo"], null, null, 0]
> I/O processing start.
> Session Opened.
> Opening Link to write to mailbox: foo
> [1] -> BEGIN @17 [1, 0, 1024, 1024]
> [1] -> ATTACH @18 ["sender", 1, true, null, null, null, @41 ["foo"], null, null, 0]
> [1] -> FLOW @19 [0, 1024, 0, 1024, 1, 0, 1, null, false]
> Driver sleep...
> ...Driver wakeup.
> Process Connector
> I/O processing start.
> Driver sleep...
> ...Driver wakeup.
> Process Connector
> [1] <- TRANSFER @20 [1, 0, b"post-deliver-4", 0, true, false] (5) "test0"
> [1] <- DISPOSITION @21 [false, 0, 0, true, null]
> I/O processing start.
> Process delivery post-deliver-4.
> Msg Received 5
> Mailbox foo contains: ['test0']
> Msg Accepted.
> remote disposition for post-deliver-4: 0
> [1] -> FLOW @19 [1, 1023, 0, 1024, 1, 1, 1, null, false]
> Driver sleep...
> ...Driver wakeup.
> Process Connector
> I/O processing start.
> Driver sleep...
> ...Driver wakeup.
> Process Connector
> [1] <- TRANSFER @20 [1, 1, b"post-deliver-3", 0, true, false] (5) "test1"
> [1] <- DISPOSITION @21 [false, 1, 1, true, null]
> I/O processing start.
> Process delivery post-deliver-3.
> Msg Received 5
> Mailbox foo contains: ['test0', 'test1']
> Msg Accepted.
> remote disposition for post-deliver-3: 0
> [1] -> FLOW @19 [2, 1023, 0, 1024, 1, 2, 1, null, false]
> Driver sleep...
> ...Driver wakeup.
> Process Connector
> I/O processing start.
> Driver sleep...
> ...Driver wakeup.
> Process Connector
> [1] <- TRANSFER @20 [1, 2, b"post-deliver-2", 0, true, false] (5) "test2"
> [1] <- DISPOSITION @21 [false, 2, 2, true, null]
> I/O processing start.
> Process delivery post-deliver-2.
> Msg Received 5
> Mailbox foo contains: ['test0', 'test1', 'test2']
> Msg Accepted.
> remote disposition for post-deliver-2: 0
> [1] -> FLOW @19 [3, 1023, 0, 1024, 1, 3, 1, null, false]
> Driver sleep...
> ...Driver wakeup.
> Process Connector
> I/O processing start.
> Driver sleep...
> ...Driver wakeup.
> Process Connector
> [1] <- TRANSFER @20 [1, 3, b"post-deliver-1", 0, true, false] (5) "test3"
> [1] <- DISPOSITION @21 [false, 3, 3, true, null]
> I/O processing start.
> Process delivery post-deliver-1.
> Msg Received 5
> Mailbox foo contains: ['test0', 'test1', 'test2', 'test3']
> Msg Accepted.
> remote disposition for post-deliver-1: 0
> [1] -> FLOW @19 [4, 1023, 0, 1024, 1, 4, 1, null, false]
> Driver sleep...
> ...Driver wakeup.
> Process Connector
> I/O processing start.
> Driver sleep...
> ...Driver wakeup.
> Process Connector
> [0] -> CLOSE @24 [@29 [:"amqp:connection:framing-error"]]
> ERROR amqp:connection:framing-error connection aborted
> <- EOS
> error in process_input: PN_ERR
> -> EOS
> I/O processing start.
> Driver sleep...
> ...Driver wakeup.
> Process Connector
> closed
> I/O processing start.
> Closing connector
> Driver sleep...
>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org
Re: [Proton] ERROR amqp:connection:framing-error connection aborted
Posted by "Darryl L. Pierce" <dp...@redhat.com>.
On Mon, Jul 02, 2012 at 04:07:53PM -0400, Rafael Schloming wrote:
> That most likely means the TCP connection is being terminated without
> waiting for the proper protocol close handshake to occur. To debug this
> try setting the environment variable PN_TRACE_FRM to 1 when you run the
> client and/or server. That will let you see exactly what frames are
> being exchanged. If you post the output here I can give you a better
> idea of what is going on.
Grabbed the output from both sides. Again, this is the Python server app
and the Ruby post.rb app for the mailbox example.
Here is the client side:
mcpierce@mcpierce-laptop:cmake (Ruby-bindings) $ PN_TRACE_FRM=1 ruby -I bindings/ruby/ ../examples/ruby/post.rb -m foo test0 test1 test2 test3 test4
Connected to 0.0.0.0:5672
-> AMQP SASL 1.0
[0] -> SASL-INIT @65 [:ANONYMOUS, null]
<- AMQP SASL 1.0
[0] <- SASL-MECHANISMS @64 [@PN_SYMBOL[:ANONYMOUS]]
[0] <- SASL-OUTCOME @68 [0]
<- AMQP 1.0
-> AMQP 1.0
[0] -> OPEN @16 [null, null]
[1] -> BEGIN @17 [null, 0, 1024, 1024]
[1] -> ATTACH @18 ["sender", 1, false, null, null, null, @41 ["foo"], null, null, 0]
[0] <- OPEN @16 [null, null]
[1] <- BEGIN @17 [1, 0, 1024, 1024]
[1] <- ATTACH @18 ["sender", 1, true, null, null, null, @41 ["foo"], null, null, 0]
[1] <- FLOW @19 [0, 1024, 0, 1024, 1, 0, 1, null, false]
[1] -> TRANSFER @20 [1, 0, b"post-deliver-4", 0, true, false] (5) "test0"
[1] -> DISPOSITION @21 [false, 0, 0, true, null]
[1] <- FLOW @19 [1, 1023, 0, 1024, 1, 1, 1, null, false]
[1] -> TRANSFER @20 [1, 1, b"post-deliver-3", 0, true, false] (5) "test1"
[1] -> DISPOSITION @21 [false, 1, 1, true, null]
[1] <- FLOW @19 [2, 1023, 0, 1024, 1, 2, 1, null, false]
[1] -> TRANSFER @20 [1, 2, b"post-deliver-2", 0, true, false] (5) "test2"
[1] -> DISPOSITION @21 [false, 2, 2, true, null]
[1] <- FLOW @19 [3, 1023, 0, 1024, 1, 3, 1, null, false]
[1] -> TRANSFER @20 [1, 3, b"post-deliver-1", 0, true, false] (5) "test3"
[1] -> DISPOSITION @21 [false, 3, 3, true, null]
[1] <- FLOW @19 [4, 1023, 0, 1024, 1, 4, 1, null, false]
Cproton::pn_unsettled returns 0
Closing the connection.
And here is the server side:
mcpierce@mcpierce-laptop:cmake (Ruby-bindings) $ PN_TRACE_FRM=1 PYTHONPATH=bindings/python/ ../examples/mailbox/server
Server started, listening on 0.0.0.0:5672
Listening on 0.0.0.0:5672
Driver sleep...
...Driver wakeup.
Accepting Connection.
accepted from mcpierce-laptop:60728
Driver sleep...
...Driver wakeup.
Process Connector
<- AMQP SASL 1.0
[0] <- SASL-INIT @65 [:ANONYMOUS, null]
-> AMQP SASL 1.0
Authenticating...
Authenticating-CONF...
Authenticating-STEP...
Authentication-PASSED
[0] -> SASL-MECHANISMS @64 [@PN_SYMBOL[:ANONYMOUS]]
[0] -> SASL-OUTCOME @68 [0]
-> AMQP 1.0
Driver sleep...
...Driver wakeup.
Process Connector
I/O processing start.
Connection Opened.
[0] -> OPEN @16 [null, null]
Driver sleep...
...Driver wakeup.
Process Connector
I/O processing start.
Driver sleep...
...Driver wakeup.
Process Connector
<- AMQP 1.0
[0] <- OPEN @16 [null, null]
[1] <- BEGIN @17 [null, 0, 1024, 1024]
[1] <- ATTACH @18 ["sender", 1, false, null, null, null, @41 ["foo"], null, null, 0]
I/O processing start.
Session Opened.
Opening Link to write to mailbox: foo
[1] -> BEGIN @17 [1, 0, 1024, 1024]
[1] -> ATTACH @18 ["sender", 1, true, null, null, null, @41 ["foo"], null, null, 0]
[1] -> FLOW @19 [0, 1024, 0, 1024, 1, 0, 1, null, false]
Driver sleep...
...Driver wakeup.
Process Connector
I/O processing start.
Driver sleep...
...Driver wakeup.
Process Connector
[1] <- TRANSFER @20 [1, 0, b"post-deliver-4", 0, true, false] (5) "test0"
[1] <- DISPOSITION @21 [false, 0, 0, true, null]
I/O processing start.
Process delivery post-deliver-4.
Msg Received 5
Mailbox foo contains: ['test0']
Msg Accepted.
remote disposition for post-deliver-4: 0
[1] -> FLOW @19 [1, 1023, 0, 1024, 1, 1, 1, null, false]
Driver sleep...
...Driver wakeup.
Process Connector
I/O processing start.
Driver sleep...
...Driver wakeup.
Process Connector
[1] <- TRANSFER @20 [1, 1, b"post-deliver-3", 0, true, false] (5) "test1"
[1] <- DISPOSITION @21 [false, 1, 1, true, null]
I/O processing start.
Process delivery post-deliver-3.
Msg Received 5
Mailbox foo contains: ['test0', 'test1']
Msg Accepted.
remote disposition for post-deliver-3: 0
[1] -> FLOW @19 [2, 1023, 0, 1024, 1, 2, 1, null, false]
Driver sleep...
...Driver wakeup.
Process Connector
I/O processing start.
Driver sleep...
...Driver wakeup.
Process Connector
[1] <- TRANSFER @20 [1, 2, b"post-deliver-2", 0, true, false] (5) "test2"
[1] <- DISPOSITION @21 [false, 2, 2, true, null]
I/O processing start.
Process delivery post-deliver-2.
Msg Received 5
Mailbox foo contains: ['test0', 'test1', 'test2']
Msg Accepted.
remote disposition for post-deliver-2: 0
[1] -> FLOW @19 [3, 1023, 0, 1024, 1, 3, 1, null, false]
Driver sleep...
...Driver wakeup.
Process Connector
I/O processing start.
Driver sleep...
...Driver wakeup.
Process Connector
[1] <- TRANSFER @20 [1, 3, b"post-deliver-1", 0, true, false] (5) "test3"
[1] <- DISPOSITION @21 [false, 3, 3, true, null]
I/O processing start.
Process delivery post-deliver-1.
Msg Received 5
Mailbox foo contains: ['test0', 'test1', 'test2', 'test3']
Msg Accepted.
remote disposition for post-deliver-1: 0
[1] -> FLOW @19 [4, 1023, 0, 1024, 1, 4, 1, null, false]
Driver sleep...
...Driver wakeup.
Process Connector
I/O processing start.
Driver sleep...
...Driver wakeup.
Process Connector
[0] -> CLOSE @24 [@29 [:"amqp:connection:framing-error"]]
ERROR amqp:connection:framing-error connection aborted
<- EOS
error in process_input: PN_ERR
-> EOS
I/O processing start.
Driver sleep...
...Driver wakeup.
Process Connector
closed
I/O processing start.
Closing connector
Driver sleep...
--
Darryl L. Pierce, Sr. Software Engineer @ Red Hat, Inc.
Delivering value year after year.
Red Hat ranks #1 in value among software vendors.
http://www.redhat.com/promo/vendor/
Re: [Proton] ERROR amqp:connection:framing-error connection aborted
Posted by Rafael Schloming <ra...@redhat.com>.
That most likely means the TCP connection is being terminated without
waiting for the proper protocol close handshake to occur. To debug this
try setting the environment variable PN_TRACE_FRM to 1 when you run the
client and/or server. That will let you see exactly what frames are
being exchanged. If you post the output here I can give you a better
idea of what is going on.
--Rafael
On Mon, 2012-07-02 at 12:09 -0400, Darryl L. Pierce wrote:
> I keep hitting this issue and I'm not quite sure the problem. In writing
> the Ruby version of mailserver, post and fetch, I see this come up when
> post sends its last message to the mail server.
>
> The combination that I'm using is the Python server
> (examples/mailbox/server) and the Ruby post.rb application. The output I
> see from server is, at the end:
>
> I/O processing start.
> Process delivery post-deliver-5.
> Msg Received 5
> Mailbox foo contains: ['test0', 'test1', 'test2', 'test3']
> Msg Accepted.
> remote disposition for post-deliver-5: 0
> Driver sleep...
> ...Driver wakeup.
> Process Connector
> I/O processing start.
> Driver sleep...
> ...Driver wakeup.
> Process Connector
> ERROR amqp:connection:framing-error connection aborted
> error in process_input: PN_ERR
> I/O processing start.
> Driver sleep...
> ...Driver wakeup.
> Process Connector
> I/O processing start.
> Closing connector
> Driver sleep...
>
> In this case I sent five messages:
>
> test0 test1 test2 test3 test4
>
> If I drop or add any messages, it always sends through the very last
> message but then the server gives the same message after message n-1.
>
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org