[PATCH] percpu: improve percpu_alloc_percpu event trace

[PATCH] percpu: improve percpu_alloc_percpu event trace

[Vasily Averin]

Added bytes_alloc and gfp_flags fields to the output of the
percpu_alloc_percpu ftrace event. This is required to track
memcg-accounted percpu allocations.

Signed-off-by: Vasily Averin <vvs-GEFAQzZX7r8dnm+yROfE0A@public.gmane.org>
---
 include/trace/events/percpu.h | 17 ++++++++++++-----
 mm/percpu-internal.h          |  8 ++++----
 mm/percpu.c                   |  3 ++-
 3 files changed, 18 insertions(+), 10 deletions(-)

diff --git a/include/trace/events/percpu.h b/include/trace/events/percpu.h
index df112a64f6c9..a6d640d2cb8b 100644
--- a/include/trace/events/percpu.h
+++ b/include/trace/events/percpu.h
@@ -6,13 +6,16 @@
 #define _TRACE_PERCPU_H
 
 #include <linux/tracepoint.h>
+#include <trace/events/mmflags.h>
 
 TRACE_EVENT(percpu_alloc_percpu,
 
 	TP_PROTO(bool reserved, bool is_atomic, size_t size,
-		 size_t align, void *base_addr, int off, void __percpu *ptr),
+		 size_t align, void *base_addr, int off,
+		 void __percpu *ptr, size_t bytes_alloc, gfp_t gfp_flags),
 
