Unable to connect to azure queues (AmqpMalformedPayloadError)

[Alex-Wauters]

Hi,

we are using node-amqp10 to receive messages from a queue hosted on Azure Service Bus. This has worked fine for weeks. Since today, our code is failing with the following error:

 AmqpMalformedPayloadError: malformed payload: Unable to decode value of 71 from
 buffer 4210710000000f0000001f0000002f0000003f0000004f0000005f0000006f0000007f00
00008f0000009f000000af000000bf000000cf000000df000000ef000000ff at index 12 of ar
ray

Full logs with debug mode enabled:

amqp10:client connecting to: amqps://ReadWrite:PASSWORDOMMITTED@SERVICEBUSOMMITTED +0ms
  amqp10:transport:tls Connecting to SERVICEBUSOMMITTED:5671 via TLS +25ms
  amqp10:connection Transitioning from DISCONNECTED to START due to connect +2ms

  amqp10:connection Sending Header 414d515003010000 +79ms
  amqp10:connection Transitioning from START to IN_SASL due to connected +0ms
  amqp10:connection Rx: 414d515003010000 +15ms
  amqp10:sasl Server SASL Version: 414d515003010000 vs 414d515003010000 +4ms
  amqp10:connection Rx: 0000003f02010000005340c03201e02f04b3000000074d5353424342
5300000005504c41494e00000009414e4f4e594d4f55530000000845585445524e414c +53ms
  amqp10:sasl Sending ReadWrite:PASSWORDOMMITTED +3m
s
  amqp10:framing sending frame:  +2ms @sasl-init(65) [mechanism='PLAIN' initialR
esponse=<Buffer 00 52 65 61 64 57 72 69 74 65 00 4a 58 6b 61 46 56 53 38 41 5a 7
6 2b 2f 57 55 69 66 38 33 62 47 77 78 6d 56 45 6f 64 4f 39 75 74 6c 7a 7a 48 6c
54 65 ... > hostname=null] : 0000004f02010000005341c04203a305504c41494ea03700526
561645772697465004a586b6146565338415a762b2f575569663833624777786d56456f644f39757
46c7a7a486c5465796a37633d40
  amqp10:connection Rx: 0000001a02010000005344c00d025000a00857656c636f6d6521 +17
ms
  amqp10:connection Sending Header 414d515000010000 +1ms
  amqp10:connection Transitioning from IN_SASL to HDR_SENT due to success +3ms
  amqp10:connection Rx: 414d515000010000 +18ms
  amqp10:connection Server AMQP Version: 414d515000010000 vs 414d515000010000 +1
ms
  amqp10:connection Transitioning from HDR_SENT to HDR_EXCH due to validVersion
