After nvidia display driver install -- long boot times (minutes)

After installing nvidia proprietary drivers, I am now experiencing excessively long boot times. The time to get to grub login screen is normal. The time to complete the screen with the three little squares is also normal.

After completing the 3 square sequence, the screen goes black (no blinking cursor), and the drive light comes on. Drive light is on for 1min 15 seconds before going out. Black screen persists for another minute, then the normal login screen appears. That makes it about 2 1/2 minutes from time screen with 3 squares is completed to login screen. Toward the end of the black screen period some text flashes by too quickly to read. From login screen, the system boots properly into the various desktops installed.

Perusal of the log files shows no period where system looks idle, i.e., waiting for something. It is continually reporting activity.

This boot period is completely different then when using the prior nouveau drivers.

Computer is moderately fast so hardware should not be the issue. Asus x99 mb, i7 upper speed cpu chip, 32 gig memory, lots of free disk space in root partition.

Anyone have a solution or diagnostic ideas? This is just an inconvenience but it is radical change from before nvidia drivers and I would like to resolve it

thanks, tom kosvic

Show

systemd-analyze blame

this shows times for each unit to start

Results of systemd analyze blame. Hope this is not too long. Looks like 1 minute @ plymouth service. This does not fully explain the 2 1/2 minutes overall.

localhost:/home/tom # systemd-analyze blame
    1min 34.399s plymouth-quit-wait.service
         30.096s wicked.service
          5.546s systemd-udev-settle.service
          4.318s libvirtd.service
          3.910s lvm2-monitor.service
          3.223s initrd-switch-root.service
          2.577s rsyslog.service
          2.011s mcelog.service
          1.977s udisks2.service
          1.910s nscd.service
          1.904s systemd-machined.service
          1.902s kbdsettings.service
          1.900s alsa-restore.service
          1.865s bluetooth.service
          1.863s avahi-daemon.service
          1.780s smartd.service
          1.304s apparmor.service
          1.163s postfix.service
          1.065s firewalld.service
           979ms display-manager.service
           768ms systemd-udevd.service
           748ms systemd-fsck@dev-disk-by\x2duuid-e748b401\x2d3a8f\x2d4152\x2da9ea\x2def540efb0230.service
           675ms polkit.service
           603ms dracut-initqueue.service
           438ms upower.service
           429ms plymouth-start.service
           398ms systemd-tmpfiles-setup-dev.service
           379ms boot-efi.mount
           333ms klog.service
           314ms systemd-fsck@dev-disk-by\x2duuid-C93A\x2dC87E.service
           306ms ModemManager.service
           285ms accounts-daemon.service
           260ms systemd-tmpfiles-setup.service
           246ms systemd-sysctl.service
           238ms auditd.service
           229ms wickedd-dhcp6.service
           228ms wickedd-auto4.service
           228ms wickedd-dhcp4.service
           224ms user@461.service
           192ms systemd-journald.service
           185ms user@1000.service
           180ms systemd-udev-trigger.service
           177ms plymouth-switch-root.service
           173ms colord.service
           147ms dev-disk-by\x2duuid-732223f6\x2db4fa\x2d4fa0\x2d9d5a\x2d78ced9984c72.swap
           122ms systemd-rfkill.service
           115ms initrd-parse-etc.service
           101ms chronyd.service
            95ms systemd-modules-load.service
            91ms dev-hugepages.mount
            79ms systemd-tmpfiles-clean.service
            79ms systemd-remount-fs.service
            79ms sys-kernel-debug.mount
            77ms wickedd-nanny.service
            76ms systemd-logind.service
            73ms systemd-fsck-root.service
            70ms systemd-journal-flush.service
            64ms wpa_supplicant.service
            45ms systemd-vconsole-setup.service
            41ms home.mount
            37ms dracut-cmdline.service
            34ms rtkit-daemon.service
            34ms dev-mqueue.mount
            32ms iscsi.service
            31ms wickedd.service
            31ms systemd-random-seed.service
            26ms systemd-update-utmp.service
            22ms kmod-static-nodes.service
            17ms dracut-pre-udev.service
            13ms dracut-shutdown.service
            13ms user-runtime-dir@461.service
            13ms sysroot.mount
            11ms plymouth-read-write.service
            10ms systemd-user-sessions.service
             7ms user-runtime-dir@1000.service
             6ms initrd-cleanup.service
             5ms systemd-update-utmp-runlevel.service
             4ms initrd-udevadm-cleanup-db.service
             2ms sys-fs-fuse-connections.mount

