NVIDIA module delay

adomas · 2018-05-05 18:48:39

Hello,
Yesterday I got a new SSD and installed Arch Linux on it. I also removed 1 GPU from my system (had 2 GPUs) and got rid of second monitor. On the old SSD I had up-to-date Arch system, I think even same kernel + nvidia driver version. But three days ago I had no such issue, everything was booting fast and smooth.

Now every time I boot my system I have 30 seconds delay before SDDM shows up. In dmesg every time I see this:

[    5.668792] IPv6: ADDRCONF(NETDEV_CHANGE): eno1: link becomes ready
[   31.697965] random: crng init done
[   32.197386] resource sanity check: requesting [mem 0x000c0000-0x000fffff], which spans more than PCI Bus 0000:00 [mem 0x000d0000-0x000d3fff window]
[   32.197505] caller _nv001169rm+0xe3/0x1d0 [nvidia] mapping multiple BARs
[   32.467155] nvidia-modeset: Allocated GPU:0 (GPU-4e4b5a1d-9270-5438-8904-eede0a9b35e0) @ PCI:0000:01:00.0
[   32.623451] ------------[ cut here ]------------
[   32.623454] Bad or missing usercopy whitelist? Kernel memory exposure attempt detected from SLUB object 'nvidia_stack_cache' (offset 11440, size 3)!
[   32.623461] WARNING: CPU: 0 PID: 463 at mm/usercopy.c:81 usercopy_warn+0x7e/0xa0
[   32.623461] Modules linked in: snd_hda_codec_hdmi joydev intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass snd_hda_codec_realtek crct10dif_pclmul crc32_pclmul ghash_clmulni_intel pcbc snd_hda_codec_generic aesni_intel aes_x86_64 crypto_simd glue_helper cryptd nvidia_drm(PO) intel_cstate nvidia_modeset(PO) nvidia(PO) drm_kms_helper drm snd_hda_intel ofpart snd_hda_codec cmdlinepart intel_spi_platform intel_spi spi_nor igb snd_hda_core agpgart uas ipmi_devintf snd_hwdep mtd usb_storage snd_pcm intel_uncore iTCO_wdt mousedev ipmi_msghandler iTCO_vendor_support input_leds led_class syscopyarea sysfillrect sysimgblt mxm_wmi i2c_algo_bit intel_rapl_perf fb_sys_fops pcspkr dca i2c_i801 lpc_ich e1000e snd_timer mei_me snd mei evdev ptp soundcore shpchp pps_core rtc_cmos mac_hid
[   32.623488]  wmi ip_tables x_tables ext4 crc16 mbcache jbd2 fscrypto hid_generic usbhid hid sd_mod ahci libahci xhci_pci ehci_pci libata firewire_ohci xhci_hcd ehci_hcd crc32c_intel firewire_core crc_itu_t scsi_mod usbcore usb_common
[   32.623499] CPU: 0 PID: 463 Comm: Xorg Tainted: P           O     4.16.6-1-ARCH #1
[   32.623499] Hardware name: Gigabyte Technology Co., Ltd. Z87X-UD5H/Z87X-UD5H-CF, BIOS 10c 06/12/2014
[   32.623501] RIP: 0010:usercopy_warn+0x7e/0xa0
[   32.623502] RSP: 0018:ffffb78402423b58 EFLAGS: 00010286
[   32.623503] RAX: 0000000000000000 RBX: ffff96ab8b622cb0 RCX: 0000000000000001
[   32.623503] RDX: 0000000080000001 RSI: ffffffff83e680bc RDI: 00000000ffffffff
[   32.623504] RBP: 0000000000000003 R08: 0000000000000098 R09: 00000000000003ad
[   32.623504] R10: ffffffff83ea43b9 R11: 0000000000000001 R12: 0000000000000001
[   32.623505] R13: ffff96ab8b622cb3 R14: 0000000000000000 R15: ffff96ab8b622cf8
[   32.623506] FS:  00007f8169bd3940(0000) GS:ffff96ab9ec00000(0000) knlGS:0000000000000000
[   32.623506] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   32.623507] CR2: 00007f8161afc010 CR3: 00000003fd956001 CR4: 00000000001606f0
[   32.623507] Call Trace:
[   32.623511]  __check_object_size+0x130/0x1a0
[   32.623603]  os_memcpy_to_user+0x21/0x40 [nvidia]
[   32.623714]  _nv009377rm+0xbf/0xe0 [nvidia]
[   32.623800]  ? _nv028067rm+0x79/0x90 [nvidia]
[   32.623886]  ? _nv028067rm+0x55/0x90 [nvidia]
[   32.623966]  ? _nv013694rm+0xee/0x100 [nvidia]
[   32.624046]  ? _nv015342rm+0x154/0x270 [nvidia]
[   32.624153]  ? _nv008310rm+0x134/0x1a0 [nvidia]
[   32.624260]  ? _nv008289rm+0x29c/0x2b0 [nvidia]
[   32.624367]  ? _nv001072rm+0xe/0x20 [nvidia]
[   32.624474]  ? _nv007316rm+0xd8/0x100 [nvidia]
[   32.624580]  ? _nv001171rm+0x627/0x830 [nvidia]
[   32.624687]  ? rm_ioctl+0x73/0x100 [nvidia]
[   32.624739]  ? nvidia_ioctl+0x573/0x720 [nvidia]
[   32.624741]  ? kmem_cache_free+0x1bd/0x1f0
[   32.624793]  ? nvidia_frontend_unlocked_ioctl+0x3e/0x50 [nvidia]
[   32.624795]  ? do_vfs_ioctl+0xa4/0x630
[   32.624796]  ? __fput+0x131/0x1e0
[   32.624798]  ? preempt_count_add+0x68/0xa0
[   32.624800]  ? SyS_ioctl+0x74/0x80
[   32.624801]  ? do_syscall_64+0x74/0x190
[   32.624804]  ? entry_SYSCALL_64_after_hwframe+0x3d/0xa2
[   32.624805] Code: 48 c7 c0 81 23 e7 83 48 0f 44 c2 41 50 51 41 51 48 89 f9 49 89 f1 4d 89 d8 4c 89 d2 48 89 c6 48 c7 c7 d8 23 e7 83 e8 42 aa e3 ff <0f> 0b 48 83 c4 18 c3 48 c7 c6 bc 80 e6 83 49 89 f1 49 89 f3 eb 
[   32.624823] ---[ end trace 30e52d8f2701e6a0 ]---

