[PATCH] clk: Add tracepoints for hardware operations

It's useful to have tracepoints around operations that change the
hardware state so that we can debug clock hardware performance
and operations. Three basic types of events are supported: on/off
events for enable, disable, prepare, unprepare that only record
an event and a clock name, rate changing events for
clk_set_rate() and parent changing events for clk_set_parent().

Cc: Steven Rostedt <rostedt@goodmis.org>
Signed-off-by: Stephen Boyd <redacted>
---

I see that there are tracepoints for clock_enable/clock_set_rate
in events/power.h but those look to be unused and they also
take cpu_id which seems odd. I'd rather we just make a new set of
events for the common clock framework instead and add the "_complete"
set of events so we know when things have completed.

 drivers/clk/clk.c          |  28 ++++++++
 include/trace/events/clk.h | 165 +++++++++++++++++++++++++++++++++++++++++++++
 2 files changed, 193 insertions(+)
 create mode 100644 include/trace/events/clk.h

diff --git a/drivers/clk/clk.c b/drivers/clk/clk.c
index 8b73edef151d..f8bf69df3210 100644
--- a/drivers/clk/clk.c
+++ b/drivers/clk/clk.c

@@ -21,6 +21,9 @@
 #include <linux/init.h>
 #include <linux/sched.h>
 
+#define CREATE_TRACE_POINTS
+#include <trace/events/clk.h>
+
 #include "clk.h"
 
 static DEFINE_SPINLOCK(enable_lock);

@@ -483,10 +486,12 @@ static void clk_unprepare_unused_subtree(struct clk *clk)
 		return;
 
 	if (__clk_is_prepared(clk)) {
+		trace_clk_unprepare(clk);
 		if (clk->ops->unprepare_unused)
 			clk->ops->unprepare_unused(clk->hw);
 		else if (clk->ops->unprepare)
 			clk->ops->unprepare(clk->hw);
+		trace_clk_unprepare_complete(clk);
 	}
 }
 

@@ -516,10 +521,12 @@ static void clk_disable_unused_subtree(struct clk *clk)
 	 * back to .disable
 	 */
 	if (__clk_is_enabled(clk)) {
+		trace_clk_disable(clk);
 		if (clk->ops->disable_unused)
 			clk->ops->disable_unused(clk->hw);
 		else if (clk->ops->disable)
 			clk->ops->disable(clk->hw);
+		trace_clk_disable_complete(clk);
 	}
 
 unlock_out:

@@ -802,9 +809,13 @@ void __clk_unprepare(struct clk *clk)
 
 	WARN_ON(clk->enable_count > 0);
 
+	trace_clk_unprepare(clk);
+
 	if (clk->ops->unprepare)
 		clk->ops->unprepare(clk->hw);
 
+	trace_clk_unprepare_complete(clk);
+
 	__clk_unprepare(clk->parent);
 }
 

@@ -842,6 +853,8 @@ int __clk_prepare(struct clk *clk)
 		if (ret)
 			return ret;
 
+		trace_clk_prepare(clk);
+
 		if (clk->ops->prepare) {
 			ret = clk->ops->prepare(clk->hw);
 			if (ret) {

@@ -849,6 +862,8 @@ int __clk_prepare(struct clk *clk)
 				return ret;
 			}
 		}
+
+		trace_clk_prepare_complete(clk);
 	}
 
 	clk->prepare_count++;

@@ -891,9 +906,13 @@ static void __clk_disable(struct clk *clk)
 	if (--clk->enable_count > 0)
 		return;
 
+	trace_clk_disable(clk);
+
 	if (clk->ops->disable)
 		clk->ops->disable(clk->hw);
 
+	trace_clk_disable_complete(clk);
+
 	__clk_disable(clk->parent);
 }
 

@@ -938,6 +957,7 @@ static int __clk_enable(struct clk *clk)
 		if (ret)
 			return ret;
 
+		trace_clk_enable(clk);
 		if (clk->ops->enable) {
 			ret = clk->ops->enable(clk->hw);
 			if (ret) {

@@ -945,6 +965,7 @@ static int __clk_enable(struct clk *clk)
 				return ret;
 			}
 		}
+		trace_clk_enable_complete(clk);
 	}
 
 	clk->enable_count++;

