Unexpected message-size-exceeded on AMQP

[opekhovskiy-zf]

Development Machine, OS, Compiler (and Other Relevant Toolchain Info)

Ubuntu 20.04.3 LTS
gcc version 9.3.0 (Ubuntu 9.3.0-17ubuntu1~20.04)

SDK Version

1.8.0
Commit SHA: 5805fb6
Release 2022-01-22

Protocol

AMQP

Describe the Bug

We are experiencing an unexpected Azure IoT Client behavior sending data to the cloud through AMQP.

When we send a batch of messages (where for example one message is 230KB and the others 11 are 10KB each) we get
"amqp_connection was closed unexpectedly; connection retry will be triggered." and "IOTHUB_CLIENT_CONFIRMATION_ERROR"
for all messages in the batch without any specific details.

According to the quotas reference "IoT Hub quotas and throttling", "Throttling details" section:
"D2C messages can be up to 256 KB; C2D messages can be up to 64 KB. These are the [maximum message sizes] for each type of message."
https://github.com/MicrosoftDocs/azure-docs/blob/main/articles/iot-hub/iot-hub-devguide-quotas-throttling.md
That means that our case lies within the restrictions.

This issue doesn't occur on MQTT protocol.

To reproduce this error a dedicated test was implemented.
It sends the batch mentioned above and waits for confirmation through IOTHUB_CLIENT_EVENT_CONFIRMATION_CALLBACK callback.

Are there any other obvious resctrictions that affects D2C messages (maybe not mentioned in the reference)?

MCVE

Please use example attached

azure_12_msg_batch_test.zip

Console Logs

