Slow boot and shutdown

Boot time is over one minute with nvme…

It does not show why…
[root@lenovo roger]# systemd-analyze
Startup finished in 4.594s (firmware) + 1.906s (loader) + 2.297s (kernel) + 2.064s (userspace) = 10.863s
graphical.target reached after 1.943s in userspace

I tried to disable watchdog that does not stop on shutdown (30 secs delay approx) using all 4 available methods…

I’d like to know for first, what happens really on boot time. Any idea?

Hello @roger64
Maybe you could use the log tool and post a link to one of the available boot logs. Then maybe someone can look at it and see if they can pick up on anything. The journalctl logs.

after journalctl -p 4, this is what I get:

-- Journal begins at Wed 2020-12-23 10:36:21 HKT, ends at Wed 2020-12-23 15:53:20 HKT. --
déc. 23 10:36:21 lenovo kernel: MDS CPU bug present and SMT on, data leak possible. See https://www.kernel.org/doc/html/latest/admin-guide/hw-vuln/mds.html for more details.
déc. 23 10:36:21 lenovo kernel:  #5 #6 #7
déc. 23 10:36:21 lenovo kernel: platform MSFT0101:00: failed to claim resource 1: [mem 0xfed40000-0xfed40fff]
déc. 23 10:36:21 lenovo kernel: acpi MSFT0101:00: platform device creation failed: -16
déc. 23 10:36:21 lenovo kernel: resource sanity check: requesting [mem 0xfdffe800-0xfe0007ff], which spans more than pnp 00:00 [mem 0xfdb00000-0xfdffffff]
déc. 23 10:36:21 lenovo kernel: caller pmc_core_probe+0x85/0x380 mapping multiple BARs
déc. 23 10:36:21 lenovo kernel: usb: port power management may be unreliable
déc. 23 10:36:21 lenovo systemd-udevd[269]: Configuration file /etc/udev/rules.d/40-libsane.rules is marked executable. Please remove executable permission bits. Proceeding anyway.
déc. 23 10:36:21 lenovo systemd-udevd[269]: /etc/udev/rules.d/40-libsane.rules:26: GOTO="libsane_rules_end" has no matching label, ignoring
déc. 23 10:36:21 lenovo systemd-udevd[269]: Configuration file /etc/udev/rules.d/60-schedulers.rules is marked executable. Please remove executable permission bits. Proceeding anyway.
déc. 23 10:36:21 lenovo systemd-udevd[269]: Configuration file /etc/udev/rules.d/S99-2000S1.rules is marked executable. Please remove executable permission bits. Proceeding anyway.
déc. 23 10:36:21 lenovo systemd-udevd[269]: /etc/udev/rules.d/S99-2000S1.rules:26: GOTO="libsane_rules_end" has no matching label, ignoring
déc. 23 10:36:21 lenovo kernel: wmi_bus wmi_bus-PNP0C14:00: WQ data block query control method not found
déc. 23 10:36:21 lenovo kernel: wmi_bus wmi_bus-PNP0C14:00: WQ data block query control method not found
déc. 23 10:36:21 lenovo kernel: wmi_bus wmi_bus-PNP0C14:00: WQ data block query control method not found
déc. 23 10:36:21 lenovo kernel: wmi_bus wmi_bus-PNP0C14:00: WQ data block query control method not found
déc. 23 10:36:21 lenovo kernel: acpi PNP0C14:02: duplicate WMI GUID 05901221-D566-11D1-B2F0-00A0C9062910 (first instance was on PNP0C14:01)
déc. 23 10:36:21 lenovo kernel: vboxdrv: loading out-of-tree module taints kernel.
déc. 23 10:36:21 lenovo kernel: tpm_crb MSFT0101:00: [Firmware Bug]: Bad ACPI memory layout
déc. 23 10:36:21 lenovo systemd-udevd[293]: sda: /etc/udev/rules.d/60-schedulers.rules:6 Failed to write ATTR{/sys/devices/pci0000:00/0000:00:17.0/ata3/host2/target2:0:0/2:0:0:0/block/sda/queue/scheduler}, ignoring: Invalid argument
déc. 23 10:36:21 lenovo kernel: VBoxNetAdp: Successfully started.
déc. 23 10:36:21 lenovo kernel: VBoxNetFlt: Successfully started.
déc. 23 10:36:21 lenovo kernel: r8169 0000:04:00.0: can't disable ASPM; OS doesn't have ASPM control
déc. 23 10:36:22 lenovo kernel: snd_hda_intel: unknown parameter 'vid' ignored
déc. 23 10:36:22 lenovo kernel: snd_hda_intel: unknown parameter 'pid' ignored
déc. 23 10:36:22 lenovo systemd-udevd[302]: cfg80211: Process '/usr/bin/set-wireless-regdom' failed with exit code 1.
déc. 23 10:36:22 lenovo kernel: [Firmware Bug]: ACPI(PEGP) defines _DOD but not _DOS
déc. 23 10:36:22 lenovo avahi-daemon[465]: WARNING: No NSS support for mDNS detected, consider installing nss-mdns!
déc. 23 10:36:22 lenovo kernel: ACPI Warning: \_SB.PCI0.PEG0.PEGP._DSM: Argument #4 type mismatch - Found [Buffer], ACPI requires [Package] (20200717/nsarguments-59)
déc. 23 10:36:23 lenovo libvirtd[531]: Cannot check dnsmasq binary /usr/bin/dnsmasq: Aucun fichier ou dossier de ce type
déc. 23 10:36:23 lenovo libvirtd[531]: Network name='default' uuid=90a4f981-9a58-4075-aaac-37dca2b51744 is tainted: hook-script
déc. 23 10:36:23 lenovo libvirtd[531]: direct firewall backend requested, but /usr/bin/ebtables is not available: Aucun fichier ou dossier de ce type
déc. 23 10:36:23 lenovo libvirtd[531]: internal error: Failed to initialize a valid firewall backend
déc. 23 10:36:23 lenovo libvirtd[531]: internal error: Failed to initialize a valid firewall backend
déc. 23 10:36:23 lenovo systemd-udevd[272]: ethtool: could not get ethtool features for virbr0-nic
déc. 23 10:36:23 lenovo systemd-udevd[272]: virbr0-nic: Could not set offload features, ignoring: No such device
déc. 23 10:36:23 lenovo dhcpcd[477]: dhcpcd_prestartinterface: Operation not possible due to RF-kill
déc. 23 10:36:23 lenovo dhcpcd[477]: dhcpcd_prestartinterface: Operation not possible due to RF-kill
déc. 23 10:36:23 lenovo dhcpcd[477]: ps_root_dispatch: No such file or directory
déc. 23 10:36:23 lenovo dhcpcd[477]: ps_root_dispatch: No such process
déc. 23 10:36:23 lenovo libvirtd[531]: internal error: Failed to initialize a valid firewall backend
déc. 23 10:36:23 lenovo libvirtd[531]: internal error: Unknown PCI header type '127' for device '0000:01:00.0'
déc. 23 10:36:24 lenovo kernel: kauditd_printk_skb: 38 callbacks suppressed
déc. 23 10:36:24 lenovo lightdm[674]: gkr-pam: no password is available for user
déc. 23 10:36:24 lenovo systemd-xdg-autostart-generator[687]: Configuration file /home/roger/.config/autostart/expressvpn-agent.desktop is marked executable. Please remove executable permission bits. Proceeding anyway.
déc. 23 10:36:24 lenovo systemd-xdg-autostart-generator[687]: Not generating service for XDG autostart app-parcellite\x2dstartup-autostart.service, error parsing Exec= line: No such file or directory
déc. 23 10:36:24 lenovo systemd[680]: -.slice: Failed to migrate controller cgroups from /user.slice/user-1000.slice/user@1000.service, ignoring: Permission denied
déc. 23 10:36:34 lenovo kernel: kauditd_printk_skb: 10 callbacks suppressed
déc. 23 10:36:38 lenovo dhcpcd[477]: enp4s0: no IPv6 Routers available
déc. 23 10:36:55 lenovo pulseaudio[790]: Échec d'ouverture du module module-rescue-streams.so : module-rescue-streams.so: Ne peut ouvrir le fichier d'objet partagé: Aucun fichier ou dossier de ce type
déc. 23 10:36:55 lenovo pulseaudio[790]: Failed to open module "module-rescue-streams".
déc. 23 10:36:57 lenovo gpaste-daemon[1048]: Couldn't grab keybindings with gnome-shell: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.gnome.Shell was not provided by any .service files
déc. 23 10:37:02 lenovo cinnamon-session[698]: WARNING: t+36,99819s: Detected that screensaver has appeared on the bus
déc. 23 10:39:37 lenovo gpaste-ui[1531]: gdk_window_get_origin: assertion 'GDK_IS_WINDOW (window)' failed
déc. 23 10:39:37 lenovo gpaste-ui[1531]: gdk_window_get_origin: assertion 'GDK_IS_WINDOW (window)' failed
déc. 23 10:39:37 lenovo gpaste-ui[1531]: gdk_window_get_origin: assertion 'GDK_IS_WINDOW (window)' failed
déc. 23 10:39:37 lenovo gpaste-ui[1531]: gdk_window_get_origin: assertion 'GDK_IS_WINDOW (window)' failed
déc. 23 10:39:37 lenovo gpaste-ui[1531]: gdk_window_get_origin: assertion 'GDK_IS_WINDOW (window)' failed
déc. 23 10:39:37 lenovo gpaste-ui[1531]: gdk_window_get_origin: assertion 'GDK_IS_WINDOW (window)' failed
déc. 23 10:39:37 lenovo gpaste-ui[1531]: gdk_window_get_origin: assertion 'GDK_IS_WINDOW (window)' failed
déc. 23 10:39:37 lenovo gpaste-ui[1531]: gdk_window_get_origin: assertion 'GDK_IS_WINDOW (window)' failed
déc. 23 10:39:37 lenovo gpaste-ui[1531]: gdk_window_get_origin: assertion 'GDK_IS_WINDOW (window)' failed
déc. 23 10:48:33 lenovo gpaste-ui[2205]: gdk_window_get_origin: assertion 'GDK_IS_WINDOW (window)' failed
déc. 23 10:48:33 lenovo gpaste-ui[2205]: gdk_window_get_origin: assertion 'GDK_IS_WINDOW (window)' failed
déc. 23 10:48:33 lenovo gpaste-ui[2205]: gdk_window_get_origin: assertion 'GDK_IS_WINDOW (window)' failed
déc. 23 10:48:33 lenovo gpaste-ui[2205]: gdk_window_get_origin: assertion 'GDK_IS_WINDOW (window)' failed
déc. 23 10:48:33 lenovo gpaste-ui[2205]: gdk_window_get_origin: assertion 'GDK_IS_WINDOW (window)' failed
déc. 23 10:48:33 lenovo gpaste-ui[2205]: gdk_window_get_origin: assertion 'GDK_IS_WINDOW (window)' failed
déc. 23 10:48:33 lenovo gpaste-ui[2205]: gdk_window_get_origin: assertion 'GDK_IS_WINDOW (window)' failed
déc. 23 10:48:33 lenovo gpaste-ui[2205]: gdk_window_get_origin: assertion 'GDK_IS_WINDOW (window)' failed
déc. 23 10:48:33 lenovo gpaste-ui[2205]: gdk_window_get_origin: assertion 'GDK_IS_WINDOW (window)' failed
déc. 23 10:48:58 lenovo dhcpcd[784]: enp4s0: ps_bpf_recvbpf: Network is down
déc. 23 10:48:58 lenovo dhcpcd[2301]: enp4s0: ps_bpf_recvbpf: Network is down
déc. 23 10:48:58 lenovo dhcpcd[2301]: ps_bpf_recvmsg: Network is down
déc. 23 12:17:07 lenovo kernel: [Firmware Bug]: TSC ADJUST differs: CPU0 0 --> -451467473. Restoring
déc. 23 12:17:07 lenovo kernel: smpboot: Scheduler frequency invariance went wobbly, disabling!
déc. 23 12:17:07 lenovo kernel: done.
déc. 23 12:17:07 lenovo upowerd[862]: treating change event as add on /sys/devices/pci0000:00/0000:00:14.0/usb1/1-11
déc. 23 12:17:07 lenovo upowerd[862]: treating change event as add on /sys/devices/pci0000:00/0000:00:14.0/usb1/1-11
déc. 23 12:17:22 lenovo dhcpcd[477]: enp4s0: no IPv6 Routers available
déc. 23 12:53:43 lenovo dhcpcd[2400]: enp4s0: ps_bpf_recvbpf: Network is down
déc. 23 12:53:43 lenovo dhcpcd[3790]: enp4s0: ps_bpf_recvbpf: Network is down
déc. 23 12:53:43 lenovo dhcpcd[3790]: ps_bpf_recvmsg: Network is down
déc. 23 15:00:22 lenovo kernel: [Firmware Bug]: TSC ADJUST differs: CPU0 0 --> -449595662. Restoring
déc. 23 15:00:22 lenovo upowerd[862]: treating change event as add on /sys/devices/pci0000:00/0000:00:14.0/usb1/1-11
déc. 23 15:00:22 lenovo upowerd[862]: treating change event as add on /sys/devices/pci0000:00/0000:00:14.0/usb1/1-11
déc. 23 15:00:37 lenovo dhcpcd[477]: enp4s0: no IPv6 Routers available
déc. 23 15:31:00 lenovo kernel: kauditd_printk_skb: 11 callbacks suppressed
déc. 23 15:31:17 lenovo kernel: kauditd_printk_skb: 10 callbacks suppressed
déc. 23 15:52:24 lenovo gnome-terminal-[5484]: gtk_notebook_get_tab_label: assertion 'list != NULL' failed
déc. 23 15:52:24 lenovo gnome-terminal-[5484]: gtk_notebook_get_tab_label: assertion 'list != NULL' failed
déc. 23 15:52:24 lenovo gnome-terminal-[5484]: gtk_notebook_get_tab_label: assertion 'list != NULL' failed
déc. 23 15:52:24 lenovo gnome-terminal-[5484]: gtk_notebook_get_tab_label: assertion 'list != NULL' failed
déc. 23 15:52:24 lenovo gnome-terminal-[5484]: gtk_notebook_get_tab_label: assertion 'list != NULL' failed

