2021-04-20 06:48:30

by kernel test robot

[permalink] [raw]
Subject: [nvme] ba887975f3: WARNING:at_block/blk-core.c:#blk_update_request



Greeting,

FYI, we noticed the following commit (built with gcc-9):

commit: ba887975f326c8ca067a801ff2824b4bd03c2b2b ("nvme: return BLK_STS_DO_NOT_RETRY if the DNR bit is set")
https://git.kernel.org/cgit/linux/kernel/git/device-mapper/linux-dm.git nvme-error-handling-fixes/for-5.13-v4


in testcase: fio-basic
version: fio-x86_64-3.15-1_20200907
with following parameters:

disk: 1SSD
fs: ext4
runtime: 300s
nr_task: 4
rw: write
bs: 4k
ioengine: libaio
test_size: 256g
cpufreq_governor: performance
ucode: 0x4003006

test-description: Fio is a tool that will spawn a number of threads or processes doing a particular type of I/O action as specified by the user.
test-url: https://github.com/axboe/fio


on test machine: 192 threads Intel(R) Xeon(R) CPU @ 2.20GHz with 192G memory

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):



If you fix the issue, kindly add following tag
Reported-by: kernel test robot <[email protected]>


[ 37.166074] WARNING: CPU: 96 PID: 0 at block/blk-core.c:216 blk_update_request (kbuild/src/consumer/block/blk-core.c:216 kbuild/src/consumer/block/blk-core.c:1429)
[ 37.182993] IOAPIC[11]: Preconfigured routing entry (21-2 -> IRQ 59 Level:1 ActiveLow:1)
0m.
[ 37.185105] Modules linked in: sysfillrect ahci(+) sysimgblt nvme libahci mei_me fb_sys_fops nvme_core intel_uncore(+) acpi_ipmi drm ioatdma(+) t10_pi ipmi_si(+) libata mei joydev intel_pch_thermal dca wmi ipmi_devintf ipmi_msghandler acpi_pad acpi_power_meter ip_tables
[ 37.206693] IOAPIC[11]: Preconfigured routing entry (21-3 -> IRQ 61 Level:1 ActiveLow:1)
[ 37.229452] CPU: 96 PID: 0 Comm: swapper/96 Not tainted 5.12.0-rc7-00001-gba887975f326 #1
[ 37.229456] RIP: 0010:blk_update_request (kbuild/src/consumer/block/blk-core.c:216 kbuild/src/consumer/block/blk-core.c:1429)
[ 37.250683] Code: 4e 68 be 00 10 00 00 8b 79 0c 8b 49 08 44 01 c7 44 29 c1 81 e7 ff 0f 00 00 29 fe 39 d1 0f 46 d1 39 d6 0f 46 d6 e9 9a fe ff ff <0f> 0b ba fb ff ff ff e9 b6 fc ff ff b8 30 00 00 00 e9 0c fd ff ff
All code
========
0: 4e 68 be 00 10 00 rex.WRX pushq $0x1000be
6: 00 8b 79 0c 8b 49 add %cl,0x498b0c79(%rbx)
c: 08 44 01 c7 or %al,-0x39(%rcx,%rax,1)
10: 44 29 c1 sub %r8d,%ecx
13: 81 e7 ff 0f 00 00 and $0xfff,%edi
19: 29 fe sub %edi,%esi
1b: 39 d1 cmp %edx,%ecx
1d: 0f 46 d1 cmovbe %ecx,%edx
20: 39 d6 cmp %edx,%esi
22: 0f 46 d6 cmovbe %esi,%edx
25: e9 9a fe ff ff jmpq 0xfffffffffffffec4
2a:* 0f 0b ud2 <-- trapping instruction
2c: ba fb ff ff ff mov $0xfffffffb,%edx
31: e9 b6 fc ff ff jmpq 0xfffffffffffffcec
36: b8 30 00 00 00 mov $0x30,%eax
3b: e9 0c fd ff ff jmpq 0xfffffffffffffd4c

Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: ba fb ff ff ff mov $0xfffffffb,%edx
7: e9 b6 fc ff ff jmpq 0xfffffffffffffcc2
c: b8 30 00 00 00 mov $0x30,%eax
11: e9 0c fd ff ff jmpq 0xfffffffffffffd22
[ 37.256590] ipmi_si IPI0001:00: IPMI kcs interface initialized
[ 37.269428] RSP: 0000:ffffc9000e184f28 EFLAGS: 00010202
Startin
[ 37.269433] RAX: 0000000000000011 RBX: 0000000000001000 RCX: 0000000000000002
[ 37.284540] IOAPIC[16]: Preconfigured routing entry (27-3 -> IRQ 71 Level:1 ActiveLow:1)
r to synchronize
[ 37.289011] RDX: 0000000000001000 RSI: 0000000000000011 RDI: ffff88811d054180
[ 37.315078] RBP: 0000000000000011 R08: 0000000000000000 R09: 0000000000000000
boot up for ifu
[ 37.322212] R10: 0000000000000010 R11: ffffffff828060c0 R12: ffff88811d054180
[ 37.330722] R13: 0000000000000011 R14: 0000000000000010 R15: 0000000000000011
[ 37.337854] FS: 0000000000000000(0000) GS:ffff888c4fc00000(0000) knlGS:0000000000000000
[ 37.347141] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 37.352889] CR2: 0000000000000000 CR3: 000000307e20a003 CR4: 00000000007706e0
[ 37.360020] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 37.367152] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 37.374284] PKRU: 55555554
Startin
[ 37.376996] Call Trace:
Journal to Pers
[ 37.384236] blk_mq_end_request (kbuild/src/consumer/block/blk-mq.c:564)
0m...
[ 37.395031] __do_softirq (kbuild/src/consumer/arch/x86/include/asm/jump_label.h:25 kbuild/src/consumer/include/linux/jump_label.h:200 kbuild/src/consumer/include/trace/events/irq.h:142 kbuild/src/consumer/kernel/softirq.c:346)
[ 37.399218] irq_exit_rcu (kbuild/src/consumer/kernel/softirq.c:221 kbuild/src/consumer/kernel/softirq.c:422 kbuild/src/consumer/kernel/softirq.c:434)
[ 37.402721] common_interrupt (kbuild/src/consumer/arch/x86/kernel/irq.c:240 (discriminator 14))
[ 37.406564] </IRQ>
[ 37.408671] asm_common_interrupt (kbuild/src/consumer/arch/x86/include/asm/idtentry.h:623)
1;39mHelper to s
[ 37.439351] RSP: 0000:ffffc9000cdf7e80 EFLAGS: 00000206
[ 37.445960] RAX: ffff888c4fc2b200 RBX: 0000000000000003 RCX: 000000000000001f
ynchronize boot
[ 37.453092] RDX: 0000000000000000 RSI: 000000003a518aaa RDI: 0000000000000000
[ 37.461602] RBP: ffffe8dc14601000 R08: 00000008a6c75d3d R09: 0000000000000404
[ 37.477245] R13: 00000008a6c75d3d R14: 0000000000000003 R15: 0000000000000000
[0m.
[ 37.484378] cpuidle_enter (kbuild/src/consumer/drivers/cpuidle/cpuidle.c:353)
[ 37.488468] do_idle (kbuild/src/consumer/kernel/sched/idle.c:243 kbuild/src/consumer/kernel/sched/idle.c:300)
[ 37.491711] cpu_startup_entry (kbuild/src/consumer/kernel/sched/idle.c:396 (discriminator 1))
[ 37.491713] start_secondary (kbuild/src/consumer/arch/x86/kernel/smpboot.c:273)
[ 37.499571] secondary_startup_64_no_verify (kbuild/src/consumer/arch/x86/kernel/head_64.S:283)
[ 37.504629] ---[ end trace 718afc489fdb815b ]---
[ 37.513917] scsi host0: ahci
[ 37.517734] scsi host1: ahci
[ 37.522607] nvme nvme0: 128/0/0 default/read/poll queues
1;39mRaise netwo
[ 37.544324] ahci 0000:00:17.0: AHCI 0001.0301 32 slots 4 ports 6 Gbps 0xf0 impl SATA mode
m.
[ 37.55343t is 2^-32 Joules, 1 fixed counters, 655360 ms ovfl timer
[ 38.084801] RAPL PMU: hw unit of domain package 2^-14 Joules
[ 38.108752] xor: automatically using best checksumming function avx
[ 37.324628] rc.local[2111]: PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
[ 38.205569] random: ln: uninitialized urandom read (6 bytes read)
:/lkp/lkp/src/bin
Startin
[ 38.217252] random: ln: uninitialized urandom read (6 bytes read)
LKP: HOSTNAME lkp-csl-2ap1, MAC a4:bf:01:68:bc:76, kernel 5.12.0-rc7-00001-gba887975f326 1, serial console /dev/ttyS0
Startin
[ 38.272439] Btrfs loaded, crc32c=crc32c-intel, zoned=yes
[ 38.309164] BTRFS: device fsid 66cddfe3-ba37-473d-94fa-7f52aeb2db9b devid 1 transid 6201 /dev/nvme0n1p3 scanned by systemd-udevd (1790)
[ 38.501976] EDAC MC3: Giving out device to module skx_edac controller Skylake Socket#1 IMC#1: DEV 0000:53:0c.0 (INTERRUPT)
[ 38.555494] EDAC MC7: Giving out device to module skx_edac controller Skylake Socket#3 IMC#1: DEV 0000:d3:0c.0 (INTERRUPT)
[ 38.642630] intel_rapl_common: Found RAPL domain package
[ 38.656760] intel_rapl_common: RAPL package-0-die-0 domain package locked by BIOS
[ 38.674606] intel_rapl_common: Found RAPL domain package
[ 38.688883] intel_rapl_common: RAPL package-0-die-1 domain package locked by BIOS
[ 38.706854] intel_rapl_common: Found RAPL domain package
[ 38.721173] intel_rapl_common: RAPL package-1-die-0 domain package locked by BIOS
[ 38.739388] intel_rapl_common: Found RAPL domain package
[ 38.753664] intel_rapl_common: RAPL package-1-die-1 domain package locked by BIOS
[ 39.494147] urandom_read: 1 callbacks suppressed
[ 39.494150] random: python3.7: uninitialized urandom read (24 bytes read)
[ 39.648433] random: crng init done
[ 41.972532] Kernel tests: Boot OK!
[ 41.972537]
[ 45.154764] error: dpkg -i /opt/deb/python3_3.7.3-1_amd64.deb failed.
[ 45.154769]
[ 45.548645] install debs round one: dpkg -i --force-confdef --force-depends /opt/deb/ntpdate_1%3a4.2.8p12+dfsg-4_amd64.deb
[ 45.548649]
[ 45.562702] /opt/deb/libpython3.7-minimal_3.7.3-2+deb10u2_amd64.deb
[ 45.562704]
[ 45.571692] /opt/deb/python3.7-minimal_3.7.3-2+deb10u2_amd64.deb
[ 45.571694]
[ 45.580428] /opt/deb/libpython3.7-stdlib_3.7.3-2+deb10u2_amd64.deb
[ 45.580430]
[ 45.589169] /opt/deb/python3.7_3.7.3-2+deb10u2_amd64.deb
[ 45.589171]
[ 45.597064] /opt/deb/libpython2.7_2.7.16-2+deb10u1_amd64.deb
[ 45.597066]
[ 45.605520] /opt/deb/libpython3.7_3.7.3-2+deb10u2_amd64.deb
[ 45.605522]
[ 45.613467] /opt/deb/sysstat_12.0.3-2_amd64.deb
[ 45.613470]
[ 45.620667] /opt/deb/libpython3.7-minimal_3.7.3-2+deb10u1_amd64.deb
[ 45.620670]
[ 45.629625] /opt/deb/python3.7-minimal_3.7.3-2+deb10u1_amd64.deb
[ 45.629627]
[ 45.638189] /opt/deb/python3-minimal_3.7.3-1_amd64.deb
[ 45.638191]
[ 45.646011] /opt/deb/libpython3.7-stdlib_3.7.3-2+deb10u1_amd64.deb
[ 45.646013]
[ 45.654750] /opt/deb/python3.7_3.7.3-2+deb10u1_amd64.deb
[ 45.654752]
[ 45.662574] /opt/deb/libpython3-stdlib_3.7.3-1_amd64.deb
[ 45.662577]
[ 45.670221] /opt/deb/python3_3.7.3-1_amd64.deb
[ 45.670223]
[ 45.677160] /opt/deb/libf2fs-format4_1.11.0-1.1_amd64.deb
[ 45.677162]
[ 45.685002] /opt/deb/gawk_1%3a4.2.1+dfsg-1_amd64.deb
[ 45.685004]
[ 45.692523] Selecting previously unselected package ntpdate.
[ 45.692525]
[ 45.701188] (Reading database ... 16553 files and directories currently installed.)
[ 45.701191]
[ 45.711844] Preparing to unpack .../ntpdate_1%3a4.2.8p12+dfsg-4_amd64.deb ...
[ 45.711846]
[ 45.721537] Unpacking ntpdate (1:4.2.8p12+dfsg-4) ...
[ 45.721539]


To reproduce:

git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp install job.yaml # job file is attached in this email
bin/lkp split-job --compatible job.yaml
bin/lkp run compatible-job.yaml



---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/[email protected] Intel Corporation

Thanks,
Oliver Sang


Attachments:
(No filename) (10.32 kB)
config-5.12.0-rc7-00001-gba887975f326 (175.55 kB)
job-script (8.39 kB)
dmesg.xz (34.02 kB)
job.yaml (5.77 kB)
reproduce (774.00 B)
Download all attachments