Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: f5934dda5442999d71eea07d9a324b259e5a36a5 ("[PATCH] iomap: Address soft lockup in iomap_finish_ioend()")
url: https://github.com/0day-ci/linux/commits/trondmy-kernel-org/iomap-Address-soft-lockup-in-iomap_finish_ioend/20211231-034313
base: https://git.kernel.org/cgit/fs/xfs/xfs-linux.git for-next
patch link: https://lore.kernel.org/linux-xfs/[email protected]
in testcase: xfstests
version: xfstests-x86_64-972d710-1_20211231
with following parameters:
disk: 4HDD
fs: xfs
test: xfs-reflink-21
ucode: 0x28
test-description: xfstests is a regression test suite for xfs and other files ystems.
test-url: git://git.kernel.org/pub/scm/fs/xfs/xfstests-dev.git
on test machine: 8 threads 1 sockets Intel(R) Core(TM) i7-4790 v3 @ 3.60GHz with 6G 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]>
[ 40.451880][ C5] BUG: sleeping function called from invalid context at fs/iomap/buffered-io.c:1058
[ 40.461015][ C5] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 0, name: swapper/5
[ 40.469465][ C5] preempt_count: 101, expected: 0
[ 40.474309][ C5] CPU: 5 PID: 0 Comm: swapper/5 Not tainted 5.16.0-rc5-00009-gf5934dda5442 #1
[ 40.482940][ C5] Hardware name: Dell Inc. OptiPlex 9020/03CPWF, BIOS A11 04/01/2015
[ 40.490773][ C5] Call Trace:
[ 40.493882][ C5] <IRQ>
[ 40.496560][ C5] dump_stack_lvl (lib/dump_stack.c:107)
[ 40.500877][ C5] __might_resched.cold (kernel/sched/core.c:9539 kernel/sched/core.c:9492)
[ 40.505879][ C5] ? folio_end_writeback (arch/x86/include/asm/atomic.h:123 include/linux/atomic/atomic-instrumented.h:543 include/linux/page_ref.h:210 include/linux/mm.h:738 include/linux/mm.h:743 include/linux/mm.h:1236 mm/filemap.c:1611)
[ 40.510969][ C5] iomap_finish_ioend (include/linux/sched.h:2024 fs/iomap/buffered-io.c:1058)
[ 40.515807][ C5] blk_update_request (block/blk-mq.c:744)
[ 40.520722][ C5] scsi_end_request (drivers/scsi/scsi_lib.c:543)
[ 40.525293][ C5] scsi_io_completion (drivers/scsi/scsi_lib.c:939)
[ 40.530206][ C5] ? sd_completed_bytes (drivers/scsi/sd.c:2030) sd_mod
[ 40.535989][ C5] ? scsi_unblock_requests (drivers/scsi/scsi_lib.c:910)
[ 40.541074][ C5] ? scsi_device_unbusy (arch/x86/include/asm/bitops.h:60 include/asm-generic/bitops/instrumented-atomic.h:29 include/linux/sbitmap.h:324 include/linux/sbitmap.h:333 drivers/scsi/scsi_lib.c:303)
[ 40.546075][ C5] blk_complete_reqs (block/blk-mq.c:891 (discriminator 3))
[ 40.550727][ C5] __do_softirq (arch/x86/include/asm/jump_label.h:27 include/linux/jump_label.h:212 include/trace/events/irq.h:142 kernel/softirq.c:559)
[ 40.555040][ C5] irq_exit_rcu (kernel/softirq.c:432 kernel/softirq.c:637 kernel/softirq.c:649)
[ 40.559353][ C5] common_interrupt (arch/x86/kernel/irq.c:240 (discriminator 14))
[ 40.563838][ C5] </IRQ>
[ 40.566600][ C5] <TASK>
[ 40.569363][ C5] asm_common_interrupt (arch/x86/include/asm/idtentry.h:629)
[ 40.574189][ C5] RIP: 0010:cpuidle_enter_state (drivers/cpuidle/cpuidle.c:259)
[ 40.579877][ C5] Code: 89 c6 0f 1f 44 00 00 31 ff e8 3d 37 61 fe 80 3c 24 00 74 12 9c 58 f6 c4 02 0f 85 27 07 00 00 31 ff e8 25 17 76 fe fb 45 85 ed <0f> 88 97 03 00 00 49 63 ed 48 83 fd 09 0f 87 cf 08 00 00 48 8d 44
All code
========
0: 89 c6 mov %eax,%esi
2: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
7: 31 ff xor %edi,%edi
9: e8 3d 37 61 fe callq 0xfffffffffe61374b
e: 80 3c 24 00 cmpb $0x0,(%rsp)
12: 74 12 je 0x26
14: 9c pushfq
15: 58 pop %rax
16: f6 c4 02 test $0x2,%ah
19: 0f 85 27 07 00 00 jne 0x746
1f: 31 ff xor %edi,%edi
21: e8 25 17 76 fe callq 0xfffffffffe76174b
26: fb sti
27: 45 85 ed test %r13d,%r13d
2a:* 0f 88 97 03 00 00 js 0x3c7 <-- trapping instruction
30: 49 63 ed movslq %r13d,%rbp
33: 48 83 fd 09 cmp $0x9,%rbp
37: 0f 87 cf 08 00 00 ja 0x90c
3d: 48 rex.W
3e: 8d .byte 0x8d
3f: 44 rex.R
Code starting with the faulting instruction
===========================================
0: 0f 88 97 03 00 00 js 0x39d
6: 49 63 ed movslq %r13d,%rbp
9: 48 83 fd 09 cmp $0x9,%rbp
d: 0f 87 cf 08 00 00 ja 0x8e2
13: 48 rex.W
14: 8d .byte 0x8d
15: 44 rex.R
[ 40.599142][ C5] RSP: 0018:ffffc90000167d80 EFLAGS: 00000202
[ 40.605000][ C5] RAX: dffffc0000000000 RBX: ffffe8ffffc80000 RCX: 000000000000001f
[ 40.612750][ C5] RDX: 1ffff11026f570d1 RSI: 0000000023a34dfe RDI: ffff888137ab8688
[ 40.620496][ C5] RBP: 0000000000000002 R08: 000000aa3dd5a974 R09: ffffed1026f57126
[ 40.628244][ C5] R10: ffff888137ab892b R11: ffffed1026f57125 R12: ffffffff84d3a3a0
[ 40.635990][ C5] R13: 0000000000000002 R14: 000000096b1e9b17 R15: ffffffff84d3a488
[ 40.643738][ C5] ? menu_reflect (drivers/cpuidle/governors/menu.c:440)
[ 40.648137][ C5] cpuidle_enter (drivers/cpuidle/cpuidle.c:353)
[ 40.652363][ C5] do_idle (kernel/sched/idle.c:158 kernel/sched/idle.c:239 kernel/sched/idle.c:306)
[ 40.656244][ C5] ? arch_cpu_idle_exit+0xc0/0xc0
[ 40.661070][ C5] cpu_startup_entry (kernel/sched/idle.c:402 (discriminator 1))
[ 40.665638][ C5] start_secondary (arch/x86/kernel/smpboot.c:224)
[ 40.670210][ C5] ? set_cpu_sibling_map (arch/x86/kernel/smpboot.c:224)
[ 40.675468][ C5] secondary_startup_64_no_verify (arch/x86/kernel/head_64.S:283)
[ 40.681155][ C5] </TASK>
[ 40.866821][ T2166] 420 (2166): drop_caches: 1
[ 40.878623][ T2536] XFS (sda4): Unmounting Filesystem
[ 40.967510][ T2542] XFS (sda4): Mounting V5 Filesystem
[ 41.010880][ T2542] XFS (sda4): Ending clean mount
[ 41.017620][ T2542] xfs filesystem being mounted at /fs/scratch supports timestamps until 2038 (0x7fffffff)
[ 41.097015][ T2576] XFS (sda1): Unmounting Filesystem
[ 41.266165][ T2643] XFS (sda4): Unmounting Filesystem
[ 41.409393][ T2820] XFS (sda4): Mounting V5 Filesystem
[ 41.430863][ T2820] XFS (sda4): Ending clean mount
[ 41.437619][ T2820] xfs filesystem being mounted at /fs/scratch supports timestamps until 2038 (0x7fffffff)
[ 41.454851][ T2830] XFS (sda4): Unmounting Filesystem
[ 41.508142][ T346] xfs/420 _check_dmesg: something found in dmesg (see /lkp/benchmarks/xfstests/results//xfs/420.dmesg)
[ 41.508152][ T346]
[ 41.521191][ T346]
[ 41.521196][ T346]
[ 41.558537][ T1597] run fstests xfs/421 at 2022-01-01 19:19:09
[ 42.000464][ T3060] XFS (sda1): Mounting V5 Filesystem
[ 42.071087][ T3060] XFS (sda1): Ending clean mount
[ 42.078076][ T3060] xfs filesystem being mounted at /fs/sda1 supports timestamps until 2038 (0x7fffffff)
[ 43.073514][ T3137] XFS (sda4): Mounting V5 Filesystem
[ 43.146618][ T3137] XFS (sda4): Ending clean mount
[ 43.153737][ T3137] xfs filesystem being mounted at /fs/scratch supports timestamps until 2038 (0x7fffffff)
[ 43.192057][ T3153] XFS (sda4): Unmounting Filesystem
[ 44.224872][ T3210] XFS (sda4): Mounting V5 Filesystem
[ 44.296088][ T3210] XFS (sda4): Ending clean mount
[ 44.303329][ T3210] xfs filesystem being mounted at /fs/scratch supports timestamps until 2038 (0x7fffffff)
[ 44.383646][ T3231] XFS (sda4): Unmounting Filesystem
[ 44.467185][ T3237] XFS (sda4): Mounting V5 Filesystem
[ 44.510544][ T3237] XFS (sda4): Ending clean mount
[ 44.517356][ T3237] xfs filesystem being mounted at /fs/scratch supports timestamps until 2038 (0x7fffffff)
[ 44.611180][ T2930] 421 (2930): drop_caches: 1
[ 44.798358][ T2930] 421 (2930): drop_caches: 1
[ 44.949219][ T2930] 421 (2930): drop_caches: 1
[ 44.961260][ T3312] XFS (sda4): Unmounting Filesystem
[ 45.050492][ T3320] XFS (sda4): Mounting V5 Filesystem
[ 45.126821][ T3320] XFS (sda4): Ending clean mount
[ 45.133426][ T3320] xfs filesystem being mounted at /fs/scratch supports timestamps until 2038 (0x7fffffff)
[ 45.212078][ T3355] XFS (sda1): Unmounting Filesystem
[ 45.385041][ T3422] XFS (sda4): Unmounting Filesystem
[ 45.491804][ T3599] XFS (sda4): Mounting V5 Filesystem
[ 45.526767][ T3599] XFS (sda4): Ending clean mount
[ 45.533445][ T3599] xfs filesystem being mounted at /fs/scratch supports timestamps until 2038 (0x7fffffff)
[ 45.550650][ T3609] XFS (sda4): Unmounting Filesystem
[ 45.621721][ T346] xfs/421 4s
[ 45.621730][ T346]
[ 45.663021][ T1597] run fstests xfs/435 at 2022-01-01 19:19:13
[ 46.088251][ T3841] XFS (sda1): Mounting V5 Filesystem
[ 46.185273][ T3841] XFS (sda1): Ending clean mount
[ 46.192234][ T3841] xfs filesystem being mounted at /fs/sda1 supports timestamps until 2038 (0x7fffffff)
[ 46.290869][ T3884] XFS (sda1): Unmounting Filesystem
[ 46.761754][ T3888] SGI XFS with ACLs, security attributes, realtime, scrub, repair, quota, fatal assert, debug enabled
[ 46.789787][ T3894] XFS (sda1): Mounting V5 Filesystem
[ 46.832054][ T3894] XFS (sda1): Ending clean mount
[ 46.838578][ T3894] xfs filesystem being mounted at /fs/sda1 supports timestamps until 2038 (0x7fffffff)
[ 47.773681][ T3951] XFS (sda4): Mounting V5 Filesystem
[ 47.845813][ T3951] XFS (sda4): Ending clean mount
[ 47.852948][ T3951] xfs filesystem being mounted at /fs/scratch supports timestamps until 2038 (0x7fffffff)
[ 47.907907][ T3964] XFS (sda4): Unmounting Filesystem
[ 48.856657][ T3989] XFS (sda4): Mounting V5 Filesystem
[ 48.928626][ T3989] XFS (sda4): Ending clean mount
[ 48.934389][ T3989] XFS (sda4): Quotacheck needed: Please wait.
[ 48.958046][ T3989] XFS (sda4): Quotacheck: Done.
[ 48.963681][ T3989] xfs filesystem being mounted at /fs/scratch supports timestamps until 2038 (0x7fffffff)
[ 49.024435][ T4007] XFS (sda4): Unmounting Filesystem
[ 49.164158][ T4020] XFS (sda4): Mounting V5 Filesystem
[ 49.204473][ T4020] XFS (sda4): Ending clean mount
[ 49.211130][ T4020] xfs filesystem being mounted at /fs/scratch supports timestamps until 2038 (0x7fffffff)
[ 49.225240][ T4029] XFS (sda4): Unmounting Filesystem
[ 49.276739][ T4039] XFS (sda1): Unmounting Filesystem
[ 49.724210][ T4043] SGI XFS with ACLs, security attributes, realtime, scrub, repair, quota, fatal assert, debug enabled
[ 49.752466][ T4049] XFS (sda1): Mounting V5 Filesystem
[ 49.815033][ T4049] XFS (sda1): Ending clean mount
[ 49.821589][ T4049] xfs filesystem being mounted at /fs/sda1 supports timestamps until 2038 (0x7fffffff)
[ 49.845370][ T4061] XFS (sda1): Unmounting Filesystem
[ 49.897630][ T346] xfs/435 4s
[ 49.897639][ T346]
[ 49.912268][ T346] Ran: xfs/420 xfs/421 xfs/435
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
sudo bin/lkp install job.yaml # job file is attached in this email
bin/lkp split-job --compatible job.yaml # generate the yaml file for lkp run
sudo bin/lkp run generated-yaml-file
# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.
---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/[email protected] Intel Corporation
Thanks,
Oliver Sang