Skip to main content
Topic solved
This topic has been marked as solved and requires no further attention.
Topic: Solved: Delay during boot (Read 1758 times) previous topic - next topic
0 Members and 1 Guest are viewing this topic.

Solved: Delay during boot

I'm trying to understand a delay in booting.  If someone familiar with the process could give me a hint, I'd appreciate it. Booting goes like this:
Code: [Select]
Enter passphrase for hd1,gpt2
15 seconds later
Slot 0 opened
Loading Linux Linux
Loading initial ramdisk...
17 seconds of HP logo on black screen
Starting version 250.5-3-artix
20 seconds later, xfce desktop

Code: [Select]
from dmesg:
[    1.724399] usb 1-1.4: new high-speed USB device number 3 using ehci-pci
[    1.754396] usb 2-1.1: new full-speed USB device number 3 using ehci-pci
[    1.860976] usb 1-1.4: New USB device found, idVendor=05c8, idProduct=038f, bcdDevice= 1.02
[    1.860991] usb 1-1.4: New USB device strings: Mfr=3, Product=1, SerialNumber=2
[    1.860996] usb 1-1.4: Product: HP TrueVision HD
[    1.860999] usb 1-1.4: Manufacturer: Generic
[    1.861003] usb 1-1.4: SerialNumber: 200901010001
[    1.869653] usb 2-1.1: New USB device found, idVendor=8087, idProduct=0a2a, bcdDevice= 0.01
[    1.869667] usb 2-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[   16.911065] ata2.00: qc timeout (cmd 0x47)
[   16.911089] ata2.00: Read log 0x00 page 0x00 failed, Emask 0x40
[   16.911095] ata2.00: NCQ Send/Recv Log not supported
[   16.911099] ata2.00: Read log 0x00 page 0x00 failed, Emask 0x40
[   16.911103] ata2.00: ATA Identify Device Log not supported

Related?  When I mkinitcpio, I get warnings about possible missing firmware for xhci_pci and qat_4xxx.  Since module xhci_pci is loaded, I installed upd72020x-fw from aur.  This gets rid of the xhci_pci warning at mkinitcpio, but the boot delay and error messages are unchanged.

inxi
Code: [Select]
 Host: Pluto Kernel: 5.17.8-artix1-1 arch: x86_64 bits: 64 compiler: gcc
    v: 12.1.0 Desktop: Xfce v: 4.16.0 Distro: Artix Linux base: Arch Linux
Machine:
  Type: Laptop System: HP product: HP Notebook v: Type1ProductConfigId
    serial: <superuser required>
  Mobo: HP model: 8305 v: KBC Version 73.16 serial: <superuser required>
    UEFI: Insyde v: F.25 date: 01/19/2017
CPU:
  Info: quad core AMD E2-7110 APU with AMD Radeon R2 Graphics [MCP]
    arch: Puma speed (MHz): avg: 1263 min/max: 1000/1800
Graphics:
  Device-1: AMD Mullins [Radeon R3 Graphics] vendor: Hewlett-Packard
    driver: radeon v: kernel bus-ID: 00:01.0
  Device-2: Cheng Uei Precision Industry (Foxlink) HP TrueVision HD
    type: USB driver: uvcvideo bus-ID: 1-1.4:3
  Display: x11 server: X.org v: 1.21.1.3 driver: X: loaded: radeon
    unloaded: fbdev,modesetting,vesa gpu: radeon resolution: 1920x1080~60Hz
  Message: Unable to show GL data. Required tool glxinfo missing.
Network:
  Device-1: Realtek RTL810xE PCI Express Fast Ethernet
    vendor: Hewlett-Packard driver: r8169 v: kernel port: 2000 bus-ID: 02:00.0
  Device-2: Intel Wireless 3165 driver: iwlwifi v: kernel bus-ID: 03:00.0
  Device-3: Intel Bluetooth wireless interface type: USB driver: btusb
    bus-ID: 2-1.1:3
Drives:
  Drives:
  Local Storage: total: 148.31 GiB used: 51.45 GiB (34.7%)
  ID-1: /dev/sda vendor: BHT model: WR202HH032G E70215F5 size: 29.12 GiB
    speed: 3.0 Gb/s type: SSD serial: P02702HH2G10572665bb rev: 00 scheme: GPT
  ID-2: /dev/sdb vendor: Aireye model: S1 120GB SSD size: 111.79 GiB                ##  attached to internal cd port ##
    speed: 6.0 Gb/s type: SSD serial: H02811R000326 rev: V2.8 scheme: GPT    
