Slow boot and shutdown

roger64 · December 25, 2020, 1:39am

No, I do not have gnome-session and its service.

I did include audit=0 in the Grub prefs and it gave this dmesg much shorter, without indeed any “audit”.

I made tests to see if it shortens the boot or shutdown.

46 secs to boot from pressing the button to GUI. So the system takes a little over 30secs. This is better but not fast.
Still exactly 30 secs to shutdown, without any message with watchdog which shows that the problem lies elsewhere.

ricklinux · December 25, 2020, 1:59am

Sorry i thought you were using Gnome. I see you posted the hardware and you are on Cinnamon? Only thing i see in the a hardware is that you have a hybrid system with Intel and Nvidia. It is running on the kernel driver for Intel. Nothing is loaded for Nvidia?

Device-2: NVIDIA GP107M [GeForce GTX 1050 Mobile] driver: N/A

roger64 · December 25, 2020, 2:09am

NVIDIA card is running OK with optimus and bumblebee. I can activate it only when needed with the command optirun. I could check its impressive output with glxspheres64.

ricklinux · December 25, 2020, 2:21am

Okay… you must have had it off then and it doesn’t show in the hardware.

roger64 · December 26, 2020, 1:36am

I thought this obscure delay could be triggered by the DE. I checked the Cinnamon looking-glass logs that say that Cinnamon starts in a little more than 2 secs.
…

fbodymechanic · December 26, 2020, 3:11am

When I was on GNOME, I couldn’t kill the user@1000 process even with a script. I had to log out before I could shutdown or it would take minutes.

systemd-analyze is helpful

Posting systemd-analyze blame will actually be much more informative and help us pinpoint which processes we can focus in on to really help boot up time.

linesma · December 26, 2020, 5:17am

I would try using the following acpi kernel parameter. acpi_osi='Windows 2018'

To try this parameter, do the following:

When you boot your laptop, press “E” on the grub screen and find the line with the “quiet” parameter.
l Replace the word “quiet” with acpi_osi='Windows 2018'. (Make sure to keep the syntax the same, otherwise the parameter will not be used.)
Press F-10 to boot your computer.

A slow boot and shutdown, especially on a laptop, can be caused by the bios sending acpi calls to the Linux kernel that it does not understand. While Linux implements the ACPI standard properly, many OEM’s do not. They sometimes “tweak” the standard and this can break compatibility.

I hope this helps.

roger64 · December 26, 2020, 11:44pm

@fbodymechanic

I can’t disagree with your comment. As it happpens, I did give here above both systemd-analyze and systemd-analyze blame results.

The point is that a whole part of my booting process is still uncovered (that one between 10 secs to 40 secs) and I found no clue about it in these messages. Have a look.

I had thought that, on shutting down, the process was blocked by the watchdog. When discarding the watchdog, I realize now that the 30 secs delay is still in place, and thus is caused by something else. As for user1000, I had some error messages in the past but they appear no more.

roger64 · December 26, 2020, 11:46pm

Thanks for the link. I did read it but I have no error message that could justify its use. When needed my Nvidia card works well.

linesma · December 27, 2020, 5:33am

There might not be an error message given. Some ACPI errors will not be reported. Why? The kernel will interpret the ACPI call, but it may be interpreting it improperly. This can cause what you are describing.

It has more implications than just with the video card. As stated in the start of the article,

A real slow boot time and a long shutdown time is the sign of an ACPI mismatch.

I would still give the kernel parameter I suggested a shot. It will not break the system. The directions I gave to add it, do not add it permanently to grub. It will be gone on the next boot.

All that being said, good luck with whatever you find that fixes the problem.

ricklinux · December 27, 2020, 6:35am

I see it also as having to do with ACPI and hardware. It is listing like 16 or 24 usb ports? I might be able to see 8 or so but it’s most likely duplication or something.

linesma · December 27, 2020, 6:56am

(Edited so discourse would not auto-delete the quote)

This is what is leading me to believe it is an ACPI issue. I have never seen so many ports listed like that. To test this theory, I hooked up my two powered 7 port USB hubs (total of 14 USB ports), and they did not add to the total seen. New ports only appeared when I plugged something into the hub itself.

