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
261 stars 227 forks source link

AMQP Transport: Downstream device messages stop sending after 2047 messages #513

Closed danielscholl closed 5 years ago

danielscholl commented 5 years ago

Context

└─┬ azure-iot-device-amqp@1.9.4
  ├─┬ async@2.6.1
  │ └── lodash@4.17.11
  ├─┬ azure-iot-amqp-base@2.2.4
  │ ├── async@2.6.1 deduped
  │ ├── azure-iot-common@1.9.4 deduped
  │ ├── debug@3.2.6 deduped
  │ ├── lodash.merge@4.6.1
  │ ├── machina@4.0.2 deduped
  │ ├── rhea@0.3.11 deduped
  │ ├── uuid@3.3.2 deduped
  │ └─┬ ws@6.2.0
  │   └── async-limiter@1.0.0
  ├─┬ azure-iot-common@1.9.4
  │ └─┬ getos@3.1.1
  │   └── async@2.6.1 deduped
  ├─┬ azure-iot-device@1.9.4
  │ ├── azure-iot-common@1.9.4 deduped
  │ ├─┬ azure-iot-http-base@1.9.4
  │ │ ├── azure-iot-common@1.9.4 deduped
  │ │ ├── debug@3.2.6 deduped
  │ │ └── uuid@3.3.2 deduped
  │ ├─┬ azure-storage@2.10.2
  │ │ ├── browserify-mime@1.2.9
  │ │ ├── extend@3.0.2
  │ │ ├─┬ json-edm-parser@0.1.2
  │ │ │ └── jsonparse@1.2.0
  │ │ ├─┬ md5.js@1.3.4
  │ │ │ ├─┬ hash-base@3.0.4
  │ │ │ │ ├── inherits@2.0.3 deduped
  │ │ │ │ └── safe-buffer@5.1.2 deduped
  │ │ │ └── inherits@2.0.3
  │ │ ├─┬ readable-stream@2.0.6
  │ │ │ ├── core-util-is@1.0.2
  │ │ │ ├── inherits@2.0.3 deduped
  │ │ │ ├── isarray@1.0.0
  │ │ │ ├── process-nextick-args@1.0.7
  │ │ │ ├── string_decoder@0.10.31
  │ │ │ └── util-deprecate@1.0.2
  │ │ ├─┬ request@2.88.0
  │ │ │ ├── aws-sign2@0.7.0
  │ │ │ ├── aws4@1.8.0
  │ │ │ ├── caseless@0.12.0
  │ │ │ ├─┬ combined-stream@1.0.7
  │ │ │ │ └── delayed-stream@1.0.0
  │ │ │ ├── extend@3.0.2 deduped
  │ │ │ ├── forever-agent@0.6.1
  │ │ │ ├─┬ form-data@2.3.3
  │ │ │ │ ├── asynckit@0.4.0
  │ │ │ │ ├── combined-stream@1.0.7 deduped
  │ │ │ │ └── mime-types@2.1.22 deduped
  │ │ │ ├─┬ har-validator@5.1.3
  │ │ │ │ ├─┬ ajv@6.10.0
  │ │ │ │ │ ├── fast-deep-equal@2.0.1
  │ │ │ │ │ ├── fast-json-stable-stringify@2.0.0
  │ │ │ │ │ ├── json-schema-traverse@0.4.1
  │ │ │ │ │ └─┬ uri-js@4.2.2
  │ │ │ │ │   └── punycode@2.1.1
  │ │ │ │ └── har-schema@2.0.0
  │ │ │ ├─┬ http-signature@1.2.0
  │ │ │ │ ├── assert-plus@1.0.0
  │ │ │ │ ├─┬ jsprim@1.4.1
  │ │ │ │ │ ├── assert-plus@1.0.0 deduped
  │ │ │ │ │ ├── extsprintf@1.3.0
  │ │ │ │ │ ├── json-schema@0.2.3
  │ │ │ │ │ └─┬ verror@1.10.0
  │ │ │ │ │   ├── assert-plus@1.0.0 deduped
  │ │ │ │ │   ├── core-util-is@1.0.2 deduped
  │ │ │ │ │   └── extsprintf@1.3.0 deduped
  │ │ │ │ └─┬ sshpk@1.16.1
  │ │ │ │   ├─┬ asn1@0.2.4
  │ │ │ │   │ └── safer-buffer@2.1.2 deduped
  │ │ │ │   ├── assert-plus@1.0.0 deduped
  │ │ │ │   ├─┬ bcrypt-pbkdf@1.0.2
  │ │ │ │   │ └── tweetnacl@0.14.5 deduped
  │ │ │ │   ├─┬ dashdash@1.14.1
  │ │ │ │   │ └── assert-plus@1.0.0 deduped
  │ │ │ │   ├─┬ ecc-jsbn@0.1.2
  │ │ │ │   │ ├── jsbn@0.1.1 deduped
  │ │ │ │   │ └── safer-buffer@2.1.2 deduped
  │ │ │ │   ├─┬ getpass@0.1.7
  │ │ │ │   │ └── assert-plus@1.0.0 deduped
  │ │ │ │   ├── jsbn@0.1.1
  │ │ │ │   ├── safer-buffer@2.1.2
  │ │ │ │   └── tweetnacl@0.14.5
  │ │ │ ├── is-typedarray@1.0.0
  │ │ │ ├── isstream@0.1.2
  │ │ │ ├── json-stringify-safe@5.0.1
  │ │ │ ├─┬ mime-types@2.1.22
  │ │ │ │ └── mime-db@1.38.0
  │ │ │ ├── oauth-sign@0.9.0
  │ │ │ ├── performance-now@2.1.0
  │ │ │ ├── qs@6.5.2
  │ │ │ ├── safe-buffer@5.1.2
  │ │ │ ├─┬ tough-cookie@2.4.3
  │ │ │ │ ├── psl@1.1.31
  │ │ │ │ └── punycode@1.4.1 extraneous
  │ │ │ ├─┬ tunnel-agent@0.6.0
  │ │ │ │ └── safe-buffer@5.1.2 deduped
  │ │ │ └── uuid@3.3.2 deduped
  │ │ ├── underscore@1.8.3
  │ │ ├── uuid@3.3.2 deduped
  │ │ ├── validator@9.4.1
  │ │ ├─┬ xml2js@0.2.8
  │ │ │ └── sax@0.5.8
  │ │ └── xmlbuilder@9.0.7
  │ ├── debug@3.2.6 deduped
  │ ├── lodash@4.17.11 deduped
  │ ├── machina@4.0.2 deduped
  │ └── traverse@0.6.6
  ├─┬ debug@3.2.6
  │ └── ms@2.1.1
  ├─┬ machina@4.0.2
  │ └── lodash@4.17.11 deduped
  ├─┬ rhea@0.3.11
  │ └── debug@3.2.6 deduped
  └── uuid@3.3.2

