Fedora Account System
Red Hat Associate
Red Hat Customer
Description of problem: I boot my laptop, display manager pops up (lightdm or gdm) and /run/user/1000 is owned by root. This breaks a lot of my apps: I can't even start my XFCE session because of this. When I change to different VT and chown it to my user, it usually fixes most of the problems. Version-Release number of selected component (if applicable): systemd-239-6.git9f3aed1.fc29.x86_64
Created attachment 1504734 [details] journalctl logs, ll /run/user/1000
Lukas suggested to strace the binary which creates the directory: Nov 13 16:50:42 hops strace[2639]: mkdir("/run/user/1000", 0700) = 0 Nov 13 16:50:42 hops strace[2639]: openat(AT_FDCWD, "/proc/thread-self/attr/fscreate", O_RDWR|O_CLOEXEC) = 4 Nov 13 16:50:42 hops strace[2639]: write(4, NULL, 0) = 0 Nov 13 16:50:42 hops strace[2639]: close(4) = 0 Nov 13 16:50:42 hops strace[2639]: mount("tmpfs", "/run/user/1000", "tmpfs", MS_NOSUID|MS_NODEV, "mode=0700,uid=1000,gid=1000,size"...) = 0 Nov 13 16:50:42 hops strace[2639]: openat(AT_FDCWD, "/run/user/1000", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 4 Nov 13 16:50:42 hops strace[2639]: fstat(4, {st_mode=S_IFDIR|0700, st_size=40, ...}) = 0 Nov 13 16:50:42 hops strace[2639]: setxattr("/proc/self/fd/4", "security.selinux", "system_u:object_r:user_tmp_t:s0", 32, 0) = 0 Nov 13 16:50:42 hops strace[2639]: close(4) = 0 Nov 13 16:50:42 hops strace[2639]: exit_group(0) = ? Nov 13 16:50:42 hops strace[2639]: +++ exited with 0 +++ I'm not sure if chown should follow but even when the mount has args uid=1000 it's still owned by root. Is this is a bug in systemd or kernel?
Current status: systemd code seems to be okay in the end: I added ls & tree to the unit above to verify status of the dir and it's correct: Nov 14 09:22:20 hops ls[2731]: drwx------. 2 tt tt 40 Nov 14 09:22 /run/user/1000 Nov 14 09:22:20 hops tree[2733]: /run/user/1000 Nov 14 09:22:20 hops tree[2733]: 0 directories, 0 files So there seems to be some other service or tool which changes the ownership to root, which is...
Is the directory still mounted later? What does 'findmnt /run/user/1000` show? FTR, here I see: $ findmnt /run/user/1000 TARGET SOURCE FSTYPE OPTIONS /run/user/1000 tmpfs tmpfs rw,nosuid,nodev,relatime,seclabel,size=803568k,mode=700,uid=1000,gid=1000 Also, please paste 'systemtl status user-runtime-dir /run/user/1000'. Does disabling selinux make a difference?
$ findmnt /run/user/1000 TARGET SOURCE FSTYPE OPTIONS /run/user/1000 tmpfs tmpfs rw,nosuid,nodev,relatime,seclabel,size=1630452k,mode=700,uid=1000,gid=1000 ● user-runtime-dir - User Runtime Directory /run/user/1000 Loaded: loaded (/usr/lib/systemd/system/user-runtime-dir@.service; static; vendor preset: disabled) Drop-In: /etc/systemd/system/user-runtime-dir.d └─override.conf Active: active (exited) since Thu 2018-11-15 09:23:31 CET; 3h 37min ago Docs: man:user@.service(5) Process: 2858 ExecStop=/usr/bin/strace /usr/lib/systemd/systemd-user-runtime-dir stop 1000 (code=exited, status=0/SUCCESS) Process: 3029 ExecStart=/usr/bin/tree /run/user/1000 (code=exited, status=0/SUCCESS) Process: 3028 ExecStart=/bin/ls -lhad /run/user/1000 (code=exited, status=0/SUCCESS) Process: 3021 ExecStart=/usr/bin/strace /usr/lib/systemd/systemd-user-runtime-dir start 1000 (code=exited, status=0/SUCCESS) Main PID: 3029 (code=exited, status=0/SUCCESS) nov 15 09:23:31 hops strace[3021]: openat(AT_FDCWD, "/run/user/1000", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 4 nov 15 09:23:31 hops strace[3021]: fstat(4, {st_mode=S_IFDIR|0700, st_size=40, ...}) = 0 nov 15 09:23:31 hops strace[3021]: setxattr("/proc/self/fd/4", "security.selinux", "system_u:object_r:user_tmp_t:s0", 32, 0) = 0 nov 15 09:23:31 hops strace[3021]: close(4) = 0 nov 15 09:23:31 hops strace[3021]: exit_group(0) = ? nov 15 09:23:31 hops strace[3021]: +++ exited with 0 +++ nov 15 09:23:31 hops ls[3028]: drwx------. 2 tt tt 40 Nov 15 09:23 /run/user/1000 nov 15 09:23:31 hops tree[3029]: /run/user/1000 nov 15 09:23:31 hops tree[3029]: 0 directories, 0 files nov 15 09:23:31 hops systemd[1]: Started User Runtime Directory /run/user/1000. ● run-user-1000.mount - /run/user/1000 Loaded: loaded (/proc/self/mountinfo) Active: active (mounted) since Thu 2018-11-15 09:23:31 CET; 3h 37min ago Where: /run/user/1000 What: tmpfs SELinux is in permissive mode. I went through the journal logs once more and I can't see anything which would explicitly tell who changed the ownership.
Please install inotify-tools and run $ systemd-run inotifywait --syslog -e attrib,create -m -r /run/user (or this could be made into a unit: # /etc/systemd/system/monitor.service [Service] ExecStart=/bin/inotifywait --syslog -e attrib,create -m -r /run/user $ systemctl start monitor ) This will interleave information in the journal with information what is being started. Hopefully this we give a hint what is changing the permissions.
What a heisenbug! This really has to be a race condition. $ systemctl cat who-changed-run-user2.service # /etc/systemd/system/who-changed-run-user2.service [Unit] Requires=user-runtime-dir After=user-runtime-dir [Service] Type=simple ExecStart=/bin/inotifywait --syslog -e attrib,create -m /run/user/1000 [Install] WantedBy=sysinit.target Logs: Nov 16 10:22:03 hops systemd[1]: Started who-changed-run-user2.service. Nov 16 10:22:03 hops inotifywait[1129]: Setting up watches. Nov 16 10:22:03 hops inotifywait[1129]: Watches established. Nov 16 10:22:05 hops inotifywait[1129]: /run/user/1000/ CREATE,ISDIR bus Nov 16 10:22:05 hops inotifywait[1129]: /run/user/1000/ ATTRIB,ISDIR bus Nov 16 10:22:12 hops inotifywait[1129]: /run/user/1000/ CREATE,ISDIR systemd Nov 16 10:22:12 hops inotifywait[1129]: /run/user/1000/ CREATE,ISDIR pulse Nov 16 10:22:12 hops inotifywait[1129]: /run/user/1000/ CREATE pipewire-0 Nov 16 10:22:12 hops inotifywait[1129]: /run/user/1000/ ATTRIB pipewire-0 Nov 16 10:22:12 hops inotifywait[1129]: /run/user/1000/ ATTRIB,ISDIR pulse Nov 16 10:25:27 hops inotifywait[1129]: /run/user/1000/ CREATE,ISDIR keyring Nov 16 10:25:27 hops inotifywait[1129]: /run/user/1000/ CREATE,ISDIR gdm Nov 16 10:25:27 hops inotifywait[1129]: /run/user/1000/ CREATE,ISDIR dbus-1 Nov 16 10:25:28 hops inotifywait[1129]: /run/user/1000/ CREATE,ISDIR gvfs Nov 16 10:25:28 hops inotifywait[1129]: /run/user/1000/ CREATE,ISDIR dconf Nov 16 10:25:28 hops inotifywait[1129]: /run/user/1000/ CREATE,ISDIR gnupg Nov 16 10:25:29 hops inotifywait[1129]: /run/user/1000/ CREATE,ISDIR Nextcloud But most importantly, the dir is suddenly owned by my user and not root: $ ls -lhd /run/user/1000 drwx------. 12 tt tt 260 Nov 16 10:25 /run/user/1000 Since dbus is always first to act on that dir, it's my prime suspect.
Maybe you could use trace tool from bcc-tools package to figure out what is changing ownership of the directory. Bellow command will start tracing globally all the callers (PID + comm) of chown_common() kernel function which is used by all syscalls from (l|f)chown family. Problem is that you won't know which file the chown_common() was called on. I was not able to figure out this information because it looks like gcc "rewrote" the function (due to optimizations) and actually dropped the struct path * pointer and it is no longer passed into the function (I see same also with debug kernel). To really get to bottom of this we would need to recompile the kernel without some aggressive gcc optimizations and then use "trace" again and get the filename from struct path *. $ dnf install -y bcc-tools kernel-devel $ /usr/share/bcc/tools/trace -T $(grep chown_common /proc/kallsyms | cut -d' ' -f3)
Michal, thanks for the suggestion. Since the issue "disappeared" thanks to the debugging steps, I feel like I'm good since no one else is experiencing this. I'll try to reproduce later this week.
After I updated my system recently, the problem disappeared completely. I can't even reproduce now. Thank you everyone for helping me out.