Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

lxc: Failed to activate service 'org.freedesktop.systemd1': timed out after update to 233.75-3 from 232-8 #6408

Closed
jjb2016 opened this issue Jul 19, 2017 · 16 comments
Labels
bug 🐛 Programming errors, that need preferential fixing cgroups pid1

Comments

@jjb2016
Copy link

jjb2016 commented Jul 19, 2017

Submission type

  • Bug report

systemd version the issue has been seen with

233.75-3

Used distribution

Arch Linux

In case of bug report: Expected behaviour you didn't see

systemd starts up all services at boot

In case of bug report: Unexpected behaviour you saw

systemd seems to freeze after update and fails to start any services at reboot. I'm seeing the following output from journalctl ...

Jul 19 21:00:43 subsonic dbus[21]: [system] Reloaded configuration
Jul 19 21:00:43 subsonic dbus[21]: [system] Reloaded configuration
Jul 19 21:00:43 subsonic systemd[1]: Reexecuting.
Jul 19 21:00:43 subsonic systemd[1]: systemd 233 running in system mode. (+PAM -AUDIT -SELINUX -IMA -APPARMOR +SMACK -SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 -SECCOMP +BLKID +ELFUTILS +KMOD +IDN default-hierarchy=hybrid)
Jul 19 21:00:43 subsonic systemd[1]: Detected virtualization lxc.
Jul 19 21:00:43 subsonic systemd[1]: Detected architecture x86-64.
Jul 19 21:00:43 subsonic systemd[1]: Failed to create /init.scope control group: Permission denied
Jul 19 21:00:43 subsonic systemd[1]: Failed to allocate manager object: Permission denied
Jul 19 21:00:43 subsonic systemd[1]: Freezing execution.
Jul 19 21:01:08 subsonic dbus[21]: [system] Failed to activate service 'org.freedesktop.systemd1': timed out

In case of bug report: Steps to reproduce the problem

I am seeing this issue when updating an lxc container on my server. The server itself has updated to 233.75-3 without a problem. The lxc container is unprivileged. Although root starts the container all the processes running in the container run effectively as nobody from the host machine point of view. Perhaps the latest systemd update does not support this setup? Any ideas?

@jjb2016
Copy link
Author

jjb2016 commented Jul 19, 2017

Apologies for the formatting of the journalctl output above. I'm not sure how to improve this here.

@hewittc
Copy link

hewittc commented Jul 19, 2017

Unsure if related, but I experienced similar breakage on an Arch Linux ARM host, where systemd-logind and systemd-networkd fail to start on boot and logins are significantly delayed after recent package updates. I tracked my problem down to the expat package. Booting appears to work properly with expat 2.2.0-1 but not 2.2.1-1. Curious if downgrading would temporarily resolve your issue as well.

@jjb2016
Copy link
Author

jjb2016 commented Jul 19, 2017

Hi hewittc - thanks for responding. I rolled back the container to a good snapshot in which expat was at version 2.2.0-2 and systemd was at 232-8. Everything in the container works just fine at these versions. I added expat to the IgnorePkg list in pacman.conf to prevent it from being updated to 2.2.1-1. systemd was still updated to 233.75-3. Unfortunately this made no difference and systemd still no longer works after the update. I've posted a thread in the arch forum if anybody wants to see more detailed information ...

https://bbs.archlinux.org/viewtopic.php?id=228376

@evverx
Copy link
Member

evverx commented Jul 19, 2017

The same issue seems to have been discussed in lxc/lxc#1678, but I'm not sure that it has been solved. Is there any chance you could try the recipe mentioned in lxc/lxc#1678 and then report the result back to the maintainers of lxc?

@evverx evverx added the pid1 label Jul 19, 2017
@poettering poettering changed the title Failed to activate service 'org.freedesktop.systemd1': timed out after update to 233.75-3 from 232-8 lxc: Failed to activate service 'org.freedesktop.systemd1': timed out after update to 233.75-3 from 232-8 Jul 20, 2017
@evverx evverx added the cgroups label Jul 20, 2017
@jjb2016
Copy link
Author

jjb2016 commented Jul 20, 2017

@evverx Thanks I have read through that thread but I can't see a solution there. The thread is marked as closed but the original poster's last few comments seem to show the issue is not resolved. Maybe I've missed something.

@smcv
Copy link
Contributor

smcv commented Jul 21, 2017

Unsure if related, but I experienced similar breakage on an Arch Linux ARM host, where systemd-logind and systemd-networkd fail to start on boot and logins are significantly delayed after recent package updates. I tracked my problem down to the expat package. Booting appears to work properly with expat 2.2.0-1 but not 2.2.1-1.

I think this is a separate issue that happens to cause a similar symptom. I opened #6418.

@evverx
Copy link
Member

evverx commented Jul 21, 2017

The thread is marked as closed but the original poster's last few comments seem to show the issue is not resolved.

The original poster seems to have written that systemd was up and running without /sys/fs/cgroup/unified.

systemd can be "frozen" easily by doing some weird things like the following

bash-4.3# echo $$
1
bash-4.3# /lib/systemd/systemd --version
systemd 234
+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN default-hierarchy=hybrid
bash-4.3# mount -t sysfs sysfs /sys
bash-4.3# mount -t tmpfs tmpfs /sys/fs/cgroup/
bash-4.3# mkdir /sys/fs/cgroup/unified
bash-4.3# mount -t cgroup2 cgroup2 -o ro /sys/fs/cgroup/unified
bash-4.3# exec /lib/systemd/systemd
...
[!!!!!!] Failed to allocate manager object, freezing.

Do you know if something similar happens inside or outside your container?

I've already run pacman -Suy within an unprivileged container and I didn't see any issues

