Public bug reported:

After the docker.io package was updated last Friday (Jan 20 2017) we
started experiencing issues and getting errors when new containers
should be launched.

Here's an excerpt of errors found in syslog:

Jan 23 06:25:07 dockerserver kernel: [7751793.479504] aufs 
au_opts_verify:1597:dockerd[10676]: dirperm1 breaks the protection by the 
permission bits on the 
lower branch
Jan 23 06:25:07 dockerserver dockerd[13066]: 
time="2017-01-23T06:25:07.616134541+01:00" level=error msg="containerd: start 
container" error="oci runtime err
or: process_linux.go:330: running prestart hook 0 caused \"fork/exec 
/usr/bin/dockerd (deleted): no such file or directory: \"" 
id=e20acb788ee6554bb1240bc7c07
bd033a8d15d8e4f246c553120beba4bfbcb2f
Jan 23 06:25:07 dockerserver dockerd[13066]: 
time="2017-01-23T06:25:07.627421952+01:00" level=error msg="Create container 
failed with error: oci runtime err
or: process_linux.go:330: running prestart hook 0 caused \"fork/exec 
/usr/bin/dockerd (deleted): no such file or directory: \""
Jan 23 06:25:07 dockerserver dockerd[13066]: 
time="2017-01-23T06:25:07.647734613+01:00" level=warning msg="Couldn't run 
auplink before unmount /var/lib/dock
er/aufs/mnt/e513ea71816cd308e5815c5b24ce34833f1de4e6d4f700de090c50c70b050678: 
exec: \"auplink\": executable file not found in $PATH"
Jan 23 06:25:07 dockerserver dockerd[13066]: 
time="2017-01-23T06:25:07.664973641+01:00" level=error msg="Handler for POST 
/v1.22/containers/e20acb788ee6554b
b1240bc7c07bd033a8d15d8e4f246c553120beba4bfbcb2f/start returned error: oci 
runtime error: process_linux.go:330: running prestart hook 0 caused \"fork/exec 
/us
r/bin/dockerd (deleted): no such file or directory: \""
Jan 23 06:25:07 dockerserver kernel: [7751793.760983] aufs 
au_opts_verify:1597:dockerd[30845]: dirperm1 breaks the protection by the 
permission bits on the 
lower branch
Jan 23 06:25:07 dockerserver dockerd[13066]: 
time="2017-01-23T06:25:07.902874678+01:00" level=error msg="containerd: start 
container" error="oci runtime err
or: process_linux.go:330: running prestart hook 0 caused \"fork/exec 
/usr/bin/dockerd (deleted): no such file or directory: \"" 
id=e20acb788ee6554bb1240bc7c07
bd033a8d15d8e4f246c553120beba4bfbcb2f


It looks like the update was installed correctly and afterwards started
the Docker service (engine) - but there was no stop before applying the
update (which could be added in a docker.io.preinst file).

apt history shows:

Start-Date: 2017-01-20  15:04:06
Commandline: /usr/bin/apt-get -y -o Dpkg::Options::=--force-confdef -o 
Dpkg::Options::=--force-confold install docker.io
Requested-By: ansible (1001)
Upgrade: runc:amd64 (1.0.0~rc1-0ubuntu1~16.04, 1.0.0~rc1-0ubuntu2~16.04.1), 
docker.io:amd64 (1.12.1-0ubuntu13~16.04.1, 1.12.3-0ubuntu4~16.04.2)
End-Date: 2017-01-20  15:04:10

syslog shows for that timeframe (15.04:06 to 15:04:10):