I tailored my wiki article to cover the most common ACPI issue which was graphics cards. However, ACPI does so much more. To cover it all, the article would be too long to be of use to anyone.

Stephane · December 27, 2020, 11:54am

can you return

sudo lsusb -vt
sudo systemd-analyze blame
sudo journalctl -b0 -p4
sudo journalctl -b0 -g failed
sudo journalctl -b0 -p err

have you added this on booot line kernel
“nvme_core.default_ps_max_latency_us=0”

there also this log
“systemd-remount-fs[261]: mount: /etc/fstab : erreur d’analyse à la ligne 14 — ignorée”
“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”
“i915 0000:00:02.0: [drm] Panel advertises DPCD backlight support, but VBT disagrees. If your backlight controls don’t work try booting with i915.enable_dpcd_backlight=1. If your machine needs this, please file a new bug report on drm/i915, see https://gitlab.freedesktop.org/drm/intel/-/wikis/How-to-file-i915-bugs for details.”

are you using lvm2 storage ?
fsck appears after on any others disks

roger64 · December 28, 2020, 3:56am

some partial replies, other will follow

roger@lenovo ~]$ sudo lsusb -vt
[sudo] Mot de passe de roger : 
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/8p, 5000M
    ID 1d6b:0003 Linux Foundation 3.0 root hub
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/16p, 480M
    ID 1d6b:0002 Linux Foundation 2.0 root hub
    |__ Port 2: Dev 3, If 0, Class=Human Interface Device, Driver=usbhid, 1.5M
        ID 1c4f:0034 SiGma Micro XM102K Optical Wheel Mouse
    |__ Port 6: Dev 4, If 0, Class=Video, Driver=uvcvideo, 480M
        ID 5986:06b0 Acer, Inc 
    |__ Port 6: Dev 4, If 1, Class=Video, Driver=uvcvideo, 480M
        ID 5986:06b0 Acer, Inc 
    |__ Port 11: Dev 5, If 0, Class=Wireless, Driver=btusb, 12M
        ID 0cf3:e500 Qualcomm Atheros Communications 
    |__ Port 11: Dev 5, If 1, Class=Wireless, Driver=btusb, 12M
        ID 0cf3:e500 Qualcomm Atheros Communications 
[roger@lenovo ~]$ 


