David Martin created QPIDJMS-535:
------------------------------------
Summary: Looping failure after SASL negotiation with Artemis v2.16
Key: QPIDJMS-535
URL: https://issues.apache.org/jira/browse/QPIDJMS-535
Project: Qpid JMS
Issue Type: Bug
Affects Versions: 0.58.0
Reporter: David Martin
This is not a production issue for us so tagging it as minor. Encountered
during some destructive testing, killing brokers, clients, seeing that
connections re-establish ok.
It sometimes happens when re-establishing a connection to an artemis broker
hosted in kubernetes which has been recycled by deleting the pod.
{noformat}
2021-04-09 11:48:13.940 DEBUG 11152 --- [.84.10.4:30672]] proton.trace
: IN: CH[28] : Flow{nextIncomingId=1,
incomingWindow=2147483647, nextOutgoingId=1, outgoingWindow=2147483647,
handle=0, deliveryCount=14000, linkCredit=0, available=null, drain=true,
echo=false, properties=null}
2021-04-09 11:48:14.278 INFO 11152 --- [.84.10.4:30672]]
o.a.qpid.jms.provider.amqp.AmqpProvider : Transport failed: An existing
connection was forcibly closed by the remote host
2021-04-09 11:48:14.324 DEBUG 11152 --- [.84.10.4:30672]]
io.netty.buffer.PoolThreadCache : Freed 18 thread-local buffer(s) from
thread: AmqpProvider :(1):[amqp://10.84.10.4:30672]
2021-04-09 11:48:36.778 DEBUG 11152 --- [.84.10.4:30672]]
o.a.qpid.jms.sasl.SaslMechanismFinder : Best match for SASL auth was:
SASL-PLAIN
2021-04-09 11:48:36.862 DEBUG 11152 --- [.84.10.4:30672]]
o.a.qpid.proton.engine.impl.SaslImpl : Handled outcome: SaslImpl
[_outcome=PN_SASL_OK, state=PN_SASL_PASS, done=true, role=CLIENT]
2021-04-09 11:48:36.936 DEBUG 11152 --- [.84.10.4:30672]] proton.trace
: IN: CH[0] : Open{ containerId='', hostname='null',
maxFrameSize=131072, channelMax=65535, idleTimeOut=null, outgoingLocales=null,
incomingLocales=null, offeredCapabilities=null, desiredCapabilities=null,
properties={amqp:connection-establishment-failed=true}}
2021-04-09 11:48:36.937 DEBUG 11152 --- [.84.10.4:30672]] proton.trace
: IN: CH[0] :
Close{error=Error{condition=amqp:invalid-field, description='null',
info={invalid-field=container-id}}}
2021-04-09 11:48:36.940 DEBUG 11152 --- [.84.10.4:30672]]
io.netty.buffer.PoolThreadCache : Freed 3 thread-local buffer(s) from
thread: AmqpProvider :(3):[amqp://10.84.10.4:30672]
2021-04-09 11:48:37.128 DEBUG 11152 --- [.84.10.4:30672]]
o.a.qpid.jms.sasl.SaslMechanismFinder : Best match for SASL auth was:
SASL-PLAIN
2021-04-09 11:48:37.200 DEBUG 11152 --- [.84.10.4:30672]]
o.a.qpid.proton.engine.impl.SaslImpl : Handled outcome: SaslImpl
[_outcome=PN_SASL_OK, state=PN_SASL_PASS, done=true, role=CLIENT]
2021-04-09 11:48:37.274 DEBUG 11152 --- [.84.10.4:30672]] proton.trace
: IN: CH[0] : Open{ containerId='', hostname='null',
maxFrameSize=131072, channelMax=65535, idleTimeOut=null, outgoingLocales=null,
incomingLocales=null, offeredCapabilities=null, desiredCapabilities=null,
properties={amqp:connection-establishment-failed=true}}
2021-04-09 11:48:37.274 DEBUG 11152 --- [.84.10.4:30672]] proton.trace
: IN: CH[0] :
Close{error=Error{condition=amqp:invalid-field, description='null',
info={invalid-field=container-id}}}
2021-04-09 11:48:37.276 DEBUG 11152 --- [.84.10.4:30672]]
io.netty.buffer.PoolThreadCache : Freed 3 thread-local buffer(s) from
thread: AmqpProvider :(4):[amqp://10.84.10.4:30672]
2021-04-09 11:48:37.486 DEBUG 11152 --- [.84.10.4:30672]]
o.a.qpid.jms.sasl.SaslMechanismFinder : Best match for SASL auth was:
SASL-PLAIN
2021-04-09 11:48:37.557 DEBUG 11152 --- [.84.10.4:30672]]
o.a.qpid.proton.engine.impl.SaslImpl : Handled outcome: SaslImpl
[_outcome=PN_SASL_OK, state=PN_SASL_PASS, done=true, role=CLIENT]
2021-04-09 11:48:37.629 DEBUG 11152 --- [.84.10.4:30672]] proton.trace
: IN: CH[0] : Open{ containerId='', hostname='null',
maxFrameSize=131072, channelMax=65535, idleTimeOut=null, outgoingLocales=null,
incomingLocales=null, offeredCapabilities=null, desiredCapabilities=null,
properties={amqp:connection-establishment-failed=true}}
2021-04-09 11:48:37.629 DEBUG 11152 --- [.84.10.4:30672]] proton.trace
: IN: CH[0] :
Close{error=Error{condition=amqp:invalid-field, description='null',
info={invalid-field=container-id}}}
2021-04-09 11:48:37.631 DEBUG 11152 --- [.84.10.4:30672]]
io.netty.buffer.PoolThreadCache : Freed 3 thread-local buffer(s) from
thread: AmqpProvider :(5):[amqp://10.84.10.4:30672]
2021-04-09 11:48:37.875 DEBUG 11152 --- [.84.10.4:30672]]
o.a.qpid.jms.sasl.SaslMechanismFinder : Best match for SASL auth was:
SASL-PLAIN
2021-04-09 11:48:37.945 DEBUG 11152 --- [.84.10.4:30672]]
o.a.qpid.proton.engine.impl.SaslImpl : Handled outcome: SaslImpl
[_outcome=PN_SASL_OK, state=PN_SASL_PASS, done=true, role=CLIENT]
2021-04-09 11:48:38.015 DEBUG 11152 --- [.84.10.4:30672]] proton.trace
: IN: CH[0] : Open{ containerId='', hostname='null',
maxFrameSize=131072, channelMax=65535, idleTimeOut=null, outgoingLocales=null,
incomingLocales=null, offeredCapabilities=null, desiredCapabilities=null,
properties={amqp:connection-establishment-failed=true}}
2021
{noformat}
... and so on. Only restarting the client makes it reconnect. The connection is
non-SSL AMQP from a client in a pod to a broker in a pod. Using a Spring
CachingConnectionFactory with resetConnectionOnException enabled.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@qpid.apache.org
For additional commands, e-mail: dev-h...@qpid.apache.org
