[PATCH 0/2] tracing: drivers: devfreq: add basic trace mechanism

[PATCH 0/2] tracing: drivers: devfreq: add basic trace mechanism

[Lukasz Luba]

Hi all,

This patch set adds support for tracing in devfreq framework. It is related
to the discussion regarding devfreq workqueue mechanism and wake-ups.
These two tracing patches have been submitted in larger patch set, which
needs more discussion. For the further discussion and development there
is a need of measurements/testing, though. It was agreed that trace events
would help. The whole discussion is here [1].

With these patches it is possible to capture current behaviour for the 
devfreq subsystem and devices such as when and which workqueue is used,
on which CPU, what is the load and frequency of the device.

A few comments for the first version has been addressed here:
- moved long '/' operation to post-processing phase, according to Seven's
  comments [2] 
- re-ordered fields in the structure to avoid holes, according to Seven's
  comments [3] 
- removed unneeded variable, according to Chanwoo's comment [4]

I did not dare to add 'Reviewed-by: Chanwoo Choi <cw00.choi@samsung.com>'
for the 1st patch, which was in [5], since the code slightly changed.
The 2nd patch has it. 

Regards,
Lukasz Luba

[1] https://lkml.org/lkml/2019/2/12/1179
[2] https://lkml.org/lkml/2019/2/12/1201
[3] https://lkml.org/lkml/2019/2/13/532
[4] https://lkml.org/lkml/2019/2/13/1587
[5] https://lkml.org/lkml/2019/2/14/2

Lukasz Luba (2):
  trace: events: add devfreq trace event file
  drivers: devfreq: add tracing for scheduling work

 MAINTAINERS                    |  1 +
 drivers/devfreq/devfreq.c      |  8 ++++++++
 include/trace/events/devfreq.h | 42 ++++++++++++++++++++++++++++++++++++++++++
 3 files changed, 51 insertions(+)
 create mode 100644 include/trace/events/devfreq.h

-- 
2.7.4

[PATCH 1/2] trace: events: add devfreq trace event file

[Lukasz Luba]

The patch adds a new file for with trace events for devfreq
framework. They are used for performance analysis of the framework.
It also contains updates in MAINTAINERS file adding new entry for
devfreq maintainers.

Signed-off-by: Lukasz Luba <l.luba@partner.samsung.com>
---
 MAINTAINERS                    |  1 +
 include/trace/events/devfreq.h | 42 ++++++++++++++++++++++++++++++++++++++++++
 2 files changed, 43 insertions(+)
 create mode 100644 include/trace/events/devfreq.h

diff --git a/MAINTAINERS b/MAINTAINERS
index 41ce5f4..9c44076 100644
--- a/MAINTAINERS
+++ b/MAINTAINERS
@@ -4447,6 +4447,7 @@ S:	Maintained
 F:	drivers/devfreq/
 F:	include/linux/devfreq.h
 F:	Documentation/devicetree/bindings/devfreq/
+F:	include/trace/events/devfreq.h
 
 DEVICE FREQUENCY EVENT (DEVFREQ-EVENT)
 M:	Chanwoo Choi <cw00.choi@samsung.com>
