search

Azure / azure-iot-sdk-node

A Node.js SDK for connecting devices to Microsoft Azure IoT services
https://docs.microsoft.com/en-us/azure/iot-hub/
Other
262 stars 227 forks source link

AMQP transport: downstream device messages stop sending after 2047 messages, recovers after about 25 minutes #1089

Closed ra-dave closed 2 years ago

ra-dave commented 2 years ago

Context

Description of the issue

Using the Node.js SDK to send device to cloud messages with the AMQP protocol to an Edge runtime (gateway). The messages are sent successfully at 1 second intervals until 2047 and then messages actually stop being sent with no error being thrown. Messages start sending again after approx. 25 minutes and the cycle repeats. Message interval can be changed to be even faster so that the problem occurs sooner but it will always happen at 2047. This only occurs when using the Edge Runtime. Going directly to Azure Hub has no issue.

This seems to be the same issue as #513

Tried the Node.js SDK from Oct. 22, 2021 as well as version 1.11.0.

The corresponding samples from the .NET and Python SDKs do not have this issue.

Code sample exhibiting the issue

Using the edge_downstream_device.js sample from the SDK without changes.

Console log of the issue

This is the portion of the debug log where the messages stop sending:

azure-iot-amqp-base:SenderLink message placed in dictionary for lookup later. +3ms rhea:frames [connection-1]:0 -> transfer#14 {"handle":3,"delivery_id":2046,"delivery_tag":{"type":"Buffer","data":[50,48,52,53]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 2f 00 00 00 03 40 40 a1 27 2f 64 65 76 69 63 65 73 2f 66 74 65 67 6c 65 61 66 64 65 76 69 63 65 2f 6d 65 73 73 61 67 ... 180 more bytes> +214ms rhea:raw [connection-1] SENT: 266 0000010a02000000005314d00000001400000006520370000007fea0043230343543424200537045005373d00000002f000000034040a1272f646576696365732f667465676c6561666465766963652f6d657373616765732f6576656e7473005374d10000001c00000002a11074656d7065726174757265416c657274a10474727565005375a0827b226465766963654964223a226d794669727374446f776e73747265616d446576696365222c2277696e645370656564223a31322e37323336333536383738393830342c2274656d7065726174757265223a32392e3331373936333338343934333131332c2268756d6964697479223a36362e39363438343832383335343839397d +216ms rhea:io [connection-1] read 27 bytes +237ms rhea:io [connection-1] got frame of size 27 +0ms rhea:raw [connection-1] RECV: 27 0000001b02000000005315c00e064170000007fe40410053244540 +21ms rhea:frames [connection-1]:0 <- disposition#15 {"role":true,"first":2046,"settled":true,"state":[]} +23ms rhea:events [connection-1] Received disposition for outgoing transfers +236ms rhea:events [connection-1] Link got event: accepted +0ms azure-iot-amqp-base:SenderLink in sender attached state - accepted event for rheaSender_8ccea200-3737-499d-a5ba-851c2a893768 +24ms rhea:events [connection-1] Link got event: settled +0ms rhea:events [connection-1] Session got event: settled +0ms rhea:events [connection-1] Connection got event: settled +0ms rhea:events [eddd3f42-e035-ed4f-a27b-2cdb180c8869] Container got event: settled +0ms azure-iot-common:RetryOperation Operation start time: 1642621829300 - Will stop retrying after: 1642622069300 +254ms azure-iot-device-amqp:Amqp using existing d2c link +254ms azure-iot-amqp-base:SenderLink placing a message in the unsent message queue. +226ms azure-iot-amqp-base:SenderLink unsent message queue length is: 1 +0ms rhea:message Encoding section 1 of 4: Typed { type: TypeDesc { name: 'List0', typecode: 69, width: 0, category: 1, create: [Function (anonymous)] { typecode: 69 } }, value: [], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 112 } } +251ms rhea:message Encoding section 2 of 4: Typed { type: TypeDesc { name: 'List32', typecode: 208, width: 4, category: 3, create: [Function (anonymous)] { typecode: 208 } }, value: [ <2 empty items>, Typed { type: [TypeDesc], value: '/devices/ftegleafdevice/messages/events' } ], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 115 } } +1ms rhea:message Encoding section 3 of 4: Typed { type: TypeDesc { name: 'Map32', typecode: 209, width: 4, category: 3, create: [Function (anonymous)] { typecode: 209 } }, value: [ Typed { type: [TypeDesc], value: 'temperatureAlert' }, Typed { type: [TypeDesc], value: 'false' } ], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 116 } } +1ms rhea:message Encoding section 4 of 4: Typed { type: TypeDesc { name: 'Vbin8', typecode: 160, width: 1, category: 2, create: [Function (anonymous)] { typecode: 160 } }, value: <Buffer 7b 22 64 65 76 69 63 65 49 64 22 3a 22 6d 79 46 69 72 73 74 44 6f 77 6e 73 74 72 65 61 6d 44 65 76 69 63 65 22 2c 22 77 69 6e 64 53 70 65 65 64 22 3a ... 81 more bytes>, descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 117 } } +0ms rhea:message encoded 232 bytes +1ms azure-iot-amqp-base:SenderLink message placed in dictionary for lookup later. +3ms rhea:frames [connection-1]:0 -> transfer#14 {"handle":3,"delivery_id":2047,"delivery_tag":{"type":"Buffer","data":[50,48,52,54]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 2f 00 00 00 03 40 40 a1 27 2f 64 65 76 69 63 65 73 2f 66 74 65 67 6c 65 61 66 64 65 76 69 63 65 2f 6d 65 73 73 61 67 ... 182 more bytes> +231ms rhea:raw [connection-1] SENT: 268 0000010c02000000005314d00000001400000006520370000007ffa0043230343643424200537045005373d00000002f000000034040a1272f646576696365732f667465676c6561666465766963652f6d657373616765732f6576656e7473005374d10000001d00000002a11074656d7065726174757265416c657274a10566616c7365005375a0837b226465766963654964223a226d794669727374446f776e73747265616d446576696365222c2277696e645370656564223a31322e3332323536303835323435373733342c2274656d7065726174757265223a32322e3331393138363838333335373737362c2268756d6964697479223a37312e37353437353838393430333838377d +232ms rhea:io [connection-1] read 27 bytes +266ms rhea:io [connection-1] got frame of size 27 +1ms rhea:raw [connection-1] RECV: 27 0000001b02000000005315c00e064170000007ff40410053244540 +35ms rhea:frames [connection-1]:0 <- disposition#15 {"role":true,"first":2047,"settled":true,"state":[]} +36ms rhea:events [connection-1] Received disposition for outgoing transfers +267ms rhea:events [connection-1] Link got event: accepted +0ms azure-iot-amqp-base:SenderLink in sender attached state - accepted event for rheaSender_8ccea200-3737-499d-a5ba-851c2a893768 +38ms rhea:events [connection-1] Link got event: settled +0ms rhea:events [connection-1] Session got event: settled +0ms rhea:events [connection-1] Connection got event: settled +1ms rhea:events [eddd3f42-e035-ed4f-a27b-2cdb180c8869] Container got event: settled +0ms azure-iot-common:RetryOperation Operation start time: 1642621829550 - Will stop retrying after: 1642622069550 +250ms azure-iot-device-amqp:Amqp using existing d2c link +251ms azure-iot-amqp-base:SenderLink placing a message in the unsent message queue. +210ms azure-iot-common:RetryOperation Operation start time: 1642621829815 - Will stop retrying after: 1642622069815 +265ms azure-iot-device-amqp:Amqp using existing d2c link +264ms azure-iot-amqp-base:SenderLink placing a message in the unsent message queue. +265ms azure-iot-common:RetryOperation Operation start time: 1642621830065 - Will stop retrying after: 1642622070065 +250ms azure-iot-device-amqp:Amqp using existing d2c link +250ms azure-iot-amqp-base:SenderLink placing a message in the unsent message queue. +250ms

