ftrace: Add a C/P state tracer to help power optimization

PATCH In review Arjan van de Ven 3 participants 5 messages Nov 23, 2008 – Nov 26, 2008

Subsystems (3)

x86 Tracing ftrace

lore

Share & tools

lore

Arjan van de Ven

author

2008-11-23 20:58 UTC #0 lore raw

PATCH 1/1 ftrace: Add a C/P state tracer to help power optimization

Quoted 1 line

From 9625f8f58b86ddfd49351a252adce2ce85f6070c Mon Sep 17 00:00:00 2001

From: Arjan van de Ven <[email protected]>
Date: Fri, 3 Oct 2008 10:18:21 -0700
Subject: [PATCH] ftrace: Add a C/P state tracer to help power optimization

This patch adds a C/P-state ftrace plugin that will generate detailed statistics about the C/P-states that are being used, so that we can look at detailed decisions that the C/P-state code is making, rather than the too high level "average" that we have today.

An example way of using this is:
mount -t debugfs none /sys/kernel/debug
echo cstate > /sys/kernel/debug/tracing/current_tracer
echo 1 > /sys/kernel/debug/tracing/tracing_enabled
sleep 1
echo 0 > /sys/kernel/debug/tracing/tracing_enabled
cat /sys/kernel/debug/tracing/trace | perl scripts/trace/cstate.pl > out.svg

Impact: New code
Impact: Minor additions to existing code

Signed-off-by Arjan van de Ven <[email protected]>

---
 arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c |    4 +
 arch/x86/kernel/process.c                  |   16 +++
 include/linux/ftrace.h                     |   29 +++++
 kernel/trace/Kconfig                       |   11 ++
 kernel/trace/Makefile                      |    1 +
 kernel/trace/trace.h                       |    7 +
 kernel/trace/trace_power.c                 |  184 ++++++++++++++++++++++++++++
 7 files changed, 252 insertions(+), 0 deletions(-)
 create mode 100644 kernel/trace/trace_power.c

arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c +4 -0

index 8e48c5d..88ea02d 100644
@@ -33,6 +33,7 @@
 #include <linux/cpufreq.h>
 #include <linux/compiler.h>
 #include <linux/dmi.h>
+#include <linux/ftrace.h>
 
 #include <linux/acpi.h>
 #include <acpi/processor.h>

@@ -391,6 +392,7 @@ static int acpi_cpufreq_target(struct cpufreq_policy *policy,
 	unsigned int next_perf_state = 0; /* Index into perf table */
 	unsigned int i;
 	int result = 0;
+	struct power_trace it;
 
 	dprintk("acpi_cpufreq_target %d (%d)\n", target_freq, policy->cpu);

@@ -427,6 +429,8 @@ static int acpi_cpufreq_target(struct cpufreq_policy *policy,
 		}
 	}
 