Jan 20 15:04:03 dockerserver systemd[1]: Created slice User Slice of ansible.
Jan 20 15:04:03 dockerserver systemd[1]: Starting User Manager for UID 1001...
Jan 20 15:04:03 dockerserver systemd[1]: Started Session 14956 of user ansible.
Jan 20 15:04:03 dockerserver systemd[18545]: Reached target Sockets.
Jan 20 15:04:03 dockerserver systemd[18545]: Reached target Timers.
Jan 20 15:04:03 dockerserver systemd[18545]: Reached target Paths.
Jan 20 15:04:03 dockerserver systemd[18545]: Reached target Basic System.
Jan 20 15:04:03 dockerserver systemd[18545]: Reached target Default.
Jan 20 15:04:03 dockerserver systemd[18545]: Startup finished in 22ms.
Jan 20 15:04:03 dockerserver systemd[1]: Started User Manager for UID 1001.
Jan 20 15:04:08 dockerserver systemd[1]: Reloading.
Jan 20 15:04:09 dockerserver systemd[1]: apt-daily.timer: Adding 37min 
2.565881s random time.
Jan 20 15:04:09 dockerserver systemd[1]: Started ACPI event daemon.
Jan 20 15:04:09 dockerserver systemd[1]: Reloading.
Jan 20 15:04:09 dockerserver systemd[1]: apt-daily.timer: Adding 5h 27min 
32.130480s random time.
Jan 20 15:04:09 dockerserver systemd[1]: Started ACPI event daemon.
Jan 20 15:04:10 dockerserver systemd[1]: Reloading.
Jan 20 15:04:10 dockerserver systemd[1]: apt-daily.timer: Adding 11h 55min 
14.530665s random time.
Jan 20 15:04:10 dockerserver systemd[1]: Started ACPI event daemon.
Jan 20 15:04:10 dockerserver systemd[1]: Reloading.
Jan 20 15:04:10 dockerserver systemd[1]: apt-daily.timer: Adding 11h 16min 
17.514645s random time.
Jan 20 15:04:10 dockerserver systemd[1]: Started ACPI event daemon.
Jan 20 15:04:10 dockerserver systemd[1]: Started Docker Application Container 
Engine.
Jan 20 15:04:10 dockerserver systemd[1]: Reloading.
Jan 20 15:04:10 dockerserver systemd[1]: apt-daily.timer: Adding 11h 42min 
36.963745s random time.
Jan 20 15:04:10 dockerserver systemd[1]: Started ACPI event daemon. 

So there's indeed a Start of Docker at 15:04:10 but where's the stop
prior to that?

If I manually restart the Docker service, syslog entries look like:

Jan 23 09:54:38 dockerserver systemd[1]: Stopping Docker Application Container 
Engine...
Jan 23 09:54:50 dockerserver systemd[1]: Stopped Docker Application Container 
Engine.
Jan 23 09:54:50 dockerserver systemd[1]: Closed Docker Socket for the API.
Jan 23 09:54:50 dockerserver systemd[1]: Stopping Docker Socket for the API.
Jan 23 09:54:50 dockerserver systemd[1]: Starting Docker Socket for the API.
Jan 23 09:54:50 dockerserver systemd[1]: Listening on Docker Socket for the API.
Jan 23 09:54:50 dockerserver systemd[1]: Starting Docker Application Container 
Engine...
Jan 23 09:54:54 dockerserver dockerd[26724]: 
time="2017-01-23T09:54:54.088301837+01:00" level=info msg="Docker daemon" 
commit=6b644ec graphdriver=aufs version=1.12.3
Jan 23 09:54:54 dockerserver systemd[1]: Started Docker Application Container 
Engine. 

Please confirm or let me know if I'm mistaken.

ProblemType: Bug
DistroRelease: Ubuntu 16.04
Package: docker.io 1.12.3-0ubuntu4~16.04.2
ProcVersionSignature: Ubuntu 4.4.0-45.66-generic 4.4.21
Uname: Linux 4.4.0-45-generic x86_64
ApportVersion: 2.20.1-0ubuntu2.4
Architecture: amd64
Date: Mon Jan 23 14:52:40 2017
InstallationDate: Installed on 2016-10-25 (90 days ago)
InstallationMedia: Ubuntu-Server 16.04 LTS "Xenial Xerus" - Release amd64 
(20160420.3)
ProcEnviron:
 LANGUAGE=en_US:en
 TERM=xterm
 PATH=(custom, no user)
 LANG=en_US.UTF-8
 SHELL=/bin/bash
SourcePackage: docker.io
UpgradeStatus: No upgrade log present (probably fresh install)

** Affects: docker.io (Ubuntu)
     Importance: Undecided
         Status: New


** Tags: amd64 apport-bug xenial

-- 
You received this bug notification because you are a member of Ubuntu
Bugs, which is subscribed to Ubuntu.
https://bugs.launchpad.net/bugs/1658691

Title:
  Docker service is not properly restarted when updating docker.io
  package

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/docker.io/+bug/1658691/+subscriptions

-- 
ubuntu-bugs mailing list
ubuntu-bugs@lists.ubuntu.com
https://lists.ubuntu.com/mailman/listinfo/ubuntu-bugs

Reply via email to