diff mbox series

[v3,6/7] trace: events: add devfreq trace event file

Message ID 1550010238-24002-7-git-send-email-l.luba@partner.samsung.com (mailing list archive)
State Not Applicable, archived
Headers show
Series drivers: devfreq: fix and optimize workqueue mechanism | expand

Commit Message

Lukasz Luba Feb. 12, 2019, 10:23 p.m. UTC 
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 | 39 +++++++++++++++++++++++++++++++++++++++
 2 files changed, 40 insertions(+)
 create mode 100644 include/trace/events/devfreq.h

Comments

Steven Rostedt Feb. 12, 2019, 11:14 p.m. UTC | #1 
On Tue, 12 Feb 2019 23:23:57 +0100
Lukasz Luba <l.luba@partner.samsung.com> wrote:

> 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 | 39 +++++++++++++++++++++++++++++++++++++++
>  2 files changed, 40 insertions(+)
>  create mode 100644 include/trace/events/devfreq.h
> 
> diff --git a/MAINTAINERS b/MAINTAINERS
> index 9919840..c042fda 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..fec9304
> --- /dev/null
> +++ b/include/trace/events/devfreq.h
> @@ -0,0 +1,39 @@
> +/* 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(
> +		__string(dev_name, dev_name)
> +		__field(unsigned long, freq)
> +		__field(unsigned int, polling_ms)
> +		__field(unsigned int, load)
> +	),
> +
> +	TP_fast_assign(
> +		__assign_str(dev_name, dev_name);
> +		__entry->freq = freq;
> +		__entry->polling_ms = polling_ms;
> +		__entry->load = (100 * busy_time) / total_time;

How critical is the code that this trace event is called in. If it is
not that critical (it is a slow path), then this is fine, but if this
is not a slow path (something triggered 100 HZ or less), then I would
recommend moving the above calculation to TP_printk(). A divide is a
slow operation, and is best to do that in the post processing. The
current location does the divide at the time of the tracepoint is
called.

I would also have a check to make sure that total_time is not zero
here, otherwise that could be bad.

		__entry->busy_time = busy_time;
		__entry->total_time = total_time;

> +	),
> +
> +	TP_printk("dev_name=%s freq=%lu polling_ms=%u load=%u",


> +		__get_str(dev_name), __entry->freq, __entry->polling_ms,

		__entry->total_time == 0 ? 100 :
			__entry->busy_time / __entry->total_time)

-- Steve

> +		__entry->load)
> +);
> +#endif /* _TRACE_DEVFREQ_H */
> +
> +/* This part must be outside protection */
> +#include <trace/define_trace.h>
Lukasz Luba Feb. 13, 2019, 1:35 p.m. UTC | #2 
Hi Steven,

On 2/13/19 12:14 AM, Steven Rostedt wrote:
> On Tue, 12 Feb 2019 23:23:57 +0100
> Lukasz Luba <l.luba@partner.samsung.com> wrote:
> 
>> 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 | 39 +++++++++++++++++++++++++++++++++++++++
>>   2 files changed, 40 insertions(+)
>>   create mode 100644 include/trace/events/devfreq.h
>>
>> diff --git a/MAINTAINERS b/MAINTAINERS
>> index 9919840..c042fda 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..fec9304
>> --- /dev/null
>> +++ b/include/trace/events/devfreq.h
>> @@ -0,0 +1,39 @@
>> +/* 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(
>> +		__string(dev_name, dev_name)
>> +		__field(unsigned long, freq)
>> +		__field(unsigned int, polling_ms)
>> +		__field(unsigned int, load)
>> +	),
>> +
>> +	TP_fast_assign(
>> +		__assign_str(dev_name, dev_name);
>> +		__entry->freq = freq;
>> +		__entry->polling_ms = polling_ms;
>> +		__entry->load = (100 * busy_time) / total_time;
> 
> How critical is the code that this trace event is called in. If it is
> not that critical (it is a slow path), then this is fine, but if this
> is not a slow path (something triggered 100 HZ or less), then I would
> recommend moving the above calculation to TP_printk(). A divide is a
> slow operation, and is best to do that in the post processing. The
> current location does the divide at the time of the tracepoint is
> called.
I wasn't aware of these two stages, good to know.
I will move it to TP_printk().
> 
> I would also have a check to make sure that total_time is not zero
> here, otherwise that could be bad.
> 
> 		__entry->busy_time = busy_time;
> 		__entry->total_time = total_time;
> 

>> +	),
>> +
>> +	TP_printk("dev_name=%s freq=%lu polling_ms=%u load=%u",
> 
> 
>> +		__get_str(dev_name), __entry->freq, __entry->polling_ms,
> 
> 		__entry->total_time == 0 ? 100 :
> 			__entry->busy_time / __entry->total_time)
Thank you for the review.
I will add this check.

Regards,
Lukasz
> 
> -- Steve
> 
>> +		__entry->load)
>> +);
>> +#endif /* _TRACE_DEVFREQ_H */
>> +
>> +/* This part must be outside protection */
>> +#include <trace/define_trace.h>
> 
> 
>
Steven Rostedt Feb. 13, 2019, 1:56 p.m. UTC | #3 
On Tue, 12 Feb 2019 23:23:57 +0100
Lukasz Luba <l.luba@partner.samsung.com> wrote:

