^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 1) NVMe Fault Injection
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 2) ====================
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 3) Linux's fault injection framework provides a systematic way to support
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 4) error injection via debugfs in the /sys/kernel/debug directory. When
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 5) enabled, the default NVME_SC_INVALID_OPCODE with no retry will be
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 6) injected into the nvme_try_complete_req. Users can change the default status
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 7) code and no retry flag via the debugfs. The list of Generic Command
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 8) Status can be found in include/linux/nvme.h
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 9)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 10) Following examples show how to inject an error into the nvme.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 11)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 12) First, enable CONFIG_FAULT_INJECTION_DEBUG_FS kernel config,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 13) recompile the kernel. After booting up the kernel, do the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 14) following.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 15)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 16) Example 1: Inject default status code with no retry
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 17) ---------------------------------------------------
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 18)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 19) ::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 20)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 21) mount /dev/nvme0n1 /mnt
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 22) echo 1 > /sys/kernel/debug/nvme0n1/fault_inject/times
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 23) echo 100 > /sys/kernel/debug/nvme0n1/fault_inject/probability
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 24) cp a.file /mnt
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 25)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 26) Expected Result::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 27)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 28) cp: cannot stat ‘/mnt/a.file’: Input/output error
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 29)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 30) Message from dmesg::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 31)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 32) FAULT_INJECTION: forcing a failure.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 33) name fault_inject, interval 1, probability 100, space 0, times 1
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 34) CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.15.0-rc8+ #2
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 35) Hardware name: innotek GmbH VirtualBox/VirtualBox,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 36) BIOS VirtualBox 12/01/2006
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 37) Call Trace:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 38) <IRQ>
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 39) dump_stack+0x5c/0x7d
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 40) should_fail+0x148/0x170
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 41) nvme_should_fail+0x2f/0x50 [nvme_core]
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 42) nvme_process_cq+0xe7/0x1d0 [nvme]
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 43) nvme_irq+0x1e/0x40 [nvme]
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 44) __handle_irq_event_percpu+0x3a/0x190
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 45) handle_irq_event_percpu+0x30/0x70
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 46) handle_irq_event+0x36/0x60
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 47) handle_fasteoi_irq+0x78/0x120
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 48) handle_irq+0xa7/0x130
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 49) ? tick_irq_enter+0xa8/0xc0
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 50) do_IRQ+0x43/0xc0
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 51) common_interrupt+0xa2/0xa2
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 52) </IRQ>
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 53) RIP: 0010:native_safe_halt+0x2/0x10
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 54) RSP: 0018:ffffffff82003e90 EFLAGS: 00000246 ORIG_RAX: ffffffffffffffdd
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 55) RAX: ffffffff817a10c0 RBX: ffffffff82012480 RCX: 0000000000000000
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 56) RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 57) RBP: 0000000000000000 R08: 000000008e38ce64 R09: 0000000000000000
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 58) R10: 0000000000000000 R11: 0000000000000000 R12: ffffffff82012480
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 59) R13: ffffffff82012480 R14: 0000000000000000 R15: 0000000000000000
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 60) ? __sched_text_end+0x4/0x4
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 61) default_idle+0x18/0xf0
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 62) do_idle+0x150/0x1d0
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 63) cpu_startup_entry+0x6f/0x80
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 64) start_kernel+0x4c4/0x4e4
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 65) ? set_init_arg+0x55/0x55
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 66) secondary_startup_64+0xa5/0xb0
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 67) print_req_error: I/O error, dev nvme0n1, sector 9240
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 68) EXT4-fs error (device nvme0n1): ext4_find_entry:1436:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 69) inode #2: comm cp: reading directory lblock 0
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 70)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 71) Example 2: Inject default status code with retry
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 72) ------------------------------------------------
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 73)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 74) ::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 75)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 76) mount /dev/nvme0n1 /mnt
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 77) echo 1 > /sys/kernel/debug/nvme0n1/fault_inject/times
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 78) echo 100 > /sys/kernel/debug/nvme0n1/fault_inject/probability
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 79) echo 1 > /sys/kernel/debug/nvme0n1/fault_inject/status
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 80) echo 0 > /sys/kernel/debug/nvme0n1/fault_inject/dont_retry
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 81)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 82) cp a.file /mnt
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 83)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 84) Expected Result::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 85)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 86) command success without error
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 87)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 88) Message from dmesg::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 89)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 90) FAULT_INJECTION: forcing a failure.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 91) name fault_inject, interval 1, probability 100, space 0, times 1
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 92) CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.15.0-rc8+ #4
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 93) Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 94) Call Trace:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 95) <IRQ>
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 96) dump_stack+0x5c/0x7d
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 97) should_fail+0x148/0x170
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 98) nvme_should_fail+0x30/0x60 [nvme_core]
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 99) nvme_loop_queue_response+0x84/0x110 [nvme_loop]
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 100) nvmet_req_complete+0x11/0x40 [nvmet]
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 101) nvmet_bio_done+0x28/0x40 [nvmet]
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 102) blk_update_request+0xb0/0x310
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 103) blk_mq_end_request+0x18/0x60
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 104) flush_smp_call_function_queue+0x3d/0xf0
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 105) smp_call_function_single_interrupt+0x2c/0xc0
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 106) call_function_single_interrupt+0xa2/0xb0
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 107) </IRQ>
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 108) RIP: 0010:native_safe_halt+0x2/0x10
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 109) RSP: 0018:ffffc9000068bec0 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff04
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 110) RAX: ffffffff817a10c0 RBX: ffff88011a3c9680 RCX: 0000000000000000
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 111) RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 112) RBP: 0000000000000001 R08: 000000008e38c131 R09: 0000000000000000
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 113) R10: 0000000000000000 R11: 0000000000000000 R12: ffff88011a3c9680
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 114) R13: ffff88011a3c9680 R14: 0000000000000000 R15: 0000000000000000
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 115) ? __sched_text_end+0x4/0x4
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 116) default_idle+0x18/0xf0
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 117) do_idle+0x150/0x1d0
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 118) cpu_startup_entry+0x6f/0x80
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 119) start_secondary+0x187/0x1e0
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 120) secondary_startup_64+0xa5/0xb0
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 121)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 122) Example 3: Inject an error into the 10th admin command
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 123) ------------------------------------------------------
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 124)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 125) ::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 126)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 127) echo 100 > /sys/kernel/debug/nvme0/fault_inject/probability
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 128) echo 10 > /sys/kernel/debug/nvme0/fault_inject/space
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 129) echo 1 > /sys/kernel/debug/nvme0/fault_inject/times
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 130) nvme reset /dev/nvme0
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 131)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 132) Expected Result::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 133)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 134) After NVMe controller reset, the reinitialization may or may not succeed.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 135) It depends on which admin command is actually forced to fail.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 136)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 137) Message from dmesg::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 138)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 139) nvme nvme0: resetting controller
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 140) FAULT_INJECTION: forcing a failure.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 141) name fault_inject, interval 1, probability 100, space 1, times 1
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 142) CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.2.0-rc2+ #2
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 143) Hardware name: MSI MS-7A45/B150M MORTAR ARCTIC (MS-7A45), BIOS 1.50 04/25/2017
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 144) Call Trace:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 145) <IRQ>
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 146) dump_stack+0x63/0x85
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 147) should_fail+0x14a/0x170
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 148) nvme_should_fail+0x38/0x80 [nvme_core]
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 149) nvme_irq+0x129/0x280 [nvme]
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 150) ? blk_mq_end_request+0xb3/0x120
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 151) __handle_irq_event_percpu+0x84/0x1a0
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 152) handle_irq_event_percpu+0x32/0x80
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 153) handle_irq_event+0x3b/0x60
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 154) handle_edge_irq+0x7f/0x1a0
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 155) handle_irq+0x20/0x30
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 156) do_IRQ+0x4e/0xe0
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 157) common_interrupt+0xf/0xf
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 158) </IRQ>
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 159) RIP: 0010:cpuidle_enter_state+0xc5/0x460
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 160) Code: ff e8 8f 5f 86 ff 80 7d c7 00 74 17 9c 58 0f 1f 44 00 00 f6 c4 02 0f 85 69 03 00 00 31 ff e8 62 aa 8c ff fb 66 0f 1f 44 00 00 <45> 85 ed 0f 88 37 03 00 00 4c 8b 45 d0 4c 2b 45 b8 48 ba cf f7 53
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 161) RSP: 0018:ffffffff88c03dd0 EFLAGS: 00000246 ORIG_RAX: ffffffffffffffdc
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 162) RAX: ffff9dac25a2ac80 RBX: ffffffff88d53760 RCX: 000000000000001f
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 163) RDX: 0000000000000000 RSI: 000000002d958403 RDI: 0000000000000000
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 164) RBP: ffffffff88c03e18 R08: fffffff75e35ffb7 R09: 00000a49a56c0b48
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 165) R10: ffffffff88c03da0 R11: 0000000000001b0c R12: ffff9dac25a34d00
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 166) R13: 0000000000000006 R14: 0000000000000006 R15: ffffffff88d53760
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 167) cpuidle_enter+0x2e/0x40
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 168) call_cpuidle+0x23/0x40
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 169) do_idle+0x201/0x280
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 170) cpu_startup_entry+0x1d/0x20
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 171) rest_init+0xaa/0xb0
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 172) arch_call_rest_init+0xe/0x1b
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 173) start_kernel+0x51c/0x53b
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 174) x86_64_start_reservations+0x24/0x26
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 175) x86_64_start_kernel+0x74/0x77
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 176) secondary_startup_64+0xa4/0xb0
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 177) nvme nvme0: Could not set queue count (16385)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 178) nvme nvme0: IO queues not created
Orange Pi5 kernel
Deprecated Linux kernel 5.10.110 for OrangePi 5/5B/5+ boards
3 Commits
0 Branches
0 Tags