+	trace_power_mark(&it, POWER_PSTATE, next_perf_state);
+
 	switch (data->cpu_feature) {
 	case SYSTEM_INTEL_MSR_CAPABLE:
 		cmd.type = SYSTEM_INTEL_MSR_CAPABLE;

arch/x86/kernel/process.c +16 -0

index c622772..c27af49 100644
@@ -7,6 +7,7 @@
 #include <linux/module.h>
 #include <linux/pm.h>
 #include <linux/clockchips.h>
+#include <linux/ftrace.h>
 #include <asm/system.h>
 
 unsigned long idle_halt;

@@ -100,6 +101,9 @@ static inline int hlt_use_halt(void)
 void default_idle(void)
 {
 	if (hlt_use_halt()) {
+		struct power_trace it;
+
+		trace_power_start(&it, POWER_CSTATE, 1);
 		current_thread_info()->status &= ~TS_POLLING;
 		/*
 		 * TS_POLLING-cleared state must be visible before we

@@ -112,6 +116,7 @@ void default_idle(void)
 		else
 			local_irq_enable();
 		current_thread_info()->status |= TS_POLLING;
+		trace_power_end(&it);
 	} else {
 		local_irq_enable();
 		/* loop is done by the caller */

@@ -154,24 +159,31 @@ EXPORT_SYMBOL_GPL(cpu_idle_wait);
  */
 void mwait_idle_with_hints(unsigned long ax, unsigned long cx)
 {
+	struct power_trace it;
+
+	trace_power_start(&it, POWER_CSTATE, (ax>>4)+1);
 	if (!need_resched()) {
 		__monitor((void *)&current_thread_info()->flags, 0, 0);
 		smp_mb();
 		if (!need_resched())
 			__mwait(ax, cx);
 	}
+	trace_power_end(&it);
 }
 
 /* Default MONITOR/MWAIT with no hints, used for default C1 state */
 static void mwait_idle(void)
 {
+	struct power_trace it;
 	if (!need_resched()) {
+		trace_power_start(&it, POWER_CSTATE, 1);
 		__monitor((void *)&current_thread_info()->flags, 0, 0);
 		smp_mb();
 		if (!need_resched())
 			__sti_mwait(0, 0);
 		else
 			local_irq_enable();
+		trace_power_end(&it);
 	} else
 		local_irq_enable();
 }

@@ -183,9 +195,13 @@ static void mwait_idle(void)
  */
 static void poll_idle(void)
 {
+	struct power_trace it;
+
+	trace_power_start(&it, POWER_CSTATE, 0);
 	local_irq_enable();
 	while (!need_resched())
 		cpu_relax();
+	trace_power_end(&it);
 }
 
 /*

include/linux/ftrace.h +29 -0

index 703eb53..573095b 100644
@@ -248,6 +248,35 @@ static inline void start_boot_trace(void) { }
 static inline void stop_boot_trace(void) { }
 #endif
 
+enum {
+	POWER_NONE = 0,
+	POWER_CSTATE = 1,
+	POWER_PSTATE = 2,
+};
+
+struct power_trace {
+#ifdef CONFIG_POWER_TRACER
+	ktime_t			stamp;
+	ktime_t			end;
+	int			type;
+	int			state;
+#endif
+};
+
+#ifdef CONFIG_POWER_TRACER
+extern void trace_power_start(struct power_trace *it, unsigned int type,
+					unsigned int state);
+extern void trace_power_mark(struct power_trace *it, unsigned int type,
+					unsigned int state);
+extern void trace_power_end(struct power_trace *it);
+#else
+static inline void trace_power_start(struct power_trace *it, unsigned int type,
+					unsigned int state) { }
+static inline void trace_power_mark(struct power_trace *it, unsigned int type,
+					unsigned int state) { }
+static inline void trace_power_end(struct power_trace *it) { }
+#endif
+
 
 
 #endif /* _LINUX_FTRACE_H */

kernel/trace/Kconfig +11 -0

index 33dbefd..f5f2363 100644
@@ -138,6 +138,17 @@ config BOOT_TRACER
 	    selected, because the self-tests are an initcall as well and that
 	    would invalidate the boot trace. )
 
+config POWER_TRACER
+	bool "Trace power consumption behavior"
+	depends on DEBUG_KERNEL
+	depends on X86
+	select TRACING
+	help
+	  This tracer helps developers to analyze and optimize the kernels
+	  power management decisions, specifically the C-state and P-state
+	  behavior.
+
+
 config STACK_TRACER
 	bool "Trace max stack"
 	depends on HAVE_FUNCTION_TRACER

kernel/trace/Makefile +1 -0

index c8228b1..917b42e 100644
@@ -24,5 +24,6 @@ obj-$(CONFIG_NOP_TRACER) += trace_nop.o
 obj-$(CONFIG_STACK_TRACER) += trace_stack.o
 obj-$(CONFIG_MMIOTRACE) += trace_mmiotrace.o
 obj-$(CONFIG_BOOT_TRACER) += trace_boot.o
+obj-$(CONFIG_POWER_TRACER) += trace_power.o
 
 libftrace-y := ftrace.o

kernel/trace/trace.h +7 -0

index 8465ad0..77cc01c 100644
@@ -22,6 +22,7 @@ enum trace_type {
 	TRACE_MMIO_RW,
 	TRACE_MMIO_MAP,
 	TRACE_BOOT,
+	TRACE_POWER,
 
 	__TRACE_LAST_TYPE
 };

@@ -117,6 +118,11 @@ struct trace_boot {
 	struct boot_trace	initcall;
 };
 
+struct trace_power {
+	struct trace_entry	ent;
+	struct power_trace	state_data;
+};
+
 /*
  * trace_flag_type is an enumeration that holds different
  * states when a trace occurs. These are:

@@ -219,6 +225,7 @@ extern void __ftrace_bad_type(void);
 		IF_ASSIGN(var, ent, struct trace_mmiotrace_map,		\
 			  TRACE_MMIO_MAP);				\
 		IF_ASSIGN(var, ent, struct trace_boot, TRACE_BOOT);	\
+		IF_ASSIGN(var, ent, struct trace_power, TRACE_POWER); \
 		__ftrace_bad_type();					\
 	} while (0)

kernel/trace/trace_power.c new file +184 -0

184 lines not on this page · raw message

Signature · 8 lines

1.6.0.3



-- 
Arjan van de Ven 	Intel Open Source Technology Centre
For development, discussion and tips for power savings, 
visit http://www.lesswatts.org

Frédéric Weisbecker

2008-11-23 21:12 UTC #1 lore raw

Hi Arjan,

2008/11/23 Arjan van de Ven <[email protected]>:

kernel/trace/trace_power.c line 51

Quoted 7 lines

kernel/trace/trace_power.c new file +7 -0

+static void power_trace_ctrl_update(struct trace_array *tr)
+{
+       if (tr->ctrl)
+               start_power_trace();
+       else
+               stop_power_trace(tr);
+}

The ctrl_update callback doesn't exist anymore...

Arjan van de Ven

author

2008-11-24 00:49 UTC #2 lore raw

Quoted 13 lines · On Sun, 23 Nov 2008 22:12:44 +0100 "Frédéric Weisbecker" <[email protected]>…

Hi Arjan,
2008/11/23 Arjan van de Ven <[email protected]>:
Review
Quoted 7 lines
(quoted diff) +7 -0
+static void power_trace_ctrl_update(struct trace_array *tr)
+{
+       if (tr->ctrl)
+               start_power_trace();
+       else
+               stop_power_trace(tr);
+}
The ctrl_update callback doesn't exist anymore...

the patch was against mainline;
below is an updated patch against -tip:

Quoted 1 line

From 679db8acb007a7cb74719c5609307b79b88b18a7 Mon Sep 17 00:00:00 2001

From: Arjan van de Ven <[email protected]>
Date: Sun, 23 Nov 2008 16:48:47 -0800
Subject: [PATCH] ftrace: Add a C/P state tracer to help power optimization

Impact: New code
Impact: Minor additions to existing code

Signed-off-by Arjan van de Ven <[email protected]>

---
 arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c |    4 +
 arch/x86/kernel/process.c                  |   16 +++
 include/linux/ftrace.h                     |   29 +++++
 kernel/trace/Kconfig                       |   11 ++
 kernel/trace/Makefile                      |    1 +
 kernel/trace/trace.h                       |    7 +
 kernel/trace/trace_power.c                 |  179 ++++++++++++++++++++++++++++
 scripts/trace/power.pl                     |  108 +++++++++++++++++
 8 files changed, 355 insertions(+), 0 deletions(-)
 create mode 100644 kernel/trace/trace_power.c
 create mode 100644 scripts/trace/power.pl

arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c +4 -0

index 8e48c5d..88ea02d 100644
@@ -33,6 +33,7 @@
 #include <linux/cpufreq.h>
 #include <linux/compiler.h>
 #include <linux/dmi.h>
+#include <linux/ftrace.h>
 
 #include <linux/acpi.h>
 #include <acpi/processor.h>

@@ -391,6 +392,7 @@ static int acpi_cpufreq_target(struct cpufreq_policy *policy,
 	unsigned int next_perf_state = 0; /* Index into perf table */
 	unsigned int i;
 	int result = 0;
+	struct power_trace it;
 
 	dprintk("acpi_cpufreq_target %d (%d)\n", target_freq, policy->cpu);

@@ -427,6 +429,8 @@ static int acpi_cpufreq_target(struct cpufreq_policy *policy,
 		}
 	}
 
+	trace_power_mark(&it, POWER_PSTATE, next_perf_state);
+
 	switch (data->cpu_feature) {
 	case SYSTEM_INTEL_MSR_CAPABLE:
 		cmd.type = SYSTEM_INTEL_MSR_CAPABLE;

arch/x86/kernel/process.c +16 -0

index 8455480..d07993d 100644
@@ -7,6 +7,7 @@
 #include <linux/module.h>
 #include <linux/pm.h>
 #include <linux/clockchips.h>
+#include <linux/ftrace.h>
 #include <asm/system.h>
 #include <asm/apic.h>

@@ -101,6 +102,9 @@ static inline int hlt_use_halt(void)
 void default_idle(void)
 {
 	if (hlt_use_halt()) {
+		struct power_trace it;
+
+		trace_power_start(&it, POWER_CSTATE, 1);
 		current_thread_info()->status &= ~TS_POLLING;
 		/*
 		 * TS_POLLING-cleared state must be visible before we

@@ -113,6 +117,7 @@ void default_idle(void)
 		else
 			local_irq_enable();
 		current_thread_info()->status |= TS_POLLING;
+		trace_power_end(&it);
 	} else {
 		local_irq_enable();
 		/* loop is done by the caller */

@@ -170,24 +175,31 @@ EXPORT_SYMBOL_GPL(cpu_idle_wait);
  */
 void mwait_idle_with_hints(unsigned long ax, unsigned long cx)
 {
+	struct power_trace it;
+
+	trace_power_start(&it, POWER_CSTATE, (ax>>4)+1);
 	if (!need_resched()) {
 		__monitor((void *)&current_thread_info()->flags, 0, 0);
 		smp_mb();
 		if (!need_resched())
 			__mwait(ax, cx);
 	}
+	trace_power_end(&it);
 }
 
 /* Default MONITOR/MWAIT with no hints, used for default C1 state */
 static void mwait_idle(void)
 {
+	struct power_trace it;
 	if (!need_resched()) {
+		trace_power_start(&it, POWER_CSTATE, 1);
 		__monitor((void *)&current_thread_info()->flags, 0, 0);
 		smp_mb();
 		if (!need_resched())
 			__sti_mwait(0, 0);
 		else
 			local_irq_enable();
+		trace_power_end(&it);
 	} else
 		local_irq_enable();
 }

@@ -199,9 +211,13 @@ static void mwait_idle(void)
  */
 static void poll_idle(void)
 {
+	struct power_trace it;
+
+	trace_power_start(&it, POWER_CSTATE, 0);
 	local_irq_enable();
 	while (!need_resched())
 		cpu_relax();
+	trace_power_end(&it);
 }
 
 /*

include/linux/ftrace.h +29 -0

index 7854d87..0df2886 100644
@@ -311,6 +311,35 @@ ftrace_init_module(struct module *mod,
 		   unsigned long *start, unsigned long *end) { }
 #endif
 
+enum {
+	POWER_NONE = 0,
+	POWER_CSTATE = 1,
+	POWER_PSTATE = 2,
+};
+
+struct power_trace {
+#ifdef CONFIG_POWER_TRACER
+	ktime_t			stamp;
+	ktime_t			end;
+	int			type;
+	int			state;
+#endif
+};
+
+#ifdef CONFIG_POWER_TRACER
+extern void trace_power_start(struct power_trace *it, unsigned int type,
+					unsigned int state);
+extern void trace_power_mark(struct power_trace *it, unsigned int type,
+					unsigned int state);
+extern void trace_power_end(struct power_trace *it);
+#else
+static inline void trace_power_start(struct power_trace *it, unsigned int type,
+					unsigned int state) { }
+static inline void trace_power_mark(struct power_trace *it, unsigned int type,
+					unsigned int state) { }
+static inline void trace_power_end(struct power_trace *it) { }
+#endif
+
 
 /*
  * Structure that defines a return function trace.

kernel/trace/Kconfig +11 -0

index 9cbf776..eabcd43 100644
@@ -214,6 +214,17 @@ config BRANCH_TRACER
 
 	  Say N if unsure.
 
+config POWER_TRACER
+	bool "Trace power consumption behavior"
+	depends on DEBUG_KERNEL
+	depends on X86
+	select TRACING
+	help
+	  This tracer helps developers to analyze and optimize the kernels
+	  power management decisions, specifically the C-state and P-state
+	  behavior.
+
+
 config STACK_TRACER
 	bool "Trace max stack"
 	depends on HAVE_FUNCTION_TRACER

kernel/trace/Makefile +1 -0

index 1a8c925..a5ed56b 100644
@@ -31,5 +31,6 @@ obj-$(CONFIG_MMIOTRACE) += trace_mmiotrace.o
 obj-$(CONFIG_BOOT_TRACER) += trace_boot.o
 obj-$(CONFIG_FUNCTION_RET_TRACER) += trace_functions_return.o
 obj-$(CONFIG_TRACE_BRANCH_PROFILING) += trace_branch.o
+obj-$(CONFIG_POWER_TRACER) += trace_power.o
 
 libftrace-y := ftrace.o

kernel/trace/trace.h +7 -0

index 28c15c2..440faca 100644
@@ -27,6 +27,7 @@ enum trace_type {
 	TRACE_BOOT_RET,
 	TRACE_FN_RET,
 	TRACE_USER_STACK,
+	TRACE_POWER,
 
 	__TRACE_LAST_TYPE
 };

@@ -153,6 +154,11 @@ struct trace_branch {
 	char			correct;
 };
 
+struct trace_power {
+	struct trace_entry	ent;
+	struct power_trace	state_data;
+};
+
 /*
  * trace_flag_type is an enumeration that holds different
  * states when a trace occurs. These are:

@@ -258,6 +264,7 @@ extern void __ftrace_bad_type(void);
 		IF_ASSIGN(var, ent, struct trace_boot_ret, TRACE_BOOT_RET);\
 		IF_ASSIGN(var, ent, struct trace_branch, TRACE_BRANCH); \
 		IF_ASSIGN(var, ent, struct ftrace_ret_entry, TRACE_FN_RET);\
+ 		IF_ASSIGN(var, ent, struct trace_power, TRACE_POWER); \
 		__ftrace_bad_type();					\
 	} while (0)

kernel/trace/trace_power.c new file +179 -0

179 lines not on this page · raw message

scripts/trace/power.pl new file +108 -0

108 lines not on this page · raw message

Signature · 9 lines

1.6.0.3




-- 
Arjan van de Ven 	Intel Open Source Technology Centre
For development, discussion and tips for power savings, 
visit http://www.lesswatts.org

Frédéric Weisbecker

2008-11-25 11:26 UTC #3 lore raw

That looks good...

2008/11/24 Arjan van de Ven <[email protected]>:

Quoted 27 lines

include/linux/ftrace.h +19 -0

index 7854d87..0df2886 100644
@@ -311,6 +311,35 @@ ftrace_init_module(struct module *mod,
                  unsigned long *start, unsigned long *end) { }
 #endif
 
+enum {
+       POWER_NONE = 0,
+       POWER_CSTATE = 1,
+       POWER_PSTATE = 2,
+};
+
+struct power_trace {
+#ifdef CONFIG_POWER_TRACER
+       ktime_t                 stamp;
+       ktime_t                 end;
+       int                     type;
+       int                     state;
+#endif
+};
+
+#ifdef CONFIG_POWER_TRACER
+extern void trace_power_start(struct power_trace *it, unsigned int type,
+                                       unsigned int state);
+extern void trace_power_mark(struct power_trace *it, unsigned int type,

include/linux/ftrace.h ftrace_init_module(struct module *mod, · line 342

Quoted 10 lines

include/linux/ftrace.h +10 -0

+                                       unsigned int state);
+extern void trace_power_end(struct power_trace *it);
+#else
+static inline void trace_power_start(struct power_trace *it, unsigned int type,
+                                       unsigned int state) { }
+static inline void trace_power_mark(struct power_trace *it, unsigned int type,
+                                       unsigned int state) { }
+static inline void trace_power_end(struct power_trace *it) { }
+#endif
+

Sorry I didn't see it on my last mail.
But these headers seem to relate more on "power tracing" rather than "ftrace". Perhaps these would find a better place on trace/power.h
I guess that could be done on a delta patch as well....

Just for curiosity, do you have an example of trace and/or graph from this tracer?

Ingo Molnar

2008-11-26 07:36 UTC #4 lore raw

Quoted 1 line · Frédéric Weisbecker

That looks good...

[...]

Quoted 3 lines

Just for curiosity, do you have an example of trace and/or graph from this tracer?

Output looks like this:

# tracer: power
#
# TASK-PID CPU# TIMESTAMP FUNCTION
# | | | | |

[   54.698035123] CSTATE: Going to C1 on cpu 0 for 0.000022629
[   54.698059987] CSTATE: Going to C1 on cpu 0 for 0.000074032
[   54.698191011] CSTATE: Going to C1 on cpu 0 for 0.000134655
[   54.698327901] CSTATE: Going to C1 on cpu 0 for 0.000276017
[   54.699178020] CSTATE: Going to C1 on cpu 8 for 0.001454114
[   54.698138489] CSTATE: Going to C1 on cpu 5 for 0.002507334
[   54.699079124] CSTATE: Going to C1 on cpu 4 for 0.001611677
[   54.698605873] CSTATE: Going to C1 on cpu 0 for 0.003998045
[   54.700276498] CSTATE: Going to C1 on cpu 10 for 0.003994971
[   54.700636045] CSTATE: Going to C1 on cpu 6 for 0.003993295
[   54.700637442] CSTATE: Going to C1 on cpu 2 for 0.003993295
[   54.700634648] CSTATE: Going to C1 on cpu 8 for 0.003998883

Ingo