[bug report] RIP: 0010:blk_flush_complete_seq+0x450/0x1060 observed during blktests nvme/tcp nvme/012

[Yi Zhang]

On Tue, Apr 30, 2024 at 2:17 PM Johannes Thumshirn
<Johannes.Thumshirn at wdc.com> wrote:
>
> On 30.04.24 00:18, Chaitanya Kulkarni wrote:
> > On 4/29/24 07:35, Johannes Thumshirn wrote:
> >> On 23.04.24 15:18, Yi Zhang wrote:
> >>> Hi
> >>> I found this issue on the latest linux-block/for-next by blktests
> >>> nvme/tcp nvme/012, please help check it and let me know if you need
> >>> any info/testing for it, thanks.
> >>>
> >>> [ 1873.394323] run blktests nvme/012 at 2024-04-23 04:13:47
> >>> [ 1873.761900] loop0: detected capacity change from 0 to 2097152
> >>> [ 1873.846926] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
> >>> [ 1873.987806] nvmet_tcp: enabling port 0 (127.0.0.1:4420)
> >>> [ 1874.208883] nvmet: creating nvm controller 1 for subsystem
> >>> blktests-subsystem-1 for NQN
> >>> nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349.
> >>> [ 1874.243423] nvme nvme0: creating 48 I/O queues.
> >>> [ 1874.362383] nvme nvme0: mapped 48/0/0 default/read/poll queues.
> >>> [ 1874.517677] nvme nvme0: new ctrl: NQN "blktests-subsystem-1", addr
> >>> 127.0.0.1:4420, hostnqn:
> >>> nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349
> >
> > [...]
> >
> >>>
> >>> [  326.827260] run blktests nvme/012 at 2024-04-29 16:28:31
> >>> [  327.475957] loop0: detected capacity change from 0 to 2097152
> >>> [  327.538987] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
> >>>
> >>> [  327.603405] nvmet_tcp: enabling port 0 (127.0.0.1:4420)
> >>>
> >>>
> >>> [  327.872343] nvmet: creating nvm controller 1 for subsystem
> >>> blktests-subsystem-1 for NQN
> >>> nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349.
> >>>
> >>> [  327.877120] nvme nvme0: Please enable CONFIG_NVME_MULTIPATH for full
> >>> support of multi-port devices.
> >
> > seems like you don't have multipath enabled that is one difference
> > I can see in above log posted by Yi, and your log.
>
>
> Yup, but even with multipath enabled I can't get the bug to trigger :(

It's not one 100% reproduced issue, I tried on my another server and
it cannot be reproduced.

>
> nvme/012 (run mkfs and data verification fio job on NVMeOF block
> device-backed ns)
>
> [  279.642826] run blktests nvme/012 at 2024-04-29 18:52:26
>
> [  280.296493] loop0: detected capacity change from 0 to 2097152
> [  280.360139] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
>
>
> [  280.426171] nvmet_tcp: enabling port 0 (127.0.0.1:4420)
> [  280.712262] nvmet: creating nvm controller 1 for subsystem
> blktests-subsystem-1 for NQN
> nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349.
>
> [  280.718259] nvme nvme0: creating 4 I/O queues.
>
>
> [  280.722258] nvme nvme0: mapped 4/0/0 default/read/poll queues.
>
>
> [  280.726088] nvme nvme0: new ctrl: NQN "blktests-subsystem-1", addr
> 127.0.0.1:4420, hostnqn:
> nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349
> [  281.343044] XFS (nvme0n1): Mounting V5 Filesystem
> 513881ee-db18-48c7-a2b0-3e4e3e41f38c
>
> [  281.381925] XFS (nvme0n1): Ending clean mount
>
>
> [  281.390154] xfs filesystem being mounted at /mnt/blktests supports
> timestamps until 2038-01-19 (0x7fffffff)
> [  309.958309] perf: interrupt took too long (2593 > 2500), lowering
> kernel.perf_event_max_sample_rate to 77000
>
> [  377.847337] perf: interrupt took too long (3278 > 3241), lowering
> kernel.perf_event_max_sample_rate to 61000
>
> [  471.964099] XFS (nvme0n1): Unmounting Filesystem
> 513881ee-db18-48c7-a2b0-3e4e3e41f38c
>
> nvme/012 (run mkfs and data verification fio job on NVMeOF block
> device-backed ns) [passed]
>
>      runtime    ...  192.747s
>
>
>
> Can you see if you can reproduce it on your side?
>
> Thanks,
>         Johannes



-- 
Best Regards,
  Yi Zhang