qpid-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Keith Wall (JIRA)" <j...@apache.org>
Subject [jira] [Comment Edited] (QPIDJMS-290) [Websocket] Receiving bytes message with more than 65347 bytes of content fails within the decoder
Date Mon, 15 May 2017 12:26:04 GMT

    [ https://issues.apache.org/jira/browse/QPIDJMS-290?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16010408#comment-16010408 ] 

Keith Wall edited comment on QPIDJMS-290 at 5/15/17 12:25 PM:
--------------------------------------------------------------

Apologies for not testing sooner, but I missed the JIRA update.

I am testing on Qpid JMS Client (master) with HelloWorld modified to send a BytesMessage with the Java Broker configured for plain websockets.   I am seeing two problems:

1) With a bytes payload of 32576 the client reports the following "tail closed" exception reported as warning.  The test seems to pass despite this.

{noformat}
objc[2871]: Class JavaLaunchHelper is implemented in both /Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/bin/java and /Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/libinstrument.dylib. One of the two will be used. Which one is undefined.
[1160904268:0] -> Open{ containerId='ID:36426f56-fe12-49bd-85ad-8707f3cb5835:1', hostname='localhost', maxFrameSize=1048576, channelMax=32767, idleTimeOut=30000, outgoingLocales=null, incomingLocales=null, offeredCapabilities=null, desiredCapabilities=[sole-connection-for-container], properties={product=QpidJMS, version=0.24.0-SNAPSHOT, platform=JVM: 1.8.0_131, 25.131-b11, Oracle Corporation, OS: Mac OS X, 10.11.6, x86_64}}
[1160904268:0] <- Open{ containerId='26621e27-52b7-4626-8db9-71a967e11eaf', hostname='null', maxFrameSize=262144, channelMax=255, idleTimeOut=0, outgoingLocales=null, incomingLocales=null, offeredCapabilities=[ANONYMOUS-RELAY, SHARED-SUBS], desiredCapabilities=null, properties={product=qpid, version=7.0.0-SNAPSHOT, qpid.build=, qpid.instance_name=Broker}}
[1160904268:0] -> Begin{remoteChannel=null, nextOutgoingId=1, incomingWindow=2047, outgoingWindow=2147483647, handleMax=65535, offeredCapabilities=null, desiredCapabilities=null, properties=null}
[1160904268:0] <- Begin{remoteChannel=0, nextOutgoingId=0, incomingWindow=8192, outgoingWindow=2048, handleMax=4294967295, offeredCapabilities=null, desiredCapabilities=null, properties=null}
[1160904268:1] -> Begin{remoteChannel=null, nextOutgoingId=1, incomingWindow=2047, outgoingWindow=2147483647, handleMax=65535, offeredCapabilities=null, desiredCapabilities=null, properties=null}
[1160904268:1] <- Begin{remoteChannel=1, nextOutgoingId=0, incomingWindow=8192, outgoingWindow=2048, handleMax=4294967295, offeredCapabilities=null, desiredCapabilities=null, properties=null}
[1160904268:1] -> Attach{name='qpid-jms:sender:ID:71915654-e767-4baa-b2f4-e91da9e32117:1:1:1:queue', handle=0, role=SENDER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='ID:71915654-e767-4baa-b2f4-e91da9e32117:1:1:1', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=null, outcomes=[amqp:accepted:list, amqp:rejected:list, amqp:released:list, amqp:modified:list], capabilities=null}, target=Target{address='queue', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=[queue]}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=0, maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=[DELAYED_DELIVERY], properties=null}
[1160904268:1] <- Attach{name='qpid-jms:sender:ID:71915654-e767-4baa-b2f4-e91da9e32117:1:1:1:queue', handle=0, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='ID:71915654-e767-4baa-b2f4-e91da9e32117:1:1:1', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=null, outcomes=[amqp:accepted:list, amqp:rejected:list, amqp:released:list, amqp:modified:list], capabilities=null}, target=Target{address='queue', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=[REJECT_UNROUTABLE, DELAYED_DELIVERY]}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=null, maxMessageSize=null, offeredCapabilities=[REJECT_UNROUTABLE, DELAYED_DELIVERY], desiredCapabilities=null, properties={}}
[1160904268:1] <- Flow{nextIncomingId=1, incomingWindow=8192, nextOutgoingId=0, outgoingWindow=2048, handle=0, deliveryCount=0, linkCredit=20000, available=null, drain=false, echo=false, properties=null}
[1160904268:1] -> Attach{name='qpid-jms:receiver:ID:71915654-e767-4baa-b2f4-e91da9e32117:1:1:1:queue', handle=1, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='queue', durable=NONE, expiryPolicy=LINK_DETACH, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=Modified{deliveryFailed=true, undeliverableHere=null, messageAnnotations=null}, outcomes=[amqp:accepted:list, amqp:rejected:list, amqp:released:list, amqp:modified:list], capabilities=[queue]}, target=Target{address='null', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=null, maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=null, properties=null}
[1160904268:1] <- Attach{name='qpid-jms:receiver:ID:71915654-e767-4baa-b2f4-e91da9e32117:1:1:1:queue', handle=1, role=SENDER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='queue', durable=NONE, expiryPolicy=LINK_DETACH, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=null, outcomes=null, capabilities=[queue]}, target=Target{address='null', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=0, maxMessageSize=null, offeredCapabilities=[SHARED-SUBS], desiredCapabilities=null, properties={}}
[1160904268:1] -> Flow{nextIncomingId=0, incomingWindow=2047, nextOutgoingId=1, outgoingWindow=2147483647, handle=1, deliveryCount=0, linkCredit=1000, available=null, drain=false, echo=false, properties=null}
[1160904268:1] -> Transfer{handle=0, deliveryId=0, deliveryTag=0, messageFormat=0, settled=null, more=false, rcvSettleMode=null, state=null, resume=false, aborted=false, batchable=false} (32733) "\x00Sr\xc1)\x04\xa3\x0ex-opt-jms-destQ\x00\xa3\x12x-opt-jms-msg-typeQ\x03\x00Ss\xc0b\x0a\xa1/ID:71915654-e767-4baa-b2f4-e91da9e32117:1:1:1-1@\xa1\x05queue@@@\xa3\x18application/octet-stream@@\x83\x00\x00\x01\x5c\x0c\x0de}\x00Su\xb0\x00\x00\x7f@\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"...(truncated)
Done producing
[1160904268:1] <- Disposition{role=RECEIVER, first=0, last=0, settled=true, state=Accepted{}, batchable=false}
[1160904268:1] <- Transfer{handle=1, deliveryId=0, deliveryTag=\x00\x00\x00\x00\x00\x00\x00\x00, messageFormat=0, settled=null, more=false, rcvSettleMode=null, state=null, resume=false, aborted=false, batchable=false} (32733) "\x00Sr\xc1)\x04\xa3\x0ex-opt-jms-destQ\x00\xa3\x12x-opt-jms-msg-typeQ\x03\x00Ss\xc0b\x0a\xa1/ID:71915654-e767-4baa-b2f4-e91da9e32117:1:1:1-1@\xa1\x05queue@@@\xa3\x18application/octet-stream@@\x83\x00\x00\x01\x5c\x0c\x0de}\x00Su\xb0\x00\x00\x7f@\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"...(truncated)
[1160904268:0] -> Close{error=null}
JmsBytesMessage { org.apache.qpid.jms.provider.amqp.message.AmqpJmsBytesMessageFacade@224edc67 }
32576
2017-05-15 13:20:38,721 [localhost:5670]] - WARN  AmqpProvider                   - Caught problem during data processing: tail closed
org.apache.qpid.proton.engine.TransportException: tail closed
	at org.apache.qpid.proton.engine.impl.FrameParser.tail(FrameParser.java:508)
	at org.apache.qpid.proton.engine.impl.SaslImpl$SaslTransportWrapper.tail(SaslImpl.java:588)
	at org.apache.qpid.proton.engine.impl.HandshakeSniffingTransportWrapper.tail(HandshakeSniffingTransportWrapper.java:84)
	at org.apache.qpid.proton.engine.impl.TransportImpl.tail(TransportImpl.java:1473)
	at org.apache.qpid.proton.engine.impl.TransportImpl.getInputBuffer(TransportImpl.java:1435)
	at org.apache.qpid.jms.provider.amqp.AmqpProvider$18.run(AmqpProvider.java:778)
	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)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:748)
{noformat} 

