Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 23.128.96.18 as permitted sender) client-ip=23.128.96.18;
Date:   Thu, 18 Jun 2020 22:56:02 +0900
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>,
        Masami Hiramatsu <mhiramat@kernel.org>,
        Steven Rostedt <rostedt@goodmis.org>,
        linux-block <linux-block@vger.kernel.org>
Subject: Re: kprobe: __blkdev_put probe is missed
Message-Id: <20200618225602.3f2cca3f0ed48427fc0a483b@kernel.org>
In-Reply-To: <20200618125438.GA191266@T590>
References: <CACVXFVO5saamQXs0naLamTKJfXZMW+p446weeqJK=9+V34UM0g@mail.gmail.com>
        <20200618125438.GA191266@T590>
Mime-Version: 1.0
Content-Type: text/plain; charset=US-ASCII
Content-Transfer-Encoding: 7bit
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk

Hi Ming,

On Thu, 18 Jun 2020 20:54:38 +0800
Ming Lei <ming.lei@redhat.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@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...?


Thank you,

-- 
Masami Hiramatsu <mhiramat@kernel.org>