diff mbox series

[v2,2/2] trace: allocate space from temparary trace sequence buffer

Message ID 1671078807-20748-2-git-send-email-quic_linyyuan@quicinc.com
State New
Headers
Series [v1,1/2] trace: add new file under include/trace/stages/ for perf/bpf |

Commit Message

Linyu Yuan Dec. 15, 2022, 4:33 a.m. UTC 
  there is one dwc3 trace event declare as below,
DECLARE_EVENT_CLASS(dwc3_log_event,
	TP_PROTO(u32 event, struct dwc3 *dwc),
	TP_ARGS(event, dwc),
	TP_STRUCT__entry(
		__field(u32, event)
		__field(u32, ep0state)
		__dynamic_array(char, str, DWC3_MSG_MAX)
	),
	TP_fast_assign(
		__entry->event = event;
		__entry->ep0state = dwc->ep0state;
	),
	TP_printk("event (%08x): %s", __entry->event,
			dwc3_decode_event(__get_str(str), DWC3_MSG_MAX,
				__entry->event, __entry->ep0state))
);
the problem is when trace function called, it will allocate up to
DWC3_MSG_MAX bytes from trace event buffer, but never fill the buffer
during fast assignment, it only fill the buffer when output function are
called, so this means if output function are not called, the buffer will
never used.

add __get_buf(len) which allocate space from iter->tmp_seq when trace
output function called, it allow user write any data to allocatd space.

the mentioned dwc3 trace event will changed as below,
DECLARE_EVENT_CLASS(dwc3_log_event,
	TP_PROTO(u32 event, struct dwc3 *dwc),
	TP_ARGS(event, dwc),
	TP_STRUCT__entry(
		__field(u32, event)
		__field(u32, ep0state)
	),
	TP_fast_assign(
		__entry->event = event;
		__entry->ep0state = dwc->ep0state;
	),
	TP_printk("event (%08x): %s", __entry->event,
		dwc3_decode_event(__get_buf(DWC3_MSG_MAX), DWC3_MSG_MAX,
				__entry->event, __entry->ep0state))
);.

Signed-off-by: Linyu Yuan <quic_linyyuan@quicinc.com>
---
 include/linux/trace_seq.h                  |  6 ++++++
 include/trace/stages/stage3_trace_output.h |  4 ++++
 include/trace/stages/stage7_class_define.h |  1 +
 kernel/trace/trace_seq.c                   | 31 ++++++++++++++++++++++++++++++
 4 files changed, 42 insertions(+)

Comments

Steven Rostedt Dec. 15, 2022, 4:54 a.m. UTC | #1 
On Thu, 15 Dec 2022 12:33:27 +0800
Linyu Yuan <quic_linyyuan@quicinc.com> wrote:

> there is one dwc3 trace event declare as below,
> DECLARE_EVENT_CLASS(dwc3_log_event,
> 	TP_PROTO(u32 event, struct dwc3 *dwc),
> 	TP_ARGS(event, dwc),
> 	TP_STRUCT__entry(
> 		__field(u32, event)
> 		__field(u32, ep0state)
> 		__dynamic_array(char, str, DWC3_MSG_MAX)
> 	),
> 	TP_fast_assign(
> 		__entry->event = event;
> 		__entry->ep0state = dwc->ep0state;
> 	),
> 	TP_printk("event (%08x): %s", __entry->event,
> 			dwc3_decode_event(__get_str(str), DWC3_MSG_MAX,
> 				__entry->event, __entry->ep0state))
> );
> the problem is when trace function called, it will allocate up to
> DWC3_MSG_MAX bytes from trace event buffer, but never fill the buffer
> during fast assignment, it only fill the buffer when output function are
> called, so this means if output function are not called, the buffer will
> never used.
> 
> add __get_buf(len) which allocate space from iter->tmp_seq when trace
> output function called, it allow user write any data to allocatd space.
> 
> the mentioned dwc3 trace event will changed as below,
> DECLARE_EVENT_CLASS(dwc3_log_event,
> 	TP_PROTO(u32 event, struct dwc3 *dwc),
> 	TP_ARGS(event, dwc),
> 	TP_STRUCT__entry(
> 		__field(u32, event)
> 		__field(u32, ep0state)
> 	),
> 	TP_fast_assign(
> 		__entry->event = event;
> 		__entry->ep0state = dwc->ep0state;
> 	),
> 	TP_printk("event (%08x): %s", __entry->event,
> 		dwc3_decode_event(__get_buf(DWC3_MSG_MAX), DWC3_MSG_MAX,
> 				__entry->event, __entry->ep0state))
> );.
> 
> Signed-off-by: Linyu Yuan <quic_linyyuan@quicinc.com>