With a bytes message payload of 65348, I see a hang. The producer's message never makes it to the Broker.

{noformat}
objc[2853]: Class JavaLaunchHelper is implemented in both /Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/bin/java and /Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/libinstrument.dylib. One of the two will be used. Which one is undefined.
[859661288:0] -> Open{ containerId='ID:3d0eb882-3a98-44c7-809a-5d90cd2db392:1', hostname='localhost', maxFrameSize=1048576, channelMax=32767, idleTimeOut=30000, outgoingLocales=null, incomingLocales=null, offeredCapabilities=null, desiredCapabilities=[sole-connection-for-container], properties={product=QpidJMS, version=0.24.0-SNAPSHOT, platform=JVM: 1.8.0_131, 25.131-b11, Oracle Corporation, OS: Mac OS X, 10.11.6, x86_64}}
[859661288:0] <- Open{ containerId='26621e27-52b7-4626-8db9-71a967e11eaf', hostname='null', maxFrameSize=262144, channelMax=255, idleTimeOut=0, outgoingLocales=null, incomingLocales=null, offeredCapabilities=[ANONYMOUS-RELAY, SHARED-SUBS], desiredCapabilities=null, properties={product=qpid, version=7.0.0-SNAPSHOT, qpid.build=, qpid.instance_name=Broker}}
[859661288:0] -> Begin{remoteChannel=null, nextOutgoingId=1, incomingWindow=2047, outgoingWindow=2147483647, handleMax=65535, offeredCapabilities=null, desiredCapabilities=null, properties=null}
[859661288:0] <- Begin{remoteChannel=0, nextOutgoingId=0, incomingWindow=8192, outgoingWindow=2048, handleMax=4294967295, offeredCapabilities=null, desiredCapabilities=null, properties=null}
[859661288:1] -> Begin{remoteChannel=null, nextOutgoingId=1, incomingWindow=2047, outgoingWindow=2147483647, handleMax=65535, offeredCapabilities=null, desiredCapabilities=null, properties=null}
[859661288:1] <- Begin{remoteChannel=1, nextOutgoingId=0, incomingWindow=8192, outgoingWindow=2048, handleMax=4294967295, offeredCapabilities=null, desiredCapabilities=null, properties=null}
[859661288:1] -> Attach{name='qpid-jms:sender:ID:9dfb6566-eff5-438d-9c00-1155e739bf27:1:1:1:queue', handle=0, role=SENDER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='ID:9dfb6566-eff5-438d-9c00-1155e739bf27:1:1:1', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=null, outcomes=[amqp:accepted:list, amqp:rejected:list, amqp:released:list, amqp:modified:list], capabilities=null}, target=Target{address='queue', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=[queue]}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=0, maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=[DELAYED_DELIVERY], properties=null}
[859661288:1] <- Attach{name='qpid-jms:sender:ID:9dfb6566-eff5-438d-9c00-1155e739bf27:1:1:1:queue', handle=0, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='ID:9dfb6566-eff5-438d-9c00-1155e739bf27:1:1:1', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=null, outcomes=[amqp:accepted:list, amqp:rejected:list, amqp:released:list, amqp:modified:list], capabilities=null}, target=Target{address='queue', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=[REJECT_UNROUTABLE, DELAYED_DELIVERY]}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=null, maxMessageSize=null, offeredCapabilities=[REJECT_UNROUTABLE, DELAYED_DELIVERY], desiredCapabilities=null, properties={}}
[859661288:1] <- Flow{nextIncomingId=1, incomingWindow=8192, nextOutgoingId=0, outgoingWindow=2048, handle=0, deliveryCount=0, linkCredit=20000, available=null, drain=false, echo=false, properties=null}
[859661288:1] -> Attach{name='qpid-jms:receiver:ID:9dfb6566-eff5-438d-9c00-1155e739bf27:1:1:1:queue', handle=1, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='queue', durable=NONE, expiryPolicy=LINK_DETACH, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=Modified{deliveryFailed=true, undeliverableHere=null, messageAnnotations=null}, outcomes=[amqp:accepted:list, amqp:rejected:list, amqp:released:list, amqp:modified:list], capabilities=[queue]}, target=Target{address='null', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=null, maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=null, properties=null}
[859661288:1] <- Attach{name='qpid-jms:receiver:ID:9dfb6566-eff5-438d-9c00-1155e739bf27:1:1:1:queue', handle=1, role=SENDER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='queue', durable=NONE, expiryPolicy=LINK_DETACH, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=null, outcomes=null, capabilities=[queue]}, target=Target{address='null', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=0, maxMessageSize=null, offeredCapabilities=[SHARED-SUBS], desiredCapabilities=null, properties={}}
[859661288:1] -> Flow{nextIncomingId=0, incomingWindow=2047, nextOutgoingId=1, outgoingWindow=2147483647, handle=1, deliveryCount=0, linkCredit=1000, available=null, drain=false, echo=false, properties=null}
[859661288:1] -> Transfer{handle=0, deliveryId=0, deliveryTag=0, messageFormat=0, settled=null, more=false, rcvSettleMode=null, state=null, resume=false, aborted=false, batchable=false} (65505) "\x00Sr\xc1)\x04\xa3\x0ex-opt-jms-destQ\x00\xa3\x12x-opt-jms-msg-typeQ\x03\x00Ss\xc0b\x0a\xa1/ID:9dfb6566-eff5-438d-9c00-1155e739bf27:1:1:1-1@\xa1\x05queue@@@\xa3\x18application/octet-stream@@\x83\x00\x00\x01\x5c\x0c\x09\x93S\x00Su\xb0\x00\x00\xffD\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"...(truncated)
Done producing
[859661288:0] <- Empty Frame
{noformat}