@@ -1241,6 +1262,8 @@ static struct clk *__clk_set_parent_before(struct clk *clk, struct clk *parent)
 	unsigned long flags;
 	struct clk *old_parent = clk->parent;
 
+	trace_clk_set_parent(clk, parent);
+
 	/*
 	 * Migrate prepare state between parents and prevent race with
 	 * clk_enable().

@@ -1285,6 +1308,7 @@ static void __clk_set_parent_after(struct clk *clk, struct clk *parent,
 		__clk_unprepare(old_parent);
 	}
 
+	trace_clk_set_parent_complete(clk, parent);
 	/* update debugfs with new clk tree topology */
 	clk_debug_reparent(clk, parent);
 }

@@ -1507,6 +1531,8 @@ static void clk_change_rate(struct clk *clk)
 	else if (clk->parent)
 		best_parent_rate = clk->parent->rate;
 
+	trace_clk_set_rate(clk, clk->new_rate);
+
 	if (clk->new_parent && clk->new_parent != clk->parent) {
 		old_parent = __clk_set_parent_before(clk, clk->new_parent);
 

@@ -1525,6 +1551,8 @@ static void clk_change_rate(struct clk *clk)
 	if (!skip_set_rate && clk->ops->set_rate)
 		clk->ops->set_rate(clk->hw, clk->new_rate, best_parent_rate);
 
+	trace_clk_set_rate_complete(clk, clk->new_rate);
+
 	clk->rate = clk_recalc(clk, best_parent_rate);
 
 	if (clk->notifier_count && old_rate != clk->rate)

diff --git a/include/trace/events/clk.h b/include/trace/events/clk.h
new file mode 100644
index 000000000000..8523adce0f73
--- /dev/null
+++ b/include/trace/events/clk.h

@@ -0,0 +1,165 @@
+/*
+ * Copyright (c) 2014, The Linux Foundation. All rights reserved.
+ *
+ * This software is licensed under the terms of the GNU General Public
+ * License version 2, as published by the Free Software Foundation, and
+ * may be copied, distributed, and modified under those terms.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ */
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM clk
+
+#if !defined(_TRACE_CLK_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_CLK_H
+
+#include <linux/tracepoint.h>
+
+struct clk;
+
+DECLARE_EVENT_CLASS(clk,
+
+	TP_PROTO(struct clk *clk),
+
+	TP_ARGS(clk),
+
+	TP_STRUCT__entry(
+		__string(        name,           __clk_get_name(clk)       )
+	),
+
+	TP_fast_assign(
+		__assign_str(name, __clk_get_name(clk));
+	),
+
+	TP_printk("%s", __get_str(name))
+);
+
+DEFINE_EVENT(clk, clk_enable,
+
+	TP_PROTO(struct clk *clk),
+
+	TP_ARGS(clk)
+);
+
+DEFINE_EVENT(clk, clk_enable_complete,
+
+	TP_PROTO(struct clk *clk),
+
+	TP_ARGS(clk)
+);
+
+DEFINE_EVENT(clk, clk_disable,
+
+	TP_PROTO(struct clk *clk),
+
+	TP_ARGS(clk)
+);
+
+DEFINE_EVENT(clk, clk_disable_complete,
+
+	TP_PROTO(struct clk *clk),
+
+	TP_ARGS(clk)
+);
+
+DEFINE_EVENT(clk, clk_prepare,
+
+	TP_PROTO(struct clk *clk),
+
+	TP_ARGS(clk)
+);
+
+DEFINE_EVENT(clk, clk_prepare_complete,
+
+	TP_PROTO(struct clk *clk),
+
+	TP_ARGS(clk)
+);
+
+DEFINE_EVENT(clk, clk_unprepare,
+
+	TP_PROTO(struct clk *clk),
+
+	TP_ARGS(clk)
+);
+
+DEFINE_EVENT(clk, clk_unprepare_complete,
+
+	TP_PROTO(struct clk *clk),
+
+	TP_ARGS(clk)
+);
+
+DECLARE_EVENT_CLASS(clk_rate,
+
+	TP_PROTO(struct clk *clk, unsigned long rate),
+
+	TP_ARGS(clk, rate),
+
+	TP_STRUCT__entry(
+		__string(        name,           __clk_get_name(clk)       )
+		__field(unsigned long,           rate                      )
+	),
+
+	TP_fast_assign(
+		__assign_str(name, __clk_get_name(clk));
+		__entry->rate = rate;
+	),
+
+	TP_printk("%s %lu", __get_str(name), (unsigned long)__entry->rate)
+);
+
+DEFINE_EVENT(clk_rate, clk_set_rate,
+
+	TP_PROTO(struct clk *clk, unsigned long rate),
+
+	TP_ARGS(clk, rate)
+);
+
+DEFINE_EVENT(clk_rate, clk_set_rate_complete,
+
+	TP_PROTO(struct clk *clk, unsigned long rate),
+
+	TP_ARGS(clk, rate)
+);
+
+DECLARE_EVENT_CLASS(clk_parent,
+
+	TP_PROTO(struct clk *clk, struct clk *parent),
+
+	TP_ARGS(clk, parent),
+
+	TP_STRUCT__entry(
+		__string(        name,           __clk_get_name(clk)       )
+		__string(        pname,          __clk_get_name(parent)    )
+	),
+
+	TP_fast_assign(
+		__assign_str(name, __clk_get_name(clk));
+		__assign_str(pname, __clk_get_name(parent));
+	),
+
+	TP_printk("%s %s", __get_str(name), __get_str(pname))
+);
+
+DEFINE_EVENT(clk_parent, clk_set_parent,
+
+	TP_PROTO(struct clk *clk, struct clk *parent),
+
+	TP_ARGS(clk, parent)
+);
+
+DEFINE_EVENT(clk_parent, clk_set_parent_complete,
+
+	TP_PROTO(struct clk *clk, struct clk *parent),
+
+	TP_ARGS(clk, parent)
+);
+
+#endif /* _TRACE_CLK_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>

-- 
The Qualcomm Innovation Center, Inc. is a member of the Code Aurora Forum,
hosted by The Linux Foundation

On Mon, 30 Jun 2014 16:56:39 -0700
Stephen Boyd [off-list ref] wrote:

Does it make sense to do these when clk->ops->unprepared_unused or
uprepare is not set?

You can use DEFINE_EVENT_CONDITIONAL() and add as condition:

   clk->ops->unprepared_unused || clk->ops->unprepare

Same here.

And here.

A pattern is happening.

ditto

ditto

It may make even more sense to add the tracepoints within the if
statement. Especially if you have a return on error.

For example, you would make the above DEFINE_EVENT_CONDITION()
and then add

 TP_CONDITION(clk->ops->unprepared_unused || clk->ops->unprepare)

You can look at include/trace/f2fs.h for an example.

-- Steve

+);
+
+DEFINE_EVENT(clk, clk_unprepare_complete,
+
+	TP_PROTO(struct clk *clk),
+
+	TP_ARGS(clk)
+);
+
+DECLARE_EVENT_CLASS(clk_rate,
+
+	TP_PROTO(struct clk *clk, unsigned long rate),
+
+	TP_ARGS(clk, rate),
+
+	TP_STRUCT__entry(
+		__string(        name,           __clk_get_name(clk)       )
+		__field(unsigned long,           rate                      )
+	),
+
+	TP_fast_assign(
+		__assign_str(name, __clk_get_name(clk));
+		__entry->rate = rate;
+	),
+
+	TP_printk("%s %lu", __get_str(name), (unsigned long)__entry->rate)
+);
+
+DEFINE_EVENT(clk_rate, clk_set_rate,
+
+	TP_PROTO(struct clk *clk, unsigned long rate),
+
+	TP_ARGS(clk, rate)
+);
+
+DEFINE_EVENT(clk_rate, clk_set_rate_complete,
+
+	TP_PROTO(struct clk *clk, unsigned long rate),
+
+	TP_ARGS(clk, rate)
+);
+
+DECLARE_EVENT_CLASS(clk_parent,
+
+	TP_PROTO(struct clk *clk, struct clk *parent),
+
+	TP_ARGS(clk, parent),
+
+	TP_STRUCT__entry(
+		__string(        name,           __clk_get_name(clk)       )
+		__string(        pname,          __clk_get_name(parent)    )
+	),
+
+	TP_fast_assign(
+		__assign_str(name, __clk_get_name(clk));
+		__assign_str(pname, __clk_get_name(parent));
+	),
+
+	TP_printk("%s %s", __get_str(name), __get_str(pname))
+);
+
+DEFINE_EVENT(clk_parent, clk_set_parent,
+
+	TP_PROTO(struct clk *clk, struct clk *parent),
+
+	TP_ARGS(clk, parent)
+);
+
+DEFINE_EVENT(clk_parent, clk_set_parent_complete,
+
+	TP_PROTO(struct clk *clk, struct clk *parent),
+
+	TP_ARGS(clk, parent)
+);
+
+#endif /* _TRACE_CLK_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>

