Date:	Fri, 20 Mar 2015 15:44:19 -0700
From:	Badhri Jagan Sridharan <badhri@...gle.com>
To:	Mike Turquette <mturquette@...aro.org>,
	Stephen Boyd <sboyd@...eaurora.org>
Cc:	linux-kernel@...r.kernel.org,
	Badhri Jagan Sridharan <Badhri@...gle.com>
Subject: [PATCH] clk: debugfs: Support frequency stats accounting

Added frequency statistics accounting to common
clk debug framework. This change tracks the
frequency of the clocks which don't have the
CLK_GET_RATE_NOCACHE flag set. This is done by
monitoring the calls to  clk_set_rate, clk_enable
and then clk_disable. This patch would help
debugging power drain issues.

There is a new node called frequency_stats_table
created under DEBUG_FS/clk/<clk_debug_name>/ to
report the collected statistics. In addition,
the stats also gets printed as a part of the
clk_summary. Frequency gets reported in HZ and
the time_spent gets reported in msec units.

sample output of clk_summary:

   clock                         enable_cnt  prepare_cnt        rate   accuracy   phase
----------------------------------------------------------------------------------------
 clk24mhz                                 2            3    24000000          0 0
 *[        default_freq                                   48188]
 *         400000000					     54

default_freq accounts the time for which the
clk was on without an explicit call to the
clk_set_rate API. The [] braces highlight the
latest frequency set through clk_set_rate API.

Frequency accounting can be started(or)stopped
by writing 1(or)0 to /d/clk/freq_stats_on.
Writing 1 also causes the counters to reset.

Enabling CONFIG_FREQ_STATS_ACCOUNTING includes
the feature.

Enabling CONFIG_BEGIN_ACCOUNTING_FROM_BOOT
starts accounting right from boot.

Signed-off-by: Badhri Jagan Sridharan <Badhri@...gle.com>
---
 drivers/clk/Kconfig |  18 ++++
 drivers/clk/clk.c   | 299 ++++++++++++++++++++++++++++++++++++++++++++++++++--
 2 files changed, 311 insertions(+), 6 deletions(-)

diff --git a/drivers/clk/Kconfig b/drivers/clk/Kconfig
index 0b474a0..0ea6cc2 100644
--- a/drivers/clk/Kconfig
+++ b/drivers/clk/Kconfig
@@ -143,6 +143,24 @@ config COMMON_CLK_CDCE706
 	---help---
 	  This driver supports TI CDCE706 programmable 3-PLL clock synthesizer.
 
+config COMMON_CLK_FREQ_STATS_ACCOUNTING
+	bool "Enable clock frequency stats accounting"
+	depends on COMMON_CLK
+	depends on DEBUG_FS
+	---help---
+	 Allows accounting of the time spent by various clocks in each
+	 of its operating frequency. The stats get reported as a part
+	 of clk_summary. Would be be useful in finding out which
+	 components are running at what power states to debug
+	 battery consumption issues.
+
+config COMMON_CLK_BEGIN_ACCOUNTING_FROM_BOOT
+	bool "Start clock frequency stats accounting from boot"
+	depends on COMMON_CLK_FREQ_STATS_ACCOUNTING
+	---help---
+	 Enabling this option starts the frequency accounting right from
+	 the boot.
+
 source "drivers/clk/qcom/Kconfig"
 
 endmenu
diff --git a/drivers/clk/clk.c b/drivers/clk/clk.c
index 237f23f..6d082e9 100644
--- a/drivers/clk/clk.c
+++ b/drivers/clk/clk.c
@@ -11,16 +11,19 @@
 
 #include <linux/clk-provider.h>
 #include <linux/clk/clk-conf.h>
-#include <linux/module.h>
-#include <linux/mutex.h>
-#include <linux/spinlock.h>
+#include <linux/device.h>
 #include <linux/err.h>
+#include <linux/init.h>
+#include <linux/ktime.h>
 #include <linux/list.h>
-#include <linux/slab.h>
+#include <linux/module.h>
+#include <linux/mutex.h>
 #include <linux/of.h>
-#include <linux/device.h>
-#include <linux/init.h>
+#include <linux/rbtree.h>
 #include <linux/sched.h>