For this 65348  case, on the Broker, I see an empty {{onMessage}} call arrive from Jetty in the place where the transfer should be.  Client and Broker then start to exchange empty frames (heartbeating) but the transfer never arrives.

{noformat}  
2017-05-15 13:16:13,129 DEBUG [qtp1580504897-243] (o.a.q.s.p.frame) - SEND[/127.0.0.1:58701|1] : Attach{name=qpid-jms:receiver:ID:9dfb6566-eff5-438d-9c00-1155e739bf27:1:1:1:queue,handle=1,role=sender,sndSettleMode=unsettled,rcvSettleMode=first,source=Source{address=queue,durable=none,expiryPolicy=link-detach,dynamic=false,capabilities=[queue]},target=Target{},initialDeliveryCount=0,offeredCapabilities=[SHARED-SUBS],properties={}}
2017-05-15 13:16:13,130 DEBUG [qtp1580504897-243] (o.a.q.s.t.w.WebSocketProvider) - KWDEBUG Sending 166
2017-05-15 13:16:13,133 DEBUG [qtp1580504897-246] (o.a.q.s.t.w.WebSocketProvider) - KWDEBUG onMessage 35
2017-05-15 13:16:13,134 DEBUG [qtp1580504897-246] (o.a.q.s.p.frame) - RECV[/127.0.0.1:58701|1] : Flow{nextIncomingId=0,incomingWindow=2047,nextOutgoingId=1,outgoingWindow=2147483647,handle=1,deliveryCount=0,linkCredit=1000}
2017-05-15 13:16:13,176 DEBUG [qtp1580504897-247] (o.a.q.s.t.w.WebSocketProvider) - KWDEBUG onMessage 0
2017-05-15 13:16:28,134 DEBUG [qtp1580504897-293] (o.a.q.s.p.frame) - SEND[/127.0.0.1:58701|0] : <<HEARTBEAT>>
2017-05-15 13:16:28,135 DEBUG [qtp1580504897-293] (o.a.q.s.t.w.WebSocketProvider) - KWDEBUG Sending 8
{noformat}  




was (Author: k-wall):
Apologies, for not testing sooner, but I missed the JIRA update.

I am testing on Qpid JMS Client (master) with HelloWorld modified to send a BytesMessage with the Java Broker configured for plain websockets.   I am seeing two problems:

