PM-Graph

Downloading & Installing PM-Graph

The tools can most easily be installed via git clone and make install

$> git clone http://github.com/intel/pm-graph.git
$> cd pm-graph
$> sudo make install
$> man sleepgraph

A snapshot of the tool is also found in the kernel source under tools/power/pm-graph. The pm-graph tools run with python2 or python3, the choice is made by the /usr/bin/python link. The tools should run in python3 out of the box on most systems, but for python2 you must install python-configparser.

Package Requirements:

• python (core execution)
• python-configparser (for python2)
• python-requests (for googlesheet tools)
• linux-tools-common (includes turbostat which sleepgraph uses in freeze)

$> sudo apt-get install python-configparser python-requests linux-tools-common

Configuring Your Linux Kernel

The kernel config is what determines which parts of the kernel are to be enabled when the kernel is built. In OS distros this config is usually placed in /boot/config-kversion. You will need to be sure that the following kernel config options are enabled for your kernel in order for the sleepgraph & bootgraph tools to work. If they're not, you will need to build a custom kernel and install it yourself.

Required: the tool uses the debug output from the PM subsystem to capture device timing.

• CONFIG_PM=y
• CONFIG_PM_DEBUG=y
• CONFIG_PM_SLEEP_DEBUG=y
• CONFIG_FTRACE=y
• CONFIG_FUNCTION_TRACER=y
• CONFIG_FUNCTION_GRAPH_TRACER=y
• CONFIG_KPROBES=y
• CONFIG_KPROBES_ON_FTRACE=y
• CONFIGURING KERNEL COMMAND LINE OPTIONS (V3.15 OR OLDER)

When the kernel is loaded, it pulls in a set of command line paramaters which allow for runtime configuration of the kernel: much like a user mode program. The parameters are stored in the boot loader config and must be configured using whatever boot loader your system has. The following kernel parameters are required for sleepgraph & bootgraph: initcall_debug and log_buf_len. initcall_debug is required so that the tool can know when devices are being initialized on boot, suspend, and resume. It's also a good idea to increase the size of the kernel log buffer because we don't want it to overflow.

For ubuntu/fedora: you can add these parameters at boot time in the grub menu by editting the /boot/grub/grub.cfg file, or by adding them to /etc/default/grub. The last method is the best because it will automatically edit the grub.cfg file for newly installed kernels.

/etc/default/grub:
GRUB_CMDLINE_LINUX_DEFAULT="... initcall_debug log_buf_len=16M ..."

For Android: These paramters must be set when you build the kernel. In your android source folder, edit the BoardConfig.mk file for the target build and add the new parameters:

nano device/<vendor>/<platform>/BoardConfig.mk
BOARD_KERNEL_CMDLINE += initcall_debug log_buf_len=16M

then build android and boot/install with live.img

source build/envsetup.sh
lunch <platform>-<build>
make -j8 allimages
dd if=out/target/product/<platform>/live.img of=/dev/sdc

Usage (Basic)

First configure a kernel using the instructions from the previous sections. Then build, install, and boot with it. Open up a terminal window and execute the mode list command:

%> sudo sleepgraph -modes
['freeze', 'mem', 'disk', 'mem-s2idle', 'disk-platform', 'disk-shutdown', 'disk-reboot', 'disk-suspend', 'disk-test_resume']

Now you can execute a test using one of the available power modes, e.g. mem (S3):

%> sudo sleepgraph -m mem -rtcwake 15

or with a config file

%> sudo sleepgraph -config config/suspend.cfg

When the system comes back you'll see the script finishing up and creating the output files in the test subdir. It generates output files in subdirectory: suspend-mmddyy-HHMMSS. The ftrace file can be used to regenerate the html timeline with different options.

View the html in firefox or chrome. It will look like this:

Usage (Dev Mode)

Developer mode adds information on low level source calls to the timeline. The tool sets kprobes on all delay and mutex calls to see which devices are waiting for something and when. It also sets a suite of kprobes on subsystem dependant calls to better fill out the timeline.
 
