From: Masami Hiramatsu <mhiramat@kernel.org>
To: Ming Lei <ming.lei@redhat.com>
Cc: Ming Lei <tom.leiming@gmail.com>,
"Naveen N. Rao" <naveen.n.rao@linux.ibm.com>,
Anil S Keshavamurthy <anil.s.keshavamurthy@intel.com>,
Linux Kernel Mailing List <linux-kernel@vger.kernel.org>,
"David S. Miller" <davem@davemloft.net>,
Steven Rostedt <rostedt@goodmis.org>,
linux-block <linux-block@vger.kernel.org>
Subject: Re: kprobe: __blkdev_put probe is missed
Date: Fri, 19 Jun 2020 14:12:39 +0900 [thread overview]
Message-ID: <20200619141239.56f6dda0976453b790190ff7@kernel.org> (raw)
In-Reply-To: <20200618231901.GA196099@T590>
Hi Ming,
On Fri, 19 Jun 2020 07:19:01 +0800
Ming Lei <ming.lei@redhat.com> wrote:
> > I'm using 5.4 on ubuntu and can not reproduce it with kprobe_event.
> >
> > root@devnote2:/sys/kernel/tracing# uname -a
> > Linux devnote2 5.4.0-37-generic #41-Ubuntu SMP Wed Jun 3 18:57:02 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux
> > root@devnote2:/sys/kernel/tracing# echo p __blkdev_put > kprobe_events
> > root@devnote2:/sys/kernel/tracing# echo 1 > events/kprobes/p___blkdev_put_0/enable
> > root@devnote2:/sys/kernel/tracing# cat trace
> > # tracer: nop
> > #
> > # entries-in-buffer/entries-written: 0/0 #P:8
> > #
> > # _-----=> irqs-off
> > # / _----=> need-resched
> > # | / _---=> hardirq/softirq
> > # || / _--=> preempt-depth
> > # ||| / delay
> > # TASK-PID CPU# |||| TIMESTAMP FUNCTION
> > # | | | |||| | |
> > root@devnote2:/sys/kernel/tracing# blockdev --getbsz /dev/nvme0n1
> > 4096
> > root@devnote2:/sys/kernel/tracing# cat trace
> > # tracer: nop
> > #
> > # entries-in-buffer/entries-written: 1/1 #P:8
> > #
> > # _-----=> irqs-off
> > # / _----=> need-resched
> > # | / _---=> hardirq/softirq
> > # || / _--=> preempt-depth
> > # ||| / delay
> > # TASK-PID CPU# |||| TIMESTAMP FUNCTION
> > # | | | |||| | |
> > <...>-111740 [002] .... 301734.476991: p___blkdev_put_0: (__blkdev_put+0x0/0x1e0)
> >
> > Hmm, maybe some issue in the latest kernel...?
>
> Hello Masami,
>
> I am testing the latest upstream kernel, your trace actually reproduces
> this issue.
OK.
>
> After 'blockdev --getbsz /dev/nvme0n1' returns, __blkdev_put() should
> have been called two times(one for partition, and the other for disk),
> however kprobe trace just shows one time of calling this function.
>
> If trace_printk() is added at the entry of __blkdev_put() manually,
> you will see that __blkdev_put() is called two times in 'blockdev
> --getbsz /dev/nvme0n1'.
OK, let me check again on the latest kernel.
Here I tested with qemu.
root@devnote2:/sys/kernel/debug/tracing# uname -a
Linux devnote2 5.8.0-rc1+ #26 SMP PREEMPT Fri Jun 19 12:12:53 JST 2020 x86_64 x86_64 x86_64 GNU/Linux
And we have a (virtual) sda with 1 partition.
root@devnote2:/sys/kernel/debug/tracing# cat /proc/partitions
major minor #blocks name
8 0 10240 sda
8 1 9216 sda1
OK, then let's make events (for sure)
root@devnote2:/sys/kernel/debug/tracing# echo p __blkdev_put >> kprobe_events
root@devnote2:/sys/kernel/debug/tracing# echo r __blkdev_put >> kprobe_events
root@devnote2:/sys/kernel/debug/tracing# echo p blkdev_put >> kprobe_events
There are 3 events in the kernel, blkdev_put() and __blkdev_put() and
the return of __blkdev_put().
Then enable it and access to */dev/sda* (a disk)
root@devnote2:/sys/kernel/debug/tracing# echo 1 > events/kprobes/enable
root@devnote2:/sys/kernel/debug/tracing# blockdev --getbsz /dev/sda
4096
root@devnote2:/sys/kernel/debug/tracing# echo 0 > events/kprobes/enable
root@devnote2:/sys/kernel/debug/tracing# cat trace
# tracer: nop
#
# entries-in-buffer/entries-written: 3/3 #P:8
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
blockdev-185 [002] ...1 72.604266: p_blkdev_put_0: (blkdev_put+0x0/0x130)
blockdev-185 [002] ...1 72.604276: p___blkdev_put_0: (__blkdev_put+0x0/0x220)
blockdev-185 [002] d..2 72.604288: r___blkdev_put_0: (blkdev_put+0x50/0x130 <- __blkdev_put)
So the __blkdev_put() is called once from blkdev_put().
Next, we do same trace with accessing */dev/sda1* (a partition).
root@devnote2:/sys/kernel/debug/tracing# echo > trace
root@devnote2:/sys/kernel/debug/tracing# echo 1 > events/kprobes/enable
root@devnote2:/sys/kernel/debug/tracing# blockdev --getbsz /dev/sda1
4096
root@devnote2:/sys/kernel/debug/tracing# echo 0 > events/kprobes/enable
root@devnote2:/sys/kernel/debug/tracing# cat trace
# tracer: nop
#
# entries-in-buffer/entries-written: 5/5 #P:8
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
blockdev-191 [005] ...1 194.401517: p_blkdev_put_0: (blkdev_put+0x0/0x130)
blockdev-191 [005] ...1 194.401527: p___blkdev_put_0: (__blkdev_put+0x0/0x220)
blockdev-191 [005] ...1 194.401529: p___blkdev_put_0: (__blkdev_put+0x0/0x220)
blockdev-191 [005] d..2 194.401535: r___blkdev_put_0: (__blkdev_put+0x1ea/0x220 <- __blkdev_put)
blockdev-191 [005] d..2 194.401536: r___blkdev_put_0: (blkdev_put+0x50/0x130 <- __blkdev_put)
In this case, we can see the __blkdev_put() is called twice, from
blkdev_put() and __blkdev_put() itself (nested call).
So, it seems that the kprobe event correctly works.
Could you do same thing on your environment, and share the result?
Thank you,
--
Masami Hiramatsu <mhiramat@kernel.org>
next prev parent reply other threads:[~2020-06-19 5:12 UTC|newest]
Thread overview: 18+ messages / expand[flat|nested] mbox.gz Atom feed top
2020-06-17 10:30 krobe: __blkdev_put probe is missed Ming Lei
2020-06-18 12:54 ` kprobe: " Ming Lei
2020-06-18 13:56 ` Masami Hiramatsu
2020-06-18 23:19 ` Ming Lei
2020-06-19 5:12 ` Masami Hiramatsu [this message]
2020-06-19 7:28 ` Ming Lei
2020-06-19 12:19 ` Steven Rostedt
2020-06-19 13:32 ` Ming Lei
2020-06-19 15:35 ` Masami Hiramatsu
2020-06-19 23:28 ` Ming Lei
2020-06-20 0:59 ` Steven Rostedt
2020-06-20 1:37 ` Masami Hiramatsu
2020-06-22 0:27 ` Ming Lei
2020-06-22 1:34 ` Masami Hiramatsu
2020-06-22 13:01 ` Steven Rostedt
2020-06-22 23:47 ` Masami Hiramatsu
2020-06-23 0:38 ` Masami Hiramatsu
2020-06-23 5:28 ` Masami Hiramatsu
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=20200619141239.56f6dda0976453b790190ff7@kernel.org \
--to=mhiramat@kernel.org \
--cc=anil.s.keshavamurthy@intel.com \
--cc=davem@davemloft.net \
--cc=linux-block@vger.kernel.org \
--cc=linux-kernel@vger.kernel.org \
--cc=ming.lei@redhat.com \
--cc=naveen.n.rao@linux.ibm.com \
--cc=rostedt@goodmis.org \
--cc=tom.leiming@gmail.com \
/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 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).