[PATCH v2] tracing: Add verbose gfp_flag printing to synthetic events

[PATCH v2] tracing: Add verbose gfp_flag printing to synthetic events

[Zhengjun Xing]

Add on top of 'trace:add "gfp_t" support in synthetic_events'.

Prints the gfp flags as hex in addition to the human-readable flag
string.  Example output:

  whoopsie-630 [000] ...1 78.969452: testevent: bar=b20 (GFP_ATOMIC|__GFP_ZERO)
    rcuc/0-11  [000] ...1 81.097555: testevent: bar=a20 (GFP_ATOMIC)
    rcuc/0-11  [000] ...1 81.583123: testevent: bar=a20 (GFP_ATOMIC)

Signed-off-by: Tom Zanussi <zanussi@kernel.org>
Signed-off-by: Zhengjun Xing <zhengjun.xing@linux.intel.com>
---
 kernel/trace/trace_events_hist.c | 19 +++++++++++++++++++
 1 file changed, 19 insertions(+)

diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c
index ca6b0dff60c5..938ef3f54c5c 100644
--- a/kernel/trace/trace_events_hist.c
+++ b/kernel/trace/trace_events_hist.c
@@ -13,6 +13,10 @@
 #include <linux/rculist.h>
 #include <linux/tracefs.h>
 
+/* for gfp flag names */
+#include <linux/trace_events.h>
+#include <trace/events/mmflags.h>
+
 #include "tracing_map.h"
 #include "trace.h"
 #include "trace_dynevent.h"
@@ -752,6 +756,8 @@ static int synth_field_size(char *type)
 		size = sizeof(unsigned long);
 	else if (strcmp(type, "pid_t") == 0)
 		size = sizeof(pid_t);
+	else if (strcmp(type, "gfp_t") == 0)
+		size = sizeof(gfp_t);
 	else if (synth_field_is_string(type))
 		size = synth_field_string_size(type);
 
@@ -792,6 +798,8 @@ static const char *synth_field_fmt(char *type)
 		fmt = "%lu";
 	else if (strcmp(type, "pid_t") == 0)
 		fmt = "%d";
+	else if (strcmp(type, "gfp_t") == 0)
+		fmt = "%x";
 	else if (synth_field_is_string(type))
 		fmt = "%s";
 
@@ -834,9 +838,20 @@ static enum print_line_t print_synth_event(struct trace_iterator *iter,
 					 i == se->n_fields - 1 ? "" : " ");
 			n_u64 += STR_VAR_LEN_MAX / sizeof(u64);
 		} else {
+			struct trace_print_flags __flags[] = {
+			    __def_gfpflag_names, {-1, NULL} };
+
 			trace_seq_printf(s, print_fmt, se->fields[i]->name,
 					 entry->fields[n_u64],
 					 i == se->n_fields - 1 ? "" : " ");
+
+			if (strcmp(se->fields[i]->type, "gfp_t") == 0) {
+				trace_seq_puts(s, " (");
+				trace_print_flags_seq(s, "|",
+						      entry->fields[n_u64],
+						      __flags);
+				trace_seq_putc(s, ')');
+			}
 			n_u64++;
 		}
 	}
-- 
2.14.1

Re: [PATCH v2] tracing: Add verbose gfp_flag printing to synthetic events

[Tom Zanussi]

Hi Zhengjun,

The patch itself looks fine to me, but could you please create a v3
with a couple changes to the commit message?  I noticed you dropped
your original commit message - please add it back and combine with part
of mine, as below.  Also, please keep your original Subject line
('[PATCH] trace:add "gfp_t" support in synthetic_events') (but the
first word after trace:, 'add', should be capitalized.) 

On Thu, 2019-07-11 at 16:46 +0800, Zhengjun Xing wrote:
> Add on top of 'trace:add "gfp_t" support in synthetic_events'.

Please remove this part but keep the part below.

> 
> Prints the gfp flags as hex in addition to the human-readable flag
> string.  Example output:
> 
>   whoopsie-630 [000] ...1 78.969452: testevent: bar=b20
> (GFP_ATOMIC|__GFP_ZERO)
>     rcuc/0-11  [000] ...1 81.097555: testevent: bar=a20 (GFP_ATOMIC)
>     rcuc/0-11  [000] ...1 81.583123: testevent: bar=a20 (GFP_ATOMIC)
> 