systemd-analyze critical-chain

Read more at: https://www.commandlinux.com/man-page/man1/systemd-analyze.1.html

systemd-analyze critical-chain

may give more insight

Are you timing boot or to working desktop??

30 seconds for wicked is pretty high.
systemd-analyze critical-chain

Read more at: https://www.commandlinux.com/man-page/man1/systemd-analyze.1.html

systemd-analyze critical-chain

Read more at: https://www.commandlinux.com/man-page/man1/systemd-analyze.1.html
systemd-analyze critical-chain

Read more at: https://www.commandlinux.com/man-page/man1/systemd-analyze.1.html

systemd-analyze critical-chain

Read more at: https://www.commandlinux.com/man-page/man1/systemd-analyze.1.html

systemd-analyze critical-chain

Read more at: https://www.commandlinux.com/man-page/man1/systemd-analyze.1.html

may give more insight

Are you timing boot or to working desktop??

30 seconds for wicked is pretty high.

439ms plymouth-quit-wait.service here

At boot try e then line starting linuxefi add quiet to stop plymouth.

Hi
It’s actually plymouth.enable=0

I added plymouth.enable=0 at end of linux commandline in grub boot and then initiated boot with f10.

I got pages of text messages about what it was doing.

It stopped for about a minute on:

“Started Update UTMP about System Runlevel Changes” . Also disk activity light was on during this time.

Over all boot was somewhat faster but I dont have a timing.

I have no knowledge about UTMP.

Any guidance would be appreciated.

tom kosvic

Please post:

zypper se -si kernel nvidia
uname -a
localhost:/home/tom # zypper se -si kernel nvidia
Loading repository data...
Reading installed packages...

S  | Name                      | Type    | Version                               | Arch   | Repository
---+---------------------------+---------+---------------------------------------+--------+------------------------
i  | jupyter-ipykernel         | package | 5.2.1-lp152.1.2                       | noarch | Main Repository
i+ | kernel-default            | package | 5.3.18-lp152.75.1                     | x86_64 | Main Update Repository
i+ | kernel-default            | package | 5.3.18-lp152.72.1                     | x86_64 | Main Update Repository
i  | kernel-default-devel      | package | 5.3.18-lp152.75.1                     | x86_64 | Main Update Repository
i  | kernel-devel              | package | 5.3.18-lp152.75.1                     | noarch | Main Update Repository
i  | kernel-firmware           | package | 20200107-lp152.2.6.1                  | noarch | Main Update Repository
i  | kernel-macros             | package | 5.3.18-lp152.75.1                     | noarch | Main Update Repository
i  | kernel-preempt-devel      | package | 5.3.18-lp152.75.1                     | x86_64 | Main Update Repository
i  | nfs-kernel-server         | package | 2.1.1-lp152.9.6.1                     | x86_64 | Main Update Repository
i  | nvidia-computeG05         | package | 460.73.01-lp152.39.1                  | x86_64 | nVidia Graphics Drivers
i+ | nvidia-gfxG05-kmp-default | package | 460.73.01_k5.3.18_lp152.19-lp152.39.1 | x86_64 | nVidia Graphics Drivers
i+ | nvidia-glG05              | package | 460.73.01-lp152.39.1                  | x86_64 | nVidia Graphics Drivers
i  | purge-kernels-service     | package | 0-lp152.4.1                           | noarch | Main Repository
i  | python3-ipykernel         | package | 5.2.1-lp152.1.2                       | noarch | Main Repository
i  | x11-video-nvidiaG05       | package | 460.73.01-lp152.39.1                  | x86_64 | nVidia Graphics Drivers
localhost:/home/tom #
localhost:/home/tom # uname -a
Linux localhost 5.3.18-lp152.75-default #1 SMP Wed May 5 09:22:56 UTC 2021 (16c42c8) x86_64 x86_64 x86_64 GNU/Linux
localhost:/home/tom # 