1) With a bytes payload of 32576 the client reports the following "tail closed" exception reported as warning.  The test seems to pass despite this.

{noformat}
objc[2871]: Class JavaLaunchHelper is implemented in both /Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/bin/java and /Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/libinstrument.dylib. One of the two will be used. Which one is undefined.
[1160904268:0] -> Open{ containerId='ID:36426f56-fe12-49bd-85ad-8707f3cb5835:1', hostname='localhost', maxFrameSize=1048576, channelMax=32767, idleTimeOut=30000, outgoingLocales=null, incomingLocales=null, offeredCapabilities=null, desiredCapabilities=[sole-connection-for-container], properties={product=QpidJMS, version=0.24.0-SNAPSHOT, platform=JVM: 1.8.0_131, 25.131-b11, Oracle Corporation, OS: Mac OS X, 10.11.6, x86_64}}
[1160904268:0] <- Open{ containerId='26621e27-52b7-4626-8db9-71a967e11eaf', hostname='null', maxFrameSize=262144, channelMax=255, idleTimeOut=0, outgoingLocales=null, incomingLocales=null, offeredCapabilities=[ANONYMOUS-RELAY, SHARED-SUBS], desiredCapabilities=null, properties={product=qpid, version=7.0.0-SNAPSHOT, qpid.build=, qpid.instance_name=Broker}}
[1160904268:0] -> Begin{remoteChannel=null, nextOutgoingId=1, incomingWindow=2047, outgoingWindow=2147483647, handleMax=65535, offeredCapabilities=null, desiredCapabilities=null, properties=null}
[1160904268:0] <- Begin{remoteChannel=0, nextOutgoingId=0, incomingWindow=8192, outgoingWindow=2048, handleMax=4294967295, offeredCapabilities=null, desiredCapabilities=null, properties=null}
[1160904268:1] -> Begin{remoteChannel=null, nextOutgoingId=1, incomingWindow=2047, outgoingWindow=2147483647, handleMax=65535, offeredCapabilities=null, desiredCapabilities=null, properties=null}
[1160904268:1] <- Begin{remoteChannel=1, nextOutgoingId=0, incomingWindow=8192, outgoingWindow=2048, handleMax=4294967295, offeredCapabilities=null, desiredCapabilities=null, properties=null}
[1160904268:1] -> Attach{name='qpid-jms:sender:ID:71915654-e767-4baa-b2f4-e91da9e32117:1:1:1:queue', handle=0, role=SENDER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='ID:71915654-e767-4baa-b2f4-e91da9e32117:1:1:1', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=null, outcomes=[amqp:accepted:list, amqp:rejected:list, amqp:released:list, amqp:modified:list], capabilities=null}, target=Target{address='queue', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=[queue]}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=0, maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=[DELAYED_DELIVERY], properties=null}
[1160904268:1] <- Attach{name='qpid-jms:sender:ID:71915654-e767-4baa-b2f4-e91da9e32117:1:1:1:queue', handle=0, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='ID:71915654-e767-4baa-b2f4-e91da9e32117:1:1:1', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=null, outcomes=[amqp:accepted:list, amqp:rejected:list, amqp:released:list, amqp:modified:list], capabilities=null}, target=Target{address='queue', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=[REJECT_UNROUTABLE, DELAYED_DELIVERY]}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=null, maxMessageSize=null, offeredCapabilities=[REJECT_UNROUTABLE, DELAYED_DELIVERY], desiredCapabilities=null, properties={}}
[1160904268:1] <- Flow{nextIncomingId=1, incomingWindow=8192, nextOutgoingId=0, outgoingWindow=2048, handle=0, deliveryCount=0, linkCredit=20000, available=null, drain=false, echo=false, properties=null}
[1160904268:1] -> Attach{name='qpid-jms:receiver:ID:71915654-e767-4baa-b2f4-e91da9e32117:1:1:1:queue', handle=1, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='queue', durable=NONE, expiryPolicy=LINK_DETACH, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=Modified{deliveryFailed=true, undeliverableHere=null, messageAnnotations=null}, outcomes=[amqp:accepted:list, amqp:rejected:list, amqp:released:list, amqp:modified:list], capabilities=[queue]}, target=Target{address='null', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=null, maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=null, properties=null}
[1160904268:1] <- Attach{name='qpid-jms:receiver:ID:71915654-e767-4baa-b2f4-e91da9e32117:1:1:1:queue', handle=1, role=SENDER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='queue', durable=NONE, expiryPolicy=LINK_DETACH, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=null, outcomes=null, capabilities=[queue]}, target=Target{address='null', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=0, maxMessageSize=null, offeredCapabilities=[SHARED-SUBS], desiredCapabilities=null, properties={}}
[1160904268:1] -> Flow{nextIncomingId=0, incomingWindow=2047, nextOutgoingId=1, outgoingWindow=2147483647, handle=1, deliveryCount=0, linkCredit=1000, available=null, drain=false, echo=false, properties=null}
[1160904268:1] -> Transfer{handle=0, deliveryId=0, deliveryTag=0, messageFormat=0, settled=null, more=false, rcvSettleMode=null, state=null, resume=false, aborted=false, batchable=false} (32733) "\x00Sr\xc1)\x04\xa3\x0ex-opt-jms-destQ\x00\xa3\x12x-opt-jms-msg-typeQ\x03\x00Ss\xc0b\x0a\xa1/ID:71915654-e767-4baa-b2f4-e91da9e32117:1:1:1-1@\xa1\x05queue@@@\xa3\x18application/octet-stream@@\x83\x00\x00\x01\x5c\x0c\x0de}\x00Su\xb0\x00\x00\x7f@\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"...(truncated)
Done producing
[1160904268:1] <- Disposition{role=RECEIVER, first=0, last=0, settled=true, state=Accepted{}, batchable=false}
[1160904268:1] <- Transfer{handle=1, deliveryId=0, deliveryTag=\x00\x00\x00\x00\x00\x00\x00\x00, messageFormat=0, settled=null, more=false, rcvSettleMode=null, state=null, resume=false, aborted=false, batchable=false} (32733) "\x00Sr\xc1)\x04\xa3\x0ex-opt-jms-destQ\x00\xa3\x12x-opt-jms-msg-typeQ\x03\x00Ss\xc0b\x0a\xa1/ID:71915654-e767-4baa-b2f4-e91da9e32117:1:1:1-1@\xa1\x05queue@@@\xa3\x18application/octet-stream@@\x83\x00\x00\x01\x5c\x0c\x0de}\x00Su\xb0\x00\x00\x7f@\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"...(truncated)
[1160904268:0] -> Close{error=null}
JmsBytesMessage { org.apache.qpid.jms.provider.amqp.message.AmqpJmsBytesMessageFacade@224edc67 }
32576
2017-05-15 13:20:38,721 [localhost:5670]] - WARN  AmqpProvider                   - Caught problem during data processing: tail closed
org.apache.qpid.proton.engine.TransportException: tail closed
	at org.apache.qpid.proton.engine.impl.FrameParser.tail(FrameParser.java:508)
	at org.apache.qpid.proton.engine.impl.SaslImpl$SaslTransportWrapper.tail(SaslImpl.java:588)
	at org.apache.qpid.proton.engine.impl.HandshakeSniffingTransportWrapper.tail(HandshakeSniffingTransportWrapper.java:84)
	at org.apache.qpid.proton.engine.impl.TransportImpl.tail(TransportImpl.java:1473)
	at org.apache.qpid.proton.engine.impl.TransportImpl.getInputBuffer(TransportImpl.java:1435)
	at org.apache.qpid.jms.provider.amqp.AmqpProvider$18.run(AmqpProvider.java:778)
	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)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:748)
{noformat} 