So basically, something like this:

[PATCH] trace: Add "gfp_t" support in synthetic_events

Add "gfp_t" support in synthetic_events, then the "gfp_t" type
parameter in some functions can be traced.

Print the gfp flags as hex in addition to the human-readable flag
string.  Example output:

  whoopsie-630 [000] ...1 78.969452: testevent: bar=b20 (GFP_ATOMIC|__GFP_ZERO)
    rcuc/0-11  [000] ...1 81.097555: testevent: bar=a20 (GFP_ATOMIC)
    rcuc/0-11  [000] ...1 81.583123: testevent: bar=a20 (GFP_ATOMIC)

> Signed-off-by: Tom Zanussi <zanussi@kernel.org>
> Signed-off-by: Zhengjun Xing <zhengjun.xing@linux.intel.com>


Thanks,

Tom

> ---
>  kernel/trace/trace_events_hist.c | 19 +++++++++++++++++++
>  1 file changed, 19 insertions(+)
> 
> diff --git a/kernel/trace/trace_events_hist.c
> b/kernel/trace/trace_events_hist.c
> index ca6b0dff60c5..938ef3f54c5c 100644
> --- a/kernel/trace/trace_events_hist.c
> +++ b/kernel/trace/trace_events_hist.c
> @@ -13,6 +13,10 @@
>  #include <linux/rculist.h>
>  #include <linux/tracefs.h>
>  
> +/* for gfp flag names */
> +#include <linux/trace_events.h>
> +#include <trace/events/mmflags.h>
> +
>  #include "tracing_map.h"
>  #include "trace.h"
>  #include "trace_dynevent.h"
> @@ -752,6 +756,8 @@ static int synth_field_size(char *type)
>  		size = sizeof(unsigned long);
>  	else if (strcmp(type, "pid_t") == 0)
>  		size = sizeof(pid_t);
> +	else if (strcmp(type, "gfp_t") == 0)
> +		size = sizeof(gfp_t);
>  	else if (synth_field_is_string(type))
>  		size = synth_field_string_size(type);
>  
> @@ -792,6 +798,8 @@ static const char *synth_field_fmt(char *type)
>  		fmt = "%lu";
>  	else if (strcmp(type, "pid_t") == 0)
>  		fmt = "%d";
> +	else if (strcmp(type, "gfp_t") == 0)
> +		fmt = "%x";
>  	else if (synth_field_is_string(type))
>  		fmt = "%s";
>  
> @@ -834,9 +838,20 @@ static enum print_line_t
> print_synth_event(struct trace_iterator *iter,
>  					 i == se->n_fields - 1 ? ""
> : " ");
>  			n_u64 += STR_VAR_LEN_MAX / sizeof(u64);
>  		} else {
> +			struct trace_print_flags __flags[] = {
> +			    __def_gfpflag_names, {-1, NULL} };
> +
>  			trace_seq_printf(s, print_fmt, se-
> >fields[i]->name,
>  					 entry->fields[n_u64],
>  					 i == se->n_fields - 1 ? ""
> : " ");
> +
> +			if (strcmp(se->fields[i]->type, "gfp_t") ==
> 0) {
> +				trace_seq_puts(s, " (");
> +				trace_print_flags_seq(s, "|",
> +						      entry-
> >fields[n_u64],
> +						      __flags);
> +				trace_seq_putc(s, ')');
> +			}
>  			n_u64++;
>  		}
>  	}

Re: [PATCH v2] tracing: Add verbose gfp_flag printing to synthetic events

[Xing Zhengjun]

Hi Tom,

On 7/11/2019 11:42 PM, Tom Zanussi wrote:
> Hi Zhengjun,
> 
> The patch itself looks fine to me, but could you please create a v3
> with a couple changes to the commit message?  I noticed you dropped
> your original commit message - please add it back and combine with part
> of mine, as below.  Also, please keep your original Subject line
> ('[PATCH] trace:add "gfp_t" support in synthetic_events') (but the
> first word after trace:, 'add', should be capitalized.)
> 
Thanks. I will send v3 version patch soon.

