Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

edgeHub crashes after changing config.yaml when configured for additional offline storage #1177

Closed
betsy-c opened this issue May 6, 2019 · 11 comments
Labels
1.0.7 Targeted for 1.0.7 release bug Something isn't working customer-reported iotedge

Comments

@betsy-c
Copy link

betsy-c commented May 6, 2019

Expected Behavior

Changing RuntimeLogLevel to “debug” in /etc/config.yaml and restarting the iotedge runtime (systemctl restart iotedge) when the edgeHub is configured for additional storage should change the log level of the edgeAgent and edgeHub and not cause the edgeHub to repeatedly crash.

Current Behavior

If I configure the edgeHub to use non-container storage (https://docs.microsoft.com/en-us/azure/iot-edge/offline-capabilities) and then edit the config.yaml file ( /etc/iotedge/config.yaml ) to change the RuntimeLogLevel and restart systemctl restart iotedge the edgeHub fails to come back up completely, logging that it received 500 Internal Server Error when making a call to the workload API to decrypt.

Changing the config.yaml file back to the way it was before and restarting again does not resolve the issue.

Steps to Reproduce

Create & change permissions on the directory for offline/non-container edgeHub storage if you haven’t already done so
sudo mkdir /etc/iotedge/strorage && sudo chown -R 1000:1000 /etc/iotedge/storage

Update your deployment.json to use this directory for storage. My systemModules section looks like the following:

"systemModules": {
    "edgeAgent": {
        "settings": {
            "image": "mcr.microsoft.com/azureiotedge-agent:1.0.6",
            "createOptions": ""
        },
        "type": "docker"
    },
    "edgeHub": {
        "settings": {
            "image": "mcr.microsoft.com/azureiotedge-hub:1.0.6",
            "createOptions": "{\"HostConfig\":{\"Binds\":[\"/etc/iotedge/storage/:/iotedge/storage/\"],\"PortBindings\":{\"8883/tcp\":[{\"HostPort\":\"8883\"}],\"443/tcp\":[{\"HostPort\":\"443\"}],\"5671/tcp\":[{\"HostPort\":\"5671\"}]}}}"
        },
        "type": "docker",
        "env": {
            "storageFolder": {
                "value": "/iotedge/storage/"
            }
        },
        "status": "running",
        "restartPolicy": "always"
    }
}

Deploy and make sure everything is working/that you are using the additional storage.

Edit /etc/iotedge/config.yaml and change RuntimeLogLevel to debug (or if you have it at debug, you can change it to info or whatever your favorite log level happens to be). Save your changes and then restart the edge runtime systemctl restart itoedge so the changes are applied.

If you follow the edgeHub and edge daemon logs, you should now see errors.
journalctl -u iotedge:

May 06 14:19:51 betsyc-iotedge9 iotedged[4327]: 2019-05-06T14:19:51Z [ERR!] - Internal server error: Could not decrypt
May 06 14:19:51 betsyc-iotedge9 iotedged[4327]:         caused by: A error occurred in the key store.
May 06 14:19:51 betsyc-iotedge9 iotedged[4327]:         caused by: HSM failure
May 06 14:19:51 betsyc-iotedge9 iotedged[4327]:         caused by: HSM API failure occurred: 417
May 06 14:19:51 betsyc-iotedge9 iotedged[4327]: 2019-05-06T14:19:51Z [INFO] - [work] - - - [2019-05-06 14:19:51.665964641 UTC] "POST /modules/%24edgeHub/genid/636927468235895329/decrypt?api-version=2018-06-28 HTTP/1.1" 500 Internal Server Error 150 "-" "-" pid(5198)

docker logs edgeHub:

2019-05-06 14:19:15.488 +00:00 [INF] [EdgeHub] - Starting Edge Hub
2019-05-06 14:19:15.489 +00:00 [INF] [EdgeHub] - 
        █████╗ ███████╗██╗   ██╗██████╗ ███████╗
       ██╔══██╗╚══███╔╝██║   ██║██╔══██╗██╔════╝
       ███████║  ███╔╝ ██║   ██║██████╔╝█████╗
       ██╔══██║ ███╔╝  ██║   ██║██╔══██╗██╔══╝
       ██║  ██║███████╗╚██████╔╝██║  ██║███████╗
       ╚═╝  ╚═╝╚══════╝ ╚═════╝ ╚═╝  ╚═╝╚══════╝

 ██╗ ██████╗ ████████╗    ███████╗██████╗  ██████╗ ███████╗
 ██║██╔═══██╗╚══██╔══╝    ██╔════╝██╔══██╗██╔════╝ ██╔════╝
 ██║██║   ██║   ██║       █████╗  ██║  ██║██║  ███╗█████╗
 ██║██║   ██║   ██║       ██╔══╝  ██║  ██║██║   ██║██╔══╝
 ██║╚██████╔╝   ██║       ███████╗██████╔╝╚██████╔╝███████╗
 ╚═╝ ╚═════╝    ╚═╝       ╚══════╝╚═════╝  ╚═════╝ ╚══════╝

2019-05-06 14:19:15.489 +00:00 [INF] [EdgeHub] - Version - 1.0.6.19913336 (8288bc9bd6f6e15295fea506cd3f99d7f6347a6a)
2019-05-06 14:19:15.491 +00:00 [INF] [EdgeHub] - Loaded server certificate with expiration date of "2019-08-04T13:52:25.0000000+00:00"
2019-05-06 14:19:15.523 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Created new message store
2019-05-06 14:19:15.523 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Started task to cleanup processed and stale messages
2019-05-06 14:19:15.592 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - Created DeviceConnectivityManager with connected check frequency 00:05:00 and disconnected check frequency 00:02:00
2019-05-06 14:19:20.350 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/workload.sock
2019-05-06 14:19:20.351 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/workload.sock
2019-05-06 14:19:20.351 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://workload.sock/modules/%24edgeHub/genid/636927468235895329/decrypt?api-version=2018-06-28
2019-05-06 14:19:20.354 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received InternalServerError
2019-05-06 14:19:20.354 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Retrying Http call to unix:///var/run/iotedge/workload.sock to Decrypt because of error Error, retry count = 3
2019-05-06 14:19:30.062 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/workload.sock
2019-05-06 14:19:30.063 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/workload.sock
2019-05-06 14:19:30.063 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://workload.sock/modules/%24edgeHub/genid/636927468235895329/decrypt?api-version=2018-06-28
2019-05-06 14:19:30.066 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received InternalServerError

Unhandled Exception: System.AggregateException: One or more errors occurred. (Error calling Decrypt: Could not decrypt
	caused by: A error occurred in the key store.
	caused by: HSM failure
	caused by: HSM API failure occurred: 417) ---> Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadCommunicationException: Error calling Decrypt: Could not decrypt
	caused by: A error occurred in the key store.
	caused by: HSM failure
	caused by: HSM API failure occurred: 417
   at Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient.Execute[T](Func`1 func, String operation) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/edged/WorkloadClient.cs:line 109
   at Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient.DecryptAsync(String initializationVector, String encryptedText) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/edged/WorkloadClient.cs:line 83
   at Microsoft.Azure.Devices.Edge.Storage.EncryptedStore`2.<>c__DisplayClass17_0.<<IterateBatch>b__0>d.MoveNext() in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Storage/EncryptedStore.cs:line 89
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Azure.Devices.Edge.Storage.RocksDb.ColumnFamilyDbStore.IterateBatch(Action`1 seeker, Int32 batchSize, Func`3 callback, CancellationToken cancellationToken) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Storage.RocksDb/ColumnFamilyDbStore.cs:line 162
   at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter(Task task, TimeSpan timeout) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 142
   at Microsoft.Azure.Devices.Edge.Hub.Core.DeviceScopeIdentitiesCache.ReadCacheFromStore(IKeyValueStore`2 encryptedStore) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/DeviceScopeIdentitiesCache.cs:line 135
   at Microsoft.Azure.Devices.Edge.Hub.Core.DeviceScopeIdentitiesCache.Create(IServiceProxy serviceProxy, IKeyValueStore`2 encryptedStorage, TimeSpan refreshRate) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/DeviceScopeIdentitiesCache.cs:line 55
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.CommonModule.<Load>b__17_9(IComponentContext c) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/CommonModule.cs:line 211
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.RoutingModule.<Load>b__20_10(IComponentContext c) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/RoutingModule.cs:line 193
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.RoutingModule.<Load>b__20_12(IComponentContext c) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/RoutingModule.cs:line 225
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.RoutingModule.<Load>b__20_25(IComponentContext c) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/RoutingModule.cs:line 392
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.RoutingModule.<Load>b__20_28(IComponentContext c) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/RoutingModule.cs:line 450
   at Microsoft.Azure.Devices.Edge.Hub.Service.Program.MainAsync(IConfigurationRoot configuration) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/Program.cs:line 62
   --- End of inner exception stack trace ---
   at System.Threading.Tasks.Task`1.GetResultCore(Boolean waitCompletionNotification)
   at Microsoft.Azure.Devices.Edge.Hub.Service.Program.Main() in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/Program.cs:line 30

Context (Environment)

Device (Host) Operating System

Ubuntu 18.04 LTS

Container Operating System

Linux Containers

Runtime Versions

iotedged

iotedge 1.0.6.1 (3fa6cbe)

Edge Agent

1.0.6

Edge Hub

1.0.6

Docker

3.0.5

Logs

edgedlogs.log

Additional Information

When the edgeHub is not configured for additional storage, I don’t see this issue. I can change the RuntimeLogLevel repeatedly and restart the runtime without issue.
After getting to this bad state, I can return to a workings state by stopping the runtime, clearing out the storage directory, and restarting the runtime.
systemctl stop iotedge
sudo rm -rf /etc/iotedge/storage/*
systemctl restart iotedge

@myagley
Copy link
Contributor

myagley commented May 6, 2019

Thank you for the bug report. You are running into this bug: #1082

This fix is in the 1.0.7 release which will be out today (in a couple of hours).

@myagley myagley added bug Something isn't working 1.0.7 Targeted for 1.0.7 release labels May 6, 2019
@mill5james
Copy link

Thanks for the heads up @myagley. Looking forward to the next release.

@myagley
Copy link
Contributor

myagley commented May 6, 2019

The release is out. The fix for this specific bug is in the daemon. To upgrade, you will need to update your local apt cache and upgrade:

apt-get update
apt-get install iotedge libiothsm-std

@BewaAutomatisierung-RD
Copy link

@myagley - Unfortunately updating does not work for me.

sudo apt-get install iotedge libiothsm-std

gives me the following output:

Reading package lists... Done
Building dependency tree
Reading state information... Done
libiothsm-std is already the newest version (1.0.6.1-1).
iotedge is already the newest version (1.0.6.1-1).
0 upgraded, 0 newly installed, 0 to remove and 68 not upgraded.

I get the same output for

sudo apt-get install libiothsm iotedge

which is recommended on https://docs.microsoft.com/de-de/azure/iot-edge/how-to-update-iot-edge#update-the-security-daemon

@myagley
Copy link
Contributor

myagley commented May 7, 2019

You will need to update the local package repository before installing:

apt-get update
apt-get install iotedge libiothsm-std

The first command contacts the remote repository to download the list of all new available packages. The second will actually download and install the new version.

@BewaAutomatisierung-RD
Copy link

@myagley - I used both commands but just added the output of the second.
I just used both commands one more time and again it did not work. Here is the output of both commands:

pi@raspberrypi:~ $ sudo apt-get update
Get:1 http://archive.raspberrypi.org/debian stretch InRelease [25.4 kB]
Get:2 http://raspbian.raspberrypi.org/raspbian stretch InRelease [15.0 kB]
Get:3 http://archive.raspberrypi.org/debian stretch/main armhf Packages [221 kB]
Fetched 262 kB in 8s (29.2 kB/s)
Reading package lists... Done
pi@raspberrypi:~ $ sudo apt-get install iotedge libiothsm-std
Reading package lists... Done
Building dependency tree
Reading state information... Done
libiothsm-std is already the newest version (1.0.6.1-1).
iotedge is already the newest version (1.0.6.1-1).
0 upgraded, 0 newly installed, 0 to remove and 68 not upgraded.

@BewaAutomatisierung-RD
Copy link

@myagley - Doing another installation as described here seems to do the trick.
After that I ran the update and install commands again and this time it said that its already version 1.0.7-1.
Here's the complete output:

pi@raspberrypi:~ $ curl -L https://aka.ms/libiothsm-std-linux-armhf-latest -o libiothsm-std.deb && sudo dpkg -i ./libiothsm-std.deb
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:--  0:00:06 --:--:--     0
100   622    0   622    0     0     50      0 --:--:--  0:00:12 --:--:--   167
100  513k  100  513k    0     0  27724      0  0:00:18  0:00:18 --:--:--  121k
(Reading database ... 34666 files and directories currently installed.)
Preparing to unpack ./libiothsm-std.deb ...
Unpacking libiothsm-std (1.0.7-1) over (1.0.6.1-1) ...
Setting up libiothsm-std (1.0.7-1) ...
pi@raspberrypi:~ $ curl -L https://aka.ms/iotedged-linux-armhf-latest -o iotedge.deb && sudo dpkg -i ./iotedge.deb
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:--  0:00:05 --:--:--     0
100   616    0   616    0     0     50      0 --:--:--  0:00:12 --:--:--   131
100 3993k  100 3993k    0     0   176k      0  0:00:22  0:00:22 --:--:--  948k
(Reading database ... 34666 files and directories currently installed.)
Preparing to unpack ./iotedge.deb ...
The user `iotedge' is already a member of `docker'.
Unpacking iotedge (1.0.7-1) over (1.0.6.1-1) ...
Setting up iotedge (1.0.7-1) ...

Configuration file '/etc/iotedge/config.yaml'
 ==> Modified (by you or by a script) since installation.
 ==> Package distributor has shipped an updated version.
   What would you like to do about it ?  Your options are:
    Y or I  : install the package maintainer's version
    N or O  : keep your currently-installed version
      D     : show the differences between the versions
      Z     : start a shell to examine the situation
 The default action is to keep your current version.
*** config.yaml (Y/I/N/O/D/Z) [default=N] ? n
===============================================================================

                              Azure IoT Edge

  IMPORTANT: Please update the configuration file located at:

    /etc/iotedge/config.yaml

  with your device's provisioning information. You will need to restart the
  'iotedge' service for these changes to take effect.

  To restart the 'iotedge' service, use:

    'systemctl restart iotedge'

    - OR -

    /etc/init.d/iotedge restart

  These commands may need to be run with sudo depending on your environment.

===============================================================================
Processing triggers for systemd (232-25+deb9u6) ...
Processing triggers for man-db (2.7.6.1-2) ...
pi@raspberrypi:~ $ sudo apt-get install -f
Reading package lists... Done
Building dependency tree
Reading state information... Done
0 upgraded, 0 newly installed, 0 to remove and 68 not upgraded.
pi@raspberrypi:~ $ sudo apt-get update
Hit:1 http://raspbian.raspberrypi.org/raspbian stretch InRelease
Hit:2 http://archive.raspberrypi.org/debian stretch InRelease
Reading package lists... Done
pi@raspberrypi:~ $ sudo apt-get install iotedge libiothsm-std
Reading package lists... Done
Building dependency tree
Reading state information... Done
libiothsm-std is already the newest version (1.0.7-1).
iotedge is already the newest version (1.0.7-1).
0 upgraded, 0 newly installed, 0 to remove and 68 not upgraded.

@ancaantochi
Copy link
Contributor

The commands you run from here installed 1.0.7 version, so when you run sudo apt-get install iotedge libiothsm-std it's already at version 1.0.7

Was the original issue with the storage solved after the update?

@myagley
Copy link
Contributor

myagley commented May 29, 2019

I'm going to close this issue, as it is fixed in 1.0.7. Please feel to reopen if you are still facing issues.

@myagley myagley closed this as completed May 29, 2019
@chriswue
Copy link

chriswue commented Oct 1, 2019

@myagley We just ran into this issue running iotedge 1.0.8 on the host with the 1.0.7.1 version of the edgeHub and edgeAgent modules:

[2019-10-01 02:54:30 : Starting Edge Hub
[10/01/2019 02:54:30.650 AM] Edge Hub Main()
[10/01/2019 02:54:31.930 AM] Found intermediate certificates: [CN=iotedged workload ca:12/30/2019 02:52:37],[CN=Test Edge Device CA:12/30/2019 02:52:37],[CN=Test Edge Owner CA:12/30/2019 02:52:37]
2019-10-01 02:54:33.058 +00:00 [INF] - Created persistent store at /iotedge/storage/edgeHub
2019-10-01 02:54:33.174 +00:00 [INF] - Starting Edge Hub
2019-10-01 02:54:33.175 +00:00 [INF] -
        █████╗ ███████╗██╗   ██╗██████╗ ███████╗
       ██╔══██╗╚══███╔╝██║   ██║██╔══██╗██╔════╝
       ███████║  ███╔╝ ██║   ██║██████╔╝█████╗
       ██╔══██║ ███╔╝  ██║   ██║██╔══██╗██╔══╝
       ██║  ██║███████╗╚██████╔╝██║  ██║███████╗
       ╚═╝  ╚═╝╚══════╝ ╚═════╝ ╚═╝  ╚═╝╚══════╝

 ██╗ ██████╗ ████████╗    ███████╗██████╗  ██████╗ ███████╗
 ██║██╔═══██╗╚══██╔══╝    ██╔════╝██╔══██╗██╔════╝ ██╔════╝
 ██║██║   ██║   ██║       █████╗  ██║  ██║██║  ███╗█████╗
 ██║██║   ██║   ██║       ██╔══╝  ██║  ██║██║   ██║██╔══╝
 ██║╚██████╔╝   ██║       ███████╗██████╔╝╚██████╔╝███████╗
 ╚═╝ ╚═════╝    ╚═╝       ╚══════╝╚═════╝  ╚═════╝ ╚══════╝

2019-10-01 02:54:33.176 +00:00 [INF] - Version - 1.0.7.1.22377503 (f7c51d92be8336bc6be042e1f1f2505ba01679f3)
2019-10-01 02:54:33.180 +00:00 [INF] - Loaded server certificate with expiration date of "2019-12-30T02:52:37.0000000+00:00"
2019-10-01 02:54:33.214 +00:00 [INF] - Created new message store
2019-10-01 02:54:33.219 +00:00 [INF] - Started task to cleanup processed and stale messages

Unhandled Exception: System.AggregateException: One or more errors occurred. (Error calling Decrypt: Could not decrypt
        caused by: An error occurred in the key store.
        caused by: HSM failure
        caused by: HSM API failure occurred: 428) ---> Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadCommunicationException: Error calling Decrypt: Could not decrypt
        caused by: An error occurred in the key store.
        caused by: HSM failure
        caused by: HSM API failure occurred: 428
   at Microsoft.Azure.Devices.Edge.Util.Edged.Version_2019_01_30.WorkloadClient.HandleException(Exception ex, String operation) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/edged/version_2019_01_30/WorkloadClient.cs:line 100
   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 57
   at Microsoft.Azure.Devices.Edge.Util.Edged.Version_2019_01_30.WorkloadClient.DecryptAsync(String initializationVector, String encryptedText) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/edged/version_2019_01_30/WorkloadClient.cs:line 73
   at Microsoft.Azure.Devices.Edge.Storage.EncryptedStore`2.<>c__DisplayClass17_0.<<IterateBatch>b__0>d.MoveNext() in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Storage/EncryptedStore.cs:line 89
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Azure.Devices.Edge.Storage.RocksDb.ColumnFamilyDbStore.IterateBatch(Action`1 seeker, Int32 batchSize, Func`3 callback, CancellationToken cancellationToken) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Storage.RocksDb/ColumnFamilyDbStore.cs:line 162
   at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter(Task task, TimeSpan timeout) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 142
   at Microsoft.Azure.Devices.Edge.Hub.Core.DeviceScopeIdentitiesCache.ReadCacheFromStore(IKeyValueStore`2 encryptedStore) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/DeviceScopeIdentitiesCache.cs:line 135
   at Microsoft.Azure.Devices.Edge.Hub.Core.DeviceScopeIdentitiesCache.Create(IServiceProxy serviceProxy, IKeyValueStore`2 encryptedStorage, TimeSpan refreshRate) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/DeviceScopeIdentitiesCache.cs:line 55
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.CommonModule.<Load>b__18_9(IComponentContext c) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/CommonModule.cs:line 216
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.RoutingModule.<Load>b__20_10(IComponentContext c) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/RoutingModule.cs:line 192
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.RoutingModule.<Load>b__20_12(IComponentContext c) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/RoutingModule.cs:line 224
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.RoutingModule.<Load>b__20_25(IComponentContext c) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/RoutingModule.cs:line 391
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.RoutingModule.<Load>b__20_29(IComponentContext c) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/RoutingModule.cs:line 463
   at Microsoft.Azure.Devices.Edge.Hub.Service.Program.MainAsync(IConfigurationRoot configuration) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/Program.cs:line 62
   --- End of inner exception stack trace ---
   at System.Threading.Tasks.Task`1.GetResultCore(Boolean waitCompletionNotification)
   at Microsoft.Azure.Devices.Edge.Hub.Service.Program.Main() in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/Program.cs:line 30

Version:

> iotedge --version
iotedge 1.0.8 (208b2204fd30e856d00b280112422130c104b9f0)

I've tried

sudo systemctl stop iotedge
sudo rm -rf /etc/iotedge/storage/*
sudo rm -rf /var/lib/iotedge/hsm/
sudo rm -rf /var/lib/iotedge/cache/
sudo systemctl start iotedge

but that doesn't help (results in the same error)

@chriswue
Copy link

chriswue commented Oct 1, 2019

Well, looks like the actual issue is different, just the symptom is the same:

I forgot we bind-mount a named volume for the edgeHub storage instead of /etc/iotedge/storage. After stopping iotedge and deleting the named volume and restarting iotedge caused the deployment to re-apply and re-create the named volume. At which point edgeHub successfully managed to start up. I'll create a new issue for this

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
1.0.7 Targeted for 1.0.7 release bug Something isn't working customer-reported iotedge
Projects
None yet
Development

No branches or pull requests

7 participants