AMQP transport: downstream device messages stop sending after 2048 messages, recovers after about 25 minutes then repeats the cycle #6036
Comments
ra-dave
changed the title
|
@RA-David-A FYI: This is definitely triggering, what until now, was the theoretical issue that was noted in amqp/rhea#367 |
|
edgeHub is not disposing put-token message which triggers the issue in rhea. I am working on a fix in edgeHub. The workaround for now is if you could use MQTT protocol head until fix is released. |
@ancaantochi So is this fix going to be in Edge or in the Node.js SDK? |
|
I will fix edgeHub to dispose put-token message and this will solve the nodejs issue in most cases. The issue in rhea could still happen in cases the disposition message is lost until amqp/rhea#367 is fixed. |
|
@ancaantochi I guess what I want to know is, once the fix is in Edge our product will just start working without having to make a new release with an updated Node.js SDK, right? Not including rhea#367 of course. And will this just be an update to Edge 1.2 or will there be an update to the 1.1 LTS as well? |
|
yes, Nodejs SDK won't need to be updated. The fix is planned for edgeHub 1.2 |
Fixes #6036 * dispose message ## Azure IoT Edge PR checklist: This checklist is used to make sure that common guidelines for a pull request are followed. ### General Guidelines and Best Practices - [x] I have read the [contribution guidelines](https://github.com/azure/iotedge#contributing). - [x] Title of the pull request is clear and informative. - [x] Description of the pull request includes a concise summary of the enhancement or bug fix. ### Testing Guidelines - [x] Pull request includes test coverage for the included changes. - Description of the pull request includes - [x] concise summary of tests added/modified - [x] local testing done.
Fixes Azure#6036 * dispose message ## Azure IoT Edge PR checklist: This checklist is used to make sure that common guidelines for a pull request are followed. ### General Guidelines and Best Practices - [x] I have read the [contribution guidelines](https://github.com/azure/iotedge#contributing). - [x] Title of the pull request is clear and informative. - [x] Description of the pull request includes a concise summary of the enhancement or bug fix. ### Testing Guidelines - [x] Pull request includes test coverage for the included changes. - Description of the pull request includes - [x] concise summary of tests added/modified - [x] local testing done.
Fixes #6036 * dispose message ## Azure IoT Edge PR checklist: This checklist is used to make sure that common guidelines for a pull request are followed. ### General Guidelines and Best Practices - [x] I have read the [contribution guidelines](https://github.com/azure/iotedge#contributing). - [x] Title of the pull request is clear and informative. - [x] Description of the pull request includes a concise summary of the enhancement or bug fix. ### Testing Guidelines - [x] Pull request includes test coverage for the included changes. - Description of the pull request includes - [x] concise summary of tests added/modified - [x] local testing done. ***Please replace this line with your PR description and read PR checklist below*** ## Azure IoT Edge PR checklist: This checklist is used to make sure that common guidelines for a pull request are followed. ### General Guidelines and Best Practices - [ ] I have read the [contribution guidelines](https://github.com/azure/iotedge#contributing). - [x] Title of the pull request is clear and informative. - [x] Description of the pull request includes a concise summary of the enhancement or bug fix. ### Testing Guidelines - [ ] Pull request includes test coverage for the included changes. - Description of the pull request includes - [ ] concise summary of tests added/modified - [ ] local testing done.
|
This issue is being marked as stale because it has been open for 30 days with no activity. |
|
Issue is fixed in 1.2.9 edgeHub release |
Expected Behavior
Messages should not stop flowing from client to cloud.
Current Behavior
Messages stop flowing after 2048 messages have been sent. The circular buffer in the rhea library in the IoT Node.js SDK is filling up, preventing any more messages from being queued.
Steps to Reproduce
Very simple. Use the edge_downstream_device.js sample code from the IoT SDK for Node.js with an edge runtime (any version). The client will stop sending messages after 2048 messages. After some period of time (approx 25 minutes, but it depends on the message sending interval) the connection will be reestablished and another 2048 messages will be sent.
This issue only occurs when using edge. If the client connects directly to Azure Hub it does not occur.
Context (Environment)
OS and version used: Windows Server 2019 Standard Evaluation, version 1809, OS build 17763.737 with Edge 1.1.8
Also used Ubuntu 18.04 with Edge 1.2.7
Node.js version: 16.13.2
npm version: 8.1.2
Output of
iotedge checkConfiguration checks (aziot-identity-service)
√ keyd configuration is well-formed - OK
√ certd configuration is well-formed - OK
√ tpmd configuration is well-formed - OK
√ identityd configuration is well-formed - OK
√ daemon configurations up-to-date with config.toml - OK
√ identityd config toml file specifies a valid hostname - OK
√ aziot-identity-service package is up-to-date - OK
√ host time is close to reference time - OK
√ preloaded certificates are valid - OK
√ keyd is running - OK
√ certd is running - OK
√ identityd is running - OK
√ read all preloaded certificates from the Certificates Service - OK
√ read all preloaded key pairs from the Keys Service - OK
√ ensure all preloaded certificates match preloaded private keys with the same ID - OK
Connectivity checks (aziot-identity-service)
√ host can connect to and perform TLS handshake with iothub AMQP port - OK
√ host can connect to and perform TLS handshake with iothub HTTPS / WebSockets port - OK
√ host can connect to and perform TLS handshake with iothub MQTT port - OK
Configuration checks
√ aziot-edged configuration is well-formed - OK
√ configuration up-to-date with config.toml - OK
√ container engine is installed and functional - OK
√ configuration has correct URIs for daemon mgmt endpoint - OK
√ aziot-edge package is up-to-date - OK
√ container time is close to host time - OK
‼ DNS server - Warning
Container engine is not configured with DNS server setting, which may impact connectivity to IoT Hub.
Please see https://aka.ms/iotedge-prod-checklist-dns for best practices.
You can ignore this warning if you are setting DNS server per module in the Edge deployment.
‼ production readiness: logs policy - Warning
Container engine is not configured to rotate module logs which may cause it run out of disk space.
Please see https://aka.ms/iotedge-prod-checklist-logs for best practices.
You can ignore this warning if you are setting log policy per module in the Edge deployment.
‼ production readiness: Edge Agent's storage directory is persisted on the host filesystem - Warning
The edgeAgent module is not configured to persist its /tmp/edgeAgent directory on the host filesystem.
Data might be lost if the module is deleted or updated.
Please see https://aka.ms/iotedge-storage-host for best practices.
‼ production readiness: Edge Hub's storage directory is persisted on the host filesystem - Warning
The edgeHub module is not configured to persist its /tmp/edgeHub directory on the host filesystem.
Data might be lost if the module is deleted or updated.
Please see https://aka.ms/iotedge-storage-host for best practices.
√ Agent image is valid and can be pulled from upstream - OK
√ proxy settings are consistent in aziot-edged, aziot-identityd, moby daemon and config.toml - OK
Connectivity checks
√ container on the default network can connect to upstream AMQP port - OK
√ container on the default network can connect to upstream HTTPS / WebSockets port - OK
√ container on the default network can connect to upstream MQTT port - OK
√ container on the IoT Edge module network can connect to upstream AMQP port - OK
√ container on the IoT Edge module network can connect to upstream HTTPS / WebSockets port - OK
√ container on the IoT Edge module network can connect to upstream MQTT port - OK
32 check(s) succeeded.
4 check(s) raised warnings. Re-run with --verbose for more details.
Logs
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
Additional Information
This issue does not occur with the .NET or the Python IoT SDKs.
I can post more logs if needed but quite frankly this is so easy to reproduce and the logs are providing little information I think it would be best for the devs to just reproduce and debug.
The text was updated successfully, but these errors were encountered: