bug#34333: Docker daemon failing to start on boot

[Allan Adair]

Hi Danny.

Danny Milosavljevic writes:

> Hi Allan,
>
> On Mon, 11 Mar 2019 09:59:19 +0100
> Allan Adair <address@hidden> wrote:
>
>> Sorry for the late response. I was offline for the last week or so.
>
> No problem!
>
>> 
>> I ended up having to repeat the first command with sudo
>> privileges. Please see below.
>
> Yes, so that looks as if it works fine.  What's the difference to a failed 
> start by herd (log file in /var/log/docker.log) ?

I have never actually been able to start the dockerd service using herd
explicitly. After booting:

address@hidden ~$ docker ps
Cannot connect to the Docker daemon at unix:///var/run/docker.sock. Is the 
docker daemon running?
address@hidden ~$ cat /var/log/docker.log
time="2019-03-18T10:23:30.462181353+01:00" level=warning msg="Error while 
setting daemon root propagation, this is not generally critical but may cause 
some functionality to not work or fallback to less desirable behavior" 
dir=/var/lib/docker error="error writing file to signal mount cleanup on 
shutdown: open /var/run/docker/unmount-on-shutdown: no such file or directory"
time="2019-03-18T10:23:30.465999919+01:00" level=info msg="parsed scheme: 
\"unix\"" module=grpc
time="2019-03-18T10:23:30.466019010+01:00" level=info msg="scheme \"unix\" not 
registered, fallback to default scheme" module=grpc
time="2019-03-18T10:23:30.466291192+01:00" level=info msg="ccResolverWrapper: 
sending new addresses to cc: [{unix:///run/containerd/containerd.sock 0  
<nil>}]" module=grpc
time="2019-03-18T10:23:30.466315303+01:00" level=info msg="ClientConn switching 
balancer to \"pick_first\"" module=grpc
time="2019-03-18T10:23:30.466349982+01:00" level=info msg="pickfirstBalancer: 
HandleSubConnStateChange: 0xc00012d090, CONNECTING" module=grpc
time="2019-03-18T10:23:30.467362222+01:00" level=info msg="pickfirstBalancer: 
HandleSubConnStateChange: 0xc00012d090, READY" module=grpc
time="2019-03-18T10:23:30.467531354+01:00" level=info msg="parsed scheme: 
\"unix\"" module=grpc
time="2019-03-18T10:23:30.467544289+01:00" level=info msg="scheme \"unix\" not 
registered, fallback to default scheme" module=grpc
time="2019-03-18T10:23:30.467972429+01:00" level=info msg="ccResolverWrapper: 
sending new addresses to cc: [{unix:///run/containerd/containerd.sock 0  
<nil>}]" module=grpc
time="2019-03-18T10:23:30.467991848+01:00" level=info msg="ClientConn switching 
balancer to \"pick_first\"" module=grpc
time="2019-03-18T10:23:30.468161326+01:00" level=info msg="pickfirstBalancer: 
HandleSubConnStateChange: 0xc00012d380, CONNECTING" module=grpc
time="2019-03-18T10:23:30.468444097+01:00" level=info msg="pickfirstBalancer: 
HandleSubConnStateChange: 0xc00012d380, READY" module=grpc
time="2019-03-18T10:23:30.471722313+01:00" level=error msg="'overlay' not found 
as a supported filesystem on this host. Please ensure kernel is new enough and 
has overlay support loaded." storage-driver=overlay2
time="2019-03-18T10:23:30.471762928+01:00" level=error msg="[graphdriver] prior 
storage driver overlay2 failed: driver not supported"
Error starting daemon: error initializing graphdriver: driver not supported

The service does start after a guix system reconfigure:

address@hidden ~$ sudo guix system reconfigure /etc/config.scm > /dev/null 2>&1
Password: 
address@hidden ~$ docker ps
CONTAINER ID        IMAGE               COMMAND             CREATED             
STATUS              PORTS               NAMES
address@hidden ~$ cat /var/log/docker.log
time="2019-03-18T11:04:08.548958068+01:00" level=info msg="parsed scheme: 
\"unix\"" module=grpc
time="2019-03-18T11:04:08.549060661+01:00" level=info msg="scheme \"unix\" not 
registered, fallback to default scheme" module=grpc
time="2019-03-18T11:04:08.549129691+01:00" level=info msg="parsed scheme: 
\"unix\"" module=grpc
time="2019-03-18T11:04:08.549145165+01:00" level=info msg="scheme \"unix\" not 
registered, fallback to default scheme" module=grpc
time="2019-03-18T11:04:08.549194625+01:00" level=info msg="ccResolverWrapper: 
sending new addresses to cc: [{unix:///run/containerd/containerd.sock 0  
<nil>}]" module=grpc
time="2019-03-18T11:04:08.549225327+01:00" level=info msg="ClientConn switching 
balancer to \"pick_first\"" module=grpc
time="2019-03-18T11:04:08.549295334+01:00" level=info msg="pickfirstBalancer: 
HandleSubConnStateChange: 0xc0007c8730, CONNECTING" module=grpc
time="2019-03-18T11:04:08.549428581+01:00" level=info msg="pickfirstBalancer: 
HandleSubConnStateChange: 0xc0007c8730, READY" module=grpc
time="2019-03-18T11:04:08.549823791+01:00" level=info msg="ccResolverWrapper: 
sending new addresses to cc: [{unix:///run/containerd/containerd.sock 0  
<nil>}]" module=grpc
time="2019-03-18T11:04:08.549852586+01:00" level=info msg="ClientConn switching 
balancer to \"pick_first\"" module=grpc
time="2019-03-18T11:04:08.549895079+01:00" level=info msg="pickfirstBalancer: 
HandleSubConnStateChange: 0xc00048c190, CONNECTING" module=grpc
time="2019-03-18T11:04:08.550230781+01:00" level=info msg="pickfirstBalancer: 
HandleSubConnStateChange: 0xc00048c190, READY" module=grpc
time="2019-03-18T11:04:08.563100196+01:00" level=info msg="[graphdriver] using 
prior storage driver: overlay2"
time="2019-03-18T11:04:08.649791498+01:00" level=info msg="Graph migration to 
content-addressability took 0.00 seconds"
time="2019-03-18T11:04:08.649963115+01:00" level=warning msg="Your kernel does 
not support swap memory limit"
time="2019-03-18T11:04:08.650005407+01:00" level=warning msg="Your kernel does 
not support cgroup rt period"
time="2019-03-18T11:04:08.650018501+01:00" level=warning msg="Your kernel does 
not support cgroup rt runtime"
time="2019-03-18T11:04:08.650029780+01:00" level=warning msg="Your kernel does 
not support cgroup blkio weight"
time="2019-03-18T11:04:08.650040103+01:00" level=warning msg="Your kernel does 
not support cgroup blkio weight_device"
time="2019-03-18T11:04:08.650127344+01:00" level=warning msg="mountpoint for 
pids not found"
time="2019-03-18T11:04:08.650316692+01:00" level=info msg="Loading containers: 
start."
time="2019-03-18T11:04:09.231485582+01:00" 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"
time="2019-03-18T11:04:09.381248432+01:00" level=info msg="Loading containers: 
done."
time="2019-03-18T11:04:09.381974297+01:00" level=warning msg="Could not get 
operating system name: Error opening /usr/lib/os-release: open 
/usr/lib/os-release: no such file or directory"
time="2019-03-18T11:04:09.388621054+01:00" level=warning msg="failed to 
retrieve /gnu/store/fxmfknby00xva6jlz3m4pjj2jyj2xxiw-runc-1.0.0-rc6/sbin/runc 
version: unknown output format: runc version 1.0.0-rc6\nspec: 1.0.1-dev\n"
time="2019-03-18T11:04:09.388997410+01:00" level=warning msg="failed to 
retrieve docker-init version: exec: \"docker-init\": executable file not found 
in $PATH"
time="2019-03-18T11:04:10.926517059+01:00" level=info msg="Docker daemon" 
commit=v18.09.3 graphdriver(s)=overlay2 version=dev
time="2019-03-18T11:04:10.926776715+01:00" level=info msg="Daemon has completed 
initialization"
time="2019-03-18T11:04:10.941524868+01:00" level=info msg="API listen on 
/var/run/docker.sock"


-- 
Allan Adair
http://allan.adair.io