+0ms
  amqp10:framing sending frame:  +3ms @open(16) [containerId='conn1467110470297'
hostname='SERVICEBUSOMMITTED' maxFrameSize=429496729
5 channelMax=65535 idleTimeout=120000 outgoingLocales='en-US' incomingLocales='e
n-US' offeredCapabilities=null desiredCapabilities=null properties={}] : 0000007
002000000005310c0630aa111636f6e6e31343637313130343730323937a12d70726f6a656374687
5626572742d6465762d616c65782e736572766963656275732e77696e646f77732e6e657470fffff
fff60ffff700001d4c0a305656e2d5553a305656e2d55534040c10100
  amqp10:connection Transitioning from HDR_EXCH to OPEN_SENT due to sendOpen +15
ms
  amqp10:connection Rx: 0000004702000000005310c03a0aa124633939336636613836623831
34383561386330636532333864393835333962645f473633407000010000601387700003a9804040
404040 +24ms
  amqp10:connection Transitioning from OPEN_SENT to OPENED due to openReceived +
1ms
  amqp10:connection Connected with params { maxFrameSize=65536, channelMax=4999,
idleTimeout=120000 } +1ms
  amqp10:connection Setting heartbeat check timeout to 15000 +0ms
  amqp10:client connected +1ms
  amqp10:session Transitioning from UNMAPPED to BEGIN_SENT due to sendBegin +1ms

  amqp10:framing sending frame:  +1ms @begin(17) [remoteChannel=null nextOutgoin
gId=1 incomingWindow=100 outgoingWindow=100 handleMax=4294967295 offeredCapabili
ties=null desiredCapabilities=null properties={}] : 0000001f02000001005311c01208
4052015264526470ffffffff4040c10100
  amqp10:connection Rx: 0000002102000000005311c0140860000152017000001388526452ff
4040c10100 +17ms
  amqp10:session processing frame:  +1ms @begin(17) [remoteChannel=1 nextOutgoin
gId=1 incomingWindow=5000 outgoingWindow=100 handleMax=255 offeredCapabilities=n
ull desiredCapabilities=null properties={}]
  amqp10:session Transitioning from BEGIN_SENT to MAPPED due to beginReceived +5
ms
  amqp10:session On BEGIN_RCVD, setting params to (1,5000,100,255) +1ms
  amqp10:client mapped +0ms
  amqp10:link undefined:0: Transitioning from DETACHED to ATTACHING due to sendA
ttach +4ms
  amqp10:link attach CH=1, Handle=0 +1ms
  amqp10:framing sending frame:  +0ms @attach(18) [name='orderqueue_fe1c188f-0d2
0-47fc-967e-0377e6c9fdc1' handle=0 role=true sndSettleMode=2 rcvSettleMode=0 sou
rce=@source(40) [address='orderqueue' durable=0 expiryPolicy='session-end' timeo
ut=0 dynamic=false dynamicNodeProperties={} distributionMode=null filter={} defa
ultOutcome=null outcomes=null capabilities=null] target=@target(41) [address='lo
calhost' durable=0 expiryPolicy='session-end' timeout=0 dynamic=false dynamicNod
eProperties={} capabilities=null] unsettled={} incompleteUnsettled=false initial
DeliveryCount=1 maxMessageSize=10000 offeredCapabilities=null desiredCapabilitie
s=null properties={}] : 000000aa02000001005312c09d0ea12f6f7264657271756575655f66
653163313838662d306432302d343766632d393637652d3033373765366339666463314341500250
00005328c0270ba10a6f72646572717565756543a30b73657373696f6e2d656e644342c1010040c1
0100404040005329c02007a1096c6f63616c686f737443a30b73657373696f6e2d656e644342c101
0040c101004252018000000000000027104040c10100
  amqp10:connection Rx: 0000018602000000005312d0000001760000000ea12f6f7264657271
756575655f66653163313838662d306432302d343766632d393637652d3033373765366339666463
31434250025000005328c0270ba10a6f72646572717565756543a30b73657373696f6e2d656e6443
42c1010040c10100404040005329c02007a1096c6f63616c686f737443a30b73657373696f6e2d65
6e644342c10100404040438000000000000037104040c1da08a319636f6d2e6d6963726f736f6674
3a747261636b696e672d6964a1246339393366366138366238313438356138633063653233386439
3835333962645f473633a31b656e61626c652d6d6573736167652d706172746974696f6e696e6741
a3176c6f676963616c2d706172746974696f6e2d636f756e74610100a3186c6f676963616c2d7061
72746974696f6e2d72616e676573e04210710000000f0000001f0000002f0000003f0000004f0000
005f0000006f0000007f0000008f0000009f000000af000000bf000000cf000000df000000ef0000
00ff +19ms

Simplification of our amqp10 code and settings:

var AMQPClient = require('amqp10').Client,
    Policy = require('amqp10').Policy;

var client = new AMQPClient(Policy.ServiceBusQueue, {
    receiverLink: {attach: {receiverSettleMode: 1}}
});

var init = function () {
    return client.connect('queueURIommitted')
        .then(function () {
            return client.createReceiver('queuenameommitted')
                .then(function (receiver) {
                    receiver.on('errorReceived', function (rx_err) {
                        console.error('===> RX ERROR: ', rx_err);
                    });
                    receiver.on('message', function (message) {
                        console.info('received: ', message.body);
                        //doing something with the message
                    });
                    console.info("Queue with name ommitted initialized");
                }, (err)=>{
                    console.error(err);
                    throw err;
                })
        })
};

We're in touch with Azure just in case it is something on their end, any hints as to how we can circumvent this issue are appreciated

[Luzenna]

+1

I have the exact same issue.

[mbroadst]

@Alex-Wauters hi, can you please confirm what version of amqp10 you are running? If you're using semver, could you please try pinning your version to 3.1.5? I might have screwed something up in that last release

[Alex-Wauters]

Hi @mbroadst, thank you for your answer; we are using 3.2.0 node version: 4.4.5

I installed amqp10@3.1.5 and still experience the same issue

[mbroadst]

@Alex-Wauters okay that sounds like it's an issue with Azure itself unfortunately. I'll try to inspect the bits that are actually failing, but we'll have to get some feedback from @noodlefrenzy as to what might have changed on the Azure side of things. Sorry for the trouble!

[Alex-Wauters]

Thank you very much, that was my assumption as well, I will keep this issue updated in case MS support discover something / resolve the issue. @Luzenna: is this issue also new for you since today?

[Luzenna]

@Alex-Wauters Yes, it started today. And we are seeing the exact same buffer (4210710000000f0000001f0000002f0000003f0000004f0000005f0000006f0000007f00 00008f0000009f000000af000000bf000000cf000000df000000ef000000ff), so we too came to the conclusion that it is most likely an Azure issue.

[mbroadst]

@Alex-Wauters yeah I just ran this through our handy little tool for inspecting amqp frames and it came up with a number of "unexpected" sequences. It's possible that Microsoft has rolled out an update to Azure that includes an amqp framing error. Let's see what they say

[Alex-Wauters]

According to Azure Support, there seems to be a problem with the scale unit on which our namespaces reside. The status has been updated on https://azure.microsoft.com/en-us/status/#current

Thanks a lot for checking the issue @mbroadst ; you can close this issue if you wish, otherwise I'll update it when I hear more on when the issue is resolved on Azure side.

[mbroadst]

@Alex-Wauters glad to hear it wasn't us 😄

[jtaubensee]

@Luzenna - Can you create a support ticket for this? The support team will make sure to prioritize your location to receive the update first.

@Alex-Wauters - You have already created one, correct?

[Alex-Wauters]

Correct, thank you for checking!

[Luzenna]

@jtaubensee No, I don't think I can. I tried to send a ticket to the technical support team through the azure portal when I first noticed this issue, however it wanted to sell me a support plan, which I do not really want at this moment. I reached out to you guys through twitter, where I got a message back after some hours (I was off work at that time) saying it should be resolved. However, it has not yet been resolved for us. We still see malformed AMQP payloads (see my previous comment) being sent from the Azure Service Bus (North Europe). How should we proceed?

[Alex-Wauters]

It seems several things were going on yesterday and our issue was not the one resolved in the first fixes; we're also still facing this issue.

The fix is still getting deployed; as a short term solution you could use non-partitioned entities as the change only affects partitioned entities. However, I have found no way to change existing entities to non-partitioned.

[Luzenna]

@Alex-Wauters Thanks for the updates.

@jtaubensee I contacted Azure Support twitter and they were generous enough to give us a one-off free support to help us out with this issue. A support ticket has been created in the Azure Portal. EDIT: I got a response from Azure: "We are aware of this issue since yesterday and already produced a fix. The ETA for deployment to the live system is 8-10 hours from now."

[jtaubensee]

@Luzenna - Glad to hear that you were able to get support! Let me know if things aren't fixed in the time-frame they provided. Thanks!

[mbroadst]

I'm going to open this back up until someone confirms the problem has been solved since we're now getting duplicate tickets for the issue.

[ragnarol]

@mbroadst thanks! dont know how I missed this ticket!

[mbroadst]

@ragnarol I can! It's hard to remember to look through closed tickets as well (they look like they're not a problem anymore) 😄

[Alex-Wauters]

The issue is resolved for us! Thank you very much for all the help and info everyone

[mbroadst]

@Alex-Wauters glad to hear it, can we get confirmation from @Luzenna and @ragnarol please?

[ragnarol]

@mbroadst fixed for us as well. Thanks!

[Luzenna]

@mbroadst All good on our end! :)

[mbroadst]

thanks everybody

[jtaubensee]

Would you be interested in joining our Yammer Service Bus Advisors group? I'd like to get as many customers as possible in there who use Node, as you guys are a little under-represented at the moment. If you are interested, just let me know!

[Alex-Wauters]

Hi @jtaubensee, thanks for the invitation, I'll send our details over linkedIn