You have a kernel-preempt-devel Package so at some point you must have been hit by the preempt bug.
This may cause problems with the nvidia-kmp since it does a recompile on first run of new kernel or nvidia packages.
in any case it is not needed remove it
see if that helps let us know.

Using yast, I removed kernel-preempt-devel. No appreciable change to boot times if one was expected. Or perhaps that prevented a future problem.

In searching on the long dwell time for “Started Update UTMP about System Runlevel Changes” as previously mentioned, there are many references to problems with this. Mostly from ubuntu forums. Problem seems to be with some xserver intel process that I know nothing about. I think others did not wait long enough and declared a failed boot. But when you wait a couple of minutes, it clears and does boot to login dialogue. Any thoughts about that???

thanks again. This is out of my league so I need guidance.

tom kosvic

I would install all 4 nvidia Packages once more and restart.

Using yast software management, I reinstalled 4 nvidia files (up arrow) and rebooted. No detectable change in boot time. Still about 2 minutes but it did boot into right resolution successfully.

This procedure downloaded new files on top of the old ones. I did not first delete the old files. If another procedure should have been done, let me know.

If anyone has additional ideas, I will try them.

Thanks for your time, tom kosvic

Ran systemd-analyze critical chain and got results below:

tom@localhost:~> systemd-analyze critical-chain
The time after the unit is active or started is printed after the "@" character.
The time the unit takes to start is printed after the "+" character.

graphical.target @2min 17.774s
└─multi-user.target @2min 17.774s
  └─getty.target @2min 17.773s
    └─getty@tty1.service @2min 17.773s
      └─systemd-user-sessions.service @42.553s +43ms
        └─remote-fs.target @42.553s
          └─iscsi.service @42.445s +107ms
            └─network-online.target @42.444s
              └─network.target @42.440s
                └─wicked.service @12.340s +30.099s
                  └─wickedd-nanny.service @12.271s +67ms
                    └─wickedd.service @12.240s +29ms
                      └─wickedd-dhcp6.service @12.074s +164ms
                        └─network-pre.target @12.054s
                          └─firewalld.service @10.616s +1.437s
                            └─polkit.service @8.488s +2.119s
                              └─basic.target @8.473s
                                └─paths.target @8.472s
                                  └─btrfsmaintenance-refresh.path @8.472s
                                    └─sysinit.target @8.471s
                                      └─systemd-udev-settle.service @2.787s +5.683s
                                        └─systemd-udev-trigger.service @2.622s +164ms
                                          └─systemd-udevd-control.socket @2.504s
                                            └─-.slice

tom@localhost:~> 

I think this says that systemd-user-sessions.service started at 42 seconds and getty@tty1.service started at @2min 17.773s.
Also wicked seems to take a long time (30 seconds).

What can I do with this information??

thanks, tom kosvic

Has your / filesystem run out of freespace by installing the NVidia drivers and their deps?