Info:
  Processes: 210 Uptime: 17m Memory: 3.31 GiB used: 1.16 GiB (35.1%)
  Init: runit Compilers: gcc: 12.1.0 Packages: 969 Shell: Bash v: 5.1.16
  inxi: 3.3.15




Re: Delay during boot

Reply #1
Which hardware have you created the dmcrypt container with?

The thing is, dmcrypt uses iterative hash-function in order to encrypt the actual encryption keys with your password. It usually takes several seconds to decrypt the container, no matter how powerful your CPU is. The more powerful is the hardware with which you create a container, the more iterations of the hash-functions happen, the more strong is your key encryption.

So, the delay before opening the container is OK. 15 seconds of delay is a bit too much, according to my experience, thus I suggest that you've encrypted this container with a more powerful hardware than that you use now. I have some 5 seconds delay when the container is opened on both Core i3 5005 and Ryzen 7 Pro 3700. But the containers I use with these processors are used with their 'native' CPUs, the CPUs which which they were created.

But nevertheless, if you are using dmcrypt, prepare to have certain delays during boot. If you use full disk encryption, the delays will be even worse, because in that case the container is opened twice: first, it is opened by grub, and second, by an initramfs script during early boot stage in Linux.

Re: Delay during boot

Reply #2
Thanks for that information.  The luks encryption was done on this same machine.  I'm not worried about the first delay because there's an explanation for it, although you imply it might be a little long.  It's the second delay, apparently associated with an error message,  "ata2.00: Read log 0x00 page 0x00 failed, Emask 0x40", that I thought might be fixable. 
Weirdly, a non-encrypted install on the same ssd almost immediately displays "ata1.00: Read log 0x00 page 0x00 failed" for about 15 s.  ata1 is the original emms drive, ata2 is the added ssd.
Quote
If you use full disk encryption, the delays will be even worse, because in that case the container is opened twice: first, it is opened by grub, and second, by an initramfs script
That's the case here.

Re: Delay during boot

Reply #3
I'm not worried about the first delay because there's an explanation for it, although you imply it might be a little long.
I'm OK with my delays as well, and I haven't measured them with a timer, so everything here is just a suggestion. The delays also depend on what encryption type you use in LUKS. I use luks1 with default encryption algorithm, and I've still never used luks2 with its argon algorithm, and I don't know, how much time it takes to work out.

All and all, those delays are necessary for the encryption to be working. Without these, your password would be hacked by brute force with powerful hardware in a reasonable time. More security = less convenience. And in home usage, everyone should choose the right balance between security and convenience for himself personally.


It's the second delay, apparently associated with an error message,  "ata2.00: Read log 0x00 page 0x00 failed, Emask 0x40", that I thought might be fixable.
Ah, this. Yeah, laptops are often capricious with Linux, especially when using niche and unconventional pieces of hardware. I've never stumbled upon such HDD models.

But perhaps this is somehow related to a kernel bug(?) or rather regression(?) described here:
https://www.reddit.com/r/archlinux/comments/sw4apq/boot_delay_issue_sata_controller_qc_timeout_cmd/
(It seems like this 15 sec delay is a 'qc timeout' hardwired into the kernel code)

If you use the linux kernel, try using the linux-lts one and check if this delay still persists.

Re: Delay during boot

Reply #4
I'm impressed that you found that reddit post--his dmesg is just like mine. 
It seems like this 15 sec delay is a 'qc timeout' hardwired into the kernel code
I tried lts kernel, no change.   So I'll live with a short delay and hope it goes away with a kernel update one day.  Thanks for educating me on this.

Re: Delay during boot

Reply #5
I'm impressed that you found that reddit post--his dmesg is just like mine.
Of course, it is. I've just searched for 'qc timeout (cmd 0x47)' in Google. This is the message generated by the code which actually caused the delay, according to timestamps.

 

Re: Delay during boot

Reply #6
laptops are often capricious with Linux, especially when using niche and unconventional pieces of hardware.  I've never stumbled upon such HDD models.
I replaced the aireye ssd with a crucial ssd, and qc timeout is gone :)  Thanks for your help.
EDIT
Complaints about slow decryption by grub are plentiful.  The explanation seems to be that grub is inherently slower because it "can only do pure software decryption". https://www.reddit.com/r/archlinux/comments/6ahvnk/grub_decryption_really_slow/  Grub takes 17s to decrypt my luks partition, Thunar  about 2s, presumably because it uses kernel modules for the job.
ANOTHER EDIT to wrap up this topic... 
The aireye ssd, which caused qc timeout in this machine, passes all tests in gsmartcontrol and is working normally on another computer.
After changing to non-encrypted root and luks-encrypted home partition, decryption step takes about 2s   :)