tests: `nvme-cli - nvme_copy_test`: Command Size Limit Exceeded

[igaw]

When running the tests against a Qemu nvme device, the nvme_copy_test fails. Figure out what's the problem.

root@localhost:/home/wagi/work/nvme-cli/.build-debian# /usr/bin/python3 /home/wagi/work/nvme-cli/tests/tap_runner.py --start-dir /home/wagi/work/nvme-cli/tests nvme_copy_test

TAP version 13
1..1
# Using nvme binary 'nvme'
# Running: find /sys/devices -name \*nvme0 | grep -i pci
# /sys/devices/pci0000:00/0000:00:05.0/nvme/nvme0
#
# Running: nvme id-ctrl /dev/nvme0 --output-format=json
# {
#   "vid":6966,
#   "ssvid":6900,
#   "sn":"nvme-0              ",
#   "mn":"QEMU NVMe Ctrl                          ",
#   "fr":"10.1.5  ",
#   "rab":6,
#   "ieee":5395456,
#   "cmic":0,
#   "mdts":7,
#   "cntlid":0,
#   "ver":66560,
#   "rtd3r":0,
#   "rtd3e":0,
#   "oaes":256,
#   "ctratt":32768,
#   "rrls":0,
#   "bpcap":0,
#   "nssl":0,
#   "plsi":0,
#   "cntrltype":1,
#   "fguid":"00000000-0000-0000-0000-000000000000",
#   "crdt1":0,
#   "crdt2":0,
#   "crdt3":0,
#   "crcap":0,
#   "nvmsr":0,
#   "vwci":0,
#   "mec":0,
#   "oacs":298,
#   "acl":3,
#   "aerl":3,
#   "frmw":3,
#   "lpa":7,
#   "elpe":0,
#   "npss":0,
#   "avscc":0,
#   "apsta":0,
#   "wctemp":343,
#   "cctemp":373,
#   "mtfa":0,
#   "hmpre":0,
#   "hmmin":0,
#   "tnvmcap":0,
#   "unvmcap":0,
#   "rpmbs":0,
#   "edstt":0,
#   "dsto":0,
#   "fwug":0,
#   "kas":0,
#   "hctma":0,
#   "mntmt":0,
#   "mxtmt":0,
#   "sanicap":0,
#   "hmminds":0,
#   "hmmaxd":0,
#   "nsetidmax":0,
#   "endgidmax":0,
#   "anatt":0,
#   "anacap":0,
#   "anagrpmax":0,
#   "nanagrpid":0,
#   "pels":0,
#   "domainid":0,
#   "kpioc":0,
#   "mptfawr":0,
#   "megcap":0,
#   "tmpthha":0,
#   "cqt":0,
#   "cdpa":0,
#   "mup":0,
#   "ipmsr":0,
#   "msmt":0,
#   "sqes":102,
#   "cqes":68,
#   "maxcmd":0,
#   "nn":256,
#   "oncs":1885,
#   "fuses":0,
#   "fna":0,
#   "vwc":7,
#   "awun":0,
#   "awupf":0,
#   "icsvscc":0,
#   "nwpc":0,
#   "acwu":0,
#   "ocfs":15,
#   "sgls":524289,
#   "mnan":0,
#   "maxdna":0,
#   "maxcna":0,
#   "oaqd":0,
#   "rhiri":0,
#   "hirt":0,
#   "cmmrtd":0,
#   "nmmrtd":0,
#   "minmrtg":0,
#   "maxmrtg":0,
#   "trattr":0,
#   "mcudmq":0,
#   "mnsudmq":0,
#   "mcmr":0,
#   "nmcmr":0,
#   "mcdqpc":0,
#   "subnqn":"nqn.2019-08.org.qemu:nvme-0",
#   "ioccsz":0,
#   "iorcsz":0,
#   "icdoff":0,
#   "fcatt":0,
#   "msdbd":0,
#   "ofcs":0,
#   "dctype":0,
#   "ccrl":0,
#   "psds":[
#     {
#       "max_power":2500,
#       "max_power_scale":0,
#       "non-operational_state":0,
#       "entry_lat":16,
#       "exit_lat":4,
#       "read_tput":0,
#       "read_lat":0,
#       "write_tput":0,
#       "write_lat":0,
#       "idle_power":0,
#       "idle_scale":0,
#       "active_power":0,
#       "active_power_work":0,
#       "active_scale":0,
#       "emerg_power_fail_recover_time":0,
#       "emerg_power_fail_recover_scale":0,
#       "force_quiesce_vault_time":0,
#       "force_quiesce_vault_scale":0,
#       "emerg_power_fail_vault_time":0,
#       "emerg_power_fail_vault_scale":0
#     }
#   ]
# }
#
# setup: ctrl: /dev/nvme0, ns1: /dev/nvme0n1, default_nsid: 1, flbas: 0
# Running: nvme id-ctrl /dev/nvme0 --output-format=json
# {
#   "vid":6966,
#   "ssvid":6900,
#   "sn":"nvme-0              ",
#   "mn":"QEMU NVMe Ctrl                          ",
#   "fr":"10.1.5  ",
#   "rab":6,
#   "ieee":5395456,
#   "cmic":0,
#   "mdts":7,
#   "cntlid":0,
#   "ver":66560,
#   "rtd3r":0,
#   "rtd3e":0,
#   "oaes":256,
#   "ctratt":32768,
#   "rrls":0,
#   "bpcap":0,
#   "nssl":0,
#   "plsi":0,
#   "cntrltype":1,
#   "fguid":"00000000-0000-0000-0000-000000000000",
#   "crdt1":0,
#   "crdt2":0,
#   "crdt3":0,
#   "crcap":0,
#   "nvmsr":0,
#   "vwci":0,
#   "mec":0,
#   "oacs":298,
#   "acl":3,
#   "aerl":3,
#   "frmw":3,
#   "lpa":7,
#   "elpe":0,
#   "npss":0,
#   "avscc":0,
#   "apsta":0,
#   "wctemp":343,
#   "cctemp":373,
#   "mtfa":0,
#   "hmpre":0,
#   "hmmin":0,
#   "tnvmcap":0,
#   "unvmcap":0,
#   "rpmbs":0,
#   "edstt":0,
#   "dsto":0,
#   "fwug":0,
#   "kas":0,
#   "hctma":0,
#   "mntmt":0,
#   "mxtmt":0,
#   "sanicap":0,
#   "hmminds":0,
#   "hmmaxd":0,
#   "nsetidmax":0,
#   "endgidmax":0,
#   "anatt":0,
#   "anacap":0,
#   "anagrpmax":0,
#   "nanagrpid":0,
#   "pels":0,
#   "domainid":0,
#   "kpioc":0,
#   "mptfawr":0,
#   "megcap":0,
#   "tmpthha":0,
#   "cqt":0,
#   "cdpa":0,
#   "mup":0,
#   "ipmsr":0,
#   "msmt":0,
#   "sqes":102,
#   "cqes":68,
#   "maxcmd":0,
#   "nn":256,
#   "oncs":1885,
#   "fuses":0,
#   "fna":0,
#   "vwc":7,
#   "awun":0,
#   "awupf":0,
#   "icsvscc":0,
#   "nwpc":0,
#   "acwu":0,
#   "ocfs":15,
#   "sgls":524289,
#   "mnan":0,
#   "maxdna":0,
#   "maxcna":0,
#   "oaqd":0,
#   "rhiri":0,
#   "hirt":0,
#   "cmmrtd":0,
#   "nmmrtd":0,
#   "minmrtg":0,
#   "maxmrtg":0,
#   "trattr":0,
#   "mcudmq":0,
#   "mnsudmq":0,
#   "mcmr":0,
#   "nmcmr":0,
#   "mcdqpc":0,
#   "subnqn":"nqn.2019-08.org.qemu:nvme-0",
#   "ioccsz":0,
#   "iorcsz":0,
#   "icdoff":0,
#   "fcatt":0,
#   "msdbd":0,
#   "ofcs":0,
#   "dctype":0,
#   "ccrl":0,
#   "psds":[
#     {
#       "max_power":2500,
#       "max_power_scale":0,
#       "non-operational_state":0,
#       "entry_lat":16,
#       "exit_lat":4,
#       "read_tput":0,
#       "read_lat":0,
#       "write_tput":0,
#       "write_lat":0,
#       "idle_power":0,
#       "idle_scale":0,
#       "active_power":0,
#       "active_power_work":0,
#       "active_scale":0,
#       "emerg_power_fail_recover_time":0,
#       "emerg_power_fail_recover_scale":0,
#       "force_quiesce_vault_time":0,
#       "force_quiesce_vault_scale":0,
#       "emerg_power_fail_vault_time":0,
#       "emerg_power_fail_vault_scale":0
#     }
#   ]
# }
#
# Running: nvme get-feature /dev/nvme0 --feature-id=0x16 --data-len=512 --raw-binary
#
# Running: nvme set-feature /dev/nvme0 --feature-id=0x16 --data-len=512
# set-feature:0x16 (Host Behavior), value:00000000, cdw12:00000000, save:0
#        0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f
# 0000: 00 00 01 00 62 27 5c 78 30 63 5c 78 30 30 27 00 "....b'\x0c\x00'."
# 0010: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 "................"
# *
# 0200:
#
#
# Running: nvme get-ns-id /dev/nvme0n1
# nvme0n1: namespace-id:1
#
# Running: nvme copy /dev/nvme0n1 --format=0 --sdlba=0 --blocks=1 --slbs=2
# NVMe status: Command Size Limit Exceeded(0x4183)
#
not ok 1 - test_copy (TestNVMeCopy)
  ---
  traceback: |
    Traceback (most recent call last):
      File "/usr/lib/python3.11/unittest/case.py", line 57, in testPartExecutor
        yield
      File "/usr/lib/python3.11/unittest/case.py", line 623, in run
        self._callTestMethod(testMethod)
      File "/usr/lib/python3.11/unittest/case.py", line 579, in _callTestMethod
        if method() is not None:
           ^^^^^^^^
      File "/home/wagi/work/nvme-cli/tests/nvme_copy_test.py", line 106, in test_copy
        self.copy(0, 1, 2, descriptor_format=0)
      File "/home/wagi/work/nvme-cli/tests/nvme_copy_test.py", line 102, in copy
        self.assertEqual(self.exec_cmd(copy_cmd), 0)
    AssertionError: 1 != 0
  ...
