You are not logged in.
Hello everyone, I hope you could help me debug/resolve this weird issue which I'm fighting against since several days now.
When booting ArchLinux with a /var which is on a different partition than the root one, after inserting the Grub encrypted boot password, it freezes with a black screen and by later analysing the boot log via journalctl, one can notice the following Kernel oops:
Apr 26 19:43:03 archibald kernel: BUG: unable to handle page fault for address: fffffffffffffdfc
Apr 26 19:43:03 archibald kernel: #PF: supervisor read access in kernel mode
Apr 26 19:43:03 archibald kernel: #PF: error_code(0x0000) - not-present page
Apr 26 19:43:03 archibald kernel: PGD 35f60f067 P4D 35f60f067 PUD 35f611067 PMD 0
Apr 26 19:43:03 archibald kernel: Oops: 0000 [#1] PREEMPT SMP PTI
Apr 26 19:43:03 archibald kernel: CPU: 5 PID: 1946 Comm: gnome-shell Tainted: P OE 5.6.6-arch1-1 #1
Apr 26 19:43:03 archibald kernel: Hardware name: Gigabyte Technology Co., Ltd. Z270X-UD3/Z270X-UD3-CF, BIOS F6 04/24/20>
Apr 26 19:43:03 archibald kernel: RIP: 0010:drm_gem_map_dma_buf+0x3f/0xf0 [drm]
Apr 26 19:43:03 archibald kernel: Code: 00 00 83 fe 03 0f 84 a4 00 00 00 48 8b 87 38 01 00 00 41 89 f5 48 85 c0 74 5c 4>
Apr 26 19:43:03 archibald kernel: RSP: 0018:ffffa8fe4249ba18 EFLAGS: 00010246
Apr 26 19:43:03 archibald kernel: RAX: fffffffffffffdf4 RBX: ffff906cdab06980 RCX: 0000fffefcbf9881
Apr 26 19:43:03 archibald kernel: RDX: ffff906d2646da00 RSI: 0000000000000000 RDI: ffff906d2aa290b0
Apr 26 19:43:03 archibald kernel: RBP: 0000000000000000 R08: 0000000000000015 R09: ffff906d2573dc40
Apr 26 19:43:03 archibald kernel: R10: 0000000000000000 R11: ffff906cdabffc00 R12: fffffffffffffdf4
Apr 26 19:43:03 archibald kernel: R13: 0000000000000000 R14: 0000000000002a00 R15: ffff906d054182c0
Apr 26 19:43:03 archibald kernel: FS: 00007fa5f4c4e580(0000) GS:ffff906d2ed40000(0000) knlGS:0000000000000000
Apr 26 19:43:03 archibald kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Apr 26 19:43:03 archibald kernel: CR2: fffffffffffffdfc CR3: 00000008296c6005 CR4: 00000000003606e0
Apr 26 19:43:03 archibald kernel: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Apr 26 19:43:03 archibald kernel: DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Apr 26 19:43:03 archibald kernel: Call Trace:
Apr 26 19:43:03 archibald kernel: dma_buf_map_attachment+0x4b/0x90
Apr 26 19:43:03 archibald kernel: i915_gem_object_get_pages_dmabuf+0x17/0x60 [i915]
Apr 26 19:43:03 archibald kernel: __i915_gem_object_get_pages+0x54/0x60 [i915]
Apr 26 19:43:03 archibald kernel: i915_vma_pin+0x59b/0x6b0 [i915]
Apr 26 19:43:03 archibald kernel: ? kmem_cache_alloc+0x175/0x210
Apr 26 19:43:03 archibald kernel: eb_lookup_vmas+0x209/0xba0 [i915]
Apr 26 19:43:03 archibald kernel: ? preempt_count_add+0x68/0xa0
Apr 26 19:43:03 archibald kernel: i915_gem_do_execbuffer+0x687/0x1a80 [i915]
Apr 26 19:43:03 archibald kernel: ? __switch_to_asm+0x40/0x70
Apr 26 19:43:03 archibald kernel: ? __switch_to_asm+0x34/0x70
Apr 26 19:43:03 archibald kernel: ? __switch_to_asm+0x40/0x70
Apr 26 19:43:03 archibald kernel: ? __switch_to_asm+0x34/0x70
Apr 26 19:43:03 archibald kernel: ? __switch_to_asm+0x40/0x70
Apr 26 19:43:03 archibald kernel: i915_gem_execbuffer2_ioctl+0x2c5/0x3c0 [i915]
Apr 26 19:43:03 archibald kernel: ? i915_gem_execbuffer_ioctl+0x2d0/0x2d0 [i915]
Apr 26 19:43:03 archibald kernel: drm_ioctl_kernel+0xb2/0x100 [drm]
Apr 26 19:43:03 archibald kernel: drm_ioctl+0x209/0x360 [drm]
Apr 26 19:43:03 archibald kernel: ? i915_gem_execbuffer_ioctl+0x2d0/0x2d0 [i915]
Apr 26 19:43:03 archibald kernel: ksys_ioctl+0x87/0xc0
Apr 26 19:43:03 archibald kernel: __x64_sys_ioctl+0x16/0x20
Apr 26 19:43:03 archibald kernel: do_syscall_64+0x4e/0x150
Apr 26 19:43:03 archibald kernel: entry_SYSCALL_64_after_hwframe+0x44/0xa9
Apr 26 19:43:03 archibald kernel: RIP: 0033:0x7fa5fa1aa2eb
Apr 26 19:43:03 archibald kernel: Code: 0f 1e fa 48 8b 05 a5 8b 0c 00 64 c7 00 26 00 00 00 48 c7 c0 ff ff ff ff c3 66 0>
Apr 26 19:43:03 archibald kernel: RSP: 002b:00007ffdd583e9a8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
Apr 26 19:43:03 archibald kernel: RAX: ffffffffffffffda RBX: 00005588387d75f0 RCX: 00007fa5fa1aa2eb
Apr 26 19:43:03 archibald kernel: RDX: 00007ffdd583e9c0 RSI: 0000000040406469 RDI: 0000000000000012
Apr 26 19:43:03 archibald kernel: RBP: 00007ffdd583ea50 R08: 0000000000000001 R09: 0000000000000000
Apr 26 19:43:03 archibald kernel: R10: 00007ffdd583ea70 R11: 0000000000000246 R12: 00007fa5f17809e8
Apr 26 19:43:03 archibald kernel: R13: 0000000000000000 R14: 00007ffdd583e9c0 R15: 0000000000000012
Apr 26 19:43:03 archibald kernel: Modules linked in: xt_CHECKSUM xt_MASQUERADE xt_conntrack ipt_REJECT nf_reject_ipv4 x>
Apr 26 19:43:03 archibald kernel: evdev mac_hid sg crypto_user ip_tables x_tables ext4 crc32c_generic crc16 mbcache jb>
Apr 26 19:43:03 archibald kernel: CR2: fffffffffffffdfc
Apr 26 19:43:03 archibald kernel: ---[ end trace 5168c2c96e07a0f3 ]---
Apr 26 19:43:03 archibald kernel: RIP: 0010:drm_gem_map_dma_buf+0x3f/0xf0 [drm]
Apr 26 19:43:03 archibald kernel: Code: 00 00 83 fe 03 0f 84 a4 00 00 00 48 8b 87 38 01 00 00 41 89 f5 48 85 c0 74 5c 4>
Apr 26 19:43:03 archibald kernel: RSP: 0018:ffffa8fe4249ba18 EFLAGS: 00010246
Apr 26 19:43:03 archibald kernel: RAX: fffffffffffffdf4 RBX: ffff906cdab06980 RCX: 0000fffefcbf9881
Apr 26 19:43:03 archibald kernel: RDX: ffff906d2646da00 RSI: 0000000000000000 RDI: ffff906d2aa290b0
Apr 26 19:43:03 archibald kernel: RBP: 0000000000000000 R08: 0000000000000015 R09: ffff906d2573dc40
Apr 26 19:43:03 archibald kernel: R10: 0000000000000000 R11: ffff906cdabffc00 R12: fffffffffffffdf4
Apr 26 19:43:03 archibald kernel: R13: 0000000000000000 R14: 0000000000002a00 R15: ffff906d054182c0
Apr 26 19:43:03 archibald kernel: FS: 00007fa5f4c4e580(0000) GS:ffff906d2ed40000(0000) knlGS:0000000000000000
Apr 26 19:43:03 archibald kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Apr 26 19:43:03 archibald kernel: CR2: fffffffffffffdfc CR3: 00000008296c6005 CR4: 00000000003606e0
Apr 26 19:43:03 archibald kernel: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Apr 26 19:43:03 archibald kernel: DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400NAME MAJ:MIN RM SIZE RO TYPE MOUNTPOINT
sdb 8:16 0 279.5G 0 disk
└─home 254:1 0 279.5G 0 crypt /home
sdc 8:32 0 209.6G 0 disk
├─sdc1 8:33 0 200M 0 part
│ └─boot 254:2 0 198M 0 crypt /boot
├─sdc3 8:35 0 100M 0 part /efi
│ └─root 254:0 0 29.8G 0 crypt /
sdd 8:48 0 111.8G 0 disk
└─sdd2 8:50 0 61.8G 0 part
└─cache 254:5 0 61.8G 0 crypt /cache
sde 8:64 0 419.2G 0 disk
└─data1 254:3 0 419.2G 0 crypt /data1
sdf 8:80 0 419.2G 0 disk
└─data2 254:4 0 419.2G 0 crypt /data2I've removed the disks/partitions which are not involved in this, for clarity.
I'm using Grub as a bootloader and as you can see all my partitions (except efi) are encrypted (with LUKS), included the boot one.
All the encrypted partitions, except root, are present in /etc/crypttab
/cache is the partition mountpoint that contains the var and tmp folders, which are bind mounted to /var and /tmp respectively.
This setup always worked, until I noticed by looking at the boot journalctl logs that when mounting the /cache/var folder on /var, files were already there (the mount command complained about it).
By booting into an ArchLinux on a USB pen, I've discovered that there were several folders and files that are normally present in a /var, but they were clearly on the root partition and not in my var partition.
I deleted all those files, because those should not have been used. This led me to the current situation.
What I already discovered is that adding nomodeset to the kernel boot, makes ArchLinux boot correctly.
Checking the journalctl boot logs though I notice once again that the mount command complains about files present in /var.
Booting again into a recovery Linux I find that there's the following file: /var/run/gdm/custom.conf
It doesn't matter if I delete it, everytime I boot it gets recreated.
How is this possible?
It seems that gdm is somehow writing into /var before the correct folder is mounted. But this should not be the case because again checking the journalctl boot logs, I can clearly see that the folders are mounted before gdm is called.
Moreover, even using systemctl list-dependencies gdm.service I can see that it depends on a var.mount which depends on /cache and so on. So /var should be correctly bind mounted from /cache/var before gdm starts.
Further, I have this same exact issue on Ubuntu 20.04, where the weirdest workaround that worked is to call cryptsetup luksOpen <cache device> cache --key-file <path to keyfile> into a script which runs inside the initramfs.
Mind again that the cache partition is present in /etc/crypttab, and that script is only decrypting the partition, not even mounting it!
I don't have the faintest idea of what's happening... it almost seems like some sort of race condition happening when systemd later decrypts the partition which makes the /var mount to happen somehow later than the start of gdm, although the journalctl logs and everything else says otherwise.
Does anyone have a clue?
Last edited by Smjert (2020-04-26 19:02:58)
Offline
Apr 26 19:43:03 archibald kernel: Call Trace:
Apr 26 19:43:03 archibald kernel: dma_buf_map_attachment+0x4b/0x90
Apr 26 19:43:03 archibald kernel: i915_gem_object_get_pages_dmabuf+0x17/0x60 [i915]
Apr 26 19:43:03 archibald kernel: __i915_gem_object_get_pages+0x54/0x60 [i915]
Apr 26 19:43:03 archibald kernel: i915_vma_pin+0x59b/0x6b0 [i915]
Apr 26 19:43:03 archibald kernel: ? kmem_cache_alloc+0x175/0x210
Apr 26 19:43:03 archibald kernel: eb_lookup_vmas+0x209/0xba0 [i915]
Apr 26 19:43:03 archibald kernel: ? preempt_count_add+0x68/0xa0
Apr 26 19:43:03 archibald kernel: i915_gem_do_execbuffer+0x687/0x1a80 [i915]
Apr 26 19:43:03 archibald kernel: ? __switch_to_asm+0x40/0x70
Apr 26 19:43:03 archibald kernel: ? __switch_to_asm+0x34/0x70
Apr 26 19:43:03 archibald kernel: ? __switch_to_asm+0x40/0x70
Apr 26 19:43:03 archibald kernel: ? __switch_to_asm+0x34/0x70
Apr 26 19:43:03 archibald kernel: ? __switch_to_asm+0x40/0x70
Apr 26 19:43:03 archibald kernel: i915_gem_execbuffer2_ioctl+0x2c5/0x3c0 [i915]
Apr 26 19:43:03 archibald kernel: ? i915_gem_execbuffer_ioctl+0x2d0/0x2d0 [i915]
Apr 26 19:43:03 archibald kernel: drm_ioctl_kernel+0xb2/0x100 [drm]
Apr 26 19:43:03 archibald kernel: drm_ioctl+0x209/0x360 [drm]
Apr 26 19:43:03 archibald kernel: ? i915_gem_execbuffer_ioctl+0x2d0/0x2d0 [i915]
Apr 26 19:43:03 archibald kernel: ksys_ioctl+0x87/0xc0
Apr 26 19:43:03 archibald kernel: __x64_sys_ioctl+0x16/0x20
Apr 26 19:43:03 archibald kernel: do_syscall_64+0x4e/0x150
Apr 26 19:43:03 archibald kernel: entry_SYSCALL_64_after_hwframe+0x44/0xa9That call trace shows a the issue is triggered from the i915 module. nomodeset stopping the issue from occurring also indicates it is an i915 issue.
Did you update the kernel during the same time period as removing the duplicate files from /var?
Offline
Apparently it took me to write this long post to understand what was happening :facepalm:
Although I already knew the content of the file in /var/run/gdm/custom.conf, which was disabling Wayland, I didn't connect the dots.
I have an Nvidia driver; there's a udev rule, /usr/lib/udev/rules.d/61-gdm.rules, which checks for it and calls /usr/lib/gdm-disable-wayland, which write a custom.conf file in the path mentioned above.
This apparently is not depending on the fact that the /var has to be mounted, so it's called before it's.
And now my suspicion of a race condition is founded, because by removing the time it takes to decrypt the /cache partition, the /var mount gets mounted before this udev rule run.
To fix this now I just disabled Wayland via /etc/gdm/custom.conf; I will also disable that udev rule.
EDIT:
Hi @loqs and thanks for your quick answer, I've found the "solution" above.
Last edited by Smjert (2020-04-26 19:27:17)
Offline
So the issue is still present in the kernel and you work around it by forcing the use of X instead of Wayland.
An alternative workaround might be to order systemd-udevd.service later using RequiresMountsFor=/var/run
Offline
So the issue is still present in the kernel and you work around it by forcing the use of X instead of Wayland.
An alternative workaround might be to order systemd-udevd.service later using RequiresMountsFor=/var/run
Yes!
I already knew that the official NVIDIA driver doesn't work with Wayland, so I know I have to disable it.
That been said I forgot what was doing it, so I initially didn't remember about it and checked it.
I can try that too, yes; just hope to not break any other not explicitly defined dependency ^^'.
Offline
Yes!
I already knew that the official NVIDIA driver doesn't work with Wayland, so I know I have to disable it.
I thought that was due to the driver not supporting required functionality not that the driver caused kernel memory corruption.
I understand you do not want this configuration but if you disabled the nvidia drivers does the issue no longer trigger using Wayland?
Indicating it is nvidia causing the issue not simply Wayland exposing an issue in the i915 module.
Offline
I thought that was due to the driver not supporting required functionality not that the driver caused kernel memory corruption.
I understand you do not want this configuration but if you disabled the nvidia drivers does the issue no longer trigger using Wayland?
Indicating it is nvidia causing the issue not simply Wayland exposing an issue in the i915 module.
I see what you're trying to understand, and indeed the i915 module might be involved too.
I'll try that later (currently busy with something else ^^'), and let you know, thanks!
Last edited by Smjert (2020-04-26 20:43:23)
Offline
So after some tests I think I've found the culprit: on the kernel boot line I had nvidia_drm.modeset=1, plus nvidia modules listed in mkinitcpio.conf.
I don't recall what I was trying to do at the time, but long story short, if I remove that, plug my monitor to the motherboard hdmi out, then I'll see the GNOME DE, using Wayland.
Offline