The tool will also expose kernel threads that don't normally show up in the timeline. This is useful in discovering dependant threads to get a better idea of what each device is waiting for. For instance, the scsi_eh thread, a.k.a. scsi resume error handler, is what each SATA disk device waits for before it can continue resume.
 
The timeline will be much larger if run with dev mode, so it can be useful to set the -mindev option to clip out any device blocks that are too small to see easily. The following command will give a nice dev mode run:
 

%> sudo sleepgraph -m mem -rtcwake 15 -mindev 1 -dev

or with a config file

%> sudo sleepgraph -config config/suspend-dev.cfg

View the html in firefox or chrome. It will look like this:

Usage (Proc Mode)

Proc mode adds user process info to the timeline. This is done in a manner similar to the bootchart utility, which graphs init processes and their execution as the system boots. This tool option does the same thing but for the period before and after suspend/resume.

In order to see any process info, there needs to be some delay before or after resume since processes are frozen in suspend_prepare and thawed in resume_complete. The predelay and postdelay args allow you to do this. It can also be useful to run in x2 mode with an x2 delay, this way you can see process activity before and after resume, and in between two successive suspend/resumes.

The command is run like this:

%> sudo sleepgraph -m mem -rtcwake 15 -x2 -x2delay 1000 -predelay 1000 -postdelay 1000 -proc

or with a config file

%> sudo sleepgraph -config config/suspend-proc.cfg

View the html in firefox or chrome. It will look like this:

Basic Commands

Test Whether the Tool Can Execute (-Status)

The sleepgraph tool has several basic requirements which have to be met before it can do its job. For instance, when testing on linux you need root permission and the sysfs filesystem mounted. You also need ftrace to be configured properly and available in sysfs. So there's alot to verify, and the tool can do it for you. The status command will go through all the command line arguments and test whether or not you can run that particular command on the current platform. This can be helpful to help diagnose errors. For example here is the output of a command that the system supports:

%> sudo sleepgraph -status -m mem

Checking this system (ivybridge)...
    have root access: YES
    is sysfs mounted: YES
    is "mem" a valid power mode: YES
    is ftrace supported: YES
    are kprobes supported: YES
    timeline data source: FTRACE (all trace events found)
    is rtcwake supported: YES

This is the output of a command with a missing requirement:

%> sudo sleepgraph -status -m standby

Checking this system (ivybridge)...
    have root access: YES
    is sysfs mounted: YES
    is "standby" a valid power mode: NO
    is ftrace supported: YES
    are kprobes supported: YES
    timeline data source: FTRACE (all trace events found)
    is rtcwake supported: YES

View Supported Low-Power Modes (-Modes)

The tool was designed with S3 suspend/resume as its primary target, but it can run any power mode that the system allows you to enter via /sys/power/state. Nearly all systems support S3: "mem", and also hibernate: "disk". But there are also modes like "standby" and "freeze". Running this command lets you know what's available.

%> sleepgraph -modes
['freeze', 'mem', 'disk', 'mem-s2idle', 'disk-platform', 'disk-shutdown', 'disk-reboot', 'disk-suspend', 'disk-test_resume']

View Firmware Performance Data Table (-FPDT)

The ACPI subsystem in the kernel provides access to several tables populated with firmware data. There's one in particular called the Firmware Performance Data Table (FPDT) that the tool now makes use of. This table provides nanosecond level timing data on the last run suspend and resume initiated on the system. The tool first provides a new argument called -fpdt which causes the tool to read out the current table contents. This can be used to test if this feature is supported on your platform.

%> sudo sleepgraph -fpdt

Firmware Performance Data Table (FPDT)
                  Signature : FPDT
               Table Length : 68
                   Revision : 1
                   Checksum : 0x84
                     OEM ID : INTEL
               OEM Table ID : TIANO   
               OEM Revision : 1
                 Creator ID : MSFT
           Creator Revision : 0x1000013