diff --git a/include/trace/events/devfreq.h b/include/trace/events/devfreq.h
new file mode 100644
index 0000000..d6990dc
--- /dev/null
+++ b/include/trace/events/devfreq.h
@@ -0,0 +1,42 @@
+/* SPDX-License-Identifier: GPL-2.0 */
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM devfreq
+
+#if !defined(_TRACE_DEVFREQ_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_DEVFREQ_H
+
+#include <linux/devfreq.h>
+#include <linux/tracepoint.h>
+
+TRACE_EVENT(devfreq_monitor,
+	TP_PROTO(const char *dev_name, unsigned long freq,
+		 unsigned int polling_ms, unsigned long busy_time,
+		 unsigned long total_time),
+
+	TP_ARGS(dev_name, freq, polling_ms, busy_time, total_time),
+
+	TP_STRUCT__entry(
+		__field(unsigned long, freq)
+		__field(unsigned long, busy_time)
+		__field(unsigned long, total_time)
+		__field(unsigned int, polling_ms)
+		__string(dev_name, dev_name)
+	),
+
+	TP_fast_assign(
+		__entry->freq = freq;
+		__entry->busy_time = busy_time;
+		__entry->total_time = total_time;
+		__entry->polling_ms = polling_ms;
+		__assign_str(dev_name, dev_name);
+	),
+
+	TP_printk("dev_name=%s freq=%lu polling_ms=%u load=%lu",
+		__get_str(dev_name), __entry->freq, __entry->polling_ms,
+		__entry->total_time == 0 ? 100 :
+			(100 * __entry->busy_time) / __entry->total_time)
+);
+#endif /* _TRACE_DEVFREQ_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
-- 
2.7.4

[PATCH 2/2] drivers: devfreq: add tracing for scheduling work

[Lukasz Luba]

This patch add basic tracing of the devfreq workqueue and delayed work.
It aims to capture changes of the polling intervals and device state.

Reviewed-by: Chanwoo Choi <cw00.choi@samsung.com>
Signed-off-by: Lukasz Luba <l.luba@partner.samsung.com>
---
 drivers/devfreq/devfreq.c | 8 ++++++++
 1 file changed, 8 insertions(+)

diff --git a/drivers/devfreq/devfreq.c b/drivers/devfreq/devfreq.c
index 0ae3de7..c9714fd 100644
--- a/drivers/devfreq/devfreq.c
+++ b/drivers/devfreq/devfreq.c
@@ -29,6 +29,9 @@
 #include <linux/of.h>
 #include "governor.h"
 
