Re: libtraceevent -- undefined functions

Re: libtraceevent -- undefined functions

[Steven Rostedt]

[ This is helpful information for trace users and developers so I've
  included the two lists ]

On Tue, 30 Aug 2022 12:59:46 +0200 (CEST)
Michael Petlan <mpetlan@redhat.com> wrote:

> Hello Steve,
> 
> during perf testing, I have found out that the print formats of some tracepoints
> are translated to quite complicated code, that differs per architecture and quite
> often contains various builtins and functions that are not recognized by the parser
> in libtraceevent.
> 
> It looks like this:
> 
> [root@gigabyte-r120-03 base_kmem]# perf kmem --page record -o ./perf.data -- true
> libtraceevent: No such file or directory
>   [kmem:mm_page_alloc] function __builtin_constant_p not defined
>   [kmem:mm_page_free] function __builtin_constant_p not defined
> 
> I have digged down to event-parse.c source and commits like 1b20d9491cf9 ("tools
> lib traceevent: Add handler for __builtin_expect()") that add some missing func
> support.
> 
> I have added __builtin_constant_p, it helped to suppress the warning, but then
> I found out I was missing sizeof()...
> 
> On an x86_64 F35 machine, I have found the following list of missing funcs:
>  __builtin_choose_expr
>  decode_prq_descriptor
>  jiffies_to_msecs
>  libata_trace_parse_eh_action
>  libata_trace_parse_host_stat
>  libata_trace_parse_qc_flags
>  libata_trace_parse_subcmd
>  libata_trace_parse_tf_flags
>  mc_event_error_type
>  pgd_val
>  pmd_val
>  pte_val
>  pud_val
>  scsi_trace_parse_cdb
>  sizeof

The problem with a lot of the above is that user space does not know how to
parse them. "jiffies_to_msecs" depends on knowing the HZ value. Now if the
kernel exported this, we could look for it and save this information, and
then be able to parse it correctly.

>  xen_hypercall_name
>  xhci_decode_ctrl_ctx
>  xhci_decode_doorbell
>  xhci_decode_ep_context
>  xhci_decode_portsc
>  xhci_decode_slot_context
>  xhci_ring_type_string
> 
> There are of course more, since on other platforms, the print format expands to
> different code.
> 
> I wonder, whether it might be useful to add these functions to libtraceevent
> parser. Finally, what is the purpose of the handlers, such as __builtin_expect()
> you have added? It looks like that the parser machine now accepts this token and
> handles that it has to have two parameters, but does nothing more with it. It
> lets the parser to dive deeper and process the first arg and forgets the second,
> just like replacing
>   __builtin_expect( exp, c)
> by
>   exp
> so when something executes the code, it ignores the builtin? Am I right?

Correct. As __builtin_expect() is just a compile time optimization that
"likely()" and "unlikely()" are defined to, it has no meaning to the
parser. But we still want the contents of the expression.

I had to update libtraceevent to basically ignore the __builtin_expect().

That is, "unlikely(cond)" turns into "!!__builtin_exepect(cond, 0)"

libtraceevent does not care about the "unlikely()" part, only the
condition, so the parser basically treats it the same:

  "unlikely(cond)" == "cond"

> 
> The __builtin_constant_p(arg) should decide whether arg is constant or not and
> return 1 or 0 respectively...
> 

What is using __builting_constant_p() inside the TP_printk()?

> My questions are:
>    1) Does it matther whether or not the above functions are accepted by the parser
>    grammar or not?

When it can't parse something, it falls back to just printing out the raw
fields the best it can.

>    2) Does (1) affect how the code is later executed somewhere?

It affects how it prints the event. It then ignores the TP_printk() format,
and then, as mentioned above, just prints the raw fields.

>    3) Would e.g. replacing __builtin_constant_p(arg) by 0 by default help/simplify
>    anything?

I have to see how it's used. What event does that?

-- Steve

Re: libtraceevent -- undefined functions

[Michael Petlan]

On Thu, 1 Sep 2022, Steven Rostedt wrote:
>

Hello all!

Thanks Steve for information.

> [ This is helpful information for trace users and developers so I've
>   included the two lists ]

Sure.