sudo [btrfs filesystem](https://en.opensuse.org/SDB:BTRFS) df

Good analysis, first thing I would like to know is what these services are doing, so:

sudo systemctl status systemd-user-sessions.service
sudo systemctl cat systemd-user-sessions.service
sudo systemctl status getty@tty1.service
sudo systemctl cat getty@tty1.service

In the "systemctl cat"output you see a Description=, a Documenation= (so try “man systemd-user-sessions.service 8”) and even the command that is executed after ExecStart=

For systemd-user-sessions.service that looks simple enough so I understand what @mrmazda is suspecting.

No btrfs file system. ext4 for root and home. I ran the listed commands, see below. I am not clear on what try “man systemd-user-sessions.service 8”. Is this not a reference to a man doc file? That file ran in the man system.

localhost:/home/tom # systemctl status systemd-user-sessions.service
● systemd-user-sessions.service - Permit User Sessions
   Loaded: loaded (/usr/lib/systemd/system/systemd-user-sessions.service; static; vendor preset: disabled)
   Active: active (exited) since Sat 2021-05-15 16:14:19 CDT; 15h ago
     Docs: man:systemd-user-sessions.service(8)
  Process: 2682 ExecStart=/usr/lib/systemd/systemd-user-sessions start (code=exited, status=0/SUCCESS)
 Main PID: 2682 (code=exited, status=0/SUCCESS)
    Tasks: 0
   CGroup: /system.slice/systemd-user-sessions.service

May 15 16:14:19 localhost systemd[1]: Starting Permit User Sessions...
May 15 16:14:19 localhost systemd[1]: Started Permit User Sessions.
localhost:/home/tom #
localhost:/home/tom # systemctl cat systemd-user-sessions.service
# /usr/lib/systemd/system/systemd-user-sessions.service
#  This file is part of systemd.
#
#  systemd is free software; you can redistribute it and/or modify it
#  under the terms of the GNU Lesser General Public License as published by
#  the Free Software Foundation; either version 2.1 of the License, or
#  (at your option) any later version.

[Unit]
Description=Permit User Sessions
Documentation=man:systemd-user-sessions.service(8)
After=remote-fs.target nss-user-lookup.target network.target

[Service]
Type=oneshot
RemainAfterExit=yes
ExecStart=/usr/lib/systemd/systemd-user-sessions start
ExecStop=/usr/lib/systemd/systemd-user-sessions stop
localhost:/home/tom # 

command after exec start just started service as below:

localhost:/home/tom # /usr/lib/systemd/systemd-user-sessions start
localhost:/home/tom # 

localhost:/home/tom # systemctl status getty@tty1.service
● getty@tty1.service - Getty on tty1
   Loaded: loaded (/usr/lib/systemd/system/getty@.service; enabled; vendor preset: enabled)
  Drop-In: /usr/lib/systemd/system/getty@tty1.service.d
           └─noclear.conf
   Active: active (running) since Sat 2021-05-15 16:15:54 CDT; 15h ago
     Docs: man:agetty(8)
           man:systemd-getty-generator(8)
           http://0pointer.de/blog/projects/serial-console.html
 Main PID: 3764 (agetty)
    Tasks: 1
   CGroup: /system.slice/system-getty.slice/getty@tty1.service
           └─3764 /sbin/agetty -o -p -- \u --noclear tty1 linux

May 15 16:15:54 localhost systemd[1]: Started Getty on tty1.

localhost:/home/tom # systemctl cat getty@tty1.service
# /usr/lib/systemd/system/getty@.service
#  This file is part of systemd.
#
#  systemd is free software; you can redistribute it and/or modify it
#  under the terms of the GNU Lesser General Public License as published by
#  the Free Software Foundation; either version 2.1 of the License, or
#  (at your option) any later version.

[Unit]
Description=Getty on %I
Documentation=man:agetty(8) man:systemd-getty-generator(8)
Documentation=http://0pointer.de/blog/projects/serial-console.html
After=systemd-user-sessions.service plymouth-quit-wait.service
After=rc-local.service

# If additional gettys are spawned during boot then we should make
# sure that this is synchronized before getty.target, even though
# getty.target didn't actually pull it in.
Before=getty.target
IgnoreOnIsolate=yes

# IgnoreOnIsolate causes issues with sulogin, if someone isolates
# rescue.target or starts rescue.service from multi-user.target or
# graphical.target.
Conflicts=rescue.service
Before=rescue.service

# On systems without virtual consoles, don't start any getty. Note
# that serial gettys are covered by serial-getty@.service, not this
# unit.
ConditionPathExists=/dev/tty0

[Service]
# the VT is cleared by TTYVTDisallocate
# The '-o' option value tells agetty to replace 'login' arguments with an
# option to preserve environment (-p), followed by '--' for safety, and then
# the entered username.
ExecStart=-/sbin/agetty -o '-p -- \\u' --noclear %I $TERM
Type=idle
Restart=always
RestartSec=0
UtmpIdentifier=%I
TTYPath=/dev/%I
TTYReset=yes
TTYVHangup=yes
TTYVTDisallocate=yes
KillMode=process
IgnoreSIGPIPE=no
SendSIGHUP=yes

# Unset locale for the console getty since the console has problems
# displaying some internationalized messages.
Environment=LANG= LANGUAGE= LC_CTYPE= LC_NUMERIC= LC_TIME= LC_COLLATE= LC_MONETARY= LC_MESSAGES= LC_PAPER= LC_NAME= LC_ADDRESS= LC_TELEPHONE= LC_MEASUREMENT= LC_ID>

[Install]
WantedBy=getty.target
DefaultInstance=tty1

# /usr/lib/systemd/system/getty@tty1.service.d/noclear.conf
[Service]
# ensure tty1 isn't cleared (bnc#804158)
TTYVTDisallocate=no

Sorry if I wasn’t clear but I just gave these commands so you can get some insight on what are the services you pointed out doing.

Looking again at your output

tom@localhost:~> systemd-analyze critical-chain The time after the unit is active or started is printed after the "@" character.
The time the unit takes to start is printed after the "+" character.
graphical.target @2min 17.774s
└─multi-user.target @2min 17.774s
  └─getty.target @2min 17.773s
    └─getty@tty1.service @2min 17.773s
      └─systemd-user-sessions.service @42.553s +43ms
        └─remote-fs.target @42.553s
          └─iscsi.service @42.445s +107ms
            └─network-online.target @42.444s
              └─network.target @42.440s
                └─wicked.service @12.340s +30.099s
                  └─wickedd-nanny.service @12.271s +67ms

It is clear that wicked.service is taking 30 seconds, but there is something in between systemd-user-session and getty@tty1 that is taking 95 seconds.

On that in-between time:

In the output of “systemctl cat systemd-user-sessions.service” you see:

After=remote-fs.target nss-user-lookup.target network.target

So it is one of these 3 targets that is causing the 95 seconds.
By doing a "sudo systemctl status " for all these 3 targets you can see which is the one and maybe the output gives some hint on what is wrong. It also details how to open the man page describing these targets.

Everything points for me to something network related, can you think of anything?

For more information you can try:

sudo systemd-analyze plot > /tmp/boot.svg

You can open that file in your browser to see the plot, if you want you can share it in this thread using “susepaste -e 0 -n tckosvic /tmp/boot.svg”

Hi
For wicked I always change the network config line WAIT_FOR_INTERFACES fro 30 to a 1… (0 gives a 6 second delay…)


cat /etc/sysconfig/network/config | grep WAIT_FOR_INTERFACES

# WAIT_FOR_INTERFACES is a global wait for all mandatory interfaces in
WAIT_FOR_INTERFACES="1"

1.201s wicked.service

Per suggested diagnostic suggestions to run systemctl on three suspect process, see code below:

localhost:/home/tom # systemctl status remote-fs.target
● remote-fs.target - Remote File Systems
   Loaded: loaded (/usr/lib/systemd/system/remote-fs.target; enabled; vendor preset: enabled)
  Drop-In: /run/systemd/generator/remote-fs.target.d
           └─50-insserv.conf.conf
   Active: active since Wed 2021-05-19 21:48:59 CDT; 2 days ago
     Docs: man:systemd.special(7)

May 19 21:48:59 localhost systemd[1]: Reached target Remote File Systems.


localhost:/home/tom # systemctl status nss-user-lookup.target
● nss-user-lookup.target - User and Group Name Lookups
   Loaded: loaded (/usr/lib/systemd/system/nss-user-lookup.target; static; vendor preset: disabled)
   Active: active since Wed 2021-05-19 21:48:26 CDT; 2 days ago
     Docs: man:systemd.special(7)

May 19 21:48:26 localhost systemd[1]: Reached target User and Group Name Lookups.


localhost:/home/tom # systemctl status network.target
● network.target - Network
   Loaded: loaded (/usr/lib/systemd/system/network.target; static; vendor preset: disabled)
   Active: active since Wed 2021-05-19 21:48:59 CDT; 2 days ago
     Docs: man:systemd.special(7)
           https://www.freedesktop.org/wiki/Software/systemd/NetworkTarget

May 19 21:48:59 localhost systemd[1]: Reached target Network.
localhost:/home/tom # 

The only anomaly I see is vender preset enabled for first process and not for others. I don’t know what this means. Perhaps someone could suggest additional diagnostics.

I will also run the graphical diagnosis as suggested and attempt to post results.

I will also change the wait times in conf file as suggested and report as to effect on boot time.

thanks again, tom kosvic