Bug 2133187

Summary: kinoite rawhide 20221008 doesn't set XDG evars, missing /run/user/uid dir
Product: [Fedora] Fedora Reporter: jonikelee
Component: systemdAssignee: systemd-maint
Status: CLOSED CURRENTRELEASE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 38CC: besser82, fedoraproject, filbranden, flepied, ipedrosa, jonikelee, lnykryn, msekleta, ryncsn, ssahani, s, systemd-maint, tm, yuwatana, zbyszek
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2024-03-23 17:13:22 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
/var/log/boot.log
none
journalctl --boot none

Description jonikelee 2022-10-08 14:55:30 UTC 
Description of problem:

After upgrading from Kinoite Rawhide 20221007 to 20221008, most XDG evars (including XDG_RUNTIME_DIR) are not set at login.  This causes startplasma-wayland (via console login) to fail with:
QStandardPaths: XDG_RUNTIME_DIR not set, defaulting to '/tmp/runtime-user1'
startplasmacompositor: Could not start D-Bus.  Can you call qdbus?

Also, other pam-related things seem broken, such as doing 'systemctl reboot' gets: Call to Reboot failed: Interactive authentication required.  With sudo it works, though.  Also, /run/user is not populated.

Version-Release number of selected component (if applicable):
20221008

How reproducible:
happens at every login

I have somewhat unusual setup - I disabled sddm (systemctl disable sddm) to force console logins, and also removed --xwayland option from kwin_wayland.  But the pam/XDG evars happens well before any of these changes should have an impact.

Steps to Reproduce:
1. systemctl disable sddm (to force console login)
2. upgrade to kinoite rawhide 20221008
3. login and check XDG_RUNTIME_DIR and /run/user/

Actual results:
XDG_RUNTIME_DIR unset, /run/user/ empty

Expected results:
XDG_RUNTIME_DIR set to /run/user/1000, /run/user/1000 present

Additional info:
I'm rolling back to 20221007.
Comment 1 Iker Pedrosa 2022-10-10 07:32:09 UTC 
XDG_RUNTIME_DIR isn't set by PAM but by pam_systemd, so I'm changing the component to it.
Comment 2 Lukáš Nykrýn 2022-10-17 12:08:21 UTC 
Can you please reproduce the issue and attach the logs.
Comment 3 jonikelee 2022-10-20 16:06:20 UTC 
@lnykryn 

Which logs do you want?
Comment 4 jonikelee 2022-10-20 16:15:09 UTC 
I am having a problem getting back to that particular version of rawhide.  I tried:
"rpm-ostree deploy Rawhide.20221008.n.0", but got this:
"error: Version Rawhide.20221008.n.0 not found in fedora:fedora/36/x86_64/kinoite"

How do I get back to that particular version of kinoite rawhide?  I will instead try the most recent rawhide.
Comment 5 jonikelee 2022-10-20 16:47:10 UTC 
Created attachment 1919288 [details]
/var/log/boot.log

I replicated the bug in kinoite Rawhide.20221017.n.0.  Attached is the boot.log.  If you want a different log, please specify which.
Comment 6 jonikelee 2022-10-20 17:35:35 UTC 
Created attachment 1919293 [details]
journalctl --boot

