linux-rt-users.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* uprobes enable condition (user space) - sysfs interface
@ 2017-11-29 18:34 bhargavb
  2017-12-01 16:40 ` Arnaldo Carvalho de Melo
  0 siblings, 1 reply; 11+ messages in thread
From: bhargavb @ 2017-11-29 18:34 UTC (permalink / raw)
  To: linux-rt-users, linux-perf-users

Hello,

I am trying to understand user space profiling using linux inbuilt
mechanism. (Trying with perf also but could not get complete clear
documentation and could not proceed, so retained linux-perf-users in
to list as the underlying interface used is same for both).

I observed below behaviour when I tried as per directions using URL:
https://opensource.com/article/17/7/dynamic-tracing-linux-user-and-kernel-space#comment-136366
:


echo 'p:<func_entry> ./test:0x420' >
/sys/kernel/debug/tracing/uprobe_events              (for creating
uprobe)
echo 1 > /sys/kernel/debug/tracing/events/enable
                                (enabling uproble)
There is another enable parameter:
/sys/kernel/debug/tracing/events/uprobes/enable

I understand unless enabled both events/enable and
events/uprobes/enable, the /sys/kernel/debug/tracing/trace is not
complete. I do not understand the relevance of
.....events/uprobes/enable as I could not get any trace data in trace
log for 'func_entry' the user space function being added for tracing.
Irrespective of the probe function added, the trace log shows complete
system trace log during the period of execution of the user
application being traced.

Can this be clearly mentioned as to when to use one of them, role of
both and and also, I could not see uprobe function in particular at
all but generic trace in /sys/kernel/debug/tracing/trace. Kindly guide
me in understanding uprobe enable logic in user space in detail.

Regards,
Bhargav

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: uprobes enable condition (user space) - sysfs interface
  2017-11-29 18:34 uprobes enable condition (user space) - sysfs interface bhargavb
@ 2017-12-01 16:40 ` Arnaldo Carvalho de Melo
  2017-12-03 17:14   ` bhargavb
  2017-12-04 12:36   ` Masami Hiramatsu
  0 siblings, 2 replies; 11+ messages in thread
From: Arnaldo Carvalho de Melo @ 2017-12-01 16:40 UTC (permalink / raw)
  To: bhargavb; +Cc: linux-rt-users, linux-perf-users, Masami Hiramatsu

Adding Masami to the CC list, to see if he can come up with a fix for
the 'perf probe' failure below, improving the message or ignoring
versioned symbols (with a warning perhaps).

Em Thu, Nov 30, 2017 at 12:04:23AM +0530, bhargavb escreveu:
> Hello,
> 
> I am trying to understand user space profiling using linux inbuilt
> mechanism. (Trying with perf also but could not get complete clear
> documentation and could not proceed, so retained linux-perf-users in
> to list as the underlying interface used is same for both).

So yo uwant to trace function entry/exit in some userspace library? You
can try using the tracefs as below or leave it to perf to do that, first
you set up the probes, say for some glibc functions:

[root@jouet ~]# perf probe -F -x /lib64/libc-2.25.so  | grep ^malloc
malloc
malloc_check
malloc_consolidate.part.1
malloc_get_state@GLIBC_2.2.5
malloc_hook_ini
malloc_info
malloc_printerr
malloc_set_state@GLIBC_2.2.5
malloc_stats
malloc_trim
malloc_usable_size
mallochook
[root@jouet ~]#

[root@jouet ~]# perf probe -x /lib64/libc-2.25.so malloc*
Failed to write event: Invalid argument
  Error: Failed to add events.
[root@jouet ~]# 

For now ignore that error, its a bug I just found, what matters is that
it _has_ put in place probes for most of those functions, as you can see
by looking at:

[root@jouet ~]# perf probe -l
  probe_libc:malloc    (on __malloc in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_check (on malloc_check in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_consolidate (on malloc_consolidate.part.1 in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_hook_ini (on malloc_hook_ini in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_info (on __malloc_info in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_printerr (on malloc_printerr in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_stats (on __malloc_stats in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_trim (on __malloc_trim in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_usable_size (on __malloc_usable_size in /usr/lib64/libc-2.25.so)
  probe_libc:mallochook (on mallochook in /usr/lib64/libc-2.25.so)
[root@jouet ~]#

Masami, this one also doesn't work:

[root@jouet ~]# perf probe -x /lib64/libc-2.25.so 'malloc*%return'
Error: event "malloc_printerr" already exists.
<SNIP>

doing it a bit differently:

[root@jouet ~]# perf probe -F -x /lib64/libc-2.25.so | egrep ^malloc[^@]+$ | while read function ; do perf probe -x /lib64/libc-2.25.so "${function}_return=$function%return" ; done
Added new event:
  probe_libc:malloc_check_return (on malloc_check%return in /usr/lib64/libc-2.25.so)

You can now use it in all perf tools, such as:

	perf record -e probe_libc:malloc_check_return -aR sleep 1

<SNIP>
-----------

This now makes us have:

[root@jouet ~]# perf probe -l
  probe:check_stack_object (on check_stack_object%return@acme/git/linux/mm/usercopy.c with ret)
  probe_libc:malloc    (on __malloc in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_check (on malloc_check in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_consolidate (on malloc_consolidate.part.1 in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_hook_ini (on malloc_hook_ini in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_info (on __malloc_info in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_printerr (on malloc_printerr in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_stats (on __malloc_stats in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_trim (on __malloc_trim in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_usable_size (on __malloc_usable_size in /usr/lib64/libc-2.25.so)
  probe_libc:mallochook (on mallochook in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_check_return (on malloc_check%return in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_hook_ini_return (on malloc_hook_ini%return in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_info_return (on __malloc_info%return in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_printerr_return (on malloc_printerr%return in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_stats_return (on __malloc_stats%return in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_trim_return (on __malloc_trim%return in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_usable_size_return (on __malloc_usable_size%return in /usr/lib64/libc-2.25.so)
  probe_libc:mallochook_return (on mallochook%return in /usr/lib64/libc-2.25.so)
  probe_libc:malloc_return (on __malloc%return in /usr/lib64/libc-2.25.so)
[root@jouet ~]# 

There were some usability snags that prevented this from being put in
place, so do it manually:

[root@jouet ~]# perf probe -x /lib64/libc-2.25.so 'malloc_consolidate_return=malloc_consolidate.part.1%return'
Added new event:
  probe_libc:malloc_consolidate_return (on malloc_consolidate.part.1%return in /usr/lib64/libc-2.25.so)

You can now use it in all perf tools, such as:

	perf record -e probe_libc:malloc_consolidate_return -aR sleep 1

[root@jouet ~]#

Ok, now we can trace this syswide using:

[root@jouet ~]# perf trace --no-syscalls -e probe_libc:*
<BIG SNIP>
   339.557 probe_libc:malloc:(7fda55c22970))
   339.562 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
   339.567 probe_libc:malloc_consolidate:(7fda55c1b7b0))
   339.570 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
   339.596 probe_libc:malloc:(7fda55c22970))
   339.600 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
   339.622 probe_libc:malloc:(7fda55c22970))
   339.626 probe_libc:malloc_return:(7fda55c22970 <- 7fda56ba9a39))
   339.631 probe_libc:malloc:(7fda55c22970))
   339.634 probe_libc:malloc_return:(7fda55c22970 <- 7fda578f1713))
   339.637 probe_libc:malloc:(7fda55c22970))
   339.641 probe_libc:malloc_return:(7fda55c22970 <- 7fda578f14ae))
   339.657 probe_libc:malloc_consolidate:(7fda55c1b7b0))
   339.661 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1dbd6))
   339.664 probe_libc:malloc:(7fda55c22970))
   339.667 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
   339.670 probe_libc:malloc:(7fda55c22970))
   339.673 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
   339.678 probe_libc:malloc_consolidate:(7fda55c1b7b0))
   339.681 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
   339.685 probe_libc:malloc_consolidate:(7fda55c1b7b0))
   339.688 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
   339.693 probe_libc:malloc_consolidate:(7fda55c1b7b0))
   339.696 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
   339.778 probe_libc:malloc:(7fda55c22970))
   339.783 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
   339.788 probe_libc:malloc_consolidate:(7fda55c1b7b0))
  ^C(7fda55c22970 <- 7fda578f14ae))
[root@jouet ~]# 

It works as well with 'perf record' + 'perf script'.

Other features from perf can be added to the mix, like callchains, etc.

But see below for doing it via tracefs
 
> I observed below behaviour when I tried as per directions using URL:
> https://opensource.com/article/17/7/dynamic-tracing-linux-user-and-kernel-space#comment-136366
> :
> 
> 
> echo 'p:<func_entry> ./test:0x420' >
> /sys/kernel/debug/tracing/uprobe_events              (for creating
> uprobe)
> echo 1 > /sys/kernel/debug/tracing/events/enable
>                                 (enabling uproble)
> There is another enable parameter:
> /sys/kernel/debug/tracing/events/uprobes/enable
> 
> I understand unless enabled both events/enable and
> events/uprobes/enable, the /sys/kernel/debug/tracing/trace is not
> complete. I do not understand the relevance of
> .....events/uprobes/enable as I could not get any trace data in trace
> log for 'func_entry' the user space function being added for tracing.
> Irrespective of the probe function added, the trace log shows complete
> system trace log during the period of execution of the user
> application being traced.

Is this what you want:

[root@jouet ~]# cd /sys/kernel/debug/tracing/
[root@jouet tracing]# cat available_tracers 
hwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop
[root@jouet tracing]# echo nop > current_tracer 
[root@jouet tracing]# echo 1 > events/probe_libc/malloc/enable 
[root@jouet tracing]# echo 1 > tracing_on 
[root@jouet tracing]# tail trace
            tail-1581  [002] d... 118484.507167: malloc: (0x7fdb32d67970)
            tail-1581  [002] d... 118484.507172: malloc: (0x7fdb32d67970)
            tail-1581  [002] d... 118484.507189: malloc: (0x7fdb32d67970)
            tail-1581  [002] d... 118484.507193: malloc: (0x7fdb32d67970)
            tail-1581  [002] d... 118484.507198: malloc: (0x7fdb32d67970)
            tail-1581  [002] d... 118484.507203: malloc: (0x7fdb32d67970)
            tail-1581  [002] d... 118484.507208: malloc: (0x7fdb32d67970)
            tail-1581  [002] d... 118484.507214: malloc: (0x7fdb32d67970)
            tail-1581  [002] d... 118484.507224: malloc: (0x7fdb32d67970)
            tail-1581  [002] d... 118484.507237: malloc: (0x7fdb32d67970)
[root@jouet tracing]#

?
 
> Can this be clearly mentioned as to when to use one of them, role of
> both and and also, I could not see uprobe function in particular at
> all but generic trace in /sys/kernel/debug/tracing/trace. Kindly guide
> me in understanding uprobe enable logic in user space in detail.
> 
> Regards,
> Bhargav
> --
> To unsubscribe from this list: send the line "unsubscribe linux-perf-users" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: uprobes enable condition (user space) - sysfs interface
  2017-12-01 16:40 ` Arnaldo Carvalho de Melo
@ 2017-12-03 17:14   ` bhargavb
  2017-12-04  6:03     ` Namhyung Kim
  2017-12-04 12:36   ` Masami Hiramatsu
  1 sibling, 1 reply; 11+ messages in thread
From: bhargavb @ 2017-12-03 17:14 UTC (permalink / raw)
  To: Arnaldo Carvalho de Melo
  Cc: linux-rt-users, linux-perf-users, Masami Hiramatsu

Dear Arnaldo,
Exactly, the last one was what I was looking for. Thank you very much...
That apart I am also exploring various profiling options that can give
me a full control of monitoring running processes (user space
profiling ).
sysfs seems powerful and very useful, though I got to know lately (and
not much mentioned, I think as tools like perf etc).  I was confused
when u said tracefs in your response, I understand it is same as
sysfs. Please correct me if I am wrong.

Thanks and regards,
bhargav


On Fri, Dec 1, 2017 at 10:10 PM, Arnaldo Carvalho de Melo
<arnaldo.melo@gmail.com> wrote:
> Adding Masami to the CC list, to see if he can come up with a fix for
> the 'perf probe' failure below, improving the message or ignoring
> versioned symbols (with a warning perhaps).
>
> Em Thu, Nov 30, 2017 at 12:04:23AM +0530, bhargavb escreveu:
>> Hello,
>>
>> I am trying to understand user space profiling using linux inbuilt
>> mechanism. (Trying with perf also but could not get complete clear
>> documentation and could not proceed, so retained linux-perf-users in
>> to list as the underlying interface used is same for both).
>
> So yo uwant to trace function entry/exit in some userspace library? You
> can try using the tracefs as below or leave it to perf to do that, first
> you set up the probes, say for some glibc functions:
>
> [root@jouet ~]# perf probe -F -x /lib64/libc-2.25.so  | grep ^malloc
> malloc
> malloc_check
> malloc_consolidate.part.1
> malloc_get_state@GLIBC_2.2.5
> malloc_hook_ini
> malloc_info
> malloc_printerr
> malloc_set_state@GLIBC_2.2.5
> malloc_stats
> malloc_trim
> malloc_usable_size
> mallochook
> [root@jouet ~]#
>
> [root@jouet ~]# perf probe -x /lib64/libc-2.25.so malloc*
> Failed to write event: Invalid argument
>   Error: Failed to add events.
> [root@jouet ~]#
>
> For now ignore that error, its a bug I just found, what matters is that
> it _has_ put in place probes for most of those functions, as you can see
> by looking at:
>
> [root@jouet ~]# perf probe -l
>   probe_libc:malloc    (on __malloc in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_check (on malloc_check in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_consolidate (on malloc_consolidate.part.1 in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_hook_ini (on malloc_hook_ini in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_info (on __malloc_info in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_printerr (on malloc_printerr in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_stats (on __malloc_stats in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_trim (on __malloc_trim in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_usable_size (on __malloc_usable_size in /usr/lib64/libc-2.25.so)
>   probe_libc:mallochook (on mallochook in /usr/lib64/libc-2.25.so)
> [root@jouet ~]#
>
> Masami, this one also doesn't work:
>
> [root@jouet ~]# perf probe -x /lib64/libc-2.25.so 'malloc*%return'
> Error: event "malloc_printerr" already exists.
> <SNIP>
>
> doing it a bit differently:
>
> [root@jouet ~]# perf probe -F -x /lib64/libc-2.25.so | egrep ^malloc[^@]+$ | while read function ; do perf probe -x /lib64/libc-2.25.so "${function}_return=$function%return" ; done
> Added new event:
>   probe_libc:malloc_check_return (on malloc_check%return in /usr/lib64/libc-2.25.so)
>
> You can now use it in all perf tools, such as:
>
>         perf record -e probe_libc:malloc_check_return -aR sleep 1
>
> <SNIP>
> -----------
>
> This now makes us have:
>
> [root@jouet ~]# perf probe -l
>   probe:check_stack_object (on check_stack_object%return@acme/git/linux/mm/usercopy.c with ret)
>   probe_libc:malloc    (on __malloc in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_check (on malloc_check in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_consolidate (on malloc_consolidate.part.1 in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_hook_ini (on malloc_hook_ini in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_info (on __malloc_info in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_printerr (on malloc_printerr in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_stats (on __malloc_stats in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_trim (on __malloc_trim in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_usable_size (on __malloc_usable_size in /usr/lib64/libc-2.25.so)
>   probe_libc:mallochook (on mallochook in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_check_return (on malloc_check%return in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_hook_ini_return (on malloc_hook_ini%return in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_info_return (on __malloc_info%return in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_printerr_return (on malloc_printerr%return in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_stats_return (on __malloc_stats%return in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_trim_return (on __malloc_trim%return in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_usable_size_return (on __malloc_usable_size%return in /usr/lib64/libc-2.25.so)
>   probe_libc:mallochook_return (on mallochook%return in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_return (on __malloc%return in /usr/lib64/libc-2.25.so)
> [root@jouet ~]#
>
> There were some usability snags that prevented this from being put in
> place, so do it manually:
>
> [root@jouet ~]# perf probe -x /lib64/libc-2.25.so 'malloc_consolidate_return=malloc_consolidate.part.1%return'
> Added new event:
>   probe_libc:malloc_consolidate_return (on malloc_consolidate.part.1%return in /usr/lib64/libc-2.25.so)
>
> You can now use it in all perf tools, such as:
>
>         perf record -e probe_libc:malloc_consolidate_return -aR sleep 1
>
> [root@jouet ~]#
>
> Ok, now we can trace this syswide using:
>
> [root@jouet ~]# perf trace --no-syscalls -e probe_libc:*
> <BIG SNIP>
>    339.557 probe_libc:malloc:(7fda55c22970))
>    339.562 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
>    339.567 probe_libc:malloc_consolidate:(7fda55c1b7b0))
>    339.570 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
>    339.596 probe_libc:malloc:(7fda55c22970))
>    339.600 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
>    339.622 probe_libc:malloc:(7fda55c22970))
>    339.626 probe_libc:malloc_return:(7fda55c22970 <- 7fda56ba9a39))
>    339.631 probe_libc:malloc:(7fda55c22970))
>    339.634 probe_libc:malloc_return:(7fda55c22970 <- 7fda578f1713))
>    339.637 probe_libc:malloc:(7fda55c22970))
>    339.641 probe_libc:malloc_return:(7fda55c22970 <- 7fda578f14ae))
>    339.657 probe_libc:malloc_consolidate:(7fda55c1b7b0))
>    339.661 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1dbd6))
>    339.664 probe_libc:malloc:(7fda55c22970))
>    339.667 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
>    339.670 probe_libc:malloc:(7fda55c22970))
>    339.673 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
>    339.678 probe_libc:malloc_consolidate:(7fda55c1b7b0))
>    339.681 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
>    339.685 probe_libc:malloc_consolidate:(7fda55c1b7b0))
>    339.688 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
>    339.693 probe_libc:malloc_consolidate:(7fda55c1b7b0))
>    339.696 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
>    339.778 probe_libc:malloc:(7fda55c22970))
>    339.783 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
>    339.788 probe_libc:malloc_consolidate:(7fda55c1b7b0))
>   ^C(7fda55c22970 <- 7fda578f14ae))
> [root@jouet ~]#
>
> It works as well with 'perf record' + 'perf script'.
>
> Other features from perf can be added to the mix, like callchains, etc.
>
> But see below for doing it via tracefs
>
>> I observed below behaviour when I tried as per directions using URL:
>> https://opensource.com/article/17/7/dynamic-tracing-linux-user-and-kernel-space#comment-136366
>> :
>>
>>
>> echo 'p:<func_entry> ./test:0x420' >
>> /sys/kernel/debug/tracing/uprobe_events              (for creating
>> uprobe)
>> echo 1 > /sys/kernel/debug/tracing/events/enable
>>                                 (enabling uproble)
>> There is another enable parameter:
>> /sys/kernel/debug/tracing/events/uprobes/enable
>>
>> I understand unless enabled both events/enable and
>> events/uprobes/enable, the /sys/kernel/debug/tracing/trace is not
>> complete. I do not understand the relevance of
>> .....events/uprobes/enable as I could not get any trace data in trace
>> log for 'func_entry' the user space function being added for tracing.
>> Irrespective of the probe function added, the trace log shows complete
>> system trace log during the period of execution of the user
>> application being traced.
>
> Is this what you want:
>
> [root@jouet ~]# cd /sys/kernel/debug/tracing/
> [root@jouet tracing]# cat available_tracers
> hwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop
> [root@jouet tracing]# echo nop > current_tracer
> [root@jouet tracing]# echo 1 > events/probe_libc/malloc/enable
> [root@jouet tracing]# echo 1 > tracing_on
> [root@jouet tracing]# tail trace
>             tail-1581  [002] d... 118484.507167: malloc: (0x7fdb32d67970)
>             tail-1581  [002] d... 118484.507172: malloc: (0x7fdb32d67970)
>             tail-1581  [002] d... 118484.507189: malloc: (0x7fdb32d67970)
>             tail-1581  [002] d... 118484.507193: malloc: (0x7fdb32d67970)
>             tail-1581  [002] d... 118484.507198: malloc: (0x7fdb32d67970)
>             tail-1581  [002] d... 118484.507203: malloc: (0x7fdb32d67970)
>             tail-1581  [002] d... 118484.507208: malloc: (0x7fdb32d67970)
>             tail-1581  [002] d... 118484.507214: malloc: (0x7fdb32d67970)
>             tail-1581  [002] d... 118484.507224: malloc: (0x7fdb32d67970)
>             tail-1581  [002] d... 118484.507237: malloc: (0x7fdb32d67970)
> [root@jouet tracing]#
>
> ?
>
>> Can this be clearly mentioned as to when to use one of them, role of
>> both and and also, I could not see uprobe function in particular at
>> all but generic trace in /sys/kernel/debug/tracing/trace. Kindly guide
>> me in understanding uprobe enable logic in user space in detail.
>>
>> Regards,
>> Bhargav
>> --
>> To unsubscribe from this list: send the line "unsubscribe linux-perf-users" in
>> the body of a message to majordomo@vger.kernel.org
>> More majordomo info at  http://vger.kernel.org/majordomo-info.html



-- 
Bhargav

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: uprobes enable condition (user space) - sysfs interface
  2017-12-03 17:14   ` bhargavb
@ 2017-12-04  6:03     ` Namhyung Kim
  0 siblings, 0 replies; 11+ messages in thread
From: Namhyung Kim @ 2017-12-04  6:03 UTC (permalink / raw)
  To: bhargavb
  Cc: Arnaldo Carvalho de Melo, linux-rt-users, linux-perf-users,
	Masami Hiramatsu, kernel-team

Hi,

On Sun, Dec 03, 2017 at 10:44:22PM +0530, bhargavb wrote:
> Dear Arnaldo,
> Exactly, the last one was what I was looking for. Thank you very much...
> That apart I am also exploring various profiling options that can give
> me a full control of monitoring running processes (user space
> profiling ).
> sysfs seems powerful and very useful, though I got to know lately (and
> not much mentioned, I think as tools like perf etc).  I was confused
> when u said tracefs in your response, I understand it is same as
> sysfs. Please correct me if I am wrong.

It's a different filesystem for controlling tracing features but just
happens to be mounted on top of a sysfs (or debugfs) directory.

  $ mount | grep tracefs
  tracefs on /sys/kernel/debug/tracing type tracefs (rw,relatime)


Also, writing to the 'enable' file changes state of every events in
that directory and its subdirectory.  So $TRACEFS/events/enable
changes all events.

Thanks,
Namhyung


> 
> 
> On Fri, Dec 1, 2017 at 10:10 PM, Arnaldo Carvalho de Melo
> <arnaldo.melo@gmail.com> wrote:
> > Adding Masami to the CC list, to see if he can come up with a fix for
> > the 'perf probe' failure below, improving the message or ignoring
> > versioned symbols (with a warning perhaps).
> >
> > Em Thu, Nov 30, 2017 at 12:04:23AM +0530, bhargavb escreveu:
> >> Hello,
> >>
> >> I am trying to understand user space profiling using linux inbuilt
> >> mechanism. (Trying with perf also but could not get complete clear
> >> documentation and could not proceed, so retained linux-perf-users in
> >> to list as the underlying interface used is same for both).
> >
> > So yo uwant to trace function entry/exit in some userspace library? You
> > can try using the tracefs as below or leave it to perf to do that, first
> > you set up the probes, say for some glibc functions:
> >
> > [root@jouet ~]# perf probe -F -x /lib64/libc-2.25.so  | grep ^malloc
> > malloc
> > malloc_check
> > malloc_consolidate.part.1
> > malloc_get_state@GLIBC_2.2.5
> > malloc_hook_ini
> > malloc_info
> > malloc_printerr
> > malloc_set_state@GLIBC_2.2.5
> > malloc_stats
> > malloc_trim
> > malloc_usable_size
> > mallochook
> > [root@jouet ~]#
> >
> > [root@jouet ~]# perf probe -x /lib64/libc-2.25.so malloc*
> > Failed to write event: Invalid argument
> >   Error: Failed to add events.
> > [root@jouet ~]#
> >
> > For now ignore that error, its a bug I just found, what matters is that
> > it _has_ put in place probes for most of those functions, as you can see
> > by looking at:
> >
> > [root@jouet ~]# perf probe -l
> >   probe_libc:malloc    (on __malloc in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_check (on malloc_check in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_consolidate (on malloc_consolidate.part.1 in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_hook_ini (on malloc_hook_ini in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_info (on __malloc_info in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_printerr (on malloc_printerr in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_stats (on __malloc_stats in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_trim (on __malloc_trim in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_usable_size (on __malloc_usable_size in /usr/lib64/libc-2.25.so)
> >   probe_libc:mallochook (on mallochook in /usr/lib64/libc-2.25.so)
> > [root@jouet ~]#
> >
> > Masami, this one also doesn't work:
> >
> > [root@jouet ~]# perf probe -x /lib64/libc-2.25.so 'malloc*%return'
> > Error: event "malloc_printerr" already exists.
> > <SNIP>
> >
> > doing it a bit differently:
> >
> > [root@jouet ~]# perf probe -F -x /lib64/libc-2.25.so | egrep ^malloc[^@]+$ | while read function ; do perf probe -x /lib64/libc-2.25.so "${function}_return=$function%return" ; done
> > Added new event:
> >   probe_libc:malloc_check_return (on malloc_check%return in /usr/lib64/libc-2.25.so)
> >
> > You can now use it in all perf tools, such as:
> >
> >         perf record -e probe_libc:malloc_check_return -aR sleep 1
> >
> > <SNIP>
> > -----------
> >
> > This now makes us have:
> >
> > [root@jouet ~]# perf probe -l
> >   probe:check_stack_object (on check_stack_object%return@acme/git/linux/mm/usercopy.c with ret)
> >   probe_libc:malloc    (on __malloc in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_check (on malloc_check in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_consolidate (on malloc_consolidate.part.1 in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_hook_ini (on malloc_hook_ini in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_info (on __malloc_info in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_printerr (on malloc_printerr in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_stats (on __malloc_stats in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_trim (on __malloc_trim in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_usable_size (on __malloc_usable_size in /usr/lib64/libc-2.25.so)
> >   probe_libc:mallochook (on mallochook in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_check_return (on malloc_check%return in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_hook_ini_return (on malloc_hook_ini%return in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_info_return (on __malloc_info%return in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_printerr_return (on malloc_printerr%return in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_stats_return (on __malloc_stats%return in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_trim_return (on __malloc_trim%return in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_usable_size_return (on __malloc_usable_size%return in /usr/lib64/libc-2.25.so)
> >   probe_libc:mallochook_return (on mallochook%return in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_return (on __malloc%return in /usr/lib64/libc-2.25.so)
> > [root@jouet ~]#
> >
> > There were some usability snags that prevented this from being put in
> > place, so do it manually:
> >
> > [root@jouet ~]# perf probe -x /lib64/libc-2.25.so 'malloc_consolidate_return=malloc_consolidate.part.1%return'
> > Added new event:
> >   probe_libc:malloc_consolidate_return (on malloc_consolidate.part.1%return in /usr/lib64/libc-2.25.so)
> >
> > You can now use it in all perf tools, such as:
> >
> >         perf record -e probe_libc:malloc_consolidate_return -aR sleep 1
> >
> > [root@jouet ~]#
> >
> > Ok, now we can trace this syswide using:
> >
> > [root@jouet ~]# perf trace --no-syscalls -e probe_libc:*
> > <BIG SNIP>
> >    339.557 probe_libc:malloc:(7fda55c22970))
> >    339.562 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
> >    339.567 probe_libc:malloc_consolidate:(7fda55c1b7b0))
> >    339.570 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
> >    339.596 probe_libc:malloc:(7fda55c22970))
> >    339.600 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
> >    339.622 probe_libc:malloc:(7fda55c22970))
> >    339.626 probe_libc:malloc_return:(7fda55c22970 <- 7fda56ba9a39))
> >    339.631 probe_libc:malloc:(7fda55c22970))
> >    339.634 probe_libc:malloc_return:(7fda55c22970 <- 7fda578f1713))
> >    339.637 probe_libc:malloc:(7fda55c22970))
> >    339.641 probe_libc:malloc_return:(7fda55c22970 <- 7fda578f14ae))
> >    339.657 probe_libc:malloc_consolidate:(7fda55c1b7b0))
> >    339.661 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1dbd6))
> >    339.664 probe_libc:malloc:(7fda55c22970))
> >    339.667 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
> >    339.670 probe_libc:malloc:(7fda55c22970))
> >    339.673 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
> >    339.678 probe_libc:malloc_consolidate:(7fda55c1b7b0))
> >    339.681 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
> >    339.685 probe_libc:malloc_consolidate:(7fda55c1b7b0))
> >    339.688 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
> >    339.693 probe_libc:malloc_consolidate:(7fda55c1b7b0))
> >    339.696 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
> >    339.778 probe_libc:malloc:(7fda55c22970))
> >    339.783 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
> >    339.788 probe_libc:malloc_consolidate:(7fda55c1b7b0))
> >   ^C(7fda55c22970 <- 7fda578f14ae))
> > [root@jouet ~]#
> >
> > It works as well with 'perf record' + 'perf script'.
> >
> > Other features from perf can be added to the mix, like callchains, etc.
> >
> > But see below for doing it via tracefs
> >
> >> I observed below behaviour when I tried as per directions using URL:
> >> https://opensource.com/article/17/7/dynamic-tracing-linux-user-and-kernel-space#comment-136366
> >> :
> >>
> >>
> >> echo 'p:<func_entry> ./test:0x420' >
> >> /sys/kernel/debug/tracing/uprobe_events              (for creating
> >> uprobe)
> >> echo 1 > /sys/kernel/debug/tracing/events/enable
> >>                                 (enabling uproble)
> >> There is another enable parameter:
> >> /sys/kernel/debug/tracing/events/uprobes/enable
> >>
> >> I understand unless enabled both events/enable and
> >> events/uprobes/enable, the /sys/kernel/debug/tracing/trace is not
> >> complete. I do not understand the relevance of
> >> .....events/uprobes/enable as I could not get any trace data in trace
> >> log for 'func_entry' the user space function being added for tracing.
> >> Irrespective of the probe function added, the trace log shows complete
> >> system trace log during the period of execution of the user
> >> application being traced.
> >
> > Is this what you want:
> >
> > [root@jouet ~]# cd /sys/kernel/debug/tracing/
> > [root@jouet tracing]# cat available_tracers
> > hwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop
> > [root@jouet tracing]# echo nop > current_tracer
> > [root@jouet tracing]# echo 1 > events/probe_libc/malloc/enable
> > [root@jouet tracing]# echo 1 > tracing_on
> > [root@jouet tracing]# tail trace
> >             tail-1581  [002] d... 118484.507167: malloc: (0x7fdb32d67970)
> >             tail-1581  [002] d... 118484.507172: malloc: (0x7fdb32d67970)
> >             tail-1581  [002] d... 118484.507189: malloc: (0x7fdb32d67970)
> >             tail-1581  [002] d... 118484.507193: malloc: (0x7fdb32d67970)
> >             tail-1581  [002] d... 118484.507198: malloc: (0x7fdb32d67970)
> >             tail-1581  [002] d... 118484.507203: malloc: (0x7fdb32d67970)
> >             tail-1581  [002] d... 118484.507208: malloc: (0x7fdb32d67970)
> >             tail-1581  [002] d... 118484.507214: malloc: (0x7fdb32d67970)
> >             tail-1581  [002] d... 118484.507224: malloc: (0x7fdb32d67970)
> >             tail-1581  [002] d... 118484.507237: malloc: (0x7fdb32d67970)
> > [root@jouet tracing]#
> >
> > ?
> >
> >> Can this be clearly mentioned as to when to use one of them, role of
> >> both and and also, I could not see uprobe function in particular at
> >> all but generic trace in /sys/kernel/debug/tracing/trace. Kindly guide
> >> me in understanding uprobe enable logic in user space in detail.
> >>
> >> Regards,
> >> Bhargav
> >> --
> >> To unsubscribe from this list: send the line "unsubscribe linux-perf-users" in
> >> the body of a message to majordomo@vger.kernel.org
> >> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> 
> 
> 
> -- 
> Bhargav
> --
> To unsubscribe from this list: send the line "unsubscribe linux-perf-users" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: uprobes enable condition (user space) - sysfs interface
  2017-12-01 16:40 ` Arnaldo Carvalho de Melo
  2017-12-03 17:14   ` bhargavb
@ 2017-12-04 12:36   ` Masami Hiramatsu
  2017-12-04 14:55     ` Arnaldo Carvalho de Melo
  1 sibling, 1 reply; 11+ messages in thread
From: Masami Hiramatsu @ 2017-12-04 12:36 UTC (permalink / raw)
  To: Arnaldo Carvalho de Melo
  Cc: bhargavb, linux-rt-users, linux-perf-users, Masami Hiramatsu

On Fri, 1 Dec 2017 13:40:39 -0300
Arnaldo Carvalho de Melo <acme@kernel.org> wrote:

> Adding Masami to the CC list, to see if he can come up with a fix for
> the 'perf probe' failure below, improving the message or ignoring
> versioned symbols (with a warning perhaps).

Thanks. Should we ignore the versioned symbols? or can we put a probe
on that? If we have symbol address, we can put a probe on it, even
if it is versioned.

> 
> Em Thu, Nov 30, 2017 at 12:04:23AM +0530, bhargavb escreveu:
> > Hello,
> > 
> > I am trying to understand user space profiling using linux inbuilt
> > mechanism. (Trying with perf also but could not get complete clear
> > documentation and could not proceed, so retained linux-perf-users in
> > to list as the underlying interface used is same for both).
> 
> So yo uwant to trace function entry/exit in some userspace library? You
> can try using the tracefs as below or leave it to perf to do that, first
> you set up the probes, say for some glibc functions:
> 
> [root@jouet ~]# perf probe -F -x /lib64/libc-2.25.so  | grep ^malloc
> malloc
> malloc_check
> malloc_consolidate.part.1
> malloc_get_state@GLIBC_2.2.5
> malloc_hook_ini
> malloc_info
> malloc_printerr
> malloc_set_state@GLIBC_2.2.5
> malloc_stats
> malloc_trim
> malloc_usable_size
> mallochook
> [root@jouet ~]#
> 
> [root@jouet ~]# perf probe -x /lib64/libc-2.25.so malloc*
> Failed to write event: Invalid argument
>   Error: Failed to add events.
> [root@jouet ~]# 

OK, this is not good, at least it should analyse the reason(versioned)
and warn that (Or, I think we can just remove the suffix after "@").

> 
> For now ignore that error, its a bug I just found, what matters is that
> it _has_ put in place probes for most of those functions, as you can see
> by looking at:
> 
> [root@jouet ~]# perf probe -l
>   probe_libc:malloc    (on __malloc in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_check (on malloc_check in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_consolidate (on malloc_consolidate.part.1 in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_hook_ini (on malloc_hook_ini in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_info (on __malloc_info in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_printerr (on malloc_printerr in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_stats (on __malloc_stats in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_trim (on __malloc_trim in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_usable_size (on __malloc_usable_size in /usr/lib64/libc-2.25.so)
>   probe_libc:mallochook (on mallochook in /usr/lib64/libc-2.25.so)
> [root@jouet ~]#
> 
> Masami, this one also doesn't work:
> 
> [root@jouet ~]# perf probe -x /lib64/libc-2.25.so 'malloc*%return'
> Error: event "malloc_printerr" already exists.
> <SNIP>

Hm, this looks like a collision happens on that event name. "-f"(--force)
option allows you to add events with number suffix (e.g. _1, _2, ... )

> 
> doing it a bit differently:
> 
> [root@jouet ~]# perf probe -F -x /lib64/libc-2.25.so | egrep ^malloc[^@]+$ | while read function ; do perf probe -x /lib64/libc-2.25.so "${function}_return=$function%return" ; done
> Added new event:
>   probe_libc:malloc_check_return (on malloc_check%return in /usr/lib64/libc-2.25.so)
> 
> You can now use it in all perf tools, such as:
> 
> 	perf record -e probe_libc:malloc_check_return -aR sleep 1

Hmm, would you think we should add __return suffix by default?

Thanks,

> 
> <SNIP>
> -----------
> 
> This now makes us have:
> 
> [root@jouet ~]# perf probe -l
>   probe:check_stack_object (on check_stack_object%return@acme/git/linux/mm/usercopy.c with ret)
>   probe_libc:malloc    (on __malloc in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_check (on malloc_check in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_consolidate (on malloc_consolidate.part.1 in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_hook_ini (on malloc_hook_ini in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_info (on __malloc_info in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_printerr (on malloc_printerr in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_stats (on __malloc_stats in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_trim (on __malloc_trim in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_usable_size (on __malloc_usable_size in /usr/lib64/libc-2.25.so)
>   probe_libc:mallochook (on mallochook in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_check_return (on malloc_check%return in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_hook_ini_return (on malloc_hook_ini%return in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_info_return (on __malloc_info%return in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_printerr_return (on malloc_printerr%return in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_stats_return (on __malloc_stats%return in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_trim_return (on __malloc_trim%return in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_usable_size_return (on __malloc_usable_size%return in /usr/lib64/libc-2.25.so)
>   probe_libc:mallochook_return (on mallochook%return in /usr/lib64/libc-2.25.so)
>   probe_libc:malloc_return (on __malloc%return in /usr/lib64/libc-2.25.so)
> [root@jouet ~]# 
> 
> There were some usability snags that prevented this from being put in
> place, so do it manually:
> 
> [root@jouet ~]# perf probe -x /lib64/libc-2.25.so 'malloc_consolidate_return=malloc_consolidate.part.1%return'
> Added new event:
>   probe_libc:malloc_consolidate_return (on malloc_consolidate.part.1%return in /usr/lib64/libc-2.25.so)
> 
> You can now use it in all perf tools, such as:
> 
> 	perf record -e probe_libc:malloc_consolidate_return -aR sleep 1
> 
> [root@jouet ~]#
> 
> Ok, now we can trace this syswide using:
> 
> [root@jouet ~]# perf trace --no-syscalls -e probe_libc:*
> <BIG SNIP>
>    339.557 probe_libc:malloc:(7fda55c22970))
>    339.562 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
>    339.567 probe_libc:malloc_consolidate:(7fda55c1b7b0))
>    339.570 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
>    339.596 probe_libc:malloc:(7fda55c22970))
>    339.600 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
>    339.622 probe_libc:malloc:(7fda55c22970))
>    339.626 probe_libc:malloc_return:(7fda55c22970 <- 7fda56ba9a39))
>    339.631 probe_libc:malloc:(7fda55c22970))
>    339.634 probe_libc:malloc_return:(7fda55c22970 <- 7fda578f1713))
>    339.637 probe_libc:malloc:(7fda55c22970))
>    339.641 probe_libc:malloc_return:(7fda55c22970 <- 7fda578f14ae))
>    339.657 probe_libc:malloc_consolidate:(7fda55c1b7b0))
>    339.661 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1dbd6))
>    339.664 probe_libc:malloc:(7fda55c22970))
>    339.667 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
>    339.670 probe_libc:malloc:(7fda55c22970))
>    339.673 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
>    339.678 probe_libc:malloc_consolidate:(7fda55c1b7b0))
>    339.681 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
>    339.685 probe_libc:malloc_consolidate:(7fda55c1b7b0))
>    339.688 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
>    339.693 probe_libc:malloc_consolidate:(7fda55c1b7b0))
>    339.696 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
>    339.778 probe_libc:malloc:(7fda55c22970))
>    339.783 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
>    339.788 probe_libc:malloc_consolidate:(7fda55c1b7b0))
>   ^C(7fda55c22970 <- 7fda578f14ae))
> [root@jouet ~]# 
> 
> It works as well with 'perf record' + 'perf script'.
> 
> Other features from perf can be added to the mix, like callchains, etc.
> 
> But see below for doing it via tracefs
>  
> > I observed below behaviour when I tried as per directions using URL:
> > https://opensource.com/article/17/7/dynamic-tracing-linux-user-and-kernel-space#comment-136366
> > :
> > 
> > 
> > echo 'p:<func_entry> ./test:0x420' >
> > /sys/kernel/debug/tracing/uprobe_events              (for creating
> > uprobe)
> > echo 1 > /sys/kernel/debug/tracing/events/enable
> >                                 (enabling uproble)
> > There is another enable parameter:
> > /sys/kernel/debug/tracing/events/uprobes/enable
> > 
> > I understand unless enabled both events/enable and
> > events/uprobes/enable, the /sys/kernel/debug/tracing/trace is not
> > complete. I do not understand the relevance of
> > .....events/uprobes/enable as I could not get any trace data in trace
> > log for 'func_entry' the user space function being added for tracing.
> > Irrespective of the probe function added, the trace log shows complete
> > system trace log during the period of execution of the user
> > application being traced.
> 
> Is this what you want:
> 
> [root@jouet ~]# cd /sys/kernel/debug/tracing/
> [root@jouet tracing]# cat available_tracers 
> hwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop
> [root@jouet tracing]# echo nop > current_tracer 
> [root@jouet tracing]# echo 1 > events/probe_libc/malloc/enable 
> [root@jouet tracing]# echo 1 > tracing_on 
> [root@jouet tracing]# tail trace
>             tail-1581  [002] d... 118484.507167: malloc: (0x7fdb32d67970)
>             tail-1581  [002] d... 118484.507172: malloc: (0x7fdb32d67970)
>             tail-1581  [002] d... 118484.507189: malloc: (0x7fdb32d67970)
>             tail-1581  [002] d... 118484.507193: malloc: (0x7fdb32d67970)
>             tail-1581  [002] d... 118484.507198: malloc: (0x7fdb32d67970)
>             tail-1581  [002] d... 118484.507203: malloc: (0x7fdb32d67970)
>             tail-1581  [002] d... 118484.507208: malloc: (0x7fdb32d67970)
>             tail-1581  [002] d... 118484.507214: malloc: (0x7fdb32d67970)
>             tail-1581  [002] d... 118484.507224: malloc: (0x7fdb32d67970)
>             tail-1581  [002] d... 118484.507237: malloc: (0x7fdb32d67970)
> [root@jouet tracing]#
> 
> ?
>  
> > Can this be clearly mentioned as to when to use one of them, role of
> > both and and also, I could not see uprobe function in particular at
> > all but generic trace in /sys/kernel/debug/tracing/trace. Kindly guide
> > me in understanding uprobe enable logic in user space in detail.
> > 
> > Regards,
> > Bhargav
> > --

-- 
Masami Hiramatsu <mhiramat@kernel.org>

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: uprobes enable condition (user space) - sysfs interface
  2017-12-04 12:36   ` Masami Hiramatsu
@ 2017-12-04 14:55     ` Arnaldo Carvalho de Melo
  2017-12-04 15:23       ` Paul Clarke
  2017-12-05  6:51       ` Masami Hiramatsu
  0 siblings, 2 replies; 11+ messages in thread
From: Arnaldo Carvalho de Melo @ 2017-12-04 14:55 UTC (permalink / raw)
  To: Masami Hiramatsu; +Cc: bhargavb, linux-rt-users, linux-perf-users

Em Mon, Dec 04, 2017 at 09:36:19PM +0900, Masami Hiramatsu escreveu:
> On Fri, 1 Dec 2017 13:40:39 -0300
> Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
> 
> > Adding Masami to the CC list, to see if he can come up with a fix for
> > the 'perf probe' failure below, improving the message or ignoring
> > versioned symbols (with a warning perhaps).
> 
> Thanks. Should we ignore the versioned symbols? or can we put a probe
> on that? If we have symbol address, we can put a probe on it, even
> if it is versioned.

Lemme try...

[root@jouet ~]# perf probe -x /usr/lib64/libc-2.25.so malloc_get_state_225=malloc_get_state@GLIBC_2.2.5
The /usr/lib64/libc-2.25.so file has no debug information.
Rebuild with -g, or install an appropriate debuginfo package.
  Error: Failed to add events.
[root@jouet ~]# perf probe -x /usr/lib64/libc-2.25.so malloc_get_state@GLIBC_2.2.5
The /usr/lib64/libc-2.25.so file has no debug information.
Rebuild with -g, or install an appropriate debuginfo package.
  Error: Failed to add events.
[root@jouet ~]# perf probe -x /usr/lib64/libc-2.25.so malloc
Added new event:
  probe_libc:malloc    (on malloc in /usr/lib64/libc-2.25.so)

You can now use it in all perf tools, such as:

	perf record -e probe_libc:malloc -aR sleep 1

[root@jouet ~]#

So here the message is misleading, as we did manage to put a probe on
'malloc', but not on the versioned symbol, both when trying to give it a
different name (malloc_get_state_225) and when doing it directly
(malloc_get_state@GLIBC_2.2.5).
 
> > 
> > Em Thu, Nov 30, 2017 at 12:04:23AM +0530, bhargavb escreveu:
> > > Hello,
> > > 
> > > I am trying to understand user space profiling using linux inbuilt
> > > mechanism. (Trying with perf also but could not get complete clear
> > > documentation and could not proceed, so retained linux-perf-users in
> > > to list as the underlying interface used is same for both).
> > 
> > So yo uwant to trace function entry/exit in some userspace library? You
> > can try using the tracefs as below or leave it to perf to do that, first
> > you set up the probes, say for some glibc functions:
> > 
> > [root@jouet ~]# perf probe -F -x /lib64/libc-2.25.so  | grep ^malloc
> > malloc
> > malloc_check
> > malloc_consolidate.part.1
> > malloc_get_state@GLIBC_2.2.5
> > malloc_hook_ini
> > malloc_info
> > malloc_printerr
> > malloc_set_state@GLIBC_2.2.5
> > malloc_stats
> > malloc_trim
> > malloc_usable_size
> > mallochook
> > [root@jouet ~]#
> > 
> > [root@jouet ~]# perf probe -x /lib64/libc-2.25.so malloc*
> > Failed to write event: Invalid argument
> >   Error: Failed to add events.
> > [root@jouet ~]# 
> 
> OK, this is not good, at least it should analyse the reason(versioned)
> and warn that (Or, I think we can just remove the suffix after "@").

I think it is a matter of replacing special characters with some other.
I think we should support versioned symbols, i.e. one may well want to
intercept calls to a specific version of a symbol.
 
> > 
> > For now ignore that error, its a bug I just found, what matters is that
> > it _has_ put in place probes for most of those functions, as you can see
> > by looking at:
> > 
> > [root@jouet ~]# perf probe -l
> >   probe_libc:malloc    (on __malloc in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_check (on malloc_check in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_consolidate (on malloc_consolidate.part.1 in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_hook_ini (on malloc_hook_ini in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_info (on __malloc_info in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_printerr (on malloc_printerr in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_stats (on __malloc_stats in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_trim (on __malloc_trim in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_usable_size (on __malloc_usable_size in /usr/lib64/libc-2.25.so)
> >   probe_libc:mallochook (on mallochook in /usr/lib64/libc-2.25.so)
> > [root@jouet ~]#
> > 
> > Masami, this one also doesn't work:
> > 
> > [root@jouet ~]# perf probe -x /lib64/libc-2.25.so 'malloc*%return'
> > Error: event "malloc_printerr" already exists.
> > <SNIP>
> 
> Hm, this looks like a collision happens on that event name. "-f"(--force)
> option allows you to add events with number suffix (e.g. _1, _2, ... )

Probably this was because the same name was used for both entry and
exit, see below on automatically adding __return to %return probes.
 
> > 
> > doing it a bit differently:
> > 
> > [root@jouet ~]# perf probe -F -x /lib64/libc-2.25.so | egrep ^malloc[^@]+$ | while read function ; do perf probe -x /lib64/libc-2.25.so "${function}_return=$function%return" ; done
> > Added new event:
> >   probe_libc:malloc_check_return (on malloc_check%return in /usr/lib64/libc-2.25.so)
> > 
> > You can now use it in all perf tools, such as:
> > 
> > 	perf record -e probe_libc:malloc_check_return -aR sleep 1
> 
> Hmm, would you think we should add __return suffix by default?

I think so, as it is a common operation to ask for entry+exit.

- Arnaldo
 
> Thanks,
> 
> > 
> > <SNIP>
> > -----------
> > 
> > This now makes us have:
> > 
> > [root@jouet ~]# perf probe -l
> >   probe:check_stack_object (on check_stack_object%return@acme/git/linux/mm/usercopy.c with ret)
> >   probe_libc:malloc    (on __malloc in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_check (on malloc_check in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_consolidate (on malloc_consolidate.part.1 in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_hook_ini (on malloc_hook_ini in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_info (on __malloc_info in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_printerr (on malloc_printerr in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_stats (on __malloc_stats in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_trim (on __malloc_trim in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_usable_size (on __malloc_usable_size in /usr/lib64/libc-2.25.so)
> >   probe_libc:mallochook (on mallochook in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_check_return (on malloc_check%return in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_hook_ini_return (on malloc_hook_ini%return in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_info_return (on __malloc_info%return in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_printerr_return (on malloc_printerr%return in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_stats_return (on __malloc_stats%return in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_trim_return (on __malloc_trim%return in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_usable_size_return (on __malloc_usable_size%return in /usr/lib64/libc-2.25.so)
> >   probe_libc:mallochook_return (on mallochook%return in /usr/lib64/libc-2.25.so)
> >   probe_libc:malloc_return (on __malloc%return in /usr/lib64/libc-2.25.so)
> > [root@jouet ~]# 
> > 
> > There were some usability snags that prevented this from being put in
> > place, so do it manually:
> > 
> > [root@jouet ~]# perf probe -x /lib64/libc-2.25.so 'malloc_consolidate_return=malloc_consolidate.part.1%return'
> > Added new event:
> >   probe_libc:malloc_consolidate_return (on malloc_consolidate.part.1%return in /usr/lib64/libc-2.25.so)
> > 
> > You can now use it in all perf tools, such as:
> > 
> > 	perf record -e probe_libc:malloc_consolidate_return -aR sleep 1
> > 
> > [root@jouet ~]#
> > 
> > Ok, now we can trace this syswide using:
> > 
> > [root@jouet ~]# perf trace --no-syscalls -e probe_libc:*
> > <BIG SNIP>
> >    339.557 probe_libc:malloc:(7fda55c22970))
> >    339.562 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
> >    339.567 probe_libc:malloc_consolidate:(7fda55c1b7b0))
> >    339.570 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
> >    339.596 probe_libc:malloc:(7fda55c22970))
> >    339.600 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
> >    339.622 probe_libc:malloc:(7fda55c22970))
> >    339.626 probe_libc:malloc_return:(7fda55c22970 <- 7fda56ba9a39))
> >    339.631 probe_libc:malloc:(7fda55c22970))
> >    339.634 probe_libc:malloc_return:(7fda55c22970 <- 7fda578f1713))
> >    339.637 probe_libc:malloc:(7fda55c22970))
> >    339.641 probe_libc:malloc_return:(7fda55c22970 <- 7fda578f14ae))
> >    339.657 probe_libc:malloc_consolidate:(7fda55c1b7b0))
> >    339.661 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1dbd6))
> >    339.664 probe_libc:malloc:(7fda55c22970))
> >    339.667 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
> >    339.670 probe_libc:malloc:(7fda55c22970))
> >    339.673 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
> >    339.678 probe_libc:malloc_consolidate:(7fda55c1b7b0))
> >    339.681 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
> >    339.685 probe_libc:malloc_consolidate:(7fda55c1b7b0))
> >    339.688 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
> >    339.693 probe_libc:malloc_consolidate:(7fda55c1b7b0))
> >    339.696 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
> >    339.778 probe_libc:malloc:(7fda55c22970))
> >    339.783 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
> >    339.788 probe_libc:malloc_consolidate:(7fda55c1b7b0))
> >   ^C(7fda55c22970 <- 7fda578f14ae))
> > [root@jouet ~]# 
> > 
> > It works as well with 'perf record' + 'perf script'.
> > 
> > Other features from perf can be added to the mix, like callchains, etc.
> > 
> > But see below for doing it via tracefs
> >  
> > > I observed below behaviour when I tried as per directions using URL:
> > > https://opensource.com/article/17/7/dynamic-tracing-linux-user-and-kernel-space#comment-136366
> > > :
> > > 
> > > 
> > > echo 'p:<func_entry> ./test:0x420' >
> > > /sys/kernel/debug/tracing/uprobe_events              (for creating
> > > uprobe)
> > > echo 1 > /sys/kernel/debug/tracing/events/enable
> > >                                 (enabling uproble)
> > > There is another enable parameter:
> > > /sys/kernel/debug/tracing/events/uprobes/enable
> > > 
> > > I understand unless enabled both events/enable and
> > > events/uprobes/enable, the /sys/kernel/debug/tracing/trace is not
> > > complete. I do not understand the relevance of
> > > .....events/uprobes/enable as I could not get any trace data in trace
> > > log for 'func_entry' the user space function being added for tracing.
> > > Irrespective of the probe function added, the trace log shows complete
> > > system trace log during the period of execution of the user
> > > application being traced.
> > 
> > Is this what you want:
> > 
> > [root@jouet ~]# cd /sys/kernel/debug/tracing/
> > [root@jouet tracing]# cat available_tracers 
> > hwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop
> > [root@jouet tracing]# echo nop > current_tracer 
> > [root@jouet tracing]# echo 1 > events/probe_libc/malloc/enable 
> > [root@jouet tracing]# echo 1 > tracing_on 
> > [root@jouet tracing]# tail trace
> >             tail-1581  [002] d... 118484.507167: malloc: (0x7fdb32d67970)
> >             tail-1581  [002] d... 118484.507172: malloc: (0x7fdb32d67970)
> >             tail-1581  [002] d... 118484.507189: malloc: (0x7fdb32d67970)
> >             tail-1581  [002] d... 118484.507193: malloc: (0x7fdb32d67970)
> >             tail-1581  [002] d... 118484.507198: malloc: (0x7fdb32d67970)
> >             tail-1581  [002] d... 118484.507203: malloc: (0x7fdb32d67970)
> >             tail-1581  [002] d... 118484.507208: malloc: (0x7fdb32d67970)
> >             tail-1581  [002] d... 118484.507214: malloc: (0x7fdb32d67970)
> >             tail-1581  [002] d... 118484.507224: malloc: (0x7fdb32d67970)
> >             tail-1581  [002] d... 118484.507237: malloc: (0x7fdb32d67970)
> > [root@jouet tracing]#
> > 
> > ?
> >  
> > > Can this be clearly mentioned as to when to use one of them, role of
> > > both and and also, I could not see uprobe function in particular at
> > > all but generic trace in /sys/kernel/debug/tracing/trace. Kindly guide
> > > me in understanding uprobe enable logic in user space in detail.
> > > 
> > > Regards,
> > > Bhargav
> > > --
> 
> -- 
> Masami Hiramatsu <mhiramat@kernel.org>

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: uprobes enable condition (user space) - sysfs interface
  2017-12-04 14:55     ` Arnaldo Carvalho de Melo
@ 2017-12-04 15:23       ` Paul Clarke
  2017-12-05  6:53         ` Masami Hiramatsu
  2017-12-05  7:45         ` Masami Hiramatsu
  2017-12-05  6:51       ` Masami Hiramatsu
  1 sibling, 2 replies; 11+ messages in thread
From: Paul Clarke @ 2017-12-04 15:23 UTC (permalink / raw)
  To: Arnaldo Carvalho de Melo, Masami Hiramatsu
  Cc: bhargavb, linux-rt-users, linux-perf-users

On 12/04/2017 08:55 AM, Arnaldo Carvalho de Melo wrote:
> Em Mon, Dec 04, 2017 at 09:36:19PM +0900, Masami Hiramatsu escreveu:
>> On Fri, 1 Dec 2017 13:40:39 -0300
>> Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
>>
>>> Adding Masami to the CC list, to see if he can come up with a fix for
>>> the 'perf probe' failure below, improving the message or ignoring
>>> versioned symbols (with a warning perhaps).
>>
>> Thanks. Should we ignore the versioned symbols? or can we put a probe
>> on that? If we have symbol address, we can put a probe on it, even
>> if it is versioned.
> 
> Lemme try...
> 
> [root@jouet ~]# perf probe -x /usr/lib64/libc-2.25.so malloc_get_state_225=malloc_get_state@GLIBC_2.2.5
> The /usr/lib64/libc-2.25.so file has no debug information.
> Rebuild with -g, or install an appropriate debuginfo package.
>   Error: Failed to add events.
> [root@jouet ~]# perf probe -x /usr/lib64/libc-2.25.so malloc_get_state@GLIBC_2.2.5
> The /usr/lib64/libc-2.25.so file has no debug information.
> Rebuild with -g, or install an appropriate debuginfo package.
>   Error: Failed to add events.

commit d80406453ad4a69932dc17a617d5b7bc7ae80b8f should have allowed adding probes on versioned symbols if you omit the versioning part of the symbol.  So, in the above example, this should work:

# perf probe -x /usr/lib64/libc-2.25.so malloc_get_state

PC

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: uprobes enable condition (user space) - sysfs interface
  2017-12-04 14:55     ` Arnaldo Carvalho de Melo
  2017-12-04 15:23       ` Paul Clarke
@ 2017-12-05  6:51       ` Masami Hiramatsu
  1 sibling, 0 replies; 11+ messages in thread
From: Masami Hiramatsu @ 2017-12-05  6:51 UTC (permalink / raw)
  To: Arnaldo Carvalho de Melo; +Cc: bhargavb, linux-rt-users, linux-perf-users

On Mon, 4 Dec 2017 11:55:58 -0300
Arnaldo Carvalho de Melo <acme@kernel.org> wrote:

> Em Mon, Dec 04, 2017 at 09:36:19PM +0900, Masami Hiramatsu escreveu:
> > On Fri, 1 Dec 2017 13:40:39 -0300
> > Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
> > 
> > > Adding Masami to the CC list, to see if he can come up with a fix for
> > > the 'perf probe' failure below, improving the message or ignoring
> > > versioned symbols (with a warning perhaps).
> > 
> > Thanks. Should we ignore the versioned symbols? or can we put a probe
> > on that? If we have symbol address, we can put a probe on it, even
> > if it is versioned.
> 
> Lemme try...
> 
> [root@jouet ~]# perf probe -x /usr/lib64/libc-2.25.so malloc_get_state_225=malloc_get_state@GLIBC_2.2.5
> The /usr/lib64/libc-2.25.so file has no debug information.
> Rebuild with -g, or install an appropriate debuginfo package.
>   Error: Failed to add events.
> [root@jouet ~]# perf probe -x /usr/lib64/libc-2.25.so malloc_get_state@GLIBC_2.2.5
> The /usr/lib64/libc-2.25.so file has no debug information.
> Rebuild with -g, or install an appropriate debuginfo package.
>   Error: Failed to add events.

Ah, those cases, perf-probe parsed A@B as function@file...

> [root@jouet ~]# perf probe -x /usr/lib64/libc-2.25.so malloc
> Added new event:
>   probe_libc:malloc    (on malloc in /usr/lib64/libc-2.25.so)
> 
> You can now use it in all perf tools, such as:
> 
> 	perf record -e probe_libc:malloc -aR sleep 1
> 
> [root@jouet ~]#
> 
> So here the message is misleading, as we did manage to put a probe on
> 'malloc', but not on the versioned symbol, both when trying to give it a
> different name (malloc_get_state_225) and when doing it directly
> (malloc_get_state@GLIBC_2.2.5).

So, yes, the message is misleading. That should say something like

"malloc_get_state@GLIBC_2.2.5 requires source file(GLIBC_2.2.5) information,
 but /usr/lib64/libc-2.25.so file has no debug information."

[..]
> > > [root@jouet ~]# perf probe -x /lib64/libc-2.25.so malloc*
> > > Failed to write event: Invalid argument
> > >   Error: Failed to add events.
> > > [root@jouet ~]# 
> > 
> > OK, this is not good, at least it should analyse the reason(versioned)
> > and warn that (Or, I think we can just remove the suffix after "@").
> 
> I think it is a matter of replacing special characters with some other.
> I think we should support versioned symbols, i.e. one may well want to
> intercept calls to a specific version of a symbol.

Then, there are 2 issues. Parser and event-name generator.

Parser has to understand that the versioned event to find it from symbol-map
(I have to check but versioned-suffix is not recorded in debuginfo).
Also, event-name generator should handle that. (I think this part is easy
to cut off the suffix)

Anyway, I think that (tracing specific versioned symbol) is rare case,
so for the parser we just need to introduce an "escape" backslash, like

perf probe -x /usr/lib64/libc-2.25.so malloc_get_state\\@GLIBC_2.2.5

(note that bash/sh will consume the first '\', so we need '\\'.)
This will allow user to specify version.


[..]
> > > 
> > > Masami, this one also doesn't work:
> > > 
> > > [root@jouet ~]# perf probe -x /lib64/libc-2.25.so 'malloc*%return'
> > > Error: event "malloc_printerr" already exists.
> > > <SNIP>
> > 
> > Hm, this looks like a collision happens on that event name. "-f"(--force)
> > option allows you to add events with number suffix (e.g. _1, _2, ... )
> 
> Probably this was because the same name was used for both entry and
> exit, see below on automatically adding __return to %return probes.
>  
> > > 
> > > doing it a bit differently:
> > > 
> > > [root@jouet ~]# perf probe -F -x /lib64/libc-2.25.so | egrep ^malloc[^@]+$ | while read function ; do perf probe -x /lib64/libc-2.25.so "${function}_return=$function%return" ; done
> > > Added new event:
> > >   probe_libc:malloc_check_return (on malloc_check%return in /usr/lib64/libc-2.25.so)
> > > 
> > > You can now use it in all perf tools, such as:
> > > 
> > > 	perf record -e probe_libc:malloc_check_return -aR sleep 1
> > 
> > Hmm, would you think we should add __return suffix by default?
> 
> I think so, as it is a common operation to ask for entry+exit.

OK, I'll do that.

Thank you,

> 
> - Arnaldo
>  
> > Thanks,
> > 
> > > 
> > > <SNIP>
> > > -----------
> > > 
> > > This now makes us have:
> > > 
> > > [root@jouet ~]# perf probe -l
> > >   probe:check_stack_object (on check_stack_object%return@acme/git/linux/mm/usercopy.c with ret)
> > >   probe_libc:malloc    (on __malloc in /usr/lib64/libc-2.25.so)
> > >   probe_libc:malloc_check (on malloc_check in /usr/lib64/libc-2.25.so)
> > >   probe_libc:malloc_consolidate (on malloc_consolidate.part.1 in /usr/lib64/libc-2.25.so)
> > >   probe_libc:malloc_hook_ini (on malloc_hook_ini in /usr/lib64/libc-2.25.so)
> > >   probe_libc:malloc_info (on __malloc_info in /usr/lib64/libc-2.25.so)
> > >   probe_libc:malloc_printerr (on malloc_printerr in /usr/lib64/libc-2.25.so)
> > >   probe_libc:malloc_stats (on __malloc_stats in /usr/lib64/libc-2.25.so)
> > >   probe_libc:malloc_trim (on __malloc_trim in /usr/lib64/libc-2.25.so)
> > >   probe_libc:malloc_usable_size (on __malloc_usable_size in /usr/lib64/libc-2.25.so)
> > >   probe_libc:mallochook (on mallochook in /usr/lib64/libc-2.25.so)
> > >   probe_libc:malloc_check_return (on malloc_check%return in /usr/lib64/libc-2.25.so)
> > >   probe_libc:malloc_hook_ini_return (on malloc_hook_ini%return in /usr/lib64/libc-2.25.so)
> > >   probe_libc:malloc_info_return (on __malloc_info%return in /usr/lib64/libc-2.25.so)
> > >   probe_libc:malloc_printerr_return (on malloc_printerr%return in /usr/lib64/libc-2.25.so)
> > >   probe_libc:malloc_stats_return (on __malloc_stats%return in /usr/lib64/libc-2.25.so)
> > >   probe_libc:malloc_trim_return (on __malloc_trim%return in /usr/lib64/libc-2.25.so)
> > >   probe_libc:malloc_usable_size_return (on __malloc_usable_size%return in /usr/lib64/libc-2.25.so)
> > >   probe_libc:mallochook_return (on mallochook%return in /usr/lib64/libc-2.25.so)
> > >   probe_libc:malloc_return (on __malloc%return in /usr/lib64/libc-2.25.so)
> > > [root@jouet ~]# 
> > > 
> > > There were some usability snags that prevented this from being put in
> > > place, so do it manually:
> > > 
> > > [root@jouet ~]# perf probe -x /lib64/libc-2.25.so 'malloc_consolidate_return=malloc_consolidate.part.1%return'
> > > Added new event:
> > >   probe_libc:malloc_consolidate_return (on malloc_consolidate.part.1%return in /usr/lib64/libc-2.25.so)
> > > 
> > > You can now use it in all perf tools, such as:
> > > 
> > > 	perf record -e probe_libc:malloc_consolidate_return -aR sleep 1
> > > 
> > > [root@jouet ~]#
> > > 
> > > Ok, now we can trace this syswide using:
> > > 
> > > [root@jouet ~]# perf trace --no-syscalls -e probe_libc:*
> > > <BIG SNIP>
> > >    339.557 probe_libc:malloc:(7fda55c22970))
> > >    339.562 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
> > >    339.567 probe_libc:malloc_consolidate:(7fda55c1b7b0))
> > >    339.570 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
> > >    339.596 probe_libc:malloc:(7fda55c22970))
> > >    339.600 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
> > >    339.622 probe_libc:malloc:(7fda55c22970))
> > >    339.626 probe_libc:malloc_return:(7fda55c22970 <- 7fda56ba9a39))
> > >    339.631 probe_libc:malloc:(7fda55c22970))
> > >    339.634 probe_libc:malloc_return:(7fda55c22970 <- 7fda578f1713))
> > >    339.637 probe_libc:malloc:(7fda55c22970))
> > >    339.641 probe_libc:malloc_return:(7fda55c22970 <- 7fda578f14ae))
> > >    339.657 probe_libc:malloc_consolidate:(7fda55c1b7b0))
> > >    339.661 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1dbd6))
> > >    339.664 probe_libc:malloc:(7fda55c22970))
> > >    339.667 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
> > >    339.670 probe_libc:malloc:(7fda55c22970))
> > >    339.673 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
> > >    339.678 probe_libc:malloc_consolidate:(7fda55c1b7b0))
> > >    339.681 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
> > >    339.685 probe_libc:malloc_consolidate:(7fda55c1b7b0))
> > >    339.688 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
> > >    339.693 probe_libc:malloc_consolidate:(7fda55c1b7b0))
> > >    339.696 probe_libc:malloc_consolidate_return:(7fda55c1b7b0 <- 7fda55c1f886))
> > >    339.778 probe_libc:malloc:(7fda55c22970))
> > >    339.783 probe_libc:malloc_return:(7fda55c22970 <- 7fda55c23918))
> > >    339.788 probe_libc:malloc_consolidate:(7fda55c1b7b0))
> > >   ^C(7fda55c22970 <- 7fda578f14ae))
> > > [root@jouet ~]# 
> > > 
> > > It works as well with 'perf record' + 'perf script'.
> > > 
> > > Other features from perf can be added to the mix, like callchains, etc.
> > > 
> > > But see below for doing it via tracefs
> > >  
> > > > I observed below behaviour when I tried as per directions using URL:
> > > > https://opensource.com/article/17/7/dynamic-tracing-linux-user-and-kernel-space#comment-136366
> > > > :
> > > > 
> > > > 
> > > > echo 'p:<func_entry> ./test:0x420' >
> > > > /sys/kernel/debug/tracing/uprobe_events              (for creating
> > > > uprobe)
> > > > echo 1 > /sys/kernel/debug/tracing/events/enable
> > > >                                 (enabling uproble)
> > > > There is another enable parameter:
> > > > /sys/kernel/debug/tracing/events/uprobes/enable
> > > > 
> > > > I understand unless enabled both events/enable and
> > > > events/uprobes/enable, the /sys/kernel/debug/tracing/trace is not
> > > > complete. I do not understand the relevance of
> > > > .....events/uprobes/enable as I could not get any trace data in trace
> > > > log for 'func_entry' the user space function being added for tracing.
> > > > Irrespective of the probe function added, the trace log shows complete
> > > > system trace log during the period of execution of the user
> > > > application being traced.
> > > 
> > > Is this what you want:
> > > 
> > > [root@jouet ~]# cd /sys/kernel/debug/tracing/
> > > [root@jouet tracing]# cat available_tracers 
> > > hwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop
> > > [root@jouet tracing]# echo nop > current_tracer 
> > > [root@jouet tracing]# echo 1 > events/probe_libc/malloc/enable 
> > > [root@jouet tracing]# echo 1 > tracing_on 
> > > [root@jouet tracing]# tail trace
> > >             tail-1581  [002] d... 118484.507167: malloc: (0x7fdb32d67970)
> > >             tail-1581  [002] d... 118484.507172: malloc: (0x7fdb32d67970)
> > >             tail-1581  [002] d... 118484.507189: malloc: (0x7fdb32d67970)
> > >             tail-1581  [002] d... 118484.507193: malloc: (0x7fdb32d67970)
> > >             tail-1581  [002] d... 118484.507198: malloc: (0x7fdb32d67970)
> > >             tail-1581  [002] d... 118484.507203: malloc: (0x7fdb32d67970)
> > >             tail-1581  [002] d... 118484.507208: malloc: (0x7fdb32d67970)
> > >             tail-1581  [002] d... 118484.507214: malloc: (0x7fdb32d67970)
> > >             tail-1581  [002] d... 118484.507224: malloc: (0x7fdb32d67970)
> > >             tail-1581  [002] d... 118484.507237: malloc: (0x7fdb32d67970)
> > > [root@jouet tracing]#
> > > 
> > > ?
> > >  
> > > > Can this be clearly mentioned as to when to use one of them, role of
> > > > both and and also, I could not see uprobe function in particular at
> > > > all but generic trace in /sys/kernel/debug/tracing/trace. Kindly guide
> > > > me in understanding uprobe enable logic in user space in detail.
> > > > 
> > > > Regards,
> > > > Bhargav
> > > > --
> > 
> > -- 
> > Masami Hiramatsu <mhiramat@kernel.org>