> 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 | 39 +++++++++++++++++++++++++++++++++++++++
>  2 files changed, 40 insertions(+)
>  create mode 100644 include/trace/events/devfreq.h
> 
> diff --git a/MAINTAINERS b/MAINTAINERS
> index 9919840..c042fda 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..fec9304
> --- /dev/null
> +++ b/include/trace/events/devfreq.h
> @@ -0,0 +1,39 @@
> +/* 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(
> +		__string(dev_name, dev_name)

I would also put the string at the end. Strings are stored as a dynamic
array in the event, where the position of __string() holds a 32 bit
number. The 16 MSBs is the length of the string and the 16 LSBs is the
offset into the trace event (after the TP_STRUCT__entry).

That means on a 64 bit machine, there's a chance that this struct will
have a 4 byte "hole" between the __string() meta data and the freq
field.

-- Steve

> +		__field(unsigned long, freq)
> +		__field(unsigned int, polling_ms)
> +		__field(unsigned int, load)
> +	),
> +
> +	TP_fast_assign(
> +		__assign_str(dev_name, dev_name);
> +		__entry->freq = freq;
> +		__entry->polling_ms = polling_ms;
> +		__entry->load = (100 * busy_time) / total_time;
> +	),
> +
> +	TP_printk("dev_name=%s freq=%lu polling_ms=%u load=%u",
> +		__get_str(dev_name), __entry->freq, __entry->polling_ms,
> +		__entry->load)
> +);
> +#endif /* _TRACE_DEVFREQ_H */
> +
> +/* This part must be outside protection */
> +#include <trace/define_trace.h>
Lukasz Luba Feb. 13, 2019, 2:37 p.m. UTC | #4 
Hi Steven,

On 2/13/19 2:56 PM, Steven Rostedt wrote:
> On Tue, 12 Feb 2019 23:23:57 +0100
> Lukasz Luba <l.luba@partner.samsung.com> wrote:
> 
>> 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 | 39 +++++++++++++++++++++++++++++++++++++++
>>   2 files changed, 40 insertions(+)
>>   create mode 100644 include/trace/events/devfreq.h
>>
>> diff --git a/MAINTAINERS b/MAINTAINERS
>> index 9919840..c042fda 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..fec9304
>> --- /dev/null
>> +++ b/include/trace/events/devfreq.h
>> @@ -0,0 +1,39 @@
>> +/* 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(
>> +		__string(dev_name, dev_name)
> 
> I would also put the string at the end. Strings are stored as a dynamic
> array in the event, where the position of __string() holds a 32 bit
> number. The 16 MSBs is the length of the string and the 16 LSBs is the
> offset into the trace event (after the TP_STRUCT__entry).
That's a nice engineering. Thank you for sharing this knowledge.
> 
> That means on a 64 bit machine, there's a chance that this struct will
> have a 4 byte "hole" between the __string() meta data and the freq
> field.
I will put the string at the end.

Regards,
Lukasz
> 
> -- Steve
> 
>> +		__field(unsigned long, freq)
>> +		__field(unsigned int, polling_ms)
>> +		__field(unsigned int, load)
>> +	),
>> +
>> +	TP_fast_assign(
>> +		__assign_str(dev_name, dev_name);
>> +		__entry->freq = freq;
>> +		__entry->polling_ms = polling_ms;
>> +		__entry->load = (100 * busy_time) / total_time;
>> +	),
>> +
>> +	TP_printk("dev_name=%s freq=%lu polling_ms=%u load=%u",
>> +		__get_str(dev_name), __entry->freq, __entry->polling_ms,
>> +		__entry->load)
>> +);
>> +#endif /* _TRACE_DEVFREQ_H */
>> +
>> +/* This part must be outside protection */
>> +#include <trace/define_trace.h>
> 
> 
>
Chanwoo Choi Feb. 14, 2019, 5:01 a.m. UTC | #5 
Hi Lukasz,