-	TP_ARGS(reserved, is_atomic, size, align, base_addr, off, ptr),
+	TP_ARGS(reserved, is_atomic, size, align, base_addr, off, ptr,
+		bytes_alloc, gfp_flags),
 
 	TP_STRUCT__entry(
 		__field(	bool,			reserved	)
@@ -22,8 +25,9 @@ TRACE_EVENT(percpu_alloc_percpu,
 		__field(	void *,			base_addr	)
 		__field(	int,			off		)
 		__field(	void __percpu *,	ptr		)
+		__field(	size_t,			bytes_alloc	)
+		__field(	gfp_t,			gfp_flags	)
 	),
-
 	TP_fast_assign(
 		__entry->reserved	= reserved;
 		__entry->is_atomic	= is_atomic;
@@ -32,12 +36,15 @@ TRACE_EVENT(percpu_alloc_percpu,
 		__entry->base_addr	= base_addr;
 		__entry->off		= off;
 		__entry->ptr		= ptr;
+		__entry->bytes_alloc	= bytes_alloc;
+		__entry->gfp_flags	= gfp_flags;
 	),
 
-	TP_printk("reserved=%d is_atomic=%d size=%zu align=%zu base_addr=%p off=%d ptr=%p",
+	TP_printk("reserved=%d is_atomic=%d size=%zu align=%zu base_addr=%p off=%d ptr=%p bytes_alloc=%zu gfp_flags=%s",
 		  __entry->reserved, __entry->is_atomic,
 		  __entry->size, __entry->align,
-		  __entry->base_addr, __entry->off, __entry->ptr)
+		  __entry->base_addr, __entry->off, __entry->ptr,
+		  __entry->bytes_alloc, show_gfp_flags(__entry->gfp_flags))
 );
 
 TRACE_EVENT(percpu_free_percpu,
diff --git a/mm/percpu-internal.h b/mm/percpu-internal.h
index 411d1593ef23..70b1ea23f4d2 100644
--- a/mm/percpu-internal.h
+++ b/mm/percpu-internal.h
@@ -113,7 +113,6 @@ static inline int pcpu_chunk_map_bits(struct pcpu_chunk *chunk)
 	return pcpu_nr_pages_to_map_bits(chunk->nr_pages);
 }
 
-#ifdef CONFIG_MEMCG_KMEM
 /**
  * pcpu_obj_full_size - helper to calculate size of each accounted object
  * @size: size of area to allocate in bytes
@@ -123,13 +122,14 @@ static inline int pcpu_chunk_map_bits(struct pcpu_chunk *chunk)
  */
 static inline size_t pcpu_obj_full_size(size_t size)
 {
-	size_t extra_size;
+	size_t extra_size = 0;
 
-	extra_size = size / PCPU_MIN_ALLOC_SIZE * sizeof(struct obj_cgroup *);
+#ifdef CONFIG_MEMCG_KMEM
+	extra_size += size / PCPU_MIN_ALLOC_SIZE * sizeof(struct obj_cgroup *);
+#endif
 
 	return size * num_possible_cpus() + extra_size;
 }
-#endif /* CONFIG_MEMCG_KMEM */
 
 #ifdef CONFIG_PERCPU_STATS
 
diff --git a/mm/percpu.c b/mm/percpu.c
index ea28db283044..cbeb380c359d 100644
--- a/mm/percpu.c
+++ b/mm/percpu.c
@@ -1885,7 +1885,8 @@ static void __percpu *pcpu_alloc(size_t size, size_t align, bool reserved,
 	kmemleak_alloc_percpu(ptr, size, gfp);
 
 	trace_percpu_alloc_percpu(reserved, is_atomic, size, align,
-			chunk->base_addr, off, ptr);
+			chunk->base_addr, off, ptr,
+			pcpu_obj_full_size(size), gfp);
 
 	pcpu_memcg_post_alloc_hook(objcg, chunk, off, size);
 
-- 
2.31.1

Re: [PATCH] percpu: improve percpu_alloc_percpu event trace

[Vasily Averin]

On 5/6/22 07:46, Vasily Averin wrote:
> Added bytes_alloc and gfp_flags fields to the output of the
> percpu_alloc_percpu ftrace event. This is required to track
> memcg-accounted percpu allocations.

Perhaps it makes sense to add call_site too...

[PATCH v2] percpu: improve percpu_alloc_percpu event trace

[Vasily Averin]

Added call_site, bytes_alloc and gfp_flags fields to the output
of the percpu_alloc_percpu ftrace event:

mkdir-4393  [001]   169.334788: percpu_alloc_percpu:
 call_site=mem_cgroup_css_alloc+0xa6 reserved=0 is_atomic=0 size=2408 align=8
  base_addr=0xffffc7117fc00000 off=402176 ptr=0x3dc867a62300 bytes_alloc=14448
   gfp_flags=GFP_KERNEL_ACCOUNT

This is required to track memcg-accounted percpu allocations.

Signed-off-by: Vasily Averin <vvs-GEFAQzZX7r8dnm+yROfE0A@public.gmane.org>
---
v2: added call_site, improved patch description
---
 include/trace/events/percpu.h | 23 +++++++++++++++++------
 mm/percpu-internal.h          |  8 ++++----
 mm/percpu.c                   |  5 +++--
 3 files changed, 24 insertions(+), 12 deletions(-)

diff --git a/include/trace/events/percpu.h b/include/trace/events/percpu.h
index df112a64f6c9..e989cefc0def 100644
--- a/include/trace/events/percpu.h
+++ b/include/trace/events/percpu.h
@@ -6,15 +6,20 @@
 #define _TRACE_PERCPU_H
 
 #include <linux/tracepoint.h>
+#include <trace/events/mmflags.h>
 
 TRACE_EVENT(percpu_alloc_percpu,
 
-	TP_PROTO(bool reserved, bool is_atomic, size_t size,
-		 size_t align, void *base_addr, int off, void __percpu *ptr),
+	TP_PROTO(unsigned long call_site,
+		 bool reserved, bool is_atomic, size_t size,
+		 size_t align, void *base_addr, int off,
+		 void __percpu *ptr, size_t bytes_alloc, gfp_t gfp_flags),
 
-	TP_ARGS(reserved, is_atomic, size, align, base_addr, off, ptr),
+	TP_ARGS(call_site, reserved, is_atomic, size, align, base_addr, off,
+		ptr, bytes_alloc, gfp_flags),
 
 	TP_STRUCT__entry(
+		__field(	unsigned long,		call_site	)
 		__field(	bool,			reserved	)
 		__field(	bool,			is_atomic	)
 		__field(	size_t,			size		)
@@ -22,9 +27,11 @@ TRACE_EVENT(percpu_alloc_percpu,
 		__field(	void *,			base_addr	)
 		__field(	int,			off		)
 		__field(	void __percpu *,	ptr		)
+		__field(	size_t,			bytes_alloc	)
+		__field(	gfp_t,			gfp_flags	)
 	),
-
 	TP_fast_assign(
+		__entry->call_site	= call_site;
 		__entry->reserved	= reserved;
 		__entry->is_atomic	= is_atomic;
 		__entry->size		= size;
@@ -32,12 +39,16 @@ TRACE_EVENT(percpu_alloc_percpu,
 		__entry->base_addr	= base_addr;
 		__entry->off		= off;
 		__entry->ptr		= ptr;
+		__entry->bytes_alloc	= bytes_alloc;
+		__entry->gfp_flags	= gfp_flags;
 	),
 
-	TP_printk("reserved=%d is_atomic=%d size=%zu align=%zu base_addr=%p off=%d ptr=%p",
+	TP_printk("call_site=%pS reserved=%d is_atomic=%d size=%zu align=%zu base_addr=%p off=%d ptr=%p bytes_alloc=%zu gfp_flags=%s",
+		  (void *)__entry->call_site,
 		  __entry->reserved, __entry->is_atomic,
 		  __entry->size, __entry->align,
-		  __entry->base_addr, __entry->off, __entry->ptr)
+		  __entry->base_addr, __entry->off, __entry->ptr,
+		  __entry->bytes_alloc, show_gfp_flags(__entry->gfp_flags))
 );
 
 TRACE_EVENT(percpu_free_percpu,
diff --git a/mm/percpu-internal.h b/mm/percpu-internal.h
index 411d1593ef23..70b1ea23f4d2 100644
--- a/mm/percpu-internal.h
+++ b/mm/percpu-internal.h
@@ -113,7 +113,6 @@ static inline int pcpu_chunk_map_bits(struct pcpu_chunk *chunk)
 	return pcpu_nr_pages_to_map_bits(chunk->nr_pages);
 }
 
-#ifdef CONFIG_MEMCG_KMEM
 /**
  * pcpu_obj_full_size - helper to calculate size of each accounted object
  * @size: size of area to allocate in bytes
@@ -123,13 +122,14 @@ static inline int pcpu_chunk_map_bits(struct pcpu_chunk *chunk)
  */
 static inline size_t pcpu_obj_full_size(size_t size)
 {
-	size_t extra_size;
+	size_t extra_size = 0;
 
-	extra_size = size / PCPU_MIN_ALLOC_SIZE * sizeof(struct obj_cgroup *);
+#ifdef CONFIG_MEMCG_KMEM
+	extra_size += size / PCPU_MIN_ALLOC_SIZE * sizeof(struct obj_cgroup *);
+#endif
 
 	return size * num_possible_cpus() + extra_size;
 }
-#endif /* CONFIG_MEMCG_KMEM */
 
 #ifdef CONFIG_PERCPU_STATS
 
diff --git a/mm/percpu.c b/mm/percpu.c
index ea28db283044..3633eeefaa0d 100644
--- a/mm/percpu.c
+++ b/mm/percpu.c
@@ -1884,8 +1884,9 @@ static void __percpu *pcpu_alloc(size_t size, size_t align, bool reserved,
 	ptr = __addr_to_pcpu_ptr(chunk->base_addr + off);
 	kmemleak_alloc_percpu(ptr, size, gfp);
 
-	trace_percpu_alloc_percpu(reserved, is_atomic, size, align,
-			chunk->base_addr, off, ptr);
+	trace_percpu_alloc_percpu(_RET_IP_, reserved, is_atomic, size, align,
+				  chunk->base_addr, off, ptr,
+				  pcpu_obj_full_size(size), gfp);
 
 	pcpu_memcg_post_alloc_hook(objcg, chunk, off, size);
 
-- 
2.31.1

Re: [PATCH] percpu: improve percpu_alloc_percpu event trace

[kernel test robot]

Hi Vasily,

Thank you for the patch! Perhaps something to improve:

[auto build test WARNING on rostedt-trace/for-next]
[also build test WARNING on hnaz-mm/master v5.18-rc5]
[cannot apply to dennis-percpu/for-next]
[If your patch is applied to the wrong git tree, kindly drop us a note.
And when submitting patch, we suggest to use '--base' as documented in
https://git-scm.com/docs/git-format-patch]

url:    https://github.com/intel-lab-lkp/linux/commits/Vasily-Averin/percpu-improve-percpu_alloc_percpu-event-trace/20220506-124742
base:   https://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git for-next
config: i386-randconfig-s001 (https://download.01.org/0day-ci/archive/20220507/202205070420.aAhuqpYk-lkp-ral2JQCrhuEAvxtiuMwx3w@public.gmane.org/config)
compiler: gcc-11 (Debian 11.2.0-20) 11.2.0
reproduce:
        # apt-get install sparse
        # sparse version: v0.6.4-dirty
        # https://github.com/intel-lab-lkp/linux/commit/dee6876db0a7a4715516e673f9edaca2ba40677c
        git remote add linux-review https://github.com/intel-lab-lkp/linux
        git fetch --no-tags linux-review Vasily-Averin/percpu-improve-percpu_alloc_percpu-event-trace/20220506-124742
        git checkout dee6876db0a7a4715516e673f9edaca2ba40677c
        # save the config file
        mkdir build_dir && cp config build_dir/.config
        make W=1 C=1 CF='-fdiagnostic-prefix -D__CHECK_ENDIAN__' O=build_dir ARCH=i386 SHELL=/bin/bash

If you fix the issue, kindly add following tag as appropriate
Reported-by: kernel test robot <lkp-ral2JQCrhuEAvxtiuMwx3w@public.gmane.org>


sparse warnings: (new ones prefixed by >>)
   mm/percpu.c: note: in included file (through include/trace/trace_events.h, include/trace/define_trace.h, include/trace/events/percpu.h):
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: incorrect type in argument 3 (different base types) @@     expected unsigned long flags @@     got restricted gfp_t [usertype] gfp_flags @@
   include/trace/events/percpu.h:11:1: sparse:     expected unsigned long flags
   include/trace/events/percpu.h:11:1: sparse:     got restricted gfp_t [usertype] gfp_flags
   mm/percpu.c: note: in included file (through include/trace/trace_events.h, include/trace/define_trace.h, include/trace/events/percpu.h):
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast to restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: cast to restricted gfp_t
>> include/trace/events/percpu.h:11:1: sparse: sparse: restricted gfp_t degrades to integer
>> include/trace/events/percpu.h:11:1: sparse: sparse: restricted gfp_t degrades to integer
   mm/percpu.c:2012:24: sparse: sparse: context imbalance in 'pcpu_balance_free' - unexpected unlock

vim +11 include/trace/events/percpu.h

df95e795a72289 Dennis Zhou   2017-06-19  10  
df95e795a72289 Dennis Zhou   2017-06-19 @11  TRACE_EVENT(percpu_alloc_percpu,
df95e795a72289 Dennis Zhou   2017-06-19  12  
df95e795a72289 Dennis Zhou   2017-06-19  13  	TP_PROTO(bool reserved, bool is_atomic, size_t size,
dee6876db0a7a4 Vasily Averin 2022-05-06  14  		 size_t align, void *base_addr, int off,
dee6876db0a7a4 Vasily Averin 2022-05-06  15  		 void __percpu *ptr, size_t bytes_alloc, gfp_t gfp_flags),
df95e795a72289 Dennis Zhou   2017-06-19  16  
dee6876db0a7a4 Vasily Averin 2022-05-06  17  	TP_ARGS(reserved, is_atomic, size, align, base_addr, off, ptr,
dee6876db0a7a4 Vasily Averin 2022-05-06  18  		bytes_alloc, gfp_flags),
df95e795a72289 Dennis Zhou   2017-06-19  19  
df95e795a72289 Dennis Zhou   2017-06-19  20  	TP_STRUCT__entry(
df95e795a72289 Dennis Zhou   2017-06-19  21  		__field(	bool,			reserved	)
df95e795a72289 Dennis Zhou   2017-06-19  22  		__field(	bool,			is_atomic	)
df95e795a72289 Dennis Zhou   2017-06-19  23  		__field(	size_t,			size		)
df95e795a72289 Dennis Zhou   2017-06-19  24  		__field(	size_t,			align		)
df95e795a72289 Dennis Zhou   2017-06-19  25  		__field(	void *,			base_addr	)
df95e795a72289 Dennis Zhou   2017-06-19  26  		__field(	int,			off		)
df95e795a72289 Dennis Zhou   2017-06-19  27  		__field(	void __percpu *,	ptr		)
dee6876db0a7a4 Vasily Averin 2022-05-06  28  		__field(	size_t,			bytes_alloc	)
dee6876db0a7a4 Vasily Averin 2022-05-06  29  		__field(	gfp_t,			gfp_flags	)
df95e795a72289 Dennis Zhou   2017-06-19  30  	),
df95e795a72289 Dennis Zhou   2017-06-19  31  	TP_fast_assign(
df95e795a72289 Dennis Zhou   2017-06-19  32  		__entry->reserved	= reserved;
df95e795a72289 Dennis Zhou   2017-06-19  33  		__entry->is_atomic	= is_atomic;
df95e795a72289 Dennis Zhou   2017-06-19  34  		__entry->size		= size;
df95e795a72289 Dennis Zhou   2017-06-19  35  		__entry->align		= align;
df95e795a72289 Dennis Zhou   2017-06-19  36  		__entry->base_addr	= base_addr;
df95e795a72289 Dennis Zhou   2017-06-19  37  		__entry->off		= off;
df95e795a72289 Dennis Zhou   2017-06-19  38  		__entry->ptr		= ptr;
dee6876db0a7a4 Vasily Averin 2022-05-06  39  		__entry->bytes_alloc	= bytes_alloc;
dee6876db0a7a4 Vasily Averin 2022-05-06  40  		__entry->gfp_flags	= gfp_flags;
df95e795a72289 Dennis Zhou   2017-06-19  41  	),
df95e795a72289 Dennis Zhou   2017-06-19  42  
dee6876db0a7a4 Vasily Averin 2022-05-06  43  	TP_printk("reserved=%d is_atomic=%d size=%zu align=%zu base_addr=%p off=%d ptr=%p bytes_alloc=%zu gfp_flags=%s",
df95e795a72289 Dennis Zhou   2017-06-19  44  		  __entry->reserved, __entry->is_atomic,
df95e795a72289 Dennis Zhou   2017-06-19  45  		  __entry->size, __entry->align,
dee6876db0a7a4 Vasily Averin 2022-05-06  46  		  __entry->base_addr, __entry->off, __entry->ptr,
dee6876db0a7a4 Vasily Averin 2022-05-06  47  		  __entry->bytes_alloc, show_gfp_flags(__entry->gfp_flags))
df95e795a72289 Dennis Zhou   2017-06-19  48  );
df95e795a72289 Dennis Zhou   2017-06-19  49  

-- 
0-DAY CI Kernel Test Service
https://01.org/lkp

Re: [PATCH] percpu: improve percpu_alloc_percpu event trace

[Vasily Averin]

On 5/6/22 23:38, kernel test robot wrote:
>>> include/trace/events/percpu.h:11:1: sparse: sparse: cast from restricted gfp_t
>>> include/trace/events/percpu.h:11:1: sparse: sparse: incorrect type in argument 3 (different base types) @@     expected unsigned long flags @@     got restricted gfp_t [usertype] gfp_flags @@
>    include/trace/events/percpu.h:11:1: sparse:     expected unsigned long flags
>    include/trace/events/percpu.h:11:1: sparse:     got restricted gfp_t [usertype] gfp_flags
>    mm/percpu.c: note: in included file (through include/trace/trace_events.h, include/trace/define_trace.h, include/trace/events/percpu.h):
>>> include/trace/events/percpu.h:11:1: sparse: sparse: cast to restricted gfp_t
>>> include/trace/events/percpu.h:11:1: sparse: sparse: cast to restricted gfp_t
>>> include/trace/events/percpu.h:11:1: sparse: sparse: restricted gfp_t degrades to integer
>>> include/trace/events/percpu.h:11:1: sparse: sparse: restricted gfp_t degrades to integer
>    mm/percpu.c:2012:24: sparse: sparse: context imbalance in 'pcpu_balance_free' - unexpected unlock

The same messages are generated for any other gfp_t argument in trace events.
As far as I understand it is not a bug per se,
but trace macros lacks __force attribute in 'gfp_t'-> 'unsigned long' casts.
The same thing happens with mode_t and with some other places using __print_flags()
for __bitwise marked types.

I can make sparse happy, here and elsewhere but it requires a lot of __force attributes.
Is anyone interested in such patches, or can we silently ignore these messages?

Need to add __force attribute to all entries in __def_gfpflag_names array
and add few changes into trace description, below is an example.

> vim +11 include/trace/events/percpu.h
> 
> df95e795a72289 Dennis Zhou   2017-06-19  10  
> df95e795a72289 Dennis Zhou   2017-06-19 @11  TRACE_EVENT(percpu_alloc_percpu,
> df95e795a72289 Dennis Zhou   2017-06-19  12  
> df95e795a72289 Dennis Zhou   2017-06-19  13  	TP_PROTO(bool reserved, bool is_atomic, size_t size,
> dee6876db0a7a4 Vasily Averin 2022-05-06  14  		 size_t align, void *base_addr, int off,
> dee6876db0a7a4 Vasily Averin 2022-05-06  15  		 void __percpu *ptr, size_t bytes_alloc, gfp_t gfp_flags),
> df95e795a72289 Dennis Zhou   2017-06-19  16  
> dee6876db0a7a4 Vasily Averin 2022-05-06  17  	TP_ARGS(reserved, is_atomic, size, align, base_addr, off, ptr,
> dee6876db0a7a4 Vasily Averin 2022-05-06  18  		bytes_alloc, gfp_flags),
> df95e795a72289 Dennis Zhou   2017-06-19  19  
> df95e795a72289 Dennis Zhou   2017-06-19  20  	TP_STRUCT__entry(
> df95e795a72289 Dennis Zhou   2017-06-19  21  		__field(	bool,			reserved	)
> df95e795a72289 Dennis Zhou   2017-06-19  22  		__field(	bool,			is_atomic	)
> df95e795a72289 Dennis Zhou   2017-06-19  23  		__field(	size_t,			size		)
> df95e795a72289 Dennis Zhou   2017-06-19  24  		__field(	size_t,			align		)
> df95e795a72289 Dennis Zhou   2017-06-19  25  		__field(	void *,			base_addr	)
> df95e795a72289 Dennis Zhou   2017-06-19  26  		__field(	int,			off		)
> df95e795a72289 Dennis Zhou   2017-06-19  27  		__field(	void __percpu *,	ptr		)
> dee6876db0a7a4 Vasily Averin 2022-05-06  28  		__field(	size_t,			bytes_alloc	)
> dee6876db0a7a4 Vasily Averin 2022-05-06  29  		__field(	gfp_t,			gfp_flags	)
VvS: need to replace gfp_t to unsigned long ...

> df95e795a72289 Dennis Zhou   2017-06-19  30  	),
> df95e795a72289 Dennis Zhou   2017-06-19  31  	TP_fast_assign(
> df95e795a72289 Dennis Zhou   2017-06-19  32  		__entry->reserved	= reserved;
> df95e795a72289 Dennis Zhou   2017-06-19  33  		__entry->is_atomic	= is_atomic;
> df95e795a72289 Dennis Zhou   2017-06-19  34  		__entry->size		= size;
> df95e795a72289 Dennis Zhou   2017-06-19  35  		__entry->align		= align;
> df95e795a72289 Dennis Zhou   2017-06-19  36  		__entry->base_addr	= base_addr;
> df95e795a72289 Dennis Zhou   2017-06-19  37  		__entry->off		= off;
> df95e795a72289 Dennis Zhou   2017-06-19  38  		__entry->ptr		= ptr;
> dee6876db0a7a4 Vasily Averin 2022-05-06  39  		__entry->bytes_alloc	= bytes_alloc;
> dee6876db0a7a4 Vasily Averin 2022-05-06  40  		__entry->gfp_flags	= gfp_flags;
VvS: ... and use here (__force unsigned long)

> df95e795a72289 Dennis Zhou   2017-06-19  41  	),
> df95e795a72289 Dennis Zhou   2017-06-19  42  
> dee6876db0a7a4 Vasily Averin 2022-05-06  43  	TP_printk("reserved=%d is_atomic=%d size=%zu align=%zu base_addr=%p off=%d ptr=%p bytes_alloc=%zu gfp_flags=%s",
> df95e795a72289 Dennis Zhou   2017-06-19  44  		  __entry->reserved, __entry->is_atomic,
> df95e795a72289 Dennis Zhou   2017-06-19  45  		  __entry->size, __entry->align,
> dee6876db0a7a4 Vasily Averin 2022-05-06  46  		  __entry->base_addr, __entry->off, __entry->ptr,
> dee6876db0a7a4 Vasily Averin 2022-05-06  47  		  __entry->bytes_alloc, show_gfp_flags(__entry->gfp_flags))
> df95e795a72289 Dennis Zhou   2017-06-19  48  );
> df95e795a72289 Dennis Zhou   2017-06-19  49  
 Thank you,
	Vasily Averin

Re: [PATCH] percpu: improve percpu_alloc_percpu event trace

[Steven Rostedt]

On Sat, 7 May 2022 17:51:16 +0300
Vasily Averin <vvs-GEFAQzZX7r8dnm+yROfE0A@public.gmane.org> wrote:

> The same messages are generated for any other gfp_t argument in trace events.
> As far as I understand it is not a bug per se,
> but trace macros lacks __force attribute in 'gfp_t'-> 'unsigned long' casts.
> The same thing happens with mode_t and with some other places using __print_flags()
> for __bitwise marked types.

I'm curious as to where the gfp_t to unsigned long is happening in the
macros?

-- Steve

Re: [PATCH] percpu: improve percpu_alloc_percpu event trace

[Vasily Averin]

On 5/10/22 00:06, Steven Rostedt wrote:
> I'm curious as to where the gfp_t to unsigned long is happening in the
> macros?

original ___GFP_* flags are usual defines

/* Plain integer GFP bitmasks. Do not use this directly. */
#define ___GFP_DMA              0x01u
#define ___GFP_HIGHMEM          0x02u
#define ___GFP_DMA32            0x04u

... but __GFP_* flags used elsewhere are declared as 'forced to gfp_t'

#define __GFP_DMA       ((__force gfp_t)___GFP_DMA)
#define __GFP_HIGHMEM   ((__force gfp_t)___GFP_HIGHMEM)
#define __GFP_DMA32     ((__force gfp_t)___GFP_DMA32)
...
#define GFP_DMA         __GFP_DMA
#define GFP_DMA32       __GFP_DMA32

... and when  __def_gfpflag_names() traslates them to unsigned long

       {(unsigned long)GFP_DMA,                "GFP_DMA"},             \
       {(unsigned long)__GFP_HIGHMEM,          "__GFP_HIGHMEM"},       \
       {(unsigned long)GFP_DMA32,              "GFP_DMA32"},           \

... it leads to sparse warnings bacuse type gfp_t was declared as 'bitwise'
From mas sparse

       -Wbitwise
              Warn about unsupported operations or type mismatches with
              restricted integer types.

               Sparse supports an extended attribute,
              __attribute__((bitwise)), which creates a new restricted
              integer type from a base integer type, distinct from the
              base integer type and from any other restricted integer
              type not declared in the same declaration or typedef.

             __bitwise is for *unique types* that cannot be mixed with
              other types, and that you'd never want to just use as a
              random integer (the integer 0 is special, though, and gets
              silently accepted iirc - it's kind of like "NULL" for
              pointers). So "gfp_t" or the "safe endianness" types would
              be __bitwise: you can only operate on them by doing
              specific operations that know about *that* particular
              type.

              Sparse issues these warnings by default.

Thank you,
	Vasily Averin

Re: [PATCH] percpu: improve percpu_alloc_percpu event trace

[Steven Rostedt]

On Tue, 10 May 2022 07:22:02 +0300
Vasily Averin <vvs-GEFAQzZX7r8dnm+yROfE0A@public.gmane.org> wrote:

> ... and when  __def_gfpflag_names() traslates them to unsigned long
> 
>        {(unsigned long)GFP_DMA,                "GFP_DMA"},             \
>        {(unsigned long)__GFP_HIGHMEM,          "__GFP_HIGHMEM"},       \
>        {(unsigned long)GFP_DMA32,              "GFP_DMA32"},           \
> 
> ... it leads to sparse warnings bacuse type gfp_t was declared as 'bitwise'

Ah' it's the printing of the flag bits. Got it.

-- Steve

Re: [PATCH v2] percpu: improve percpu_alloc_percpu event trace

[Roman Gushchin]

On Fri, May 06, 2022 at 10:29:25PM +0300, Vasily Averin wrote:
> Added call_site, bytes_alloc and gfp_flags fields to the output
> of the percpu_alloc_percpu ftrace event:
> 
> mkdir-4393  [001]   169.334788: percpu_alloc_percpu:
>  call_site=mem_cgroup_css_alloc+0xa6 reserved=0 is_atomic=0 size=2408 align=8
>   base_addr=0xffffc7117fc00000 off=402176 ptr=0x3dc867a62300 bytes_alloc=14448
>    gfp_flags=GFP_KERNEL_ACCOUNT
> 
> This is required to track memcg-accounted percpu allocations.
> 
> Signed-off-by: Vasily Averin <vvs-GEFAQzZX7r8dnm+yROfE0A@public.gmane.org>

Acked-by: Roman Gushchin <roman.gushchin-fxUVXftIFDnyG1zEObXtfA@public.gmane.org>

LGTM, thanks Vasily!

One minor thing below.

> ---
> v2: added call_site, improved patch description
> ---
>  include/trace/events/percpu.h | 23 +++++++++++++++++------
>  mm/percpu-internal.h          |  8 ++++----
>  mm/percpu.c                   |  5 +++--
>  3 files changed, 24 insertions(+), 12 deletions(-)
> 
> diff --git a/include/trace/events/percpu.h b/include/trace/events/percpu.h
> index df112a64f6c9..e989cefc0def 100644
> --- a/include/trace/events/percpu.h
> +++ b/include/trace/events/percpu.h
> @@ -6,15 +6,20 @@
>  #define _TRACE_PERCPU_H
>  
>  #include <linux/tracepoint.h>
> +#include <trace/events/mmflags.h>
>  
>  TRACE_EVENT(percpu_alloc_percpu,
>  
> -	TP_PROTO(bool reserved, bool is_atomic, size_t size,
> -		 size_t align, void *base_addr, int off, void __percpu *ptr),
> +	TP_PROTO(unsigned long call_site,
> +		 bool reserved, bool is_atomic, size_t size,
> +		 size_t align, void *base_addr, int off,
> +		 void __percpu *ptr, size_t bytes_alloc, gfp_t gfp_flags),

Don't we want to preserve the order and add the call_site at the end?
Trace events are not ABI, but if we don't have a strong reason to break it,
I'd preserve the old order.

Thanks!

Re: [PATCH v2] percpu: improve percpu_alloc_percpu event trace

[Vasily Averin]

On 5/11/22 05:33, Roman Gushchin wrote:
> On Fri, May 06, 2022 at 10:29:25PM +0300, Vasily Averin wrote:
>>  TRACE_EVENT(percpu_alloc_percpu,
>>  
>> -	TP_PROTO(bool reserved, bool is_atomic, size_t size,
>> -		 size_t align, void *base_addr, int off, void __percpu *ptr),
>> +	TP_PROTO(unsigned long call_site,
>> +		 bool reserved, bool is_atomic, size_t size,
>> +		 size_t align, void *base_addr, int off,
>> +		 void __percpu *ptr, size_t bytes_alloc, gfp_t gfp_flags),
> 
> Don't we want to preserve the order and add the call_site at the end?
> Trace events are not ABI, but if we don't have a strong reason to break it,
> I'd preserve the old order.

I checked recent trace patches and found that order changes is acceptable.

commit 8c39b8bc82aafcc8dd378bd79c76fac8e8a89c8d
Author: David Howells <dhowells-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org>
Date:   Fri Jan 14 11:44:54 2022 +0000

    cachefiles: Make some tracepoint adjustments

-           TP_printk("o=%08x i=%lx e=%d",
-                     __entry->obj, __entry->ino, __entry->error)
+           TP_printk("o=%08x dB=%lx B=%lx e=%d",
+                     __entry->obj, __entry->dino, __entry->ino, __entry->error)

On the other hand I'm agree to keep old order by default.
that's why I added bytes_alloc and gfp_flags to end of output.
However I think call_site is an exception. In all cases found, 
call_site is output first.
For me personally it simplified output parsing.

So I would like to know Steven's position on this question.

Thank you,
	Vasily Averin

Re: [PATCH v2] percpu: improve percpu_alloc_percpu event trace

[Roman Gushchin]

On Wed, May 11, 2022 at 08:11:54AM +0300, Vasily Averin wrote:
> On 5/11/22 05:33, Roman Gushchin wrote:
> > On Fri, May 06, 2022 at 10:29:25PM +0300, Vasily Averin wrote:
> >>  TRACE_EVENT(percpu_alloc_percpu,
> >>  
> >> -	TP_PROTO(bool reserved, bool is_atomic, size_t size,
> >> -		 size_t align, void *base_addr, int off, void __percpu *ptr),
> >> +	TP_PROTO(unsigned long call_site,
> >> +		 bool reserved, bool is_atomic, size_t size,
> >> +		 size_t align, void *base_addr, int off,
> >> +		 void __percpu *ptr, size_t bytes_alloc, gfp_t gfp_flags),
> > 
> > Don't we want to preserve the order and add the call_site at the end?
> > Trace events are not ABI, but if we don't have a strong reason to break it,
> > I'd preserve the old order.
> 
> I checked recent trace patches and found that order changes is acceptable.
> 
> commit 8c39b8bc82aafcc8dd378bd79c76fac8e8a89c8d
> Author: David Howells <dhowells-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org>
> Date:   Fri Jan 14 11:44:54 2022 +0000
> 
>     cachefiles: Make some tracepoint adjustments
> 
> -           TP_printk("o=%08x i=%lx e=%d",
> -                     __entry->obj, __entry->ino, __entry->error)
> +           TP_printk("o=%08x dB=%lx B=%lx e=%d",
> +                     __entry->obj, __entry->dino, __entry->ino, __entry->error)
> 
> On the other hand I'm agree to keep old order by default.
> that's why I added bytes_alloc and gfp_flags to end of output.
> However I think call_site is an exception. In all cases found, 
> call_site is output first.
> For me personally it simplified output parsing.
> 
> So I would like to know Steven's position on this question.

Ok, not a strong opinion, I think both options are acceptable.

Thanks!

Re: [PATCH v2] percpu: improve percpu_alloc_percpu event trace

[Steven Rostedt]

On Tue, 10 May 2022 19:33:17 -0700
Roman Gushchin <roman.gushchin@linux.dev> wrote:

>  --- a/include/trace/events/percpu.h
> > +++ b/include/trace/events/percpu.h
> > @@ -6,15 +6,20 @@
> >  #define _TRACE_PERCPU_H
> >  
> >  #include <linux/tracepoint.h>
> > +#include <trace/events/mmflags.h>
> >  
> >  TRACE_EVENT(percpu_alloc_percpu,
> >  
> > -	TP_PROTO(bool reserved, bool is_atomic, size_t size,
> > -		 size_t align, void *base_addr, int off, void __percpu *ptr),
> > +	TP_PROTO(unsigned long call_site,
> > +		 bool reserved, bool is_atomic, size_t size,
> > +		 size_t align, void *base_addr, int off,
> > +		 void __percpu *ptr, size_t bytes_alloc, gfp_t gfp_flags),  
> 
> Don't we want to preserve the order and add the call_site at the end?
> Trace events are not ABI, but if we don't have a strong reason to break it,
> I'd preserve the old order.

Ideally everyone should be using libtraceevent which will parse the format
file for the needed entries.

Nothing (important) should be parsing the raw ascii from the trace files.
It's slow and unreliable. The raw format (trace_pipe_raw) files, along with
libtraceevent will handle fining the fields you are looking for, even if
the fields move around (internally or externally).

Then there's trace-cruncher (a python script that uses libtracefs and
libtraceevent) that will work too.

  https://github.com/vmware/trace-cruncher

-- Steve