> On Tue, 30 Aug 2022 12:59:46 +0200 (CEST)
> Michael Petlan <mpetlan@redhat.com> wrote:
> 
> > Hello Steve,
> > 
> > during perf testing, I have found out that the print formats of some tracepoints
> > are translated to quite complicated code, that differs per architecture and quite
> > often contains various builtins and functions that are not recognized by the parser
> > in libtraceevent.
> > 
> > It looks like this:
> > 
> > [root@gigabyte-r120-03 base_kmem]# perf kmem --page record -o ./perf.data -- true
> > libtraceevent: No such file or directory
> >   [kmem:mm_page_alloc] function __builtin_constant_p not defined
> >   [kmem:mm_page_free] function __builtin_constant_p not defined
> > 
> > I have digged down to event-parse.c source and commits like 1b20d9491cf9 ("tools
> > lib traceevent: Add handler for __builtin_expect()") that add some missing func
> > support.
> > 
> > I have added __builtin_constant_p, it helped to suppress the warning, but then
> > I found out I was missing sizeof()...
> > 
> > On an x86_64 F35 machine, I have found the following list of missing funcs:
> >  __builtin_choose_expr
> >  decode_prq_descriptor
> >  jiffies_to_msecs
> >  libata_trace_parse_eh_action
> >  libata_trace_parse_host_stat
> >  libata_trace_parse_qc_flags
> >  libata_trace_parse_subcmd
> >  libata_trace_parse_tf_flags
> >  mc_event_error_type
> >  pgd_val
> >  pmd_val
> >  pte_val
> >  pud_val
> >  scsi_trace_parse_cdb
> >  sizeof
> 
> The problem with a lot of the above is that user space does not know how to
> parse them. "jiffies_to_msecs" depends on knowing the HZ value. Now if the
> kernel exported this, we could look for it and save this information, and
> then be able to parse it correctly.

Well, under the term "parse" I understand "to verify, whether the tokens
match the grammar" (i.e. that a function name has to be followed by '(' and
')' characters, that there have to be e.g. two args, separated by ',' etc.

By adding __builtin_expect support, you have added exactly this --> it now
knows the function, but does nothing around it.

Then it comes to interpreting the code, that is also done in libtraceevent,
isn't it? Does the parser produce some intermediate rep? What code performs
the interpretation?

> >  xen_hypercall_name
> >  xhci_decode_ctrl_ctx
> >  xhci_decode_doorbell
> >  xhci_decode_ep_context
> >  xhci_decode_portsc
> >  xhci_decode_slot_context
> >  xhci_ring_type_string
> > 
> > There are of course more, since on other platforms, the print format expands to
> > different code.
> > 
> > I wonder, whether it might be useful to add these functions to libtraceevent
> > parser. Finally, what is the purpose of the handlers, such as __builtin_expect()
> > you have added? It looks like that the parser machine now accepts this token and
> > handles that it has to have two parameters, but does nothing more with it. It
> > lets the parser to dive deeper and process the first arg and forgets the second,
> > just like replacing
> >   __builtin_expect( exp, c)
> > by
> >   exp
> > so when something executes the code, it ignores the builtin? Am I right?
> 
> Correct. As __builtin_expect() is just a compile time optimization that
> "likely()" and "unlikely()" are defined to, it has no meaning to the
> parser. But we still want the contents of the expression.
> 
> I had to update libtraceevent to basically ignore the __builtin_expect().
> 
> That is, "unlikely(cond)" turns into "!!__builtin_exepect(cond, 0)"
> 
> libtraceevent does not care about the "unlikely()" part, only the
> condition, so the parser basically treats it the same:
> 
>   "unlikely(cond)" == "cond"

Good, so I understood your approach correctly.
> 
> > 
> > The __builtin_constant_p(arg) should decide whether arg is constant or not and
> > return 1 or 0 respectively...
> > 
> 
> What is using __builting_constant_p() inside the TP_printk()?

There are several events. However, I don't know who takes the tracepoint description
and generates the terribly complicated expression below.

> 
> > My questions are:
> >    1) Does it matther whether or not the above functions are accepted by the parser
> >    grammar or not?
> 
> When it can't parse something, it falls back to just printing out the raw
> fields the best it can.
> 
> >    2) Does (1) affect how the code is later executed somewhere?
> 
> It affects how it prints the event. It then ignores the TP_printk() format,
> and then, as mentioned above, just prints the raw fields.

