lxc-start fails: lxc_cgfsng - cgfsng.c:all_controllers_found:430 - no systemd controller mountpoint found

[Stephen Warren]

On Ubuntu Xenial pre-release, I see the following, so can't start a container:

[swarren@sprint ~]$ lxc-create -t download -n t2 -- -d ubuntu -r trusty -a amd64
Using image from local cache
Unpacking the rootfs

---
You just created an Ubuntu container (release=trusty, arch=amd64, variant=default)

To enable sshd, run: apt-get install openssh-server

For security reason, container images ship without user accounts
and without a root password.

Use lxc-attach or chroot directly into the rootfs to set a root password
or create user accounts.

swarren@sprint ~]$ lxc-start -n t2 -d
lxc-start: lxc_start.c: main: 344 The container failed to start.
lxc-start: lxc_start.c: main: 346 To get more details, run the container in foreground mode.
lxc-start: lxc_start.c: main: 348 Additional information can be obtained by setting the --logfile and --logpriority options.

[swarren@sprint ~]$ lxc-start -n t2 -d -o /dev/stdout -l debug -F
      lxc-start 20160312101415.704 INFO lxc_start_ui - lxc_start.c:main:264 - using rcfile /home/swarren/.local/share/lxc/t2/config
      lxc-start 20160312101415.705 WARN lxc_confile - confile.c:config_pivotdir:1859 - lxc.pivotdir is ignored. It will soon become an error.
      lxc-start 20160312101415.705 INFO lxc_confile - confile.c:config_idmap:1495 - read uid map: type u nsid 0 hostid 100000 range 65536
      lxc-start 20160312101415.705 INFO lxc_confile - confile.c:config_idmap:1495 - read uid map: type g nsid 0 hostid 100000 range 65536
      lxc-start 20160312101415.707 INFO lxc_lsm - lsm/lsm.c:lsm_init:48 - LSM security driver AppArmor
      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:parse_config_v2:342 - processing: .reject_force_umount # comment this to allow umount -f; not recommended.
      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:parse_config_v2:446 - Adding native rule for reject_force_umount action 0
      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:do_resolve_add_rule:216 - Setting seccomp rule to reject force umounts

      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:parse_config_v2:449 - Adding compat rule for reject_force_umount action 0
      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:do_resolve_add_rule:216 - Setting seccomp rule to reject force umounts

      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:parse_config_v2:342 - processing: .[all].
      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:parse_config_v2:342 - processing: .kexec_load errno 1.
      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:parse_config_v2:446 - Adding native rule for kexec_load action 327681
      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:parse_config_v2:449 - Adding compat rule for kexec_load action 327681
      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:parse_config_v2:342 - processing: .open_by_handle_at errno 1.
      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:parse_config_v2:446 - Adding native rule for open_by_handle_at action 327681
      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:parse_config_v2:449 - Adding compat rule for open_by_handle_at action 327681
      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:parse_config_v2:342 - processing: .init_module errno 1.
      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:parse_config_v2:446 - Adding native rule for init_module action 327681
      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:parse_config_v2:449 - Adding compat rule for init_module action 327681
      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:parse_config_v2:342 - processing: .finit_module errno 1.
      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:parse_config_v2:446 - Adding native rule for finit_module action 327681
      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:parse_config_v2:449 - Adding compat rule for finit_module action 327681
      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:parse_config_v2:342 - processing: .delete_module errno 1.
      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:parse_config_v2:446 - Adding native rule for delete_module action 327681
      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:parse_config_v2:449 - Adding compat rule for delete_module action 327681
      lxc-start 20160312101415.708 INFO lxc_seccomp - seccomp.c:parse_config_v2:456 - Merging in the compat seccomp ctx into the main one
      lxc-start 20160312101415.708 DEBUG lxc_start - start.c:setup_signal_fd:289 - sigchild handler set
      lxc-start 20160312101415.708 DEBUG lxc_console - console.c:lxc_console_peer_default:437 - opening /dev/tty for console peer
      lxc-start 20160312101415.708 INFO lxc_caps - caps.c:lxc_caps_up:101 - Last supported cap was 36
      lxc-start 20160312101415.708 DEBUG lxc_console - console.c:lxc_console_peer_default:443 - using '/dev/tty' as console
      lxc-start 20160312101415.708 DEBUG lxc_console - console.c:lxc_console_sigwinch_init:142 - 3200 got SIGWINCH fd 9
      lxc-start 20160312101415.708 DEBUG lxc_console - console.c:lxc_console_winsz:72 - set winsz dstfd:6 cols:347 rows:93
      lxc-start 20160312101415.770 INFO lxc_start - start.c:lxc_init:488 - 't2' is initialized
      lxc-start 20160312101415.771 DEBUG lxc_start - start.c:__lxc_start:1259 - Not dropping cap_sys_boot or watching utmp
      lxc-start 20160312101415.771 INFO lxc_start - start.c:resolve_clone_flags:956 - Cloning a new user namespace
      lxc-start 20160312101415.771 INFO lxc_cgroup - cgroup.c:cgroup_init:68 - cgroup driver cgroupfs-ng initing for t2
      lxc-start 20160312101415.771 ERROR lxc_cgfsng - cgfsng.c:all_controllers_found:430 - no systemd controller mountpoint found