# Running: nvme set-feature /dev/nvme0 --feature-id=0x16 --data-len=512
# set-feature:0x16 (Host Behavior), value:00000000, cdw12:00000000, save:0
#        0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f
# 0000: 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 "................"
# 0010: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 "................"
# *
# 0200:
#
#

[ikegami-t]

Just pushed the PR: #3323 then seems the issue can be resolved by the chanes.

(Deleted)
Sorry the nr value is correctly set with minus 1 then the PR was incorrect.

static inline void
nvme_init_copy(struct libnvme_passthru_cmd *cmd, __u32 nsid, __u64 sdlba,
		__u16 nr, __u8 desfmt, __u8 prinfor, __u8 prinfow,
		__u8 cetype, __u8 dtype, bool stcw, bool stcr, bool fua,
		bool lr, __u16 cev, __u16 dspec, void *cpydsc)
{
...
	cmd->cdw12 = NVME_FIELD_ENCODE(nr - 1,
			NVME_COPY_CDW12_NR_SHIFT,
			NVME_COPY_CDW12_NR_MASK) |

[igaw]

Note, this tests work in the nightly CI runs against real hardware. It's either a bug in Qemu's nvme implementation or the tests should detect that this is not supported.

correction, the real hardware doesn't support this operation:

# Running: /nvme-cli/.build-ci/nvme get-ns-id /dev/nvme1n1
# nvme1n1: namespace-id:1
# 
# Skip copy because descriptor format 0 is not supported
# Skip copy because descriptor format 1 is not supported
# Skip copy because descriptor format 2 is not supported
# Skip copy because descriptor format 2 is not supported
# Skip copy because descriptor format 3 is not supported
# Skip copy because descriptor format 3 is not supported

So there is another bug in the test framework. this tests should then be marked as skipped...

[igaw]

root@localhost:/home/wagi/work/nvme-cli/.build-debian# nvme copy /dev/nvme0n1 --format=0 --sdlba=0 --blocks=1 --slbs=2 -vv
opcode       : 06
flags        : 00
rsvd1        : 0000
nsid         : 00000001
cdw2         : 00000000
cdw3         : 00000000
data_len     : 00001000
metadata_len : 00000000
addr         : 5610a7865000
metadata     : 0
cdw10        : 00000000
cdw11        : 00000000
cdw12        : 00000000
cdw13        : 00000000
cdw14        : 00000000
cdw15        : 00000000
timeout_ms   : 00000000
result       : 0
err          : 0
latency      : 156 us
opcode       : 06
flags        : 00
rsvd1        : 0000
nsid         : 00000001
cdw2         : 00000000
cdw3         : 00000000
data_len     : 00001000
metadata_len : 00000000
addr         : 5610a7867000
metadata     : 0
cdw10        : 00000005
cdw11        : 00000000
cdw12        : 00000000
cdw13        : 00000000
cdw14        : 00000000
cdw15        : 00000000
timeout_ms   : 00000000
result       : 0
err          : 0
latency      : 68 us
opcode       : 19
flags        : 00
rsvd1        : 0000
nsid         : 00000001
cdw2         : 00000000
cdw3         : 00000000
data_len     : 00000020
metadata_len : 00000000
addr         : 5610a7861000
metadata     : 0
cdw10        : 00000000
cdw11        : 00000000
cdw12        : 00000000
cdw13        : 00000000
cdw14        : 00000000
cdw15        : 00000000
timeout_ms   : 00000000
result       : 0
err          : 16771
latency      : 75 us
NVMe status: Command Size Limit Exceeded(0x4183)

[igaw]

Since we get Command Size Limit Exceeded as status, I think the descriptor might not be correct. Let's check what we do there.

[igaw]

Argh, back to our big vs little endian interpretation of the tags. Qemu interpretes them as little endian:

https://github.com/qemu/qemu/blob/aa15257174da180c6a8a9d58f87319cfe61c5520/hw/nvme/ctrl.c#L2798

The copy command implementation is here:

https://github.com/qemu/qemu/blob/aa15257174da180c6a8a9d58f87319cfe61c5520/hw/nvme/ctrl.c#L3324

[igaw]

The Qemu ctrl reports mcl=0 and if I read it correctly nvme_check_copy_mcl will return NVME_CMD_SIZE_LIMIT even for a nlb=0

static void nvme_copy_source_range_parse_format0_2(void *ranges,
                                                   int idx, uint64_t *slba,
                                                   uint32_t *nlb,
                                                   uint32_t *snsid,
                                                   uint16_t *apptag,
                                                   uint16_t *appmask,
                                                   uint64_t *reftag)
{
[...]
    if (nlb) {
        *nlb = le16_to_cpu(_ranges[idx].nlb) + 1;
    }
[...]
}


static void nvme_copy_source_range_parse(void *ranges, int idx, uint8_t format,
                                         uint64_t *slba, uint32_t *nlb,
                                         uint32_t *snsid, uint16_t *apptag,
                                         uint16_t *appmask, uint64_t *reftag)
{
    switch (format) {
    case NVME_COPY_FORMAT_0:
    case NVME_COPY_FORMAT_2:
        nvme_copy_source_range_parse_format0_2(ranges, idx, slba, nlb, snsid,
                                               apptag, appmask, reftag);
[...]
}

static inline uint16_t nvme_check_copy_mcl(NvmeNamespace *ns,
                                           NvmeCopyAIOCB *iocb, uint16_t nr)
{
    uint32_t copy_len = 0;

    for (int idx = 0; idx < nr; idx++) {
        uint32_t nlb;
        nvme_copy_source_range_parse(iocb->ranges, idx, iocb->format, NULL,
                                     &nlb, NULL, NULL, NULL, NULL);
        copy_len += nlb;
    }
    iocb->tcl = copy_len;
    if (copy_len > ns->id_ns.mcl) {
        return NVME_CMD_SIZE_LIMIT | NVME_DNR;
    }

    return NVME_SUCCESS;
}

root@localhost:~# nvme id-ns /dev/nvme0n1
NVME Identify Namespace 1:
nsze    : 0x200000
ncap    : 0x200000
nuse    : 0x200000
nsfeat  : 0x34
nlbaf   : 7
flbas   : 0
mc      : 0x3
dpc     : 0x1f
dps     : 0
nmic    : 0
rescap  : 0
fpi     : 0
dlfeat  : 1
nawun   : 0
nawupf  : 0
nacwu   : 0
nabsn   : 0
nabo    : 0
nabspf  : 0
noiob   : 0
nvmcap  : 0
npwg    : 0
npwa    : 0
npdg    : 7
npda    : 7
nows    : 0
mssrl   : 0
mcl     : 0
msrc    : 0
kpios   : 0
nulbaf  : 0
kpiodaag: 0
anagrpid: 0
nsattr  : 0
nvmsetid: 0
endgid  : 0
nguid   : 00000000000000000000000000000000
eui64   : 0000000000000000
lbaf  0 : ms:0   lbads:9  rp:0 (in use)
lbaf  1 : ms:8   lbads:9  rp:0
lbaf  2 : ms:16  lbads:9  rp:0
lbaf  3 : ms:64  lbads:9  rp:0
lbaf  4 : ms:0   lbads:12 rp:0
lbaf  5 : ms:8   lbads:12 rp:0
lbaf  6 : ms:16  lbads:12 rp:0
lbaf  7 : ms:64  lbads:12 rp:0

[igaw]

It turns out, it's necessary to set mcl, mssrl and msrc parameters via the Qemu command line:

-drive file=/home/wagi/images/nvme.raw,format=raw,if=none,id=ns0 \
-device nvme,id=nvme0,serial=nvme-0,bus=pcie.0,addr=0x5${nvme_args} \
-device nvme-ns,drive=ns0,nsid=1,mcl=1024,mssrl=1024,msrc=63

and we get a different error:

# Running: nvme get-feature /dev/nvme0 --feature-id=0x16 --data-len=512 --raw-binary
#
# Running: nvme set-feature /dev/nvme0 --feature-id=0x16 --data-len=512
# set-feature:0x16 (Host Behavior), value:00000000, cdw12:00000000, save:0
#        0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f
# 0000: 00 00 01 00 62 27 5c 78 30 63 5c 78 30 30 27 00 "....b'\x0c\x00'."
# 0010: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 "................"
# *
# 0200:
#
#
# Running: nvme get-ns-id /dev/nvme0n1
# nvme0n1: namespace-id:1
#
# Running: nvme copy /dev/nvme0n1 --format=0 --sdlba=0 --blocks=1 --slbs=2
# NVMe Copy: success
#
# Running: nvme copy /dev/nvme0n1 --format=1 --sdlba=0 --blocks=1 --slbs=2
# NVMe status: Invalid Format: The LBA Format specified is not supported(0x410a)
#
not ok 1 - test_copy (TestNVMeCopy)
  ---
  traceback: |
    Traceback (most recent call last):
      File "/usr/lib/python3.11/unittest/case.py", line 57, in testPartExecutor
        yield
      File "/usr/lib/python3.11/unittest/case.py", line 623, in run
        self._callTestMethod(testMethod)
      File "/usr/lib/python3.11/unittest/case.py", line 579, in _callTestMethod
        if method() is not None:
           ^^^^^^^^
      File "/home/wagi/work/nvme-cli/tests/nvme_copy_test.py", line 107, in test_copy
        self.copy(0, 1, 2, descriptor_format=1)
      File "/home/wagi/work/nvme-cli/tests/nvme_copy_test.py", line 102, in copy
        self.assertEqual(self.exec_cmd(copy_cmd), 0)
    AssertionError: 1 != 0
  ...
# Running: nvme set-feature /dev/nvme0 --feature-id=0x16 --data-len=512
# set-feature:0x16 (Host Behavior), value:00000000, cdw12:00000000, save:0
#        0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f
# 0000: 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 "................"
# 0010: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 "................"
# *
# 0200:
#
#