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

[Sagi Grimberg <sagi@grimberg.me>]

>> 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