Description of the issue:

Using the nodejs SDK to send device to cloud messages with the AMQP protocol to an iotedge. The messages are sent successfully at 1 second intervals until 2047 and then messages actually stop being sent with no error being thrown.

Code sample exhibiting the issue:

https://raw.githubusercontent.com/Azure/azure-iot-sdk-node/master/device/samples/edge_downstream_device.js

Console log of the issue:


Sending message: {"deviceId":"myFirstDownstreamDevice","windSpeed":11.6018632088513,"temperature":24.24468229301263,"humidity":78.88646588062446,"count":2044}
    azure-iot-device-amqp:Amqp using existing d2c link +1s
    azure-iot-amqp-base:SenderLink placing a message in the unsent message queue. +932ms
    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] typecode: 69 } }, value: [], descriptor: { [Number: 112] type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Object] }, value: 112 } } +1s
    rhea:message Encoding section 2 of 4: Typed { type: TypeDesc { name: 'List32', typecode: 208, width: 4, category: 3, create: { [Function] typecode: 208 } }, value: [ <2 empty items>, Typed { type: [Object], value: '/devices/device/messages/events' } ], descriptor: { [Number: 115] type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Object] }, value: 115 } } +2ms
    rhea:message Encoding section 3 of 4: Typed { type: TypeDesc { name: 'Map32', typecode: 209, width: 4, category: 3, create: { [Function] typecode: 209 } }, value: [ Typed { type: [Object], value: 'temperatureAlert' }, Typed { type: [Object], value: 'false' } ], descriptor: { [Number: 116] type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Object] }, value: 116 } } +3ms
    rhea:message Encoding section 4 of 4: Typed { type: TypeDesc { name: 'Vbin8', typecode: 160, width: 1, category: 2, create: { [Function] 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 ... >, descriptor: { [Number: 117] type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Object] }, value: 117 } } +13ms
    rhea:message encoded 234 bytes +2ms
    azure-iot-amqp-base:SenderLink message placed in dictionary for lookup later. +20ms
    rhea:frames [connection-1]:0 -> transfer#14 {"handle":3,"delivery_id":2044,"delivery_tag":{"type":"Buffer","data":[50,48,52,51]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 27 00 00 00 03 40 40 a1 1f 2f 64 65 76 69 63 65 73 2f 64 65 76 69 63 65 2f 6d 65 73 73 61 67 65 73 2f 65 76 65 6e 74 ... > +956ms
    rhea:raw [connection-1] SENT: 270 0000010e02000000005314d00000001400000006520370000007fca0043230343343424200537045005373d000000027000000034040a11f2f646576696365732f6465766963652f6d657373616765732f6576656e7473005374d10000001d00000002a11074656d7065726174757265416c657274a10566616c7365005375a08d7b226465766963654964223a226d794669727374446f776e73747265616d446576696365222c2277696e645370656564223a31312e363031383633323038383531332c2274656d7065726174757265223a32342e32343436383232393330313236332c2268756d6964697479223a37382e38383634363538383036323434362c22636f756e74223a323034347d +958ms
    rhea:io [connection-1] read 27 bytes +1s
    rhea:io [connection-1] got frame of size 27 +1ms
    rhea:raw [connection-1] RECV: 27 0000001b02000000005315c00e064170000007fc40410053244540 +73ms
    rhea:frames [connection-1]:0 <- disposition#15 {"role":true,"first":2044,"settled":true,"state":[]}  +74ms
    rhea:events [connection-1] Received disposition for outgoing transfers +1s
    rhea:events [connection-1] Link got event: accepted +0ms
    azure-iot-amqp-base:SenderLink in sender attached state - accepted event for rheaSender_b7efa7d0-d614-48be-8835-895652f7eeda +77ms