-- 
Masami Hiramatsu <mhiramat@kernel.org>

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: uprobes enable condition (user space) - sysfs interface
  2017-12-04 15:23       ` Paul Clarke
@ 2017-12-05  6:53         ` Masami Hiramatsu
  2017-12-05  7:45         ` Masami Hiramatsu
  1 sibling, 0 replies; 11+ messages in thread
From: Masami Hiramatsu @ 2017-12-05  6:53 UTC (permalink / raw)
  To: Paul Clarke
  Cc: Arnaldo Carvalho de Melo, bhargavb, linux-rt-users, linux-perf-users

On Mon, 4 Dec 2017 09:23:16 -0600
Paul Clarke <pc@us.ibm.com> wrote:

> On 12/04/2017 08:55 AM, Arnaldo Carvalho de Melo wrote:
> > Em Mon, Dec 04, 2017 at 09:36:19PM +0900, Masami Hiramatsu escreveu:
> >> On Fri, 1 Dec 2017 13:40:39 -0300
> >> Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
> >>
> >>> Adding Masami to the CC list, to see if he can come up with a fix for
> >>> the 'perf probe' failure below, improving the message or ignoring
> >>> versioned symbols (with a warning perhaps).
> >>
> >> Thanks. Should we ignore the versioned symbols? or can we put a probe
> >> on that? If we have symbol address, we can put a probe on it, even
> >> if it is versioned.
> > 
> > Lemme try...
> > 
> > [root@jouet ~]# perf probe -x /usr/lib64/libc-2.25.so malloc_get_state_225=malloc_get_state@GLIBC_2.2.5
> > The /usr/lib64/libc-2.25.so file has no debug information.
> > Rebuild with -g, or install an appropriate debuginfo package.
> >   Error: Failed to add events.
> > [root@jouet ~]# perf probe -x /usr/lib64/libc-2.25.so malloc_get_state@GLIBC_2.2.5
> > The /usr/lib64/libc-2.25.so file has no debug information.
> > Rebuild with -g, or install an appropriate debuginfo package.
> >   Error: Failed to add events.
> 
> commit d80406453ad4a69932dc17a617d5b7bc7ae80b8f should have allowed adding probes on versioned symbols if you omit the versioning part of the symbol.  So, in the above example, this should work:
> 
> # perf probe -x /usr/lib64/libc-2.25.so malloc_get_state

Would there be no chance that single binary has different versioned symbols?

Thank you,

> 
> PC
> 


-- 
Masami Hiramatsu <mhiramat@kernel.org>

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: uprobes enable condition (user space) - sysfs interface
  2017-12-04 15:23       ` Paul Clarke
  2017-12-05  6:53         ` Masami Hiramatsu
@ 2017-12-05  7:45         ` Masami Hiramatsu
  2017-12-05 13:58           ` Paul Clarke
  1 sibling, 1 reply; 11+ messages in thread
From: Masami Hiramatsu @ 2017-12-05  7:45 UTC (permalink / raw)
  To: Paul Clarke
  Cc: Arnaldo Carvalho de Melo, bhargavb, linux-rt-users, linux-perf-users

On Mon, 4 Dec 2017 09:23:16 -0600
Paul Clarke <pc@us.ibm.com> wrote:

> On 12/04/2017 08:55 AM, Arnaldo Carvalho de Melo wrote:
> > Em Mon, Dec 04, 2017 at 09:36:19PM +0900, Masami Hiramatsu escreveu:
> >> On Fri, 1 Dec 2017 13:40:39 -0300
> >> Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
> >>
> >>> Adding Masami to the CC list, to see if he can come up with a fix for
> >>> the 'perf probe' failure below, improving the message or ignoring
> >>> versioned symbols (with a warning perhaps).
> >>
> >> Thanks. Should we ignore the versioned symbols? or can we put a probe
> >> on that? If we have symbol address, we can put a probe on it, even
> >> if it is versioned.
> > 
> > Lemme try...
> > 
> > [root@jouet ~]# perf probe -x /usr/lib64/libc-2.25.so malloc_get_state_225=malloc_get_state@GLIBC_2.2.5
> > The /usr/lib64/libc-2.25.so file has no debug information.
> > Rebuild with -g, or install an appropriate debuginfo package.
> >   Error: Failed to add events.
> > [root@jouet ~]# perf probe -x /usr/lib64/libc-2.25.so malloc_get_state@GLIBC_2.2.5
> > The /usr/lib64/libc-2.25.so file has no debug information.
> > Rebuild with -g, or install an appropriate debuginfo package.
> >   Error: Failed to add events.
> 
> commit d80406453ad4a69932dc17a617d5b7bc7ae80b8f should have allowed adding probes on versioned symbols if you omit the versioning part of the symbol.  So, in the above example, this should work:
> 
> # perf probe -x /usr/lib64/libc-2.25.so malloc_get_state

No, it doesn't, the above commit improves *find_symbol_by_name(),
but perf probe uses its own lookup function, because it has to
support glob pattern matching.
Let me see, how I can improve that...

Thanks,

> 
> PC
> 


-- 
Masami Hiramatsu <mhiramat@kernel.org>

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: uprobes enable condition (user space) - sysfs interface
  2017-12-05  7:45         ` Masami Hiramatsu