With a bytes message payload of 65348, I see a hang. The producer's message never makes it to the Broker.

{noformat}
objc[2853]: Class JavaLaunchHelper is implemented in both /Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/bin/java and /Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/libinstrument.dylib. One of the two will be used. Which one is undefined.
[859661288:0] -> Open{ containerId='ID:3d0eb882-3a98-44c7-809a-5d90cd2db392:1', hostname='localhost', maxFrameSize=1048576, channelMax=32767, idleTimeOut=30000, outgoingLocales=null, incomingLocales=null, offeredCapabilities=null, desiredCapabilities=[sole-connection-for-container], properties={product=QpidJMS, version=0.24.0-SNAPSHOT, platform=JVM: 1.8.0_131, 25.131-b11, Oracle Corporation, OS: Mac OS X, 10.11.6, x86_64}}
[859661288:0] <- Open{ containerId='26621e27-52b7-4626-8db9-71a967e11eaf', hostname='null', maxFrameSize=262144, channelMax=255, idleTimeOut=0, outgoingLocales=null, incomingLocales=null, offeredCapabilities=[ANONYMOUS-RELAY, SHARED-SUBS], desiredCapabilities=null, properties={product=qpid, version=7.0.0-SNAPSHOT, qpid.build=, qpid.instance_name=Broker}}
[859661288:0] -> Begin{remoteChannel=null, nextOutgoingId=1, incomingWindow=2047, outgoingWindow=2147483647, handleMax=65535, offeredCapabilities=null, desiredCapabilities=null, properties=null}
[859661288:0] <- Begin{remoteChannel=0, nextOutgoingId=0, incomingWindow=8192, outgoingWindow=2048, handleMax=4294967295, offeredCapabilities=null, desiredCapabilities=null, properties=null}
[859661288:1] -> Begin{remoteChannel=null, nextOutgoingId=1, incomingWindow=2047, outgoingWindow=2147483647, handleMax=65535, offeredCapabilities=null, desiredCapabilities=null, properties=null}
[859661288:1] <- Begin{remoteChannel=1, nextOutgoingId=0, incomingWindow=8192, outgoingWindow=2048, handleMax=4294967295, offeredCapabilities=null, desiredCapabilities=null, properties=null}
[859661288:1] -> Attach{name='qpid-jms:sender:ID:9dfb6566-eff5-438d-9c00-1155e739bf27:1:1:1:queue', handle=0, role=SENDER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='ID:9dfb6566-eff5-438d-9c00-1155e739bf27:1:1:1', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=null, outcomes=[amqp:accepted:list, amqp:rejected:list, amqp:released:list, amqp:modified:list], capabilities=null}, target=Target{address='queue', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=[queue]}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=0, maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=[DELAYED_DELIVERY], properties=null}
[859661288:1] <- Attach{name='qpid-jms:sender:ID:9dfb6566-eff5-438d-9c00-1155e739bf27:1:1:1:queue', handle=0, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='ID:9dfb6566-eff5-438d-9c00-1155e739bf27:1:1:1', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=null, outcomes=[amqp:accepted:list, amqp:rejected:list, amqp:released:list, amqp:modified:list], capabilities=null}, target=Target{address='queue', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=[REJECT_UNROUTABLE, DELAYED_DELIVERY]}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=null, maxMessageSize=null, offeredCapabilities=[REJECT_UNROUTABLE, DELAYED_DELIVERY], desiredCapabilities=null, properties={}}
[859661288:1] <- Flow{nextIncomingId=1, incomingWindow=8192, nextOutgoingId=0, outgoingWindow=2048, handle=0, deliveryCount=0, linkCredit=20000, available=null, drain=false, echo=false, properties=null}
[859661288:1] -> Attach{name='qpid-jms:receiver:ID:9dfb6566-eff5-438d-9c00-1155e739bf27:1:1:1:queue', handle=1, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='queue', durable=NONE, expiryPolicy=LINK_DETACH, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=Modified{deliveryFailed=true, undeliverableHere=null, messageAnnotations=null}, outcomes=[amqp:accepted:list, amqp:rejected:list, amqp:released:list, amqp:modified:list], capabilities=[queue]}, target=Target{address='null', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=null, maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=null, properties=null}
[859661288:1] <- Attach{name='qpid-jms:receiver:ID:9dfb6566-eff5-438d-9c00-1155e739bf27:1:1:1:queue', handle=1, role=SENDER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='queue', durable=NONE, expiryPolicy=LINK_DETACH, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=null, outcomes=null, capabilities=[queue]}, target=Target{address='null', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=0, maxMessageSize=null, offeredCapabilities=[SHARED-SUBS], desiredCapabilities=null, properties={}}
[859661288:1] -> Flow{nextIncomingId=0, incomingWindow=2047, nextOutgoingId=1, outgoingWindow=2147483647, handle=1, deliveryCount=0, linkCredit=1000, available=null, drain=false, echo=false, properties=null}
[859661288:1] -> Transfer{handle=0, deliveryId=0, deliveryTag=0, messageFormat=0, settled=null, more=false, rcvSettleMode=null, state=null, resume=false, aborted=false, batchable=false} (65505) "\x00Sr\xc1)\x04\xa3\x0ex-opt-jms-destQ\x00\xa3\x12x-opt-jms-msg-typeQ\x03\x00Ss\xc0b\x0a\xa1/ID:9dfb6566-eff5-438d-9c00-1155e739bf27:1:1:1-1@\xa1\x05queue@@@\xa3\x18application/octet-stream@@\x83\x00\x00\x01\x5c\x0c\x09\x93S\x00Su\xb0\x00\x00\xffD\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"...(truncated)
Done producing
[859661288:0] <- Empty Frame
{noformat}