This is where the messages resume sending after about 25 minutes. It looks like there is one "Could not send is not retriable" error for every failed message (I have omitted all but the last few):

azure-iot-common:RetryOperation Error: Error: AMQP Transport: Could not send is not retriable +0ms azure-iot-common:RetryOperation Error: Error: AMQP Transport: Could not send is not retriable +0ms azure-iot-common:RetryOperation Error: Error: AMQP Transport: Could not send is not retriable +0ms azure-iot-common:RetryOperation Error: Error: AMQP Transport: Could not send is not retriable +1ms azure-iot-common:RetryOperation Error: Error: AMQP Transport: Could not send is not retriable +0ms rhea:frames [connection-1]:0 -> end#17 {} +3s rhea:raw [connection-1] SENT: 12 0000000c0200000000531745 +3s azure-iot-common:RetryOperation Operation start time: 1642624881671 - Will stop retrying after: 1642625121671 +13ms azure-iot-device-amqp:Amqp using existing d2c link +3s azure-iot-amqp-base:SenderLink placing a message in the unsent message queue. +3s azure-iot-amqp-base:SenderLink detached -> attaching (action:detached.attach) +0ms azure-iot-amqp-base:SenderLink attaching sender name: rheaSender_13a15356-d046-4de6-b6a3-45e28775e419 with address: /devices/ftegleafdevice/messages/events +1ms rhea:frames [connection-1]:0 -> attach#12 {"name":"rheaSender_13a15356-d046-4de6-b6a3-45e28775e419","source":[],"target":["/devices/ftegleafdevice/messages/events"],"properties":{"com.microsoft:client-version":"azure-iot-device/1.17.6 (node v16.13.2; Windows_NT 10.0.17763; x64)"}} +10ms rhea:raw [connection-1] SENT: 244 000000f402000000005312d0000000e40000000ea12f7268656153656e6465725f31336131353335362d643034362d346465362d623661332d3435653238373735653431394342404000532845005329d00000002d00000001a1272f646576696365732f667465676c6561666465766963652f6d657373616765732f6576656e7473404043404040d10000006700000002a31c636f6d2e6d6963726f736f66743a636c69656e742d76657273696f6ea143617a7572652d696f742d6465766963652f312e31372e3620286e6f6465207631362e31332e323b2057696e646f77735f4e542031302e302e31373736333b2078363429 +9ms rhea:io [connection-1] read 15 bytes +3s rhea:io [connection-1] got frame of size 15 +0ms rhea:raw [connection-1] RECV: 15 0000000f02000000005317c0020140 +1ms rhea:frames [connection-1]:0 <- end#17 {} +1ms rhea:events [connection-1] Session got event: session_close +3s azure-iot-amqp-base:Amqp session close event handler +3s azure-iot-amqp-base:Amqp entering disconnect function of disconnecting state +0ms azure-iot-amqp-base:Amqp disconnect in disconnecting state is about send a close to the peer. +0ms rhea:frames [connection-1]:0 -> close#18 {} +2ms rhea:raw [connection-1] SENT: 12 0000000c0200000000531845 +2ms rhea:io [connection-1] read 15 bytes +2ms rhea:io [connection-1] got frame of size 15 +0ms rhea:raw [connection-1] RECV: 15 0000000f02000000005318c0020140 +0ms rhea:frames [connection-1]:0 <- close#18 {} +0ms rhea:events [connection-1] Connection got event: connection_close +2ms azure-iot-amqp-base:Amqp connection close event handler +2ms azure-iot-amqp-base:Amqp disconnecting -> disconnected (action:disconnecting.connection_close) +0ms azure-iot-device-amqp:Amqp Error updating the shared access signature +8ms azure-iot-device-amqp:Amqp authenticated -> disconnecting (authenticated.disconnect) +0ms azure-iot-device-amqp:Amqp device methods links detached. +1ms azure-iot-device-amqp:Amqp device twin links detached +0ms azure-iot-amqp-base:SenderLink Detaching while attaching of rhea sender link /devices/ftegleafdevice/messages/events +8ms azure-iot-amqp-base:SenderLink failed to auto-attach, likely because a forceDetach happened: Error: Unexpected link detach while attaching +0ms azure-iot-amqp-base:SenderLink attaching -> detached (action:attaching.detach) +0ms azure-iot-amqp-base:SenderLink link detached: /devices/ftegleafdevice/messages/events +2ms azure-iot-amqp-base:SenderLink unsent message queue length: 1 +0ms azure-iot-amqp-base:SenderLink dequeuing and failing unsent messages +0ms azure-iot-common:RetryOperation Error: Error: AMQP Transport: Could not send is not retriable +12ms azure-iot-device-amqp:Amqp error detaching the D2C link: Error: Unexpected link detach while attaching +4ms azure-iot-amqp-base:ReceiverLink while detached - detach for receiver link /devices/ftegleafdevice/messages/devicebound +3s azure-iot-device-amqp:Amqp C2D link successfully detached +0ms azure-iot-amqp-base:ReceiverLink while detached - detach for receiver link /devices/ftegleafdevice/messages/devicebound +1ms azure-iot-device-amqp:Amqp amqp connection successfully disconnected. +1ms azure-iot-device-amqp:Amqp disconnecting -> disconnected () +0ms azure-iot-device-amqp:Amqp emitting the disconnect event in response to a update signature failure +1ms azure-iot-device:InternalClient transport disconnect event: Error: AMQP Transport: Could not authorize with puttoken +0ms azure-iot-device:DeviceClient in removeListener, disabling C2D. +47m azure-iot-device:DeviceClient disabling C2D +0ms azure-iot-device:DeviceClient disabled C2D +1ms azure-iot-device:DeviceClient removeListener successfully disabled C2D. +0ms azure-iot-common:RetryOperation Operation start time: 1642624881687 - Will stop retrying after: 1642625121687 +4ms azure-iot-device-amqp:Amqp disconnected -> connecting (disconnected.connect) +1ms azure-iot-amqp-base:Amqp disconnected -> connecting (action:disconnected.connect) +12ms azure-iot-device:DeviceClient transport disconnect event: Error: AMQP Transport: Could not authorize with puttoken +15ms rhea:io [connection-2] connected 10.0.2.15:50546 -> 10.0.2.15:5671 +52ms rhea:frames [connection-2] -> { protocol_id: 0, major: 1, minor: 0, revision: 0 } +52ms rhea:frames [connection-2]:0 -> open#10 {"container_id":"78059d0a-c01b-fa4a-bb42-f202739f56be","hostname":"win-3u7uddj5jgo"} +1ms rhea:raw [connection-2] SENT: 75 0000004b02000000005310d00000003b00000002a12437383035396430612d633031622d666134612d626234322d663230323733396635366265a10f77696e2d3375377564646a356a676f +57ms rhea:io [connection-2] read 8 bytes +7ms rhea:frames [connection-2] <- { protocol_id: 0, major: 1, minor: 0, revision: 0 } +6ms rhea:io [connection-2] read 91 bytes +0ms rhea:io [connection-2] got frame of size 91 +0ms rhea:raw [connection-2] RECV: 91 0000005b02000000005310c04e0aa12e446576696365476174657761795f3764616230663432633536323431633362653562393332383335666332313734a1096c6f63616c686f73747000010000601fff700003a9804040404040 +3ms rhea:frames [connection-2]:0 <- open#10 {"container_id":"DeviceGateway_7dab0f42c56241c3be5b932835fc2174","hostname":"localhost","max_frame_size":65536,"channel_max":8191,"idle_time_out":240000} +1ms rhea:events [connection-2] Connection got event: connection_open +59ms azure-iot-amqp-base:Amqp connection open event handler +48ms azure-iot-amqp-base:Amqp connecting -> connecting_session (action:connecting.connection_open) +0ms rhea:frames [connection-2]:0 -> begin#11 {"incoming_window":2048,"outgoing_window":4294967295} +2ms rhea:raw [connection-2] SENT: 32 0000002002000000005311d000000010000000044043700000080070ffffffff +3ms rhea:io [connection-2] read 37 bytes +4ms rhea:io [connection-2] got frame of size 37 +0ms rhea:raw [connection-2] RECV: 37 0000002502000000005311c01808600000520170000013887000000800700003ffff404040 +0ms rhea:frames [connection-2]:0 <- begin#11 {"next_outgoing_id":1,"incoming_window":5000,"outgoing_window":2048,"handle_max":262143} +2ms rhea:events [connection-2] Session got event: session_open +4ms azure-iot-amqp-base:Amqp session open event handler +3ms azure-iot-amqp-base:Amqp connecting_session -> connected (action:connecting_session.session_open) +0ms azure-iot-device-amqp:Amqp connecting -> authenticating () +55ms azure-iot-amqp-base:SenderLink link detached: $cbs +61ms azure-iot-amqp-base:SenderLink unsent message queue length: 0 +0ms azure-iot-amqp-base:SenderLink detached -> attaching (action:detached.attach) +1ms azure-iot-amqp-base:SenderLink attaching sender name: rheaSender_abc2af93-3c60-4ab2-966c-6b3355fb8b32 with address: $cbs +0ms rhea:frames [connection-2]:0 -> attach#12 {"name":"rheaSender_abc2af93-3c60-4ab2-966c-6b3355fb8b32","source":[],"target":["$cbs"],"properties":{"com.microsoft:client-version":"azure-iot-device/1.17.6 (node v16.13.2; Windows_NT 10.0.17763; x64)"}} +5ms rhea:raw [connection-2] SENT: 209 000000d102000000005312d0000000c10000000ea12f7268656153656e6465725f61626332616639332d336336302d346162322d393636632d3662333335356662386233324342404000532845005329d00000000a00000001a10424636273404043404040d10000006700000002a31c636f6d2e6d6963726f736f66743a636c69656e742d76657273696f6ea143617a7572652d696f742d6465766963652f312e31372e3620286e6f6465207631362e31332e323b2057696e646f77735f4e542031302e302e31373736333b2078363429 +6ms rhea:io [connection-2] read 218 bytes +14ms rhea:io [connection-2] got frame of size 218 +0ms rhea:raw [connection-2] RECV: 218 000000da02000000005312c0cd0ea12f7268656153656e6465725f61626332616639332d336336302d346162322d393636632d36623333353566623862333243414040005328c00c0b4040404040404040404040005329c00d07a104246362734040404040404040408000000000001000004040c16402a31c636f6d2e6d6963726f736f66743a636c69656e742d76657273696f6ea143617a7572652d696f742d6465766963652f312e31372e3620286e6f6465207631362e31332e323b2057696e646f77735f4e542031302e302e31373736333b2078363429 +8ms rhea:frames [connection-2]:0 <- attach#12 {"name":"rheaSender_abc2af93-3c60-4ab2-966c-6b3355fb8b32","role":true,"source":[null,null,null,null,null,null,null,null,null,null,null],"target":["$cbs",null,null,null,null,null,null],"max_message_size":1048576,"properties":{"com.microsoft:client-version":"azure-iot-device/1.17.6 (node v16.13.2; Windows_NT 10.0.17763; x64)"}} +9ms rhea:events [connection-2] Link got event: sender_open +15ms azure-iot-amqp-base:SenderLink attaching -> attached (action:attaching.senderOpenEvent) +11ms azure-iot-amqp-base:SenderLink link attached. processing unsent message queue +0ms azure-iot-amqp-base:ReceiverLink detached -> attaching (action:detached.attach) +72ms azure-iot-amqp-base:ReceiverLink attaching receiver name: rheaReceiver_e0fa51db-37c8-493d-b25f-da5226245641 with address: $cbs +0ms rhea:frames [connection-2]:0 -> attach#12 {"name":"rheaReceiver_e0fa51db-37c8-493d-b25f-da5226245641","handle":1,"role":true,"source":["$cbs"],"target":[],"properties":{"com.microsoft:client-version":"azure-iot-device/1.17.6 (node v16.13.2; Windows_NT 10.0.17763; x64)"}} +3ms rhea:raw [connection-2] SENT: 212 000000d402000000005312d0000000c40000000ea1317268656152656365697665725f65306661353164622d333763382d343933642d623235662d6461353232363234353634315201414040005328d00000000a00000001a1042463627300532945404040404040d10000006700000002a31c636f6d2e6d6963726f736f66743a636c69656e742d76657273696f6ea143617a7572652d696f742d6465766963652f312e31372e3620286e6f6465207631362e31332e323b2057696e646f77735f4e542031302e302e31373736333b2078363429 +5ms rhea:io [connection-2] read 38 bytes +5ms rhea:io [connection-2] got frame of size 38 +0ms rhea:raw [connection-2] RECV: 38 0000002602000000005313c0190b43700000138852017000000800434370000003e843404240 +1ms rhea:frames [connection-2]:0 <- flow#13 {"incoming_window":5000,"next_outgoing_id":1,"outgoing_window":2048,"link_credit":1000} +2ms rhea:events [connection-2] Link got event: sender_flow +5ms rhea:events [connection-2] Session got event: sender_flow +0ms rhea:events [connection-2] Connection got event: sender_flow +0ms rhea:events [78059d0a-c01b-fa4a-bb42-f202739f56be] Container got event: sender_flow +0ms rhea:events [connection-2] Link got event: sendable +1ms rhea:io [connection-2] read 221 bytes +3ms rhea:io [connection-2] got frame of size 221 +0ms rhea:raw [connection-2] RECV: 221 000000dd02000000005312c0d00ea1317268656152656365697665725f65306661353164622d333763382d343933642d623235662d6461353232363234353634315201424040005328c0110ba1042463627340404040404040404040005329c00807404040404040404040438000000000001000004040c16402a31c636f6d2e6d6963726f736f66743a636c69656e742d76657273696f6ea143617a7572652d696f742d6465766963652f312e31372e3620286e6f6465207631362e31332e323b2057696e646f77735f4e542031302e302e31373736333b2078363429 +2ms rhea:frames [connection-2]:0 <- attach#12 {"name":"rheaReceiver_e0fa51db-37c8-493d-b25f-da5226245641","handle":1,"source":["$cbs",null,null,null,null,null,null,null,null,null,null],"target":[null,null,null,null,null,null,null],"max_message_size":1048576,"properties":{"com.microsoft:client-version":"azure-iot-device/1.17.6 (node v16.13.2; Windows_NT 10.0.17763; x64)"}} +3ms rhea:events [connection-2] Link got event: receiver_open +1ms azure-iot-amqp-base:ReceiverLink In receiver attaching state - open event for rheaReceiver_e0fa51db-37c8-493d-b25f-da5226245641 +7ms azure-iot-amqp-base:ReceiverLink attaching -> attached (action:attaching.receiverOpenEvent) +0ms azure-iot-amqp-base:SenderLink placing a message in the unsent message queue. +9ms azure-iot-amqp-base:SenderLink unsent message queue length is: 1 +0ms rhea:message Encoding section 1 of 4: Typed { type: TypeDesc { name: 'List0', typecode: 69, width: 0, category: 1, create: [Function (anonymous)] { typecode: 69 } }, value: [], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 112 } } +38m rhea:message Encoding section 2 of 4: Typed { type: TypeDesc { name: 'List32', typecode: 208, width: 4, category: 3, create: [Function (anonymous)] { typecode: 208 } }, value: [ Typed { type: [TypeDesc], value: 'd9ace2af-d01b-471f-9c79-32d3bbb8b8af' }, <1 empty item>, Typed { type: [TypeDesc], value: '$cbs' }, <1 empty item>, Typed { type: [TypeDesc], value: 'cbs' } ], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 115 } } +1ms rhea:message Encoding section 3 of 4: Typed { type: TypeDesc { name: 'Map32', typecode: 209, width: 4, category: 3, create: [Function (anonymous)] { typecode: 209 } }, value: [ Typed { type: [TypeDesc], value: 'operation' }, Typed { type: [TypeDesc], value: 'put-token' }, Typed { type: [TypeDesc], value: 'type' }, Typed { type: [TypeDesc], value: 'servicebus.windows.net:sastoken' }, Typed { type: [TypeDesc], value: 'name' }, Typed { type: [TypeDesc], value: 'name-omitted.azure-devices.net%2Fdevices%2Fftegleafdevice' } ], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 116 } } +1ms rhea:message Encoding section 4 of 4: Typed { type: TypeDesc { name: 'Str8', typecode: 161, width: 1, category: 2, encoding: 'utf8', create: [Function (anonymous)] { typecode: 161 } }, value: 'SharedAccessSignature sr=name-omitted.azure-devices.net%2Fdevices%2Fftegleafdevice&sig=T%2F9ZRRDE5CQQhy00gcZgVeTpxIJj1%2Bq2NDkEDY%2BYaxo%3D&se=1642628358', descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 119 } } +1ms rhea:message encoded 369 bytes +1ms azure-iot-amqp-base:SenderLink message placed in dictionary for lookup later. +5ms rhea:frames [connection-2]:0 -> transfer#14 {"delivery_tag":{"type":"Buffer","data":[48]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 37 00 00 00 05 a1 24 64 39 61 63 65 32 61 66 2d 64 30 31 62 2d 34 37 31 66 2d 39 63 37 39 2d 33 32 64 33 62 62 62 38 ... 319 more bytes> +8ms rhea:raw [connection-2] SENT: 397 0000018d02000000005314d00000000c000000064343a0013043424200537045005373d00000003700000005a12464396163653261662d643031622d343731662d396337392d33326433626262386238616640a1042463627340a103636273005374d10000008500000006a1096f7065726174696f6ea1097075742d746f6b656ea10474797065a11f736572766963656275732e77696e646f77732e6e65743a736173746f6b656ea1046e616d65a13c6d64616d69636f2d696f742d6875622e617a7572652d646576696365732e6e657425324664657669636573253246667465676c656166646576696365005377a19c5368617265644163636573735369676e61747572652073723d6d64616d69636f2d696f742d6875622e617a7572652d646576696365732e6e657425324664657669636573253246667465676c656166646576696365267369673d54253246395a52524445354351516879303067635a675665547078494a6a3125324271324e446b4544592532425961786f2533442673653d31363432363238333538 +9ms rhea:frames [connection-2]:0 -> flow#13 {"incoming_window":2048,"next_outgoing_id":1,"outgoing_window":4294967294,"handle":1,"link_credit":1000} +8ms rhea:raw [connection-2] SENT: 41 0000002902000000005313d00000001900000007437000000800520170fffffffe52014370000003e8 +9ms rhea:io [connection-2] read 135 bytes +38ms rhea:io [connection-2] got frame of size 135 +0ms rhea:raw [connection-2] RECV: 135 0000008702000000005314c0120b520143a004010000004340424040404042005373c0330d4040404040a12464396163653261662d643031622d343731662d396337392d33326433626262386238616640404040404040005374c12b04a10b7374617475732d636f646571000000c8a1127374617475732d6465736372697074696f6ea1024f4b +20ms rhea:frames [connection-2]:0 <- transfer#14 {"handle":1,"delivery_tag":{"type":"Buffer","data":[1,0,0,0]}} <Buffer 00 53 73 c0 33 0d 40 40 40 40 40 a1 24 64 39 61 63 65 32 61 66 2d 64 30 31 62 2d 34 37 31 66 2d 39 63 37 39 2d 33 32 64 33 62 62 62 38 62 38 61 66 40 ... 54 more bytes> +22ms rhea:message decoding section: Typed { type: TypeDesc { name: 'List8', typecode: 192, width: 1, category: 3, create: [Function (anonymous)] { typecode: 192 } }, value: [ Typed { type: [TypeDesc], value: null }, Typed { type: [TypeDesc], value: null }, Typed { type: [TypeDesc], value: null }, Typed { type: [TypeDesc], value: null }, Typed { type: [TypeDesc], value: null }, Typed { type: [TypeDesc], value: 'd9ace2af-d01b-471f-9c79-32d3bbb8b8af' }, Typed { type: [TypeDesc], value: null }, Typed { type: [TypeDesc], value: null }, Typed { type: [TypeDesc], value: null }, Typed { type: [TypeDesc], value: null }, Typed { type: [TypeDesc], value: null }, Typed { type: [TypeDesc], value: null }, Typed { type: [TypeDesc], value: null } ], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 115 } } of type: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function (anonymous)] { typecode: 83 } }, value: 115 } +33ms rhea:message decoding section: Typed { type: TypeDesc { name: 'Map8', typecode: 193, width: 1, category: 3, create: [Function (anonymous)] { typecode: 193 } }, value: [ Typed { type: [TypeDesc], value: 'status-code' }, Typed { type: [TypeDesc], value: 200 }, Typed { type: [TypeDesc], value: 'status-description' }, Typed { type: [TypeDesc], value: 'OK' } ], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 116 } } of type: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function (anonymous)] { typecode: 83 } }, value: 116 } +4ms rhea:events [connection-2] Link got event: message +45ms azure-iot-device-amqp:Amqp authenticating -> authenticated () +67ms rhea:frames [connection-2]:0 -> disposition#15 {"role":true,"settled":true,"state":[]} +9ms rhea:raw [connection-2] SENT: 28 0000001c02000000005315d00000000c000000054143434100532445 +11ms azure-iot-common:RetryOperation Operation start time: 1642624882067 - Will stop retrying after: 1642625122067 +380ms azure-iot-device-amqp:Amqp waiting for a D2C link +260ms azure-iot-device-amqp:Amqp attaching D2C link +1ms azure-iot-amqp-base:Amqp creating sender link for: /devices/ftegleafdevice/messages/events +329ms azure-iot-amqp-base:SenderLink link detached: /devices/ftegleafdevice/messages/events +301ms azure-iot-amqp-base:SenderLink unsent message queue length: 0 +0ms azure-iot-amqp-base:SenderLink detached -> attaching (action:detached.attach) +1ms azure-iot-amqp-base:SenderLink attaching sender name: rheaSender_d9ac22e4-6c25-4c13-8d1a-87b543da182a with address: /devices/ftegleafdevice/messages/events +0ms rhea:frames [connection-2]:0 -> attach#12 {"name":"rheaSender_d9ac22e4-6c25-4c13-8d1a-87b543da182a","handle":2,"source":[],"target":["/devices/ftegleafdevice/messages/events"],"properties":{"com.microsoft:client-version":"azure-iot-device/1.17.6 (node v16.13.2; Windows_NT 10.0.17763; x64)"}} +264ms rhea:raw [connection-2] SENT: 245 000000f502000000005312d0000000e50000000ea12f7268656153656e6465725f64396163323265342d366332352d346331332d386431612d383762353433646131383261520242404000532845005329d00000002d00000001a1272f646576696365732f667465676c6561666465766963652f6d657373616765732f6576656e7473404043404040d10000006700000002a31c636f6d2e6d6963726f736f66743a636c69656e742d76657273696f6ea143617a7572652d696f742d6465766963652f312e31372e3620286e6f6465207631362e31332e323b2057696e646f77735f4e542031302e302e31373736333b2078363429 +268ms rhea:io [connection-2] read 254 bytes +285ms rhea:io [connection-2] got frame of size 254 +2ms rhea:raw [connection-2] RECV: 254 000000fe02000000005312c0f10ea12f7268656153656e6465725f64396163323265342d366332352d346331332d386431612d3837623534336461313832615202414040005328c00c0b4040404040404040404040005329c03007a1272f646576696365732f667465676c6561666465766963652f6d657373616765732f6576656e74734040404040404040408000000000001000004040c16402a31c636f6d2e6d6963726f736f66743a636c69656e742d76657273696f6ea143617a7572652d696f742d6465766963652f312e31372e3620286e6f6465207631362e31332e323b2057696e646f77735f4e542031302e302e31373736333b2078363429 +9ms rhea:frames [connection-2]:0 <- attach#12 {"name":"rheaSender_d9ac22e4-6c25-4c13-8d1a-87b543da182a","handle":2,"role":true,"source":[null,null,null,null,null,null,null,null,null,null,null],"target":["/devices/ftegleafdevice/messages/events",null,null,null,null,null,null],"max_message_size":1048576,"properties":{"com.microsoft:client-version":"azure-iot-device/1.17.6 (node v16.13.2; Windows_NT 10.0.17763; x64)"}} +23ms rhea:events [connection-2] Link got event: sender_open +295ms azure-iot-amqp-base:SenderLink attaching -> attached (action:attaching.senderOpenEvent) +31ms azure-iot-amqp-base:SenderLink link attached. processing unsent message queue +1ms azure-iot-device-amqp:Amqp got a new D2C link +34ms azure-iot-amqp-base:SenderLink placing a message in the unsent message queue. +1ms rhea:io [connection-2] read 40 bytes +18ms rhea:io [connection-2] got frame of size 40 +4ms rhea:raw [connection-2] RECV: 40 0000002802000000005313c01b0b52017000001387520270000007fe52024370000003e843404240 +21ms rhea:frames [connection-2]:0 <- flow#13 {"next_incoming_id":1,"incoming_window":4999,"next_outgoing_id":2,"outgoing_window":2046,"handle":2,"link_credit":1000} +13ms rhea:events [connection-2] Link got event: sender_flow +10ms rhea:events [connection-2] Session got event: sender_flow +1ms rhea:events [connection-2] Connection got event: sender_flow +0ms rhea:events [78059d0a-c01b-fa4a-bb42-f202739f56be] Container got event: sender_flow +0ms rhea:events [connection-2] Link got event: sendable +0ms azure-iot-amqp-base:SenderLink unsent message queue length is: 1 +10ms rhea:message Encoding section 1 of 4: Typed { type: TypeDesc { name: 'List0', typecode: 69, width: 0, category: 1, create: [Function (anonymous)] { typecode: 69 } }, value: [], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 112 } } +309ms rhea:message Encoding section 2 of 4: Typed { type: TypeDesc { name: 'List32', typecode: 208, width: 4, category: 3, create: [Function (anonymous)] { typecode: 208 } }, value: [ <2 empty items>, Typed { type: [TypeDesc], value: '/devices/ftegleafdevice/messages/events' } ], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 115 } } +1ms rhea:message Encoding section 3 of 4: Typed { type: TypeDesc { name: 'Map32', typecode: 209, width: 4, category: 3, create: [Function (anonymous)] { typecode: 209 } }, value: [ Typed { type: [TypeDesc], value: 'temperatureAlert' }, Typed { type: [TypeDesc], value: 'true' } ], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 116 } } +9ms rhea:message Encoding section 4 of 4: Typed { type: TypeDesc { name: 'Vbin8', typecode: 160, width: 1, category: 2, create: [Function (anonymous)] { typecode: 160 } }, value: <Buffer 7b 22 64 65 76 69 63 65 49 64 22 3a 22 6d 79 46 69 72 73 74 44 6f 77 6e 73 74 72 65 61 6d 44 65 76 69 63 65 22 2c 22 77 69 6e 64 53 70 65 65 64 22 3a ... 80 more bytes>, descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 117 } } +1ms rhea:message encoded 230 bytes +1ms azure-iot-amqp-base:SenderLink message placed in dictionary for lookup later. +12ms rhea:frames [connection-2]:0 -> transfer#14 {"handle":2,"delivery_id":1,"delivery_tag":{"type":"Buffer","data":[48]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 2f 00 00 00 03 40 40 a1 27 2f 64 65 76 69 63 65 73 2f 66 74 65 67 6c 65 61 66 64 65 76 69 63 65 2f 6d 65 73 73 61 67 ... 180 more bytes> +18ms rhea:raw [connection-2] SENT: 260 0000010402000000005314d00000000e0000000652025201a0013043424200537045005373d00000002f000000034040a1272f646576696365732f667465676c6561666465766963652f6d657373616765732f6576656e7473005374d10000001c00000002a11074656d7065726174757265416c657274a10474727565005375a0827b226465766963654964223a226d794669727374446f776e73747265616d446576696365222c2277696e645370656564223a31302e3139303032303732373233393932322c2274656d7065726174757265223a32382e31353037313831323337353738352c2268756d6964697479223a36302e32323533363438343838373733327d +21ms rhea:io [connection-2] read 24 bytes +84ms rhea:io [connection-2] got frame of size 24 +2ms rhea:raw [connection-2] RECV: 24 0000001802000000005315c00b0641520140410053244540 +65ms rhea:frames [connection-2]:0 <- disposition#15 {"role":true,"first":1,"settled":true,"state":[]} +68ms rhea:events [connection-2] Received disposition for outgoing transfers +82ms rhea:events [connection-2] Link got event: accepted +0ms azure-iot-amqp-base:SenderLink in sender attached state - accepted event for rheaSender_d9ac22e4-6c25-4c13-8d1a-87b543da182a +70ms rhea:events [connection-2] Link got event: settled +5ms rhea:events [connection-2] Session got event: settled +0ms rhea:events [connection-2] Connection got event: settled +1ms rhea:events [78059d0a-c01b-fa4a-bb42-f202739f56be] Container got event: settled +0ms azure-iot-common:RetryOperation Operation start time: 1642624882327 - Will stop retrying after: 1642625122327 +260ms azure-iot-device-amqp:Amqp using existing d2c link +225ms azure-iot-amqp-base:SenderLink placing a message in the unsent message queue. +132ms azure-iot-amqp-base:SenderLink unsent message queue length is: 1 +1ms rhea:message Encoding section 1 of 4: Typed { type: TypeDesc { name: 'List0', typecode: 69, width: 0, category: 1, create: [Function (anonymous)] { typecode: 69 } }, value: [], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 112 } } +203ms rhea:message Encoding section 2 of 4: Typed { type: TypeDesc { name: 'List32', typecode: 208, width: 4, category: 3, create: [Function (anonymous)] { typecode: 208 } }, value: [ <2 empty items>, Typed { type: [TypeDesc], value: '/devices/ftegleafdevice/messages/events' } ], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 115 } } +2ms rhea:message Encoding section 3 of 4: Typed { type: TypeDesc { name: 'Map32', typecode: 209, width: 4, category: 3, create: [Function (anonymous)] { typecode: 209 } }, value: [ Typed { type: [TypeDesc], value: 'temperatureAlert' }, Typed { type: [TypeDesc], value: 'false' } ], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 116 } } +1ms rhea:message Encoding section 4 of 4: Typed { type: TypeDesc { name: 'Vbin8', typecode: 160, width: 1, category: 2, create: [Function (anonymous)] { typecode: 160 } }, value: <Buffer 7b 22 64 65 76 69 63 65 49 64 22 3a 22 6d 79 46 69 72 73 74 44 6f 77 6e 73 74 72 65 61 6d 44 65 76 69 63 65 22 2c 22 77 69 6e 64 53 70 65 65 64 22 3a ... 80 more bytes>, descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 117 } } +1ms rhea:message encoded 231 bytes +1ms azure-iot-amqp-base:SenderLink message placed in dictionary for lookup later. +6ms rhea:frames [connection-2]:0 -> transfer#14 {"handle":2,"delivery_id":2,"delivery_tag":{"type":"Buffer","data":[49]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 2f 00 00 00 03 40 40 a1 27 2f 64 65 76 69 63 65 73 2f 66 74 65 67 6c 65 61 66 64 65 76 69 63 65 2f 6d 65 73 73 61 67 ... 181 more bytes> +140ms rhea:raw [connection-2] SENT: 261 0000010502000000005314d00000000e0000000652025202a0013143424200537045005373d00000002f000000034040a1272f646576696365732f667465676c6561666465766963652f6d657373616765732f6576656e7473005374d10000001d00000002a11074656d7065726174757265416c657274a10566616c7365005375a0827b226465766963654964223a226d794669727374446f776e73747265616d446576696365222c2277696e645370656564223a31312e3137313637373837333836353437352c2274656d7065726174757265223a32312e3932333031343438393636303934332c2268756d6964697479223a36352e313939333138343635373237357d +143ms rhea:io [connection-2] read 24 bytes +170ms rhea:io [connection-2] got frame of size 24 +2ms rhea:raw [connection-2] RECV: 24 0000001802000000005315c00b0641520240410053244540 +30ms rhea:frames [connection-2]:0 <- disposition#15 {"role":true,"first":2,"settled":true,"state":[]} +32ms rhea:events [connection-2] Received disposition for outgoing transfers +166ms rhea:events [connection-2] Link got event: accepted +1ms azure-iot-amqp-base:SenderLink in sender attached state - accepted event for rheaSender_d9ac22e4-6c25-4c13-8d1a-87b543da182a +33ms rhea:events [connection-2] Link got event: settled +0ms rhea:events [connection-2] Session got event: settled +0ms rhea:events [connection-2] Connection got event: settled +1ms rhea:events [78059d0a-c01b-fa4a-bb42-f202739f56be] Container got event: settled +0ms azure-iot-common:RetryOperation Operation start time: 1642624882584 - Will stop retrying after: 1642625122584 +257ms azure-iot-device-amqp:Amqp using existing d2c link +257ms azure-iot-amqp-base:SenderLink placing a message in the unsent message queue. +217ms azure-iot-amqp-base:SenderLink unsent message queue length is: 1 +0ms rhea:message Encoding section 1 of 4: Typed { type: TypeDesc { name: 'List0', typecode: 69, width: 0, category: 1, create: [Function (anonymous)] { typecode: 69 } }, value: [], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 112 } } +251ms rhea:message Encoding section 2 of 4: Typed { type: TypeDesc { name: 'List32', typecode: 208, width: 4, category: 3, create: [Function (anonymous)] { typecode: 208 } }, value: [ <2 empty items>, Typed { type: [TypeDesc], value: '/devices/ftegleafdevice/messages/events' } ], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 115 } } +1ms rhea:message Encoding section 3 of 4: Typed { type: TypeDesc { name: 'Map32', typecode: 209, width: 4, category: 3, create: [Function (anonymous)] { typecode: 209 } }, value: [ Typed { type: [TypeDesc], value: 'temperatureAlert' }, Typed { type: [TypeDesc], value: 'false' } ], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 116 } } +1ms rhea:message Encoding section 4 of 4: Typed { type: TypeDesc { name: 'Vbin8', typecode: 160, width: 1, category: 2, create: [Function (anonymous)] { typecode: 160 } }, value: <Buffer 7b 22 64 65 76 69 63 65 49 64 22 3a 22 6d 79 46 69 72 73 74 44 6f 77 6e 73 74 72 65 61 6d 44 65 76 69 63 65 22 2c 22 77 69 6e 64 53 70 65 65 64 22 3a ... 78 more bytes>, descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 117 } } +1ms rhea:message encoded 229 bytes +0ms azure-iot-amqp-base:SenderLink message placed in dictionary for lookup later. +4ms rhea:frames [connection-2]:0 -> transfer#14 {"handle":2,"delivery_id":3,"delivery_tag":{"type":"Buffer","data":[50]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 2f 00 00 00 03 40 40 a1 27 2f 64 65 76 69 63 65 73 2f 66 74 65 67 6c 65 61 66 64 65 76 69 63 65 2f 6d 65 73 73 61 67 ... 179 more bytes> +222ms rhea:raw [connection-2] SENT: 259 0000010302000000005314d00000000e0000000652025203a0013243424200537045005373d00000002f000000034040a1272f646576696365732f667465676c6561666465766963652f6d657373616765732f6576656e7473005374d10000001d00000002a11074656d7065726174757265416c657274a10566616c7365005375a0807b226465766963654964223a226d794669727374446f776e73747265616d446576696365222c2277696e645370656564223a31322e393331383535353734333937332c2274656d7065726174757265223a32312e35373331303232353733303937342c2268756d6964697479223a37332e34303434363238363332393233357d +223ms rhea:io [connection-2] read 24 bytes +247ms rhea:io [connection-2] got frame of size 24 +0ms rhea:raw [connection-2] RECV: 24 0000001802000000005315c00b0641520340410053244540 +23ms rhea:frames [connection-2]:0 <- disposition#15 {"role":true,"first":3,"settled":true,"state":[]} +24ms rhea:events [connection-2] Received disposition for outgoing transfers +245ms rhea:events [connection-2] Link got event: accepted +0ms azure-iot-amqp-base:SenderLink in sender attached state - accepted event for rheaSender_d9ac22e4-6c25-4c13-8d1a-87b543da182a +25ms rhea:events [connection-2] Link got event: settled +0ms rhea:events [connection-2] Session got event: settled +1ms rhea:events [connection-2] Connection got event: settled +0ms rhea:events [78059d0a-c01b-fa4a-bb42-f202739f56be] Container got event: settled +0ms azure-iot-common:RetryOperation Operation start time: 1642624882834 - Will stop retrying after: 1642625122834 +250ms azure-iot-device-amqp:Amqp using existing d2c link +250ms azure-iot-amqp-base:SenderLink placing a message in the unsent message queue. +222ms azure-iot-amqp-base:SenderLink unsent message queue length is: 1 +0ms rhea:message Encoding section 1 of 4: Typed { type: TypeDesc { name: 'List0', typecode: 69, width: 0, category: 1, create: [Function (anonymous)] { typecode: 69 } }, value: [], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 112 } } +248ms rhea:message Encoding section 2 of 4: Typed { type: TypeDesc { name: 'List32', typecode: 208, width: 4, category: 3, create: [Function (anonymous)] { typecode: 208 } }, value: [ <2 empty items>, Typed { type: [TypeDesc], value: '/devices/ftegleafdevice/messages/events' } ], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 115 } } +1ms rhea:message Encoding section 3 of 4: Typed { type: TypeDesc { name: 'Map32', typecode: 209, width: 4, category: 3, create: [Function (anonymous)] { typecode: 209 } }, value: [ Typed { type: [TypeDesc], value: 'temperatureAlert' }, Typed { type: [TypeDesc], value: 'false' } ], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 116 } } +1ms rhea:message Encoding section 4 of 4: Typed { type: TypeDesc { name: 'Vbin8', typecode: 160, width: 1, category: 2, create: [Function (anonymous)] { typecode: 160 } }, value: <Buffer 7b 22 64 65 76 69 63 65 49 64 22 3a 22 6d 79 46 69 72 73 74 44 6f 77 6e 73 74 72 65 61 6d 44 65 76 69 63 65 22 2c 22 77 69 6e 64 53 70 65 65 64 22 3a ... 80 more bytes>, descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 117 } } +2ms rhea:message encoded 231 bytes +1ms azure-iot-amqp-base:SenderLink message placed in dictionary for lookup later. +6ms rhea:frames [connection-2]:0 -> transfer#14 {"handle":2,"delivery_id":4,"delivery_tag":{"type":"Buffer","data":[51]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 2f 00 00 00 03 40 40 a1 27 2f 64 65 76 69 63 65 73 2f 66 74 65 67 6c 65 61 66 64 65 76 69 63 65 2f 6d 65 73 73 61 67 ... 181 more bytes> +230ms rhea:raw [connection-2] SENT: 261 0000010502000000005314d00000000e0000000652025204a0013343424200537045005373d00000002f000000034040a1272f646576696365732f667465676c6561666465766963652f6d657373616765732f6576656e7473005374d10000001d00000002a11074656d7065726174757265416c657274a10566616c7365005375a0827b226465766963654964223a226d794669727374446f776e73747265616d446576696365222c2277696e645370656564223a31322e3938373936373630343632383234392c2274656d7065726174757265223a32322e39353333373630323132323035322c2268756d6964697479223a37342e37313936333935303233313935347d +232ms rhea:io [connection-2] read 24 bytes +261ms rhea:io [connection-2] got frame of size 24 +2ms rhea:raw [connection-2] RECV: 24 0000001802000000005315c00b0641520440410053244540 +31ms rhea:frames [connection-2]:0 <- disposition#15 {"role":true,"first":4,"settled":true,"state":[]} +34ms rhea:events [connection-2] Received disposition for outgoing transfers +262ms rhea:events [connection-2] Link got event: accepted +0ms azure-iot-amqp-base:SenderLink in sender attached state - accepted event for rheaSender_d9ac22e4-6c25-4c13-8d1a-87b543da182a +35ms rhea:events [connection-2] Link got event: settled +1ms rhea:events [connection-2] Session got event: settled +0ms rhea:events [connection-2] Connection got event: settled +0ms rhea:events [78059d0a-c01b-fa4a-bb42-f202739f56be] Container got event: settled +0ms azure-iot-common:RetryOperation Operation start time: 1642624883097 - Will stop retrying after: 1642625123097 +263ms azure-iot-device-amqp:Amqp using existing d2c link +263ms azure-iot-amqp-base:SenderLink placing a message in the unsent message queue. +221ms azure-iot-amqp-base:SenderLink unsent message queue length is: 1 +0ms rhea:message Encoding section 1 of 4: Typed { type: TypeDesc { name: 'List0', typecode: 69, width: 0, category: 1, create: [Function (anonymous)] { typecode: 69 } }, value: [], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 112 } } +257ms rhea:message Encoding section 2 of 4: Typed { type: TypeDesc { name: 'List32', typecode: 208, width: 4, category: 3, create: [Function (anonymous)] { typecode: 208 } }, value: [ <2 empty items>, Typed { type: [TypeDesc], value: '/devices/ftegleafdevice/messages/events' } ], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 115 } } +1ms rhea:message Encoding section 3 of 4: Typed { type: TypeDesc { name: 'Map32', typecode: 209, width: 4, category: 3, create: [Function (anonymous)] { typecode: 209 } }, value: [ Typed { type: [TypeDesc], value: 'temperatureAlert' }, Typed { type: [TypeDesc], value: 'false' } ], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 116 } } +1ms rhea:message Encoding section 4 of 4: Typed { type: TypeDesc { name: 'Vbin8', typecode: 160, width: 1, category: 2, create: [Function (anonymous)] { typecode: 160 } }, value: <Buffer 7b 22 64 65 76 69 63 65 49 64 22 3a 22 6d 79 46 69 72 73 74 44 6f 77 6e 73 74 72 65 61 6d 44 65 76 69 63 65 22 2c 22 77 69 6e 64 53 70 65 65 64 22 3a ... 81 more bytes>, descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 117 } } +1ms rhea:message encoded 232 bytes +1ms azure-iot-amqp-base:SenderLink message placed in dictionary for lookup later. +4ms rhea:frames [connection-2]:0 -> transfer#14 {"handle":2,"delivery_id":5,"delivery_tag":{"type":"Buffer","data":[52]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 2f 00 00 00 03 40 40 a1 27 2f 64 65 76 69 63 65 73 2f 66 74 65 67 6c 65 61 66 64 65 76 69 63 65 2f 6d 65 73 73 61 67 ... 182 more bytes> +226ms rhea:raw [connection-2] SENT: 262 0000010602000000005314d00000000e0000000652025205a0013443424200537045005373d00000002f000000034040a1272f646576696365732f667465676c6561666465766963652f6d657373616765732f6576656e7473005374d10000001d00000002a11074656d7065726174757265416c657274a10566616c7365005375a0837b226465766963654964223a226d794669727374446f776e73747265616d446576696365222c2277696e645370656564223a31312e3239323838343635373731363336322c2274656d7065726174757265223a32352e3830333236313337323633383535322c2268756d6964697479223a36382e39383531303632343831373735397d +228ms rhea:io [connection-2] read 24 bytes +264ms rhea:io [connection-2] got frame of size 24 +1ms rhea:raw [connection-2] RECV: 24 0000001802000000005315c00b0641520540410053244540 +37ms rhea:frames [connection-2]:0 <- disposition#15 {"role":true,"first":5,"settled":true,"state":[]} +38ms rhea:events [connection-2] Received disposition for outgoing transfers +264ms rhea:events [connection-2] Link got event: accepted +0ms azure-iot-amqp-base:SenderLink in sender attached state - accepted event for rheaSender_d9ac22e4-6c25-4c13-8d1a-87b543da182a +40ms rhea:events [connection-2] Link got event: settled +0ms rhea:events [connection-2] Session got event: settled +1ms rhea:events [connection-2] Connection got event: settled +0ms rhea:events [78059d0a-c01b-fa4a-bb42-f202739f56be] Container got event: settled +0ms azure-iot-common:RetryOperation Operation start time: 1642624883355 - Will stop retrying after: 1642625123355 +258ms azure-iot-device-amqp:Amqp using existing d2c link +258ms azure-iot-amqp-base:SenderLink placing a message in the unsent message queue. +215ms azure-iot-amqp-base:SenderLink unsent message queue length is: 1 +0ms

ra-dave commented 2 years ago

Possibly related to this rhea issue?

https://github.com/amqp/rhea/issues/367

anthonyvercolano commented 2 years ago

@RA-David-A Talked with the edge team. They suggested that you repost this issues to github.com/azure/iotedge/issues

ra-dave commented 2 years ago

@anthonyvercolano It turns out that Edge 1.2.7 does have the issue as well. Messages stop sending after 2047.

Given the fact that only the Node.js SDK has this issue and the .NET and Python SDKs do not, I would think this would be a Node.js SDK issue. But I will follow up with the help ticket that we have submitted.