Attaching the output of journalctl --boot as well (a different boot, but the problem is still there).
Comment 7 Zbigniew Jędrzejewski-Szmek 2022-12-08 22:25:25 UTC 
Oct 20 13:30:04 fedora kernel: ------------[ cut here ]------------
Oct 20 13:30:04 fedora kernel: DMA-API: virtio-pci 0000:00:02.0: mapping sg segment longer than device claims to support [len=974848] [max=65536]
Oct 20 13:30:04 fedora kernel: WARNING: CPU: 0 PID: 454 at kernel/dma/debug.c:1160 debug_dma_map_sg+0x32c/0x380
Oct 20 13:30:04 fedora kernel: Modules linked in: crct10dif_pclmul crc32_pclmul crc32c_intel polyval_clmulni polyval_generic 9pnet_virtio ghash_clmulni_intel 9pnet virtio_gpu(+) sha512_ssse3 serio_raw virtio_dma_buf floppy ata_generic pata_acpi scsi_dh_rdac scsi_dh_emc scsi_dh_alua ip6_tables ip_tables dm_multipath fuse qemu_fw_cfg
Oct 20 13:30:04 fedora kernel: CPU: 0 PID: 454 Comm: plymouthd Not tainted 6.1.0-0.rc0.20221014git9c9155a3509a.11.fc38.x86_64 #1
Oct 20 13:30:04 fedora kernel: Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
Oct 20 13:30:04 fedora kernel: RIP: 0010:debug_dma_map_sg+0x32c/0x380
Oct 20 13:30:04 fedora kernel: Code: 5c 24 10 8b 4c 24 18 48 8b 54 24 20 48 89 c6 44 8b 44 24 2c 48 c7 c7 58 6b 92 aa 4c 89 5c 24 10 4c 89 4c 24 08 e8 48 6c d3 00 <0f> 0b 4c 8b 5c 24 10 4c 8b 4c 24 08 8b 15 a2 a6 43 02 85 d2 0f 85
Oct 20 13:30:04 fedora kernel: RSP: 0018:ffffc307010b7b28 EFLAGS: 00010282
Oct 20 13:30:04 fedora kernel: RAX: 0000000000000072 RBX: ffffa0f0018e80d0 RCX: 0000000000000000
Oct 20 13:30:04 fedora kernel: RDX: 0000000000000001 RSI: ffffffffaa98eb83 RDI: 00000000ffffffff
Oct 20 13:30:04 fedora kernel: RBP: ffffa0f00cb60f60 R08: 0000000000000000 R09: ffffc307010b79c0
Oct 20 13:30:04 fedora kernel: R10: 0000000000000003 R11: ffffffffab366328 R12: 0000000000000000
Oct 20 13:30:04 fedora kernel: R13: 0000000000000003 R14: 0000000000000003 R15: ffffa0f001947880
Oct 20 13:30:04 fedora kernel: FS:  00007f103f5af740(0000) GS:ffffa0f03b600000(0000) knlGS:0000000000000000
Oct 20 13:30:04 fedora kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Oct 20 13:30:04 fedora kernel: CR2: 00007f48973b6000 CR3: 000000010d00e001 CR4: 0000000000060ef0
Oct 20 13:30:04 fedora kernel: Call Trace:
Oct 20 13:30:04 fedora kernel:  <TASK>
Oct 20 13:30:04 fedora kernel:  __dma_map_sg_attrs+0xb9/0x100
Oct 20 13:30:04 fedora kernel:  dma_map_sgtable+0x19/0x30
Oct 20 13:30:04 fedora kernel:  drm_gem_shmem_get_pages_sgt+0x8c/0xf0
Oct 20 13:30:04 fedora kernel:  virtio_gpu_object_create+0x99/0x320 [virtio_gpu]
Oct 20 13:30:04 fedora kernel:  virtio_gpu_mode_dumb_create+0xd0/0x180 [virtio_gpu]
Oct 20 13:30:04 fedora kernel:  ? drm_mode_create_dumb+0x90/0x90
Oct 20 13:30:04 fedora kernel:  drm_ioctl_kernel+0xac/0x160
Oct 20 13:30:04 fedora kernel:  drm_ioctl+0x1e7/0x450
Oct 20 13:30:04 fedora kernel:  ? drm_mode_create_dumb+0x90/0x90
Oct 20 13:30:04 fedora kernel:  __x64_sys_ioctl+0x90/0xd0
Oct 20 13:30:04 fedora kernel:  do_syscall_64+0x5b/0x80
Oct 20 13:30:04 fedora kernel:  ? kvm_clock_get_cycles+0x14/0x30
Oct 20 13:30:04 fedora kernel:  ? ktime_get+0x4d/0xb0
Oct 20 13:30:04 fedora kernel:  ? lapic_next_deadline+0x28/0x30
Oct 20 13:30:04 fedora kernel:  ? clockevents_program_event+0x96/0x100
Oct 20 13:30:04 fedora kernel:  ? kvm_sched_clock_read+0x14/0x40
Oct 20 13:30:04 fedora kernel:  ? lock_is_held_type+0xe8/0x140
Oct 20 13:30:04 fedora kernel:  ? asm_sysvec_apic_timer_interrupt+0x16/0x20
Oct 20 13:30:04 fedora kernel:  ? lockdep_hardirqs_on+0x7d/0x100
Oct 20 13:30:04 fedora kernel:  entry_SYSCALL_64_after_hwframe+0x63/0xcd
Oct 20 13:30:04 fedora kernel: RIP: 0033:0x7f103f7e204f
Oct 20 13:30:04 fedora kernel: Code: 00 48 89 44 24 18 31 c0 48 8d 44 24 60 c7 04 24 10 00 00 00 48 89 44 24 08 48 8d 44 24 20 48 89 44 24 10 b8 10 00 00 00 0f 05 <89> c2 3d 00 f0 ff ff 77 18 48 8b 44 24 18 64 48 2b 04 25 28 00 00
Oct 20 13:30:04 fedora kernel: RSP: 002b:00007ffc60b73090 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
Oct 20 13:30:04 fedora kernel: RAX: ffffffffffffffda RBX: 0000000000000404 RCX: 00007f103f7e204f
Oct 20 13:30:04 fedora kernel: RDX: 00007ffc60b73150 RSI: 00000000c02064b2 RDI: 0000000000000009
Oct 20 13:30:04 fedora kernel: RBP: 00007ffc60b73150 R08: 00007f103f8b4c70 R09: 0000000000000404
Oct 20 13:30:04 fedora kernel: R10: 0000000000000700 R11: 0000000000000246 R12: 00000000c02064b2
Oct 20 13:30:04 fedora kernel: R13: 0000000000000009 R14: 0000000000000700 R15: 0000556ce667d2f0
Oct 20 13:30:04 fedora kernel:  </TASK>
Oct 20 13:30:04 fedora kernel: irq event stamp: 64057
Oct 20 13:30:04 fedora kernel: hardirqs last  enabled at (64063): [<ffffffffa918e21e>] __up_console_sem+0x5e/0x70
Oct 20 13:30:04 fedora kernel: hardirqs last disabled at (64068): [<ffffffffa918e203>] __up_console_sem+0x43/0x70
Oct 20 13:30:04 fedora kernel: softirqs last  enabled at (63428): [<ffffffffa91012ed>] __irq_exit_rcu+0xed/0x160
Oct 20 13:30:04 fedora kernel: softirqs last disabled at (63423): [<ffffffffa91012ed>] __irq_exit_rcu+0xed/0x160
Oct 20 13:30:04 fedora kernel: ---[ end trace 0000000000000000 ]---