On 06/30/14 17:52, Steven Rostedt wrote:

On Mon, 30 Jun 2014 16:56:39 -0700
Stephen Boyd [off-list ref] wrote:

quoted

@@ -483,10 +486,12 @@ static void clk_unprepare_unused_subtree(struct clk *clk)
 		return;
 
 	if (__clk_is_prepared(clk)) {
+		trace_clk_unprepare(clk);

Does it make sense to do these when clk->ops->unprepared_unused or
uprepare is not set?

You can use DEFINE_EVENT_CONDITIONAL() and add as condition:

   clk->ops->unprepared_unused || clk->ops->unprepare

Neat. I don't know if we actually want to do that though. If we always
record an event even when the hardware doesn't support the operation we
get information about events happening to the clock from a software
perspective. If that isn't important, then we can probably just put it
under the if conditions.

quoted

 		if (clk->ops->enable) {
 			ret = clk->ops->enable(clk->hw);
 			if (ret) {

@@ -945,6 +965,7 @@ static int __clk_enable(struct clk *clk)
 				return ret;

It may make even more sense to add the tracepoints within the if
statement. Especially if you have a return on error.

Right. I was thinking that no "clk*_complete" event would mean there was
some error. Detecting that case is not so easy though. It may be better
to always have the completion event so we know how long hardware
operations take and so that error handling is simpler.

-- 
Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum,
hosted by The Linux Foundation

On Mon, 30 Jun 2014 18:07:49 -0700
Stephen Boyd [off-list ref] wrote:

quoted

quoted

 		if (clk->ops->enable) {
 			ret = clk->ops->enable(clk->hw);
 			if (ret) {

@@ -945,6 +965,7 @@ static int __clk_enable(struct clk *clk)
 				return ret;

It may make even more sense to add the tracepoints within the if
statement. Especially if you have a return on error.

Right. I was thinking that no "clk*_complete" event would mean there was
some error. Detecting that case is not so easy though. It may be better
to always have the completion event so we know how long hardware
operations take and so that error handling is simpler.

You could also have the event record the ret as well.

-- Steve

Quoting Stephen Boyd (2014-06-30 18:07:49)

On 06/30/14 17:52, Steven Rostedt wrote:

quoted

On Mon, 30 Jun 2014 16:56:39 -0700
Stephen Boyd [off-list ref] wrote:

quoted

@@ -483,10 +486,12 @@ static void clk_unprepare_unused_subtree(struct clk *clk)
             return;
 
     if (__clk_is_prepared(clk)) {
+            trace_clk_unprepare(clk);

Does it make sense to do these when clk->ops->unprepared_unused or
uprepare is not set?

You can use DEFINE_EVENT_CONDITIONAL() and add as condition:

   clk->ops->unprepared_unused || clk->ops->unprepare

Neat. I don't know if we actually want to do that though. If we always
record an event even when the hardware doesn't support the operation we
get information about events happening to the clock from a software
perspective. If that isn't important, then we can probably just put it
under the if conditions.

+1 for recording the tree walk even if no hardware operation is backing
it.

Regards,
Mike

quoted

quoted

             if (clk->ops->enable) {
                     ret = clk->ops->enable(clk->hw);
                     if (ret) {

@@ -945,6 +965,7 @@ static int __clk_enable(struct clk *clk)
                             return ret;

It may make even more sense to add the tracepoints within the if
statement. Especially if you have a return on error.

Right. I was thinking that no "clk*_complete" event would mean there was
some error. Detecting that case is not so easy though. It may be better
to always have the completion event so we know how long hardware
operations take and so that error handling is simpler.

-- 
Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum,
hosted by The Linux Foundation