send status: MessageEnqueued
    rhea:events [connection-1] Link got event: settled +2ms
    rhea:events [connection-1] Session got event: settled +0ms
    rhea:events [connection-1] Connection got event: settled +1ms
    rhea:events [ad6e5716-6886-7f48-9a46-319d3d730779] Container got event: settled +0ms

Sending message: {"deviceId":"myFirstDownstreamDevice","windSpeed":11.20533813490462,"temperature":25.230561735528166,"humidity":67.13461588963159,"count":2045}
    azure-iot-device-amqp:Amqp using existing d2c link +1s
    azure-iot-amqp-base:SenderLink placing a message in the unsent message queue. +929ms
    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] typecode: 69 } }, value: [], descriptor: { [Number: 112] type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Object] }, value: 112 } } +1s
    rhea:message Encoding section 2 of 4: Typed { type: TypeDesc { name: 'List32', typecode: 208, width: 4, category: 3, create: { [Function] typecode: 208 } }, value: [ <2 empty items>, Typed { type: [Object], value: '/devices/device/messages/events' } ], descriptor: { [Number: 115] type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Object] }, value: 115 } } +3ms
    rhea:message Encoding section 3 of 4: Typed { type: TypeDesc { name: 'Map32', typecode: 209, width: 4, category: 3, create: { [Function] typecode: 209 } }, value: [ Typed { type: [Object], value: 'temperatureAlert' }, Typed { type: [Object], value: 'false' } ], descriptor: { [Number: 116] type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Object] }, value: 116 } } +16ms
    rhea:message Encoding section 4 of 4: Typed { type: TypeDesc { name: 'Vbin8', typecode: 160, width: 1, category: 2, create: { [Function] 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 ... >, descriptor: { [Number: 117] type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Object] }, value: 117 } } +1ms
    rhea:message encoded 236 bytes +2ms
    azure-iot-amqp-base:SenderLink message placed in dictionary for lookup later. +23ms
    rhea:frames [connection-1]:0 -> transfer#14 {"handle":3,"delivery_id":2045,"delivery_tag":{"type":"Buffer","data":[50,48,52,52]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 27 00 00 00 03 40 40 a1 1f 2f 64 65 76 69 63 65 73 2f 64 65 76 69 63 65 2f 6d 65 73 73 61 67 65 73 2f 65 76 65 6e 74 ... > +956ms
    rhea:raw [connection-1] SENT: 272 0000011002000000005314d00000001400000006520370000007fda0043230343443424200537045005373d000000027000000034040a11f2f646576696365732f6465766963652f6d657373616765732f6576656e7473005374d10000001d00000002a11074656d7065726174757265416c657274a10566616c7365005375a08f7b226465766963654964223a226d794669727374446f776e73747265616d446576696365222c2277696e645370656564223a31312e32303533333831333439303436322c2274656d7065726174757265223a32352e3233303536313733353532383136362c2268756d6964697479223a36372e31333436313538383936333135392c22636f756e74223a323034357d +957ms
    rhea:io [connection-1] read 27 bytes +1s
    rhea:io [connection-1] got frame of size 27 +1ms
    rhea:raw [connection-1] RECV: 27 0000001b02000000005315c00e064170000007fd40410053244540 +71ms
    rhea:frames [connection-1]:0 <- disposition#15 {"role":true,"first":2045,"settled":true,"state":[]}  +73ms
    rhea:events [connection-1] Received disposition for outgoing transfers +1s
    rhea:events [connection-1] Link got event: accepted +1ms
    azure-iot-amqp-base:SenderLink in sender attached state - accepted event for rheaSender_b7efa7d0-d614-48be-8835-895652f7eeda +75ms
