2019-02-15 01:58:47

by Lukasz Luba

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

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 <[email protected]>'
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



2019-02-15 02:00:13

by Lukasz Luba

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

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 <[email protected]>
---
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 <[email protected]>
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


2019-02-15 02:01:21

by Lukasz Luba

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

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 <[email protected]>
Signed-off-by: Lukasz Luba <[email protected]>
---
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


2019-02-15 02:02:00

by Steven Rostedt

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

On Thu, 14 Feb 2019 19:57:56 +0100
Lukasz Luba <[email protected]> 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 <[email protected]>
> Signed-off-by: Lukasz Luba <[email protected]>
> ---
> 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

> }
>
> /**


2019-02-15 16:12:16

by Lukasz Luba

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

Hi Steven,

On 2/14/19 8:07 PM, Steven Rostedt wrote:
> On Thu, 14 Feb 2019 19:57:56 +0100
> Lukasz Luba <[email protected]> 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 <[email protected]>
>> Signed-off-by: Lukasz Luba <[email protected]>
>> ---
>> 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
>
>> }
>>
>> /**
>
>
>