Slow boot (40s) from clover menu to desktop on NVME SSD

[thy1225]

I'm having this slow boot problem for a while, other than this, everything is running smoothly.

It took 40 seconds from the clover menu to the desktop. I'd checked my boot log from the terminal by this command 'bdmesg' and notice there's a thing that spent "18s" but I just can't figure it out what it is.

Could someone help me identify the problem?

Please let me know if I need to provide some other information~

Thanks

here's the boot log in the attachment

boot.log

[MaLd0n]

[ref]thy1225[/ref], check with

log show --last boot --style syslog

[thy1225]

[ref]MaLd0n[/ref], here is the output log

I zipped it cause it was 11MB

Really appreciate for helping ??~

bootLog.log.zip

[thy1225]

Hi [ref]MaLd0n[/ref], I found out where the problem might be.

Maybe it's about "(AppleACPIEC)" and " in the log below" (it took almost 9 seconds here)

I found a thread also talking about slow booting in catalina here (https://Olarila.com/forum/viewtopic.php?t=13368)

In there you mention about kill the EC device and add a fake one.

But I don't know how.

can I just comment it off as I did in the screenshot?

Thanks

 

2019-12-23 11:48:33.768038+0800  localhost kernel[0]: PMRD: destroyed capability client set <private>
2019-12-23 11:48:33.768041+0800  localhost kernel[0]: PMRD: PowerChangeDone: ON_STATE->ON_STATE
2019-12-23 11:48:34.652716+0800  localhost kernel[0]: (AppleACPIEC) EC IBF=0 poll timed out
2019-12-23 11:48:34.925001+0800  localhost kernel[0]: PMRD: getAggressiveness type 0x2 not found
2019-12-23 11:48:34.925028+0800  localhost kernel[0]: PMRD: power event 7 args <private> 0x0
2019-12-23 11:48:34.925084+0800  localhost kernel[0]: PMRD: destroyed capability client set <private>
2019-12-23 11:48:34.925087+0800  localhost kernel[0]: PMRD: PowerChangeDone: ON_STATE->ON_STATE
2019-12-23 11:48:34.925253+0800  localhost kernel[0]: PMRD: power event 7 args <private> 0x0
2019-12-23 11:48:34.925261+0800  localhost kernel[0]: PMRD: destroyed capability client set <private>
2019-12-23 11:48:34.925266+0800  localhost kernel[0]: PMRD: PowerChangeDone: ON_STATE->ON_STATE
2019-12-23 11:48:35.756309+0800  localhost kernel[0]: (AppleACPIEC) EC IBF=0 poll timed out
2019-12-23 11:48:36.859867+0800  localhost kernel[0]: (AppleACPIEC) EC IBF=0 poll timed out
2019-12-23 11:48:37.963430+0800  localhost kernel[0]: (AppleACPIEC) EC IBF=0 poll timed out
2019-12-23 11:48:39.067004+0800  localhost kernel[0]: (AppleACPIEC) EC IBF=0 poll timed out
2019-12-23 11:48:39.067008+0800  localhost kernel[0]: (AppleACPIEC) ACPI: no ECDT
2019-12-23 11:48:44.585992+0800  localhost kernel[0]: <compose failure [uUID]>
2019-12-23 11:48:44.586058+0800  localhost kernel[0]: MAC Framework successfully initialized
2019-12-23 11:48:44.586063+0800  localhost kernel[0]: ulock_initialize>thread_max=40960, ull_hash_buckets=16384
2019-12-23 11:48:44.586275+0800  localhost kernel[0]: (IOUSBFamily) 000012.586271 AppleUSBLegacyRoot@(null): AppleUSBLegacyRoot::init: enabling legacy matching
2019-12-23 11:48:44.586320+0800  localhost kernel[0]: PMRD: PowerChangeDone: ON_STATE->ON_STATE
2019-12-23 11:48:44.586338+0800  localhost kernel[0]: PMRD: PowerChangeDone: ON_STATE->ON_STATE

[MaLd0n]

[ref]thy1225[/ref], fixed it

use it instead

Device (EC)
               {
                   Name (_HID, "MALD0000")  // _HID: Hardware ID
               }

[thy1225]

Hi [ref]MaLd0n[/ref], I just did what you said and now it's faster (from:40s -> 30s) !!

thank you so much!!

30 seconds still seems to have some room for improvement but I'll keep looking!

Thanks for the quick help!!!

 

[ref]thy1225[/ref], fixed it

use it instead

Device (EC)
               {
                   Name (_HID, "MALD0000")  // _HID: Hardware ID
               }

[MaLd0n]

[ref]thy1225[/ref], use last update Olarila folder

[thy1225]

[ref]MaLd0n[/ref], Thanks I did it and also update the clover to 5101

Now it's 5 seconds faster. (25 seconds in total)

I keep googling about it and someone mension this "apfs_module_start:1683" is the problem and the solution is to add a "SSDT-EC.aml", I added it but it made no difference and the "apfs_module_start:1683" is still in the boot log

if I boot with -v, is always hang around here:

ALF, old data swfs_pid_entry <ptr>, updaterules_msg <ptr>, updaterules_state <ptr>

 

Thanks again for helping

[MaLd0n]

[ref]thy1225[/ref], with verbose mode u gain some seconds too, remove it

[thy1225]

[ref]MaLd0n[/ref], Thanks!! I'll remove it and see how it goes.

[voyager99]

Hello, would appreciate any advice on a slow boot issue I'm having. I am currently running Catalina 10.15.6 (build 19G2021 August 12, 2020) using OpenCore 0.60 with an i7-10700K on an MSI MPG Z490M GAMING EDGE WIFI board. The system is stable, but the boot time is running about 15 seconds slower than it should. Running the command:

 

log show --last boot --style syslog

Update: Kernel log from HackinTool:

 

I believe I've identified the issue (about a 15 second delay) as an incompatible wifi module (Intel AX201) on this motherboard. In my config.plist, my smbios is set to iMac19,1 to allow it to work with Intel Comet Lake CPU's.

 

Partial log file displaying the issue I believe is the problem.

New kernel log below:

2020-09-09 14:31:05.743794-0400  localhost kernel[0]: BSD root: disk4s5
2020-09-09 14:31:05.743795-0400  localhost kernel[0]: , major 1, minor 14
2020-09-09 14:31:05.743872-0400  localhost kernel[0]: (IOStorageFamily) <IOStorageFamily`dkreadwritecompletion(void*, void*, int, unsigned long long)> disk4s5: device is not readable.
2020-09-09 14:31:05.743875-0400  localhost kernel[0]: (HFS) <HFS`hfs_mountfs> hfs_mountfs: buf_meta_bread failed with 13
2020-09-09 14:31:05.743878-0400  localhost kernel[0]: (HFS) <HFS`hfs_mount> hfs_mount: hfs_mountfs returned error=13 for device unknown-dev
2020-09-09 14:31:05.743880-0400  localhost kernel[0]: hfs_mountroot failed: 13
2020-09-09 14:31:05.743882-0400  localhost kernel[0]: (apfs) <apfs`log_debug> apfs_vfsop_mountroot:1502: apfs: mountroot called!
2020-09-09 14:31:05.743980-0400  localhost kernel[0]: (apfs) <apfs`log_debug> dev_init:294: /dev/disk4: device accelerated crypto: 0 (compiled @ Jul  6 2020 11:46:26)
2020-09-09 14:31:05.743983-0400  localhost kernel[0]: (apfs) <apfs`log_debug> dev_init:297: /dev/disk4: device_handle block size 4096 block count 249999948 features 16 internal solidstate
2020-09-09 14:31:05.744050-0400  localhost kernel[0]: (apfs) <apfs`log_debug> nx_kernel_mount:1121: /dev/disk4: initializing cache w/hash_size 16384 and cache size 40960
2020-09-09 14:31:05.753043-0400  localhost kernel[0]: (apfs) <apfs`log_debug> nx_kernel_mount:1385: /dev/disk4: checkpoint search: largest xid 36575, best xid 36575 @ 114
2020-09-09 14:31:05.753428-0400  localhost kernel[0]: (apfs) <apfs`log_debug> sanity_check_alloced_blocks:270: fs_alloc_count mismatch: fs root nodes 40957 extent 1 omap 550 snap_meta 1 er: 0 udata: 2665387 fs_alloc_count 2710321
2020-09-09 14:31:05.753430-0400  localhost kernel[0]: (apfs) <apfs`log_debug> er_state_obj_get_for_recovery:4639: No ER state object for volume hack1nt0sh - rolling is not happening, nothing to recover.
2020-09-09 14:31:05.753432-0400  localhost kernel[0]: (apfs) <apfs`log_debug> apfs_vfsop_mount:1318: Promoter has been locked for /dev/disk4
2020-09-09 14:31:05.753470-0400  localhost kernel[0]: (apfs) <apfs`log_info> handle_mount:329: vol-uuid: B6C8D021-9BB7-4A78-87BF-3EC54A7EA42A block size: 4096 block count: 249999948 (unencrypted; flags: 0x1; features: 1.0.12)
2020-09-09 14:31:05.754127-0400  localhost kernel[0]: (apfs) <apfs`log_debug> handle_mount:342: setting dev block size to 4096 from 512
2020-09-09 14:31:05.754130-0400  localhost kernel[0]: (apfs) <apfs`log_debug> handle_mount:383: ROSV: apfs mounted RO and is the system volume of a volume group and mounted as the root fs: creating the shadow fs_root
2020-09-09 14:31:05.754134-0400  localhost kernel[0]: (apfs) <apfs`log_debug> fs_setup_shadow_fs_root_tree:1452: Created the shadow_fs_root tree <private>
2020-09-09 14:31:05.754156-0400  localhost kernel[0]: (apfs) <apfs`log_debug> nx_volume_group_update:6431: Set volume (role 0x1) to 41d xid 0
2020-09-09 14:31:05.754181-0400  localhost kernel[0]: (apfs) <apfs`log_debug> apfs_vfsop_mount:1489: mounted volume: hack1nt0sh
2020-09-09 14:31:05.754250-0400  localhost kernel[0]: ioqueue_depth = 256,   ioscale = 8
2020-09-09 14:31:05.754849-0400  localhost kernel[0]: NOTE: Attempting ROSV mount
2020-09-09 14:31:05.754850-0400  localhost kernel[0]: NOTE: DETECTED ROSV CONFIG
2020-09-09 14:31:05.754851-0400  localhost kernel[0]: attempting kernel mount for data volume...
2020-09-09 14:31:05.756079-0400  localhost kernel[0]: (apfs) <apfs`log_debug> sanity_check_alloced_blocks:270: fs_alloc_count mismatch: fs root nodes 89881 extent 1509 omap 1944 snap_meta 1 er: 0 udata: 7946200 fs_alloc_count 8088476
2020-09-09 14:31:28.797446-0400  localhost kernel[0]: (ALF) <ALF`sockwall_cntl_updaterules> ALF, old data swfs_pid_entry <private>, updaterules_msg <private>, updaterules_state <private>
2020-09-09 14:31:28.799850-0400  localhost kernel[0]: PMRD: power event 4 args 0x3b773984eebb8303 0x0
2020-09-09 14:31:28.804643-0400  localhost kernel[0]: PMRD: power event 6 args 0x3b773984f0ed7403 0x0
2020-09-09 14:31:28.804644-0400  localhost kernel[0]: PMRD: power event 6 args 0x3b773984f0ed7403 0x0
2020-09-09 14:31:28.804651-0400  localhost kernel[0]: PMRD: destroyed capability client set 0x3b773984f0f90833
2020-09-09 14:31:28.804658-0400  localhost kernel[0]: PMRD: PowerChangeDone: ON_STATE->ON_STATE
2020-09-09 14:31:28.804858-0400  localhost kernel[0]: PMRD: power event 12 args 0x3b773984f0f924e3 0x0
2020-09-09 14:31:28.804860-0400  localhost kernel[0]: PMRD: SleepWake UUID queued: B3ED6BB3-1B07-4D88-8C04-DB703B6CA917
2020-09-09 14:31:28.805129-0400  localhost kernel[0]: Waiting for DSMOS...
2020-09-09 14:31:28.815566-0400  localhost kernel[0]: ifnet_attach: All kernel threads created for interface en0 have been scheduled at least once. Proceeding.
2020-09-09 14:31:28.857175-0400  localhost kernel[0]: (HFS) <HFS`hfs_mountfs> hfs: mounted samsung1Tb on device disk2s1
2020-09-09 14:31:29.045311-0400  localhost kernel[0]: PMRD: power event 5 args 0x3b773984eebb8303 0x0
2020-09-09 14:31:29.046825-0400  localhost kernel[0]: PMRD: setAggressiveness(0) kPMMinutesToSleep = 60
2020-09-09 14:31:29.046830-0400  localhost kernel[0]: PMRD: setAggressiveness(0) kPMMinutesToDim = 60
2020-09-09 14:31:29.047114-0400  localhost kernel[0]: PMRD: aggressiveness changed: system 0->60, display 60
2020-09-09 14:31:29.047115-0400  localhost kernel[0]: PMRD: idle time -> 0 secs (ena 1)
2020-09-09 14:31:29.047115-0400  localhost kernel[0]: PMRD: idle sleep timer enabled

 

My question is, can you please tell me how I can prevent Catalina from trying to load/enable Wifi (I tried disabling Wifi and Bluetooth in the BIOS without success)? Can I disable it in the devices section in my config.plist or by editing a .kext? Thank you for any help you can provide.

I have 2 NVME SSD's (1 Samsung 970 and 1 ADATA SX8200 Pro).

Trim support has been enabled.

Any ideas on how to resolve the boot delay? Appreciated!

 

voyager99

Edited September 9, 2020 by voyager99

[MaLd0n]

10 hours ago, voyager99 said:

Trim support has been enabled.

u enabled trim or "native" trim nvme?

[voyager99]

On 9/9/2020 at 11:10 PM, MaLd0n said:

u enabled trim or "native" trim nvme?

I tried both, but no success. I read that enabling trim is not possible on nvme drives. I've tried everything I can think of, but no luck. I am using opencore 0.6.0, but recently tried 0.6.1 and a new iMac20,1, but also no luck. I even purchased the ADATA SX8200 Pro because they use the same controller (Silicon Motion) as OWC Mac Sales.

The issue has always been:

2020-09-09 14:31:28.797446-0400  localhost kernel[0]: (ALF) <ALF`sockwall_cntl_updaterules> ALF, old data swfs_pid_entry <private>, updaterules_msg <private>, updaterules_state <private>

Any help would be appreciated. Thanks.

[MaLd0n]

the freeze appears in some nvme. like samsung 970 and others. don't have solution

next time use WD Black SN750 NVMe SSD

check my boot time with clover or opencore

 

 

[voyager99]

I see. That's impressive (11 sec. boot time). Are you using a WD Black SN750 NVMe SSD for OS X and what board and cpu are you using?

Also, opencore or clover?

Thanks. 

[MaLd0n]

8 minutes ago, voyager99 said:

I see.

here

https://www.olarila.com/topic/9506-olarila-hackbeast-z490-vision-d-thunderbolt-full-dsdt-patches-clover-or-opencore-imac-20-hackintosh-guide-and-discussion/

[voyager99]

On 9/12/2020 at 10:32 AM, MaLd0n said:

here

https://www.olarila.com/topic/9506-olarila-hackbeast-z490-vision-d-thunderbolt-full-dsdt-patches-clover-or-opencore-imac-20-hackintosh-guide-and-discussion/

Thanks, I can confirm that the problem can be solved by buying a Western Digital Black SN750 SSD (as you suggested):

https://www.amazon.com/Western-Digital-Black-SN750-500GB/dp/B07NDF52G2

and cloning the existing drive using Carbon Copy Cloner and swapping out the existing Samsung (or other SSD like my ADATA SX8200 Pro) SSD. I also had to mount the EFI partition and copy over the folder into the new WD SSD. This worked like a charm for me and now allows my system running Catalina 10.15.6 to boot in 10.7 seconds (down from 32.5 seconds). Amazing SSD from Western Digital! Thank you.

[MaLd0n]

26 minutes ago, voyager99 said:

Amazing SSD from Western Digital! Thank you.

Enjoy!  

[Mac-B]

Vi que alguns estão reclamando da demora do boot, mas o meu, pra iniciar, bate o recorde. São cerca de 3 min. Imagino que deva ser alguma configuração no Clover. O que poderia ser feito pra melhorar o meu tempo de boot? Máquina: Chipset H61, Processador Intel Core i3 3220, 8GB mem. Atualmente uso a sábios iMac 16,1 mas sei que o ideal para esse hardware é o iMac 13,2 (Tem uma explicação para isso) que mesmo assim também os mesmos 3 minutos para o boot completo. Se puder me ajudar, precisa de algo que eu tenho que fazer aqui?

Obrigado.

[MaLd0n]

tem de ver o que está causando isso. vc usa ssd? trim está ativado com o ssd em apfs?

[LiveSorcerer]

Estou passando por um problema parecido.

Aqui troquei meu NVMe Samsung 970 Evo Plus  500GB por  um XPG S11 Pro 1TB, e estou levando o mesmo tempo do outro, media de 25~30 segundos.
Dai a duvida, não poderia ser os HHDs que tenho ligado nessa maquina, e ele tenta indexar?

Sao 4 HDD de 4TB.