Firmware Basic Boot Performance Record (FBPT)
                  Reset END : 8836123 ns
  OS Loader LoadImage Start : 0 ns
 OS Loader StartImage Start : 10796773297 ns
     ExitBootServices Entry : 0 ns
      ExitBootServices Exit : 0 ns

S3 Performance Table Record (S3PT)
    Basic S3 Resume Performance Record
               Resume Count : 0
                 FullResume : 0 ns
              AverageResume : 0 ns
    Basic S3 Suspend Performance Record
               SuspendStart : 0 ns
                 SuspendEnd : 0 ns
                SuspendTime : 0 ns

The tool also makes use of this data during a test run and adds it into the timeline. If the FPDT data is available and valid, a new section will appear in the timeline named BIOS; along with two entries: firmware-suspend and firmware-resume. If the fpdt data isn't there then the timeline just displays the kernel data. NOTE: this does not yet function on android.

Recreate the HTML Output From a Previous Run's Log Data (-FTRACE)

The primary input to the tool is the ftrace output recorded during the suspend/resume. Ftrace logs that were generated by this tool have a few additional lines at the top & bottom which record basic test information about what, where, and when the test was run. Logs generated by this tool can be used to re-create exact copies of the html outputs. You just need to run the tool with the path of the ftrace log and the same arguments as the test run (-dev and -proc for instance).

%> sleepgraph -ftrace ivybridge_mem_ftrace.txt (-dev -f -proc)

or with a config

%> sleepgraph -ftrace ivybridge_mem_ftrace.txt -config myconfig.cfg

Tool Q&A

What is Sleepgraph?

The sleepgraph tool is a python script which gathers performance data from a system suspend and converts it into a device timeline and an optional callgraph. It is used to assist linux developers in optimizing and debuging their kernel's suspend/resume execution path.

How Can I Tell What Features and Arguments are Available?

The help text can be seen with sleepgraph -h, and there is a man page installed.

SleepGraph v5.5
Usage: sudo sleepgraph <options> <commands>

Description:
  This tool is designed to assist kernel and OS developers in optimizing
  their linux stack's suspend/resume time. Using a kernel image built
  with a few extra options enabled, the tool will execute a suspend and
  capture dmesg and ftrace data until resume is complete. This data is
  transformed into a device timeline and an optional callgraph to give
  a detailed view of which devices/subsystems are taking the most
  time in suspend/resume.

  If no specific command is given, the default behavior is to initiate
  a suspend/resume and capture the dmesg/ftrace output as an html timeline.

  Generates output files in subdirectory: suspend-yymmdd-HHMMSS

   HTML output:                    <hostname>_<mode>.html
   raw dmesg output:               <hostname>_<mode>_dmesg.txt
   raw ftrace output:              <hostname>_<mode>_ftrace.txt