It is better if you use the EndeavourOS log tool that is on here btw. You could use that and edit your post if you wanted. Not sure if you are aware of the tool?

Example: http://ix.io/2JeC

Edit: The EndeavourOS log tool is in the menu.

Sorry. I did not find it. Is this better?

This was better to look at. I’m no expert on this but maybe some others will look at it have some ideas. Nothing i see jumps out at me.

I am not sure you want to post all your IP information that is towards the end of that file?

I did see this…That is a ton of usb ports…

déc. 23 10:36:21 lenovo kernel: hub 1-0:1.0: USB hub found
déc. 23 10:36:21 lenovo kernel: hub 1-0:1.0: 16 ports detected

déc. 23 10:36:21 lenovo kernel: hub 2-0:1.0: USB hub found
déc. 23 10:36:21 lenovo kernel: hub 2-0:1.0: 8 ports detected
1 Like

@roger64

Maybe you could try the suggestions 1. and 2. from the following post:

  1. You may want to check to see if there is some kind of option for “fast boot” in your BIOS. If not, you could try to see if you can disable as much as possible in the UEFI firmware menu (bios). When the machine POSTs, it polls for anything and everything that may be attached to the machine. For things like USB, that can be pretty slow. So if you can disable them, it should speed things up. Once the kernel is loaded, it will re-poll for devices anyway and get everything going.

  2. You could combine the above with changing the default/fallback boot path. Some UEFI firmwares require a bootable file at a known location before they will show UEFI NVRAM boot entries. The solution is reinstalling or moving the GRUB EFI executable.

