docker broken after latest updates

[nataraj]

After applying the latest updates on 6/26/15 using "pacman -Syu", I can no longer run docker. It worked fine after the previous updates that I applied on 6/16/15 and I had a container running just prior to applying the latest updates and rebooting. No other changes were made to my system.

[nataraj@alarm ~]$ docker run -i -t alarm/imx6-cubox-web:latest /bin/bash
Error response from daemon: Cannot start container ee634684a25aaded0cc08154b81cb2a6ae67dd8aa9eed08eb8c06d0a4efb9bff: socket operation on non-socket
[nataraj@alarm ~]$

I have also tried the docker start command and get the same error.

I would appreciate if anyone has any ideas what to look at here. Note I am running on a Cubox I4 Pro (ARMV7h).

Here's the last several lines of an strace:

clock_gettime(CLOCK_MONOTONIC, {2227, 697391}) = 0
clock_gettime(CLOCK_MONOTONIC, {2227, 1898459}) = 0
clock_gettime(CLOCK_MONOTONIC, {2227, 2076802}) = 0
ioctl(0, TCGETS, {B38400 opost isig icanon echo ...}) = 0
ioctl(1, TCGETS, 0x7e85aad4) = -1 ENOTTY (Inappropriate ioctl for device)
stat64("/root/.docker/config.json", 0x10b325b0) = -1 ENOENT (No such file or directory)
stat64("/root/.dockercfg", 0x10b32930) = -1 ENOENT (No such file or directory)
clock_gettime(CLOCK_MONOTONIC, {2227, 4702951}) = 0
clock_gettime(CLOCK_MONOTONIC, {2227, 5635671}) = 0
clock_gettime(CLOCK_MONOTONIC, {2227, 5854683}) = 0
clock_gettime(CLOCK_REALTIME, {1435307974, 573966712}) = 0
clock_gettime(CLOCK_REALTIME, {1435307974, 574186725}) = 0
socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 6
setsockopt(6, SOL_SOCKET, SO_BROADCAST, [1], 4) = 0
connect(6, {sa_family=AF_LOCAL, sun_path="/var/run/docker.sock"}, 23) = 0
clock_gettime(CLOCK_REALTIME, {1435307974, 575282120}) = 0
epoll_ctl(4, EPOLL_CTL_ADD, 6, {EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, {u32=1990203616, u64=1990203616}}) = 0
getsockname(6, {sa_family=AF_LOCAL, NULL}, [2]) = 0
getpeername(6, {sa_family=AF_LOCAL, sun_path="/var/run/docker.sock"}, [23]) = 0
clock_gettime(CLOCK_MONOTONIC, {2227, 11075313}) = 0
read(6, 0x10bc4000, 4096) = -1 EAGAIN (Resource temporarily unavailable)
write(6, "POST /v1.19/containers/create HT"..., 1142) = 1142
close(5) = 0
epoll_wait(4, {{EPOLLOUT, {u32=1990203616, u64=1990203616}}}, 128, 0) = 1
epoll_wait(4, {{EPOLLIN|EPOLLOUT, {u32=1990203616, u64=1990203616}}}, 128, -1) = 1
clock_gettime(CLOCK_MONOTONIC, {2227, 362566933}) = 0
futex(0x9d6514, FUTEX_WAKE, 1) = 1
futex(0x9d64c0, FUTEX_WAKE, 1) = 1
read(6, "HTTP/1.1 201 Created\r\nContent-Ty"..., 4096) = 203
futex(0x9d6514, FUTEX_WAKE, 1) = 0
futex(0x9d64c0, FUTEX_WAKE, 1) = 1
read(6, 0x10bc4000, 4096) = -1 EAGAIN (Resource temporarily unavailable)
futex(0x9d6a68, FUTEX_WAIT, 0, NULL) = 0
epoll_wait(4, {{EPOLLOUT, {u32=1990203616, u64=1990203616}}}, 128, 0) = 1
epoll_wait(4, {{EPOLLOUT, {u32=1990203736, u64=1990203736}}}, 128, -1) = 1
epoll_wait(4, {{EPOLLOUT, {u32=1990203736, u64=1990203736}}}, 128, -1) = 1
epoll_wait(4, {{EPOLLOUT, {u32=1990203736, u64=1990203736}}}, 128, -1) = 1
epoll_wait(4, {{EPOLLOUT, {u32=1990203736, u64=1990203736}}}, 128, -1) = 1
epoll_wait(4, {{EPOLLOUT, {u32=1990203736, u64=1990203736}}}, 128, -1) = 1
epoll_wait(4, {{EPOLLOUT, {u32=1990203736, u64=1990203736}}}, 128, -1) = 1
epoll_wait(4, {{EPOLLOUT, {u32=1990203736, u64=1990203736}}}, 128, -1) = 1
epoll_wait(4, {{EPOLLIN|EPOLLOUT, {u32=1990203616, u64=1990203616}}}, 128, -1) = 1
clock_gettime(CLOCK_MONOTONIC, {2227, 711279063}) = 0
futex(0x9d6514, FUTEX_WAKE, 1) = 1
futex(0x9d64c0, FUTEX_WAKE, 1) = 1
read(6, "HTTP/1.1 500 Internal Server Err"..., 4096) = 257
futex(0x9d6514, FUTEX_WAKE, 1) = 1
futex(0x9d64c0, FUTEX_WAKE, 1) = 1
read(6, 0x10bc4000, 4096) = -1 EAGAIN (Resource temporarily unavailable)
futex(0x9d6a68, FUTEX_WAIT, 0, NULLError response from daemon: Cannot start container 0201fce874977acd0a89a56adcc5721826e2\
249e4d84c6b1cb9b41919ac6ec94: socket operation on non-socket
<unfinished ...>
+++ exited with 1 +++

[WarheadsSE]

Okay, and is there any message from the daemon itself? (see the journal)

[nataraj]

I'm fairly new to systemd, but I'm guessing that what I included below is what you are looking for.

Thank You,
Nataraj

[root@alarm ~]# systemctl status -l docker
* docker.service - Docker Application Container Engine
Loaded: loaded (/usr/lib/systemd/system/docker.service; enabled; vendor preset: disabled)
Active: active (running) since Sat 2000-08-05 03:40:18 MST; 14 years 10 months ago
Docs: https://docs.docker.com
Main PID: 287 (docker)
CGroup: /system.slice/docker.service
`-287 /usr/bin/docker -d -H fd://

Jun 26 11:20:19 alarm.rjl.com docker[287]: time="2015-06-26T11:20:19.287521264-07:00" level=info msg="GET /v1.19/containers/json"
Jun 26 12:27:29 alarm.rjl.com docker[287]: time="2015-06-26T12:27:29.527709498-07:00" level=info msg="POST /v1.19/containers/create"
Jun 26 12:27:29 alarm.rjl.com docker[287]: time="2015-06-26T12:27:29.691928397-07:00" level=error msg="Couldn't run auplink before unmount: exec: \"auplink\": executable file not found in $PATH"
Jun 26 12:27:29 alarm.rjl.com docker[287]: time="2015-06-26T12:27:29.774700716-07:00" level=error msg="Couldn't run auplink before unmount: exec: \"auplink\": executable file not found in $PATH"
Jun 26 12:27:29 alarm.rjl.com docker[287]: time="2015-06-26T12:27:29.836407185-07:00" level=info msg="POST /v1.19/containers/830dead41860d2e79338b460f6f2281ced60360e263aadf18b892a60741156f9/attach?stderr=1&stdin=1&stdout=1&stream=1"
Jun 26 12:27:29 alarm.rjl.com docker[287]: time="2015-06-26T12:27:29.846476418-07:00" level=info msg="POST /v1.19/containers/830dead41860d2e79338b460f6f2281ced60360e263aadf18b892a60741156f9/start"
Jun 26 12:27:30 alarm.rjl.com docker[287]: time="2015-06-26T12:27:30.025648824-07:00" level=error msg="leaving endpoint failed: a container has already joined the endpoint"
Jun 26 12:27:30 alarm.rjl.com docker[287]: time="2015-06-26T12:27:30.029477039-07:00" level=error msg="Couldn't run auplink before unmount: exec: \"auplink\": executable file not found in $PATH"
Jun 26 12:27:30 alarm.rjl.com docker[287]: time="2015-06-26T12:27:30.088380683-07:00" level=error msg="Handler for POST /containers/{name:.*}/start returned error: Cannot start container 830dead41860d2e79338b460f6f2281ced60360e263aadf18b892a60741156f9: socket operation on non-socket"
Jun 26 12:27:30 alarm.rjl.com docker[287]: time="2015-06-26T12:27:30.088614030-07:00" level=error msg="HTTP Error" err="Cannot start container 830dead41860d2e79338b460f6f2281ced60360e263aadf18b892a60741156f9: socket operation on non-socket" statusCode=500
[root@alarm ~]#

[nataraj]

I found the following message in dmesg (does not seem to show up in the systemd journal) which comes up 3 times everytime I try to start a container. Any idea what it means?

[19816.962592] aufs au_opts_verify:1604:docker[287]: dirperm1 breaks the protection by the permission bits on the lower branch
[19817.050708] aufs au_opts_verify:1604:docker[295]: dirperm1 breaks the protection by the permission bits on the lower branch
[19817.132263] aufs au_opts_verify:1604:docker[305]: dirperm1 breaks the protection by the permission bits on the lower branch

Thank You,
Nataraj

[tki]

This same issue has been reported on github docker repo:
https://github.com/docker/docker/issues/14184
Since the same error reproduces on Scaleway, Raspberry Pi, ODROID C1 and XU3, whether with ALARM or ubuntu, the issue seems to be not specific to distribution or device, but to Linux/ARM platform itself.

Until it gets proper treatment, you may wish to use prior version 1.6.2:

https://gist.github.com/tkiapril/49d881a849efe5147745/raw/e7ae9f91935d07749d9cf9b93b49ce58489a4f7e/docker-1_1.6.2-2-armv7h.pkg.tar.xz
https://gist.github.com/tkiapril/49d881a849efe5147745/raw/be8a8e9824177ce15ef77f0f856280ea20d5170b/docker-1_1.6.2-2-armv7h.pkg.tar.xz.sig

I was able to run docker properly after downgrading to this version.
Files were luckily acquired from this repo which seems to be not updated immediately: http://mirrors.jlu.edu.cn/archlinuxarm/armv7h/community/
If you haven't run -pacman Sc recently, you may also have your copy of cached version in /var/cache/pacman/pkg.

[nataraj]

Thank you. I have been able to get docker working again by downgrading to version 1.6.2.