Options:
   -h           Print this help text
   -v           Print the current tool version
   -config fn   Pull arguments and config options from file fn
   -verbose     Print extra information during execution and analysis
   -m mode      Mode to initiate for suspend (default: mem)
   -o name      Overrides the output subdirectory name when running a new test
                default: suspend-{date}-{time}
   -rtcwake t   Wakeup t seconds after suspend, set t to "off" to disable (default: 15)
   -addlogs     Add the dmesg and ftrace logs to the html output
   -noturbostat Dont use turbostat in freeze mode (default: disabled)
   -srgap       Add a visible gap in the timeline between sus/res (default: disabled)
   -skiphtml    Run the test and capture the trace logs, but skip the timeline (default: disabled)
   -result fn   Export a results table to a text file for parsing.
  [testprep]
   -sync        Sync the filesystems before starting the test
   -rs on/off   Enable/disable runtime suspend for all devices, restore all after test
   -display m   Change the display mode to m for the test (on/off/standby/suspend)
  [advanced]
   -gzip        Gzip the trace and dmesg logs to save space
   -cmd {s}     Run the timeline over a custom command, e.g. "sync -d"
   -proc        Add usermode process info into the timeline (default: disabled)
   -dev         Add kernel function calls and threads to the timeline (default: disabled)
   -x2          Run two suspend/resumes back to back (default: disabled)
   -x2delay t   Include t ms delay between multiple test runs (default: 0 ms)
   -predelay t  Include t ms delay before 1st suspend (default: 0 ms)
   -postdelay t Include t ms delay after last resume (default: 0 ms)
   -mindev ms   Discard all device blocks shorter than ms milliseconds (e.g. 0.001 for us)
   -multi n d   Execute <n> consecutive tests at <d> seconds intervals. The outputs will
                be created in a new subdirectory with a summary page.
  [debug]
   -f           Use ftrace to create device callgraphs (default: disabled)
   -ftop        Use ftrace on the top level call: "suspend_devices_and_enter" (default: disabled)
   -maxdepth N  limit the callgraph data to N call levels (default: 0=all)
   -expandcg    pre-expand the callgraph data in the html output (default: disabled)
   -fadd file   Add functions to be graphed in the timeline from a list in a text file
   -filter "d1,d2,..." Filter out all but this comma-delimited list of device names
   -mincg  ms   Discard all callgraphs shorter than ms milliseconds (e.g. 0.001 for us)
   -cgphase P   Only show callgraph data for phase P (e.g. suspend_late)
   -cgtest N    Only show callgraph data for test N (e.g. 0 or 1 in an x2 run)
   -timeprec N  Number of significant digits in timestamps (0:S, [3:ms], 6:us)
   -cgfilter S  Filter the callgraph output in the timeline
   -cgskip file Callgraph functions to skip, off to disable (default: cgskip.txt)
   -bufsize N   Set trace buffer size to N kilo-bytes (default: all of free memory)
   -devdump     Print out all the raw device data for each phase
   -cgdump      Print out all the raw callgraph data
Other commands:
   -modes       List available suspend modes
   -status      Test to see if the system is enabled to run this tool
   -fpdt        Print out the contents of the ACPI Firmware Performance Data Table
   -battery     Print out battery info (if available)
   -wifi        Print out wifi connection info (if wireless-tools and device exists)
   -x<mode>     Test xset by toggling the given mode (on/off/standby/suspend)
   -sysinfo     Print out system info extracted from BIOS
   -devinfo     Print out the pm settings of all devices which support runtime suspend
   -flist       Print the list of functions currently being captured in ftrace
   -flistall    Print all functions capable of being captured in ftrace
   -summary dir Create a summary of tests in this dir [-genhtml builds missing html]
  [redo]
   -ftrace ftracefile  Create HTML output using ftrace input (used with -dmesg)
   -dmesg dmesgfile    Create HTML output using dmesg (used with -ftrace)

How Does It Initiate the Suspend/Resume?

The tool interfaces with the kernel entirely using the /sys filesystem. The /sys/power/(state, mem_sleep, and disk) files can be read to determine what low power modes the kernel supports, and can be written to initiate those modes.

root$ cat /sys/power/state
   standby freeze mem disk
root$ cat /sys/power/mem_sleep 
   s2idle [deep]
root$ cat /sys/power/disk 
   [platform] shutdown reboot suspend test_resume 

The above outputs are converted into the following modes that sleepgraph supports:

root$ sleepgraph -modes
['freeze', 'mem', 'disk', 'mem-s2idle', 'disk-platform', 'disk-shutdown', 'disk-reboot', 'disk-suspend', 'disk-test_resume']

When you pass the above strings to "sleepgraph -m <mode>", the tool performs the following operations to enter the requested mode:

freeze

• echo freeze > /sys/power/state

mem

• echo deep > /sys/power/mem_sleep
• echo mem > /sys/power/state

mem-s2idle

• echo s2idle > /sys/power/mem_sleep
• echo mem > /sys/power/state

disk