Oct 20 13:30:08 fedora audit[585]: AVC avc:  denied  { write } for  pid=585 comm="systemd-gpt-aut" name="sda" dev="devtmpfs" ino=147 scontext=system_u:system_r:systemd_gpt_generator_t:s0 tcontext=system_u:object_r:fixed_disk_device_t:s0 tclass=blk_file permissive=0
→ that is #2083900. Here it doesn't matter.

Oct 20 13:30:10 fedora audit[619]: AVC avc:  denied  { watch } for  pid=619 comm="systemd-time-wa" path="/run/systemd" dev="tmpfs" ino=2 scontext=system_u:system_r:systemd_timedated_t:s0 tcontext=system_u:object_r:init_var_run_t:s0 tclass=dir permissive=0
Oct 20 13:30:10 fedora audit[619]: SYSCALL arch=c000003e syscall=254 success=no exit=-13 a0=5 a1=5570400e9098 a2=100 a3=7ffc5cab582c items=0 ppid=1 pid=619 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="systemd-time-wa" exe="/usr/lib/systemd/systemd-time-wait-sync" subj=system_u:system_r:systemd_timedated_t:s0 key=(null)
Oct 20 13:30:10 fedora audit: PROCTITLE proctitle="/usr/lib/systemd/systemd-time-wait-sync"
→ this most likely renders time-wait-sync inoperable.

Oct 20 13:30:10 fedora systemd[1]: systemd-time-wait-sync.service: Main process exited, code=exited, status=1/FAILURE
Oct 20 13:30:10 fedora systemd[1]: systemd-time-wait-sync.service: Failed with result 'exit-code'.
Oct 20 13:30:10 fedora systemd[1]: Failed to start systemd-time-wait-sync.service - Wait Until Kernel Time Synchronized.
→ Indeed.

Oct 20 13:30:11 fedora systemd-udevd[640]: /usr/lib/udev/rules.d/50-udev-default.rules:43 Unknown group 'render', ignoring
Oct 20 13:30:11 fedora systemd-udevd[640]: /usr/lib/udev/rules.d/50-udev-default.rules:44 Unknown group 'render', ignoring
Oct 20 13:30:11 fedora systemd-udevd[640]: /usr/lib/udev/rules.d/50-udev-default.rules:46 Unknown group 'sgx', ignoring
Oct 20 13:30:11 fedora systemd-udevd[640]: /usr/lib/udev/rules.d/50-udev-default.rules:47 Unknown group 'sgx', ignoring
Oct 20 13:30:11 fedora systemd-udevd[640]: /usr/lib/udev/rules.d/50-udev-default.rules:97 Unknown group 'kvm', ignoring
Oct 20 13:30:11 fedora systemd-udevd[640]: /usr/lib/udev/rules.d/50-udev-default.rules:102 Unknown group 'kvm', ignoring
Oct 20 13:30:11 fedora systemd-udevd[640]: /usr/lib/udev/rules.d/50-udev-default.rules:104 Unknown group 'kvm', ignoring
Oct 20 13:30:11 fedora systemd-udevd[640]: /usr/lib/udev/rules.d/50-udev-default.rules:106 Unknown group 'kvm', ignoring
→ This is an ostree issue. There was a bug for this. I thought it was already solved a while ago.

