[systemd-devel] Systemd weird behavior after upgrade

[arnaud gaboury]

OS= Fedora 26
Linux container managed by machinectl

 % 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

% machinectl list
MACHINE CLASS     SERVICE        OS     VERSION ADDRESSES
poppy   container systemd-nspawn fedora 26      192.168.1.94...

% machinectl show poppy
Name=poppy
Id=59b720b533834a4eafe07a62c2482266
Timestamp=Wed 2017-07-12 22:07:15 CEST
TimestampMonotonic=6928076
Service=systemd-nspawn
Unit=systemd-nspawn at poppy.service
Leader=648
Class=container
RootDirectory=/var/lib/machines/poppy
State=running


-----------------------------------------------------------------------------------------------------

After upgrade from Fedora 25 to 26, some services are broken.
Below are some broken service status


% systemctl status user at 1000.service
● user at 1000.service - User Manager for UID 1000
   Loaded: loaded (/usr/lib/systemd/system/user at .service; static; vendor
preset: disabled)
   Active: failed (Result: protocol) since Wed 2017-07-12 22:09:45 CEST;
15h ago
 Main PID: 257 (code=exited, status=237/KEYRING)

Jul 12 22:09:45 thetradinghall.com systemd[1]: Starting User Manager for
UID 1000...
Jul 12 22:09:45 thetradinghall.com systemd[257]: user at 1000.service: Failed
at step KEYRING spawning /usr/lib/systemd/systemd: Permission denied
Jul 12 22:09:45 thetradinghall.com systemd[1]: Failed to start User Manager
for UID 1000.
Jul 12 22:09:45 thetradinghall.com systemd[1]: user at 1000.service: Unit
entered failed state.
Jul 12 22:09:45 thetradinghall.com systemd[1]: user at 1000.service: Failed
with result 'protocol'.


%  systemctl status user.slice
● user.slice - User and Session Slice
   Loaded: loaded (/usr/lib/systemd/system/user.slice; static; vendor
preset: disabled)
   Active: active since Wed 2017-07-12 22:07:15 CEST; 15h ago
     Docs: man:systemd.special(7)
   CGroup: /user.slice
           └─user-1000.slice
             ├─session-c1.scope
             │ ├─ 256 login -- poisonivy
             │ ├─ 258 -zsh
             │ ├─ 356 su
             │ ├─ 357 zsh
             │ ├─1553 systemctl status user.slice
             │ └─1554 less
             └─session-c2.scope
               ├─449 login -- poisonivy
               ├─450 -zsh
               ├─494 su
               ├─495 zsh
               └─526 /usr/bin/python3 -O /usr/bin/ranger

Jul 12 22:09:45 thetradinghall.com systemd[1]: user.slice: Failed to set
invocation ID on control group /user.slice, ignoring: Operation not
permitted

% systemctl status opendkim.service
● opendkim.service - DomainKeys Identified Mail (DKIM) Milter
   Loaded: loaded (/usr/lib/systemd/system/opendkim.service; enabled;
vendor preset: disabled)
  Drop-In: /etc/systemd/system/opendkim.service.d
           └─override.conf
   Active: failed (Result: exit-code) since Thu 2017-07-13 11:33:25 CEST;
2h 30min ago
     Docs: man:opendkim(8)
           man:opendkim.conf(5)
           man:opendkim-genkey(8)
           man:opendkim-genzone(8)
           man:opendkim-testadsp(8)
           man:opendkim-testkey
           http://www.opendkim.org/docs.html

Jul 13 11:33:25 thetradinghall.com systemd[1]: Starting DomainKeys
Identified Mail (DKIM) Milter...
Jul 13 11:33:25 thetradinghall.com systemd[1243]: opendkim.service: Failed
at step KEYRING spawning /usr/sbin/opendkim: Permission denied

*N.B:* I can manually start opendkim as root
------------------------------------------------------

I have no ideas why these new issues. The only hint is the following one.

I build my kernel with CONFIG_USER_NS=y since a while. I guess it is this
setting which cause the following trouble with UID/GID

>From host
root at hortensia ➤➤ ~aur # ls -al $POPPY/var/log/journal
total 0
drwxr-xr-x+ 1 vu-poppy-0 systemd-journal   64 Oct  4  2016 ./
drwxr-xr-x  1 vu-poppy-0 vg-poppy-0      1.3K Jul 12 20:20 ../
drwxr-sr-x+ 1 root       systemd-journal 7.8K Mar 11 15:25
59b720b533834a4eafe07a62c2482266/

>From container:
root at thetradinghall ➤➤ dovecot/conf.d # ls -al /var/log/journal
total 0
drwxr-xr-x+ 1 root   nobody   64 Oct  4  2016 ./
drwxr-xr-x  1 root   root   1.3K Jul 12 20:20 ../
drwxr-sr-x+ 1 nobody nobody 7.8K Mar 11 15:25
59b720b533834a4eafe07a62c2482266/

As you can see, on host, root:root is by default vu-poppy-0 vg-poppy-0
On container, I am left with lots of files/folders owned by nobody.

---------------------------
When looking at the output of systemctl --failed, and verifying status, I
can observe a commun failure, like the one below:

 postgresql.service: Failed at step KEYRING spawning
/usr/libexec/postgresql-check-db-dir: Permission denied

-----------------------------

When upgrading some package, I have again a permission issue.

# dnf upgrade filesystem
......................
error: unpacking of archive failed on file /proc: cpio: chown

# ls -al /proc/filesystems
.........
-r--r--r-- 1 nobody nobody 0 Jul 13 14:22 /proc/filesystems
.....................
 # chown root:root /proc/filesystems
chown: changing ownership of '/proc/filesystems': Operation not permitted
-------------------------------------

Can anyone help me in debugging my system, as it starts to be difficult to
use the container. Thank you
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/systemd-devel/attachments/20170713/26a0efdc/attachment.html>