moby: Headless install of docker fails on ubuntu 15.10

Description of problem:

I’m trying to install docker-engine 1.9.1 in a headless fashion on ubuntu wily 15.10, and it is failing with:

Setting up docker-engine (1.9.1-0~wily) ...
Job for docker.service failed because the control process exited with error code. See "systemctl status docker.service" and "journalctl -xe" for details.
invoke-rc.d: initscript docker, action "start" failed.
dpkg: error processing package docker-engine (--configure):
 subprocess installed post-installation script returned error exit status 1

By headless, I mean I am using the user-data feature of ec2 to run the install script:

#!/bin/bash
export DEBIAN_FRONTEND=noninteractive
sudo apt-key adv --keyserver hkp://p80.pool.sks-keyservers.net:80 --recv-keys 58118E89F3A912897C070ADBF76221572C52609D
sudo bash -c 'echo "deb https://apt.dockerproject.org/repo ubuntu-wily main" > /etc/apt/sources.list.d/docker.list'
sudo apt-get update && sudo apt-get install -y docker-engine

I launch an ec2 instance (m3.medium) using the ubuntu wily 15.10 ami (ami-305d115a) and the above user-data script (you can do this in the ec2 web ui)

Once the instance comes up, you can watch the cloud-init logs to see when it fails:

tail -f /var/log/cloud-init-output.log

If you subsequently run the install manually with an apt-get install docker-engine, it will then succeed. Likewise if you start a similar instance with no user-data, then a manual install will also succeed.

When looking at the output of journalctl -xe I notice that in the failure case, the docker.socket service does not get started, whilst in the success case, it does get started, so I’m guessing the problem lies somewhere near there, but don’t know enough about systemd to contribute further.

Failure case:

Dec 04 21:55:38 ip-10-1-3-83 cloud-init[1086]: Setting up docker-engine (1.9.1-0~wily) ...
Dec 04 21:55:38 ip-10-1-3-83 groupadd[2197]: group added to /etc/group: name=docker, GID=999
Dec 04 21:55:38 ip-10-1-3-83 groupadd[2197]: group added to /etc/gshadow: name=docker
Dec 04 21:55:38 ip-10-1-3-83 groupadd[2197]: new group: name=docker, GID=999
Dec 04 21:55:39 ip-10-1-3-83 systemd[1]: Reloading.
Dec 04 21:55:39 ip-10-1-3-83 systemd[1]: Reloading.
Dec 04 21:55:39 ip-10-1-3-83 systemd[1]: Reloading.
Dec 04 21:55:39 ip-10-1-3-83 systemd[1]: Reloading.
Dec 04 21:55:39 ip-10-1-3-83 systemd[1]: Starting Docker Application Container Engine...
-- Subject: Unit docker.service has begun start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit docker.service has begun starting up.
Dec 04 21:55:40 ip-10-1-3-83 docker[2283]: time="2015-12-04T21:55:40.104265748Z" level=fatal msg="No sockets found"
Dec 04 21:55:40 ip-10-1-3-83 systemd[1]: docker.service: Main process exited, code=exited, status=1/FAILURE
Dec 04 21:55:40 ip-10-1-3-83 systemd[1]: Failed to start Docker Application Container Engine.
-- Subject: Unit docker.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit docker.service has failed.
-- 
-- The result is failed.
Dec 04 21:55:40 ip-10-1-3-83 systemd[1]: docker.service: Unit entered failed state.
Dec 04 21:55:40 ip-10-1-3-83 systemd[1]: docker.service: Failed with result 'exit-code'.

Success case:

Dec 04 22:02:41 ip-10-1-3-83 systemd[1]: Starting Docker Socket for the API.
-- Subject: Unit docker.socket has begun start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit docker.socket has begun starting up.
Dec 04 22:02:41 ip-10-1-3-83 systemd[1]: Listening on Docker Socket for the API.
-- Subject: Unit docker.socket has finished start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit docker.socket has finished starting up.
-- 
-- The start-up result is done.
Dec 04 22:02:41 ip-10-1-3-83 systemd[1]: Starting Docker Application Container Engine...
-- Subject: Unit docker.service has begun start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit docker.service has begun starting up.
Dec 04 22:02:41 ip-10-1-3-83 docker[2442]: time="2015-12-04T22:02:41.771564686Z" level=info msg="API listen on /var/run/docker.sock"
Dec 04 22:02:41 ip-10-1-3-83 systemd-udevd[328]: Network interface NamePolicy= disabled on kernel command line, ignoring.
Dec 04 22:02:41 ip-10-1-3-83 docker[2442]: time="2015-12-04T22:02:41.843392181Z" level=warning msg="Usage of loopback devices is strongly discouraged for production use. Please use `--storage-opt dm.thinpooldev` or use `man docker` to refer to dm.thinpooldev section."
Dec 04 22:02:41 ip-10-1-3-83 docker[2442]: time="2015-12-04T22:02:41.861958623Z" level=warning msg="XFS is not supported in your system. Either the kernel doesnt support it or mkfs.xfs is not in your PATH. Defaulting to ext4 filesystem"
Dec 04 22:03:28 ip-10-1-3-83 kernel: Bridge firewalling registered
Dec 04 22:03:28 ip-10-1-3-83 docker[2442]: time="2015-12-04T22:03:28.668257106Z" level=info msg="Firewalld running: false"
Dec 04 22:03:28 ip-10-1-3-83 docker[2442]: time="2015-12-04T22:03:28.706934982Z" level=info msg="Default bridge (docker0) is assigned with an IP address 172.17.0.0/16. Daemon option --bip can be used to set a preferred IP address"
Dec 04 22:03:28 ip-10-1-3-83 systemd-udevd[2519]: Could not generate persistent MAC address for docker0: No such file or directory
Dec 04 22:03:28 ip-10-1-3-83 kernel: IPv6: ADDRCONF(NETDEV_UP): docker0: link is not ready
Dec 04 22:03:28 ip-10-1-3-83 docker[2442]: time="2015-12-04T22:03:28.804027004Z" level=warning msg="Your kernel does not support swap memory limit."
Dec 04 22:03:28 ip-10-1-3-83 audit[2564]: AVC apparmor="STATUS" operation="profile_load" profile="unconfined" name="docker-default" pid=2564 comm="apparmor_parser"
Dec 04 22:03:28 ip-10-1-3-83 kernel: audit: type=1400 audit(1449266608.886:15): apparmor="STATUS" operation="profile_load" profile="unconfined" name="docker-default" pid=2564 comm="apparmor_parser"
Dec 04 22:03:28 ip-10-1-3-83 systemd[1]: libcontainer-2442-systemd-test-default-dependencies.scope: Scope has no PIDs. Refusing.
Dec 04 22:03:28 ip-10-1-3-83 docker[2442]: time="2015-12-04T22:03:28.894238435Z" level=info msg="Loading containers: start."
Dec 04 22:03:28 ip-10-1-3-83 docker[2442]: time="2015-12-04T22:03:28.894654457Z" level=info msg="Loading containers: done."
Dec 04 22:03:28 ip-10-1-3-83 docker[2442]: time="2015-12-04T22:03:28.894897537Z" level=info msg="Daemon has completed initialization"
Dec 04 22:03:28 ip-10-1-3-83 docker[2442]: time="2015-12-04T22:03:28.895149450Z" level=info msg="Docker daemon" commit=a34a1d5 execdriver=native-0.2 graphdriver=devicemapper version=1.9.1
Dec 04 22:03:28 ip-10-1-3-83 systemd[1]: Started Docker Application Container Engine.
-- Subject: Unit docker.service has finished start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit docker.service has finished starting up.
-- 
-- The start-up result is done.

docker version:

Client:
 Version:      1.9.1
 API version:  1.21
 Go version:   go1.4.2
 Git commit:   a34a1d5
 Built:        Fri Nov 20 13:20:08 UTC 2015
 OS/Arch:      linux/amd64

Server:
 Version:      1.9.1
 API version:  1.21
 Go version:   go1.4.2
 Git commit:   a34a1d5
 Built:        Fri Nov 20 13:20:08 UTC 2015
 OS/Arch:      linux/amd64

docker info:

Containers: 0
Images: 0
Server Version: 1.9.1
Storage Driver: devicemapper
 Pool Name: docker-202:1-148879-pool
 Pool Blocksize: 65.54 kB
 Base Device Size: 107.4 GB
 Backing Filesystem: ext4
 Data file: /dev/loop0
 Metadata file: /dev/loop1
 Data Space Used: 1.821 GB
 Data Space Total: 107.4 GB
 Data Space Available: 5.447 GB
 Metadata Space Used: 1.479 MB
 Metadata Space Total: 2.147 GB
 Metadata Space Available: 2.146 GB
 Udev Sync Supported: true
 Deferred Removal Enabled: false
 Deferred Deletion Enabled: false
 Deferred Deleted Device Count: 0
 Data loop file: /var/lib/docker/devicemapper/devicemapper/data
 Metadata loop file: /var/lib/docker/devicemapper/devicemapper/metadata
 Library Version: 1.02.99 (2015-06-20)