No!

Here, I did it for you:

-- Steve

diff --git a/drivers/usb/dwc3/debug.h b/drivers/usb/dwc3/debug.h
index 48b44b88dc25..81abdcbfc660 100644
--- a/drivers/usb/dwc3/debug.h
+++ b/drivers/usb/dwc3/debug.h
@@ -11,6 +11,7 @@
 #ifndef __DWC3_DEBUG_H
 #define __DWC3_DEBUG_H
 
+#include <linux/trace_seq.h>
 #include "core.h"
 
 /**
@@ -381,6 +382,19 @@ static inline const char *dwc3_decode_event(char *str, size_t size, u32 event,
 		return dwc3_ep_event_string(str, size, &evt.depevt, ep0state);
 }
 
+static inline const char *dwc3_decode_event_seq(struct trace_seq *p,
+						u32 event, u32 ep0state)
+{
+	char *str = trace_seq_buffer_ptr(p);
+	int size = seq_buf_buffer_left(&p->seq);
+
+	dwc3_decode_event(str, size, event, ep0state);
+
+	seq_buf_commit(&p->seq, strlen(str));
+
+	return str;
+}
+
 static inline const char *dwc3_ep_cmd_status_string(int status)
 {
 	switch (status) {
diff --git a/drivers/usb/dwc3/trace.h b/drivers/usb/dwc3/trace.h
index 1975aec8d36d..bee2589e85a8 100644
--- a/drivers/usb/dwc3/trace.h
+++ b/drivers/usb/dwc3/trace.h
@@ -54,15 +54,13 @@ DECLARE_EVENT_CLASS(dwc3_log_event,
 	TP_STRUCT__entry(
 		__field(u32, event)
 		__field(u32, ep0state)
-		__dynamic_array(char, str, DWC3_MSG_MAX)
 	),
 	TP_fast_assign(
 		__entry->event = event;
 		__entry->ep0state = dwc->ep0state;
 	),
 	TP_printk("event (%08x): %s", __entry->event,
-			dwc3_decode_event(__get_str(str), DWC3_MSG_MAX,
-					__entry->event, __entry->ep0state))
+			dwc3_decode_event_seq(p, __entry->event, __entry->ep0state))
 );
 
 DEFINE_EVENT(dwc3_log_event, dwc3_event,
Linyu Yuan Dec. 15, 2022, 5:08 a.m. UTC | #2 
On 12/15/2022 12:54 PM, Steven Rostedt wrote:
> On Thu, 15 Dec 2022 12:33:27 +0800
> Linyu Yuan <quic_linyyuan@quicinc.com> wrote:
>
>> there is one dwc3 trace event declare as below,
>> DECLARE_EVENT_CLASS(dwc3_log_event,
>> 	TP_PROTO(u32 event, struct dwc3 *dwc),
>> 	TP_ARGS(event, dwc),
>> 	TP_STRUCT__entry(
>> 		__field(u32, event)
>> 		__field(u32, ep0state)
>> 		__dynamic_array(char, str, DWC3_MSG_MAX)
>> 	),
>> 	TP_fast_assign(
>> 		__entry->event = event;
>> 		__entry->ep0state = dwc->ep0state;
>> 	),
>> 	TP_printk("event (%08x): %s", __entry->event,
>> 			dwc3_decode_event(__get_str(str), DWC3_MSG_MAX,
>> 				__entry->event, __entry->ep0state))
>> );
>> the problem is when trace function called, it will allocate up to
>> DWC3_MSG_MAX bytes from trace event buffer, but never fill the buffer
>> during fast assignment, it only fill the buffer when output function are
>> called, so this means if output function are not called, the buffer will
>> never used.
>>
>> add __get_buf(len) which allocate space from iter->tmp_seq when trace
>> output function called, it allow user write any data to allocatd space.
>>
>> the mentioned dwc3 trace event will changed as below,
>> DECLARE_EVENT_CLASS(dwc3_log_event,
>> 	TP_PROTO(u32 event, struct dwc3 *dwc),
>> 	TP_ARGS(event, dwc),
>> 	TP_STRUCT__entry(
>> 		__field(u32, event)
>> 		__field(u32, ep0state)
>> 	),
>> 	TP_fast_assign(
>> 		__entry->event = event;
>> 		__entry->ep0state = dwc->ep0state;
>> 	),
>> 	TP_printk("event (%08x): %s", __entry->event,
>> 		dwc3_decode_event(__get_buf(DWC3_MSG_MAX), DWC3_MSG_MAX,
>> 				__entry->event, __entry->ep0state))
>> );.
>>
>> Signed-off-by: Linyu Yuan <quic_linyyuan@quicinc.com>
>
> No!
ok, so you don't like a common function in trace_seq.c ?
>
> Here, I did it for you:
>
> -- Steve
>
> diff --git a/drivers/usb/dwc3/debug.h b/drivers/usb/dwc3/debug.h
> index 48b44b88dc25..81abdcbfc660 100644
> --- a/drivers/usb/dwc3/debug.h
> +++ b/drivers/usb/dwc3/debug.h
> @@ -11,6 +11,7 @@
>   #ifndef __DWC3_DEBUG_H
>   #define __DWC3_DEBUG_H
>   
> +#include <linux/trace_seq.h>
>   #include "core.h"
>   
>   /**
> @@ -381,6 +382,19 @@ static inline const char *dwc3_decode_event(char *str, size_t size, u32 event,
>   		return dwc3_ep_event_string(str, size, &evt.depevt, ep0state);
>   }
>   
> +static inline const char *dwc3_decode_event_seq(struct trace_seq *p,
> +						u32 event, u32 ep0state)
> +{
> +	char *str = trace_seq_buffer_ptr(p);
> +	int size = seq_buf_buffer_left(&p->seq);
> +
> +	dwc3_decode_event(str, size, event, ep0state);
> +
> +	seq_buf_commit(&p->seq, strlen(str));
> +
> +	return str;
> +}
> +
>   static inline const char *dwc3_ep_cmd_status_string(int status)
>   {
>   	switch (status) {
> diff --git a/drivers/usb/dwc3/trace.h b/drivers/usb/dwc3/trace.h
> index 1975aec8d36d..bee2589e85a8 100644
> --- a/drivers/usb/dwc3/trace.h
> +++ b/drivers/usb/dwc3/trace.h
> @@ -54,15 +54,13 @@ DECLARE_EVENT_CLASS(dwc3_log_event,
>   	TP_STRUCT__entry(
>   		__field(u32, event)
>   		__field(u32, ep0state)
> -		__dynamic_array(char, str, DWC3_MSG_MAX)
>   	),
>   	TP_fast_assign(
>   		__entry->event = event;
>   		__entry->ep0state = dwc->ep0state;
>   	),
>   	TP_printk("event (%08x): %s", __entry->event,
> -			dwc3_decode_event(__get_str(str), DWC3_MSG_MAX,
> -					__entry->event, __entry->ep0state))
> +			dwc3_decode_event_seq(p, __entry->event, __entry->ep0state))
>   );
>   
>   DEFINE_EVENT(dwc3_log_event, dwc3_event,
Steven Rostedt Dec. 15, 2022, 12:09 p.m. UTC | #3 
On Thu, 15 Dec 2022 13:08:21 +0800
Linyu Yuan <quic_linyyuan@quicinc.com> wrote:

> On 12/15/2022 12:54 PM, Steven Rostedt wrote:
> > On Thu, 15 Dec 2022 12:33:27 +0800
> > Linyu Yuan <quic_linyyuan@quicinc.com> wrote:
> >  
> >> there is one dwc3 trace event declare as below,
> >> DECLARE_EVENT_CLASS(dwc3_log_event,
> >> 	TP_PROTO(u32 event, struct dwc3 *dwc),
> >> 	TP_ARGS(event, dwc),
> >> 	TP_STRUCT__entry(
> >> 		__field(u32, event)
> >> 		__field(u32, ep0state)
> >> 		__dynamic_array(char, str, DWC3_MSG_MAX)
> >> 	),
> >> 	TP_fast_assign(
> >> 		__entry->event = event;
> >> 		__entry->ep0state = dwc->ep0state;
> >> 	),
> >> 	TP_printk("event (%08x): %s", __entry->event,
> >> 			dwc3_decode_event(__get_str(str), DWC3_MSG_MAX,
> >> 				__entry->event, __entry->ep0state))
> >> );
> >> the problem is when trace function called, it will allocate up to
> >> DWC3_MSG_MAX bytes from trace event buffer, but never fill the buffer
> >> during fast assignment, it only fill the buffer when output function are
> >> called, so this means if output function are not called, the buffer will
> >> never used.
> >>
> >> add __get_buf(len) which allocate space from iter->tmp_seq when trace
> >> output function called, it allow user write any data to allocatd space.
> >>
> >> the mentioned dwc3 trace event will changed as below,
> >> DECLARE_EVENT_CLASS(dwc3_log_event,
> >> 	TP_PROTO(u32 event, struct dwc3 *dwc),
> >> 	TP_ARGS(event, dwc),
> >> 	TP_STRUCT__entry(
> >> 		__field(u32, event)
> >> 		__field(u32, ep0state)
> >> 	),
> >> 	TP_fast_assign(
> >> 		__entry->event = event;
> >> 		__entry->ep0state = dwc->ep0state;
> >> 	),
> >> 	TP_printk("event (%08x): %s", __entry->event,
> >> 		dwc3_decode_event(__get_buf(DWC3_MSG_MAX), DWC3_MSG_MAX,
> >> 				__entry->event, __entry->ep0state))
> >> );.
> >>
> >> Signed-off-by: Linyu Yuan <quic_linyyuan@quicinc.com>  
> >
> > No!  

> ok, so you don't like a common function in trace_seq.c ?

Ah sorry, I got confused by the name "alloc" thinking you allocated a new
trace_seq. I misread your patch (it was late and I was about to go to bed
when I replied).

Let me look at it again when I'm more awake ;-)

-- Steve
Steven Rostedt Dec. 15, 2022, 1:23 p.m. UTC | #4 
On Thu, 15 Dec 2022 12:33:27 +0800
Linyu Yuan <quic_linyyuan@quicinc.com> wrote:

> --- a/include/linux/trace_seq.h
> +++ b/include/linux/trace_seq.h
> @@ -95,6 +95,7 @@ extern void trace_seq_bitmask(struct trace_seq *s, const unsigned long *maskp,
>  extern int trace_seq_hex_dump(struct trace_seq *s, const char *prefix_str,
>  			      int prefix_type, int rowsize, int groupsize,
>  			      const void *buf, size_t len, bool ascii);
> +void *trace_seq_alloc_buffer(struct trace_seq *s, int len);

So, I really don't like the name with "alloc" in it. That makes the
assumption that it also needs to be freed. Which it does not, and why it
confused me last night.

A better name would be trace_seq_acquire(s, len);

And it should return a char *, as it it process stings and not arbitrary
binary data.

> +/**
> + * trace_seq_alloc_buffer - allocate seq buffer with size len
> + * @s: trace sequence descriptor
> + * @len: size of buffer to be allocated
> + *
> + * allocate space with size of @len from seq buffer for output usage,
> + * On success, it returns start address of the allocated buffer,
> + * user can fill data start from the address, user should make sure the
> + * data length not exceed the @len, if it exceed, behavior is undefined.
> + *
> + * Returns NULL if no buffer can be allocated, it also means system will
> + * crash, it is user responsiblity to make sure total buffer used will
> + * not exceed PAGE_SIZE.
> + *
> + * it allow multiple usage in one trace output function call.
> + */
> +void *trace_seq_alloc_buffer(struct trace_seq *s, int len)

