[PATCH] cma:tracing: Print alloc result in trace_cma_alloc_finish

[PATCH] cma:tracing: Print alloc result in trace_cma_alloc_finish

[Wenchao Hao]

The result of allocation is not printed in trace_cma_alloc_finish
now, while it's important to do it so we can set filters to catch
specific error on allocation or trigger some operations on specific
error.

Although we have printed the result in log, but the log is
conditional and could not be filtered by tracing event.

What's more, it introduce little overhead to print this result.
The result of allocation is named as errorno in trace.

Signed-off-by: Wenchao Hao <haowenchao@huawei.com>
---
 include/trace/events/cma.h | 32 +++++++++++++++++++++++++++++---
 mm/cma.c                   |  2 +-
 2 files changed, 30 insertions(+), 4 deletions(-)

diff --git a/include/trace/events/cma.h b/include/trace/events/cma.h
index 3d708dae1542..ef75ea606ab2 100644
--- a/include/trace/events/cma.h
+++ b/include/trace/events/cma.h
@@ -91,12 +91,38 @@ TRACE_EVENT(cma_alloc_start,
 		  __entry->align)
 );
 
-DEFINE_EVENT(cma_alloc_class, cma_alloc_finish,
+TRACE_EVENT(cma_alloc_finish,
 
 	TP_PROTO(const char *name, unsigned long pfn, const struct page *page,
-		 unsigned long count, unsigned int align),
+		 unsigned long count, unsigned int align, int errorno),
 
-	TP_ARGS(name, pfn, page, count, align)
+	TP_ARGS(name, pfn, page, count, align, errorno),
+
+	TP_STRUCT__entry(
+		__string(name, name)
+		__field(unsigned long, pfn)
+		__field(const struct page *, page)
+		__field(unsigned long, count)
+		__field(unsigned int, align)
+		__field(int, errorno)
+	),
+
+	TP_fast_assign(
+		__assign_str(name, name);
+		__entry->pfn = pfn;
+		__entry->page = page;
+		__entry->count = count;
+		__entry->align = align;
+		__entry->errorno = errorno;
+	),
+
+	TP_printk("name=%s pfn=0x%lx page=%p count=%lu align=%u errorno=%d",
+		  __get_str(name),
+		  __entry->pfn,
+		  __entry->page,
+		  __entry->count,
+		  __entry->align,
+		  __entry->errorno)
 );
 
 DEFINE_EVENT(cma_alloc_class, cma_alloc_busy_retry,
diff --git a/mm/cma.c b/mm/cma.c
index 4a978e09547a..a75b17b03b66 100644
--- a/mm/cma.c
+++ b/mm/cma.c
@@ -491,7 +491,7 @@ struct page *cma_alloc(struct cma *cma, unsigned long count,
 		start = bitmap_no + mask + 1;
 	}
 
-	trace_cma_alloc_finish(cma->name, pfn, page, count, align);
+	trace_cma_alloc_finish(cma->name, pfn, page, count, align, ret);
 
 	/*
 	 * CMA can allocate multiple page blocks, which results in different
-- 
2.32.0

Re: [PATCH] cma:tracing: Print alloc result in trace_cma_alloc_finish

[Wenchao Hao]

On 2022/12/8 22:21, Wenchao Hao wrote:
> The result of allocation is not printed in trace_cma_alloc_finish
> now, while it's important to do it so we can set filters to catch
> specific error on allocation or trigger some operations on specific
> error.
> 
> Although we have printed the result in log, but the log is
> conditional and could not be filtered by tracing event.
> 
> What's more, it introduce little overhead to print this result.
> The result of allocation is named as errorno in trace.
> 
> Signed-off-by: Wenchao Hao <haowenchao@huawei.com>
> ---
>  include/trace/events/cma.h | 32 +++++++++++++++++++++++++++++---
>  mm/cma.c                   |  2 +-
>  2 files changed, 30 insertions(+), 4 deletions(-)
> 
> diff --git a/include/trace/events/cma.h b/include/trace/events/cma.h
> index 3d708dae1542..ef75ea606ab2 100644
> --- a/include/trace/events/cma.h
> +++ b/include/trace/events/cma.h
> @@ -91,12 +91,38 @@ TRACE_EVENT(cma_alloc_start,
>  		  __entry->align)
>  );
>  
> -DEFINE_EVENT(cma_alloc_class, cma_alloc_finish,
> +TRACE_EVENT(cma_alloc_finish,
>  
>  	TP_PROTO(const char *name, unsigned long pfn, const struct page *page,
> -		 unsigned long count, unsigned int align),
> +		 unsigned long count, unsigned int align, int errorno),
>  
> -	TP_ARGS(name, pfn, page, count, align)
> +	TP_ARGS(name, pfn, page, count, align, errorno),
> +
> +	TP_STRUCT__entry(
> +		__string(name, name)
> +		__field(unsigned long, pfn)
> +		__field(const struct page *, page)
> +		__field(unsigned long, count)
> +		__field(unsigned int, align)
> +		__field(int, errorno)
> +	),
> +
> +	TP_fast_assign(
> +		__assign_str(name, name);
> +		__entry->pfn = pfn;
> +		__entry->page = page;
> +		__entry->count = count;
> +		__entry->align = align;
> +		__entry->errorno = errorno;
> +	),
> +
> +	TP_printk("name=%s pfn=0x%lx page=%p count=%lu align=%u errorno=%d",
> +		  __get_str(name),
> +		  __entry->pfn,
> +		  __entry->page,
> +		  __entry->count,
> +		  __entry->align,
> +		  __entry->errorno)
>  );
>  
>  DEFINE_EVENT(cma_alloc_class, cma_alloc_busy_retry,
> diff --git a/mm/cma.c b/mm/cma.c
> index 4a978e09547a..a75b17b03b66 100644
> --- a/mm/cma.c
> +++ b/mm/cma.c
> @@ -491,7 +491,7 @@ struct page *cma_alloc(struct cma *cma, unsigned long count,
>  		start = bitmap_no + mask + 1;
>  	}
>  
> -	trace_cma_alloc_finish(cma->name, pfn, page, count, align);
> +	trace_cma_alloc_finish(cma->name, pfn, page, count, align, ret);
>  
>  	/*
>  	 * CMA can allocate multiple page blocks, which results in different

pinging

Re: [PATCH] cma:tracing: Print alloc result in trace_cma_alloc_finish

[Steven Rostedt]

On Fri, 16 Dec 2022 19:47:59 +0800
Wenchao Hao <haowenchao@huawei.com> wrote:

> On 2022/12/8 22:21, Wenchao Hao wrote:
> > The result of allocation is not printed in trace_cma_alloc_finish
> > now, while it's important to do it so we can set filters to catch
> > specific error on allocation or trigger some operations on specific
> > error.
> > 
> > Although we have printed the result in log, but the log is
> > conditional and could not be filtered by tracing event.
> > 
> > What's more, it introduce little overhead to print this result.
> > The result of allocation is named as errorno in trace.
> > 
> > Signed-off-by: Wenchao Hao <haowenchao@huawei.com>
> > ---

> 
> pinging


From a tracing point of view, I see nothing wrong with it.

Reviewed-by: Steven Rostedt (Google) <rostedt@goodmis.org>

But I believe Andrew needs to take it.

-- Steve

Re: [PATCH] cma:tracing: Print alloc result in trace_cma_alloc_finish

[Masami Hiramatsu]

On Thu, 8 Dec 2022 22:21:30 +0800
Wenchao Hao <haowenchao@huawei.com> wrote:

> The result of allocation is not printed in trace_cma_alloc_finish
> now, while it's important to do it so we can set filters to catch
> specific error on allocation or trigger some operations on specific
> error.
> 
> Although we have printed the result in log, but the log is
> conditional and could not be filtered by tracing event.
> 
> What's more, it introduce little overhead to print this result.
> The result of allocation is named as errorno in trace.

This looks good to me. BTW, with this change, cma_alloc_class has only
one event - cma_alloc_busy_retry. If so, can we remove the cma_alloc_class?

Thank you,

> 
> Signed-off-by: Wenchao Hao <haowenchao@huawei.com>
> ---
>  include/trace/events/cma.h | 32 +++++++++++++++++++++++++++++---
>  mm/cma.c                   |  2 +-
>  2 files changed, 30 insertions(+), 4 deletions(-)
> 
> diff --git a/include/trace/events/cma.h b/include/trace/events/cma.h
> index 3d708dae1542..ef75ea606ab2 100644
> --- a/include/trace/events/cma.h
> +++ b/include/trace/events/cma.h
> @@ -91,12 +91,38 @@ TRACE_EVENT(cma_alloc_start,
>  		  __entry->align)
>  );
>  
> -DEFINE_EVENT(cma_alloc_class, cma_alloc_finish,
> +TRACE_EVENT(cma_alloc_finish,
>  
>  	TP_PROTO(const char *name, unsigned long pfn, const struct page *page,
> -		 unsigned long count, unsigned int align),
> +		 unsigned long count, unsigned int align, int errorno),
>  
> -	TP_ARGS(name, pfn, page, count, align)
> +	TP_ARGS(name, pfn, page, count, align, errorno),
> +
> +	TP_STRUCT__entry(
> +		__string(name, name)
> +		__field(unsigned long, pfn)
> +		__field(const struct page *, page)
> +		__field(unsigned long, count)
> +		__field(unsigned int, align)
> +		__field(int, errorno)
> +	),
> +
> +	TP_fast_assign(
> +		__assign_str(name, name);
> +		__entry->pfn = pfn;
> +		__entry->page = page;
> +		__entry->count = count;
> +		__entry->align = align;
> +		__entry->errorno = errorno;
> +	),
> +
> +	TP_printk("name=%s pfn=0x%lx page=%p count=%lu align=%u errorno=%d",
> +		  __get_str(name),
> +		  __entry->pfn,
> +		  __entry->page,
> +		  __entry->count,
> +		  __entry->align,
> +		  __entry->errorno)
>  );
>  
>  DEFINE_EVENT(cma_alloc_class, cma_alloc_busy_retry,
> diff --git a/mm/cma.c b/mm/cma.c
> index 4a978e09547a..a75b17b03b66 100644
> --- a/mm/cma.c
> +++ b/mm/cma.c
> @@ -491,7 +491,7 @@ struct page *cma_alloc(struct cma *cma, unsigned long count,
>  		start = bitmap_no + mask + 1;
>  	}
>  
> -	trace_cma_alloc_finish(cma->name, pfn, page, count, align);
> +	trace_cma_alloc_finish(cma->name, pfn, page, count, align, ret);
>  
>  	/*
>  	 * CMA can allocate multiple page blocks, which results in different
> -- 
> 2.32.0
> 


-- 
Masami Hiramatsu (Google) <mhiramat@kernel.org>

Re: [PATCH] cma:tracing: Print alloc result in trace_cma_alloc_finish

[Wenchao Hao]

On 2022/12/18 9:20, Masami Hiramatsu (Google) wrote:
> On Thu, 8 Dec 2022 22:21:30 +0800
> Wenchao Hao <haowenchao@huawei.com> wrote:
> 
>> The result of allocation is not printed in trace_cma_alloc_finish
>> now, while it's important to do it so we can set filters to catch
>> specific error on allocation or trigger some operations on specific
>> error.
>>
>> Although we have printed the result in log, but the log is
>> conditional and could not be filtered by tracing event.
>>
>> What's more, it introduce little overhead to print this result.
>> The result of allocation is named as errorno in trace.
> 
> This looks good to me. BTW, with this change, cma_alloc_class has only
> one event - cma_alloc_busy_retry. If so, can we remove the cma_alloc_class?
> 
> Thank you,
> 

Sorry, I got COVID-19 and just recovered, so did not response your email in time.

The cma_alloc_class should be removed. Since Andrew has applied this patch,
I would send another one to remove it.

>>
>> Signed-off-by: Wenchao Hao <haowenchao@huawei.com>
>> ---
>>  include/trace/events/cma.h | 32 +++++++++++++++++++++++++++++---
>>  mm/cma.c                   |  2 +-
>>  2 files changed, 30 insertions(+), 4 deletions(-)
>>
>> diff --git a/include/trace/events/cma.h b/include/trace/events/cma.h
>> index 3d708dae1542..ef75ea606ab2 100644
>> --- a/include/trace/events/cma.h
>> +++ b/include/trace/events/cma.h
>> @@ -91,12 +91,38 @@ TRACE_EVENT(cma_alloc_start,
>>  		  __entry->align)
>>  );
>>  
>> -DEFINE_EVENT(cma_alloc_class, cma_alloc_finish,
>> +TRACE_EVENT(cma_alloc_finish,
>>  
>>  	TP_PROTO(const char *name, unsigned long pfn, const struct page *page,
>> -		 unsigned long count, unsigned int align),
>> +		 unsigned long count, unsigned int align, int errorno),
>>  
>> -	TP_ARGS(name, pfn, page, count, align)
>> +	TP_ARGS(name, pfn, page, count, align, errorno),
>> +
>> +	TP_STRUCT__entry(
>> +		__string(name, name)
>> +		__field(unsigned long, pfn)
>> +		__field(const struct page *, page)
>> +		__field(unsigned long, count)
>> +		__field(unsigned int, align)
>> +		__field(int, errorno)
>> +	),
>> +
>> +	TP_fast_assign(
>> +		__assign_str(name, name);
>> +		__entry->pfn = pfn;
>> +		__entry->page = page;
>> +		__entry->count = count;
>> +		__entry->align = align;
>> +		__entry->errorno = errorno;
>> +	),
>> +
>> +	TP_printk("name=%s pfn=0x%lx page=%p count=%lu align=%u errorno=%d",
>> +		  __get_str(name),
>> +		  __entry->pfn,
>> +		  __entry->page,
>> +		  __entry->count,
>> +		  __entry->align,
>> +		  __entry->errorno)
>>  );
>>  
>>  DEFINE_EVENT(cma_alloc_class, cma_alloc_busy_retry,
>> diff --git a/mm/cma.c b/mm/cma.c
>> index 4a978e09547a..a75b17b03b66 100644
>> --- a/mm/cma.c
>> +++ b/mm/cma.c
>> @@ -491,7 +491,7 @@ struct page *cma_alloc(struct cma *cma, unsigned long count,
>>  		start = bitmap_no + mask + 1;
>>  	}
>>  
>> -	trace_cma_alloc_finish(cma->name, pfn, page, count, align);
>> +	trace_cma_alloc_finish(cma->name, pfn, page, count, align, ret);
>>  
>>  	/*
>>  	 * CMA can allocate multiple page blocks, which results in different
>> -- 
>> 2.32.0
>>
> 
>