https://bugzilla.kernel.org/show_bug.cgi?id=201111
--- Comment #2 from John ([email protected]) --- I edited suspend.c to add some log output at several points in this process. The hope was to better capture where the delay happened. As shown below, there are several atypical lines after "suspend entry (deep)". I also changed pm_pr_dbg to pr_info in several places. previously, the delay appeared to be before "Syncing filesystems ... done." I don't know if this is really the case, I but wondered if the timestep was for the line below pr_cont("done.\n"); This would have been after ksys_sync(). So I was trying to find if the delay was from ksys_sync(). in bug 101101, Aaron Lu indicated that dmesg was a more reliable source of information for timesteps, but my experience has been different. For a recent suspend instance, this is my dmesg output: --------------------------------------------------------------------------------------------------------------- [ 83.358713] PM: suspend entry (deep) [ 83.358717] PM: enter_state: entered [ 83.358720] PM: enter_state: before pm_mutex lock [ 83.358723] PM: enter_state: pm_mutex lock acquired [ 83.358724] PM: Syncing filesystems ... [ 83.369092] PM: Preparing system for sleep (deep) [ 83.369698] Freezing user space processes ... (elapsed 0.001 seconds) done. [ 83.371163] OOM killer disabled. [ 83.371165] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done. [ 83.372414] PM: Suspending system (deep) [ 83.372542] Suspending console(s) (use no_console_suspend to debug) [ 83.373011] wlp2s0: deauthenticating from xx:xx:xx:xx:xx:xx by local choice (Reason: 3=DEAUTH_LEAVING) [ 83.393004] sd 0:0:0:0: [sda] Synchronizing SCSI cache [ 83.396715] sd 0:0:0:0: [sda] Stopping disk [ 83.770548] ACPI: EC: interrupt blocked [ 83.786863] ACPI: Preparing to enter system sleep state S3 [ 83.789004] ACPI: EC: event blocked [ 83.789006] ACPI: EC: EC stopped [ 83.789008] PM: Saving platform NVS memory [ 83.790412] Disabling non-boot CPUs ... [ 83.847815] smpboot: CPU 1 is now offline [ 83.887931] smpboot: CPU 2 is now offline [ 83.921127] smpboot: CPU 3 is now offline [ 83.924454] ACPI: Low-level resume complete [ 83.924507] ACPI: EC: EC started [ 83.924508] PM: Restoring platform NVS memory [ 83.926184] Enabling non-boot CPUs ... --------------------------------------------------------------------------------------------------------------- As shown here, the process takes place in approx 0.6 seconds. journalctl's output shows the delay: --------------------------------------------------------------------------------------------------------------- Sep 23 20:34:39 computername kernel: PM: suspend entry (deep) Sep 23 20:34:39 computername kernel: PM: enter_state: entered Sep 23 20:34:39 computername kernel: PM: enter_state: before pm_mutex lock Sep 23 20:34:39 computername kernel: PM: enter_state: pm_mutex lock acquired Sep 23 20:34:39 computername kernel: PM: Syncing filesystems ... Sep 23 20:34:39 computername kernel: PM: Preparing system for sleep (deep) Sep 23 20:36:43 computername kernel: Freezing user space processes ... (elapsed 0.001 seconds) done. Sep 23 20:36:43 computername kernel: OOM killer disabled. Sep 23 20:36:43 computername kernel: Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done. Sep 23 20:36:43 computername kernel: PM: Suspending system (deep) Sep 23 20:36:43 computername kernel: Suspending console(s) (use no_console_suspend to debug) Sep 23 20:36:43 computername kernel: wlp2s0: deauthenticating from xx:xx:xx:xx:xx:xx by local choice (Reason: 3=DEAUTH_LEAVING) Sep 23 20:36:43 computername kernel: sd 0:0:0:0: [sda] Synchronizing SCSI cache Sep 23 20:36:43 computername kernel: sd 0:0:0:0: [sda] Stopping disk Sep 23 20:36:43 computername kernel: ACPI: EC: interrupt blocked Sep 23 20:36:43 computername kernel: ACPI: Preparing to enter system sleep state S3 Sep 23 20:36:43 computername kernel: ACPI: EC: event blocked Sep 23 20:36:43 computername kernel: ACPI: EC: EC stopped Sep 23 20:36:43 computername kernel: PM: Saving platform NVS memory Sep 23 20:36:43 computername kernel: Disabling non-boot CPUs ... Sep 23 20:36:43 computername kernel: smpboot: CPU 1 is now offline Sep 23 20:36:43 computername kernel: smpboot: CPU 2 is now offline Sep 23 20:36:43 computername kernel: smpboot: CPU 3 is now offline --------------------------------------------------------------------------------------------------------------- but I agree with Aaron Lu, in that journalctl, as a process, seems to be suspended before the hang-up occurs, and therefore its timestep cannot be considered reliable. In fact, the gap in time shown in journalctl is a factor of the amount of time between when i initiate the suspend and when I resume by pushing the power button. If I waited 4 minutes to resume when the computer actually enters sleep after 2, journalctl's output shows 4 minutes as the delay. Both stories aren't as helpful as I'd like them to be for finding the point in the suspend process where the delay actually occurs. -- You are receiving this mail because: You are watching the assignee of the bug. _______________________________________________ acpi-bugzilla mailing list [email protected] https://lists.sourceforge.net/lists/listinfo/acpi-bugzilla
