When tracking down issues with pm-suspend (for me, STR or suspend to ram) the files /var/log/pm-suspend.log and, when things go bad, /var/log/messages usually have useful info on what is causing problems.
Navigating /var/log/messages can be messy - many processes send info in asynchronously.
I made the following (highlighted) additions to my systems pm-utils scripts to add markers in /var/log/messages
PVE-LinuxSRV5:~# cd /usr/lib/pm-utils/sleep.d
PVE-LinuxSRV5:/usr/lib/pm-utils/sleep.d # cat 00logging
#!/bin/sh
# Log some extra information at the beginning of a suspend/resume cycle.
# TODO: Make this hook only run when PM_DEBUG is true?
# SUSE: setup also kernel loglevel to show a progress bar
. "${PM_FUNCTIONS}"
case "$1" in
hibernate|suspend)
-n "$PM_LOGFILE" ] || exit 0
# save the old loglevel
read KERNEL_LOGLEVEL DUMMY < /proc/sys/kernel/printk
echo "export KERNEL_LOGLEVEL=$KERNEL_LOGLEVEL" >> /var/run/pm-suspend
# set the loglevel so we see the progress bar.
# if the level is higher than needed, we leave it alone.
if $KERNEL_LOGLEVEL -lt 5 ]; then
echo 5 > /proc/sys/kernel/printk
fi
echo "`date` $1 initiated (cjm)" >> /var/log/messages
echo "$1 initiated: `date`"
echo
echo "`/bin/uname -a`"
echo "kernel command line: '`cat /proc/cmdline`'"
echo "`lsmod`"
echo
echo "`free`"
echo
;;
thaw|resume)
if -n "$KERNEL_LOGLEVEL" ] ; then
echo $KERNEL_LOGLEVEL > /proc/sys/kernel/printk
fi
echo "`date` $1 resume initiated (cjm)" >> /var/log/messages
;;
esac
This script is owned buy root, exercise care when making the edit and keep a backup just in case. Test a suspend when you are done.
Also, be aware that this tweak will likely be overwritten when pm-utils is updated by zypper or YAST.
In my experience, when there is a problem with the suspend process there are messages logged to /var/log/messages, frequently crash notifications and the like. These do not show up in /var/log/pm-suspend.log. Unless you keep really good track of time, it can be difficult (time wise) to know when the suspend process is initiating and to decipher what entries there might (or might not) be suspend related. This is not a solution, but, for me, a useful tool. And I’m off to figure out how to use “logger” rather than >>messages.
Here is my solution following Carlos’ recommendations
carl@PVE-LinuxSRV5:/etc/pm> cd /etc/pm/sleep.d
carl@PVE-LinuxSRV5:/etc/pm/sleep.d> ll
total 20
-rwxr-xr-x 1 root root 495 Apr 22 10:15 00cjm_logging
-rwxr-xr-x 1 root root 164 Oct 29 12:47 99at
-rwxr-xr-x 1 root root 495 Apr 22 10:14 zz_99cjm_logging
carl@PVE-LinuxSRV5:/etc/pm/sleep.d> cat 00cjm_logging
#!/bin/sh
# Log some extra information at the beginning of a suspend/resume cycle.
# TODO: Make this hook only run when PM_DEBUG is true?
# SUSE: setup also kernel loglevel to show a progress bar
# This script created from /usr/lib/pm-utils/sleep.d/00logging to add clear markers in /var/log/messages on suspend/resume
. "${PM_FUNCTIONS}"
case "$1" in
hibernate|suspend)
logger "`date` $1 initiated (cjm)"
;;
# thaw|resume)
# logger "`date` $1 resume initiated (cjm)"
# ;;
esac
carl@PVE-LinuxSRV5:/etc/pm/sleep.d> cat zz_99cjm_logging
#!/bin/sh
# Log some extra information at the beginning of a suspend/resume cycle.
# TODO: Make this hook only run when PM_DEBUG is true?
# SUSE: setup also kernel loglevel to show a progress bar
# This script created from /usr/lib/pm-utils/sleep.d/00logging to add clear markers in /var/log/messages on suspend/resume
. "${PM_FUNCTIONS}"
case "$1" in
# hibernate|suspend)
# logger "`date` $1 initiated (cjm)"
# ;;
thaw|resume)
logger "`date` $1 resume initiated (cjm)"
;;
esac
Make sure the scripts in /etc/pm/sleep.d are executable.
The entry in /var/log/messages on resume appears at the end of the kernel wakeup, when the pm-util resume scripts are run.
For me, opening /var/log/messages and searching for logger jumps to the right spot.
Here is a /var/log messages snippet
............
Apr 22 10:20:34 PVE-LinuxSRV5 logger: Sun Apr 22 10:20:34 EDT 2012 suspend initiated (cjm)
Apr 22 10:20:34 PVE-LinuxSRV5 su: (to carl) root on none
Apr 22 10:20:34 PVE-LinuxSRV5 dbus-daemon[1220]: **** /proc/self/mountinfo changed
Apr 22 10:20:34 PVE-LinuxSRV5 kernel: 204.195280] EXT4-fs (sdb1): re-mounted. Opts: acl,user_xattr,commit=0
Apr 22 10:20:34 PVE-LinuxSRV5 dbus-daemon[1220]: **** /proc/self/mountinfo changed
Apr 22 10:20:34 PVE-LinuxSRV5 dbus-daemon[1220]: **** /proc/self/mountinfo changed
Apr 22 10:20:34 PVE-LinuxSRV5 kernel: 204.205193] EXT4-fs (dm-0): re-mounted. Opts: acl,user_xattr,commit=0
Apr 22 10:20:36 PVE-LinuxSRV5 dbus[1220]: [system] Activating via systemd: service name='org.freedesktop.NetworkManager' unit='dbus-org.freedesktop.NetworkManager.service'
Apr 22 10:20:36 PVE-LinuxSRV5 dbus-daemon[1220]: dbus[1220]: [system] Activating via systemd: service name='org.freedesktop.NetworkManager' unit='dbus-org.freedesktop.NetworkManager.service'
Apr 22 10:20:36 PVE-LinuxSRV5 dbus[1220]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.NetworkManager.service': Unit dbus-org.freedesktop.NetworkManager.service failed to load: No such file or directory. See system logs and 'systemctl status dbus-org.freedesktop.NetworkManager.service' for details.
Apr 22 10:20:36 PVE-LinuxSRV5 dbus-daemon[1220]: dbus[1220]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.NetworkManager.service': Unit dbus-org.freedesktop.NetworkManager.service failed to load: No such file or directory. See system logs and 'systemctl status dbus-org.freedesktop.NetworkManager.service' for details.
Apr 22 10:25:10 PVE-LinuxSRV5 kernel: 207.087416] PM: Syncing filesystems ... done.
Apr 22 10:25:10 PVE-LinuxSRV5 kernel: 207.133097] PM: Preparing system for mem sleep
Apr 22 10:25:10 PVE-LinuxSRV5 kernel: 207.133380] Freezing user space processes ... (elapsed 0.01 seconds) done.
...then a whole lot more