Jiri Daněk created QPIDJMS-345:
----------------------------------
Summary: TransportException: AMQP SASL header mismatch value 0,
expecting 3. In state: HEADER4
Key: QPIDJMS-345
URL: https://issues.apache.org/jira/browse/QPIDJMS-345
Project: Qpid JMS
Issue Type: Bug
Components: qpid-jms-client
Affects Versions: 0.27.0
Reporter: Jiri Daněk
Priority: Minor
Attachments: failedqpidjmstests.txt
Reproducibility: I've been unable to reproduce this. I saw it once in a Travis
Build, which I restarted (log from it is attached). I tried running the tests
in a loop against Artemis 2.4.0 (RC1) and the tests always passed. Triggering
the Travis build repeatedly also did not result in a fail.
The Travis build in queston is
https://travis-ci.org/rh-messaging/cli-java/builds/297841655. Log on Travis was
overwritten by subsequent runs, it is attached to this issue.
What the test does is to send to queue, browse the queue and receive from the
queue. The error appeared after browsing and before receiving step.
Command to run in loop was
{noformat}
ret=0
while [[ ret -eq 0 ]]; do mvn package -pl :cli-qpid-jms -am; ret=$?; done
{noformat}
The Travis log is
{noformat}
[INFO] ------------------------------------------------------------------------
[INFO] Building cli-qpid-jms 1.2.2-SNAPSHOT
[INFO] ------------------------------------------------------------------------
[INFO] Downloading:
http://repo.maven.apache.org/maven2/org/apache/qpid/qpid-jms-client/0.27.0/qpid-jms-client-0.27.0.pom
[INFO] Downloaded:
http://repo.maven.apache.org/maven2/org/apache/qpid/qpid-jms-client/0.27.0/qpid-jms-client-0.27.0.pom
(6.9 kB at 275 kB/s)
[INFO] Downloading:
http://repo.maven.apache.org/maven2/org/apache/qpid/proton-j/0.23.0/proton-j-0.23.0.pom
[INFO] Downloaded:
http://repo.maven.apache.org/maven2/org/apache/qpid/proton-j/0.23.0/proton-j-0.23.0.pom
(2.2 kB at 83 kB/s)
[INFO] Downloading:
http://repo.maven.apache.org/maven2/org/apache/qpid/proton-j-parent/0.23.0/proton-j-parent-0.23.0.pom
[INFO] Downloaded:
http://repo.maven.apache.org/maven2/org/apache/qpid/proton-j-parent/0.23.0/proton-j-parent-0.23.0.pom
(7.7 kB at 334 kB/s)
[INFO] Downloading:
http://repo.maven.apache.org/maven2/org/apache/qpid/qpid-jms-client/0.27.0/qpid-jms-client-0.27.0.jar
[INFO] Downloading:
http://repo.maven.apache.org/maven2/org/apache/qpid/proton-j/0.23.0/proton-j-0.23.0.jar
[INFO] Downloaded:
http://repo.maven.apache.org/maven2/org/apache/qpid/qpid-jms-client/0.27.0/qpid-jms-client-0.27.0.jar
(722 kB at 6.2 MB/s)
[INFO] Downloaded:
http://repo.maven.apache.org/maven2/org/apache/qpid/proton-j/0.23.0/proton-j-0.23.0.jar
(662 kB at 4.6 MB/s)
{noformat}
[...]
{noformat}
07:13:37.718Sending: {'address': 'lalaLand_rp5skalpii5kotuqg634lisj1d',
'group-id': None, 'subject': None, 'user-id': None, 'correlation-id': None,
'content-encoding': None, 'priority': 4, 'type': None, 'ttl': 0,
'absolute-expiry-time': 0, 'content': None, 'redelivered': False,
'reply-to-group-id': None, 'durable': True, 'delivery-time': 1509952418102,
'group-sequence': '0', 'creation-time': 1509952418102, 'content-type': None,
'id': '1f05308b-151a-4a3c-8ffc-adcb15e160cc:1:1:1-1', 'reply-to': None,
'properties': {'JMSXDeliveryCount': 1}}
Browsing: {'address': 'lalaLand_rp5skalpii5kotuqg634lisj1d', 'group-id': None,
'subject': None, 'user-id': None, 'correlation-id': None, 'content-encoding':
None, 'priority': 4, 'type': None, 'ttl': 0, 'absolute-expiry-time': 0,
'content': None, 'redelivered': False, 'reply-to-group-id': None, 'durable':
True, 'delivery-time': 1509952418102, 'group-sequence': '0', 'creation-time':
1509952418102, 'content-type': None, 'id':
'1f05308b-151a-4a3c-8ffc-adcb15e160cc:1:1:1-1', 'reply-to': None, 'properties':
{'JMSXDeliveryCount': 1}}
07:13:38,843 WARN
[org.apache.activemq.artemis.protocol.amqp.proton.handler.ProtonHandler] Sasl
can't be initiated after transport has started processing:
java.lang.IllegalStateException: Sasl can't be initiated after transport has
started processing
at
org.apache.qpid.proton.engine.impl.TransportImpl.sasl(TransportImpl.java:361)
[proton-j-0.22.0.jar:]
at
org.apache.activemq.artemis.protocol.amqp.proton.handler.ProtonHandler.createServerSASL(ProtonHandler.java:167)
[artemis-amqp-protocol-2.4.0-SNAPSHOT.jar:]
at
org.apache.activemq.artemis.protocol.amqp.proton.AMQPConnectionContext.onAuthInit(AMQPConnectionContext.java:304)
[artemis-amqp-protocol-2.4.0-SNAPSHOT.jar:]
at
org.apache.activemq.artemis.protocol.amqp.proton.handler.ProtonHandler.dispatchAuth(ProtonHandler.java:423)
[artemis-amqp-protocol-2.4.0-SNAPSHOT.jar:]
at
org.apache.activemq.artemis.protocol.amqp.proton.handler.ProtonHandler.inputBuffer(ProtonHandler.java:221)
[artemis-amqp-protocol-2.4.0-SNAPSHOT.jar:]
at
org.apache.activemq.artemis.protocol.amqp.proton.AMQPConnectionContext.inputBuffer(AMQPConnectionContext.java:150)
[artemis-amqp-protocol-2.4.0-SNAPSHOT.jar:]
at
org.apache.activemq.artemis.protocol.amqp.broker.ActiveMQProtonRemotingConnection.bufferReceived(ActiveMQProtonRemotingConnection.java:141)
[artemis-amqp-protocol-2.4.0-SNAPSHOT.jar:]
at
org.apache.activemq.artemis.core.remoting.server.impl.RemotingServiceImpl$DelegatingBufferHandler.bufferReceived(RemotingServiceImpl.java:642)
[artemis-server-2.4.0-SNAPSHOT.jar:2.4.0-SNAPSHOT]
at
org.apache.activemq.artemis.core.remoting.impl.netty.ActiveMQChannelHandler.channelRead(ActiveMQChannelHandler.java:68)
[artemis-core-client-2.4.0-SNAPSHOT.jar:2.4.0-SNAPSHOT]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
[netty-all-4.1.16.Final.jar:4.1.16.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
[netty-all-4.1.16.Final.jar:4.1.16.Final]
at
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
[netty-all-4.1.16.Final.jar:4.1.16.Final]
at
io.netty.handler.codec.ByteToMessageDecoder.handlerRemoved(ByteToMessageDecoder.java:236)
[netty-all-4.1.16.Final.jar:4.1.16.Final]
at
io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:494)
[netty-all-4.1.16.Final.jar:4.1.16.Final]
at
io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:428)
[netty-all-4.1.16.Final.jar:4.1.16.Final]
at
io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265)
[netty-all-4.1.16.Final.jar:4.1.16.Final]
at
org.apache.activemq.artemis.core.protocol.ProtocolHandler$ProtocolDecoder.channelRead(ProtocolHandler.java:124)
[artemis-server-2.4.0-SNAPSHOT.jar:2.4.0-SNAPSHOT]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
[netty-all-4.1.16.Final.jar:4.1.16.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
[netty-all-4.1.16.Final.jar:4.1.16.Final]
at
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
[netty-all-4.1.16.Final.jar:4.1.16.Final]
at
io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1359)
[netty-all-4.1.16.Final.jar:4.1.16.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
[netty-all-4.1.16.Final.jar:4.1.16.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
[netty-all-4.1.16.Final.jar:4.1.16.Final]
at
io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:935)
[netty-all-4.1.16.Final.jar:4.1.16.Final]
at
io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:797)
[netty-all-4.1.16.Final.jar:4.1.16.Final]
at
io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:404)
[netty-all-4.1.16.Final.jar:4.1.16.Final]
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:304)
[netty-all-4.1.16.Final.jar:4.1.16.Final]
at
io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
[netty-all-4.1.16.Final.jar:4.1.16.Final]
at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_131]
Receiving: 07:13:38,883 ERROR Failed to connect to remote at:
amqp://127.0.0.1:5672
07:13:38,884 ERROR org.apache.qpid.proton.engine.TransportException: AMQP SASL
header mismatch value 0, expecting 3. In state: HEADER4
javax.jms.JMSException: org.apache.qpid.proton.engine.TransportException: AMQP
SASL header mismatch value 0, expecting 3. In state: HEADER4
at
org.apache.qpid.jms.exceptions.JmsExceptionSupport.create(JmsExceptionSupport.java:86)
at
org.apache.qpid.jms.exceptions.JmsExceptionSupport.create(JmsExceptionSupport.java:108)
at org.apache.qpid.jms.JmsConnection.connect(JmsConnection.java:167)
at
org.apache.qpid.jms.JmsConnectionFactory.createConnection(JmsConnectionFactory.java:203)
at
org.apache.qpid.jms.JmsConnectionFactory.createConnection(JmsConnectionFactory.java:190)
at
com.redhat.mqe.jms.AacConnectionManager.<init>(AacConnectionManager.java:105)
at
com.redhat.mqe.jms.AacConnectionManagerFactory.make(AacConnectionManagerFactory.java:30)
at
com.redhat.mqe.jms.AacConnectionManagerFactory.make(AacConnectionManagerFactory.java:25)
at com.redhat.mqe.lib.CoreClient.createConnection(CoreClient.java:92)
at
com.redhat.mqe.lib.ReceiverClient.consumeMessage(ReceiverClient.java:157)
at
com.redhat.mqe.lib.ReceiverClient.startClient(ReceiverClient.java:133)
at com.redhat.mqe.lib.Main.main(Main.java:46)
at com.redhat.mqe.jms.Main.main(Main.java:29)
at AacMainTest.main(MainTest.kt:124)
at
AbstractMainTest$sendBrowseAndReceiveSingleMessage$1.execute(AbstractMainTest.kt:142)
at
org.junit.jupiter.api.AssertTimeout.lambda$assertTimeoutPreemptively$7(AssertTimeout.java:97)
at
org.junit.jupiter.api.AssertTimeout.lambda$assertTimeoutPreemptively$10(AssertTimeout.java:117)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.io.IOException:
org.apache.qpid.proton.engine.TransportException: AMQP SASL header mismatch
value 0, expecting 3. In state: HEADER4
at
org.apache.qpid.jms.util.IOExceptionSupport.create(IOExceptionSupport.java:45)
at
org.apache.qpid.jms.provider.ProviderFuture.failOnError(ProviderFuture.java:114)
at
org.apache.qpid.jms.provider.ProviderFuture.sync(ProviderFuture.java:91)
at
org.apache.qpid.jms.provider.amqp.AmqpProvider.connect(AmqpProvider.java:222)
at org.apache.qpid.jms.JmsConnection.connect(JmsConnection.java:155)
... 18 more
Caused by: org.apache.qpid.proton.engine.TransportException:
org.apache.qpid.proton.engine.TransportException: AMQP SASL header mismatch
value 0, expecting 3. In state: HEADER4
at
org.apache.qpid.proton.engine.TransportResultFactory$TransportResultImpl.checkIsOk(TransportResultFactory.java:116)
at
org.apache.qpid.jms.provider.amqp.AmqpProvider$17.run(AmqpProvider.java:784)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
... 3 more
Caused by: org.apache.qpid.proton.engine.TransportException: AMQP SASL header
mismatch value 0, expecting 3. In state: HEADER4
at
org.apache.qpid.proton.engine.impl.SaslFrameParser.input(SaslFrameParser.java:157)
at
org.apache.qpid.proton.engine.impl.SaslImpl$SaslTransportWrapper.reallyProcessInput(SaslImpl.java:636)
at
org.apache.qpid.proton.engine.impl.SaslImpl$SaslTransportWrapper.process(SaslImpl.java:607)
at
org.apache.qpid.proton.engine.impl.HandshakeSniffingTransportWrapper.process(HandshakeSniffingTransportWrapper.java:101)
at
org.apache.qpid.proton.engine.impl.TransportImpl.process(TransportImpl.java:1495)
at
org.apache.qpid.proton.engine.impl.TransportImpl.processInput(TransportImpl.java:1453)
... 8 more
Results :
{noformat}
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