@ 2017-12-05 13:58           ` Paul Clarke
  0 siblings, 0 replies; 11+ messages in thread
From: Paul Clarke @ 2017-12-05 13:58 UTC (permalink / raw)
  To: Masami Hiramatsu
  Cc: Arnaldo Carvalho de Melo, bhargavb, linux-rt-users, linux-perf-users

On 12/05/2017 01:45 AM, Masami Hiramatsu wrote:
> On Mon, 4 Dec 2017 09:23:16 -0600
> Paul Clarke <pc@us.ibm.com> wrote:
>> On 12/04/2017 08:55 AM, Arnaldo Carvalho de Melo wrote:
>>> Em Mon, Dec 04, 2017 at 09:36:19PM +0900, Masami Hiramatsu escreveu:
>>>> On Fri, 1 Dec 2017 13:40:39 -0300
>>>> Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
>>>>
>>>>> Adding Masami to the CC list, to see if he can come up with a fix for
>>>>> the 'perf probe' failure below, improving the message or ignoring
>>>>> versioned symbols (with a warning perhaps).
>>>>
>>>> Thanks. Should we ignore the versioned symbols? or can we put a probe
>>>> on that? If we have symbol address, we can put a probe on it, even
>>>> if it is versioned.
>>>
>>> Lemme try...
>>>
>>> [root@jouet ~]# perf probe -x /usr/lib64/libc-2.25.so malloc_get_state_225=malloc_get_state@GLIBC_2.2.5
>>> The /usr/lib64/libc-2.25.so file has no debug information.
>>> Rebuild with -g, or install an appropriate debuginfo package.
>>>   Error: Failed to add events.
>>> [root@jouet ~]# perf probe -x /usr/lib64/libc-2.25.so malloc_get_state@GLIBC_2.2.5
>>> The /usr/lib64/libc-2.25.so file has no debug information.
>>> Rebuild with -g, or install an appropriate debuginfo package.
>>>   Error: Failed to add events.
>>
>> commit d80406453ad4a69932dc17a617d5b7bc7ae80b8f should have allowed adding probes on versioned symbols if you omit the versioning part of the symbol.  So, in the above example, this should work:
>>
>> # perf probe -x /usr/lib64/libc-2.25.so malloc_get_state
> 
> No, it doesn't, the above commit improves *find_symbol_by_name(),
> but perf probe uses its own lookup function, because it has to
> support glob pattern matching.

That commit was explicitly to allow perf probe on versioned symbols.  However, it was limited to creating probes on _default_ versioned symbols (marked by '@@").  So, you're correct that it would not work on this symbol in particular.

The value of the commit was to prevent something like the following from failing, even though the symbol existed, but was versioned (presuming one of the versions of the symbol was marked as default ('@@')):

# perf probe perf probe -x /lib/powerpc64le-linux-gnu/libpthread.so.0 pthread_create

PC


^ permalink raw reply	[flat|nested] 11+ messages in thread

end of thread, other threads:[~2017-12-05 13:58 UTC | newest]

Thread overview: 11+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2017-11-29 18:34 uprobes enable condition (user space) - sysfs interface bhargavb
2017-12-01 16:40 ` Arnaldo Carvalho de Melo
2017-12-03 17:14   ` bhargavb
2017-12-04  6:03     ` Namhyung Kim
2017-12-04 12:36   ` Masami Hiramatsu
2017-12-04 14:55     ` Arnaldo Carvalho de Melo
2017-12-04 15:23       ` Paul Clarke
2017-12-05  6:53         ` Masami Hiramatsu
2017-12-05  7:45         ` Masami Hiramatsu
2017-12-05 13:58           ` Paul Clarke
2017-12-05  6:51       ` Masami Hiramatsu

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).