From: Masami Hiramatsu <mhiramat@kernel.org>
To: Arnaldo Carvalho de Melo <acme@kernel.org>
Cc: Masami Hiramatsu <mhiramat@kernel.org>,
Jiri Olsa <jolsa@kernel.org>, Kajol Jain <kjain@linux.ibm.com>,
Andi Kleen <andi@firstfloor.org>,
Linux Kernel Mailing List <linux-kernel@vger.kernel.org>,
linux-perf-users@vger.kernel.org
Subject: Re: perf probe + uprobes missing events
Date: Wed, 8 Apr 2020 12:14:52 +0900 [thread overview]
Message-ID: <20200408121452.eef4eb8e66367677f295f9ea@kernel.org> (raw)
In-Reply-To: <20200407213943.3a92e040d4ce30dc55e9aa1f@kernel.org>
Hi Arnaldo,
This seems like a perf (perf's ringbuffer?) issue.
Actually, we can not enable perf and ftrace on same uprobe event yet, but the hit counter (uprobe_profile) works.
1) Setup the event.
$ sudo ./perf probe -x ./perf expr__parse expr:string
Added new event:
probe_perf:expr__parse (on expr__parse in /home/mhiramat/ksrc/linux/tools/perf/perf with expr:string)
You can now use it in all perf tools, such as:
perf record -e probe_perf:expr__parse -aR sleep 1
$ sudo cat /sys/kernel/debug/tracing/uprobe_profile
/home/mhiramat/ksrc/linux/tools/perf/perf expr__parse 0
2) run the test command
$ sudo ./perf trace -e probe_perf:expr_* perf test -F expr
7: Simple expression parser : Ok
0.000 perf/9789 probe_perf:expr__parse(__probe_ip: 94836726971904, expr_string: "1+1")
$ sudo cat /sys/kernel/debug/tracing/uprobe_profile
/home/mhiramat/ksrc/linux/tools/perf/perf expr__parse 12
OK, this shows the perf trace command only shows 1 event, but uprobe_event itself hits 12 times.
3) run the test command again
$ sudo ./perf trace -e probe_perf:expr_* perf test -F expr
7: Simple expression parser : Ok
0.000 perf/9847 probe_perf:expr__parse(__probe_ip: 94778335464960, expr_string: "1+1")
0.014 perf/9847 probe_perf:expr__parse(__probe_ip: 94778335464960, expr_string: "FOO+BAR")
0.018 perf/9847 probe_perf:expr__parse(__probe_ip: 94778335464960, expr_string: "(BAR/2)%2")
$ sudo cat /sys/kernel/debug/tracing/uprobe_profile
/home/mhiramat/ksrc/linux/tools/perf/perf expr__parse 24
Again, the perf trace shows only 3 events, but uprobe event hits +12 times
4) run the test command with ftrace.
$ echo 1 | sudo tee /sys/kernel/debug/tracing/events/probe_perf/enable
1
$ ./perf test -F expr
7: Simple expression parser : Ok
$ sudo cat /sys/kernel/debug/tracing/uprobe_profile
/home/mhiramat/ksrc/linux/tools/perf/perf expr__parse 36
Hit +12 times and the ftrace shows all events correctly.
$ sudo cat /sys/kernel/debug/tracing/trace
# tracer: nop
#
# entries-in-buffer/entries-written: 24/24 #P:8
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
perf-9883 [003] d... 9287.936678: expr__parse: (0x55ea35ce9e00) expr_string="1+1"
perf-9883 [003] d... 9287.936694: expr__parse: (0x55ea35ce9e00) expr_string="FOO+BAR"
perf-9883 [003] d... 9287.936699: expr__parse: (0x55ea35ce9e00) expr_string="(BAR/2)%2"
perf-9883 [003] d... 9287.936704: expr__parse: (0x55ea35ce9e00) expr_string="1 - -4"
perf-9883 [003] d... 9287.936707: expr__parse: (0x55ea35ce9e00) expr_string="(FOO-1)*2 + (BAR/2)%2 - -4"
perf-9883 [003] d... 9287.936712: expr__parse: (0x55ea35ce9e00) expr_string="1-1 | 1"
perf-9883 [003] d... 9287.936716: expr__parse: (0x55ea35ce9e00) expr_string="1-1 & 1"
perf-9883 [003] d... 9287.936719: expr__parse: (0x55ea35ce9e00) expr_string="min(1,2) + 1"
perf-9883 [003] d... 9287.936723: expr__parse: (0x55ea35ce9e00) expr_string="max(1,2) + 1"
perf-9883 [003] d... 9287.936726: expr__parse: (0x55ea35ce9e00) expr_string="1+1 if 3*4 else 0"
perf-9883 [003] d... 9287.936731: expr__parse: (0x55ea35ce9e00) expr_string="FOO/0"
perf-9883 [003] d... 9287.936734: expr__parse: (0x55ea35ce9e00) expr_string="BAR/"
It seems that the perf ring buffer returns only early events
(since expr_string="1+1" is always shown), so I guess there is
a timing issue when the ring buffer is read.
Can we delay the read timing?
Thank you,
--
Masami Hiramatsu <mhiramat@kernel.org>
prev parent reply other threads:[~2020-04-08 3:14 UTC|newest]
Thread overview: 4+ messages / expand[flat|nested] mbox.gz Atom feed top
2020-04-06 14:53 perf probe + uprobes missing events Arnaldo Carvalho de Melo
2020-04-06 14:54 ` Arnaldo Carvalho de Melo
2020-04-07 12:39 ` Masami Hiramatsu
2020-04-08 3:14 ` Masami Hiramatsu [this message]
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20200408121452.eef4eb8e66367677f295f9ea@kernel.org \
--to=mhiramat@kernel.org \
--cc=acme@kernel.org \
--cc=andi@firstfloor.org \
--cc=jolsa@kernel.org \
--cc=kjain@linux.ibm.com \
--cc=linux-kernel@vger.kernel.org \
--cc=linux-perf-users@vger.kernel.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.