Nomad agent fails to start Docker container when client data_dir is a relative path

[agy]

Problem

While following the getting-started instructions I discovered that the Nomad agent fails to start a Docker container when the Nomad client's data_dir is configured as a relative path.

/config/server.json:

{
    "log_level": "DEBUG",
    "data_dir": "/data",
    "server": {
        "enabled": true,
        "bootstrap_expect": 1
    }
}

/config/client.json:

{
    "log_level": "DEBUG",
    "data_dir": "./client-data",
    "client": {
        "enabled": true,
        "servers": [
            "127.0.0.1:4647"
        ]
    },
    "ports": {
        "http": 5656
    }
}

How to reproduce:

• Start Nomad server

$ /usr/local/bin/nomad agent -config=/config/server.json
...

• Start Nomand client (with relative data_dir path)

$ /usr/local/bin/nomad agent -config=/config/client.json
...
2015/12/08 17:23:13 [INFO] client: using state directory client-data/client
2015/12/08 17:23:13 [INFO] client: using alloc directory client-data/alloc
...

• Create an example job

$ /usr/local/bin/nomad init
Example job file written to example.nomad

• Run the example job

$ /usr/local/bin/nomad run example.nomad
==> Monitoring evaluation "36c18a14-8947-7d87-dbe3-699b19114f21"
    Evaluation triggered by job "example"
    Allocation "b0c89939-de51-d779-1675-de403a428894" created: node "9d58108b-1dee-83f4-8368-a4b4326d15f6", group "cache"
    Evaluation status changed: "pending" -> "complete"
==> Evaluation "36c18a14-8947-7d87-dbe3-699b19114f21" finished with status "complete"

• Wait for a while (the container needs to be pulled) and then see the failure in the client output

...
2015/12/08 17:12:08 [DEBUG] driver.docker: docker pull redis:latest succeeded
2015/12/08 17:12:08 [DEBUG] driver.docker: identified image redis:latest as 0643f0c7d17d348881b2dab88cfdb57ad86dcf32ea22bd0b2cd0957b6c7ab8c3
2015/12/08 17:12:08 [DEBUG] driver.docker: using 268435456 bytes memory for redis:latest
2015/12/08 17:12:08 [DEBUG] driver.docker: using 500 cpu shares for redis:latest
2015/12/08 17:12:08 [DEBUG] driver.docker: binding directories []string{"client-data/alloc/b0c89939-de51-d779-1675-de403a428894/alloc:/alloc:rw,z", "client-data/alloc/b0c89939-de51-d779-1675-de403a428894/redis:/local:rw,Z"} for redis:latest
2015/12/08 17:12:08 [DEBUG] driver.docker: networking mode not specified; defaulting to bridge
2015/12/08 17:12:08 [DEBUG] driver.docker: allocated port 23.253.23.86:42378 -> 6379 (mapped)
2015/12/08 17:12:08 [DEBUG] driver.docker: exposed port 6379
2015/12/08 17:12:08 [DEBUG] driver.docker: setting container name to: redis-b0c89939-de51-d779-1675-de403a428894
2015/12/08 17:12:08 [ERR] driver.docker: failed to create container from image redis:latest: API error (400): client-data/alloc/b0c89939-de51-d779-1675-de403a428894/alloc includes invalid characters for a local volume name, only [a-zA-Z0-9][a-zA-Z0-9_.-] are allowed
2015/12/08 17:12:08 [ERR] client: failed to start task 'redis' for alloc 'b0c89939-de51-d779-1675-de403a428894': Failed to create container from image redis:latest: API error (400): client-data/alloc/b0c89939-de51-d779-1675-de403a428894/alloc includes invalid characters for a local volume name, only [a-zA-Z0-9][a-zA-Z0-9_.-] are allowed
2015/12/08 17:12:08 [DEBUG] client: updated allocations at index 1333 (1 allocs)
2015/12/08 17:12:08 [DEBUG] client: allocs: (added 0) (removed 0) (updated 1) (ignore 0)
...

• See the error in /var/log/upstart/docker.log (the log output includes the whitespace for some reason)

...
INFO[69770] POST /images/create?fromImage=redis&tag=latest
INFO[69832] GET /images/redis:latest/json
INFO[69832] POST /containers/create?name=redis-b0c89939-de51-d779-1675-de403a428894
ERRO[69832] Handler for POST /containers/create returned error: client-data/alloc/b0c89939-de51-d779-1675-de403a428894/alloc includes invalid characters for a local volume name, only [a-zA-Z0-9][a-zA-Z0-9_.-] are allowed
ERRO[69832] HTTP Error                                    err=client-data/alloc/b0c89939-de51-d779-1675-de403a428894/alloc includes invalid characters for a local volume name, only [a-zA-Z0-9][a-zA-Z0-9_.-] are allowed statusCode=400
...

• Note that the ./client-data directory is populated with alloc and client directories

Workaround:

To work around the problem, ensure that the client's data_dir is a full path to the client's data directory. Restart the client to ensure that the config takes effect.

• Stop the previous job from running

$ /usr/local/bin/nomad stop example

• Restart the client with the reconfigured data_dir (see config below)

$ /usr/local/bin/nomad agent -config=/config/client.json
...
2015/12/08 17:24:24 [INFO] client: using state directory /data/client-data/client
2015/12/08 17:24:24 [INFO] client: using alloc directory /data/client-data/alloc
...

• Re-run the example job

$ /usr/local/bin/nomad run example.nomad

• See that it works as expected

...
2015/12/08 17:26:48 [DEBUG] client: starting runner for alloc '2df4730c-1ce9-b817-531e-1e3e74f7e208'
2015/12/08 17:26:48 [DEBUG] client: starting task context for 'redis' (alloc '2df4730c-1ce9-b817-531e-1e3e74f7e208')
2015/12/08 17:26:48 [DEBUG] driver.docker: using client connection initialized from environment
2015/12/08 17:26:49 [DEBUG] driver.docker: docker pull redis:latest succeeded
2015/12/08 17:26:49 [DEBUG] driver.docker: identified image redis:latest as 0643f0c7d17d348881b2dab88cfdb57ad86dcf32ea22bd0b2cd0957b6c7ab8c3
2015/12/08 17:26:49 [DEBUG] driver.docker: using 268435456 bytes memory for redis:latest
2015/12/08 17:26:49 [DEBUG] driver.docker: using 500 cpu shares for redis:latest
2015/12/08 17:26:49 [DEBUG] driver.docker: binding directories []string{"/data/client-data/alloc/2df4730c-1ce9-b817-531e-1e3e74f7e208/alloc:/alloc:rw,z", "/data/client-data/alloc/2df4730c-1ce9-b817-531e-1e3e74f7e208/redis:/local:rw,Z"} for redis:latest
2015/12/08 17:26:49 [DEBUG] driver.docker: networking mode not specified; defaulting to bridge
2015/12/08 17:26:49 [DEBUG] driver.docker: allocated port 23.253.23.86:55692 -> 6379 (mapped)
2015/12/08 17:26:49 [DEBUG] driver.docker: exposed port 6379
2015/12/08 17:26:49 [DEBUG] driver.docker: setting container name to: redis-2df4730c-1ce9-b817-531e-1e3e74f7e208
2015/12/08 17:26:49 [INFO] driver.docker: created container d4c4f119aa63243efa519fad1908fe0ed99ecff0a69174548ff7c8aadca53462
2015/12/08 17:26:50 [INFO] driver.docker: started container d4c4f119aa63243efa519fad1908fe0ed99ecff0a69174548ff7c8aadca53462
...

Example working /config/client.json:

{
    "log_level": "DEBUG",
    "data_dir": "/data/client-data",
    "client": {
        "enabled": true,
        "servers": [
            "127.0.0.1:4647"
        ]
    },
    "ports": {
        "http": 5656
    }
}

Software versions:

$ nomad --version
Nomad v0.2.1

$ docker version
Client:
 Version:      1.9.1
 API version:  1.21
 Go version:   go1.4.3
 Git commit:   a34a1d5
 Built:        Fri Nov 20 17:56:04 UTC 2015
 OS/Arch:      linux/amd64

Server:
 Version:      1.9.1
 API version:  1.21
 Go version:   go1.4.3
 Git commit:   a34a1d5
 Built:        Fri Nov 20 17:56:04 UTC 2015
 OS/Arch:      linux/amd64

Please let me know if you need any further information?

[cbednarski]

Thanks for the report.

To work around the problem, ensure that the client's data_dir is a full path to the client's data directory. Restart the client to ensure that the config takes effect.

I think if I understand correctly we should change the documentation to say that this must be an absolute path, not a relative path. We can validate this during config parsing also.

The problem is if this is relative... to what is it relative? The config file? The directory where you invoke the nomad command? What about when you start it with upstart? All three cases will get a different path.

By default data_dir sets the root directory for storage, and the client and server data will be placed under $data_dir/client and $data_dir/server respectively, so you can set both of them to the same thing. In our default config we recommend /var/lib/nomad which means your data will live under /var/lib/nomad/client and /var/lib/nomad/server.

[agy]

Updating the documentation along with config validation is probably the right thing to do.

I filed the bug for two reasons:

1. To help others Googling for an answer.
2. To have someone else who knows the project better than I suggest a solution.
3. Point out that I was doing something stupid.

Often it's (3) ;-)

[cbednarski]

Yep definitely something we can improve, both in terms of docs and feedback from the agent. Thanks for opening an issue!

[github-actions]

I'm going to lock this issue because it has been closed for 120 days ⏳. This helps our maintainers find and focus on the active issues.
If you have found a problem that seems similar to this, please open a new issue and complete the issue template so we can capture all the details necessary to investigate further.