On 19. 2. 13. 오후 10:35, Lukasz Luba wrote:
> Hi Steven,
> 
> On 2/13/19 12:14 AM, Steven Rostedt wrote:
>> On Tue, 12 Feb 2019 23:23:57 +0100
>> Lukasz Luba <l.luba@partner.samsung.com> wrote:
>>
>>> 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 | 39 +++++++++++++++++++++++++++++++++++++++
>>>   2 files changed, 40 insertions(+)
>>>   create mode 100644 include/trace/events/devfreq.h
>>>
>>> diff --git a/MAINTAINERS b/MAINTAINERS
>>> index 9919840..c042fda 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..fec9304
>>> --- /dev/null
>>> +++ b/include/trace/events/devfreq.h
>>> @@ -0,0 +1,39 @@
>>> +/* 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(
>>> +		__string(dev_name, dev_name)
>>> +		__field(unsigned long, freq)
>>> +		__field(unsigned int, polling_ms)
>>> +		__field(unsigned int, load)
>>> +	),
>>> +
>>> +	TP_fast_assign(
>>> +		__assign_str(dev_name, dev_name);
>>> +		__entry->freq = freq;
>>> +		__entry->polling_ms = polling_ms;
>>> +		__entry->load = (100 * busy_time) / total_time;
>>
>> How critical is the code that this trace event is called in. If it is
>> not that critical (it is a slow path), then this is fine, but if this
>> is not a slow path (something triggered 100 HZ or less), then I would
>> recommend moving the above calculation to TP_printk(). A divide is a
>> slow operation, and is best to do that in the post processing. The
>> current location does the divide at the time of the tracepoint is
>> called.
> I wasn't aware of these two stages, good to know.
> I will move it to TP_printk().
>>
>> I would also have a check to make sure that total_time is not zero
>> here, otherwise that could be bad.
>>
>> 		__entry->busy_time = busy_time;
>> 		__entry->total_time = total_time;
>>
> 
>>> +	),
>>> +
>>> +	TP_printk("dev_name=%s freq=%lu polling_ms=%u load=%u",
>>
>>
>>> +		__get_str(dev_name), __entry->freq, __entry->polling_ms,
>>
>> 		__entry->total_time == 0 ? 100 :
>> 			__entry->busy_time / __entry->total_time)
> Thank you for the review.
> I will add this check.
> 
> Regards,
> Lukasz
>>
>> -- Steve
>>
>>> +		__entry->load)
>>> +);
>>> +#endif /* _TRACE_DEVFREQ_H */
>>> +
>>> +/* This part must be outside protection */
>>> +#include <trace/define_trace.h>
>>
>>
>>
> 
> 

I agree that trace point is necessary for devfreq framework.
Reviewed-by: Chanwoo Choi <cw00.choi@samsung.com>
diff mbox series

Patch

diff --git a/MAINTAINERS b/MAINTAINERS
index 9919840..c042fda 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..fec9304
--- /dev/null
+++ b/include/trace/events/devfreq.h
@@ -0,0 +1,39 @@ 
+/* 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(
+		__string(dev_name, dev_name)
+		__field(unsigned long, freq)
+		__field(unsigned int, polling_ms)
+		__field(unsigned int, load)
+	),
+
+	TP_fast_assign(
+		__assign_str(dev_name, dev_name);
+		__entry->freq = freq;
+		__entry->polling_ms = polling_ms;
+		__entry->load = (100 * busy_time) / total_time;
+	),
+
+	TP_printk("dev_name=%s freq=%lu polling_ms=%u load=%u",
+		__get_str(dev_name), __entry->freq, __entry->polling_ms,
+		__entry->load)
+);
+#endif /* _TRACE_DEVFREQ_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>