char *trace_seq_acquire(struct trace_seq *s, int len)

> +{
> +	char *buf = trace_seq_buffer_ptr(s);
> +

You need to check the length first before committing:

	if (seq_buf_buffer_left(&s->seq) < len)
		return NULL;

	
> +	seq_buf_commit(&s->seq, len);

Because the above is a bug if len is too big.

> +
> +	if (unlikely(seq_buf_has_overflowed(&s->seq))) {

And then we don't need this either.

I must apologize for the response last night. It was past my normal bed
time, and I must really avoid reviewing patches when I should be going to
bed ;-)

-- Steve


> +		s->full = 1;
> +		return NULL;
> +	}
> +
> +	return (void *)buf;
> +}
> +EXPORT_SYMBOL(trace_seq_alloc_buffer);
Linyu Yuan Dec. 16, 2022, 2:05 a.m. UTC | #5 
On 12/15/2022 9:23 PM, Steven Rostedt wrote:
> On Thu, 15 Dec 2022 12:33:27 +0800
> Linyu Yuan <quic_linyyuan@quicinc.com> wrote:
>
>> --- a/include/linux/trace_seq.h
>> +++ b/include/linux/trace_seq.h
>> @@ -95,6 +95,7 @@ extern void trace_seq_bitmask(struct trace_seq *s, const unsigned long *maskp,
>>   extern int trace_seq_hex_dump(struct trace_seq *s, const char *prefix_str,
>>   			      int prefix_type, int rowsize, int groupsize,
>>   			      const void *buf, size_t len, bool ascii);
>> +void *trace_seq_alloc_buffer(struct trace_seq *s, int len);
> So, I really don't like the name with "alloc" in it. That makes the
> assumption that it also needs to be freed. Which it does not, and why it
> confused me last night.
>
> A better name would be trace_seq_acquire(s, len);
>
> And it should return a char *, as it it process stings and not arbitrary
> binary data.
thanks, will update next version.
>
>> +/**
>> + * trace_seq_alloc_buffer - allocate seq buffer with size len
>> + * @s: trace sequence descriptor
>> + * @len: size of buffer to be allocated
>> + *
>> + * allocate space with size of @len from seq buffer for output usage,
>> + * On success, it returns start address of the allocated buffer,
>> + * user can fill data start from the address, user should make sure the
>> + * data length not exceed the @len, if it exceed, behavior is undefined.
>> + *
>> + * Returns NULL if no buffer can be allocated, it also means system will
>> + * crash, it is user responsiblity to make sure total buffer used will
>> + * not exceed PAGE_SIZE.
>> + *
>> + * it allow multiple usage in one trace output function call.
>> + */
>> +void *trace_seq_alloc_buffer(struct trace_seq *s, int len)
> char *trace_seq_acquire(struct trace_seq *s, int len)
>
>> +{
>> +	char *buf = trace_seq_buffer_ptr(s);
>> +
> You need to check the length first before committing:
>
> 	if (seq_buf_buffer_left(&s->seq) < len)
> 		return NULL;
will change next version.
> 	
>> +	seq_buf_commit(&s->seq, len);
> Because the above is a bug if len is too big.
>
>> +
>> +	if (unlikely(seq_buf_has_overflowed(&s->seq))) {
> And then we don't need this either.
>
> I must apologize for the response last night. It was past my normal bed
> time, and I must really avoid reviewing patches when I should be going to
> bed ;-)

sorry to bring your attention near your bed time.

I accept late response next time 😁.

thanks again for all your comment today, it is very good.

>
> -- Steve
>
>
>> +		s->full = 1;
>> +		return NULL;
>> +	}
>> +
>> +	return (void *)buf;
>> +}
>> +EXPORT_SYMBOL(trace_seq_alloc_buffer);
diff mbox series

