Azure / iotedge

The IoT Edge OSS project
MIT License
1.46k stars 460 forks source link

edgeHub module won't start after certificate renewal #7397

Open DavidH-SG opened 1 day ago

DavidH-SG commented 1 day ago

Expected Behavior

edgeHub module restart successfuly after cert renewal

Current Behavior

edgeHub shuts down and stay in this state until manual restart

Steps to Reproduce

Just running iotEdge on a device. No perticular scenario

Context (Environment)

PROD

Output of iotedge check

Click here ``` ```

Device Information

Runtime Versions

Logs

aziot-edged logs ``` ov 17 09:35:41 016-AIZ aziot-edged[2336]: 2024-11-17T07:35:41Z [INFO] - Watchdog checking Edge runtime status Nov 17 09:35:41 016-AIZ aziot-edged[2336]: 2024-11-17T07:35:41Z [INFO] - Edge runtime is running Nov 17 09:36:17 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:17Z [INFO] - <-- POST /modules/%24edgeHub/genid/638192622530868516/sign?api-version=2020-07-07 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/json Nov 17 09:36:17 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:17Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - <-- GET /trust-bundle?api-version=2018-06-28 {"accept": "application/json", "host": "workload.sock:80", "connection": "close"} Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - <-- POST /modules/%24edgeHub/genid/638192622530868516/decrypt?api-version=2020-07-07 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/j Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - <-- POST /modules/%24edgeHub/genid/638192622530868516/encrypt?api-version=2020-07-07 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/j Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - <-- POST /modules/%24edgeHub/genid/638192622530868516/decrypt?api-version=2020-07-07 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/j Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - <-- POST /modules/%24edgeHub/genid/638192622530868516/encrypt?api-version=2020-07-07 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/j Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - <-- POST /modules/%24edgeHub/genid/638192622530868516/decrypt?api-version=2020-07-07 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/j Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - <-- POST /modules/%24edgeHub/genid/638192622530868516/decrypt?api-version=2020-07-07 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/j Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - <-- POST /modules/%24edgeHub/genid/638192622530868516/encrypt?api-version=2020-07-07 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/j Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - <-- GET /trust-bundle?api-version=2018-06-28 {"accept": "application/json", "host": "workload.sock:80", "connection": "close"} Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - <-- POST /modules/%24edgeHub/genid/638192622530868516/decrypt?api-version=2020-07-07 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/j Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - <-- POST /modules/%24edgeHub/genid/638192622530868516/decrypt?api-version=2020-07-07 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/j Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - <-- POST /modules/%24edgeHub/genid/638192622530868516/encrypt?api-version=2020-07-07 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/j Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - <-- POST /modules/%24edgeHub/genid/638192622530868516/decrypt?api-version=2020-07-07 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/j Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - <-- POST /modules/%24edgeHub/genid/638192622530868516/decrypt?api-version=2020-07-07 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/j Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - <-- POST /modules/%24edgeHub/genid/638192622530868516/encrypt?api-version=2020-07-07 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/j Nov 17 09:36:25 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:25Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:30 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:30Z [INFO] - <-- POST /modules/%24edgeHub/genid/638192622530868516/decrypt?api-version=2020-07-07 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/j Nov 17 09:36:30 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:30Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:30 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:30Z [INFO] - <-- POST /modules/%24edgeHub/genid/638192622530868516/decrypt?api-version=2020-07-07 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/j Nov 17 09:36:30 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:30Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:31 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:31Z [INFO] - <-- POST /modules/%24edgeHub/genid/638192622530868516/decrypt?api-version=2020-07-07 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/j Nov 17 09:36:31 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:31Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:31 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:31Z [INFO] - <-- POST /modules/%24edgeHub/genid/638192622530868516/encrypt?api-version=2020-07-07 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/j Nov 17 09:36:31 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:31Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:31 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:31Z [INFO] - <-- POST /modules/%24edgeHub/genid/638192622530868516/decrypt?api-version=2020-07-07 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/j Nov 17 09:36:31 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:31Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:36:41 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:41Z [INFO] - Watchdog checking Edge runtime status Nov 17 09:36:41 016-AIZ aziot-edged[2336]: 2024-11-17T07:36:41Z [INFO] - Edge runtime is running Nov 17 09:37:37 016-AIZ aziot-edged[2336]: 2024-11-17T07:37:37Z [INFO] - <-- GET /systeminfo/resources?api-version=2022-08-03 {"accept": "application/json", "host": "mgmt.sock:80", "connection": "close"} Nov 17 09:37:37 016-AIZ aziot-edged[2336]: 2024-11-17T07:37:37Z [INFO] - Querying system resources... Nov 17 09:37:41 016-AIZ aziot-edged[2336]: 2024-11-17T07:37:41Z [INFO] - Watchdog checking Edge runtime status Nov 17 09:37:41 016-AIZ aziot-edged[2336]: 2024-11-17T07:37:41Z [INFO] - Edge runtime is running Nov 17 09:37:51 016-AIZ aziot-edged[2336]: 2024-11-17T07:37:51Z [INFO] - --> 200 {"content-type": "application/json"} Nov 17 09:38:41 016-AIZ aziot-edged[2336]: 2024-11-17T07:38:41Z [INFO] - Watchdog checking Edge runtime status Nov 17 09:38:41 016-AIZ aziot-edged[2336]: 2024-11-17T07:38:41Z [INFO] - Edge runtime is running ```
edge-agent logs ``` <4> 2024-11-17 07:34:02.814 +00:00 [WRN] - Agent reconcile concluded with errors. System.TimeoutException: Operation timed out at Microsoft.Azure.Devices.Edge.Util.TaskEx.<>c.<.cctor>b__27_0() in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 114 at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter(Task task, TimeSpan timeout, Action action) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 160 at Microsoft.Azure.Devices.Edge.Agent.Service.Program.MainAsync(IConfiguration configuration) in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Service/Program.cs:line 271 <6> 2024-11-17 07:38:48.976 +00:00 [INF] - Starting periodic operation refresh twin config... <6> 2024-11-17 07:38:49.126 +00:00 [INF] - Obtained Edge agent twin from IoTHub with desired properties version 60 and reported properties version 334. <6> 2024-11-17 07:38:49.134 +00:00 [INF] - Successfully completed periodic operation refresh twin config ```
edge-hub logs ``` 2024-11-17 07:36:25.013 +00:00 [INF] - Restarting process to perform server certificate renewal. <6> 2024-11-17 07:36:25.021 +00:00 [INF] - Stopping the protocol heads... <6> 2024-11-17 07:36:25.029 +00:00 [INF] - Closing protocol heads - (MQTT, AMQP, HTTP) <6> 2024-11-17 07:36:25.037 +00:00 [INF] - Stopping MQTT protocol head <6> 2024-11-17 07:36:25.062 +00:00 [INF] - Closing link Events for ------ <6> 2024-11-17 07:36:25.062 +00:00 [INF] - Closing link TwinSending for ------ <6> 2024-11-17 07:36:25.063 +00:00 [INF] - Closing link TwinReceiving for ------ <6> 2024-11-17 07:36:25.064 +00:00 [INF] - Closing link Events for ------ <6> 2024-11-17 07:36:25.065 +00:00 [INF] - Closing link MethodSending for ------ <6> 2024-11-17 07:36:25.065 +00:00 [INF] - Closing link MethodReceiving for ------ <6> 2024-11-17 07:36:25.068 +00:00 [INF] - Closing HTTP head <6> 2024-11-17 07:36:25.069 +00:00 [INF] - Setting proxy inactive for ------ <6> 2024-11-17 07:36:25.069 +00:00 [INF] - Removing device connection for device ------ <6> 2024-11-17 07:36:25.066 +00:00 [INF] - Closing link TwinSending for ------ <6> 2024-11-17 07:36:25.072 +00:00 [INF] - Closing link TwinReceiving for ------ <6> 2024-11-17 07:36:25.073 +00:00 [INF] - Setting proxy inactive for ------ <6> 2024-11-17 07:36:25.073 +00:00 [INF] - Removing device connection for device ------ <6> 2024-11-17 07:36:25.082 +00:00 [INF] - Connection closed CorrelationId dd41fca5-8980-4c99-9ad2-e2db7345dd2a <6> 2024-11-17 07:36:25.089 +00:00 [INF] - Connection closed CorrelationId a4113baf-8da2-4724-96fd-ed22a358592c <6> 2024-11-17 07:36:25.105 +00:00 [INF] - "Request finished HTTP/1.1 GET https://016-aiz/$iothub/websocket - - - 101 - - 2018442415.1831ms" <6> 2024-11-17 07:36:25.106 +00:00 [INF] - "Request finished HTTP/1.1 GET https://016-aiz/$iothub/websocket - - - 101 - - 2591836583.4646ms" <6> 2024-11-17 07:36:25.126 +00:00 [INF] - Closed HTTP head <6> 2024-11-17 07:36:25.201 +00:00 [INF] - Closing receiver in cloud proxy 39a84d63-4339-4fb3-9716-f5ee5ea8b817 for ------ <6> 2024-11-17 07:36:25.201 +00:00 [INF] - Closed cloud proxy 39a84d63-4339-4fb3-9716-f5ee5ea8b817 for ------ <6> 2024-11-17 07:36:25.201 +00:00 [INF] - Device connection removed for device ------ <6> 2024-11-17 07:36:25.209 +00:00 [INF] - Remove device connection for device ------ <6> 2024-11-17 07:36:25.211 +00:00 [INF] - Closing receiver in cloud proxy 9b0cec60-74c6-4833-9acb-6030cebc63ac for ------ <6> 2024-11-17 07:36:25.212 +00:00 [INF] - Closed cloud proxy 9b0cec60-74c6-4833-9acb-6030cebc63ac for ------ <6> 2024-11-17 07:36:25.212 +00:00 [INF] - Device connection removed for device ------ <6> 2024-11-17 07:36:25.212 +00:00 [INF] - Remove device connection for device ------ <6> 2024-11-17 07:36:25.720 +00:00 [INF] - Updated reported properties for ------ <6> 2024-11-17 07:36:31.160 +00:00 [INF] - Updated reported properties for ------ <6> 2024-11-17 07:37:10.210 +00:00 [INF] - Stopped MQTT protocol head <6> 2024-11-17 07:37:10.210 +00:00 [INF] - Protocol heads stopped. <6> 2024-11-17 07:37:10.260 +00:00 [INF] - Shutdown complete. <6> 2024-11-17 07:37:10.270 +00:00 [INF] - Termination requested, initiating shutdown. <6> 2024-11-17 07:37:10.270 +00:00 [INF] - Waiting for cleanup to finish <6> 2024-11-17 07:37:10.270 +00:00 [INF] - Done with cleanup. Shutting down. 2024-11-18 14:41:05 Starting Edge Hub 2024-11-18 14:41:05 Starting Edge Hub ```

Additional Information

Please provide any additional information that may be helpful in understanding the issue.