iotedge: edgeHub crashes on raspberry pi with what(): std::bad_alloc
Expected Behavior
edgeHub should run stable for a long time
Current Behavior
edgeHub reproducable crashes with: terminate called after throwing an instance of ‘std::bad_alloc’ what(): std::bad_alloc
Steps to Reproduce
- We send data from a smartphone app to an raspberry pi based edge device (edgeHub) over Wifi (240 - 600 values / sec)
- We analyse the data in a custom module
- The system works fine for approx. 15 - 20 min
- The edgeHub crashes with the error message: terminate called after throwing an instance of ‘std::bad_alloc’ what(): std::bad_alloc
Context (Environment)
Device (Host) Operating System
Raspberry Pi 3 Linux EDGE-GW001 4.14.52-v7+ #1123 SMP Wed Jun 27 17:35:49 BST 2018 armv7l GNU/Linux
Architecture
arm32
Container Operating System
Raspian stretch
Runtime Versions
dotnet: Microsoft .NET Core Shared Framework Host Version : 2.0.9 Build : 1632fa1589b0eee3277a8841ce1770e554ece037
java: openjdk version “1.8.0_171” OpenJDK Runtime Environment (build 1.8.0_171-8u171-b11-1~deb9u1-b11) OpenJDK Client VM (build 25.171-b11, mixed mode)
iotedged
iotedge 1.0.0 (52ef77db24126bf473265fc09c53d35290a2dd6b)
Edge Agent
mcr.microsoft.com/azureiotedge-agent:1.0
Edge Hub
mcr.microsoft.com/azureiotedge-hub:1.0
Docker
Docker version 18.06.0-dev, build daf021fe
Logs
edgeHub:
2018-08-03 06:50:49.384 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17776 with batch size 10.
2018-08-03 06:50:49.385 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 1. Next start offset = 17777.
2018-08-03 06:50:49.386 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.ModuleEndpoint] - Sending 1 message(s) to module GW001/Scoring.
2018-08-03 06:50:49.387 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Sent message with correlation ID ed27a144-72ba-45a2-aacd-8d64c37d07a4 to GW001/Scoring
2018-08-03 06:50:49.413 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Received feedback Complete for message ed27a144-72ba-45a2-aacd-8d64c37d07a4 from device/module GW001/Scoring
2018-08-03 06:50:49.423 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17777 with batch size 10.
2018-08-03 06:50:49.423 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 0. Next start offset = 17777.
2018-08-03 06:50:49.512 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Mqtt.MessagingServiceClient] - Sending message for device Id Sensor1
2018-08-03 06:50:49.513 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.RoutingEdgeHub] - Received message from Sensor1
2018-08-03 06:50:49.514 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17777 with batch size 10.
2018-08-03 06:50:49.573 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 1. Next start offset = 17778.
2018-08-03 06:50:49.574 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.ModuleEndpoint] - Sending 1 message(s) to module GW001/Scoring.
2018-08-03 06:50:49.574 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Sent message with correlation ID 941749f8-bfbd-4268-b3c3-2181f645e154 to GW001/Scoring
2018-08-03 06:50:49.583 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Received feedback Complete for message 941749f8-bfbd-4268-b3c3-2181f645e154 from device/module GW001/Scoring
2018-08-03 06:50:49.586 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17778 with batch size 10.
2018-08-03 06:50:49.587 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 0. Next start offset = 17778.
2018-08-03 06:50:50.379 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Mqtt.MessagingServiceClient] - Sending message for device Id Sensor1
2018-08-03 06:50:50.379 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.RoutingEdgeHub] - Received message from Sensor1
2018-08-03 06:50:50.384 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17778 with batch size 10.
2018-08-03 06:50:50.386 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 1. Next start offset = 17779.
2018-08-03 06:50:50.387 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.ModuleEndpoint] - Sending 1 message(s) to module GW001/Scoring.
2018-08-03 06:50:50.387 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Sent message with correlation ID b2353b2b-265b-4cd2-ac65-ad49aa690e97 to GW001/Scoring
2018-08-03 06:50:50.403 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Received feedback Complete for message b2353b2b-265b-4cd2-ac65-ad49aa690e97 from device/module GW001/Scoring
2018-08-03 06:50:50.405 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17779 with batch size 10.
2018-08-03 06:50:50.406 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 0. Next start offset = 17779.
2018-08-03 06:50:50.481 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Mqtt.MessagingServiceClient] - Sending message for device Id Sensor1
2018-08-03 06:50:50.481 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.RoutingEdgeHub] - Received message from Sensor1
2018-08-03 06:50:50.484 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17779 with batch size 10.
2018-08-03 06:50:50.485 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 1. Next start offset = 17780.
2018-08-03 06:50:50.486 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.ModuleEndpoint] - Sending 1 message(s) to module GW001/Scoring.
2018-08-03 06:50:50.486 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Sent message with correlation ID 8588edcb-b98a-486c-be54-fab1ff365109 to GW001/Scoring
2018-08-03 06:50:50.503 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Received feedback Complete for message 8588edcb-b98a-486c-be54-fab1ff365109 from device/module GW001/Scoring
2018-08-03 06:50:50.505 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17780 with batch size 10.
2018-08-03 06:50:50.506 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 0. Next start offset = 17780.
2018-08-03 06:50:51.379 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Mqtt.MessagingServiceClient] - Sending message for device Id Sensor1
2018-08-03 06:50:51.379 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.RoutingEdgeHub] - Received message from Sensor1
2018-08-03 06:50:51.382 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17780 with batch size 10.
2018-08-03 06:50:51.500 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 1. Next start offset = 17781.
2018-08-03 06:50:51.501 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.ModuleEndpoint] - Sending 1 message(s) to module GW001/Scoring.
2018-08-03 06:50:51.502 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Sent message with correlation ID 7a5e449c-00c1-4918-96e8-10cf50a19310 to GW001/Scoring
2018-08-03 06:50:51.514 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Received feedback Complete for message 7a5e449c-00c1-4918-96e8-10cf50a19310 from device/module GW001/Scoring
2018-08-03 06:50:51.516 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17781 with batch size 10.
2018-08-03 06:50:51.516 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 0. Next start offset = 17781.
2018-08-03 06:50:51.530 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Mqtt.MessagingServiceClient] - Sending message for device Id Sensor1
2018-08-03 06:50:51.530 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.RoutingEdgeHub] - Received message from Sensor1
2018-08-03 06:50:51.531 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17781 with batch size 10.
2018-08-03 06:50:51.533 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 1. Next start offset = 17782.
2018-08-03 06:50:51.534 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.ModuleEndpoint] - Sending 1 message(s) to module GW001/Scoring.
2018-08-03 06:50:51.534 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Sent message with correlation ID 8ae638f4-02f2-45a5-8597-823dba282fe3 to GW001/Scoring
2018-08-03 06:50:51.542 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Received feedback Complete for message 8ae638f4-02f2-45a5-8597-823dba282fe3 from device/module GW001/Scoring
2018-08-03 06:50:51.548 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17782 with batch size 10.
2018-08-03 06:50:51.549 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 0. Next start offset = 17782.
2018-08-03 06:50:52.380 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Mqtt.MessagingServiceClient] - Sending message for device Id Sensor1
2018-08-03 06:50:52.380 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.RoutingEdgeHub] - Received message from Sensor1
2018-08-03 06:50:52.383 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17782 with batch size 10.
2018-08-03 06:50:52.385 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 1. Next start offset = 17783.
2018-08-03 06:50:52.386 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.ModuleEndpoint] - Sending 1 message(s) to module GW001/Scoring.
2018-08-03 06:50:52.387 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Sent message with correlation ID 7f965cb9-564c-4897-a513-d14065bd8801 to GW001/Scoring
2018-08-03 06:50:52.403 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Received feedback Complete for message 7f965cb9-564c-4897-a513-d14065bd8801 from device/module GW001/Scoring
2018-08-03 06:50:52.405 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17783 with batch size 10.
2018-08-03 06:50:52.406 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 0. Next start offset = 17783.
2018-08-03 06:50:52.499 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Mqtt.MessagingServiceClient] - Sending message for device Id Sensor1
2018-08-03 06:50:52.499 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.RoutingEdgeHub] - Received message from Sensor1
2018-08-03 06:50:52.502 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17783 with batch size 10.
2018-08-03 06:50:52.504 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 1. Next start offset = 17784.
2018-08-03 06:50:52.505 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.ModuleEndpoint] - Sending 1 message(s) to module GW001/Scoring.
2018-08-03 06:50:52.506 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Sent message with correlation ID e64b2c8b-ca41-42d9-93d2-ef285f5235ef to GW001/Scoring
2018-08-03 06:50:52.633 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Received feedback Complete for message e64b2c8b-ca41-42d9-93d2-ef285f5235ef from device/module GW001/Scoring
2018-08-03 06:50:52.635 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17784 with batch size 10.
2018-08-03 06:50:52.636 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 0. Next start offset = 17784.
2018-08-03 06:50:53.268 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Sending 10 message(s) upstream.
2018-08-03 06:50:53.268 +00:00 [ERR] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Received message does not contain a device Id
2018-08-03 06:50:53.268 +00:00 [ERR] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Received message does not contain a device Id
2018-08-03 06:50:53.269 +00:00 [ERR] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Received message does not contain a device Id
2018-08-03 06:50:53.269 +00:00 [ERR] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Received message does not contain a device Id
2018-08-03 06:50:53.269 +00:00 [ERR] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Received message does not contain a device Id
2018-08-03 06:50:53.269 +00:00 [ERR] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Received message does not contain a device Id
2018-08-03 06:50:53.269 +00:00 [ERR] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Received message does not contain a device Id
2018-08-03 06:50:53.270 +00:00 [ERR] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Received message does not contain a device Id
2018-08-03 06:50:53.270 +00:00 [ERR] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Received message does not contain a device Id
2018-08-03 06:50:53.270 +00:00 [ERR] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Received message does not contain a device Id
2018-08-03 06:50:53.375 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Mqtt.MessagingServiceClient] - Sending message for device Id Sensor1
2018-08-03 06:50:53.376 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.RoutingEdgeHub] - Received message from Sensor1
2018-08-03 06:50:53.378 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17784 with batch size 10.
2018-08-03 06:50:53.380 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 1. Next start offset = 17785.
2018-08-03 06:50:53.380 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.ModuleEndpoint] - Sending 1 message(s) to module GW001/Scoring.
2018-08-03 06:50:53.381 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Sent message with correlation ID bcbfc024-65ca-467d-b71d-8376f5e311d5 to GW001/Scoring
2018-08-03 06:50:53.394 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Received feedback Complete for message bcbfc024-65ca-467d-b71d-8376f5e311d5 from device/module GW001/Scoring
2018-08-03 06:50:53.396 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17785 with batch size 10.
2018-08-03 06:50:53.397 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 0. Next start offset = 17785.
2018-08-03 06:50:53.518 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Mqtt.MessagingServiceClient] - Sending message for device Id Sensor1
2018-08-03 06:50:53.519 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.RoutingEdgeHub] - Received message from Sensor1
2018-08-03 06:50:53.521 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17785 with batch size 10.
2018-08-03 06:50:53.524 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 1. Next start offset = 17786.
2018-08-03 06:50:53.638 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.ModuleEndpoint] - Sending 1 message(s) to module GW001/Scoring.
2018-08-03 06:50:53.639 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Sent message with correlation ID c55fac11-c170-4d96-8d39-04fd362e70f0 to GW001/Scoring
2018-08-03 06:50:53.653 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Device.DeviceMessageHandler] - Received feedback Complete for message c55fac11-c170-4d96-8d39-04fd362e70f0 from device/module GW001/Scoring
2018-08-03 06:50:53.654 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17786 with batch size 10.
2018-08-03 06:50:53.655 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 0. Next start offset = 17786.
terminate called after throwing an instance of 'std::bad_alloc'
what(): std::bad_alloc
[2018-08-03 06:51:08 +00:00]: Starting Edge Hub
[08/03/2018 06:51:09.533 AM] Edge Hub Main()
2018-08-03 06:51:10.947 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Making a Http call to unix:///var/run/iotedge/workload.sock to CreateServerCertificateAsync
2018-08-03 06:51:12.325 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/workload.sock
2018-08-03 06:51:12.348 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/workload.sock
2018-08-03 06:51:12.380 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://workload.sock/modules/%24edgeHub/genid/636662374498110148/certificate/server?api-version=2018-06-28
2018-08-03 06:51:12.677 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received Created
2018-08-03 06:51:13.086 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Received a valid Http response from unix:///var/run/iotedge/workload.sock for CreateServerCertificateAsync
2018-08-03 06:51:17.285 +00:00 [INF] [EdgeHub] - Starting Edge Hub
2018-08-03 06:51:17.289 +00:00 [INF] [EdgeHub] - Version - 1.0.0.14487025 (52ef77db24126bf473265fc09c53d35290a2dd6b)
2018-08-03 06:51:17.302 +00:00 [INF] [EdgeHub] -
█████╗ ███████╗██╗ ██╗██████╗ ███████╗
██╔══██╗╚══███╔╝██║ ██║██╔══██╗██╔════╝
███████║ ███╔╝ ██║ ██║██████╔╝█████╗
██╔══██║ ███╔╝ ██║ ██║██╔══██╗██╔══╝
██║ ██║███████╗╚██████╔╝██║ ██║███████╗
╚═╝ ╚═╝╚══════╝ ╚═════╝ ╚═╝ ╚═╝╚══════╝
██╗ ██████╗ ████████╗ ███████╗██████╗ ██████╗ ███████╗
██║██╔═══██╗╚══██╔══╝ ██╔════╝██╔══██╗██╔════╝ ██╔════╝
██║██║ ██║ ██║ █████╗ ██║ ██║██║ ███╗█████╗
██║██║ ██║ ██║ ██╔══╝ ██║ ██║██║ ██║██╔══╝
██║╚██████╔╝ ██║ ███████╗██████╔╝╚██████╔╝███████╗
╚═╝ ╚═════╝ ╚═╝ ╚══════╝╚═════╝ ╚═════╝ ╚══════╝
2018-08-03 06:51:17.302 +00:00 [INF] [EdgeHub] - Installing intermediate certificates.
2018-08-03 06:51:17.583 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - Created DeviceConnectivityManager with connected check frequency 00:05:00 and disconnected check frequency 00:02:00
2018-08-03 06:51:17.872 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection] - Attempting to connect to IoT Hub for client GW001/$edgeHub via AMQP...
2018-08-03 06:51:18.216 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection] - Connected to IoT Hub for client GW001/$edgeHub via AMQP, with client operation timeout 60000.
2018-08-03 06:51:18.254 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection] - Updated cloud connection for client GW001/$edgeHub
2018-08-03 06:51:18.258 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection] - Created cloud connection for client GW001/$edgeHub
2018-08-03 06:51:18.265 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - New cloud connection created for device GW001/$edgeHub
2018-08-03 06:51:18.305 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - CloudProxy to test device connectivity set
2018-08-03 06:51:18.305 +00:00 [INF] [EdgeHub] - Initializing configuration
2018-08-03 06:51:28.908 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Service.Modules.RoutingModule] - Created persistent store at /tmp/edgeHub
2018-08-03 06:51:29.063 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Started task to cleanup processed and stale messages
2018-08-03 06:51:29.063 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Created new message store
2018-08-03 06:51:29.360 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Binding cloud listener for device GW001/$edgeHub
2018-08-03 06:51:29.397 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - New device connection for device GW001/$edgeHub
2018-08-03 06:51:29.417 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.RoutingEdgeHub] - Adding subscription DesiredPropertyUpdates for client GW001/$edgeHub.
2018-08-03 06:51:33.877 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Received connection status changed callback with connection status Connected and reason Connection_Ok
2018-08-03 06:51:34.723 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - IotHub call succeeded
2018-08-03 06:51:34.781 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - Entering connected state
2018-08-03 06:51:34.797 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.TwinManager] - ConnectionEstablished for GW001/$edgeHub
2018-08-03 06:51:34.848 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.TwinManager] - Processing ConnectionEstablished for device GW001/$edgeHub
2018-08-03 06:51:34.907 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation UpdateReportedPropertiesAsync succeeded
2018-08-03 06:51:34.915 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Updating reported properties for device GW001/$edgeHub
2018-08-03 06:51:34.924 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.TwinManager] - Successfully sent reported properties to cloud for GW001/$edgeHub and reported properties version 0
2018-08-03 06:51:35.157 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.TwinManager] - Updated cached reported property for GW001/$edgeHub at reported property version 2123 cloudVerified True
2018-08-03 06:51:35.200 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.EdgeHubConnection] - Established IoT Hub connection for edge hub GW001/$edgeHub
2018-08-03 06:51:35.244 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.TwinManager] - Getting twin for GW001/$edgeHub on ConnectionEstablished
2018-08-03 06:51:35.707 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - IotHub call succeeded
2018-08-03 06:51:35.717 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation GetTwinAsync succeeded
2018-08-03 06:51:35.726 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Getting twin for device GW001/$edgeHub
2018-08-03 06:51:35.753 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.TwinManager] - Successfully got twin for GW001/$edgeHub from cloud at desired version 276 reported version 2132
2018-08-03 06:51:35.820 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.TwinManager] - Updating cached twin for GW001/$edgeHub from desired version 275 to 276 and reported version 2123 to 2132
2018-08-03 06:51:35.832 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.TwinManager] - Sending desired property update for GW001/$edgeHub old desired version 275 cloud desired version 276
2018-08-03 06:51:35.855 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.TwinManager] - Sending diff {
"routes": {
"route_2": "FROM /messages/* INTO BrokeredEndpoint(\"/modules/Scoring/inputs/input1\")",
"route_3": null
},
"storeAndForwardConfiguration": {
"timeToLiveSecs": 7200
},
"$version": 276
} to GW001/$edgeHub
2018-08-03 06:51:35.955 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - IotHub call succeeded
2018-08-03 06:51:35.956 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation GetTwinAsync succeeded
2018-08-03 06:51:35.956 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Getting twin for device GW001/$edgeHub
2018-08-03 06:51:35.957 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.TwinManager] - Successfully got twin for GW001/$edgeHub from cloud at desired version 276 reported version 2132
2018-08-03 06:51:35.963 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.TwinManager] - Local twin for GW001/$edgeHub at higher or equal desired version 276 compared to cloud 276 or reported version 2132 compared to cloud 2132
2018-08-03 06:51:37.278 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - IotHub call succeeded
2018-08-03 06:51:37.279 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation UpdateReportedPropertiesAsync succeeded
2018-08-03 06:51:37.279 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Updating reported properties for device GW001/$edgeHub
2018-08-03 06:51:37.279 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.TwinManager] - Successfully sent reported properties to cloud for GW001/$edgeHub and reported properties version 0
2018-08-03 06:51:37.281 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.TwinManager] - Updated cached reported property for GW001/$edgeHub at reported property version 2132 cloudVerified True
2018-08-03 06:51:37.283 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.EdgeHubConnection] - Obtained edge hub config from module twin
2018-08-03 06:51:37.322 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.EdgeHubConnection] - Obtained edge hub config patch update from module twin
2018-08-03 06:51:38.086 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Added sequential store for endpoint iothub
2018-08-03 06:51:38.154 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Added sequential store for endpoint GW001/Scoring/input1
2018-08-03 06:51:38.169 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater] - Set the following 2 route(s) in edge hub
2018-08-03 06:51:38.176 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater] - route_1: FROM /* INTO $upstream
2018-08-03 06:51:38.176 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater] - route_2: FROM /messages/* INTO BrokeredEndpoint("/modules/Scoring/inputs/input1")
2018-08-03 06:51:38.179 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint GW001/Scoring/input1 starting from 17786 with batch size 10.
2018-08-03 06:51:38.179 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 10.
2018-08-03 06:51:38.182 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Updated message store TTL to 7200 seconds
2018-08-03 06:51:38.185 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater] - Updated the edge hub store and forward configuration
2018-08-03 06:51:38.187 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater] - Initialized edge hub configuration
2018-08-03 06:51:38.211 +00:00 [DBG] [EdgeHub] - Waiting on shutdown handler to trigger
2018-08-03 06:51:38.232 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint GW001/Scoring/input1 with batch size 0. Next start offset = 17786.
2018-08-03 06:51:38.377 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 10. Next start offset = 29293.
2018-08-03 06:51:38.504 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Sending 10 message(s) upstream.
2018-08-03 06:51:38.539 +00:00 [ERR] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Received message does not contain a device Id
2018-08-03 06:51:38.540 +00:00 [ERR] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Received message does not contain a device Id
2018-08-03 06:51:38.541 +00:00 [ERR] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Received message does not contain a device Id
2018-08-03 06:51:38.541 +00:00 [ERR] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Received message does not contain a device Id
2018-08-03 06:51:38.541 +00:00 [ERR] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Received message does not contain a device Id
2018-08-03 06:51:38.541 +00:00 [ERR] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Received message does not contain a device Id
2018-08-03 06:51:38.542 +00:00 [ERR] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Received message does not contain a device Id
2018-08-03 06:51:38.542 +00:00 [ERR] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Received message does not contain a device Id
2018-08-03 06:51:38.542 +00:00 [ERR] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Received message does not contain a device Id
2018-08-03 06:51:38.542 +00:00 [ERR] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.CloudEndpoint] - Received message does not contain a device Id
Additional Information
top:
Tasks: 121 total, 1 running, 75 sleeping, 0 stopped, 0 zombie
%Cpu(s): 6.6 us, 2.4 sy, 0.0 ni, 90.8 id, 0.2 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem : 949452 total, 47500 free, 297480 used, 604472 buff/cache
KiB Swap: 102396 total, 95484 free, 6912 used. 552104 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
18492 devicea+ 20 0 2055236 156836 55304 S 14.6 16.5 2:00.36 dotnet
20599 root 20 0 369708 53240 10004 S 8.6 5.6 1:02.04 java
705 root 20 0 981344 82332 26212 S 7.0 8.7 86:46.93 dockerd
20516 root 20 0 793292 2748 2200 S 1.7 0.3 0:09.85 docker-containe
1175 root 20 0 270672 59796 35908 S 1.3 6.3 11:16.38 dotnet
20664 devicea+ 20 0 8256 3000 2540 R 1.0 0.3 0:00.27 top
709 iotedge 20 0 49084 11120 8536 S 0.7 1.2 3:09.75 iotedged
1153 root 20 0 793292 3484 3036 S 0.7 0.4 0:54.10 docker-containe
766 root 20 0 966888 15916 10188 S 0.3 1.7 4:24.87 docker-containe
18474 root 20 0 793228 2908 2200 S 0.3 0.3 0:01.39 docker-containe
19379 root 20 0 0 0 0 I 0.3 0.0 0:00.39 kworker/u8:2
About this issue
- Original URL
- State: closed
- Created 6 years ago
- Comments: 50 (21 by maintainers)
We may have finally found the root cause of this issue. 🎊 This PR has the fix: #1299. It’s still a little early in testing but we are pretty confident this is causing the memory pressure on constrained devices. We will be backporting this to the
1.0.8branch.One thing you can try is to choose either MQTT or AMQP for all clients (devices and modules) to connect to EdgeHub, and then turn off the other protocol head. To do this, set the environment variable amqpSettings__enabled=false or mqttSettings__enabled=false (depending on whether you want to turn off AMQP or MQTT… also note the double underscores) That should reduce the memory pressure on the system.