[bug report][bisected] modprob -r scsi-debug take more than 3mins during blktests srp/ tests

From: Yi Zhang <yi.zhang@redhat.com>
To: linux-scsi <linux-scsi@vger.kernel.org>
Cc: dgilbert@interlog.com, Bart Van Assche <bvanassche@acm.org>,
	linux-block <linux-block@vger.kernel.org>
Subject: [bug report][bisected] modprob -r scsi-debug take more than 3mins during blktests srp/ tests
Date: Sat, 2 Apr 2022 15:06:34 +0800	[thread overview]
Message-ID: <CAHj4cs8F51f_Br7kBPYN0yDo4FqFFbodHAUN6_c=Rd4Bd+Y1sw@mail.gmail.com> (raw)

Hello
I found the scsi-debug module removing [1] takes more than 3mins
during blktests srp/ tests, and bisecting shows it was introduced from
[2],
Pls help check it, let me know if you need more info for it, thanks.

[1]
# time ./check srp/001
srp/001 (Create and remove LUNs)                             [passed]
    runtime    ...  3.194s
real 3m12.119s
user 0m0.859s
sys 0m2.227s

# ps aux | grep modprobe
root      250153  0.0  0.0  10600  2264 pts/0    D+   01:34   0:00
modprobe -r scsi_debug

# cat /proc/250153/stack
[<0>] blk_execute_rq+0x95/0xb0
[<0>] __scsi_execute+0xe2/0x250
[<0>] sd_sync_cache+0xac/0x190
[<0>] sd_shutdown+0x67/0xf0
[<0>] sd_remove+0x39/0x80
[<0>] __device_release_driver+0x234/0x240
[<0>] device_release_driver+0x23/0x30
[<0>] bus_remove_device+0xd8/0x140
[<0>] device_del+0x18b/0x3f0
[<0>] __scsi_remove_device+0x102/0x140
[<0>] scsi_forget_host+0x55/0x60
[<0>] scsi_remove_host+0x72/0x110
[<0>] sdebug_driver_remove+0x22/0xa0 [scsi_debug]
[<0>] __device_release_driver+0x181/0x240
[<0>] device_release_driver+0x23/0x30
[<0>] bus_remove_device+0xd8/0x140
[<0>] device_del+0x18b/0x3f0
[<0>] device_unregister+0x13/0x60
[<0>] sdebug_do_remove_host+0xd1/0xf0 [scsi_debug]
[<0>] scsi_debug_exit+0x58/0xe1e [scsi_debug]
[<0>] __do_sys_delete_module.constprop.0+0x170/0x260
[<0>] do_syscall_64+0x3a/0x80
[<0>] entry_SYSCALL_64_after_hwframe+0x44/0xae

# dmesg | tail -10
[  345.863755] ib_srpt:srpt_release_channel_work: ib_srpt 10.16.221.74-32
[  345.863855] ib_srpt:srpt_release_channel_work: ib_srpt 10.16.221.74-34
[  345.863953] ib_srpt:srpt_release_channel_work: ib_srpt 10.16.221.74-36
[  346.373371] sd 15:0:0:0: [sdb] Synchronizing SCSI cache
[  532.864536] sd 15:0:0:0: [sdb] Synchronize Cache(10) failed:
Result: hostbyte=DID_TIME_OUT driverbyte=DRIVER_OK
------> seems most of the time were taken here
[  532.929626] eno1np0 speed is unknown, defaulting to 1000
[  532.938524] eno2np1 speed is unknown, defaulting to 1000
[  532.943957] eno4 speed is unknown, defaulting to 1000
[  532.998059] rdma_rxe: rxe-ah pool destroyed with unfree'd elem
[  533.011781] rdma_rxe: unloaded

[2]
commit 2aad3cd8537033cd34f70294a23f54623ffe9c1b (refs/bisect/bad)
Author: Douglas Gilbert <dgilbert@interlog.com>
Date:   Sat Jan 8 20:28:45 2022 -0500

    scsi: scsi_debug: Address races following module load