+#define CREATE_TRACE_POINTS
+#include <trace/events/devfreq.h>
+
 static struct class *devfreq_class;
 
 /*
@@ -394,6 +397,11 @@ static void devfreq_monitor(struct work_struct *work)
 	queue_delayed_work(devfreq_wq, &devfreq->work,
 				msecs_to_jiffies(devfreq->profile->polling_ms));
 	mutex_unlock(&devfreq->lock);
+
+	trace_devfreq_monitor(dev_name(&devfreq->dev), devfreq->previous_freq,
+			      devfreq->profile->polling_ms,
+			      devfreq->last_status.busy_time,
+			      devfreq->last_status.total_time);
 }
 
 /**
-- 
2.7.4

Re: [PATCH 2/2] drivers: devfreq: add tracing for scheduling work

[Steven Rostedt]

On Thu, 14 Feb 2019 19:57:56 +0100
Lukasz Luba <l.luba@partner.samsung.com> wrote:

> This patch add basic tracing of the devfreq workqueue and delayed work.
> It aims to capture changes of the polling intervals and device state.
> 
> Reviewed-by: Chanwoo Choi <cw00.choi@samsung.com>
> Signed-off-by: Lukasz Luba <l.luba@partner.samsung.com>
> ---
>  drivers/devfreq/devfreq.c | 8 ++++++++
>  1 file changed, 8 insertions(+)
> 
> diff --git a/drivers/devfreq/devfreq.c b/drivers/devfreq/devfreq.c
> index 0ae3de7..c9714fd 100644
> --- a/drivers/devfreq/devfreq.c
> +++ b/drivers/devfreq/devfreq.c
> @@ -29,6 +29,9 @@
>  #include <linux/of.h>
>  #include "governor.h"
>  
> +#define CREATE_TRACE_POINTS
> +#include <trace/events/devfreq.h>
> +
>  static struct class *devfreq_class;
>  
>  /*
> @@ -394,6 +397,11 @@ static void devfreq_monitor(struct work_struct *work)
>  	queue_delayed_work(devfreq_wq, &devfreq->work,
>  				msecs_to_jiffies(devfreq->profile->polling_ms));
>  	mutex_unlock(&devfreq->lock);
> +
> +	trace_devfreq_monitor(dev_name(&devfreq->dev), devfreq->previous_freq,
> +			      devfreq->profile->polling_ms,
> +			      devfreq->last_status.busy_time,
> +			      devfreq->last_status.total_time);

I would pass just devfreq into the tracepoint (it will be less work by
gcc in this code path), and do all this work in the TP__fast_assign()

The string can still handle this with:

		__string(dev_name, dev_name(&devfreq->dev))

And assigned:

		__assign_str(dev_name, dev_name(&devfreq->dev))

But the rest of fast assign should be:

	TP_fast_assign(
		__entry->freq = devfreq->previous_freq;
		__entry->busy_time = devfreq->last_status.busy_time;
		__entry->total_time = devfreq->last_status.total_time;
		__entry->polling_ms = devfreq->profile->polling_ms;
		__assign_str(dev_name, dev_name(&deqfreq->dev));
	}

-- Steve

>  }
>  
>  /**

Re: [PATCH 2/2] drivers: devfreq: add tracing for scheduling work

[Lukasz Luba]

Hi Steven,

On 2/14/19 8:07 PM, Steven Rostedt wrote:
> On Thu, 14 Feb 2019 19:57:56 +0100
> Lukasz Luba <l.luba@partner.samsung.com> wrote:
> 
>> This patch add basic tracing of the devfreq workqueue and delayed work.
>> It aims to capture changes of the polling intervals and device state.
>>
>> Reviewed-by: Chanwoo Choi <cw00.choi@samsung.com>
>> Signed-off-by: Lukasz Luba <l.luba@partner.samsung.com>
>> ---
>>   drivers/devfreq/devfreq.c | 8 ++++++++
>>   1 file changed, 8 insertions(+)
>>
>> diff --git a/drivers/devfreq/devfreq.c b/drivers/devfreq/devfreq.c
>> index 0ae3de7..c9714fd 100644
>> --- a/drivers/devfreq/devfreq.c
>> +++ b/drivers/devfreq/devfreq.c
>> @@ -29,6 +29,9 @@
>>   #include <linux/of.h>
>>   #include "governor.h"
>>   
>> +#define CREATE_TRACE_POINTS
>> +#include <trace/events/devfreq.h>
>> +
>>   static struct class *devfreq_class;
>>   
>>   /*
>> @@ -394,6 +397,11 @@ static void devfreq_monitor(struct work_struct *work)
>>   	queue_delayed_work(devfreq_wq, &devfreq->work,
>>   				msecs_to_jiffies(devfreq->profile->polling_ms));
>>   	mutex_unlock(&devfreq->lock);
>> +
>> +	trace_devfreq_monitor(dev_name(&devfreq->dev), devfreq->previous_freq,
>> +			      devfreq->profile->polling_ms,
>> +			      devfreq->last_status.busy_time,
>> +			      devfreq->last_status.total_time);
> 
> I would pass just devfreq into the tracepoint (it will be less work by
> gcc in this code path), and do all this work in the TP__fast_assign()
> 
> The string can still handle this with:
> 
> 		__string(dev_name, dev_name(&devfreq->dev))
> 
> And assigned:
> 
> 		__assign_str(dev_name, dev_name(&devfreq->dev))
> 
> But the rest of fast assign should be:
> 
> 	TP_fast_assign(
> 		__entry->freq = devfreq->previous_freq;
> 		__entry->busy_time = devfreq->last_status.busy_time;
> 		__entry->total_time = devfreq->last_status.total_time;
> 		__entry->polling_ms = devfreq->profile->polling_ms;
> 		__assign_str(dev_name, dev_name(&deqfreq->dev));
> 	}
I agree, it makes sense. Let me test this approach and then send v3
patches. Thank you for the review.

Regards,
Lukasz
> 
> -- Steve
> 
>>   }
>>   
>>   /**
> 
> 
>