All of lore.kernel.org
 help / color / mirror / Atom feed
* blktests failures with v5.19-rc1
@ 2022-06-09 23:53 Shinichiro Kawasaki
  2022-06-10  8:07 ` Christoph Hellwig
  2022-06-10  9:22 ` Chaitanya Kulkarni
  0 siblings, 2 replies; 23+ messages in thread
From: Shinichiro Kawasaki @ 2022-06-09 23:53 UTC (permalink / raw)
  To: linux-block, linux-nvme, linux-scsi

Hi all,

I ran the latest blktests (git hash: c17a19d) with v5.19-rc1 kernel and observed
6 test cases fail. I call for helps to fix them. Please refer the list of the
failure cases and descriptions below.

- I don't know details of these failures. Not sure if they are kernel bugs or
  not. Some of them might be test script bugs or test system set up issues.
- All of the test cases failed also with v5.18 kernel, except scsi/007. The
  scsi/007 failure could be a new issue introduced with v5.19-rc1.
- I used Fedora 36 on QEMU for test runs. Related drivers were built as modules.

If further information is required for fixes, please let me know.


List of failure cases
=====================
#1: block/002
#2: scsi/007
#3: nvme/002
#4: nvme/016
#5: nvme/017
#6: nvme/032

Failure descriptiion
====================
#1: block/002: Failed 3 times with 3 trials.
    Known issue. It is suggested to remove this test case [1].
    [1] https://lore.kernel.org/linux-block/20220530134548.3108185-3-hch@lst.de/

    runtime    ...  1.250s
    --- tests/block/002.out     2022-06-02 10:18:53.526739780 +0900
    +++ /home/shin/kts/kernel-test-suite/src/blktests/results/nodev/block/002.out.bad   2022-06-09 09:44:02.779122029 +0900
    @@ -1,2 +1,3 @@
     Running block/002
    +debugfs directory leaked
     Test complete

#2: scsi/007: Failed 3 times with 3 trials.

    runtime  29.867s  ...  40.688s
    --- tests/scsi/007.out      2022-06-02 10:18:53.550739780 +0900
    +++ /home/shin/kts/kernel-test-suite/src/blktests/results/nodev/scsi/007.out.bad    2022-06-09 09:18:38.644237681 +0900
    @@ -1,3 +1,3 @@
     Running scsi/007
    -Reading from scsi_debug failed
    +Reading from scsi_debug succeeded
     Test complete

#3: nvme/002: Failed 3 times with 3 trials.

    runtime    ...  85.697s
    --- tests/nvme/002.out      2022-06-02 10:18:53.538739780 +0900
    +++ /home/shin/kts/kernel-test-suite/src/blktests/results/nodev/nvme/002.out.bad    2022-06-09 09:51:45.714027241 +0900
    @@ -1,3003 +1,3006 @@
     Running nvme/002
    -Discovery Log Number of Records 1000, Generation counter X
    +Discovery Log Number of Records 1001, Generation counter X
     =====Discovery Log Entry 0======
     trtype:  loop
    -subnqn:  blktests-subsystem-0
    +subnqn:  nqn.2014-08.org.nvmexpress.discovery
    ...

#4: nvme/016: Failed 3 times with 3 trials.

    runtime  36.240s  ...  35.984s
    --- tests/nvme/016.out      2022-06-02 10:18:53.541739780 +0900
    +++ /home/shin/kts/kernel-test-suite/src/blktests/results/nodev/nvme/016.out.bad    2022-06-09 10:06:11.797004672 +0900
    @@ -1,6 +1,9 @@
     Running nvme/016
    -Discovery Log Number of Records 1, Generation counter X
    +Discovery Log Number of Records 2, Generation counter X
     =====Discovery Log Entry 0======
     trtype:  loop
    +subnqn:  nqn.2014-08.org.nvmexpress.discovery
    +=====Discovery Log Entry 1======
    ...

#5: nvme/017: Failed 3 times with 3 trials.

    runtime  43.724s  ...  42.912s
    --- tests/nvme/017.out      2022-06-02 10:18:53.541739780 +0900
    +++ /home/shin/kts/kernel-test-suite/src/blktests/results/nodev/nvme/017.out.bad    2022-06-09 10:09:18.016394996 +0900
    @@ -1,6 +1,9 @@
     Running nvme/017
    -Discovery Log Number of Records 1, Generation counter X
    +Discovery Log Number of Records 2, Generation counter X
     =====Discovery Log Entry 0======
     trtype:  loop
    +subnqn:  nqn.2014-08.org.nvmexpress.discovery
    +=====Discovery Log Entry 1======
    ...

