Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: aced02f26141d4ad6fb3370f16282029575a099d ("[Patch net] rtnetlink: use rwsem to protect rtnl_af_ops list")
url: https://github.com/0day-ci/linux/commits/Cong-Wang/rtnetlink-use-rwsem-to-protect-rtnl_af_ops-list/20210506-073907
base: https://git.kernel.org/cgit/linux/kernel/git/davem/net.git 8621436671f3a4bba5db57482e1ee604708bf1eb
in testcase: kernel-selftests
version: kernel-selftests-x86_64-0d95472a-1_20210507
with following parameters:
group: x86
ucode: 0xde
test-description: The kernel contains a set of "self tests" under the tools/testing/selftests/ directory. These are intended to be small unit tests to exercise individual code paths in the kernel.
test-url: https://www.kernel.org/doc/Documentation/kselftest.txt
on test machine: 4 threads 1 sockets Intel(R) Core(TM) i7-7567U CPU @ 3.50GHz with 32G 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]>
kern :err : [ 28.131242] BUG: sleeping function called from invalid context at kernel/locking/rwsem.c:1352
kern :err : [ 28.132015] in_atomic(): 0, irqs_disabled(): 0, non_block: 0, pid: 376, name: ip
kern :warn : [ 28.132651] 2 locks held by ip/376:
kern :warn : [ 28.132982] #0: ffffffff8343bcc0 (rcu_read_lock){....}-{1:2}, at: rtnetlink_rcv_msg (kbuild/src/consumer/include/linux/rcupdate.h:655 kbuild/src/consumer/net/core/rtnetlink.c:5490)
kern :warn : [ 28.136748] #1: ffffffff8343bcc0 (rcu_read_lock){....}-{1:2}, at: rtnl_calcit+0x9f/0x200
kern :err : [ 28.137792] Preemption disabled at:
kern :err : [ 28.137794] 0x0
kern :warn : [ 28.138727] CPU: 3 PID: 376 Comm: ip Not tainted 5.12.0-11126-gaced02f26141 #1
kern :warn : [ 28.139350] Hardware name: Intel Corporation NUC7i7BNH/NUC7i7BNB, BIOS BNKBL357.86A.0067.2018.0814.1500 08/14/2018
kern :warn : [ 28.140196] Call Trace:
kern :warn : [ 28.140454] dump_stack (kbuild/src/consumer/lib/dump_stack.c:122)
kern :warn : [ 28.140777] ___might_sleep.cold (kbuild/src/consumer/kernel/sched/core.c:8339)
kern :warn : [ 28.141164] down_read (kbuild/src/consumer/include/linux/kernel.h:96 kbuild/src/consumer/kernel/locking/rwsem.c:1352)
kern :warn : [ 28.141486] if_nlmsg_size (kbuild/src/consumer/net/core/rtnetlink.c:591 kbuild/src/consumer/net/core/rtnetlink.c:1047)
kern :warn : [ 28.141846] rtnl_calcit+0x102/0x200
kern :warn : [ 28.142279] ? rtnl_fill_ifinfo (kbuild/src/consumer/net/core/rtnetlink.c:2057)
kern :warn : [ 28.142677] rtnetlink_rcv_msg (kbuild/src/consumer/net/core/rtnetlink.c:5507)
kern :warn : [ 28.143058] ? lock_acquire (kbuild/src/consumer/kernel/locking/lockdep.c:438 kbuild/src/consumer/kernel/locking/lockdep.c:5514 kbuild/src/consumer/kernel/locking/lockdep.c:5477)
kern :warn : [ 28.143414] ? rtnetlink_put_metrics (kbuild/src/consumer/net/core/rtnetlink.c:5463)
kern :warn : [ 28.143831] netlink_rcv_skb (kbuild/src/consumer/net/netlink/af_netlink.c:2502)
kern :warn : [ 28.144199] netlink_unicast (kbuild/src/consumer/net/netlink/af_netlink.c:1313 kbuild/src/consumer/net/netlink/af_netlink.c:1338)
kern :warn : [ 28.144569] netlink_sendmsg (kbuild/src/consumer/net/netlink/af_netlink.c:1927)
kern :warn : [ 28.144946] sock_sendmsg (kbuild/src/consumer/net/socket.c:654 kbuild/src/consumer/net/socket.c:674)
kern :warn : [ 28.145282] __sys_sendto (kbuild/src/consumer/net/socket.c:1977)
kern :warn : [ 28.145664] ? lock_is_held_type (kbuild/src/consumer/kernel/locking/lockdep.c:438 kbuild/src/consumer/kernel/locking/lockdep.c:5556)
kern :warn : [ 28.146053] ? syscall_enter_from_user_mode (kbuild/src/consumer/kernel/entry/common.c:290 kbuild/src/consumer/arch/x86/include/asm/irqflags.h:80 kbuild/src/consumer/kernel/entry/common.c:106)
kern :warn : [ 28.146519] __x64_sys_sendto (kbuild/src/consumer/net/socket.c:1989 kbuild/src/consumer/net/socket.c:1985 kbuild/src/consumer/net/socket.c:1985)
kern :warn : [ 28.146877] do_syscall_64 (kbuild/src/consumer/arch/x86/entry/common.c:47)
kern :warn : [ 28.147218] entry_SYSCALL_64_after_hwframe (kbuild/src/consumer/arch/x86/entry/entry_64.S:112)
kern :warn : [ 28.147663] RIP: 0033:0x7f2e3859385d
kern :warn : [ 28.148000] Code: ff ff ff ff eb b6 0f 1f 80 00 00 00 00 48 8d 05 a9 5e 0c 00 41 89 ca 8b 00 85 c0 75 20 45 31 c9 45 31 c0 b8 2c 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 6b c3 66 2e 0f 1f 84 00 00 00 00 00 41 56 41
All code
========
0: ff (bad)
1: ff (bad)
2: ff (bad)
3: ff (bad)
4: eb b6 jmp 0xffffffffffffffbc
6: 0f 1f 80 00 00 00 00 nopl 0x0(%rax)
d: 48 8d 05 a9 5e 0c 00 lea 0xc5ea9(%rip),%rax # 0xc5ebd
14: 41 89 ca mov %ecx,%r10d
17: 8b 00 mov (%rax),%eax
19: 85 c0 test %eax,%eax
1b: 75 20 jne 0x3d
1d: 45 31 c9 xor %r9d,%r9d
20: 45 31 c0 xor %r8d,%r8d
23: b8 2c 00 00 00 mov $0x2c,%eax
28: 0f 05 syscall
2a:* 48 3d 00 f0 ff ff cmp $0xfffffffffffff000,%rax <-- trapping instruction
30: 77 6b ja 0x9d
32: c3 retq
33: 66 2e 0f 1f 84 00 00 nopw %cs:0x0(%rax,%rax,1)
3a: 00 00 00
3d: 41 56 push %r14
3f: 41 rex.B
Code starting with the faulting instruction
===========================================
0: 48 3d 00 f0 ff ff cmp $0xfffffffffffff000,%rax
6: 77 6b ja 0x73
8: c3 retq
9: 66 2e 0f 1f 84 00 00 nopw %cs:0x0(%rax,%rax,1)
10: 00 00 00
13: 41 56 push %r14
15: 41 rex.B
kern :warn : [ 28.149463] RSP: 002b:00007ffc052f28c8 EFLAGS: 00000246 ORIG_RAX: 000000000000002c
kern :warn : [ 28.150107] RAX: ffffffffffffffda RBX: 000055edaab5a580 RCX: 00007f2e3859385d
kern :warn : [ 28.150699] RDX: 0000000000000028 RSI: 00007ffc052f28d0 RDI: 0000000000000003
kern :warn : [ 28.151291] RBP: 00007ffc052f28d0 R08: 0000000000000000 R09: 0000000000000000
kern :warn : [ 28.151882] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000011
kern :warn : [ 28.152474] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
kern :warn : [ 28.159184] =============================
kern :warn : [ 28.159536] [ BUG: Invalid wait context ]
kern :warn : [ 28.159900] 5.12.0-11126-gaced02f26141 #1 Tainted: G W
kern :warn : [ 28.160424] -----------------------------
kern :warn : [ 28.160779] ip/376 is trying to lock:
kern :warn : [ 28.161109] ffffffff8366adf0 (af_ops_sem){++++}-{3:3}, at: if_nlmsg_size (kbuild/src/consumer/net/core/rtnetlink.c:591 kbuild/src/consumer/net/core/rtnetlink.c:1047)
kern :warn : [ 28.161769] other info that might help us debug this:
kern :warn : [ 28.162190] context-{4:4}
kern :warn : [ 28.162445] 2 locks held by ip/376:
kern :warn : [ 28.162760] #0: ffffffff8343bcc0 (rcu_read_lock){....}-{1:2}, at: rtnetlink_rcv_msg (kbuild/src/consumer/include/linux/rcupdate.h:655 kbuild/src/consumer/net/core/rtnetlink.c:5490)
kern :warn : [ 28.163457] #1: ffffffff8343bcc0 (rcu_read_lock){....}-{1:2}, at: rtnl_calcit+0x9f/0x200
kern :warn : [ 28.164160] stack backtrace:
kern :warn : [ 28.164431] CPU: 3 PID: 376 Comm: ip Tainted: G W 5.12.0-11126-gaced02f26141 #1
kern :warn : [ 28.165120] Hardware name: Intel Corporation NUC7i7BNH/NUC7i7BNB, BIOS BNKBL357.86A.0067.2018.0814.1500 08/14/2018
kern :warn : [ 28.165926] Call Trace:
kern :warn : [ 28.166177] dump_stack (kbuild/src/consumer/lib/dump_stack.c:122)
kern :warn : [ 28.166488] __lock_acquire.cold (kbuild/src/consumer/kernel/locking/lockdep.c:6391 kbuild/src/consumer/kernel/locking/lockdep.c:4614 kbuild/src/consumer/kernel/locking/lockdep.c:4852)
kern :warn : [ 28.166853] ? lock_is_held_type (kbuild/src/consumer/kernel/locking/lockdep.c:438 kbuild/src/consumer/kernel/locking/lockdep.c:5556)
kern :warn : [ 28.167220] lock_acquire (kbuild/src/consumer/kernel/locking/lockdep.c:438 kbuild/src/consumer/kernel/locking/lockdep.c:5514 kbuild/src/consumer/kernel/locking/lockdep.c:5477)
kern :warn : [ 28.167543] ? if_nlmsg_size (kbuild/src/consumer/net/core/rtnetlink.c:591 kbuild/src/consumer/net/core/rtnetlink.c:1047)
kern :warn : [ 28.167895] down_read (kbuild/src/consumer/arch/x86/include/asm/atomic64_64.h:160 kbuild/src/consumer/include/asm-generic/atomic-instrumented.h:893 kbuild/src/consumer/include/asm-generic/atomic-long.h:65 kbuild/src/consumer/kernel/locking/rwsem.c:237 kbuild/src/consumer/kernel/locking/rwsem.c:1212 kbuild/src/consumer/kernel/locking/rwsem.c:1222 kbuild/src/consumer/kernel/locking/rwsem.c:1355)
kern :warn : [ 28.168201] ? if_nlmsg_size (kbuild/src/consumer/net/core/rtnetlink.c:591 kbuild/src/consumer/net/core/rtnetlink.c:1047)
kern :warn : [ 28.168549] if_nlmsg_size (kbuild/src/consumer/net/core/rtnetlink.c:591 kbuild/src/consumer/net/core/rtnetlink.c:1047)
kern :warn : [ 28.168884] rtnl_calcit+0x102/0x200
kern :warn : [ 28.169260] ? rtnl_fill_ifinfo (kbuild/src/consumer/net/core/rtnetlink.c:2057)
kern :warn : [ 28.169639] rtnetlink_rcv_msg (kbuild/src/consumer/net/core/rtnetlink.c:5507)
kern :warn : [ 28.170000] ? lock_acquire (kbuild/src/consumer/kernel/locking/lockdep.c:438 kbuild/src/consumer/kernel/locking/lockdep.c:5514 kbuild/src/consumer/kernel/locking/lockdep.c:5477)
kern :warn : [ 28.170335] ? rtnetlink_put_metrics (kbuild/src/consumer/net/core/rtnetlink.c:5463)
kern :warn : [ 28.170730] netlink_rcv_skb (kbuild/src/consumer/net/netlink/af_netlink.c:2502)
kern :warn : [ 28.171073] netlink_unicast (kbuild/src/consumer/net/netlink/af_netlink.c:1313 kbuild/src/consumer/net/netlink/af_netlink.c:1338)
kern :warn : [ 28.171421] netlink_sendmsg (kbuild/src/consumer/net/netlink/af_netlink.c:1927)
kern :warn : [ 28.171770] sock_sendmsg (kbuild/src/consumer/net/socket.c:654 kbuild/src/consumer/net/socket.c:674)
kern :warn : [ 28.172088] __sys_sendto (kbuild/src/consumer/net/socket.c:1977)
kern :warn : [ 28.172414] ? lock_is_held_type (kbuild/src/consumer/kernel/locking/lockdep.c:438 kbuild/src/consumer/kernel/locking/lockdep.c:5556)
kern :warn : [ 28.172779] ? syscall_enter_from_user_mode (kbuild/src/consumer/kernel/entry/common.c:290 kbuild/src/consumer/arch/x86/include/asm/irqflags.h:80 kbuild/src/consumer/kernel/entry/common.c:106)
kern :warn : [ 28.173203] __x64_sys_sendto (kbuild/src/consumer/net/socket.c:1989 kbuild/src/consumer/net/socket.c:1985 kbuild/src/consumer/net/socket.c:1985)
kern :warn : [ 28.173543] do_syscall_64 (kbuild/src/consumer/arch/x86/entry/common.c:47)
kern :warn : [ 28.173865] entry_SYSCALL_64_after_hwframe (kbuild/src/consumer/arch/x86/entry/entry_64.S:112)
kern :warn : [ 28.174290] RIP: 0033:0x7f2e3859385d
kern :warn : [ 28.174613] Code: ff ff ff ff eb b6 0f 1f 80 00 00 00 00 48 8d 05 a9 5e 0c 00 41 89 ca 8b 00 85 c0 75 20 45 31 c9 45 31 c0 b8 2c 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 6b c3 66 2e 0f 1f 84 00 00 00 00 00 41 56 41
All code
========
0: ff (bad)
1: ff (bad)
2: ff (bad)
3: ff (bad)
4: eb b6 jmp 0xffffffffffffffbc
6: 0f 1f 80 00 00 00 00 nopl 0x0(%rax)
d: 48 8d 05 a9 5e 0c 00 lea 0xc5ea9(%rip),%rax # 0xc5ebd
14: 41 89 ca mov %ecx,%r10d
17: 8b 00 mov (%rax),%eax
19: 85 c0 test %eax,%eax
1b: 75 20 jne 0x3d
1d: 45 31 c9 xor %r9d,%r9d
20: 45 31 c0 xor %r8d,%r8d
23: b8 2c 00 00 00 mov $0x2c,%eax
28: 0f 05 syscall
2a:* 48 3d 00 f0 ff ff cmp $0xfffffffffffff000,%rax <-- trapping instruction
30: 77 6b ja 0x9d
32: c3 retq
33: 66 2e 0f 1f 84 00 00 nopw %cs:0x0(%rax,%rax,1)
3a: 00 00 00
3d: 41 56 push %r14
3f: 41 rex.B
Code starting with the faulting instruction
===========================================
0: 48 3d 00 f0 ff ff cmp $0xfffffffffffff000,%rax
6: 77 6b ja 0x73
8: c3 retq
9: 66 2e 0f 1f 84 00 00 nopw %cs:0x0(%rax,%rax,1)
10: 00 00 00
13: 41 56 push %r14
15: 41 rex.B
kern :warn : [ 28.176011] RSP: 002b:00007ffc052f28c8 EFLAGS: 00000246 ORIG_RAX: 000000000000002c
kern :warn : [ 28.176624] RAX: ffffffffffffffda RBX: 000055edaab5a580 RCX: 00007f2e3859385d
kern :warn : [ 28.177191] RDX: 0000000000000028 RSI: 00007ffc052f28d0 RDI: 0000000000000003
kern :warn : [ 28.177756] RBP: 00007ffc052f28d0 R08: 0000000000000000 R09: 0000000000000000
kern :warn : [ 28.178323] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000011
kern :warn : [ 28.178890] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
kern :info : [ 28.396508] ata1: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
kern :debug : [ 28.397686] ata1.00: ACPI cmd ef/10:06:00:00:00:00 (SET FEATURES) succeeded
kern :info : [ 28.398251] ata1.00: ACPI cmd f5/00:00:00:00:00:00 (SECURITY FREEZE LOCK) filtered out
kern :info : [ 28.398891] ata1.00: ACPI cmd b1/c1:00:00:00:00:00 (DEVICE CONFIGURATION OVERLAY) filtered out
kern :info : [ 28.399815] ata1.00: ATA-9: INTEL SSDSC2BB800G4, D2010370, max UDMA/133
kern :info : [ 28.400358] ata1.00: 1562824368 sectors, multi 1: LBA48 NCQ (depth 32)
kern :debug : [ 28.401620] ata1.00: ACPI cmd ef/10:06:00:00:00:00 (SET FEATURES) succeeded
kern :info : [ 28.402186] ata1.00: ACPI cmd f5/00:00:00:00:00:00 (SECURITY FREEZE LOCK) filtered out
kern :info : [ 28.402826] ata1.00: ACPI cmd b1/c1:00:00:00:00:00 (DEVICE CONFIGURATION OVERLAY) filtered out
kern :info : [ 28.403862] ata1.00: configured for UDMA/133
kern :notice: [ 28.404448] scsi 0:0:0:0: Direct-Access ATA INTEL SSDSC2BB80 0370 PQ: 0 ANSI: 5
kern :info : [ 28.451494] ata3: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
kern :info : [ 28.477306] ata3.00: ATA-10: INTEL SSDSCKJW180H6, RG11, max UDMA/133
kern :info : [ 28.477862] ata3.00: 351651888 sectors, multi 16: LBA48 NCQ (depth 32), AA
kern :info : [ 28.491327] ata3.00: configured for UDMA/133
kern :notice: [ 28.985058] scsi 2:0:0:0: Direct-Access ATA INTEL SSDSCKJW18 RG11 PQ: 0 ANSI: 5
kern :notice: [ 29.011071] scsi 0:0:0:0: Attached scsi generic sg0 type 0
kern :notice: [ 29.011625] scsi 2:0:0:0: Attached scsi generic sg1 type 0
kern :info : [ 29.016535] i915 0000:00:02.0: [drm] Found 64MB of eDRAM
kern :info : [ 29.017037] i915 0000:00:02.0: vgaarb: deactivate vga console
kern :info : [ 29.019659] Console: switching to colour dummy device 80x25
kern :info : [ 29.038204] ata1.00: Enabling discard_zeroes_data
kern :notice: [ 29.038581] sd 2:0:0:0: [sdb] 351651888 512-byte logical blocks: (180 GB/168 GiB)
kern :notice: [ 29.039221] sd 0:0:0:0: [sda] 1562824368 512-byte logical blocks: (800 GB/745 GiB)
kern :notice: [ 29.039749] sd 0:0:0:0: [sda] 4096-byte physical blocks
kern :notice: [ 29.040181] sd 2:0:0:0: [sdb] Write Protect is off
kern :debug : [ 29.040520] sd 2:0:0:0: [sdb] Mode Sense: 00 3a 00 00
kern :notice: [ 29.040893] sd 2:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
kern :notice: [ 29.041582] sd 0:0:0:0: [sda] Write Protect is off
kern :debug : [ 29.041923] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
kern :notice: [ 29.042351] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
kern :info : [ 29.044791] i915 0000:00:02.0: vgaarb: changed VGA decodes: olddecodes=io+mem,decodes=io+mem:owns=io+mem
kern :warn : [ 29.046583] i915 0000:00:02.0: Direct firmware load for i915/kbl_dmc_ver1_04.bin failed with error -2
kern :notice: [ 29.047231] i915 0000:00:02.0: [drm] Failed to load DMC firmware i915/kbl_dmc_ver1_04.bin. Disabling runtime power management.
kern :notice: [ 29.048024] i915 0000:00:02.0: [drm] DMC firmware homepage: https://git.kernel.org/pub/scm/linux/kernel/git/firmware/linux-firmware.git/tree/i915
kern :info : [ 29.050276] sda: sda1 sda2
kern :info : [ 29.050804] sdb: sdb1
kern :notice: [ 29.052966] sd 2:0:0:0: [sdb] Attached SCSI disk
kern :info : [ 29.053348] ata1.00: Enabling discard_zeroes_data
kern :notice: [ 29.053795] sd 0:0:0:0: [sda] Attached SCSI disk
kern :notice: [ 29.120205] random: fast init done
kern :info : [ 29.136978] intel_rapl_common: Found RAPL domain package
kern :info : [ 29.137361] intel_rapl_common: Found RAPL domain core
kern :info : [ 29.137725] intel_rapl_common: Found RAPL domain uncore
kern :info : [ 29.138106] intel_rapl_common: Found RAPL domain dram
kern :info : [ 29.138462] intel_rapl_common: Found RAPL domain psys
kern :info : [ 29.179045] raid6: avx2x4 gen() 21771 MB/s
kern :info : [ 29.196054] raid6: avx2x4 xor() 11737 MB/s
kern :info : [ 29.213043] raid6: avx2x2 gen() 21199 MB/s
kern :info : [ 29.230016] raid6: avx2x2 xor() 12500 MB/s
kern :info : [ 29.247096] raid6: avx2x1 gen() 18062 MB/s
kern :info : [ 29.263989] raid6: avx2x1 xor() 10888 MB/s
kern :info : [ 29.281390] raid6: sse2x4 gen() 10083 MB/s
kern :info : [ 29.298000] raid6: sse2x4 xor() 6499 MB/s
kern :info : [ 29.315014] raid6: sse2x2 gen() 11017 MB/s
kern :info : [ 29.331999] raid6: sse2x2 xor() 6471 MB/s
kern :info : [ 29.348999] raid6: sse2x1 gen() 7271 MB/s
kern :info : [ 29.365989] raid6: sse2x1 xor() 5586 MB/s
kern :info : [ 29.366303] raid6: using algorithm avx2x4 gen() 21771 MB/s
kern :info : [ 29.366687] raid6: .... xor() 11737 MB/s, rmw enabled
kern :info : [ 29.367071] raid6: using avx2x2 recovery algorithm
kern :info : [ 29.383721] xor: automatically using best checksumming function avx
kern :info : [ 29.483041] i915 0000:00:02.0: [drm] failed to retrieve link info, disabling eDP
kern :warn : [ 29.484170] ------------[ cut here ]------------
kern :warn : [ 29.484497] WARN_ON(!ww && vma->resv && lock_is_held(&(&(vma->resv)->lock.base)->dep_map))
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 # generate the yaml file for lkp run
bin/lkp run generated-yaml-file
---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/[email protected] Intel Corporation
Thanks,
Oliver Sang