+#include <linux/spinlock.h>
+#include <linux/slab.h>
+#include <linux/timekeeping.h>
 
 #include "clk.h"
 
@@ -45,6 +48,13 @@ static bool clk_core_is_enabled(struct clk_core *clk);
 static struct clk_core *clk_core_lookup(const char *name);
 
 /***    private data structures    ***/
+#ifdef CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING
+struct freq_stats {
+	ktime_t time_spent;
+	unsigned long rate;
+	struct rb_node node;
+};
+#endif /*CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING*/
 
 struct clk_core {
 	const char		*name;
@@ -73,6 +83,12 @@ struct clk_core {
 	unsigned int		notifier_count;
 #ifdef CONFIG_DEBUG_FS
 	struct dentry		*dentry;
+#ifdef CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING
+	struct rb_root freq_stats_table;
+	struct freq_stats *current_freq_stats;
+	ktime_t default_freq_time;
+	ktime_t start_time;
+#endif /* CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING*/
 #endif
 	struct kref		ref;
 };
@@ -163,6 +179,134 @@ static struct hlist_head *orphan_list[] = {
 	NULL,
 };
 
+#ifdef CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING
+
+#ifdef CONFIG_COMMON_CLK_BEGIN_ACCOUNTING_FROM_BOOT
+static bool freq_stats_on = true;
+#else
+static bool freq_stats_on;
+#endif /*CONFIG_COMMON_CLK_BEGIN_ACCOUNTING_FROM_BOOT*/
+
+void free_tree(struct rb_node *node)
+{
+	struct freq_stats *this;
+
+	if (!node)
+		return;
+
+	free_tree(node->rb_left);
+	free_tree(node->rb_right);
+
+	this = rb_entry(node, struct freq_stats, node);
+	kfree(this);
+}
+
+struct freq_stats *freq_stats_insert(struct rb_root *freq_stats_table,
+				unsigned long rate)
+{
+	struct rb_node **new = &(freq_stats_table->rb_node), *parent = NULL;
+	struct freq_stats *this;
+
+	/* Figure out where to put new node */
+	while (*new) {
+		this = rb_entry(*new, struct freq_stats, node);
+		parent = *new;
+
+		if (rate < this->rate)
+			new = &((*new)->rb_left);
+		else if (rate > this->rate)
+			new = &((*new)->rb_right);
+		else
+			return this;
+	}
+
+	this = kzalloc(sizeof(*this), GFP_ATOMIC);
+	this->rate = rate;
+
+	/* Add new node and rebalance tree. */
+	rb_link_node(&this->node, parent, new);
+	rb_insert_color(&this->node, freq_stats_table);
+
+	return this;
+}
+
+static void generic_print_freq_stats_table(struct seq_file *m,
+				struct clk_core *clk,
+				bool indent, int level)
+{
+	struct rb_node *pos;
+	struct freq_stats *cur;
+
+	if (indent)
+		seq_printf(m, "%*s*%s%20s", level * 3 + 1, "",
+			!clk->current_freq_stats ? "[" : "",
+			"default_freq");
+	else
+		seq_printf(m, "%2s%20s", !clk->current_freq_stats ? "[" : "",
+			"default_freq");
+
+	if (!clk->current_freq_stats && !ktime_equal(clk->start_time,
+					ktime_set(0, 0)))
+		seq_printf(m, "%40llu",
+			ktime_to_ms(ktime_add(clk->default_freq_time,
+			ktime_sub(ktime_get(), clk->start_time))));
+	else
+		seq_printf(m, "%40llu", ktime_to_ms(clk->default_freq_time));
+
+	if (!clk->current_freq_stats)
+		seq_puts(m, "]");
+
+	seq_puts(m, "\n");
+
+	for (pos = rb_first(&clk->freq_stats_table); pos; pos = rb_next(pos)) {
+		cur = rb_entry(pos, typeof(*cur), node);
+
+		if (indent)
+			seq_printf(m, "%*s*%s%20lu", level * 3 + 1, "",
+				cur->rate == clk->rate ? "[" : "", cur->rate);
+		else
+			seq_printf(m, "%2s%20lu", cur->rate == clk->rate ?
+				"[" : "", cur->rate);
+
+		if (cur->rate == clk->rate && !ktime_equal(clk->start_time,
+					ktime_set(0, 0)))
+			seq_printf(m, "%40llu",
+				ktime_to_ms(ktime_add(cur->time_spent,
+				ktime_sub(ktime_get(), clk->start_time))));
+		else
+			seq_printf(m, "%40llu", ktime_to_ms(cur->time_spent));
+
+		if (cur->rate == clk->rate)
+			seq_puts(m, "]");
+		seq_puts(m, "\n");
+	}
+}
+
+
+static int clock_print_freq_stats_table(struct seq_file *m, void *unused)
+{
+	struct clk_core *clk = m->private;
+
+	if (!(clk->flags & CLK_GET_RATE_NOCACHE))
+		generic_print_freq_stats_table(m, clk, false, 0);
+
+	return 0;
+}
+
+static int freq_stats_table_open(struct inode *inode, struct file *file)
+{
+	return single_open(file, clock_print_freq_stats_table,
+			inode->i_private);
+}
+
+static const struct file_operations freq_stats_table_fops = {
+	.open           = freq_stats_table_open,
+	.read           = seq_read,
+	.llseek         = seq_lseek,
+	.release        = seq_release,
+};
+#endif /*CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING*/
+
 static void clk_summary_show_one(struct seq_file *s, struct clk_core *c,
 				 int level)
 {
@@ -174,8 +318,14 @@ static void clk_summary_show_one(struct seq_file *s, struct clk_core *c,
 		   30 - level * 3, c->name,
 		   c->enable_count, c->prepare_count, clk_core_get_rate(c),
 		   clk_core_get_accuracy(c), clk_core_get_phase(c));
+
+#ifdef CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING
+	if (!(c->flags & CLK_GET_RATE_NOCACHE))
+		generic_print_freq_stats_table(s, c, true, level);
+#endif /*CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING*/
 }
 
+
 static void clk_summary_show_subtree(struct seq_file *s, struct clk_core *c,
 				     int level)
 {
@@ -290,6 +440,78 @@ static const struct file_operations clk_dump_fops = {
 	.release	= single_release,
 };
 
+#ifdef CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING
+static int freq_stats_get(void *unused, u64 *val)
+{
+	*val = freq_stats_on;
+	return 0;
+}
+
+static void clk_traverse_subtree(struct clk_core *clk, int freq_stats_on)
+{
+	struct clk_core *child;
+	struct rb_node *node;
+
+	if (!clk)
+		return;
+
+	if (freq_stats_on) {
+		for (node = rb_first(&clk->freq_stats_table);
+			node; node = rb_next(node))
+			rb_entry(node, struct freq_stats, node)->time_spent =
+							ktime_set(0, 0);
+
+		clk->current_freq_stats = freq_stats_insert(
+						&clk->freq_stats_table,
+						clk_core_get_rate(clk));
+
+		if (clk->enable_count > 0)
+			clk->start_time = ktime_get();
+	} else {
+		if (clk->enable_count > 0) {
+			if (!clk->current_freq_stats)
+				clk->default_freq_time =
+				ktime_add(clk->default_freq_time,
+				ktime_sub(ktime_get(), clk->start_time));
+			else
+				clk->current_freq_stats->time_spent =
+				ktime_add(clk->current_freq_stats->time_spent,
+				ktime_sub(ktime_get(), clk->start_time));
+
+			clk->start_time = ktime_set(0, 0);
+		}
+	}
+	hlist_for_each_entry(child, &clk->children, child_node)
+		clk_traverse_subtree(child, freq_stats_on);
+}
+
+static int freq_stats_set(void *data, u64 val)
+{
+	struct clk_core *c;
+	unsigned long flags;
+	struct hlist_head **lists = (struct hlist_head **)data;
+
+	clk_prepare_lock();
+	flags = clk_enable_lock();
+
+	if (val == 0)
+		freq_stats_on = 0;
+	else
+		freq_stats_on = 1;
+
+	for (; *lists; lists++)
+		hlist_for_each_entry(c, *lists, child_node)
+			clk_traverse_subtree(c, freq_stats_on);
+
+	clk_enable_unlock(flags);
+	clk_prepare_unlock();
+
+	return 0;
+}
+DEFINE_SIMPLE_ATTRIBUTE(freq_stats_fops, freq_stats_get,
+			freq_stats_set, "%llu\n");
+#endif /*CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING*/
+
 static int clk_debug_create_one(struct clk_core *clk, struct dentry *pdentry)
 {
 	struct dentry *d;
@@ -341,6 +563,14 @@ static int clk_debug_create_one(struct clk_core *clk, struct dentry *pdentry)
 	if (!d)
 		goto err_out;
 
+#ifdef CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING
+	d = debugfs_create_file("frequency_stats_table", S_IRUGO, clk->dentry,
+			clk, &freq_stats_table_fops);
+
+	if (!d)
+		goto err_out;
+#endif /*CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING*/
+
 	if (clk->ops->debug_init) {
 		ret = clk->ops->debug_init(clk->hw, clk->dentry);
 		if (ret)
@@ -454,6 +684,13 @@ static int __init clk_debug_init(void)
 	if (!d)
 		return -ENOMEM;
 
+#ifdef CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING
+	d = debugfs_create_file("freq_stats_on", S_IRUGO|S_IWUSR,
+				rootdir, &all_lists, &freq_stats_fops);
+	if (!d)
+		return -ENOMEM;
+#endif /*CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING*/
+
 	mutex_lock(&clk_debug_lock);
 	hlist_for_each_entry(clk, &clk_debug_list, debug_node)
 		clk_debug_create_one(clk, rootdir);
@@ -998,6 +1235,22 @@ static void clk_core_disable(struct clk_core *clk)
 	if (clk->ops->disable)
 		clk->ops->disable(clk->hw);
 
+#ifdef CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING
+
+	if (freq_stats_on) {
+		if (!clk->current_freq_stats)
+			clk->default_freq_time =
+			ktime_add(clk->default_freq_time,
+			ktime_sub(ktime_get(), clk->start_time));
+		else
+			clk->current_freq_stats->time_spent =
+			ktime_add(clk->current_freq_stats->time_spent,
+			ktime_sub(ktime_get(), clk->start_time));
+
+		clk->start_time = ktime_set(0, 0);
+	}
+#endif /*CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING*/
+
 	clk_core_disable(clk->parent);
 }
 
@@ -1057,6 +1310,11 @@ static int clk_core_enable(struct clk_core *clk)
 				return ret;
 			}
 		}
+
+#ifdef CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING
+	if (freq_stats_on)
+		clk->start_time = ktime_get();
+#endif /*CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING*/
 	}
 
 	clk->enable_count++;
