Wake up from suspend takes 4 minutes

Ask Fedora
, ,
1

I recently install fedora 38 on my MBP 2011, and it takes forever to wake up from suspend, approximately 3-4 minutes. I have double boot with ubuntu, and in ubuntu everything works fine. As i can see in journalctl there is a very long delay before it starts to wake up, but i was just pressing suspend button, then wait for 10 second and press a key to wake it up.

May 06 15:43:47 fedora kernel: PM: suspend devices took 0.733 seconds
May 06 15:43:47 fedora kernel: sd 0:0:0:0: [sda] Stopping disk
May 06 15:43:47 fedora kernel: sd 2:0:0:0: [sdb] Stopping disk
May 06 15:43:47 fedora kernel: sd 0:0:0:0: [sda] Synchronizing SCSI cache
May 06 15:43:47 fedora kernel: sd 2:0:0:0: [sdb] Synchronizing SCSI cache
May 06 15:43:47 fedora kernel: wlp3s0 Scan_results error (-22)
May 06 15:43:47 fedora kernel: ERROR @wl_notify_scan_status : 
May 06 15:43:47 fedora kernel: printk: Suspending console(s) (use no_console_suspend to debug)
May 06 15:43:47 fedora kernel: Freezing remaining freezable tasks completed (elapsed 0.001 seconds)
May 06 15:43:47 fedora kernel: Freezing remaining freezable tasks
May 06 15:43:47 fedora kernel: OOM killer disabled.
May 06 15:43:47 fedora kernel: Freezing user space processes completed (elapsed 0.002 seconds)
May 06 15:43:47 fedora kernel: Freezing user space processes
May 06 15:40:54 fedora kernel: Filesystems sync: 0.361 seconds
May 06 15:40:54 fedora kernel: PM: suspend entry (deep)
May 06 15:40:54 fedora systemd-sleep[4473]: Entering sleep state 'suspend'...
May 06 15:40:54 fedora wpa_supplicant[1133]: nl80211: deinit ifname=wlp3s0 disabled_11b_rates=0
May 06 15:40:54 fedora wpa_supplicant[1133]: wlp3s0: CTRL-EVENT-DSCP-POLICY clear_all

The only thing i’ve noticed that there is bolt.service that makes troubles.

May 06 15:43:47 fedora rtkit-daemon[855]: Successfully demoted thread 2265 of process 2265 (/usr/bin/pipewire).
May 06 15:43:47 fedora systemd[1]: bolt.service: Killing process 1039 (boltd) with signal SIGABRT.
May 06 15:43:47 fedora rtkit-daemon[855]: Successfully demoted thread 2278 of process 2265 (/usr/bin/pipewire).
May 06 15:43:47 fedora audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-coredump@0-4575-0 comm="systemd" exe="/usr/lib/syste>
May 06 15:43:47 fedora audit: BPF prog-id=94 op=LOAD
May 06 15:43:47 fedora audit: BPF prog-id=93 op=LOAD
May 06 15:43:47 fedora audit: BPF prog-id=92 op=LOAD
May 06 15:43:47 fedora kernel: rfkill: input handler enabled
May 06 15:43:47 fedora gnome-shell[2114]: Could not release device '/dev/input/event13' (13,77): Timeout was reached
May 06 15:43:47 fedora rtkit-daemon[855]: Successfully demoted thread 4144 of process 4004 (/usr/lib64/firefox/firefox).
May 06 15:43:47 fedora systemd[1]: bolt.service: Watchdog timeout (limit 3min)!
May 06 15:43:47 fedora rtkit-daemon[855]: Demoting known real-time threads.
May 06 15:43:47 fedora systemd-resolved[807]: Clock change detected. Flushing caches.
2

I had the same problem when I upgraded my desktop PC at work to F38.
As I didn’t have time to debug it, I simply disabled the automatic suspend after x minutes.

When I have some time, I’ll investigate and report here.

3

Did you have f37 before, was it working fine?

4

Yes, I had f37 and suspend was working fine.

5

I had this problem on my MBP 2011 too. The exact same problem. For me there used to be a crash too in the logs

watchdog: bug: soft lockup - cpu#3 stuck for 22s! [cpuhp/3:30]

I managed to solve this post an observation made by a user regarding the soft lockup above. The solution was to run a script before and after wakeup as in this post.

1 Like
6

I tried that solution but it’s not working.
add an echo to better find an output in log