You can see here these 8 and 16 USB ports.```
I disabled lvm2 service.
I repaired the first partition of sdb (FAT32) which is USB3 external storage (now unplugged).

I'll boot with "nvme_core" parameters

linesma · December 28, 2020, 4:07am

What this parameter does is adjust the “power state” of the nvme drive. There is a “bug” in the firmware of some nvme drives that cause the kernel to put the drive into a “sleep state” at random. My Western Digital Black nvme drive is one of those drives. To have it work properly, I had to adjust the value of the parameter from 0 to 5500. This means: nvme_core.default_ps_max_latency_us=5500

I will be interested to see what happens. Your issue is very interesting.

roger64 · December 28, 2020, 4:12am

So I added the “nvme…” parameter to the grub command line. It booted as usual (about 40 secs).

Here are the journalctl errors. The first two are identified there are caused by the missing Trusted Platform Module of Microsoft. I discarded a long time ago everything MSFT on my computer.

- Journal begins at Mon 2020-12-28 12:02:08 HKT, ends at Mon 2020-12-28 12:05:11 HKT. --
déc. 28 12:02:08 lenovo kernel: platform MSFT0101:00: failed to claim resource 1: [mem 0xfed40000-0xfed40fff]
déc. 28 12:02:08 lenovo kernel: acpi MSFT0101:00: platform device creation failed: -16
déc. 28 12:02:08 lenovo systemd-udevd[265]: /etc/udev/rules.d/40-libsane.rules:26: GOTO="libsane_rules_end" has no matching label, ignoring
déc. 28 12:02:08 lenovo systemd-udevd[265]: /etc/udev/rules.d/S99-2000S1.rules:26: GOTO="libsane_rules_end" has no matching label, ignoring
déc. 28 12:02:08 lenovo systemd-udevd[290]: sda: /etc/udev/rules.d/60-schedulers.rules:6 Failed to write ATTR{/sys/devices/pci0000:00/0000:00:17.0/ata3/host2/>
déc. 28 12:02:09 lenovo libvirtd[501]: Cannot check dnsmasq binary /usr/bin/dnsmasq: Aucun fichier ou dossier de ce type
déc. 28 12:02:09 lenovo libvirtd[501]: direct firewall backend requested, but /usr/bin/ebtables is not available: Aucun fichier ou dossier de ce type
déc. 28 12:02:09 lenovo libvirtd[501]: internal error: Failed to initialize a valid firewall backend
déc. 28 12:02:09 lenovo libvirtd[501]: internal error: Failed to initialize a valid firewall backend
déc. 28 12:02:09 lenovo dhcpcd[460]: ps_root_dispatch: No such file or directory
déc. 28 12:02:09 lenovo dhcpcd[460]: ps_root_dispatch: No such process
déc. 28 12:02:09 lenovo dhcpcd[460]: dhcpcd_prestartinterface: Operation not possible due to RF-kill
déc. 28 12:02:09 lenovo dhcpcd[460]: dhcpcd_prestartinterface: Operation not possible due to RF-kill
déc. 28 12:02:10 lenovo libvirtd[501]: internal error: Failed to initialize a valid firewall backend
déc. 28 12:02:10 lenovo libvirtd[501]: internal error: Unknown PCI header type '127' for device '0000:01:00.0'
déc. 28 12:02:42 lenovo pulseaudio[788]: Échec d'ouverture du module module-rescue-streams.so : module-rescue-streams.so: Ne peut ouvrir le fichier d'objet pa>
déc. 28 12:02:42 lenovo pulseaudio[788]: Failed to open module "module-rescue-streams".
~

roger64 · December 28, 2020, 4:15am

Here are the failed

-- Journal begins at Mon 2020-12-28 12:02:08 HKT, ends at Mon 2020-12-28 12:13:38 HKT. --
déc. 28 12:02:08 lenovo kernel: platform MSFT0101:00: failed to claim resource 1: [mem 0xfed40000-0xfed40fff]
déc. 28 12:02:08 lenovo kernel: acpi MSFT0101:00: platform device creation failed: -16
déc. 28 12:02:08 lenovo kernel: pci 0000:01:00.0: BAR 6: failed to assign [mem size 0x00080000 pref]
déc. 28 12:02:08 lenovo systemd-udevd[290]: 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/>
déc. 28 12:02:08 lenovo kernel: vboxdrv: module verification failed: signature and/or required key missing - tainting kernel
déc. 28 12:02:09 lenovo systemd-udevd[274]: cfg80211: Process '/usr/bin/set-wireless-regdom' failed with exit code 1.
déc. 28 12:02:09 lenovo libvirtd[501]: internal error: Failed to initialize a valid firewall backend
déc. 28 12:02:09 lenovo libvirtd[501]: internal error: Failed to initialize a valid firewall backend
déc. 28 12:02:10 lenovo libvirtd[501]: internal error: Failed to initialize a valid firewall backend
déc. 28 12:02:11 lenovo dbus-daemon[450]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.resolve1.service': Unit dbus-org.freedesktop.resolve1.service not found.
déc. 28 12:02:11 lenovo dbus-daemon[450]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.home1.service': Unit dbus-org.freedesktop.home1.service not found.
déc. 28 12:02:11 lenovo dbus-daemon[450]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.home1.service': Unit dbus-org.freedesktop.home1.service not found.
déc. 28 12:02:11 lenovo systemd[689]: -.slice: Failed to migrate controller cgroups from /user.slice/user-1000.slice/user@1000.service, ignoring: Permission denied
déc. 28 12:02:42 lenovo cinnamon-session[708]: WARNING: t+29,98180s: Application 'pulseaudio.desktop' failed to register before timeout
déc. 28 12:02:42 lenovo pulseaudio[788]: Failed to open module "module-rescue-streams".
déc. 28 12:05:11 lenovo dbus-daemon[450]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.home1.service': Unit dbus-org.freedesktop.home1.service not found.
déc. 28 12:13:38 lenovo dbus-daemon[450]: [system] Activating via systemd: service name='org.freedesktop.home1' unit='dbus-org.freedesktop.home1.service' requested by ':1.65' (uid=0 pid=1788 com>
déc. 28 12:13:38 lenovo dbus-daemon[450]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.home1.service': Unit dbus-org.freedesktop.home1.service not found.
déc. 28 12:13:38 lenovo sudo[1788]:    roger : TTY=pts/0 ; PWD=/home/roger ; USER=root ; COMMAND=/usr/sbin/journalctl -b0 -g failed

roger64 · December 28, 2020, 9:41am

Once I uninstalled libvirt and other friends, errs boiled down to

-- Journal begins at Mon 2020-12-28 17:37:33 HKT, ends at Mon 2020-12-28 17:38:18 HKT. --
déc. 28 17:37:33 lenovo kernel: platform MSFT0101:00: failed to claim resource 1: [mem 0xfed40000-0xfed40fff]
déc. 28 17:37:33 lenovo kernel: acpi MSFT0101:00: platform device creation failed: -16
déc. 28 17:37:33 lenovo systemd-udevd[269]: /etc/udev/rules.d/40-libsane.rules:26: GOTO="libsane_rules_end" has no matching label, ignori>
déc. 28 17:37:33 lenovo systemd-udevd[269]: /etc/udev/rules.d/S99-2000S1.rules:26: GOTO="libsane_rules_end" has no matching label, ignori>
déc. 28 17:37:33 lenovo systemd-udevd[277]: sda: /etc/udev/rules.d/60-schedulers.rules:6 Failed to write ATTR{/sys/devices/pci0000:00/000>
déc. 28 17:37:35 lenovo dhcpcd[466]: dhcpcd_prestartinterface: Operation not possible due to RF-kill
déc. 28 17:37:35 lenovo dhcpcd[466]: dhcpcd_prestartinterface: Operation not possible due to RF-kill
déc. 28 17:38:07 lenovo pulseaudio[752]: Échec d'ouverture du module module-rescue-streams.so : module-rescue-streams.so: Ne peut ouvrir >
déc. 28 17:38:07 lenovo pulseaudio[752]: Failed to open module "module-rescue-streams".
~

roger64 · December 28, 2020, 9:45am

and failed

-- Journal begins at Mon 2020-12-28 17:37:33 HKT, ends at Mon 2020-12-28 17:38:18 HKT. --
déc. 28 17:37:33 lenovo kernel: platform MSFT0101:00: failed to claim resource 1: [mem 0xfed40000-0xfed40fff]
déc. 28 17:37:33 lenovo kernel: acpi MSFT0101:00: platform device creation failed: -16
déc. 28 17:37:33 lenovo systemd-udevd[269]: /etc/udev/rules.d/40-libsane.rules:26: GOTO="libsane_rules_end" has no matching label, ignori>
déc. 28 17:37:33 lenovo systemd-udevd[269]: /etc/udev/rules.d/S99-2000S1.rules:26: GOTO="libsane_rules_end" has no matching label, ignori>
déc. 28 17:37:33 lenovo systemd-udevd[277]: sda: /etc/udev/rules.d/60-schedulers.rules:6 Failed to write ATTR{/sys/devices/pci0000:00/000>
déc. 28 17:37:35 lenovo dhcpcd[466]: dhcpcd_prestartinterface: Operation not possible due to RF-kill
déc. 28 17:37:35 lenovo dhcpcd[466]: dhcpcd_prestartinterface: Operation not possible due to RF-kill
déc. 28 17:38:07 lenovo pulseaudio[752]: Échec d'ouverture du module module-rescue-streams.so : module-rescue-streams.so: Ne peut ouvrir >
déc. 28 17:38:07 lenovo pulseaudio[752]: Failed to open module "module-rescue-streams".
~