[hide]

1 PM debug and profiling

[edit] PM debug and profiling

[edit] Tracing of clock and power domains events

The perf and ftrace frameworks are used to generate the following events:

cpuidle transitions to and from idle,
system suspend,
individual clocks enable, disable and set_rate,
cpufreq/DVFS transitions,
power domain transitions,
low power mode entry/exit latency profiling.

Cf. the patch/RFC in the links here below for details.

Patches submissions:

Initial discussion on LKML: cf. [1].
Power trace API rework + use of the tracepoints for ARM/OMAP: submitted to the LKML, cf. [4].

[edit] Links

[1] http://marc.info/?l=linux-kernel&m=128195697205096&w=4 : patch proposal on LKML
[2] http://omappedia.org/wiki/Power_Management_Debug_and_Profiling : PM Debug and Profiling wiki page
[3] http://git.kernel.org/?p=linux/kernel/git/x86/linux-2.6-tip.git;a=commitdiff;h=74704ac6ea402d50c9543cb28247e6d9f521f7ae
[4] http://marc.info/?l=linux-omap&m=128620574100676&w=2 : re-spin of LKML patches (also cf. the 3 following patches).

[edit] On-going activities

profile the low level ASM code for OMAP. The 32K timer clock needs to be enabled soon in the wake-up path to allow the tracing deep in the idle/suspend paths.
pytimechart needs some changes to display the new PM events correctly, with the correct parameters (i.e. clock names for the clock_enable and clock_disable events...) => proposed patch at File:Clock power.patch.gz, to be submitted once kernel change are accepted.
add low power transition code events for fine profiling: LOW_POWER_ENTER/LOW_POWER_EXIT or POWER_ASLEEP/POWER_WAKEN?
add low power transition code path latency stats in pytimechart => prototype ready, cf. screenshot here below.
various pytimechart bugfixes and re-write => 2 patches merged in, cf. http://gitorious.com/pytimechart/pytimechart/commits/master
other tools: cpufrequtils, powertop... ?

[edit] Compilation and usage

Starting from the pm branch of Tony's tree (at http://git.kernel.org/?p=linux/kernel/git/tmlind/linux-omap-2.6.git), the submitted patch needs to be applied in order to get support for the new events and the OMAP specific trace points.

The config in use is omap3_pm_defconfig, with the following extra options to be enabled:

CONFIG_PERF_EVENTS=y
CONFIG_TRACEPOINTS=y
CONFIG_HW_PERF_EVENTS=y
CONFIG_EVENT_TRACING=y
CONFIG_ENABLE_DEFAULT_TRACERS=y
CONFIG_TRACING=y
CONFIG_GENERIC_TRACER=y
CONFIG_TRACING_SUPPORT=y
CONFIG_FTRACE=y

[edit] Userspace filesystem

The filesystem archive File:Arago-console-image-omap3evm.tar.gz contains the necessary power management related utilities (cpufreq, perf) as well as a few useful utilities (bash, sshd).

More info at http://arago-project.org/wiki/index.php/Setting_Up_Build_Environment.

To add the perf tool to the build, a new recipe must be added and a few patches to the arago and arago-oe-dev trees are needed:

1: Apply the following patch in arago

diff --git a/recipes/images/arago-image.inc b/recipes/images/arago-image.incindex 022df8c..06594b1 100644--- a/recipes/images/arago-image.inc+++ b/recipes/images/arago-image.inc@@ -8,7 +8,7 @@ EXTRA_IMAGECMD_ext2.gz += "-i 4096"  IMAGE_PREPROCESS_COMMAND = "create_etc_timestamp" -IMAGE_INSTALL = "+IMAGE_INSTALL += "     ${DISTRO_SSH_DAEMON}      angstrom-version      "

2: Apply the following changes in arago-oe-dev:

2.1: Patch to kernel.bbclass, in order to export ('stage') the perf source code