$ CONT_PID=$(lxc-info -p -n arch -H)
$ ps u $CONT_PID
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
165536    2142  0.2  0.6  55852  6968 ?        Ss   14:30   0:06 /usr/lib/systemd/systemd --system --deserialize 42

$ grep /sys/fs/cgroup/unified OUT
statfs("/sys/fs/cgroup/unified/", 0x7ffd50241840) = -1 ENOENT (No such file or directory)
statfs("/sys/fs/cgroup/unified/", 0x7ffd50241860) = -1 ENOENT (No such file or directory)
statfs("/sys/fs/cgroup/unified/", 0x7ffd50241840) = -1 ENOENT (No such file or directory)
mkdir("/sys/fs/cgroup/unified", 0755)   = -1 EROFS (Read-only file system)
mount("cgroup", "/sys/fs/cgroup/unified", "cgroup2", MS_NOSUID|MS_NODEV|MS_NOEXEC, NULL) = -1 ENOENT (No such file or directory)
statfs("/sys/fs/cgroup/unified/", 0x7ffd50241870) = -1 ENOENT (No such file or directory)
statfs("/sys/fs/cgroup/unified/", 0x7fffc7b8bf10) = -1 ENOENT (No such file or directory)
statfs("/sys/fs/cgroup/unified/", 0x7fffc7b8bf30) = -1 ENOENT (No such file or directory)
statfs("/sys/fs/cgroup/unified/", 0x7fffc7b8bf10) = -1 ENOENT (No such file or directory)
mkdir("/sys/fs/cgroup/unified", 0755)   = -1 EROFS (Read-only file system)
mount("cgroup", "/sys/fs/cgroup/unified", "cgroup2", MS_NOSUID|MS_NODEV|MS_NOEXEC, NULL) = -1 ENOENT (No such file or directory)
statfs("/sys/fs/cgroup/unified/", 0x7fffc7b8bf40) = -1 ENOENT (No such file or directory)
statfs("/sys/fs/cgroup/unified/", 0x7ffe316b8d80) = -1 ENOENT (No such file or directory)

I'd suggest running systemd within the container under strace during pacman -Suy to see what is going on. It would also be useful to mention which cgroup hierarchies are used on the host and inside the container before/after daemon-reexec. But, to be honest, I don't think the issue is a bug in either systemd or lxc.

@evverx evverx added the needs-reporter-feedback ❓ There's an unanswered question, the reporter needs to answer label Jul 21, 2017
@jjb2016
Copy link
Author

jjb2016 commented Jul 21, 2017

I'm working / travelling at the moment. I'll try and get back on this over the weekend - thanks.

@jjb2016
Copy link
Author

jjb2016 commented Jul 23, 2017

Hi - here is some more detailed information:
systemd version on host machine:

[justin@IXTREME ~]$ sudo systemctl --version
systemd 233
+PAM -AUDIT -SELINUX -IMA -APPARMOR +SMACK -SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 -SECCOMP +BLKID +ELFUTILS +KMOD +IDN default-hierarchy=hybrid
[justin@IXTREME ~]$

cgroups listed on host machine:

[justin@IXTREME ~]$ ls -lh /sys/fs/cgroup
total 0
dr-xr-xr-x 7 root root  0 Jul 20 17:36 blkio
lrwxrwxrwx 1 root root 11 Jul 20 17:36 cpu -> cpu,cpuacct
lrwxrwxrwx 1 root root 11 Jul 20 17:36 cpuacct -> cpu,cpuacct
dr-xr-xr-x 7 root root  0 Jul 20 17:36 cpu,cpuacct
dr-xr-xr-x 4 root root  0 Jul 20 17:36 cpuset
dr-xr-xr-x 7 root root  0 Jul 20 17:36 devices
dr-xr-xr-x 4 root root  0 Jul 20 17:36 freezer
dr-xr-xr-x 7 root root  0 Jul 20 17:36 memory
lrwxrwxrwx 1 root root 16 Jul 20 17:36 net_cls -> net_cls,net_prio
dr-xr-xr-x 4 root root  0 Jul 20 17:36 net_cls,net_prio
lrwxrwxrwx 1 root root 16 Jul 20 17:36 net_prio -> net_cls,net_prio
dr-xr-xr-x 4 root root  0 Jul 20 17:36 perf_event
dr-xr-xr-x 7 root root  0 Jul 20 17:36 pids
dr-xr-xr-x 7 root root  0 Jul 20 17:36 systemd
dr-xr-xr-x 6 root root  0 Jul 20 17:36 unified
[justin@IXTREME ~]$

attach to the running lxc container (before systemd upgrade from 232-8 to 233.75-3), show systemd version + cgroups ...

[justin@IXTREME ~]$ sudo lxc-attach -n subsonic
[sudo] password for justin: 
[root@subsonic /]# systemctl --version
systemd 232
+PAM -AUDIT -SELINUX -IMA -APPARMOR +SMACK -SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN
[root@subsonic /]# ls -lh /sys/fs/cgroup
total 0
drwxrwxr-x 2 nobody root  0 Jul 23 11:00 blkio
lrwxrwxrwx 1 root   root 11 Jul 23 11:00 cpu -> cpu,cpuacct
drwxrwxr-x 2 nobody root  0 Jul 23 11:00 cpu,cpuacct
lrwxrwxrwx 1 root   root 11 Jul 23 11:00 cpuacct -> cpu,cpuacct
drwxrwxr-x 2 nobody root  0 Jul 23 11:00 cpuset
drwxrwxr-x 5 nobody root  0 Jul 23 11:00 devices
drwxrwxr-x 2 nobody root  0 Jul 23 11:00 freezer
drwxrwxr-x 2 nobody root  0 Jul 23 11:00 memory
lrwxrwxrwx 1 root   root 16 Jul 23 11:00 net_cls -> net_cls,net_prio
drwxrwxr-x 2 nobody root  0 Jul 23 11:00 net_cls,net_prio
lrwxrwxrwx 1 root   root 16 Jul 23 11:00 net_prio -> net_cls,net_prio
drwxrwxr-x 2 nobody root  0 Jul 23 11:00 perf_event
drwxrwxr-x 5 nobody root  0 Jul 23 11:00 pids
drwxrwxr-x 5 nobody root  0 Jul 23 11:00 systemd
[root@subsonic /]#

