[QPIDJMS-290] [Websocket] Receiving bytes message with more than 65347 bytes of content fails within the decoder

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 0.22.0
• Fix Version/s: 0.23.0
• Component/s: qpid-jms-client
• Assignee: Timothy A. Bish
• Reporter: Keith Wall
• Created: 01/May/17 18:51
• Updated: 16/May/17 14:08
• Resolved: 16/May/17 14:08

Description

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.

/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