send status: MessageEnqueued
    rhea:events [connection-1] Link got event: settled +1ms
    rhea:events [connection-1] Session got event: settled +1ms
    rhea:events [connection-1] Connection got event: settled +0ms
    rhea:events [ad6e5716-6886-7f48-9a46-319d3d730779] Container got event: settled +0ms

Sending message: {"deviceId":"myFirstDownstreamDevice","windSpeed":12.768968070326174,"temperature":27.173105617473297,"humidity":61.55267434775055,"count":2046}
    azure-iot-device-amqp:Amqp using existing d2c link +1s
    azure-iot-amqp-base:SenderLink placing a message in the unsent message queue. +928ms
    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] typecode: 69 } }, value: [], descriptor: { [Number: 112] type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Object] }, value: 112 } } +1s
    rhea:message Encoding section 2 of 4: Typed { type: TypeDesc { name: 'List32', typecode: 208, width: 4, category: 3, create: { [Function] typecode: 208 } }, value: [ <2 empty items>, Typed { type: [Object], value: '/devices/device/messages/events' } ], descriptor: { [Number: 115] type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Object] }, value: 115 } } +1ms
    rhea:message Encoding section 3 of 4: Typed { type: TypeDesc { name: 'Map32', typecode: 209, width: 4, category: 3, create: { [Function] typecode: 209 } }, value: [ Typed { type: [Object], value: 'temperatureAlert' }, Typed { type: [Object], value: 'false' } ], descriptor: { [Number: 116] type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Object] }, value: 116 } } +1ms
    rhea:message Encoding section 4 of 4: Typed { type: TypeDesc { name: 'Vbin8', typecode: 160, width: 1, category: 2, create: { [Function] 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 ... >, descriptor: { [Number: 117] type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Object] }, value: 117 } } +1ms
    rhea:message encoded 237 bytes +1ms
    azure-iot-amqp-base:SenderLink message placed in dictionary for lookup later. +5ms
    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 27 00 00 00 03 40 40 a1 1f 2f 64 65 76 69 63 65 73 2f 64 65 76 69 63 65 2f 6d 65 73 73 61 67 65 73 2f 65 76 65 6e 74 ... > +935ms
    rhea:raw [connection-1] SENT: 273 0000011102000000005314d00000001400000006520370000007fea0043230343543424200537045005373d000000027000000034040a11f2f646576696365732f6465766963652f6d657373616765732f6576656e7473005374d10000001d00000002a11074656d7065726174757265416c657274a10566616c7365005375a0907b226465766963654964223a226d794669727374446f776e73747265616d446576696365222c2277696e645370656564223a31322e3736383936383037303332363137342c2274656d7065726174757265223a32372e3137333130353631373437333239372c2268756d6964697479223a36312e35353236373433343737353035352c22636f756e74223a323034367d +937ms
    rhea:io [connection-1] read 27 bytes +1s
    rhea:io [connection-1] got frame of size 27 +3ms
    rhea:raw [connection-1] RECV: 27 0000001b02000000005315c00e064170000007fe40410053244540 +74ms
    rhea:frames [connection-1]:0 <- disposition#15 {"role":true,"first":2046,"settled":true,"state":[]}  +76ms
    rhea:events [connection-1] Received disposition for outgoing transfers +1s
    rhea:events [connection-1] Link got event: accepted +1ms
    azure-iot-amqp-base:SenderLink in sender attached state - accepted event for rheaSender_b7efa7d0-d614-48be-8835-895652f7eeda +81ms
