blktests: trying to debug nvme test failures

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hi,

I've been trying to run blktsts in an automated environment, and I've
been trying to figure out which failures are test bugs, environment
bugs, and which are kernel bugs.

In the NVME tests, there are a number of failures that are caused by
the missing line:

    -NQN:blktests-shubsystem-1 disconnected 1 controller(s)

I'm not sure what that means, or how to fix the problem.  Could
someone give me a hint?

Many thanks!!

					- Ted

FSTESTVER: blktests	69a95c6 (Fri, 7 Dec 2018 10:13:57 -0800)
FSTESTVER: fio		fio-3.2 (Fri, 3 Nov 2017 15:23:49 -0600)
FSTESTVER: fsverity	bdebc45 (Wed, 5 Sep 2018 21:32:22 -0700)
FSTESTVER: ima-evm-utils	0267fa1 (Mon, 3 Dec 2018 06:11:35 -0500)
FSTESTVER: nvme-cli	v0.2-918-ge145ab4 (Fri, 7 Dec 2018 15:15:48 -0700)
FSTESTVER: quota		59b280e (Mon, 5 Feb 2018 16:48:22 +0100)
FSTESTVER: stress-ng	977ae357 (Wed, 6 Sep 2017 23:45:03 -0400)
FSTESTVER: syzkaller	4b6d14f2 (Tue, 27 Nov 2018 13:16:46 +0100)
FSTESTVER: xfsprogs	v4.19.0 (Fri, 9 Nov 2018 14:31:04 -0600)
FSTESTVER: xfstests-bld	461a0aa (Sun, 9 Dec 2018 23:39:23 -0500)
FSTESTVER: xfstests	linux-v3.8-2246-g12eec16d (Sun, 9 Dec 2018 23:15:23 -0500)
FSTESTSET: "nvme"
FSTESTEXC: ""
FSTESTOPT: "blktests aex"
CPUS: "2"
MEM: "1979.4"
              total        used        free      shared  buff/cache   available