@@ -1724,6 +1982,31 @@ static void clk_change_rate(struct clk_core *clk)
 
 	clk->rate = clk_recalc(clk, best_parent_rate);
 
+#ifdef CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING
+	if (freq_stats_on) {
+		if (!ktime_equal(clk->start_time, ktime_set(0, 0))) {
+			if (!clk->current_freq_stats)
+				clk->default_freq_time =
+					ktime_add(clk->default_freq_time,
+					ktime_sub(ktime_get(),
+					clk->start_time));
+			else
+				clk->current_freq_stats->time_spent =
+					ktime_add(
+					clk->current_freq_stats->time_spent,
+					ktime_sub(ktime_get(),
+					clk->start_time));
+		}
+
+		clk->current_freq_stats = freq_stats_insert(
+						&clk->freq_stats_table,
+						clk->rate);
+
+		if (clk->enable_count > 0)
+			clk->start_time = ktime_get();
+	}
+#endif /*CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING*/
+
 	if (clk->notifier_count && old_rate != clk->rate)
 		__clk_notify(clk, POST_RATE_CHANGE, old_rate, clk->rate);
 
@@ -2519,6 +2802,10 @@ static void __clk_release(struct kref *ref)
 
 	kfree(clk->parent_names);
 	kfree_const(clk->name);
+
+#ifdef CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING
+	free_tree(clk->freq_stats_table.rb_node);
+#endif/*CONFIG_COMMON_CLK_FREQ_STATS_ACCOUNTING*/
 	kfree(clk);
 }
 
-- 
2.2.0.rc0.207.ga3a616c

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Powered by blists - more mailing lists