[PATCH] clk: debugfs: Support frequency stats accounting

From: Badhri Jagan Sridharan
Date: Fri Mar 20 2015 - 18:45:07 EST

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@xxxxxxxxxx>
---
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@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/