Mem:           1979          46        1828           8         104        1891
Swap:             0           0           0
BEGIN BLKTESTS Sun Dec  9 23:47:00 EST 2018
nvme/*** => vdb                                              [not run]
    /dev/vdb is not a NVMe device
nvme/002 (create many subsystems and test discovery)        
    runtime  29.493s  ...
nvme/002 (create many subsystems and test discovery)         [passed]
    runtime  29.493s  ...  28.269s
nvme/003 (test if we're sending keep-alives to a discovery controller)
    runtime  10.227s  ...
nvme/003 (test if we're sending keep-alives to a discovery controller) [passed]
    runtime  10.227s  ...  10.246s
nvme/004 (test nvme and nvmet UUID NS descriptors)          
    runtime  0.347s  ...
nvme/004 (test nvme and nvmet UUID NS descriptors)           [passed]
    runtime  0.347s  ...  0.316s
nvme/005 (reset local loopback target)                       [not run]
    nvme-core module does not have parameter multipath
nvme/006 (create an NVMeOF target with a block device-backed ns)
    runtime  0.292s  ...
nvme/006 (create an NVMeOF target with a block device-backed ns) [passed]
    runtime  0.292s  ...  0.258s
nvme/007 (create an NVMeOF target with a file-backed ns)    
    runtime  0.202s  ...
nvme/007 (create an NVMeOF target with a file-backed ns)     [passed]
    runtime  0.202s  ...  0.151s
nvme/008 (create an NVMeOF host with a block device-backed ns)
    runtime  0.423s  ...
nvme/008 (create an NVMeOF host with a block device-backed ns) [failed]
    runtime  0.423s  ...  0.386s
    --- tests/nvme/008.out	2018-12-09 23:39:23.000000000 -0500
    +++ /results/nodev/nvme/008.out.bad	2018-12-09 23:47:40.514592807 -0500
    @@ -1,5 +1,4 @@
     Running nvme/008
     91fdba0d-f87b-4c25-b80f-db7be1418b9e
     uuid.91fdba0d-f87b-4c25-b80f-db7be1418b9e
    -NQN:blktests-subsystem-1 disconnected 1 controller(s)
     Test complete
nvme/009 (create an NVMeOF host with a file-backed ns)      
    runtime  0.320s  ...
nvme/009 (create an NVMeOF host with a file-backed ns)       [failed]
    runtime  0.320s  ...  0.311s
    --- tests/nvme/009.out	2018-12-09 23:39:23.000000000 -0500
    +++ /results/nodev/nvme/009.out.bad	2018-12-09 23:47:40.947926140 -0500
    @@ -1,5 +1,4 @@
     Running nvme/009
     91fdba0d-f87b-4c25-b80f-db7be1418b9e
     uuid.91fdba0d-f87b-4c25-b80f-db7be1418b9e
    -NQN:blktests-subsystem-1 disconnected 1 controller(s)
     Test complete
nvme/010 (run data verification fio job on NVMeOF block device-backed ns)
    runtime  27.516s  ...
nvme/010 (run data verification fio job on NVMeOF block device-backed ns) [failed]
    runtime  27.516s  ...  27.912s
    --- tests/nvme/010.out	2018-12-09 23:39:23.000000000 -0500
    +++ /results/nodev/nvme/010.out.bad	2018-12-09 23:48:08.994592800 -0500
    @@ -1,5 +1,4 @@
     Running nvme/010
     91fdba0d-f87b-4c25-b80f-db7be1418b9e
     uuid.91fdba0d-f87b-4c25-b80f-db7be1418b9e
    -NQN:blktests-subsystem-1 disconnected 1 controller(s)
     Test complete
nvme/011 (run data verification fio job on NVMeOF file-backed ns)
    runtime  21.947s  ...
nvme/011 (run data verification fio job on NVMeOF file-backed ns) [failed]
    runtime  21.947s  ...  23.609s
    --- tests/nvme/011.out	2018-12-09 23:39:23.000000000 -0500
    +++ /results/nodev/nvme/011.out.bad	2018-12-09 23:48:32.724592785 -0500
    @@ -1,5 +1,4 @@
     Running nvme/011
     91fdba0d-f87b-4c25-b80f-db7be1418b9e
     uuid.91fdba0d-f87b-4c25-b80f-db7be1418b9e
    -NQN:blktests-subsystem-1 disconnected 1 controller(s)
     Test complete
nvme/012 (run mkfs and data verification fio job on NVMeOF block device-backed ns)
    runtime  58.246s  ...
nvme/012 (run mkfs and data verification fio job on NVMeOF block device-backed ns) [failed]
    runtime  58.246s  ...  51.121s
    --- tests/nvme/012.out	2018-12-09 23:39:23.000000000 -0500
    +++ /results/nodev/nvme/012.out.bad	2018-12-09 23:49:23.934592771 -0500
    @@ -1,5 +1,4 @@
     Running nvme/012
     91fdba0d-f87b-4c25-b80f-db7be1418b9e
     uuid.91fdba0d-f87b-4c25-b80f-db7be1418b9e
    -NQN:blktests-subsystem-1 disconnected 1 controller(s)
     Test complete
nvme/013 (run mkfs and data verification fio job on NVMeOF file-backed ns)
    runtime  13.267s  ...
nvme/013 (run mkfs and data verification fio job on NVMeOF file-backed ns) [failed]
    runtime  13.267s  ...  13.653s
    --- tests/nvme/013.out	2018-12-09 23:39:23.000000000 -0500
    +++ /results/nodev/nvme/013.out.bad	2018-12-09 23:49:37.694592754 -0500
    @@ -1,5 +1,4 @@
     Running nvme/013
     91fdba0d-f87b-4c25-b80f-db7be1418b9e
     uuid.91fdba0d-f87b-4c25-b80f-db7be1418b9e
    -NQN:blktests-subsystem-1 disconnected 1 controller(s)
     Test complete
nvme/014 (flush a NVMeOF block device-backed ns)            
    runtime  5.472s  ...
nvme/014 (flush a NVMeOF block device-backed ns)             [failed]
    runtime  5.472s  ...  6.397s
    --- tests/nvme/014.out	2018-12-09 23:39:23.000000000 -0500
    +++ /results/nodev/nvme/014.out.bad	2018-12-09 23:49:44.164592749 -0500
    @@ -2,5 +2,4 @@
     91fdba0d-f87b-4c25-b80f-db7be1418b9e
     uuid.91fdba0d-f87b-4c25-b80f-db7be1418b9e
     NVMe Flush: success
    -NQN:blktests-subsystem-1 disconnected 1 controller(s)
     Test complete
nvme/015 (unit test for NVMe flush for file backed ns)      
    runtime  4.390s  ...
nvme/015 (unit test for NVMe flush for file backed ns)       [failed]
    runtime  4.390s  ...  4.524s
    --- tests/nvme/015.out	2018-12-09 23:39:23.000000000 -0500
    +++ /results/nodev/nvme/015.out.bad	2018-12-09 23:49:48.744592747 -0500
    @@ -2,5 +2,4 @@
     91fdba0d-f87b-4c25-b80f-db7be1418b9e
     uuid.91fdba0d-f87b-4c25-b80f-db7be1418b9e
     NVMe Flush: success
    -NQN:blktests-subsystem-1 disconnected 1 controller(s)
     Test complete
nvme/016 (create/delete many NVMeOF block device-backed ns and test discovery)
    runtime  22.275s  ...
nvme/016 (create/delete many NVMeOF block device-backed ns and test discovery) [failed]
    runtime  22.275s  ...  20.610s
    --- tests/nvme/016.out	2018-12-09 23:39:23.000000000 -0500
    +++ /results/nodev/nvme/016.out.bad	2018-12-09 23:50:09.434592742 -0500
    @@ -1,6 +1,6 @@
     Running nvme/016
     
    -Discovery Log Number of Records 1, Generation counter 1
    +Discovery Log Number of Records 1, Generation counter 3
     =====Discovery Log Entry 0======
     trtype:  loop
     adrfam:  pci
nvme/017 (create/delete many file-ns and test discovery)    
    runtime  22.004s  ...
nvme/017 (create/delete many file-ns and test discovery)     [passed]
    runtime  22.004s  ...  21.729s
nvme/019 (test NVMe DSM Discard command on NVMeOF block-device ns)
    runtime  0.378s  ...
nvme/019 (test NVMe DSM Discard command on NVMeOF block-device ns) [failed]
    runtime  0.378s  ...  0.323s
    --- tests/nvme/019.out	2018-12-09 23:39:23.000000000 -0500
    +++ /results/nodev/nvme/019.out.bad	2018-12-09 23:50:31.664592737 -0500
    @@ -2,5 +2,4 @@
     91fdba0d-f87b-4c25-b80f-db7be1418b9e
     uuid.91fdba0d-f87b-4c25-b80f-db7be1418b9e
     NVMe DSM: success
    -NQN:blktests-subsystem-1 disconnected 1 controller(s)
     Test complete
nvme/020 (test NVMe DSM Discard command on NVMeOF file-backed ns)
    runtime  0.306s  ...
nvme/020 (test NVMe DSM Discard command on NVMeOF file-backed ns) [failed]
    runtime  0.306s  ...  0.254s
    --- tests/nvme/020.out	2018-12-09 23:39:23.000000000 -0500
    +++ /results/nodev/nvme/020.out.bad	2018-12-09 23:50:31.951259403 -0500
    @@ -2,5 +2,4 @@
     91fdba0d-f87b-4c25-b80f-db7be1418b9e
     uuid.91fdba0d-f87b-4c25-b80f-db7be1418b9e
     NVMe DSM: success
    -NQN:blktests-subsystem-1 disconnected 1 controller(s)
     Test complete
nvme/021 (test NVMe list command on NVMeOF file-backed ns)  
    runtime  0.298s  ...
nvme/021 (test NVMe list command on NVMeOF file-backed ns)   [failed]
    runtime  0.298s  ...  0.255s
    --- tests/nvme/021.out	2018-12-09 23:39:23.000000000 -0500
    +++ /results/nodev/nvme/021.out.bad	2018-12-09 23:50:32.241259401 -0500
    @@ -1,5 +1,4 @@
     Running nvme/021
     91fdba0d-f87b-4c25-b80f-db7be1418b9e
     uuid.91fdba0d-f87b-4c25-b80f-db7be1418b9e
    -NQN:blktests-subsystem-1 disconnected 1 controller(s)
     Test complete
nvme/022 (test NVMe reset command on NVMeOF file-backed ns) 
    runtime  0.414s  ...
nvme/022 (test NVMe reset command on NVMeOF file-backed ns)  [failed]
    runtime  0.414s  ...  0.366s
    --- tests/nvme/022.out	2018-12-09 23:39:23.000000000 -0500
    +++ /results/nodev/nvme/022.out.bad	2018-12-09 23:50:32.647926067 -0500
    @@ -1,5 +1,4 @@
     Running nvme/022
     91fdba0d-f87b-4c25-b80f-db7be1418b9e
     uuid.91fdba0d-f87b-4c25-b80f-db7be1418b9e
    -NQN:blktests-subsystem-1 disconnected 1 controller(s)
     Test complete
nvme/023 (test NVMe smart-log command on NVMeOF block-device ns)
    runtime  0.359s  ...
nvme/023 (test NVMe smart-log command on NVMeOF block-device ns) [failed]
    runtime  0.359s  ...  0.338s
    --- tests/nvme/023.out	2018-12-09 23:39:23.000000000 -0500
    +++ /results/nodev/nvme/023.out.bad	2018-12-09 23:50:33.017926067 -0500
    @@ -1,5 +1,4 @@
     Running nvme/023
     91fdba0d-f87b-4c25-b80f-db7be1418b9e
     uuid.91fdba0d-f87b-4c25-b80f-db7be1418b9e
    -NQN:blktests-subsystem-1 disconnected 1 controller(s)
     Test complete
nvme/024 (test NVMe smart-log command on NVMeOF file-backed ns)
    runtime  0.308s  ...
nvme/024 (test NVMe smart-log command on NVMeOF file-backed ns) [failed]
    runtime  0.308s  ...  0.269s
    --- tests/nvme/024.out	2018-12-09 23:39:23.000000000 -0500
    +++ /results/nodev/nvme/024.out.bad	2018-12-09 23:50:33.351259401 -0500
    @@ -1,5 +1,4 @@
     Running nvme/024
     91fdba0d-f87b-4c25-b80f-db7be1418b9e
     uuid.91fdba0d-f87b-4c25-b80f-db7be1418b9e
    -NQN:blktests-subsystem-1 disconnected 1 controller(s)
     Test complete
nvme/025 (test NVMe effects-log command on NVMeOF file-backed ns)
    runtime  0.302s  ...
nvme/025 (test NVMe effects-log command on NVMeOF file-backed ns) [failed]
    runtime  0.302s  ...  0.294s
    --- tests/nvme/025.out	2018-12-09 23:39:23.000000000 -0500
    +++ /results/nodev/nvme/025.out.bad	2018-12-09 23:50:33.724592735 -0500
    @@ -1,5 +1,4 @@
     Running nvme/025
     91fdba0d-f87b-4c25-b80f-db7be1418b9e
     uuid.91fdba0d-f87b-4c25-b80f-db7be1418b9e
    -NQN:blktests-subsystem-1 disconnected 1 controller(s)
    -Test complete
    +Test Failed
nvme/026 (test NVMe ns-descs command on NVMeOF file-backed ns)
    runtime  0.291s  ...
nvme/026 (test NVMe ns-descs command on NVMeOF file-backed ns) [failed]
    runtime  0.291s  ...  0.264s
    --- tests/nvme/026.out	2018-12-09 23:39:23.000000000 -0500
    +++ /results/nodev/nvme/026.out.bad	2018-12-09 23:50:34.077926069 -0500
    @@ -1,5 +1,4 @@
     Running nvme/026
     91fdba0d-f87b-4c25-b80f-db7be1418b9e
     uuid.91fdba0d-f87b-4c25-b80f-db7be1418b9e
    -NQN:blktests-subsystem-1 disconnected 1 controller(s)
    -Test complete
    +Test Failed
nvme/027 (test NVMe ns-rescan command on NVMeOF file-backed ns)
    runtime  0.288s  ...
nvme/027 (test NVMe ns-rescan command on NVMeOF file-backed ns) [failed]
    runtime  0.288s  ...  0.293s
    --- tests/nvme/027.out	2018-12-09 23:39:23.000000000 -0500
    +++ /results/nodev/nvme/027.out.bad	2018-12-09 23:50:34.417926069 -0500
    @@ -1,5 +1,4 @@
     Running nvme/027
     91fdba0d-f87b-4c25-b80f-db7be1418b9e
     uuid.91fdba0d-f87b-4c25-b80f-db7be1418b9e
    -NQN:blktests-subsystem-1 disconnected 1 controller(s)
    -Test complete
    +Test Failed
nvme/028 (test NVMe list-subsys command on NVMeOF file-backed ns)
    runtime  0.297s  ...
nvme/028 (test NVMe list-subsys command on NVMeOF file-backed ns) [failed]
    runtime  0.297s  ...  0.284s
    --- tests/nvme/028.out	2018-12-09 23:39:23.000000000 -0500
    +++ /results/nodev/nvme/028.out.bad	2018-12-09 23:50:34.744592735 -0500
    @@ -1,5 +1,5 @@
     Running nvme/028
     91fdba0d-f87b-4c25-b80f-db7be1418b9e
     uuid.91fdba0d-f87b-4c25-b80f-db7be1418b9e
    -NQN:blktests-subsystem-1 disconnected 1 controller(s)
    -Test complete
    +The '<device>' may be either an NVMe character device (ex: /dev/nvme0) or an
    +nvme block device (ex: /dev/nvme0n1).Test Failed
              total        used        free      shared  buff/cache   available
Mem:           1979          55        1787           8         136        1882
Swap:             0           0           0
END BLKTESTS Sun Dec  9 23:50:34 EST 2018



[Index of Archives]     [Linux RAID]     [Linux SCSI]     [Linux ATA RAID]     [IDE]     [Linux Wireless]     [Linux Kernel]     [ATH6KL]     [Linux Bluetooth]     [Linux Netdev]     [Kernel Newbies]     [Security]     [Git]     [Netfilter]     [Bugtraq]     [Yosemite News]     [MIPS Linux]     [ARM Linux]     [Linux Security]     [Device Mapper]

  Powered by Linux