Re: [PATCH v2 blktests] tests/nvme: add tests for error logging

[Shinichiro Kawasaki <shinichiro.kawasaki@wdc.com>]

On May 11, 2022 / 13:25, Alan Adamson wrote:
> 
> 
> > On May 10, 2022, at 8:34 PM, Shinichiro Kawasaki <shinichiro.kawasaki@wdc.com> wrote:
> > 
> > On May 10, 2022 / 16:48, Sagi Grimberg wrote:
> >> 
> >>>> On 5/10/22 19:43, Alan Adamson wrote:
> >>>>> Test nvme error logging by injecting errors. Kernel must have FAULT_INJECTION
> >>>>> and FAULT_INJECTION_DEBUG_FS configured to use error injector. Tests can be
> >>>>> run with or without NVME_VERBOSE_ERRORS configured.
> >>>>> 
> >>>>> These test verify the functionality delivered by the follow:
> >>>>> 	commit bd83fe6f2cd2 ("nvme: add verbose error logging")
> >>>>> 
> >>>>> Signed-off-by: Alan Adamson <alan.adamson@oracle.com>
> >>>>> Signed-off-by: Chaitanya Kulkarni <kch@nvidia.com>
> >>>>> ---
> >>>>>   tests/nvme/039     | 185 +++++++++++++++++++++++++++++++++++++++++++++
> >>>>>   tests/nvme/039.out |   7 ++
> >>>>>   2 files changed, 192 insertions(+)
> >>>>>   create mode 100755 tests/nvme/039
> >>>>>   create mode 100644 tests/nvme/039.out
> >>>>> 
> >>>>> diff --git a/tests/nvme/039 b/tests/nvme/039
> >>>>> new file mode 100755
> >>>>> index 000000000000..e6d45a6e3fe5
> >>>>> --- /dev/null
> >>>>> +++ b/tests/nvme/039
> >>>>> @@ -0,0 +1,185 @@
> >>>>> +#!/bin/bash
> >>>>> +# SPDX-License-Identifier: GPL-3.0+
> >>>>> +# Copyright (C) 2022 Oracle and/or its affiliates
> >>>>> +#
> >>>>> +# Test nvme error logging by injecting errors. Kernel must have FAULT_INJECTION
> >>>>> +# and FAULT_INJECTION_DEBUG_FS configured to use error injector. Tests can be
> >>>>> +# run with or without NVME_VERBOSE_ERRORS configured.
> >>>>> +#
> >>>>> +# Test for commit bd83fe6f2cd2 ("nvme: add verbose error logging").
> >>>>> +
> >>>>> +. tests/nvme/rc
> >>>>> +DESCRIPTION="test error logging"
> >>>>> +QUICK=1
> >>>>> +
> >>>>> +requires() {
> >>>>> +	_nvme_requires
> >>>>> +	_have_kernel_option FAULT_INJECTION && \
> >>>>> +	    _have_kernel_option FAULT_INJECTION_DEBUG_FS
> >>>>> +}
> >>>>> +
> >>>>> +declare -A NS_DEV_FAULT_INJECT_SAVE
> >>>>> +declare -A CTRL_DEV_FAULT_INJECT_SAVE
> >>>>> +
> >>>>> +save_err_inject_attr()
> >>>>> +{
> >>>>> +	local a
> >>>>> +
> >>>>> +	for a in /sys/kernel/debug/"${ns_dev}"/fault_inject/*; do
> >>>>> +		NS_DEV_FAULT_INJECT_SAVE[${a}]=$(<"${a}")
> >>>>> +	done
> >>>>> +	for a in /sys/kernel/debug/"${ctrl_dev}"/fault_inject/*; do
> >>>>> +		CTRL_DEV_FAULT_INJECT_SAVE[${a}]=$(<"${a}")
> >>>>> +	done
> >>>>> +}
> >>>>> +
> >>>>> +restore_err_inject_attr()
> >>>>> +{
> >>>>> +	local a
> >>>>> +
> >>>>> +	for a in /sys/kernel/debug/"${ns_dev}"/fault_inject/*; do
> >>>>> +		echo "${NS_DEV_FAULT_INJECT_SAVE[${a}]}" > "${a}"
> >>>>> +	done
> >>>>> +	for a in /sys/kernel/debug/"${ctrl_dev}"/fault_inject/*; do
> >>>>> +		echo "${CTRL_DEV_FAULT_INJECT_SAVE[${a}]}" > "${a}"
> >>>>> +	done
> >>>>> +}
> >>>>> +
> >>>>> +set_verbose_prob_retry()
> >>>>> +{
> >>>>> +	echo 0 > /sys/kernel/debug/"$1"/fault_inject/verbose
> >>>>> +	echo 100 > /sys/kernel/debug/"$1"/fault_inject/probability
> >>>>> +	echo 1 > /sys/kernel/debug/"$1"/fault_inject/dont_retry
> >>>>> +}
> >>>>> +
> >>>>> +set_status_time()
> >>>>> +{
> >>>>> +	echo "$1" > /sys/kernel/debug/"$3"/fault_inject/status
> >>>>> +	echo "$2" > /sys/kernel/debug/"$3"/fault_inject/times
> >>>>> +}
> >>>>> +
> >>>>> +inject_unrec_read_err()
> >>>>> +{
> >>>>> +	# Inject a 'Unrecovered Read Error' error on a READ
> >>>>> +	set_status_time 0x281 1 "$1"
> >>>>> +
> >>>>> +	dd if=/dev/"$1" of=/dev/null bs=512 count=1 iflag=direct \
> >>>>> +	    2> /dev/null 1>&2
> >>>>> +
> >>>>> +	if ${nvme_verbose_errors}; then
> >>>>> +		dmesg -t | tail -2 | grep "Unrecovered Read Error (" | \
> >>>>> +		    sed 's/nvme.*://g'
> >>>>> +	else
> >>>>> +		dmesg -t | tail -2 | grep "Cmd(" | sed 's/I\/O Cmd/Read/g' | \
> >>>>> +		    sed 's/I\/O Error/Unrecovered Read Error/g' | \
> >>>>> +		    sed 's/nvme.*://g'
> >>>>> +	fi
> >>>>> +}
> >>>>> +
> >>>>> +inject_invalid_read_err()
> >>>>> +{
> >>>>> +	# Inject a valid invalid error status (0x375) on a READ
> >>>>> +	set_status_time 0x375 1 "$1"
> >>>>> +
> >>>>> +	dd if=/dev/"$1" of=/dev/null bs=512 count=1 iflag=direct \
> >>>>> +	    2> /dev/null 1>&2
> >>>>> +
> >>>>> +	if ${nvme_verbose_errors}; then
> >>>>> +		dmesg -t | tail -2 | grep "Unknown (" | \
> >>>>> +		    sed 's/nvme.*://g'
> >>>>> +	else
> >>>>> +		dmesg -t | tail -2 | grep "Cmd(" | sed 's/I\/O Cmd/Read/g' | \
> >>>>> +		    sed 's/I\/O Error/Unknown/g' | \
> >>>>> +		    sed 's/nvme.*://g'
> >>>>> +	fi
> >>>>> +}
> >>>>> +
> >>>>> +inject_write_fault()
> >>>>> +{
> >>>>> +	# Inject a 'Write Fault' error on a WRITE
> >>>>> +	set_status_time 0x280 1 "$1"
> >>>>> +
> >>>>> +	dd if=/dev/zero of=/dev/"$1" bs=512 count=1 oflag=direct \
> >>>>> +	    2> /dev/null 1>&2
> >>>>> +
> >>>>> +	if ${nvme_verbose_errors}; then
> >>>>> +		dmesg -t | tail -2 | grep "Write Fault (" | \
> >>>>> +		    sed 's/nvme.*://g'
> >>>>> +	else
> >>>>> +		dmesg -t | tail -2 | grep "Cmd(" | sed 's/I\/O Cmd/Write/g' | \
> >>>>> +		    sed 's/I\/O Error/Write Fault/g' | \
> >>>>> +		    sed 's/nvme.*://g'
> >>>>> +	fi
> >>>>> +}
> >>>>> +
> >>>>> +inject_id_admin()
> >>>>> +{
> >>>>> +	# Inject a valid (Identify) Admin command
> >>>>> +	set_status_time 0x286 1000 "$1"
> >>>>> +
> >>>>> +	nvme admin-passthru /dev/"$1" --opcode=0x06 --data-len=4096 \
> >>>>> +	    --cdw10=1 -r 2> /dev/null 1>&2
> >>>>> +
> >>>>> +	if ${nvme_verbose_errors}; then
> >>>>> +		dmesg -t | tail -1 | grep "Access Denied (" | \
> >>>>> +		    sed 's/nvme.*://g'
> >>>>> +	else
> >>>>> +		dmesg -t | tail -1 | grep "Admin Cmd(" | \
> >>>>> +		    sed 's/Admin Cmd/Identify/g' | \
> >>>>> +		    sed 's/I\/O Error/Access Denied/g' | \
> >>>>> +		    sed 's/nvme.*://g'
> >>>>> +	fi
> >>>>> +}
> >>>>> +
> >>>>> +inject_invalid_cmd()
> >>>>> +{
> >>>>> +	# Inject an invalid command (0x96)
> >>>>> +	set_status_time 0x1 1 "$1"
> >>>>> +
> >>>>> +	nvme admin-passthru /dev/"$1" --opcode=0x96 --data-len=4096 \
> >>>>> +	    --cdw10=1 -r 2> /dev/null 1>&2
> >>>>> +	if ${nvme_verbose_errors}; then
> >>>>> +		dmesg -t | tail -1 | grep "Invalid Command Opcode (" | \
> >>>>> +		    sed 's/nvme.*://g'
> >>>>> +	else
> >>>>> +		dmesg -t | tail -1 | grep "Admin Cmd(" | \
> >>>>> +		    sed 's/Admin Cmd/Unknown/g' | \
> >>>>> +		    sed 's/I\/O Error/Invalid Command Opcode/g' | \
> >>>>> +		    sed 's/nvme.*://g'
> >>>>> +	fi
> >>>>> +}
> >>>>> +
> >>>> 
> >>>> All of the above seems like they belong in common code...
> >>> 
> >>> So far, this nvme/039 is the only one user of the helper functions above. Do you
> >>> foresee that future new test cases in nvmeof-mp or srp group will use them?
> >>> 
> >> 
> >> I can absolutely see other tests inject errors. I meant that this code
> >> should live in nvme/rc
> 
> Should the helpers inject errors itself (_nvme_inject_write_fault), or just provide the functions to setup the
> error injector (_nvme_set_inject) and let the test specify the error status and do the IO that causes the injected
> error?

Per Sagi's comment, I assume the 4 inject_*() functions similar as the v2 patch
are desired in nvme/rc. So I assume the helpers to "inject errors itself".
Having said that, "the functions to setup the error injector" sounds simple and
good as the common helper function.

Sagi, do you have preference on this?

-- 
Best Regards,
Shin'ichiro Kawasaki