From 147a7d9d25ca2551aab15071cb1f048ecd9b7953 Mon Sep 17 00:00:00 2001 From: "Rafael J. Wysocki" Date: Tue, 20 Feb 2018 12:10:32 +0100 Subject: [PATCH 01/56] ACPI / PM: Do not reconfigure GPEs for suspend-to-idle It is reported that commit 235d81a630ca (ACPI / PM: Clean up device wakeup enable/disable code) broke wakeup from suspend-to-idle on some platforms. That is due to the acpi_enable_all_wakeup_gpes() in acpi_s2idle_prepare() which needs acpi_enable_wakeup_devices() to be called before it as the latter sets up the GPE masks used by the former and commit 235d81a630ca removed acpi_enable_wakeup_devices() invocation from the suspend-to-idle path. However, acpi_enable_wakeup_devices() does more than just setting the GPE masks and the remaining part of it is not necessary for suspend-to-idle. Moreover, non-wakeup GPEs are disabled on suspend- to-idle entry to avoid spurious wakeups, but that should not be strictly necessary any more after commit 33e4f80ee69b (ACPI / PM: Ignore spurious SCI wakeups from suspend-to-idle) which prevents spurious GPE wakeups from resuming the system. The only consequence of leaving non-wakeup GPEs enabled may be more interrupt-related activity while suspended, which is not ideal (more energy is used if that happens), but it is not critical too. For this reason, drop the GPE reconfiguration from the suspend-to-idle path entirely. This change also allows Dells XPS13 9360 blacklisted by commit 71630b7a832f (ACPI / PM: Blacklist Low Power S0 Idle _DSM for Dell XPS13 9360) to use the power button for waking up from suspend- to-idle and it helps at least one other older Dell system (the wakeup button GPE on that one is not listed in _PRW for any devices, so it is not regarded as a wakeup one and gets disabled on suspend-to-idle entry today). Fixes: 235d81a630ca (ACPI / PM: Clean up device wakeup enable/disable code) Reported-by: Du Wenkai Tested-by: Du Wenkai Signed-off-by: Rafael J. Wysocki --- drivers/acpi/sleep.c | 11 +---------- 1 file changed, 1 insertion(+), 10 deletions(-) diff --git a/drivers/acpi/sleep.c b/drivers/acpi/sleep.c index 46cde0912762..c53119740a3c 100644 --- a/drivers/acpi/sleep.c +++ b/drivers/acpi/sleep.c @@ -953,15 +953,8 @@ static int acpi_s2idle_prepare(void) if (lps0_device_handle) { acpi_sleep_run_lps0_dsm(ACPI_LPS0_SCREEN_OFF); acpi_sleep_run_lps0_dsm(ACPI_LPS0_ENTRY); - } else { - /* - * The configuration of GPEs is changed here to avoid spurious - * wakeups, but that should not be necessary if this is a - * "low-power S0" platform and the low-power S0 _DSM is present. - */ - acpi_enable_all_wakeup_gpes(); - acpi_os_wait_events_complete(); } + if (acpi_sci_irq_valid()) enable_irq_wake(acpi_sci_irq); @@ -1007,8 +1000,6 @@ static void acpi_s2idle_restore(void) if (lps0_device_handle) { acpi_sleep_run_lps0_dsm(ACPI_LPS0_EXIT); acpi_sleep_run_lps0_dsm(ACPI_LPS0_SCREEN_ON); - } else { - acpi_enable_all_runtime_gpes(); } } From a6fbdbb2b852c2208156f21747b270931fd0d427 Mon Sep 17 00:00:00 2001 From: Todd E Brandt Date: Tue, 30 Jan 2018 00:17:18 -0800 Subject: [PATCH 02/56] pm-graph: config files and installer - name change: analyze_boot.py to bootgraph.py - name change: analyze_suspend.py to sleepgraph.py - added config files for easier sleepgraph usage - added example.cfg which describes all config options - added cgskip.txt definition for slimmer callgraphs Signed-off-by: Todd Brandt Signed-off-by: Rafael J. Wysocki --- tools/power/pm-graph/Makefile | 29 ++- .../{analyze_boot.py => bootgraph.py} | 0 tools/power/pm-graph/config/cgskip.txt | 65 ++++++ .../config/custom-timeline-functions.cfg | 205 ++++++++++++++++++ tools/power/pm-graph/config/example.cfg | 133 ++++++++++++ .../pm-graph/config/freeze-callgraph.cfg | 94 ++++++++ tools/power/pm-graph/config/freeze-dev.cfg | 93 ++++++++ tools/power/pm-graph/config/freeze.cfg | 93 ++++++++ .../pm-graph/config/standby-callgraph.cfg | 94 ++++++++ tools/power/pm-graph/config/standby-dev.cfg | 93 ++++++++ tools/power/pm-graph/config/standby.cfg | 93 ++++++++ .../pm-graph/config/suspend-callgraph.cfg | 98 +++++++++ tools/power/pm-graph/config/suspend-dev.cfg | 93 ++++++++ .../power/pm-graph/config/suspend-x2-proc.cfg | 93 ++++++++ tools/power/pm-graph/config/suspend.cfg | 93 ++++++++ .../{analyze_suspend.py => sleepgraph.py} | 0 16 files changed, 1362 insertions(+), 7 deletions(-) rename tools/power/pm-graph/{analyze_boot.py => bootgraph.py} (100%) create mode 100644 tools/power/pm-graph/config/cgskip.txt create mode 100644 tools/power/pm-graph/config/custom-timeline-functions.cfg create mode 100644 tools/power/pm-graph/config/example.cfg create mode 100644 tools/power/pm-graph/config/freeze-callgraph.cfg create mode 100644 tools/power/pm-graph/config/freeze-dev.cfg create mode 100644 tools/power/pm-graph/config/freeze.cfg create mode 100644 tools/power/pm-graph/config/standby-callgraph.cfg create mode 100644 tools/power/pm-graph/config/standby-dev.cfg create mode 100644 tools/power/pm-graph/config/standby.cfg create mode 100644 tools/power/pm-graph/config/suspend-callgraph.cfg create mode 100644 tools/power/pm-graph/config/suspend-dev.cfg create mode 100644 tools/power/pm-graph/config/suspend-x2-proc.cfg create mode 100644 tools/power/pm-graph/config/suspend.cfg rename tools/power/pm-graph/{analyze_suspend.py => sleepgraph.py} (100%) diff --git a/tools/power/pm-graph/Makefile b/tools/power/pm-graph/Makefile index 4e1e999e7b05..c1899cd72c80 100644 --- a/tools/power/pm-graph/Makefile +++ b/tools/power/pm-graph/Makefile @@ -7,11 +7,24 @@ all: install : uninstall install -d $(DESTDIR)$(PREFIX)/lib/pm-graph - install analyze_suspend.py $(DESTDIR)$(PREFIX)/lib/pm-graph - install analyze_boot.py $(DESTDIR)$(PREFIX)/lib/pm-graph + install sleepgraph.py $(DESTDIR)$(PREFIX)/lib/pm-graph + install bootgraph.py $(DESTDIR)$(PREFIX)/lib/pm-graph + install -d $(DESTDIR)$(PREFIX)/lib/pm-graph/config + install -m 644 config/cgskip.txt $(DESTDIR)$(PREFIX)/lib/pm-graph/config + install -m 644 config/freeze-callgraph.cfg $(DESTDIR)$(PREFIX)/lib/pm-graph/config + install -m 644 config/freeze.cfg $(DESTDIR)$(PREFIX)/lib/pm-graph/config + install -m 644 config/freeze-dev.cfg $(DESTDIR)$(PREFIX)/lib/pm-graph/config + install -m 644 config/standby-callgraph.cfg $(DESTDIR)$(PREFIX)/lib/pm-graph/config + install -m 644 config/standby.cfg $(DESTDIR)$(PREFIX)/lib/pm-graph/config + install -m 644 config/standby-dev.cfg $(DESTDIR)$(PREFIX)/lib/pm-graph/config + install -m 644 config/suspend-callgraph.cfg $(DESTDIR)$(PREFIX)/lib/pm-graph/config + install -m 644 config/suspend.cfg $(DESTDIR)$(PREFIX)/lib/pm-graph/config + install -m 644 config/suspend-dev.cfg $(DESTDIR)$(PREFIX)/lib/pm-graph/config + install -m 644 config/suspend-x2-proc.cfg $(DESTDIR)$(PREFIX)/lib/pm-graph/config - ln -s $(DESTDIR)$(PREFIX)/lib/pm-graph/analyze_boot.py $(DESTDIR)$(PREFIX)/bin/bootgraph - ln -s $(DESTDIR)$(PREFIX)/lib/pm-graph/analyze_suspend.py $(DESTDIR)$(PREFIX)/bin/sleepgraph + install -d $(DESTDIR)$(PREFIX)/bin + ln -s $(DESTDIR)$(PREFIX)/lib/pm-graph/bootgraph.py $(DESTDIR)$(PREFIX)/bin/bootgraph + ln -s $(DESTDIR)$(PREFIX)/lib/pm-graph/sleepgraph.py $(DESTDIR)$(PREFIX)/bin/sleepgraph install -d $(DESTDIR)$(PREFIX)/share/man/man8 install bootgraph.8 $(DESTDIR)$(PREFIX)/share/man/man8 @@ -24,9 +37,11 @@ uninstall : rm -f $(DESTDIR)$(PREFIX)/bin/bootgraph rm -f $(DESTDIR)$(PREFIX)/bin/sleepgraph - rm -f $(DESTDIR)$(PREFIX)/lib/pm-graph/analyze_boot.py - rm -f $(DESTDIR)$(PREFIX)/lib/pm-graph/analyze_suspend.py - rm -f $(DESTDIR)$(PREFIX)/lib/pm-graph/*.pyc + rm -f $(DESTDIR)$(PREFIX)/lib/pm-graph/config/* + if [ -d $(DESTDIR)$(PREFIX)/lib/pm-graph/config ] ; then \ + rmdir $(DESTDIR)$(PREFIX)/lib/pm-graph/config; \ + fi; + rm -f $(DESTDIR)$(PREFIX)/lib/pm-graph/* if [ -d $(DESTDIR)$(PREFIX)/lib/pm-graph ] ; then \ rmdir $(DESTDIR)$(PREFIX)/lib/pm-graph; \ fi; diff --git a/tools/power/pm-graph/analyze_boot.py b/tools/power/pm-graph/bootgraph.py similarity index 100% rename from tools/power/pm-graph/analyze_boot.py rename to tools/power/pm-graph/bootgraph.py diff --git a/tools/power/pm-graph/config/cgskip.txt b/tools/power/pm-graph/config/cgskip.txt new file mode 100644 index 000000000000..e48d588fbfb4 --- /dev/null +++ b/tools/power/pm-graph/config/cgskip.txt @@ -0,0 +1,65 @@ +# ----------------------------------------------- +# CallGraph function skip list +# +# This file contains a list of functions which are +# meant to be skipped in the callgraph trace. It reduces +# the callgraph html file size by treating these functions +# as leaves with no child calls. It can be editted by +# adding or removing function symbol names. +# +# The sleepgraph tool automatically pulls this file in when +# it is found in the config folder. It can be ignored if +# the tool is called with "-cgskip off". +# ----------------------------------------------- + +# low level scheduling and timing +up +down_timeout +mutex_lock +down_read +complete_all +schedule_timeout +wake_up_process +msleep +__udelay +ktime_get + +# console calls +printk +dev_printk +console_unlock + +# memory handling +__kmalloc +__kmalloc_track_caller +kmem_cache_alloc +kmem_cache_alloc_trace +kmem_cache_free +kstrdup +kstrdup_const +kmalloc_slab +new_slab +__slab_alloc +__slab_free +raw_pci_read +pci_read +alloc_pages_current + +# debugfs and sysfs setup +debugfs_remove_recursive +debugfs_create_dir +debugfs_create_files +debugfs_create_dir +debugfs_get_inode +sysfs_add_file_mode_ns +sysfs_add_file +sysfs_create_dir_ns +sysfs_create_link +sysfs_create_group +sysfs_create_groups +sysfs_create_bin_file +dpm_sysfs_add +sysfs_create_file_ns +sysfs_merge_group +sysfs_add_link_to_group +sysfs_create_link_sd diff --git a/tools/power/pm-graph/config/custom-timeline-functions.cfg b/tools/power/pm-graph/config/custom-timeline-functions.cfg new file mode 100644 index 000000000000..4f80ad7d7275 --- /dev/null +++ b/tools/power/pm-graph/config/custom-timeline-functions.cfg @@ -0,0 +1,205 @@ +# +# This is the configuration file for sleepgraph. It contains +# all the tool arguments so that they don't have to be given on the +# command line. It also includes advanced settings for functions +# and kprobes. It is run like this +# +# sudo ./sleepgraph.py -config thisfile.txt +# + +[Settings] + +# Verbosity +# print verbose messages (default: false) +verbose: false + +# Suspend Mode +# e.g. standby, mem, freeze, disk (default: mem) +mode: mem + +# Automatic Wakeup +# Use rtcwake to autoresume after X seconds, or off to disable (default: 15) +rtcwake: 15 + +# Add Logs +# add the dmesg and ftrace log to the html output (default: false) +addlogs: false + +# Display function calls +# graph source functions in the timeline (default: false) +dev: true + +# Callgraph +# gather detailed ftrace callgraph data on all timeline events (default: false) +callgraph: false + +# Back to Back Suspend/Resume +# Run two suspend/resumes back to back (default: false) +x2: false + +# Back to Back Suspend Delay +# Time delay between the two test runs in ms (default: 0 ms) +x2delay: 0 + +# Minimum Device Length +# graph only devices longer than min in the timeline (default: 0.001 ms) +mindev: 1 + +# Minimum Callgraph Length +# provide callgraph data for blocks longer than min (default: 0.001 ms) +mincg: 1 + +# Suspend/Resume Gap +# insert a small visible gap between suspend and resume on the timeline (default: false) +srgap: false + +# Output Directory Format +# output folder for html, ftrace, and dmesg. Use {date} and {time} for current values +output-dir: suspend-{hostname}-{date}-{time}-custom + +# Override default timeline entries +# Do not use the internal default functions for timeline entries (default: false) +# Set this to true if you intend to only use the ones defined in this config +override-timeline-functions: true + +# Override default dev timeline entries +# Do not use the internal default functions for dev timeline entries (default: false) +# Set this to true if you intend to only use the ones defined in this config +override-dev-timeline-functions: true + +[timeline_functions_x86_64] +# +# Function calls to display in the timeline alongside device callbacks. +# The tool has an internal set of these functions which should cover the +# whole of kernel execution, but you can append or override here. +# +# This is a list of kprobes which use both symbol data and function arg data. +# The function calls are displayed on the timeline alongside the device blocks. +# The args are pulled directly from the stack using this architecture's registers +# and stack formatting. Three pieces of info are required. The function name, +# a format string, and an argument list +# +# Entry format: +# +# function: format{fn_arg1}_{fn_arg2} fn_arg1 fn_arg2 ... [color=purple] +# +# Required Arguments: +# +# function: The symbol name for the function you want probed, this is the +# minimum required for an entry, it will show up as the function +# name with no arguments. +# +# example: _cpu_up: +# +# Optional Arguments: +# +# format: The format to display the data on the timeline in. Use braces to +# enclose the arg names. +# +# example: CPU_ON[{cpu}] +# +# color: The color of the entry block in the timeline. The default color is +# transparent, so the entry shares the phase color. The color is an +# html color string, either a word, or an RGB. +# +# example: [color=#CC00CC] +# +# arglist: A list of arguments from registers/stack addresses. See URL: +# https://www.kernel.org/doc/Documentation/trace/kprobetrace.txt +# +# example: cpu=%di:s32 +# +# Example: Display cpu resume in the timeline +# +# _cpu_up: CPU_ON[{cpu}] cpu=%di:s32 [color=orange] +# +_cpu_down: CPU_OFF[{cpu}] cpu=%di:s32 +_cpu_up: CPU_ON[{cpu}] cpu=%di:s32 +sys_sync: +pm_prepare_console: +pm_notifier_call_chain: +freeze_processes: +freeze_kernel_threads: +pm_restrict_gfp_mask: +acpi_suspend_begin: +suspend_console: +acpi_pm_prepare: +syscore_suspend: +arch_enable_nonboot_cpus_end: +syscore_resume: +acpi_pm_finish: +resume_console: +acpi_pm_end: +pm_restore_gfp_mask: +thaw_processes: +pm_restore_console: + +[dev_timeline_functions_x86_64] +# +# Dev mode function calls to display inside timeline entries +# +# This is a list of kprobes which use both symbol data and function arg data. +# The function calls are displayed on the timeline alongside the device blocks. +# The args are pulled directly from the stack using this architecture's registers +# and stack formatting. Three pieces of info are required. The function name, +# a format string, and an argument list +# +# Entry format: +# +# function: format{fn_arg1}_{fn_arg2} fn_arg1 fn_arg2 ... [color=purple] +# +# Required Arguments: +# +# function: The symbol name for the function you want probed, this is the +# minimum required for an entry, it will show up as the function +# name with no arguments. +# +# example: ata_eh_recover: +# +# Optional Arguments: +# +# format: The format to display the data on the timeline in. Use braces to +# enclose the arg names. +# +# example: ata{port}_port_reset +# +# color: The color of the entry block in the timeline. The default color is +# transparent, so the entry shares the phase color. The color is an +# html color string, either a word, or an RGB. +# +# example: [color=#CC00CC] +# +# arglist: A list of arguments from registers/stack addresses. See URL: +# https://www.kernel.org/doc/Documentation/trace/kprobetrace.txt +# +# example: port=+36(%di):s32 +# +# Example: Display ATA port reset as ataN_port_reset in the timeline +# +# ata_eh_recover: ata{port}_port_reset port=+36(%di):s32 +# +msleep: msleep time=%di:s32 +schedule_timeout_uninterruptible: schedule_timeout_uninterruptible timeout=%di:s32 +schedule_timeout: schedule_timeout timeout=%di:s32 +usleep_range: usleep_range min=%di:s32 max=%si:s32 +__const_udelay: udelay loops=%di:s32 +__mutex_lock_slowpath: mutex_lock_slowpath +ata_eh_recover: ata_eh_recover port=+36(%di):s32 +acpi_os_stall: +acpi_resume_power_resources: +acpi_ps_parse_aml: +ext4_sync_fs: +i915_gem_resume: +i915_restore_state: +intel_opregion_setup: +g4x_pre_enable_dp: +vlv_pre_enable_dp: +chv_pre_enable_dp: +g4x_enable_dp: +vlv_enable_dp: +intel_hpd_init: +intel_opregion_register: +intel_dp_detect: +intel_hdmi_detect: +intel_opregion_init: +intel_fbdev_set_suspend: diff --git a/tools/power/pm-graph/config/example.cfg b/tools/power/pm-graph/config/example.cfg new file mode 100644 index 000000000000..05b2efb9bb54 --- /dev/null +++ b/tools/power/pm-graph/config/example.cfg @@ -0,0 +1,133 @@ +# +# Generic S3 (Suspend to Mem) test +# +# This is the configuration file for sleepgraph. It contains +# all the tool arguments so that they don't have to be given on the +# command line. It also includes advanced settings for functions +# and kprobes. It is run like this +# +# sudo ./sleepgraph.py -config config/example.cfg +# + +[Settings] + +# ---- General Options ---- + +# Verbosity +# print verbose messages (default: false) +verbose: false + +# Suspend Mode +# e.g. standby, mem, freeze, disk (default: mem) +mode: mem + +# Output Directory Format +# output folder for html, ftrace, and dmesg. Use {date} and {time} for current values +output-dir: suspend-{hostname}-{date}-{time} + +# Automatic Wakeup +# Use rtcwake to autoresume after X seconds, or off to disable (default: 15) +rtcwake: 15 + +# Add Logs +# add the dmesg and ftrace log to the html output (default: false) +addlogs: true + +# Suspend/Resume Gap +# insert a small visible gap between suspend and resume on the timeline (default: false) +srgap: false + +# Skip HTML generation +# Only capture the logs, don't generate the html timeline (default: false) +skiphtml: false + +# Sync filesystem before suspend +# run sync before the test, minimizes sys_sync call time (default: false) +sync: true + +# Runtime suspend enable/disable +# Enable/disable runtime suspend for all devices, restore all after test (default: no-action) +# rs: disable + +# Turn display on/off for test +# Switch the display on/off for the test using xset (default: no-action) +# display: on + +# Print results to text file +# Print the status of the test run in the given file (default: no-action) +result: result.txt + +# Gzip the log files to save space +# Gzip the generated log files, and read gzipped log files (default: false) +gzip: true + +# ---- Advanced Options ---- + +# Command to execute in lieu of suspend (default: "") +# command: echo mem > /sys/power/state + +# Display user processes +# graph user processes and cpu usage in the timeline (default: false) +proc: false + +# Display function calls +# graph source functions in the timeline (default: false) +dev: false + +# Multiple test runs +# Run N tests D seconds apart, generates separate outputs with a summary (default: false) +# multi: 3 5 + +# Back to Back Suspend/Resume +# Run two suspend/resumes back to back and display in the same timeline (default: false) +x2: false + +# Back to Back Suspend Delay +# Time delay between the two test runs in ms (default: 0 ms) +x2delay: 0 + +# Pre Suspend Delay +# Include an N ms delay before (1st) suspend (default: 0 ms) +predelay: 0 + +# Post Resume Delay +# Include an N ms delay after (last) resume (default: 0 ms) +postdelay: 0 + +# Minimum Device Length +# graph only devices longer than min in the timeline (default: 0.001 ms) +mindev: 0.001 + +# ---- Debug Options ---- + +# Callgraph +# gather detailed ftrace callgraph data on all timeline events (default: false) +callgraph: false + +# Callgraph phase filter +# Only enable callgraphs for one phase, i.e. resume_noirq (default: all) +cgphase: suspend + +# Callgraph x2 test filter +# Only enable callgraphs test 0 or 1 when using -x2 (default: 1) +cgtest: 0 + +# Expand Callgraph +# pre-expand the callgraph data in the html output (default: disabled) +expandcg: false + +# Minimum Callgraph Length +# provide callgraph data for blocks longer than min (default: 0.001 ms) +mincg: 1 + +# Timestamp Precision +# Number of significant digits in timestamps (0:S, [3:ms], 6:us) +timeprec: 6 + +# Device Filter +# show only devices whose name/driver includes one of these strings +# devicefilter: _cpu_up,_cpu_down,i915,usb + +# Add kprobe functions to the timeline +# Add functions to the timeline from a text file (default: no-action) +# fadd: file.txt diff --git a/tools/power/pm-graph/config/freeze-callgraph.cfg b/tools/power/pm-graph/config/freeze-callgraph.cfg new file mode 100644 index 000000000000..f692821c4828 --- /dev/null +++ b/tools/power/pm-graph/config/freeze-callgraph.cfg @@ -0,0 +1,94 @@ +# +# Full Callgraph for S2 (Freeze) test +# +# This is the configuration file for sleepgraph. It contains +# all the tool arguments so that they don't have to be given on the +# command line. It also includes advanced settings for functions +# and kprobes. It is run like this +# +# sudo ./sleepgraph.py -config config/freeze-callgraph.cfg +# +# NOTE: the output of this test is very large (> 30MB) + +[Settings] + +# ---- General Options ---- + +# Verbosity +# print verbose messages (default: false) +verbose: false + +# Suspend Mode +# e.g. standby, mem, freeze, disk (default: mem) +mode: freeze + +# Output Directory Format +# output folder for html, ftrace, and dmesg. Use {date} and {time} for current values +output-dir: freeze-{hostname}-{date}-{time}-cg + +# Automatic Wakeup +# Use rtcwake to autoresume after X seconds, or off to disable (default: 15) +rtcwake: 15 + +# Add Logs +# add the dmesg and ftrace log to the html output (default: false) +addlogs: false + +# Suspend/Resume Gap +# insert a small visible gap between suspend and resume on the timeline (default: false) +srgap: false + +# ---- Advanced Options ---- + +# Command to execute in lieu of freeze (default: "") +# command: echo freeze > /sys/power/state + +# Display user processes +# graph user processes and cpu usage in the timeline (default: false) +proc: false + +# Display function calls +# graph source functions in the timeline (default: false) +dev: false + +# Back to Back Suspend/Resume +# Run two suspend/resumes back to back (default: false) +x2: false + +# Back to Back Suspend Delay +# Time delay between the two test runs in ms (default: 0 ms) +x2delay: 0 + +# Pre Suspend Delay +# Include an N ms delay before (1st) suspend (default: 0 ms) +predelay: 0 + +# Post Resume Delay +# Include an N ms delay after (last) resume (default: 0 ms) +postdelay: 0 + +# Minimum Device Length +# graph only devices longer than min in the timeline (default: 0.001 ms) +mindev: 1 + +# ---- Debug Options ---- + +# Callgraph +# gather detailed ftrace callgraph data on all timeline events (default: false) +callgraph: true + +# Expand Callgraph +# pre-expand the callgraph data in the html output (default: disabled) +expandcg: false + +# Minimum Callgraph Length +# provide callgraph data for blocks longer than min (default: 0.001 ms) +mincg: 1 + +# Timestamp Precision +# Number of significant digits in timestamps (0:S, [3:ms], 6:us) +timeprec: 6 + +# Device Filter +# show only devs whose name/driver includes one of these strings +# devicefilter: _cpu_up,_cpu_down,i915,usb diff --git a/tools/power/pm-graph/config/freeze-dev.cfg b/tools/power/pm-graph/config/freeze-dev.cfg new file mode 100644 index 000000000000..c4ad5cea3cbf --- /dev/null +++ b/tools/power/pm-graph/config/freeze-dev.cfg @@ -0,0 +1,93 @@ +# +# Dev S2 (Freeze) test - includes src calls / kernel threads +# +# This is the configuration file for sleepgraph. It contains +# all the tool arguments so that they don't have to be given on the +# command line. It also includes advanced settings for functions +# and kprobes. It is run like this +# +# sudo ./sleepgraph.py -config config/freeze-dev.cfg +# + +[Settings] + +# ---- General Options ---- + +# Verbosity +# print verbose messages (default: false) +verbose: false + +# Suspend Mode +# e.g. standby, mem, freeze, disk (default: mem) +mode: freeze + +# Output Directory Format +# output folder for html, ftrace, and dmesg. Use {date} and {time} for current values +output-dir: freeze-{hostname}-{date}-{time}-dev + +# Automatic Wakeup +# Use rtcwake to autoresume after X seconds, or off to disable (default: 15) +rtcwake: 15 + +# Add Logs +# add the dmesg and ftrace log to the html output (default: false) +addlogs: false + +# Suspend/Resume Gap +# insert a small visible gap between suspend and resume on the timeline (default: false) +srgap: false + +# ---- Advanced Options ---- + +# Command to execute in lieu of freeze (default: "") +# command: echo freeze > /sys/power/state + +# Display user processes +# graph user processes and cpu usage in the timeline (default: false) +proc: false + +# Display function calls +# graph source functions in the timeline (default: false) +dev: true + +# Back to Back Suspend/Resume +# Run two suspend/resumes back to back (default: false) +x2: false + +# Back to Back Suspend Delay +# Time delay between the two test runs in ms (default: 0 ms) +x2delay: 0 + +# Pre Suspend Delay +# Include an N ms delay before (1st) suspend (default: 0 ms) +predelay: 0 + +# Post Resume Delay +# Include an N ms delay after (last) resume (default: 0 ms) +postdelay: 0 + +# Minimum Device Length +# graph only devices longer than min in the timeline (default: 0.001 ms) +mindev: 1 + +# ---- Debug Options ---- + +# Callgraph +# gather detailed ftrace callgraph data on all timeline events (default: false) +callgraph: false + +# Expand Callgraph +# pre-expand the callgraph data in the html output (default: disabled) +expandcg: false + +# Minimum Callgraph Length +# provide callgraph data for blocks longer than min (default: 0.001 ms) +mincg: 1 + +# Timestamp Precision +# Number of significant digits in timestamps (0:S, [3:ms], 6:us) +timeprec: 3 + +# Device Filter +# show only devs whose name/driver includes one of these strings +# devicefilter: _cpu_up,_cpu_down,i915,usb diff --git a/tools/power/pm-graph/config/freeze.cfg b/tools/power/pm-graph/config/freeze.cfg new file mode 100644 index 000000000000..0b70e0b74527 --- /dev/null +++ b/tools/power/pm-graph/config/freeze.cfg @@ -0,0 +1,93 @@ +# +# Generic S2 (Freeze) test +# +# This is the configuration file for sleepgraph. It contains +# all the tool arguments so that they don't have to be given on the +# command line. It also includes advanced settings for functions +# and kprobes. It is run like this +# +# sudo ./sleepgraph.py -config config/freeze.cfg +# + +[Settings] + +# ---- General Options ---- + +# Verbosity +# print verbose messages (default: false) +verbose: false + +# Suspend Mode +# e.g. standby, mem, freeze, disk (default: mem) +mode: freeze + +# Output Directory Format +# output folder for html, ftrace, and dmesg. Use {date} and {time} for current values +output-dir: freeze-{hostname}-{date}-{time} + +# Automatic Wakeup +# Use rtcwake to autoresume after X seconds, or off to disable (default: 15) +rtcwake: 15 + +# Add Logs +# add the dmesg and ftrace log to the html output (default: false) +addlogs: false + +# Suspend/Resume Gap +# insert a small visible gap between suspend and resume on the timeline (default: false) +srgap: false + +# ---- Advanced Options ---- + +# Command to execute in lieu of freeze (default: "") +# command: echo freeze > /sys/power/state + +# Display user processes +# graph user processes and cpu usage in the timeline (default: false) +proc: false + +# Display function calls +# graph source functions in the timeline (default: false) +dev: false + +# Back to Back Suspend/Resume +# Run two suspend/resumes back to back (default: false) +x2: false + +# Back to Back Suspend Delay +# Time delay between the two test runs in ms (default: 0 ms) +x2delay: 0 + +# Pre Suspend Delay +# Include an N ms delay before (1st) suspend (default: 0 ms) +predelay: 0 + +# Post Resume Delay +# Include an N ms delay after (last) resume (default: 0 ms) +postdelay: 0 + +# Minimum Device Length +# graph only devices longer than min in the timeline (default: 0.001 ms) +mindev: 0.001 + +# ---- Debug Options ---- + +# Callgraph +# gather detailed ftrace callgraph data on all timeline events (default: false) +callgraph: false + +# Expand Callgraph +# pre-expand the callgraph data in the html output (default: disabled) +expandcg: false + +# Minimum Callgraph Length +# provide callgraph data for blocks longer than min (default: 0.001 ms) +mincg: 1 + +# Timestamp Precision +# Number of significant digits in timestamps (0:S, [3:ms], 6:us) +timeprec: 3 + +# Device Filter +# show only devs whose name/driver includes one of these strings +# devicefilter: _cpu_up,_cpu_down,i915,usb diff --git a/tools/power/pm-graph/config/standby-callgraph.cfg b/tools/power/pm-graph/config/standby-callgraph.cfg new file mode 100644 index 000000000000..f52a6b9d5c32 --- /dev/null +++ b/tools/power/pm-graph/config/standby-callgraph.cfg @@ -0,0 +1,94 @@ +# +# Full Callgraph for S1 (Standby) test +# +# This is the configuration file for sleepgraph. It contains +# all the tool arguments so that they don't have to be given on the +# command line. It also includes advanced settings for functions +# and kprobes. It is run like this +# +# sudo ./sleepgraph.py -config config/standby-callgraph.cfg +# +# NOTE: the output of this test is very large (> 30MB) + +[Settings] + +# ---- General Options ---- + +# Verbosity +# print verbose messages (default: false) +verbose: false + +# Suspend Mode +# e.g. standby, mem, freeze, disk (default: mem) +mode: standby + +# Output Directory Format +# output folder for html, ftrace, and dmesg. Use {date} and {time} for current values +output-dir: standby-{hostname}-{date}-{time}-cg + +# Automatic Wakeup +# Use rtcwake to autoresume after X seconds, or off to disable (default: 15) +rtcwake: 15 + +# Add Logs +# add the dmesg and ftrace log to the html output (default: false) +addlogs: false + +# Suspend/Resume Gap +# insert a small visible gap between suspend and resume on the timeline (default: false) +srgap: false + +# ---- Advanced Options ---- + +# Command to execute in lieu of standby (default: "") +# command: echo standby > /sys/power/state + +# Display user processes +# graph user processes and cpu usage in the timeline (default: false) +proc: false + +# Display function calls +# graph source functions in the timeline (default: false) +dev: false + +# Back to Back Suspend/Resume +# Run two suspend/resumes back to back (default: false) +x2: false + +# Back to Back Suspend Delay +# Time delay between the two test runs in ms (default: 0 ms) +x2delay: 0 + +# Pre Suspend Delay +# Include an N ms delay before (1st) suspend (default: 0 ms) +predelay: 0 + +# Post Resume Delay +# Include an N ms delay after (last) resume (default: 0 ms) +postdelay: 0 + +# Minimum Device Length +# graph only devices longer than min in the timeline (default: 0.001 ms) +mindev: 1 + +# ---- Debug Options ---- + +# Callgraph +# gather detailed ftrace callgraph data on all timeline events (default: false) +callgraph: true + +# Expand Callgraph +# pre-expand the callgraph data in the html output (default: disabled) +expandcg: false + +# Minimum Callgraph Length +# provide callgraph data for blocks longer than min (default: 0.001 ms) +mincg: 1 + +# Timestamp Precision +# Number of significant digits in timestamps (0:S, [3:ms], 6:us) +timeprec: 6 + +# Device Filter +# show only devs whose name/driver includes one of these strings +# devicefilter: _cpu_up,_cpu_down,i915,usb diff --git a/tools/power/pm-graph/config/standby-dev.cfg b/tools/power/pm-graph/config/standby-dev.cfg new file mode 100644 index 000000000000..a5498ece3def --- /dev/null +++ b/tools/power/pm-graph/config/standby-dev.cfg @@ -0,0 +1,93 @@ +# +# Dev S1 (Standby) test - includes src calls / kernel threads +# +# This is the configuration file for sleepgraph. It contains +# all the tool arguments so that they don't have to be given on the +# command line. It also includes advanced settings for functions +# and kprobes. It is run like this +# +# sudo ./sleepgraph.py -config config/standby-dev.cfg +# + +[Settings] + +# ---- General Options ---- + +# Verbosity +# print verbose messages (default: false) +verbose: false + +# Suspend Mode +# e.g. standby, mem, freeze, disk (default: mem) +mode: standby + +# Output Directory Format +# output folder for html, ftrace, and dmesg. Use {date} and {time} for current values +output-dir: standby-{hostname}-{date}-{time}-dev + +# Automatic Wakeup +# Use rtcwake to autoresume after X seconds, or off to disable (default: 15) +rtcwake: 15 + +# Add Logs +# add the dmesg and ftrace log to the html output (default: false) +addlogs: false + +# Suspend/Resume Gap +# insert a small visible gap between suspend and resume on the timeline (default: false) +srgap: false + +# ---- Advanced Options ---- + +# Command to execute in lieu of standby (default: "") +# command: echo standby > /sys/power/state + +# Display user processes +# graph user processes and cpu usage in the timeline (default: false) +proc: false + +# Display function calls +# graph source functions in the timeline (default: false) +dev: true + +# Back to Back Suspend/Resume +# Run two suspend/resumes back to back (default: false) +x2: false + +# Back to Back Suspend Delay +# Time delay between the two test runs in ms (default: 0 ms) +x2delay: 0 + +# Pre Suspend Delay +# Include an N ms delay before (1st) suspend (default: 0 ms) +predelay: 0 + +# Post Resume Delay +# Include an N ms delay after (last) resume (default: 0 ms) +postdelay: 0 + +# Minimum Device Length +# graph only devices longer than min in the timeline (default: 0.001 ms) +mindev: 1 + +# ---- Debug Options ---- + +# Callgraph +# gather detailed ftrace callgraph data on all timeline events (default: false) +callgraph: false + +# Expand Callgraph +# pre-expand the callgraph data in the html output (default: disabled) +expandcg: false + +# Minimum Callgraph Length +# provide callgraph data for blocks longer than min (default: 0.001 ms) +mincg: 1 + +# Timestamp Precision +# Number of significant digits in timestamps (0:S, [3:ms], 6:us) +timeprec: 3 + +# Device Filter +# show only devs whose name/driver includes one of these strings +# devicefilter: _cpu_up,_cpu_down,i915,usb diff --git a/tools/power/pm-graph/config/standby.cfg b/tools/power/pm-graph/config/standby.cfg new file mode 100644 index 000000000000..f0dd264dfeff --- /dev/null +++ b/tools/power/pm-graph/config/standby.cfg @@ -0,0 +1,93 @@ +# +# Generic S1 (Standby) test +# +# This is the configuration file for sleepgraph. It contains +# all the tool arguments so that they don't have to be given on the +# command line. It also includes advanced settings for functions +# and kprobes. It is run like this +# +# sudo ./sleepgraph.py -config config/standby.cfg +# + +[Settings] + +# ---- General Options ---- + +# Verbosity +# print verbose messages (default: false) +verbose: false + +# Suspend Mode +# e.g. standby, mem, freeze, disk (default: mem) +mode: standby + +# Output Directory Format +# output folder for html, ftrace, and dmesg. Use {date} and {time} for current values +output-dir: standby-{hostname}-{date}-{time} + +# Automatic Wakeup +# Use rtcwake to autoresume after X seconds, or off to disable (default: 15) +rtcwake: 15 + +# Add Logs +# add the dmesg and ftrace log to the html output (default: false) +addlogs: false + +# Suspend/Resume Gap +# insert a small visible gap between suspend and resume on the timeline (default: false) +srgap: false + +# ---- Advanced Options ---- + +# Command to execute in lieu of standby (default: "") +# command: echo standby > /sys/power/state + +# Display user processes +# graph user processes and cpu usage in the timeline (default: false) +proc: false + +# Display function calls +# graph source functions in the timeline (default: false) +dev: false + +# Back to Back Suspend/Resume +# Run two suspend/resumes back to back (default: false) +x2: false + +# Back to Back Suspend Delay +# Time delay between the two test runs in ms (default: 0 ms) +x2delay: 0 + +# Pre Suspend Delay +# Include an N ms delay before (1st) suspend (default: 0 ms) +predelay: 0 + +# Post Resume Delay +# Include an N ms delay after (last) resume (default: 0 ms) +postdelay: 0 + +# Minimum Device Length +# graph only devices longer than min in the timeline (default: 0.001 ms) +mindev: 0.001 + +# ---- Debug Options ---- + +# Callgraph +# gather detailed ftrace callgraph data on all timeline events (default: false) +callgraph: false + +# Expand Callgraph +# pre-expand the callgraph data in the html output (default: disabled) +expandcg: false + +# Minimum Callgraph Length +# provide callgraph data for blocks longer than min (default: 0.001 ms) +mincg: 1 + +# Timestamp Precision +# Number of significant digits in timestamps (0:S, [3:ms], 6:us) +timeprec: 3 + +# Device Filter +# show only devs whose name/driver includes one of these strings +# devicefilter: _cpu_up,_cpu_down,i915,usb diff --git a/tools/power/pm-graph/config/suspend-callgraph.cfg b/tools/power/pm-graph/config/suspend-callgraph.cfg new file mode 100644 index 000000000000..11b8cbc12d34 --- /dev/null +++ b/tools/power/pm-graph/config/suspend-callgraph.cfg @@ -0,0 +1,98 @@ +# +# Full Callgraph for S3 (Suspend to Mem) test +# +# This is the configuration file for sleepgraph. It contains +# all the tool arguments so that they don't have to be given on the +# command line. It also includes advanced settings for functions +# and kprobes. It is run like this +# +# sudo ./sleepgraph.py -config config/suspend.cfg +# +# NOTE: the output of this test is very large (> 30MB) + +[Settings] + +# ---- General Options ---- + +# Verbosity +# print verbose messages (default: false) +verbose: false + +# Suspend Mode +# e.g. standby, mem, freeze, disk (default: mem) +mode: mem + +# Output Directory Format +# output folder for html, ftrace, and dmesg. Use {date} and {time} for current values +output-dir: suspend-{hostname}-{date}-{time}-cg + +# Automatic Wakeup +# Use rtcwake to autoresume after X seconds, or off to disable (default: 15) +rtcwake: 15 + +# Add Logs +# add the dmesg and ftrace log to the html output (default: false) +addlogs: false + +# Suspend/Resume Gap +# insert a small visible gap between suspend and resume on the timeline (default: false) +srgap: false + +# ---- Advanced Options ---- + +# Command to execute in lieu of suspend (default: "") +# command: echo mem > /sys/power/state + +# Display user processes +# graph user processes and cpu usage in the timeline (default: false) +proc: false + +# Display function calls +# graph source functions in the timeline (default: false) +dev: false + +# Back to Back Suspend/Resume +# Run two suspend/resumes back to back (default: false) +x2: false + +# Back to Back Suspend Delay +# Time delay between the two test runs in ms (default: 0 ms) +x2delay: 0 + +# Pre Suspend Delay +# Include an N ms delay before (1st) suspend (default: 0 ms) +predelay: 0 + +# Post Resume Delay +# Include an N ms delay after (last) resume (default: 0 ms) +postdelay: 0 + +# Minimum Device Length +# graph only devices longer than min in the timeline (default: 0.001 ms) +mindev: 0.001 + +# ---- Debug Options ---- + +# Callgraph +# gather detailed ftrace callgraph data on all timeline events (default: false) +callgraph: true + +# Max graph depth +# limit the callgraph trace to this depth (default: 0 = all) +maxdepth: 5 + +# Expand Callgraph +# pre-expand the callgraph data in the html output (default: disabled) +expandcg: false + +# Minimum Callgraph Length +# provide callgraph data for blocks longer than min (default: 0.001 ms) +mincg: 1 + +# Timestamp Precision +# Number of significant digits in timestamps (0:S, [3:ms], 6:us) +timeprec: 6 + +# Device Filter +# show only devs whose name/driver includes one of these strings +# devicefilter: _cpu_up,_cpu_down,i915,usb diff --git a/tools/power/pm-graph/config/suspend-dev.cfg b/tools/power/pm-graph/config/suspend-dev.cfg new file mode 100644 index 000000000000..56f1d21cc79b --- /dev/null +++ b/tools/power/pm-graph/config/suspend-dev.cfg @@ -0,0 +1,93 @@ +# +# Dev S3 (Suspend to Mem) test - includes src calls / kernel threads +# +# This is the configuration file for sleepgraph. It contains +# all the tool arguments so that they don't have to be given on the +# command line. It also includes advanced settings for functions +# and kprobes. It is run like this +# +# sudo ./sleepgraph.py -config config/suspend-dev.cfg +# + +[Settings] + +# ---- General Options ---- + +# Verbosity +# print verbose messages (default: false) +verbose: false + +# Suspend Mode +# e.g. standby, mem, freeze, disk (default: mem) +mode: mem + +# Output Directory Format +# output folder for html, ftrace, and dmesg. Use {date} and {time} for current values +output-dir: suspend-{hostname}-{date}-{time}-dev + +# Automatic Wakeup +# Use rtcwake to autoresume after X seconds, or off to disable (default: 15) +rtcwake: 15 + +# Add Logs +# add the dmesg and ftrace log to the html output (default: false) +addlogs: false + +# Suspend/Resume Gap +# insert a small visible gap between suspend and resume on the timeline (default: false) +srgap: false + +# ---- Advanced Options ---- + +# Command to execute in lieu of suspend (default: "") +# command: echo mem > /sys/power/state + +# Display user processes +# graph user processes and cpu usage in the timeline (default: false) +proc: false + +# Display function calls +# graph source functions in the timeline (default: false) +dev: true + +# Back to Back Suspend/Resume +# Run two suspend/resumes back to back (default: false) +x2: false + +# Back to Back Suspend Delay +# Time delay between the two test runs in ms (default: 0 ms) +x2delay: 0 + +# Pre Suspend Delay +# Include an N ms delay before (1st) suspend (default: 0 ms) +predelay: 0 + +# Post Resume Delay +# Include an N ms delay after (last) resume (default: 0 ms) +postdelay: 0 + +# Minimum Device Length +# graph only devices longer than min in the timeline (default: 0.001 ms) +mindev: 1 + +# ---- Debug Options ---- + +# Callgraph +# gather detailed ftrace callgraph data on all timeline events (default: false) +callgraph: false + +# Expand Callgraph +# pre-expand the callgraph data in the html output (default: disabled) +expandcg: false + +# Minimum Callgraph Length +# provide callgraph data for blocks longer than min (default: 0.001 ms) +mincg: 1 + +# Timestamp Precision +# Number of significant digits in timestamps (0:S, [3:ms], 6:us) +timeprec: 3 + +# Device Filter +# show only devs whose name/driver includes one of these strings +# devicefilter: _cpu_up,_cpu_down,i915,usb diff --git a/tools/power/pm-graph/config/suspend-x2-proc.cfg b/tools/power/pm-graph/config/suspend-x2-proc.cfg new file mode 100644 index 000000000000..0ecca0ede138 --- /dev/null +++ b/tools/power/pm-graph/config/suspend-x2-proc.cfg @@ -0,0 +1,93 @@ +# +# Proc S3 (Suspend to Mem) x2 test - includes user processes +# +# This is the configuration file for sleepgraph. It contains +# all the tool arguments so that they don't have to be given on the +# command line. It also includes advanced settings for functions +# and kprobes. It is run like this +# +# sudo ./sleepgraph.py -config config/suspend-proc.cfg +# + +[Settings] + +# ---- General Options ---- + +# Verbosity +# print verbose messages (default: false) +verbose: false + +# Suspend Mode +# e.g. standby, mem, freeze, disk (default: mem) +mode: mem + +# Output Directory Format +# output folder for html, ftrace, and dmesg. Use {date} and {time} for current values +output-dir: suspend-{hostname}-{date}-{time}-x2-proc + +# Automatic Wakeup +# Use rtcwake to autoresume after X seconds, or off to disable (default: 15) +rtcwake: 15 + +# Add Logs +# add the dmesg and ftrace log to the html output (default: false) +addlogs: false + +# Suspend/Resume Gap +# insert a small visible gap between suspend and resume on the timeline (default: false) +srgap: false + +# ---- Advanced Options ---- + +# Command to execute in lieu of suspend (default: "") +# command: echo mem > /sys/power/state + +# Display user processes +# graph user processes and cpu usage in the timeline (default: false) +proc: true + +# Display function calls +# graph source functions in the timeline (default: false) +dev: false + +# Back to Back Suspend/Resume +# Run two suspend/resumes back to back (default: false) +x2: true + +# Back to Back Suspend Delay +# Time delay between the two test runs in ms (default: 0 ms) +x2delay: 1000 + +# Pre Suspend Delay +# Include an N ms delay before (1st) suspend (default: 0 ms) +predelay: 1000 + +# Post Resume Delay +# Include an N ms delay after (last) resume (default: 0 ms) +postdelay: 1000 + +# Minimum Device Length +# graph only devices longer than min in the timeline (default: 0.001 ms) +mindev: 1 + +# ---- Debug Options ---- + +# Callgraph +# gather detailed ftrace callgraph data on all timeline events (default: false) +callgraph: false + +# Expand Callgraph +# pre-expand the callgraph data in the html output (default: disabled) +expandcg: false + +# Minimum Callgraph Length +# provide callgraph data for blocks longer than min (default: 0.001 ms) +mincg: 1 + +# Timestamp Precision +# Number of significant digits in timestamps (0:S, [3:ms], 6:us) +timeprec: 3 + +# Device Filter +# show only devs whose name/driver includes one of these strings +# devicefilter: _cpu_up,_cpu_down,i915,usb diff --git a/tools/power/pm-graph/config/suspend.cfg b/tools/power/pm-graph/config/suspend.cfg new file mode 100644 index 000000000000..70d293231b06 --- /dev/null +++ b/tools/power/pm-graph/config/suspend.cfg @@ -0,0 +1,93 @@ +# +# Generic S3 (Suspend to Mem) test +# +# This is the configuration file for sleepgraph. It contains +# all the tool arguments so that they don't have to be given on the +# command line. It also includes advanced settings for functions +# and kprobes. It is run like this +# +# sudo ./sleepgraph.py -config config/suspend.cfg +# + +[Settings] + +# ---- General Options ---- + +# Verbosity +# print verbose messages (default: false) +verbose: false + +# Suspend Mode +# e.g. standby, mem, freeze, disk (default: mem) +mode: mem + +# Output Directory Format +# output folder for html, ftrace, and dmesg. Use {date} and {time} for current values +output-dir: suspend-{hostname}-{date}-{time} + +# Automatic Wakeup +# Use rtcwake to autoresume after X seconds, or off to disable (default: 15) +rtcwake: 15 + +# Add Logs +# add the dmesg and ftrace log to the html output (default: false) +addlogs: false + +# Suspend/Resume Gap +# insert a small visible gap between suspend and resume on the timeline (default: false) +srgap: false + +# ---- Advanced Options ---- + +# Command to execute in lieu of suspend (default: "") +# command: echo mem > /sys/power/state + +# Display user processes +# graph user processes and cpu usage in the timeline (default: false) +proc: false + +# Display function calls +# graph source functions in the timeline (default: false) +dev: false + +# Back to Back Suspend/Resume +# Run two suspend/resumes back to back (default: false) +x2: false + +# Back to Back Suspend Delay +# Time delay between the two test runs in ms (default: 0 ms) +x2delay: 0 + +# Pre Suspend Delay +# Include an N ms delay before (1st) suspend (default: 0 ms) +predelay: 0 + +# Post Resume Delay +# Include an N ms delay after (last) resume (default: 0 ms) +postdelay: 0 + +# Minimum Device Length +# graph only devices longer than min in the timeline (default: 0.001 ms) +mindev: 0.001 + +# ---- Debug Options ---- + +# Callgraph +# gather detailed ftrace callgraph data on all timeline events (default: false) +callgraph: false + +# Expand Callgraph +# pre-expand the callgraph data in the html output (default: disabled) +expandcg: false + +# Minimum Callgraph Length +# provide callgraph data for blocks longer than min (default: 0.001 ms) +mincg: 1 + +# Timestamp Precision +# Number of significant digits in timestamps (0:S, [3:ms], 6:us) +timeprec: 3 + +# Device Filter +# show only devs whose name/driver includes one of these strings +# devicefilter: _cpu_up,_cpu_down,i915,usb diff --git a/tools/power/pm-graph/analyze_suspend.py b/tools/power/pm-graph/sleepgraph.py similarity index 100% rename from tools/power/pm-graph/analyze_suspend.py rename to tools/power/pm-graph/sleepgraph.py From d83a76a8ec34b3c52e9aadafadb370ebd82cf79a Mon Sep 17 00:00:00 2001 From: Todd E Brandt Date: Tue, 30 Jan 2018 00:17:19 -0800 Subject: [PATCH 03/56] pm-graph: AnalyzeBoot v2.2 - add -cgskip option to reduce callgraph output size - add -cgfilter option to focus on a list of devices - add -result option for exporting batch test results - removed all phoronix hooks, use -result to enable batch testing - changed argument -f to match sleegraph, -f = -callgraph - use -fstat for function status instead of -f - add -verbose option to print out timeline stats and kernel options - include command string and kernel params in timeline output header Signed-off-by: Todd Brandt Signed-off-by: Rafael J. Wysocki --- tools/power/pm-graph/bootgraph.8 | 18 ++- tools/power/pm-graph/bootgraph.py | 219 ++++++++++++++++++++---------- 2 files changed, 160 insertions(+), 77 deletions(-) diff --git a/tools/power/pm-graph/bootgraph.8 b/tools/power/pm-graph/bootgraph.8 index dbdafcf546df..64d513f80a2a 100644 --- a/tools/power/pm-graph/bootgraph.8 +++ b/tools/power/pm-graph/bootgraph.8 @@ -37,6 +37,9 @@ Print the current tool version Add the dmesg log to the html output. It will be viewable by clicking a button in the timeline. .TP +\fB-result \fIfile\fR +Export a results table to a text file for parsing. +.TP \fB-o \fIname\fR Overrides the output subdirectory name when running a new test. Use {date}, {time}, {hostname} for current values. @@ -44,14 +47,14 @@ Use {date}, {time}, {hostname} for current values. e.g. boot-{hostname}-{date}-{time} .SS "advanced" .TP -\fB-f\fR -Use ftrace to add function detail (default: disabled) -.TP -\fB-callgraph\fR +\fB-f or -callgraph\fR Use ftrace to create initcall callgraphs (default: disabled). If -func is not used there will be one callgraph per initcall. This can produce very large outputs, i.e. 10MB - 100MB. .TP +\fB-fstat\fR +Use ftrace to add function detail (default: disabled) +.TP \fB-maxdepth \fIlevel\fR limit the callgraph trace depth to \fIlevel\fR (default: 2). This is the best way to limit the output size when using -callgraph. @@ -67,6 +70,13 @@ Reduce callgraph output in the timeline by limiting it to a list of calls. The argument can be a single function name or a comma delimited list. (default: none) .TP +\fB-cgskip \fIfile\fR +Reduce callgraph output in the timeline by skipping over uninteresting +functions in the trace, e.g. printk or console_unlock. The functions listed +in this file will show up as empty leaves in the callgraph with only the start/end +times displayed. +(default: none) +.TP \fB-timeprec \fIn\fR Number of significant digits in timestamps (0:S, 3:ms, [6:us]) .TP diff --git a/tools/power/pm-graph/bootgraph.py b/tools/power/pm-graph/bootgraph.py index e83df141a597..abb4c38f029b 100755 --- a/tools/power/pm-graph/bootgraph.py +++ b/tools/power/pm-graph/bootgraph.py @@ -32,7 +32,7 @@ import platform import shutil from datetime import datetime, timedelta from subprocess import call, Popen, PIPE -import analyze_suspend as aslib +import sleepgraph as aslib # ----------------- CLASSES -------------------- @@ -42,23 +42,18 @@ import analyze_suspend as aslib # store system values and test parameters class SystemValues(aslib.SystemValues): title = 'BootGraph' - version = '2.1' + version = '2.2' hostname = 'localhost' testtime = '' kernel = '' dmesgfile = '' ftracefile = '' htmlfile = 'bootgraph.html' - outfile = '' testdir = '' - testdirprefix = 'boot' - embedded = False - testlog = False - dmesglog = False - ftracelog = False + kparams = '' + result = '' useftrace = False usecallgraph = False - usedevsrc = True suspendmode = 'boot' max_graph_depth = 2 graph_filter = 'do_one_initcall' @@ -69,11 +64,6 @@ class SystemValues(aslib.SystemValues): bootloader = 'grub' blexec = [] def __init__(self): - if('LOG_FILE' in os.environ and 'TEST_RESULTS_IDENTIFIER' in os.environ): - self.embedded = True - self.dmesglog = True - self.outfile = os.environ['LOG_FILE'] - self.htmlfile = os.environ['LOG_FILE'] self.hostname = platform.node() self.testtime = datetime.now().strftime('%Y-%m-%d_%H:%M:%S') if os.path.exists('/proc/version'): @@ -148,11 +138,18 @@ class SystemValues(aslib.SystemValues): cmdline = '%s -cronjob' % os.path.abspath(sys.argv[0]) args = iter(sys.argv[1:]) for arg in args: - if arg in ['-h', '-v', '-cronjob', '-reboot']: + if arg in ['-h', '-v', '-cronjob', '-reboot', '-verbose']: continue elif arg in ['-o', '-dmesg', '-ftrace', '-func']: args.next() continue + elif arg == '-result': + cmdline += ' %s "%s"' % (arg, os.path.abspath(args.next())) + continue + elif arg == '-cgskip': + file = self.configFile(args.next()) + cmdline += ' %s "%s"' % (arg, os.path.abspath(file)) + continue cmdline += ' '+arg if self.graph_filter != 'do_one_initcall': cmdline += ' -func "%s"' % self.graph_filter @@ -166,14 +163,6 @@ class SystemValues(aslib.SystemValues): print '3. After reboot, re-run this tool with the same arguments but no command (w/o -reboot or -manual).\n' print 'CMDLINE="%s"' % cmdline sys.exit() - def getExec(self, cmd): - dirlist = ['/sbin', '/bin', '/usr/sbin', '/usr/bin', - '/usr/local/sbin', '/usr/local/bin'] - for path in dirlist: - cmdfull = os.path.join(path, cmd) - if os.path.exists(cmdfull): - return cmdfull - return '' def blGrub(self): blcmd = '' for cmd in ['update-grub', 'grub-mkconfig', 'grub2-mkconfig']: @@ -199,6 +188,14 @@ class SystemValues(aslib.SystemValues): self.blGrub() else: doError('unknown boot loader: %s' % self.bootloader) + def writeDatafileHeader(self, filename): + self.kparams = open('/proc/cmdline', 'r').read().strip() + fp = open(filename, 'w') + fp.write(self.teststamp+'\n') + fp.write(self.sysstamp+'\n') + fp.write('# command | %s\n' % self.cmdline) + fp.write('# kparams | %s\n' % self.kparams) + fp.close() sysvals = SystemValues() @@ -249,7 +246,7 @@ class Data(aslib.Data): return name def deviceMatch(self, pid, cg): if cg.end - cg.start == 0: - return True + return '' for p in data.phases: list = self.dmesg[p]['list'] for devname in list: @@ -260,14 +257,25 @@ class Data(aslib.Data): if(cg.start <= dev['start'] and cg.end >= dev['end'] and dev['length'] > 0): dev['ftrace'] = cg self.do_one_initcall = True - return True + return devname else: if(cg.start > dev['start'] and cg.end < dev['end']): if 'ftraces' not in dev: dev['ftraces'] = [] dev['ftraces'].append(cg) - return True - return False + return devname + return '' + def printDetails(self): + sysvals.vprint('Timeline Details:') + sysvals.vprint(' Host: %s' % sysvals.hostname) + sysvals.vprint(' Kernel: %s' % sysvals.kernel) + sysvals.vprint(' Test time: %s' % sysvals.testtime) + sysvals.vprint(' Boot time: %s' % self.boottime) + for phase in self.phases: + dc = len(self.dmesg[phase]['list']) + sysvals.vprint('%9s mode: %.3f - %.3f (%d initcalls)' % (phase, + self.dmesg[phase]['start']*1000, + self.dmesg[phase]['end']*1000, dc)) # ----------------- FUNCTIONS -------------------- @@ -275,6 +283,8 @@ class Data(aslib.Data): # Description: # parse a kernel log for boot data def parseKernelLog(): + sysvals.vprint('Analyzing the dmesg data (%s)...' % \ + os.path.basename(sysvals.dmesgfile)) phase = 'kernel' data = Data(0) data.dmesg['kernel']['start'] = data.start = ktime = 0.0 @@ -298,6 +308,12 @@ def parseKernelLog(): elif re.match(tp.sysinfofmt, line): tp.sysinfo = line continue + elif re.match(tp.cmdlinefmt, line): + tp.cmdline = line + continue + elif re.match(tp.kparamsfmt, line): + tp.kparams = line + continue idx = line.find('[') if idx > 1: line = line[idx:] @@ -353,6 +369,17 @@ def parseKernelLog(): # Description: # Check if trace is available and copy to a temp file def parseTraceLog(data): + sysvals.vprint('Analyzing the ftrace data (%s)...' % \ + os.path.basename(sysvals.ftracefile)) + # if available, calculate cgfilter allowable ranges + cgfilter = [] + if len(sysvals.cgfilter) > 0: + for p in data.phases: + list = data.dmesg[p]['list'] + for i in sysvals.cgfilter: + if i in list: + cgfilter.append([list[i]['start']-0.0001, + list[i]['end']+0.0001]) # parse the trace log ftemp = dict() tp = aslib.TestProps() @@ -366,7 +393,16 @@ def parseTraceLog(data): continue m_time, m_proc, m_pid, m_msg, m_dur = \ m.group('time', 'proc', 'pid', 'msg', 'dur') - if float(m_time) > data.end: + t = float(m_time) + if len(cgfilter) > 0: + allow = False + for r in cgfilter: + if t >= r[0] and t < r[1]: + allow = True + break + if not allow: + continue + if t > data.end: break if(m_time and m_pid and m_msg): t = aslib.FTraceLine(m_time, m_msg, m_dur) @@ -378,24 +414,36 @@ def parseTraceLog(data): key = (m_proc, pid) if(key not in ftemp): ftemp[key] = [] - ftemp[key].append(aslib.FTraceCallGraph(pid)) + ftemp[key].append(aslib.FTraceCallGraph(pid, sysvals)) cg = ftemp[key][-1] - if(cg.addLine(t)): - ftemp[key].append(aslib.FTraceCallGraph(pid)) + res = cg.addLine(t) + if(res != 0): + ftemp[key].append(aslib.FTraceCallGraph(pid, sysvals)) + if(res == -1): + ftemp[key][-1].addLine(t) + tf.close() # add the callgraph data to the device hierarchy for key in ftemp: proc, pid = key for cg in ftemp[key]: - if len(cg.list) < 1 or cg.invalid: + if len(cg.list) < 1 or cg.invalid or (cg.end - cg.start == 0): continue if(not cg.postProcess()): print('Sanity check failed for %s-%d' % (proc, pid)) continue # match cg data to devices - if not data.deviceMatch(pid, cg): - print ' BAD: %s %s-%d [%f - %f]' % (cg.name, proc, pid, cg.start, cg.end) + devname = data.deviceMatch(pid, cg) + if not devname: + kind = 'Orphan' + if cg.partial: + kind = 'Partial' + sysvals.vprint('%s callgraph found for %s %s-%d [%f - %f]' %\ + (kind, cg.name, proc, pid, cg.start, cg.end)) + elif len(cg.list) > 1000000: + print 'WARNING: the callgraph found for %s is massive! (%d lines)' %\ + (devname, len(cg.list)) # Function: retrieveLogs # Description: @@ -473,7 +521,7 @@ def createBootGraph(data): devtl = aslib.Timeline(100, 20) # write the test title and general info header - devtl.createHeader(sysvals) + devtl.createHeader(sysvals, sysvals.stamp) # Generate the header for this timeline t0 = data.start @@ -574,12 +622,9 @@ def createBootGraph(data): data.dmesg[phase]['color'], phase+'_mode', phase[0]) devtl.html += '\n' - if(sysvals.outfile == sysvals.htmlfile): - hf = open(sysvals.htmlfile, 'a') - else: - hf = open(sysvals.htmlfile, 'w') + hf = open(sysvals.htmlfile, 'w') - # add the css if this is not an embedded run + # add the css extra = '\ .c1 {background:rgba(209,0,0,0.4);}\n\ .c2 {background:rgba(255,102,34,0.4);}\n\ @@ -597,8 +642,7 @@ def createBootGraph(data): .fstat td {text-align:left;width:35px;}\n\ .srccall {position:absolute;font-size:10px;z-index:7;overflow:hidden;color:black;text-align:center;white-space:nowrap;border-radius:5px;border:1px solid black;background:linear-gradient(to bottom right,#CCC,#969696);}\n\ .srccall:hover {color:white;font-weight:bold;border:1px solid white;}\n' - if(not sysvals.embedded): - aslib.addCSS(hf, sysvals, 1, False, extra) + aslib.addCSS(hf, sysvals, 1, False, extra) # write the device timeline hf.write(devtl.html) @@ -631,6 +675,9 @@ def createBootGraph(data): if(sysvals.usecallgraph): aslib.addCallgraphs(sysvals, hf, data) + # add the test log as a hidden div + if sysvals.testlog and sysvals.logmsg: + hf.write('\n') # add the dmesg log as a hidden div if sysvals.dmesglog: hf.write('\n') - if(not sysvals.embedded): - # write the footer and close - aslib.addScriptCode(hf, [data]) - hf.write('\n\n') - else: - # embedded out will be loaded in a page, skip the js - hf.write('' % \ - (data.start*1000, data.end*1000)) + # write the footer and close + aslib.addScriptCode(hf, [data]) + hf.write('\n\n') hf.close() return True @@ -780,6 +822,7 @@ def doError(msg, help=False): if help == True: printHelp() print 'ERROR: %s\n' % msg + sysvals.outputResult({'error':msg}) sys.exit() # Function: printHelp @@ -806,18 +849,21 @@ def printHelp(): print('Options:') print(' -h Print this help text') print(' -v Print the current tool version') + print(' -verbose Print extra information during execution and analysis') print(' -addlogs Add the dmesg log to the html output') + print(' -result fn Export a results table to a text file for parsing.') print(' -o name Overrides the output subdirectory name when running a new test') print(' default: boot-{date}-{time}') print(' [advanced]') - print(' -f Use ftrace to add function detail (default: disabled)') - print(' -callgraph Add callgraph detail, can be very large (default: disabled)') + print(' -fstat Use ftrace to add function detail and statistics (default: disabled)') + print(' -f/-callgraph Add callgraph detail, can be very large (default: disabled)') print(' -maxdepth N limit the callgraph data to N call levels (default: 2)') print(' -mincg ms Discard all callgraphs shorter than ms milliseconds (e.g. 0.001 for us)') print(' -timeprec N Number of significant digits in timestamps (0:S, 3:ms, [6:us])') print(' -expandcg pre-expand the callgraph data in the html output (default: disabled)') print(' -func list Limit ftrace to comma-delimited list of functions (default: do_one_initcall)') print(' -cgfilter S Filter the callgraph output in the timeline') + print(' -cgskip file Callgraph functions to skip, off to disable (default: cgskip.txt)') print(' -bl name Use the following boot loader for kernel params (default: grub)') print(' -reboot Reboot the machine automatically and generate a new timeline') print(' -manual Show the steps to generate a new timeline manually (used with -reboot)') @@ -837,8 +883,13 @@ if __name__ == '__main__': # loop through the command line arguments cmd = '' testrun = True + switchoff = ['disable', 'off', 'false', '0'] simplecmds = ['-sysinfo', '-kpupdate', '-flistall', '-checkbl'] + cgskip = '' + if '-f' in sys.argv: + cgskip = sysvals.configFile('cgskip.txt') args = iter(sys.argv[1:]) + mdset = False for arg in args: if(arg == '-h'): printHelp() @@ -846,13 +897,17 @@ if __name__ == '__main__': elif(arg == '-v'): print("Version %s" % sysvals.version) sys.exit() + elif(arg == '-verbose'): + sysvals.verbose = True elif(arg in simplecmds): cmd = arg[1:] - elif(arg == '-f'): + elif(arg == '-fstat'): sysvals.useftrace = True - elif(arg == '-callgraph'): + elif(arg == '-callgraph' or arg == '-f'): sysvals.useftrace = True sysvals.usecallgraph = True + elif(arg == '-cgdump'): + sysvals.cgdump = True elif(arg == '-mincg'): sysvals.mincglen = aslib.getArgFloat('-mincg', args, 0.0, 10000.0) elif(arg == '-cgfilter'): @@ -860,7 +915,18 @@ if __name__ == '__main__': val = args.next() except: doError('No callgraph functions supplied', True) - sysvals.setDeviceFilter(val) + sysvals.setCallgraphFilter(val) + elif(arg == '-cgskip'): + try: + val = args.next() + except: + doError('No file supplied', True) + if val.lower() in switchoff: + cgskip = '' + else: + cgskip = sysvals.configFile(val) + if(not cgskip): + doError('%s does not exist' % cgskip) elif(arg == '-bl'): try: val = args.next() @@ -872,6 +938,7 @@ if __name__ == '__main__': elif(arg == '-timeprec'): sysvals.setPrecision(aslib.getArgInt('-timeprec', args, 0, 6)) elif(arg == '-maxdepth'): + mdset = True sysvals.max_graph_depth = aslib.getArgInt('-maxdepth', args, 0, 1000) elif(arg == '-func'): try: @@ -902,8 +969,6 @@ if __name__ == '__main__': doError('No dmesg file supplied', True) if(os.path.exists(val) == False): doError('%s does not exist' % val) - if(sysvals.htmlfile == val or sysvals.outfile == val): - doError('Output filename collision') testrun = False sysvals.dmesgfile = val elif(arg == '-o'): @@ -912,6 +977,12 @@ if __name__ == '__main__': except: doError('No subdirectory name supplied', True) sysvals.testdir = sysvals.setOutputFolder(val) + elif(arg == '-result'): + try: + val = args.next() + except: + doError('No result file supplied', True) + sysvals.result = val elif(arg == '-reboot'): sysvals.reboot = True elif(arg == '-manual'): @@ -947,7 +1018,7 @@ if __name__ == '__main__': sysvals.getBootLoader() print 'Boot Loader: %s\n%s' % (sysvals.bootloader, sysvals.blexec) elif(cmd == 'sysinfo'): - sysvals.printSystemInfo() + sysvals.printSystemInfo(True) sys.exit() # reboot: update grub, setup a cronjob, and reboot @@ -963,6 +1034,10 @@ if __name__ == '__main__': sysvals.manualRebootRequired() sys.exit() + if sysvals.usecallgraph and cgskip: + sysvals.vprint('Using cgskip file: %s' % cgskip) + sysvals.setCallgraphBlacklist(cgskip) + # cronjob: remove the cronjob, grub changes, and disable ftrace if sysvals.iscronjob: updateCron(True) @@ -980,29 +1055,23 @@ if __name__ == '__main__': # process the log data if sysvals.dmesgfile: + if not mdset: + sysvals.max_graph_depth = 0 data = parseKernelLog() if(not data.valid): doError('No initcall data found in %s' % sysvals.dmesgfile) if sysvals.useftrace and sysvals.ftracefile: parseTraceLog(data) + if sysvals.cgdump: + data.debugPrint() + sys.exit() else: doError('dmesg file required') - print(' Host: %s' % sysvals.hostname) - print(' Test time: %s' % sysvals.testtime) - print(' Boot time: %s' % data.boottime) - print('Kernel Version: %s' % sysvals.kernel) - print(' Kernel start: %.3f' % (data.start * 1000)) - print('Usermode start: %.3f' % (data.tUserMode * 1000)) - print('Last Init Call: %.3f' % (data.end * 1000)) - - # handle embedded output logs - if(sysvals.outfile and sysvals.embedded): - fp = open(sysvals.outfile, 'w') - fp.write('pass %s initstart %.3f end %.3f boot %s\n' % - (data.valid, data.tUserMode*1000, data.end*1000, data.boottime)) - fp.close() - + sysvals.vprint('Creating the html timeline (%s)...' % sysvals.htmlfile) + sysvals.vprint('Command:\n %s' % sysvals.cmdline) + sysvals.vprint('Kernel parameters:\n %s' % sysvals.kparams) + data.printDetails() createBootGraph(data) # if running as root, change output dir owner to sudo_user @@ -1010,3 +1079,7 @@ if __name__ == '__main__': os.getuid() == 0 and 'SUDO_USER' in os.environ: cmd = 'chown -R {0}:{0} {1} > /dev/null 2>&1' call(cmd.format(os.environ['SUDO_USER'], sysvals.testdir), shell=True) + + sysvals.stamp['boot'] = (data.tUserMode - data.start) * 1000 + sysvals.stamp['lastinit'] = data.end * 1000 + sysvals.outputResult(sysvals.stamp) From 700abc90f07b7f60e512c5d5b7cb33bdc207e47c Mon Sep 17 00:00:00 2001 From: Todd E Brandt Date: Tue, 30 Jan 2018 00:17:20 -0800 Subject: [PATCH 04/56] pm-graph: AnalyzeSuspend v5.0 - add -cgskip option to reduce callgraph output size - add -cgfilter option to focus on a list of devices - add -result option for exporting batch test results - removed all phoronix hooks, use -result to enable batch testing - change -usbtopo to -devinfo, now prints all devices - add -gzip option to read/write logs in gz format - add -bufsize option to manually control ftrace buffer size - add -sync option to run filesystem sync prior to test - add -display option to enable/disable the display prior to test - add -rs option to enable/disable runtime suspend on all devices for test - add installed config files to search path - add kernel error/warning links into the timeline - fix callgraph trace to better handle interrupts - include command string and kernel params in timeline output header Signed-off-by: Todd Brandt Signed-off-by: Rafael J. Wysocki --- tools/power/pm-graph/sleepgraph.8 | 47 +- tools/power/pm-graph/sleepgraph.py | 1623 +++++++++++++++++----------- 2 files changed, 1052 insertions(+), 618 deletions(-) diff --git a/tools/power/pm-graph/sleepgraph.8 b/tools/power/pm-graph/sleepgraph.8 index fbe7bd3eae8e..18baaf6300c9 100644 --- a/tools/power/pm-graph/sleepgraph.8 +++ b/tools/power/pm-graph/sleepgraph.8 @@ -52,9 +52,32 @@ disable rtcwake and require a user keypress to resume. \fB-addlogs\fR Add the dmesg and ftrace logs to the html output. They will be viewable by clicking buttons in the timeline. +.TP +\fB-result \fIfile\fR +Export a results table to a text file for parsing. +.TP +\fB-sync\fR +Sync the filesystems before starting the test. This reduces the size of +the sys_sync call which happens in the suspend_prepare phase. +.TP +\fB-rs \fIenable/disable\fR +During test, enable/disable runtime suspend for all devices. The test is delayed +by 5 seconds to allow runtime suspend changes to occur. The settings are restored +after the test is complete. +.TP +\fB-display \fIon/off\fR +Turn the display on or off for the test using the xset command. This helps +maintain the consistecy of test data for better comparison. +.TP +\fB-skiphtml\fR +Run the test and capture the trace logs, but skip the timeline generation. .SS "advanced" .TP +\fB-gzip\fR +Gzip the trace and dmesg logs to save space. The tool can also read in gzipped +logs for processing. +.TP \fB-cmd \fIstr\fR Run the timeline over a custom suspend command, e.g. pm-suspend. By default the tool forces suspend via /sys/power/state so this allows testing over @@ -114,6 +137,18 @@ This reduces the html file size as there can be many tiny callgraphs which are barely visible in the timeline. The value is a float: e.g. 0.001 represents 1 us. .TP +\fB-cgfilter \fI"func1,func2,..."\fR +Reduce callgraph output in the timeline by limiting it to a list of calls. The +argument can be a single function name or a comma delimited list. +(default: none) +.TP +\fB-cgskip \fIfile\fR +Reduce callgraph timeline size by skipping over uninteresting functions +in the trace, e.g. printk or console_unlock. The functions listed +in this file will show up as empty leaves in the callgraph with only the start/end +times displayed. cgskip.txt is used automatically if found in the path, so +use "off" to disable completely (default: cgskip.txt) +.TP \fB-cgphase \fIp\fR Only show callgraph data for phase \fIp\fR (e.g. suspend_late). .TP @@ -122,6 +157,9 @@ In an x2 run, only show callgraph data for test \fIn\fR (e.g. 0 or 1). .TP \fB-timeprec \fIn\fR Number of significant digits in timestamps (0:S, [3:ms], 6:us). +.TP +\fB-bufsize \fIN\fR +Set trace buffer size to N kilo-bytes (default: all of free memory up to 3GB) .SH COMMANDS .TP @@ -144,11 +182,8 @@ Print out the contents of the ACPI Firmware Performance Data Table. \fB-sysinfo\fR Print out system info extracted from BIOS. Reads /dev/mem directly instead of going through dmidecode. .TP -\fB-usbtopo\fR -Print out the current USB topology with power info. -.TP -\fB-usbauto\fR -Enable autosuspend for all connected USB devices. +\fB-devinfo\fR +Print out the pm settings of all devices which support runtime suspend. .TP \fB-flist\fR Print the list of ftrace functions currently being captured. Functions @@ -198,7 +233,7 @@ Execute a mem suspend with a 15 second wakeup. Include the logs in the html. .PP Execute a standby with a 15 second wakeup. Change the output folder name. .IP -\f(CW$ sudo sleepgraph -m standby -rtcwake 15 -o "standby-{hostname}-{date}-{time}"\fR +\f(CW$ sudo sleepgraph -m standby -rtcwake 15 -o "standby-{host}-{date}-{time}"\fR .PP Execute a freeze with no wakeup (require keypress). Change output folder name. .IP diff --git a/tools/power/pm-graph/sleepgraph.py b/tools/power/pm-graph/sleepgraph.py index 1b60fe203741..266409fb27ae 100755 --- a/tools/power/pm-graph/sleepgraph.py +++ b/tools/power/pm-graph/sleepgraph.py @@ -19,7 +19,7 @@ # Home Page # https://01.org/suspendresume # Source repo -# https://github.com/01org/pm-graph +# git@github.com:01org/pm-graph # # Description: # This tool is designed to assist kernel and OS developers in optimizing @@ -57,6 +57,7 @@ import platform from datetime import datetime import struct import ConfigParser +import gzip from threading import Thread from subprocess import call, Popen, PIPE @@ -68,8 +69,12 @@ from subprocess import call, Popen, PIPE # store system values and test parameters class SystemValues: title = 'SleepGraph' - version = '4.7' + version = '5.0' ansi = False + rs = 0 + display = 0 + gzip = False + sync = False verbose = False testlog = True dmesglog = False @@ -78,14 +83,19 @@ class SystemValues: mincglen = 0.0 cgphase = '' cgtest = -1 + cgskip = '' + multitest = {'run': False, 'count': 0, 'delay': 0} max_graph_depth = 0 callloopmaxgap = 0.0001 callloopmaxlen = 0.005 + bufsize = 0 cpucount = 0 memtotal = 204800 + memfree = 204800 srgap = 0 cgexp = False testdir = '' + outdir = '' tpath = '/sys/kernel/debug/tracing/' fpdtpath = '/sys/firmware/acpi/tables/FPDT' epath = '/sys/kernel/debug/tracing/events/power/' @@ -109,22 +119,24 @@ class SystemValues: dmesgfile = '' ftracefile = '' htmlfile = 'output.html' - embedded = False + result = '' rtcwake = True rtcwaketime = 15 rtcpath = '' devicefilter = [] + cgfilter = [] stamp = 0 execcount = 1 x2delay = 0 + skiphtml = False usecallgraph = False usetraceevents = False - usetraceeventsonly = False usetracemarkers = True usekprobes = True usedevsrc = False useprocmon = False notestrun = False + cgdump = False mixedphaseheight = True devprops = dict() predelay = 0 @@ -134,24 +146,33 @@ class SystemValues: tracertypefmt = '# tracer: (?P.*)' firmwarefmt = '# fwsuspend (?P[0-9]*) fwresume (?P[0-9]*)$' tracefuncs = { - 'sys_sync': dict(), - 'pm_prepare_console': dict(), - 'pm_notifier_call_chain': dict(), - 'freeze_processes': dict(), - 'freeze_kernel_threads': dict(), - 'pm_restrict_gfp_mask': dict(), - 'acpi_suspend_begin': dict(), - 'suspend_console': dict(), - 'acpi_pm_prepare': dict(), - 'syscore_suspend': dict(), - 'arch_enable_nonboot_cpus_end': dict(), - 'syscore_resume': dict(), - 'acpi_pm_finish': dict(), - 'resume_console': dict(), - 'acpi_pm_end': dict(), - 'pm_restore_gfp_mask': dict(), - 'thaw_processes': dict(), - 'pm_restore_console': dict(), + 'sys_sync': {}, + '__pm_notifier_call_chain': {}, + 'pm_prepare_console': {}, + 'pm_notifier_call_chain': {}, + 'freeze_processes': {}, + 'freeze_kernel_threads': {}, + 'pm_restrict_gfp_mask': {}, + 'acpi_suspend_begin': {}, + 'acpi_hibernation_begin': {}, + 'acpi_hibernation_enter': {}, + 'acpi_hibernation_leave': {}, + 'acpi_pm_freeze': {}, + 'acpi_pm_thaw': {}, + 'hibernate_preallocate_memory': {}, + 'create_basic_memory_bitmaps': {}, + 'swsusp_write': {}, + 'suspend_console': {}, + 'acpi_pm_prepare': {}, + 'syscore_suspend': {}, + 'arch_enable_nonboot_cpus_end': {}, + 'syscore_resume': {}, + 'acpi_pm_finish': {}, + 'resume_console': {}, + 'acpi_pm_end': {}, + 'pm_restore_gfp_mask': {}, + 'thaw_processes': {}, + 'pm_restore_console': {}, 'CPU_OFF': { 'func':'_cpu_down', 'args_x86_64': {'cpu':'%di:s32'}, @@ -173,56 +194,54 @@ class SystemValues: 'mutex_lock_slowpath': { 'func':'__mutex_lock_slowpath', 'ub': 1 }, 'acpi_os_stall': {'ub': 1}, # ACPI - 'acpi_resume_power_resources': dict(), - 'acpi_ps_parse_aml': dict(), + 'acpi_resume_power_resources': {}, + 'acpi_ps_parse_aml': {}, # filesystem - 'ext4_sync_fs': dict(), + 'ext4_sync_fs': {}, # 80211 - 'iwlagn_mac_start': dict(), - 'iwlagn_alloc_bcast_station': dict(), - 'iwl_trans_pcie_start_hw': dict(), - 'iwl_trans_pcie_start_fw': dict(), - 'iwl_run_init_ucode': dict(), - 'iwl_load_ucode_wait_alive': dict(), - 'iwl_alive_start': dict(), - 'iwlagn_mac_stop': dict(), - 'iwlagn_mac_suspend': dict(), - 'iwlagn_mac_resume': dict(), - 'iwlagn_mac_add_interface': dict(), - 'iwlagn_mac_remove_interface': dict(), - 'iwlagn_mac_change_interface': dict(), - 'iwlagn_mac_config': dict(), - 'iwlagn_configure_filter': dict(), - 'iwlagn_mac_hw_scan': dict(), - 'iwlagn_bss_info_changed': dict(), - 'iwlagn_mac_channel_switch': dict(), - 'iwlagn_mac_flush': dict(), + 'iwlagn_mac_start': {}, + 'iwlagn_alloc_bcast_station': {}, + 'iwl_trans_pcie_start_hw': {}, + 'iwl_trans_pcie_start_fw': {}, + 'iwl_run_init_ucode': {}, + 'iwl_load_ucode_wait_alive': {}, + 'iwl_alive_start': {}, + 'iwlagn_mac_stop': {}, + 'iwlagn_mac_suspend': {}, + 'iwlagn_mac_resume': {}, + 'iwlagn_mac_add_interface': {}, + 'iwlagn_mac_remove_interface': {}, + 'iwlagn_mac_change_interface': {}, + 'iwlagn_mac_config': {}, + 'iwlagn_configure_filter': {}, + 'iwlagn_mac_hw_scan': {}, + 'iwlagn_bss_info_changed': {}, + 'iwlagn_mac_channel_switch': {}, + 'iwlagn_mac_flush': {}, # ATA 'ata_eh_recover': { 'args_x86_64': {'port':'+36(%di):s32'} }, # i915 - 'i915_gem_resume': dict(), - 'i915_restore_state': dict(), - 'intel_opregion_setup': dict(), - 'g4x_pre_enable_dp': dict(), - 'vlv_pre_enable_dp': dict(), - 'chv_pre_enable_dp': dict(), - 'g4x_enable_dp': dict(), - 'vlv_enable_dp': dict(), - 'intel_hpd_init': dict(), - 'intel_opregion_register': dict(), - 'intel_dp_detect': dict(), - 'intel_hdmi_detect': dict(), - 'intel_opregion_init': dict(), - 'intel_fbdev_set_suspend': dict(), + 'i915_gem_resume': {}, + 'i915_restore_state': {}, + 'intel_opregion_setup': {}, + 'g4x_pre_enable_dp': {}, + 'vlv_pre_enable_dp': {}, + 'chv_pre_enable_dp': {}, + 'g4x_enable_dp': {}, + 'vlv_enable_dp': {}, + 'intel_hpd_init': {}, + 'intel_opregion_register': {}, + 'intel_dp_detect': {}, + 'intel_hdmi_detect': {}, + 'intel_opregion_init': {}, + 'intel_fbdev_set_suspend': {}, } + cgblacklist = [] kprobes = dict() timeformat = '%.3f' + cmdline = '%s %s' % \ + (os.path.basename(sys.argv[0]), string.join(sys.argv[1:], ' ')) def __init__(self): - # if this is a phoronix test run, set some default options - if('LOG_FILE' in os.environ and 'TEST_RESULTS_IDENTIFIER' in os.environ): - self.embedded = True - self.dmesglog = self.ftracelog = True - self.htmlfile = os.environ['LOG_FILE'] self.archargs = 'args_'+platform.machine() self.hostname = platform.node() if(self.hostname == ''): @@ -237,18 +256,36 @@ class SystemValues: if (hasattr(sys.stdout, 'isatty') and sys.stdout.isatty()): self.ansi = True self.testdir = datetime.now().strftime('suspend-%y%m%d-%H%M%S') + def vprint(self, msg): + self.logmsg += msg+'\n' + if(self.verbose): + print(msg) def rootCheck(self, fatal=True): if(os.access(self.powerfile, os.W_OK)): return True if fatal: - doError('This command requires sysfs mount and root access') + msg = 'This command requires sysfs mount and root access' + print('ERROR: %s\n') % msg + self.outputResult({'error':msg}) + sys.exit() return False def rootUser(self, fatal=False): if 'USER' in os.environ and os.environ['USER'] == 'root': return True if fatal: - doError('This command must be run as root') + msg = 'This command must be run as root' + print('ERROR: %s\n') % msg + self.outputResult({'error':msg}) + sys.exit() return False + def getExec(self, cmd): + dirlist = ['/sbin', '/bin', '/usr/sbin', '/usr/bin', + '/usr/local/sbin', '/usr/local/bin'] + for path in dirlist: + cmdfull = os.path.join(path, cmd) + if os.path.exists(cmdfull): + return cmdfull + return '' def setPrecision(self, num): if num < 0 or num > 6: return @@ -258,15 +295,15 @@ class SystemValues: n = datetime.now() args['date'] = n.strftime('%y%m%d') args['time'] = n.strftime('%H%M%S') - args['hostname'] = self.hostname + args['hostname'] = args['host'] = self.hostname return value.format(**args) def setOutputFile(self): if self.dmesgfile != '': - m = re.match('(?P.*)_dmesg\.txt$', self.dmesgfile) + m = re.match('(?P.*)_dmesg\.txt.*', self.dmesgfile) if(m): self.htmlfile = m.group('name')+'.html' if self.ftracefile != '': - m = re.match('(?P.*)_ftrace\.txt$', self.ftracefile) + m = re.match('(?P.*)_ftrace\.txt.*', self.ftracefile) if(m): self.htmlfile = m.group('name')+'.html' def systemInfo(self, info): @@ -283,16 +320,19 @@ class SystemValues: c = info['processor-version'] if 'bios-version' in info: b = info['bios-version'] - self.sysstamp = '# sysinfo | man:%s | plat:%s | cpu:%s | bios:%s | numcpu:%d | memsz:%d' % \ - (m, p, c, b, self.cpucount, self.memtotal) - def printSystemInfo(self): + self.sysstamp = '# sysinfo | man:%s | plat:%s | cpu:%s | bios:%s | numcpu:%d | memsz:%d | memfr:%d' % \ + (m, p, c, b, self.cpucount, self.memtotal, self.memfree) + def printSystemInfo(self, fatal=False): self.rootCheck(True) - out = dmidecode(self.mempath, True) + out = dmidecode(self.mempath, fatal) + if len(out) < 1: + return fmt = '%-24s: %s' for name in sorted(out): print fmt % (name, out[name]) print fmt % ('cpucount', ('%d' % self.cpucount)) print fmt % ('memtotal', ('%d kB' % self.memtotal)) + print fmt % ('memfree', ('%d kB' % self.memfree)) def cpuInfo(self): self.cpucount = 0 fp = open('/proc/cpuinfo', 'r') @@ -305,7 +345,9 @@ class SystemValues: m = re.match('^MemTotal:[ \t]*(?P[0-9]*) *kB', line) if m: self.memtotal = int(m.group('sz')) - break + m = re.match('^MemFree:[ \t]*(?P[0-9]*) *kB', line) + if m: + self.memfree = int(m.group('sz')) fp.close() def initTestOutput(self, name): self.prefix = self.hostname @@ -315,39 +357,34 @@ class SystemValues: testtime = datetime.now().strftime(fmt) self.teststamp = \ '# '+testtime+' '+self.prefix+' '+self.suspendmode+' '+kver - if(self.embedded): - self.dmesgfile = \ - '/tmp/'+testtime+'_'+self.suspendmode+'_dmesg.txt' - self.ftracefile = \ - '/tmp/'+testtime+'_'+self.suspendmode+'_ftrace.txt' - return + ext = '' + if self.gzip: + ext = '.gz' self.dmesgfile = \ - self.testdir+'/'+self.prefix+'_'+self.suspendmode+'_dmesg.txt' + self.testdir+'/'+self.prefix+'_'+self.suspendmode+'_dmesg.txt'+ext self.ftracefile = \ - self.testdir+'/'+self.prefix+'_'+self.suspendmode+'_ftrace.txt' + self.testdir+'/'+self.prefix+'_'+self.suspendmode+'_ftrace.txt'+ext self.htmlfile = \ self.testdir+'/'+self.prefix+'_'+self.suspendmode+'.html' if not os.path.isdir(self.testdir): os.mkdir(self.testdir) + def getValueList(self, value): + out = [] + for i in value.split(','): + if i.strip(): + out.append(i.strip()) + return out def setDeviceFilter(self, value): - self.devicefilter = [] - if value: - value = value.split(',') - for i in value: - self.devicefilter.append(i.strip()) + self.devicefilter = self.getValueList(value) + def setCallgraphFilter(self, value): + self.cgfilter = self.getValueList(value) + def setCallgraphBlacklist(self, file): + self.cgblacklist = self.listFromFile(file) def rtcWakeAlarmOn(self): call('echo 0 > '+self.rtcpath+'/wakealarm', shell=True) - outD = open(self.rtcpath+'/date', 'r').read().strip() - outT = open(self.rtcpath+'/time', 'r').read().strip() - mD = re.match('^(?P[0-9]*)-(?P[0-9]*)-(?P[0-9]*)', outD) - mT = re.match('^(?P[0-9]*):(?P[0-9]*):(?P[0-9]*)', outT) - if(mD and mT): - # get the current time from hardware - utcoffset = int((datetime.now() - datetime.utcnow()).total_seconds()) - dt = datetime(\ - int(mD.group('y')), int(mD.group('m')), int(mD.group('d')), - int(mT.group('h')), int(mT.group('m')), int(mT.group('s'))) - nowtime = int(dt.strftime('%s')) + utcoffset + nowtime = open(self.rtcpath+'/since_epoch', 'r').read().strip() + if nowtime: + nowtime = int(nowtime) else: # if hardware time fails, use the software time nowtime = int(datetime.now().strftime('%s')) @@ -369,10 +406,10 @@ class SystemValues: ktime = m.group('ktime') fp.close() self.dmesgstart = float(ktime) - def getdmesg(self): + def getdmesg(self, fwdata=[]): + op = self.writeDatafileHeader(sysvals.dmesgfile, fwdata) # store all new dmesg lines since initdmesg was called fp = Popen('dmesg', stdout=PIPE).stdout - op = open(self.dmesgfile, 'a') for line in fp: line = line.replace('\r\n', '') idx = line.find('[') @@ -386,11 +423,17 @@ class SystemValues: op.write(line) fp.close() op.close() - def addFtraceFilterFunctions(self, file): + def listFromFile(self, file): + list = [] fp = open(file) - list = fp.read().split('\n') + for i in fp.read().split('\n'): + i = i.strip() + if i and i[0] != '#': + list.append(i) fp.close() - for i in list: + return list + def addFtraceFilterFunctions(self, file): + for i in self.listFromFile(file): if len(i) < 2: continue self.tracefuncs[i] = dict() @@ -399,9 +442,7 @@ class SystemValues: if not current: call('cat '+self.tpath+'available_filter_functions', shell=True) return - fp = open(self.tpath+'available_filter_functions') - master = fp.read().split('\n') - fp.close() + master = self.listFromFile(self.tpath+'available_filter_functions') for i in self.tracefuncs: if 'func' in self.tracefuncs[i]: i = self.tracefuncs[i]['func'] @@ -410,9 +451,7 @@ class SystemValues: else: print self.colorText(i) def setFtraceFilterFunctions(self, list): - fp = open(self.tpath+'available_filter_functions') - master = fp.read().split('\n') - fp.close() + master = self.listFromFile(self.tpath+'available_filter_functions') flist = '' for i in list: if i not in master: @@ -501,6 +540,7 @@ class SystemValues: rejects = [] # sort kprobes: trace, ub-dev, custom, dev kpl = [[], [], [], []] + linesout = len(self.kprobes) for name in sorted(self.kprobes): res = self.colorText('YES', 32) if not self.testKprobe(name, self.kprobes[name]): @@ -528,17 +568,10 @@ class SystemValues: for kp in kplist: kprobeevents += self.kprobeText(kp, self.kprobes[kp]) self.fsetVal(kprobeevents, 'kprobe_events') - # verify that the kprobes were set as ordered - check = self.fgetVal('kprobe_events') - linesout = len(kprobeevents.split('\n')) - 1 - linesack = len(check.split('\n')) - 1 if output: - res = '%d/%d' % (linesack, linesout) - if linesack < linesout: - res = self.colorText(res, 31) - else: - res = self.colorText(res, 32) - print(' working kprobe functions enabled: %s' % res) + check = self.fgetVal('kprobe_events') + linesack = (len(check.split('\n')) - 1) / 2 + print(' kprobe functions enabled: %d/%d' % (linesack, linesout)) self.fsetVal('1', 'events/kprobes/enable') def testKprobe(self, kname, kprobe): self.fsetVal('0', 'events/kprobes/enable') @@ -555,8 +588,7 @@ class SystemValues: if linesack < linesout: return False return True - def fsetVal(self, val, path, mode='w'): - file = self.tpath+path + def setVal(self, val, file, mode='w'): if not os.path.exists(file): return False try: @@ -567,8 +599,9 @@ class SystemValues: except: return False return True - def fgetVal(self, path): - file = self.tpath+path + def fsetVal(self, val, path, mode='w'): + return self.setVal(val, self.tpath+path, mode) + def getVal(self, file): res = '' if not os.path.exists(file): return res @@ -579,10 +612,13 @@ class SystemValues: except: pass return res + def fgetVal(self, path): + return self.getVal(self.tpath+path) def cleanupFtrace(self): - if(self.usecallgraph or self.usetraceevents): + if(self.usecallgraph or self.usetraceevents or self.usedevsrc): self.fsetVal('0', 'events/kprobes/enable') self.fsetVal('', 'kprobe_events') + self.fsetVal('1024', 'buffer_size_kb') def setupAllKprobes(self): for name in self.tracefuncs: self.defaultKprobe(name, self.tracefuncs[name]) @@ -599,7 +635,8 @@ class SystemValues: if name == f: return True return False - def initFtrace(self, testing=False): + def initFtrace(self): + self.printSystemInfo(False) print('INITIALIZING FTRACE...') # turn trace off self.fsetVal('0', 'tracing_on') @@ -607,17 +644,21 @@ class SystemValues: # set the trace clock to global self.fsetVal('global', 'trace_clock') self.fsetVal('nop', 'current_tracer') - # set trace buffer to a huge value - if self.usecallgraph or self.usedevsrc: - tgtsize = min(self.memtotal / 2, 2*1024*1024) - maxbuf = '%d' % (tgtsize / max(1, self.cpucount)) - if self.cpucount < 1 or not self.fsetVal(maxbuf, 'buffer_size_kb'): - self.fsetVal('131072', 'buffer_size_kb') + # set trace buffer to an appropriate value + cpus = max(1, self.cpucount) + if self.bufsize > 0: + tgtsize = self.bufsize + elif self.usecallgraph or self.usedevsrc: + tgtsize = min(self.memfree, 3*1024*1024) else: - self.fsetVal('16384', 'buffer_size_kb') - # go no further if this is just a status check - if testing: - return + tgtsize = 65536 + while not self.fsetVal('%d' % (tgtsize / cpus), 'buffer_size_kb'): + # if the size failed to set, lower it and keep trying + tgtsize -= 65536 + if tgtsize < 65536: + tgtsize = int(self.fgetVal('buffer_size_kb')) * cpus + break + print 'Setting trace buffers to %d kB (%d kB per cpu)' % (tgtsize, tgtsize/cpus) # initialize the callgraph trace if(self.usecallgraph): # set trace type @@ -635,7 +676,7 @@ class SystemValues: self.fsetVal('graph-time', 'trace_options') self.fsetVal('%d' % self.max_graph_depth, 'max_graph_depth') cf = ['dpm_run_callback'] - if(self.usetraceeventsonly): + if(self.usetraceevents): cf += ['dpm_prepare', 'dpm_complete'] for fn in self.tracefuncs: if 'func' in self.tracefuncs[fn]: @@ -688,16 +729,65 @@ class SystemValues: return str return '\x1B[%d;40m%s\x1B[m' % (color, str) def writeDatafileHeader(self, filename, fwdata=[]): - fp = open(filename, 'w') - fp.write(self.teststamp+'\n') - fp.write(self.sysstamp+'\n') + fp = self.openlog(filename, 'w') + fp.write('%s\n%s\n# command | %s\n' % (self.teststamp, self.sysstamp, self.cmdline)) if(self.suspendmode == 'mem' or self.suspendmode == 'command'): for fw in fwdata: if(fw): fp.write('# fwsuspend %u fwresume %u\n' % (fw[0], fw[1])) + return fp + def sudouser(self, dir): + if os.path.exists(dir) and os.getuid() == 0 and \ + 'SUDO_USER' in os.environ: + cmd = 'chown -R {0}:{0} {1} > /dev/null 2>&1' + call(cmd.format(os.environ['SUDO_USER'], dir), shell=True) + def outputResult(self, testdata, num=0): + if not self.result: + return + n = '' + if num > 0: + n = '%d' % num + fp = open(self.result, 'a') + if 'error' in testdata: + fp.write('result%s: fail\n' % n) + fp.write('error%s: %s\n' % (n, testdata['error'])) + else: + fp.write('result%s: pass\n' % n) + for v in ['suspend', 'resume', 'boot', 'lastinit']: + if v in testdata: + fp.write('%s%s: %.3f\n' % (v, n, testdata[v])) + for v in ['fwsuspend', 'fwresume']: + if v in testdata: + fp.write('%s%s: %.3f\n' % (v, n, testdata[v] / 1000000.0)) + if 'bugurl' in testdata: + fp.write('url%s: %s\n' % (n, testdata['bugurl'])) fp.close() + self.sudouser(self.result) + def configFile(self, file): + dir = os.path.dirname(os.path.realpath(__file__)) + if os.path.exists(file): + return file + elif os.path.exists(dir+'/'+file): + return dir+'/'+file + elif os.path.exists(dir+'/config/'+file): + return dir+'/config/'+file + return '' + def openlog(self, filename, mode): + isgz = self.gzip + if mode == 'r': + try: + with gzip.open(filename, mode+'b') as fp: + test = fp.read(64) + isgz = True + except: + isgz = False + if isgz: + return gzip.open(filename, mode+'b') + return open(filename, mode) sysvals = SystemValues() +switchvalues = ['enable', 'disable', 'on', 'off', 'true', 'false', '1', '0'] +switchoff = ['disable', 'off', 'false', '0'] suspendmodename = { 'freeze': 'Freeze (S0)', 'standby': 'Standby (S1)', @@ -826,34 +916,65 @@ class Data: for phase in self.phases: self.devicegroups.append([phase]) self.errorinfo = {'suspend':[],'resume':[]} - def extractErrorInfo(self, dmesg): - error = '' - tm = 0.0 - for i in range(len(dmesg)): - if 'Call Trace:' in dmesg[i]: - m = re.match('[ \t]*(\[ *)(?P[0-9\.]*)(\]) .*', dmesg[i]) - if not m: - continue - tm = float(m.group('ktime')) - if tm < self.start or tm > self.end: - continue - for j in range(i-10, i+1): - error += dmesg[j] + def extractErrorInfo(self): + lf = sysvals.openlog(sysvals.dmesgfile, 'r') + i = 0 + list = [] + # sl = start line, et = error time, el = error line + type = 'ERROR' + sl = et = el = -1 + for line in lf: + i += 1 + m = re.match('[ \t]*(\[ *)(?P[0-9\.]*)(\]) (?P.*)', line) + if not m: continue - if error: - m = re.match('[ \t]*\[ *[0-9\.]*\] \[\<[0-9a-fA-F]*\>\] .*', dmesg[i]) - if m: - error += dmesg[i] - else: - if tm < self.tSuspended: - dir = 'suspend' - else: - dir = 'resume' - error = error.replace('<', '<').replace('>', '>') - vprint('kernel error found in %s at %f' % (dir, tm)) - self.errorinfo[dir].append((tm, error)) + t = float(m.group('ktime')) + if t < self.start or t > self.end: + continue + if t < self.tSuspended: + dir = 'suspend' + else: + dir = 'resume' + msg = m.group('msg') + if re.match('-*\[ *cut here *\]-*', msg): + type = 'WARNING' + sl = i + elif re.match('genirq: .*', msg): + type = 'IRQ' + sl = i + elif re.match('BUG: .*', msg) or re.match('kernel BUG .*', msg): + type = 'BUG' + sl = i + elif re.match('-*\[ *end trace .*\]-*', msg) or \ + re.match('R13: .*', msg): + if et >= 0 and sl >= 0: + list.append((type, dir, et, sl, i)) self.kerror = True - error = '' + sl = et = el = -1 + type = 'ERROR' + elif 'Call Trace:' in msg: + if el >= 0 and et >= 0: + list.append((type, dir, et, el, el)) + self.kerror = True + et, el = t, i + if sl < 0 or type == 'BUG': + slval = i + if sl >= 0: + slval = sl + list.append((type, dir, et, slval, i)) + self.kerror = True + sl = et = el = -1 + type = 'ERROR' + if el >= 0 and et >= 0: + list.append((type, dir, et, el, el)) + self.kerror = True + for e in list: + type, dir, t, idx1, idx2 = e + sysvals.vprint('kernel %s found in %s at %f' % (type, dir, t)) + self.errorinfo[dir].append((type, t, idx1, idx2)) + if self.kerror: + sysvals.dmesglog = True + lf.close() def setStart(self, time): self.start = time def setEnd(self, time): @@ -867,6 +988,14 @@ class Data: time < d['end']): return False return True + def phaseCollision(self, phase, isbegin, line): + key = 'end' + if isbegin: + key = 'start' + if self.dmesg[phase][key] >= 0: + sysvals.vprint('IGNORE: %s' % line.strip()) + return True + return False def sourcePhase(self, start): for phase in self.phases: pend = self.dmesg[phase]['end'] @@ -918,7 +1047,7 @@ class Data: return self.addDeviceFunctionCall(displayname, kprobename, proc, pid, start, end, cdata, rdata) # this should not happen if not tgtdev: - vprint('[%f - %f] %s-%d %s %s %s' % \ + sysvals.vprint('[%f - %f] %s-%d %s %s %s' % \ (start, end, proc, pid, kprobename, cdata, rdata)) return False # place the call data inside the src element of the tgtdev @@ -1054,6 +1183,13 @@ class Data: if('src' in d): for e in d['src']: e.time = self.trimTimeVal(e.time, t0, dT, left) + for dir in ['suspend', 'resume']: + list = [] + for e in self.errorinfo[dir]: + type, tm, idx1, idx2 = e + tm = self.trimTimeVal(tm, t0, dT, left) + list.append((type, tm, idx1, idx2)) + self.errorinfo[dir] = list def normalizeTime(self, tZero): # trim out any standby or freeze clock time if(self.tSuspended != self.tResumed): @@ -1100,7 +1236,7 @@ class Data: if self.dmesg[p]['end'] > dev['start']: dev['end'] = self.dmesg[p]['end'] break - vprint('%s (%s): callback didnt return' % (devname, phase)) + sysvals.vprint('%s (%s): callback didnt return' % (devname, phase)) def deviceFilter(self, devicefilter): for phase in self.phases: list = self.dmesg[phase]['list'] @@ -1200,15 +1336,15 @@ class Data: devlist.append(child) return devlist def printDetails(self): - vprint('Timeline Details:') - vprint(' test start: %f' % self.start) - vprint('kernel suspend start: %f' % self.tKernSus) + sysvals.vprint('Timeline Details:') + sysvals.vprint(' test start: %f' % self.start) + sysvals.vprint('kernel suspend start: %f' % self.tKernSus) for phase in self.phases: dc = len(self.dmesg[phase]['list']) - vprint(' %16s: %f - %f (%d devices)' % (phase, \ + sysvals.vprint(' %16s: %f - %f (%d devices)' % (phase, \ self.dmesg[phase]['start'], self.dmesg[phase]['end'], dc)) - vprint(' kernel resume end: %f' % self.tKernRes) - vprint(' test end: %f' % self.end) + sysvals.vprint(' kernel resume end: %f' % self.tKernRes) + sysvals.vprint(' test end: %f' % self.end) def deviceChildrenAllPhases(self, devname): devlist = [] for phase in self.phases: @@ -1358,14 +1494,21 @@ class Data: tres.append(t) # process the events for suspend and resume if len(proclist) > 0: - vprint('Process Execution:') + sysvals.vprint('Process Execution:') for ps in proclist: c = self.addProcessUsageEvent(ps, tsus) if c > 0: - vprint('%25s (sus): %d' % (ps, c)) + sysvals.vprint('%25s (sus): %d' % (ps, c)) c = self.addProcessUsageEvent(ps, tres) if c > 0: - vprint('%25s (res): %d' % (ps, c)) + sysvals.vprint('%25s (res): %d' % (ps, c)) + def debugPrint(self): + for p in self.phases: + list = self.dmesg[p]['list'] + for devname in list: + dev = list[devname] + if 'ftrace' in dev: + dev['ftrace'].debugPrint(' [%s]' % devname) # Class: DevFunction # Description: @@ -1504,18 +1647,24 @@ class FTraceLine: # something else (possibly a trace marker) else: self.name = m + def isCall(self): + return self.fcall and not self.freturn + def isReturn(self): + return self.freturn and not self.fcall + def isLeaf(self): + return self.fcall and self.freturn def getDepth(self, str): return len(str)/2 - def debugPrint(self, dev=''): - if(self.freturn and self.fcall): - print('%s -- %f (%02d): %s(); (%.3f us)' % (dev, self.time, \ - self.depth, self.name, self.length*1000000)) - elif(self.freturn): - print('%s -- %f (%02d): %s} (%.3f us)' % (dev, self.time, \ - self.depth, self.name, self.length*1000000)) + def debugPrint(self, info=''): + if self.isLeaf(): + print(' -- %12.6f (depth=%02d): %s(); (%.3f us) %s' % (self.time, \ + self.depth, self.name, self.length*1000000, info)) + elif self.freturn: + print(' -- %12.6f (depth=%02d): %s} (%.3f us) %s' % (self.time, \ + self.depth, self.name, self.length*1000000, info)) else: - print('%s -- %f (%02d): %s() { (%.3f us)' % (dev, self.time, \ - self.depth, self.name, self.length*1000000)) + print(' -- %12.6f (depth=%02d): %s() { (%.3f us) %s' % (self.time, \ + self.depth, self.name, self.length*1000000, info)) def startMarker(self): # Is this the starting line of a suspend? if not self.fevent: @@ -1558,107 +1707,160 @@ class FTraceCallGraph: depth = 0 pid = 0 name = '' - def __init__(self, pid): + partial = False + vfname = 'missing_function_name' + ignore = False + sv = 0 + def __init__(self, pid, sv): self.start = -1.0 self.end = -1.0 self.list = [] self.depth = 0 self.pid = pid - def addLine(self, line, debug=False): + self.sv = sv + def addLine(self, line): # if this is already invalid, just leave if(self.invalid): - return False - # invalidate on too much data or bad depth - if(len(self.list) >= 1000000 or self.depth < 0): + if(line.depth == 0 and line.freturn): + return 1 + return 0 + # invalidate on bad depth + if(self.depth < 0): self.invalidate(line) - return False + return 0 + # ignore data til we return to the current depth + if self.ignore: + if line.depth > self.depth: + return 0 + else: + self.list[-1].freturn = True + self.list[-1].length = line.time - self.list[-1].time + self.ignore = False + # if this is a return at self.depth, no more work is needed + if line.depth == self.depth and line.isReturn(): + if line.depth == 0: + self.end = line.time + return 1 + return 0 # compare current depth with this lines pre-call depth prelinedep = line.depth - if(line.freturn and not line.fcall): + if line.isReturn(): prelinedep += 1 last = 0 lasttime = line.time - virtualfname = 'missing_function_name' if len(self.list) > 0: last = self.list[-1] lasttime = last.time + if last.isLeaf(): + lasttime += last.length # handle low misalignments by inserting returns - if prelinedep < self.depth: - if debug and last: - print '-------- task %d --------' % self.pid - last.debugPrint() + mismatch = prelinedep - self.depth + warning = self.sv.verbose and abs(mismatch) > 1 + info = [] + if mismatch < 0: idx = 0 # add return calls to get the depth down while prelinedep < self.depth: - if debug: - print 'MISALIGN LOW (add returns): C%d - eC%d' % (self.depth, prelinedep) self.depth -= 1 - if idx == 0 and last and last.fcall and not last.freturn: + if idx == 0 and last and last.isCall(): # special case, turn last call into a leaf last.depth = self.depth last.freturn = True last.length = line.time - last.time - if debug: - last.debugPrint() + if warning: + info.append(('[make leaf]', last)) else: vline = FTraceLine(lasttime) vline.depth = self.depth - vline.name = virtualfname + vline.name = self.vfname vline.freturn = True self.list.append(vline) - if debug: - vline.debugPrint() + if warning: + if idx == 0: + info.append(('', last)) + info.append(('[add return]', vline)) idx += 1 - if debug: - line.debugPrint() - print '' + if warning: + info.append(('', line)) # handle high misalignments by inserting calls - elif prelinedep > self.depth: - if debug and last: - print '-------- task %d --------' % self.pid - last.debugPrint() + elif mismatch > 0: idx = 0 + if warning: + info.append(('', last)) # add calls to get the depth up while prelinedep > self.depth: - if debug: - print 'MISALIGN HIGH (add calls): C%d - eC%d' % (self.depth, prelinedep) - if idx == 0 and line.freturn and not line.fcall: + if idx == 0 and line.isReturn(): # special case, turn this return into a leaf line.fcall = True prelinedep -= 1 + if warning: + info.append(('[make leaf]', line)) else: vline = FTraceLine(lasttime) vline.depth = self.depth - vline.name = virtualfname + vline.name = self.vfname vline.fcall = True - if debug: - vline.debugPrint() self.list.append(vline) self.depth += 1 if not last: self.start = vline.time + if warning: + info.append(('[add call]', vline)) idx += 1 - if debug: - line.debugPrint() - print '' + if warning and ('[make leaf]', line) not in info: + info.append(('', line)) + if warning: + print 'WARNING: ftrace data missing, corrections made:' + for i in info: + t, obj = i + if obj: + obj.debugPrint(t) # process the call and set the new depth - if(line.fcall and not line.freturn): - self.depth += 1 - elif(line.freturn and not line.fcall): + skipadd = False + md = self.sv.max_graph_depth + if line.isCall(): + # ignore blacklisted/overdepth funcs + if (md and self.depth >= md - 1) or (line.name in self.sv.cgblacklist): + self.ignore = True + else: + self.depth += 1 + elif line.isReturn(): self.depth -= 1 + # remove blacklisted/overdepth/empty funcs that slipped through + if (last and last.isCall() and last.depth == line.depth) or \ + (md and last and last.depth >= md) or \ + (line.name in self.sv.cgblacklist): + while len(self.list) > 0 and self.list[-1].depth > line.depth: + self.list.pop(-1) + if len(self.list) == 0: + self.invalid = True + return 1 + self.list[-1].freturn = True + self.list[-1].length = line.time - self.list[-1].time + self.list[-1].name = line.name + skipadd = True if len(self.list) < 1: self.start = line.time - self.list.append(line) + # check for a mismatch that returned all the way to callgraph end + res = 1 + if mismatch < 0 and self.list[-1].depth == 0 and self.list[-1].freturn: + line = self.list[-1] + skipadd = True + res = -1 + if not skipadd: + self.list.append(line) if(line.depth == 0 and line.freturn): if(self.start < 0): self.start = line.time self.end = line.time if line.fcall: self.end += line.length - if self.list[0].name == virtualfname: + if self.list[0].name == self.vfname: self.invalid = True - return True - return False + if res == -1: + self.partial = True + return res + return 0 def invalidate(self, line): if(len(self.list) > 0): first = self.list[0] @@ -1668,29 +1870,30 @@ class FTraceCallGraph: id = 'task %s' % (self.pid) window = '(%f - %f)' % (self.start, line.time) if(self.depth < 0): - vprint('Too much data for '+id+\ + print('Data misalignment for '+id+\ ' (buffer overflow), ignoring this callback') else: - vprint('Too much data for '+id+\ + print('Too much data for '+id+\ ' '+window+', ignoring this callback') - def slice(self, t0, tN): - minicg = FTraceCallGraph(0) - count = -1 - firstdepth = 0 + def slice(self, dev): + minicg = FTraceCallGraph(dev['pid'], self.sv) + minicg.name = self.name + mydepth = -1 + good = False for l in self.list: - if(l.time < t0 or l.time > tN): + if(l.time < dev['start'] or l.time > dev['end']): continue - if(count < 0): - if(not l.fcall or l.name == 'dev_driver_string'): - continue - firstdepth = l.depth - count = 0 - l.depth -= firstdepth - minicg.addLine(l) - if((count == 0 and l.freturn and l.fcall) or - (count > 0 and l.depth <= 0)): + if mydepth < 0: + if l.name == 'mutex_lock' and l.freturn: + mydepth = l.depth + continue + elif l.depth == mydepth and l.name == 'mutex_unlock' and l.fcall: + good = True break - count += 1 + l.depth -= mydepth + minicg.addLine(l) + if not good or len(minicg.list) < 1: + return 0 return minicg def repair(self, enddepth): # bring the depth back to 0 with additional returns @@ -1701,11 +1904,11 @@ class FTraceCallGraph: t.depth = i t.freturn = True fixed = self.addLine(t) - if fixed: + if fixed != 0: self.end = last.time return True return False - def postProcess(self, debug=False): + def postProcess(self): if len(self.list) > 0: self.name = self.list[0].name stack = dict() @@ -1714,20 +1917,23 @@ class FTraceCallGraph: for l in self.list: # ftrace bug: reported duration is not reliable # check each leaf and clip it at max possible length - if(last and last.freturn and last.fcall): + if last and last.isLeaf(): if last.length > l.time - last.time: last.length = l.time - last.time - if(l.fcall and not l.freturn): + if l.isCall(): stack[l.depth] = l cnt += 1 - elif(l.freturn and not l.fcall): + elif l.isReturn(): if(l.depth not in stack): - if debug: + if self.sv.verbose: print 'Post Process Error: Depth missing' l.debugPrint() return False # calculate call length from call/return lines - stack[l.depth].length = l.time - stack[l.depth].time + cl = stack[l.depth] + cl.length = l.time - cl.time + if cl.name == self.vfname: + cl.name = l.name stack.pop(l.depth) l.length = 0 cnt -= 1 @@ -1736,13 +1942,13 @@ class FTraceCallGraph: # trace caught the whole call tree return True elif(cnt < 0): - if debug: + if self.sv.verbose: print 'Post Process Error: Depth is less than 0' return False # trace ended before call tree finished return self.repair(cnt) def deviceMatch(self, pid, data): - found = False + found = '' # add the callgraph data to the device hierarchy borderphase = { 'dpm_prepare': 'suspend_prepare', @@ -1756,8 +1962,10 @@ class FTraceCallGraph: if(pid == dev['pid'] and self.start <= dev['start'] and self.end >= dev['end']): - dev['ftrace'] = self.slice(dev['start'], dev['end']) - found = True + cg = self.slice(dev) + if cg: + dev['ftrace'] = cg + found = devname return found for p in data.phases: if(data.dmesg[p]['start'] <= self.start and @@ -1769,7 +1977,7 @@ class FTraceCallGraph: self.start <= dev['start'] and self.end >= dev['end']): dev['ftrace'] = self - found = True + found = devname break break return found @@ -1793,18 +2001,20 @@ class FTraceCallGraph: if out: phase, myname = out data.dmesg[phase]['list'][myname]['ftrace'] = self - def debugPrint(self): - print('[%f - %f] %s (%d)') % (self.start, self.end, self.name, self.pid) + def debugPrint(self, info=''): + print('%s pid=%d [%f - %f] %.3f us') % \ + (self.name, self.pid, self.start, self.end, + (self.end - self.start)*1000000) for l in self.list: - if(l.freturn and l.fcall): - print('%f (%02d): %s(); (%.3f us)' % (l.time, \ - l.depth, l.name, l.length*1000000)) - elif(l.freturn): - print('%f (%02d): %s} (%.3f us)' % (l.time, \ - l.depth, l.name, l.length*1000000)) + if l.isLeaf(): + print('%f (%02d): %s(); (%.3f us)%s' % (l.time, \ + l.depth, l.name, l.length*1000000, info)) + elif l.freturn: + print('%f (%02d): %s} (%.3f us)%s' % (l.time, \ + l.depth, l.name, l.length*1000000, info)) else: - print('%f (%02d): %s() { (%.3f us)' % (l.time, \ - l.depth, l.name, l.length*1000000)) + print('%f (%02d): %s() { (%.3f us)%s' % (l.time, \ + l.depth, l.name, l.length*1000000, info)) print(' ') class DevItem: @@ -1839,8 +2049,8 @@ class Timeline: self.rowH = rowheight self.scaleH = scaleheight self.html = '' - def createHeader(self, sv): - if(not sv.stamp['time']): + def createHeader(self, sv, stamp): + if(not stamp['time']): return self.html += '
%s v%s
' \ % (sv.title, sv.version) @@ -1851,12 +2061,12 @@ class Timeline: if sv.ftracelog: self.html += '' headline_stamp = '
{0} {1} {2} {3}
\n' - self.html += headline_stamp.format(sv.stamp['host'], sv.stamp['kernel'], - sv.stamp['mode'], sv.stamp['time']) - if 'man' in sv.stamp and 'plat' in sv.stamp and 'cpu' in sv.stamp: + self.html += headline_stamp.format(stamp['host'], stamp['kernel'], + stamp['mode'], stamp['time']) + if 'man' in stamp and 'plat' in stamp and 'cpu' in stamp and \ + stamp['man'] and stamp['plat'] and stamp['cpu']: headline_sysinfo = '
{0} {1} with {2}
\n' - self.html += headline_sysinfo.format(sv.stamp['man'], - sv.stamp['plat'], sv.stamp['cpu']) + self.html += headline_sysinfo.format(stamp['man'], stamp['plat'], stamp['cpu']) # Function: getDeviceRows # Description: @@ -2067,12 +2277,16 @@ class Timeline: class TestProps: stamp = '' sysinfo = '' + cmdline = '' + kparams = '' S0i3 = False fwdata = [] stampfmt = '# [a-z]*-(?P[0-9]{2})(?P[0-9]{2})(?P[0-9]{2})-'+\ '(?P[0-9]{2})(?P[0-9]{2})(?P[0-9]{2})'+\ ' (?P.*) (?P.*) (?P.*)$' sysinfofmt = '^# sysinfo .*' + cmdlinefmt = '^# command \| (?P.*)' + kparamsfmt = '^# kparams \| (?P.*)' ftrace_line_fmt_fg = \ '^ *(?P