send status: MessageEnqueued
    rhea:events [connection-1] Link got event: settled +3ms
    rhea:events [connection-1] Session got event: settled +1ms
    rhea:events [connection-1] Connection got event: settled +32ms
    rhea:events [ad6e5716-6886-7f48-9a46-319d3d730779] Container got event: settled +1ms

Sending message: {"deviceId":"myFirstDownstreamDevice","windSpeed":12.6262082039516,"temperature":27.65154102111438,"humidity":79.21827714676931,"count":2047}
    azure-iot-device-amqp:Amqp using existing d2c link +1s
    azure-iot-amqp-base:SenderLink placing a message in the unsent message queue. +925ms
    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] typecode: 69 } }, value: [], descriptor: { [Number: 112] type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Object] }, value: 112 } } +1s
    rhea:message Encoding section 2 of 4: Typed { type: TypeDesc { name: 'List32', typecode: 208, width: 4, category: 3, create: { [Function] typecode: 208 } }, value: [ <2 empty items>, Typed { type: [Object], value: '/devices/device/messages/events' } ], descriptor: { [Number: 115] type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Object] }, value: 115 } } +3ms
    rhea:message Encoding section 3 of 4: Typed { type: TypeDesc { name: 'Map32', typecode: 209, width: 4, category: 3, create: { [Function] typecode: 209 } }, value: [ Typed { type: [Object], value: 'temperatureAlert' }, Typed { type: [Object], value: 'false' } ], descriptor: { [Number: 116] type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Object] }, value: 116 } } +2ms
    rhea:message Encoding section 4 of 4: Typed { type: TypeDesc { name: 'Vbin8', typecode: 160, width: 1, category: 2, create: { [Function] 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 ... >, descriptor: { [Number: 117] type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Object] }, value: 117 } } +14ms
    rhea:message encoded 234 bytes +2ms
    azure-iot-amqp-base:SenderLink message placed in dictionary for lookup later. +23ms
    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 27 00 00 00 03 40 40 a1 1f 2f 64 65 76 69 63 65 73 2f 64 65 76 69 63 65 2f 6d 65 73 73 61 67 65 73 2f 65 76 65 6e 74 ... > +952ms
    rhea:raw [connection-1] SENT: 270 0000010e02000000005314d00000001400000006520370000007ffa0043230343643424200537045005373d000000027000000034040a11f2f646576696365732f6465766963652f6d657373616765732f6576656e7473005374d10000001d00000002a11074656d7065726174757265416c657274a10566616c7365005375a08d7b226465766963654964223a226d794669727374446f776e73747265616d446576696365222c2277696e645370656564223a31322e363236323038323033393531362c2274656d7065726174757265223a32372e36353135343130323131313433382c2268756d6964697479223a37392e32313832373731343637363933312c22636f756e74223a323034377d +954ms
    rhea:io [connection-1] read 27 bytes +1s
    rhea:io [connection-1] got frame of size 27 +1ms
    rhea:raw [connection-1] RECV: 27 0000001b02000000005315c00e064170000007ff40410053244540 +67ms
    rhea:frames [connection-1]:0 <- disposition#15 {"role":true,"first":2047,"settled":true,"state":[]}  +69ms
    rhea:events [connection-1] Received disposition for outgoing transfers +981ms
    rhea:events [connection-1] Link got event: accepted +1ms
    azure-iot-amqp-base:SenderLink in sender attached state - accepted event for rheaSender_b7efa7d0-d614-48be-8835-895652f7eeda +70ms
send status: MessageEnqueued
    rhea:events [connection-1] Link got event: settled +1ms
    rhea:events [connection-1] Session got event: settled +1ms
    rhea:events [connection-1] Connection got event: settled +0ms
    rhea:events [ad6e5716-6886-7f48-9a46-319d3d730779] Container got event: settled +1ms

