You are viewing a plain text version of this content. The canonical link for it is here.
Posted to proton@qpid.apache.org by Tomáš Šoltys <to...@gmail.com> on 2015/09/16 14:04:57 UTC
Error detection/handling
Hi,
I have a client that sends a messages to broker. It can happen that message
contains incorrect subject which will trigger ACL deny on the broker.
But on the client side everything seems to be OK.
How do I detect such errors?
Regards,
Tomas
Re: Error detection/handling
Posted by Gordon Sim <gs...@redhat.com>.
On 09/17/2015 08:37 AM, Tomáš Šoltys wrote:
> Here is an output from the broker when trace+ is enabled on protocol level.
Thanks! This looks like the same root cause as
https://issues.apache.org/jira/browse/QPID-6660, which is now fixed on
trunk (but didn't make it into the 0.34 release)
> Scenario:
> send 1 message with incorrect subject and afterwards send 3 messages with
> correct subject.
> 3 messages will get delivered to the queue.
I've confirmed that on trunk, the messages after the one barred by acl
do *not* get enqueued.
Re: Error detection/handling
Posted by Tomáš Šoltys <to...@gmail.com>.
Hi Gordon,
thanks a lot for help. Condition gives exactly what I needs.
Here is an output from the broker when trace+ is enabled on protocol level.
Scenario:
send 1 message with incorrect subject and afterwards send 3 messages with
correct subject.
3 messages will get delivered to the queue.
---------------------------------------------------------------------------------------------------------------------------------------------
2015-09-17 09:28:14 [Network] info Set TCP_NODELAY on connection to
172.16.81.5:61576
2015-09-17 09:28:14 [Broker] info Using AMQP 1.0 (with SASL layer)
2015-09-17 09:28:14 [Security] info SASL: Mechanism list: PLAIN DIGEST-MD5
CRAM-MD5
2015-09-17 09:28:14 [Protocol] debug
qpid.172.16.153.10:29999-172.16.81.5:61576 Sent SASL-MECHANISMS(PLAIN
DIGEST-MD5 CRAM-MD5) 50
2015-09-17 09:28:14 [Protocol] debug
qpid.172.16.153.10:29999-172.16.81.5:61576 writing protocol header: 1-0
2015-09-17 09:28:14 [Protocol] debug
qpid.172.16.153.10:29999-172.16.81.5:61576 Received SASL-INIT(PLAIN,
amqpsrv\x00amqpsrv\x00amqpsrv)
2015-09-17 09:28:14 [Security] info SASL: Starting authentication with
mechanism: PLAIN
2015-09-17 09:28:14 [Protocol] debug
qpid.172.16.153.10:29999-172.16.81.5:61576 Sent SASL-OUTCOME(0) 16
2015-09-17 09:28:14 [Security] info
qpid.172.16.153.10:29999-172.16.81.5:61576 Authenticated as amqpsrv@QPID9999
2015-09-17 09:28:14 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: -> AMQP
2015-09-17 09:28:14 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: <- AMQP
2015-09-17 09:28:14 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: 0 <- @open(16)
[container-id="reactor", hostname="172.16.153.10:29999",
max-frame-size=512, channel-max=32767, idle-time-out=500]
2015-09-17 09:28:14 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: 0 <- @begin(17)
[next-outgoing-id=0, incoming-window=2048, outgoing-window=2147483647]
2015-09-17 09:28:14 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: 0 <- @attach(18)
[name="broadcast", handle=0, role=false, snd-settle-mode=2,
rcv-settle-mode=0, source=@source(40) [address="broadcast", durable=0,
timeout=0, dynamic=false], target=@target(41) [address="broadcast",
durable=0, timeout=0, dynamic=false], initial-delivery-count=0]
2015-09-17 09:28:14 [Protocol] debug
qpid.172.16.153.10:29999-172.16.81.5:61576 link 0x2636830 attached on
0x26998b0
2015-09-17 09:28:14 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: 0 -> @open(16)
[container-id="a11b7eb6-efbb-4883-915d-bbe792589e51", idle-time-out=500,
properties={:product="qpid-cpp", :version="0.34", :platform="Linux", :host="
cbgd03.xeop.de"}]
2015-09-17 09:28:14 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: 0 -> @begin(17)
[remote-channel=0, next-outgoing-id=0, incoming-window=2147483647,
outgoing-window=0]
2015-09-17 09:28:14 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: 0 -> @attach(18)
[name="broadcast", handle=0, role=true, snd-settle-mode=2,
rcv-settle-mode=0, source=@source(40) [durable=0, timeout=0,
dynamic=false], target=@target(41) [address="broadcast", durable=0,
timeout=0, dynamic=false], initial-delivery-count=0]
2015-09-17 09:28:14 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: 0 -> @flow(19)
[next-incoming-id=0, incoming-window=2147483647, next-outgoing-id=0,
outgoing-window=0, handle=0, delivery-count=0, link-credit=500, drain=false]
2015-09-17 09:28:14 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: 0 -> (EMPTY FRAME)
2015-09-17 09:28:14 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: 0 <- (EMPTY FRAME)
2015-09-17 09:28:14 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: 0 <- @transfer(20) [handle=0,
delivery-id=0, delivery-tag=b"\x01\x00\x00\x00\x00\x00\x00\x00",
message-format=0, settled=true, more=false] (353)
"\x00Sp\xd0\x00\x00\x00\x0b\x00\x00\x00\x05BP\x04@BR
\x00\x00Ss\xd0\x00\x00\x00B\x00\x00\x00\x0d@
@\xa1\x09broadcast\xa1\x14ppp-broadcast.Public@S\x01@
@\x83\x00\x00\x00\x00\x00\x00\x00\x00\x83\x00\x00\x01O\xda4$\xde@R\x00@\x00Sw\xa0\xffHello
1\x00\x10\x00\x00\x00\x80k\xa3z\x01\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\xe8V\x85z\x01\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00$\x00\x00\x00\x00\x00\x00\x0e\x02\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xfd\x07\x00\x00\xf0V\x85z\x00\x00\x00\x00\x90\xdf\x0f\x00\xff\xff\xff\xff!\x04\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x98W\x85z\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xa0W\x85z\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x86E\x00\x00\x00\x00\x00\x00\x1a\x00\x00\x00\x00\x00\x00\x00>\x00\x01\x00\x00\x00\x00\x005\x00\x00\x00\x00\x00\x00\x00>\x00\x01\x00\x00\x00\x00\x00\x09\x82
\x08\x82 \x08\x82"... (truncated)
2015-09-17 09:28:14 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: 0 <- @transfer(20) [handle=0,
delivery-id=1, delivery-tag=b"\x02\x00\x00\x00\x00\x00\x00\x00",
message-format=0, settled=true, more=false] (349)
"\x00Sp\xd0\x00\x00\x00\x0b\x00\x00\x00\x05BP\x04@BR
\x00\x00Ss\xd0\x00\x00\x00>\x00\x00\x00\x0d@
@\xa1\x09broadcast\xa1\x10broadcast.Public@S\x02@
@\x83\x00\x00\x00\x00\x00\x00\x00\x00\x83\x00\x00\x01O\xda4%3@R\x00@\x00Sw\xa0\xffHello
2\x00\x10\x00\x00\x00\x80k\xa3z\x01\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\xe8V\x85z\x01\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00$\x00\x00\x00\x00\x00\x00\x0e\x02\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xfd\x07\x00\x00\xf0V\x85z\x00\x00\x00\x00\x90\xdf\x0f\x00\xff\xff\xff\xff!\x04\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x98W\x85z\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xa0W\x85z\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x86E\x00\x00\x00\x00\x00\x00\x1a\x00\x00\x00\x00\x00\x00\x00>\x00\x01\x00\x00\x00\x00\x005\x00\x00\x00\x00\x00\x00\x00>\x00\x01\x00\x00\x00\x00\x00\x09\x82
\x08\x82 \x08\x82>\x0"... (truncated)
2015-09-17 09:28:14 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: 0 <- @transfer(20) [handle=0,
delivery-id=2, delivery-tag=b"\x03\x00\x00\x00\x00\x00\x00\x00",
message-format=0, settled=true, more=false] (349)
"\x00Sp\xd0\x00\x00\x00\x0b\x00\x00\x00\x05BP\x04@BR
\x00\x00Ss\xd0\x00\x00\x00>\x00\x00\x00\x0d@
@\xa1\x09broadcast\xa1\x10broadcast.Public@S\x03@
@\x83\x00\x00\x00\x00\x00\x00\x00\x00\x83\x00\x00\x01O\xda4%\x97@R\x00@\x00Sw\xa0\xffHello
3\x00\x10\x00\x00\x00\x80k\xa3z\x01\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\xe8V\x85z\x01\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00$\x00\x00\x00\x00\x00\x00\x0e\x02\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xfd\x07\x00\x00\xf0V\x85z\x00\x00\x00\x00\x90\xdf\x0f\x00\xff\xff\xff\xff!\x04\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x98W\x85z\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xa0W\x85z\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x86E\x00\x00\x00\x00\x00\x00\x1a\x00\x00\x00\x00\x00\x00\x00>\x00\x01\x00\x00\x00\x00\x005\x00\x00\x00\x00\x00\x00\x00>\x00\x01\x00\x00\x00\x00\x00\x09\x82
\x08\x82 \x08\x82>\x0"... (truncated)
2015-09-17 09:28:14 [Security] info ACL Deny id:amqpsrv@QPID9999
action:publish ObjectType:exchange Name:broadcast
2015-09-17 09:28:14 [Protocol] error Error processing deliveries:
amqpsrv@QPID9999 cannot publish to broadcast with routing-key
ppp-broadcast.Public
(/builddir/build/BUILD/qpid-cpp-0.34/src/qpid/broker/amqp/Authorise.cpp:118)
2015-09-17 09:28:14 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: 0 -> @detach(22) [handle=0,
closed=true, error=@error(29) [condition=:"amqp:unauthorized-access",
description="amqpsrv@QPID9999 cannot publish to broadcast with routing-key
ppp-broadcast.Public
(/builddir/build/BUILD/qpid-cpp-0.34/src/qpid/broker/amqp/Authorise.cpp:118)"]]
2015-09-17 09:28:15 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: 0 <- (EMPTY FRAME)
2015-09-17 09:28:15 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: 0 <- @transfer(20) [handle=0,
delivery-id=3, delivery-tag=b"\x04\x00\x00\x00\x00\x00\x00\x00",
message-format=0, settled=true, more=false] (349)
"\x00Sp\xd0\x00\x00\x00\x0b\x00\x00\x00\x05BP\x04@BR
\x00\x00Ss\xd0\x00\x00\x00>\x00\x00\x00\x0d@
@\xa1\x09broadcast\xa1\x10broadcast.Public@S\x04@
@\x83\x00\x00\x00\x00\x00\x00\x00\x00\x83\x00\x00\x01O\xda4%\xfb@R\x00@\x00Sw\xa0\xffHello
4\x00\x10\x00\x00\x00\x80k\xa3z\x01\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\xe8V\x85z\x01\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00$\x00\x00\x00\x00\x00\x00\x0e\x02\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xfd\x07\x00\x00\xf0V\x85z\x00\x00\x00\x00\x90\xdf\x0f\x00\xff\xff\xff\xff!\x04\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x98W\x85z\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xa0W\x85z\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x86E\x00\x00\x00\x00\x00\x00\x1a\x00\x00\x00\x00\x00\x00\x00>\x00\x01\x00\x00\x00\x00\x005\x00\x00\x00\x00\x00\x00\x00>\x00\x01\x00\x00\x00\x00\x00\x09\x82
\x08\x82 \x08\x82>\x0"... (truncated)
2015-09-17 09:28:15 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: 0 <- @detach(22) [handle=0,
closed=true]
2015-09-17 09:28:15 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: 0 <- @close(24) []
2015-09-17 09:28:15 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: <- EOS
2015-09-17 09:28:15 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: 0 -> (EMPTY FRAME)
2015-09-17 09:28:15 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: 0 -> @close(24) []
2015-09-17 09:28:15 [Protocol] trace
[qpid.172.16.153.10:29999-172.16.81.5:61576]: -> EOS
2015-09-16 15:33 GMT+02:00 Gordon Sim <gs...@redhat.com>:
> On 09/16/2015 02:02 PM, Tomáš Šoltys wrote:
>
>> Thanks Gordon,
>>
>> I have already noticed that I am getting PN_LINK_REMOTE_CLOSE event type.
>> But I am not able to get any error.
>> pn_error_text(pn_link_error(pn_event_link(pEvent))) returns NULL.
>>
>
> Try pn_link_remote_condition & pn_condition_get_description instead of
> pn_link_error and pn_error_text.
>
> Other thing that I do not understand is, that after sending erroneous
>> message I am still able to send messages (this time with correct subject)
>> to broker without any problem and messages are delivered.
>>
>> I thought that event type PN_LINK_REMOTE_CLOSE indicated that link was on
>> remote side closed.
>>
>
> That does indeed sound odd. Do you have a protocol trace to hand?
>
>
--
Tomáš Šoltys
tomas.soltys@gmail.com
http://www.range-software.com
(+420) 776-843-663
Re: Error detection/handling
Posted by Gordon Sim <gs...@redhat.com>.
On 09/16/2015 02:02 PM, Tomáš Šoltys wrote:
> Thanks Gordon,
>
> I have already noticed that I am getting PN_LINK_REMOTE_CLOSE event type.
> But I am not able to get any error.
> pn_error_text(pn_link_error(pn_event_link(pEvent))) returns NULL.
Try pn_link_remote_condition & pn_condition_get_description instead of
pn_link_error and pn_error_text.
> Other thing that I do not understand is, that after sending erroneous
> message I am still able to send messages (this time with correct subject)
> to broker without any problem and messages are delivered.
>
> I thought that event type PN_LINK_REMOTE_CLOSE indicated that link was on
> remote side closed.
That does indeed sound odd. Do you have a protocol trace to hand?
Re: Error detection/handling
Posted by Tomáš Šoltys <to...@gmail.com>.
Thanks Gordon,
I have already noticed that I am getting PN_LINK_REMOTE_CLOSE event type.
But I am not able to get any error.
pn_error_text(pn_link_error(pn_event_link(pEvent))) returns NULL.
Other thing that I do not understand is, that after sending erroneous
message I am still able to send messages (this time with correct subject)
to broker without any problem and messages are delivered.
I thought that event type PN_LINK_REMOTE_CLOSE indicated that link was on
remote side closed.
2015-09-16 14:53 GMT+02:00 Gordon Sim <gs...@redhat.com>:
> On 09/16/2015 01:36 PM, Tomáš Šoltys wrote:
>
>> I'm using reactor API and the broker is c++ broker from qpid 0.34
>>
>
> In that case the broker closes the link with an error condition. So on the
> client you should be able to be notified of the error by handling the
> appropriate event. If you are using MessagingHandler you can do that by
> implementing on_link_closing() or on_link_error(). Otherwise you can
> implement on_link_remote_close().
>
>
>
--
Tomáš Šoltys
tomas.soltys@gmail.com
http://www.range-software.com
(+420) 776-843-663
Re: Error detection/handling
Posted by Gordon Sim <gs...@redhat.com>.
On 09/16/2015 01:36 PM, Tomáš Šoltys wrote:
> I'm using reactor API and the broker is c++ broker from qpid 0.34
In that case the broker closes the link with an error condition. So on
the client you should be able to be notified of the error by handling
the appropriate event. If you are using MessagingHandler you can do that
by implementing on_link_closing() or on_link_error(). Otherwise you can
implement on_link_remote_close().
Re: Error detection/handling
Posted by Tomáš Šoltys <to...@gmail.com>.
I'm using reactor API and the broker is c++ broker from qpid 0.34
2015-09-16 14:22 GMT+02:00 Gordon Sim <gs...@redhat.com>:
> On 09/16/2015 01:04 PM, Tomáš Šoltys wrote:
>
>> Hi,
>>
>> I have a client that sends a messages to broker. It can happen that
>> message
>> contains incorrect subject which will trigger ACL deny on the broker.
>> But on the client side everything seems to be OK.
>>
>> How do I detect such errors?
>>
>
> What API are you using? (And what broker, as the other important question
> is how the broker is indicating the issue to the client).
>
>
--
Tomáš Šoltys
tomas.soltys@gmail.com
http://www.range-software.com
(+420) 776-843-663
Re: Error detection/handling
Posted by Gordon Sim <gs...@redhat.com>.
On 09/16/2015 01:04 PM, Tomáš Šoltys wrote:
> Hi,
>
> I have a client that sends a messages to broker. It can happen that message
> contains incorrect subject which will trigger ACL deny on the broker.
> But on the client side everything seems to be OK.
>
> How do I detect such errors?
What API are you using? (And what broker, as the other important
question is how the broker is indicating the issue to the client).
Default error behavior in event-driven APIs (was Re: Error
detection/handling)
Posted by aconway <ac...@redhat.com>.
On Wed, 2015-09-16 at 14:04 +0200, Tomáš Šoltys wrote:
> Hi,
>
> I have a client that sends a messages to broker. It can happen that
> message
> contains incorrect subject which will trigger ACL deny on the broker.
> But on the client side everything seems to be OK.
>
> How do I detect such errors?
>
> Regards,
> Tomas
A different but related question: what should be the default error
handling behavior in an event-driven API?
The "silently ignore" option is just bad IMO. Telling people after
their applicaiton has malfunctioned but continued to run with bad data
that "hey didn't you have an on_*_error handler" is not friendly.
Composable event-driven APIs pose a challenge here. It's not really ok
to require at compile time that event handlers *must* have on_*_error
handlers, since it would be legit design to have one handler that
deliberately doesn't handle errors but is intended to be used with
another that does.
At runtime, when an error occurs it is possible to throw, raise, panic
or abort if no user handler takes care of it. I would argue that this
is better than silently ignoring it, on the "fail fast" principle. The
user *should* have error handlers, if not their program is incorrect
and it is better to crash than close your eyes and carry on down the
wrong path.
It would be much better to analyze the user's handlers and detect the
"no error handler" problem at the start of the event loop, but in
general that is tricky.
I would advocate that all bindings should throw/raise/panic/abort on an
unhandled error as a last line of defence, and we should add
better/earlier safeguards if we can come up with them
Cheers,
Alan.