#!/bin/sh
echo "fix macbook wakeup"
case "$1/$2" in
  pre/*)
    echo "Going to $2..."       
    echo 0 > /sys/devices/system/cpu/cpu3/online
    ;;
  post/*)
    echo "Waking up from $2..."
    echo 1 > /sys/devices/system/cpu/cpu3/online
    ;;
esac

and now there a 2 minutes between suspend and wake up. But i press a key 2-3 second later after my MBP was suspended.

May 26 15:59:55 fedora systemd-sleep[5164]: fix macbook wakeup
May 26 15:59:55 fedora systemd-sleep[5164]: Going to suspend...
May 26 15:59:55 fedora kernel: smpboot: CPU 3 is now offline
May 26 15:59:55 fedora systemd-sleep[5153]: Entering sleep state 'suspend'...
May 26 15:59:55 fedora kernel: PM: suspend entry (deep)
May 26 15:59:56 fedora kernel: Filesystems sync: 0.773 seconds
May 26 16:02:06 fedora kernel: Freezing user space processes
May 26 16:02:06 fedora kernel: Freezing user space processes completed (elapsed 0.003 seconds)

and that is output by wake up from the script just several lines later

May 26 16:02:06 fedora systemd-sleep[5301]: fix macbook wakeup
May 26 16:02:06 fedora systemd-sleep[5301]: Waking up from suspend...

I also install fedora 37, and it didn’t solve the problem.

By the way i have MBP 17" early 2011

7

Ok, now the problem is solved for me, thank you. In my case the main issue was CPU 5, but i also noticed that CPU 6 and sometime 7 was slow waking up. I was looking in journalctl -b to see when MBP goes to sleep and wakes up. Then using dmesg -T was looking for a CPU that slows the waking up process. This was in my log

[Fri May 26 22:30:13 2023] x86: Booting SMP configuration:
[Fri May 26 22:30:13 2023] smpboot: Booting Node 0 Processor 1 APIC 0x2
[Fri May 26 22:30:15 2023] CPU1 is up
[Fri May 26 22:30:15 2023] smpboot: Booting Node 0 Processor 2 APIC 0x4
[Fri May 26 22:30:16 2023] CPU2 is up
[Fri May 26 22:30:16 2023] smpboot: Booting Node 0 Processor 4 APIC 0x1
[Fri May 26 22:30:16 2023] CPU4 is up
[Fri May 26 22:30:16 2023] smpboot: Booting Node 0 Processor 5 APIC 0x3
[Fri May 26 22:30:54 2023] perf: interrupt took too long (56978 > 56560), lowering kernel.perf_event_max_sample_rate to 3000
[Fri May 26 22:31:34 2023] CPU5 is up
[Fri May 26 22:31:34 2023] smpboot: Booting Node 0 Processor 6 APIC 0x5
[Fri May 26 22:32:14 2023] perf: interrupt took too long (71958 > 71222), lowering kernel.perf_event_max_sample_rate to 2000
[Fri May 26 22:32:16 2023] CPU6 is up
[Fri May 26 22:32:16 2023] smpboot: Booting Node 0 Processor 7 APIC 0x7
[Fri May 26 22:32:19 2023] CPU7 is up

Then i decided to disable before suspend and enable after wake up CPU 5, 6, 7

#!/bin/sh
echo "fix macbook wakeup"
case "$1/$2" in
  pre/*)
    echo "going to $2..."       
    echo 0 > /sys/devices/system/cpu/cpu5/online
    echo 0 > /sys/devices/system/cpu/cpu6/online
    echo 0 > /sys/devices/system/cpu/cpu7/online
    ;;
  post/*)
    echo "waking up from $2..."
    echo 1 > /sys/devices/system/cpu/cpu5/online
    echo 1 > /sys/devices/system/cpu/cpu6/online
    echo 1 > /sys/devices/system/cpu/cpu7/online
    ;;
esac

Now I’m considering to disable/enable all of them 1-7.

2 Likes
8

Now i did some more measurement and come to the conclusion that switching only 1-2 cores results of wake up time of 1-2 minutes, and 3 cores - 5,6,7, give me approximately wake up time of 10 seconds, but switching all CPUs 1-7 give me wake up time of 5 seconds.

9

This is the script that switches all the CPUs

#!/bin/sh

switch_cpu () {
    for cpu in $(ls /sys/devices/system/cpu | egrep -i 'cpu[1-9][0-9]?'); do
      echo $1 > /sys/devices/system/cpu/$cpu/online;
    done
}

echo "fix macbook wakeup"
case "$1/$2" in
  pre/*)
    echo "going to $2..."       
    switch_cpu 0        
    ;;
  post/*)
    echo "waking up from $2..."
    switch_cpu 1
   ;;
esac
1 Like