Patch

diff --git a/include/linux/trace_seq.h b/include/linux/trace_seq.h
index 5a2c650..9703d03 100644
--- a/include/linux/trace_seq.h
+++ b/include/linux/trace_seq.h
@@ -95,6 +95,7 @@  extern void trace_seq_bitmask(struct trace_seq *s, const unsigned long *maskp,
 extern int trace_seq_hex_dump(struct trace_seq *s, const char *prefix_str,
 			      int prefix_type, int rowsize, int groupsize,
 			      const void *buf, size_t len, bool ascii);
+void *trace_seq_alloc_buffer(struct trace_seq *s, int len);
 
 #else /* CONFIG_TRACING */
 static inline void trace_seq_printf(struct trace_seq *s, const char *fmt, ...)
@@ -138,6 +139,11 @@  static inline int trace_seq_path(struct trace_seq *s, const struct path *path)
 {
 	return 0;
 }
+
+static inline void *trace_seq_alloc_buffer(struct trace_seq *s, int len)
+{
+	return NULL;
+}
 #endif /* CONFIG_TRACING */
 
 #endif /* _LINUX_TRACE_SEQ_H */
diff --git a/include/trace/stages/stage3_trace_output.h b/include/trace/stages/stage3_trace_output.h
index 66374df..a2921bd 100644
--- a/include/trace/stages/stage3_trace_output.h
+++ b/include/trace/stages/stage3_trace_output.h
@@ -139,3 +139,7 @@ 
 		u64 ____val = (u64)(value);		\
 		(u32) do_div(____val, NSEC_PER_SEC);	\
 	})
