iotedge: Memory Leak in an embedded Linux environment

Expected Behavior

The device on which IoT Edge is running should have a constant memory use, after a post-boot transition phase.

Current Behavior

The memory use of the device keeps increasing until it becomes unresponsive due to low memory availability.

Steps to Reproduce

  1. Install IoT Edge on an embedded Linux device (Raspberry Pi CM3+ in our case)
  2. Add the edgeHub and edgeAgent modules to its deployment
  3. Start IoT Edge
  4. Observe the memory usage increase over the course of multiple days, until the device becomes unresponsive to SSH connections.

Context (Environment)

Output of iotedge check

Click here 
Configuration checks
--------------------
√ config.yaml is well-formed - OK
√ config.yaml has well-formed connection string - OK
√ container engine is installed and functional - OK
√ config.yaml has correct hostname - OK
√ config.yaml has correct URIs for daemon mgmt endpoint - OK
‼ latest security daemon - Warning
    Installed IoT Edge daemon has version 1.0.10 but 1.1.0 is the latest stable version available.
    Please see https://aka.ms/iotedge-update-runtime for update instructions.
√ host time is close to real time - OK
√ container time is close to host time - OK
√ DNS server - OK
‼ production readiness: certificates - Warning
    The Edge device is using self-signed automatically-generated development certificates.
    They will expire in 5469 days (at 2036-02-22 17:47:54 UTC) causing module-to-module and downstream device communication to fail on an active deployment.
    After the certs have expired, restarting the IoT Edge daemon will trigger it to generate new development certs.
    Please consider using production certificates instead. See https://aka.ms/iotedge-prod-checklist-certs for best practices.
√ production readiness: container engine - OK
‼ 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.

Connectivity checks
-------------------
√ host can connect to and perform TLS handshake with DPS endpoint - OK
√ host can connect to and perform TLS handshake with IoT Hub AMQP port - OK
√ host can connect to and perform TLS handshake with IoT Hub HTTPS / WebSockets port - OK
√ host can connect to and perform TLS handshake with IoT Hub MQTT port - OK
√ container on the default network can connect to IoT Hub AMQP port - OK
√ container on the default network can connect to IoT Hub HTTPS / WebSockets port - OK
√ container on the default network can connect to IoT Hub MQTT port - OK
√ container on the IoT Edge module network can connect to IoT Hub AMQP port - OK
√ container on the IoT Edge module network can connect to IoT Hub HTTPS / WebSockets port - OK
√ container on the IoT Edge module network can connect to IoT Hub MQTT port - OK

19 check(s) succeeded.
5 check(s) raised warnings. Re-run with --verbose for more details.

Device Information

  • Host OS: Custom Debian 10 (buster), on a RevolutionPi CM3+, with a 4.19.95-rt38-v7 kernel
  • Architecture: arm32
  • Container OS: Linux Containers

Runtime Versions

  • aziot-edged: iotedge 1.0.10
  • Edge Agent: 1.0.10
  • Edge Hub: 1.0.10
  • Docker/Moby: 3.0.13+azure

Logs

These logs correspond to the startup sequence of iotedge on a nominal device, that exhibits a memory leak.