Seems that something does not play well. Three days ago I had GTX 780 + GTX 1080 Ti and I removed GTX 780, so my system now is running one GPU which is GTX 1080 Ti.

My kernel is x86_64 Linux 4.16.6-1-ARCH
My NVIDIA driver is 390.48-12

Is there anything I could try to get rid of this delay?

By the way, I also reset my UEFI Firmware to Optimized Defaults, then tweaked a bit, but in general most of settings stays the same. Can it be UEFI Firmware related?

To use nouveau is not a solution as it has poor support for my GTX 1080 Ti (with GTX 780 it was great).

loqs · 2018-05-05 18:58:58

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

adomas · 2018-05-05 19:15:21

loqs wrote:

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

Hey, loqs, thanks for the link. I checked that thread, but it seems unrelated to my issue

loqs · 2018-05-05 19:20:19

Could be a coincidence that

[   31.697965] random: crng init done

is at the start of the output. If you downgraded to 4.16.3-1 and the matching nvidia module and the issue persisted that would prove they are not related.

V1del · 2018-05-05 19:50:27

It's almost guaranteed to be the same issue. I don't have a problem with nvidia module load, that stack trace is normal with any 4.16 kernel.

adomas · 2018-05-05 20:03:35

loqs wrote:

Could be a coincidence that
[   31.697965] random: crng init done
is at the start of the output. If you downgraded to 4.16.3-1 and the matching nvidia module and the issue persisted that would prove they are not related.

This is unrelated I think, because this line was always there, before the problem appeared. This normally was at time of 15-20s after start-up, not it is 31s, but I really don't think it has anything to do with my problem.

EDIT: I checked old kernel logs, from 3 months ago and 7 months ago, that line is there, and I had no issues at the time.

Note: https://wiki.archlinux.org/index.php/Ra … generation

Last edited by adomas (2018-05-05 20:05:01)

V1del · 2018-05-05 20:10:41

Yes the line was there, that it created a 30s delay is very new (well not the line creates the delay, the random seed being starved creates the delay). As mentioned, either downgrade the kernel, or test if installing and enabling haveged helps here.

loqs · 2018-05-05 20:46:49

Even randomly pressing keys has been reported to reduce the delay.
edit:
https://fedoraproject.org/wiki/Common_F … .4_onwards

Last edited by loqs (2018-05-05 20:49:50)

Arch Linux

#1 2018-05-05 18:48:39

NVIDIA module delay

#2 2018-05-05 18:58:58

Re: NVIDIA module delay

#3 2018-05-05 19:15:21

Re: NVIDIA module delay

#4 2018-05-05 19:20:19

Re: NVIDIA module delay

#5 2018-05-05 19:50:27

Re: NVIDIA module delay

#6 2018-05-05 20:03:35

Re: NVIDIA module delay

#7 2018-05-05 20:10:41

Re: NVIDIA module delay

#8 2018-05-05 20:46:49

Re: NVIDIA module delay

Board footer