> On Thu, 2019-07-11 at 16:46 +0800, Zhengjun Xing wrote:
>> Add on top of 'trace:add "gfp_t" support in synthetic_events'.
> 
> Please remove this part but keep the part below.
> 
>>
>> Prints the gfp flags as hex in addition to the human-readable flag
>> string.  Example output:
>>
>>    whoopsie-630 [000] ...1 78.969452: testevent: bar=b20
>> (GFP_ATOMIC|__GFP_ZERO)
>>      rcuc/0-11  [000] ...1 81.097555: testevent: bar=a20 (GFP_ATOMIC)
>>      rcuc/0-11  [000] ...1 81.583123: testevent: bar=a20 (GFP_ATOMIC)
>>
> 
> So basically, something like this:
> 
> [PATCH] trace: Add "gfp_t" support in synthetic_events
> 
> Add "gfp_t" support in synthetic_events, then the "gfp_t" type
> parameter in some functions can be traced.
> 
> Print the gfp flags as hex in addition to the human-readable flag
> string.  Example output:
> 
>    whoopsie-630 [000] ...1 78.969452: testevent: bar=b20 (GFP_ATOMIC|__GFP_ZERO)
>      rcuc/0-11  [000] ...1 81.097555: testevent: bar=a20 (GFP_ATOMIC)
>      rcuc/0-11  [000] ...1 81.583123: testevent: bar=a20 (GFP_ATOMIC)
> 
>> Signed-off-by: Tom Zanussi <zanussi@kernel.org>
>> Signed-off-by: Zhengjun Xing <zhengjun.xing@linux.intel.com>
> 
> 
> Thanks,
> 
> Tom
> 
>> ---
>>   kernel/trace/trace_events_hist.c | 19 +++++++++++++++++++
>>   1 file changed, 19 insertions(+)
>>
>> diff --git a/kernel/trace/trace_events_hist.c
>> b/kernel/trace/trace_events_hist.c
>> index ca6b0dff60c5..938ef3f54c5c 100644
>> --- a/kernel/trace/trace_events_hist.c
>> +++ b/kernel/trace/trace_events_hist.c
>> @@ -13,6 +13,10 @@
>>   #include <linux/rculist.h>
>>   #include <linux/tracefs.h>
>>   
>> +/* for gfp flag names */
>> +#include <linux/trace_events.h>
>> +#include <trace/events/mmflags.h>
>> +
>>   #include "tracing_map.h"
>>   #include "trace.h"
>>   #include "trace_dynevent.h"
>> @@ -752,6 +756,8 @@ static int synth_field_size(char *type)
>>   		size = sizeof(unsigned long);
>>   	else if (strcmp(type, "pid_t") == 0)
>>   		size = sizeof(pid_t);
>> +	else if (strcmp(type, "gfp_t") == 0)
>> +		size = sizeof(gfp_t);
>>   	else if (synth_field_is_string(type))
>>   		size = synth_field_string_size(type);
>>   
>> @@ -792,6 +798,8 @@ static const char *synth_field_fmt(char *type)
>>   		fmt = "%lu";
>>   	else if (strcmp(type, "pid_t") == 0)
>>   		fmt = "%d";
>> +	else if (strcmp(type, "gfp_t") == 0)
>> +		fmt = "%x";
>>   	else if (synth_field_is_string(type))
>>   		fmt = "%s";
>>   
>> @@ -834,9 +838,20 @@ static enum print_line_t
>> print_synth_event(struct trace_iterator *iter,
>>   					 i == se->n_fields - 1 ? ""
>> : " ");
>>   			n_u64 += STR_VAR_LEN_MAX / sizeof(u64);
>>   		} else {
>> +			struct trace_print_flags __flags[] = {
>> +			    __def_gfpflag_names, {-1, NULL} };
>> +
>>   			trace_seq_printf(s, print_fmt, se-
>>> fields[i]->name,
>>   					 entry->fields[n_u64],
>>   					 i == se->n_fields - 1 ? ""
>> : " ");
>> +
>> +			if (strcmp(se->fields[i]->type, "gfp_t") ==
>> 0) {
>> +				trace_seq_puts(s, " (");
>> +				trace_print_flags_seq(s, "|",
>> +						      entry-
>>> fields[n_u64],
>> +						      __flags);
>> +				trace_seq_putc(s, ')');
>> +			}
>>   			n_u64++;
>>   		}
>>   	}

-- 
Zhengjun Xing