OK, so if parsing does not fail, the code is interpreted by libtraceevent?

In such case, the missing functions should be added or added as bypassed
the similar way (e.g. __builtin_constant_p could be replaced by 0). Then,
for example the sizeof should be accepted by the parser, but also interpreted
correctly...

> >    3) Would e.g. replacing __builtin_constant_p(arg) by 0 by default help/simplify
> >    anything?
> 
> I have to see how it's used. What event does that?

This is aarch64, event mm_page_alloc, kernel is from RHEL-9, so 5.14:

print fmt: "page=%p pfn=0x%lx order=%d migratetype=%d gfp_flags=%s", REC->pfn != -1UL ? (((struct page *)(-((((1UL))) << ((48) - (12 - (( __builtin_constant_p(sizeof(struct page)) ? ( ((sizeof(struct page)) == 0 || (sizeof(struct page)) == 1) ? 0 : ( __builtin_constant_p((sizeof(struct page)) - 1) ? (((sizeof(struct page)) - 1) < 2 ? 0 : 63 - __builtin_clzll((sizeof(struct page)) - 1)) : (sizeof((sizeof(struct page)) - 1) <= 4) ? __ilog2_u32((sizeof(struct page)) - 1) : __ilog2_u64((sizeof(struct page)) - 1) ) + 1) : __order_base_2(sizeof(struct page)) )))))) - (memstart_addr >> 12)) + (REC->pfn)) : ((void *)0), REC->pfn != -1UL ? REC->pfn : 0, REC->order, REC->migratetype, (REC->gfp_flags) ? __print_flags(REC->gfp_flags, "|", {(unsigned long)(((((((( gfp_t)(0x400u|0x800u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x100000u)) | (( gfp_t)0x02u)) | (( gfp_t)0x08u) | (( gfp_t)0x1000000u)) | (( gfp_t)0x40000u) | (( gfp_t)0x80000u) | (( gfp_t)0x2000u)) & ~(( gfp_t)(0x400u|0x800u))) 
 | (( gfp_t)0x400u)), "GFP_TRANSHUGE"}, {(unsigned long)((((((( gfp_t)(0x400u|0x800u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x100000u)) | (( gfp_t)0x02u)) | (( gfp_t)0x08u) | (( gfp_t)0x1000000u)) | (( gfp_t)0x40000u) | (( gfp_t)0x80000u) | (( gfp_t)0x2000u)) & ~(( gfp_t)(0x400u|0x800u))), "GFP_TRANSHUGE_LIGHT"}, {(unsigned long)((((( gfp_t)(0x400u|0x800u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x100000u)) | (( gfp_t)0x02u)) | (( gfp_t)0x08u) | (( gfp_t)0x1000000u)), "GFP_HIGHUSER_MOVABLE"}, {(unsigned long)(((( gfp_t)(0x400u|0x800u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x100000u)) | (( gfp_t)0x02u)), "GFP_HIGHUSER"}, {(unsigned long)((( gfp_t)(0x400u|0x800u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x100000u)), "GFP_USER"}, {(unsigned long)(((( gfp_t)(0x400u|0x800u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u)) | (( gfp_t)0x400000u)), "GFP_KERNEL_ACCOUNT"}, {(unsigned long)((( gfp_t)(0x400u|0x800u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u)), "GFP_KERNEL"}, {(
 unsigned long)((( gfp_t)(0x400u|0x800u)) | (( gfp_t)0x40u)), "GFP_NOFS"}, {(unsigned long)((( gfp_t)0x20u)|(( gfp_t)0x200u)|(( gfp_t)0x800u)), "GFP_ATOMIC"}, {(unsigned long)((( gfp_t)(0x400u|0x800u))), "GFP_NOIO"}, {(unsigned long)((( gfp_t)0x800u)), "GFP_NOWAIT"}, {(unsigned long)(( gfp_t)0x01u), "GFP_DMA"}, {(unsigned long)(( gfp_t)0x02u), "__GFP_HIGHMEM"}, {(unsigned long)(( gfp_t)0x04u), "GFP_DMA32"}, {(unsigned long)(( gfp_t)0x20u), "__GFP_HIGH"}, {(unsigned long)(( gfp_t)0x200u), "__GFP_ATOMIC"}, {(unsigned long)(( gfp_t)0x40u), "__GFP_IO"}, {(unsigned long)(( gfp_t)0x80u), "__GFP_FS"}, {(unsigned long)(( gfp_t)0x2000u), "__GFP_NOWARN"}, {(unsigned long)(( gfp_t)0x4000u), "__GFP_RETRY_MAYFAIL"}, {(unsigned long)(( gfp_t)0x8000u), "__GFP_NOFAIL"}, {(unsigned long)(( gfp_t)0x10000u), "__GFP_NORETRY"}, {(unsigned long)(( gfp_t)0x40000u), "__GFP_COMP"}, {(unsigned long)(( gfp_t)0x100u), "__GFP_ZERO"}, {(unsigned long)(( gfp_t)0x80000u), "__GFP_NOMEMALLOC"}, {(unsigned long)(( gfp
 _t)0x20000u), "__GFP_MEMALLOC"}, {(unsigned long)(( gfp_t)0x100000u), "__GFP_HARDWALL"}, {(unsigned long)(( gfp_t)0x200000u), "__GFP_THISNODE"}, {(unsigned long)(( gfp_t)0x10u), "__GFP_RECLAIMABLE"}, {(unsigned long)(( gfp_t)0x08u), "__GFP_MOVABLE"}, {(unsigned long)(( gfp_t)0x400000u), "__GFP_ACCOUNT"}, {(unsigned long)(( gfp_t)0x1000u), "__GFP_WRITE"}, {(unsigned long)(( gfp_t)(0x400u|0x800u)), "__GFP_RECLAIM"}, {(unsigned long)(( gfp_t)0x400u), "__GFP_DIRECT_RECLAIM"}, {(unsigned long)(( gfp_t)0x800u), "__GFP_KSWAPD_RECLAIM"}, {(unsigned long)(( gfp_t)0x800000u), "__GFP_ZEROTAGS"}, {(unsigned long)(( gfp_t)0x1000000u),"__GFP_SKIP_KASAN_POISON"} ) : "none"

Quite long, but whatever...

> 
> -- Steve
> 
> 

Re: libtraceevent -- undefined functions

[Steven Rostedt]

On Mon, 5 Sep 2022 17:36:28 +0200 (CEST)
Michael Petlan <mpetlan@redhat.com> wrote:
> > 
> > The problem with a lot of the above is that user space does not know how to
> > parse them. "jiffies_to_msecs" depends on knowing the HZ value. Now if the
> > kernel exported this, we could look for it and save this information, and
> > then be able to parse it correctly.  
> 
> Well, under the term "parse" I understand "to verify, whether the tokens
> match the grammar" (i.e. that a function name has to be followed by '(' and
> ')' characters, that there have to be e.g. two args, separated by ',' etc.
> 
> By adding __builtin_expect support, you have added exactly this --> it now
> knows the function, but does nothing around it.

The difference is that one is an optimization for the compiler, where the
output will always be the same. The other changes what the value will be
depending on what the kernel HZ is.

I chose to fail parsing if we cannot prove that the output has integrity.

> 
> Then it comes to interpreting the code, that is also done in libtraceevent,
> isn't it? Does the parser produce some intermediate rep? What code performs
> the interpretation?
> 

> > 
> > Correct. As __builtin_expect() is just a compile time optimization that
> > "likely()" and "unlikely()" are defined to, it has no meaning to the
> > parser. But we still want the contents of the expression.
> > 
> > I had to update libtraceevent to basically ignore the __builtin_expect().
> > 
> > That is, "unlikely(cond)" turns into "!!__builtin_exepect(cond, 0)"
> > 
> > libtraceevent does not care about the "unlikely()" part, only the
> > condition, so the parser basically treats it the same:
> > 
> >   "unlikely(cond)" == "cond"  
> 
> Good, so I understood your approach correctly.
> >   
> > > 
> > > The __builtin_constant_p(arg) should decide whether arg is constant or not and
> > > return 1 or 0 respectively...
> > >   
> > 
> > What is using __builting_constant_p() inside the TP_printk()?  
> 
> There are several events. However, I don't know who takes the tracepoint description
> and generates the terribly complicated expression below.
> 
> >   
> > > My questions are:
> > >    1) Does it matther whether or not the above functions are accepted by the parser
> > >    grammar or not?  
> > 
> > When it can't parse something, it falls back to just printing out the raw
> > fields the best it can.
> >   
> > >    2) Does (1) affect how the code is later executed somewhere?  
> > 
> > It affects how it prints the event. It then ignores the TP_printk() format,
> > and then, as mentioned above, just prints the raw fields.  
> 
> OK, so if parsing does not fail, the code is interpreted by libtraceevent?

Correct.

> 
> In such case, the missing functions should be added or added as bypassed
> the similar way (e.g. __builtin_constant_p could be replaced by 0). Then,
> for example the sizeof should be accepted by the parser, but also interpreted
> correctly...

Now what we could do for undefined functions, is to keep the warning that
it doesn't know how to interpret it, but instead of failing to parse, to
instead show the function in the output:

For the event ata_qc_issue (the first one I found when doing a
"trace-cmd record -e all" that failed to parse):

It has in its TP_printk()

   libata_trace_parse_subcmd(p, REC->cmd, REC->feature, REC->hob_nsect)

We could convert that in the output where it has:

  print fmt: "ata_port=%u ata_dev=%u tag=%d proto=%s cmd=%s%s  tf=(%02x/%02x:%02x:%02x:%02x:%02x/%02x:%02x:%02x:%02x:%02x/%02x)"
                                                            ^
                                                            |
              libata_trace_parse_subcmd(p, REC->cmd, REC->feature, REC->hob_nsect)

Instead of printing:

sleep-47414 [006] 313119.147175: ata_qc_issue:         [FAILED TO PARSE] ata_port=1 ata_dev=0 tag=22 cmd=96 dev=64 lbal=24 lbam=69 lbah=253 nsect=176 feature=16 hob_lbal=2 hob_lbam=0 hob_lbah=0 hob_nsect=0 hob_feature=0 ctl=120 proto=6 flags=0x726f776b00000000


It could print:


sleep-47414 [006] 313119.147175: ata_qc_issue:         ata_port=1 ata_dev=0 tag=22 [..]libata_trace_parse_subcmd(p, cmd=96, feature=16, nob_nsect=0) [...]

And continue to parse everything else it understands.

> 
> > >    3) Would e.g. replacing __builtin_constant_p(arg) by 0 by default help/simplify
> > >    anything?  
> > 
> > I have to see how it's used. What event does that?  
> 
> This is aarch64, event mm_page_alloc, kernel is from RHEL-9, so 5.14:
> 
> print fmt: "page=%p pfn=0x%lx order=%d migratetype=%d gfp_flags=%s", REC->pfn != -1UL ? (((struct page *)(-((((1UL))) << ((48) - (12 - (( __builtin_constant_p(sizeof(struct page)) ? ( ((sizeof(struct page)) == 0 || (sizeof(struct page)) == 1) ? 0 : ( __builtin_constant_p((sizeof(struct page)) - 1) ? (((sizeof(struct page)) - 1) < 2 ? 0 : 63 - __builtin_clzll((sizeof(struct page)) - 1)) : (sizeof((sizeof(struct page)) - 1) <= 4) ? __ilog2_u32((sizeof(struct page)) - 1) : __ilog2_u64((sizeof(struct page)) - 1) ) + 1) : __order_base_2(sizeof(struct page)) )))))) - (memstart_addr >> 12)) + (REC->pfn)) : ((void *)0), REC->pfn != -1UL ? REC->pfn : 0, REC->order, REC->migratetype, (REC->gfp_flags) ? __print_flags(REC->gfp_flags, "|", {(unsigned long)(((((((( gfp_t)(0x400u|0x800u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x100000u)) | (( gfp_t)0x02u)) | (( gfp_t)0x08u) | (( gfp_t)0x1000000u)) | (( gfp_t)0x40000u) | (( gfp_t)0x80000u) | (( gfp_t)0x2000u)) & ~(( gfp_t)(0x400u|0x800u))
 ) 
>  | (( gfp_t)0x400u)), "GFP_TRANSHUGE"}, {(unsigned long)((((((( gfp_t)(0x400u|0x800u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x100000u)) | (( gfp_t)0x02u)) | (( gfp_t)0x08u) | (( gfp_t)0x1000000u)) | (( gfp_t)0x40000u) | (( gfp_t)0x80000u) | (( gfp_t)0x2000u)) & ~(( gfp_t)(0x400u|0x800u))), "GFP_TRANSHUGE_LIGHT"}, {(unsigned long)((((( gfp_t)(0x400u|0x800u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x100000u)) | (( gfp_t)0x02u)) | (( gfp_t)0x08u) | (( gfp_t)0x1000000u)), "GFP_HIGHUSER_MOVABLE"}, {(unsigned long)(((( gfp_t)(0x400u|0x800u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x100000u)) | (( gfp_t)0x02u)), "GFP_HIGHUSER"}, {(unsigned long)((( gfp_t)(0x400u|0x800u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x100000u)), "GFP_USER"}, {(unsigned long)(((( gfp_t)(0x400u|0x800u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u)) | (( gfp_t)0x400000u)), "GFP_KERNEL_ACCOUNT"}, {(unsigned long)((( gfp_t)(0x400u|0x800u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u)), "GFP_KERNEL"}, 
 {(
>  unsigned long)((( gfp_t)(0x400u|0x800u)) | (( gfp_t)0x40u)), "GFP_NOFS"}, {(unsigned long)((( gfp_t)0x20u)|(( gfp_t)0x200u)|(( gfp_t)0x800u)), "GFP_ATOMIC"}, {(unsigned long)((( gfp_t)(0x400u|0x800u))), "GFP_NOIO"}, {(unsigned long)((( gfp_t)0x800u)), "GFP_NOWAIT"}, {(unsigned long)(( gfp_t)0x01u), "GFP_DMA"}, {(unsigned long)(( gfp_t)0x02u), "__GFP_HIGHMEM"}, {(unsigned long)(( gfp_t)0x04u), "GFP_DMA32"}, {(unsigned long)(( gfp_t)0x20u), "__GFP_HIGH"}, {(unsigned long)(( gfp_t)0x200u), "__GFP_ATOMIC"}, {(unsigned long)(( gfp_t)0x40u), "__GFP_IO"}, {(unsigned long)(( gfp_t)0x80u), "__GFP_FS"}, {(unsigned long)(( gfp_t)0x2000u), "__GFP_NOWARN"}, {(unsigned long)(( gfp_t)0x4000u), "__GFP_RETRY_MAYFAIL"}, {(unsigned long)(( gfp_t)0x8000u), "__GFP_NOFAIL"}, {(unsigned long)(( gfp_t)0x10000u), "__GFP_NORETRY"}, {(unsigned long)(( gfp_t)0x40000u), "__GFP_COMP"}, {(unsigned long)(( gfp_t)0x100u), "__GFP_ZERO"}, {(unsigned long)(( gfp_t)0x80000u), "__GFP_NOMEMALLOC"}, {(unsigned long)(( g
 fp
>  _t)0x20000u), "__GFP_MEMALLOC"}, {(unsigned long)(( gfp_t)0x100000u), "__GFP_HARDWALL"}, {(unsigned long)(( gfp_t)0x200000u), "__GFP_THISNODE"}, {(unsigned long)(( gfp_t)0x10u), "__GFP_RECLAIMABLE"}, {(unsigned long)(( gfp_t)0x08u), "__GFP_MOVABLE"}, {(unsigned long)(( gfp_t)0x400000u), "__GFP_ACCOUNT"}, {(unsigned long)(( gfp_t)0x1000u), "__GFP_WRITE"}, {(unsigned long)(( gfp_t)(0x400u|0x800u)), "__GFP_RECLAIM"}, {(unsigned long)(( gfp_t)0x400u), "__GFP_DIRECT_RECLAIM"}, {(unsigned long)(( gfp_t)0x800u), "__GFP_KSWAPD_RECLAIM"}, {(unsigned long)(( gfp_t)0x800000u), "__GFP_ZEROTAGS"}, {(unsigned long)(( gfp_t)0x1000000u),"__GFP_SKIP_KASAN_POISON"} ) : "none"
> 
> Quite long, but whatever...
> 
> 

The TRACE_EVENT() macro that defines that mess is:

TRACE_EVENT(mm_page_alloc,

        TP_PROTO(struct page *page, unsigned int order,
                        gfp_t gfp_flags, int migratetype),

        TP_ARGS(page, order, gfp_flags, migratetype),

        TP_STRUCT__entry(
                __field(        unsigned long,  pfn             )
                __field(        unsigned int,   order           )
                __field(        unsigned long,  gfp_flags       )
                __field(        int,            migratetype     )
        ),

        TP_fast_assign(
                __entry->pfn            = page ? page_to_pfn(page) : -1UL;
                __entry->order          = order;
                __entry->gfp_flags      = (__force unsigned long)gfp_flags;
                __entry->migratetype    = migratetype;
        ),

        TP_printk("page=%p pfn=0x%lx order=%d migratetype=%d gfp_flags=%s",
                __entry->pfn != -1UL ? pfn_to_page(__entry->pfn) : NULL,
                __entry->pfn != -1UL ? __entry->pfn : 0,
                __entry->order,
                __entry->migratetype,
                show_gfp_flags(__entry->gfp_flags))
);


So looking at the first line:

                __entry->pfn != -1UL ? pfn_to_page(__entry->pfn) : NULL,

The pfn_to_page() must be a macro expanded to that huge output. 

The thing is, there's no way that user space can know what the result of
that pfn_to_page is, as that information is hidden inside the kernel.

I do not see that expanding like the above in the latest kernel. I'm
guessing the kernel you have has that crazy expansion of pfn_to_page() though.

Probably the best thing that user space can do is to just do what it does
now and simply output the event fields. We do not want to have the output
showing all that builtin_constant_p() and size_of() callers.

-- Steve

Re: libtraceevent -- undefined functions

[Steven Rostedt]

On Mon, 5 Sep 2022 12:29:16 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:

> So looking at the first line:
> 
>                 __entry->pfn != -1UL ? pfn_to_page(__entry->pfn) : NULL,
> 
> The pfn_to_page() must be a macro expanded to that huge output. 
> 
> The thing is, there's no way that user space can know what the result of
> that pfn_to_page is, as that information is hidden inside the kernel.
> 
> I do not see that expanding like the above in the latest kernel. I'm
> guessing the kernel you have has that crazy expansion of pfn_to_page() though.
> 
> Probably the best thing that user space can do is to just do what it does
> now and simply output the event fields. We do not want to have the output
> showing all that builtin_constant_p() and size_of() callers.

Yeah, on 5.14 it looks like this:

#define pfn_to_page __pfn_to_page

#define __pfn_to_page(pfn)      (vmemmap + (pfn))

#define vmemmap                 ((struct page *)VMEMMAP_START - (memstart_addr >> PAGE_SHIFT))

#define VMEMMAP_START           (-(UL(1) << (VA_BITS - VMEMMAP_SHIFT)))

#define VA_BITS                 (CONFIG_ARM64_VA_BITS)

#define VMEMMAP_SHIFT   (PAGE_SHIFT - STRUCT_PAGE_MAX_SHIFT)

#define PAGE_SHIFT              CONFIG_ARM64_PAGE_SHIFT

#define STRUCT_PAGE_MAX_SHIFT    (order_base_2(sizeof(struct page)))

#define order_base_2(n)                         \
(                                               \
        __builtin_constant_p(n) ? (             \
                ((n) == 0 || (n) == 1) ? 0 :    \
                ilog2((n) - 1) + 1) :           \
        __order_base_2(n)                       \
)

#define ilog2(n) \
( \
        __builtin_constant_p(n) ?       \
        ((n) < 2 ? 0 :                  \
         63 - __builtin_clzll(n)) :     \
        (sizeof(n) <= 4) ?              \
        __ilog2_u32(n) :                \
        __ilog2_u64(n)                  \
 )

and so on.

Thus, the pfn_to_page() macro gets expanded to some God awful expression.

There's not much we can do about this from the libtraceevent perspective :-/

-- Steve