iotedged logs 
Mar 03 14:29:43 redacted_hostname systemd[1]: Starting Azure IoT Edge daemon...
Mar 03 14:29:43 redacted_hostname systemd[1]: Started Azure IoT Edge daemon.
Mar 03 14:29:43 redacted_hostname iotedged[1249]: 2021-03-03T13:29:43Z [INFO] - Starting Azure IoT Edge Security Daemon
Mar 03 14:29:43 redacted_hostname iotedged[1249]: 2021-03-03T13:29:43Z [INFO] - Version - 1.0.10
Mar 03 14:29:43 redacted_hostname iotedged[1249]: 2021-03-03T13:29:43Z [INFO] - Using config file: /etc/iotedge/config.yaml
Mar 03 14:29:43 redacted_hostname iotedged[1249]: 2021-03-03T13:29:43Z [INFO] - Configuring /var/lib/iotedge as the home directory.
Mar 03 14:29:43 redacted_hostname iotedged[1249]: 2021-03-03T13:29:43Z [INFO] - Configuring certificates...
Mar 03 14:29:43 redacted_hostname iotedged[1249]: 2021-03-03T13:29:43Z [INFO] - Transparent gateway certificates not found, operating in quick start mode...
Mar 03 14:29:43 redacted_hostname iotedged[1249]: 2021-03-03T13:29:43Z [INFO] - Finished configuring provisioning environment variables and certificates.
Mar 03 14:29:43 redacted_hostname iotedged[1249]: 2021-03-03T13:29:43Z [INFO] - Initializing hsm...
Mar 03 14:29:55 redacted_hostname iotedged[1249]: 2021-03-03T13:29:55Z [INFO] - Finished initializing hsm.
Mar 03 14:29:55 redacted_hostname iotedged[1249]: 2021-03-03T13:29:55Z [INFO] - Provisioning edge device...
Mar 03 14:29:55 redacted_hostname iotedged[1249]: 2021-03-03T13:29:55Z [INFO] - Starting provisioning edge device via TPM...
Mar 03 14:29:55 redacted_hostname iotedged[1249]: 2021-03-03T13:29:55Z [INFO] - Starting DPS registration with scope_id "redacted_scope", registration_id "redacted_id"
Mar 03 14:30:10 redacted_hostname iotedged[1249]: 2021-03-03T13:30:10Z [INFO] - DPS registration assigned device "redacted_hostname" in hub "redacted-iothub.azure-devices.net"
Mar 03 14:30:10 redacted_hostname iotedged[1249]: 2021-03-03T13:30:10Z [INFO] - Finished provisioning edge device.
Mar 03 14:30:10 redacted_hostname iotedged[1249]: 2021-03-03T13:30:10Z [INFO] - Initializing the module runtime...
Mar 03 14:30:10 redacted_hostname iotedged[1249]: 2021-03-03T13:30:10Z [INFO] - Initializing module runtime...
Mar 03 14:30:10 redacted_hostname iotedged[1249]: 2021-03-03T13:30:10Z [INFO] - Using runtime network id azure-iot-edge
Mar 03 14:30:10 redacted_hostname iotedged[1249]: 2021-03-03T13:30:10Z [INFO] - Successfully initialized module runtime
Mar 03 14:30:10 redacted_hostname iotedged[1249]: 2021-03-03T13:30:10Z [INFO] - Finished initializing the module runtime.
Mar 03 14:30:10 redacted_hostname iotedged[1249]: 2021-03-03T13:30:10Z [INFO] - Stopping all modules...
Mar 03 14:30:10 redacted_hostname iotedged[1249]: 2021-03-03T13:30:10Z [INFO] - Finished stopping modules.
Mar 03 14:30:10 redacted_hostname iotedged[1249]: 2021-03-03T13:30:10Z [INFO] - Reprovisioning status InitialAssignment will trigger reconfiguration of modules.
Mar 03 14:30:10 redacted_hostname iotedged[1249]: 2021-03-03T13:30:10Z [INFO] - Detecting if configuration file has changed...
Mar 03 14:30:10 redacted_hostname iotedged[1249]: 2021-03-03T13:30:10Z [INFO] - Change to configuration file detected.
Mar 03 14:30:10 redacted_hostname iotedged[1249]: 2021-03-03T13:30:10Z [INFO] - Removing all modules...
Mar 03 14:30:10 redacted_hostname iotedged[1249]: 2021-03-03T13:30:10Z [INFO] - Finished removing modules.
Mar 03 14:30:10 redacted_hostname iotedged[1249]: 2021-03-03T13:30:10Z [INFO] - Edge issuer CA expiration date: 2036-02-28T13:29:48Z
Mar 03 14:30:17 redacted_hostname iotedged[1249]: 2021-03-03T13:30:17Z [INFO] - Starting management API...
Mar 03 14:30:17 redacted_hostname iotedged[1249]: 2021-03-03T13:30:17Z [INFO] - Starting workload API...
Mar 03 14:30:17 redacted_hostname iotedged[1249]: 2021-03-03T13:30:17Z [INFO] - Starting watchdog with 60 second frequency...
Mar 03 14:30:17 redacted_hostname iotedged[1249]: 2021-03-03T13:30:17Z [INFO] - Listening on fd://iotedge.mgmt.socket/ with 1 thread for management API.
Mar 03 14:30:17 redacted_hostname iotedged[1249]: 2021-03-03T13:30:17Z [INFO] - Listening on fd://iotedge.socket/ with 1 thread for workload API.
Mar 03 14:30:17 redacted_hostname iotedged[1249]: 2021-03-03T13:30:17Z [INFO] - Checking edge runtime status
Mar 03 14:30:17 redacted_hostname iotedged[1249]: 2021-03-03T13:30:17Z [INFO] - Creating and starting edge runtime module edgeAgent
Mar 03 14:30:17 redacted_hostname iotedged[1249]: 2021-03-03T13:30:17Z [INFO] - [mgmt] - - - [2021-03-03 13:30:17.842024039 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 14 "-" "iotedge/0.1.0" auth_id(-)
Mar 03 14:30:18 redacted_hostname iotedged[1249]: 2021-03-03T13:30:18Z [INFO] - Updating identity for module $edgeAgent
Mar 03 14:30:18 redacted_hostname iotedged[1249]: 2021-03-03T13:30:18Z [INFO] - Pulling image mcr.microsoft.com/azureiotedge-agent:1.0...
Mar 03 14:30:18 redacted_hostname iotedged[1249]: 2021-03-03T13:30:18Z [WARN] - Could not pull image mcr.microsoft.com/azureiotedge-agent:1.0
Mar 03 14:30:18 redacted_hostname iotedged[1249]: 2021-03-03T13:30:18Z [WARN] -         caused by: Get https://mcr.microsoft.com/v2/: dial tcp: lookup mcr.microsoft.com on [::1]:53: read udp [::1]:51409->[::1]:53: read: connection refused
Mar 03 14:30:18 redacted_hostname iotedged[1249]: 2021-03-03T13:30:18Z [WARN] - Error in watchdog when checking for edge runtime status:
Mar 03 14:30:18 redacted_hostname iotedged[1249]: 2021-03-03T13:30:18Z [WARN] - A module runtime error occurred.
Mar 03 14:30:18 redacted_hostname iotedged[1249]: 2021-03-03T13:30:18Z [WARN] -         caused by: Could not pull image mcr.microsoft.com/azureiotedge-agent:1.0
Mar 03 14:30:18 redacted_hostname iotedged[1249]: 2021-03-03T13:30:18Z [WARN] -         caused by: Get https://mcr.microsoft.com/v2/: dial tcp: lookup mcr.microsoft.com on [::1]:53: read udp [::1]:51409->[::1]:53: read: connection refused
Mar 03 14:31:10 redacted_hostname iotedged[1249]: 2021-03-03T13:31:10Z [INFO] - [mgmt] - - - [2021-03-03 13:31:10.858214036 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 14 "-" "iotedge/0.1.0" auth_id(-)
Mar 03 14:31:17 redacted_hostname iotedged[1249]: 2021-03-03T13:31:17Z [INFO] - Checking edge runtime status
Mar 03 14:31:17 redacted_hostname iotedged[1249]: 2021-03-03T13:31:17Z [INFO] - Creating and starting edge runtime module edgeAgent
Mar 03 14:31:17 redacted_hostname iotedged[1249]: 2021-03-03T13:31:17Z [INFO] - Updating identity for module $edgeAgent
Mar 03 14:31:18 redacted_hostname iotedged[1249]: 2021-03-03T13:31:18Z [INFO] - Pulling image mcr.microsoft.com/azureiotedge-agent:1.0...
Mar 03 14:32:07 redacted_hostname iotedged[1249]: 2021-03-03T13:32:07Z [INFO] - Successfully pulled image mcr.microsoft.com/azureiotedge-agent:1.0
Mar 03 14:32:07 redacted_hostname iotedged[1249]: 2021-03-03T13:32:07Z [INFO] - Creating module edgeAgent...
Mar 03 14:32:09 redacted_hostname iotedged[1249]: 2021-03-03T13:32:09Z [INFO] - Successfully created module edgeAgent
Mar 03 14:32:09 redacted_hostname iotedged[1249]: 2021-03-03T13:32:09Z [INFO] - Starting module edgeAgent...
Mar 03 14:32:11 redacted_hostname iotedged[1249]: 2021-03-03T13:32:11Z [INFO] - Successfully started module edgeAgent
Mar 03 14:32:11 redacted_hostname iotedged[1249]: 2021-03-03T13:32:11Z [INFO] - [mgmt] - - - [2021-03-03 13:32:11.384362823 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 528 "-" "iotedge/0.1.0" auth_id(-)
Mar 03 14:32:14 redacted_hostname iotedged[1249]: 2021-03-03T13:32:14Z [INFO] - [work] - - - [2021-03-03 13:32:14.622914926 UTC] "GET /trust-bundle?api-version=2019-01-30 HTTP/1.1" 200 OK 1944 "-" "-" auth_id(-)
Mar 03 14:32:16 redacted_hostname iotedged[1249]: 2021-03-03T13:32:16Z [INFO] - Querying system info...
Mar 03 14:32:16 redacted_hostname iotedged[1249]: none
Mar 03 14:32:16 redacted_hostname iotedged[1249]: 2021-03-03T13:32:16Z [INFO] - Successfully queried system info
Mar 03 14:32:16 redacted_hostname iotedged[1249]: 2021-03-03T13:32:16Z [INFO] - [mgmt] - - - [2021-03-03 13:32:16.649810653 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 304 "-" "-" auth_id(-)
Mar 03 14:32:17 redacted_hostname iotedged[1249]: 2021-03-03T13:32:17Z [INFO] - Checking edge runtime status
Mar 03 14:32:17 redacted_hostname iotedged[1249]: 2021-03-03T13:32:17Z [INFO] - Edge runtime is running.
Mar 03 14:32:20 redacted_hostname iotedged[1249]: 2021-03-03T13:32:20Z [INFO] - Querying system info...
Mar 03 14:32:20 redacted_hostname iotedged[1249]: none
Mar 03 14:32:20 redacted_hostname iotedged[1249]: 2021-03-03T13:32:20Z [INFO] - Successfully queried system info
Mar 03 14:32:20 redacted_hostname iotedged[1249]: 2021-03-03T13:32:20Z [INFO] - [mgmt] - - - [2021-03-03 13:32:20.361963461 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 304 "-" "-" auth_id(-)
Mar 03 14:32:20 redacted_hostname iotedged[1249]: 2021-03-03T13:32:20Z [INFO] - [mgmt] - - - [2021-03-03 13:32:20.883846733 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 528 "-" "-" auth_id(-)
Mar 03 14:32:21 redacted_hostname iotedged[1249]: 2021-03-03T13:32:21Z [INFO] - [work] - - - [2021-03-03 13:32:21.140759386 UTC] "POST /modules/%24edgeAgent/genid/637431235995678909/sign?api-version=2018-06-28 HTTP/1.1" 200 OK 57 "-" "-" auth_id(-)
Mar 03 14:32:23 redacted_hostname iotedged[1249]: 2021-03-03T13:32:23Z [INFO] - [work] - - - [2021-03-03 13:32:23.588487800 UTC] "POST /modules/%24edgeAgent/genid/637431235995678909/encrypt?api-version=2020-07-07 HTTP/1.1" 200 OK 12989 "-" "-" auth_id(-)
Mar 03 14:32:24 redacted_hostname iotedged[1249]: 2021-03-03T13:32:24Z [INFO] - [mgmt] - - - [2021-03-03 13:32:24.179885622 UTC] "GET /identities/?api-version=2020-07-07 HTTP/1.1" 200 OK 1550 "-" "-" auth_id(-)
Mar 03 14:32:28 redacted_hostname iotedged[1249]: 2021-03-03T13:32:28Z [INFO] - [mgmt] - - - [2021-03-03 13:32:28.936162679 UTC] "PUT /identities/%24edgeHub?api-version=2020-07-07 HTTP/1.1" 200 OK 98 "-" "-" auth_id(-)
Mar 03 14:32:28 redacted_hostname iotedged[1249]: 2021-03-03T13:32:28Z [INFO] - [mgmt] - - - [2021-03-03 13:32:28.950608724 UTC] "PUT /identities/azureblobstorageoniotedge?api-version=2020-07-07 HTTP/1.1" 200 OK 115 "-" "-" auth_id(-)
Mar 03 14:32:28 redacted_hostname iotedged[1249]: 2021-03-03T13:32:28Z [INFO] - [mgmt] - - - [2021-03-03 13:32:28.982062931 UTC] "PUT /identities/ECSManager?api-version=2020-07-07 HTTP/1.1" 200 OK 100 "-" "-" auth_id(-)
Mar 03 14:32:29 redacted_hostname iotedged[1249]: 2021-03-03T13:32:29Z [INFO] - [mgmt] - - - [2021-03-03 13:32:29.225766954 UTC] "PUT /identities/FsmManager?api-version=2020-07-07 HTTP/1.1" 200 OK 100 "-" "-" auth_id(-)
Mar 03 14:32:29 redacted_hostname iotedged[1249]: 2021-03-03T13:32:29Z [INFO] - [mgmt] - - - [2021-03-03 13:32:29.639171665 UTC] "PUT /identities/Average?api-version=2020-07-07 HTTP/1.1" 200 OK 97 "-" "-" auth_id(-)
Mar 03 14:32:30 redacted_hostname iotedged[1249]: 2021-03-03T13:32:30Z [INFO] - [mgmt] - - - [2021-03-03 13:32:30.418182875 UTC] "PUT /identities/BlueTooth?api-version=2020-07-07 HTTP/1.1" 200 OK 99 "-" "-" auth_id(-)
Mar 03 14:32:31 redacted_hostname iotedged[1249]: 2021-03-03T13:32:31Z [INFO] - [mgmt] - - - [2021-03-03 13:32:31.290279365 UTC] "PUT /identities/ModbusMapper?api-version=2020-07-07 HTTP/1.1" 200 OK 102 "-" "-" auth_id(-)
Mar 03 14:32:32 redacted_hostname iotedged[1249]: 2021-03-03T13:32:32Z [INFO] - [mgmt] - - - [2021-03-03 13:32:32.079532940 UTC] "PUT /identities/Modbus?api-version=2020-07-07 HTTP/1.1" 200 OK 96 "-" "-" auth_id(-)
Mar 03 14:32:32 redacted_hostname iotedged[1249]: 2021-03-03T13:32:32Z [INFO] - [mgmt] - - - [2021-03-03 13:32:32.134285889 UTC] "PUT /identities/ActuatorMonitor?api-version=2020-07-07 HTTP/1.1" 200 OK 105 "-" "-" auth_id(-)
Mar 03 14:32:33 redacted_hostname iotedged[1249]: 2021-03-03T13:32:33Z [INFO] - Pulling image mcr.microsoft.com/azureiotedge-agent:1.0.10...
Mar 03 14:33:16 redacted_hostname iotedged[1249]: 2021-03-03T13:33:16Z [INFO] - Querying system resources...
Mar 03 14:33:17 redacted_hostname iotedged[1249]: 2021-03-03T13:33:17Z [INFO] - Checking edge runtime status
Mar 03 14:33:17 redacted_hostname iotedged[1249]: 2021-03-03T13:33:17Z [INFO] - Edge runtime is running.
Mar 03 14:33:17 redacted_hostname iotedged[1249]: 2021-03-03T13:33:17Z [INFO] - [mgmt] - - - [2021-03-03 13:33:17.620092937 UTC] "GET /systeminfo/resources?api-version=2020-07-07 HTTP/1.1" 200 OK 2536 "-" "-" auth_id(-)
Mar 03 14:33:22 redacted_hostname iotedged[1249]: 2021-03-03T13:33:22Z [INFO] - Successfully pulled image mcr.microsoft.com/azureiotedge-agent:1.0.10
Mar 03 14:33:22 redacted_hostname iotedged[1249]: 2021-03-03T13:33:22Z [INFO] - [mgmt] - - - [2021-03-03 13:33:22.910738607 UTC] "POST /modules/edgeAgent/prepareupdate?api-version=2020-07-07 HTTP/1.1" 204 No Content - "-" "-" auth_id(-)
Mar 03 14:33:23 redacted_hostname iotedged[1249]: 2021-03-03T13:33:23Z [INFO] - Updating and starting module edgeAgent
Mar 03 14:33:23 redacted_hostname iotedged[1249]: 2021-03-03T13:33:23Z [INFO] - Removing module edgeAgent...
Mar 03 14:33:28 redacted_hostname iotedged[1249]: 2021-03-03T13:33:28Z [INFO] - [mgmt] - - - [2021-03-03 13:33:28.665675288 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 611 "-" "iotedge/0.1.0" auth_id(-)
Mar 03 14:33:28 redacted_hostname iotedged[1249]: 2021-03-03T13:33:28Z [INFO] - Successfully removed module edgeAgent
Mar 03 14:33:28 redacted_hostname iotedged[1249]: 2021-03-03T13:33:28Z [INFO] - Pulling image mcr.microsoft.com/azureiotedge-agent:1.0.10...
Mar 03 14:33:29 redacted_hostname iotedged[1249]: 2021-03-03T13:33:29Z [INFO] - Successfully pulled image mcr.microsoft.com/azureiotedge-agent:1.0.10
Mar 03 14:33:29 redacted_hostname iotedged[1249]: 2021-03-03T13:33:29Z [INFO] - Creating module edgeAgent...
Mar 03 14:33:29 redacted_hostname iotedged[1249]: 2021-03-03T13:33:29Z [INFO] - Successfully created module edgeAgent
Mar 03 14:33:29 redacted_hostname iotedged[1249]: 2021-03-03T13:33:29Z [INFO] - Starting module edgeAgent
Mar 03 14:33:29 redacted_hostname iotedged[1249]: 2021-03-03T13:33:29Z [INFO] - Starting module edgeAgent...
Mar 03 14:33:31 redacted_hostname iotedged[1249]: 2021-03-03T13:33:31Z [INFO] - Successfully started module edgeAgent
Mar 03 14:33:31 redacted_hostname iotedged[1249]: 2021-03-03T13:33:31Z [INFO] - [mgmt] - - - [2021-03-03 13:33:31.332345835 UTC] "PUT /modules/edgeAgent?api-version=2020-07-07&start=true HTTP/1.1" 200 OK 1596 "-" "-" auth_id(-)
Mar 03 14:33:31 redacted_hostname iotedged[1249]: 2021-03-03T13:33:31Z [ERR!] - server connection error: (unknown)
Mar 03 14:33:31 redacted_hostname iotedged[1249]: 2021-03-03T13:33:31Z [ERR!] - error writing a body to connection: Broken pipe (os error 32)
Mar 03 14:33:34 redacted_hostname iotedged[1249]: 2021-03-03T13:33:34Z [INFO] - [work] - - - [2021-03-03 13:33:34.613702742 UTC] "GET /trust-bundle?api-version=2019-01-30 HTTP/1.1" 200 OK 1944 "-" "-" auth_id(-)
Mar 03 14:33:36 redacted_hostname iotedged[1249]: 2021-03-03T13:33:36Z [INFO] - Querying system info...
Mar 03 14:33:36 redacted_hostname iotedged[1249]: none
Mar 03 14:33:36 redacted_hostname iotedged[1249]: 2021-03-03T13:33:36Z [INFO] - Successfully queried system info
Mar 03 14:33:36 redacted_hostname iotedged[1249]: 2021-03-03T13:33:36Z [INFO] - [mgmt] - - - [2021-03-03 13:33:36.702292701 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 304 "-" "-" auth_id(-)
Mar 03 14:33:40 redacted_hostname iotedged[1249]: 2021-03-03T13:33:40Z [INFO] - Querying system info...
Mar 03 14:33:40 redacted_hostname iotedged[1249]: none
Mar 03 14:33:40 redacted_hostname iotedged[1249]: 2021-03-03T13:33:40Z [INFO] - Successfully queried system info
Mar 03 14:33:40 redacted_hostname iotedged[1249]: 2021-03-03T13:33:40Z [INFO] - [mgmt] - - - [2021-03-03 13:33:40.520795226 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 304 "-" "-" auth_id(-)
Mar 03 14:33:40 redacted_hostname iotedged[1249]: 2021-03-03T13:33:40Z [INFO] - [work] - - - [2021-03-03 13:33:40.839089993 UTC] "POST /modules/%24edgeAgent/genid/637431235995678909/sign?api-version=2018-06-28 HTTP/1.1" 200 OK 57 "-" "-" auth_id(-)
Mar 03 14:33:40 redacted_hostname iotedged[1249]: 2021-03-03T13:33:40Z [INFO] - [mgmt] - - - [2021-03-03 13:33:40.935913664 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 725 "-" "-" auth_id(-)
Mar 03 14:33:43 redacted_hostname iotedged[1249]: 2021-03-03T13:33:43Z [INFO] - [work] - - - [2021-03-03 13:33:43.322042600 UTC] "POST /modules/%24edgeAgent/genid/637431235995678909/encrypt?api-version=2020-07-07 HTTP/1.1" 200 OK 12989 "-" "-" auth_id(-)
Mar 03 14:33:43 redacted_hostname iotedged[1249]: 2021-03-03T13:33:43Z [INFO] - [mgmt] - - - [2021-03-03 13:33:43.949413711 UTC] "GET /identities/?api-version=2020-07-07 HTTP/1.1" 200 OK 1550 "-" "-" auth_id(-)
Mar 03 14:33:47 redacted_hostname iotedged[1249]: 2021-03-03T13:33:47Z [INFO] - [mgmt] - - - [2021-03-03 13:33:47.617445138 UTC] "PUT /identities/ECSManager?api-version=2020-07-07 HTTP/1.1" 200 OK 100 "-" "-" auth_id(-)
Mar 03 14:33:50 redacted_hostname iotedged[1249]: 2021-03-03T13:33:50Z [INFO] - [mgmt] - - - [2021-03-03 13:33:50.114634616 UTC] "PUT /identities/%24edgeHub?api-version=2020-07-07 HTTP/1.1" 200 OK 98 "-" "-" auth_id(-)
Mar 03 14:33:50 redacted_hostname iotedged[1249]: 2021-03-03T13:33:50Z [INFO] - [mgmt] - - - [2021-03-03 13:33:50.370219839 UTC] "PUT /identities/Average?api-version=2020-07-07 HTTP/1.1" 200 OK 97 "-" "-" auth_id(-)
Mar 03 14:33:51 redacted_hostname iotedged[1249]: 2021-03-03T13:33:51Z [INFO] - [mgmt] - - - [2021-03-03 13:33:51.004208453 UTC] "PUT /identities/BlueTooth?api-version=2020-07-07 HTTP/1.1" 200 OK 99 "-" "-" auth_id(-)
Mar 03 14:33:51 redacted_hostname iotedged[1249]: 2021-03-03T13:33:51Z [INFO] - [mgmt] - - - [2021-03-03 13:33:51.780505771 UTC] "PUT /identities/ModbusMapper?api-version=2020-07-07 HTTP/1.1" 200 OK 102 "-" "-" auth_id(-)
Mar 03 14:33:51 redacted_hostname iotedged[1249]: 2021-03-03T13:33:51Z [INFO] - [mgmt] - - - [2021-03-03 13:33:51.780505823 UTC] "PUT /identities/Modbus?api-version=2020-07-07 HTTP/1.1" 200 OK 96 "-" "-" auth_id(-)
Mar 03 14:33:51 redacted_hostname iotedged[1249]: 2021-03-03T13:33:51Z [INFO] - [mgmt] - - - [2021-03-03 13:33:51.780505771 UTC] "PUT /identities/azureblobstorageoniotedge?api-version=2020-07-07 HTTP/1.1" 200 OK 115 "-" "-" auth_id(-)
Mar 03 14:33:51 redacted_hostname iotedged[1249]: 2021-03-03T13:33:51Z [INFO] - [mgmt] - - - [2021-03-03 13:33:51.780505719 UTC] "PUT /identities/FsmManager?api-version=2020-07-07 HTTP/1.1" 200 OK 100 "-" "-" auth_id(-)
Mar 03 14:33:51 redacted_hostname iotedged[1249]: 2021-03-03T13:33:51Z [INFO] - [mgmt] - - - [2021-03-03 13:33:51.826149137 UTC] "PUT /identities/ActuatorMonitor?api-version=2020-07-07 HTTP/1.1" 200 OK 105 "-" "-" auth_id(-)
Mar 03 14:33:52 redacted_hostname iotedged[1249]: 2021-03-03T13:33:52Z [INFO] - Pulling image redacted_registry.azurecr.io/modbusmapper:2.0.0-20210301080123PM-arm32v7...
Mar 03 14:34:17 redacted_hostname iotedged[1249]: 2021-03-03T13:34:17Z [INFO] - Checking edge runtime status
Mar 03 14:34:17 redacted_hostname iotedged[1249]: 2021-03-03T13:34:17Z [INFO] - Edge runtime is running.
Mar 03 14:34:36 redacted_hostname iotedged[1249]: 2021-03-03T13:34:36Z [INFO] - Querying system resources...
Mar 03 14:34:37 redacted_hostname iotedged[1249]: 2021-03-03T13:34:37Z [INFO] - [mgmt] - - - [2021-03-03 13:34:37.640691352 UTC] "GET /systeminfo/resources?api-version=2020-07-07 HTTP/1.1" 200 OK 2536 "-" "-" auth_id(-)
Mar 03 14:34:53 redacted_hostname iotedged[1249]: 2021-03-03T13:34:53Z [INFO] - [mgmt] - - - [2021-03-03 13:34:53.556695591 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 725 "-" "iotedge/0.1.0" auth_id(-)
Mar 03 14:35:17 redacted_hostname iotedged[1249]: 2021-03-03T13:35:17Z [INFO] - Checking edge runtime status
Mar 03 14:35:17 redacted_hostname iotedged[1249]: 2021-03-03T13:35:17Z [INFO] - Edge runtime is running.
Mar 03 14:35:32 redacted_hostname iotedged[1249]: 2021-03-03T13:35:32Z [INFO] - Pulling image mcr.microsoft.com/azureiotedge-hub:1.0.10...
Mar 03 14:35:58 redacted_hostname iotedged[1249]: 2021-03-03T13:35:58Z [INFO] - [mgmt] - - - [2021-03-03 13:35:58.389688938 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 725 "-" "iotedge/0.1.0" auth_id(-)
Mar 03 14:36:17 redacted_hostname iotedged[1249]: 2021-03-03T13:36:17Z [INFO] - Checking edge runtime status
Mar 03 14:36:17 redacted_hostname iotedged[1249]: 2021-03-03T13:36:17Z [INFO] - Edge runtime is running.
Mar 03 14:36:59 redacted_hostname iotedged[1249]: 2021-03-03T13:36:59Z [INFO] - [mgmt] - - - [2021-03-03 13:36:59.551832423 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 725 "-" "iotedge/0.1.0" auth_id(-)
Mar 03 14:37:13 redacted_hostname iotedged[1249]: 2021-03-03T13:37:13Z [INFO] - Pulling image redacted_registry.azurecr.io/ecsmanager:2.0.0-20210301080123PM-arm32v7...
Mar 03 14:37:13 redacted_hostname iotedged[1249]: 2021-03-03T13:37:13Z [INFO] - Successfully pulled image mcr.microsoft.com/azureiotedge-hub:1.0.10
Mar 03 14:37:13 redacted_hostname iotedged[1249]: 2021-03-03T13:37:13Z [INFO] - Creating module edgeHub...
Mar 03 14:37:16 redacted_hostname iotedged[1249]: 2021-03-03T13:37:16Z [INFO] - Successfully created module edgeHub
Mar 03 14:37:16 redacted_hostname iotedged[1249]: 2021-03-03T13:37:16Z [INFO] - [mgmt] - - - [2021-03-03 13:37:16.359865244 UTC] "POST /modules?api-version=2020-07-07 HTTP/1.1" 201 Created 1295 "-" "-" auth_id(-)
Mar 03 14:37:17 redacted_hostname iotedged[1249]: 2021-03-03T13:37:17Z [INFO] - Checking edge runtime status
Mar 03 14:37:17 redacted_hostname iotedged[1249]: 2021-03-03T13:37:17Z [INFO] - Edge runtime is running.
Mar 03 14:37:26 redacted_hostname iotedged[1249]: 2021-03-03T13:37:26Z [INFO] - Successfully pulled image redacted_registry.azurecr.io/modbusmapper:2.0.0-20210301080123PM-arm32v7
Mar 03 14:37:26 redacted_hostname iotedged[1249]: 2021-03-03T13:37:26Z [INFO] - Creating module ModbusMapper...
Mar 03 14:37:27 redacted_hostname iotedged[1249]: 2021-03-03T13:37:27Z [INFO] - Successfully created module ModbusMapper
Mar 03 14:37:27 redacted_hostname iotedged[1249]: 2021-03-03T13:37:27Z [INFO] - [mgmt] - - - [2021-03-03 13:37:27.653397748 UTC] "POST /modules?api-version=2020-07-07 HTTP/1.1" 201 Created 1688 "-" "-" auth_id(-)
Mar 03 14:38:00 redacted_hostname iotedged[1249]: 2021-03-03T13:38:00Z [INFO] - [mgmt] - - - [2021-03-03 13:38:00.321742123 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1540 "-" "iotedge/0.1.0" auth_id(-)
Mar 03 14:38:17 redacted_hostname iotedged[1249]: 2021-03-03T13:38:17Z [INFO] - Checking edge runtime status
Mar 03 14:38:17 redacted_hostname iotedged[1249]: 2021-03-03T13:38:17Z [INFO] - Edge runtime is running.
Mar 03 14:38:53 redacted_hostname iotedged[1249]: 2021-03-03T13:38:53Z [INFO] - Pulling image redacted_registry.azurecr.io/fsmmanager:2.0.0-20210301080123PM-arm32v7...
Mar 03 14:39:03 redacted_hostname iotedged[1249]: 2021-03-03T13:39:03Z [INFO] - [mgmt] - - - [2021-03-03 13:39:03.823087480 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1540 "-" "iotedge/0.1.0" auth_id(-)
Mar 03 14:39:17 redacted_hostname iotedged[1249]: 2021-03-03T13:39:17Z [INFO] - Checking edge runtime status
Mar 03 14:39:17 redacted_hostname iotedged[1249]: 2021-03-03T13:39:17Z [INFO] - Edge runtime is running.
Mar 03 14:39:27 redacted_hostname iotedged[1249]: 2021-03-03T13:39:27Z [INFO] - Successfully pulled image redacted_registry.azurecr.io/ecsmanager:2.0.0-20210301080123PM-arm32v7
Mar 03 14:39:27 redacted_hostname iotedged[1249]: 2021-03-03T13:39:27Z [INFO] - Creating module ECSManager...
Mar 03 14:39:28 redacted_hostname iotedged[1249]: 2021-03-03T13:39:28Z [INFO] - Successfully created module ECSManager
Mar 03 14:39:28 redacted_hostname iotedged[1249]: 2021-03-03T13:39:28Z [INFO] - [mgmt] - - - [2021-03-03 13:39:28.672271941 UTC] "POST /modules?api-version=2020-07-07 HTTP/1.1" 201 Created 1736 "-" "-" auth_id(-)
Mar 03 14:39:37 redacted_hostname iotedged[1249]: 2021-03-03T13:39:37Z [INFO] - Querying system resources...
Mar 03 14:39:39 redacted_hostname iotedged[1249]: 2021-03-03T13:39:39Z [INFO] - [mgmt] - - - [2021-03-03 13:39:39.024144498 UTC] "GET /systeminfo/resources?api-version=2020-07-07 HTTP/1.1" 200 OK 5173 "-" "-" auth_id(-)
Mar 03 14:40:02 redacted_hostname iotedged[1249]: 2021-03-03T13:40:02Z [INFO] - [mgmt] - - - [2021-03-03 13:40:02.044827986 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1966 "-" "iotedge/0.1.0" auth_id(-)
Mar 03 14:40:17 redacted_hostname iotedged[1249]: 2021-03-03T13:40:17Z [INFO] - Checking edge runtime status
Mar 03 14:40:17 redacted_hostname iotedged[1249]: 2021-03-03T13:40:17Z [INFO] - Edge runtime is running.
Mar 03 14:40:33 redacted_hostname iotedged[1249]: 2021-03-03T13:40:33Z [INFO] - Pulling image mcr.microsoft.com/azureiotedge/modbus:1.0...
Mar 03 14:41:11 redacted_hostname iotedged[1249]: 2021-03-03T13:41:11Z [INFO] - [mgmt] - - - [2021-03-03 13:41:11.043480979 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1966 "-" "iotedge/0.1.0" auth_id(-)
Mar 03 14:41:11 redacted_hostname iotedged[1249]: 2021-03-03T13:41:11Z [INFO] - Successfully pulled image redacted_registry.azurecr.io/fsmmanager:2.0.0-20210301080123PM-arm32v7
Mar 03 14:41:11 redacted_hostname iotedged[1249]: 2021-03-03T13:41:11Z [INFO] - Creating module FsmManager...
Mar 03 14:41:15 redacted_hostname iotedged[1249]: 2021-03-03T13:41:15Z [INFO] - Successfully created module FsmManager
Mar 03 14:41:15 redacted_hostname iotedged[1249]: 2021-03-03T13:41:15Z [INFO] - [mgmt] - - - [2021-03-03 13:41:15.169822433 UTC] "POST /modules?api-version=2020-07-07 HTTP/1.1" 201 Created 2590 "-" "-" auth_id(-)
Mar 03 14:41:17 redacted_hostname iotedged[1249]: 2021-03-03T13:41:17Z [INFO] - Checking edge runtime status
Mar 03 14:41:17 redacted_hostname iotedged[1249]: 2021-03-03T13:41:17Z [INFO] - Edge runtime is running.
Mar 03 14:41:31 redacted_hostname iotedged[1249]: 2021-03-03T13:41:31Z [INFO] - Successfully pulled image mcr.microsoft.com/azureiotedge/modbus:1.0
Mar 03 14:41:31 redacted_hostname iotedged[1249]: 2021-03-03T13:41:31Z [INFO] - Creating module Modbus...
Mar 03 14:41:34 redacted_hostname iotedged[1249]: 2021-03-03T13:41:34Z [INFO] - Successfully created module Modbus
Mar 03 14:41:34 redacted_hostname iotedged[1249]: 2021-03-03T13:41:34Z [INFO] - [mgmt] - - - [2021-03-03 13:41:34.029419030 UTC] "POST /modules?api-version=2020-07-07 HTTP/1.1" 201 Created 1195 "-" "-" auth_id(-)
Mar 03 14:41:34 redacted_hostname iotedged[1249]: 2021-03-03T13:41:34Z [INFO] - Starting module Modbus...
Mar 03 14:41:35 redacted_hostname iotedged[1249]: 2021-03-03T13:41:35Z [INFO] - Successfully started module Modbus
Mar 03 14:41:35 redacted_hostname iotedged[1249]: 2021-03-03T13:41:35Z [INFO] - [mgmt] - - - [2021-03-03 13:41:35.806731127 UTC] "POST /modules/Modbus/start?api-version=2020-07-07 HTTP/1.1" 204 No Content - "-" "-" auth_id(-)
Mar 03 14:41:35 redacted_hostname iotedged[1249]: 2021-03-03T13:41:35Z [INFO] - Pulling image redacted_registry.azurecr.io/actuatormonitor:2.0.0-20210301080123PM-arm32v7...
Mar 03 14:41:37 redacted_hostname iotedged[1249]: 2021-03-03T13:41:37Z [INFO] - [work] - - - [2021-03-03 13:41:37.324418447 UTC] "GET /trust-bundle?api-version=2018-06-28 HTTP/1.1" 200 OK 1944 "-" "-" auth_id(-)
Mar 03 14:42:17 redacted_hostname iotedged[1249]: 2021-03-03T13:42:17Z [INFO] - Checking edge runtime status
Mar 03 14:42:17 redacted_hostname iotedged[1249]: 2021-03-03T13:42:17Z [INFO] - Edge runtime is running.
Mar 03 14:42:26 redacted_hostname iotedged[1249]: 2021-03-03T13:42:26Z [INFO] - [mgmt] - - - [2021-03-03 13:42:26.326078586 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2826 "-" "iotedge/0.1.0" auth_id(-)
Mar 03 14:43:16 redacted_hostname iotedged[1249]: 2021-03-03T13:43:16Z [INFO] - Pulling image redacted_registry.azurecr.io/average:2.0.0-20210301080123PM-arm32v7...
Mar 03 14:43:17 redacted_hostname iotedged[1249]: 2021-03-03T13:43:17Z [INFO] - Checking edge runtime status
Mar 03 14:43:17 redacted_hostname iotedged[1249]: 2021-03-03T13:43:17Z [INFO] - Edge runtime is running.
Mar 03 14:43:31 redacted_hostname iotedged[1249]: 2021-03-03T13:43:31Z [INFO] - [mgmt] - - - [2021-03-03 13:43:31.119573041 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2826 "-" "iotedge/0.1.0" auth_id(-)
Mar 03 14:43:45 redacted_hostname iotedged[1249]: 2021-03-03T13:43:45Z [INFO] - Successfully pulled image redacted_registry.azurecr.io/actuatormonitor:2.0.0-20210301080123PM-arm32v7
Mar 03 14:43:45 redacted_hostname iotedged[1249]: 2021-03-03T13:43:45Z [INFO] - Creating module ActuatorMonitor...
Mar 03 14:43:47 redacted_hostname iotedged[1249]: 2021-03-03T13:43:47Z [INFO] - Successfully created module ActuatorMonitor
Mar 03 14:43:47 redacted_hostname iotedged[1249]: 2021-03-03T13:43:47Z [INFO] - [mgmt] - - - [2021-03-03 13:43:47.101679127 UTC] "POST /modules?api-version=2020-07-07 HTTP/1.1" 201 Created 1755 "-" "-" auth_id(-)
Mar 03 14:44:17 redacted_hostname iotedged[1249]: 2021-03-03T13:44:17Z [INFO] - Checking edge runtime status
Mar 03 14:44:17 redacted_hostname iotedged[1249]: 2021-03-03T13:44:17Z [INFO] - Edge runtime is running.
Mar 03 14:44:32 redacted_hostname iotedged[1249]: 2021-03-03T13:44:32Z [INFO] - [mgmt] - - - [2021-03-03 13:44:32.298988171 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 3262 "-" "iotedge/0.1.0" auth_id(-)
Mar 03 14:44:39 redacted_hostname iotedged[1249]: 2021-03-03T13:44:39Z [INFO] - Querying system resources...
Mar 03 14:44:42 redacted_hostname iotedged[1249]: 2021-03-03T13:44:42Z [INFO] - [mgmt] - - - [2021-03-03 13:44:42.208647863 UTC] "GET /systeminfo/resources?api-version=2020-07-07 HTTP/1.1" 200 OK 9091 "-" "-" auth_id(-)
Mar 03 14:44:56 redacted_hostname iotedged[1249]: 2021-03-03T13:44:56Z [INFO] - Pulling image mcr.microsoft.com/azure-blob-storage:latest...
Mar 03 14:45:15 redacted_hostname iotedged[1249]: 2021-03-03T13:45:15Z [INFO] - Successfully pulled image redacted_registry.azurecr.io/average:2.0.0-20210301080123PM-arm32v7
Mar 03 14:45:15 redacted_hostname iotedged[1249]: 2021-03-03T13:45:15Z [INFO] - Creating module Average...
Mar 03 14:45:17 redacted_hostname iotedged[1249]: 2021-03-03T13:45:17Z [INFO] - Checking edge runtime status
Mar 03 14:45:19 redacted_hostname iotedged[1249]: 2021-03-03T13:45:19Z [INFO] - Edge runtime is running.
Mar 03 14:45:19 redacted_hostname iotedged[1249]: 2021-03-03T13:45:19Z [INFO] - Successfully created module Average
Mar 03 14:45:19 redacted_hostname iotedged[1249]: 2021-03-03T13:45:19Z [INFO] - [mgmt] - - - [2021-03-03 13:45:19.524246726 UTC] "POST /modules?api-version=2020-07-07 HTTP/1.1" 201 Created 1670 "-" "-" auth_id(-)
Mar 03 14:45:43 redacted_hostname iotedged[1249]: 2021-03-03T13:45:43Z [INFO] - [mgmt] - - - [2021-03-03 13:45:43.389090197 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 3682 "-" "iotedge/0.1.0" auth_id(-)
Mar 03 14:45:50 redacted_hostname iotedged[1249]: 2021-03-03T13:45:50Z [INFO] - Successfully pulled image mcr.microsoft.com/azure-blob-storage:latest
Mar 03 14:45:50 redacted_hostname iotedged[1249]: 2021-03-03T13:45:50Z [INFO] - Creating module azureblobstorageoniotedge...
Mar 03 14:45:52 redacted_hostname iotedged[1249]: 2021-03-03T13:45:52Z [INFO] - Successfully created module azureblobstorageoniotedge
Mar 03 14:45:52 redacted_hostname iotedged[1249]: 2021-03-03T13:45:52Z [INFO] - [mgmt] - - - [2021-03-03 13:45:52.795919024 UTC] "POST /modules?api-version=2020-07-07 HTTP/1.1" 201 Created 1410 "-" "-" auth_id(-)
Mar 03 14:45:52 redacted_hostname iotedged[1249]: 2021-03-03T13:45:52Z [INFO] - Starting module azureblobstorageoniotedge...
Mar 03 14:45:54 redacted_hostname iotedged[1249]: 2021-03-03T13:45:54Z [INFO] - Successfully started module azureblobstorageoniotedge
Mar 03 14:45:54 redacted_hostname iotedged[1249]: 2021-03-03T13:45:54Z [INFO] - [mgmt] - - - [2021-03-03 13:45:54.747087779 UTC] "POST /modules/azureblobstorageoniotedge/start?api-version=2020-07-07 HTTP/1.1" 204 No Content - "-" "-" auth_id(-)
Mar 03 14:45:54 redacted_hostname iotedged[1249]: 2021-03-03T13:45:54Z [INFO] - Pulling image redacted_registry.azurecr.io/bluetooth:2.0.0-20210301080123PM-arm32v7...
Mar 03 14:45:56 redacted_hostname iotedged[1249]: 2021-03-03T13:45:56Z [INFO] - [work] - - - [2021-03-03 13:45:56.026461437 UTC] "GET /trust-bundle?api-version=2018-06-28 HTTP/1.1" 200 OK 1944 "-" "-" auth_id(-)
Mar 03 14:46:17 redacted_hostname iotedged[1249]: 2021-03-03T13:46:17Z [INFO] - Checking edge runtime status
Mar 03 14:46:17 redacted_hostname iotedged[1249]: 2021-03-03T13:46:17Z [INFO] - Edge runtime is running.
Mar 03 14:46:49 redacted_hostname iotedged[1249]: 2021-03-03T13:46:49Z [INFO] - [mgmt] - - - [2021-03-03 13:46:49.693686868 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 4902 "-" "iotedge/0.1.0" auth_id(-)
Mar 03 14:47:17 redacted_hostname iotedged[1249]: 2021-03-03T13:47:17Z [INFO] - Checking edge runtime status
Mar 03 14:47:17 redacted_hostname iotedged[1249]: 2021-03-03T13:47:17Z [INFO] - Edge runtime is running.
Mar 03 14:47:35 redacted_hostname iotedged[1249]: 2021-03-03T13:47:35Z [INFO] - [work] - - - [2021-03-03 13:47:35.143992385 UTC] "POST /modules/%24edgeAgent/genid/637431235995678909/encrypt?api-version=2020-07-07 HTTP/1.1" 200 OK 12989 "-" "-" auth_id(-)
Mar 03 14:47:36 redacted_hostname iotedged[1249]: 2021-03-03T13:47:36Z [INFO] - [mgmt] - - - [2021-03-03 13:47:36.104328479 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 4902 "-" "-" auth_id(-)
Mar 03 14:47:38 redacted_hostname iotedged[1249]: 2021-03-03T13:47:38Z [INFO] - [mgmt] - - - [2021-03-03 13:47:38.802418882 UTC] "GET /identities/?api-version=2020-07-07 HTTP/1.1" 200 OK 1550 "-" "-" auth_id(-)
Mar 03 14:47:39 redacted_hostname iotedged[1249]: 2021-03-03T13:47:39Z [INFO] - [mgmt] - - - [2021-03-03 13:47:39.926288510 UTC] "PUT /identities/BlueTooth?api-version=2020-07-07 HTTP/1.1" 200 OK 99 "-" "-" auth_id(-)
Mar 03 14:47:40 redacted_hostname iotedged[1249]: 2021-03-03T13:47:40Z [INFO] - Stopping module edgeHub...
Mar 03 14:47:40 redacted_hostname iotedged[1249]: 2021-03-03T13:47:40Z [WARN] - Could not stop module edgeHub
Mar 03 14:47:40 redacted_hostname iotedged[1249]: 2021-03-03T13:47:40Z [WARN] -         caused by: Target of operation already in this state
Mar 03 14:47:40 redacted_hostname iotedged[1249]: 2021-03-03T13:47:40Z [INFO] - [mgmt] - - - [2021-03-03 13:47:40.260984684 UTC] "POST /modules/edgeHub/stop?api-version=2020-07-07 HTTP/1.1" 304 Not Modified 0 "-" "-" auth_id(-)
Mar 03 14:47:40 redacted_hostname iotedged[1249]: 2021-03-03T13:47:40Z [INFO] - Starting module edgeHub...
Mar 03 14:47:47 redacted_hostname iotedged[1249]: 2021-03-03T13:47:47Z [INFO] - Successfully started module edgeHub
Mar 03 14:47:47 redacted_hostname iotedged[1249]: 2021-03-03T13:47:47Z [INFO] - [mgmt] - - - [2021-03-03 13:47:47.332462516 UTC] "POST /modules/edgeHub/start?api-version=2020-07-07 HTTP/1.1" 204 No Content - "-" "-" auth_id(-)
Mar 03 14:47:47 redacted_hostname iotedged[1249]: 2021-03-03T13:47:47Z [INFO] - Stopping module FsmManager...
Mar 03 14:47:47 redacted_hostname iotedged[1249]: 2021-03-03T13:47:47Z [WARN] - Could not stop module FsmManager
Mar 03 14:47:47 redacted_hostname iotedged[1249]: 2021-03-03T13:47:47Z [WARN] -         caused by: Target of operation already in this state
Mar 03 14:47:47 redacted_hostname iotedged[1249]: 2021-03-03T13:47:47Z [INFO] - [mgmt] - - - [2021-03-03 13:47:47.360173923 UTC] "POST /modules/FsmManager/stop?api-version=2020-07-07 HTTP/1.1" 304 Not Modified 0 "-" "-" auth_id(-)
Mar 03 14:47:47 redacted_hostname iotedged[1249]: 2021-03-03T13:47:47Z [INFO] - Starting module FsmManager...
Mar 03 14:47:48 redacted_hostname iotedged[1249]: 2021-03-03T13:47:48Z [INFO] - Successfully started module FsmManager
Mar 03 14:47:48 redacted_hostname iotedged[1249]: 2021-03-03T13:47:48Z [INFO] - [mgmt] - - - [2021-03-03 13:47:48.657747346 UTC] "POST /modules/FsmManager/start?api-version=2020-07-07 HTTP/1.1" 204 No Content - "-" "-" auth_id(-)
Mar 03 14:47:48 redacted_hostname iotedged[1249]: 2021-03-03T13:47:48Z [INFO] - Stopping module ActuatorMonitor...
Mar 03 14:47:48 redacted_hostname iotedged[1249]: 2021-03-03T13:47:48Z [WARN] - Could not stop module ActuatorMonitor
Mar 03 14:47:48 redacted_hostname iotedged[1249]: 2021-03-03T13:47:48Z [WARN] -         caused by: Target of operation already in this state
Mar 03 14:47:48 redacted_hostname iotedged[1249]: 2021-03-03T13:47:48Z [INFO] - [mgmt] - - - [2021-03-03 13:47:48.677838043 UTC] "POST /modules/ActuatorMonitor/stop?api-version=2020-07-07 HTTP/1.1" 304 Not Modified 0 "-" "-" auth_id(-)
Mar 03 14:47:48 redacted_hostname iotedged[1249]: 2021-03-03T13:47:48Z [INFO] - Starting module ActuatorMonitor...
Mar 03 14:47:51 redacted_hostname iotedged[1249]: 2021-03-03T13:47:51Z [INFO] - Successfully started module ActuatorMonitor
Mar 03 14:47:51 redacted_hostname iotedged[1249]: 2021-03-03T13:47:51Z [INFO] - [mgmt] - - - [2021-03-03 13:47:51.377738262 UTC] "POST /modules/ActuatorMonitor/start?api-version=2020-07-07 HTTP/1.1" 204 No Content - "-" "-" auth_id(-)
Mar 03 14:47:51 redacted_hostname iotedged[1249]: 2021-03-03T13:47:51Z [INFO] - [mgmt] - - - [2021-03-03 13:47:51.382944984 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 5052 "-" "iotedge/0.1.0" auth_id(-)
Mar 03 14:47:51 redacted_hostname iotedged[1249]: 2021-03-03T13:47:51Z [INFO] - Stopping module ModbusMapper...
Mar 03 14:47:51 redacted_hostname iotedged[1249]: 2021-03-03T13:47:51Z [WARN] - Could not stop module ModbusMapper
Mar 03 14:47:51 redacted_hostname iotedged[1249]: 2021-03-03T13:47:51Z [WARN] -         caused by: Target of operation already in this state
Mar 03 14:47:51 redacted_hostname iotedged[1249]: 2021-03-03T13:47:51Z [INFO] - [mgmt] - - - [2021-03-03 13:47:51.395978196 UTC] "POST /modules/ModbusMapper/stop?api-version=2020-07-07 HTTP/1.1" 304 Not Modified 0 "-" "-" auth_id(-)
Mar 03 14:47:51 redacted_hostname iotedged[1249]: 2021-03-03T13:47:51Z [INFO] - Starting module ModbusMapper...
Mar 03 14:47:55 redacted_hostname iotedged[1249]: 2021-03-03T13:47:55Z [INFO] - Successfully started module ModbusMapper
Mar 03 14:47:55 redacted_hostname iotedged[1249]: 2021-03-03T13:47:55Z [INFO] - [mgmt] - - - [2021-03-03 13:47:55.607997116 UTC] "POST /modules/ModbusMapper/start?api-version=2020-07-07 HTTP/1.1" 204 No Content - "-" "-" auth_id(-)
Mar 03 14:47:55 redacted_hostname iotedged[1249]: 2021-03-03T13:47:55Z [INFO] - Stopping module Modbus...
Mar 03 14:47:55 redacted_hostname iotedged[1249]: 2021-03-03T13:47:55Z [WARN] - Could not stop module Modbus
Mar 03 14:47:55 redacted_hostname iotedged[1249]: 2021-03-03T13:47:55Z [WARN] -         caused by: Target of operation already in this state
Mar 03 14:47:55 redacted_hostname iotedged[1249]: 2021-03-03T13:47:55Z [INFO] - [mgmt] - - - [2021-03-03 13:47:55.699091788 UTC] "POST /modules/Modbus/stop?api-version=2020-07-07 HTTP/1.1" 304 Not Modified 0 "-" "-" auth_id(-)
Mar 03 14:47:55 redacted_hostname iotedged[1249]: 2021-03-03T13:47:55Z [INFO] - [work] - - - [2021-03-03 13:47:55.700960156 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/certificate/server?api-version=2019-01-30 HTTP/1.1" 201 Created 9278 "-" "-" auth_id(-)
Mar 03 14:47:55 redacted_hostname iotedged[1249]: 2021-03-03T13:47:55Z [INFO] - Starting module Modbus...
Mar 03 14:47:56 redacted_hostname iotedged[1249]: 2021-03-03T13:47:56Z [INFO] - [work] - - - [2021-03-03 13:47:56.827662054 UTC] "GET /trust-bundle?api-version=2018-06-28 HTTP/1.1" 200 OK 1944 "-" "-" auth_id(-)
Mar 03 14:47:58 redacted_hostname iotedged[1249]: 2021-03-03T13:47:58Z [INFO] - [work] - - - [2021-03-03 13:47:58.812332955 UTC] "GET /trust-bundle?api-version=2018-06-28 HTTP/1.1" 200 OK 1944 "-" "-" auth_id(-)
Mar 03 14:47:59 redacted_hostname iotedged[1249]: 2021-03-03T13:47:59Z [INFO] - Successfully started module Modbus
Mar 03 14:47:59 redacted_hostname iotedged[1249]: 2021-03-03T13:47:59Z [INFO] - [mgmt] - - - [2021-03-03 13:47:59.084619120 UTC] "POST /modules/Modbus/start?api-version=2020-07-07 HTTP/1.1" 204 No Content - "-" "-" auth_id(-)
Mar 03 14:47:59 redacted_hostname iotedged[1249]: 2021-03-03T13:47:59Z [INFO] - Stopping module Average...
Mar 03 14:47:59 redacted_hostname iotedged[1249]: 2021-03-03T13:47:59Z [WARN] - Could not stop module Average
Mar 03 14:47:59 redacted_hostname iotedged[1249]: 2021-03-03T13:47:59Z [WARN] -         caused by: Target of operation already in this state
Mar 03 14:47:59 redacted_hostname iotedged[1249]: 2021-03-03T13:47:59Z [INFO] - [mgmt] - - - [2021-03-03 13:47:59.176522848 UTC] "POST /modules/Average/stop?api-version=2020-07-07 HTTP/1.1" 304 Not Modified 0 "-" "-" auth_id(-)
Mar 03 14:47:59 redacted_hostname iotedged[1249]: 2021-03-03T13:47:59Z [INFO] - Starting module Average...
Mar 03 14:48:01 redacted_hostname iotedged[1249]: 2021-03-03T13:48:01Z [INFO] - [work] - - - [2021-03-03 13:48:01.214308906 UTC] "GET /trust-bundle?api-version=2018-06-28 HTTP/1.1" 200 OK 1944 "-" "-" auth_id(-)
Mar 03 14:48:02 redacted_hostname iotedged[1249]: 2021-03-03T13:48:02Z [INFO] - [work] - - - [2021-03-03 13:48:02.132477306 UTC] "GET /trust-bundle?api-version=2019-01-30 HTTP/1.1" 200 OK 1944 "-" "-" auth_id(-)
Mar 03 14:48:02 redacted_hostname iotedged[1249]: 2021-03-03T13:48:02Z [INFO] - Successfully started module Average
Mar 03 14:48:02 redacted_hostname iotedged[1249]: 2021-03-03T13:48:02Z [INFO] - [mgmt] - - - [2021-03-03 13:48:02.540782266 UTC] "POST /modules/Average/start?api-version=2020-07-07 HTTP/1.1" 204 No Content - "-" "-" auth_id(-)
Mar 03 14:48:02 redacted_hostname iotedged[1249]: 2021-03-03T13:48:02Z [INFO] - [work] - - - [2021-03-03 13:48:02.838396482 UTC] "POST /modules/%24edgeAgent/genid/637431235995678909/encrypt?api-version=2020-07-07 HTTP/1.1" 200 OK 12989 "-" "-" auth_id(-)
Mar 03 14:48:03 redacted_hostname iotedged[1249]: 2021-03-03T13:48:03Z [INFO] - [work] - - - [2021-03-03 13:48:03.791308005 UTC] "GET /trust-bundle?api-version=2018-06-28 HTTP/1.1" 200 OK 1944 "-" "-" auth_id(-)
Mar 03 14:48:07 redacted_hostname iotedged[1249]: 2021-03-03T13:48:07Z [INFO] - [work] - - - [2021-03-03 13:48:07.161373390 UTC] "GET /trust-bundle?api-version=2018-06-28 HTTP/1.1" 200 OK 1944 "-" "-" auth_id(-)
Mar 03 14:48:08 redacted_hostname iotedged[1249]: 2021-03-03T13:48:08Z [INFO] - [mgmt] - - - [2021-03-03 13:48:08.478490003 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 5152 "-" "-" auth_id(-)
Mar 03 14:48:09 redacted_hostname iotedged[1249]: 2021-03-03T13:48:09Z [INFO] - [mgmt] - - - [2021-03-03 13:48:09.324240879 UTC] "GET /identities/?api-version=2020-07-07 HTTP/1.1" 200 OK 1550 "-" "-" auth_id(-)
Mar 03 14:48:10 redacted_hostname iotedged[1249]: 2021-03-03T13:48:10Z [INFO] - [mgmt] - - - [2021-03-03 13:48:10.443034704 UTC] "PUT /identities/BlueTooth?api-version=2020-07-07 HTTP/1.1" 200 OK 99 "-" "-" auth_id(-)
Mar 03 14:48:10 redacted_hostname iotedged[1249]: 2021-03-03T13:48:10Z [INFO] - Pulling image redacted_registry.azurecr.io/bluetooth:2.0.0-20210301080123PM-arm32v7...
Mar 03 14:48:10 redacted_hostname iotedged[1249]: 2021-03-03T13:48:10Z [INFO] - [work] - - - [2021-03-03 13:48:10.996239540 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/sign?api-version=2019-01-30 HTTP/1.1" 200 OK 57 "-" "-" auth_id(-)
Mar 03 14:48:13 redacted_hostname iotedged[1249]: 2021-03-03T13:48:13Z [INFO] - [work] - - - [2021-03-03 13:48:13.327719580 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 393 "-" "-" auth_id(-)
Mar 03 14:48:13 redacted_hostname iotedged[1249]: 2021-03-03T13:48:13Z [INFO] - [work] - - - [2021-03-03 13:48:13.822951626 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/decrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 368 "-" "-" auth_id(-)
Mar 03 14:48:14 redacted_hostname iotedged[1249]: 2021-03-03T13:48:14Z [INFO] - [work] - - - [2021-03-03 13:48:14.010236566 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 573 "-" "-" auth_id(-)
Mar 03 14:48:14 redacted_hostname iotedged[1249]: 2021-03-03T13:48:14Z [INFO] - [work] - - - [2021-03-03 13:48:14.207497143 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/decrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 552 "-" "-" auth_id(-)
Mar 03 14:48:14 redacted_hostname iotedged[1249]: 2021-03-03T13:48:14Z [INFO] - [work] - - - [2021-03-03 13:48:14.733159380 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 621 "-" "-" auth_id(-)
Mar 03 14:48:14 redacted_hostname iotedged[1249]: 2021-03-03T13:48:14Z [INFO] - [work] - - - [2021-03-03 13:48:14.888842684 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 637 "-" "-" auth_id(-)
Mar 03 14:48:15 redacted_hostname iotedged[1249]: 2021-03-03T13:48:15Z [INFO] - [work] - - - [2021-03-03 13:48:15.223131218 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 629 "-" "-" auth_id(-)
Mar 03 14:48:15 redacted_hostname iotedged[1249]: 2021-03-03T13:48:15Z [INFO] - [work] - - - [2021-03-03 13:48:15.230613389 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/sign?api-version=2019-01-30 HTTP/1.1" 200 OK 57 "-" "-" auth_id(-)
Mar 03 14:48:15 redacted_hostname iotedged[1249]: 2021-03-03T13:48:15Z [INFO] - [work] - - - [2021-03-03 13:48:15.377904531 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 625 "-" "-" auth_id(-)
Mar 03 14:48:15 redacted_hostname iotedged[1249]: 2021-03-03T13:48:15Z [INFO] - [work] - - - [2021-03-03 13:48:15.512231679 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 641 "-" "-" auth_id(-)
Mar 03 14:48:15 redacted_hostname iotedged[1249]: 2021-03-03T13:48:15Z [INFO] - [work] - - - [2021-03-03 13:48:15.671819740 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 625 "-" "-" auth_id(-)
Mar 03 14:48:15 redacted_hostname iotedged[1249]: 2021-03-03T13:48:15Z [INFO] - [work] - - - [2021-03-03 13:48:15.785476036 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 649 "-" "-" auth_id(-)
Mar 03 14:48:15 redacted_hostname iotedged[1249]: 2021-03-03T13:48:15Z [INFO] - [work] - - - [2021-03-03 13:48:15.894911330 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 645 "-" "-" auth_id(-)
Mar 03 14:48:15 redacted_hostname iotedged[1249]: 2021-03-03T13:48:15Z [INFO] - [work] - - - [2021-03-03 13:48:15.996649038 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 641 "-" "-" auth_id(-)
Mar 03 14:48:16 redacted_hostname iotedged[1249]: 2021-03-03T13:48:16Z [INFO] - [work] - - - [2021-03-03 13:48:16.102504730 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 637 "-" "-" auth_id(-)
Mar 03 14:48:16 redacted_hostname iotedged[1249]: 2021-03-03T13:48:16Z [INFO] - [work] - - - [2021-03-03 13:48:16.199771334 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 477 "-" "-" auth_id(-)
Mar 03 14:48:16 redacted_hostname iotedged[1249]: 2021-03-03T13:48:16Z [INFO] - [work] - - - [2021-03-03 13:48:16.296683411 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 641 "-" "-" auth_id(-)
Mar 03 14:48:16 redacted_hostname iotedged[1249]: 2021-03-03T13:48:16Z [INFO] - [work] - - - [2021-03-03 13:48:16.399385069 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 641 "-" "-" auth_id(-)
Mar 03 14:48:16 redacted_hostname iotedged[1249]: 2021-03-03T13:48:16Z [INFO] - [work] - - - [2021-03-03 13:48:16.530007668 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 633 "-" "-" auth_id(-)
Mar 03 14:48:16 redacted_hostname iotedged[1249]: 2021-03-03T13:48:16Z [INFO] - [work] - - - [2021-03-03 13:48:16.630394036 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/decrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 552 "-" "-" auth_id(-)
Mar 03 14:48:16 redacted_hostname iotedged[1249]: 2021-03-03T13:48:16Z [INFO] - [work] - - - [2021-03-03 13:48:16.663294670 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 673 "-" "-" auth_id(-)
Mar 03 14:48:16 redacted_hostname iotedged[1249]: 2021-03-03T13:48:16Z [INFO] - [work] - - - [2021-03-03 13:48:16.829973135 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/decrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 552 "-" "-" auth_id(-)
Mar 03 14:48:16 redacted_hostname iotedged[1249]: 2021-03-03T13:48:16Z [INFO] - [work] - - - [2021-03-03 13:48:16.859884683 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/decrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 552 "-" "-" auth_id(-)
Mar 03 14:48:16 redacted_hostname iotedged[1249]: 2021-03-03T13:48:16Z [INFO] - [work] - - - [2021-03-03 13:48:16.904705884 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 637 "-" "-" auth_id(-)
Mar 03 14:48:17 redacted_hostname iotedged[1249]: 2021-03-03T13:48:17Z [INFO] - [work] - - - [2021-03-03 13:48:17.527845773 UTC] "POST /modules/%24edgeHub/genid/637431235995678909/decrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 552 "-" "-" auth_id(-)
Mar 03 14:48:17 redacted_hostname iotedged[1249]: 2021-03-03T13:48:17Z [INFO] - Checking edge runtime status
Mar 03 14:48:17 redacted_hostname iotedged[1249]: 2021-03-03T13:48:17Z [INFO] - Edge runtime is running.

More detailed or specific logs can be provided if needed.

Additional Information

Additional Software

Our devices also run the following services:

  • Rsyslog (8.1901.0 (aka 2019.01))
  • Telegraf agent (1.17.3), reporting various health metrics (cpu, net, mem, disk,…) to Azure Metrics on an IoT Hub
  • Logrotate (3.14.0), configured to rotate logs daily
  • Around 6 IoT Edge modules containing the business logic, built on .NET Core 2.1

Experiments

We have tried multiple ideas to identify the root cause of the memory leak, and try to fix it, but with no luck so far. All the following graphs come from the data collected by the Telegraf agent, visualized on Azure Metrics.

Control experiment

With all the services enabled, and working as planned in production, we get the following memory behavior:

control

Impact of rsyslog

Disabling rsyslog does not change the memory behavior:

rsyslog

Impact of our IoT Edge modules

Disabling all of our custom IoT Edge modules reduces the memory usage increase, but does not remove it completely.

modules

Impact of Telegraf

Greatly increasing the workload of Telegraf (by increasing the amount of metrics to report tenfold) leads to an erratic memory behavior. It initially seems that the memory leak is gone, but it reappears after a dozen hours, hinting that the memory usage of Telegraf was only hiding the memory leak in noise.

telegraf

Impact of IoT Edge

Disabling IoT Edge entirely (with systemctl disable iotedge followed by a reboot) reduces the memory leak to less than 5Mo/day.

iotedge

Impact of Docker container memory limits

Up until this points, all of the IoT Edge modules/Docker containers have been running with full access to the 1GB of RAM of the device. Limiting this memory to 26Mo per custom module, 58Mo for edgeAgent, and 137Mo for edgeHub still results in a memory leak, but this time accompanied with frequent crashes/reboots of edgeHub.

docker_memory

Impact of a swap file

Adding a 512Mo swapfile to our device initially helps alleviate the memory leak, but this effect stops after about 12 hours.

swapfile

Impact of the .NET Garbage Collection

According to the information found in this .NET issue and this blog post, the default .NET garbage collector is not always perfectly adapted to memory-constrained environments. A potential fix is to change it, by adding the following in the .csproj of each module:

<PropertyGroup>
    <ServerGarbageCollection>false</ServerGarbageCollection>
</PropertyGroup>

This did not have any effect on the memory consumption.

gc

Impact of the .NET Core version

All of our modules are built on top of .NET 2.1 LTS. This Microsoft blog post claims that .NET Core 3.0 (and beyond) is more suited to resource-constrained environments, such as an embedded device running multiple Docker containers. To test this, we upgraded all of our modules to .NET 3.1. This did not have any effect on the memory usage.

dotnet_version

Impact of limited system memory

To confirm that the two previous tests did indeed cause issues when the system memory ran out, we artificially reduced the system memory of our devices to 650MB (out of 1GB available). This is done with the total_mem=650 configuration option in /boot/config.txt (see this link for reference). This did not change the memory consumption of the devices, and only caused them to become unresponsive after less than 24 hours of uptime.

Garbage Collector: memory_gc

.NET 3.1: memory_dotnet_version

About this issue

  • Original URL
  • State: closed
  • Created 3 years ago
  • Comments: 36 (13 by maintainers)

Most upvoted comments

@emilm I am using just Memory.

@AdrienCos I can’t attach the deployment file as the file type is json I pasted it below and stripped the credentials.

{
    "modulesContent": {
        "$edgeAgent": {
            "properties.desired": {
                "modules": {},
                "runtime": {
                    "settings": {
                        "minDockerVersion": "v1.25",
                        "registryCredentials": {}
                    },
                    "type": "docker"
                },
                "schemaVersion": "1.0",
                "systemModules": {
                    "edgeAgent": {
                        "settings": {
                            "image": "mcr.microsoft.com/azureiotedge-agent:1.1.0-linux-arm32v7",
                            "createOptions": "{\"ExposedPorts\": {\"9600/tcp\": {}}, \"HostConfig\": {\"LogConfig\":{\"Type\":\"json-file\",\"Config\":{\"max-size\":\"4m\",\"max-file\":\"125\",\"compress\":\"true\"}}, \"PortBindings\": {\"9600/tcp\": [{\"HostPort\": \"9600\"}]}}}"
                        },
                        "type": "docker"
                    },
                    "edgeHub": {
                        "settings": {
                            "image": "mcr.microsoft.com/azureiotedge-hub:1.1.0-linux-arm32v7",
                            "createOptions": "{\"ExposedPorts\": {\"9600/tcp\": {}}, \"HostConfig\": {\"Memory\":105000000, \"LogConfig\":{\"Type\":\"json-file\",\"Config\":{\"max-size\":\"4m\",\"max-file\":\"125\",\"compress\":\"true\"}}, \"PortBindings\": {\"8883/tcp\": [{\"HostPort\": \"8883\"}],\"5671/tcp\": [{\"HostPort\": \"5671\"}],\"9600/tcp\": [{\"HostPort\": \"9601\"}]}}}"
                        },
                        "type": "docker",
                        "env": {
                            "OptimizeForPerformance": {
                                "value": "false"
                            }
                        },
                        "status": "running",
                        "restartPolicy": "always"
                    }
                }
            }
        },
        "$edgeHub": {
            "properties.desired": {
                "routes": {
                    "TempSensorToTempFilter": "FROM /messages/modules/* INTO $upstream"
                },
                "schemaVersion": "1.0",
                "storeAndForwardConfiguration": {
                    "timeToLiveSecs": 86400
                }
            }
        }
    }
}
+2
and-rewsmith on Apr 16, 2021

Ok, we will start the following tests as soon as possible to confirm your hypothesis:

  • One device running just edgeHub and edgeAgent
  • One device running just edgeHub and edgeAgent, but with only 400MB of system RAM available

I will post the results here when they arrive.

Regarding the logs of edgeHub, I don’t have them on hand, as the logs on our devices got rotated before I had a chance to grab them. I will post them here if I manage to get them.

+2
AdrienCos on Mar 10, 2021

@AdrienCos Everything is still looking good in the test where I strictly limit EdgeHub memory usage via docker createOptions. So it is looking like the second case outlined above. strict-limit-4-14

+1
and-rewsmith on Apr 14, 2021

@emilm

What are the appropriate memory constraint settings in AMQPS for Hub ?

I think the main concern is that enough memory is left available for the system resources. My intuition is that around 200-300MB is enough for EdgeHub to handle a busy environment.

And should there be settings on Agent?

I know that when uploading logs a lot of memory can be used, so I would set this too. Otherwise Edge Agent seems to be less of a risk. I would err on the side of caution and limit it anyway. My intution is ~100MB. Maybe more if you have log upload issues.

Is there any danger in running 1.1 containers on 1.0.10.3 iotedged?

We don’t test for compatibility between service and system modules. I think you would want to upgrade both the service and the system modules.

+1
and-rewsmith on Apr 13, 2021
Read more comments on GitHub
← iotedge: Log Retention Setting is not being set at module level when we are changing it in deployment template as create option
iotedge: Memory Leak in edgeHub module →