This should shave off some of that boot and shutdown time.

Note: Just ignore the encryption related stuff in that thread.

1 Like

Could you edit this and enclose that novel in code tags, please?

1 Like

:+1:

What does systemd-analyze blame return?

2 Likes

Have you tried the fix described in paragraph “Delay when powering off or restarting” of

https://wiki.archlinux.org/index.php/GNOME/Troubleshooting#Delay%20when%20powering%20off%20or%20restarting

1 Like

nss-mdns

Thank you all for your replies in such a festive day.

Before posting here, I tried four different methods to stop watchdog to no avail. Since then,I received above various proposals.

When I opened this thread, I had quite a modest purpose: I wished to see (visualize) what happens to my boot process between the first ten seconds (see above: systemd-analyze) and the opening of my Cinnamon session about one minute later.

Only then, when I should have learnt what slowed down my boot process, I thought I would be justified to tinker with my system with some chances of success.

Nevertheless I will try to install nss-mdns as suggested by sammiev because this seems to be a very easily reversible process.

Edit: did it. It seems I gained some seconds. Down to about 50 secs at boot…

1 Like

systemd-analyze is just a synopsis. As @skaffen asked:

1 Like

Here it is. It’s the detail of the 10 secs given above where nothing is wrong. It does not provide info about the remaining 40 or 50 secs.