diff --git a/classes/kernel.bbclass b/classes/kernel.bbclassindex 9555f30..3636d46 100644--- a/classes/kernel.bbclass+++ b/classes/kernel.bbclass@@ -156,7 +156,7 @@ kernel_do_install() {        mkdir -p $kerneldir/include/asm-generic        cp -fR include/asm-generic/* $kerneldir/include/asm-generic/ -       for entry in drivers/crypto drivers/media include/generated include/linux include/net include/pcmcia include/media include/acpi include/sound include/video include/scsi include/trace include/mtd include/rdma include/drm include/xen; do+       for entry in drivers/crypto drivers/media include/generated include/linux include/net include/pcmcia include/media include/acpi include/sound include/video include/scsi include/trace include/mtd include/rdma include/drm include/xen tools/perf lib; do                if [ -d $entry ]; then                        mkdir -p $kerneldir/$entry                        cp -fR $entry/* $kerneldir/$entry/

2.2: Patch to the linux kernel code, in order to provide a missing typedef

diff --git a/recipes/linux/files/tools-perf-add-the-definition-of-GElf_Nhdr.patch b/recipes/linux/files/tools-perf-add-the-definition-of-GElf_Nhdr.patchnew file mode 100644index 0000000..7d86a95--- /dev/null+++ b/recipes/linux/files/tools-perf-add-the-definition-of-GElf_Nhdr.patch@@ -0,0 +1,43 @@+From 1af04619368f87bf518d8ed9c7f18e7d1eaf74c4 Mon Sep 17 00:00:00 2001+From: Jean Pihet <jean.pihet@newoldbits.com>+Date: Thu, 23 Sep 2010 10:23:19 +0200+Subject: [PATCH] tools/perf: add the definition of GElf_Nhdr++Signed-off-by: Jean Pihet <j-pihet@ti.com>+---+ tools/perf/util/gelf.h   |   10 +++++++++++ tools/perf/util/symbol.h |    1 ++ 2 files changed, 11 insertions(+), 0 deletions(-)+ create mode 100644 tools/perf/util/gelf.h++diff --git a/tools/perf/util/gelf.h b/tools/perf/util/gelf.h+new file mode 100644+index 0000000..27dfd03+--- /dev/null++++ b/tools/perf/util/gelf.h+@@ -0,0 +1,10 @@++#ifndef __GELF_NHDR__++#include <libelf.h>++#include <gelf.h>++++#if __LIBELF64++typedef Elf64_Nhdr GElf_Nhdr;++#else++typedef Elf32_Nhdr GElf_Nhdr;++#endif++#endif+diff --git a/tools/perf/util/symbol.h b/tools/perf/util/symbol.h+index b7a8da4..b5424d8 100644+--- a/tools/perf/util/symbol.h++++ b/tools/perf/util/symbol.h+@@ -8,6 +8,7 @@+ #include <linux/list.h>+ #include <linux/rbtree.h>+ #include <stdio.h>++#include "gelf.h"+ + #ifdef HAVE_CPLUS_DEMANGLE+ extern char *cplus_demangle(const char *, int);+-- +1.7.1+

2.3: Patch to the kernel recipe, in order to use the new patch

diff --git a/recipes/linux/linux_2.6.35.bb b/recipes/linux/linux_2.6.35.bbindex 8765846..b5813ac 100644--- a/recipes/linux/linux_2.6.35.bb+++ b/recipes/linux/linux_2.6.35.bb@@ -10,7 +10,8 @@ DEFAULT_PREFERENCE_simone = "1" SRC_URI = "${KERNELORG_MIRROR}/pub/linux/kernel/v2.6/${P}.tar.bz2;name=kernel             ${KERNELORG_MIRROR}/pub/linux/kernel/v2.6/patch-${PV}.1.bz2;apply=yes;name=stablepatch             file://fix.module.loading.16310.patch -           file://defconfig "+           file://defconfig +           file://tools-perf-add-the-definition-of-GElf_Nhdr.patch "  SRC_URI_append_dockstar = "file://dockstar.patch" SRC_URI_append_rx1950 = "file://0001-s3c2410_ts-add-fake-pressure-events.patch

2.4: Patch to the util-linux-ng recipe (build failure fix)

diff --git a/recipes/util-linux-ng/util-linux-ng.inc b/recipes/util-linux-ng/util-linux-ng.incindex ca0790e..4826295 100644--- a/recipes/util-linux-ng/util-linux-ng.inc+++ b/recipes/util-linux-ng/util-linux-ng.inc@@ -11,7 +11,7 @@ DEFAULT_PREFERENCE = "-1" INC_PR = "r28"  # allows for a release candidate-RC ?= ""+RC ?= "-arago1"  SRC_URI = "${KERNELORG_MIRROR}/pub/linux/utils/util-linux-ng/v${PV}/util-linux-ng-${PV}${RC}.tar.bz2;name=archive"

2.5: Add the linux-perf.bb recipe

diff --git a/recipes/linux/linux-perf.bb b/recipes/linux/linux-perf.bbnew file mode 100644index 0000000..f3dcf62--- /dev/null+++ b/recipes/linux/linux-perf.bb@@ -0,0 +1,24 @@+DESCRIPTION = "Linux perf tracing tool"+LICENSE = "GPL"++PR = "r0"+DEPENDS = "linux libelf"+RDEPENDS_${PN} = "libelf"++S = "${WORKDIR}"+SRC_URI_append = "file://tools-perf-add-the-definition-of-GElf_Nhdr.patch"++PACKAGE_ARCH="${MACHINE_ARCH}"++do_compile() {+        oe_runmake -C ${STAGING_KERNEL_DIR}/tools/perf NO_LIBPERL=1 V=1+}++do_install() {+        oe_runmake -C ${STAGING_KERNEL_DIR}/tools/perf DESTDIR="${D}" install+}++do_stage () {+        :+}+

A few extra packages have been added by adding the following to arago/conf/local.conf

IMAGE_INSTALL += " bash sshd linux-perf cpufrequtils"

The filesystem has been built using Arago's arago-console-image task, a lot of patience and perferably a few GB's of RAM ;p

MACHINE=omap3evm bitbake arago-console-image

Here we go with the login invitation!!

 _____                    _____           _         _   |  _  |___ ___ ___ ___   |  _  |___ ___  |_|___ ___| |_ |     |  _| .'| . | . |  |   __|  _| . | | | -_|  _|  _||__|__|_| |__,|_  |___|  |__|  |_| |___|_| |___|___|_|                |___|                    |___|            Arago Project http://arago-project.org omap3evm ttyS0Arago 2010.07 omap3evm ttyS0omap3evm login:

Note about the kernel: Arago builds the TI PSP kernel for OMAP. The kernel used for PM Debug and Profiling comes from the pm branch of Tony's git tree.

[edit] Tracing instructions

[edit] Mounting debugfs

# mount -t debugfs nodev /sys/kernel/debug/

[edit] Enabling power events

Enabling all power events

# echo 1 > /sys/kernel/debug/tracing/events/power/enable

Per event enabling/disabling

# echo 1 > /sys/kernel/debug/tracing/events/power/power_end/enable# echo 0 > /sys/kernel/debug/tracing/events/power/power_end/enable

Optionally the scheduling events can be enabled, in order to get the details on the CPU activity

# echo 1 > /sys/kernel/debug/tracing/events/sched/enable

[edit] Dump trace

Consuming events from the ring buffer

# cat /sys/kernel/debug/tracing/trace_pipe

Dump of the buffer, non comsuming

# cat /sys/kernel/debug/tracing/trace

[edit] PM specific commands reference

[edit] cpuidle

# echo 5 > /sys/devices/platform/serial8250.0/sleep_timeout # echo 5 > /sys/devices/platform/serial8250.1/sleep_timeout # echo 5 > /sys/devices/platform/serial8250.2/sleep_timeout # echo 1 > /sys/kernel/debug/pm_debug/sleep_while_idle# echo 1 > /sys/kernel/debug/pm_debug/enable_off_mode# uptime 06:33:42 up 15:35, load average: 0.88, 0.86, 0.70# cat /sys/kernel/debug/pm_debug/countusbhost_pwrdm (OFF),OFF:1,RET:1,INA:0,ON:1,RET-LOGIC-OFF:0,RET-MEMBANK1-OFF:0sgx_pwrdm (OFF),OFF:1,RET:0,INA:0,ON:1,RET-LOGIC-OFF:0,RET-MEMBANK1-OFF:0per_pwrdm (ON),OFF:89107,RET:14182,INA:0,ON:103290,RET-LOGIC-OFF:0,RET-MEMBANK1-OFF:0dss_pwrdm (OFF),OFF:1,RET:1,INA:0,ON:1,RET-LOGIC-OFF:0,RET-MEMBANK1-OFF:0cam_pwrdm (OFF),OFF:1,RET:1,INA:0,ON:1,RET-LOGIC-OFF:0,RET-MEMBANK1-OFF:0core_pwrdm (ON),OFF:57359,RET:31776,INA:0,ON:89136,RET-LOGIC-OFF:0,RET-MEMBANK1-OFF:0,RET-MEMBANK2-OFF:0neon_pwrdm (ON),OFF:93707,RET:9496,INA:240,ON:103444,RET-LOGIC-OFF:0mpu_pwrdm (ON),OFF:93707,RET:9496,INA:240,ON:103444,RET-LOGIC-OFF:0,RET-MEMBANK1-OFF:0iva2_pwrdm (OFF),OFF:1,RET:1,INA:0,ON:1,RET-LOGIC-OFF:0,RET-MEMBANK1-OFF:0,RET-MEMBANK2-OFF:0,RET-MEMBANK3-OFF:0,RET-MEMBANK4-OFF:0per_clkdm->per_pwrdm (11)usbhost_clkdm->usbhost_pwrdm (0)cam_clkdm->cam_pwrdm (0)dss_clkdm->dss_pwrdm (0)core_l4_clkdm->core_pwrdm (8)core_l3_clkdm->core_pwrdm (4)d2d_clkdm->core_pwrdm (0)sgx_clkdm->sgx_pwrdm (0)iva2_clkdm->iva2_pwrdm (0)neon_clkdm->neon_pwrdm (0)mpu_clkdm->mpu_pwrdm (0)prm_clkdm->wkup_pwrdm (0)cm_clkdm->core_pwrdm (0)# cat /sys/kernel/debug/pm_debug/time usbhost_pwrdm (OFF),OFF:55673971160888,RET:477995910645,INA:0,ON:687805175sgx_pwrdm (OFF),OFF:56151967041016,RET:0,INA:0,ON:687866210per_pwrdm (ON),OFF:54581824584529,RET:889348693710,INA:0,ON:681481628987dss_pwrdm (OFF),OFF:55673971282959,RET:477967254639,INA:0,ON:716400146cam_pwrdm (OFF),OFF:55673971282959,RET:477967376709,INA:0,ON:716278076core_pwrdm (ON),OFF:49292550109366,RET:5300081390665,INA:0,ON:1560023437713neon_pwrdm (ON),OFF:54474985870229,RET:994778198203,INA:532592784,ON:682358307045mpu_pwrdm (ON),OFF:54475175811532,RET:994814758256,INA:533477796,ON:682130920677iva2_pwrdm (OFF),OFF:55673971405029,RET:477995727540,INA:0,ON:687866210

[edit] cpufreq/DVFS

# echo 550000 > /sys/devices/system/cpu/cpu0/cpufreq/scaling_setspeed# echo 500000 > /sys/devices/system/cpu/cpu0/cpufreq/scaling_setspeed# echo 250000 > /sys/devices/system/cpu/cpu0/cpufreq/scaling_setspeed# echo ondemand > /sys/devices/system/cpu/cpu0/cpufreq/scaling_governor

[edit] Trace logs

Test setup:
- on-demand DVFS,
- 5s timeout on UARTs,
- sleep_while_idle=1,
- enable_off_mode=1.

# cat /sys/kernel/debug/tracing/trace# tracer: nop##           TASK-PID    CPU#    TIMESTAMP  FUNCTION#              | |       |          |         |          <idle>-0     [000]  1606.593781: power_start: type=1 state=1                       <= Here starts the idle loop                     <idle>-0     [000]  1606.593781: power_domain_transition: mpu_pwrdm state=0         |  Power domain transition, MPU domain to target state OFF          <idle>-0     [000]  1606.593781: power_domain_transition: core_pwrdm state=1        |  Power domain transition, CORE domain to target state RET          <idle>-0     [000]  1606.593842: power_domain_transition: neon_pwrdm state=0        |  Power domain transition, NEON domain to target state OFF          <idle>-0     [000]  1606.593872: clock_disable: gpio6_dbck state=0                  |  Clock gpio6_dbck disable          <idle>-0     [000]  1606.593903: clock_disable: uart3_ick state=0                   |  ...          <idle>-0     [000]  1606.593903: clock_disable: uart3_fck state=0                   |  All UARTs clocks disable          <idle>-0     [000]  1606.593903: clock_disable: uart1_ick state=0                   |  ...          <idle>-0     [000]  1606.593903: clock_disable: uart1_fck state=0                   |          <idle>-0     [000]  1606.593933: clock_disable: uart2_ick state=0                   |          <idle>-0     [000]  1606.593933: clock_disable: uart2_fck state=0                   |          <idle>-0     [000]  1606.640106: clock_enable: uart1_ick state=1                    |  All UARTs clocks enable          <idle>-0     [000]  1606.640137: clock_enable: uart1_fck state=1                    |  ...          <idle>-0     [000]  1606.640228: clock_enable: uart2_ick state=1                    |          <idle>-0     [000]  1606.640228: clock_enable: uart2_fck state=1                    |          <idle>-0     [000]  1606.640259: clock_enable: gpio6_dbck state=1                   |          <idle>-0     [000]  1606.640259: clock_enable: uart3_ick state=1                    |          <idle>-0     [000]  1606.640259: clock_enable: uart3_fck state=1                    |          <idle>-0     [000]  1606.640564: power_end: dummy=65535                            <= Here ends the idle loop     kondemand/0-404   [000]  1606.640717: power_frequency: type=2 state=125000000           <= DVFS event triggered by the on-demand governor, MPU freq=125MHz     kondemand/0-404   [000]  1606.640778: clock_set_rate: dpll3_m2_ck state=166000000        |  Clock tree updates: dpll3_m2 to 166MHz     kondemand/0-404   [000]  1606.641144: clock_set_rate: dpll1_ck state=125000000           |                      dpll1 to 125MHz     kondemand/0-404   [000]  1606.641357: clock_set_rate: dpll2_ck state=90000000            |                      dpll2 to 90MHz          <idle>-0     [000]  1606.642914: power_start: type=1 state=1                       <= End of DVFS, idle loop entry           <idle>-0     [000]  1606.642914: power_domain_transition: mpu_pwrdm state=0          <idle>-0     [000]  1606.642944: power_domain_transition: core_pwrdm state=3          <idle>-0     [000]  1606.643127: power_domain_transition: neon_pwrdm state=0          <idle>-0     [000]  1606.643158: clock_disable: gpio6_dbck state=0          <idle>-0     [000]  1606.643188: power_domain_transition: per_pwrdm state=1          <idle>-0     [000]  1606.643219: clock_disable: uart3_ick state=0          <idle>-0     [000]  1606.643250: clock_disable: uart3_fck state=0          <idle>-0     [000]  1606.654236: clock_enable: gpio6_dbck state=1          <idle>-0     [000]  1606.654266: clock_enable: uart3_ick state=1          <idle>-0     [000]  1606.654266: clock_enable: uart3_fck state=1          <idle>-0     [000]  1606.654297: power_domain_transition: per_pwrdm state=0          <idle>-0     [000]  1606.654846: power_end: dummy=65535          <idle>-0     [000]  1606.677887: power_start: type=1 state=1          <idle>-0     [000]  1606.677948: power_domain_transition: mpu_pwrdm state=3          <idle>-0     [000]  1606.677948: power_domain_transition: core_pwrdm state=3          <idle>-0     [000]  1606.678131: power_domain_transition: neon_pwrdm state=3          <idle>-0     [000]  1606.678192: clock_disable: gpio6_dbck state=0          <idle>-0     [000]  1606.678223: power_domain_transition: per_pwrdm state=1          <idle>-0     [000]  1606.678253: clock_disable: uart3_ick state=0          <idle>-0     [000]  1606.678253: clock_disable: uart3_fck state=0          <idle>-0     [000]  1606.678314: clock_enable: gpio6_dbck state=1          <idle>-0     [000]  1606.678345: clock_enable: uart3_ick state=1          <idle>-0     [000]  1606.678375: clock_enable: uart3_fck state=1          <idle>-0     [000]  1606.678406: power_domain_transition: per_pwrdm state=0          <idle>-0     [000]  1606.678925: power_end: dummy=65535          <idle>-0     [000]  1606.682739: power_start: type=1 state=1          <idle>-0     [000]  1606.682770: power_domain_transition: mpu_pwrdm state=0          <idle>-0     [000]  1606.682800: power_domain_transition: core_pwrdm state=1          <idle>-0     [000]  1606.682953: power_domain_transition: neon_pwrdm state=0          <idle>-0     [000]  1606.683014: clock_disable: gpio6_dbck state=0          <idle>-0     [000]  1606.683105: clock_disable: uart3_ick state=0          <idle>-0     [000]  1606.683105: clock_disable: uart3_fck state=0          <idle>-0     [000]  1606.683136: clock_disable: uart1_ick state=0          <idle>-0     [000]  1606.683167: clock_disable: uart1_fck state=0          <idle>-0     [000]  1606.683197: clock_disable: uart2_ick state=0          <idle>-0     [000]  1606.683197: clock_disable: uart2_fck state=0          <idle>-0     [000]  1606.767761: clock_enable: uart1_ick state=1          <idle>-0     [000]  1606.767822: clock_enable: uart1_fck state=1          <idle>-0     [000]  1606.767975: clock_enable: uart2_ick state=1          <idle>-0     [000]  1606.768005: clock_enable: uart2_fck state=1          <idle>-0     [000]  1606.768066: clock_enable: gpio6_dbck state=1          <idle>-0     [000]  1606.768097: clock_enable: uart3_ick state=1          <idle>-0     [000]  1606.768097: clock_enable: uart3_fck state=1          <idle>-0     [000]  1606.768921: power_end: dummy=65535...     kondemand/0-404   [000]  2043.842743: power_frequency: type=2 state=600000000     kondemand/0-404   [000]  2043.843628: clock_set_rate: dpll1_ck state=600000000     kondemand/0-404   [000]  2043.843903: clock_set_rate: dpll2_ck state=430000000     kondemand/0-404   [000]  2043.844299: clock_set_rate: dpll3_m2_ck state=332000000

Test setup:
- on-demand DVFS,
- 5s timeout on UARTs,
- sleep_while_idle=1,
- enable_off_mode=1,
- triggering a suspend.

# echo mem > /sys/power/statePM: Syncing filesystems ... done.Freezing user space processes ... (elapsed 0.01 seconds) done.Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.Suspending console(s) (use no_console_suspend to debug)PM: suspend of devices complete after 8.514 msecsPM: late suspend of devices complete after 3.112 msecsSuccessfully put all powerdomains to target statePM: early resume of devices complete after 0.457 msecsPM: resume of devices complete after 9.918 msecsRestarting tasks ... done.# cat /sys/kernel/debug/tracing/trace# tracer: nop##           TASK-PID    CPU#    TIMESTAMP  FUNCTION#              | |       |          |         |          <idle>-0     [000]  2153.873413: power_start: type=1 state=1                       <= Here starts the idle loop          <idle>-0     [000]  2153.873444: power_domain_transition: mpu_pwrdm state=3         |  Power domain transition, MPU domain to target state ON          <idle>-0     [000]  2153.873474: power_domain_transition: core_pwrdm state=3        |  Power domain transition, CORE domain to target state ON          <idle>-0     [000]  2153.873688: power_domain_transition: neon_pwrdm state=3        |  Power domain transition, NEON domain to target state ON          <idle>-0     [000]  2153.873749: clock_disable: gpio6_dbck state=0                  |  Clock gpio6_dbck disable          <idle>-0     [000]  2153.873749: power_domain_transition: per_pwrdm state=1         |  ...          <idle>-0     [000]  2153.873779: clock_disable: uart3_ick state=0                   |          <idle>-0     [000]  2153.873810: clock_disable: uart3_fck state=0                   |          <idle>-0     [000]  2153.889099: clock_enable: gpio6_dbck state=1                   |          <idle>-0     [000]  2153.889130: clock_enable: uart3_ick state=1                    |  Clock uart3_ick enable          <idle>-0     [000]  2153.889130: clock_enable: uart3_fck state=1                    |          <idle>-0     [000]  2153.889160: power_domain_transition: per_pwrdm state=0         |          <idle>-0     [000]  2153.889740: power_end: dummy=65535                            <= Here ends the idle loop              sh-1148  [000]  2153.915649: power_domain_transition: mpu_pwrdm state=0        <= Suspend entry: all power domains to OFF              sh-1148  [000]  2153.915710: power_domain_transition: neon_pwrdm state=0        |              sh-1148  [000]  2153.915741: power_domain_transition: core_pwrdm state=0        |              sh-1148  [000]  2153.915771: power_start: type=3 state=0                        |  state=0: suspend entry              sh-1148  [000]  2153.915985: power_domain_transition: neon_pwrdm state=0        |  ...              sh-1148  [000]  2153.916016: clock_disable: gpio6_dbck state=0                  |  Clocks disable              sh-1148  [000]  2153.916138: clock_disable: uart3_ick state=0                   |  ...              sh-1148  [000]  2153.916138: clock_disable: uart3_fck state=0                   |              sh-1148  [000]  2153.916199: clock_disable: uart1_ick state=0                   |              sh-1148  [000]  2153.916199: clock_disable: uart1_fck state=0                   |              sh-1148  [000]  2153.916229: clock_disable: uart2_ick state=0                   |              sh-1148  [000]  2153.916260: clock_disable: uart2_fck state=0                   | Board frozen for ~10s ...              sh-1148  [000]  2164.128876: clock_enable: hsotgusb_ick state=1                 | Resuming from deep sleep, enabling clocks              sh-1148  [000]  2164.128967: clock_disable: hsotgusb_ick state=0                | ...              sh-1148  [000]  2164.128998: clock_enable: uart1_ick state=1                    |              sh-1148  [000]  2164.129028: clock_enable: uart1_fck state=1                    |              sh-1148  [000]  2164.129150: clock_enable: uart2_ick state=1                    |              sh-1148  [000]  2164.129181: clock_enable: uart2_fck state=1                    |              sh-1148  [000]  2164.129272: clock_enable: gpio6_dbck state=1                   |              sh-1148  [000]  2164.129303: clock_enable: uart3_ick state=1                    |              sh-1148  [000]  2164.129333: clock_enable: uart3_fck state=1                    |              sh-1148  [000]  2164.129608: power_domain_transition: mpu_pwrdm state=3         |  Power domain transition, MPU domain to target state ON              sh-1148  [000]  2164.129639: power_domain_transition: neon_pwrdm state=3        |  Power domain transition, NEON domain to target state ON              sh-1148  [000]  2164.129669: power_domain_transition: core_pwrdm state=3        |  Power domain transition, CORE domain to target state ON.          <idle>-0     [000]  2164.270233: power_start: type=1 state=1                       <= System fully awake, idle loop entry          <idle>-0     [000]  2164.270294: power_domain_transition: mpu_pwrdm state=3         |  ...          <idle>-0     [000]  2164.270325: power_domain_transition: core_pwrdm state=3          <idle>-0     [000]  2164.270538: power_domain_transition: neon_pwrdm state=3          <idle>-0     [000]  2164.270569: clock_disable: gpio6_dbck state=0          <idle>-0     [000]  2164.270599: power_domain_transition: per_pwrdm state=1          <idle>-0     [000]  2164.270660: clock_disable: uart3_ick state=0          <idle>-0     [000]  2164.270660: clock_disable: uart3_fck state=0          <idle>-0     [000]  2164.275848: clock_enable: gpio6_dbck state=1          <idle>-0     [000]  2164.275879: clock_enable: uart3_ick state=1          <idle>-0     [000]  2164.275909: clock_enable: uart3_fck state=1          <idle>-0     [000]  2164.275940: power_domain_transition: per_pwrdm state=0         | ...          <idle>-0     [000]  2164.276642: power_end: dummy=65535                            <= Idle loop ends...          <idle>-0     [000]  2167.608856: power_start: type=1 state=1          <idle>-0     [000]  2167.608887: power_domain_transition: mpu_pwrdm state=3          <idle>-0     [000]  2167.608887: power_domain_transition: core_pwrdm state=3          <idle>-0     [000]  2167.609131: power_domain_transition: neon_pwrdm state=3          <idle>-0     [000]  2167.609161: clock_disable: gpio6_dbck state=0          <idle>-0     [000]  2167.609192: power_domain_transition: per_pwrdm state=1          <idle>-0     [000]  2167.609222: clock_disable: uart3_ick state=0          <idle>-0     [000]  2167.609253: clock_disable: uart3_fck state=0          <idle>-0     [000]  2167.689941: clock_enable: gpio6_dbck state=1          <idle>-0     [000]  2167.689972: clock_enable: uart3_ick state=1          <idle>-0     [000]  2167.690002: clock_enable: uart3_fck state=1          <idle>-0     [000]  2167.690033: power_domain_transition: per_pwrdm state=0          <idle>-0     [000]  2167.690613: power_end: dummy=65535...                                                                                             !! Need to wait ~6s for idle to change states from ON to RET/OFF ??...          <idle>-0     [000]  2170.605103: power_start: type=1 state=1          <idle>-0     [000]  2170.605133: power_domain_transition: mpu_pwrdm state=0          <idle>-0     [000]  2170.605133: power_domain_transition: core_pwrdm state=0          <idle>-0     [000]  2170.605316: power_domain_transition: neon_pwrdm state=0          <idle>-0     [000]  2170.605347: clock_disable: gpio6_dbck state=0          <idle>-0     [000]  2170.605438: clock_disable: uart3_ick state=0          <idle>-0     [000]  2170.605469: clock_disable: uart3_fck state=0          <idle>-0     [000]  2170.605499: clock_disable: uart1_ick state=0          <idle>-0     [000]  2170.605499: clock_disable: uart1_fck state=0          <idle>-0     [000]  2170.605530: clock_disable: uart2_ick state=0          <idle>-0     [000]  2170.605560: clock_disable: uart2_fck state=0          <idle>-0     [000]  2171.031067: clock_enable: hsotgusb_ick state=1          <idle>-0     [000]  2171.031158: clock_disable: hsotgusb_ick state=0          <idle>-0     [000]  2171.031189: clock_enable: uart1_ick state=1          <idle>-0     [000]  2171.031189: clock_enable: uart1_fck state=1          <idle>-0     [000]  2171.031311: clock_enable: uart2_ick state=1          <idle>-0     [000]  2171.031311: clock_enable: uart2_fck state=1          <idle>-0     [000]  2171.031403: clock_enable: gpio6_dbck state=1          <idle>-0     [000]  2171.031433: clock_enable: uart3_ick state=1          <idle>-0     [000]  2171.031433: clock_enable: uart3_fck state=1          <idle>-0     [000]  2171.032379: power_end: dummy=65535          <idle>-0     [000]  2171.033203: power_start: type=1 state=1          <idle>-0     [000]  2171.033234: power_domain_transition: mpu_pwrdm state=0          <idle>-0     [000]  2171.033264: power_domain_transition: core_pwrdm state=3          <idle>-0     [000]  2171.033447: power_domain_transition: neon_pwrdm state=0          <idle>-0     [000]  2171.033478: clock_disable: gpio6_dbck state=0          <idle>-0     [000]  2171.033508: power_domain_transition: per_pwrdm state=1          <idle>-0     [000]  2171.033539: clock_disable: uart3_ick state=0          <idle>-0     [000]  2171.033569: clock_disable: uart3_fck state=0          <idle>-0     [000]  2171.138824: clock_enable: gpio6_dbck state=1          <idle>-0     [000]  2171.138916: clock_enable: uart3_ick state=1          <idle>-0     [000]  2171.138916: clock_enable: uart3_fck state=1          <idle>-0     [000]  2171.138977: power_domain_transition: per_pwrdm state=0          <idle>-0     [000]  2171.139832: power_end: dummy=65535

[edit] Trace parsing, GUIs, and other debug tools

[edit] pytimechart UI

[edit] Intro

PyTimechart is a tool that parses ftrace text traces, and display them with the help of a dynamic plot framework, Chaco (http://code.enthought.com/chaco/ )The GUI makes the best it can to ease the browsing of huge traces.

[edit] Download and installation

Cf. http://gitorious.com/pytimechart/ for download of the latest code.

pytimechart depends on python-chaco. It can be installed on recent distributions (tested on Debian 6 and Ubuntu 10.04).

[edit] Usage

Cf. http://gitorious.com/pytimechart/pages/Home for usage instructions.

[edit] Screenshots

A good screenshot says it all!

This chart shows the scheduling details, the ondemand cpufreq governor changing the CPU frequencies and cpuidle changing the CPU C-states (5 is for C6: MPU OFF + Core RET)

Similar chart, with the clock and power_domain events added

Close-up of the previous chart

With the patch from File:Clock power.patch.gz applied, pytimechart shows the new clock and power events

Close up of previous chart

Prototype of the detailed low power modes transitions and C-states latency statistics. Note the C-state and duration are displayed as well!

[edit] Powertop

Powertop is a useful tool that can profile the system's C-states, frequencies, and wakeup sources. Installation instructions can be found here.

Retrieved from "http://omappedia.org/wiki/Power_Management_Debug_and_Profiling"

本站仅提供存储服务，所有内容均由用户发布，如发现有害或侵权内容，请点击举报。

Contents