Reported by @eriegger in docker/docker#29794.
runc version: 54296cf40ad8143b62dbcaa1d90e520a2136ddfe
Kernel Version: 4.4.0-70-generic
Operating System: Ubuntu 16.04.2 LTS
OSType: linux
Architecture: x86_64
They gave us an strace log. But the key point is this:
[pid 26452] open("/proc/8391/ns/ipc", O_RDONLY) = 8
[pid 26452] open("/proc/8391/ns/uts", O_RDONLY) = 9
[pid 26452] open("/proc/8391/ns/net", O_RDONLY) = 10
[pid 26452] open("/proc/8391/ns/pid", O_RDONLY) = 11
[pid 26452] open("/proc/8391/ns/mnt", O_RDONLY) = 12
[pid 26452] setns(8, CLONE_NEWIPC) = -1 EINVAL (Invalid argument)
Does anyone know if Ubuntu broke IPC namespaces somehow? As far as I can see, the only straightforward paths in sys_setns that could give you EINVAL is if the fd is not an nsfs handle or doesn't match the nstype -- which we can't possibly be hitting because we explicitly opened the fd ourselves.
@eriegger What does ls -laF /proc/8391/ns/* give you?
# ls -laF /proc/8391/ns/*
lrwxrwxrwx 1 root root 0 M盲r 31 14:45 /proc/8391/ns/cgroup -> cgroup:[4026531835]
lrwxrwxrwx 1 root root 0 M盲r 31 14:35 /proc/8391/ns/ipc -> ipc:[4026532418]
lrwxrwxrwx 1 root root 0 M盲r 31 14:35 /proc/8391/ns/mnt -> mnt:[4026532416]
lrwxrwxrwx 1 root root 0 M盲r 31 14:28 /proc/8391/ns/net -> net:[4026532421]
lrwxrwxrwx 1 root root 0 M盲r 31 14:35 /proc/8391/ns/pid -> pid:[4026532419]
lrwxrwxrwx 1 root root 0 M盲r 31 14:45 /proc/8391/ns/user -> user:[4026531837]
lrwxrwxrwx 1 root root 0 M盲r 31 14:35 /proc/8391/ns/uts -> uts:[4026532417]
If you have nsenter installed (part of utils-linux) does this work?
$ unshare -i /proc/8391/ns/ipc
Hi, no, neither as eriegger nor as root:
$ unshare -i /proc/8391/ns/ipc
unshare: unshare failed: Operation not permitted
# unshare -i /proc/8391/ns/ipc
unshare: failed to execute /proc/8391/ns/ipc: Permission denied
Sorry, I meant this:
# unshare --ipc=/proc/8391/ns/ipc bash
Is this just happening on a stock 16.04.2 install?
Hm, think you hate my box, already ;-)
# unshare --ipc=/proc/8391/ns/ipc
unshare: mount /proc/8922/ns/ipc on /proc/8391/ns/ipc failed: Invalid argument
Far out, that doesn't make any sense. Is this just a stock 16.04 machine? Are you running a custom kernel or some weird kernel modules?
Hi,
to my knowledge it should be a stock 16.04 machine.
$ cat /etc/issue
Ubuntu 16.04.2 LTS \n \l
$
uname -a
Linux pb7tt6t 4.4.0-71-generic #92-Ubuntu SMP Fri Mar 24 12:59:01 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
From https://github.com/docker/docker/issues/29794#issuecomment-290729669
However, IIRC Ubuntu has some kernel patches related to IPC that might be causing this issue. Can anyone who is familiar with Ubuntu kernel patches comment?
ping @sforshee any ideas if that could be related, or should this be reported in the canonical issue tracker?
At a glance I didn't find any extra patches that would obviously be responsible. I'll try to find some time to look closer in the next few days.
Yeah, I checked out the Ubuntu kernel source and couldn't find any obvious extra code in the setns installation code for CLONE_NEWIPC.
Thanks both for checking 馃
Works fine on my ubuntu 16.10 machine.
@eriegger We can try to trace kernel calls. For that you need to create two small scripts:
[$ cat test.sh
echo $$ > /sys/kernel/debug/tracing/set_ftrace_pid
echo function_graph > /sys/kernel/debug/tracing/current_tracer
echo 1 > /sys/kernel/debug/tracing/tracing_on
exec nsenter --ipc=/proc/$1/ns/ipc true
$ cat test1.sh
sh ./test.sh $1
cat /sys/kernel/debug/tracing/trace
Then execute test1.sh TARGET_PID and show its output?
sh test1.sh 8391 &> output
Sorry, forgot to answer. Think I need a little help with the test.
Where does TARGET_PID come from, in your example 8391 ?
@avagin: Is TARGET_PID the PID of docker-runc list ?
1776.zip
# docker-runc list
ID PID STATUS BUNDLE CREATED
42f178648a855e24a8a4f0c1c9a4c40f1d1dcc922bc201542ef4d0804c8efa10 1776 running /run/docker/libcontainerd/42f178648a855e24a8a4f0c1c9a4c40f1d1dcc922bc201542ef4d0804c8efa10 2017-05-03T11:45:24.160349731Z
# sh test1.sh 1776 &> 1776.out
Not sure if this is critical:
nsenter: reassociate to namespace 'ns/ipc' failed: Invalid argument
# tracer: function_graph
#
# CPU DURATION FUNCTION CALLS
# | | | | | | |
2) ! 420.347 us | } /* schedule_preempt_disabled */
2) | tick_nohz_idle_enter() {
2) 0.126 us | set_cpu_sd_state_idle();
...
1) | SyS_setns() {
1) | proc_ns_fget() {
1) | fget() {
1) 0.049 us | __fget();
1) 0.283 us | }
1) 0.030 us | fput();
1) 0.789 us | }
1) 1.049 us | }
@eriegger Could you show /proc/self/mountinfo from this host?
Hello,
18 24 0:17 / /sys rw,nosuid,nodev,noexec,relatime shared:7 - sysfs sysfs rw
19 24 0:4 / /proc rw,nosuid,nodev,noexec,relatime shared:12 - proc proc rw
20 24 0:6 / /dev rw,nosuid,relatime shared:2 - devtmpfs udev rw,size=3903848k,nr_inodes=975962,mode=755
21 20 0:14 / /dev/pts rw,nosuid,noexec,relatime shared:3 - devpts devpts rw,gid=5,mode=620,ptmxmode=000
22 24 0:18 / /run rw,nosuid,noexec,relatime shared:5 - tmpfs tmpfs rw,size=785052k,mode=755
24 0 252:1 / / rw,relatime shared:1 - ext4 /dev/mapper/xubuntu--vg-root rw,errors=remount-ro,data=ordered
25 18 0:12 / /sys/kernel/security rw,nosuid,nodev,noexec,relatime shared:8 - securityfs securityfs rw
26 20 0:20 / /dev/shm rw,nosuid,nodev shared:4 - tmpfs tmpfs rw
27 22 0:21 / /run/lock rw,nosuid,nodev,noexec,relatime shared:6 - tmpfs tmpfs rw,size=5120k
28 18 0:22 / /sys/fs/cgroup ro,nosuid,nodev,noexec shared:9 - tmpfs tmpfs ro,mode=755
29 28 0:23 / /sys/fs/cgroup/systemd rw,nosuid,nodev,noexec,relatime shared:10 - cgroup cgroup rw,xattr,release_agent=/lib/systemd/systemd-cgroups-agent,name=systemd
30 18 0:24 / /sys/fs/pstore rw,nosuid,nodev,noexec,relatime shared:11 - pstore pstore rw
31 28 0:25 / /sys/fs/cgroup/blkio rw,nosuid,nodev,noexec,relatime shared:13 - cgroup cgroup rw,blkio
32 28 0:26 / /sys/fs/cgroup/freezer rw,nosuid,nodev,noexec,relatime shared:14 - cgroup cgroup rw,freezer
33 28 0:27 / /sys/fs/cgroup/net_cls,net_prio rw,nosuid,nodev,noexec,relatime shared:15 - cgroup cgroup rw,net_cls,net_prio
34 28 0:28 / /sys/fs/cgroup/devices rw,nosuid,nodev,noexec,relatime shared:16 - cgroup cgroup rw,devices
35 28 0:29 / /sys/fs/cgroup/cpu,cpuacct rw,nosuid,nodev,noexec,relatime shared:17 - cgroup cgroup rw,cpu,cpuacct
36 28 0:30 / /sys/fs/cgroup/memory rw,nosuid,nodev,noexec,relatime shared:18 - cgroup cgroup rw,memory
37 28 0:31 / /sys/fs/cgroup/hugetlb rw,nosuid,nodev,noexec,relatime shared:19 - cgroup cgroup rw,hugetlb
38 28 0:32 / /sys/fs/cgroup/perf_event rw,nosuid,nodev,noexec,relatime shared:20 - cgroup cgroup rw,perf_event
39 28 0:33 / /sys/fs/cgroup/pids rw,nosuid,nodev,noexec,relatime shared:21 - cgroup cgroup rw,pids
40 28 0:34 / /sys/fs/cgroup/cpuset rw,nosuid,nodev,noexec,relatime shared:22 - cgroup cgroup rw,cpuset
41 19 0:35 / /proc/sys/fs/binfmt_misc rw,relatime shared:23 - autofs systemd-1 rw,fd=30,pgrp=1,timeout=0,minproto=5,maxproto=5,direct
42 18 0:7 / /sys/kernel/debug rw,relatime shared:24 - debugfs debugfs rw
43 20 0:16 / /dev/mqueue rw,relatime shared:25 - mqueue mqueue rw
44 20 0:36 / /dev/hugepages rw,relatime shared:26 - hugetlbfs hugetlbfs rw
45 18 0:37 / /sys/fs/fuse/connections rw,relatime shared:27 - fusectl fusectl rw
46 24 8:1 / /boot rw,relatime shared:28 - ext2 /dev/sda1 rw,block_validity,barrier,user_xattr,acl
249 24 252:1 /var/lib/docker/aufs /var/lib/docker/aufs rw,relatime - ext4 /dev/mapper/xubuntu--vg-root rw,errors=remount-ro,data=ordered
255 22 0:42 / /run/user/25592 rw,nosuid,nodev,relatime shared:188 - tmpfs tmpfs rw,size=785052k,mode=700,uid=25592,gid=25592
210 255 0:41 / /run/user/25592/gvfs rw,nosuid,nodev,relatime shared:231 - fuse.gvfsd-fuse gvfsd-fuse rw,user_id=25592,group_id=25592
161 249 0:40 / /var/lib/docker/aufs/mnt/b7921e4c5587ebb80e0b4d923834284bbdb9965d1a03604688550366ef43e391 rw,relatime - aufs none rw,si=f6a4aed4bfdd3525,dio,dirperm1
162 24 0:43 / /var/lib/docker/containers/94e202a264e11a12c0d8cf4705add92c5e4be55d03305d3dfe65ac59ea49bc77/shm rw,nosuid,nodev,noexec,relatime shared:139 - tmpfs shm rw,size=65536k
275 22 0:3 net:[4026532416] /run/docker/netns/5551e145e17b rw shared:144 - nsfs nsfs rw
170 42 0:9 / /sys/kernel/debug/tracing rw,relatime shared:149 - tracefs tracefs rw
same issue here.
[pid 3455] prctl(PR_SET_NAME, 0x7b807f, 0, 0, 0) = 0
[pid 3455] open("/proc/32017/ns/ipc", O_RDONLY) = 6
[pid 3455] open("/proc/32017/ns/uts", O_RDONLY) = 9
[pid 3455] open("/proc/32017/ns/net", O_RDONLY) = 10
[pid 3455] open("/proc/32017/ns/pid", O_RDONLY) = 11
[pid 3455] open("/proc/32017/ns/mnt", O_RDONLY) = 12
[pid 3455] setns(6, 134217728) = -1 EINVAL (Invalid argument)
[pid 3455] write(2, "nsenter: failed to setns to /pro"..., 65) = 65
Docker info:
...
Runtimes: runc
Default Runtime: runc
Init Binary: docker-init
containerd version: 6e23458c129b551d5c9871e5174f6b1b7f6d1170
runc version: 810190ceaa507aa2727d7ae6f4790c76ec150bd2
init version: 949e6fa
Security Options:
apparmor
Kernel Version: 3.13.0-128-generic
Operating System: Ubuntu 14.04.5 LTS
OSType: linux
Architecture: x86_64
...
mount info:
17 22 0:15 / /sys rw,nosuid,nodev,noexec,relatime - sysfs sysfs rw
18 22 0:3 / /proc rw,nosuid,nodev,noexec,relatime - proc proc rw
19 22 0:5 / /dev rw,relatime - devtmpfs udev rw,size=3906220k,nr_inodes=976555,mode=755
20 19 0:12 / /dev/pts rw,nosuid,noexec,relatime - devpts devpts rw,gid=5,mode=620,ptmxmode=000
21 22 0:16 / /run rw,nosuid,noexec,relatime - tmpfs tmpfs rw,size=785216k,mode=755
22 1 252:1 / / rw,noatime - ext4 /dev/dm-1 rw,nobarrier,errors=remount-ro,data=ordered
24 17 0:17 / /sys/fs/cgroup rw,relatime - tmpfs none rw,size=4k,mode=755
25 17 0:18 / /sys/fs/fuse/connections rw,relatime - fusectl none rw
26 17 0:6 / /sys/kernel/debug rw,relatime - debugfs none rw
27 17 0:10 / /sys/kernel/security rw,relatime - securityfs none rw
28 21 0:19 / /run/lock rw,nosuid,nodev,noexec,relatime - tmpfs none rw,size=5120k
29 21 0:20 / /run/shm rw,nosuid,nodev,relatime - tmpfs none rw
30 21 0:21 / /run/user rw,nosuid,nodev,noexec,relatime - tmpfs none rw,size=102400k,mode=755
31 17 0:22 / /sys/fs/pstore rw,relatime - pstore none rw
32 24 0:23 / /sys/fs/cgroup/cpuset rw,relatime - cgroup cgroup rw,cpuset
33 24 0:24 / /sys/fs/cgroup/cpu rw,relatime - cgroup cgroup rw,cpu
34 24 0:25 / /sys/fs/cgroup/cpuacct rw,relatime - cgroup cgroup rw,cpuacct
35 24 0:26 / /sys/fs/cgroup/memory rw,relatime - cgroup cgroup rw,memory
36 24 0:27 / /sys/fs/cgroup/devices rw,relatime - cgroup cgroup rw,devices
37 24 0:28 / /sys/fs/cgroup/freezer rw,relatime - cgroup cgroup rw,freezer
38 24 0:29 / /sys/fs/cgroup/blkio rw,relatime - cgroup cgroup rw,blkio
39 24 0:30 / /sys/fs/cgroup/perf_event rw,relatime - cgroup cgroup rw,perf_event
40 24 0:31 / /sys/fs/cgroup/hugetlb rw,relatime - cgroup cgroup rw,hugetlb
41 22 8:1 / /boot rw,relatime - ext2 /dev/sda1 rw,stripe=4
42 18 0:32 / /proc/sys/fs/binfmt_misc rw,nosuid,nodev,noexec,relatime - binfmt_misc binfmt_misc rw
44 21 0:33 / /run/rpc_pipefs rw,relatime - rpc_pipefs rpc_pipefs rw
45 24 0:34 / /sys/fs/cgroup/systemd rw,nosuid,nodev,noexec,relatime - cgroup systemd rw,name=systemd
46 22 0:35 / /gsa rw,relatime - autofs /etc/auto.gsa rw,fd=6,pgrp=1630,timeout=300,minproto=5,maxproto=5,indirect
23 30 0:36 / /run/user/1000/gvfs rw,nosuid,nodev,relatime - fuse.gvfsd-fuse gvfsd-fuse rw,user_id=1000,group_id=1000
64 22 252:1 /var/lib/docker/plugins /var/lib/docker/plugins rw,noatime - ext4 /dev/dm-1 rw,nobarrier,errors=remount-ro,data=ordered
66 22 252:1 /var/lib/docker/aufs /var/lib/docker/aufs rw,noatime - ext4 /dev/dm-1 rw,nobarrier,errors=remount-ro,data=ordered
51 66 0:51 / /var/lib/docker/aufs/mnt/843c66117f167cc3d18279511a0de1e3158b134119831778201ee975ec472561 rw,relatime - aufs none rw,si=74272b90dfc2f24f,dio
62 22 0:53 / /var/lib/docker/containers/e0d802a404130b08302ce311d7887e53fc075b0bcda8306e43b751a5c8eb2a69/shm rw,nosuid,nodev,noexec,relatime - tmpfs shm rw,size=65536k
126 21 0:3 / /run/docker/netns/c02555c27609 rw,nosuid,nodev,noexec,relatime - proc proc rw
As I said in docker/docker#29794 I'm going to spin up a VM to see what's going on.
Alright, I've verified this doesn't happen on a stock 16.04 machine. It appears to be caused by a bug in Symantic's kernel module. Closing, but feel free to reopen this issue (or open a new one) if you can reproduce it on a machine with Symantic's kernel module disabled. Thanks for figuring that one out @digglife.
It only happened for me on boxes that upgraded their way 16.04.2, freshly installed machines got a different kernel level (4.8? vs the 4.4 on 16.04).. that said.. I think I did have the Symantec kernel module present too. Installing the HWE on the upgraded boxes let them update to the 4.8 kernel, where the issue went away.