【发布时间】：2018-08-31 11:25:44
【问题描述】：
我正在尝试将一个模块部署到 iot-edge 设备中，因为我正在关注这些 Official Documentation。
- 已在其中创建了 IoTHub 订阅 Edge Device 已安装 我的本地机器上的 IoTEdge 运行时（就像模拟的一样 设备）
- Windows 的 Docker 已安装、启动并运行
（到目前为止一切正常，因为我检查了
Get-Service iotedge命令的状态） - 设置设备模块并将
mcr.microsoft.com/azureiotedge-simulated-temperature-sensor:1.0用作图像
在 Microsoft Azure 门户上设置模块后，edgeHub 模块进入退避状态。我已经看到这个问题IOT-Edge Hub back-off state 并尝试按照一些 cmets 的建议重新启动 docker，但都是徒劳的。
我还运行了docker logs edgeAgent 命令向您展示了一些日志，这些日志附在这篇文章中。
编辑： 附件是来自 Azure 的状态
而这个是iotedgeruntime的状态
编辑 2
我在 azure 上重新创建了 iotedge 设备，然后在我的 Windows 机器上重新安装了 iotedgeruntime。无需创建模块。以下是日志
> iotedge logs edgeAgent
[09/03/2018 10:22:32.855 AM] Edge Agent Main()
2018-09-03 15:22:33.043 +05:00 [INF] - Starting module management agent.
2018-09-03 15:22:33.182 +05:00 [INF] - Version - 1.0.1.15962126 (6e5e86dcf0c9a3732fc72a64d9ec9b0fcb2d6fad)
2018-09-03 15:22:33.298 +05:00 [INF] - Edge agent attempting to connect to IoT Hub via Amqp_Tcp_Only...
2018-09-03 15:22:34.360 +05:00 [INF] - Created persistent store at C:\Users\ContainerAdministrator\AppData\Local\Temp\edgeAgent
2018-09-03 15:22:39.749 +05:00 [WRN] - Empty edge agent config was received. Attempting to read config from backup file (backup.json) instead
2018-09-03 15:22:39.751 +05:00 [INF] - Edge agent config backup file does not exist - backup.json
2018-09-03 15:22:43.239 +05:00 [INF] - Edge agent connected to IoT Hub via Amqp_Tcp_Only.
2018-09-03 15:22:46.031 +05:00 [INF] - Deployment config in edge agent's desired properties is empty.
2018-09-03 15:22:46.050 +05:00 [ERR] - Error refreshing edge agent configuration from twin.
Microsoft.Azure.Devices.Edge.Agent.Core.ConfigSources.ConfigEmptyException: This device has an empty configuration for the edge agent. Please set a deployment manifest.
at Microsoft.Azure.Devices.Edge.Agent.IoTHub.EdgeAgentConnection.UpdateDeploymentConfig() in C:\agent\_work\1\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.IoTHub\EdgeAgentConnection.cs:line 187
at Microsoft.Azure.Devices.Edge.Agent.IoTHub.EdgeAgentConnection.RefreshTwinAsync() in C:\agent\_work\1\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.IoTHub\EdgeAgentConnection.cs:line 148
此日志显示 EdgeAgent 已启动，但在使用空部署配置时出现问题。所以我创建了一个空配置。这里提到https://github.com/Azure/iot-edge-v1/issues/441#issuecomment-350824433。然后出现了同样的问题。显示以下命令的日志。
> Get-WinEvent -ea SilentlyContinue `-FilterHashtable @{ProviderName="iotedged"; LogName = "application"; StartTime = [datetime]::Today} |select TimeCreated, Message |sort-object @{Expression="TimeCreated";Descending=$false} |format-table -autosize -wrap
日志文件
TimeCreated Message
----------- -------
9/3/2018 3:22:07 PM info: iotedged::app -- Starting Azure IoT Edge Security Daemon
9/3/2018 3:22:07 PM info: iotedged -- Initializing the module runtime...
9/3/2018 3:22:07 PM info: iotedged -- Using runtime network id nat
9/3/2018 3:22:07 PM info: iotedged::app -- Version - 1.0.0 (52ef77db24126bf473265fc09c53d35290a2dd6b)
9/3/2018 3:22:07 PM info: iotedged::app -- Using config file: C:\ProgramData\iotedge\config.yaml
9/3/2018 3:22:07 PM info: iotedged::windows -- Starting iotedged service.
9/3/2018 3:22:07 PM info: iotedged -- Configuring C:\ProgramData\iotedge as the home directory.
9/3/2018 3:22:07 PM info: iotedged -- Finished initializing the module runtime.
9/3/2018 3:22:07 PM info: iotedged -- Transparent gateway certificates not found, operating in quick start mode...
9/3/2018 3:22:07 PM info: iotedged -- Finished configuring certificates.
9/3/2018 3:22:07 PM info: iotedged -- Initializing hsm...
9/3/2018 3:22:07 PM info: iotedged -- Configuring certificates...
9/3/2018 3:22:08 PM info: iotedged -- Finished initializing hsm.
9/3/2018 3:22:08 PM info: iotedged -- Detecting if configuration file has changed...
9/3/2018 3:22:08 PM info: iotedged -- Change to configuration file detected.
9/3/2018 3:22:08 PM info: iotedged -- Removing all modules...
9/3/2018 3:22:09 PM info: iotedged -- Finished removing modules.
9/3/2018 3:22:09 PM info: iotedged -- Provisioning edge device...
9/3/2018 3:28:09 PM info: edgelet_core::watchdog -- Checking edge runtime status
9/3/2018 3:28:09 PM info: edgelet_core::watchdog -- Edge runtime is running.
9/3/2018 3:28:12 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:28:12.431950 UTC] "GET /modules?api-version=2018-06-28 HTTP/1.1" 200 OK 449 "-" "-" pid(any)
9/3/2018 3:28:17 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:28:17.442486300 UTC] "GET /modules?api-version=2018-06-28 HTTP/1.1" 200 OK 449 "-" "-" pid(any)
9/3/2018 3:28:22 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:28:22.448494200 UTC] "GET /modules?api-version=2018-06-28 HTTP/1.1" 200 OK 449 "-" "-" pid(any)
9/3/2018 3:28:27 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:28:27.469429300 UTC] "GET /modules?api-version=2018-06-28 HTTP/1.1" 200 OK 449 "-" "-" pid(any)
9/3/2018 3:28:32 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:28:32.471719400 UTC] "GET /modules?api-version=2018-06-28 HTTP/1.1" 200 OK 449 "-" "-" pid(any)
9/3/2018 3:28:37 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:28:37.485219700 UTC] "GET /modules?api-version=2018-06-28 HTTP/1.1" 200 OK 449 "-" "-" pid(any)
9/3/2018 3:28:42 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:28:42.500957700 UTC] "GET /modules?api-version=2018-06-28 HTTP/1.1" 200 OK 449 "-" "-" pid(any)
9/3/2018 3:28:47 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:28:47.511517800 UTC] "GET /modules?api-version=2018-06-28 HTTP/1.1" 200 OK 449 "-" "-" pid(any)
9/3/2018 3:28:52 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:28:52.517649100 UTC] "GET /modules?api-version=2018-06-28 HTTP/1.1" 200 OK 449 "-" "-" pid(any)
9/3/2018 3:28:57 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:28:57.533708400 UTC] "GET /modules?api-version=2018-06-28 HTTP/1.1" 200 OK 449 "-" "-" pid(any)
9/3/2018 3:29:02 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:29:02.543274600 UTC] "GET /modules?api-version=2018-06-28 HTTP/1.1" 200 OK 449 "-" "-" pid(any)
9/3/2018 3:29:07 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:29:07.554093 UTC] "GET /modules?api-version=2018-06-28 HTTP/1.1" 200 OK 449 "-" "-" pid(any)
9/3/2018 3:29:09 PM info: edgelet_core::watchdog -- Checking edge runtime status
9/3/2018 3:29:09 PM info: edgelet_core::watchdog -- Edge runtime is running.
9/3/2018 3:29:12 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:29:12.567305200 UTC] "GET /modules?api-version=2018-06-28 HTTP/1.1" 200 OK 449 "-" "-" pid(any)
9/3/2018 3:29:17 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:29:17.575885700 UTC] "GET /modules?api-version=2018-06-28 HTTP/1.1" 200 OK 449 "-" "-" pid(any)
9/3/2018 3:29:22 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:29:22.590898700 UTC] "GET /modules?api-version=2018-06-28 HTTP/1.1" 200 OK 449 "-" "-" pid(any)
9/3/2018 3:29:27 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:29:27.599495900 UTC] "GET /modules?api-version=2018-06-28 HTTP/1.1" 200 OK 449 "-" "-" pid(any)
9/3/2018 3:29:32 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:29:32.611798600 UTC] "GET /modules?api-version=2018-06-28 HTTP/1.1" 200 OK 449 "-" "-" pid(any)
9/3/2018 3:29:37 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:29:37.620460100 UTC] "GET /modules?api-version=2018-06-28 HTTP/1.1" 200 OK 449 "-" "-" pid(any)
9/3/2018 3:29:42 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:29:42.621030200 UTC] "GET /modules?api-version=2018-06-28 HTTP/1.1" 200 OK 449 "-" "-" pid(any)
9/3/2018 3:29:42 PM info: edgelet_http::logging -- [work] - - - [2018-09-03 10:29:42.745729500 UTC] "POST /modules/%24edgeAgent/genid/636715662943777437/encrypt?api-version=2018-06-28 HTTP/1.1" 200 OK 985 "-" "-" pid(any)
9/3/2018 3:29:43 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:29:43.740061700 UTC] "GET /identities/?api-version=2018-06-28 HTTP/1.1" 200 OK 210 "-" "-" pid(any)
9/3/2018 3:29:44 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:29:44.067628900 UTC] "PUT /identities/%24edgeHub?api-version=2018-06-28 HTTP/1.1" 200 OK 98 "-" "-" pid(any)
9/3/2018 3:29:46 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:29:46.999173700 UTC] "POST /modules?api-version=2018-06-28 HTTP/1.1" 201 Created 908 "-" "-" pid(any)
9/3/2018 3:29:47 PM warn: edgelet_utils::logging -- Container runtime error - ApiError(ApiError { code: InternalServerError, content: Some(Object({"message": String("failed to create endpoint edgeHub on network nat: HNS failed with error : The process
cannot access the file because it is being used by another process. ")})) })
9/3/2018 3:29:47 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:29:47.247618 UTC] "POST /modules/edgeHub/start?api-version=2018-06-28 HTTP/1.1" 500 Internal Server Error 294 "-" "-" pid(any)
9/3/2018 3:29:47 PM warn: edgelet_utils::logging -- Container runtime error - ApiError(ApiError { code: InternalServerError, content: Some(Object({"message": String("failed to create endpoint edgeHub on network nat: HNS failed with error : The process
cannot access the file because it is being used by another process. ")})) })
9/3/2018 3:29:47 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:29:47.460481300 UTC] "POST /modules/edgeHub/start?api-version=2018-06-28 HTTP/1.1" 500 Internal Server Error 294 "-" "-" pid(any)
9/3/2018 3:29:52 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:29:52.039166500 UTC] "POST /modules/edgeHub/start?api-version=2018-06-28 HTTP/1.1" 500 Internal Server Error 294 "-" "-" pid(any)
9/3/2018 3:29:52 PM warn: edgelet_utils::logging -- Container runtime error - ApiError(ApiError { code: InternalServerError, content: Some(Object({"message": String("failed to create endpoint edgeHub on network nat: HNS failed with error : The process
cannot access the file because it is being used by another process. ")})) })
9/3/2018 3:29:58 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:29:58.058868200 UTC] "GET /modules/edgeAgent/logs?api-version=2018-06-28&follow=false&tail=all HTTP/1.1" 200 OK - "-" "iotedge/0.1.0" pid(any)
9/3/2018 3:30:03 PM warn: edgelet_utils::logging -- Container runtime error - ApiError(ApiError { code: InternalServerError, content: Some(Object({"message": String("failed to create endpoint edgeHub on network nat: HNS failed with error : The process
cannot access the file because it is being used by another process. ")})) })
9/3/2018 3:30:03 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:30:03.261676500 UTC] "POST /modules/edgeHub/start?api-version=2018-06-28 HTTP/1.1" 500 Internal Server Error 294 "-" "-" pid(any)
9/3/2018 3:30:03 PM info: edgelet_http::logging -- [work] - - - [2018-09-03 10:30:03.317280 UTC] "POST /modules/%24edgeAgent/genid/636715662943777437/encrypt?api-version=2018-06-28 HTTP/1.1" 200 OK 985 "-" "-" pid(any)
9/3/2018 3:30:08 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:30:08.632153200 UTC] "GET /modules?api-version=2018-06-28 HTTP/1.1" 200 OK 831 "-" "-" pid(any)
9/3/2018 3:30:08 PM info: edgelet_http::logging -- [work] - - - [2018-09-03 10:30:08.633152900 UTC] "POST /modules/%24edgeAgent/genid/636715662943777437/encrypt?api-version=2018-06-28 HTTP/1.1" 200 OK 985 "-" "-" pid(any)
9/3/2018 3:30:08 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:30:08.802696300 UTC] "POST /modules/edgeHub/stop?api-version=2018-06-28 HTTP/1.1" 304 Not Modified - "-" "-" pid(any)
9/3/2018 3:30:08 PM warn: edgelet_utils::logging -- Container already in this state
9/3/2018 3:30:08 PM warn: edgelet_utils::logging -- Container runtime error - ApiError(ApiError { code: InternalServerError, content: Some(Object({"message": String("failed to create endpoint edgeHub on network nat: HNS failed with error : The process
cannot access the file because it is being used by another process. ")})) })
9/3/2018 3:30:08 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:30:08.929044700 UTC] "POST /modules/edgeHub/start?api-version=2018-06-28 HTTP/1.1" 500 Internal Server Error 294 "-" "-" pid(any)
9/3/2018 3:30:09 PM info: edgelet_core::watchdog -- Checking edge runtime status
9/3/2018 3:30:09 PM info: edgelet_core::watchdog -- Edge runtime is running.
9/3/2018 3:30:09 PM warn: edgelet_utils::logging -- Container runtime error - ApiError(ApiError { code: InternalServerError, content: Some(Object({"message": String("failed to create endpoint edgeHub on network nat: HNS failed with error : The process
cannot access the file because it is being used by another process. ")})) })
9/3/2018 3:30:09 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:30:09.086215200 UTC] "POST /modules/edgeHub/start?api-version=2018-06-28 HTTP/1.1" 500 Internal Server Error 294 "-" "-" pid(any)
9/3/2018 3:30:14 PM warn: edgelet_utils::logging -- Container runtime error - ApiError(ApiError { code: InternalServerError, content: Some(Object({"message": String("failed to create endpoint edgeHub on network nat: HNS failed with error : The process
cannot access the file because it is being used by another process. ")})) })
9/3/2018 3:30:14 PM info: edgelet_http::logging -- [mgmt] - - - [2018-09-03 10:30:14.661189 UTC] "POST /modules/edgeHub/start?api-version=2018-06-28 HTTP/1.1" 500 Internal Server Error 294 "-" "-" pid(any)
它最初显示 edgeAgent 已启动，但一旦部署一个模块，它就会显示与我上面提到的相同的错误。
【问题讨论】：
-
您是否尝试在不同的网络上添加 edgeHub？从 edgeAgent 日志中，我看到它正在尝试将 edgeHub 添加到 HN 网络中？我在日志中看到的另一件事是 edgeAgent 尝试与 docker 通信以创建 edgeHub 时出现问题。既然你在windows上，你能得到服务日志并分享吗？按照此处的步骤操作：docs.microsoft.com/en-us/azure/iot-edge/troubleshoot。最后，随意打开一个github问题，我相信那里有一个关于退避的问题，不知道是不是你的。
-
我不想在不同的网络上添加 edgeHub，只是按照文档进行操作。不知道它是否这样做（因为我对这一切都很陌生）。我也在 GitHub 上打开了这个问题。 github.com/Azure/iotedge/issues/240
-
@AngeloRibeiro 我更新了我的帖子。看看吧。
-
是的，从日志来看，docker 创建 edgeHub 容器存在一些问题。这是问题发生时的行：9/3/2018 3:29:47 PM warn: edgelet_utils::logging -- 容器运行时错误 - ApiError(ApiError { code: InternalServerError, content: Some(Object({"message" : String("在网络 nat 上创建端点 edgeHub 失败：HNS 失败并出现错误：进程无法访问该文件，因为它正被另一个进程使用。")})) })
标签： docker azure-iot-hub azure-iot-edge