Storage blktests - nvme-tcp: nvme/012: TIMEOUT

Snippet of test failure

# https://beaker-archive.host.prod.eng.bos.redhat.com/beaker-logs/2022/06/66913/6691337/12092781/145692708/taskout.log
>>> 2022-06-06 00:30:10 | Start to run test case nvme-tcp: /mnt/tests/gitlab.com/cki-project/kernel-tests/-/archive/main/kernel-tests-main.zip/storage/blktests/nvme/nvme-tcp/blktests/tests/nvme/012 ...
nvme/012 (run mkfs and data verification fio job on NVMeOF block device-backed ns)

# https://s3.us-east-1.amazonaws.com/arr-cki-prod-datawarehouse-public/datawarehouse-public/2022/06/06/556160049/redhat:556160049_x86_64/tests/Storage_blktests_nvme_tcp/12092781_x86_64_1_dmesg.log
[ 7868.464721] Running test [R:12092781 T:145692708 - Storage blktests - nvme-tcp]
[ 7880.171718] run blktests nvme/003 at 2022-06-06 00:22:34
[ 7880.472509] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
[ 7880.476567] nvmet_tcp: enabling port 0 (127.0.0.1:4420)
[ 7880.610860] nvmet: creating discovery controller 1 for subsystem nqn.2014-08.org.nvmexpress.discovery for NQN nqn.2014-08.org.nvmexpress:uuid:6d475e1b-b425-5577-b22b-bde7016fb23e.
[ 7880.611952] nvme nvme0: new ctrl: NQN "nqn.2014-08.org.nvmexpress.discovery", addr 127.0.0.1:4420
[ 7890.636780] nvme nvme0: Removing ctrl: NQN "nqn.2014-08.org.nvmexpress.discovery"
[ 7891.994676] run blktests nvme/004 at 2022-06-06 00:22:46
[ 7892.109061] loop0: detected capacity change from 0 to 2097152
[ 7892.116578] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
[ 7892.120041] nvmet_tcp: enabling port 0 (127.0.0.1:4420)
[ 7892.130513] nvmet: creating nvm controller 1 for subsystem blktests-subsystem-1 for NQN nqn.2014-08.org.nvmexpress:uuid:6d475e1b-b425-5577-b22b-bde7016fb23e.
[ 7892.131807] nvme nvme0: creating 8 I/O queues.
[ 7892.133382] nvme nvme0: mapped 8/0/0 default/read/poll queues.
[ 7892.180216] nvme nvme0: new ctrl: NQN "blktests-subsystem-1", addr 127.0.0.1:4420
[ 7893.232546] nvme nvme0: Removing ctrl: NQN "blktests-subsystem-1"
[ 7894.542641] run blktests nvme/005 at 2022-06-06 00:22:48
[ 7894.646228] loop0: detected capacity change from 0 to 2097152
[ 7894.721928] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
[ 7894.725488] nvmet_tcp: enabling port 0 (127.0.0.1:4420)
[ 7894.735198] nvmet: creating nvm controller 1 for subsystem blktests-subsystem-1 for NQN nqn.2014-08.org.nvmexpress:uuid:6d475e1b-b425-5577-b22b-bde7016fb23e.
[ 7894.736451] nvme nvme0: creating 8 I/O queues.
[ 7894.738027] nvme nvme0: mapped 8/0/0 default/read/poll queues.
[ 7894.798266] nvme nvme0: new ctrl: NQN "blktests-subsystem-1", addr 127.0.0.1:4420
[ 7895.940215] nvmet: creating nvm controller 2 for subsystem blktests-subsystem-1 for NQN nqn.2014-08.org.nvmexpress:uuid:6d475e1b-b425-5577-b22b-bde7016fb23e.
[ 7895.941277] nvme nvme0: creating 8 I/O queues.
[ 7896.111411] nvme nvme0: mapped 8/0/0 default/read/poll queues.
[ 7896.120366] nvme nvme0: Removing ctrl: NQN "blktests-subsystem-1"
[ 7896.325007] block nvme0n1: no available path - failing I/O
[ 7896.325020] block nvme0n1: no available path - failing I/O
[ 7896.325023] Buffer I/O error on dev nvme0n1, logical block 0, async page read
[ 7897.721775] run blktests nvme/006 at 2022-06-06 00:22:52
[ 7897.819832] loop0: detected capacity change from 0 to 2097152
[ 7897.827132] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
[ 7897.836190] nvmet_tcp: enabling port 0 (127.0.0.1:4420)
[ 7899.224238] run blktests nvme/007 at 2022-06-06 00:22:53
[ 7899.326135] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
[ 7899.335442] nvmet_tcp: enabling port 0 (127.0.0.1:4420)
[ 7900.609793] run blktests nvme/008 at 2022-06-06 00:22:55
[ 7900.708834] loop0: detected capacity change from 0 to 2097152
[ 7900.715856] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
[ 7900.786744] nvmet_tcp: enabling port 0 (127.0.0.1:4420)
[ 7900.796422] nvmet: creating nvm controller 1 for subsystem blktests-subsystem-1 for NQN nqn.2014-08.org.nvmexpress:uuid:6d475e1b-b425-5577-b22b-bde7016fb23e.
[ 7900.797750] nvme nvme0: creating 8 I/O queues.
[ 7900.799322] nvme nvme0: mapped 8/0/0 default/read/poll queues.
[ 7900.854213] nvme nvme0: new ctrl: NQN "blktests-subsystem-1", addr 127.0.0.1:4420
[ 7901.937615] nvme nvme0: Removing ctrl: NQN "blktests-subsystem-1"
[ 7903.219848] run blktests nvme/009 at 2022-06-06 00:22:57
[ 7903.321631] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
[ 7903.330846] nvmet_tcp: enabling port 0 (127.0.0.1:4420)
[ 7903.396447] nvmet: creating nvm controller 1 for subsystem blktests-subsystem-1 for NQN nqn.2014-08.org.nvmexpress:uuid:6d475e1b-b425-5577-b22b-bde7016fb23e.
[ 7903.629250] nvme nvme0: creating 8 I/O queues.
[ 7903.630713] nvme nvme0: mapped 8/0/0 default/read/poll queues.
[ 7903.753457] nvme nvme0: new ctrl: NQN "blktests-subsystem-1", addr 127.0.0.1:4420
[ 7904.839770] nvme nvme0: Removing ctrl: NQN "blktests-subsystem-1"
[ 7906.317640] run blktests nvme/010 at 2022-06-06 00:23:00
[ 7906.416400] loop0: detected capacity change from 0 to 2097152
[ 7906.423494] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
[ 7906.432904] nvmet_tcp: enabling port 0 (127.0.0.1:4420)
[ 7906.442736] nvmet: creating nvm controller 1 for subsystem blktests-subsystem-1 for NQN nqn.2014-08.org.nvmexpress:uuid:6d475e1b-b425-5577-b22b-bde7016fb23e.
[ 7906.444050] nvme nvme0: creating 8 I/O queues.
[ 7906.445527] nvme nvme0: mapped 8/0/0 default/read/poll queues.
[ 7906.486150] nvme nvme0: new ctrl: NQN "blktests-subsystem-1", addr 127.0.0.1:4420
[ 7959.248801] nvme nvme0: Removing ctrl: NQN "blktests-subsystem-1"
[ 7965.223452] run blktests nvme/011 at 2022-06-06 00:23:59
[ 7965.326624] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
[ 7965.335813] nvmet_tcp: enabling port 0 (127.0.0.1:4420)
[ 7965.346875] nvmet: creating nvm controller 1 for subsystem blktests-subsystem-1 for NQN nqn.2014-08.org.nvmexpress:uuid:6d475e1b-b425-5577-b22b-bde7016fb23e.
[ 7965.348208] nvme nvme0: creating 8 I/O queues.
[ 7965.349879] nvme nvme0: mapped 8/0/0 default/read/poll queues.
[ 7965.401331] nvme nvme0: new ctrl: NQN "blktests-subsystem-1", addr 127.0.0.1:4420
[ 8324.239597] nvme nvme0: Removing ctrl: NQN "blktests-subsystem-1"
[ 8324.313510] block nvme0n1: no available path - failing I/O
[ 8324.313525] block nvme0n1: no available path - failing I/O
[ 8324.313529] Buffer I/O error on dev nvme0n1, logical block 16, async page read

Test logs on DataWarehouse

Test : https://datawarehouse.cki-project.org/kcidb/tests/3756083
- Beaker task : https://beaker.engineering.redhat.com/recipes/12092781#task145692708

DataWarehouse issue

DW issue : https://datawarehouse.cki-project.org/issue/1291
- Regex : https://datawarehouse.cki-project.org/issue/-/regex/1246
  - Text Match : \[\s*\d+\.\d+\] Buffer I\/O error on dev nvme0n1, logical block \d+, async page read
  - (Log) File Name Match : dmesg.log
  - Test Name Match : Storage blktests - nvme-tcp
  - KPET Tree Name Match : (upstream|rawhide)

Additional details

N/A

In case opening the links above result in a 404 page on DataWarehouse, please make sure you are correctly logged into DataWarehouse via Red Hat SSO.

Edited Jun 09, 2022 by Huanian Li

To upload designs, you'll need to enable LFS and have an admin enable hashed storage. More information