iotedge: EdgeAgent: Direct method call for UploadSupportBundle not working / fuzzy
Expected Behavior
When calling the direct method call “UploadSupportBundle” it should create and upload the support bundle to the given SAS-Url.
Current Behavior
As I’m tracking the current status with “GetTaskStatus” direct method call it returns status cancelled after a while and there is an exception in edgeAgent. The interesting behaviour is also that it works sometimes and sometimes not, no matter if I changed something or not.
Steps to Reproduce
Provide a detailed set of steps to reproduce the bug.
- Clean install of Raspberry Pi OS with Raspberry Pi 3 Model B V1.2
- Follow instructions of Microsoft to get latest IoT Edge version installed
- Provision Raspberry Pi to IoT Hub with x.509 via DPS (don’t know if this matters)
- Call UploadSupportBundle via IoT Hub in Azure Portal
- Wait for failure 😦
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 - OK
√ host time is close to real time - OK
√ container time is close to host time - OK
√ DNS server - OK
√ production readiness: identity certificates expiry - OK
√ production readiness: certificates - OK
√ production readiness: container engine - OK
√ production readiness: logs policy - OK
√ production readiness: Edge Agent's storage directory is persisted on the host filesystem - OK
√ production readiness: Edge Hub's storage directory is persisted on the host filesystem - OK
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
25 check(s) succeeded.
Device Information
- Host OS [e.g. Ubuntu 18.04, Windows Server IoT 2019]: Raspbian GNU/Linux 10 (buster)
- Architecture [e.g. amd64, arm32, arm64]: arm32
- Container OS [e.g. Linux containers, Windows containers]: Linux containers
Runtime Versions
- aziot-edged [run
iotedge version]: iotedge 1.1.0 - Edge Agent [image tag (e.g. 1.0.0)]: 1.1
- Edge Hub [image tag (e.g. 1.0.0)]: 1.1
- Docker/Moby [run
docker version]: 3.0.13+azure
Note: when using Windows containers on Windows, run docker -H npipe:////./pipe/iotedge_moby_engine version instead
Logs
aziot-edged logs
Feb 24 16:57:07 raspi-tim-dev iotedged[1282]: 2021-02-24T16:57:07Z [INFO] - Checking edge runtime status
Feb 24 16:57:07 raspi-tim-dev iotedged[1282]: 2021-02-24T16:57:07Z [INFO] - Edge runtime is running.
Feb 24 16:57:08 raspi-tim-dev iotedged[1282]: 2021-02-24T16:57:08Z [INFO] - [mgmt] - - - [2021-02-24 16:57:08.555006493 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 16:57:13 raspi-tim-dev iotedged[1282]: 2021-02-24T16:57:13Z [INFO] - [mgmt] - - - [2021-02-24 16:57:13.683742836 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 16:57:18 raspi-tim-dev iotedged[1282]: 2021-02-24T16:57:18Z [INFO] - [mgmt] - - - [2021-02-24 16:57:18.833796718 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 16:57:27 raspi-tim-dev iotedged[1282]: 2021-02-24T16:57:27Z [INFO] - [mgmt] - - - [2021-02-24 16:57:27.285223376 UTC] "GET /modules/?api-version=2018-06-28 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-
Feb 24 16:58:07 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:07Z [INFO] - Checking edge runtime status
Feb 24 16:58:07 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:07Z [INFO] - Edge runtime is running.
Feb 24 16:58:42 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:42Z [INFO] - [mgmt] - - - [2021-02-24 16:58:42.235021317 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 16:58:42 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:42Z [INFO] - Getting logs for module X...
Feb 24 16:58:42 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:42Z [INFO] - Successfully got logs for module X
Feb 24 16:58:42 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:42Z [INFO] - Getting logs for module X...
Feb 24 16:58:42 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:42Z [INFO] - Successfully got logs for module X
Feb 24 16:58:42 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:42Z [INFO] - Getting logs for module edgeAgent...
Feb 24 16:58:42 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:42Z [INFO] - Successfully got logs for module edgeAgent
Feb 24 16:58:42 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:42Z [INFO] - Getting logs for module X...
Feb 24 16:58:42 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:42Z [INFO] - Successfully got logs for module X
Feb 24 16:58:42 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:42Z [INFO] - Getting logs for module X...
Feb 24 16:58:42 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:42Z [INFO] - Successfully got logs for module X
Feb 24 16:58:42 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:42Z [INFO] - Getting logs for module edgeHub...
Feb 24 16:58:42 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:42Z [INFO] - Successfully got logs for module edgeHub
Feb 24 16:58:45 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:45Z [INFO] - [mgmt] - - - [2021-02-24 16:58:45.134243552 UTC] "GET /systeminfo/supportbundle?api-version=2020-07-07&since=2d&iothub_hostnam
Feb 24 16:58:47 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:47Z [INFO] - [mgmt] - - - [2021-02-24 16:58:47.411531086 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 16:58:47 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:47Z [INFO] - Querying system resources...
Feb 24 16:58:52 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:52Z [INFO] - [mgmt] - - - [2021-02-24 16:58:52.566113726 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 16:58:57 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:57Z [INFO] - [mgmt] - - - [2021-02-24 16:58:57.698573144 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 16:58:58 raspi-tim-dev iotedged[1282]: 2021-02-24T16:58:58Z [INFO] - [mgmt] - - - [2021-02-24 16:58:58.776888791 UTC] "GET /systeminfo/resources?api-version=2020-07-07 HTTP/1.1" 200 OK 8171 "-" "
Feb 24 16:59:02 raspi-tim-dev iotedged[1282]: 2021-02-24T16:59:02Z [INFO] - [mgmt] - - - [2021-02-24 16:59:02.843421524 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 16:59:07 raspi-tim-dev iotedged[1282]: 2021-02-24T16:59:07Z [INFO] - Checking edge runtime status
Feb 24 16:59:07 raspi-tim-dev iotedged[1282]: 2021-02-24T16:59:07Z [INFO] - Edge runtime is running.
Feb 24 16:59:07 raspi-tim-dev iotedged[1282]: 2021-02-24T16:59:07Z [INFO] - [mgmt] - - - [2021-02-24 16:59:07.971304922 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 16:59:13 raspi-tim-dev iotedged[1282]: 2021-02-24T16:59:13Z [INFO] - [mgmt] - - - [2021-02-24 16:59:13.105714797 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 16:59:18 raspi-tim-dev iotedged[1282]: 2021-02-24T16:59:18Z [INFO] - [mgmt] - - - [2021-02-24 16:59:18.243046942 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 16:59:23 raspi-tim-dev iotedged[1282]: 2021-02-24T16:59:23Z [INFO] - [mgmt] - - - [2021-02-24 16:59:23.371786244 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 16:59:28 raspi-tim-dev iotedged[1282]: 2021-02-24T16:59:28Z [INFO] - [mgmt] - - - [2021-02-24 16:59:28.515654394 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 16:59:33 raspi-tim-dev iotedged[1282]: 2021-02-24T16:59:33Z [INFO] - [mgmt] - - - [2021-02-24 16:59:33.657125567 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 16:59:38 raspi-tim-dev iotedged[1282]: 2021-02-24T16:59:38Z [INFO] - [mgmt] - - - [2021-02-24 16:59:38.798884862 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 16:59:43 raspi-tim-dev iotedged[1282]: 2021-02-24T16:59:43Z [INFO] - [mgmt] - - - [2021-02-24 16:59:43.931623384 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 16:59:49 raspi-tim-dev iotedged[1282]: 2021-02-24T16:59:49Z [INFO] - [mgmt] - - - [2021-02-24 16:59:49.170623234 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 16:59:54 raspi-tim-dev iotedged[1282]: 2021-02-24T16:59:54Z [INFO] - [mgmt] - - - [2021-02-24 16:59:54.318243431 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 16:59:59 raspi-tim-dev iotedged[1282]: 2021-02-24T16:59:59Z [INFO] - [mgmt] - - - [2021-02-24 16:59:59.457414118 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:00:04 raspi-tim-dev iotedged[1282]: 2021-02-24T17:00:04Z [INFO] - [mgmt] - - - [2021-02-24 17:00:04.595612072 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:00:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:00:07Z [INFO] - Checking edge runtime status
Feb 24 17:00:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:00:07Z [INFO] - Edge runtime is running.
Feb 24 17:00:09 raspi-tim-dev iotedged[1282]: 2021-02-24T17:00:09Z [INFO] - [mgmt] - - - [2021-02-24 17:00:09.728765116 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:00:14 raspi-tim-dev iotedged[1282]: 2021-02-24T17:00:14Z [INFO] - [mgmt] - - - [2021-02-24 17:00:14.853257990 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:00:19 raspi-tim-dev iotedged[1282]: 2021-02-24T17:00:19Z [INFO] - [mgmt] - - - [2021-02-24 17:00:19.982347120 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:00:25 raspi-tim-dev iotedged[1282]: 2021-02-24T17:00:25Z [INFO] - [mgmt] - - - [2021-02-24 17:00:25.130626177 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:00:30 raspi-tim-dev iotedged[1282]: 2021-02-24T17:00:30Z [INFO] - [mgmt] - - - [2021-02-24 17:00:30.283419634 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:00:35 raspi-tim-dev iotedged[1282]: 2021-02-24T17:00:35Z [INFO] - [mgmt] - - - [2021-02-24 17:00:35.420474599 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:00:40 raspi-tim-dev iotedged[1282]: 2021-02-24T17:00:40Z [INFO] - [mgmt] - - - [2021-02-24 17:00:40.572086499 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:01:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:01:07Z [INFO] - Checking edge runtime status
Feb 24 17:01:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:01:07Z [INFO] - Edge runtime is running.
Feb 24 17:02:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:02:07Z [INFO] - Checking edge runtime status
Feb 24 17:02:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:02:07Z [INFO] - Edge runtime is running.
Feb 24 17:02:31 raspi-tim-dev iotedged[1282]: 2021-02-24T17:02:31Z [INFO] - [mgmt] - - - [2021-02-24 17:02:31.285765200 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:02:36 raspi-tim-dev iotedged[1282]: 2021-02-24T17:02:36Z [INFO] - [mgmt] - - - [2021-02-24 17:02:36.603213010 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:02:41 raspi-tim-dev iotedged[1282]: 2021-02-24T17:02:41Z [INFO] - [mgmt] - - - [2021-02-24 17:02:41.739840993 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:02:46 raspi-tim-dev iotedged[1282]: 2021-02-24T17:02:46Z [INFO] - [mgmt] - - - [2021-02-24 17:02:46.879175420 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:02:52 raspi-tim-dev iotedged[1282]: 2021-02-24T17:02:52Z [INFO] - [mgmt] - - - [2021-02-24 17:02:52.032391456 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:02:57 raspi-tim-dev iotedged[1282]: 2021-02-24T17:02:57Z [INFO] - [mgmt] - - - [2021-02-24 17:02:57.164322893 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:02 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:02Z [INFO] - [mgmt] - - - [2021-02-24 17:03:02.308748156 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:07Z [INFO] - Checking edge runtime status
Feb 24 17:03:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:07Z [INFO] - Edge runtime is running.
Feb 24 17:03:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:07Z [INFO] - [mgmt] - - - [2021-02-24 17:03:07.444692605 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:12 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:12Z [INFO] - [mgmt] - - - [2021-02-24 17:03:12.581170733 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:17 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:17Z [INFO] - [mgmt] - - - [2021-02-24 17:03:17.713291758 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:22 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:22Z [INFO] - [mgmt] - - - [2021-02-24 17:03:22.850665230 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:27 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:27Z [INFO] - [mgmt] - - - [2021-02-24 17:03:27.983425430 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:33 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:33Z [INFO] - [mgmt] - - - [2021-02-24 17:03:33.105849599 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:38 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:38Z [INFO] - [mgmt] - - - [2021-02-24 17:03:38.245080584 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:43 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:43Z [INFO] - [mgmt] - - - [2021-02-24 17:03:43.384347473 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:48 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:48Z [INFO] - [mgmt] - - - [2021-02-24 17:03:48.519613596 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:53 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:53Z [INFO] - [mgmt] - - - [2021-02-24 17:03:53.653969456 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:07Z [INFO] - Checking edge runtime status
Feb 24 17:03:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:07Z [INFO] - Edge runtime is running.
Feb 24 17:03:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:07Z [INFO] - [mgmt] - - - [2021-02-24 17:03:07.444692605 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:12 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:12Z [INFO] - [mgmt] - - - [2021-02-24 17:03:12.581170733 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:17 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:17Z [INFO] - [mgmt] - - - [2021-02-24 17:03:17.713291758 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:22 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:22Z [INFO] - [mgmt] - - - [2021-02-24 17:03:22.850665230 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:27 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:27Z [INFO] - [mgmt] - - - [2021-02-24 17:03:27.983425430 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:33 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:33Z [INFO] - [mgmt] - - - [2021-02-24 17:03:33.105849599 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:38 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:38Z [INFO] - [mgmt] - - - [2021-02-24 17:03:38.245080584 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:43 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:43Z [INFO] - [mgmt] - - - [2021-02-24 17:03:43.384347473 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:48 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:48Z [INFO] - [mgmt] - - - [2021-02-24 17:03:48.519613596 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:53 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:53Z [INFO] - [mgmt] - - - [2021-02-24 17:03:53.653969456 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:58 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:58Z [INFO] - [mgmt] - - - [2021-02-24 17:03:58.786497180 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:58 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:58Z [INFO] - Querying system resources...
Feb 24 17:04:03 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:03Z [INFO] - [mgmt] - - - [2021-02-24 17:04:03.933964962 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:04:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:07Z [INFO] - Checking edge runtime status
Feb 24 17:04:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:07Z [INFO] - Edge runtime is running.
Feb 24 17:04:09 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:09Z [INFO] - [mgmt] - - - [2021-02-24 17:04:09.093472541 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:04:10 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:10Z [INFO] - [mgmt] - - - [2021-02-24 17:04:10.071579978 UTC] "GET /systeminfo/resources?api-version=2020-07-07 HTTP/1.1" 200 OK 8174 "-" "
Feb 24 17:04:14 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:14Z [INFO] - [mgmt] - - - [2021-02-24 17:04:14.221882152 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:04:19 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:19Z [INFO] - [mgmt] - - - [2021-02-24 17:04:19.353792695 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:58 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:58Z [INFO] - [mgmt] - - - [2021-02-24 17:03:58.786497180 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:03:58 raspi-tim-dev iotedged[1282]: 2021-02-24T17:03:58Z [INFO] - Querying system resources...
Feb 24 17:04:03 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:03Z [INFO] - [mgmt] - - - [2021-02-24 17:04:03.933964962 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:04:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:07Z [INFO] - Checking edge runtime status
Feb 24 17:04:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:07Z [INFO] - Edge runtime is running.
Feb 24 17:04:09 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:09Z [INFO] - [mgmt] - - - [2021-02-24 17:04:09.093472541 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:04:10 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:10Z [INFO] - [mgmt] - - - [2021-02-24 17:04:10.071579978 UTC] "GET /systeminfo/resources?api-version=2020-07-07 HTTP/1.1" 200 OK 8174 "-" "
Feb 24 17:04:14 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:14Z [INFO] - [mgmt] - - - [2021-02-24 17:04:14.221882152 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:04:19 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:19Z [INFO] - [mgmt] - - - [2021-02-24 17:04:19.353792695 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:04:24 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:24Z [INFO] - [mgmt] - - - [2021-02-24 17:04:24.497902224 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:04:29 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:29Z [INFO] - [mgmt] - - - [2021-02-24 17:04:29.635911012 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:04:34 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:34Z [INFO] - [mgmt] - - - [2021-02-24 17:04:34.753010572 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:04:39 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:39Z [INFO] - [mgmt] - - - [2021-02-24 17:04:39.872884569 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:04:45 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:45Z [INFO] - [mgmt] - - - [2021-02-24 17:04:45.019385790 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:04:50 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:50Z [INFO] - [mgmt] - - - [2021-02-24 17:04:50.141259060 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:04:55 raspi-tim-dev iotedged[1282]: 2021-02-24T17:04:55Z [INFO] - [mgmt] - - - [2021-02-24 17:04:55.272645124 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:05:00 raspi-tim-dev iotedged[1282]: 2021-02-24T17:05:00Z [INFO] - [mgmt] - - - [2021-02-24 17:05:00.407794918 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:05:05 raspi-tim-dev iotedged[1282]: 2021-02-24T17:05:05Z [INFO] - [mgmt] - - - [2021-02-24 17:05:05.532800887 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:05:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:05:07Z [INFO] - Checking edge runtime status
Feb 24 17:05:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:05:07Z [INFO] - Edge runtime is running.
Feb 24 17:05:10 raspi-tim-dev iotedged[1282]: 2021-02-24T17:05:10Z [INFO] - [mgmt] - - - [2021-02-24 17:05:10.664884996 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:05:15 raspi-tim-dev iotedged[1282]: 2021-02-24T17:05:15Z [INFO] - [mgmt] - - - [2021-02-24 17:05:15.799992291 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:05:20 raspi-tim-dev iotedged[1282]: 2021-02-24T17:05:20Z [INFO] - [mgmt] - - - [2021-02-24 17:05:20.925552612 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:00:40 raspi-tim-dev iotedged[1282]: 2021-02-24T17:00:40Z [INFO] - [mgmt] - - - [2021-02-24 17:00:40.572086499 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 2981 "-" "-" auth_id(-)
Feb 24 17:01:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:01:07Z [INFO] - Checking edge runtime status
Feb 24 17:01:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:01:07Z [INFO] - Edge runtime is running.
Feb 24 17:02:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:02:07Z [INFO] - Checking edge runtime status
Feb 24 17:02:07 raspi-tim-dev iotedged[1282]: 2021-02-24T17:02:07Z [INFO] - Edge runtime is running.
edge-agent logs
2021-02-24 16:42:01 +00:00 Starting Edge Agent
2021-02-24 16:42:01 +00:00 Changing ownership of storage folder: /iotedge/storage//edgeAgent to 1000
2021-02-24 16:42:01 +00:00 Changing ownership of management socket: /var/run/iotedge/mgmt.sock
2021-02-24 16:42:03.251 +00:00 Edge Agent Main()
<6> 2021-02-24 16:42:05.930 +00:00 [INF] - Initializing Edge Agent.
<6> 2021-02-24 16:42:07.929 +00:00 [INF] - Version - 1.1.0.39334128 (92ac4878a4c8ca74c0db14cd2e63273f1c8661f4)
<6> 2021-02-24 16:42:07.935 +00:00 [INF] -
█████╗ ███████╗██╗ ██╗██████╗ ███████╗
██╔══██╗╚══███╔╝██║ ██║██╔══██╗██╔════╝
███████║ ███╔╝ ██║ ██║██████╔╝█████╗
██╔══██║ ███╔╝ ██║ ██║██╔══██╗██╔══╝
██║ ██║███████╗╚██████╔╝██║ ██║███████╗
╚═╝ ╚═╝╚══════╝ ╚═════╝ ╚═╝ ╚═╝╚══════╝
██╗ ██████╗ ████████╗ ███████╗██████╗ ██████╗ ███████╗
██║██╔═══██╗╚══██╔══╝ ██╔════╝██╔══██╗██╔════╝ ██╔════╝
██║██║ ██║ ██║ █████╗ ██║ ██║██║ ███╗█████╗
██║██║ ██║ ██║ ██╔══╝ ██║ ██║██║ ██║██╔══╝
██║╚██████╔╝ ██║ ███████╗██████╔╝╚██████╔╝███████╗
╚═╝ ╚═════╝ ╚═╝ ╚══════╝╚═════╝ ╚═════╝ ╚══════╝
<6> 2021-02-24 16:42:08.390 +00:00 [INF] - Experimental features configuration: {"Enabled":false,"DisableCloudSubscriptions":false}
<6> 2021-02-24 16:42:09.669 +00:00 [INF] - Installing certificates [CN=<hidden>, O=<hidden>, C=DE:05/30/2030 08:37:39] to Root
<6> 2021-02-24 16:42:11.043 +00:00 [INF] - Starting metrics listener on Host: *, Port: 9600, Suffix: /metrics
<6> 2021-02-24 16:42:12.631 +00:00 [INF] - Updating performance metrics every 05m:00s
<6> 2021-02-24 16:42:12.677 +00:00 [INF] - Started operation Get system resources
<6> 2021-02-24 16:42:12.692 +00:00 [INF] - Collecting metadata metrics
<6> 2021-02-24 16:42:13.316 +00:00 [INF] - Set metadata metrics: 1.1.0.39334128 (92ac4878a4c8ca74c0db14cd2e63273f1c8661f4), {"Enabled":false,"DisableCloudSubscriptions":false}, {"OperatingSystemType":"linux","Architecture":"armv7l","Version":"1.1.0","Provisioning":{"Type":"dps.x509","DynamicReprovisioning":false},"ServerVersion":"3.0.13+azure","KernelVersion":"5.4.83-v7+","OperatingSystem":"Raspbian GNU/Linux 10 (buster)","NumCpus":4,"Virtualized":"no"}, True
<6> 2021-02-24 16:42:13.518 +00:00 [INF] - Started operation Checkpoint Availability
<6> 2021-02-24 16:42:13.575 +00:00 [INF] - Started operation refresh twin config
<6> 2021-02-24 16:42:13.698 +00:00 [INF] - Edge agent attempting to connect to IoT Hub via Amqp_WebSocket_Only...
<6> 2021-02-24 16:42:18.448 +00:00 [INF] - Created persistent store at /iotedge/storage/edgeAgent
<6> 2021-02-24 16:42:19.221 +00:00 [INF] - Started operation Metrics Scrape
<6> 2021-02-24 16:42:19.222 +00:00 [INF] - Started operation Metrics Upload
Scraping frequency: 01:00:00
Upload Frequency: 1.00:00:00
<6> 2021-02-24 16:42:21.570 +00:00 [INF] - Registering request handler UploadModuleLogs
<6> 2021-02-24 16:42:21.572 +00:00 [INF] - Registering request handler GetModuleLogs
<6> 2021-02-24 16:42:21.573 +00:00 [INF] - Registering request handler UploadSupportBundle
<6> 2021-02-24 16:42:21.574 +00:00 [INF] - Registering request handler RestartModule
<6> 2021-02-24 16:42:21.912 +00:00 [INF] - Edge agent connected to IoT Hub via Amqp_WebSocket_Only.
<6> 2021-02-24 16:42:22.693 +00:00 [INF] - Initialized new module client with subscriptions enabled
<6> 2021-02-24 16:42:23.000 +00:00 [INF] - Obtained Edge agent twin from IoTHub with desired properties version 29 and reported properties version 91.
<6> 2021-02-24 16:42:28.240 +00:00 [INF] - Plan execution started for deployment 29
<6> 2021-02-24 16:42:28.395 +00:00 [INF] - Executing command: "Command Group: (\n [Create module X]\n [Start module X]\n)"
<6> 2021-02-24 16:42:28.437 +00:00 [INF] - Executing command: "Create module X"
<6> 2021-02-24 16:42:39.016 +00:00 [INF] - Executing command: "Start module X"
<6> 2021-02-24 16:42:40.308 +00:00 [INF] - Executing command: "Command Group: (\n [Create module X]\n [Start module X]\n)"
<6> 2021-02-24 16:42:40.311 +00:00 [INF] - Executing command: "Create module X"
<6> 2021-02-24 16:42:52.124 +00:00 [INF] - Executing command: "Start module X"
<6> 2021-02-24 16:42:59.256 +00:00 [INF] - Executing command: "Command Group: (\n [Create module edgeHub]\n [Start module edgeHub]\n)"
<6> 2021-02-24 16:42:59.259 +00:00 [INF] - Executing command: "Create module edgeHub"
<6> 2021-02-24 16:43:11.972 +00:00 [INF] - Executing command: "Start module edgeHub"
<6> 2021-02-24 16:43:15.671 +00:00 [INF] - Executing command: "Command Group: (\n [Create module X]\n [Start module X]\n)"
<6> 2021-02-24 16:43:15.676 +00:00 [INF] - Executing command: "Create module X"
<6> 2021-02-24 16:43:26.172 +00:00 [INF] - Executing command: "Start module X"
<6> 2021-02-24 16:43:27.118 +00:00 [INF] - Executing command: "Command Group: (\n [Create module X]\n [Start module X]\n)"
<6> 2021-02-24 16:43:27.138 +00:00 [INF] - Executing command: "Create module X"
<6> 2021-02-24 16:43:37.926 +00:00 [INF] - Executing command: "Start module X"
<6> 2021-02-24 16:43:43.073 +00:00 [INF] - Plan execution ended for deployment 29
<6> 2021-02-24 16:43:44.506 +00:00 [INF] - Updated reported properties
<6> 2021-02-24 16:43:50.470 +00:00 [INF] - Updated reported properties
<6> 2021-02-24 16:57:18.732 +00:00 [INF] - Received direct method call - UploadSupportBundle
<6> 2021-02-24 16:57:18.748 +00:00 [INF] - Received request UploadSupportBundle with payload
<6> 2021-02-24 16:57:18.871 +00:00 [INF] - Successfully handled request UploadSupportBundle
<6> 2021-02-24 16:57:24.379 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 16:57:24.381 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 16:57:24.454 +00:00 [INF] - Handling status request for task c2905cd1-3ce2-4b28-9cc4-a3bc459b3e56 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 16:57:24.456 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 16:57:29.600 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 16:57:29.601 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 16:57:29.603 +00:00 [INF] - Handling status request for task c2905cd1-3ce2-4b28-9cc4-a3bc459b3e56 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 16:57:29.604 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 16:57:34.692 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 16:57:34.694 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 16:57:34.696 +00:00 [INF] - Handling status request for task c2905cd1-3ce2-4b28-9cc4-a3bc459b3e56 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 16:57:34.697 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 16:57:39.761 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 16:57:39.762 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 16:57:39.763 +00:00 [INF] - Handling status request for task c2905cd1-3ce2-4b28-9cc4-a3bc459b3e56 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 16:57:39.764 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 16:57:44.856 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 16:57:44.857 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 16:57:44.858 +00:00 [INF] - Handling status request for task c2905cd1-3ce2-4b28-9cc4-a3bc459b3e56 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 16:57:44.859 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 16:57:49.920 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 16:57:49.921 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 16:57:49.922 +00:00 [INF] - Handling status request for task c2905cd1-3ce2-4b28-9cc4-a3bc459b3e56 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 16:57:49.922 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 16:57:54.993 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 16:57:54.994 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 16:57:54.994 +00:00 [INF] - Handling status request for task c2905cd1-3ce2-4b28-9cc4-a3bc459b3e56 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 16:57:54.995 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 16:58:00.073 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 16:58:00.074 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 16:58:00.075 +00:00 [INF] - Handling status request for task c2905cd1-3ce2-4b28-9cc4-a3bc459b3e56 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 16:58:00.075 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 16:58:05.148 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 16:58:05.149 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 16:58:05.151 +00:00 [INF] - Handling status request for task c2905cd1-3ce2-4b28-9cc4-a3bc459b3e56 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 16:58:05.152 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 16:58:10.260 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 16:58:10.260 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 16:58:10.261 +00:00 [INF] - Handling status request for task c2905cd1-3ce2-4b28-9cc4-a3bc459b3e56 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 16:58:10.262 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 16:58:15.357 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 16:58:15.358 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 16:58:15.359 +00:00 [INF] - Handling status request for task c2905cd1-3ce2-4b28-9cc4-a3bc459b3e56 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 16:58:15.360 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 16:58:20.448 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 16:58:20.449 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 16:58:20.450 +00:00 [INF] - Handling status request for task c2905cd1-3ce2-4b28-9cc4-a3bc459b3e56 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 16:58:20.450 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 16:58:25.610 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 16:58:25.610 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 16:58:25.611 +00:00 [INF] - Handling status request for task c2905cd1-3ce2-4b28-9cc4-a3bc459b3e56 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 16:58:25.611 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 16:58:30.680 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 16:58:30.681 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 16:58:30.682 +00:00 [INF] - Handling status request for task c2905cd1-3ce2-4b28-9cc4-a3bc459b3e56 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 16:58:30.682 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 16:58:35.854 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 16:58:35.855 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 16:58:35.857 +00:00 [INF] - Handling status request for task c2905cd1-3ce2-4b28-9cc4-a3bc459b3e56 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 16:58:35.864 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 16:58:40.936 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 16:58:40.937 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 16:58:40.938 +00:00 [INF] - Handling status request for task c2905cd1-3ce2-4b28-9cc4-a3bc459b3e56 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 16:58:40.938 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 16:58:45.323 +00:00 [INF] - Uploading blob <hidden>/timraspbi/support-bundle-2021-02-24--16-58-45.zip to container support-bundles
<6> 2021-02-24 16:58:46.005 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 16:58:46.006 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 16:58:46.010 +00:00 [INF] - Handling status request for task c2905cd1-3ce2-4b28-9cc4-a3bc459b3e56 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 16:58:46.010 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 16:58:51.107 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 16:58:51.107 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 16:58:51.108 +00:00 [INF] - Handling status request for task c2905cd1-3ce2-4b28-9cc4-a3bc459b3e56 - Background task Status: Completed, Operation: upload support bundle
<6> 2021-02-24 16:58:51.108 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 17:00:41.052 +00:00 [INF] - Received direct method call - UploadSupportBundle
<6> 2021-02-24 17:00:41.052 +00:00 [INF] - Received request UploadSupportBundle with payload
<6> 2021-02-24 17:00:41.057 +00:00 [INF] - Successfully handled request UploadSupportBundle
<6> 2021-02-24 17:00:46.175 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 17:00:46.176 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 17:00:46.177 +00:00 [INF] - Handling status request for task 7792f3cb-b4e5-4cc6-88f2-8181aa385d80 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 17:00:46.177 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 17:00:51.270 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 17:00:51.271 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 17:00:51.272 +00:00 [INF] - Handling status request for task 7792f3cb-b4e5-4cc6-88f2-8181aa385d80 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 17:00:51.272 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 17:00:56.376 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 17:00:56.376 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 17:00:56.377 +00:00 [INF] - Handling status request for task 7792f3cb-b4e5-4cc6-88f2-8181aa385d80 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 17:00:56.378 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 17:01:01.642 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 17:01:01.642 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 17:01:01.643 +00:00 [INF] - Handling status request for task 7792f3cb-b4e5-4cc6-88f2-8181aa385d80 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 17:01:01.643 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 17:01:06.720 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 17:01:06.720 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 17:01:06.721 +00:00 [INF] - Handling status request for task 7792f3cb-b4e5-4cc6-88f2-8181aa385d80 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 17:01:06.722 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 17:01:11.789 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 17:01:11.790 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 17:01:11.790 +00:00 [INF] - Handling status request for task 7792f3cb-b4e5-4cc6-88f2-8181aa385d80 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 17:01:11.791 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 17:01:16.869 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 17:01:16.869 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 17:01:16.870 +00:00 [INF] - Handling status request for task 7792f3cb-b4e5-4cc6-88f2-8181aa385d80 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 17:01:16.870 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 17:01:21.969 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 17:01:21.969 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 17:01:21.970 +00:00 [INF] - Handling status request for task 7792f3cb-b4e5-4cc6-88f2-8181aa385d80 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 17:01:21.971 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 17:01:27.207 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 17:01:27.207 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 17:01:27.208 +00:00 [INF] - Handling status request for task 7792f3cb-b4e5-4cc6-88f2-8181aa385d80 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 17:01:27.215 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 17:01:32.275 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 17:01:32.276 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 17:01:32.277 +00:00 [INF] - Handling status request for task 7792f3cb-b4e5-4cc6-88f2-8181aa385d80 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 17:01:32.278 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 17:01:37.416 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 17:01:37.417 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 17:01:37.417 +00:00 [INF] - Handling status request for task 7792f3cb-b4e5-4cc6-88f2-8181aa385d80 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 17:01:37.418 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 17:01:42.485 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 17:01:42.485 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 17:01:42.489 +00:00 [INF] - Handling status request for task 7792f3cb-b4e5-4cc6-88f2-8181aa385d80 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 17:01:42.489 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 17:01:47.572 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 17:01:47.572 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 17:01:47.573 +00:00 [INF] - Handling status request for task 7792f3cb-b4e5-4cc6-88f2-8181aa385d80 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 17:01:47.573 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 17:01:52.635 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 17:01:52.635 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 17:01:52.636 +00:00 [INF] - Handling status request for task 7792f3cb-b4e5-4cc6-88f2-8181aa385d80 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 17:01:52.642 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 17:01:57.705 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 17:01:57.705 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 17:01:57.706 +00:00 [INF] - Handling status request for task 7792f3cb-b4e5-4cc6-88f2-8181aa385d80 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 17:01:57.706 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 17:02:02.771 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 17:02:02.771 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 17:02:02.772 +00:00 [INF] - Handling status request for task 7792f3cb-b4e5-4cc6-88f2-8181aa385d80 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 17:02:02.772 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 17:02:07.837 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 17:02:07.837 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 17:02:07.839 +00:00 [INF] - Handling status request for task 7792f3cb-b4e5-4cc6-88f2-8181aa385d80 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 17:02:07.839 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 17:02:12.895 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 17:02:12.896 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 17:02:12.896 +00:00 [INF] - Handling status request for task 7792f3cb-b4e5-4cc6-88f2-8181aa385d80 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 17:02:12.896 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 17:02:17.952 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 17:02:17.958 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 17:02:17.959 +00:00 [INF] - Handling status request for task 7792f3cb-b4e5-4cc6-88f2-8181aa385d80 - Background task Status: Running, Operation: upload support bundle
<6> 2021-02-24 17:02:17.959 +00:00 [INF] - Successfully handled request GetTaskStatus
<6> 2021-02-24 17:02:23.044 +00:00 [INF] - Received direct method call - GetTaskStatus
<6> 2021-02-24 17:02:23.044 +00:00 [INF] - Received request GetTaskStatus with payload
<6> 2021-02-24 17:02:23.044 +00:00 [INF] - Handling status request for task 7792f3cb-b4e5-4cc6-88f2-8181aa385d80 - Background task Status: Cancelled, Operation: upload support bundle
<6> 2021-02-24 17:02:23.045 +00:00 [INF] - Successfully handled request GetTaskStatus
<4> 2021-02-24 17:02:25.719 +00:00 [WRN] - Reconcile failed because of the an exception
System.OperationCanceledException: The operation was canceled.
at System.Threading.CancellationToken.ThrowOperationCanceledException()
at System.Threading.CancellationToken.ThrowIfCancellationRequested()
at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)
at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.GetResult(Int16 token)
at System.IO.BufferedStream.ReadFromUnderlyingStreamAsync(Memory`1 buffer, CancellationToken cancellationToken, Int32 bytesAlreadySatisfied, Task semaphoreLockTask)
at Microsoft.Azure.Devices.Edge.Util.Uds.HttpBufferedStream.ReadLineAsync(CancellationToken cancellationToken) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/uds/HttpBufferedStream.cs:line 62
at Microsoft.Azure.Devices.Edge.Util.Uds.HttpRequestResponseSerializer.SetResponseStatusLine(HttpResponseMessage httpResponse, HttpBufferedStream bufferedStream, CancellationToken cancellationToken) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/uds/HttpRequestResponseSerializer.cs:line 158
at Microsoft.Azure.Devices.Edge.Util.Uds.HttpRequestResponseSerializer.DeserializeResponse(HttpBufferedStream bufferedStream, CancellationToken cancellationToken) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/uds/HttpRequestResponseSerializer.cs:line 69
at Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/uds/HttpUdsMessageHandler.cs:line 40
at System.Net.Http.HttpClient.FinishSendAsyncUnbuffered(Task`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts)
at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2020_07_07.GeneratedCode.EdgeletHttpClient.ListModulesAsync(String api_version, CancellationToken cancellationToken) in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/version_2020_07_07/generatedCode/EdgeletHttpClient.cs:line 85
at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter[T](Task`1 task, TimeSpan timeout) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 128
at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Versioning.ModuleManagementHttpClientVersioned.Execute[T](Func`1 func, String operation) in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/versioning/ModuleManagementHttpClientVersioned.cs:line 146
at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2020_07_07.ModuleManagementHttpClient.HandleException(Exception exception, String operation) in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/version_2020_07_07/ModuleManagementHttpClient.cs:line 245
at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Versioning.ModuleManagementHttpClientVersioned.Execute[T](Func`1 func, String operation) in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/versioning/ModuleManagementHttpClientVersioned.cs:line 146
at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2020_07_07.ModuleManagementHttpClient.GetModules[T](CancellationToken cancellationToken) in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/version_2020_07_07/ModuleManagementHttpClient.cs:line 171
at Microsoft.Azure.Devices.Edge.Agent.Docker.DockerEnvironment.GetModulesAsync(CancellationToken token) in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Docker/DockerEnvironment.cs:line 51
at Microsoft.Azure.Devices.Edge.Agent.Core.Agent.GetCurrentModuleSetAsync(CancellationToken token) in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Core/Agent.cs:line 256
at Microsoft.Azure.Devices.Edge.Agent.Core.Agent.ReconcileAsync(CancellationToken token) in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Core/Agent.cs:line 208
<6> 2021-02-24 17:02:26.225 +00:00 [INF] - Updated reported properties
<6> 2021-02-24 17:02:31.563 +00:00 [INF] - Updated reported properties
edge-hub logs
2021-02-24 16:43:15 +00:00 Starting Edge Hub
2021-02-24 16:43:16.488 +00:00 Edge Hub Main()
<6> 2021-02-24 16:43:28.560 +00:00 [INF] - Installing certificates [CN=iotedged workload ca:12/31/2030 11:17:44],[CN=timraspbi.ca:12/31/2030 11:17:44],[CN=<hidden>:05/30/2030 08:43:50] to Root
<6> 2021-02-24 16:43:28.906 +00:00 [INF] - Installing certificates [CN=<hidden>, O=<hidden>, C=DE:05/30/2030 08:37:39] to Root
<6> 2021-02-24 16:43:28.952 +00:00 [INF] - Enabling SSL protocols: Tls, Tls11, Tls12
<6> 2021-02-24 16:43:30.429 +00:00 [INF] - Experimental features configuration: {"Enabled":false,"DisableCloudSubscriptions":false,"DisableConnectivityCheck":false}
<6> 2021-02-24 16:43:39.155 +00:00 [INF] - Created persistent store at /iotedge/storage/edgeHub
<6> 2021-02-24 16:43:40.137 +00:00 [INF] - Initializing Edge Hub
<6> 2021-02-24 16:43:40.141 +00:00 [INF] -
█████╗ ███████╗██╗ ██╗██████╗ ███████╗
██╔══██╗╚══███╔╝██║ ██║██╔══██╗██╔════╝
███████║ ███╔╝ ██║ ██║██████╔╝█████╗
██╔══██║ ███╔╝ ██║ ██║██╔══██╗██╔══╝
██║ ██║███████╗╚██████╔╝██║ ██║███████╗
╚═╝ ╚═╝╚══════╝ ╚═════╝ ╚═╝ ╚═╝╚══════╝
██╗ ██████╗ ████████╗ ███████╗██████╗ ██████╗ ███████╗
██║██╔═══██╗╚══██╔══╝ ██╔════╝██╔══██╗██╔════╝ ██╔════╝
██║██║ ██║ ██║ █████╗ ██║ ██║██║ ███╗█████╗
██║██║ ██║ ██║ ██╔══╝ ██║ ██║██║ ██║██╔══╝
██║╚██████╔╝ ██║ ███████╗██████╔╝╚██████╔╝███████╗
╚═╝ ╚═════╝ ╚═╝ ╚══════╝╚═════╝ ╚═════╝ ╚══════╝
<6> 2021-02-24 16:43:40.153 +00:00 [INF] - Version - 1.1.0.39334128 (92ac4878a4c8ca74c0db14cd2e63273f1c8661f4)
<6> 2021-02-24 16:43:40.154 +00:00 [INF] - OptimizeForPerformance=False
<6> 2021-02-24 16:43:40.155 +00:00 [INF] - MessageAckTimeoutSecs=30
<6> 2021-02-24 16:43:40.162 +00:00 [INF] - Loaded server certificate with expiration date of "2021-05-25T16:43:19.0000000+00:00"
<6> 2021-02-24 16:43:40.864 +00:00 [INF] - Using Asp Net server for metrics
<6> 2021-02-24 16:43:41.383 +00:00 [INF] - Started task to cleanup processed and stale messages
<6> 2021-02-24 16:43:41.383 +00:00 [INF] - Created new message store
<6> 2021-02-24 16:43:42.000 +00:00 [INF] - Created DeviceConnectivityManager with connected check frequency 00:05:00 and disconnected check frequency 00:02:00
<6> 2021-02-24 16:43:43.233 +00:00 [INF] - Created device scope identities cache
<6> 2021-02-24 16:43:43.309 +00:00 [INF] - Starting refresh of device scope identities cache
<6> 2021-02-24 16:43:43.566 +00:00 [INF] - Initialized storing twin manager
<6> 2021-02-24 16:43:43.623 +00:00 [INF] - Initializing configuration
<6> 2021-02-24 16:43:43.896 +00:00 [INF] - New device connection for device timraspbi/$edgeHub
<6> 2021-02-24 16:43:44.180 +00:00 [INF] - Client timraspbi/$edgeHub connected to edgeHub, processing existing subscriptions.
<6> 2021-02-24 16:43:44.604 +00:00 [INF] - Attempting to connect to IoT Hub for client timraspbi/$edgeHub via AMQP over WebSockets...
<6> 2021-02-24 16:43:46.423 +00:00 [INF] - Processing pending subscriptions for timraspbi/$edgeHub
<6> 2021-02-24 16:43:51.161 +00:00 [INF] - Created cloud endpoint iothub with max batch size 10 and fan-out factor of 10.
<6> 2021-02-24 16:43:51.468 +00:00 [INF] - Exiting disconnected state
<6> 2021-02-24 16:43:51.589 +00:00 [INF] - Device connected to cloud, processing subscriptions for connected clients.
<6> 2021-02-24 16:43:51.602 +00:00 [INF] - Processing subscriptions for client timraspbi/$edgeHub on device connected to cloud.
<6> 2021-02-24 16:43:51.605 +00:00 [INF] - Skipping timraspbi/$edgeHub for subscription processing, as it is currently being processed.
<6> 2021-02-24 16:43:51.631 +00:00 [INF] - Received device connected callback
<6> 2021-02-24 16:43:51.781 +00:00 [INF] - Entering connected state
<6> 2021-02-24 16:43:51.823 +00:00 [INF] - Cloud connection for timraspbi/$edgeHub is True
<6> 2021-02-24 16:43:51.846 +00:00 [INF] - Connection status for timraspbi/$edgeHub changed to ConnectionEstablished
<6> 2021-02-24 16:43:51.884 +00:00 [INF] - Client timraspbi/$edgeHub connected to cloud, processing existing subscriptions.
<6> 2021-02-24 16:43:51.884 +00:00 [INF] - Skipping timraspbi/$edgeHub for subscription processing, as it is currently being processed.
<6> 2021-02-24 16:43:51.952 +00:00 [INF] - Created cloud proxy for client timraspbi/$edgeHub via AMQP over WebSockets, with client operation timeout 20 seconds.
<6> 2021-02-24 16:43:52.002 +00:00 [INF] - Initialized cloud proxy 068f84aa-7762-4677-8689-d20054c6bed8 for timraspbi/$edgeHub
<6> 2021-02-24 16:43:52.030 +00:00 [INF] - Created cloud connection for client timraspbi/$edgeHub
<6> 2021-02-24 16:43:53.175 +00:00 [INF] - Updated reported properties for timraspbi/$edgeHub
<6> 2021-02-24 16:43:53.329 +00:00 [INF] - Processing pending subscriptions for timraspbi/$edgeHub
<6> 2021-02-24 16:43:54.057 +00:00 [INF] - Set the following 8 route(s) in edge hub
<6> 2021-02-24 16:43:54.070 +00:00 [INF] - Updated message store TTL to 7200 seconds
<6> 2021-02-24 16:43:54.073 +00:00 [INF] - Updated the edge hub store and forward configuration
<6> 2021-02-24 16:43:54.543 +00:00 [INF] - Started operation Get EdgeHub config
<6> 2021-02-24 16:43:54.546 +00:00 [INF] - Initialized edge hub configuration
<6> 2021-02-24 16:43:54.604 +00:00 [INF] - Starting timer to authenticate connections with a period of 300 seconds
<6> 2021-02-24 16:43:55.710 +00:00 [INF] - Scheduling server certificate renewal for "2021-05-25T16:40:49.0011334Z".
<6> 2021-02-24 16:43:55.722 +00:00 [INF] - Starting protocol heads - (MQTT, AMQP, HTTP)
<6> 2021-02-24 16:43:58.613 +00:00 [INF] - Starting MQTT head
<6> 2021-02-24 16:43:58.950 +00:00 [INF] - Initializing TLS endpoint on port 8883 for MQTT head.
<6> 2021-02-24 16:43:59.525 +00:00 [INF] - Starting AMQP head
<6> 2021-02-24 16:43:59.874 +00:00 [INF] - Started MQTT head
<6> 2021-02-24 16:44:00.387 +00:00 [INF] - Started AMQP head
<6> 2021-02-24 16:44:00.402 +00:00 [INF] - Obtained edge hub config from module twin
<6> 2021-02-24 16:44:00.411 +00:00 [INF] - Starting HTTP head
<6> 2021-02-24 16:44:00.653 +00:00 [INF] - Set the following 8 route(s) in edge hub
<6> 2021-02-24 16:44:00.657 +00:00 [INF] - Updated message store TTL to 7200 seconds
<6> 2021-02-24 16:44:00.658 +00:00 [INF] - Updated the edge hub store and forward configuration
<4> 2021-02-24 16:44:03.671 +00:00 [WRN] - Overriding address(es) '"http://+:80"'. Binding to endpoints defined in "UseKestrel()" instead.
<6> 2021-02-24 16:44:03.729 +00:00 [INF] - Started HTTP head
<6> 2021-02-24 16:44:03.867 +00:00 [INF] - Client timraspbi/<hidden> in device scope authenticated locally.
<6> 2021-02-24 16:44:03.972 +00:00 [INF] - Successfully generated identity for clientId timraspbi/<hidden> and username raspi-tim-dev/timraspbi/<hidden>/?api-version=2020-09-30&DeviceClientType=.NET%2F1.35.0%20%28.NET%205.0.3%3B%20Linux%205.4.83-v7%2B%20%231379%20SMP%20Mon%20Dec%2014%2013%3A08%3A57%20GMT%202020%3B%20Arm%29
<6> 2021-02-24 16:44:04.025 +00:00 [INF] - ClientAuthenticated, timraspbi/<hidden>, 7168bef5
<6> 2021-02-24 16:44:04.435 +00:00 [INF] - New device connection for device timraspbi/<hidden>
<6> 2021-02-24 16:44:04.440 +00:00 [INF] - Client timraspbi/<hidden> connected to edgeHub, processing existing subscriptions.
<6> 2021-02-24 16:44:04.563 +00:00 [INF] - Bind device proxy for device timraspbi/<hidden>
<6> 2021-02-24 16:44:04.569 +00:00 [INF] - Binding message channel for device Id timraspbi/<hidden>
<6> 2021-02-24 16:44:04.610 +00:00 [INF] - Attempting to connect to IoT Hub for client timraspbi/<hidden> via AMQP over WebSockets...
<6> 2021-02-24 16:44:04.774 +00:00 [INF] - Updated reported properties for timraspbi/$edgeHub
<6> 2021-02-24 16:44:04.927 +00:00 [INF] - Processing subscriptions TwinResponse, Methods, ModuleMessages, DesiredPropertyUpdates for client timraspbi/<hidden>.
<6> 2021-02-24 16:44:04.930 +00:00 [INF] - Processing pending subscriptions for timraspbi/<hidden>
<6> 2021-02-24 16:44:04.994 +00:00 [INF] - Set subscriptions from session state for timraspbi/<hidden>
<6> 2021-02-24 16:44:05.025 +00:00 [INF] - Cloud connection for timraspbi/<hidden> is True
<6> 2021-02-24 16:44:05.027 +00:00 [INF] - Connection status for timraspbi/<hidden> changed to ConnectionEstablished
<6> 2021-02-24 16:44:05.029 +00:00 [INF] - Client timraspbi/<hidden> connected to cloud, processing existing subscriptions.
<6> 2021-02-24 16:44:05.030 +00:00 [INF] - Skipping timraspbi/<hidden> for subscription processing, as it is currently being processed.
<6> 2021-02-24 16:44:05.031 +00:00 [INF] - Created cloud proxy for client timraspbi/<hidden> via AMQP over WebSockets, with client operation timeout 20 seconds.
<6> 2021-02-24 16:44:05.033 +00:00 [INF] - Initialized cloud proxy 74e40816-21d5-4690-943c-9815f849fe71 for timraspbi/<hidden>
<6> 2021-02-24 16:44:05.038 +00:00 [INF] - Created cloud connection for client timraspbi/<hidden>
<6> 2021-02-24 16:44:05.375 +00:00 [INF] - Processing subscriptions TwinResponse, Methods, ModuleMessages, DesiredPropertyUpdates for client timraspbi/<hidden>.
<6> 2021-02-24 16:44:05.379 +00:00 [INF] - Processing pending subscriptions for timraspbi/<hidden>
<6> 2021-02-24 16:44:05.387 +00:00 [INF] - Set subscriptions from session state for timraspbi/<hidden>
<6> 2021-02-24 16:44:05.640 +00:00 [INF] - Processing subscriptions TwinResponse, Methods, ModuleMessages, DesiredPropertyUpdates for client timraspbi/<hidden>.
<6> 2021-02-24 16:44:05.661 +00:00 [INF] - Set subscriptions from session state for timraspbi/<hidden>
<6> 2021-02-24 16:44:05.664 +00:00 [INF] - Processing pending subscriptions for timraspbi/<hidden>
<6> 2021-02-24 16:44:05.819 +00:00 [INF] - Processing subscriptions TwinResponse, Methods, ModuleMessages, DesiredPropertyUpdates for client timraspbi/<hidden>.
<6> 2021-02-24 16:44:05.821 +00:00 [INF] - Processing pending subscriptions for timraspbi/<hidden>
<6> 2021-02-24 16:44:05.836 +00:00 [INF] - Set subscriptions from session state for timraspbi/<hidden>
<6> 2021-02-24 16:44:07.220 +00:00 [INF] - Request starting HTTP/1.1 GET https://raspi-tim-dev/$iothub/websocket
<6> 2021-02-24 16:44:07.517 +00:00 [INF] - Processed MQTT WebSocket request with CorrelationId 11ca6e5c-07a4-4949-a7f6-09a0041ba5f6
<6> 2021-02-24 16:44:08.615 +00:00 [INF] - Client timraspbi/<hidden> in device scope authenticated locally.
<6> 2021-02-24 16:44:08.625 +00:00 [INF] - Successfully generated identity for clientId timraspbi/<hidden> and username raspi-tim-dev/timraspbi/<hidden>/?api-version=2020-09-30&DeviceClientType=.NET%2F1.35.0%20%28.NET%205.0.3%3B%20Linux%205.4.83-v7%2B%20%231379%20SMP%20Mon%20Dec%2014%2013%3A08%3A57%20GMT%202020%3B%20Arm%29
<6> 2021-02-24 16:44:08.632 +00:00 [INF] - ClientAuthenticated, timraspbi/<hidden>, 78abd02f
<6> 2021-02-24 16:44:08.649 +00:00 [INF] - New device connection for device timraspbi/<hidden>
<6> 2021-02-24 16:44:08.657 +00:00 [INF] - Client timraspbi/<hidden> connected to edgeHub, processing existing subscriptions.
<6> 2021-02-24 16:44:08.668 +00:00 [INF] - Attempting to connect to IoT Hub for client timraspbi/<hidden> via AMQP over WebSockets...
<6> 2021-02-24 16:44:08.783 +00:00 [INF] - Bind device proxy for device timraspbi/<hidden>
<6> 2021-02-24 16:44:08.789 +00:00 [INF] - Binding message channel for device Id timraspbi/<hidden>
<6> 2021-02-24 16:44:08.856 +00:00 [INF] - Processing subscriptions TwinResponse, Methods, ModuleMessages, DesiredPropertyUpdates for client timraspbi/<hidden>.
<6> 2021-02-24 16:44:08.863 +00:00 [INF] - Processing pending subscriptions for timraspbi/<hidden>
<6> 2021-02-24 16:44:09.202 +00:00 [INF] - Cloud connection for timraspbi/<hidden> is True
<6> 2021-02-24 16:44:09.204 +00:00 [INF] - Connection status for timraspbi/<hidden> changed to ConnectionEstablished
<6> 2021-02-24 16:44:09.206 +00:00 [INF] - Client timraspbi/<hidden> connected to cloud, processing existing subscriptions.
<6> 2021-02-24 16:44:09.207 +00:00 [INF] - Skipping timraspbi/<hidden> for subscription processing, as it is currently being processed.
<6> 2021-02-24 16:44:09.217 +00:00 [INF] - Created cloud proxy for client timraspbi/<hidden> via AMQP over WebSockets, with client operation timeout 20 seconds.
<6> 2021-02-24 16:44:09.219 +00:00 [INF] - Initialized cloud proxy 09ef9ab5-08a4-49be-817e-45864a7e1fff for timraspbi/<hidden>
<6> 2021-02-24 16:44:09.221 +00:00 [INF] - Created cloud connection for client timraspbi/<hidden>
<6> 2021-02-24 16:44:09.845 +00:00 [INF] - Client timraspbi/<hidden> in device scope authenticated locally.
<6> 2021-02-24 16:44:11.414 +00:00 [INF] - Client timraspbi/<hidden> in device scope authenticated locally.
<6> 2021-02-24 16:44:11.695 +00:00 [INF] - Updated reported properties for timraspbi/$edgeHub
<6> 2021-02-24 16:44:12.007 +00:00 [INF] - Set subscriptions from session state for timraspbi/<hidden>
<6> 2021-02-24 16:44:12.016 +00:00 [INF] - Successfully generated identity for clientId timraspbi/<hidden> and username raspi-tim-dev/timraspbi/<hidden>/?api-version=2020-09-30&DeviceClientType=.NET%2F1.35.0%20%28.NET%205.0.3%3B%20Linux%205.4.83-v7%2B%20%231379%20SMP%20Mon%20Dec%2014%2013%3A08%3A57%20GMT%202020%3B%20Arm%29
<6> 2021-02-24 16:44:12.017 +00:00 [INF] - ClientAuthenticated, timraspbi/<hidden>, 324fc823
<6> 2021-02-24 16:44:12.027 +00:00 [INF] - Successfully generated identity for clientId timraspbi/<hidden> and username raspi-tim-dev/timraspbi/<hidden>/?api-version=2020-09-30&DeviceClientType=.NET%2F1.35.0%20%28.NET%205.0.3%3B%20Linux%205.4.83-v7%2B%20%231379%20SMP%20Mon%20Dec%2014%2013%3A08%3A57%20GMT%202020%3B%20Arm%29
<6> 2021-02-24 16:44:12.030 +00:00 [INF] - ClientAuthenticated, timraspbi/<hidden>, 2e89e9ca
<6> 2021-02-24 16:44:12.030 +00:00 [INF] - New device connection for device timraspbi/<hidden>
<6> 2021-02-24 16:44:12.035 +00:00 [INF] - Client timraspbi/<hidden> connected to edgeHub, processing existing subscriptions.
<6> 2021-02-24 16:44:12.057 +00:00 [INF] - Attempting to connect to IoT Hub for client timraspbi/<hidden> via AMQP over WebSockets...
<6> 2021-02-24 16:44:12.112 +00:00 [INF] - Bind device proxy for device timraspbi/<hidden>
<6> 2021-02-24 16:44:12.113 +00:00 [INF] - Binding message channel for device Id timraspbi/<hidden>
<6> 2021-02-24 16:44:12.185 +00:00 [INF] - New device connection for device timraspbi/<hidden>
<6> 2021-02-24 16:44:12.186 +00:00 [INF] - Client timraspbi/<hidden> connected to edgeHub, processing existing subscriptions.
<6> 2021-02-24 16:44:12.190 +00:00 [INF] - Attempting to connect to IoT Hub for client timraspbi/<hidden> via AMQP over WebSockets...
<6> 2021-02-24 16:44:12.203 +00:00 [INF] - Bind device proxy for device timraspbi/<hidden>
<6> 2021-02-24 16:44:12.203 +00:00 [INF] - Binding message channel for device Id timraspbi/<hidden>
<6> 2021-02-24 16:44:12.251 +00:00 [INF] - Processing subscriptions TwinResponse, Methods, DesiredPropertyUpdates for client timraspbi/<hidden>.
<6> 2021-02-24 16:44:12.253 +00:00 [INF] - Processing pending subscriptions for timraspbi/<hidden>
<6> 2021-02-24 16:44:12.275 +00:00 [INF] - Set subscriptions from session state for timraspbi/<hidden>
<6> 2021-02-24 16:44:12.409 +00:00 [INF] - Processing subscriptions TwinResponse, Methods, ModuleMessages, DesiredPropertyUpdates for client timraspbi/<hidden>.
<6> 2021-02-24 16:44:12.421 +00:00 [INF] - Set subscriptions from session state for timraspbi/<hidden>
<6> 2021-02-24 16:44:12.603 +00:00 [INF] - Cloud connection for timraspbi/<hidden> is True
<6> 2021-02-24 16:44:12.604 +00:00 [INF] - Connection status for timraspbi/<hidden> changed to ConnectionEstablished
<6> 2021-02-24 16:44:12.604 +00:00 [INF] - Client timraspbi/<hidden> connected to cloud, processing existing subscriptions.
<6> 2021-02-24 16:44:12.604 +00:00 [INF] - Skipping timraspbi/<hidden> for subscription processing, as it is currently being processed.
<6> 2021-02-24 16:44:12.605 +00:00 [INF] - Created cloud proxy for client timraspbi/<hidden> via AMQP over WebSockets, with client operation timeout 20 seconds.
<6> 2021-02-24 16:44:12.606 +00:00 [INF] - Initialized cloud proxy e054a286-4201-4e14-a4e4-ac9182cafb55 for timraspbi/<hidden>
<6> 2021-02-24 16:44:12.617 +00:00 [INF] - Created cloud connection for client timraspbi/<hidden>
<6> 2021-02-24 16:44:12.674 +00:00 [INF] - Processing subscriptions TwinResponse, Methods, ModuleMessages, DesiredPropertyUpdates for client timraspbi/<hidden>.
<6> 2021-02-24 16:44:12.678 +00:00 [INF] - Set subscriptions from session state for timraspbi/<hidden>
<6> 2021-02-24 16:44:12.772 +00:00 [INF] - Processing subscriptions TwinResponse, Methods, DesiredPropertyUpdates for client timraspbi/<hidden>.
<6> 2021-02-24 16:44:12.778 +00:00 [INF] - Set subscriptions from session state for timraspbi/<hidden>
<6> 2021-02-24 16:44:12.789 +00:00 [INF] - Processing subscriptions TwinResponse, Methods, DesiredPropertyUpdates for client timraspbi/<hidden>.
<6> 2021-02-24 16:44:12.794 +00:00 [INF] - Set subscriptions from session state for timraspbi/<hidden>
<6> 2021-02-24 16:44:12.832 +00:00 [INF] - Processing pending subscriptions for timraspbi/<hidden>
<6> 2021-02-24 16:44:12.835 +00:00 [INF] - Processing pending subscriptions for timraspbi/<hidden>
<6> 2021-02-24 16:44:12.835 +00:00 [INF] - Processing pending subscriptions for timraspbi/<hidden>
<6> 2021-02-24 16:44:12.860 +00:00 [INF] - Cloud connection for timraspbi/<hidden> is True
<6> 2021-02-24 16:44:12.861 +00:00 [INF] - Connection status for timraspbi/<hidden> changed to ConnectionEstablished
<6> 2021-02-24 16:44:12.861 +00:00 [INF] - Client timraspbi/<hidden> connected to cloud, processing existing subscriptions.
<6> 2021-02-24 16:44:12.861 +00:00 [INF] - Skipping timraspbi/<hidden> for subscription processing, as it is currently being processed.
<6> 2021-02-24 16:44:12.862 +00:00 [INF] - Created cloud proxy for client timraspbi/<hidden> via AMQP over WebSockets, with client operation timeout 20 seconds.
<6> 2021-02-24 16:44:12.862 +00:00 [INF] - Initialized cloud proxy ff48f8ec-5d6f-492c-82fa-663eaefef077 for timraspbi/<hidden>
<6> 2021-02-24 16:44:12.862 +00:00 [INF] - Created cloud connection for client timraspbi/<hidden>
<6> 2021-02-24 16:44:12.901 +00:00 [INF] - Processing subscriptions TwinResponse, Methods, ModuleMessages, DesiredPropertyUpdates for client timraspbi/<hidden>.
<6> 2021-02-24 16:44:12.905 +00:00 [INF] - Set subscriptions from session state for timraspbi/<hidden>
<6> 2021-02-24 16:44:13.046 +00:00 [INF] - Processing subscriptions TwinResponse, Methods, DesiredPropertyUpdates for client timraspbi/<hidden>.
<6> 2021-02-24 16:44:13.058 +00:00 [INF] - Set subscriptions from session state for timraspbi/<hidden>
<6> 2021-02-24 16:44:13.151 +00:00 [INF] - Processing subscriptions TwinResponse, Methods, DesiredPropertyUpdates for client timraspbi/<hidden>.
<6> 2021-02-24 16:44:13.168 +00:00 [INF] - Set subscriptions from session state for timraspbi/<hidden>
<6> 2021-02-24 16:44:13.193 +00:00 [INF] - Processing pending subscriptions for timraspbi/<hidden>
<6> 2021-02-24 16:44:13.195 +00:00 [INF] - Processing pending subscriptions for timraspbi/<hidden>
<6> 2021-02-24 16:44:13.196 +00:00 [INF] - Processing pending subscriptions for timraspbi/<hidden>
<6> 2021-02-24 16:44:13.205 +00:00 [INF] - Processing pending subscriptions for timraspbi/<hidden>
<6> 2021-02-24 16:44:13.411 +00:00 [INF] - Processing subscriptions TwinResponse, Methods, DesiredPropertyUpdates for client timraspbi/<hidden>.
<6> 2021-02-24 16:44:13.418 +00:00 [INF] - Processing pending subscriptions for timraspbi/<hidden>
<6> 2021-02-24 16:44:13.466 +00:00 [INF] - Set subscriptions from session state for timraspbi/<hidden>
<6> 2021-02-24 16:44:15.598 +00:00 [INF] - Request starting HTTP/1.1 POST https://raspi-tim-dev/twins/timraspbi/modules/<hidden>/methods?api-version=2020-09-30 application/json; charset=utf-8 97
<6> 2021-02-24 16:44:15.693 +00:00 [INF] - Client timraspbi/<hidden> in device scope authenticated locally.
<6> 2021-02-24 16:44:16.139 +00:00 [INF] - Executing endpoint '"Microsoft.Azure.Devices.Edge.Hub.Http.Controllers.TwinsController.InvokeModuleMethodAsync (Microsoft.Azure.Devices.Edge.Hub.Http)"'
<6> 2021-02-24 16:44:16.596 +00:00 [INF] - Route matched with "{action = \"InvokeModuleMethod\", controller = \"Twins\"}". Executing controller action with signature "System.Threading.Tasks.Task InvokeModuleMethodAsync(System.String, System.String, Microsoft.Azure.Devices.Edge.Hub.Http.MethodRequest)" on controller "Microsoft.Azure.Devices.Edge.Hub.Http.Controllers.TwinsController" ("Microsoft.Azure.Devices.Edge.Hub.Http").
<6> 2021-02-24 16:44:18.374 +00:00 [INF] - Executed action "Microsoft.Azure.Devices.Edge.Hub.Http.Controllers.TwinsController.InvokeModuleMethodAsync (Microsoft.Azure.Devices.Edge.Hub.Http)" in 1705.5073ms
<6> 2021-02-24 16:44:18.386 +00:00 [INF] - Executed endpoint '"Microsoft.Azure.Devices.Edge.Hub.Http.Controllers.TwinsController.InvokeModuleMethodAsync (Microsoft.Azure.Devices.Edge.Hub.Http)"'
<6> 2021-02-24 16:44:18.431 +00:00 [INF] - Updated reported properties for timraspbi/$edgeHub
<6> 2021-02-24 16:44:18.433 +00:00 [INF] - Request finished in 2831.705ms 200 application/json; charset=utf-8
<6> 2021-02-24 16:48:54.647 +00:00 [INF] - Entering periodic task to reauthenticate connected clients
<6> 2021-02-24 16:53:54.608 +00:00 [INF] - Entering periodic task to reauthenticate connected clients
<6> 2021-02-24 16:58:54.598 +00:00 [INF] - Entering periodic task to reauthenticate connected clients
<6> 2021-02-24 17:03:54.607 +00:00 [INF] - Entering periodic task to reauthenticate connected clients
<6> 2021-02-24 17:08:54.608 +00:00 [INF] - Entering periodic task to reauthenticate connected clients
<6> 2021-02-24 17:13:41.520 +00:00 [INF] - Started task to cleanup processed and stale messages for endpoint iothub
<6> 2021-02-24 17:13:41.551 +00:00 [INF] - Cleaned up 0 messages from queue for endpoint iothub and 0 messages from message store.
<6> 2021-02-24 17:13:54.608 +00:00 [INF] - Entering periodic task to reauthenticate connected clients
edge-agent inspect
[
{
"Id": "a2161b1b6f8ccc39726fe2e6c80c237611a8fedc839dc079102c53977a7705e1",
"Created": "2021-02-24T16:41:57.997505939Z",
"Path": "/bin/sh",
"Args": [
"-c",
"exec /app/agentStart.sh"
],
"State": {
"Status": "running",
"Running": true,
"Paused": false,
"Restarting": false,
"OOMKilled": false,
"Dead": false,
"Pid": 1746,
"ExitCode": 0,
"Error": "",
"StartedAt": "2021-02-24T16:42:01.331034389Z",
"FinishedAt": "0001-01-01T00:00:00Z"
},
"Image": "sha256:0aefd791e932430d8456909fccea5b46941fba54798dc5ae8cbf84d627687dc3",
"ResolvConfPath": "/var/lib/docker/containers/a2161b1b6f8ccc39726fe2e6c80c237611a8fedc839dc079102c53977a7705e1/resolv.conf",
"HostnamePath": "/var/lib/docker/containers/a2161b1b6f8ccc39726fe2e6c80c237611a8fedc839dc079102c53977a7705e1/hostname",
"HostsPath": "/var/lib/docker/containers/a2161b1b6f8ccc39726fe2e6c80c237611a8fedc839dc079102c53977a7705e1/hosts",
"LogPath": "/var/lib/docker/containers/a2161b1b6f8ccc39726fe2e6c80c237611a8fedc839dc079102c53977a7705e1/a2161b1b6f8ccc39726fe2e6c80c237611a8fedc839dc079102c53977a7705e1-json.log",
"Name": "/edgeAgent",
"RestartCount": 0,
"Driver": "overlay2",
"Platform": "linux",
"MountLabel": "",
"ProcessLabel": "",
"AppArmorProfile": "",
"ExecIDs": null,
"HostConfig": {
"Binds": [
"/home/iotedge/:/iotedge/storage/",
"/var/run/iotedge/workload.sock:/var/run/iotedge/workload.sock",
"/var/run/iotedge/mgmt.sock:/var/run/iotedge/mgmt.sock"
],
"ContainerIDFile": "",
"LogConfig": {
"Type": "json-file",
"Config": {
"max-file": "10",
"max-size": "5m"
}
},
"NetworkMode": "default",
"PortBindings": null,
"RestartPolicy": {
"Name": "",
"MaximumRetryCount": 0
},
"AutoRemove": false,
"VolumeDriver": "",
"VolumesFrom": null,
"CapAdd": null,
"CapDrop": null,
"Capabilities": null,
"Dns": null,
"DnsOptions": null,
"DnsSearch": null,
"ExtraHosts": null,
"GroupAdd": null,
"IpcMode": "private",
"Cgroup": "",
"Links": null,
"OomScoreAdj": 0,
"PidMode": "",
"Privileged": false,
"PublishAllPorts": false,
"ReadonlyRootfs": false,
"SecurityOpt": null,
"UTSMode": "",
"UsernsMode": "",
"ShmSize": 67108864,
"Runtime": "runc",
"ConsoleSize": [
0,
0
],
"Isolation": "",
"CpuShares": 0,
"Memory": 0,
"NanoCpus": 0,
"CgroupParent": "",
"BlkioWeight": 0,
"BlkioWeightDevice": null,
"BlkioDeviceReadBps": null,
"BlkioDeviceWriteBps": null,
"BlkioDeviceReadIOps": null,
"BlkioDeviceWriteIOps": null,
"CpuPeriod": 0,
"CpuQuota": 0,
"CpuRealtimePeriod": 0,
"CpuRealtimeRuntime": 0,
"CpusetCpus": "",
"CpusetMems": "",
"Devices": null,
"DeviceCgroupRules": null,
"DeviceRequests": null,
"KernelMemory": 0,
"KernelMemoryTCP": 0,
"MemoryReservation": 0,
"MemorySwap": 0,
"MemorySwappiness": null,
"OomKillDisable": null,
"PidsLimit": null,
"Ulimits": null,
"CpuCount": 0,
"CpuPercent": 0,
"IOMaximumIOps": 0,
"IOMaximumBandwidth": 0,
"MaskedPaths": [
"/proc/asound",
"/proc/acpi",
"/proc/kcore",
"/proc/keys",
"/proc/latency_stats",
"/proc/timer_list",
"/proc/timer_stats",
"/proc/sched_debug",
"/proc/scsi",
"/sys/firmware"
],
"ReadonlyPaths": [
"/proc/bus",
"/proc/fs",
"/proc/irq",
"/proc/sys",
"/proc/sysrq-trigger"
]
},
"GraphDriver": {
"Data": {
"LowerDir": "/var/lib/docker/overlay2/868227ee8a9ff7656bd5b8b7b6b0dbce862c4f7ef5c0ec13047bc8692a0f16f4-init/diff:/var/lib/docker/overlay2/d3fa7fc7b326dccbbb34f012d959be398b60296ba8d9366c210898f37dea93bf/diff:/var/lib/docker/overlay2/beb4613d97517afb7f795f4fc55c86f06e5a63ec35b3b192e5475d3751a7f6a3/diff:/var/lib/docker/overlay2/3c2d480f14d22e1b70229be6c9e8c6645f560422f3f96e0b82fdda56e7c70633/diff:/var/lib/docker/overlay2/a7f3a71e495bcaabde3bec5cbcdc3829dfe43d372b9cbad5fdb1fe1d19909d7d/diff:/var/lib/docker/overlay2/8e83ea88cbac99fbcce25cb156c7deec3a2869d468bfab6b3925a3b230ddbc41/diff:/var/lib/docker/overlay2/9f9b78ebcd04419e210dbc2680eff1ed516b0888e7d1ee55389d2073c1b67322/diff:/var/lib/docker/overlay2/df92efec62abeb473a05528f55366a8f055faf0b24835fbe0d5a16e63ded4213/diff:/var/lib/docker/overlay2/c06226f9032d9027811fbea4f59dbf69e631c042a9c1d0ac64cb1aa0c1154d18/diff:/var/lib/docker/overlay2/b1ce6d98da10d35cc0680a5add5d32c48a76c0fc738fe0c25c071579c1acbfc5/diff:/var/lib/docker/overlay2/ed6cf11961d9c252921d91ce33fdaab139a147ca7205e9f72ff0957a2dfce23c/diff:/var/lib/docker/overlay2/05186ca79b15e8edeb2a648051d31e10e01ba5d9a0654cee3193b7e1cb2ccd6b/diff:/var/lib/docker/overlay2/44a0aa305115008817960f3ad02036048cd811f37f65627cf9cc865b6e114480/diff",
"MergedDir": "/var/lib/docker/overlay2/868227ee8a9ff7656bd5b8b7b6b0dbce862c4f7ef5c0ec13047bc8692a0f16f4/merged",
"UpperDir": "/var/lib/docker/overlay2/868227ee8a9ff7656bd5b8b7b6b0dbce862c4f7ef5c0ec13047bc8692a0f16f4/diff",
"WorkDir": "/var/lib/docker/overlay2/868227ee8a9ff7656bd5b8b7b6b0dbce862c4f7ef5c0ec13047bc8692a0f16f4/work"
},
"Name": "overlay2"
},
"Mounts": [
{
"Type": "bind",
"Source": "/var/run/iotedge/workload.sock",
"Destination": "/var/run/iotedge/workload.sock",
"Mode": "",
"RW": true,
"Propagation": "rprivate"
},
{
"Type": "bind",
"Source": "/var/run/iotedge/mgmt.sock",
"Destination": "/var/run/iotedge/mgmt.sock",
"Mode": "",
"RW": true,
"Propagation": "rprivate"
},
{
"Type": "bind",
"Source": "/home/iotedge",
"Destination": "/iotedge/storage",
"Mode": "",
"RW": true,
"Propagation": "rprivate"
}
],
"Config": {
"Hostname": "a2161b1b6f8c",
"Domainname": "",
"User": "",
"AttachStdin": false,
"AttachStdout": false,
"AttachStderr": false,
"Tty": false,
"OpenStdin": false,
"StdinOnce": false,
"Env": [
"EdgeDeviceHostName=raspi-tim-dev",
"IOTEDGE_APIVERSION=2020-07-07",
"IOTEDGE_AUTHSCHEME=sasToken",
"IOTEDGE_DEVICEID=timraspbi",
"IOTEDGE_IOTHUBHOSTNAME=<hidden>",
"IOTEDGE_MANAGEMENTURI=unix:///var/run/iotedge/mgmt.sock",
"IOTEDGE_MODULEGENERATIONID=637495038003668923",
"IOTEDGE_MODULEID=$edgeAgent",
"IOTEDGE_WORKLOADURI=unix:///var/run/iotedge/workload.sock",
"Mode=iotedged",
"NetworkId=azure-iot-edge",
"RuntimeLogLevel=Information",
"UpstreamProtocol=AMQPWS",
"storageFolder=/iotedge/storage/",
"PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin",
"ASPNETCORE_URLS=http://+:80",
"DOTNET_RUNNING_IN_CONTAINER=true",
"EDGEAGENTUSER_ID=1000"
],
"Cmd": [
"/bin/sh",
"-c",
"exec /app/agentStart.sh"
],
"Image": "mcr.microsoft.com/azureiotedge-agent:1.1",
"Volumes": null,
"WorkingDir": "/app",
"Entrypoint": null,
"OnBuild": null,
"Labels": {
"net.azure-devices.edge.create-options": "{\"HostConfig\":{\"Binds\":[\"/home/iotedge/:/iotedge/storage/\"],\"LogConfig\":{\"Config\":{\"max-size\":\"5m\",\"max-file\":\"10\"},\"Type\":\"json-file\"}}}",
"net.azure-devices.edge.env": "{\"storageFolder\":{\"value\":\"/iotedge/storage/\"},\"UpstreamProtocol\":{\"value\":\"AMQPWS\"}}",
"net.azure-devices.edge.owner": "Microsoft.Azure.Devices.Edge.Agent"
}
},
"NetworkSettings": {
"Bridge": "",
"SandboxID": "d939ada04ee7fbd9ecb0718aa663e3ef5fb35a7e68c3d971e01636ecb20770fa",
"HairpinMode": false,
"LinkLocalIPv6Address": "",
"LinkLocalIPv6PrefixLen": 0,
"Ports": {},
"SandboxKey": "/var/run/docker/netns/d939ada04ee7",
"SecondaryIPAddresses": null,
"SecondaryIPv6Addresses": null,
"EndpointID": "",
"Gateway": "",
"GlobalIPv6Address": "",
"GlobalIPv6PrefixLen": 0,
"IPAddress": "",
"IPPrefixLen": 0,
"IPv6Gateway": "",
"MacAddress": "",
"Networks": {
"azure-iot-edge": {
"IPAMConfig": null,
"Links": null,
"Aliases": [
"a2161b1b6f8c"
],
"NetworkID": "df24830a26d0f05926446e8b91ce96c7f64efb2dff8dff05c09279807d899aa1",
"EndpointID": "988d5bba0265d2ecf0514b52081e2de5c693f022e2640d2df758562203d305a2",
"Gateway": "172.18.0.1",
"IPAddress": "172.18.0.2",
"IPPrefixLen": 16,
"IPv6Gateway": "",
"GlobalIPv6Address": "",
"GlobalIPv6PrefixLen": 0,
"MacAddress": "02:42:ac:12:00:02",
"DriverOpts": null
}
}
}
}
]
edgeHub inspect
[
{
"Id": "411ed362a429d57ac51d7e5994ba3ad7e279b55625c7a55dd2d3bdeb9e62668d",
"Created": "2021-02-24T16:43:00.363032706Z",
"Path": "/bin/sh",
"Args": [
"-c",
"echo \"$(date --utc +\"%Y-%m-%d %H:%M:%S %:z\") Starting Edge Hub\" && exec /usr/bin/dotnet Microsoft.Azure.Devices.Edge.Hub.Service.dll"
],
"State": {
"Status": "running",
"Running": true,
"Paused": false,
"Restarting": false,
"OOMKilled": false,
"Dead": false,
"Pid": 2410,
"ExitCode": 0,
"Error": "",
"StartedAt": "2021-02-24T16:43:15.514604071Z",
"FinishedAt": "0001-01-01T00:00:00Z"
},
"Image": "sha256:62e2ab36d89f30a99e885501fe7686387816acdf1a28341a9e428a689e2a608f",
"ResolvConfPath": "/var/lib/docker/containers/411ed362a429d57ac51d7e5994ba3ad7e279b55625c7a55dd2d3bdeb9e62668d/resolv.conf",
"HostnamePath": "/var/lib/docker/containers/411ed362a429d57ac51d7e5994ba3ad7e279b55625c7a55dd2d3bdeb9e62668d/hostname",
"HostsPath": "/var/lib/docker/containers/411ed362a429d57ac51d7e5994ba3ad7e279b55625c7a55dd2d3bdeb9e62668d/hosts",
"LogPath": "/var/lib/docker/containers/411ed362a429d57ac51d7e5994ba3ad7e279b55625c7a55dd2d3bdeb9e62668d/411ed362a429d57ac51d7e5994ba3ad7e279b55625c7a55dd2d3bdeb9e62668d-json.log",
"Name": "/edgeHub",
"RestartCount": 0,
"Driver": "overlay2",
"Platform": "linux",
"MountLabel": "",
"ProcessLabel": "",
"AppArmorProfile": "",
"ExecIDs": null,
"HostConfig": {
"Binds": [
"/home/iotedge/:/iotedge/storage/",
"/var/run/iotedge/workload.sock:/var/run/iotedge/workload.sock"
],
"ContainerIDFile": "",
"LogConfig": {
"Type": "json-file",
"Config": {
"max-file": "10",
"max-size": "5m"
}
},
"NetworkMode": "default",
"PortBindings": {
"443/tcp": [
{
"HostIp": "",
"HostPort": "443"
}
],
"5671/tcp": [
{
"HostIp": "",
"HostPort": "5671"
}
],
"8883/tcp": [
{
"HostIp": "",
"HostPort": "8883"
}
]
},
"RestartPolicy": {
"Name": "",
"MaximumRetryCount": 0
},
"AutoRemove": false,
"VolumeDriver": "",
"VolumesFrom": null,
"CapAdd": null,
"CapDrop": null,
"Capabilities": null,
"Dns": null,
"DnsOptions": null,
"DnsSearch": null,
"ExtraHosts": null,
"GroupAdd": null,
"IpcMode": "private",
"Cgroup": "",
"Links": null,
"OomScoreAdj": 0,
"PidMode": "",
"Privileged": false,
"PublishAllPorts": false,
"ReadonlyRootfs": false,
"SecurityOpt": null,
"UTSMode": "",
"UsernsMode": "",
"ShmSize": 67108864,
"Runtime": "runc",
"ConsoleSize": [
0,
0
],
"Isolation": "",
"CpuShares": 0,
"Memory": 0,
"NanoCpus": 0,
"CgroupParent": "",
"BlkioWeight": 0,
"BlkioWeightDevice": null,
"BlkioDeviceReadBps": null,
"BlkioDeviceWriteBps": null,
"BlkioDeviceReadIOps": null,
"BlkioDeviceWriteIOps": null,
"CpuPeriod": 0,
"CpuQuota": 0,
"CpuRealtimePeriod": 0,
"CpuRealtimeRuntime": 0,
"CpusetCpus": "",
"CpusetMems": "",
"Devices": null,
"DeviceCgroupRules": null,
"DeviceRequests": null,
"KernelMemory": 0,
"KernelMemoryTCP": 0,
"MemoryReservation": 0,
"MemorySwap": 0,
"MemorySwappiness": null,
"OomKillDisable": null,
"PidsLimit": null,
"Ulimits": null,
"CpuCount": 0,
"CpuPercent": 0,
"IOMaximumIOps": 0,
"IOMaximumBandwidth": 0,
"MaskedPaths": [
"/proc/asound",
"/proc/acpi",
"/proc/kcore",
"/proc/keys",
"/proc/latency_stats",
"/proc/timer_list",
"/proc/timer_stats",
"/proc/sched_debug",
"/proc/scsi",
"/sys/firmware"
],
"ReadonlyPaths": [
"/proc/bus",
"/proc/fs",
"/proc/irq",
"/proc/sys",
"/proc/sysrq-trigger"
]
},
"GraphDriver": {
"Data": {
"LowerDir": "/var/lib/docker/overlay2/01207d5aaf769cfbab306b29839689bb8af131f912a41241b4a6cadfb02a8197-init/diff:/var/lib/docker/overlay2/1880ec008a069fbee806304a8467f526f7f23ca177afc62906d8cc9b1c366905/diff:/var/lib/docker/overlay2/a5962579f5378ce6150b73cb1b1d9957c4ed14d3606c56c1f78f56d3f5c71a6f/diff:/var/lib/docker/overlay2/e7ccf26b2a2375eb02ecc5dccc4a220a56a79a7249bf8756d9b14cae7b0f4e64/diff:/var/lib/docker/overlay2/28d923eca42e20cc0c4644d9a22654bd3f111779177d7d45dc04b20d27d2d814/diff:/var/lib/docker/overlay2/b92e635344f8ec01c9522587929ea25dd05c9ffb9c2239d97d3e1987b773d010/diff:/var/lib/docker/overlay2/5103ef8338e08e843ce9b790638f64d166b6803586ebfbefc3aee0df3a9a4793/diff:/var/lib/docker/overlay2/9f9b78ebcd04419e210dbc2680eff1ed516b0888e7d1ee55389d2073c1b67322/diff:/var/lib/docker/overlay2/df92efec62abeb473a05528f55366a8f055faf0b24835fbe0d5a16e63ded4213/diff:/var/lib/docker/overlay2/c06226f9032d9027811fbea4f59dbf69e631c042a9c1d0ac64cb1aa0c1154d18/diff:/var/lib/docker/overlay2/b1ce6d98da10d35cc0680a5add5d32c48a76c0fc738fe0c25c071579c1acbfc5/diff:/var/lib/docker/overlay2/ed6cf11961d9c252921d91ce33fdaab139a147ca7205e9f72ff0957a2dfce23c/diff:/var/lib/docker/overlay2/05186ca79b15e8edeb2a648051d31e10e01ba5d9a0654cee3193b7e1cb2ccd6b/diff:/var/lib/docker/overlay2/44a0aa305115008817960f3ad02036048cd811f37f65627cf9cc865b6e114480/diff",
"MergedDir": "/var/lib/docker/overlay2/01207d5aaf769cfbab306b29839689bb8af131f912a41241b4a6cadfb02a8197/merged",
"UpperDir": "/var/lib/docker/overlay2/01207d5aaf769cfbab306b29839689bb8af131f912a41241b4a6cadfb02a8197/diff",
"WorkDir": "/var/lib/docker/overlay2/01207d5aaf769cfbab306b29839689bb8af131f912a41241b4a6cadfb02a8197/work"
},
"Name": "overlay2"
},
"Mounts": [
{
"Type": "bind",
"Source": "/home/iotedge",
"Destination": "/iotedge/storage",
"Mode": "",
"RW": true,
"Propagation": "rprivate"
},
{
"Type": "bind",
"Source": "/var/run/iotedge/workload.sock",
"Destination": "/var/run/iotedge/workload.sock",
"Mode": "",
"RW": true,
"Propagation": "rprivate"
}
],
"Config": {
"Hostname": "411ed362a429",
"Domainname": "",
"User": "edgehubuser",
"AttachStdin": false,
"AttachStdout": false,
"AttachStderr": false,
"ExposedPorts": {
"443/tcp": {},
"5671/tcp": {},
"8883/tcp": {}
},
"Tty": false,
"OpenStdin": false,
"StdinOnce": false,
"Env": [
"EdgeDeviceHostName=raspi-tim-dev",
"IOTEDGE_APIVERSION=2019-01-30",
"IOTEDGE_AUTHSCHEME=sasToken",
"IOTEDGE_DEVICEID=timraspbi",
"IOTEDGE_IOTHUBHOSTNAME=<hidden>",
"IOTEDGE_MODULEGENERATIONID=637495038003668923",
"IOTEDGE_MODULEID=$edgeHub",
"IOTEDGE_WORKLOADURI=unix:///var/run/iotedge/workload.sock",
"OptimizeForPerformance=false",
"RuntimeLogLevel=Information",
"UpstreamProtocol=AMQPWS",
"storageFolder=/iotedge/storage/",
"PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin",
"ASPNETCORE_URLS=http://+:80",
"DOTNET_RUNNING_IN_CONTAINER=true",
"EdgeHubUser=edgehubuser",
"MqttEventsProcessorThreadCount=1"
],
"Cmd": [
"/bin/sh",
"-c",
"echo \"$(date --utc +\"%Y-%m-%d %H:%M:%S %:z\") Starting Edge Hub\" && exec /usr/bin/dotnet Microsoft.Azure.Devices.Edge.Hub.Service.dll"
],
"Image": "mcr.microsoft.com/azureiotedge-hub:1.1",
"Volumes": null,
"WorkingDir": "/app",
"Entrypoint": null,
"OnBuild": null,
"Labels": {
"net.azure-devices.edge.owner": "Microsoft.Azure.Devices.Edge.Agent"
}
},
"NetworkSettings": {
"Bridge": "",
"SandboxID": "4ae3151b6ae69339a69b2001ae9a345c8a9dd7608e8e842eb7f28d4c6c5df41d",
"HairpinMode": false,
"LinkLocalIPv6Address": "",
"LinkLocalIPv6PrefixLen": 0,
"Ports": {
"443/tcp": [
{
"HostIp": "0.0.0.0",
"HostPort": "443"
}
],
"5671/tcp": [
{
"HostIp": "0.0.0.0",
"HostPort": "5671"
}
],
"8883/tcp": [
{
"HostIp": "0.0.0.0",
"HostPort": "8883"
}
]
},
"SandboxKey": "/var/run/docker/netns/4ae3151b6ae6",
"SecondaryIPAddresses": null,
"SecondaryIPv6Addresses": null,
"EndpointID": "",
"Gateway": "",
"GlobalIPv6Address": "",
"GlobalIPv6PrefixLen": 0,
"IPAddress": "",
"IPPrefixLen": 0,
"IPv6Gateway": "",
"MacAddress": "",
"Networks": {
"azure-iot-edge": {
"IPAMConfig": null,
"Links": null,
"Aliases": [
"raspi-tim-dev",
"411ed362a429"
],
"NetworkID": "df24830a26d0f05926446e8b91ce96c7f64efb2dff8dff05c09279807d899aa1",
"EndpointID": "469611ddfb91a1a2f2ac799bb470ce1cd1ec4b1560d27938c8a24344bdbeeda5",
"Gateway": "172.18.0.1",
"IPAddress": "172.18.0.4",
"IPPrefixLen": 16,
"IPv6Gateway": "",
"GlobalIPv6Address": "",
"GlobalIPv6PrefixLen": 0,
"MacAddress": "02:42:ac:12:00:04",
"DriverOpts": null
}
}
}
}
]
Additional Information
Generating a support bundle using command sudo iotedge support-bundle --since 1h works but creating it using the direct method call is not working.
About this issue
- Original URL
- State: closed
- Created 3 years ago
- Reactions: 1
- Comments: 20 (11 by maintainers)
@damonbarry While that might be true for a Raspberry Pi we do have two industrial edge devices by different vendors where the support bundle gets canceled because iot edge check takes longer behind a firewall. Even if there is a bit of load why cancel the support bundle after such a small amount of time. It’s already a background task and to be honest I don’t care if it takes 5 or 10 or 30 minutes as long as I get the bundle. Also for scenarios where the upload speed might be a bit slower could cause the bundle to cancel I guess. So why not make the cancel timeout configurable either with a property in the direct method call or in the iot edge configuration and let the user up the limit if needed? If you accept a pull request for that I’d be happy to give it a try.