Oct 20 13:30:16 fedora systemd[1]: Starting systemd-oomd.service - Userspace Out-Of-Memory (OOM) Killer...
Oct 20 13:30:16 fedora systemd[754]: systemd-oomd.service: Failed to determine user credentials: No such process
Oct 20 13:30:16 fedora systemd[754]: systemd-oomd.service: Failed at step USER spawning /usr/lib/systemd/systemd-oomd: No such process
Oct 20 13:30:16 fedora systemd[1]: systemd-oomd.service: Main process exited, code=exited, status=217/USER
Oct 20 13:30:16 fedora systemd[1]: systemd-oomd.service: Failed with result 'exit-code'.
Oct 20 13:30:16 fedora systemd[1]: Failed to start systemd-oomd.service - Userspace Out-Of-Memory (OOM) Killer.
→ Hmm, problem with user and group setup?

Oct 20 13:30:17 fedora systemd[1]: sssd.service - System Security Services Daemon was skipped because no trigger condition checks were met.
Oct 20 13:30:17 fedora systemd[1]: Reached target nss-user-lookup.target - User and Group Name Lookups.
Oct 20 13:30:17 fedora systemd[1]: sssd-nss.socket: Bound to unit sssd.service, but unit isn't active.
Oct 20 13:30:17 fedora systemd[1]: Dependency failed for sssd-nss.socket - SSSD NSS Service responder socket.
Oct 20 13:30:17 fedora systemd[1]: sssd-nss.socket: Job sssd-nss.socket/start failed with result 'dependency'.
Oct 20 13:30:17 fedora systemd[1]: sssd-autofs.socket: Bound to unit sssd.service, but unit isn't active.
Oct 20 13:30:17 fedora systemd[1]: Dependency failed for sssd-autofs.socket - SSSD AutoFS Service responder socket.
Oct 20 13:30:17 fedora systemd[1]: sssd-autofs.socket: Job sssd-autofs.socket/start failed with result 'dependency'.
Oct 20 13:30:17 fedora systemd[1]: sssd-pac.socket: Bound to unit sssd.service, but unit isn't active.
Oct 20 13:30:17 fedora systemd[1]: Dependency failed for sssd-pac.socket - SSSD PAC Service responder socket.
Oct 20 13:30:17 fedora systemd[1]: sssd-pac.socket: Job sssd-pac.socket/start failed with result 'dependency'.
Oct 20 13:30:17 fedora systemd[1]: sssd-pam-priv.socket: Bound to unit sssd.service, but unit isn't active.
Oct 20 13:30:17 fedora systemd[1]: Dependency failed for sssd-pam-priv.socket - SSSD PAM Service responder private socket.
Oct 20 13:30:17 fedora systemd[1]: Dependency failed for sssd-pam.socket - SSSD PAM Service responder socket.
Oct 20 13:30:17 fedora systemd[1]: sssd-pam.socket: Job sssd-pam.socket/start failed with result 'dependency'.
Oct 20 13:30:17 fedora systemd[1]: sssd-pam-priv.socket: Job sssd-pam-priv.socket/start failed with result 'dependency'.
Oct 20 13:30:17 fedora systemd[1]: sssd-ssh.socket: Bound to unit sssd.service, but unit isn't active.
Oct 20 13:30:17 fedora systemd[1]: Dependency failed for sssd-ssh.socket - SSSD SSH Service responder socket.
Oct 20 13:30:17 fedora systemd[1]: sssd-ssh.socket: Job sssd-ssh.socket/start failed with result 'dependency'.
Oct 20 13:30:17 fedora systemd[1]: sssd-sudo.socket: Bound to unit sssd.service, but unit isn't active.
Oct 20 13:30:17 fedora systemd[1]: Dependency failed for sssd-sudo.socket - SSSD Sudo Service responder socket.
Oct 20 13:30:17 fedora systemd[1]: sssd-sudo.socket: Job sssd-sudo.socket/start failed with result 'dependency'.
→ This looks similar in its symptoms to #2141140.
Comment 8 Ben Cotton 2023-02-07 14:57:07 UTC 
This bug appears to have been reported against 'rawhide' during the Fedora Linux 38 development cycle.
Changing version to 38.
Comment 9 Zbigniew Jędrzejewski-Szmek 2023-03-16 17:40:56 UTC 
Can you check if this is still an issue? https://bugzilla.redhat.com/show_bug.cgi?id=2136916 was resolved in systemd-252.3-594.fc38.
Comment 10 Zbigniew Jędrzejewski-Szmek 2024-03-23 17:13:22 UTC 
Let's assume that this was fixed. Please reopen if not.