#6: nvme/032: Failed at the first run after system reboot.
              Used QEMU NVME device as TEST_DEV.

    runtime    ...  8.458s
    something found in dmesg:
    [ 1589.976481] run blktests nvme/032 at 2022-06-09 10:57:20

    [ 1597.221547] ======================================================
    [ 1597.221549] WARNING: possible circular locking dependency detected
    [ 1597.221551] 5.19.0-rc1 #1 Not tainted
    [ 1597.221554] ------------------------------------------------------
    [ 1597.221554] check/970 is trying to acquire lock:
    [ 1597.221556] ffff8881026f8cb8 (kn->active#227){++++}-{0:0}, at: kernfs_remove_by_name_ns+0x90/0xe0
    [ 1597.221580]
                   but task is already holding lock:
    ...

dmesg output:
[ 1589.976481] run blktests nvme/032 at 2022-06-09 10:57:20

[ 1597.221547] ======================================================
[ 1597.221549] WARNING: possible circular locking dependency detected
[ 1597.221551] 5.19.0-rc1 #1 Not tainted
[ 1597.221554] ------------------------------------------------------
[ 1597.221554] check/970 is trying to acquire lock:
[ 1597.221556] ffff8881026f8cb8 (kn->active#227){++++}-{0:0}, at: kernfs_remove_by_name_ns+0x90/0xe0
[ 1597.221580] 
               but task is already holding lock:
[ 1597.221580] ffffffff889c0668 (pci_rescan_remove_lock){+.+.}-{3:3}, at: pci_stop_and_remove_bus_device_locked+0xe/0x30
[ 1597.221590] 
               which lock already depends on the new lock.

[ 1597.221591] 
               the existing dependency chain (in reverse order) is:
[ 1597.221592] 
               -> #1 (pci_rescan_remove_lock){+.+.}-{3:3}:
[ 1597.221598]        __mutex_lock+0x14c/0x12b0
[ 1597.221604]        dev_rescan_store+0x94/0xd0
[ 1597.221607]        kernfs_fop_write_iter+0x34f/0x520
[ 1597.221610]        new_sync_write+0x2ca/0x500
[ 1597.221614]        vfs_write+0x62d/0x980
[ 1597.221616]        ksys_write+0xe7/0x1b0
[ 1597.221619]        do_syscall_64+0x37/0x80
[ 1597.221622]        entry_SYSCALL_64_after_hwframe+0x46/0xb0
[ 1597.221625] 
               -> #0 (kn->active#227){++++}-{0:0}:
[ 1597.221629]        __lock_acquire+0x2875/0x5510
[ 1597.221634]        lock_acquire+0x194/0x4f0
[ 1597.221636]        __kernfs_remove+0x6f3/0x910
[ 1597.221638]        kernfs_remove_by_name_ns+0x90/0xe0
[ 1597.221641]        remove_files+0x8c/0x1a0
[ 1597.221644]        sysfs_remove_group+0x77/0x150
[ 1597.221646]        sysfs_remove_groups+0x4f/0x90
[ 1597.221649]        device_remove_attrs+0x19e/0x240
[ 1597.221652]        device_del+0x492/0xb60
[ 1597.221654]        pci_remove_bus_device+0x12c/0x350
[ 1597.221656]        pci_stop_and_remove_bus_device_locked+0x1e/0x30
[ 1597.221659]        remove_store+0xac/0xc0
[ 1597.221662]        kernfs_fop_write_iter+0x34f/0x520
[ 1597.221664]        new_sync_write+0x2ca/0x500
[ 1597.221666]        vfs_write+0x62d/0x980
[ 1597.221669]        ksys_write+0xe7/0x1b0
[ 1597.221671]        do_syscall_64+0x37/0x80
[ 1597.221673]        entry_SYSCALL_64_after_hwframe+0x46/0xb0
[ 1597.221675] 
               other info that might help us debug this:

[ 1597.221676]  Possible unsafe locking scenario:

[ 1597.221677]        CPU0                    CPU1
[ 1597.221678]        ----                    ----
[ 1597.221678]   lock(pci_rescan_remove_lock);
[ 1597.221680]                                lock(kn->active#227);
[ 1597.221683]                                lock(pci_rescan_remove_lock);
[ 1597.221685]   lock(kn->active#227);
[ 1597.221687] 
                *** DEADLOCK ***

[ 1597.221688] 3 locks held by check/970:
[ 1597.221689]  #0: ffff888110106460 (sb_writers#4){.+.+}-{0:0}, at: ksys_write+0xe7/0x1b0
[ 1597.221697]  #1: ffff888120f69088 (&of->mutex){+.+.}-{3:3}, at: kernfs_fop_write_iter+0x216/0x520
[ 1597.221703]  #2: ffffffff889c0668 (pci_rescan_remove_lock){+.+.}-{3:3}, at: pci_stop_and_remove_bus_device_locked+0xe/0x30
[ 1597.221709] 
               stack backtrace:
[ 1597.221714] CPU: 1 PID: 970 Comm: check Not tainted 5.19.0-rc1 #1
[ 1597.221717] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.0-0-gd239552ce722-prebuilt.qemu.org 04/01/2014
[ 1597.221723] Call Trace:
[ 1597.221728]  <TASK>
[ 1597.221732]  dump_stack_lvl+0x5b/0x74
[ 1597.221742]  check_noncircular+0x23f/0x2e0
[ 1597.221745]  ? lock_chain_count+0x20/0x20
[ 1597.221748]  ? print_circular_bug+0x1e0/0x1e0
[ 1597.221751]  ? mark_lock+0xee/0x1610
[ 1597.221754]  ? mark_lock+0xee/0x1610
[ 1597.221759]  ? lockdep_lock+0xb8/0x1a0
[ 1597.221762]  ? call_rcu_zapped+0xb0/0xb0
[ 1597.221766]  __lock_acquire+0x2875/0x5510
[ 1597.221773]  ? lockdep_hardirqs_on_prepare+0x410/0x410
[ 1597.221779]  lock_acquire+0x194/0x4f0
[ 1597.221782]  ? kernfs_remove_by_name_ns+0x90/0xe0
[ 1597.221786]  ? lock_downgrade+0x6b0/0x6b0
[ 1597.221791]  ? up_write+0x14d/0x460
[ 1597.221795]  __kernfs_remove+0x6f3/0x910
[ 1597.221798]  ? kernfs_remove_by_name_ns+0x90/0xe0
[ 1597.221803]  ? kernfs_next_descendant_post+0x280/0x280
[ 1597.221807]  ? lock_is_held_type+0xe3/0x140
[ 1597.221811]  ? kernfs_name_hash+0x16/0xc0
[ 1597.221815]  ? kernfs_find_ns+0x1e3/0x330
[ 1597.221819]  kernfs_remove_by_name_ns+0x90/0xe0
[ 1597.221822]  remove_files+0x8c/0x1a0
[ 1597.221826]  sysfs_remove_group+0x77/0x150
[ 1597.221831]  sysfs_remove_groups+0x4f/0x90
[ 1597.221835]  device_remove_attrs+0x19e/0x240
[ 1597.221838]  ? device_remove_file+0x20/0x20
[ 1597.221842]  device_del+0x492/0xb60
[ 1597.221846]  ? __device_link_del+0x350/0x350
[ 1597.221848]  ? kfree+0xc5/0x340
[ 1597.221856]  pci_remove_bus_device+0x12c/0x350
[ 1597.221860]  pci_stop_and_remove_bus_device_locked+0x1e/0x30
[ 1597.221863]  remove_store+0xac/0xc0
[ 1597.221867]  ? subordinate_bus_number_show+0xa0/0xa0
[ 1597.221870]  ? sysfs_kf_write+0x3d/0x170
[ 1597.221874]  kernfs_fop_write_iter+0x34f/0x520
[ 1597.221881]  new_sync_write+0x2ca/0x500
[ 1597.221885]  ? new_sync_read+0x500/0x500
[ 1597.221888]  ? perf_callchain_user+0x7c0/0xaa0
[ 1597.221893]  ? lock_downgrade+0x6b0/0x6b0
[ 1597.221896]  ? inode_security+0x54/0xf0
[ 1597.221903]  ? lock_is_held_type+0xe3/0x140
[ 1597.221909]  vfs_write+0x62d/0x980
[ 1597.221913]  ksys_write+0xe7/0x1b0
[ 1597.221916]  ? __ia32_sys_read+0xa0/0xa0
[ 1597.221919]  ? syscall_enter_from_user_mode+0x20/0x70
[ 1597.221925]  do_syscall_64+0x37/0x80
[ 1597.221928]  entry_SYSCALL_64_after_hwframe+0x46/0xb0
[ 1597.221931] RIP: 0033:0x7f5608901c17
[ 1597.221939] Code: 0f 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b7 0f 1f 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 51 c3 48 83 ec 28 48 89 54 24 18 48 89 74 24
[ 1597.221942] RSP: 002b:00007fff89480c08 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[ 1597.221945] RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007f5608901c17
[ 1597.221948] RDX: 0000000000000002 RSI: 000055572288f080 RDI: 0000000000000001
[ 1597.221949] RBP: 000055572288f080 R08: 0000000000000000 R09: 0000000000000073
[ 1597.221951] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000002
[ 1597.221953] R13: 00007f56089f8780 R14: 0000000000000002 R15: 00007f56089f39e0
[ 1597.221960]  </TASK>
[ 1597.227490] pci 0000:00:09.0: [1b36:0010] type 00 class 0x010802
[ 1597.230489] pci 0000:00:09.0: reg 0x10: [mem 0xfebc4000-0xfebc7fff 64bit]
[ 1597.278136] pci 0000:00:09.0: BAR 0: assigned [mem 0x640000000-0x640003fff 64bit]
[ 1597.283549] nvme nvme5: pci function 0000:00:09.0
[ 1598.372141] nvme nvme5: 10/0/0 default/read/poll queues
[ 1598.375349] nvme nvme5: Ignoring bogus Namespace Identifiers
[ 1618.928153] run blktests nvme/032 at 2022-06-09 10:57:49
[ 1625.557584] pci 0000:00:09.0: [1b36:0010] type 00 class 0x010802
[ 1625.558348] pci 0000:00:09.0: reg 0x10: [mem 0x640000000-0x640003fff 64bit]
[ 1625.577856] pci 0000:00:09.0: BAR 0: assigned [mem 0x640000000-0x640003fff 64bit]
[ 1625.581168] nvme nvme5: pci function 0000:00:09.0
[ 1626.695897] nvme nvme5: 10/0/0 default/read/poll queues
[ 1626.701014] nvme nvme5: Ignoring bogus Namespace Identifiers

-- 
Shin'ichiro Kawasaki

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-06-09 23:53 blktests failures with v5.19-rc1 Shinichiro Kawasaki
@ 2022-06-10  8:07 ` Christoph Hellwig
  2022-06-10  9:22 ` Chaitanya Kulkarni
  1 sibling, 0 replies; 23+ messages in thread
From: Christoph Hellwig @ 2022-06-10  8:07 UTC (permalink / raw)
  To: Shinichiro Kawasaki; +Cc: linux-block, linux-nvme, linux-scsi

On Thu, Jun 09, 2022 at 11:53:30PM +0000, Shinichiro Kawasaki wrote:
> Failure descriptiion
> ====================
> #1: block/002: Failed 3 times with 3 trials.
>     Known issue. It is suggested to remove this test case [1].
>     [1] https://lore.kernel.org/linux-block/20220530134548.3108185-3-hch@lst.de/

It's a little more complicated than that.  The patch mentioned there
isn't actually in 5.19-rc yet.  But even the current code doesn't remove
synchronously, so it could happen (although I don't see it).

I'll send a patch to remove this particular check, the test case itself
can mostly remain.

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-06-09 23:53 blktests failures with v5.19-rc1 Shinichiro Kawasaki
  2022-06-10  8:07 ` Christoph Hellwig
@ 2022-06-10  9:22 ` Chaitanya Kulkarni
  2022-06-10  9:32   ` Chaitanya Kulkarni
  1 sibling, 1 reply; 23+ messages in thread
From: Chaitanya Kulkarni @ 2022-06-10  9:22 UTC (permalink / raw)
  To: Shinichiro Kawasaki, linux-block, linux-nvme, linux-scsi

Thanks a lot for running tests...

> #3: nvme/002: Failed 3 times with 3 trials.
> 
>      runtime    ...  85.697s
>      --- tests/nvme/002.out      2022-06-02 10:18:53.538739780 +0900
>      +++ /home/shin/kts/kernel-test-suite/src/blktests/results/nodev/nvme/002.out.bad    2022-06-09 09:51:45.714027241 +0900
>      @@ -1,3003 +1,3006 @@
>       Running nvme/002
>      -Discovery Log Number of Records 1000, Generation counter X
>      +Discovery Log Number of Records 1001, Generation counter X
>       =====Discovery Log Entry 0======
>       trtype:  loop
>      -subnqn:  blktests-subsystem-0
>      +subnqn:  nqn.2014-08.org.nvmexpress.discovery
>      ...

This needs a fix in the testcase, I'll send it shortly..
I guess similar fix has been posted not sure...

> 
> #4: nvme/016: Failed 3 times with 3 trials.
> 
>      runtime  36.240s  ...  35.984s
>      --- tests/nvme/016.out      2022-06-02 10:18:53.541739780 +0900
>      +++ /home/shin/kts/kernel-test-suite/src/blktests/results/nodev/nvme/016.out.bad    2022-06-09 10:06:11.797004672 +0900
>      @@ -1,6 +1,9 @@
>       Running nvme/016
>      -Discovery Log Number of Records 1, Generation counter X
>      +Discovery Log Number of Records 2, Generation counter X
>       =====Discovery Log Entry 0======
>       trtype:  loop
>      +subnqn:  nqn.2014-08.org.nvmexpress.discovery
>      +=====Discovery Log Entry 1======
>      ...
> 

same as above...

> #5: nvme/017: Failed 3 times with 3 trials.
> 
>      runtime  43.724s  ...  42.912s
>      --- tests/nvme/017.out      2022-06-02 10:18:53.541739780 +0900
>      +++ /home/shin/kts/kernel-test-suite/src/blktests/results/nodev/nvme/017.out.bad    2022-06-09 10:09:18.016394996 +0900
>      @@ -1,6 +1,9 @@
>       Running nvme/017
>      -Discovery Log Number of Records 1, Generation counter X
>      +Discovery Log Number of Records 2, Generation counter X
>       =====Discovery Log Entry 0======
>       trtype:  loop
>      +subnqn:  nqn.2014-08.org.nvmexpress.discovery
>      +=====Discovery Log Entry 1======
>      ...
> 

same above ...

> #6: nvme/032: Failed at the first run after system reboot.
>                Used QEMU NVME device as TEST_DEV.
> 
>      runtime    ...  8.458s
>      something found in dmesg:
>      [ 1589.976481] run blktests nvme/032 at 2022-06-09 10:57:20
> 
>      [ 1597.221547] ======================================================
>      [ 1597.221549] WARNING: possible circular locking dependency detected
>      [ 1597.221551] 5.19.0-rc1 #1 Not tainted
>      [ 1597.221554] ------------------------------------------------------
>      [ 1597.221554] check/970 is trying to acquire lock:
>      [ 1597.221556] ffff8881026f8cb8 (kn->active#227){++++}-{0:0}, at: kernfs_remove_by_name_ns+0x90/0xe0
>      [ 1597.221580]
>                     but task is already holding lock:
>      ...
> 
> dmesg output:

now this is a real problem we need to look into ..

> [ 1589.976481] run blktests nvme/032 at 2022-06-09 10:57:20
> 
> [ 1597.221547] ======================================================
> [ 1597.221549] WARNING: possible circular locking dependency detected
> [ 1597.221551] 5.19.0-rc1 #1 Not tainted
> [ 1597.221554] ------------------------------------------------------
> [ 1597.221554] check/970 is trying to acquire lock:
> [ 1597.221556] ffff8881026f8cb8 (kn->active#227){++++}-{0:0}, at: kernfs_remove_by_name_ns+0x90/0xe0
> [ 1597.221580]
>                 but task is already holding lock:
> [ 1597.221580] ffffffff889c0668 (pci_rescan_remove_lock){+.+.}-{3:3}, at: pci_stop_and_remove_bus_device_locked+0xe/0x30
> [ 1597.221590]
>                 which lock already depends on the new lock.
> 
> [ 1597.221591]
>                 the existing dependency chain (in reverse order) is:
> [ 1597.221592]
>                 -> #1 (pci_rescan_remove_lock){+.+.}-{3:3}:
> [ 1597.221598]        __mutex_lock+0x14c/0x12b0
> [ 1597.221604]        dev_rescan_store+0x94/0xd0
> [ 1597.221607]        kernfs_fop_write_iter+0x34f/0x520
> [ 1597.221610]        new_sync_write+0x2ca/0x500
> [ 1597.221614]        vfs_write+0x62d/0x980
> [ 1597.221616]        ksys_write+0xe7/0x1b0
> [ 1597.221619]        do_syscall_64+0x37/0x80
> [ 1597.221622]        entry_SYSCALL_64_after_hwframe+0x46/0xb0
> [ 1597.221625]
>                 -> #0 (kn->active#227){++++}-{0:0}:
> [ 1597.221629]        __lock_acquire+0x2875/0x5510
> [ 1597.221634]        lock_acquire+0x194/0x4f0
> [ 1597.221636]        __kernfs_remove+0x6f3/0x910
> [ 1597.221638]        kernfs_remove_by_name_ns+0x90/0xe0
> [ 1597.221641]        remove_files+0x8c/0x1a0
> [ 1597.221644]        sysfs_remove_group+0x77/0x150
> [ 1597.221646]        sysfs_remove_groups+0x4f/0x90
> [ 1597.221649]        device_remove_attrs+0x19e/0x240
> [ 1597.221652]        device_del+0x492/0xb60
> [ 1597.221654]        pci_remove_bus_device+0x12c/0x350
> [ 1597.221656]        pci_stop_and_remove_bus_device_locked+0x1e/0x30
> [ 1597.221659]        remove_store+0xac/0xc0
> [ 1597.221662]        kernfs_fop_write_iter+0x34f/0x520
> [ 1597.221664]        new_sync_write+0x2ca/0x500
> [ 1597.221666]        vfs_write+0x62d/0x980
> [ 1597.221669]        ksys_write+0xe7/0x1b0
> [ 1597.221671]        do_syscall_64+0x37/0x80
> [ 1597.221673]        entry_SYSCALL_64_after_hwframe+0x46/0xb0
> [ 1597.221675]
>                 other info that might help us debug this:
> 
> [ 1597.221676]  Possible unsafe locking scenario:
> 
> [ 1597.221677]        CPU0                    CPU1
> [ 1597.221678]        ----                    ----
> [ 1597.221678]   lock(pci_rescan_remove_lock);
> [ 1597.221680]                                lock(kn->active#227);
> [ 1597.221683]                                lock(pci_rescan_remove_lock);
> [ 1597.221685]   lock(kn->active#227);
> [ 1597.221687]
>                  *** DEADLOCK ***
> 
> [ 1597.221688] 3 locks held by check/970:
> [ 1597.221689]  #0: ffff888110106460 (sb_writers#4){.+.+}-{0:0}, at: ksys_write+0xe7/0x1b0
> [ 1597.221697]  #1: ffff888120f69088 (&of->mutex){+.+.}-{3:3}, at: kernfs_fop_write_iter+0x216/0x520
> [ 1597.221703]  #2: ffffffff889c0668 (pci_rescan_remove_lock){+.+.}-{3:3}, at: pci_stop_and_remove_bus_device_locked+0xe/0x30
> [ 1597.221709]
>                 stack backtrace:
> [ 1597.221714] CPU: 1 PID: 970 Comm: check Not tainted 5.19.0-rc1 #1
> [ 1597.221717] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.0-0-gd239552ce722-prebuilt.qemu.org 04/01/2014
> [ 1597.221723] Call Trace:
> [ 1597.221728]  <TASK>
> [ 1597.221732]  dump_stack_lvl+0x5b/0x74
> [ 1597.221742]  check_noncircular+0x23f/0x2e0
> [ 1597.221745]  ? lock_chain_count+0x20/0x20
> [ 1597.221748]  ? print_circular_bug+0x1e0/0x1e0
> [ 1597.221751]  ? mark_lock+0xee/0x1610
> [ 1597.221754]  ? mark_lock+0xee/0x1610
> [ 1597.221759]  ? lockdep_lock+0xb8/0x1a0
> [ 1597.221762]  ? call_rcu_zapped+0xb0/0xb0
> [ 1597.221766]  __lock_acquire+0x2875/0x5510
> [ 1597.221773]  ? lockdep_hardirqs_on_prepare+0x410/0x410
> [ 1597.221779]  lock_acquire+0x194/0x4f0
> [ 1597.221782]  ? kernfs_remove_by_name_ns+0x90/0xe0
> [ 1597.221786]  ? lock_downgrade+0x6b0/0x6b0
> [ 1597.221791]  ? up_write+0x14d/0x460
> [ 1597.221795]  __kernfs_remove+0x6f3/0x910
> [ 1597.221798]  ? kernfs_remove_by_name_ns+0x90/0xe0
> [ 1597.221803]  ? kernfs_next_descendant_post+0x280/0x280
> [ 1597.221807]  ? lock_is_held_type+0xe3/0x140
> [ 1597.221811]  ? kernfs_name_hash+0x16/0xc0
> [ 1597.221815]  ? kernfs_find_ns+0x1e3/0x330
> [ 1597.221819]  kernfs_remove_by_name_ns+0x90/0xe0
> [ 1597.221822]  remove_files+0x8c/0x1a0
> [ 1597.221826]  sysfs_remove_group+0x77/0x150
> [ 1597.221831]  sysfs_remove_groups+0x4f/0x90
> [ 1597.221835]  device_remove_attrs+0x19e/0x240
> [ 1597.221838]  ? device_remove_file+0x20/0x20
> [ 1597.221842]  device_del+0x492/0xb60
> [ 1597.221846]  ? __device_link_del+0x350/0x350
> [ 1597.221848]  ? kfree+0xc5/0x340
> [ 1597.221856]  pci_remove_bus_device+0x12c/0x350
> [ 1597.221860]  pci_stop_and_remove_bus_device_locked+0x1e/0x30
> [ 1597.221863]  remove_store+0xac/0xc0
> [ 1597.221867]  ? subordinate_bus_number_show+0xa0/0xa0
> [ 1597.221870]  ? sysfs_kf_write+0x3d/0x170
> [ 1597.221874]  kernfs_fop_write_iter+0x34f/0x520
> [ 1597.221881]  new_sync_write+0x2ca/0x500
> [ 1597.221885]  ? new_sync_read+0x500/0x500
> [ 1597.221888]  ? perf_callchain_user+0x7c0/0xaa0
> [ 1597.221893]  ? lock_downgrade+0x6b0/0x6b0
> [ 1597.221896]  ? inode_security+0x54/0xf0
> [ 1597.221903]  ? lock_is_held_type+0xe3/0x140
> [ 1597.221909]  vfs_write+0x62d/0x980
> [ 1597.221913]  ksys_write+0xe7/0x1b0
> [ 1597.221916]  ? __ia32_sys_read+0xa0/0xa0
> [ 1597.221919]  ? syscall_enter_from_user_mode+0x20/0x70
> [ 1597.221925]  do_syscall_64+0x37/0x80
> [ 1597.221928]  entry_SYSCALL_64_after_hwframe+0x46/0xb0
> [ 1597.221931] RIP: 0033:0x7f5608901c17
> [ 1597.221939] Code: 0f 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b7 0f 1f 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 51 c3 48 83 ec 28 48 89 54 24 18 48 89 74 24
> [ 1597.221942] RSP: 002b:00007fff89480c08 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
> [ 1597.221945] RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007f5608901c17
> [ 1597.221948] RDX: 0000000000000002 RSI: 000055572288f080 RDI: 0000000000000001
> [ 1597.221949] RBP: 000055572288f080 R08: 0000000000000000 R09: 0000000000000073
> [ 1597.221951] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000002
> [ 1597.221953] R13: 00007f56089f8780 R14: 0000000000000002 R15: 00007f56089f39e0
> [ 1597.221960]  </TASK>
> [ 1597.227490] pci 0000:00:09.0: [1b36:0010] type 00 class 0x010802
> [ 1597.230489] pci 0000:00:09.0: reg 0x10: [mem 0xfebc4000-0xfebc7fff 64bit]
> [ 1597.278136] pci 0000:00:09.0: BAR 0: assigned [mem 0x640000000-0x640003fff 64bit]
> [ 1597.283549] nvme nvme5: pci function 0000:00:09.0
> [ 1598.372141] nvme nvme5: 10/0/0 default/read/poll queues
> [ 1598.375349] nvme nvme5: Ignoring bogus Namespace Identifiers
> [ 1618.928153] run blktests nvme/032 at 2022-06-09 10:57:49
> [ 1625.557584] pci 0000:00:09.0: [1b36:0010] type 00 class 0x010802
> [ 1625.558348] pci 0000:00:09.0: reg 0x10: [mem 0x640000000-0x640003fff 64bit]
> [ 1625.577856] pci 0000:00:09.0: BAR 0: assigned [mem 0x640000000-0x640003fff 64bit]
> [ 1625.581168] nvme nvme5: pci function 0000:00:09.0
> [ 1626.695897] nvme nvme5: 10/0/0 default/read/poll queues
> [ 1626.701014] nvme nvme5: Ignoring bogus Namespace Identifiers
> 

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-06-10  9:22 ` Chaitanya Kulkarni
@ 2022-06-10  9:32   ` Chaitanya Kulkarni
  2022-06-10 12:25     ` Shinichiro Kawasaki
  0 siblings, 1 reply; 23+ messages in thread
From: Chaitanya Kulkarni @ 2022-06-10  9:32 UTC (permalink / raw)
  To: Shinichiro Kawasaki; +Cc: linux-block, linux-nvme, linux-scsi

Shinichiro,

> 
>> #6: nvme/032: Failed at the first run after system reboot.
>>                 Used QEMU NVME device as TEST_DEV.
>>

ofcourse we need to fix this issue but can you also
try it with the real H/W ?

>>       runtime    ...  8.458s
>>       something found in dmesg:
>>       [ 1589.976481] run blktests nvme/032 at 2022-06-09 10:57:20
>>
>>       [ 1597.221547] ======================================================
>>       [ 1597.221549] WARNING: possible circular locking dependency detected
>>       [ 1597.221551] 5.19.0-rc1 #1 Not tainted
>>       [ 1597.221554] ------------------------------------------------------
>>       [ 1597.221554] check/970 is trying to acquire lock:
>>       [ 1597.221556] ffff8881026f8cb8 (kn->active#227){++++}-{0:0}, at: kernfs_remove_by_name_ns+0x90/0xe0
>>       [ 1597.221580]
>>                      but task is already holding lock:
>>       ...
>>


-ck



^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-06-10  9:32   ` Chaitanya Kulkarni
@ 2022-06-10 12:25     ` Shinichiro Kawasaki
  2022-06-10 13:15       ` Yi Zhang
  2022-06-10 14:47       ` Keith Busch
  0 siblings, 2 replies; 23+ messages in thread
From: Shinichiro Kawasaki @ 2022-06-10 12:25 UTC (permalink / raw)
  To: Chaitanya Kulkarni; +Cc: linux-block, linux-nvme, linux-scsi

On Jun 10, 2022 / 09:32, Chaitanya Kulkarni wrote:
> Shinichiro,
> 
> > 
> >> #6: nvme/032: Failed at the first run after system reboot.
> >>                 Used QEMU NVME device as TEST_DEV.
> >>
> 
> ofcourse we need to fix this issue but can you also
> try it with the real H/W ?

Hi Chaitanya, thank you for looking into the failures. I have just run the test
case nvme/032 with real NVME device and observed the exactly same symptom as
QEMU NVME device.

FYI, here I quote the kernel WARNING with the real HW.

[  170.567809] run blktests nvme/032 at 2022-06-10 21:19:03
[  175.771062] nvme nvme0: 8/0/0 default/read/poll queues

[  176.017635] ======================================================
[  176.017637] WARNING: possible circular locking dependency detected
[  176.017639] 5.19.0-rc1+ #1 Not tainted
[  176.017643] ------------------------------------------------------
[  176.017645] check/1147 is trying to acquire lock:
[  176.017651] ffff888107010cb8 (kn->active#256){++++}-{0:0}, at: kernfs_remove_by_name_ns+0x90/0xe0
[  176.017683] 
               but task is already holding lock:
[  176.017685] ffffffff859bbcc8 (pci_rescan_remove_lock){+.+.}-{3:3}, at: pci_stop_and_remove_bus_device_locked+0xe/0x30
[  176.017701] 
               which lock already depends on the new lock.

[  176.017702] 
               the existing dependency chain (in reverse order) is:
[  176.017704] 
               -> #1 (pci_rescan_remove_lock){+.+.}-{3:3}:
[  176.017712]        __mutex_lock+0x14c/0x12b0
[  176.017720]        dev_rescan_store+0x93/0xd0
[  176.017727]        kernfs_fop_write_iter+0x351/0x520
[  176.017732]        new_sync_write+0x2cd/0x500
[  176.017737]        vfs_write+0x62c/0x980
[  176.017742]        ksys_write+0xe7/0x1a0
[  176.017746]        do_syscall_64+0x3a/0x80
[  176.017755]        entry_SYSCALL_64_after_hwframe+0x46/0xb0
[  176.017762] 
               -> #0 (kn->active#256){++++}-{0:0}:
[  176.017770]        __lock_acquire+0x2874/0x5510
[  176.017778]        lock_acquire+0x194/0x4f0
[  176.017782]        __kernfs_remove+0x6f2/0x910
[  176.017786]        kernfs_remove_by_name_ns+0x90/0xe0
[  176.017791]        remove_files+0x8c/0x1a0
[  176.017797]        sysfs_remove_group+0x77/0x150
[  176.017802]        sysfs_remove_groups+0x4f/0x90
[  176.017807]        device_remove_attrs+0x19e/0x240
[  176.017812]        device_del+0x492/0xb60
[  176.017816]        pci_remove_bus_device+0x12c/0x350
[  176.017821]        pci_stop_and_remove_bus_device_locked+0x1e/0x30
[  176.017826]        remove_store+0xab/0xc0
[  176.017831]        kernfs_fop_write_iter+0x351/0x520
[  176.017836]        new_sync_write+0x2cd/0x500
[  176.017839]        vfs_write+0x62c/0x980
[  176.017844]        ksys_write+0xe7/0x1a0
[  176.017848]        do_syscall_64+0x3a/0x80
[  176.017854]        entry_SYSCALL_64_after_hwframe+0x46/0xb0
[  176.017861] 
               other info that might help us debug this:

[  176.017862]  Possible unsafe locking scenario:

[  176.017864]        CPU0                    CPU1
[  176.017865]        ----                    ----
[  176.017866]   lock(pci_rescan_remove_lock);
[  176.017870]                                lock(kn->active#256);
[  176.017875]                                lock(pci_rescan_remove_lock);
[  176.017879]   lock(kn->active#256);
[  176.017883] 
                *** DEADLOCK ***

[  176.017884] 3 locks held by check/1147:
[  176.017888]  #0: ffff888119ad8460 (sb_writers#3){.+.+}-{0:0}, at: ksys_write+0xe7/0x1a0
[  176.017902]  #1: ffff8881241b1888 (&of->mutex){+.+.}-{3:3}, at: kernfs_fop_write_iter+0x215/0x520
[  176.017914]  #2: ffffffff859bbcc8 (pci_rescan_remove_lock){+.+.}-{3:3}, at: pci_stop_and_remove_bus_device_locked+0xe/0x30
[  176.017927] 
               stack backtrace:
[  176.017929] CPU: 7 PID: 1147 Comm: check Not tainted 5.19.0-rc1+ #1
[  176.017935] Hardware name: Supermicro Super Server/X10SRL-F, BIOS 3.2 11/22/2019
[  176.017938] Call Trace:
[  176.017941]  <TASK>
[  176.017945]  dump_stack_lvl+0x5b/0x73
[  176.017953]  check_noncircular+0x23e/0x2e0
[  176.017959]  ? lock_chain_count+0x20/0x20
[  176.017966]  ? print_circular_bug+0x1e0/0x1e0
[  176.017973]  ? mark_lock+0xee/0x1600
[  176.017983]  ? lockdep_lock+0xb8/0x1a0
[  176.017989]  ? call_rcu_zapped+0xb0/0xb0
[  176.017997]  __lock_acquire+0x2874/0x5510
[  176.018012]  ? lockdep_hardirqs_on_prepare+0x410/0x410
[  176.018023]  lock_acquire+0x194/0x4f0
[  176.018029]  ? kernfs_remove_by_name_ns+0x90/0xe0
[  176.018037]  ? lock_downgrade+0x6b0/0x6b0
[  176.018048]  ? up_write+0x14d/0x460
[  176.018055]  __kernfs_remove+0x6f2/0x910
[  176.018060]  ? kernfs_remove_by_name_ns+0x90/0xe0
[  176.018071]  ? kernfs_next_descendant_post+0x280/0x280
[  176.018078]  ? lock_is_held_type+0xe3/0x140
[  176.018085]  ? kernfs_name_hash+0x16/0xc0
[  176.018092]  ? kernfs_find_ns+0x1e3/0x320
[  176.018100]  kernfs_remove_by_name_ns+0x90/0xe0
[  176.018107]  remove_files+0x8c/0x1a0
[  176.018115]  sysfs_remove_group+0x77/0x150
[  176.018123]  sysfs_remove_groups+0x4f/0x90
[  176.018131]  device_remove_attrs+0x19e/0x240
[  176.018137]  ? device_remove_file+0x20/0x20
[  176.018146]  device_del+0x492/0xb60
[  176.018154]  ? __device_link_del+0x350/0x350
[  176.018159]  ? kfree+0xc5/0x340
[  176.018171]  pci_remove_bus_device+0x12c/0x350
[  176.018179]  pci_stop_and_remove_bus_device_locked+0x1e/0x30
[  176.018186]  remove_store+0xab/0xc0
[  176.018192]  ? subordinate_bus_number_show+0xa0/0xa0
[  176.018199]  ? sysfs_kf_write+0x3d/0x170
[  176.018207]  kernfs_fop_write_iter+0x351/0x520
[  176.018216]  new_sync_write+0x2cd/0x500
[  176.018223]  ? new_sync_read+0x500/0x500
[  176.018230]  ? perf_callchain_user+0x810/0xa90
[  176.018238]  ? lock_downgrade+0x6b0/0x6b0
[  176.018244]  ? inode_security+0x54/0xf0
[  176.018254]  ? lock_is_held_type+0xe3/0x140
[  176.018264]  vfs_write+0x62c/0x980
[  176.018273]  ksys_write+0xe7/0x1a0
[  176.018279]  ? __ia32_sys_read+0xa0/0xa0
[  176.018285]  ? syscall_enter_from_user_mode+0x20/0x70
[  176.018294]  do_syscall_64+0x3a/0x80
[  176.018303]  entry_SYSCALL_64_after_hwframe+0x46/0xb0
[  176.018310] RIP: 0033:0x7fd59a901c17
[  176.018317] Code: 0f 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b7 0f 1f 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 51 c3 48 83 ec 28 48 89 54 24 18 48 89 74 24
[  176.018322] RSP: 002b:00007fffe29bbe98 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[  176.018328] RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007fd59a901c17
[  176.018333] RDX: 0000000000000002 RSI: 0000555e68a93c20 RDI: 0000000000000001
[  176.018336] RBP: 0000555e68a93c20 R08: 0000000000000000 R09: 0000000000000073
[  176.018339] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000002
[  176.018342] R13: 00007fd59a9f8780 R14: 0000000000000002 R15: 00007fd59a9f39e0
[  176.018356]  </TASK>
[  176.057966] pci 0000:04:00.0: [15b7:5002] type 00 class 0x010802
[  176.058006] pci 0000:04:00.0: reg 0x10: [mem 0xfb600000-0xfb603fff 64bit]
[  176.058059] pci 0000:04:00.0: reg 0x20: [mem 0xfb604000-0xfb6040ff 64bit]
[  176.060129] pci 0000:04:00.0: BAR 0: assigned [mem 0xfb600000-0xfb603fff 64bit]
[  176.060152] pci 0000:04:00.0: BAR 4: assigned [mem 0xfb604000-0xfb6040ff 64bit]
[  176.061638] nvme nvme0: pci function 0000:04:00.0
[  176.074114] nvme nvme0: 8/0/0 default/read/poll queues

-- 
Shin'ichiro Kawasaki

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-06-10 12:25     ` Shinichiro Kawasaki
@ 2022-06-10 13:15       ` Yi Zhang
  2022-06-10 14:47       ` Keith Busch
  1 sibling, 0 replies; 23+ messages in thread
From: Yi Zhang @ 2022-06-10 13:15 UTC (permalink / raw)
  To: Shinichiro Kawasaki
  Cc: Chaitanya Kulkarni, linux-block, linux-nvme, linux-scsi

On Fri, Jun 10, 2022 at 8:26 PM Shinichiro Kawasaki
<shinichiro.kawasaki@wdc.com> wrote:
>
> On Jun 10, 2022 / 09:32, Chaitanya Kulkarni wrote:
> > Shinichiro,
> >
> > >
> > >> #6: nvme/032: Failed at the first run after system reboot.
> > >>                 Used QEMU NVME device as TEST_DEV.
> > >>
> >
> > ofcourse we need to fix this issue but can you also
> > try it with the real H/W ?
>
> Hi Chaitanya, thank you for looking into the failures. I have just run the test
> case nvme/032 with real NVME device and observed the exactly same symptom as
> QEMU NVME device.
>
> FYI, here I quote the kernel WARNING with the real HW.

I also reproduced this issue recently with NVMe disk:

[  702.253121] run blktests nvme/032 at 2022-06-07 02:52:26
[  707.422212] pcieport 0000:40:03.1: bridge window [io
0x1000-0x0fff] to [bus 42] add_size 1000
[  707.422266] pcieport 0000:40:03.1: BAR 13: no space for [io  size 0x1000]
[  707.422271] pcieport 0000:40:03.1: BAR 13: failed to assign [io  size 0x1000]
[  707.422326] pcieport 0000:40:03.1: BAR 13: no space for [io  size 0x1000]
[  707.422328] pcieport 0000:40:03.1: BAR 13: failed to assign [io  size 0x1000]
[  708.164329] run blktests nvme/032 at 2022-06-07 02:52:32
[  713.565934] nvme nvme1: Shutdown timeout set to 16 seconds
[  713.675800] nvme nvme1: 16/0/0 default/read/poll queues

[  714.661347] ======================================================
[  714.661349] WARNING: possible circular locking dependency detected
[  714.661351] 5.19.0-rc1+ #1 Not tainted
[  714.661355] ------------------------------------------------------
[  714.661356] check/2028 is trying to acquire lock:
[  714.661359] ffff888106c270e8 (kn->active#378){++++}-{0:0}, at:
kernfs_remove_by_name_ns+0x96/0xe0
[  714.661379]
               but task is already holding lock:
[  714.661380] ffffffff89c6f010 (pci_rescan_remove_lock){+.+.}-{3:3},
at: pci_stop_and_remove_bus_device_locked+0xe/0x30
[  714.661392]
               which lock already depends on the new lock.

[  714.661393]
               the existing dependency chain (in reverse order) is:
[  714.661395]
               -> #1 (pci_rescan_remove_lock){+.+.}-{3:3}:
[  714.661402]        lock_acquire+0x1d2/0x600
[  714.661407]        __mutex_lock+0x14c/0x2350
[  714.661413]        dev_rescan_store+0xb1/0xf0
[  714.661417]        kernfs_fop_write_iter+0x2d3/0x490
[  714.661422]        new_sync_write+0x33d/0x550
[  714.661427]        vfs_write+0x617/0x910
[  714.661431]        ksys_write+0xf1/0x1c0
[  714.661435]        do_syscall_64+0x3a/0x80
[  714.661440]        entry_SYSCALL_64_after_hwframe+0x46/0xb0
[  714.661444]
               -> #0 (kn->active#378){++++}-{0:0}:
[  714.661451]        check_prevs_add+0x3fd/0x2960
[  714.661455]        __lock_acquire+0x2c87/0x3f40
[  714.661459]        lock_acquire+0x1d2/0x600
[  714.661462]        __kernfs_remove+0x68f/0x880
[  714.661466]        kernfs_remove_by_name_ns+0x96/0xe0
[  714.661470]        remove_files.isra.1+0x6c/0x170
[  714.661474]        sysfs_remove_group+0x9b/0x170
[  714.661478]        sysfs_remove_groups+0x4f/0x90
[  714.661482]        device_remove_attrs+0x1ae/0x260
[  714.661488]        device_del+0x542/0xd10
[  714.661491]        pci_remove_bus_device+0x132/0x350
[  714.661494]        pci_stop_and_remove_bus_device_locked+0x1e/0x30
[  714.661499]        remove_store+0xca/0xe0
[  714.661503]        kernfs_fop_write_iter+0x2d3/0x490
[  714.661507]        new_sync_write+0x33d/0x550
[  714.661510]        vfs_write+0x617/0x910
[  714.661514]        ksys_write+0xf1/0x1c0
[  714.661518]        do_syscall_64+0x3a/0x80
[  714.661522]        entry_SYSCALL_64_after_hwframe+0x46/0xb0
[  714.661526]
               other info that might help us debug this:

[  714.661528]  Possible unsafe locking scenario:

[  714.661529]        CPU0                    CPU1
[  714.661530]        ----                    ----
[  714.661531]   lock(pci_rescan_remove_lock);
[  714.661534]                                lock(kn->active#378);
[  714.661538]                                lock(pci_rescan_remove_lock);
[  714.661541]   lock(kn->active#378);
[  714.661544]
                *** DEADLOCK ***

[  714.661545] 3 locks held by check/2028:
[  714.661548]  #0: ffff888268b1c470 (sb_writers#4){.+.+}-{0:0}, at:
ksys_write+0xf1/0x1c0
[  714.661559]  #1: ffff88826b9b6490 (&of->mutex){+.+.}-{3:3}, at:
kernfs_fop_write_iter+0x220/0x490
[  714.661567]  #2: ffffffff89c6f010
(pci_rescan_remove_lock){+.+.}-{3:3}, at:
pci_stop_and_remove_bus_device_locked+0xe/0x30
[  714.661577]
               stack backtrace:
[  714.661579] CPU: 10 PID: 2028 Comm: check Kdump: loaded Not tainted
5.19.0-rc1+ #1
[  714.661584] Hardware name: Dell Inc. PowerEdge R6515/07PXPY, BIOS
2.3.6 07/06/2021
[  714.661587] Call Trace:
[  714.661589]  <TASK>
[  714.661592]  dump_stack_lvl+0x44/0x57
[  714.661600]  check_noncircular+0x280/0x320
[  714.661606]  ? print_circular_bug.isra.44+0x430/0x430
[  714.661613]  ? mark_lock.part.49+0xa44/0x2370
[  714.661621]  ? lock_chain_count+0x20/0x20
[  714.661629]  check_prevs_add+0x3fd/0x2960
[  714.661636]  ? sched_clock_cpu+0x69/0x2e0
[  714.661641]  ? mark_lock.part.49+0x107/0x2370
[  714.661646]  ? check_irq_usage+0xe30/0xe30
[  714.661652]  ? sched_clock_cpu+0x69/0x2e0
[  714.661655]  ? sched_clock_cpu+0x69/0x2e0
[  714.661660]  __lock_acquire+0x2c87/0x3f40
[  714.661668]  ? lockdep_hardirqs_on_prepare+0x400/0x400
[  714.661672]  ? rcu_read_lock_sched_held+0xaf/0xe0
[  714.661679]  lock_acquire+0x1d2/0x600
[  714.661682]  ? kernfs_remove_by_name_ns+0x96/0xe0
[  714.661686]  ? rcu_read_lock_sched_held+0xaf/0xe0
[  714.661689]  ? rcu_read_unlock+0x50/0x50
[  714.661692]  ? rcu_read_lock_bh_held+0xc0/0xc0
[  714.661697]  ? up_write+0x15c/0x490
[  714.661702]  __kernfs_remove+0x68f/0x880
[  714.661704]  ? kernfs_remove_by_name_ns+0x96/0xe0
[  714.661711]  ? kernfs_fop_readdir+0x8c0/0x8c0
[  714.661714]  ? lock_is_held_type+0xd9/0x130
[  714.661718]  ? kernfs_name_hash+0x18/0xc0
[  714.661724]  kernfs_remove_by_name_ns+0x96/0xe0
[  714.661728]  remove_files.isra.1+0x6c/0x170
[  714.661733]  sysfs_remove_group+0x9b/0x170
[  714.661737]  sysfs_remove_groups+0x4f/0x90
[  714.661742]  device_remove_attrs+0x1ae/0x260
[  714.661746]  ? device_remove_file+0x20/0x20
[  714.661749]  ? up_write+0x15c/0x490
[  714.661755]  device_del+0x542/0xd10
[  714.661759]  ? __device_link_del+0x340/0x340
[  714.661765]  pci_remove_bus_device+0x132/0x350
[  714.661770]  pci_stop_and_remove_bus_device_locked+0x1e/0x30
[  714.661774]  remove_store+0xca/0xe0
[  714.661777]  ? subordinate_bus_number_show+0xc0/0xc0
[  714.661783]  ? sysfs_kf_write+0x3b/0x180
[  714.661787]  kernfs_fop_write_iter+0x2d3/0x490
[  714.661793]  new_sync_write+0x33d/0x550
[  714.661798]  ? new_sync_read+0x540/0x540
[  714.661806]  ? lock_is_held_type+0xd9/0x130
[  714.661813]  ? rcu_read_lock_held+0xc0/0xc0
[  714.661820]  vfs_write+0x617/0x910
[  714.661825]  ksys_write+0xf1/0x1c0
[  714.661829]  ? __ia32_sys_read+0xb0/0xb0
[  714.661832]  ? syscall_trace_enter.isra.15+0x175/0x250
[  714.661840]  do_syscall_64+0x3a/0x80
[  714.661844]  entry_SYSCALL_64_after_hwframe+0x46/0xb0
[  714.661847] RIP: 0033:0x7f0b88120868
[  714.661852] Code: 89 02 48 c7 c0 ff ff ff ff eb b3 0f 1f 80 00 00
00 00 f3 0f 1e fa 48 8d 05 35 4d 2a 00 8b 00 85 c0 75 17 b8 01 00 00
00 0f 05 <48> 3d 00 f0 ff ff 77 58 c3 0f 1f 80 00 00 00 00 41 54 49 89
d4 55
[  714.661855] RSP: 002b:00007fff0fceca28 EFLAGS: 00000246 ORIG_RAX:
0000000000000001
[  714.661858] RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007f0b88120868
[  714.661861] RDX: 0000000000000002 RSI: 000056501fc5ec60 RDI: 0000000000000001
[  714.661862] RBP: 000056501fc5ec60 R08: 000000000000000a R09: 00007f0b88180ac0
[  714.661864] R10: 000000000000000a R11: 0000000000000246 R12: 00007f0b883c16e0
[  714.661866] R13: 0000000000000002 R14: 00007f0b883bc880 R15: 0000000000000002
[  714.661873]  </TASK>
[  714.666060] pci 0000:44:00.0: Removing from iommu group 33
[  714.670580] pci 0000:44:00.0: [1e0f:0007] type 00 class 0x010802
[  714.670613] pci 0000:44:00.0: reg 0x10: [mem 0xa4900000-0xa4907fff 64bit]
[  714.776556] pci 0000:44:00.0: 31.504 Gb/s available PCIe bandwidth,
limited by 8.0 GT/s PCIe x4 link at 0000:40:03.3 (capable of 63.012
Gb/s with 16.0 GT/s PCIe x4 link)
[  714.802476] pci 0000:44:00.0: Adding to iommu group 33
[  714.802862] pcieport 0000:40:03.1: bridge window [io
0x1000-0x0fff] to [bus 42] add_size 1000
[  714.802900] pcieport 0000:40:03.1: BAR 13: no space for [io  size 0x1000]
[  714.802904] pcieport 0000:40:03.1: BAR 13: failed to assign [io  size 0x1000]
[  714.802939] pcieport 0000:40:03.1: BAR 13: no space for [io  size 0x1000]
[  714.802942] pcieport 0000:40:03.1: BAR 13: failed to assign [io  size 0x1000]
[  714.802977] pci 0000:44:00.0: BAR 0: assigned [mem
0xa4900000-0xa4907fff 64bit]
[  714.814760] nvme nvme1: pci function 0000:44:00.0
[  715.092766] nvme nvme1: Shutdown timeout set to 16 seconds
[  715.192803] nvme nvme1: 16/0/0 default/read/poll queues
[  715.238378]  nvme1n1: p1
[  722.202125] run blktests nvme/032 at 2022-06-07 02:52:46
[  727.840536] nvme nvme2: 16/0/0 default/read/poll queues
[  729.262229] pci 0000:45:00.0: Removing from iommu group 34
[  729.287030] pci 0000:45:00.0: [8086:0b60] type 00 class 0x010802
[  729.287059] pci 0000:45:00.0: reg 0x10: [mem 0xa4800000-0xa4803fff 64bit]
[  729.501326] pci 0000:45:00.0: 31.504 Gb/s available PCIe bandwidth,
limited by 8.0 GT/s PCIe x4 link at 0000:40:03.4 (capable of 63.012
Gb/s with 16.0 GT/s PCIe x4 link)
[  729.638560] pci 0000:45:00.0: Adding to iommu group 34
[  729.639120] pcieport 0000:40:03.1: bridge window [io
0x1000-0x0fff] to [bus 42] add_size 1000
[  729.639163] pcieport 0000:40:03.1: BAR 13: no space for [io  size 0x1000]
[  729.639167] pcieport 0000:40:03.1: BAR 13: failed to assign [io  size 0x1000]
[  729.639217] pcieport 0000:40:03.1: BAR 13: no space for [io  size 0x1000]
[  729.639219] pcieport 0000:40:03.1: BAR 13: failed to assign [io  size 0x1000]
[  729.639942] pci 0000:45:00.0: BAR 0: assigned [mem
0xa4800000-0xa4803fff 64bit]
[  729.746063] nvme nvme2: pci function 0000:45:00.0
[  729.839525] nvme nvme2: 16/0/0 default/read/poll queues
[  729.883784]  nvme2n1: p1

>
> [  170.567809] run blktests nvme/032 at 2022-06-10 21:19:03
> [  175.771062] nvme nvme0: 8/0/0 default/read/poll queues
>
> [  176.017635] ======================================================
> [  176.017637] WARNING: possible circular locking dependency detected
> [  176.017639] 5.19.0-rc1+ #1 Not tainted
> [  176.017643] ------------------------------------------------------
> [  176.017645] check/1147 is trying to acquire lock:
> [  176.017651] ffff888107010cb8 (kn->active#256){++++}-{0:0}, at: kernfs_remove_by_name_ns+0x90/0xe0
> [  176.017683]
>                but task is already holding lock:
> [  176.017685] ffffffff859bbcc8 (pci_rescan_remove_lock){+.+.}-{3:3}, at: pci_stop_and_remove_bus_device_locked+0xe/0x30
> [  176.017701]
>                which lock already depends on the new lock.
>
> [  176.017702]
>                the existing dependency chain (in reverse order) is:
> [  176.017704]
>                -> #1 (pci_rescan_remove_lock){+.+.}-{3:3}:
> [  176.017712]        __mutex_lock+0x14c/0x12b0
> [  176.017720]        dev_rescan_store+0x93/0xd0
> [  176.017727]        kernfs_fop_write_iter+0x351/0x520
> [  176.017732]        new_sync_write+0x2cd/0x500
> [  176.017737]        vfs_write+0x62c/0x980
> [  176.017742]        ksys_write+0xe7/0x1a0
> [  176.017746]        do_syscall_64+0x3a/0x80
> [  176.017755]        entry_SYSCALL_64_after_hwframe+0x46/0xb0
> [  176.017762]
>                -> #0 (kn->active#256){++++}-{0:0}:
> [  176.017770]        __lock_acquire+0x2874/0x5510
> [  176.017778]        lock_acquire+0x194/0x4f0
> [  176.017782]        __kernfs_remove+0x6f2/0x910
> [  176.017786]        kernfs_remove_by_name_ns+0x90/0xe0
> [  176.017791]        remove_files+0x8c/0x1a0
> [  176.017797]        sysfs_remove_group+0x77/0x150
> [  176.017802]        sysfs_remove_groups+0x4f/0x90
> [  176.017807]        device_remove_attrs+0x19e/0x240
> [  176.017812]        device_del+0x492/0xb60
> [  176.017816]        pci_remove_bus_device+0x12c/0x350
> [  176.017821]        pci_stop_and_remove_bus_device_locked+0x1e/0x30
> [  176.017826]        remove_store+0xab/0xc0
> [  176.017831]        kernfs_fop_write_iter+0x351/0x520
> [  176.017836]        new_sync_write+0x2cd/0x500
> [  176.017839]        vfs_write+0x62c/0x980
> [  176.017844]        ksys_write+0xe7/0x1a0
> [  176.017848]        do_syscall_64+0x3a/0x80
> [  176.017854]        entry_SYSCALL_64_after_hwframe+0x46/0xb0
> [  176.017861]
>                other info that might help us debug this:
>
> [  176.017862]  Possible unsafe locking scenario:
>
> [  176.017864]        CPU0                    CPU1
> [  176.017865]        ----                    ----
> [  176.017866]   lock(pci_rescan_remove_lock);
> [  176.017870]                                lock(kn->active#256);
> [  176.017875]                                lock(pci_rescan_remove_lock);
> [  176.017879]   lock(kn->active#256);
> [  176.017883]
>                 *** DEADLOCK ***
>
> [  176.017884] 3 locks held by check/1147:
> [  176.017888]  #0: ffff888119ad8460 (sb_writers#3){.+.+}-{0:0}, at: ksys_write+0xe7/0x1a0
> [  176.017902]  #1: ffff8881241b1888 (&of->mutex){+.+.}-{3:3}, at: kernfs_fop_write_iter+0x215/0x520
> [  176.017914]  #2: ffffffff859bbcc8 (pci_rescan_remove_lock){+.+.}-{3:3}, at: pci_stop_and_remove_bus_device_locked+0xe/0x30
> [  176.017927]
>                stack backtrace:
> [  176.017929] CPU: 7 PID: 1147 Comm: check Not tainted 5.19.0-rc1+ #1
> [  176.017935] Hardware name: Supermicro Super Server/X10SRL-F, BIOS 3.2 11/22/2019
> [  176.017938] Call Trace:
> [  176.017941]  <TASK>
> [  176.017945]  dump_stack_lvl+0x5b/0x73
> [  176.017953]  check_noncircular+0x23e/0x2e0
> [  176.017959]  ? lock_chain_count+0x20/0x20
> [  176.017966]  ? print_circular_bug+0x1e0/0x1e0
> [  176.017973]  ? mark_lock+0xee/0x1600
> [  176.017983]  ? lockdep_lock+0xb8/0x1a0
> [  176.017989]  ? call_rcu_zapped+0xb0/0xb0
> [  176.017997]  __lock_acquire+0x2874/0x5510
> [  176.018012]  ? lockdep_hardirqs_on_prepare+0x410/0x410
> [  176.018023]  lock_acquire+0x194/0x4f0
> [  176.018029]  ? kernfs_remove_by_name_ns+0x90/0xe0
> [  176.018037]  ? lock_downgrade+0x6b0/0x6b0
> [  176.018048]  ? up_write+0x14d/0x460
> [  176.018055]  __kernfs_remove+0x6f2/0x910
> [  176.018060]  ? kernfs_remove_by_name_ns+0x90/0xe0
> [  176.018071]  ? kernfs_next_descendant_post+0x280/0x280
> [  176.018078]  ? lock_is_held_type+0xe3/0x140
> [  176.018085]  ? kernfs_name_hash+0x16/0xc0
> [  176.018092]  ? kernfs_find_ns+0x1e3/0x320
> [  176.018100]  kernfs_remove_by_name_ns+0x90/0xe0
> [  176.018107]  remove_files+0x8c/0x1a0
> [  176.018115]  sysfs_remove_group+0x77/0x150
> [  176.018123]  sysfs_remove_groups+0x4f/0x90
> [  176.018131]  device_remove_attrs+0x19e/0x240
> [  176.018137]  ? device_remove_file+0x20/0x20
> [  176.018146]  device_del+0x492/0xb60
> [  176.018154]  ? __device_link_del+0x350/0x350
> [  176.018159]  ? kfree+0xc5/0x340
> [  176.018171]  pci_remove_bus_device+0x12c/0x350
> [  176.018179]  pci_stop_and_remove_bus_device_locked+0x1e/0x30
> [  176.018186]  remove_store+0xab/0xc0
> [  176.018192]  ? subordinate_bus_number_show+0xa0/0xa0
> [  176.018199]  ? sysfs_kf_write+0x3d/0x170
> [  176.018207]  kernfs_fop_write_iter+0x351/0x520
> [  176.018216]  new_sync_write+0x2cd/0x500
> [  176.018223]  ? new_sync_read+0x500/0x500
> [  176.018230]  ? perf_callchain_user+0x810/0xa90
> [  176.018238]  ? lock_downgrade+0x6b0/0x6b0
> [  176.018244]  ? inode_security+0x54/0xf0
> [  176.018254]  ? lock_is_held_type+0xe3/0x140
> [  176.018264]  vfs_write+0x62c/0x980
> [  176.018273]  ksys_write+0xe7/0x1a0
> [  176.018279]  ? __ia32_sys_read+0xa0/0xa0
> [  176.018285]  ? syscall_enter_from_user_mode+0x20/0x70
> [  176.018294]  do_syscall_64+0x3a/0x80
> [  176.018303]  entry_SYSCALL_64_after_hwframe+0x46/0xb0
> [  176.018310] RIP: 0033:0x7fd59a901c17
> [  176.018317] Code: 0f 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b7 0f 1f 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 51 c3 48 83 ec 28 48 89 54 24 18 48 89 74 24
> [  176.018322] RSP: 002b:00007fffe29bbe98 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
> [  176.018328] RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007fd59a901c17
> [  176.018333] RDX: 0000000000000002 RSI: 0000555e68a93c20 RDI: 0000000000000001
> [  176.018336] RBP: 0000555e68a93c20 R08: 0000000000000000 R09: 0000000000000073
> [  176.018339] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000002
> [  176.018342] R13: 00007fd59a9f8780 R14: 0000000000000002 R15: 00007fd59a9f39e0
> [  176.018356]  </TASK>
> [  176.057966] pci 0000:04:00.0: [15b7:5002] type 00 class 0x010802
> [  176.058006] pci 0000:04:00.0: reg 0x10: [mem 0xfb600000-0xfb603fff 64bit]
> [  176.058059] pci 0000:04:00.0: reg 0x20: [mem 0xfb604000-0xfb6040ff 64bit]
> [  176.060129] pci 0000:04:00.0: BAR 0: assigned [mem 0xfb600000-0xfb603fff 64bit]
> [  176.060152] pci 0000:04:00.0: BAR 4: assigned [mem 0xfb604000-0xfb6040ff 64bit]
> [  176.061638] nvme nvme0: pci function 0000:04:00.0
> [  176.074114] nvme nvme0: 8/0/0 default/read/poll queues
>
> --
> Shin'ichiro Kawasaki
>


-- 
Best Regards,
  Yi Zhang


^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-06-10 12:25     ` Shinichiro Kawasaki
  2022-06-10 13:15       ` Yi Zhang
@ 2022-06-10 14:47       ` Keith Busch
  2022-06-11  8:34         ` Yi Zhang
  1 sibling, 1 reply; 23+ messages in thread
From: Keith Busch @ 2022-06-10 14:47 UTC (permalink / raw)
  To: Shinichiro Kawasaki
  Cc: Chaitanya Kulkarni, linux-block, linux-nvme, linux-scsi

On Fri, Jun 10, 2022 at 12:25:17PM +0000, Shinichiro Kawasaki wrote:
> On Jun 10, 2022 / 09:32, Chaitanya Kulkarni wrote:
> > >> #6: nvme/032: Failed at the first run after system reboot.
> > >>                 Used QEMU NVME device as TEST_DEV.
> > >>
> > 
> > ofcourse we need to fix this issue but can you also
> > try it with the real H/W ?
> 
> Hi Chaitanya, thank you for looking into the failures. I have just run the test
> case nvme/032 with real NVME device and observed the exactly same symptom as
> QEMU NVME device.

QEMU is perfectly fine for this test. There's no need to bring in "real"
hardware for this.

And I am not even sure this is real. I don't know yet why this is showing up
only now, but this should fix it:

---
diff --git a/drivers/pci/pci-sysfs.c b/drivers/pci/pci-sysfs.c
index fc804e08e3cb..bebd816c11e6 100644
--- a/drivers/pci/pci-sysfs.c
+++ b/drivers/pci/pci-sysfs.c
@@ -476,7 +476,7 @@ static ssize_t dev_rescan_store(struct device *dev,
 	}
 	return count;
 }
-static struct device_attribute dev_attr_dev_rescan = __ATTR(rescan, 0200, NULL,
+static struct device_attribute dev_attr_dev_rescan = __ATTR_IGNORE_LOCKDEP(rescan, 0200, NULL,
 							    dev_rescan_store);
 
 static ssize_t remove_store(struct device *dev, struct device_attribute *attr,
--

^ permalink raw reply related	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-06-10 14:47       ` Keith Busch
@ 2022-06-11  8:34         ` Yi Zhang
  2022-06-14  1:09           ` Shinichiro Kawasaki
  0 siblings, 1 reply; 23+ messages in thread
From: Yi Zhang @ 2022-06-11  8:34 UTC (permalink / raw)
  To: Keith Busch
  Cc: Shinichiro Kawasaki, Chaitanya Kulkarni, linux-block, linux-nvme,
	linux-scsi, mstowe

On Fri, Jun 10, 2022 at 10:49 PM Keith Busch <kbusch@kernel.org> wrote:
>
> On Fri, Jun 10, 2022 at 12:25:17PM +0000, Shinichiro Kawasaki wrote:
> > On Jun 10, 2022 / 09:32, Chaitanya Kulkarni wrote:
> > > >> #6: nvme/032: Failed at the first run after system reboot.
> > > >>                 Used QEMU NVME device as TEST_DEV.
> > > >>
> > >
> > > ofcourse we need to fix this issue but can you also
> > > try it with the real H/W ?
> >
> > Hi Chaitanya, thank you for looking into the failures. I have just run the test
> > case nvme/032 with real NVME device and observed the exactly same symptom as
> > QEMU NVME device.
>
> QEMU is perfectly fine for this test. There's no need to bring in "real"
> hardware for this.
>
> And I am not even sure this is real. I don't know yet why this is showing up
> only now, but this should fix it:

Hi Keith

Confirmed the WARNING issue was fixed with the change, here is the log:

# ./check nvme/032
nvme/032 => nvme0n1 (test nvme pci adapter rescan/reset/remove during
I/O) [passed]
    runtime  5.165s  ...  5.142s
nvme/032 => nvme1n1 (test nvme pci adapter rescan/reset/remove during
I/O) [passed]
    runtime  6.723s  ...  6.635s
nvme/032 => nvme2n1 (test nvme pci adapter rescan/reset/remove during
I/O) [passed]
    runtime  7.708s  ...  7.808s

[  307.477948] run blktests nvme/032 at 2022-06-11 04:27:46
[  312.603452] pcieport 0000:40:03.1: bridge window [io
0x1000-0x0fff] to [bus 42] add_size 1000
[  312.603599] pcieport 0000:40:03.1: BAR 13: no space for [io  size 0x1000]
[  312.603603] pcieport 0000:40:03.1: BAR 13: failed to assign [io  size 0x1000]
[  312.603729] pcieport 0000:40:03.1: BAR 13: no space for [io  size 0x1000]
[  312.603733] pcieport 0000:40:03.1: BAR 13: failed to assign [io  size 0x1000]
[  313.397440] run blktests nvme/032 at 2022-06-11 04:27:51
[  318.732273] nvme nvme1: Shutdown timeout set to 16 seconds
[  318.785945] nvme nvme1: 16/0/0 default/read/poll queues
[  319.268544] pci 0000:44:00.0: Removing from iommu group 33
[  319.326814] pci 0000:44:00.0: [1e0f:0007] type 00 class 0x010802
[  319.326866] pci 0000:44:00.0: reg 0x10: [mem 0xa4900000-0xa4907fff 64bit]
[  319.483234] pci 0000:44:00.0: 31.504 Gb/s available PCIe bandwidth,
limited by 8.0 GT/s PCIe x4 link at 0000:40:03.3 (capable of 63.012
Gb/s with 16.0 GT/s PCIe x4 link)
[  319.531324] pci 0000:44:00.0: Adding to iommu group 33
[  319.547381] pcieport 0000:40:03.1: bridge window [io
0x1000-0x0fff] to [bus 42] add_size 1000
[  319.547448] pcieport 0000:40:03.1: BAR 13: no space for [io  size 0x1000]
[  319.547453] pcieport 0000:40:03.1: BAR 13: failed to assign [io  size 0x1000]
[  319.547547] pcieport 0000:40:03.1: BAR 13: no space for [io  size 0x1000]
[  319.547550] pcieport 0000:40:03.1: BAR 13: failed to assign [io  size 0x1000]
[  319.547607] pci 0000:44:00.0: BAR 0: assigned [mem
0xa4900000-0xa4907fff 64bit]
[  319.556620] nvme nvme1: pci function 0000:44:00.0
[  319.838233] nvme nvme1: Shutdown timeout set to 16 seconds
[  319.911826] nvme nvme1: 16/0/0 default/read/poll queues
[  320.900025] run blktests nvme/032 at 2022-06-11 04:27:59
[  326.311357] nvme nvme2: 16/0/0 default/read/poll queues
[  327.771945] pci 0000:45:00.0: Removing from iommu group 34
[  327.839066] pci 0000:45:00.0: [8086:0b60] type 00 class 0x010802
[  327.839106] pci 0000:45:00.0: reg 0x10: [mem 0xa4800000-0xa4803fff 64bit]
[  328.011204] pci 0000:45:00.0: 31.504 Gb/s available PCIe bandwidth,
limited by 8.0 GT/s PCIe x4 link at 0000:40:03.4 (capable of 63.012
Gb/s with 16.0 GT/s PCIe x4 link)
[  328.058523] pci 0000:45:00.0: Adding to iommu group 34
[  328.072575] pcieport 0000:40:03.1: bridge window [io
0x1000-0x0fff] to [bus 42] add_size 1000
[  328.072628] pcieport 0000:40:03.1: BAR 13: no space for [io  size 0x1000]
[  328.072632] pcieport 0000:40:03.1: BAR 13: failed to assign [io  size 0x1000]
[  328.072685] pcieport 0000:40:03.1: BAR 13: no space for [io  size 0x1000]
[  328.072688] pcieport 0000:40:03.1: BAR 13: failed to assign [io  size 0x1000]
[  328.072741] pci 0000:45:00.0: BAR 0: assigned [mem
0xa4800000-0xa4803fff 64bit]
[  328.079857] nvme nvme2: pci function 0000:45:00.0
[  328.153256] nvme nvme2: 16/0/0 default/read/poll queues
>
> ---
> diff --git a/drivers/pci/pci-sysfs.c b/drivers/pci/pci-sysfs.c
> index fc804e08e3cb..bebd816c11e6 100644
> --- a/drivers/pci/pci-sysfs.c
> +++ b/drivers/pci/pci-sysfs.c
> @@ -476,7 +476,7 @@ static ssize_t dev_rescan_store(struct device *dev,
>         }
>         return count;
>  }
> -static struct device_attribute dev_attr_dev_rescan = __ATTR(rescan, 0200, NULL,
> +static struct device_attribute dev_attr_dev_rescan = __ATTR_IGNORE_LOCKDEP(rescan, 0200, NULL,
>                                                             dev_rescan_store);
>
>  static ssize_t remove_store(struct device *dev, struct device_attribute *attr,
> --
>


-- 
Best Regards,
  Yi Zhang


^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-06-11  8:34         ` Yi Zhang
@ 2022-06-14  1:09           ` Shinichiro Kawasaki
  2022-06-14  2:23             ` Keith Busch
  0 siblings, 1 reply; 23+ messages in thread
From: Shinichiro Kawasaki @ 2022-06-14  1:09 UTC (permalink / raw)
  To: Yi Zhang
  Cc: Keith Busch, Chaitanya Kulkarni, linux-block, linux-nvme,
	linux-scsi, mstowe, linux-pci

(CC+: linux-pci)

On Jun 11, 2022 / 16:34, Yi Zhang wrote:
> On Fri, Jun 10, 2022 at 10:49 PM Keith Busch <kbusch@kernel.org> wrote:
> >
> > On Fri, Jun 10, 2022 at 12:25:17PM +0000, Shinichiro Kawasaki wrote:
> > > On Jun 10, 2022 / 09:32, Chaitanya Kulkarni wrote:
> > > > >> #6: nvme/032: Failed at the first run after system reboot.
> > > > >>                 Used QEMU NVME device as TEST_DEV.
> > > > >>
> > > >
> > > > ofcourse we need to fix this issue but can you also
> > > > try it with the real H/W ?
> > >
> > > Hi Chaitanya, thank you for looking into the failures. I have just run the test
> > > case nvme/032 with real NVME device and observed the exactly same symptom as
> > > QEMU NVME device.
> >
> > QEMU is perfectly fine for this test. There's no need to bring in "real"
> > hardware for this.
> >
> > And I am not even sure this is real. I don't know yet why this is showing up
> > only now, but this should fix it:
> 
> Hi Keith
> 
> Confirmed the WARNING issue was fixed with the change, here is the log:

Thanks. I also confirmed that Keith's change to add __ATTR_IGNORE_LOCKDEP to
dev_attr_dev_rescan avoids the fix, on v5.19-rc2.

I took a closer look into this issue and found The deadlock WARN can be
recreated with following two commands:

# echo 1 > /sys/bus/pci/devices/0000\:00\:09.0/rescan
# echo 1 > /sys/bus/pci/devices/0000\:00\:09.0/remove

And it can be recreated with PCI devices other than NVME controller, such as
SCSI controller or VGA controller. Then this is not a storage sub-system issue.

I checked function call stacks of the two commands above. As shown below, it
looks like ABBA deadlock possibility is detected and warned.

echo 1 > /sys/bus/pci/devices/*/rescan
  kernfs_fop_write_iter
    kernfs_get_active
      atomic_inc_unless_nagative
      rwsem_acquire_read(&kn->dep_map, 0, 1, _RET_IP) :lock L1 for "rescan" file
    dev_rescan_store
      pci_lock_rescan_remove
        mutex_lock(&pci_rescan_remove_lock)           :lock L2

echo 1 > /sys/bus/pci/devices/*/remove
  kernfs_fop_write_iter
    remove_store
      pci_stop_and_remove_bus_device_locked
        pci_lock_rescan_remove
          mutex_lock(&pci_rescan_remove_lock)         :lock L2
        pci_stop_and_remove_bus_device
	  pci_remove_bus_device
	    device_del
	      device_remove_attrs
		sysfs_remove_attrs
		  sysfs_remove_groups
		    sysfs_remove_group
		      remove_files    .... iterates for pci device sysfs files including "rescan" file?
			kernfs_remove_by_name_ns
			  __kernfs_remove
			    kernfs_drain
			      rwsem_acquire(&kn->dep_map, 0, 0, _RET_IP): lock L1

It looks for me that the deadlock possibility exists for real, even though the
race between rescan operation and remove operation is really rare use case.

I would like to hear comments on the guess above. I take the liberty to CC this
to linux-pci list. Is this an issue to fix?

-- 
Shin'ichiro Kawasaki

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-06-14  1:09           ` Shinichiro Kawasaki
@ 2022-06-14  2:23             ` Keith Busch
  2022-06-14  2:38               ` Chaitanya Kulkarni
  0 siblings, 1 reply; 23+ messages in thread
From: Keith Busch @ 2022-06-14  2:23 UTC (permalink / raw)
  To: Shinichiro Kawasaki
  Cc: Yi Zhang, Chaitanya Kulkarni, linux-block, linux-nvme,
	linux-scsi, mstowe, linux-pci

On Tue, Jun 14, 2022 at 01:09:07AM +0000, Shinichiro Kawasaki wrote:
> (CC+: linux-pci)
> On Jun 11, 2022 / 16:34, Yi Zhang wrote:
> > On Fri, Jun 10, 2022 at 10:49 PM Keith Busch <kbusch@kernel.org> wrote:
> > >
> > > And I am not even sure this is real. I don't know yet why this is showing up
> > > only now, but this should fix it:
> > 
> > Hi Keith
> > 
> > Confirmed the WARNING issue was fixed with the change, here is the log:
> 
> Thanks. I also confirmed that Keith's change to add __ATTR_IGNORE_LOCKDEP to
> dev_attr_dev_rescan avoids the fix, on v5.19-rc2.
> 
> I took a closer look into this issue and found The deadlock WARN can be
> recreated with following two commands:
> 
> # echo 1 > /sys/bus/pci/devices/0000\:00\:09.0/rescan
> # echo 1 > /sys/bus/pci/devices/0000\:00\:09.0/remove
> 
> And it can be recreated with PCI devices other than NVME controller, such as
> SCSI controller or VGA controller. Then this is not a storage sub-system issue.
> 
> I checked function call stacks of the two commands above. As shown below, it
> looks like ABBA deadlock possibility is detected and warned.

Yeah, I was mistaken on this report, so my proposal to suppress the warning is
definitely not right. If I run both 'echo' commands in parallel, I see it
deadlock frequently. I'm not familiar enough with this code to any good ideas
on how to fix, but I agree this is a generic pci issue.

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-06-14  2:23             ` Keith Busch
@ 2022-06-14  2:38               ` Chaitanya Kulkarni
  2022-06-14  4:00                 ` Shinichiro Kawasaki
  0 siblings, 1 reply; 23+ messages in thread
From: Chaitanya Kulkarni @ 2022-06-14  2:38 UTC (permalink / raw)
  To: Shinichiro Kawasaki
  Cc: Yi Zhang, linux-block, Keith Busch, linux-nvme, linux-scsi,
	mstowe, linux-pci

Shinichiro,

On 6/13/22 19:23, Keith Busch wrote:
> On Tue, Jun 14, 2022 at 01:09:07AM +0000, Shinichiro Kawasaki wrote:
>> (CC+: linux-pci)
>> On Jun 11, 2022 / 16:34, Yi Zhang wrote:
>>> On Fri, Jun 10, 2022 at 10:49 PM Keith Busch <kbusch@kernel.org> wrote:
>>>>
>>>> And I am not even sure this is real. I don't know yet why this is showing up
>>>> only now, but this should fix it:
>>>
>>> Hi Keith
>>>
>>> Confirmed the WARNING issue was fixed with the change, here is the log:
>>
>> Thanks. I also confirmed that Keith's change to add __ATTR_IGNORE_LOCKDEP to
>> dev_attr_dev_rescan avoids the fix, on v5.19-rc2.
>>
>> I took a closer look into this issue and found The deadlock WARN can be
>> recreated with following two commands:
>>
>> # echo 1 > /sys/bus/pci/devices/0000\:00\:09.0/rescan
>> # echo 1 > /sys/bus/pci/devices/0000\:00\:09.0/remove
>>
>> And it can be recreated with PCI devices other than NVME controller, such as
>> SCSI controller or VGA controller. Then this is not a storage sub-system issue.
>>
>> I checked function call stacks of the two commands above. As shown below, it
>> looks like ABBA deadlock possibility is detected and warned.
> 
> Yeah, I was mistaken on this report, so my proposal to suppress the warning is
> definitely not right. If I run both 'echo' commands in parallel, I see it
> deadlock frequently. I'm not familiar enough with this code to any good ideas
> on how to fix, but I agree this is a generic pci issue.

I think it is worth adding a testcase to blktests to make sure these
future releases will test this.

-ck



^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-06-14  2:38               ` Chaitanya Kulkarni
@ 2022-06-14  4:00                 ` Shinichiro Kawasaki
  2022-06-15 19:47                   ` Bjorn Helgaas
  0 siblings, 1 reply; 23+ messages in thread
From: Shinichiro Kawasaki @ 2022-06-14  4:00 UTC (permalink / raw)
  To: Chaitanya Kulkarni
  Cc: Yi Zhang, linux-block, Keith Busch, linux-nvme, linux-scsi,
	mstowe, linux-pci

On Jun 14, 2022 / 02:38, Chaitanya Kulkarni wrote:
> Shinichiro,
> 
> On 6/13/22 19:23, Keith Busch wrote:
> > On Tue, Jun 14, 2022 at 01:09:07AM +0000, Shinichiro Kawasaki wrote:
> >> (CC+: linux-pci)
> >> On Jun 11, 2022 / 16:34, Yi Zhang wrote:
> >>> On Fri, Jun 10, 2022 at 10:49 PM Keith Busch <kbusch@kernel.org> wrote:
> >>>>
> >>>> And I am not even sure this is real. I don't know yet why this is showing up
> >>>> only now, but this should fix it:
> >>>
> >>> Hi Keith
> >>>
> >>> Confirmed the WARNING issue was fixed with the change, here is the log:
> >>
> >> Thanks. I also confirmed that Keith's change to add __ATTR_IGNORE_LOCKDEP to
> >> dev_attr_dev_rescan avoids the fix, on v5.19-rc2.
> >>
> >> I took a closer look into this issue and found The deadlock WARN can be
> >> recreated with following two commands:
> >>
> >> # echo 1 > /sys/bus/pci/devices/0000\:00\:09.0/rescan
> >> # echo 1 > /sys/bus/pci/devices/0000\:00\:09.0/remove
> >>
> >> And it can be recreated with PCI devices other than NVME controller, such as
> >> SCSI controller or VGA controller. Then this is not a storage sub-system issue.
> >>
> >> I checked function call stacks of the two commands above. As shown below, it
> >> looks like ABBA deadlock possibility is detected and warned.
> > 
> > Yeah, I was mistaken on this report, so my proposal to suppress the warning is
> > definitely not right. If I run both 'echo' commands in parallel, I see it
> > deadlock frequently. I'm not familiar enough with this code to any good ideas
> > on how to fix, but I agree this is a generic pci issue.
> 
> I think it is worth adding a testcase to blktests to make sure these
> future releases will test this.

Yeah, this WARN is confusing for us then it would be valuable to test by
blktests not to repeat it. One point I wonder is: which test group the test case
will it fall in? The nvme group could be the group to add, probably.

Another point I wonder is other kernel test suite than blktests. Don't we have
more appropriate test suite to check PCI device rescan/remove race ? Such a test
sounds more like a PCI bus sub-system test than block/storage test.

Having said that, still I think the test case is valuable for block/storage.
Unless anyone opposes, I'm open for the patch to add it.

-- 
Shin'ichiro Kawasaki

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-06-14  4:00                 ` Shinichiro Kawasaki
@ 2022-06-15 19:47                   ` Bjorn Helgaas
  2022-06-15 22:01                     ` Chaitanya Kulkarni
  2022-06-15 23:16                     ` Keith Busch
  0 siblings, 2 replies; 23+ messages in thread
From: Bjorn Helgaas @ 2022-06-15 19:47 UTC (permalink / raw)
  To: Shinichiro Kawasaki
  Cc: Chaitanya Kulkarni, Yi Zhang, linux-block, Keith Busch,
	linux-nvme, linux-scsi, mstowe, linux-pci

On Tue, Jun 14, 2022 at 04:00:45AM +0000, Shinichiro Kawasaki wrote:
> On Jun 14, 2022 / 02:38, Chaitanya Kulkarni wrote:
> > Shinichiro,
> > 
> > On 6/13/22 19:23, Keith Busch wrote:
> > > On Tue, Jun 14, 2022 at 01:09:07AM +0000, Shinichiro Kawasaki wrote:
> > >> (CC+: linux-pci)
> > >> On Jun 11, 2022 / 16:34, Yi Zhang wrote:
> > >>> On Fri, Jun 10, 2022 at 10:49 PM Keith Busch <kbusch@kernel.org> wrote:
> > >>>>
> > >>>> And I am not even sure this is real. I don't know yet why
> > >>>> this is showing up only now, but this should fix it:
> > >>>
> > >>> Hi Keith
> > >>>
> > >>> Confirmed the WARNING issue was fixed with the change, here is
> > >>> the log:
> > >>
> > >> Thanks. I also confirmed that Keith's change to add
> > >> __ATTR_IGNORE_LOCKDEP to dev_attr_dev_rescan avoids the fix, on
> > >> v5.19-rc2.
> > >>
> > >> I took a closer look into this issue and found The deadlock
> > >> WARN can be recreated with following two commands:
> > >>
> > >> # echo 1 > /sys/bus/pci/devices/0000\:00\:09.0/rescan
> > >> # echo 1 > /sys/bus/pci/devices/0000\:00\:09.0/remove
> > >>
> > >> And it can be recreated with PCI devices other than NVME
> > >> controller, such as SCSI controller or VGA controller. Then
> > >> this is not a storage sub-system issue.
> > >>
> > >> I checked function call stacks of the two commands above. As
> > >> shown below, it looks like ABBA deadlock possibility is
> > >> detected and warned.
> > > 
> > > Yeah, I was mistaken on this report, so my proposal to suppress
> > > the warning is definitely not right. If I run both 'echo'
> > > commands in parallel, I see it deadlock frequently. I'm not
> > > familiar enough with this code to any good ideas on how to fix,
> > > but I agree this is a generic pci issue.
> > 
> > I think it is worth adding a testcase to blktests to make sure
> > these future releases will test this.
> 
> Yeah, this WARN is confusing for us then it would be valuable to
> test by blktests not to repeat it. One point I wonder is: which test
> group the test case will it fall in? The nvme group could be the
> group to add, probably.
> 
> Another point I wonder is other kernel test suite than blktests.
> Don't we have more appropriate test suite to check PCI device
> rescan/remove race ? Such a test sounds more like a PCI bus
> sub-system test than block/storage test.

I'm not aware of such a test, but it would be nice to have one.

Can you share your qemu config so I can reproduce this locally?

Thanks for finding and reporting this!

Bjorn

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-06-15 19:47                   ` Bjorn Helgaas
@ 2022-06-15 22:01                     ` Chaitanya Kulkarni
  2022-06-15 23:13                       ` Yi Zhang
  2022-06-15 23:16                     ` Keith Busch
  1 sibling, 1 reply; 23+ messages in thread
From: Chaitanya Kulkarni @ 2022-06-15 22:01 UTC (permalink / raw)
  To: Shinichiro Kawasaki
  Cc: Yi Zhang, linux-block, Keith Busch, linux-nvme, linux-scsi,
	mstowe, linux-pci, Bjorn Helgaas

On 6/15/22 12:47, Bjorn Helgaas wrote:
> On Tue, Jun 14, 2022 at 04:00:45AM +0000, Shinichiro Kawasaki wrote:
>> On Jun 14, 2022 / 02:38, Chaitanya Kulkarni wrote:
>>> Shinichiro,
>>>
>>> On 6/13/22 19:23, Keith Busch wrote:
>>>> On Tue, Jun 14, 2022 at 01:09:07AM +0000, Shinichiro Kawasaki wrote:
>>>>> (CC+: linux-pci)
>>>>> On Jun 11, 2022 / 16:34, Yi Zhang wrote:
>>>>>> On Fri, Jun 10, 2022 at 10:49 PM Keith Busch <kbusch@kernel.org> wrote:
>>>>>>>
>>>>>>> And I am not even sure this is real. I don't know yet why
>>>>>>> this is showing up only now, but this should fix it:
>>>>>>
>>>>>> Hi Keith
>>>>>>
>>>>>> Confirmed the WARNING issue was fixed with the change, here is
>>>>>> the log:
>>>>>
>>>>> Thanks. I also confirmed that Keith's change to add
>>>>> __ATTR_IGNORE_LOCKDEP to dev_attr_dev_rescan avoids the fix, on
>>>>> v5.19-rc2.
>>>>>
>>>>> I took a closer look into this issue and found The deadlock
>>>>> WARN can be recreated with following two commands:
>>>>>
>>>>> # echo 1 > /sys/bus/pci/devices/0000\:00\:09.0/rescan
>>>>> # echo 1 > /sys/bus/pci/devices/0000\:00\:09.0/remove
>>>>>
>>>>> And it can be recreated with PCI devices other than NVME
>>>>> controller, such as SCSI controller or VGA controller. Then
>>>>> this is not a storage sub-system issue.
>>>>>
>>>>> I checked function call stacks of the two commands above. As
>>>>> shown below, it looks like ABBA deadlock possibility is
>>>>> detected and warned.
>>>>
>>>> Yeah, I was mistaken on this report, so my proposal to suppress
>>>> the warning is definitely not right. If I run both 'echo'
>>>> commands in parallel, I see it deadlock frequently. I'm not
>>>> familiar enough with this code to any good ideas on how to fix,
>>>> but I agree this is a generic pci issue.
>>>
>>> I think it is worth adding a testcase to blktests to make sure
>>> these future releases will test this.
>>
>> Yeah, this WARN is confusing for us then it would be valuable to
>> test by blktests not to repeat it. One point I wonder is: which test
>> group the test case will it fall in? The nvme group could be the
>> group to add, probably.
>>

since this issue been discovered with nvme rescan and revmoe,
it should be added to the nvme category.

>> Another point I wonder is other kernel test suite than blktests.
>> Don't we have more appropriate test suite to check PCI device
>> rescan/remove race ? Such a test sounds more like a PCI bus
>> sub-system test than block/storage test.

I don't think so we could have caught it long time back,
but we clearly did not.

> 
> I'm not aware of such a test, but it would be nice to have one.
> 
> Can you share your qemu config so I can reproduce this locally?
> 
> Thanks for finding and reporting this!
> 
> Bjorn

-ck



^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-06-15 22:01                     ` Chaitanya Kulkarni
@ 2022-06-15 23:13                       ` Yi Zhang
  2022-06-16  4:42                         ` Shinichiro Kawasaki
  0 siblings, 1 reply; 23+ messages in thread
From: Yi Zhang @ 2022-06-15 23:13 UTC (permalink / raw)
  To: Chaitanya Kulkarni
  Cc: Shinichiro Kawasaki, linux-block, Keith Busch, linux-nvme,
	linux-scsi, mstowe, linux-pci, Bjorn Helgaas

On Thu, Jun 16, 2022 at 6:01 AM Chaitanya Kulkarni
<chaitanyak@nvidia.com> wrote:
>
> On 6/15/22 12:47, Bjorn Helgaas wrote:
> > On Tue, Jun 14, 2022 at 04:00:45AM +0000, Shinichiro Kawasaki wrote:
> >> On Jun 14, 2022 / 02:38, Chaitanya Kulkarni wrote:
> >>> Shinichiro,
> >>>
> >>> On 6/13/22 19:23, Keith Busch wrote:
> >>>> On Tue, Jun 14, 2022 at 01:09:07AM +0000, Shinichiro Kawasaki wrote:
> >>>>> (CC+: linux-pci)
> >>>>> On Jun 11, 2022 / 16:34, Yi Zhang wrote:
> >>>>>> On Fri, Jun 10, 2022 at 10:49 PM Keith Busch <kbusch@kernel.org> wrote:
> >>>>>>>
> >>>>>>> And I am not even sure this is real. I don't know yet why
> >>>>>>> this is showing up only now, but this should fix it:
> >>>>>>
> >>>>>> Hi Keith
> >>>>>>
> >>>>>> Confirmed the WARNING issue was fixed with the change, here is
> >>>>>> the log:
> >>>>>
> >>>>> Thanks. I also confirmed that Keith's change to add
> >>>>> __ATTR_IGNORE_LOCKDEP to dev_attr_dev_rescan avoids the fix, on
> >>>>> v5.19-rc2.
> >>>>>
> >>>>> I took a closer look into this issue and found The deadlock
> >>>>> WARN can be recreated with following two commands:
> >>>>>
> >>>>> # echo 1 > /sys/bus/pci/devices/0000\:00\:09.0/rescan
> >>>>> # echo 1 > /sys/bus/pci/devices/0000\:00\:09.0/remove
> >>>>>
> >>>>> And it can be recreated with PCI devices other than NVME
> >>>>> controller, such as SCSI controller or VGA controller. Then
> >>>>> this is not a storage sub-system issue.
> >>>>>
> >>>>> I checked function call stacks of the two commands above. As
> >>>>> shown below, it looks like ABBA deadlock possibility is
> >>>>> detected and warned.
> >>>>
> >>>> Yeah, I was mistaken on this report, so my proposal to suppress
> >>>> the warning is definitely not right. If I run both 'echo'
> >>>> commands in parallel, I see it deadlock frequently. I'm not
> >>>> familiar enough with this code to any good ideas on how to fix,
> >>>> but I agree this is a generic pci issue.
> >>>
> >>> I think it is worth adding a testcase to blktests to make sure
> >>> these future releases will test this.
> >>
> >> Yeah, this WARN is confusing for us then it would be valuable to
> >> test by blktests not to repeat it. One point I wonder is: which test
> >> group the test case will it fall in? The nvme group could be the
> >> group to add, probably.
> >>
>
> since this issue been discovered with nvme rescan and revmoe,
> it should be added to the nvme category.

We already have nvme/032 which tests nvme rescan/reset/remove and the
issue was reported by running this one, do we still need one more?

>
> >> Another point I wonder is other kernel test suite than blktests.
> >> Don't we have more appropriate test suite to check PCI device
> >> rescan/remove race ? Such a test sounds more like a PCI bus
> >> sub-system test than block/storage test.
>
> I don't think so we could have caught it long time back,
> but we clearly did not.
>
> >
> > I'm not aware of such a test, but it would be nice to have one.
> >
> > Can you share your qemu config so I can reproduce this locally?
> >
> > Thanks for finding and reporting this!
> >
> > Bjorn
>
> -ck
>
>


-- 
Best Regards,
  Yi Zhang


^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-06-15 19:47                   ` Bjorn Helgaas
  2022-06-15 22:01                     ` Chaitanya Kulkarni
@ 2022-06-15 23:16                     ` Keith Busch
  2022-07-19  4:50                       ` Shinichiro Kawasaki
  1 sibling, 1 reply; 23+ messages in thread
From: Keith Busch @ 2022-06-15 23:16 UTC (permalink / raw)
  To: Bjorn Helgaas
  Cc: Shinichiro Kawasaki, Chaitanya Kulkarni, Yi Zhang, linux-block,
	linux-nvme, linux-scsi, mstowe, linux-pci

On Wed, Jun 15, 2022 at 02:47:27PM -0500, Bjorn Helgaas wrote:
> On Tue, Jun 14, 2022 at 04:00:45AM +0000, Shinichiro Kawasaki wrote:
> > 
> > Yeah, this WARN is confusing for us then it would be valuable to
> > test by blktests not to repeat it. One point I wonder is: which test
> > group the test case will it fall in? The nvme group could be the
> > group to add, probably.
> > 
> > Another point I wonder is other kernel test suite than blktests.
> > Don't we have more appropriate test suite to check PCI device
> > rescan/remove race ? Such a test sounds more like a PCI bus
> > sub-system test than block/storage test.
> 
> I'm not aware of such a test, but it would be nice to have one.
> 
> Can you share your qemu config so I can reproduce this locally?
> 
> Thanks for finding and reporting this!

Hi Bjorn,

This ought to be reproducible with any pci device that can be removed. Since we
initially observed with nvme, you can try with such a device. A quick way to
get one appearing in qemu is to add parameters:

        -drive id=n,if=none,file=null-co://,format=raw \
	-device nvme,serial=foobar,drive=n

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-06-15 23:13                       ` Yi Zhang
@ 2022-06-16  4:42                         ` Shinichiro Kawasaki
  2022-06-16 17:55                           ` Chaitanya Kulkarni
  0 siblings, 1 reply; 23+ messages in thread
From: Shinichiro Kawasaki @ 2022-06-16  4:42 UTC (permalink / raw)
  To: Yi Zhang
  Cc: Chaitanya Kulkarni, linux-block, Keith Busch, linux-nvme,
	linux-scsi, mstowe, linux-pci, Bjorn Helgaas

On Jun 16, 2022 / 07:13, Yi Zhang wrote:
> On Thu, Jun 16, 2022 at 6:01 AM Chaitanya Kulkarni
> <chaitanyak@nvidia.com> wrote:
> >
> > On 6/15/22 12:47, Bjorn Helgaas wrote:
> > > On Tue, Jun 14, 2022 at 04:00:45AM +0000, Shinichiro Kawasaki wrote:
> > >> On Jun 14, 2022 / 02:38, Chaitanya Kulkarni wrote:
> > >>> Shinichiro,

[snip]

> > >>> I think it is worth adding a testcase to blktests to make sure
> > >>> these future releases will test this.
> > >>
> > >> Yeah, this WARN is confusing for us then it would be valuable to
> > >> test by blktests not to repeat it. One point I wonder is: which test
> > >> group the test case will it fall in? The nvme group could be the
> > >> group to add, probably.
> > >>
> >
> > since this issue been discovered with nvme rescan and revmoe,
> > it should be added to the nvme category.
> 
> We already have nvme/032 which tests nvme rescan/reset/remove and the
> issue was reported by running this one, do we still need one more?

That is a point. Current nvme/032 checks nvme pci adapter rescan/reset/remove
during I/O to catch problems in nvme driver and block layer, but actually it
can catch the problem in pci sub-system also. I think Chaitanya's motivation
for the new test case is to distinguish those two.

If we have the new test case, its code will be similar and duplicated as
nvme/032 code. To avoid such duplication, it would be good to improve nvme/032
to have two steps. The 1st step checks that nvme pci adapter rescan/reset/remove
without I/O causes no kernel WARN (or any other unexpected kernel messages). Any
issue found in this step is reported as a pci sub-system issue. The 2nd step
checks nvme pci adapter rescan/reset/remove during I/O, as the current nvme/032
does. With this, we don't need the new test case, but still we can distinguish
the problems in nvme/block sub-system and pci sub-system.

> > >> Another point I wonder is other kernel test suite than blktests.
> > >> Don't we have more appropriate test suite to check PCI device
> > >> rescan/remove race ? Such a test sounds more like a PCI bus
> > >> sub-system test than block/storage test.
> >
> > I don't think so we could have caught it long time back,
> > but we clearly did not.

I see, then it looks that blktests is the test suite to test it.

-- 
Shin'ichiro Kawasaki

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-06-16  4:42                         ` Shinichiro Kawasaki
@ 2022-06-16 17:55                           ` Chaitanya Kulkarni
  0 siblings, 0 replies; 23+ messages in thread
From: Chaitanya Kulkarni @ 2022-06-16 17:55 UTC (permalink / raw)
  To: Shinichiro Kawasaki, Yi Zhang
  Cc: linux-block, Keith Busch, linux-nvme, linux-scsi, mstowe,
	linux-pci, Bjorn Helgaas

On 6/15/2022 9:42 PM, Shinichiro Kawasaki wrote:
> On Jun 16, 2022 / 07:13, Yi Zhang wrote:
>> On Thu, Jun 16, 2022 at 6:01 AM Chaitanya Kulkarni
>> <chaitanyak@nvidia.com> wrote:
>>>
>>> On 6/15/22 12:47, Bjorn Helgaas wrote:
>>>> On Tue, Jun 14, 2022 at 04:00:45AM +0000, Shinichiro Kawasaki wrote:
>>>>> On Jun 14, 2022 / 02:38, Chaitanya Kulkarni wrote:
>>>>>> Shinichiro,
> 
> [snip]
> 
>>>>>> I think it is worth adding a testcase to blktests to make sure
>>>>>> these future releases will test this.
>>>>>
>>>>> Yeah, this WARN is confusing for us then it would be valuable to
>>>>> test by blktests not to repeat it. One point I wonder is: which test
>>>>> group the test case will it fall in? The nvme group could be the
>>>>> group to add, probably.
>>>>>
>>>
>>> since this issue been discovered with nvme rescan and revmoe,
>>> it should be added to the nvme category.
>>
>> We already have nvme/032 which tests nvme rescan/reset/remove and the
>> issue was reported by running this one, do we still need one more?
> 
> That is a point. Current nvme/032 checks nvme pci adapter rescan/reset/remove
> during I/O to catch problems in nvme driver and block layer, but actually it
> can catch the problem in pci sub-system also. I think Chaitanya's motivation
> for the new test case is to distinguish those two.
> 

Yes, exactly.

> If we have the new test case, its code will be similar and duplicated as
> nvme/032 code. To avoid such duplication, it would be good to improve nvme/032
> to have two steps. The 1st step checks that nvme pci adapter rescan/reset/remove
> without I/O causes no kernel WARN (or any other unexpected kernel messages). Any
> issue found in this step is reported as a pci sub-system issue. The 2nd step
> checks nvme pci adapter rescan/reset/remove during I/O, as the current nvme/032
> does. With this, we don't need the new test case, but still we can distinguish
> the problems in nvme/block sub-system and pci sub-system.
> 

Totally agree with this.

>>>>> Another point I wonder is other kernel test suite than blktests.
>>>>> Don't we have more appropriate test suite to check PCI device
>>>>> rescan/remove race ? Such a test sounds more like a PCI bus
>>>>> sub-system test than block/storage test.
>>>
>>> I don't think so we could have caught it long time back,
>>> but we clearly did not.
> 
> I see, then it looks that blktests is the test suite to test it.
> 

-ck



^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-06-15 23:16                     ` Keith Busch
@ 2022-07-19  4:50                       ` Shinichiro Kawasaki
  2022-07-19 22:31                         ` Bjorn Helgaas
  0 siblings, 1 reply; 23+ messages in thread
From: Shinichiro Kawasaki @ 2022-07-19  4:50 UTC (permalink / raw)
  To: Bjorn Helgaas
  Cc: Chaitanya Kulkarni, Yi Zhang, linux-block, linux-nvme,
	linux-scsi, mstowe, linux-pci, Xiao Yang, Keith Busch

On Jun 15, 2022 / 17:16, Keith Busch wrote:
> On Wed, Jun 15, 2022 at 02:47:27PM -0500, Bjorn Helgaas wrote:
> > On Tue, Jun 14, 2022 at 04:00:45AM +0000, Shinichiro Kawasaki wrote:
> > > 
> > > Yeah, this WARN is confusing for us then it would be valuable to
> > > test by blktests not to repeat it. One point I wonder is: which test
> > > group the test case will it fall in? The nvme group could be the
> > > group to add, probably.
> > > 
> > > Another point I wonder is other kernel test suite than blktests.
> > > Don't we have more appropriate test suite to check PCI device
> > > rescan/remove race ? Such a test sounds more like a PCI bus
> > > sub-system test than block/storage test.
> > 
> > I'm not aware of such a test, but it would be nice to have one.
> > 
> > Can you share your qemu config so I can reproduce this locally?
> > 
> > Thanks for finding and reporting this!
> 
> Hi Bjorn,
> 
> This ought to be reproducible with any pci device that can be removed. Since we
> initially observed with nvme, you can try with such a device. A quick way to
> get one appearing in qemu is to add parameters:
> 
>         -drive id=n,if=none,file=null-co://,format=raw \
> 	-device nvme,serial=foobar,drive=n

Hello Bjorn,

Did you have chance to reproduce the WARN? Recently, it was reported again [1]
and getting attention.

[1] https://lore.kernel.org/linux-block/4ed3028b-2d2f-8755-fec2-0b9cb5ad42d2@fujitsu.com/

-- 
Shin'ichiro Kawasaki

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-07-19  4:50                       ` Shinichiro Kawasaki
@ 2022-07-19 22:31                         ` Bjorn Helgaas
  2022-07-20  2:27                           ` Shinichiro Kawasaki
  0 siblings, 1 reply; 23+ messages in thread
From: Bjorn Helgaas @ 2022-07-19 22:31 UTC (permalink / raw)
  To: Shinichiro Kawasaki
  Cc: Chaitanya Kulkarni, Yi Zhang, linux-block, linux-nvme,
	linux-scsi, mstowe, linux-pci, Xiao Yang, Keith Busch

On Tue, Jul 19, 2022 at 04:50:36AM +0000, Shinichiro Kawasaki wrote:
> On Jun 15, 2022 / 17:16, Keith Busch wrote:
> > On Wed, Jun 15, 2022 at 02:47:27PM -0500, Bjorn Helgaas wrote:
> > > On Tue, Jun 14, 2022 at 04:00:45AM +0000, Shinichiro Kawasaki wrote:
> > > > 
> > > > Yeah, this WARN is confusing for us then it would be valuable to
> > > > test by blktests not to repeat it. One point I wonder is: which test
> > > > group the test case will it fall in? The nvme group could be the
> > > > group to add, probably.
> > > > 
> > > > Another point I wonder is other kernel test suite than blktests.
> > > > Don't we have more appropriate test suite to check PCI device
> > > > rescan/remove race ? Such a test sounds more like a PCI bus
> > > > sub-system test than block/storage test.
> > > 
> > > I'm not aware of such a test, but it would be nice to have one.
> > > 
> > > Can you share your qemu config so I can reproduce this locally?
> > > 
> > > Thanks for finding and reporting this!
> > 
> > This ought to be reproducible with any pci device that can be
> > removed. Since we initially observed with nvme, you can try with
> > such a device. A quick way to get one appearing in qemu is to add
> > parameters:
> > 
> >         -drive id=n,if=none,file=null-co://,format=raw \
> > 	-device nvme,serial=foobar,drive=n
> 
> Did you have chance to reproduce the WARN? Recently, it was reported
> again [1] and getting attention.

I have not paid any attention to this yet.  From what I can tell, the
problem was discovered by a test case (i.e., not reported by a
real-world user), it is not a recent regression, we haven't identified
a commit that introduced the problem, and we do not have a potential
fix for it.  Obviously it needs to be fixed and I'm not trying to
minimize the problem; I just want to calibrate it against everything
else.

> [1] https://lore.kernel.org/linux-block/4ed3028b-2d2f-8755-fec2-0b9cb5ad42d2@fujitsu.com/
> 
> -- 
> Shin'ichiro Kawasaki

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-07-19 22:31                         ` Bjorn Helgaas
@ 2022-07-20  2:27                           ` Shinichiro Kawasaki
  2022-12-19 11:27                             ` Shinichiro Kawasaki
  0 siblings, 1 reply; 23+ messages in thread
From: Shinichiro Kawasaki @ 2022-07-20  2:27 UTC (permalink / raw)
  To: Bjorn Helgaas
  Cc: Chaitanya Kulkarni, Yi Zhang, linux-block, linux-nvme,
	linux-scsi, mstowe, linux-pci, Xiao Yang, Keith Busch

On Jul 19, 2022 / 17:31, Bjorn Helgaas wrote:
> On Tue, Jul 19, 2022 at 04:50:36AM +0000, Shinichiro Kawasaki wrote:
> > On Jun 15, 2022 / 17:16, Keith Busch wrote:
> > > On Wed, Jun 15, 2022 at 02:47:27PM -0500, Bjorn Helgaas wrote:
> > > > On Tue, Jun 14, 2022 at 04:00:45AM +0000, Shinichiro Kawasaki wrote:
> > > > > 
> > > > > Yeah, this WARN is confusing for us then it would be valuable to
> > > > > test by blktests not to repeat it. One point I wonder is: which test
> > > > > group the test case will it fall in? The nvme group could be the
> > > > > group to add, probably.
> > > > > 
> > > > > Another point I wonder is other kernel test suite than blktests.
> > > > > Don't we have more appropriate test suite to check PCI device
> > > > > rescan/remove race ? Such a test sounds more like a PCI bus
> > > > > sub-system test than block/storage test.
> > > > 
> > > > I'm not aware of such a test, but it would be nice to have one.
> > > > 
> > > > Can you share your qemu config so I can reproduce this locally?
> > > > 
> > > > Thanks for finding and reporting this!
> > > 
> > > This ought to be reproducible with any pci device that can be
> > > removed. Since we initially observed with nvme, you can try with
> > > such a device. A quick way to get one appearing in qemu is to add
> > > parameters:
> > > 
> > >         -drive id=n,if=none,file=null-co://,format=raw \
> > > 	-device nvme,serial=foobar,drive=n
> > 
> > Did you have chance to reproduce the WARN? Recently, it was reported
> > again [1] and getting attention.
> 
> I have not paid any attention to this yet.  From what I can tell, the
> problem was discovered by a test case (i.e., not reported by a
> real-world user), it is not a recent regression, we haven't identified
> a commit that introduced the problem, and we do not have a potential
> fix for it.  Obviously it needs to be fixed and I'm not trying to
> minimize the problem; I just want to calibrate it against everything
> else.

Bjorn, thank you for sharing your view, which sounds reasonable for me.

-- 
Shin'ichiro Kawasaki

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-07-20  2:27                           ` Shinichiro Kawasaki
@ 2022-12-19 11:27                             ` Shinichiro Kawasaki
  2022-12-29 18:13                               ` Bjorn Helgaas
  0 siblings, 1 reply; 23+ messages in thread
From: Shinichiro Kawasaki @ 2022-12-19 11:27 UTC (permalink / raw)
  To: Bjorn Helgaas
  Cc: Chaitanya Kulkarni, Yi Zhang, linux-block, linux-nvme,
	linux-scsi, mstowe, linux-pci, Xiao Yang, Keith Busch

Bjorn, FYI. This lockdep warning disappeared with kernel version v6.1. I
bisected and found the commit 2d7f9f8c1815 ("kernfs: Improve kernfs_drain() and
always call on removal.") avoided the issue. This commit touches kernfs_drain()
and __kernfs_remove(), and modifies the condition to lock kernfs_rwsem. I think
it explains why the lockdep disappeared. No longer need to work on this issue :)

-- 
Shin'ichiro Kawasaki

^ permalink raw reply	[flat|nested] 23+ messages in thread

* Re: blktests failures with v5.19-rc1
  2022-12-19 11:27                             ` Shinichiro Kawasaki
@ 2022-12-29 18:13                               ` Bjorn Helgaas
  0 siblings, 0 replies; 23+ messages in thread
From: Bjorn Helgaas @ 2022-12-29 18:13 UTC (permalink / raw)
  To: Shinichiro Kawasaki
  Cc: Chaitanya Kulkarni, Yi Zhang, linux-block, linux-nvme,
	linux-scsi, mstowe, linux-pci, Xiao Yang, Keith Busch

On Mon, Dec 19, 2022 at 11:27:03AM +0000, Shinichiro Kawasaki wrote:
> Bjorn, FYI. This lockdep warning disappeared with kernel version
> v6.1. I bisected and found the commit 2d7f9f8c1815 ("kernfs: Improve
> kernfs_drain() and always call on removal.") avoided the issue. This
> commit touches kernfs_drain() and __kernfs_remove(), and modifies
> the condition to lock kernfs_rwsem. I think it explains why the
> lockdep disappeared. No longer need to work on this issue :)

Thanks for following up on this!

Bjorn

^ permalink raw reply	[flat|nested] 23+ messages in thread

end of thread, other threads:[~2022-12-29 18:13 UTC | newest]

Thread overview: 23+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-06-09 23:53 blktests failures with v5.19-rc1 Shinichiro Kawasaki
2022-06-10  8:07 ` Christoph Hellwig
2022-06-10  9:22 ` Chaitanya Kulkarni
2022-06-10  9:32   ` Chaitanya Kulkarni
2022-06-10 12:25     ` Shinichiro Kawasaki
2022-06-10 13:15       ` Yi Zhang
2022-06-10 14:47       ` Keith Busch
2022-06-11  8:34         ` Yi Zhang
2022-06-14  1:09           ` Shinichiro Kawasaki
2022-06-14  2:23             ` Keith Busch
2022-06-14  2:38               ` Chaitanya Kulkarni
2022-06-14  4:00                 ` Shinichiro Kawasaki
2022-06-15 19:47                   ` Bjorn Helgaas
2022-06-15 22:01                     ` Chaitanya Kulkarni
2022-06-15 23:13                       ` Yi Zhang
2022-06-16  4:42                         ` Shinichiro Kawasaki
2022-06-16 17:55                           ` Chaitanya Kulkarni
2022-06-15 23:16                     ` Keith Busch
2022-07-19  4:50                       ` Shinichiro Kawasaki
2022-07-19 22:31                         ` Bjorn Helgaas
2022-07-20  2:27                           ` Shinichiro Kawasaki
2022-12-19 11:27                             ` Shinichiro Kawasaki
2022-12-29 18:13                               ` Bjorn Helgaas

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.