lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Date:	Sat, 21 Mar 2015 00:26:07 -0700
From:	Stephen Boyd <sboyd@...eaurora.org>
To:	Badhri Jagan Sridharan <badhri@...gle.com>
Cc:	Mike Turquette <mturquette@...aro.org>,
	linux-kernel@...r.kernel.org
Subject: Re: [PATCH] clk: debugfs: Support frequency stats accounting

On 03/20, Badhri Jagan Sridharan wrote:
> 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>
> ---

Some initial questions:

 1. Have you seen the pending tracepoint patches to add
 tracepoints to the framework[1]?

 2. Have you considered using tracepoints and the ability to
 register callbacks on tracepoints and/or register_stat_tracer()
 to implement the functionality in this patch?

 3. If we had tracepoints would it be possible to do
 everything that's done here entirely in userspace with some
 userspace tool that monitors clock trace events?

[1] https://git.kernel.org/cgit/linux/kernel/git/clk/linux.git/commit/?h=clk-next&id=dfc202ead3123988793ac1160849676000b77ee4

>  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.

No mention of stats per 'clock_foo' debugfs directory?

> +
> +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>

Please don't move things around here. Just add what you need. Or
if you do need to move things around please explain why that's
done in the commit text. Alphabetizing can be done later, if at
all.

>  
>  #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*/

Useless and possibly harmful ifdef, please remove.

>  
>  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*/

Why do we want a config for this? Why not default false and then
have a module parameter that can be changed from the kernel
commandline?  It certainly makes it easier than having to
recompile the kernel just to set a bool to true.

> +
> +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))

Maybe we shouldn't even make the file if there isn't a
possibility of having any contents in the file?

> +		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*/
>  }
>  
> +

Noise?

>  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,

							^
						Space around '|' here please

> +				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

Please remove these ifdefs and make static inline functions or
use IS_ENABLED stuff so that we get better build coverage of this
code.

> +
> +	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*/

In situations like this it's better to make a new function like
clk_core_rate_stat() that hides all these details from readers
who want to understand the flow and not get bogged down in a big
chunk of debug code.

-- 
Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum,
a Linux Foundation Collaborative Project
--
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

Powered by Openwall GNU/*/Linux Powered by OpenVZ