linux-kernel - Re: kprobe: __blkdev

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <20200618231901.GA196099@T590>
Date:   Fri, 19 Jun 2020 07:19:01 +0800
From:   Ming Lei <ming.lei@...hat.com>
To:     Masami Hiramatsu <mhiramat@...nel.org>
Cc:     Ming Lei <tom.leiming@...il.com>,
        "Naveen N. Rao" <naveen.n.rao@...ux.ibm.com>,
        Anil S Keshavamurthy <anil.s.keshavamurthy@...el.com>,
        Linux Kernel Mailing List <linux-kernel@...r.kernel.org>,
        "David S. Miller" <davem@...emloft.net>,
        Steven Rostedt <rostedt@...dmis.org>,
        linux-block <linux-block@...r.kernel.org>
Subject: Re: kprobe: __blkdev_put probe is missed

On Thu, Jun 18, 2020 at 10:56:02PM +0900, Masami Hiramatsu wrote:
> Hi Ming,
> 
> On Thu, 18 Jun 2020 20:54:38 +0800
> Ming Lei <ming.lei@...hat.com> wrote:
> 
> > On Wed, Jun 17, 2020 at 06:30:39PM +0800, Ming Lei wrote:
> > > Hello Guys,
> > > 
> > > I found probe on __blkdev_put is missed, which can be observed
> > > via bcc/perf reliably:
> > > 
> > > 1) start trace
> > > - perf probe __blkdev_put
> > > - perf trace -a  -e probe:__blkdev_put
> 
> Could you dump the kprobe_event as below?
> 
> # cat /sys/kernel/tracing/kprobe_events
> 
> 
> > > 
> > > or
> > > 
> > > /usr/share/bcc/tools/stackcount __blkdev_put
> > > 
> > > 2) run the following command:
> > > blockdev --getbsz /dev/sda1
> 
> And dump the kprobe profile?
> 
> # cat /sys/kernel/tracing/kprobe_profile
> 
> > > 
> > > 3) 'perf trace'  or stackcount just  dumps one trace event, and it
> > > should have been two
> > > __blkdev_put() traces, since one __blkdev_put() is called for
> > > partition(/dev/sda1),
> > > and another is for disk(/dev/sda). If trace_printk() is added in __blkdev_put(),
> > > two events will be captured from ftrace.
> > > 
> > 
> > The issue can be shown by loading a kprobe module which registers on
> > __blkdev_put(), just by replacing _do_fork with __blkdev_put on
> > samples/kprobes/kprobe_example.c.
> 
> Could you tell me what kernel are you using?
> 
> I'm using 5.4 on ubuntu and can not reproduce it with kprobe_event.
> 
> root@...note2:/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@...note2:/sys/kernel/tracing# echo p __blkdev_put > kprobe_events 
> root@...note2:/sys/kernel/tracing# echo 1 > events/kprobes/p___blkdev_put_0/enable 
> root@...note2:/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@...note2:/sys/kernel/tracing# blockdev --getbsz /dev/nvme0n1
> 4096
> root@...note2:/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.

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'.


Thanks,
Ming