+
+#undef __get_buf
+#define __get_buf(len)							\
+	trace_seq_alloc_buffer(p, len)
diff --git a/include/trace/stages/stage7_class_define.h b/include/trace/stages/stage7_class_define.h
index 8795429..bcb960d 100644
--- a/include/trace/stages/stage7_class_define.h
+++ b/include/trace/stages/stage7_class_define.h
@@ -23,6 +23,7 @@ 
 #undef __get_rel_sockaddr
 #undef __print_array
 #undef __print_hex_dump
+#undef __get_buf
 
 /*
  * The below is not executed in the kernel. It is only what is
diff --git a/kernel/trace/trace_seq.c b/kernel/trace/trace_seq.c
index 9c90b3a..1501e3b 100644
--- a/kernel/trace/trace_seq.c
+++ b/kernel/trace/trace_seq.c
@@ -403,3 +403,34 @@  int trace_seq_hex_dump(struct trace_seq *s, const char *prefix_str,
 	return 1;
 }
 EXPORT_SYMBOL(trace_seq_hex_dump);
+
+/**
+ * trace_seq_alloc_buffer - allocate seq buffer with size len
+ * @s: trace sequence descriptor
+ * @len: size of buffer to be allocated
+ *
+ * allocate space with size of @len from seq buffer for output usage,
+ * On success, it returns start address of the allocated buffer,
+ * user can fill data start from the address, user should make sure the
+ * data length not exceed the @len, if it exceed, behavior is undefined.
+ *
+ * Returns NULL if no buffer can be allocated, it also means system will
+ * crash, it is user responsiblity to make sure total buffer used will
+ * not exceed PAGE_SIZE.
+ *
+ * it allow multiple usage in one trace output function call.
+ */
+void *trace_seq_alloc_buffer(struct trace_seq *s, int len)
+{
+	char *buf = trace_seq_buffer_ptr(s);
+
+	seq_buf_commit(&s->seq, len);
+
+	if (unlikely(seq_buf_has_overflowed(&s->seq))) {
+		s->full = 1;
+		return NULL;
+	}
+
+	return (void *)buf;
+}
+EXPORT_SYMBOL(trace_seq_alloc_buffer);