$ ./test
Test started!
SDK version: 1.8.0
-> Header (AMQP 0.1.0.0)
<- Header (AMQP 0.1.0.0)
-> [OPEN]* {197242b5-e302-4da4-9095-b90290b14747,ares-bi-odctest-iot.azure-devices.net,4294967295,65535,120000}
<- [OPEN]* {DeviceGateway_2eb6ad33432c4e6fbca1da4eb7bad724,localhost,65536,8191,240000,NULL,NULL,NULL,NULL,NULL}
-> [BEGIN]* {NULL,0,4294967295,100,4294967295}
<- [BEGIN]* {0,1,5000,4294967295,262143,NULL,NULL,NULL}
-> [ATTACH]* {$cbs-sender,0,false,0,0,* {$cbs},* {$cbs},NULL,NULL,0,0}
-> [ATTACH]* {$cbs-receiver,1,true,0,0,* {$cbs},* {$cbs},NULL,NULL,NULL,0}
<- [ATTACH]* {$cbs-sender,0,true,0,0,* {$cbs,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL},* {$cbs,NULL,NULL,NULL,NULL,NULL,NULL},NULL,NULL,NULL,1048576,NULL,NULL,NULL}
<- [FLOW]* {0,5000,1,4294967295,0,0,100,0,NULL,false,NULL}
-> [TRANSFER]* {0,0,<01 00 00 00>,0,false,false}
<- [ATTACH]* {$cbs-receiver,1,false,0,0,* {$cbs,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL},* {$cbs,NULL,NULL,NULL,NULL,NULL,NULL},NULL,NULL,0,1048576,NULL,NULL,NULL}
-> [FLOW]* {1,4294967295,1,99,1,0,10000}
<- [DISPOSITION]* {true,0,NULL,true,* {},NULL}
<- [TRANSFER]* {1,0,<01 00 00 00>,0,NULL,false,NULL,NULL,NULL,NULL,false}
-> [DISPOSITION]* {true,0,0,true,* {}}
-> [ATTACH]* {link-snd-oleg.test-4a52056c-4f89-416d-bfbf-d799964c3597,2,false,0,0,* {link-snd-oleg.test-4a52056c-4f89-416d-bfbf-d799964c3597-source},* {amqps://ares-bi-odctest-iot.azure-devices.net/devices/oleg.test/messages/events},NULL,NULL,0,18446744073709551615,NULL,NULL,{[com.microsoft:client-version:iothubclient/1.8.0 (native; Linux; x86_64)]}}
-> [ATTACH]* {link-snd-oleg.test-835e7506-d6a1-40c6-8c4c-b3f41b43f7c6,3,false,0,0,* {link-snd-oleg.test-835e7506-d6a1-40c6-8c4c-b3f41b43f7c6-source},* {amqps://ares-bi-odctest-iot.azure-devices.net/devices/oleg.test/twin},NULL,NULL,0,18446744073709551615,NULL,NULL,{[com.microsoft:client-version:iothubclient/1.8.0 (native; Linux; x86_64)],[com.microsoft:channel-correlation-id:twin:6f0d279d-212c-4c67-98ca-7c653a5fcc1f],[com.microsoft:api-version:2020-09-30]}}
<- [ATTACH]* {link-snd-oleg.test-835e7506-d6a1-40c6-8c4c-b3f41b43f7c6,3,true,1,0,* {link-snd-oleg.test-835e7506-d6a1-40c6-8c4c-b3f41b43f7c6-source,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL},* {amqps://ares-bi-odctest-iot.azure-devices.net/devices/oleg.test/twin,NULL,NULL,NULL,NULL,NULL,NULL},NULL,NULL,NULL,1048576,NULL,NULL,{[com.microsoft:client-version:iothubclient/1.8.0 (native; Linux; x86_64)],[com.microsoft:channel-correlation-id:twin:6f0d279d-212c-4c67-98ca-7c653a5fcc1f],[com.microsoft:api-version:2020-09-30]}}
<- [FLOW]* {1,5000,2,4294967295,3,0,1000,0,NULL,false,NULL}
<- [ATTACH]* {link-snd-oleg.test-4a52056c-4f89-416d-bfbf-d799964c3597,2,true,0,NULL,* {link-snd-oleg.test-4a52056c-4f89-416d-bfbf-d799964c3597-source,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL},* {amqps://ares-bi-odctest-iot.azure-devices.net/devices/oleg.test/messages/events,NULL,NULL,NULL,NULL,NULL,NULL},NULL,NULL,NULL,1048576,NULL,NULL,{[com.microsoft:client-version:iothubclient/1.8.0 (native; Linux; x86_64)]}}
<- [FLOW]* {1,5000,2,4294967295,2,0,1000,0,NULL,false,NULL}
-> [ATTACH]* {link-rcv-oleg.test-2bbe10dc-dc99-4635-95c3-6d7bb7614ab4,4,true,0,0,* {amqps://ares-bi-odctest-iot.azure-devices.net/devices/oleg.test/messages/devicebound},* {link-rcv-oleg.test-2bbe10dc-dc99-4635-95c3-6d7bb7614ab4-target},NULL,NULL,NULL,65536,NULL,NULL,{[com.microsoft:client-version:iothubclient/1.8.0 (native; Linux; x86_64)]}}
-> [ATTACH]* {link-rcv-oleg.test-e083dec9-9b18-40be-a945-b06537b204c5,5,true,0,0,* {amqps://ares-bi-odctest-iot.azure-devices.net/devices/oleg.test/twin},* {link-rcv-oleg.test-e083dec9-9b18-40be-a945-b06537b204c5-target},NULL,NULL,NULL,18446744073709551615,NULL,NULL,{[com.microsoft:client-version:iothubclient/1.8.0 (native; Linux; x86_64)],[com.microsoft:channel-correlation-id:twin:6f0d279d-212c-4c67-98ca-7c653a5fcc1f],[com.microsoft:api-version:2020-09-30]}}
<- [ATTACH]* {link-rcv-oleg.test-2bbe10dc-dc99-4635-95c3-6d7bb7614ab4,4,false,NULL,1,* {amqps://ares-bi-odctest-iot.azure-devices.net/devices/oleg.test/messages/devicebound,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL},* {link-rcv-oleg.test-2bbe10dc-dc99-4635-95c3-6d7bb7614ab4-target,NULL,NULL,NULL,NULL,NULL,NULL},NULL,NULL,0,65536,NULL,NULL,{[com.microsoft:client-version:iothubclient/1.8.0 (native; Linux; x86_64)]}}
-> [FLOW]* {2,4294967294,1,99,4,0,10000}
<- [ATTACH]* {link-rcv-oleg.test-e083dec9-9b18-40be-a945-b06537b204c5,5,false,1,0,* {amqps://ares-bi-odctest-iot.azure-devices.net/devices/oleg.test/twin,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL},* {link-rcv-oleg.test-e083dec9-9b18-40be-a945-b06537b204c5-target,NULL,NULL,NULL,NULL,NULL,NULL},NULL,NULL,0,1048576,NULL,NULL,{[com.microsoft:client-version:iothubclient/1.8.0 (native; Linux; x86_64)],[com.microsoft:channel-correlation-id:twin:6f0d279d-212c-4c67-98ca-7c653a5fcc1f],[com.microsoft:api-version:2020-09-30]}}
-> [FLOW]* {2,4294967294,1,99,5,0,10000}
-> [TRANSFER]* {3,1,<01 00 00 00>,0,false,false}
IOTHUB_CLIENT_CONNECTION_AUTHENTICATED: IOTHUB_CLIENT_CONNECTION_OK
<- [DISPOSITION]* {true,1,NULL,true,* {},NULL}
<- [TRANSFER]* {5,1,<BA C5 1C 0D EF B3 58 41 80 D8 EA 74 82 53 90 5B>,0,true,false,NULL,NULL,NULL,NULL,false}
-> [DISPOSITION]* {true,1,1,true,* {}}
-> [TRANSFER]* {2,2,<01 00 00 00>,2147563264,false,true}
-> [TRANSFER]* {2,2,<01 00 00 00>,2147563264,false,true}
-> [TRANSFER]* {2,2,<01 00 00 00>,2147563264,false,true}
-> [TRANSFER]* {2,2,<01 00 00 00>,2147563264,false,true}
-> [TRANSFER]* {2,2,<01 00 00 00>,2147563264,false,true}
-> [TRANSFER]* {2,2,<01 00 00 00>,2147563264,false,false}
-> [TRANSFER]* {3,3,<02 00 00 00>,0,false,false}
<- [DISPOSITION]* {true,3,NULL,true,* {},NULL}
<- [TRANSFER]* {5,2,<AC 41 C1 CD 6E F0 B7 45 98 20 88 AB F7 BA F1 58>,0,true,false,NULL,NULL,NULL,NULL,false}
-> [DISPOSITION]* {true,2,2,true,* {}}
<- [DISPOSITION]* {true,2,NULL,true,* {* {amqp:link:message-size-exceeded,Message size is 349372 bytes which is greater than the max size 262144 bytes allowed.,{[com.microsoft:tracking-id:103efb071939465499044761f1f8eb10-G:0-TimeStamp:02/15/2022 09:32:47],[com.microsoft:is-filtered:true]}}},NULL}
Error: Time:Tue Feb 15 10:32:48 2022 File:/home/z0148968/Work/openmatics/microsoft/test/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_DoWork Line:1464 Reconnection required. 1 of 1 registered devices are failing.
Attempt #1 => Queued: 12, Sent: 0, Dropped: 12, itemsSize: 349372

[ewertons]

Hi @opekhovskiy-zf ,
you are correct about the information provided by the Azure IoT Hub service.
However, what is not clear in that description is that 256kb is the total size of the AMQP message itself (perhaps missing in "[maximum message sizes]").
The AMQP transfer packets have an overhead, and so do the decorations added by the Azure IoT C SDK into the AMQP message (in properties, application properties and annotations). That total overhead is not fixed, it depends on the size of the IoT Hub FQDN you are using, size of the device ID, if user-defined properties are being added to the message, etc.
So the total expected payload you can send through AMQP protocol using the Azure IoT C SDK should be less than 256KB. Previous tests have shown that you should expect something in the range of 220KB to 240KB of usable payload size.

Could you try sending a total payload size within that range and confirming if that works for you?

Thanks,
Azure IoT SDK Team

[opekhovskiy-zf]

Hello, please pay attention that no matter now big the size of each message is (I also made them 10KB each), sending them in one batch leads to the same error.
So looks like either the documentation must be updated where maximum batch size ~256KB must be pointed out or SDK logic must be modified where each message cannot exceed ~256KB but no limitation on batch size.
Right now the docs says nothing about batch size limitation.

[ewertons]

@opekhovskiy-zf , that's a fair request.
Let me run a couple tests today and I'll update you back on the results and possible update to the documentation.
Thanks.

[ewertons]

Hi @opekhovskiy-zf , just to inform you we found an issue with Azure IoT Hub related to this issue, and we are working to address it. We will post an update as soon as we can. For the time being, AMQP telemetry batching in azure-iot-sdk-c will be impacted.

[ericwolz]

Closing this issue. This SDK contains the required changes #2308. The IoT hub needs to support the AMQP protocol changes with a hub update.