run pacman -Syu to update system ...

[root@subsonic /]# pacman -Syu
:: Synchronizing package databases...
 core is up to date
 extra                                                                          1659.0 KiB  4.38M/s 00:00 [###############################################################] 100%
 community                                                                         3.9 MiB  4.95M/s 00:01 [###############################################################] 100%
:: Starting full system upgrade...
resolving dependencies...
looking for conflicting packages...

Packages (58) apr-1.6.2-1  archlinux-keyring-20170611-1  ca-certificates-mozilla-3.31-3  curl-7.54.1-2  device-mapper-2.02.172-2  expat-2.2.2-1  ffmpeg-1:3.3.2-2
              gcc-libs-7.1.1-4  glib2-2.52.3-1  glibc-2.25-7  gnupg-2.1.21-3  gnutls-3.5.14-1  grep-3.1-1  harfbuzz-1.4.7-1  iproute2-4.12.0-2  jre8-openjdk-8.u141-1
              jre8-openjdk-headless-8.u141-1  libarchive-3.3.2-1  libbluray-1.0.1-1  libelf-0.169-2  libevent-2.1.8-1  libgcrypt-1.7.8-1  libjpeg-turbo-1.5.2-1  libnl-3.3.0-1
              libpng-1.6.30-1  libssh-0.7.5-2  libsystemd-233.75-3  libtiff-4.0.8-2  libtirpc-1.0.2-1  libunwind-1.2.1-1  libusb-1.0.21-2  libx264-2:148.20170521-1
              libxml2-2.9.4+96+gfb56f80e-1  llvm-libs-4.0.1-5  logrotate-3.12.3-1  lvm2-2.02.172-2  mesa-17.1.5-1  nano-2.8.5-1  nfs-utils-2.1.1-4  npth-1.5-1  nspr-4.15-1
              nss-3.31-3  opus-1.2.1-1  orc-0.4.27-1  p11-kit-0.23.7-1  pacman-5.0.2-2  pacman-mirrorlist-20170714-1  pcre-8.41-1  popt-1.16-9  psmisc-23.1-1  s-nail-14.9.0-1
              sdl2-2.0.5-4  sqlite-3.19.3-1  systemd-233.75-3  systemd-sysvcompat-233.75-3  texinfo-6.4-1  thin-provisioning-tools-0.7.0-1  zlib-1:1.2.11-2

Total Download Size:   116.22 MiB
Total Installed Size:  496.07 MiB
Net Upgrade Size:        1.00 MiB

:: Proceed with installation? [Y/n] y
:: Retrieving packages...
 glibc-2.25-7-x86_64                                                               8.2 MiB  4.84M/s 00:02 [###############################################################] 100%
 gcc-libs-7.1.1-4-x86_64                                                          17.8 MiB  4.96M/s 00:04 [###############################################################] 100%
 libgcrypt-1.7.8-1-x86_64                                                        466.0 KiB  5.06M/s 00:00 [###############################################################] 100%
 libsystemd-233.75-3-x86_64                                                      350.7 KiB  4.89M/s 00:00 [###############################################################] 100%
 libtirpc-1.0.2-1-x86_64                                                         176.9 KiB  4.67M/s 00:00 [###############################################################] 100%
 zlib-1:1.2.11-2-x86_64                                                           81.7 KiB  4.98M/s 00:00 [###############################################################] 100%
 archlinux-keyring-20170611-1-any                                                661.6 KiB  4.97M/s 00:00 [###############################################################] 100%
 p11-kit-0.23.7-1-x86_64                                                         445.7 KiB  5.06M/s 00:00 [###############################################################] 100%
 ca-certificates-mozilla-3.31-3-x86_64                                           402.0 KiB  5.17M/s 00:00 [###############################################################] 100%
 curl-7.54.1-2-x86_64                                                            902.6 KiB  5.01M/s 00:00 [###############################################################] 100%
 device-mapper-2.02.172-2-x86_64                                                 265.8 KiB  5.19M/s 00:00 [###############################################################] 100%
 expat-2.2.2-1-x86_64                                                             83.0 KiB  5.06M/s 00:00 [###############################################################] 100%
 gnutls-3.5.14-1-x86_64                                                            2.3 MiB  4.97M/s 00:00 [###############################################################] 100%
 libelf-0.169-2-x86_64                                                           342.8 KiB  5.31M/s 00:00 [###############################################################] 100%
 pcre-8.41-1-x86_64                                                              924.6 KiB  5.02M/s 00:00 [###############################################################] 100%
 glib2-2.52.3-1-x86_64                                                             2.3 MiB  4.98M/s 00:00 [###############################################################] 100%
 libnl-3.3.0-1-x86_64                                                            354.9 KiB  4.95M/s 00:00 [###############################################################] 100%
 libusb-1.0.21-2-x86_64                                                           54.1 KiB  5.28M/s 00:00 [###############################################################] 100%
 popt-1.16-9-x86_64                                                               63.7 KiB  6.22M/s 00:00 [###############################################################] 100%
 systemd-233.75-3-x86_64                                                           3.8 MiB  4.95M/s 00:01 [###############################################################] 100%
 npth-1.5-1-x86_64                                                                12.8 KiB  0.00B/s 00:00 [###############################################################] 100%
 sqlite-3.19.3-1-x86_64                                                         1259.3 KiB  4.98M/s 00:00 [###############################################################] 100%
 gnupg-2.1.21-3-x86_64                                                          2020.5 KiB  4.93M/s 00:00 [###############################################################] 100%
 grep-3.1-1-x86_64                                                               188.4 KiB  4.97M/s 00:00 [###############################################################] 100%
 iproute2-4.12.0-2-x86_64                                                        673.6 KiB  5.06M/s 00:00 [###############################################################] 100%
 nspr-4.15-1-x86_64                                                              189.1 KiB  4.99M/s 00:00 [###############################################################] 100%
 nss-3.31-3-x86_64                                                              1423.6 KiB  4.97M/s 00:00 [###############################################################] 100%
 libarchive-3.3.2-1-x86_64                                                       448.9 KiB  5.04M/s 00:00 [###############################################################] 100%
 libevent-2.1.8-1-x86_64                                                         250.2 KiB  5.20M/s 00:00 [###############################################################] 100%
 logrotate-3.12.3-1-x86_64                                                        37.2 KiB  5.19M/s 00:00 [###############################################################] 100%
 thin-provisioning-tools-0.7.0-1-x86_64                                          370.9 KiB  5.17M/s 00:00 [###############################################################] 100%
 lvm2-2.02.172-2-x86_64                                                         1288.9 KiB  4.97M/s 00:00 [###############################################################] 100%
 nano-2.8.5-1-x86_64                                                             418.5 KiB  4.92M/s 00:00 [###############################################################] 100%
 nfs-utils-2.1.1-4-x86_64                                                        271.8 KiB  5.31M/s 00:00 [###############################################################] 100%
 pacman-mirrorlist-20170714-1-any                                                  5.7 KiB  0.00B/s 00:00 [###############################################################] 100%
 pacman-5.0.2-2-x86_64                                                           737.3 KiB  5.00M/s 00:00 [###############################################################] 100%
 psmisc-23.1-1-x86_64                                                             94.4 KiB  5.42M/s 00:00 [###############################################################] 100%
 s-nail-14.9.0-1-x86_64                                                          442.1 KiB  5.20M/s 00:00 [###############################################################] 100%
 systemd-sysvcompat-233.75-3-x86_64                                                7.3 KiB  1833K/s 00:00 [###############################################################] 100%
 texinfo-6.4-1-x86_64                                                           1188.4 KiB  4.98M/s 00:00 [###############################################################] 100%
 apr-1.6.2-1-x86_64                                                              257.5 KiB  5.03M/s 00:00 [###############################################################] 100%
 libssh-0.7.5-2-x86_64                                                           191.0 KiB  4.66M/s 00:00 [###############################################################] 100%
 opus-1.2.1-1-x86_64                                                             352.7 KiB  4.92M/s 00:00 [###############################################################] 100%
 libunwind-1.2.1-1-x86_64                                                        100.9 KiB  4.93M/s 00:00 [###############################################################] 100%
 llvm-libs-4.0.1-5-x86_64                                                         12.5 MiB  4.95M/s 00:03 [###############################################################] 100%
 libxml2-2.9.4+96+gfb56f80e-1-x86_64                                            1263.9 KiB  4.94M/s 00:00 [###############################################################] 100%
 mesa-17.1.5-1-x86_64                                                             12.7 MiB  4.96M/s 00:03 [###############################################################] 100%
 sdl2-2.0.5-4-x86_64                                                             576.7 KiB  4.94M/s 00:00 [###############################################################] 100%
 harfbuzz-1.4.7-1-x86_64                                                         359.4 KiB  5.01M/s 00:00 [###############################################################] 100%
 libpng-1.6.30-1-x86_64                                                          237.9 KiB  4.94M/s 00:00 [###############################################################] 100%
 libbluray-1.0.1-1-x86_64                                                        804.6 KiB  5.01M/s 00:00 [###############################################################] 100%
 libx264-2:148.20170521-1-x86_64                                                 369.6 KiB  4.94M/s 00:00 [###############################################################] 100%
 libjpeg-turbo-1.5.2-1-x86_64                                                    351.5 KiB  4.90M/s 00:00 [###############################################################] 100%
 libtiff-4.0.8-2-x86_64                                                          789.8 KiB  4.91M/s 00:00 [###############################################################] 100%
 orc-0.4.27-1-x86_64                                                             206.1 KiB  5.03M/s 00:00 [###############################################################] 100%
 ffmpeg-1:3.3.2-2-x86_64                                                           8.2 MiB  4.95M/s 00:02 [###############################################################] 100%
 jre8-openjdk-headless-8.u141-1-x86_64                                            25.9 MiB  4.96M/s 00:05 [###############################################################] 100%
 jre8-openjdk-8.u141-1-x86_64                                                    165.2 KiB  4.75M/s 00:00 [###############################################################] 100%
(58/58) checking keys in keyring                                                                          [###############################################################] 100%
(58/58) checking package integrity                                                                        [###############################################################] 100%
(58/58) loading package files                                                                             [###############################################################] 100%
(58/58) checking for file conflicts                                                                       [###############################################################] 100%
(58/58) checking available disk space                                                                     [###############################################################] 100%
:: Processing package changes...
( 1/58) upgrading glibc                                                                                   [###############################################################] 100%
Generating locales...
  en_US.UTF-8... done
Generation complete.
New optional dependencies for glibc
    gd: for memusagestat
( 2/58) upgrading gcc-libs                                                                                [###############################################################] 100%
( 3/58) upgrading libgcrypt                                                                               [###############################################################] 100%
( 4/58) upgrading libsystemd                                                                              [###############################################################] 100%
( 5/58) upgrading libtirpc                                                                                [###############################################################] 100%
( 6/58) upgrading zlib                                                                                    [###############################################################] 100%
( 7/58) upgrading apr                                                                                     [###############################################################] 100%
( 8/58) upgrading archlinux-keyring                                                                       [###############################################################] 100%
==> Appending keys from archlinux.gpg...
==> Locally signing trusted keys in keyring...
  -> Locally signing key DDB867B92AA789C165EEFA799B729B06A680C281...
  -> Locally signing key 684148BB25B49E986A4944C55184252D824B18E8...
  -> Locally signing key 91FFE0700E80619CEB73235CA88E23E377514E00...
  -> Locally signing key AB19265E5D7D20687D303246BA1DFB64FFF979E7...
  -> Locally signing key 0E8B644079F599DFC1DDC3973348882F6AC6A4C2...
  -> Locally signing key 44D4A033AC140143927397D47EFD567D4C7EA887...
==> Importing owner trust values...
gpg: setting ownertrust to 4
==> Disabling revoked keys in keyring...
  -> Disabling key 7FA647CD89891DEDC060287BB9113D1ED21E1A55...
  -> Disabling key D4DE5ABDE2A7287644EAC7E36D1A9E70E19DAA50...
  -> Disabling key 40440DC037C05620984379A6761FAD69BA06C6A9...
  -> Disabling key BC1FBE4D2826A0B51E47ED62E2539214C6C11350...
  -> Disabling key 63F395DE2D6398BBE458F281F2DBB4931985A992...
  -> Disabling key 8F76BEEA0289F9E1D3E229C05F946DED983D4366...
  -> Disabling key 81D7F8241DB38BC759C80FCE3A726C6170E80477...
  -> Disabling key 5E7585ADFF106BFFBBA319DC654B877A0864983E...
  -> Disabling key E7210A59715F6940CF9A4E36A001876699AD6E84...
  -> Disabling key F5A361A3A13554B85E57DDDAAF7EF7873CFD4BB6...
  -> Disabling key 9515D8A8EAB88E49BB65EDBCE6B456CAF15447D5...
  -> Disabling key 4A8B17E20B88ACA61860009B5CED81B7C2E5C0D2...
  -> Disabling key 0B20CA1931F5DA3A70D0F8D2EA6836E1AB441196...
  -> Disabling key 66BD74A036D522F51DD70A3C7F2A16726521E06D...
  -> Disabling key 27FFC4769E19F096D41D9265A04F9397CDFD6BB0...
==> Updating trust database...
gpg: next trustdb check due at 2017-10-20
( 9/58) upgrading p11-kit                                                                                 [###############################################################] 100%
(10/58) upgrading ca-certificates-mozilla                                                                 [###############################################################] 100%
(11/58) upgrading curl                                                                                    [###############################################################] 100%
(12/58) upgrading device-mapper                                                                           [###############################################################] 100%
(13/58) upgrading expat                                                                                   [###############################################################] 100%
(14/58) upgrading gnutls                                                                                  [###############################################################] 100%
(15/58) upgrading libssh                                                                                  [###############################################################] 100%
(16/58) upgrading opus                                                                                    [###############################################################] 100%
(17/58) upgrading libelf                                                                                  [###############################################################] 100%
(18/58) upgrading libunwind                                                                               [###############################################################] 100%
(19/58) upgrading llvm-libs                                                                               [###############################################################] 100%
(20/58) upgrading libxml2                                                                                 [###############################################################] 100%
(21/58) upgrading mesa                                                                                    [###############################################################] 100%
(22/58) upgrading sdl2                                                                                    [###############################################################] 100%
(23/58) upgrading pcre                                                                                    [###############################################################] 100%
(24/58) upgrading glib2                                                                                   [###############################################################] 100%
(25/58) upgrading harfbuzz                                                                                [###############################################################] 100%
(26/58) upgrading libpng                                                                                  [###############################################################] 100%
(27/58) upgrading libbluray                                                                               [###############################################################] 100%
(28/58) upgrading libx264                                                                                 [###############################################################] 100%
(29/58) upgrading libnl                                                                                   [###############################################################] 100%
(30/58) upgrading libusb                                                                                  [###############################################################] 100%
(31/58) upgrading popt                                                                                    [###############################################################] 100%
(32/58) upgrading systemd                                                                                 [###############################################################] 100%
Failed to get unit file state for systemd-resolved.service: Failed to activate service 'org.freedesktop.systemd1': timed out
(33/58) upgrading libjpeg-turbo                                                                           [###############################################################] 100%
(34/58) upgrading libtiff                                                                                 [###############################################################] 100%
(35/58) upgrading orc                                                                                     [###############################################################] 100%
(36/58) upgrading ffmpeg                                                                                  [###############################################################] 100%
(37/58) upgrading npth                                                                                    [###############################################################] 100%
(38/58) upgrading sqlite                                                                                  [###############################################################] 100%
(39/58) upgrading gnupg                                                                                   [###############################################################] 100%
(40/58) upgrading grep                                                                                    [###############################################################] 100%
(41/58) upgrading iproute2                                                                                [###############################################################] 100%
(42/58) upgrading nspr                                                                                    [###############################################################] 100%
(43/58) upgrading nss                                                                                     [###############################################################] 100%
(44/58) upgrading jre8-openjdk-headless                                                                   [###############################################################] 100%
(45/58) upgrading jre8-openjdk                                                                            [###############################################################] 100%
(46/58) upgrading libarchive                                                                              [###############################################################] 100%
(47/58) upgrading libevent                                                                                [###############################################################] 100%
(48/58) upgrading logrotate                                                                               [###############################################################] 100%
(49/58) upgrading thin-provisioning-tools                                                                 [###############################################################] 100%
(50/58) upgrading lvm2                                                                                    [###############################################################] 100%
(51/58) upgrading nano                                                                                    [###############################################################] 100%
(52/58) upgrading nfs-utils                                                                               [###############################################################] 100%
(53/58) upgrading pacman-mirrorlist                                                                       [###############################################################] 100%
warning: /etc/pacman.d/mirrorlist installed as /etc/pacman.d/mirrorlist.pacnew
(54/58) upgrading pacman                                                                                  [###############################################################] 100%
(55/58) upgrading psmisc                                                                                  [###############################################################] 100%
(56/58) upgrading s-nail                                                                                  [###############################################################] 100%
(57/58) upgrading systemd-sysvcompat                                                                      [###############################################################] 100%
(58/58) upgrading texinfo                                                                                 [###############################################################] 100%
:: Running post-transaction hooks...
(1/6) Updating udev hardware database...
(2/6) Updating system user accounts...
(3/6) Creating temporary files...
(4/6) Arming ConditionNeedsUpdate...
(5/6) Updating the info directory file...
(6/6) Rebuilding certificate stores...
[root@subsonic /]#

During the systemd update there was a delay and the message displayed above.
The last few lines of journalctl -n 500 ...

Jul 23 11:11:02 subsonic dbus[20]: [system] Reloaded configuration
Jul 23 11:11:02 subsonic dbus[20]: [system] Reloaded configuration
Jul 23 11:11:02 subsonic dbus[20]: [system] Reloaded configuration
Jul 23 11:11:02 subsonic dbus[20]: [system] Reloaded configuration
Jul 23 11:11:03 subsonic dbus[20]: [system] Reloaded configuration
Jul 23 11:11:03 subsonic dbus[20]: [system] Reloaded configuration
Jul 23 11:11:03 subsonic dbus[20]: [system] Reloaded configuration
Jul 23 11:11:03 subsonic systemd[1]: Reexecuting.
Jul 23 11:11:03 subsonic systemd[1]: systemd 233 running in system mode. (+PAM -AUDIT -SELINUX -IMA -APPARMOR +SMACK -SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ
Jul 23 11:11:03 subsonic systemd[1]: Detected virtualization lxc.
Jul 23 11:11:03 subsonic systemd[1]: Detected architecture x86-64.
Jul 23 11:11:03 subsonic systemd[1]: Failed to create /init.scope control group: Permission denied
Jul 23 11:11:03 subsonic systemd[1]: Failed to allocate manager object: Permission denied
Jul 23 11:11:03 subsonic systemd[1]: Freezing execution.
Jul 23 11:11:28 subsonic dbus[20]: [system] Failed to activate service 'org.freedesktop.systemd1': timed out
lines 456-501/501 (END)

At this point the container won't shutdown either from within the container with poweroff or from outside with lxc-stop -n subsonic. Both cmmands just hang and I have to reboot the host machine to get it to stop (don't know of any other way but I'm open to suggestions!). After host reboot I started the container and attached to it with lxc-attach -n subsonic. Last few lines of journalctl shows this ...

Jul 23 11:11:02 subsonic dbus[20]: [system] Reloaded configuration
Jul 23 11:11:02 subsonic dbus[20]: [system] Reloaded configuration
Jul 23 11:11:02 subsonic dbus[20]: [system] Reloaded configuration
Jul 23 11:11:02 subsonic dbus[20]: [system] Reloaded configuration
Jul 23 11:11:03 subsonic dbus[20]: [system] Reloaded configuration
Jul 23 11:11:03 subsonic dbus[20]: [system] Reloaded configuration
Jul 23 11:11:03 subsonic dbus[20]: [system] Reloaded configuration
Jul 23 11:11:03 subsonic systemd[1]: Reexecuting.
Jul 23 11:11:03 subsonic systemd[1]: systemd 233 running in system mode. (+PAM -AUDIT -SELINUX -IMA -APPARMOR +SMACK -SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ
Jul 23 11:11:03 subsonic systemd[1]: Detected virtualization lxc.
Jul 23 11:11:03 subsonic systemd[1]: Detected architecture x86-64.
Jul 23 11:11:03 subsonic systemd[1]: Failed to create /init.scope control group: Permission denied
Jul 23 11:11:03 subsonic systemd[1]: Failed to allocate manager object: Permission denied
Jul 23 11:11:03 subsonic systemd[1]: Freezing execution.
Jul 23 11:11:28 subsonic dbus[20]: [system] Failed to activate service 'org.freedesktop.systemd1': timed out
Jul 23 11:15:26 subsonic dbus[20]: [system] Failed to activate service 'org.freedesktop.systemd1': timed out
Jul 23 11:15:32 subsonic systemd-journald[14]: Journal stopped
lines 56-101/101 (END)

top shows this ...

PID USER      PR  NI    VIRT    RES  %CPU %MEM     TIME+ S COMMAND                                                                                                            
    1 root      20   0   53.8m   2.7m   0.0  0.0   0:00.02 S systemd                                                                                                            
    2 root      20   0   21.6m   2.3m   0.0  0.0   0:00.01 S bash                                                                                                               
    9 root      20   0   39.3m   2.0m   0.0  0.0   0:00.00 R  `- top

listing cgroups inside container now shows ...

[root@subsonic /]# ls -lh /sys/fs/cgroup
total 0
drwxrwxr-x 2 nobody root    0 Jul 23 20:06 blkio
lrwxrwxrwx 1 root   root   11 Jul 23 20:06 cpu -> cpu,cpuacct
drwxrwxr-x 2 nobody root    0 Jul 23 20:06 cpu,cpuacct
lrwxrwxrwx 1 root   root   11 Jul 23 20:06 cpuacct -> cpu,cpuacct
drwxrwxr-x 2 nobody root    0 Jul 23 20:06 cpuset
drwxrwxr-x 2 nobody root    0 Jul 23 20:06 devices
drwxrwxr-x 2 nobody root    0 Jul 23 20:06 freezer
drwxrwxr-x 2 nobody root    0 Jul 23 20:06 memory
lrwxrwxrwx 1 root   root   16 Jul 23 20:06 net_cls -> net_cls,net_prio
drwxrwxr-x 2 nobody root    0 Jul 23 20:06 net_cls,net_prio
lrwxrwxrwx 1 root   root   16 Jul 23 20:06 net_prio -> net_cls,net_prio
drwxrwxr-x 2 nobody root    0 Jul 23 20:06 perf_event
drwxrwxr-x 2 nobody root    0 Jul 23 20:06 pids
drwxrwxr-x 2 nobody root    0 Jul 23 20:06 systemd
drwxr-xr-x 2 nobody nobody  0 Jul 23 20:06 unified
[root@subsonic /]#

"unified" now does appear but owned by "nobody:nobody" while others are all owned by the root group. Perhaps this is the issue? But why is unified owned by nobody group and not root like everything else? This is an unprivileged container which is started by root on the host but all processes in the container effectively run as nobody from the host point of view. users/groups 0 - 65536 inside the container are mapped to 100000 - 165536 outside the container. On the host machine I have this in the /etc/subuid file & /etc/subgid file ...

root:100000:65536

and this is the container configuration file ....

[justin@IXTREME ~]$ cat /zfsdata/lxcstore/subsonic/config
cat: /zfsdata/lxcstore/subsonic/config: Permission denied
[justin@IXTREME ~]$ sudo cat /zfsdata/lxcstore/subsonic/config
[sudo] password for justin: 
# Template used to create this container: /usr/share/lxc/templates/lxc-download
# Parameters passed to the template:
# Template script checksum (SHA-1): 9748088977ba845f625e45659f305a5395c2dc7b
# For additional config options, please look at lxc.container.conf(5)

# Uncomment the following line to support nesting containers:
#lxc.include = /usr/share/lxc/config/nesting.conf
# (Be aware this has security implications)


# Distribution configuration
lxc.include = /usr/share/lxc/config/archlinux.common.conf
lxc.include = /usr/share/lxc/config/archlinux.userns.conf
lxc.arch = x86_64

# Container specific configuration
lxc.id_map = u 0 100000 65536
lxc.id_map = g 0 100000 65536
lxc.mount.entry = /zfsdata/justin/Music /zfsdata/lxcstore/subsonic/rootfs/var/subsonic/media/Music none bind,create=dir 0 0
lxc.mount.entry = /zfsdata/justin/Videos /zfsdata/lxcstore/subsonic/rootfs/var/subsonic/media/Videos none bind,create=dir 0 0
#lxc.start.auto = 1
#lxc.start.order = 0
#lxc.start.delay = 0
#lxc.group = onboot
lxc.rootfs = /zfsdata/lxcstore/subsonic/rootfs
lxc.rootfs.backend = zfs
lxc.utsname = subsonic

# Network configuration
lxc.network.type = veth
lxc.network.link = br0
lxc.network.flags = up
lxc.network.ipv4 = 192.168.1.4/24
lxc.network.ipv4.gateway = 192.168.1.1
lxc.network.name = eth0
[justin@IXTREME ~]$

This configuration has been working perfectly well until systemd was updated from 232-8 to 233.75-3 inside the container. So this leads me to reporting it as a systemd issue, but I accept I may be wrong and it could be an issue with this uid:gid mapping mechanism in lxc. I'm hoping some more knowledgeable folk can tell me the answer!
@evverx i've never used strace before but I just tried to run strace pacman -Syu in the container after rolling it back to a good snapshot. the output from strace was verbose to say the least! Can you recommend some strace switches / options to use?

@evverx
Copy link
Member

evverx commented Jul 24, 2017

Thank you for the feedback. I think I understand what is going on.

First of all, the issue can be worked around by passing systemd.legacy_systemd_cgroup_controller=yes to systemd, that is

lxc-start -n arch /sbin/init systemd.legacy_systemd_cgroup_controller=yes

Both cmmands just hang and I have to reboot the host machine to get it to stop (don't know of any other way but I'm open to suggestions!).

systemctl -ff poweroff

can be run inside a container to shut it down. Also, it's possible to "kill" a container by running the following commands outside it:

PID=$(lxc-info -n <name-of-the-container> -p -H)
kill -9 $PID

Can you recommend some strace switches / options to use?

Yes, I can, but I've already reproduced the issue, so I think that is not needed any more.

statfs("/sys/fs/cgroup/unified/", 0x7ffcac88ddf0) = -1 ENOENT (No such file or directory)
mkdir("/sys/fs/cgroup/unified", 0755)   = 0
mount("cgroup", "/sys/fs/cgroup/unified", "cgroup2", MS_NOSUID|MS_NODEV|MS_NOEXEC, NULL) = 0
statfs("/sys/fs/cgroup/unified/", {f_type=CGROUP2_SUPER_MAGIC, f_bsize=4096, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0, f_ffree=0, f_fsid={val=[0, 0]}, f_namelen=255, f_frsize=4096, f_flags=ST_VALID|ST_NOSUID|ST_NODEV|ST_NOEXEC|ST_RELATIME}) = 0
statfs("/sys/fs/cgroup/unified/", {f_type=CGROUP2_SUPER_MAGIC, f_bsize=4096, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0, f_ffree=0, f_fsid={val=[0, 0]}, f_namelen=255, f_frsize=4096, f_flags=ST_VALID|ST
_NOSUID|ST_NODEV|ST_NOEXEC|ST_RELATIME}) = 0
newfstatat(AT_FDCWD, "/sys/fs/cgroup/unified", {st_dev=makedev(0, 23), st_ino=262, st_mode=S_IFDIR|0755, st_nlink=2, st_uid=65534, st_gid=65534, st_blksize=4096, st_blocks=0, st_size=0, st_atime=150085185
4 /* 2017-07-23T23:17:34.922020021+0000 */, st_atime_nsec=922020021, st_mtime=1500851854 /* 2017-07-23T23:17:34.922020021+0000 */, st_mtime_nsec=922020021, st_ctime=1500851854 /* 2017-07-23T23:17:34.9220$
0021+0000 */, st_ctime_nsec=922020021}, AT_SYMLINK_NOFOLLOW) = 0
stat("/sys/fs/cgroup/unified", {st_dev=makedev(0, 23), st_ino=262, st_mode=S_IFDIR|0755, st_nlink=2, st_uid=65534, st_gid=65534, st_blksize$
4096, st_blocks=0, st_size=0, st_atime=1500851854 /* 2017-07-23T23:17:34.922020021+0000 */, st_atime_nsec=922020021, st_mtime=1500851854 /* 2017-07-23T23:17:34.922020021+0000 */, st_mtime_nsec=922020021,
st_ctime=1500851854 /* 2017-07-23T23:17:34.922020021+0000 */, st_ctime_nsec=922020021}) = 0
mkdir("/sys/fs/cgroup/unified/init.scope", 0755) = -1 EACCES (Permission denied)

I think this is a bug. The hybrid hierarchy doesn't seem to be supposed to break tools which work well with the legacy hierarchy, and systemd.legacy_systemd_cgroup_controller=yes should not be used explicitly to fix everything.

@evverx evverx added bug 🐛 Programming errors, that need preferential fixing and removed needs-reporter-feedback ❓ There's an unanswered question, the reporter needs to answer labels Jul 24, 2017
brauner pushed a commit to brauner/lxc that referenced this issue Jul 26, 2017
Closes lxc#1669.
Closes lxc#1678.
Relates to systemd/systemd#6408.

Signed-off-by: Christian Brauner <christian.brauner@ubuntu.com>
@brauner
Copy link
Contributor

brauner commented Jul 26, 2017

@evverx, thanks for commenting on the https://github.com/lxc/lxc issue. :) I just sent a branch to handle the empty v2 hierarchy!

@evverx
Copy link
Member

evverx commented Jul 27, 2017

@brauner , thank you for fixing lxc/lxc#1678.

Now I'm wondering what should be done to see the following

Cannot determine cgroup we are running in: No medium found
Failed to allocate manager object: No medium found

:)

For the record, I've just seen it in lxc/lxc#1669.

@brauner
Copy link
Contributor

brauner commented Jul 27, 2017

Yeah, I'm not completely sure either. What does systemd >= 233 do if the underlying kernel doesn't support cgroup v2?

@brauner
Copy link
Contributor

brauner commented Jul 27, 2017

If this requires a patch in systemd I'm happy to send one. Did it before. :)

@evverx
Copy link
Member

evverx commented Jul 27, 2017

systemd is supposed to ignore cgroup2 if cgroup2 is not supported and that seems to happen on the host in lxc/lxc#1669, but it appears that something goes wrong when systemd is run inside the container.

If this requires a patch in systemd I'm happy to send one.

That would be great!

stgraber pushed a commit to lxc/lxc that referenced this issue Aug 14, 2017
Closes #1669.
Closes #1678.
Relates to systemd/systemd#6408.

Signed-off-by: Christian Brauner <christian.brauner@ubuntu.com>
stgraber pushed a commit to lxc/lxc-pkg-ubuntu that referenced this issue Aug 22, 2017
Closes #1669.
Closes #1678.
Relates to systemd/systemd#6408.

Signed-off-by: Christian Brauner <christian.brauner@ubuntu.com>
@evverx
Copy link
Member

evverx commented Nov 21, 2017

The fix is waiting in #7401.

@evverx evverx added the has-pr label Nov 21, 2017
evverx added a commit to evverx/systemd that referenced this issue Nov 21, 2017
…roup/unified`

It's possible for `systemd` inside an unprivileged user namespace container
to be able to mount `cgroup2` on `/sys/fs/cgroup/unified` without being able
to create directories there.  When this happens, `systemd` fails to boot, making
it impossible to reexecute itself without restarting the container runtime.

In this patch the issue is avoided by trying creating a temporary directory
after mounting `cgroup2` and falling back to `v1` if `mkdir` fails.

Closes systemd#6408 and lxc/lxc#1678.
evverx added a commit to evverx/systemd that referenced this issue Nov 21, 2017
…roup/unified`

It's possible for `systemd` inside an unprivileged user namespace container
to be able to mount `cgroup2` on `/sys/fs/cgroup/unified` without being able
to create directories there.  When this happens, `systemd` fails to boot, making
it impossible to reexecute itself without restarting the container runtime.

In this patch the issue is avoided by trying creating a temporary directory
after mounting `cgroup2` and falling back to `v1` if `mkdir` fails.

Closes systemd#6408 and lxc/lxc#1678.
@evverx evverx removed the has-pr label Nov 22, 2017
brauner pushed a commit to brauner/systemd that referenced this issue Nov 22, 2017
When systemd is running inside a container employing user
namespaces it currently mounts the unified cgroup hierarchy
without being able to write to it. This causes systemd to
freeze during boot.
This patch checks whether the unified cgroup hierarchy
is writable. If it is not it will not mount it.

This solution is based on a patch by Evgeny Vereshchagin.

Closes systemd#6408.
Closes lxc/lxc#1678 .
@evverx evverx added the has-pr label Nov 22, 2017
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug 🐛 Programming errors, that need preferential fixing cgroups pid1
Development

No branches or pull requests

5 participants