Re: [REGRESSION] commit c2b3c170db610 causes blktests block/002 failure

[Omar Sandoval <osandov@osandov.com>]

On Tue, Jun 18, 2019 at 04:09:26PM -0700, Bart Van Assche wrote:
> On 6/9/19 11:14 AM, Theodore Ts'o wrote:
> > I recently noticed that block/002 from blktests started failing:
> > 
> > root@kvm-xfstests:~# cd blktests/
> > root@kvm-xfstests:~/blktests# ./check block/002
> > block/002 (remove a device while running blktrace)
> >      runtime  ...
> > [   12.598314] run blktests block/002 at 2019-06-09 13:09:00
> > [   12.621298] scsi host0: scsi_debug: version 0188 [20190125]
> > [   12.621298]   dev_size_mb=8, opts=0x0, submit_queues=1, statistics=0
> > [   12.625578] scsi 0:0:0:0: Direct-Access     Linux    scsi_debug       0188 PQ: 0 ANSI: 7
> > [   12.627109] sd 0:0:0:0: Power-on or device reset occurred
> > [   12.630322] sd 0:0:0:0: Attached scsi generic sg0 type 0
> > [   12.634693] sd 0:0:0:0: [sda] 16384 512-byte logical blocks: (8.39 MB/8.00 MiB)
> > [   12.638881] sd 0:0:0:0: [sda] Write Protect is off
> > [   12.639464] sd 0:0:0:0: [sda] Mode Sense: 73 00 10 08
> > [   12.646951] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, supports DPO and FUA
> > [   12.658210] sd 0:0:0:0: [sda] Optimal transfer size 524288 bytes
> > [   12.722771] sd 0:0:0:0: [sda] Attached SCSI disk
> > block/002 (remove a device while running blktrace)           [failed]left
> >      runtime  ...  0.945s0: [sda] Synchronizing SCSI cache
> >      --- tests/block/002.out	2019-05-27 13:52:17.000000000 -0400
> >      +++ /root/blktests/results/nodev/block/002.out.bad	2019-06-09 13:09:01.034094065 -0400
> >      @@ -1,2 +1,3 @@
> >       Running block/002
> >      +debugfs directory leaked
> >       Test complete
> > root@kvm-xfstests:~/blktests#
> > 
> > The git bisect log (see attached) pointed at this commit:
> > 
> > commit c2b3c170db610896e4e633cba2135045333811c2 (HEAD, refs/bisect/bad)
> > Author: Andi Kleen <ak@linux.intel.com>
> > Date:   Tue Mar 26 15:18:20 2019 -0700
> > 
> >      perf stat: Revert checks for duration_time
> >      This reverts e864c5ca145e ("perf stat: Hide internal duration_time
> >      counter") but doing it manually since the code has now moved to a
> >      different file.
> >      The next patch will properly implement duration_time as a full event, so
> >      no need to hide it anymore.
> >      Signed-off-by: Andi Kleen <ak@linux.intel.com>
> >      Acked-by: Jiri Olsa <jolsa@kernel.org>
> >      Link: http://lkml.kernel.org/r/20190326221823.11518-2-andi@firstfloor.org
> >      Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
> > 
> > Is this a known issue?
> 
> Hi Ted,
> 
> Test block/002 removes a SCSI device by writing into the "delete" sysfs
> attribute. As one can see in __scsi_remove_device() that triggers a
> synchronous call of blk_cleanup_queue(). The "debugfs directory leaked"
> message is reported if the request queue debugfs directory is found after
> SCSI device deletion has finished. Request queue debugfs directory deletion
> happens upon the final put of the request queue (see also
> __blk_release_queue()). I don't think that there is any guarantee that the
> debugfs directory disappears immediately after SCSI device deletion has
> finished. In other words, I think that this is a bug in test block/002.
> Omar, are you the author of that test script?

Hi, Bart, yes I wrote this test. I can reproduce the failure. I'll try
to find a reliable way to wait, otherwise I'll probably just toss a
sleep in here.