Iotedge: Agent doesn't support Docker Health Checks

[arabold]

I've tried to add health checks to my Redis container deployed through Azure IoT Edge. I'm following the official Docker documentation and specify the Interval, Timeout and StartPeriod values in _nanoseconds_. This works as expected when running in the simulator. However, when deployed on a "real" Edge Server the agent fails.

This is the module configuration in my deployment.template.json:

"redis": {
  "version": "1.0",
  "type": "docker",
  "status": "running",
  "restartPolicy": "always",
  "settings": {
    "image": "redis:latest",
    "createOptions": {
      "HostConfig": {
        "Healthcheck": {
          "Test": [ "CMD-SHELL", "redis-cli ping || exit 1" ],
          "Interval": 15000000000,
          "Timeout": 5000000000,
          "Retries": 1,
          "StartPeriod": 300000000000
        },
        "Mounts": [
          {
            "Target": "/data",
            "Source": "redisDataVolume",
            "Type": "volume"
          }
        ]
      }
    }
  }
}

In addition I've added HEALTHCHECK statements to some of the Dockerfiles of my modules like this:

FROM node:10-alpine

# Install additional dependencie
RUN apk add --no-cache openssh git curl

WORKDIR /app
COPY . .
RUN npm run build

EXPOSE 4000
HEALTHCHECK --interval=15s --timeout=3s --start-period=5m \
  CMD curl -sf http://localhost:4000/.well-known/apollo/server-health || exit 1

USER node
CMD npm start

The error in the edgeAgent logs looks like this:

2019-04-22 15:12:16.749 +00:00 [INF] - Executing command: "Command Group: (
  [Update module mymodule]
  [Start module mymodule]
)"
2019-04-22 15:12:16.749 +00:00 [INF] - Executing command: "Update module mymodule"
2019-04-22 15:12:16.757 +00:00 [ERR] - Executing command for operation ["update"] failed.
Microsoft.Azure.Devices.Edge.Agent.Edgelet.EdgeletCommunicationException- Message:Error calling update module mymodule: An error occurred while authorizing the HTTP request
    caused by: A module runtime error occurred.
    caused by: Could not query module runtime state
    caused by: Container runtime error
    caused by: invalid value: integer `15000000000`, expected i32 at line 1 column 5406, StatusCode:404, at:   at Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient.Execute[T](Func`1 func, String operation) in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/ModuleManagementHttpClient.cs:line 205
   at Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient.UpdateModuleAsync(ModuleSpec moduleSpec) in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/ModuleManagementHttpClient.cs:line 162
   at Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory.LoggingCommand.ExecuteAsync(CancellationToken token) in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Core/LoggingCommandFactory.cs:line 60
2019-04-22 15:12:16.761 +00:00 [ERR] - Executing command for operation ["Command Group: (
  [Update module mymodule]
  [Start module mymodule]
)"] failed.
Microsoft.Azure.Devices.Edge.Agent.Edgelet.EdgeletCommunicationException- Message:Error calling update module mymodule: An error occurred while authorizing the HTTP request
    caused by: A module runtime error occurred.
    caused by: Could not query module runtime state
    caused by: Container runtime error
    caused by: invalid value: integer `15000000000`, expected i32 at line 1 column 5406, StatusCode:404, at:   at Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient.Execute[T](Func`1 func, String operation) in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/ModuleManagementHttpClient.cs:line 205
   at Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient.UpdateModuleAsync(ModuleSpec moduleSpec) in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/ModuleManagementHttpClient.cs:line 162
   at Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory.LoggingCommand.ExecuteAsync(CancellationToken token) in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Core/LoggingCommandFactory.cs:line 60
   at Microsoft.Azure.Devices.Edge.Agent.Core.Commands.GroupCommand.ExecuteAsync(CancellationToken token) in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Core/commands/GroupCommand.cs:line 35
   at Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory.LoggingCommand.ExecuteAsync(CancellationToken token) in /home/vsts/work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Core/LoggingCommandFactory.cs:line 60
2019-04-22 15:12:16.763 +00:00 [ERR] - Step failed in deployment 3, continuing execution. Failure when running command Command Group: (
  [Update module mymodule]
  [Start module mymodule]
). Will retry in 00s.

It certainly looks like the Edge Agent expects the timeout value to be in a different format.

Expected Behavior

The Edge Agent should accept Healthcheck properties as defined in the Docker documentation, specified in nanoseconds

Current Behavior

Specifying Healthcheck properties will prevent the modules from starting up properly

Steps to Reproduce

Add health checks to a module like shown in the example above. Running this in the simulator will work as expected. However, deploying it on an actual Edge Server will fail with above errors.

Context (Environment)

Device (Host) Operating System

Ubuntu 18.04.2 LTS

Architecture

amd64

Container Operating System

Runtime Versions

iotedged

1.0.6.1 (3fa6cbef8b7fc3c55a49a622735eb1021b8a5963)

Edge Agent

azureiotedge-agent:1.0

Edge Hub

azureiotedge-hub:1.0

Docker

Client:
 Version:           3.0.3
 API version:       1.40
 Go version:        go1.11.4
 Git commit:        48bd4c6d
 Built:             Wed Jan 23 16:17:56 2019
 OS/Arch:           linux/amd64
 Experimental:      false

Server:
 Engine:
  Version:          3.0.4
  API version:      1.40 (minimum version 1.12)
  Go version:       go1.11.4
  Git commit:       8ecd530
  Built:            Fri Jan 25 01:45:38 2019
  OS/Arch:          linux/amd64
  Experimental:     false
 containerd:
  Version:          v1.2.2
  GitCommit:        9754871865f7fe2f4e74d43e2fc7ccd237edcbce
 runc:
  Version:          1.0.0-rc6+dev
  GitCommit:        96ec2177ae841256168fcf76954f7177af9446eb
 docker-init:
  Version:          0.18.0
  GitCommit:        fec3683

Logs

See above

Additional Information

n/a

[mrohera]

Thanks for reporting this issue, as a quick test, could you kindly try out a value less than 2147483647 and see if this works for you. I think it would make sense to de-serialize this differently since the units are nano seconds.

[arsing]

Yes. Moby's swagger spec defines it as just type=integer, which is why our generated code uses i32. But the golang type is time.Duration which is 64-bit nanoseconds.

[arsing]

@arabold BTW, I believe you have a typo in your deployment.template.json. The Healthcheck property is a property of the createOptions itself, not createOptions.HostConfig, so it should be

"createOptions": {
    "Healthcheck": {
        "Test": [ "CMD-SHELL", "redis-cli ping || exit 1" ],
        "Interval": 15000000000,
        "Timeout": 5000000000,
        "Retries": 1,
        "StartPeriod": 300000000000
    },
    "HostConfig": { ... }
}

If you put it under HostConfig it will be ignored.