Sending message: {"deviceId":"myFirstDownstreamDevice","windSpeed":10.422274644162668,"temperature":27.78090017046823,"humidity":79.37329840611494,"count":2048}
    azure-iot-device-amqp:Amqp using existing d2c link +1s
    azure-iot-amqp-base:SenderLink placing a message in the unsent message queue. +933ms

Sending message: {"deviceId":"myFirstDownstreamDevice","windSpeed":10.751784802513274,"temperature":25.1391390543233,"humidity":67.02708964116104,"count":2049}
    azure-iot-device-amqp:Amqp using existing d2c link +1s
    azure-iot-amqp-base:SenderLink placing a message in the unsent message queue. +1s

Sending message: {"deviceId":"myFirstDownstreamDevice","windSpeed":10.84654539451935,"temperature":23.020756782142072,"humidity":65.24815239456227,"count":2050}
    azure-iot-device-amqp:Amqp using existing d2c link +1s
    azure-iot-amqp-base:SenderLink placing a message in the unsent message queue. +1s

Sending message: {"deviceId":"myFirstDownstreamDevice","windSpeed":11.760019047719661,"temperature":26.661371589481995,"humidity":70.26475521477775,"count":2051}
    azure-iot-device-amqp:Amqp using existing d2c link +1s
    azure-iot-amqp-base:SenderLink placing a message in the unsent message queue. +1s
anthonyvercolano commented 5 years ago

@danielscholl thank you for the issue.

We'll be looking at this right away. Will be examining the flow control state to see where things are going wrong.

The messages are clearly being queued in the iot amqp transport. The only reason they aren't going out on the wire would be if the amqp transport RHEA is indicating that it is not in a sendable state. Don't think that this is a RHEA problem though.

danielscholl commented 5 years ago

@anthonyvercolano this issue is resolved in release 1.11.0.