For this 65348  case, on the Broker, I see an empty {{onMessage}} call arrive from Jetty in the place where the transfer should be.  Client and Broker then start to exchange empty frames (heartbeating) but the transfer never arrives.

{noformat}  
2017-05-15 13:16:13,129 DEBUG [qtp1580504897-243] (o.a.q.s.p.frame) - SEND[/127.0.0.1:58701|1] : Attach{name=qpid-jms:receiver:ID:9dfb6566-eff5-438d-9c00-1155e739bf27:1:1:1:queue,handle=1,role=sender,sndSettleMode=unsettled,rcvSettleMode=first,source=Source{address=queue,durable=none,expiryPolicy=link-detach,dynamic=false,capabilities=[queue]},target=Target{},initialDeliveryCount=0,offeredCapabilities=[SHARED-SUBS],properties={}}
2017-05-15 13:16:13,130 DEBUG [qtp1580504897-243] (o.a.q.s.t.w.WebSocketProvider) - KWDEBUG Sending 166
2017-05-15 13:16:13,133 DEBUG [qtp1580504897-246] (o.a.q.s.t.w.WebSocketProvider) - KWDEBUG onMessage 35
2017-05-15 13:16:13,134 DEBUG [qtp1580504897-246] (o.a.q.s.p.frame) - RECV[/127.0.0.1:58701|1] : Flow{nextIncomingId=0,incomingWindow=2047,nextOutgoingId=1,outgoingWindow=2147483647,handle=1,deliveryCount=0,linkCredit=1000}
2017-05-15 13:16:13,176 DEBUG [qtp1580504897-247] (o.a.q.s.t.w.WebSocketProvider) - KWDEBUG onMessage 0
2017-05-15 13:16:28,134 DEBUG [qtp1580504897-293] (o.a.q.s.p.frame) - SEND[/127.0.0.1:58701|0] : <<HEARTBEAT>>
2017-05-15 13:16:28,135 DEBUG [qtp1580504897-293] (o.a.q.s.t.w.WebSocketProvider) - KWDEBUG Sending 8
{noformat}  



