lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [day] [month] [year] [list]
Date:   Wed, 5 Jan 2022 10:31:04 +0800
From:   kernel test robot <oliver.sang@...el.com>
To:     trondmy@...nel.org
Cc:     0day robot <lkp@...el.com>, Jens Axboe <axboe@...nel.dk>,
        LKML <linux-kernel@...r.kernel.org>, lkp@...ts.01.org,
        Christoph Hellwig <hch@...radead.org>,
        "Darrick J. Wong" <djwong@...nel.org>, linux-xfs@...r.kernel.org,
        linux-fsdevel@...r.kernel.org
Subject: [iomap]  f5934dda54:
 BUG:sleeping_function_called_from_invalid_context_at_fs/iomap/buffered-io.c



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/20211230193522.55520-1-trondmy@kernel.org

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 <oliver.sang@...el.com>


[   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/lkp@lists.01.org       Intel Corporation

Thanks,
Oliver Sang


View attachment "config-5.16.0-rc5-00009-gf5934dda5442" of type "text/plain" (177768 bytes)

View attachment "job-script" of type "text/plain" (5862 bytes)

Download attachment "dmesg.xz" of type "application/x-xz" (26496 bytes)

View attachment "xfstests" of type "text/plain" (1067 bytes)

View attachment "job.yaml" of type "text/plain" (4769 bytes)

View attachment "reproduce" of type "text/plain" (903 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