Iotedge: EdgeAgent module is not able to authenticate during reprovisioning
Expected Behavior
Reprovisioning should happen and bring device back to valid state.
Current Behavior
Endless reattempts of reprovisioning.
Steps to Reproduce
- Delete and recreate IoTHub in the cloud
Context (Environment)
Output of iotedge check
I don't think this output is relaevant for this issue - I just added it for completeness. Please also note that the errors/wanings are all firewall related and do not indicate real problems. The really interessting logs are the ones of iotedged and the edgeAgent module included below.
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 - Error
Unable to find image 'mcr.microsoft.com/azureiotedge-diagnostics:1.1.0' locally
1.1.0: Pulling from azureiotedge-diagnostics
801bfaa63ef2: Already exists
5baca56f7803: Already exists
342030e49d46: Already exists
c8e13143a614: Pulling fs layer
8623f9f8d167: Pulling fs layer
c8e13143a614: Verifying Checksum
c8e13143a614: Download complete
8623f9f8d167: Verifying Checksum
8623f9f8d167: Download complete
c8e13143a614: Pull complete
8623f9f8d167: Pull complete
Digest: sha256:c37d16b515059c4065946fe7df77f6e6a3749e4cc21f0a2a8d13d67c17112990
Status: Downloaded newer image for mcr.microsoft.com/azureiotedge-diagnostics:1.1.0
One or more errors occurred. (Connection refused /var/lib/iotedge/mgmt.sock)
‼ latest security daemon - Warning
Error while fetching latest versions of edge components: could not send HTTP request
‼ host time is close to real time - Warning
Could not query NTP server
√ 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 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 - Error
Container on the default network could not connect to ioth-bhp-edge-qa.azure-devices.net:5671
× container on the default network can connect to IoT Hub HTTPS / WebSockets port - Error
Container on the default network could not connect to ioth-bhp-edge-qa.azure-devices.net:443
× container on the default network can connect to IoT Hub MQTT port - Error
Container on the default network could not connect to ioth-bhp-edge-qa.azure-devices.net:8883
× container on the IoT Edge module network can connect to IoT Hub AMQP port - Error
Container on the azure-iot-edge network could not connect to ioth-bhp-edge-qa.azure-devices.net:5671
× container on the IoT Edge module network can connect to IoT Hub HTTPS / WebSockets port - Error
Container on the azure-iot-edge network could not connect to ioth-bhp-edge-qa.azure-devices.net:443
× container on the IoT Edge module network can connect to IoT Hub MQTT port - Error
Container on the azure-iot-edge network could not connect to ioth-bhp-edge-qa.azure-devices.net:8883
15 check(s) succeeded.
2 check(s) raised warnings. Re-run with --verbose for more details.
7 check(s) raised errors. Re-run with --verbose for more details.
Device Information
- Host OS: RHEL 7.9
- Architecture: x86_64
- Container OS: Linux containers
Runtime Versions
- aziot-edged 1.1.0
- Edge Agent 1.1.0
- Edge Hub 1.1.0
- Docker version 19.03.15+azure
Logs
aziot-edged logs
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [INFO] - Finished provisioning edge device.
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [INFO] - Initializing the module runtime...
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [INFO] - Initializing module runtime...
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [INFO] - Using runtime network id azure-iot-edge
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [INFO] - Successfully initialized module runtime
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [INFO] - Finished initializing the module runtime.
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [INFO] - Stopping all modules...
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [INFO] - Stopping module spex-bridge-solace...
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [INFO] - Stopping module baseline-metrics...
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [INFO] - Stopping module curve-grabber-metrics...
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [INFO] - Stopping module edgeHub...
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [INFO] - Stopping module spex-bridge-redis...
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [INFO] - Stopping module spex-bridge-metrics...
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [INFO] - Stopping module spex-bridge-rabbitmq...
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [INFO] - Stopping module curve-grabber-watcher...
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [INFO] - Stopping module curve-grabber-solace...
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [INFO] - Stopping module edgeAgent...
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [WARN] - Could not stop module spex-bridge-solace
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [WARN] - Could not stop module baseline-metrics
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [WARN] - Could not stop module spex-bridge-metrics
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [WARN] - Could not stop module curve-grabber-metrics
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [WARN] - Could not stop module edgeHub
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [WARN] - Could not stop module spex-bridge-redis
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [WARN] - Could not stop module spex-bridge-rabbitmq
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [WARN] - Could not stop module curve-grabber-watcher
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [WARN] - Could not stop module curve-grabber-solace
Feb 22 11:45:45 bh0vm00005 iotedged[120456]: 2021-02-22T10:45:45Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:46:15 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:15Z [INFO] - Successfully stopped module edgeAgent
Feb 22 11:46:15 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:15Z [INFO] - Finished stopping modules.
Feb 22 11:46:15 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:15Z [INFO] - Detecting if configuration file has changed...
Feb 22 11:46:15 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:15Z [INFO] - No change to configuration file detected.
Feb 22 11:46:15 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:15Z [INFO] - Edge issuer CA expiration date: 2036-02-06T16:48:02Z
Feb 22 11:46:15 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:15Z [INFO] - Obtaining workload CA succeeded.
Feb 22 11:46:15 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:15Z [INFO] - Starting management API...
Feb 22 11:46:15 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:15Z [INFO] - Starting workload API...
Feb 22 11:46:15 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:15Z [INFO] - Starting watchdog with 60 second frequency...
Feb 22 11:46:15 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:15Z [INFO] - Listening on unix:///var/lib/iotedge/mgmt.sock with 1 thread for management API.
Feb 22 11:46:15 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:15Z [INFO] - Listening on unix:///var/lib/iotedge/workload.sock with 1 thread for workload API.
Feb 22 11:46:15 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:15Z [INFO] - Checking edge runtime status
Feb 22 11:46:15 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:15Z [INFO] - Edge runtime status is failed, starting module now...
Feb 22 11:46:15 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:15Z [INFO] - Starting module edgeAgent...
Feb 22 11:46:16 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:16Z [INFO] - Successfully started module edgeAgent
Feb 22 11:46:16 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:16Z [INFO] - [work] - - - [2021-02-22 10:46:16.674635140 UTC] "GET /trust-bundle?api-version=2019-01-30 HTTP/1.1" 200 OK 1994 "-" "-" auth_id(-)
Feb 22 11:46:17 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:17Z [INFO] - Querying system info...
Feb 22 11:46:17 bh0vm00005 iotedged[120456]: vmware
Feb 22 11:46:17 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:17Z [INFO] - Successfully queried system info
Feb 22 11:46:17 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:17Z [INFO] - [mgmt] - - - [2021-02-22 10:46:17.045697347 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:46:17 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:17Z [INFO] - Querying system info...
Feb 22 11:46:17 bh0vm00005 iotedged[120456]: vmware
Feb 22 11:46:17 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:17Z [INFO] - Successfully queried system info
Feb 22 11:46:17 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:17Z [INFO] - [mgmt] - - - [2021-02-22 10:46:17.515481556 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:46:17 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:17Z [INFO] - [work] - - - [2021-02-22 10:46:17.629246461 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/decrypt?api-version=2020-07-07 HTTP/1.1" 200 OK 6068 "-" "-" auth_id(-)
Feb 22 11:46:17 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:17Z [INFO] - [mgmt] - - - [2021-02-22 10:46:17.809644205 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 5839 "-" "-" auth_id(-)
Feb 22 11:46:18 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:18Z [INFO] - [work] - - - [2021-02-22 10:46:18.126355030 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/sign?api-version=2018-06-28 HTTP/1.1" 200 OK 57 "-" "-" auth_id(-)
Feb 22 11:46:18 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:18Z [INFO] - [mgmt] - - - [2021-02-22 10:46:18.357407595 UTC] "POST /device/reprovision?api-version=2020-07-07 HTTP/1.1" 200 OK - "-" "-" auth_id(-)
Feb 22 11:46:18 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:18Z [INFO] - Edge runtime will stop because of the device reprovisioning signal.
Feb 22 11:46:18 bh0vm00005 iotedged[120456]: 2021-02-22T10:46:18Z [ERR!] - The device has been de-provisioned
Feb 22 11:46:18 bh0vm00005 systemd[1]: iotedge.service: main process exited, code=exited, status=154/n/a
Feb 22 11:46:18 bh0vm00005 systemd[1]: Unit iotedge.service entered failed state.
Feb 22 11:46:18 bh0vm00005 systemd[1]: iotedge.service failed.
Feb 22 11:46:18 bh0vm00005 systemd[1]: iotedge.service holdoff time over, scheduling restart.
Feb 22 11:46:18 bh0vm00005 systemd[1]: Stopped Azure IoT Edge daemon.
Feb 22 11:46:18 bh0vm00005 systemd[1]: Started Azure IoT Edge daemon.
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Starting Azure IoT Edge Security Daemon
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Version - 1.1.0
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Using config file: /etc/iotedge/config.yaml
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Configuring /var/lib/iotedge as the home directory.
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Configuring certificates...
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Configuring the Device CA certificate using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA-full-chain.cert.pem".
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Configuring the Device private key using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA.key.pem".
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Configuring the trusted CA certificates using "/etc/iotedge/azure-iot.root.ca.cert.pem".
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Finished configuring provisioning environment variables and certificates.
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Initializing hsm...
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Finished initializing hsm.
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Initializing hsm X509 interface...
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Detected HTTPS proxy server http://rb-proxy-sl.bosch.com:8080/
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Finished initializing hsm X509 interface...
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Provisioning edge device...
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Starting provisioning edge device via manual mode using X509 identity certificate...
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Manually provisioning device "bh0vm00005" in hub "ioth-bhp-edge-qa.azure-devices.net"
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Finished provisioning edge device.
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Initializing the module runtime...
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Initializing module runtime...
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Using runtime network id azure-iot-edge
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Successfully initialized module runtime
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Finished initializing the module runtime.
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Stopping all modules...
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Stopping module spex-bridge-solace...
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Stopping module baseline-metrics...
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Stopping module curve-grabber-metrics...
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Stopping module edgeHub...
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Stopping module spex-bridge-redis...
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Stopping module spex-bridge-metrics...
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Stopping module spex-bridge-rabbitmq...
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Stopping module curve-grabber-watcher...
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Stopping module curve-grabber-solace...
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [INFO] - Stopping module edgeAgent...
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [WARN] - Could not stop module spex-bridge-solace
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [WARN] - Could not stop module baseline-metrics
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [WARN] - Could not stop module curve-grabber-metrics
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [WARN] - Could not stop module edgeHub
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [WARN] - Could not stop module spex-bridge-redis
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [WARN] - Could not stop module spex-bridge-metrics
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [WARN] - Could not stop module spex-bridge-rabbitmq
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [WARN] - Could not stop module curve-grabber-watcher
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [WARN] - Could not stop module curve-grabber-solace
Feb 22 11:46:18 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:18Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:46:48 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:48Z [INFO] - Successfully stopped module edgeAgent
Feb 22 11:46:48 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:48Z [INFO] - Finished stopping modules.
Feb 22 11:46:48 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:48Z [INFO] - Detecting if configuration file has changed...
Feb 22 11:46:48 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:48Z [INFO] - No change to configuration file detected.
Feb 22 11:46:48 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:48Z [INFO] - Edge issuer CA expiration date: 2036-02-06T16:48:02Z
Feb 22 11:46:48 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:48Z [INFO] - Obtaining workload CA succeeded.
Feb 22 11:46:48 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:48Z [INFO] - Starting management API...
Feb 22 11:46:48 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:48Z [INFO] - Starting workload API...
Feb 22 11:46:48 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:48Z [INFO] - Starting watchdog with 60 second frequency...
Feb 22 11:46:48 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:48Z [INFO] - Listening on unix:///var/lib/iotedge/mgmt.sock with 1 thread for management API.
Feb 22 11:46:48 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:48Z [INFO] - Listening on unix:///var/lib/iotedge/workload.sock with 1 thread for workload API.
Feb 22 11:46:48 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:48Z [INFO] - Checking edge runtime status
Feb 22 11:46:48 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:48Z [INFO] - Edge runtime status is failed, starting module now...
Feb 22 11:46:48 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:48Z [INFO] - Starting module edgeAgent...
Feb 22 11:46:49 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:49Z [INFO] - Successfully started module edgeAgent
Feb 22 11:46:49 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:49Z [INFO] - [work] - - - [2021-02-22 10:46:49.653114144 UTC] "GET /trust-bundle?api-version=2019-01-30 HTTP/1.1" 200 OK 1994 "-" "-" auth_id(-)
Feb 22 11:46:50 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:50Z [INFO] - Querying system info...
Feb 22 11:46:50 bh0vm00005 iotedged[120710]: vmware
Feb 22 11:46:50 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:50Z [INFO] - Successfully queried system info
Feb 22 11:46:50 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:50Z [INFO] - [mgmt] - - - [2021-02-22 10:46:50.033091063 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:46:50 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:50Z [INFO] - Querying system info...
Feb 22 11:46:50 bh0vm00005 iotedged[120710]: vmware
Feb 22 11:46:50 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:50Z [INFO] - Successfully queried system info
Feb 22 11:46:50 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:50Z [INFO] - [mgmt] - - - [2021-02-22 10:46:50.530842775 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:46:50 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:50Z [INFO] - [work] - - - [2021-02-22 10:46:50.638026088 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/decrypt?api-version=2020-07-07 HTTP/1.1" 200 OK 6068 "-" "-" auth_id(-)
Feb 22 11:46:50 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:50Z [INFO] - [mgmt] - - - [2021-02-22 10:46:50.818896307 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 5839 "-" "-" auth_id(-)
Feb 22 11:46:51 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:51Z [INFO] - [work] - - - [2021-02-22 10:46:51.153690842 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/sign?api-version=2018-06-28 HTTP/1.1" 200 OK 57 "-" "-" auth_id(-)
Feb 22 11:46:51 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:51Z [INFO] - [mgmt] - - - [2021-02-22 10:46:51.402597993 UTC] "POST /device/reprovision?api-version=2020-07-07 HTTP/1.1" 200 OK - "-" "-" auth_id(-)
Feb 22 11:46:51 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:51Z [INFO] - Edge runtime will stop because of the device reprovisioning signal.
Feb 22 11:46:51 bh0vm00005 iotedged[120710]: 2021-02-22T10:46:51Z [ERR!] - The device has been de-provisioned
Feb 22 11:46:51 bh0vm00005 systemd[1]: iotedge.service: main process exited, code=exited, status=154/n/a
Feb 22 11:46:51 bh0vm00005 systemd[1]: Unit iotedge.service entered failed state.
Feb 22 11:46:51 bh0vm00005 systemd[1]: iotedge.service failed.
Feb 22 11:46:51 bh0vm00005 systemd[1]: iotedge.service holdoff time over, scheduling restart.
Feb 22 11:46:51 bh0vm00005 systemd[1]: Stopped Azure IoT Edge daemon.
Feb 22 11:46:51 bh0vm00005 systemd[1]: Started Azure IoT Edge daemon.
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Starting Azure IoT Edge Security Daemon
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Version - 1.1.0
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Using config file: /etc/iotedge/config.yaml
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Configuring /var/lib/iotedge as the home directory.
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Configuring certificates...
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Configuring the Device CA certificate using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA-full-chain.cert.pem".
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Configuring the Device private key using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA.key.pem".
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Configuring the trusted CA certificates using "/etc/iotedge/azure-iot.root.ca.cert.pem".
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Finished configuring provisioning environment variables and certificates.
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Initializing hsm...
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Finished initializing hsm.
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Initializing hsm X509 interface...
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Detected HTTPS proxy server http://rb-proxy-sl.bosch.com:8080/
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Finished initializing hsm X509 interface...
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Provisioning edge device...
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Starting provisioning edge device via manual mode using X509 identity certificate...
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Manually provisioning device "bh0vm00005" in hub "ioth-bhp-edge-qa.azure-devices.net"
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Finished provisioning edge device.
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Initializing the module runtime...
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Initializing module runtime...
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Using runtime network id azure-iot-edge
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Successfully initialized module runtime
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Finished initializing the module runtime.
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Stopping all modules...
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Stopping module spex-bridge-solace...
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Stopping module baseline-metrics...
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Stopping module curve-grabber-metrics...
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Stopping module edgeHub...
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Stopping module spex-bridge-redis...
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Stopping module spex-bridge-metrics...
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Stopping module spex-bridge-rabbitmq...
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Stopping module curve-grabber-watcher...
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Stopping module curve-grabber-solace...
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [INFO] - Stopping module edgeAgent...
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [WARN] - Could not stop module spex-bridge-solace
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [WARN] - Could not stop module baseline-metrics
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [WARN] - Could not stop module curve-grabber-metrics
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [WARN] - Could not stop module edgeHub
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [WARN] - Could not stop module spex-bridge-redis
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [WARN] - Could not stop module spex-bridge-metrics
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [WARN] - Could not stop module spex-bridge-rabbitmq
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [WARN] - Could not stop module curve-grabber-watcher
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [WARN] - Could not stop module curve-grabber-solace
Feb 22 11:46:51 bh0vm00005 iotedged[120982]: 2021-02-22T10:46:51Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:47:21 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:21Z [INFO] - Successfully stopped module edgeAgent
Feb 22 11:47:21 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:21Z [INFO] - Finished stopping modules.
Feb 22 11:47:21 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:21Z [INFO] - Detecting if configuration file has changed...
Feb 22 11:47:21 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:21Z [INFO] - No change to configuration file detected.
Feb 22 11:47:21 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:21Z [INFO] - Edge issuer CA expiration date: 2036-02-06T16:48:02Z
Feb 22 11:47:21 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:21Z [INFO] - Obtaining workload CA succeeded.
Feb 22 11:47:21 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:21Z [INFO] - Starting management API...
Feb 22 11:47:21 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:21Z [INFO] - Starting workload API...
Feb 22 11:47:21 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:21Z [INFO] - Starting watchdog with 60 second frequency...
Feb 22 11:47:21 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:21Z [INFO] - Listening on unix:///var/lib/iotedge/mgmt.sock with 1 thread for management API.
Feb 22 11:47:21 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:21Z [INFO] - Listening on unix:///var/lib/iotedge/workload.sock with 1 thread for workload API.
Feb 22 11:47:21 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:21Z [INFO] - Checking edge runtime status
Feb 22 11:47:21 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:21Z [INFO] - Edge runtime status is failed, starting module now...
Feb 22 11:47:21 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:21Z [INFO] - Starting module edgeAgent...
Feb 22 11:47:22 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:22Z [INFO] - Successfully started module edgeAgent
Feb 22 11:47:22 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:22Z [INFO] - [work] - - - [2021-02-22 10:47:22.843362615 UTC] "GET /trust-bundle?api-version=2019-01-30 HTTP/1.1" 200 OK 1994 "-" "-" auth_id(-)
Feb 22 11:47:23 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:23Z [INFO] - Querying system info...
Feb 22 11:47:23 bh0vm00005 iotedged[120982]: vmware
Feb 22 11:47:23 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:23Z [INFO] - Successfully queried system info
Feb 22 11:47:23 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:23Z [INFO] - [mgmt] - - - [2021-02-22 10:47:23.220163577 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:47:23 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:23Z [INFO] - Querying system info...
Feb 22 11:47:23 bh0vm00005 iotedged[120982]: vmware
Feb 22 11:47:23 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:23Z [INFO] - Successfully queried system info
Feb 22 11:47:23 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:23Z [INFO] - [mgmt] - - - [2021-02-22 10:47:23.714285709 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:47:23 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:23Z [INFO] - [work] - - - [2021-02-22 10:47:23.856561884 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/decrypt?api-version=2020-07-07 HTTP/1.1" 200 OK 6068 "-" "-" auth_id(-)
Feb 22 11:47:24 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:24Z [INFO] - [mgmt] - - - [2021-02-22 10:47:24.043101616 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 5839 "-" "-" auth_id(-)
Feb 22 11:47:24 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:24Z [INFO] - [work] - - - [2021-02-22 10:47:24.361877146 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/sign?api-version=2018-06-28 HTTP/1.1" 200 OK 57 "-" "-" auth_id(-)
Feb 22 11:47:24 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:24Z [INFO] - [mgmt] - - - [2021-02-22 10:47:24.618103845 UTC] "POST /device/reprovision?api-version=2020-07-07 HTTP/1.1" 200 OK - "-" "-" auth_id(-)
Feb 22 11:47:24 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:24Z [INFO] - Edge runtime will stop because of the device reprovisioning signal.
Feb 22 11:47:24 bh0vm00005 iotedged[120982]: 2021-02-22T10:47:24Z [ERR!] - The device has been de-provisioned
Feb 22 11:47:24 bh0vm00005 systemd[1]: iotedge.service: main process exited, code=exited, status=154/n/a
Feb 22 11:47:24 bh0vm00005 systemd[1]: Unit iotedge.service entered failed state.
Feb 22 11:47:24 bh0vm00005 systemd[1]: iotedge.service failed.
Feb 22 11:47:24 bh0vm00005 systemd[1]: iotedge.service holdoff time over, scheduling restart.
Feb 22 11:47:24 bh0vm00005 systemd[1]: Stopped Azure IoT Edge daemon.
Feb 22 11:47:24 bh0vm00005 systemd[1]: Started Azure IoT Edge daemon.
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Starting Azure IoT Edge Security Daemon
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Version - 1.1.0
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Using config file: /etc/iotedge/config.yaml
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Configuring /var/lib/iotedge as the home directory.
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Configuring certificates...
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Configuring the Device CA certificate using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA-full-chain.cert.pem".
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Configuring the Device private key using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA.key.pem".
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Configuring the trusted CA certificates using "/etc/iotedge/azure-iot.root.ca.cert.pem".
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Finished configuring provisioning environment variables and certificates.
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Initializing hsm...
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Finished initializing hsm.
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Initializing hsm X509 interface...
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Detected HTTPS proxy server http://rb-proxy-sl.bosch.com:8080/
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Finished initializing hsm X509 interface...
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Provisioning edge device...
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Starting provisioning edge device via manual mode using X509 identity certificate...
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Manually provisioning device "bh0vm00005" in hub "ioth-bhp-edge-qa.azure-devices.net"
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Finished provisioning edge device.
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Initializing the module runtime...
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Initializing module runtime...
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Using runtime network id azure-iot-edge
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Successfully initialized module runtime
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Finished initializing the module runtime.
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Stopping all modules...
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Stopping module spex-bridge-solace...
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Stopping module baseline-metrics...
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Stopping module curve-grabber-metrics...
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Stopping module edgeHub...
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Stopping module spex-bridge-redis...
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Stopping module spex-bridge-metrics...
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Stopping module spex-bridge-rabbitmq...
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Stopping module curve-grabber-watcher...
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Stopping module curve-grabber-solace...
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [INFO] - Stopping module edgeAgent...
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [WARN] - Could not stop module spex-bridge-solace
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [WARN] - Could not stop module spex-bridge-redis
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [WARN] - Could not stop module edgeHub
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [WARN] - Could not stop module baseline-metrics
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [WARN] - Could not stop module curve-grabber-metrics
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [WARN] - Could not stop module curve-grabber-solace
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [WARN] - Could not stop module spex-bridge-rabbitmq
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [WARN] - Could not stop module curve-grabber-watcher
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [WARN] - Could not stop module spex-bridge-metrics
Feb 22 11:47:24 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:24Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:47:55 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:55Z [INFO] - Successfully stopped module edgeAgent
Feb 22 11:47:55 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:55Z [INFO] - Finished stopping modules.
Feb 22 11:47:55 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:55Z [INFO] - Detecting if configuration file has changed...
Feb 22 11:47:55 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:55Z [INFO] - No change to configuration file detected.
Feb 22 11:47:55 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:55Z [INFO] - Edge issuer CA expiration date: 2036-02-06T16:48:02Z
Feb 22 11:47:55 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:55Z [INFO] - Obtaining workload CA succeeded.
Feb 22 11:47:55 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:55Z [INFO] - Starting management API...
Feb 22 11:47:55 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:55Z [INFO] - Starting workload API...
Feb 22 11:47:55 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:55Z [INFO] - Starting watchdog with 60 second frequency...
Feb 22 11:47:55 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:55Z [INFO] - Listening on unix:///var/lib/iotedge/mgmt.sock with 1 thread for management API.
Feb 22 11:47:55 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:55Z [INFO] - Listening on unix:///var/lib/iotedge/workload.sock with 1 thread for workload API.
Feb 22 11:47:55 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:55Z [INFO] - Checking edge runtime status
Feb 22 11:47:55 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:55Z [INFO] - Edge runtime status is failed, starting module now...
Feb 22 11:47:55 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:55Z [INFO] - Starting module edgeAgent...
Feb 22 11:47:55 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:55Z [INFO] - Successfully started module edgeAgent
Feb 22 11:47:55 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:55Z [INFO] - [work] - - - [2021-02-22 10:47:55.960949646 UTC] "GET /trust-bundle?api-version=2019-01-30 HTTP/1.1" 200 OK 1994 "-" "-" auth_id(-)
Feb 22 11:47:56 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:56Z [INFO] - Querying system info...
Feb 22 11:47:56 bh0vm00005 iotedged[121236]: vmware
Feb 22 11:47:56 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:56Z [INFO] - Successfully queried system info
Feb 22 11:47:56 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:56Z [INFO] - [mgmt] - - - [2021-02-22 10:47:56.341048451 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:47:56 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:56Z [INFO] - Querying system info...
Feb 22 11:47:56 bh0vm00005 iotedged[121236]: vmware
Feb 22 11:47:56 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:56Z [INFO] - Successfully queried system info
Feb 22 11:47:56 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:56Z [INFO] - [mgmt] - - - [2021-02-22 10:47:56.830768864 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:47:56 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:56Z [INFO] - [work] - - - [2021-02-22 10:47:56.955203589 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/decrypt?api-version=2020-07-07 HTTP/1.1" 200 OK 6068 "-" "-" auth_id(-)
Feb 22 11:47:57 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:57Z [INFO] - [mgmt] - - - [2021-02-22 10:47:57.154465383 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 5839 "-" "-" auth_id(-)
Feb 22 11:47:57 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:57Z [INFO] - [work] - - - [2021-02-22 10:47:57.516313351 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/sign?api-version=2018-06-28 HTTP/1.1" 200 OK 57 "-" "-" auth_id(-)
Feb 22 11:47:57 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:57Z [INFO] - Edge runtime will stop because of the device reprovisioning signal.
Feb 22 11:47:57 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:57Z [INFO] - [mgmt] - - - [2021-02-22 10:47:57.773941009 UTC] "POST /device/reprovision?api-version=2020-07-07 HTTP/1.1" 200 OK - "-" "-" auth_id(-)
Feb 22 11:47:57 bh0vm00005 iotedged[121236]: 2021-02-22T10:47:57Z [ERR!] - The device has been de-provisioned
Feb 22 11:47:57 bh0vm00005 systemd[1]: iotedge.service: main process exited, code=exited, status=154/n/a
Feb 22 11:47:57 bh0vm00005 systemd[1]: Unit iotedge.service entered failed state.
Feb 22 11:47:57 bh0vm00005 systemd[1]: iotedge.service failed.
Feb 22 11:47:57 bh0vm00005 systemd[1]: iotedge.service holdoff time over, scheduling restart.
Feb 22 11:47:57 bh0vm00005 systemd[1]: Stopped Azure IoT Edge daemon.
Feb 22 11:47:57 bh0vm00005 systemd[1]: Started Azure IoT Edge daemon.
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Starting Azure IoT Edge Security Daemon
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Version - 1.1.0
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Using config file: /etc/iotedge/config.yaml
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Configuring /var/lib/iotedge as the home directory.
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Configuring certificates...
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Configuring the Device CA certificate using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA-full-chain.cert.pem".
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Configuring the Device private key using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA.key.pem".
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Configuring the trusted CA certificates using "/etc/iotedge/azure-iot.root.ca.cert.pem".
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Finished configuring provisioning environment variables and certificates.
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Initializing hsm...
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Finished initializing hsm.
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Initializing hsm X509 interface...
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Detected HTTPS proxy server http://rb-proxy-sl.bosch.com:8080/
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Finished initializing hsm X509 interface...
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Provisioning edge device...
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Starting provisioning edge device via manual mode using X509 identity certificate...
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Manually provisioning device "bh0vm00005" in hub "ioth-bhp-edge-qa.azure-devices.net"
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Finished provisioning edge device.
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Initializing the module runtime...
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Initializing module runtime...
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Using runtime network id azure-iot-edge
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Successfully initialized module runtime
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Finished initializing the module runtime.
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Stopping all modules...
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Stopping module spex-bridge-solace...
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Stopping module baseline-metrics...
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Stopping module curve-grabber-metrics...
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Stopping module edgeHub...
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Stopping module spex-bridge-redis...
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Stopping module spex-bridge-metrics...
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Stopping module spex-bridge-rabbitmq...
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Stopping module curve-grabber-watcher...
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Stopping module curve-grabber-solace...
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [INFO] - Stopping module edgeAgent...
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [WARN] - Could not stop module spex-bridge-solace
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [WARN] - Could not stop module curve-grabber-metrics
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [WARN] - Could not stop module curve-grabber-watcher
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [WARN] - Could not stop module baseline-metrics
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [WARN] - Could not stop module spex-bridge-rabbitmq
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [WARN] - Could not stop module edgeHub
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [WARN] - Could not stop module curve-grabber-solace
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [WARN] - Could not stop module spex-bridge-metrics
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [WARN] - Could not stop module spex-bridge-redis
Feb 22 11:47:58 bh0vm00005 iotedged[121497]: 2021-02-22T10:47:58Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:48:28 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:28Z [INFO] - Successfully stopped module edgeAgent
Feb 22 11:48:28 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:28Z [INFO] - Finished stopping modules.
Feb 22 11:48:28 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:28Z [INFO] - Detecting if configuration file has changed...
Feb 22 11:48:28 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:28Z [INFO] - No change to configuration file detected.
Feb 22 11:48:28 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:28Z [INFO] - Edge issuer CA expiration date: 2036-02-06T16:48:02Z
Feb 22 11:48:28 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:28Z [INFO] - Obtaining workload CA succeeded.
Feb 22 11:48:28 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:28Z [INFO] - Starting management API...
Feb 22 11:48:28 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:28Z [INFO] - Starting workload API...
Feb 22 11:48:28 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:28Z [INFO] - Starting watchdog with 60 second frequency...
Feb 22 11:48:28 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:28Z [INFO] - Listening on unix:///var/lib/iotedge/mgmt.sock with 1 thread for management API.
Feb 22 11:48:28 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:28Z [INFO] - Listening on unix:///var/lib/iotedge/workload.sock with 1 thread for workload API.
Feb 22 11:48:28 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:28Z [INFO] - Checking edge runtime status
Feb 22 11:48:28 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:28Z [INFO] - Edge runtime status is failed, starting module now...
Feb 22 11:48:28 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:28Z [INFO] - Starting module edgeAgent...
Feb 22 11:48:28 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:28Z [INFO] - Successfully started module edgeAgent
Feb 22 11:48:29 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:29Z [INFO] - [work] - - - [2021-02-22 10:48:29.236274624 UTC] "GET /trust-bundle?api-version=2019-01-30 HTTP/1.1" 200 OK 1994 "-" "-" auth_id(-)
Feb 22 11:48:29 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:29Z [INFO] - Querying system info...
Feb 22 11:48:29 bh0vm00005 iotedged[121497]: vmware
Feb 22 11:48:29 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:29Z [INFO] - Successfully queried system info
Feb 22 11:48:29 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:29Z [INFO] - [mgmt] - - - [2021-02-22 10:48:29.632939320 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:48:30 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:30Z [INFO] - Querying system info...
Feb 22 11:48:30 bh0vm00005 iotedged[121497]: vmware
Feb 22 11:48:30 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:30Z [INFO] - Successfully queried system info
Feb 22 11:48:30 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:30Z [INFO] - [mgmt] - - - [2021-02-22 10:48:30.148991274 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:48:30 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:30Z [INFO] - [work] - - - [2021-02-22 10:48:30.275334465 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/decrypt?api-version=2020-07-07 HTTP/1.1" 200 OK 6068 "-" "-" auth_id(-)
Feb 22 11:48:30 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:30Z [INFO] - [mgmt] - - - [2021-02-22 10:48:30.472740579 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 5839 "-" "-" auth_id(-)
Feb 22 11:48:30 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:30Z [INFO] - [work] - - - [2021-02-22 10:48:30.804898279 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/sign?api-version=2018-06-28 HTTP/1.1" 200 OK 57 "-" "-" auth_id(-)
Feb 22 11:48:31 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:31Z [INFO] - [mgmt] - - - [2021-02-22 10:48:31.075296361 UTC] "POST /device/reprovision?api-version=2020-07-07 HTTP/1.1" 200 OK - "-" "-" auth_id(-)
Feb 22 11:48:31 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:31Z [INFO] - Edge runtime will stop because of the device reprovisioning signal.
Feb 22 11:48:31 bh0vm00005 iotedged[121497]: 2021-02-22T10:48:31Z [ERR!] - The device has been de-provisioned
Feb 22 11:48:31 bh0vm00005 systemd[1]: iotedge.service: main process exited, code=exited, status=154/n/a
Feb 22 11:48:31 bh0vm00005 systemd[1]: Unit iotedge.service entered failed state.
Feb 22 11:48:31 bh0vm00005 systemd[1]: iotedge.service failed.
Feb 22 11:48:31 bh0vm00005 systemd[1]: iotedge.service holdoff time over, scheduling restart.
Feb 22 11:48:31 bh0vm00005 systemd[1]: Stopped Azure IoT Edge daemon.
Feb 22 11:48:31 bh0vm00005 systemd[1]: Started Azure IoT Edge daemon.
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Starting Azure IoT Edge Security Daemon
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Version - 1.1.0
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Using config file: /etc/iotedge/config.yaml
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Configuring /var/lib/iotedge as the home directory.
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Configuring certificates...
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Configuring the Device CA certificate using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA-full-chain.cert.pem".
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Configuring the Device private key using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA.key.pem".
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Configuring the trusted CA certificates using "/etc/iotedge/azure-iot.root.ca.cert.pem".
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Finished configuring provisioning environment variables and certificates.
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Initializing hsm...
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Finished initializing hsm.
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Initializing hsm X509 interface...
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Detected HTTPS proxy server http://rb-proxy-sl.bosch.com:8080/
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Finished initializing hsm X509 interface...
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Provisioning edge device...
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Starting provisioning edge device via manual mode using X509 identity certificate...
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Manually provisioning device "bh0vm00005" in hub "ioth-bhp-edge-qa.azure-devices.net"
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Finished provisioning edge device.
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Initializing the module runtime...
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Initializing module runtime...
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Using runtime network id azure-iot-edge
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Successfully initialized module runtime
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Finished initializing the module runtime.
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Stopping all modules...
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Stopping module spex-bridge-solace...
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Stopping module baseline-metrics...
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Stopping module curve-grabber-metrics...
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Stopping module edgeHub...
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Stopping module spex-bridge-redis...
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Stopping module spex-bridge-metrics...
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Stopping module spex-bridge-rabbitmq...
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Stopping module curve-grabber-watcher...
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Stopping module curve-grabber-solace...
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [INFO] - Stopping module edgeAgent...
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [WARN] - Could not stop module spex-bridge-solace
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [WARN] - Could not stop module curve-grabber-solace
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [WARN] - Could not stop module curve-grabber-watcher
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [WARN] - Could not stop module edgeHub
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [WARN] - Could not stop module spex-bridge-rabbitmq
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [WARN] - Could not stop module spex-bridge-redis
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [WARN] - Could not stop module spex-bridge-metrics
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [WARN] - Could not stop module curve-grabber-metrics
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [WARN] - Could not stop module baseline-metrics
Feb 22 11:48:31 bh0vm00005 iotedged[121754]: 2021-02-22T10:48:31Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:49:01 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:01Z [INFO] - Successfully stopped module edgeAgent
Feb 22 11:49:01 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:01Z [INFO] - Finished stopping modules.
Feb 22 11:49:01 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:01Z [INFO] - Detecting if configuration file has changed...
Feb 22 11:49:01 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:01Z [INFO] - No change to configuration file detected.
Feb 22 11:49:01 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:01Z [INFO] - Edge issuer CA expiration date: 2036-02-06T16:48:02Z
Feb 22 11:49:01 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:01Z [INFO] - Obtaining workload CA succeeded.
Feb 22 11:49:01 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:01Z [INFO] - Starting management API...
Feb 22 11:49:01 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:01Z [INFO] - Starting workload API...
Feb 22 11:49:01 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:01Z [INFO] - Starting watchdog with 60 second frequency...
Feb 22 11:49:01 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:01Z [INFO] - Listening on unix:///var/lib/iotedge/mgmt.sock with 1 thread for management API.
Feb 22 11:49:01 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:01Z [INFO] - Listening on unix:///var/lib/iotedge/workload.sock with 1 thread for workload API.
Feb 22 11:49:01 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:01Z [INFO] - Checking edge runtime status
Feb 22 11:49:01 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:01Z [INFO] - Edge runtime status is failed, starting module now...
Feb 22 11:49:01 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:01Z [INFO] - Starting module edgeAgent...
Feb 22 11:49:01 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:01Z [INFO] - Successfully started module edgeAgent
Feb 22 11:49:02 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:02Z [INFO] - [work] - - - [2021-02-22 10:49:02.455267486 UTC] "GET /trust-bundle?api-version=2019-01-30 HTTP/1.1" 200 OK 1994 "-" "-" auth_id(-)
Feb 22 11:49:02 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:02Z [INFO] - Querying system info...
Feb 22 11:49:02 bh0vm00005 iotedged[121754]: vmware
Feb 22 11:49:02 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:02Z [INFO] - Successfully queried system info
Feb 22 11:49:02 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:02Z [INFO] - [mgmt] - - - [2021-02-22 10:49:02.830112001 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:49:03 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:03Z [INFO] - Querying system info...
Feb 22 11:49:03 bh0vm00005 iotedged[121754]: vmware
Feb 22 11:49:03 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:03Z [INFO] - Successfully queried system info
Feb 22 11:49:03 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:03Z [INFO] - [mgmt] - - - [2021-02-22 10:49:03.309843594 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:49:03 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:03Z [INFO] - [work] - - - [2021-02-22 10:49:03.426505367 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/decrypt?api-version=2020-07-07 HTTP/1.1" 200 OK 6068 "-" "-" auth_id(-)
Feb 22 11:49:03 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:03Z [INFO] - [mgmt] - - - [2021-02-22 10:49:03.619239016 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 5839 "-" "-" auth_id(-)
Feb 22 11:49:03 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:03Z [INFO] - [work] - - - [2021-02-22 10:49:03.895104427 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/sign?api-version=2018-06-28 HTTP/1.1" 200 OK 57 "-" "-" auth_id(-)
Feb 22 11:49:04 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:04Z [INFO] - [mgmt] - - - [2021-02-22 10:49:04.151216173 UTC] "POST /device/reprovision?api-version=2020-07-07 HTTP/1.1" 200 OK - "-" "-" auth_id(-)
Feb 22 11:49:04 bh0vm00005 iotedged[121754]: 2021-02-22T10:49:04Z [INFO] - Edge runtime will stop because of the device reprovisioning signal.
Feb 22 11:49:04 bh0vm00005 systemd[1]: iotedge.service: main process exited, code=exited, status=154/n/a
Feb 22 11:49:04 bh0vm00005 systemd[1]: Unit iotedge.service entered failed state.
Feb 22 11:49:04 bh0vm00005 systemd[1]: iotedge.service failed.
Feb 22 11:49:04 bh0vm00005 systemd[1]: iotedge.service holdoff time over, scheduling restart.
Feb 22 11:49:04 bh0vm00005 systemd[1]: Stopped Azure IoT Edge daemon.
Feb 22 11:49:04 bh0vm00005 systemd[1]: Started Azure IoT Edge daemon.
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Starting Azure IoT Edge Security Daemon
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Version - 1.1.0
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Using config file: /etc/iotedge/config.yaml
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Configuring /var/lib/iotedge as the home directory.
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Configuring certificates...
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Configuring the Device CA certificate using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA-full-chain.cert.pem".
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Configuring the Device private key using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA.key.pem".
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Configuring the trusted CA certificates using "/etc/iotedge/azure-iot.root.ca.cert.pem".
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Finished configuring provisioning environment variables and certificates.
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Initializing hsm...
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Finished initializing hsm.
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Initializing hsm X509 interface...
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Detected HTTPS proxy server http://rb-proxy-sl.bosch.com:8080/
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Finished initializing hsm X509 interface...
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Provisioning edge device...
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Starting provisioning edge device via manual mode using X509 identity certificate...
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Manually provisioning device "bh0vm00005" in hub "ioth-bhp-edge-qa.azure-devices.net"
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Finished provisioning edge device.
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Initializing the module runtime...
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Initializing module runtime...
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Using runtime network id azure-iot-edge
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Successfully initialized module runtime
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Finished initializing the module runtime.
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Stopping all modules...
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Stopping module spex-bridge-solace...
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Stopping module baseline-metrics...
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Stopping module curve-grabber-metrics...
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Stopping module edgeHub...
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Stopping module spex-bridge-redis...
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Stopping module spex-bridge-metrics...
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Stopping module spex-bridge-rabbitmq...
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Stopping module curve-grabber-watcher...
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Stopping module curve-grabber-solace...
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [INFO] - Stopping module edgeAgent...
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [WARN] - Could not stop module spex-bridge-solace
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [WARN] - Could not stop module spex-bridge-rabbitmq
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [WARN] - Could not stop module baseline-metrics
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [WARN] - Could not stop module curve-grabber-metrics
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [WARN] - Could not stop module edgeHub
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [WARN] - Could not stop module spex-bridge-redis
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [WARN] - Could not stop module spex-bridge-metrics
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [WARN] - Could not stop module curve-grabber-watcher
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [WARN] - Could not stop module curve-grabber-solace
Feb 22 11:49:04 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:04Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:49:34 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:34Z [INFO] - Successfully stopped module edgeAgent
Feb 22 11:49:34 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:34Z [INFO] - Finished stopping modules.
Feb 22 11:49:34 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:34Z [INFO] - Detecting if configuration file has changed...
Feb 22 11:49:34 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:34Z [INFO] - No change to configuration file detected.
Feb 22 11:49:34 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:34Z [INFO] - Edge issuer CA expiration date: 2036-02-06T16:48:02Z
Feb 22 11:49:34 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:34Z [INFO] - Obtaining workload CA succeeded.
Feb 22 11:49:34 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:34Z [INFO] - Starting management API...
Feb 22 11:49:34 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:34Z [INFO] - Starting workload API...
Feb 22 11:49:34 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:34Z [INFO] - Starting watchdog with 60 second frequency...
Feb 22 11:49:34 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:34Z [INFO] - Listening on unix:///var/lib/iotedge/mgmt.sock with 1 thread for management API.
Feb 22 11:49:34 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:34Z [INFO] - Listening on unix:///var/lib/iotedge/workload.sock with 1 thread for workload API.
Feb 22 11:49:34 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:34Z [INFO] - Checking edge runtime status
Feb 22 11:49:34 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:34Z [INFO] - Edge runtime status is failed, starting module now...
Feb 22 11:49:34 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:34Z [INFO] - Starting module edgeAgent...
Feb 22 11:49:35 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:35Z [INFO] - Successfully started module edgeAgent
Feb 22 11:49:35 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:35Z [INFO] - [work] - - - [2021-02-22 10:49:35.726663914 UTC] "GET /trust-bundle?api-version=2019-01-30 HTTP/1.1" 200 OK 1994 "-" "-" auth_id(-)
Feb 22 11:49:36 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:36Z [INFO] - Querying system info...
Feb 22 11:49:36 bh0vm00005 iotedged[123216]: vmware
Feb 22 11:49:36 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:36Z [INFO] - Successfully queried system info
Feb 22 11:49:36 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:36Z [INFO] - [mgmt] - - - [2021-02-22 10:49:36.125972680 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:49:36 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:36Z [INFO] - Querying system info...
Feb 22 11:49:36 bh0vm00005 iotedged[123216]: vmware
Feb 22 11:49:36 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:36Z [INFO] - Successfully queried system info
Feb 22 11:49:36 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:36Z [INFO] - [mgmt] - - - [2021-02-22 10:49:36.618225436 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:49:36 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:36Z [INFO] - [work] - - - [2021-02-22 10:49:36.733323557 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/decrypt?api-version=2020-07-07 HTTP/1.1" 200 OK 6068 "-" "-" auth_id(-)
Feb 22 11:49:36 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:36Z [INFO] - [mgmt] - - - [2021-02-22 10:49:36.928194379 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 5839 "-" "-" auth_id(-)
Feb 22 11:49:37 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:37Z [INFO] - [work] - - - [2021-02-22 10:49:37.228317586 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/sign?api-version=2018-06-28 HTTP/1.1" 200 OK 57 "-" "-" auth_id(-)
Feb 22 11:49:37 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:37Z [INFO] - [mgmt] - - - [2021-02-22 10:49:37.483256986 UTC] "POST /device/reprovision?api-version=2020-07-07 HTTP/1.1" 200 OK - "-" "-" auth_id(-)
Feb 22 11:49:37 bh0vm00005 iotedged[123216]: 2021-02-22T10:49:37Z [INFO] - Edge runtime will stop because of the device reprovisioning signal.
Feb 22 11:49:37 bh0vm00005 systemd[1]: iotedge.service: main process exited, code=exited, status=154/n/a
Feb 22 11:49:37 bh0vm00005 systemd[1]: Unit iotedge.service entered failed state.
Feb 22 11:49:37 bh0vm00005 systemd[1]: iotedge.service failed.
Feb 22 11:49:37 bh0vm00005 systemd[1]: iotedge.service holdoff time over, scheduling restart.
Feb 22 11:49:37 bh0vm00005 systemd[1]: Stopped Azure IoT Edge daemon.
Feb 22 11:49:37 bh0vm00005 systemd[1]: Started Azure IoT Edge daemon.
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Starting Azure IoT Edge Security Daemon
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Version - 1.1.0
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Using config file: /etc/iotedge/config.yaml
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Configuring /var/lib/iotedge as the home directory.
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Configuring certificates...
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Configuring the Device CA certificate using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA-full-chain.cert.pem".
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Configuring the Device private key using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA.key.pem".
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Configuring the trusted CA certificates using "/etc/iotedge/azure-iot.root.ca.cert.pem".
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Finished configuring provisioning environment variables and certificates.
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Initializing hsm...
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Finished initializing hsm.
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Initializing hsm X509 interface...
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Detected HTTPS proxy server http://rb-proxy-sl.bosch.com:8080/
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Finished initializing hsm X509 interface...
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Provisioning edge device...
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Starting provisioning edge device via manual mode using X509 identity certificate...
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Manually provisioning device "bh0vm00005" in hub "ioth-bhp-edge-qa.azure-devices.net"
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Finished provisioning edge device.
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Initializing the module runtime...
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Initializing module runtime...
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Using runtime network id azure-iot-edge
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Successfully initialized module runtime
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Finished initializing the module runtime.
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Stopping all modules...
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Stopping module spex-bridge-solace...
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Stopping module baseline-metrics...
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Stopping module curve-grabber-metrics...
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Stopping module edgeHub...
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Stopping module spex-bridge-redis...
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Stopping module spex-bridge-metrics...
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Stopping module spex-bridge-rabbitmq...
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Stopping module curve-grabber-watcher...
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Stopping module curve-grabber-solace...
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [INFO] - Stopping module edgeAgent...
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [WARN] - Could not stop module spex-bridge-solace
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [WARN] - Could not stop module baseline-metrics
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [WARN] - Could not stop module curve-grabber-metrics
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [WARN] - Could not stop module edgeHub
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [WARN] - Could not stop module spex-bridge-redis
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [WARN] - Could not stop module spex-bridge-rabbitmq
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [WARN] - Could not stop module spex-bridge-metrics
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [WARN] - Could not stop module curve-grabber-watcher
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [WARN] - Could not stop module curve-grabber-solace
Feb 22 11:49:37 bh0vm00005 iotedged[123473]: 2021-02-22T10:49:37Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:50:08 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:08Z [INFO] - Successfully stopped module edgeAgent
Feb 22 11:50:08 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:08Z [INFO] - Finished stopping modules.
Feb 22 11:50:08 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:08Z [INFO] - Detecting if configuration file has changed...
Feb 22 11:50:08 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:08Z [INFO] - No change to configuration file detected.
Feb 22 11:50:08 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:08Z [INFO] - Edge issuer CA expiration date: 2036-02-06T16:48:02Z
Feb 22 11:50:08 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:08Z [INFO] - Obtaining workload CA succeeded.
Feb 22 11:50:08 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:08Z [INFO] - Starting management API...
Feb 22 11:50:08 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:08Z [INFO] - Starting workload API...
Feb 22 11:50:08 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:08Z [INFO] - Starting watchdog with 60 second frequency...
Feb 22 11:50:08 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:08Z [INFO] - Listening on unix:///var/lib/iotedge/mgmt.sock with 1 thread for management API.
Feb 22 11:50:08 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:08Z [INFO] - Listening on unix:///var/lib/iotedge/workload.sock with 1 thread for workload API.
Feb 22 11:50:08 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:08Z [INFO] - Checking edge runtime status
Feb 22 11:50:08 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:08Z [INFO] - Edge runtime status is failed, starting module now...
Feb 22 11:50:08 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:08Z [INFO] - Starting module edgeAgent...
Feb 22 11:50:08 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:08Z [INFO] - Successfully started module edgeAgent
Feb 22 11:50:08 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:08Z [INFO] - [work] - - - [2021-02-22 10:50:08.968387346 UTC] "GET /trust-bundle?api-version=2019-01-30 HTTP/1.1" 200 OK 1994 "-" "-" auth_id(-)
Feb 22 11:50:09 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:09Z [INFO] - Querying system info...
Feb 22 11:50:09 bh0vm00005 iotedged[123473]: vmware
Feb 22 11:50:09 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:09Z [INFO] - Successfully queried system info
Feb 22 11:50:09 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:09Z [INFO] - [mgmt] - - - [2021-02-22 10:50:09.373284725 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:50:09 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:09Z [INFO] - Querying system info...
Feb 22 11:50:09 bh0vm00005 iotedged[123473]: vmware
Feb 22 11:50:09 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:09Z [INFO] - Successfully queried system info
Feb 22 11:50:09 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:09Z [INFO] - [mgmt] - - - [2021-02-22 10:50:09.880671239 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:50:09 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:09Z [INFO] - [work] - - - [2021-02-22 10:50:09.996460380 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/decrypt?api-version=2020-07-07 HTTP/1.1" 200 OK 6068 "-" "-" auth_id(-)
Feb 22 11:50:10 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:10Z [INFO] - [mgmt] - - - [2021-02-22 10:50:10.179627113 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 5839 "-" "-" auth_id(-)
Feb 22 11:50:10 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:10Z [INFO] - [work] - - - [2021-02-22 10:50:10.516141635 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/sign?api-version=2018-06-28 HTTP/1.1" 200 OK 57 "-" "-" auth_id(-)
Feb 22 11:50:10 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:10Z [INFO] - [mgmt] - - - [2021-02-22 10:50:10.763032955 UTC] "POST /device/reprovision?api-version=2020-07-07 HTTP/1.1" 200 OK - "-" "-" auth_id(-)
Feb 22 11:50:10 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:10Z [INFO] - Edge runtime will stop because of the device reprovisioning signal.
Feb 22 11:50:10 bh0vm00005 iotedged[123473]: 2021-02-22T10:50:10Z [ERR!] - The device has been de-provisioned
Feb 22 11:50:10 bh0vm00005 systemd[1]: iotedge.service: main process exited, code=exited, status=154/n/a
Feb 22 11:50:10 bh0vm00005 systemd[1]: Unit iotedge.service entered failed state.
Feb 22 11:50:10 bh0vm00005 systemd[1]: iotedge.service failed.
Feb 22 11:50:10 bh0vm00005 systemd[1]: iotedge.service holdoff time over, scheduling restart.
Feb 22 11:50:10 bh0vm00005 systemd[1]: Stopped Azure IoT Edge daemon.
Feb 22 11:50:11 bh0vm00005 systemd[1]: Started Azure IoT Edge daemon.
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Starting Azure IoT Edge Security Daemon
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Version - 1.1.0
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Using config file: /etc/iotedge/config.yaml
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Configuring /var/lib/iotedge as the home directory.
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Configuring certificates...
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Configuring the Device CA certificate using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA-full-chain.cert.pem".
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Configuring the Device private key using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA.key.pem".
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Configuring the trusted CA certificates using "/etc/iotedge/azure-iot.root.ca.cert.pem".
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Finished configuring provisioning environment variables and certificates.
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Initializing hsm...
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Finished initializing hsm.
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Initializing hsm X509 interface...
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Detected HTTPS proxy server http://rb-proxy-sl.bosch.com:8080/
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Finished initializing hsm X509 interface...
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Provisioning edge device...
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Starting provisioning edge device via manual mode using X509 identity certificate...
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Manually provisioning device "bh0vm00005" in hub "ioth-bhp-edge-qa.azure-devices.net"
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Finished provisioning edge device.
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Initializing the module runtime...
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Initializing module runtime...
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Using runtime network id azure-iot-edge
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Successfully initialized module runtime
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Finished initializing the module runtime.
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Stopping all modules...
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Stopping module spex-bridge-solace...
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Stopping module baseline-metrics...
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Stopping module curve-grabber-metrics...
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Stopping module edgeHub...
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Stopping module spex-bridge-redis...
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Stopping module spex-bridge-metrics...
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Stopping module spex-bridge-rabbitmq...
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Stopping module curve-grabber-watcher...
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Stopping module curve-grabber-solace...
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [INFO] - Stopping module edgeAgent...
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [WARN] - Could not stop module spex-bridge-solace
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [WARN] - Could not stop module spex-bridge-rabbitmq
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [WARN] - Could not stop module edgeHub
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [WARN] - Could not stop module spex-bridge-metrics
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [WARN] - Could not stop module curve-grabber-metrics
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [WARN] - Could not stop module spex-bridge-redis
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [WARN] - Could not stop module baseline-metrics
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [WARN] - Could not stop module curve-grabber-solace
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [WARN] - Could not stop module curve-grabber-watcher
Feb 22 11:50:11 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:11Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:50:41 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:41Z [INFO] - Successfully stopped module edgeAgent
Feb 22 11:50:41 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:41Z [INFO] - Finished stopping modules.
Feb 22 11:50:41 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:41Z [INFO] - Detecting if configuration file has changed...
Feb 22 11:50:41 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:41Z [INFO] - No change to configuration file detected.
Feb 22 11:50:41 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:41Z [INFO] - Edge issuer CA expiration date: 2036-02-06T16:48:02Z
Feb 22 11:50:41 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:41Z [INFO] - Obtaining workload CA succeeded.
Feb 22 11:50:41 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:41Z [INFO] - Starting management API...
Feb 22 11:50:41 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:41Z [INFO] - Starting workload API...
Feb 22 11:50:41 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:41Z [INFO] - Starting watchdog with 60 second frequency...
Feb 22 11:50:41 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:41Z [INFO] - Listening on unix:///var/lib/iotedge/mgmt.sock with 1 thread for management API.
Feb 22 11:50:41 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:41Z [INFO] - Listening on unix:///var/lib/iotedge/workload.sock with 1 thread for workload API.
Feb 22 11:50:41 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:41Z [INFO] - Checking edge runtime status
Feb 22 11:50:41 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:41Z [INFO] - Edge runtime status is failed, starting module now...
Feb 22 11:50:41 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:41Z [INFO] - Starting module edgeAgent...
Feb 22 11:50:41 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:41Z [INFO] - Successfully started module edgeAgent
Feb 22 11:50:42 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:42Z [INFO] - [work] - - - [2021-02-22 10:50:42.240655746 UTC] "GET /trust-bundle?api-version=2019-01-30 HTTP/1.1" 200 OK 1994 "-" "-" auth_id(-)
Feb 22 11:50:42 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:42Z [INFO] - Querying system info...
Feb 22 11:50:42 bh0vm00005 iotedged[123851]: vmware
Feb 22 11:50:42 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:42Z [INFO] - Successfully queried system info
Feb 22 11:50:42 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:42Z [INFO] - [mgmt] - - - [2021-02-22 10:50:42.614885991 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:50:43 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:43Z [INFO] - Querying system info...
Feb 22 11:50:43 bh0vm00005 iotedged[123851]: vmware
Feb 22 11:50:43 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:43Z [INFO] - Successfully queried system info
Feb 22 11:50:43 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:43Z [INFO] - [mgmt] - - - [2021-02-22 10:50:43.095592975 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:50:43 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:43Z [INFO] - [work] - - - [2021-02-22 10:50:43.208435227 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/decrypt?api-version=2020-07-07 HTTP/1.1" 200 OK 6068 "-" "-" auth_id(-)
Feb 22 11:50:43 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:43Z [INFO] - [mgmt] - - - [2021-02-22 10:50:43.402072831 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 5839 "-" "-" auth_id(-)
Feb 22 11:50:43 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:43Z [INFO] - [work] - - - [2021-02-22 10:50:43.699576688 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/sign?api-version=2018-06-28 HTTP/1.1" 200 OK 57 "-" "-" auth_id(-)
Feb 22 11:50:43 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:43Z [INFO] - [mgmt] - - - [2021-02-22 10:50:43.960106398 UTC] "POST /device/reprovision?api-version=2020-07-07 HTTP/1.1" 200 OK - "-" "-" auth_id(-)
Feb 22 11:50:43 bh0vm00005 iotedged[123851]: 2021-02-22T10:50:43Z [INFO] - Edge runtime will stop because of the device reprovisioning signal.
Feb 22 11:50:43 bh0vm00005 systemd[1]: iotedge.service: main process exited, code=exited, status=154/n/a
Feb 22 11:50:43 bh0vm00005 systemd[1]: Unit iotedge.service entered failed state.
Feb 22 11:50:43 bh0vm00005 systemd[1]: iotedge.service failed.
Feb 22 11:50:44 bh0vm00005 systemd[1]: iotedge.service holdoff time over, scheduling restart.
Feb 22 11:50:44 bh0vm00005 systemd[1]: Stopped Azure IoT Edge daemon.
Feb 22 11:50:44 bh0vm00005 systemd[1]: Started Azure IoT Edge daemon.
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Starting Azure IoT Edge Security Daemon
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Version - 1.1.0
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Using config file: /etc/iotedge/config.yaml
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Configuring /var/lib/iotedge as the home directory.
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Configuring certificates...
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Configuring the Device CA certificate using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA-full-chain.cert.pem".
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Configuring the Device private key using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA.key.pem".
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Configuring the trusted CA certificates using "/etc/iotedge/azure-iot.root.ca.cert.pem".
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Finished configuring provisioning environment variables and certificates.
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Initializing hsm...
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Finished initializing hsm.
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Initializing hsm X509 interface...
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Detected HTTPS proxy server http://rb-proxy-sl.bosch.com:8080/
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Finished initializing hsm X509 interface...
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Provisioning edge device...
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Starting provisioning edge device via manual mode using X509 identity certificate...
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Manually provisioning device "bh0vm00005" in hub "ioth-bhp-edge-qa.azure-devices.net"
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Finished provisioning edge device.
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Initializing the module runtime...
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Initializing module runtime...
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Using runtime network id azure-iot-edge
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Successfully initialized module runtime
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Finished initializing the module runtime.
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Stopping all modules...
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Stopping module spex-bridge-solace...
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Stopping module baseline-metrics...
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Stopping module curve-grabber-metrics...
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Stopping module edgeHub...
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Stopping module spex-bridge-redis...
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Stopping module spex-bridge-metrics...
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Stopping module spex-bridge-rabbitmq...
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Stopping module curve-grabber-watcher...
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Stopping module curve-grabber-solace...
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [INFO] - Stopping module edgeAgent...
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [WARN] - Could not stop module spex-bridge-solace
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [WARN] - Could not stop module baseline-metrics
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [WARN] - Could not stop module edgeHub
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [WARN] - Could not stop module spex-bridge-redis
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [WARN] - Could not stop module spex-bridge-metrics
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [WARN] - Could not stop module spex-bridge-rabbitmq
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [WARN] - Could not stop module curve-grabber-watcher
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [WARN] - Could not stop module curve-grabber-solace
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [WARN] - Could not stop module curve-grabber-metrics
Feb 22 11:50:44 bh0vm00005 iotedged[124227]: 2021-02-22T10:50:44Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:51:14 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:14Z [INFO] - Successfully stopped module edgeAgent
Feb 22 11:51:14 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:14Z [INFO] - Finished stopping modules.
Feb 22 11:51:14 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:14Z [INFO] - Detecting if configuration file has changed...
Feb 22 11:51:14 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:14Z [INFO] - No change to configuration file detected.
Feb 22 11:51:14 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:14Z [INFO] - Edge issuer CA expiration date: 2036-02-06T16:48:02Z
Feb 22 11:51:14 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:14Z [INFO] - Obtaining workload CA succeeded.
Feb 22 11:51:14 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:14Z [INFO] - Starting management API...
Feb 22 11:51:14 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:14Z [INFO] - Starting workload API...
Feb 22 11:51:14 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:14Z [INFO] - Starting watchdog with 60 second frequency...
Feb 22 11:51:14 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:14Z [INFO] - Listening on unix:///var/lib/iotedge/mgmt.sock with 1 thread for management API.
Feb 22 11:51:14 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:14Z [INFO] - Listening on unix:///var/lib/iotedge/workload.sock with 1 thread for workload API.
Feb 22 11:51:14 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:14Z [INFO] - Checking edge runtime status
Feb 22 11:51:14 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:14Z [INFO] - Edge runtime status is failed, starting module now...
Feb 22 11:51:14 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:14Z [INFO] - Starting module edgeAgent...
Feb 22 11:51:14 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:14Z [INFO] - Successfully started module edgeAgent
Feb 22 11:51:15 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:15Z [INFO] - [work] - - - [2021-02-22 10:51:15.416014659 UTC] "GET /trust-bundle?api-version=2019-01-30 HTTP/1.1" 200 OK 1994 "-" "-" auth_id(-)
Feb 22 11:51:15 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:15Z [INFO] - Querying system info...
Feb 22 11:51:15 bh0vm00005 iotedged[124227]: vmware
Feb 22 11:51:15 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:15Z [INFO] - Successfully queried system info
Feb 22 11:51:15 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:15Z [INFO] - [mgmt] - - - [2021-02-22 10:51:15.810360229 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:51:16 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:16Z [INFO] - Querying system info...
Feb 22 11:51:16 bh0vm00005 iotedged[124227]: vmware
Feb 22 11:51:16 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:16Z [INFO] - Successfully queried system info
Feb 22 11:51:16 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:16Z [INFO] - [mgmt] - - - [2021-02-22 10:51:16.296301141 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:51:16 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:16Z [INFO] - [work] - - - [2021-02-22 10:51:16.404114515 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/decrypt?api-version=2020-07-07 HTTP/1.1" 200 OK 6068 "-" "-" auth_id(-)
Feb 22 11:51:16 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:16Z [INFO] - [mgmt] - - - [2021-02-22 10:51:16.598362253 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 5839 "-" "-" auth_id(-)
Feb 22 11:51:16 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:16Z [INFO] - [work] - - - [2021-02-22 10:51:16.935708155 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/sign?api-version=2018-06-28 HTTP/1.1" 200 OK 57 "-" "-" auth_id(-)
Feb 22 11:51:17 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:17Z [INFO] - [mgmt] - - - [2021-02-22 10:51:17.211283703 UTC] "POST /device/reprovision?api-version=2020-07-07 HTTP/1.1" 200 OK - "-" "-" auth_id(-)
Feb 22 11:51:17 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:17Z [INFO] - Edge runtime will stop because of the device reprovisioning signal.
Feb 22 11:51:17 bh0vm00005 iotedged[124227]: 2021-02-22T10:51:17Z [ERR!] - The device has been de-provisioned
Feb 22 11:51:17 bh0vm00005 systemd[1]: iotedge.service: main process exited, code=exited, status=154/n/a
Feb 22 11:51:17 bh0vm00005 systemd[1]: Unit iotedge.service entered failed state.
Feb 22 11:51:17 bh0vm00005 systemd[1]: iotedge.service failed.
Feb 22 11:51:17 bh0vm00005 systemd[1]: iotedge.service holdoff time over, scheduling restart.
Feb 22 11:51:17 bh0vm00005 systemd[1]: Stopped Azure IoT Edge daemon.
Feb 22 11:51:17 bh0vm00005 systemd[1]: Started Azure IoT Edge daemon.
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Starting Azure IoT Edge Security Daemon
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Version - 1.1.0
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Using config file: /etc/iotedge/config.yaml
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Configuring /var/lib/iotedge as the home directory.
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Configuring certificates...
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Configuring the Device CA certificate using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA-full-chain.cert.pem".
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Configuring the Device private key using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA.key.pem".
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Configuring the trusted CA certificates using "/etc/iotedge/azure-iot.root.ca.cert.pem".
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Finished configuring provisioning environment variables and certificates.
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Initializing hsm...
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Finished initializing hsm.
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Initializing hsm X509 interface...
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Detected HTTPS proxy server http://rb-proxy-sl.bosch.com:8080/
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Finished initializing hsm X509 interface...
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Provisioning edge device...
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Starting provisioning edge device via manual mode using X509 identity certificate...
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Manually provisioning device "bh0vm00005" in hub "ioth-bhp-edge-qa.azure-devices.net"
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Finished provisioning edge device.
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Initializing the module runtime...
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Initializing module runtime...
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Using runtime network id azure-iot-edge
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Successfully initialized module runtime
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Finished initializing the module runtime.
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Stopping all modules...
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Stopping module spex-bridge-solace...
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Stopping module baseline-metrics...
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Stopping module curve-grabber-metrics...
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Stopping module edgeHub...
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Stopping module spex-bridge-redis...
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Stopping module spex-bridge-metrics...
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Stopping module spex-bridge-rabbitmq...
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Stopping module curve-grabber-watcher...
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Stopping module curve-grabber-solace...
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [INFO] - Stopping module edgeAgent...
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [WARN] - Could not stop module spex-bridge-solace
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [WARN] - Could not stop module curve-grabber-metrics
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [WARN] - Could not stop module edgeHub
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [WARN] - Could not stop module spex-bridge-redis
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [WARN] - Could not stop module spex-bridge-metrics
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [WARN] - Could not stop module spex-bridge-rabbitmq
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [WARN] - Could not stop module curve-grabber-watcher
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [WARN] - Could not stop module curve-grabber-solace
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [WARN] - Could not stop module baseline-metrics
Feb 22 11:51:17 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:17Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:51:47 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:47Z [INFO] - Successfully stopped module edgeAgent
Feb 22 11:51:47 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:47Z [INFO] - Finished stopping modules.
Feb 22 11:51:47 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:47Z [INFO] - Detecting if configuration file has changed...
Feb 22 11:51:47 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:47Z [INFO] - No change to configuration file detected.
Feb 22 11:51:47 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:47Z [INFO] - Edge issuer CA expiration date: 2036-02-06T16:48:02Z
Feb 22 11:51:47 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:47Z [INFO] - Obtaining workload CA succeeded.
Feb 22 11:51:47 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:47Z [INFO] - Starting management API...
Feb 22 11:51:47 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:47Z [INFO] - Starting workload API...
Feb 22 11:51:47 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:47Z [INFO] - Starting watchdog with 60 second frequency...
Feb 22 11:51:47 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:47Z [INFO] - Listening on unix:///var/lib/iotedge/mgmt.sock with 1 thread for management API.
Feb 22 11:51:47 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:47Z [INFO] - Listening on unix:///var/lib/iotedge/workload.sock with 1 thread for workload API.
Feb 22 11:51:47 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:47Z [INFO] - Checking edge runtime status
Feb 22 11:51:47 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:47Z [INFO] - Edge runtime status is failed, starting module now...
Feb 22 11:51:47 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:47Z [INFO] - Starting module edgeAgent...
Feb 22 11:51:48 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:48Z [INFO] - Successfully started module edgeAgent
Feb 22 11:51:48 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:48Z [INFO] - [work] - - - [2021-02-22 10:51:48.708440177 UTC] "GET /trust-bundle?api-version=2019-01-30 HTTP/1.1" 200 OK 1994 "-" "-" auth_id(-)
Feb 22 11:51:49 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:49Z [INFO] - Querying system info...
Feb 22 11:51:49 bh0vm00005 iotedged[124566]: vmware
Feb 22 11:51:49 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:49Z [INFO] - Successfully queried system info
Feb 22 11:51:49 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:49Z [INFO] - [mgmt] - - - [2021-02-22 10:51:49.092892570 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:51:49 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:49Z [INFO] - Querying system info...
Feb 22 11:51:49 bh0vm00005 iotedged[124566]: vmware
Feb 22 11:51:49 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:49Z [INFO] - Successfully queried system info
Feb 22 11:51:49 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:49Z [INFO] - [mgmt] - - - [2021-02-22 10:51:49.598905702 UTC] "GET /systeminfo?api-version=2020-07-07 HTTP/1.1" 200 OK 317 "-" "-" auth_id(-)
Feb 22 11:51:49 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:49Z [INFO] - [work] - - - [2021-02-22 10:51:49.883097015 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/decrypt?api-version=2020-07-07 HTTP/1.1" 200 OK 6068 "-" "-" auth_id(-)
Feb 22 11:51:50 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:50Z [INFO] - [mgmt] - - - [2021-02-22 10:51:50.072664431 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 5839 "-" "-" auth_id(-)
Feb 22 11:51:50 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:50Z [INFO] - [work] - - - [2021-02-22 10:51:50.241131931 UTC] "POST /modules/%24edgeAgent/genid/637485497193754825/sign?api-version=2018-06-28 HTTP/1.1" 200 OK 57 "-" "-" auth_id(-)
Feb 22 11:51:50 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:50Z [INFO] - [mgmt] - - - [2021-02-22 10:51:50.477072697 UTC] "POST /device/reprovision?api-version=2020-07-07 HTTP/1.1" 200 OK - "-" "-" auth_id(-)
Feb 22 11:51:50 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:50Z [INFO] - Edge runtime will stop because of the device reprovisioning signal.
Feb 22 11:51:50 bh0vm00005 iotedged[124566]: 2021-02-22T10:51:50Z [ERR!] - The device has been de-provisioned
Feb 22 11:51:50 bh0vm00005 systemd[1]: iotedge.service: main process exited, code=exited, status=154/n/a
Feb 22 11:51:50 bh0vm00005 systemd[1]: Unit iotedge.service entered failed state.
Feb 22 11:51:50 bh0vm00005 systemd[1]: iotedge.service failed.
Feb 22 11:51:50 bh0vm00005 systemd[1]: iotedge.service holdoff time over, scheduling restart.
Feb 22 11:51:50 bh0vm00005 systemd[1]: Stopped Azure IoT Edge daemon.
Feb 22 11:51:50 bh0vm00005 systemd[1]: Started Azure IoT Edge daemon.
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Starting Azure IoT Edge Security Daemon
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Version - 1.1.0
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Using config file: /etc/iotedge/config.yaml
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Configuring /var/lib/iotedge as the home directory.
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Configuring certificates...
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Configuring the Device CA certificate using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA-full-chain.cert.pem".
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Configuring the Device private key using "/etc/iotedge/iot-edge-device-ca-bh0vm00005CA.key.pem".
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Configuring the trusted CA certificates using "/etc/iotedge/azure-iot.root.ca.cert.pem".
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Finished configuring provisioning environment variables and certificates.
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Initializing hsm...
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Finished initializing hsm.
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Initializing hsm X509 interface...
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Detected HTTPS proxy server http://rb-proxy-sl.bosch.com:8080/
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Finished initializing hsm X509 interface...
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Provisioning edge device...
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Starting provisioning edge device via manual mode using X509 identity certificate...
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Manually provisioning device "bh0vm00005" in hub "ioth-bhp-edge-qa.azure-devices.net"
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Finished provisioning edge device.
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Initializing the module runtime...
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Initializing module runtime...
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Using runtime network id azure-iot-edge
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Successfully initialized module runtime
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Finished initializing the module runtime.
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Stopping all modules...
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Stopping module spex-bridge-solace...
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Stopping module baseline-metrics...
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Stopping module curve-grabber-metrics...
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Stopping module edgeHub...
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Stopping module spex-bridge-redis...
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Stopping module spex-bridge-metrics...
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Stopping module spex-bridge-rabbitmq...
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Stopping module curve-grabber-watcher...
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Stopping module curve-grabber-solace...
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [INFO] - Stopping module edgeAgent...
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [WARN] - Could not stop module spex-bridge-solace
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [WARN] - Could not stop module baseline-metrics
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [WARN] - Could not stop module curve-grabber-metrics
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [WARN] - Could not stop module edgeHub
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [WARN] - Could not stop module spex-bridge-redis
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [WARN] - Could not stop module spex-bridge-metrics
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [WARN] - Could not stop module curve-grabber-watcher
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [WARN] - Could not stop module spex-bridge-rabbitmq
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [WARN] - caused by: Target of operation already in this state
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [WARN] - Could not stop module curve-grabber-solace
Feb 22 11:51:50 bh0vm00005 iotedged[124823]: 2021-02-22T10:51:50Z [WARN] - caused by: Target of operation already in this state
edge-agent logs
2021-02-22 10:52:54 Starting Edge Agent
2021-02-22 10:52:54 Changing ownership of storage folder: /storage/edgeAgent to 1000
2021-02-22 10:52:54 Changing ownership of management socket: /var/lib/iotedge/mgmt.sock
2021-02-22 10:52:55.021 +00:00 Edge Agent Main()
<6> 2021-02-22 10:52:55.184 +00:00 [INF] - Initializing Edge Agent.
<6> 2021-02-22 10:52:55.350 +00:00 [INF] - Version - 1.1.0.39334128 (92ac4878a4c8ca74c0db14cd2e63273f1c8661f4)
<6> 2021-02-22 10:52:55.350 +00:00 [INF] -
█████╗ ███████╗██╗ ██╗██████╗ ███████╗
██╔══██╗╚══███╔╝██║ ██║██╔══██╗██╔════╝
███████║ ███╔╝ ██║ ██║██████╔╝█████╗
██╔══██║ ███╔╝ ██║ ██║██╔══██╗██╔══╝
██║ ██║███████╗╚██████╔╝██║ ██║███████╗
╚═╝ ╚═╝╚══════╝ ╚═════╝ ╚═╝ ╚═╝╚══════╝
██╗ ██████╗ ████████╗ ███████╗██████╗ ██████╗ ███████╗
██║██╔═══██╗╚══██╔══╝ ██╔════╝██╔══██╗██╔════╝ ██╔════╝
██║██║ ██║ ██║ █████╗ ██║ ██║██║ ███╗█████╗
██║██║ ██║ ██║ ██╔══╝ ██║ ██║██║ ██║██╔══╝
██║╚██████╔╝ ██║ ███████╗██████╔╝╚██████╔╝███████╗
╚═╝ ╚═════╝ ╚═╝ ╚══════╝╚═════╝ ╚═════╝ ╚══════╝
<6> 2021-02-22 10:52:55.366 +00:00 [INF] - Detected proxy http://rb-proxy-sl.bosch.com:8080/
<6> 2021-02-22 10:52:55.397 +00:00 [INF] - Experimental features configuration: {"Enabled":false,"DisableCloudSubscriptions":false}
<6> 2021-02-22 10:52:55.522 +00:00 [INF] - Installing certificates [CN=Azure_IoT_Hub_CA_Cert:02/06/2036 16:47:37] to Root
<6> 2021-02-22 10:52:55.653 +00:00 [INF] - Starting metrics listener on Host: *, Port: 9600, Suffix: /metrics
<6> 2021-02-22 10:52:55.802 +00:00 [INF] - Updating performance metrics every 05m:00s
<6> 2021-02-22 10:52:55.806 +00:00 [INF] - Started operation Get system resources
<6> 2021-02-22 10:52:55.808 +00:00 [INF] - Collecting metadata metrics
<6> 2021-02-22 10:52:55.875 +00:00 [INF] - Set metadata metrics: 1.1.0.39334128 (92ac4878a4c8ca74c0db14cd2e63273f1c8661f4), {"Enabled":false,"DisableCloudSubscriptions":false}, {"OperatingSystemType":"linux","Architecture":"x86_64","Version":"1.1.0","Provisioning":{"Type":"manual.x509","DynamicReprovisioning":true},"ServerVersion":"19.03.15+azure","KernelVersion":"3.10.0-1160.15.2.el7.x86_64","OperatingSystem":"Red Hat Enterprise Linux","NumCpus":4,"Virtualized":"yes"}, True
<6> 2021-02-22 10:52:56.307 +00:00 [INF] - Created persistent store at /storage/edgeAgent
<6> 2021-02-22 10:52:56.328 +00:00 [INF] - Started operation Checkpoint Availability
<6> 2021-02-22 10:52:56.332 +00:00 [INF] - Started operation refresh twin config
<6> 2021-02-22 10:52:56.351 +00:00 [INF] - Edge agent attempting to connect to IoT Hub via Amqp_WebSocket_Only...
<6> 2021-02-22 10:52:56.384 +00:00 [INF] - Registering request handler UploadModuleLogs
<6> 2021-02-22 10:52:56.385 +00:00 [INF] - Registering request handler GetModuleLogs
<6> 2021-02-22 10:52:56.385 +00:00 [INF] - Registering request handler UploadSupportBundle
<6> 2021-02-22 10:52:56.385 +00:00 [INF] - Registering request handler RestartModule
<3> 2021-02-22 10:52:57.325 +00:00 [ERR] - Device client threw non-transient exception during setup
Microsoft.Azure.Devices.Client.Exceptions.UnauthorizedException: error(condition:amqp:unauthorized-access,description:Put token failed. status-code: 401, status-description: Unauthorized: Device 'bh0vm00005/$edgeAgent' at IotHub 'ioth-bhp-edge-qa' does not have PrimaryKey or SecondaryKey.)
---> Microsoft.Azure.Amqp.AmqpException: Put token failed. status-code: 401, status-description: Unauthorized: Device 'bh0vm00005/$edgeAgent' at IotHub 'ioth-bhp-edge-qa' does not have PrimaryKey or SecondaryKey.
at Microsoft.Azure.Amqp.ExceptionDispatcher.Throw(Exception exception)
at Microsoft.Azure.Amqp.AsyncResult.End[TAsyncResult](IAsyncResult result)
at Microsoft.Azure.Amqp.AsyncResult`1.End(IAsyncResult asyncResult)
at Microsoft.Azure.Amqp.AmqpCbsLink.EndSendToken(IAsyncResult result)
at Microsoft.Azure.Amqp.AmqpCbsLink.<>c__DisplayClass4_0.<SendTokenAsync>b__1(IAsyncResult a)
at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
--- End of stack trace from previous location where exception was thrown ---
at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpIoTCbsLink.SendTokenAsync(ICbsTokenProvider tokenProvider, Uri namespaceAddress, String audience, String resource, String[] requiredClaims, TimeSpan timeout)
--- End of inner exception stack trace ---
at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpIoTCbsLink.SendTokenAsync(ICbsTokenProvider tokenProvider, Uri namespaceAddress, String audience, String resource, String[] requiredClaims, TimeSpan timeout)
at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpAuthenticationRefresher.InitLoopAsync(TimeSpan timeout)
at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpIoTConnection.CreateRefresherAsync(DeviceIdentity deviceIdentity, TimeSpan timeout)
at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpConnectionHolder.CreateRefresherAsync(DeviceIdentity deviceIdentity, TimeSpan timeout)
at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpUnit.EnsureSessionAsync(TimeSpan timeout)
at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpUnit.OpenAsync(TimeSpan timeout)
at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.OpenAsync(CancellationToken cancellationToken)
at Microsoft.Azure.Devices.Client.Transport.ProtocolRoutingDelegatingHandler.OpenAsync(CancellationToken cancellationToken)
at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.<>c__DisplayClass23_0.<<ExecuteWithErrorHandlingAsync>b__0>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.ExecuteWithErrorHandlingAsync[T](Func`1 asyncOperation)
at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.<>c__DisplayClass33_0.<<OpenInternalAsync>b__0>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.EnsureOpenedAsync(CancellationToken cancellationToken)
at Microsoft.Azure.Devices.Client.InternalClient.OpenAsync()
at Microsoft.Azure.Devices.Edge.Agent.IoTHub.ModuleClientProvider.CreateAndOpenSdkModuleClient(UpstreamProtocol upstreamProtocol, ConnectionStatusChangesHandler statusChangedHandler) in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.IoTHub/ModuleClientProvider.cs:line 219
at Microsoft.Azure.Devices.Edge.Agent.IoTHub.ModuleClientProvider.<>c__DisplayClass19_0.<<CreateSdkModuleClient>b__0>d.MoveNext() in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.IoTHub/ModuleClientProvider.cs:line 170
--- End of stack trace from previous location where exception was thrown ---
at Microsoft.Azure.Devices.Edge.Agent.IoTHub.ModuleClientProvider.CreateSdkModuleClientWithRetry(ConnectionStatusChangesHandler statusChangedHandler) in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.IoTHub/ModuleClientProvider.cs:line 152
<6> 2021-02-22 10:52:57.343 +00:00 [INF] - Termination requested, initiating shutdown.
<6> 2021-02-22 10:52:57.343 +00:00 [INF] - Waiting for cleanup to finish
<4> 2021-02-22 10:53:01.667 +00:00 [WRN] - Empty edge agent config was received. Attempting to read config from backup (/storage/edgeAgent/backup.json) instead
<3> 2021-02-22 10:53:01.679 +00:00 [ERR] - Shutting down because no response from unix:///var/lib/iotedge/workload.sock for Decrypt
System.Net.Internals.SocketExceptionFactory+ExtendedSocketException (111): Connection refused /var/lib/iotedge/workload.sock
at System.Net.Sockets.Socket.DoConnect(EndPoint endPointSnapshot, SocketAddress socketAddress)
at System.Net.Sockets.Socket.Connect(EndPoint remoteEP)
at System.Net.Sockets.Socket.UnsafeBeginConnect(EndPoint remoteEP, AsyncCallback callback, Object state, Boolean flowContext)
at System.Net.Sockets.Socket.BeginConnect(EndPoint remoteEP, AsyncCallback callback, Object state)
at System.Net.Sockets.Socket.ConnectAsync(EndPoint remoteEP)
at System.Net.Sockets.SocketTaskExtensions.ConnectAsync(Socket socket, EndPoint remoteEP)
at Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler.GetConnectedSocketAsync() in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/uds/HttpUdsMessageHandler.cs:line 47
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 23
at System.Net.Http.HttpClient.FinishSendAsyncUnbuffered(Task`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts)
at Microsoft.Azure.Devices.Edge.Util.Edged.Version_2018_06_28.GeneratedCode.HttpWorkloadClient.DecryptAsync(String api_version, String name, String genid, DecryptRequest payload, CancellationToken cancellationToken) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/edged/version_2018_06_28/generatedCode/HttpWorkloadClient.cs:line 353
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 126
at Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClientVersioned.Execute[T](Func`1 func, String operation) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/edged/WorkloadClientVersioned.cs:line 59
2021-02-22 10:53:28 Starting Edge Agent
2021-02-22 10:53:28 Changing ownership of storage folder: /storage/edgeAgent to 1000
2021-02-22 10:53:28 Changing ownership of management socket: /var/lib/iotedge/mgmt.sock
2021-02-22 10:53:28.293 +00:00 Edge Agent Main()
<6> 2021-02-22 10:53:28.462 +00:00 [INF] - Initializing Edge Agent.
<6> 2021-02-22 10:53:28.617 +00:00 [INF] - Version - 1.1.0.39334128 (92ac4878a4c8ca74c0db14cd2e63273f1c8661f4)
<6> 2021-02-22 10:53:28.618 +00:00 [INF] -
█████╗ ███████╗██╗ ██╗██████╗ ███████╗
██╔══██╗╚══███╔╝██║ ██║██╔══██╗██╔════╝
███████║ ███╔╝ ██║ ██║██████╔╝█████╗
██╔══██║ ███╔╝ ██║ ██║██╔══██╗██╔══╝
██║ ██║███████╗╚██████╔╝██║ ██║███████╗
╚═╝ ╚═╝╚══════╝ ╚═════╝ ╚═╝ ╚═╝╚══════╝
██╗ ██████╗ ████████╗ ███████╗██████╗ ██████╗ ███████╗
██║██╔═══██╗╚══██╔══╝ ██╔════╝██╔══██╗██╔════╝ ██╔════╝
██║██║ ██║ ██║ █████╗ ██║ ██║██║ ███╗█████╗
██║██║ ██║ ██║ ██╔══╝ ██║ ██║██║ ██║██╔══╝
██║╚██████╔╝ ██║ ███████╗██████╔╝╚██████╔╝███████╗
╚═╝ ╚═════╝ ╚═╝ ╚══════╝╚═════╝ ╚═════╝ ╚══════╝
<6> 2021-02-22 10:53:28.633 +00:00 [INF] - Detected proxy http://rb-proxy-sl.bosch.com:8080/
<6> 2021-02-22 10:53:28.663 +00:00 [INF] - Experimental features configuration: {"Enabled":false,"DisableCloudSubscriptions":false}
<6> 2021-02-22 10:53:28.790 +00:00 [INF] - Installing certificates [CN=Azure_IoT_Hub_CA_Cert:02/06/2036 16:47:37] to Root
<6> 2021-02-22 10:53:28.932 +00:00 [INF] - Starting metrics listener on Host: *, Port: 9600, Suffix: /metrics
<6> 2021-02-22 10:53:29.091 +00:00 [INF] - Updating performance metrics every 05m:00s
<6> 2021-02-22 10:53:29.096 +00:00 [INF] - Started operation Get system resources
<6> 2021-02-22 10:53:29.098 +00:00 [INF] - Collecting metadata metrics
<6> 2021-02-22 10:53:29.168 +00:00 [INF] - Set metadata metrics: 1.1.0.39334128 (92ac4878a4c8ca74c0db14cd2e63273f1c8661f4), {"Enabled":false,"DisableCloudSubscriptions":false}, {"OperatingSystemType":"linux","Architecture":"x86_64","Version":"1.1.0","Provisioning":{"Type":"manual.x509","DynamicReprovisioning":true},"ServerVersion":"19.03.15+azure","KernelVersion":"3.10.0-1160.15.2.el7.x86_64","OperatingSystem":"Red Hat Enterprise Linux","NumCpus":4,"Virtualized":"yes"}, True
<6> 2021-02-22 10:53:29.619 +00:00 [INF] - Created persistent store at /storage/edgeAgent
<6> 2021-02-22 10:53:29.646 +00:00 [INF] - Started operation Checkpoint Availability
<6> 2021-02-22 10:53:29.650 +00:00 [INF] - Started operation refresh twin config
<6> 2021-02-22 10:53:29.670 +00:00 [INF] - Edge agent attempting to connect to IoT Hub via Amqp_WebSocket_Only...
<6> 2021-02-22 10:53:29.711 +00:00 [INF] - Registering request handler UploadModuleLogs
<6> 2021-02-22 10:53:29.711 +00:00 [INF] - Registering request handler GetModuleLogs
<6> 2021-02-22 10:53:29.711 +00:00 [INF] - Registering request handler UploadSupportBundle
<6> 2021-02-22 10:53:29.711 +00:00 [INF] - Registering request handler RestartModule
<3> 2021-02-22 10:53:30.709 +00:00 [ERR] - Device client threw non-transient exception during setup
Microsoft.Azure.Devices.Client.Exceptions.UnauthorizedException: error(condition:amqp:unauthorized-access,description:Put token failed. status-code: 401, status-description: Unauthorized: Device 'bh0vm00005/$edgeAgent' at IotHub 'ioth-bhp-edge-qa' does not have PrimaryKey or SecondaryKey.)
---> Microsoft.Azure.Amqp.AmqpException: Put token failed. status-code: 401, status-description: Unauthorized: Device 'bh0vm00005/$edgeAgent' at IotHub 'ioth-bhp-edge-qa' does not have PrimaryKey or SecondaryKey.
at Microsoft.Azure.Amqp.ExceptionDispatcher.Throw(Exception exception)
at Microsoft.Azure.Amqp.AsyncResult.End[TAsyncResult](IAsyncResult result)
at Microsoft.Azure.Amqp.AsyncResult`1.End(IAsyncResult asyncResult)
at Microsoft.Azure.Amqp.AmqpCbsLink.EndSendToken(IAsyncResult result)
at Microsoft.Azure.Amqp.AmqpCbsLink.<>c__DisplayClass4_0.<SendTokenAsync>b__1(IAsyncResult a)
at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
--- End of stack trace from previous location where exception was thrown ---
at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpIoTCbsLink.SendTokenAsync(ICbsTokenProvider tokenProvider, Uri namespaceAddress, String audience, String resource, String[] requiredClaims, TimeSpan timeout)
--- End of inner exception stack trace ---
at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpIoTCbsLink.SendTokenAsync(ICbsTokenProvider tokenProvider, Uri namespaceAddress, String audience, String resource, String[] requiredClaims, TimeSpan timeout)
at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpAuthenticationRefresher.InitLoopAsync(TimeSpan timeout)
at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpIoTConnection.CreateRefresherAsync(DeviceIdentity deviceIdentity, TimeSpan timeout)
at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpConnectionHolder.CreateRefresherAsync(DeviceIdentity deviceIdentity, TimeSpan timeout)
at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpUnit.EnsureSessionAsync(TimeSpan timeout)
at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpUnit.OpenAsync(TimeSpan timeout)
at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.OpenAsync(CancellationToken cancellationToken)
at Microsoft.Azure.Devices.Client.Transport.ProtocolRoutingDelegatingHandler.OpenAsync(CancellationToken cancellationToken)
at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.<>c__DisplayClass23_0.<<ExecuteWithErrorHandlingAsync>b__0>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.ExecuteWithErrorHandlingAsync[T](Func`1 asyncOperation)
at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.<>c__DisplayClass33_0.<<OpenInternalAsync>b__0>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.EnsureOpenedAsync(CancellationToken cancellationToken)
at Microsoft.Azure.Devices.Client.InternalClient.OpenAsync()
at Microsoft.Azure.Devices.Edge.Agent.IoTHub.ModuleClientProvider.CreateAndOpenSdkModuleClient(UpstreamProtocol upstreamProtocol, ConnectionStatusChangesHandler statusChangedHandler) in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.IoTHub/ModuleClientProvider.cs:line 219
at Microsoft.Azure.Devices.Edge.Agent.IoTHub.ModuleClientProvider.<>c__DisplayClass19_0.<<CreateSdkModuleClient>b__0>d.MoveNext() in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.IoTHub/ModuleClientProvider.cs:line 170
--- End of stack trace from previous location where exception was thrown ---
at Microsoft.Azure.Devices.Edge.Agent.IoTHub.ModuleClientProvider.CreateSdkModuleClientWithRetry(ConnectionStatusChangesHandler statusChangedHandler) in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.IoTHub/ModuleClientProvider.cs:line 152
<6> 2021-02-22 10:53:30.730 +00:00 [INF] - Termination requested, initiating shutdown.
<6> 2021-02-22 10:53:30.730 +00:00 [INF] - Waiting for cleanup to finish
<4> 2021-02-22 10:53:34.987 +00:00 [WRN] - Empty edge agent config was received. Attempting to read config from backup (/storage/edgeAgent/backup.json) instead
<3> 2021-02-22 10:53:35.001 +00:00 [ERR] - Shutting down because no response from unix:///var/lib/iotedge/workload.sock for Decrypt
System.Net.Internals.SocketExceptionFactory+ExtendedSocketException (111): Connection refused /var/lib/iotedge/workload.sock
at System.Net.Sockets.Socket.DoConnect(EndPoint endPointSnapshot, SocketAddress socketAddress)
at System.Net.Sockets.Socket.Connect(EndPoint remoteEP)
at System.Net.Sockets.Socket.UnsafeBeginConnect(EndPoint remoteEP, AsyncCallback callback, Object state, Boolean flowContext)
at System.Net.Sockets.Socket.BeginConnect(EndPoint remoteEP, AsyncCallback callback, Object state)
at System.Net.Sockets.Socket.ConnectAsync(EndPoint remoteEP)
at System.Net.Sockets.SocketTaskExtensions.ConnectAsync(Socket socket, EndPoint remoteEP)
at Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler.GetConnectedSocketAsync() in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/uds/HttpUdsMessageHandler.cs:line 47
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 23
at System.Net.Http.HttpClient.FinishSendAsyncUnbuffered(Task`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts)
at Microsoft.Azure.Devices.Edge.Util.Edged.Version_2018_06_28.GeneratedCode.HttpWorkloadClient.DecryptAsync(String api_version, String name, String genid, DecryptRequest payload, CancellationToken cancellationToken) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/edged/version_2018_06_28/generatedCode/HttpWorkloadClient.cs:line 353
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 126
at Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClientVersioned.Execute[T](Func`1 func, String operation) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/edged/WorkloadClientVersioned.cs:line 59
Additional Information
docker ps returns
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
3c05470c77f6 mcr.microsoft.com/azureiotedge-agent:1.1.0 "/bin/sh -c 'exec /a…" 5 days ago Up 17 seconds 0.0.0.0:8082->9600/tcp edgeAgent
So it caught my attention that the command shows that the container was created 5 days ago, while it restarts every few seconds; so my assumption is that the state of the container is just wrong/not updated. However I have dynamic_reprovisioning set to true and no clock skew. Could it matter the timezones of host (CET) and container (UTC) are not identical (but personally I don't believe that makes a difference)?
So this issue is related but not identical to https://github.com/Azure/iotedge/issues/4241 and https://github.com/Azure/iotedge/issues/3982. Please let me know if I was unclear or if I could contribute further information.
alaendle
All 4 comments
@alaendle Thanks for reporting this issue. We're investigating.
pmzara
on 23 Feb 2021
👍1
It's a bug. We only recreate the EA module identity in Hub if the EA container doesn't already exist.
You can work around it with docker rm -f edgeAgent, but of course the point of dynamic_reprovisioning: true is to not require manual intervention.
arsing
on 23 Feb 2021
❤1
This issue is being marked as stale because it has been open for 30 days with no activity.
![github-actions[bot] picture](https://avatars.githubusercontent.com/in/15368?v=4&s=40)
github-actions[bot]
on 2 Apr 2021
4833 should resolve this. Closing issue.
gordonwang0
on 22 Apr 2021
Was this page helpful?
0 / 5 - 0 ratings
Related issues
yenseaman
·
5Comments
josiahlaivins
·
6Comments
gauravagarwal28
·
4Comments
mathiash98
·
4Comments
asergaz
·
4Comments