lxc-start: cgfsng.c: all_controllers_found: 430 no systemd controller mountpoint found
      lxc-start 20160312101415.771 ERROR lxc_start - start.c:lxc_spawn:1036 - failed initializing cgroup support
lxc-start: start.c: lxc_spawn: 1036 failed initializing cgroup support
      lxc-start 20160312101415.771 ERROR lxc_start - start.c:__lxc_start:1286 - failed to spawn 't2'
lxc-start: start.c: __lxc_start: 1286 failed to spawn 't2'
      lxc-start 20160312101415.771 INFO lxc_conf - conf.c:run_script_argv:367 - Executing script '/usr/share/lxcfs/lxc.reboot.hook' for container 't2', config section 'lxc'
      lxc-start 20160312101416.276 ERROR lxc_start_ui - lxc_start.c:main:344 - The container failed to start.
lxc-start: lxc_start.c: main: 344 The container failed to start.
      lxc-start 20160312101416.276 ERROR lxc_start_ui - lxc_start.c:main:348 - Additional information can be obtained by setting the --logfile and --logpriority options.
lxc-start: lxc_start.c: main: 348 Additional information can be obtained by setting the --logfile and --logpriority options.

ProblemType: Bug
DistroRelease: Ubuntu 16.04
Package: lxc 2.0.0~rc10-0ubuntu2
ProcVersionSignature: Ubuntu 4.4.0-12.28-generic 4.4.4
Uname: Linux 4.4.0-12-generic x86_64
NonfreeKernelModules: nvidia_uvm nvidia_modeset nvidia
ApportVersion: 2.20-0ubuntu3
Architecture: amd64
CurrentDesktop: XFCE
Date: Sat Mar 12 10:14:22 2016
InstallationDate: Installed on 2016-03-03 (9 days ago)
InstallationMedia: Ubuntu 16.04 LTS "Xenial Xerus" - Alpha amd64 (20160122.2)
PackageArchitecture: all
SourcePackage: lxc
UpgradeStatus: No upgrade log present (probably fresh install)
defaults.conf:
 lxc.network.type = veth
 lxc.network.link = lxcbr0
 lxc.network.flags = up
 lxc.network.hwaddr = 00:16:3e:xx:xx:xx

[Stephen Warren (srwarren)]

I have 2 Xenial systems. They are both fully up-to-date as of 5 minutes ago. The failing system is a laptop running XFCE GUI, and I'm attempting to use LXC from a GUI terminal. The other system is a linode that I access via ssh, and LXC works fine there. I believe I've configured the two systems the same way w.r.t. lxc (e.g. /etc/subuid, /etx/lxc/lxc-usernet, ~/.config/lxc/default.conf, etc.). The primary difference is that the Linode system is running a Linode-provided kernel, whereas my laptop is running an Ubuntu-provided kernel.

[Stephen Warren (srwarren)]

Switching the linode system to the Ubuntu kernel (booted via pv-grub) didn't make that system fail. Perhaps the difference is cgroup setup via ssh vs XFCE/GUI login?

[Serge Hallyn (serge-hallyn)]

Do you know whether you are using lightdm? Can you show your
/etc/pamd.d/common-session file?

[Evgeni Golov (evgeni)]

Hi,

I am seeing this on an up2date VM of 16.04, logging in via SSH. libpam-cgfs is installed.

Error output from the log:
      lxc-start 20160313140655.936 ERROR lxc_cgfsng - cgfsng.c:all_controllers_found:430 - no systemd controller mountpoint found
      lxc-start 20160313140655.936 ERROR lxc_start - start.c:lxc_spawn:1036 - failed initializing cgroup support
      lxc-start 20160313140655.936 ERROR lxc_start - start.c:__lxc_start:1286 - failed to spawn 'user1'

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Stephen Warren (srwarren)]

Yes, I'm running lightdm.