You know it by now, the boot process is just fine; the DE start time is not. You did not provide much information about your system so far, and did not comment on post #7 regarding those 24 usb ports.

2 Likes

I tried another thing using dmesg. I collected dmesg immediately after booting.

At the end of this file, I remarked that a lot of time is spent using “audits”. I’ve read I can disable audit writing audit=0 in the boot-loader prefs, like I wrote watchdog=0. Maybe I’ll try it.

I have no idea about these usb ports. I have two usb plugs on the right side, and one usb3 on the left.

As required, here is some information about my system.

[roger@lenovo ~]$ inxi -F
System:
  Host: lenovo Kernel: 5.9.14-arch1-1 x86_64 bits: 64 
  Desktop: Cinnamon 4.8.3 Distro: Antergos Linux 
Machine:
  Type: Laptop System: LENOVO product: 80WW v: RESCUER R720-15IKBN 
  serial: <superuser/root required> 
  Mobo: LENOVO model: LNVNB161216 v: SDK0L77769 WIN 
  serial: <superuser/root required> UEFI: LENOVO v: 4KCN30WW 
  date: 08/31/2017 
Battery:
  ID-1: BAT0 charge: 39.5 Wh condition: 40.7/45.0 Wh (90%) 
CPU:
  Info: Quad Core model: Intel Core i7-7700HQ bits: 64 type: MT MCP 
  L2 cache: 6144 KiB 
  Speed: 2595 MHz min/max: 800/3800 MHz Core speeds (MHz): 1: 800 2: 800 
  3: 800 4: 800 5: 800 6: 800 7: 800 8: 800 