• echo disk > /sys/power/state

disk-platform

• echo platform > /sys/power/disk
• echo disk > /sys/power/state

disk-shutdown

• echo shutdown > /sys/power/disk
• echo disk > /sys/power/state

disk-reboot

• echo reboot > /sys/power/disk
• echo disk > /sys/power/state

disk-platform

• echo platform > /sys/power/disk
• echo disk > /sys/power/state

disk-test_resume

• echo test_resume > /sys/power/disk
• echo disk > /sys/power/state

There are four ACPI power states that linux supports (not all of which may be supported on your system).

• standby: S1 (Power-On Suspend) - clock continues to run (delay shows in the timeline)
• freeze: S2idle (Low-Power Idle) - depends on BIOS settings, could be S3 or S2idle
• mem: S3 (suspend to RAM) - clock stops, the state is stored in RAM
• disk: S4 (suspend to disk) - clock stops, memory is flushed to disk, reboots with disk image

By default the system wakes up after 15 seconds, but you can use -rtcwake to change this number, or give it -rtcwake off to disable wakeups. In the "-rtcwake off" case the sytem stays suspended until a human interface device is touched (keypress, mouse, etc). 

What Data Does It Gather During Suspend/Resume?

The ftrace log is the primary source of information. The kernel provides tracepoint data on all pm device callbacks, and the tool adds kprobes on other functions of interest in the timeline. When running with callgraph enabled it will also include ftrace callgraph data. The tool also grabs the dmesg log as it will contain any error messages and can help in debug.

Dev mode: The tool has a large suite of kprobes which it monitors in dev mode to add function info to the timeline. It primarily focuses on delay functions such as msleeps and schedule_timeouts and also any mutex_lock_slowpaths which occur when a device is waiting a long time for some other thread. The user can also define custom kprobes in the config file which will also be added to the ftrace log.

Proc mode: The tool gathers process data by polling the /proc/pid files in the proc filesystem. Every 5 ms or so it loops through them to determine which have executed any jiffies since the last poll, and uses that data to create the cpu usage graph and process blocks in the timeline. This data is actually fed into the ftrace subsystem via trace markers, since we want the proc data to have the same timestamps as the ftrace data. It will also be contained in the ftrace log.

How Does It Output the Data for Me to See?

The output of the tool is a single html file which includes HTML, CSS, and Javascript. It can be viewed in any linux browser without any js libraries or external dependencies. The device timeline is the primary feature of the page which shows all the device execution blocks. It uses javascript/CSS to allow zooming in and out and automatically changing the scale. On first load the timeline shows up fully expanded, and there are three buttons which can be used to zoom in and out, and a scrollbar to slide back and forth

• zoom-in (+ hotkey): decrease the time window and increase the timescale precision (down to individual milliseconds)
• zoom-out (- hotkey): increase the time window and decrease the timescale precision (up to several seconds)
• zoom-1:1(* hotkey): zoom back to the default 100% view
• slider: when in higher zoom levels the slider lets you move back and forth on the timeline
• grab & drag: the timeline can be grabbed and dragged left/right with the mouse

The timeline itself is also interactive. If you hover the pointer over a device it will highlight, and after a half second will display the full name of the device and the total time spent in its pm callback. You can also click the devices to get to a device detail view, which adds another section underneath the timeline. This view gives the full title of the device, it's total time spent, and also a hierarchy of all the devices parents, siblings, and children. If you have ftrace data enabled, clicking the device will also filter the callgraph data to show you just the device you clicked, its siblings, and children. This can be very helpful if you're optimizing a subsystem and need to understand the interaction between its devices.

NOTE: You may potentially run into some sluggishness when you view the output of an ftrace enabled test. This is because all the ftrace data needed to make callgraphs for dozens of devices can take up a lot of space, typically around 30MB. If your html file is over 100MB it may crash the browser, so you should rerun the test with the -filter option enabled to focus only on the devices you care about.

 
Project: pm-graph