$ cat /etc/pam.d/common-session
session [default=1] pam_permit.so
session requisite pam_deny.so
session required pam_permit.so
session optional pam_umask.so
session required pam_unix.so
session optional pam_systemd.so
session optional pam_cgfs.so -c freezer,memory,name=systemd

(comments all stripped for brevity

That file should be unmodified relative to the package defaults, or put another way, I haven't fiddled with it.

[Serge Hallyn (serge-hallyn)]

Thanks, Stephen, culprit found. The systemd cgroup was yours - until you did a sudo.

For now you can work around this by commenting out the libpam-cgfs line from /etc/pam.d/common-session-noninteractive. Then re-chown your current systemd cgroup to yourself or log back in.

I'm not yet sure whether the proper fix will be to

1. remove the line from noninteractive,
2. have libpam-cgfs check for user-$loginuid.slice in the current systemd cgroup, and create a new one if it doesn't match
3. just add another libpam-cgfs argument to say whether to create a new systemd cgroup, and have it not do so for noninteractive.

[Stephen Warren (srwarren)]

Could you please expand on "Then re-chown your current systemd cgroup"? I'm not sure exactly how/where cgroups get mounted, so I'm not sure what path I should chown.

[Serge Hallyn (serge-hallyn)]

Quoting Stephen Warren (<email address hidden>):
> Could you please expand on "Then re-chown your current systemd cgroup"?
> I'm not sure exactly how/where cgroups get mounted, so I'm not sure what
> path I should chown.

The systemd cgroupfs is mounted under /sys/fs/cgroup/systemd. Your current
login path can be found with

awk -F: '/systemd/ { print $3 }' /proc/self/cgroup

so

pwd=/sys/fs/cgroup/systemd/`awk -F: '/systemd/ { print $3 }' /proc/self/cgroup`
sudo -E chown $(id -u):$(id -g) $pwd

should work

[Stephen Warren (srwarren)]

Thanks. The chown solves the issue. I didn't need to make the modification to the pam config file at all. I do need to do the chown every time I log in though, with or without the pam change.

FWIW, when I ssh into the working server, the relevant /sys directory is owned by swarren:swarren without any intervention. On my laptop, it's always owned by root:root.

[Launchpad Janitor (janitor)]

This bug was fixed in the package lxcfs - 2.0.0~rc5-0ubuntu1

---------------
lxcfs (2.0.0~rc5-0ubuntu1) xenial; urgency=medium

  * Merge next upstream rc
  * This fixes a bug where sudo would mis-chown a user's systemd cgroup
    (LP: #1556447)
  * Drop upstream paches which are in this rc

 -- Serge Hallyn <email address hidden> Mon, 14 Mar 2016 16:09:50 -0700

[Stephen Warren (srwarren)]

After updating to the latest packages, this issue is solve. I can lxc-start, lxc-attach, lxc-stop, and lxc-execute.

I do get some warning/error spew when running lxc-execute though. If this looks unexpected, I can open a separate bug for it:

$ lxc-execute -n t1 -- /bin/bash
lxc-execute: utils.c: safe_mount: 1691 Invalid argument - Failed to mount /sys/kernel/debug onto /usr/lib/x86_64-linux-gnu/lxc/sys/kernel/debug
lxc-execute: utils.c: safe_mount: 1691 Device or resource busy - Failed to mount mqueue onto /usr/lib/x86_64-linux-gnu/lxc/dev/mqueue
init.lxc.static: initutils.c: mount_fs: 36 failed to mount /proc : Device or resource busy
init.lxc.static: initutils.c: mount_fs: 36 failed to mount /dev/mqueue : Device or resource busy

The first two of those show up in the container log file upon lxc-start too:

lxc-start 20160316211700.325 ERROR lxc_utils - utils.c:safe_mount:1691 - Invalid argument - Failed to mount /sys/kernel/debug onto /usr/lib/x86_64-linux-gnu/lxc/sys/kernel/debug
lxc-start 20160316211700.325 ERROR lxc_utils - utils.c:safe_mount:1691 - Device or resource busy - Failed to mount mqueue onto /usr/lib/x86_64-linux-gnu/lxc/dev/mqueue

Thanks very much for fix and bug comments; this has been one of the most productive bug reports I've ever filed:-)

[Serge Hallyn (serge-hallyn)]

The EBUSY errors from lxc-init mounts are ok, it's because lxc has already mounted those (by following the automatically included configuration files).

i'd expect eperm for the /sys/kernel/debug mount, because you're not allowed to read under /sys/kernel/debug. But strace shows that by hand i also get einval. So nothing here is unexpected or (so long as it doesn't break anything for you) needing a bug.