Re: [VOTE] Release Apache Qpid protonj2 1.0.0-M20
On Mon, Mar 25, 2024 at 6:16 PM Timothy Bish wrote: > On 3/25/24 14:13, Timothy Bish wrote: > > Hi folks, > > > > I have put together a release candidate for a 1.0.0-M20 Qpid protonJ2 > > release, > > please give it a test out and vote accordingly. > > > > The source and binary archives can be grabbed from: > > https://dist.apache.org/repos/dist/dev/qpid/protonj2/1.0.0-M20-rc1/ > > > > The maven artifacts are also staged for now at: > > https://repository.apache.org/content/repositories/orgapacheqpid-1276 > > > > The JIRAs assigned are: > > > https://issues.apache.org/jira/secure/ReleaseNote.jspa?projectId=12313720&version=12354130 Not sure if I have a vote. However, + 1 from me. * Validated the source signature * Built from source and ran the tests * Tested message reception (my specific need) against the following (pre-configured queues) brokers: ** Azure Service Bus ** Azure Service Bus ( Over Websockets) ** RabbitMQ (3.13.0 (1.0 AMQP plugin enabled)) ** Apache ActiveMQ Artemis (2.33.0) ** Amazon's ActiveMQ (5.17.6) ** Amazon's ActiveMQ (5.17.6) (Over Websockets) * Checked connection retry semantics and idle timeouts now work as I expect. * Tested null bodies no longer poison my queues, which they don't.
Re: ProtonJ2 client handling of null message bodies
On Mon, Mar 18, 2024 at 8:50 PM Timothy Bish wrote: > This should now be fixed as part of: > https://issues.apache.org/jira/browse/PROTON-2809 Thanks Tim, I can confirm that to be the case on my side too! Appreciate you looking into it for me, thank you.
Re: Unexpected idle timeout behaviours
On Fri, Mar 15, 2024 at 8:03 PM Timothy Bish wrote: > > I'm glad you got to the bottom of it, thank you for bearing with me. I > can > > run a parallel compile for > > my purposes, but I was wondering if there is a planned release date for > M20 > > ? > > > > Thank you. > > > No planned date as someone keeps reporting issues. Was planning to > release something in a few weeks for protonj2 and proton-dotnet > > 😂 Sorry about that. You'll be glad to know I'm almost at the end of writing my test suite that covers the non application layer logic! Thank you for solving the underlying issue, it was a touch problematic!
Re: Unexpected idle timeout behaviours
> > > > > > This should be fixed no in: > > > > https://issues.apache.org/jira/browse/PROTON-2807 > > > > This essentially occurred because the Proton buffers were rewritten to > > allow zero copy semantics after the ingest code was written and the read > > offset is no longer reflective of the read outcome as the buffer may > > have handed off its underlying payload and have a size of zero which > > means the read offset will still be zero. This code was written in > > early days and had some safety checks in it that are no longer needed > > given other mechanics in place in the engine so has been updated to > > treat an non-empty buffer as cause to update the input sequence value. > > It's necessary to reproduce and explain the issues before making these > > changes so I needed to find a test case for this which I now have. > > I'm glad you got to the bottom of it, thank you for bearing with me. I can run a parallel compile for my purposes, but I was wondering if there is a planned release date for M20 ? Thank you.
Re: ProtonJ2 client handling of null message bodies
On Fri, Mar 15, 2024 at 6:14 PM Timothy Bish wrote:
> On 3/15/24 11:50, Ciaran wrote:
> > Hi,
> >
> > I'm attempting to build a resilient client using the protonj2 client and
> as
> > part of my testing I was checking that it would handle messages with null
> > bodies (specifically my client is only willing to work with strings or
> byte
> > arrays so it rejects any other AMQP message body type). However, when I
> put
> > a null body on the message (i.e. body length of 0), when I de-reference
> the
> > delivery's message's body property (e.g. delivery.message().body) I
> receive
> > an error from the proton engine:
>
> Can you capture a frame trace, I need enough information to try and
> create an exact reproducer which can be aided with traces of the
> incoming frames to reverse engineer a test. I wouldn't expect and
> exception here and its likely something that was missed in the current
> test suite.
>
> Code snippets of the sender and receiver bits can help as well.
>
>
> Hi,
Please find below everything I think you've asked for, the real code is
somewhat distributed
across several different classes, but this should be pretty equivalent:
RECEIVER CODE
-
ConnectionOptions options = constructBasicConnectionOptions();
options.reconnectOptions()
.reconnectEnabled(true)
.useReconnectBackOff(true)
.reconnectDelay(5000)
.maxReconnectDelay(10240001)
.maxReconnectAttempts(12)
.warnAfterReconnectAttempts(1);
Client client= Client.create();
Connection connection = client.connect("host", 1234, options);
ReceiverOptions ro = new ReceiverOptions();
ro.autoAccept(false);
Receiver receiver = connection.openReceiver( "queue", ro )) {
Delivery delivery = receiver.tryReceive();
if( delivery != null ) {
Message message= delivery.message();
// Exception occurs here.
Object body= message.body();
}
SENDER CODE
---
final Client client = Client.create();
final ConnectionOptions options = new ConnectionOptions();
options.sslOptions().sslEnabled(true);
options.user("MY_USER");
options.password("MY_PASSWORD");
Connection connection = client.connect(serverHost, serverPort, options);
Sender sender = connection.openSender(address);
sender.send(Message.create((byte[])null));
FRAME TRACE
-> SASL:[269961536:0] AMQP,3,1,0,0
<- SASL:[269961536:0] AMQP,3,1,0,0
<- SASL:[269961536:0] SaslMechanisms{saslServerMechanisms=[MSSBCBS, PLAIN,
ANONYMOUS, EXTERNAL]}
19:36:21,633 WARN SaslMechanismSelector:130 - Caught exception while
trying to create SASL mechanism MSSBCBS: No Matching SASL Mechanism with
name: MSSBCBS
-> SASL:[269961536:0] SaslInit{mechanism=PLAIN,
initialResponse="\x00MY_USER\x00MY_PASSWORD"...(truncated), hostname='
MY_HOST.servicebus.windows.net'}
<- SASL:[269961536:0] SaslOutcome{code=OK, additionalData="Welcome!"}
-> AMQP:[269961536:0] AMQP,0,1,0,0
<- AMQP:[269961536:0] AMQP,0,1,0,0
-> AMQP:[269961536:0] Open{
containerId='ID:081fcabd-ac34-41b5-9bff-fe35d0cfbff1:1:2', hostname='
MY_HOST.servicebus.windows.net', maxFrameSize=65536, channelMax=65535,
idleTimeOut=6, outgoingLocales=null, incomingLocales=null,
offeredCapabilities=null, desiredCapabilities=[ANONYMOUS-RELAY],
properties=null}
-> AMQP:[269961536:0] Begin{remoteChannel=null, nextOutgoingId=0,
incomingWindow=1600, outgoingWindow=2147483647, handleMax=null,
offeredCapabilities=null, desiredCapabilities=null, properties=null}
-> AMQP:[269961536:0]
Attach{name='receiver-ID:081fcabd-ac34-41b5-9bff-fe35d0cfbff1:1:2:1:1',
handle=0, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST,
source=Source{address='testq', durable=NONE, expiryPolicy=LINK_DETACH,
timeout=0, dynamic=false, dynamicNodeProperties=null,
distributionMode=null, filter=null,
defaultOutcome=Modified{deliveryFailed=true, undeliverableHere=false,
messageAnnotations=null}, outcomes=[amqp:accepted:list, amqp:rejected:list,
amqp:released:list, amqp:modified:list], capabilities=null},
target=Target{address='testq', durable=NONE, expiryPolicy=SESSION_END,
timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null},
unsettled=null, incompleteUnsettled=null, initialDeliveryCount=null,
maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=null,
properties=null}
-> AMQP:[269961536:0] Flow{nextIncomingId=null, incomingWindow=1600,
nextOutgoingId=0, outgoingWindow=2147483647, handle=0, deliveryCount=null,
linkCredit=10, available=null, drain=false, echo=null, properties=null}
<- AMQP:[269961536:0] Open{
containerId='af1bcb999146429ea0a245db6affd5e4_G60', hostname='null',
maxFrameSize=65536, channelMax=4999, idleTimeOut=12,
outgoingLocales=null, incomingLocales=null, offeredCapabilities=null,
desiredCapabiliti
ProtonJ2 client handling of null message bodies
Hi, I'm attempting to build a resilient client using the protonj2 client and as part of my testing I was checking that it would handle messages with null bodies (specifically my client is only willing to work with strings or byte arrays so it rejects any other AMQP message body type). However, when I put a null body on the message (i.e. body length of 0), when I de-reference the delivery's message's body property (e.g. delivery.message().body) I receive an error from the proton engine: Caused by: org.apache.qpid.protonj2.client.exceptions.ClientException: Index 1 out of bounds for length 1 at org.apache.qpid.protonj2.client.impl.ClientExceptionSupport.createNonFatalOrPassthrough( ClientExceptionSupport.java:103) at org.apache.qpid.protonj2.client.impl.ClientMessageSupport.decodeMessage( ClientMessageSupport.java:170) at org.apache.qpid.protonj2.client.impl.ClientMessageSupport.decodeMessage( ClientMessageSupport.java:152) at org.apache.qpid.protonj2.client.impl.ClientDelivery.message( ClientDelivery.java:79) at com.thisisnumero.smartagent.gateway.inbound.sources.background.amqp.AMQPMessageConsumerImpl.internalConsumeMessages( AMQPMessageConsumerImpl.java:53) ... 4 more Caused by: java.lang.ArrayIndexOutOfBoundsException: Index 1 out of bounds for length 1 at org.apache.qpid.protonj2.buffer.impl.ProtonCompositeBufferImpl.findChunkWithIndex( ProtonCompositeBufferImpl.java:1530) at org.apache.qpid.protonj2.buffer.impl.ProtonCompositeBufferImpl.copyInto( ProtonCompositeBufferImpl.java:387) at org.apache.qpid.protonj2.codec.decoders.messaging.DataTypeDecoder.readValue( DataTypeDecoder.java:85) at org.apache.qpid.protonj2.codec.decoders.messaging.DataTypeDecoder.readValue( DataTypeDecoder.java:40) at org.apache.qpid.protonj2.codec.decoders.ProtonDecoder.readObject( ProtonDecoder.java:192) at org.apache.qpid.protonj2.client.impl.ClientMessageSupport.decodeMessage( ClientMessageSupport.java:168) ... 7 more My expectation from the comments on the 'body()' method is that I should expect it to return null in this scenario? Should I be trapping this exception and rejecting the messages to avoid poisoning my queue? (I was planning on rejecting them anyway, but it seems weird to have to catch the exception first.) For reference, I'm putting messages onto the queue with the following protonj2 calls: sender.send(Message.create((byte[])null)); sender.send(Message.create((*String*)null)); Thank you (and sorry for the bombardment of things)
Re: Unexpected idle timeout behaviours
>
>
>
> >
> > I've provided the full set of frames below, but if I'm interpreting
> > correctly the inputSequence property is not being incremented on receipt
> of
> > data which means that the deadline for hearing from the peer again is not
> > being suitably increased. (I can see the sequence increments and the
> > localdeadline is recalculated for the empty frames the peer sends, but
> not
> > for when there's actual data.)
>
> I've gone back through the client and engine code and did some testing
> and cannot reproduce any issue where the sequence tracking is not
> updated when incoming frames are read regardless of which frame they are.
>
> I fixed a minor issue where the Client is not configuring the idle
> timeout to half the set value as it says it will.
>
> Hi Tim,
Thank you for taking a look, but I'm still seeing the issue :( I've
cherry-picked the idle timeout commit
on top of M19 and it /may/ be a little better, but that still feels like
it's covering up an issue.
Forgive me, but I'm not deeply familiar with the protonj2 codebase, but it
seems logical to
me that the inputSequence is incremented whenever some data is received
from the peer.
I've attached another trace with additional logging to show the state of
ProtonEngine#ingest()
function. As I mentioned earlier, for Transfer frames the readOffset of the
input buffer
after fireRead has completed is 0, which the logic treats as a 'no
sequence' operation.
The interesting part, you may see below is that for each transfer there are
multiple (two)
calls to ingest, both returning 0 as the post fireRead value of the
readOffset. I presume this
is due to buffering and needing to fetch more data for this particular
frame type, so I can get my
head around the first of these reads being ignored as a sequence increment,
but it still feels to me that
the second (or presumably the very last one in the case of larger payloads)
should return a non-zero
value to trigger the sequence increment?
I'm not quite sure what the value of enforcing this logical sequence is as
it only appears to
be used as a 'liveness' indicator for the remote connection, does it matter
if it was a valid frame
returned?
Trace with additional logging of the variable state below:
<- AMQP:[1619358550:0] Open{
containerId='91791f32464449109b4136667ccaa3f7_G52', hostname='null',
maxFrameSize=65536, channelMax=4999, idleTimeOut=12,
outgoingLocales=null, incomingLocales=null, offeredCapabilities=null,
desiredCapabilities=null, properties=null}
startIndex:0, input.getReadOffset():71
inputSequence++
<- AMQP:[1619358550:0] Begin{remoteChannel=0, nextOutgoingId=1,
incomingWindow=5000, outgoingWindow=1600, handleMax=255,
offeredCapabilities=null, desiredCapabilities=null, properties=null}
startIndex:0, input.getReadOffset():34
inputSequence++
<- AMQP:[1619358550:0]
Attach{name='receiver-ID:ecec0184-d4d3-4fe8-b8ec-0b132b249368:1:2:1:1',
handle=0, role=SENDER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST,
source=Source{address='testq', durable=NONE, expiryPolicy=LINK_DETACH,
timeout=0, dynamic=false, dynamicNodeProperties=null,
distributionMode=null, filter=null,
defaultOutcome=Modified{deliveryFailed=true, undeliverableHere=false,
messageAnnotations=null}, outcomes=[amqp:accepted:list, amqp:rejected:list,
amqp:released:list, amqp:modified:list], capabilities=null},
target=Target{address='testq', durable=NONE, expiryPolicy=SESSION_END,
timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null},
unsettled=null, incompleteUnsettled=null, initialDeliveryCount=0,
maxMessageSize=18446744073709551615, offeredCapabilities=[SHARED-SUBS],
desiredCapabilities=null, properties=null}
startIndex:0, input.getReadOffset():258
inputSequence++
startIndex:0, input.getReadOffset():0
<- AMQP:[1619358550:0] Transfer{handle=0, deliveryId=0,
deliveryTag=DeliveryTag: {[56, 109, 70, 77, -127, -59, 8, 72, -120, 61, 85,
-116, 30, -125, -121, -112]}, messageFormat=0, settled=null, more=false,
rcvSettleMode=null, state=null, resume=null, aborted=null, batchable=true}
- "\x00Sp\xc0\x0a\x05@@pH\x19\x08\x00@C
\x00Sq\xc1$\x02\xa3\x10x-opt"...(truncated)
startIndex:0, input.getReadOffset():0
-> AMQP:[1619358550:0] Disposition{role=RECEIVER, first=0, last=0,
settled=true, state=Accepted{}, batchable=false}
// This should be sequence 8, but the idle process hasn't started yet to
log the previouls 1->7
6,49840930,49790947,0,7
6,49850947,49800960,7,7
6,49850947,49810971,7,7
6,49850947,49820983,7,7
6,49850947,49831000,7,7
<- AMQP:[1619358550:0] null
startIndex:0, input.getReadOffset():8
inputSequence++
6,49850947,49840986,7,8
startIndex:0, input.getReadOffset():0
<- AMQP:[1619358550:0] Transfer{handle=0, deliveryId=1,
deliveryTag=DeliveryTag: {[49, 19, -96, -3, -69, 76, -17, 73, -78, 78, 87,
-118, 63, -16, -104, 36]}, messageFormat=0, settled=null, more=false,
rcvSettleMode=null, state=null, resume=null, aborted=null, batchable=true}
- "\x00Sp\xc0\x0a\x05@@pH\x19\x08\x00@C
\x00Sq\xc1$\x02
Unexpected idle timeout behaviours
Hi,
I'm experiencing IdleTimeoutExceptions on my connections when I don't
believe I should. I've looked around and I can see that it is not uncommon
for people to misunderstand the AMQP timeout semantics, so this is quite
possible. However, viewing the frames and attaching a diagnostic logger to
the ProtonEngine.performReadCheck logic provides me with some information
that I don't understand.
I've provided the full set of frames below, but if I'm interpreting
correctly the inputSequence property is not being incremented on receipt of
data which means that the deadline for hearing from the peer again is not
being suitably increased. (I can see the sequence increments and the
localdeadline is recalculated for the empty frames the peer sends, but not
for when there's actual data.)
Pattern for logger on line 448 of ProtonEngine.java (
https://github.com/apache/qpid-protonj2/blob/226dedec2ee2b01da47b248d2a51330826ebf4cf/protonj2/src/main/java/org/apache/qpid/protonj2/engine/impl/ProtonEngine.java#L448)
is
localIdleTimeout, localIdleDeadline, currentTime, lastInputSequence,
inputSequence
-> SASL:[392574873:0] AMQP,3,1,0,0
6,0,813312359,0,0
<- SASL:[392574873:0] AMQP,3,1,0,0
<- SASL:[392574873:0] SaslMechanisms{saslServerMechanisms=[MSSBCBS, PLAIN,
ANONYMOUS, EXTERNAL]}
21:39:55,235 WARN SaslMechanismSelector:130 - Caught exception while
trying to create SASL mechanism MSSBCBS: No Matching SASL Mechanism with
name: MSSBCBS
-> SASL:[392574873:0] SaslInit{mechanism=PLAIN,
initialResponse="\x00MY_USERNAME\x00MY_PASSWORD"...(truncated), hostname='
MY_HOST.servicebus.windows.net'}
<- SASL:[392574873:0] SaslOutcome{code=OK, additionalData="Welcome!"}
-> AMQP:[392574873:0] AMQP,0,1,0,0
<- AMQP:[392574873:0] AMQP,0,1,0,0
-> AMQP:[392574873:0] Open{
containerId='ID:36f74f46-a99f-4b7a-93f4-bbe2c0d3c5b7:1:2', hostname='
MY_HOST.servicebus.windows.net', maxFrameSize=65536, channelMax=65535,
idleTimeOut=6, outgoingLocales=null, incomingLocales=null,
offeredCapabilities=null, desiredCapabilities=[ANONYMOUS-RELAY],
properties=null}
-> AMQP:[392574873:0] Begin{remoteChannel=null, nextOutgoingId=0,
incomingWindow=1600, outgoingWindow=2147483647, handleMax=null,
offeredCapabilities=null, desiredCapabilities=null, properties=null}
-> AMQP:[392574873:0]
Attach{name='receiver-ID:36f74f46-a99f-4b7a-93f4-bbe2c0d3c5b7:1:2:1:1',
handle=0, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST,
source=Source{address='testq', durable=NONE, expiryPolicy=LINK_DETACH,
timeout=0, dynamic=false, dynamicNodeProperties=null,
distributionMode=null, filter=null,
defaultOutcome=Modified{deliveryFailed=true, undeliverableHere=false,
messageAnnotations=null}, outcomes=[amqp:accepted:list, amqp:rejected:list,
amqp:released:list, amqp:modified:list], capabilities=null},
target=Target{address='testq', durable=NONE, expiryPolicy=SESSION_END,
timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null},
unsettled=null, incompleteUnsettled=null, initialDeliveryCount=null,
maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=null,
properties=null}
-> AMQP:[392574873:0] Flow{nextIncomingId=null, incomingWindow=1600,
nextOutgoingId=0, outgoingWindow=2147483647, handle=0, deliveryCount=null,
linkCredit=10, available=null, drain=false, echo=null, properties=null}
<- AMQP:[392574873:0] Open{
containerId='543d61c8107e4369acdcf4202219b2d1_G24', hostname='null',
maxFrameSize=65536, channelMax=4999, idleTimeOut=12,
outgoingLocales=null, incomingLocales=null, offeredCapabilities=null,
desiredCapabilities=null, properties=null}
<- AMQP:[392574873:0] Begin{remoteChannel=0, nextOutgoingId=1,
incomingWindow=5000, outgoingWindow=1600, handleMax=255,
offeredCapabilities=null, desiredCapabilities=null, properties=null}
<- AMQP:[392574873:0]
Attach{name='receiver-ID:36f74f46-a99f-4b7a-93f4-bbe2c0d3c5b7:1:2:1:1',
handle=0, role=SENDER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST,
source=Source{address='testq', durable=NONE, expiryPolicy=LINK_DETACH,
timeout=0, dynamic=false, dynamicNodeProperties=null,
distributionMode=null, filter=null,
defaultOutcome=Modified{deliveryFailed=true, undeliverableHere=false,
messageAnnotations=null}, outcomes=[amqp:accepted:list, amqp:rejected:list,
amqp:released:list, amqp:modified:list], capabilities=null},
target=Target{address='testq', durable=NONE, expiryPolicy=SESSION_END,
timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null},
unsettled=null, incompleteUnsettled=null, initialDeliveryCount=0,
maxMessageSize=18446744073709551615, offeredCapabilities=[SHARED-SUBS],
desiredCapabilities=null, properties=null}
6,813372359,813322376,0,7
6,813382376,813332388,7,7
6,813382376,813342400,7,7
6,813382376,813352413,7,7
6,813382376,813362430,7,7
<- AMQP:[392574873:0] null<--- Heartbeat from peer,
increments inputSequence and causes localIdleDeadline to be recalculated
6,813382376,813372416,7,8
6,813432416,813377410,8,8
6,813432416,813379
Re: ProtonJ2 Initial connection failure, reconnect logic
On Tue, Mar 12, 2024 at 8:42 PM Timothy Bish wrote: > On 3/12/24 16:25, Ciaran wrote: > > On Tue, Mar 12, 2024 at 7:13 PM Timothy Bish > wrote: > > > >> On 3/12/24 04:08, Ciaran wrote: > >>> On Mon, Mar 11, 2024 at 9:33 PM Timothy Bish > >> wrote: > >>>> The client re-connection logic treats a SASL authentication error as a > >>>> terminal state and will not continue reconnect attempts if it > receives a > >>>> SASL outcome that indicates anything other than a temporary failure > >>>> state so it should be stopping the reconnect if it was actually > failing > >>>> to authenticate. This is true on the first attempt as well as on > >>>> subsequent attempts to other hosts if you add more than one and it has > >>>> failed to reach any of the preceding hosts while attempt to recover > the > >>>> connection. > >>>> > >>>>From the error logs attached it doesn't appear as though SASL > >>>> authentication is your issue though, at least in so much as it isn't > >>>> logging anything indicating SASL authentication as the error. Instead > >>>> the connection appears to be failing because the remote has sent a > >>>> response to the Receiver attach that does not include the initial > >>>> delivery count value as required by the specification. > >>>> > >>>> You can capture more information about the AMQP frames being sent and > >>>> received by enabling frame tracing, see the docs for how to do that. > >>>> > >>>> > >>>> > >> > https://github.com/apache/qpid-protonj2/blob/main/protonj2-client-docs/Configuration.md#logging > >>>> > >>> Thanks for getting back to me so quickly Tim, please find below the > >> frames > >>> for a successful > >>> connection and an unsuccessful connection. My test has actually been to > >>> specify an invalid user if > >>> that's relevant. > >>> > >>> I can see in both cases that the SASL challenge completes successfully, > >>> which I appreciate is > >>> strange, but I would imagine Azure Service Bus is a common enough > broker > >>> target for the library? > >> So looking at the frame trace it is clear the connection is being > >> established as the SASL outcome is returned as 'OK' and then a normal > >> Open exchange occurs so from the client point of view a connection was > >> successfully made so any initial reconnect attempts option won't apply > >> here as the connection "succeeded". For the connection to fail with bad > >> credentials the SASL outcome would need to indicate a failure. > >> > >> The connection breaks at the point the attach response arrives and is > >> lacking the mandatory initial-delivery-count field as per the AMQP 1.0 > >> specification. > >> > >> > >> > http://docs.oasis-open.org/amqp/core/v1.0/os/amqp-core-transport-v1.0-os.html#type-attach > >> > >> It could be that the user you logged in as does not have read permission > >> and the server is trying to tell the client that the link will be closed > >> with an error condition in the Detach indicating that as the returned > >> response does not carry a source or target value (both are null) whereas > >> the sent Attach has an appropriate source and target value. If that is > >> what it is doing it gets it wrong as it omits the > >> 'initial-delivery-count' which is required for an Attach with the Role > >> of Sender (as per referenced spec above) regardless of the outcome of > >> the attach. > >> > >> Sorry, I think perhaps I've not explained myself well here, the user is > > correctly configured on Azure Service Bus. > > However, the fail case is where I provide an *invalid* (non-existant) > user > > or an *invalid* password. > > > > I can see that the SaSL challenges succeeds, and agree from a client > > perspective that this success is > > problematic when the credentials provided are invalid! I guess I'm > flagging > > that my configuration is not > > exotic, and Azure Service Bus is a fairly popular AMQP broker. > > As I pointed out the remote is telling the client that the connection > succeeded so from the client point of view there just isn't anything > that it can do here to know that your user doesn't exist. I'd say you > need to take this up with MS as there just isn't anything that can be > done here. > > > > If this is the desired behaviour of the client library when interacting > > with Azure, I'll stick with my work around, which is to create a > > connection & receiver with no reconnect semantics configured, check that > > connection succeeds, close it and then > > re-open with a retryable connection. > > > > P.S. Spotted a minor issue in the ReconnectOptions.java file and have > > submitted a pull request over on Github, > > confused the hell out of me for a while! > > - Cj. > > > > -- > Tim Bish > > > - > To unsubscribe, e-mail: users-unsubscr...@qpid.apache.org > For additional commands, e-mail: users-h...@qpid.apache.org Indeed, not a problem, I've a work-around in place! Thank you.
Re: ProtonJ2 Initial connection failure, reconnect logic
On Tue, Mar 12, 2024 at 7:13 PM Timothy Bish wrote: > On 3/12/24 04:08, Ciaran wrote: > > On Mon, Mar 11, 2024 at 9:33 PM Timothy Bish > wrote: > > > >> > >> The client re-connection logic treats a SASL authentication error as a > >> terminal state and will not continue reconnect attempts if it receives a > >> SASL outcome that indicates anything other than a temporary failure > >> state so it should be stopping the reconnect if it was actually failing > >> to authenticate. This is true on the first attempt as well as on > >> subsequent attempts to other hosts if you add more than one and it has > >> failed to reach any of the preceding hosts while attempt to recover the > >> connection. > >> > >> From the error logs attached it doesn't appear as though SASL > >> authentication is your issue though, at least in so much as it isn't > >> logging anything indicating SASL authentication as the error. Instead > >> the connection appears to be failing because the remote has sent a > >> response to the Receiver attach that does not include the initial > >> delivery count value as required by the specification. > >> > >> You can capture more information about the AMQP frames being sent and > >> received by enabling frame tracing, see the docs for how to do that. > >> > >> > >> > https://github.com/apache/qpid-protonj2/blob/main/protonj2-client-docs/Configuration.md#logging > >> > >> > > Thanks for getting back to me so quickly Tim, please find below the > frames > > for a successful > > connection and an unsuccessful connection. My test has actually been to > > specify an invalid user if > > that's relevant. > > > > I can see in both cases that the SASL challenge completes successfully, > > which I appreciate is > > strange, but I would imagine Azure Service Bus is a common enough broker > > target for the library? > > So looking at the frame trace it is clear the connection is being > established as the SASL outcome is returned as 'OK' and then a normal > Open exchange occurs so from the client point of view a connection was > successfully made so any initial reconnect attempts option won't apply > here as the connection "succeeded". For the connection to fail with bad > credentials the SASL outcome would need to indicate a failure. > > The connection breaks at the point the attach response arrives and is > lacking the mandatory initial-delivery-count field as per the AMQP 1.0 > specification. > > > http://docs.oasis-open.org/amqp/core/v1.0/os/amqp-core-transport-v1.0-os.html#type-attach > > It could be that the user you logged in as does not have read permission > and the server is trying to tell the client that the link will be closed > with an error condition in the Detach indicating that as the returned > response does not carry a source or target value (both are null) whereas > the sent Attach has an appropriate source and target value. If that is > what it is doing it gets it wrong as it omits the > 'initial-delivery-count' which is required for an Attach with the Role > of Sender (as per referenced spec above) regardless of the outcome of > the attach. > > Sorry, I think perhaps I've not explained myself well here, the user is correctly configured on Azure Service Bus. However, the fail case is where I provide an *invalid* (non-existant) user or an *invalid* password. I can see that the SaSL challenges succeeds, and agree from a client perspective that this success is problematic when the credentials provided are invalid! I guess I'm flagging that my configuration is not exotic, and Azure Service Bus is a fairly popular AMQP broker. If this is the desired behaviour of the client library when interacting with Azure, I'll stick with my work around, which is to create a connection & receiver with no reconnect semantics configured, check that connection succeeds, close it and then re-open with a retryable connection. P.S. Spotted a minor issue in the ReconnectOptions.java file and have submitted a pull request over on Github, confused the hell out of me for a while! - Cj.
Re: ProtonJ2 Initial connection failure, reconnect logic
On Mon, Mar 11, 2024 at 9:33 PM Timothy Bish wrote:
>
>
> The client re-connection logic treats a SASL authentication error as a
> terminal state and will not continue reconnect attempts if it receives a
> SASL outcome that indicates anything other than a temporary failure
> state so it should be stopping the reconnect if it was actually failing
> to authenticate. This is true on the first attempt as well as on
> subsequent attempts to other hosts if you add more than one and it has
> failed to reach any of the preceding hosts while attempt to recover the
> connection.
>
> From the error logs attached it doesn't appear as though SASL
> authentication is your issue though, at least in so much as it isn't
> logging anything indicating SASL authentication as the error. Instead
> the connection appears to be failing because the remote has sent a
> response to the Receiver attach that does not include the initial
> delivery count value as required by the specification.
>
> You can capture more information about the AMQP frames being sent and
> received by enabling frame tracing, see the docs for how to do that.
>
>
> https://github.com/apache/qpid-protonj2/blob/main/protonj2-client-docs/Configuration.md#logging
>
>
Thanks for getting back to me so quickly Tim, please find below the frames
for a successful
connection and an unsuccessful connection. My test has actually been to
specify an invalid user if
that's relevant.
I can see in both cases that the SASL challenge completes successfully,
which I appreciate is
strange, but I would imagine Azure Service Bus is a common enough broker
target for the library?
When the username is invalid:
-> SASL:[1793436274:0] AMQP,3,1,0,0
<- SASL:[1793436274:0] AMQP,3,1,0,0
<- SASL:[1793436274:0] SaslMechanisms{saslServerMechanisms=[MSSBCBS, PLAIN,
ANONYMOUS, EXTERNAL]}
-> SASL:[1793436274:0] SaslInit{mechanism=PLAIN,
initialResponse="\x00INVALID_USERNAME\x00VALID_PASSWORD"...(truncated),
hostname='MY_HOST.servicebus.windows.net'}
<- SASL:[1793436274:0] SaslOutcome{code=OK, additionalData="Welcome!"}
-> AMQP:[1793436274:0] AMQP,0,1,0,0
<- AMQP:[1793436274:0] AMQP,0,1,0,0
-> AMQP:[1793436274:0] Open{
containerId='ID:c07c99d2-692b-4c77--b56bfeb2e2e0:1:1', hostname='
cjtestmq.servicebus.windows.net', maxFrameSize=65536, channelMax=65535,
idleTimeOut=6, outgoingLocales=null, incomingLocales=null,
offeredCapabilities=null, desiredCapabilities=[ANONYMOUS-RELAY],
properties=null}
-> AMQP:[1793436274:0] Begin{remoteChannel=null, nextOutgoingId=0,
incomingWindow=1600, outgoingWindow=2147483647, handleMax=null,
offeredCapabilities=null, desiredCapabilities=null, properties=null}
-> AMQP:[1793436274:0]
Attach{name='receiver-ID:c07c99d2-692b-4c77--b56bfeb2e2e0:1:1:1:1',
handle=0, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST,
source=Source{address='testq', durable=NONE, expiryPolicy=LINK_DETACH,
timeout=0, dynamic=false, dynamicNodeProperties=null,
distributionMode=null, filter=null,
defaultOutcome=Modified{deliveryFailed=true, undeliverableHere=false,
messageAnnotations=null}, outcomes=[amqp:accepted:list, amqp:rejected:list,
amqp:released:list, amqp:modified:list], capabilities=null},
target=Target{address='testq', durable=NONE, expiryPolicy=SESSION_END,
timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null},
unsettled=null, incompleteUnsettled=null, initialDeliveryCount=null,
maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=null,
properties=null}
-> AMQP:[1793436274:0] Flow{nextIncomingId=null, incomingWindow=1600,
nextOutgoingId=0, outgoingWindow=2147483647, handle=0, deliveryCount=null,
linkCredit=10, available=null, drain=false, echo=null, properties=null}
<- AMQP:[1793436274:0] Open{
containerId='5ffc5786e5b94e6da195e4e1c4660dd8_G4', hostname='null',
maxFrameSize=65536, channelMax=4999, idleTimeOut=12,
outgoingLocales=null, incomingLocales=null, offeredCapabilities=null,
desiredCapabilities=null, properties=null}
<- AMQP:[1793436274:0] Begin{remoteChannel=0, nextOutgoingId=1,
incomingWindow=5000, outgoingWindow=1600, handleMax=255,
offeredCapabilities=null, desiredCapabilities=null, properties=null}
<- AMQP:[1793436274:0]
Attach{name='receiver-ID:c07c99d2-692b-4c77--b56bfeb2e2e0:1:1:1:1',
handle=0, role=SENDER, sndSettleMode=null, rcvSettleMode=null, source=null,
target=null, unsettled=null, incompleteUnsettled=null,
initialDeliveryCount=null, maxMessageSize=null, offeredCapabilities=null,
desiredCapabilities=null, properties=null}
-> AMQP:[1793436274:0] Close{error=Error{condition=null,
description='Sending peer attach had no initial delivery count', info=null}}
07:53:20,966 WARN ClientTransportListener:63 - Caught problem during
incoming data processing: Sending peer attach had no initial delivery count
For reference, when the username is valid:
-> SASL:[1793436274:0] AMQP,3,1,0,0
<- SASL:[1793436274:0] AMQP,3,1,0,0
<- SASL:[1793436274:0] SaslMechanisms{saslServerMechanisms=[MSSBCBS, PLAIN,
ANONYMOUS, EX
ProtonJ2 Initial connection failure, reconnect logic
Hi all,
I'm taking a look at using ProtonJ2 to talk to Azure Service Bus and I've
successfully gotten everything up and running, with and without websockets,
now I'm turning my attention to the 'unhappy path' of network drop-outs and
misconfigurations leading to connection failures.
Is it possible to have a behaviour where:
- If an initial connection fails, the error is immediately propagated
and background reconnect attempts are not attempted.
- If an initial connection was successful then background reconnect
attempts are attempted.
>From looking through the api docs and reading the code, I believed that
configuring the following would exhibit the behaviours described.
options.reconnectOptions().reconnectEnabled(true);
options.reconnectOptions().maxInitialConnectionAttempts(1);
options.reconnectOptions().useReconnectBackOff();
*However, when connecting to Azure Service Bus with a deliberately invalid
password, it appears as though the reconnect logic is continuing in the
background (exceptions spamming my log ), not aborting on first connection
attempt. *Is this the expected behaviour?
I took a brief look at the code and can see that 'connectionEstablished' in
the ClientConnection class is being called even though the connection can't
possibly succeed as the authentication is wrong, is that expected behaviour
of the internals?
I've tried to summarise the code I have below, I've removed error handling,
resource cleanup for clarity:
final String serverHost = "MY_HOST.servicebus.windows.net";
final int serverPort = 443;
final String address = "testq";
final String user = "MY_USER";
final String password= "MY_PASSWORD_BUT_INVALIDATED_FOR_THIS_TEST";
final boolean useSSL = true;
final boolean useWebSockets = true;
final Client client = Client.create();
ConnectionOptions options = new
ConnectionOptions().user(user).password(password);
options.sslOptions().sslEnabled(useSSL);
options.transportOptions().useWebSockets(useWebSockets);
options.transportOptions().webSocketPath("/$servicebus/websocket");
options.reconnectOptions().reconnectEnabled(true);
options.reconnectOptions().maxInitialConnectionAttempts(1);
options.reconnectOptions().useReconnectBackOff();
Connection connection = client.connect(serverHost, serverPort, options);
ReceiverOptions ro = new ReceiverOptions();
ro.autoAccept(false);
Receiver receiver = connection.openReceiver( address, ro);
My exception / warning logs are contained at the end of the email, the
second email repeats until a ClientOperationTimedOutException is thrown
with the message 'Link open timed out waiting for remote to respond'.
Obviously, I could seperate the code into one client that does not have
reconnect logic enabled to determine if a connection is even *possible*
before engaging my proper client, but it seemed like the API offerred the
behaviour I was after?
Thank you for your patience if you made it this far
- Cj.
Exception / logs below ---
20:49:52,348 WARN SaslMechanismSelector:130 - Caught exception while
trying to create SASL mechanism MSSBCBS: No Matching SASL Mechanism with
name: MSSBCBS
20:49:52,652 WARN ClientTransportListener:63 - Caught problem during
incoming data processing: Sending peer attach had no initial delivery count
org.apache.qpid.protonj2.engine.exceptions.EngineFailedException: Sending
peer attach had no initial delivery count
at
org.apache.qpid.protonj2.engine.exceptions.ProtonExceptionSupport.createFailedException(ProtonExceptionSupport.java:63)
at
org.apache.qpid.protonj2.engine.exceptions.ProtonExceptionSupport.createFailedException(ProtonExceptionSupport.java:31)
at
org.apache.qpid.protonj2.engine.impl.ProtonEngine.engineFailed(ProtonEngine.java:306)
at
org.apache.qpid.protonj2.engine.impl.ProtonEngine.ingest(ProtonEngine.java:271)
at
org.apache.qpid.protonj2.engine.impl.ProtonEngine.ingest(ProtonEngine.java:54)
at
org.apache.qpid.protonj2.client.impl.ClientTransportListener.transportRead(ClientTransportListener.java:59)
at
org.apache.qpid.protonj2.client.transport.netty4.TcpTransport$NettyDefaultHandler.dispatchReadBuffer(TcpTransport.java:522)
at
org.apache.qpid.protonj2.client.transport.netty4.WebSocketTransport$NettyWebSocketTransportHandler.channelRead0(WebSocketTransport.java:239)
at
io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:99)
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
at
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
at
io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:346)
at
io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:318)
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(Abs
