[
https://issues.apache.org/jira/browse/ARTEMIS-2707?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Robbie Gemmell updated ARTEMIS-2707:
------------------------------------
Description:
As first noted on ARTEMIS-2659, when sending larger AMQP messages using
multiple frames the broker can be seen to send the final message payload while
still indicating the message is not complete, and then send another empty (i.e
no payload) transfer frame to indicate the message delivery is actually already
complete.
A prior example was shown in ARTEMIS-2659. A fresh example below shows a 'full'
frame (itself unexpectedly small with 1024 payload bytes, see ARTEMIS-2706)
holding the penultimate payload, then a frame with the final payload content
but still indicating more=true incorrectly, then a last transfer with no
payload and indicating more=false.
{noformat}
[417713843:1] <- Transfer{handle=1, deliveryId=0, deliveryTag=\x00,
messageFormat=0, settled=false, more=true, rcvSettleMode=null, state=null,
resume=false, aborted=false, batchable=false} (1024)
"\xa3L&\x8eq3\xa7\x83\x87]\xc8\xb92N\xa1\xb4\xe2wg\x94"'\xb6\x8c\xd6\x93\x90\x1a\x9aB%j\xcb\x13\xef\x05\xa8I\xe5\xd5\x06\xc5\x9fH\x86\xa7\x17\xd4\xbd\xf16\xd2J\xdd\xf3\xc8\xa5z\xe6\xbf\x90\xbe\x89\x0e#\x98\xdd\xadY\x09\xaa\xb6BeA\x98J\xf5\xec\x81\xf0\xfa\xaf\xbfE\xcb~\xb9G\xa2!Z\xb9\xa2\x0d\xf2{P\x98\x90\xee\xf5r\xd9d.\x95\xfeg\xf6:\x1a\xef\xfb\xbaD\xb1\x07q\x15R\x9f\x83\x89\x0a\x0cC\xa2\x9bG\x05\xa7\xd6\xfe%R\xea\x18\x15\xa6BG"\x9e\xe5{\x0f\x92ge\xfbr\xdd\xfd\xad!\xd0rp\xd1\xaa\x8a\x08\xb7\x96.\xe2\xfb\x90\xeb\xe9>CV\x01kDT\x03\xdf(<\xe7\x17\xe0\xeb\x8dA\x1f\xb0G\x06\x8fJ\x00\x10\xa9\x97\xd9\xd5\xd5\xedU\x9f\xca\xbdT\x04\x97\xe3ZGL\xabr\xfd\x81\x00\xff\xb3\xf1\xca\x9d\xa5\xd38\x94\xa7\xaf\x17\xc7\xcf\x9f\xd8\x1d\xf6\x14\x80\xd9n\x11\xb0\xa4H\x0a\xeb\xfc\x85\xad\x8e\x82\x02q\xd0\x94\xbe{\x9b9\x17`Vw\x7f}\xb3@\xf0\x8a\xbea\x9eU\x12\x97b\xc6%\x0dX\x9d\x1d\xa4\xd5\xecq\xb46`\x9b\x06\x04\xd9\x97\xe8X\xfd\x08\x9fg\xffC\xd6r\xffF\xf5W\xee[)\x03\xacv\x83\x11\xfb\xb4~\xb8\x8aOGT\xa7\xd0w\xbe\xab\xe6\x08\x0cZ\x84\xf9"...(truncated)
[417713843:1] <- Transfer{handle=1, deliveryId=0, deliveryTag=\x00,
messageFormat=0, settled=false, more=true, rcvSettleMode=null, state=null,
resume=false, aborted=false, batchable=false} (176)
"_=\xfe\xd6p%0Z\x98?\x86\x07iZNfU\x1f\x9b\x11\x93\xca\xf7\xb1\xbd9\xbf$Q\xc5\xbd:\x00\xe9T\xe8T\xf1\xab\x03\x1a\x05\x1dza[u\x84\xd2\x9e0WT\x8e\x95\xc7\x5c8=\x80\xad\x02\x5c\xb0\x9f
\x0a\xaf}u\xe3\xd6\xaa'\x1a\x14\x94\xf3\x7f2\xb1\xc0\xf6L}\xb0\xf3h\xbf\x0e\xben>\xfeb\xcf\x881\xdc\xc1\xce,5\x81\xce\xd2\x94\x8c\xfaJ\xc0\x9d^\xc0s\x97\xa7u\xb0\x8e\x07$\x1bf~cY\xbb\xdc\xb6\x01\x12\xa0\xb8Y'\xa67#la\xea\xb4\xae\xa7:\x8f\xa5\xed-\xc23\xeah\xbe
l<\xe5\xe6\x9a \x8d\xf2t\xac\xd3\xe4ss\x90\xd2\x8f\xce\xc7\xe3"
[417713843:1] <- Transfer{handle=1, deliveryId=0, deliveryTag=\x00,
messageFormat=0, settled=false, more=false, rcvSettleMode=null, state=null,
resume=false, aborted=false, batchable=false}
[417713843:1] -> Disposition{role=RECEIVER, first=0, last=0, settled=true,
state=Accepted{}, batchable=false}
{noformat}
It is a legal protocol trace, but it should never really happen in a broker.
It suggests that the delivery send isnt being completed at the point the last
payload has been added, with the transport output then generated, and only
later is the delivery being indicated completed and further transport output
generated that sends the final transfer.
was:
As first noted on ARTEMIS-2659, when sending larger AMQP messages using
multiple frames the broker can be seen to send the final message payload while
still indicating the message is not complete, and then send another empty (i.e
no payload) transfer frame to indicate the message delivery is actually already
complete.
A prior example was shown in ARTEMIS-2659. A fresh example below shows a 'full'
frame (itself unexpectedly small with 1024 payload bytes, see ARTEMIS-2706)
holding the penultimate payload, then a frame with the final payload content
but still indicating more=true incorrectly, then a last transfer with no
payload and indicating more=false.
{normat}
[417713843:1] <- Transfer{handle=1, deliveryId=0, deliveryTag=\x00,
messageFormat=0, settled=false, more=true, rcvSettleMode=null, state=null,
resume=false, aborted=false, batchable=false} (1024)
"\xa3L&\x8eq3\xa7\x83\x87]\xc8\xb92N\xa1\xb4\xe2wg\x94"'\xb6\x8c\xd6\x93\x90\x1a\x9aB%j\xcb\x13\xef\x05\xa8I\xe5\xd5\x06\xc5\x9fH\x86\xa7\x17\xd4\xbd\xf16\xd2J\xdd\xf3\xc8\xa5z\xe6\xbf\x90\xbe\x89\x0e#\x98\xdd\xadY\x09\xaa\xb6BeA\x98J\xf5\xec\x81\xf0\xfa\xaf\xbfE\xcb~\xb9G\xa2!Z\xb9\xa2\x0d\xf2{P\x98\x90\xee\xf5r\xd9d.\x95\xfeg\xf6:\x1a\xef\xfb\xbaD\xb1\x07q\x15R\x9f\x83\x89\x0a\x0cC\xa2\x9bG\x05\xa7\xd6\xfe%R\xea\x18\x15\xa6BG"\x9e\xe5{\x0f\x92ge\xfbr\xdd\xfd\xad!\xd0rp\xd1\xaa\x8a\x08\xb7\x96.\xe2\xfb\x90\xeb\xe9>CV\x01kDT\x03\xdf(<\xe7\x17\xe0\xeb\x8dA\x1f\xb0G\x06\x8fJ\x00\x10\xa9\x97\xd9\xd5\xd5\xedU\x9f\xca\xbdT\x04\x97\xe3ZGL\xabr\xfd\x81\x00\xff\xb3\xf1\xca\x9d\xa5\xd38\x94\xa7\xaf\x17\xc7\xcf\x9f\xd8\x1d\xf6\x14\x80\xd9n\x11\xb0\xa4H\x0a\xeb\xfc\x85\xad\x8e\x82\x02q\xd0\x94\xbe{\x9b9\x17`Vw\x7f}\xb3@\xf0\x8a\xbea\x9eU\x12\x97b\xc6%\x0dX\x9d\x1d\xa4\xd5\xecq\xb46`\x9b\x06\x04\xd9\x97\xe8X\xfd\x08\x9fg\xffC\xd6r\xffF\xf5W\xee[)\x03\xacv\x83\x11\xfb\xb4~\xb8\x8aOGT\xa7\xd0w\xbe\xab\xe6\x08\x0cZ\x84\xf9"...(truncated)
[417713843:1] <- Transfer{handle=1, deliveryId=0, deliveryTag=\x00,
messageFormat=0, settled=false, more=true, rcvSettleMode=null, state=null,
resume=false, aborted=false, batchable=false} (176)
"_=\xfe\xd6p%0Z\x98?\x86\x07iZNfU\x1f\x9b\x11\x93\xca\xf7\xb1\xbd9\xbf$Q\xc5\xbd:\x00\xe9T\xe8T\xf1\xab\x03\x1a\x05\x1dza[u\x84\xd2\x9e0WT\x8e\x95\xc7\x5c8=\x80\xad\x02\x5c\xb0\x9f
\x0a\xaf}u\xe3\xd6\xaa'\x1a\x14\x94\xf3\x7f2\xb1\xc0\xf6L}\xb0\xf3h\xbf\x0e\xben>\xfeb\xcf\x881\xdc\xc1\xce,5\x81\xce\xd2\x94\x8c\xfaJ\xc0\x9d^\xc0s\x97\xa7u\xb0\x8e\x07$\x1bf~cY\xbb\xdc\xb6\x01\x12\xa0\xb8Y'\xa67#la\xea\xb4\xae\xa7:\x8f\xa5\xed-\xc23\xeah\xbe
l<\xe5\xe6\x9a \x8d\xf2t\xac\xd3\xe4ss\x90\xd2\x8f\xce\xc7\xe3"
[417713843:1] <- Transfer{handle=1, deliveryId=0, deliveryTag=\x00,
messageFormat=0, settled=false, more=false, rcvSettleMode=null, state=null,
resume=false, aborted=false, batchable=false}
[417713843:1] -> Disposition{role=RECEIVER, first=0, last=0, settled=true,
state=Accepted{}, batchable=false}
{noformat}
It is a legal protocol trace, but it should never really happen in a broker.
It suggests that the delivery send isnt being completed at the point the last
payload has been added, with the transport output then generated, and only
later is the delivery being indicated completed and further transport output
generated that sends the final transfer.
> last payload is sent indicating message incomplete, then empty final transfer
> sent to complete it
> -------------------------------------------------------------------------------------------------
>
> Key: ARTEMIS-2707
> URL: https://issues.apache.org/jira/browse/ARTEMIS-2707
> Project: ActiveMQ Artemis
> Issue Type: Bug
> Components: AMQP
> Affects Versions: 2.12.0
> Reporter: Robbie Gemmell
> Priority: Major
>
> As first noted on ARTEMIS-2659, when sending larger AMQP messages using
> multiple frames the broker can be seen to send the final message payload
> while still indicating the message is not complete, and then send another
> empty (i.e no payload) transfer frame to indicate the message delivery is
> actually already complete.
> A prior example was shown in ARTEMIS-2659. A fresh example below shows a
> 'full' frame (itself unexpectedly small with 1024 payload bytes, see
> ARTEMIS-2706) holding the penultimate payload, then a frame with the final
> payload content but still indicating more=true incorrectly, then a last
> transfer with no payload and indicating more=false.
> {noformat}
> [417713843:1] <- Transfer{handle=1, deliveryId=0, deliveryTag=\x00,
> messageFormat=0, settled=false, more=true, rcvSettleMode=null, state=null,
> resume=false, aborted=false, batchable=false} (1024)
> "\xa3L&\x8eq3\xa7\x83\x87]\xc8\xb92N\xa1\xb4\xe2wg\x94"'\xb6\x8c\xd6\x93\x90\x1a\x9aB%j\xcb\x13\xef\x05\xa8I\xe5\xd5\x06\xc5\x9fH\x86\xa7\x17\xd4\xbd\xf16\xd2J\xdd\xf3\xc8\xa5z\xe6\xbf\x90\xbe\x89\x0e#\x98\xdd\xadY\x09\xaa\xb6BeA\x98J\xf5\xec\x81\xf0\xfa\xaf\xbfE\xcb~\xb9G\xa2!Z\xb9\xa2\x0d\xf2{P\x98\x90\xee\xf5r\xd9d.\x95\xfeg\xf6:\x1a\xef\xfb\xbaD\xb1\x07q\x15R\x9f\x83\x89\x0a\x0cC\xa2\x9bG\x05\xa7\xd6\xfe%R\xea\x18\x15\xa6BG"\x9e\xe5{\x0f\x92ge\xfbr\xdd\xfd\xad!\xd0rp\xd1\xaa\x8a\x08\xb7\x96.\xe2\xfb\x90\xeb\xe9>CV\x01kDT\x03\xdf(<\xe7\x17\xe0\xeb\x8dA\x1f\xb0G\x06\x8fJ\x00\x10\xa9\x97\xd9\xd5\xd5\xedU\x9f\xca\xbdT\x04\x97\xe3ZGL\xabr\xfd\x81\x00\xff\xb3\xf1\xca\x9d\xa5\xd38\x94\xa7\xaf\x17\xc7\xcf\x9f\xd8\x1d\xf6\x14\x80\xd9n\x11\xb0\xa4H\x0a\xeb\xfc\x85\xad\x8e\x82\x02q\xd0\x94\xbe{\x9b9\x17`Vw\x7f}\xb3@\xf0\x8a\xbea\x9eU\x12\x97b\xc6%\x0dX\x9d\x1d\xa4\xd5\xecq\xb46`\x9b\x06\x04\xd9\x97\xe8X\xfd\x08\x9fg\xffC\xd6r\xffF\xf5W\xee[)\x03\xacv\x83\x11\xfb\xb4~\xb8\x8aOGT\xa7\xd0w\xbe\xab\xe6\x08\x0cZ\x84\xf9"...(truncated)
> [417713843:1] <- Transfer{handle=1, deliveryId=0, deliveryTag=\x00,
> messageFormat=0, settled=false, more=true, rcvSettleMode=null, state=null,
> resume=false, aborted=false, batchable=false} (176)
> "_=\xfe\xd6p%0Z\x98?\x86\x07iZNfU\x1f\x9b\x11\x93\xca\xf7\xb1\xbd9\xbf$Q\xc5\xbd:\x00\xe9T\xe8T\xf1\xab\x03\x1a\x05\x1dza[u\x84\xd2\x9e0WT\x8e\x95\xc7\x5c8=\x80\xad\x02\x5c\xb0\x9f
>
> \x0a\xaf}u\xe3\xd6\xaa'\x1a\x14\x94\xf3\x7f2\xb1\xc0\xf6L}\xb0\xf3h\xbf\x0e\xben>\xfeb\xcf\x881\xdc\xc1\xce,5\x81\xce\xd2\x94\x8c\xfaJ\xc0\x9d^\xc0s\x97\xa7u\xb0\x8e\x07$\x1bf~cY\xbb\xdc\xb6\x01\x12\xa0\xb8Y'\xa67#la\xea\xb4\xae\xa7:\x8f\xa5\xed-\xc23\xeah\xbe
> l<\xe5\xe6\x9a \x8d\xf2t\xac\xd3\xe4ss\x90\xd2\x8f\xce\xc7\xe3"
> [417713843:1] <- Transfer{handle=1, deliveryId=0, deliveryTag=\x00,
> messageFormat=0, settled=false, more=false, rcvSettleMode=null, state=null,
> resume=false, aborted=false, batchable=false}
> [417713843:1] -> Disposition{role=RECEIVER, first=0, last=0, settled=true,
> state=Accepted{}, batchable=false}
> {noformat}
> It is a legal protocol trace, but it should never really happen in a broker.
> It suggests that the delivery send isnt being completed at the point the last
> payload has been added, with the transport output then generated, and only
> later is the delivery being indicated completed and further transport output
> generated that sends the final transfer.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