> [Websocket] Receiving bytes message with more than 65347 bytes of content fails within the decoder
> --------------------------------------------------------------------------------------------------
>
>                 Key: QPIDJMS-290
>                 URL: https://issues.apache.org/jira/browse/QPIDJMS-290
>             Project: Qpid JMS
>          Issue Type: Bug
>          Components: qpid-jms-client
>    Affects Versions: 0.22.0
>            Reporter: Keith Wall
>            Assignee: Timothy Bish
>             Fix For: 0.23.0
>
>
> I am using the Qpid JMS Client's web socket implementation with Qpid Broker J. Testing current master for both components.
> I notice if the Qpid JMS Client receives a ByteMessage with bytes content greater than 65347 bytes, the client fails with the following frame size related exception.  The sending of the message is unaffected.
> I tried manually override the frame size in the connection url, but this made no improvement.
> The exception and proton-j output is below.
> Turning on proton-j trace, I notice that the pair have negotiated a larger frame size, but it appears that the client does not respect this for incoming frames.  
> {noformat}
> /Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/bin/java -agentlib:jdwp=transport=dt_socket,address=127.0.0.1:54406,suspend=y,server=n -Dfile.encoding=UTF-8 -classpath "/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/charsets.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/deploy.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/ext/cldrdata.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/ext/dnsns.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/ext/jaccess.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/ext/jfxrt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/ext/localedata.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/ext/nashorn.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/ext/sunec.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/ext/sunjce_provider.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/ext/sunpkcs11.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/ext/zipfs.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/javaws.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/jce.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/jfr.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/jfxswt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/jsse.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/management-agent.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/plugin.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/resources.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/rt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/lib/ant-javafx.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/lib/dt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/lib/javafx-mx.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/lib/jconsole.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/lib/packager.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/lib/sa-jdi.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/lib/tools.jar:/Users/keith/src/qpid-jms/qpid-jms-examples/target/classes:/Users/keith/src/qpid-jms/qpid-jms-client/target/classes:/Users/keith/.m2/repository/org/slf4j/slf4j-api/1.7.25/slf4j-api-1.7.25.jar:/Users/keith/.m2/repository/org/apache/geronimo/specs/geronimo-jms_2.0_spec/1.0-alpha-2/geronimo-jms_2.0_spec-1.0-alpha-2.jar:/Users/keith/.m2/repository/org/apache/qpid/proton-j/0.18.0/proton-j-0.18.0.jar:/Users/keith/.m2/repository/io/netty/netty-buffer/4.1.9.Final/netty-buffer-4.1.9.Final.jar:/Users/keith/.m2/repository/io/netty/netty-common/4.1.9.Final/netty-common-4.1.9.Final.jar:/Users/keith/.m2/repository/io/netty/netty-handler/4.1.9.Final/netty-handler-4.1.9.Final.jar:/Users/keith/.m2/repository/io/netty/netty-codec/4.1.9.Final/netty-codec-4.1.9.Final.jar:/Users/keith/.m2/repository/io/netty/netty-transport/4.1.9.Final/netty-transport-4.1.9.Final.jar:/Users/keith/.m2/repository/io/netty/netty-resolver/4.1.9.Final/netty-resolver-4.1.9.Final.jar:/Users/keith/.m2/repository/io/netty/netty-transport-native-epoll/4.1.9.Final/netty-transport-native-epoll-4.1.9.Final-linux-x86_64.jar:/Users/keith/.m2/repository/io/netty/netty-codec-http/4.1.9.Final/netty-codec-http-4.1.9.Final.jar:/Users/keith/.m2/repository/org/slf4j/slf4j-log4j12/1.7.25/slf4j-log4j12-1.7.25.jar:/Users/keith/.m2/repository/log4j/log4j/1.2.17/log4j-1.2.17.jar:/Applications/IntelliJ IDEA.app/Contents/lib/idea_rt.jar" org.apache.qpid.jms.example.HelloWS
> Connected to the target VM, address: '127.0.0.1:54406', transport: 'socket'
> [1835065327:0] -> Open{ containerId='ID:c904232b-c36f-4208-87bb-4283455670c6:1', hostname='default', maxFrameSize=1048576, channelMax=32767, idleTimeOut=30000, outgoingLocales=null, incomingLocales=null, offeredCapabilities=null, desiredCapabilities=[sole-connection-for-container], properties={product=QpidJMS, version=0.23.0-SNAPSHOT, platform=JVM: 1.8.0_131, 25.131-b11, Oracle Corporation, OS: Mac OS X, 10.12.4, x86_64}}
> [1835065327:0] <- Open{ containerId='d619337c-7198-4ab3-9c72-60b2ad012179', hostname='null', maxFrameSize=262144, channelMax=255, idleTimeOut=0, outgoingLocales=null, incomingLocales=null, offeredCapabilities=[ANONYMOUS-RELAY, SHARED-SUBS], desiredCapabilities=null, properties={product=qpid, version=7.0.0-SNAPSHOT, qpid.build=e72ac287b51777d6be09f13bb541d2a60b2167e4, qpid.instance_name=Broker}}
> [1835065327:0] -> Begin{remoteChannel=null, nextOutgoingId=1, incomingWindow=2047, outgoingWindow=2147483647, handleMax=65535, offeredCapabilities=null, desiredCapabilities=null, properties=null}
> [1835065327:0] <- Begin{remoteChannel=0, nextOutgoingId=0, incomingWindow=8192, outgoingWindow=2048, handleMax=4294967295, offeredCapabilities=null, desiredCapabilities=null, properties=null}
> [1835065327:1] -> Begin{remoteChannel=null, nextOutgoingId=1, incomingWindow=2047, outgoingWindow=2147483647, handleMax=65535, offeredCapabilities=null, desiredCapabilities=null, properties=null}
> [1835065327:1] <- Begin{remoteChannel=1, nextOutgoingId=0, incomingWindow=8192, outgoingWindow=2048, handleMax=4294967295, offeredCapabilities=null, desiredCapabilities=null, properties=null}
> [1835065327:1] -> Attach{name='qpid-jms:sender:ID:66baff0e-d07c-4fd5-a8f3-7f2df806ed9d:1:1:1:Q1', handle=0, role=SENDER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='ID:66baff0e-d07c-4fd5-a8f3-7f2df806ed9d:1:1:1', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=null, outcomes=[amqp:accepted:list, amqp:rejected:list, amqp:released:list, amqp:modified:list], capabilities=null}, target=Target{address='Q1', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=[queue]}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=0, maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=[DELAYED_DELIVERY], properties=null}
> [1835065327:1] <- Attach{name='qpid-jms:sender:ID:66baff0e-d07c-4fd5-a8f3-7f2df806ed9d:1:1:1:Q1', handle=0, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='ID:66baff0e-d07c-4fd5-a8f3-7f2df806ed9d:1:1:1', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=null, outcomes=[amqp:accepted:list, amqp:rejected:list, amqp:released:list, amqp:modified:list], capabilities=null}, target=Target{address='Q1', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=[REJECT_UNROUTABLE, DELAYED_DELIVERY]}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=null, maxMessageSize=null, offeredCapabilities=[REJECT_UNROUTABLE, DELAYED_DELIVERY], desiredCapabilities=null, properties={}}
> [1835065327:1] <- Flow{nextIncomingId=1, incomingWindow=8192, nextOutgoingId=0, outgoingWindow=2048, handle=0, deliveryCount=0, linkCredit=20000, available=null, drain=false, echo=false, properties=null}
> [1835065327:1] -> Attach{name='qpid-jms:receiver:ID:66baff0e-d07c-4fd5-a8f3-7f2df806ed9d:1:1:1:Q1', handle=1, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='Q1', durable=NONE, expiryPolicy=LINK_DETACH, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=Modified{deliveryFailed=true, undeliverableHere=null, messageAnnotations=null}, outcomes=[amqp:accepted:list, amqp:rejected:list, amqp:released:list, amqp:modified:list], capabilities=[queue]}, target=Target{address='null', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=null, maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=null, properties=null}
> [1835065327:1] <- Attach{name='qpid-jms:receiver:ID:66baff0e-d07c-4fd5-a8f3-7f2df806ed9d:1:1:1:Q1', handle=1, role=SENDER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST, source=Source{address='Q1', durable=NONE, expiryPolicy=LINK_DETACH, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=null, outcomes=null, capabilities=[queue]}, target=Target{address='null', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=0, maxMessageSize=null, offeredCapabilities=[SHARED-SUBS], desiredCapabilities=null, properties={}}
> [1835065327:1] -> Flow{nextIncomingId=0, incomingWindow=2047, nextOutgoingId=1, outgoingWindow=2147483647, handle=1, deliveryCount=0, linkCredit=1000, available=null, drain=false, echo=false, properties=null}
> [1835065327:1] -> Transfer{handle=0, deliveryId=0, deliveryTag=0, messageFormat=0, settled=null, more=false, rcvSettleMode=null, state=null, resume=false, aborted=false, batchable=false} (65509) "\x00Sp\xc0\x02\x01A\x00Sr\xc1)\x04\xa3\x0ex-opt-jms-destQ\x00\xa3\x12x-opt-jms-msg-typeQ\x03\x00Ss\xc0_\x0a\xa1/ID:66baff0e-d07c-4fd5-a8f3-7f2df806ed9d:1:1:1-1@\xa1\x02Q1@@@\xa3\x18application/octet-stream@@\x83\x00\x00\x01[\xc5Ov\xfb\x00Su\xb0\x00\x00\xffD\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"...(truncated)
> [1835065327:1] <- Disposition{role=RECEIVER, first=0, last=0, settled=true, state=Accepted{}, batchable=false}
> Disconnected from the target VM, address: '127.0.0.1:54406', transport: 'socket'
> Connection ExceptionListener fired, exiting.
> javax.jms.JMSException: Max frame length of 65536 has been exceeded.
> 	at org.apache.qpid.jms.exceptions.JmsExceptionSupport.create(JmsExceptionSupport.java:85)
> 	at org.apache.qpid.jms.exceptions.JmsExceptionSupport.create(JmsExceptionSupport.java:107)
> 	at org.apache.qpid.jms.JmsConnection.onAsyncException(JmsConnection.java:1410)
> 	at org.apache.qpid.jms.JmsConnection.onProviderException(JmsConnection.java:1374)
> 	at org.apache.qpid.jms.JmsConnection.onConnectionFailure(JmsConnection.java:1242)
> 	at org.apache.qpid.jms.provider.amqp.AmqpProvider.fireProviderException(AmqpProvider.java:1045)
> 	at org.apache.qpid.jms.provider.amqp.AmqpProvider$19.run(AmqpProvider.java:818)
> 	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)
> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> 	at java.lang.Thread.run(Thread.java:748)
> Caused by: java.io.IOException: Max frame length of 65536 has been exceeded.
> 	at org.apache.qpid.jms.util.IOExceptionSupport.create(IOExceptionSupport.java:45)
> 	... 9 more
> Caused by: io.netty.handler.codec.CorruptedFrameException: Max frame length of 65536 has been exceeded.
> 	at io.netty.handler.codec.http.websocketx.WebSocket08FrameDecoder.protocolViolation(WebSocket08FrameDecoder.java:412)
> 	at io.netty.handler.codec.http.websocketx.WebSocket08FrameDecoder.decode(WebSocket08FrameDecoder.java:277)
> 	at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:411)
> 	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:248)
> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
> 	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
> 	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1334)
> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
> 	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
> 	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:926)
> 	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:134)
> 	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:624)
> 	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:559)
> 	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:476)
> 	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:438)
> 	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
> 	at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:144)
> 	... 1 more
> Process finished with exit code 1
> {noformat}



--
This message was sent by Atlassian JIRA
(v6.3.15#6346)

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


Mime
View raw message