Graphics:
  Device-1: Intel HD Graphics 630 driver: i915 v: kernel 
  Device-2: NVIDIA GP107M [GeForce GTX 1050 Mobile] driver: N/A 
  Device-3: Acer EasyCamera type: USB driver: uvcvideo 
  Display: x11 server: X.Org 1.20.10 driver: modesetting 
  unloaded: fbdev,vesa resolution: 1920x1080~60Hz 
  OpenGL: renderer: Mesa Intel HD Graphics 630 (KBL GT2) v: 4.6 Mesa 20.3.1 
Audio:
  Device-1: Intel CM238 HD Audio driver: snd_hda_intel 
  Sound Server: ALSA v: k5.9.14-arch1-1 
Network:
  Device-1: Qualcomm Atheros QCA9377 802.11ac Wireless Network Adapter 
  driver: ath10k_pci 
  IF: wlp3s0 state: down mac: f2:dd:00:66:8c:f1 
  Device-2: Realtek RTL8111/8168/8411 PCI Express Gigabit Ethernet 
  driver: r8169 
  IF: enp4s0 state: up speed: 100 Mbps duplex: full mac: 54:e1:ad:8c:29:82 
  Device-3: Qualcomm Atheros type: USB driver: btusb 
Drives:
  Local Storage: total: 1.03 TiB used: 144.66 GiB (13.8%) 
  ID-1: /dev/nvme0n1 vendor: Samsung model: MZVLW128HEGR-000L2 
  size: 119.24 GiB 
  ID-2: /dev/sda vendor: Seagate model: ST1000LM035-1RK172 size: 931.51 GiB 
Partition:
  ID-1: / size: 26.79 GiB used: 11.92 GiB (44.5%) fs: ext4 
  dev: /dev/nvme0n1p3 
  ID-2: /home size: 26.79 GiB used: 11.91 GiB (44.4%) fs: ext4 
  dev: /dev/nvme0n1p4 
Swap:
  ID-1: swap-1 type: partition size: 5.86 GiB used: 0 KiB (0.0%) 
  dev: /dev/nvme0n1p2 
Sensors:
  System Temperatures: cpu: 34.0 C mobo: N/A 
  Fan Speeds (RPM): N/A 
Info:
  Processes: 241 Uptime: 15m Memory: 7.65 GiB used: 2.07 GiB (27.1%) 
  Shell: Bash inxi: 3.1.09 
[roger@lenovo ~]$ 

I can’t find anything suspicious in the logs, except the usb port phenomenon and the the fact there is no driver for the nvidia gpu installed. Can’t interprete those audit records though.

What i would do just for testing is

  • create a new user and log in with this one just to see if there is a significant difference
  • create a fresh linux usb boot drive, boot it, and check logs et cetera

@roger64
Have you tried this?

https://wiki.archlinux.org/index.php/GNOME/Troubleshooting#Delay_when_powering_off_or_restarting

1 Like