├─┬ azure-iot-device@1.11.0 │ ├─┬ azure-iot-common@1.10.1 │ │ ├── debug@4.1.1 deduped │ │ └─┬ getos@3.1.1 │ │ └─┬ async@2.6.1 │ │ └── lodash@4.17.15 deduped │ ├─┬ azure-iot-http-base@1.9.10 │ │ ├── azure-iot-common@1.10.1 deduped │ │ ├── debug@4.1.1 deduped │ │ └── uuid@3.3.3 deduped │ ├─┬ azure-storage@2.10.3 │ │ ├── browserify-mime@1.2.9 │ │ ├── extend@3.0.2 │ │ ├─┬ json-edm-parser@0.1.2 │ │ │ └── jsonparse@1.2.0 │ │ ├─┬ md5.js@1.3.4 │ │ │ ├─┬ hash-base@3.0.4 │ │ │ │ ├── inherits@2.0.4 deduped │ │ │ │ └── safe-buffer@5.2.0 deduped │ │ │ └── inherits@2.0.4 │ │ ├─┬ readable-stream@2.0.6 │ │ │ ├── core-util-is@1.0.2 │ │ │ ├── inherits@2.0.4 deduped │ │ │ ├── isarray@1.0.0 │ │ │ ├── process-nextick-args@1.0.7 │ │ │ ├── string_decoder@0.10.31 │ │ │ └── util-deprecate@1.0.2 │ │ ├─┬ request@2.88.0 │ │ │ ├── aws-sign2@0.7.0 │ │ │ ├── aws4@1.8.0 │ │ │ ├── caseless@0.12.0 │ │ │ ├─┬ combined-stream@1.0.8 │ │ │ │ └── delayed-stream@1.0.0 │ │ │ ├── extend@3.0.2 deduped │ │ │ ├── forever-agent@0.6.1 │ │ │ ├─┬ form-data@2.3.3 │ │ │ │ ├── asynckit@0.4.0 │ │ │ │ ├── combined-stream@1.0.8 deduped │ │ │ │ └── mime-types@2.1.24 deduped │ │ │ ├─┬ har-validator@5.1.3 │ │ │ │ ├─┬ ajv@6.10.2 │ │ │ │ │ ├── fast-deep-equal@2.0.1 │ │ │ │ │ ├── fast-json-stable-stringify@2.0.0 │ │ │ │ │ ├── json-schema-traverse@0.4.1 │ │ │ │ │ └─┬ uri-js@4.2.2 │ │ │ │ │ └── punycode@2.1.1 │ │ │ │ └── har-schema@2.0.0 │ │ │ ├─┬ http-signature@1.2.0 │ │ │ │ ├── assert-plus@1.0.0 │ │ │ │ ├─┬ jsprim@1.4.1 │ │ │ │ │ ├── assert-plus@1.0.0 deduped │ │ │ │ │ ├── extsprintf@1.3.0 │ │ │ │ │ ├── json-schema@0.2.3 │ │ │ │ │ └─┬ verror@1.10.0 │ │ │ │ │ ├── assert-plus@1.0.0 deduped │ │ │ │ │ ├── core-util-is@1.0.2 deduped │ │ │ │ │ └── extsprintf@1.3.0 deduped │ │ │ │ └─┬ sshpk@1.16.1 │ │ │ │ ├─┬ asn1@0.2.4 │ │ │ │ │ └── safer-buffer@2.1.2 deduped │ │ │ │ ├── assert-plus@1.0.0 deduped │ │ │ │ ├─┬ bcrypt-pbkdf@1.0.2 │ │ │ │ │ └── tweetnacl@0.14.5 deduped │ │ │ │ ├─┬ dashdash@1.14.1 │ │ │ │ │ └── assert-plus@1.0.0 deduped │ │ │ │ ├─┬ ecc-jsbn@0.1.2 │ │ │ │ │ ├── jsbn@0.1.1 deduped │ │ │ │ │ └── safer-buffer@2.1.2 deduped │ │ │ │ ├─┬ getpass@0.1.7 │ │ │ │ │ └── assert-plus@1.0.0 deduped │ │ │ │ ├── jsbn@0.1.1 │ │ │ │ ├── safer-buffer@2.1.2 │ │ │ │ └── tweetnacl@0.14.5 │ │ │ ├── is-typedarray@1.0.0 │ │ │ ├── isstream@0.1.2 │ │ │ ├── json-stringify-safe@5.0.1 │ │ │ ├─┬ mime-types@2.1.24 │ │ │ │ └── mime-db@1.40.0 │ │ │ ├── oauth-sign@0.9.0 │ │ │ ├── performance-now@2.1.0 │ │ │ ├── qs@6.5.2 │ │ │ ├── safe-buffer@5.2.0 │ │ │ ├─┬ tough-cookie@2.4.3 │ │ │ │ ├── psl@1.3.0 │ │ │ │ └── punycode@1.4.1 │ │ │ ├─┬ tunnel-agent@0.6.0 │ │ │ │ └── safe-buffer@5.2.0 deduped │ │ │ └── uuid@3.3.3 deduped │ │ ├── underscore@1.8.3 │ │ ├── uuid@3.3.3 deduped │ │ ├── validator@9.4.1 │ │ ├─┬ xml2js@0.2.8 │ │ │ └── sax@0.5.8 │ │ └── xmlbuilder@9.0.7 │ ├─┬ debug@4.1.1 │ │ └── ms@2.1.2 │ ├── lodash@4.17.15 │ ├─┬ machina@4.0.2 │ │ └── lodash@4.17.15 deduped │ └── traverse@0.6.6 └─┬ azure-iot-device-amqp@1.10.1 ├─┬ async@2.6.3 │ └── lodash@4.17.15 deduped ├─┬ azure-iot-amqp-base@2.2.11 │ ├─┬ async@2.6.3 │ │ └── lodash@4.17.15 deduped │ ├── azure-iot-common@1.10.1 deduped │ ├── debug@4.1.1 deduped │ ├── lodash.merge@4.6.2 │ ├── machina@4.0.2 deduped │ ├── rhea@1.0.8 deduped │ ├── uuid@3.3.3 deduped │ └─┬ ws@6.2.1 │ └── async-limiter@1.0.1 ├── azure-iot-common@1.10.1 deduped ├── azure-iot-device@1.11.0 deduped ├── debug@4.1.1 deduped ├── machina@4.0.2 deduped ├─┬ rhea@1.0.8 │ └─┬ debug@3.2.6 │ └── ms@2.1.2 deduped └── uuid@3.3.3

pierreca commented 5 years ago

That's great to hear :) closing the issue. Thanks!

az-iot-builder-01 commented 5 years ago

@danielscholl, thank you for your contribution to our open-sourced project! Please help us improve by filling out this 2-minute customer satisfaction survey