Execution Driver: native-0.2
Logging Driver: json-file
Kernel Version: 4.2.0-19-generic
Operating System: Ubuntu 15.10
CPUs: 1
Total Memory: 3.675 GiB
Name: ip-10-1-3-27
ID: TACN:SGUX:6WGI:U6L4:4KQE:O2H5:5XIB:BOAZ:GQHR:RL7N:JWN3:MCC4
WARNING: No swap limit support

uname -a:

Linux ip-10-1-3-27 4.2.0-19-generic #23-Ubuntu SMP Wed Nov 11 11:39:30 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux

Environment details (AWS, VirtualBox, physical, etc.): AWS

How reproducible: See Description

Steps to Reproduce:

  1. See Description

Actual Results: Running headless prevents install

Expected Results: Should be able to do a headless install

Additional info: See Description

About this issue

  • Original URL
  • State: closed
  • Created 9 years ago
  • Comments: 23 (11 by maintainers)

Most upvoted comments

I have the same issue.

Easy way to reproduce:

This will boot an instance using current Ubuntu 15.10 image.

(Just set the environment variables to put your keys, and change key-name to your SSH key in this specific region.)

aws --region us-west-2 ec2 run-instances --image-id ami-9f2cc8ff --key-name jpetazzo --instance-type m3.medium --user-data https://get.docker.io/

Cloud-init output log excerpts:*

Setting up docker-engine (1.9.1-0~wily) ... 
Job for docker.service failed because the control process exited with error code. See "systemctl status docker.service" and "journalctl -xe" for details.
invoke-rc.d: initscript docker, action "start" failed.
dpkg: error processing package docker-engine (--configure):
 subprocess installed post-installation script returned error exit status 1
Processing triggers for libc-bin (2.21-0ubuntu4) ... 
Processing triggers for ureadahead (0.100.0-19) ... 
Processing triggers for systemd (225-1ubuntu9) ... 
Errors were encountered while processing:
 docker-engine
E: Sub-process /usr/bin/dpkg returned an error code (1)

systemctl info:*

ubuntu@ip-172-31-19-17:~$ systemctl status docker.service
● docker.service - Docker Application Container Engine
   Loaded: loaded (/lib/systemd/system/docker.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Fri 2016-01-29 21:11:44 UTC; 2min 49s ago 
     Docs: https://docs.docker.com
 Main PID: 8701 (code=exited, status=1/FAILURE)

Jan 29 21:11:43 ip-172-31-19-17 systemd[1]: Starting Docker Application Container Engine...
Jan 29 21:11:44 ip-172-31-19-17 docker[8701]: time="2016-01-29T21:11:44.012172274Z" level=fatal msg="No sockets found"
Jan 29 21:11:44 ip-172-31-19-17 systemd[1]: docker.service: Main process exited, code=exited, status=1/FAILURE
Jan 29 21:11:44 ip-172-31-19-17 systemd[1]: Failed to start Docker Application Container Engine.
Jan 29 21:11:44 ip-172-31-19-17 systemd[1]: docker.service: Unit entered failed state.
Jan 29 21:11:44 ip-172-31-19-17 systemd[1]: docker.service: Failed with result 'exit-code'.
ubuntu@ip-172-31-19-17:~$

docker info after it’s manually started:

ubuntu@ip-172-31-7-238:~$ sudo docker info
Containers: 0
Images: 0
Server Version: 1.9.1
Storage Driver: aufs
 Root Dir: /var/lib/docker/aufs
 Backing Filesystem: extfs
 Dirs: 0
 Dirperm1 Supported: true
Execution Driver: native-0.2
Logging Driver: json-file
Kernel Version: 4.2.0-25-generic
Operating System: Ubuntu 15.10
CPUs: 1
Total Memory: 3.675 GiB
Name: ip-172-31-7-238
ID: RIQZ:OV3U:SPNH:WXL3:V7VI:VQUC:MB73:Y4ME:5JNH:TF2C:AHLP:NI4D
WARNING: No swap limit support
ubuntu@ip-172-31-7-238:~$

Current workaround:

Execute sudo systemctl start docker after the boot process.

Notes:

This doesn’t seem to be linked to the storage driver (since I’m using AUFS).

This happens with stable and test versions of Docker.

This also happens with Ubuntu 15.04 (which is also using systemd).

It doesn’t happen with Ubuntu 14.04 (which uses upstart).

It also happens when executing curl -sSL https://get.docker.com/ from a cloud-init script.

It doesn’t happen when running curl sSL https://get.docker.com/ from a shell once the instance is booted.

I wonder if this could be caused by socket activation, since the message is No sockets found, but I’m totally out of my element here.

+1
jpetazzo on Jan 30, 2016
Read more comments on GitHub
← moby: hcsshim::PrepareLayer failed in Win32: This operation returned because the timeout period expired. (0x5b4)
moby: Health checks are hard to implement because of return codes →