2021-04-30 02:20:11

by kernel test robot

[permalink] [raw]
Subject: [netfilter] d509b127cc: WARNING:at_kernel/rcu/tree_plugin.h:#__rcu_read_unlock



Greeting,

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

commit: d509b127ccf0fe5fc48dd6c337c5291d24173418 ("[PATCH nf-next 5/5] netfilter: nfnetlink: consolidate callback types")
url: https://github.com/0day-ci/linux/commits/Pablo-Neira-Ayuso/nfnetlink-housekeeping/20210423-061840
base: https://git.kernel.org/cgit/linux/kernel/git/pablo/nf-next.git master

in testcase: kernel-selftests
version: kernel-selftests-x86_64-cf9ae1bd-1_20210401
with following parameters:

group: net
ucode: 0xe2

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 Intel(R) Xeon(R) CPU E3-1225 v5 @ 3.30GHz with 16G 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 :warn : [ 107.239912] WARNING: CPU: 0 PID: 4897 at kernel/rcu/tree_plugin.h:404 __rcu_read_unlock (kbuild/src/consumer/kernel/rcu/tree_plugin.h:404 kbuild/src/consumer/kernel/rcu/tree_plugin.h:392)
kern :warn : [ 107.249253] Modules linked in: nft_compat nf_tables nfnetlink esp4_offload psample esp4 cls_u32 sch_htb nf_conntrack_broadcast nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver btrfs blake2b_generic xor zstd_compress raid6_pq libcrc32c sd_mod t10_pi sg mei_wdt ipmi_devintf ipmi_msghandler intel_rapl_msr intel_rapl_common x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel rapl intel_cstate i915 hp_wmi sparse_keymap rfkill wmi_bmof ahci libahci mei_me intel_uncore i2c_i801 mei i2c_smbus serio_raw libata intel_pch_thermal intel_gtt ie31200_edac wmi video intel_pmc_core acpi_pad tpm_infineon ip_tables [last unloaded: netdevsim]
kern :warn : [ 107.315476] CPU: 0 PID: 4897 Comm: iptables Not tainted 5.12.0-rc6-02036-gd509b127ccf0 #1
kern :warn : [ 107.324047] Hardware name: HP HP Z238 Microtower Workstation/8183, BIOS N51 Ver. 01.63 10/05/2017
kern :warn : [ 107.333270] RIP: 0010:__rcu_read_unlock (kbuild/src/consumer/kernel/rcu/tree_plugin.h:404 kbuild/src/consumer/kernel/rcu/tree_plugin.h:392)
kern :warn : [ 107.338310] Code: 81 e2 00 00 0f 00 0f 85 d2 00 00 00 4d 85 ed 74 40 84 c0 74 3c bf 09 00 00 00 e8 87 9c f5 ff e8 a2 b9 09 00 fb e9 43 ff ff ff <0f> 0b 5b 5d 41 5c 41 5d c3 e8 8e ba 09 00 66 85 db 0f 85 6f ff ff
All code
========
0: 81 e2 00 00 0f 00 and $0xf0000,%edx
6: 0f 85 d2 00 00 00 jne 0xde
c: 4d 85 ed test %r13,%r13
f: 74 40 je 0x51
11: 84 c0 test %al,%al
13: 74 3c je 0x51
15: bf 09 00 00 00 mov $0x9,%edi
1a: e8 87 9c f5 ff callq 0xfffffffffff59ca6
1f: e8 a2 b9 09 00 callq 0x9b9c6
24: fb sti
25: e9 43 ff ff ff jmpq 0xffffffffffffff6d
2a:* 0f 0b ud2 <-- trapping instruction
2c: 5b pop %rbx
2d: 5d pop %rbp
2e: 41 5c pop %r12
30: 41 5d pop %r13
32: c3 retq
33: e8 8e ba 09 00 callq 0x9bac6
38: 66 85 db test %bx,%bx
3b: 0f .byte 0xf
3c: 85 6f ff test %ebp,-0x1(%rdi)
3f: ff .byte 0xff

Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: 5b pop %rbx
3: 5d pop %rbp
4: 41 5c pop %r12
6: 41 5d pop %r13
8: c3 retq
9: e8 8e ba 09 00 callq 0x9ba9c
e: 66 85 db test %bx,%bx
11: 0f .byte 0xf
12: 85 6f ff test %ebp,-0x1(%rdi)
15: ff .byte 0xff
kern :warn : [ 107.357809] RSP: 0018:ffffc90000f57a60 EFLAGS: 00010286
kern :warn : [ 107.363542] RAX: ffff888439890000 RBX: ffffc90000f57b28 RCX: 0000000000000000
kern :warn : [ 107.370996] RDX: 0000000000000001 RSI: ffffffff827e19cb RDI: ffffffff827ed77c
kern :warn : [ 107.378433] RBP: ffff888439890000 R08: 0000000000000000 R09: 000000000004073a
kern :warn : [ 107.385906] R10: ffffc90000f57ae0 R11: 0000000000000000 R12: ffff888237197618
kern :warn : [ 107.393339] R13: ffffffffc099c137 R14: 0000000000000000 R15: 0000000000000000
kern :warn : [ 107.400791] FS: 00007f5d95a17740(0000) GS:ffff88843f400000(0000) knlGS:0000000000000000
kern :warn : [ 107.409204] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
kern :warn : [ 107.415162] CR2: 00007ffdd18f6084 CR3: 00000002371ac005 CR4: 00000000003706f0
kern :warn : [ 107.422585] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
kern :warn : [ 107.430139] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
kern :warn : [ 107.437588] Call Trace:
kern :warn : [ 107.440261] nfnl_compat_get_rcu (kbuild/src/consumer/include/linux/rcupdate.h:272 kbuild/src/consumer/include/linux/rcupdate.h:710 kbuild/src/consumer/net/netfilter/nft_compat.c:660) nft_compat
kern :warn : [ 107.445931] nfnetlink_rcv_msg (kbuild/src/consumer/net/netfilter/nfnetlink.c:98 kbuild/src/consumer/net/netfilter/nfnetlink.c:295) nfnetlink
kern :warn : [ 107.451549] ? __lock_acquire (kbuild/src/consumer/kernel/locking/lockdep.c:4900)
kern :warn : [ 107.455950] ? __lock_acquire (kbuild/src/consumer/kernel/locking/lockdep.c:4900)
kern :warn : [ 107.460308] ? nfnetlink_net_init (kbuild/src/consumer/net/netfilter/nfnetlink.c:212) nfnetlink
kern :warn : [ 107.466040] netlink_rcv_skb (kbuild/src/consumer/net/netlink/af_netlink.c:2502)
kern :warn : [ 107.470245] nfnetlink_rcv (kbuild/src/consumer/net/netfilter/nfnetlink.c:651) nfnetlink
kern :warn : [ 107.475278] netlink_unicast (kbuild/src/consumer/net/netlink/af_netlink.c:1313 kbuild/src/consumer/net/netlink/af_netlink.c:1338)
kern :warn : [ 107.479491] netlink_sendmsg (kbuild/src/consumer/net/netlink/af_netlink.c:1927)
kern :warn : [ 107.483734] ------------[ cut here ]------------
kern :warn : [ 107.488519] WARNING: CPU: 0 PID: 4897 at kernel/rcu/tree_plugin.h:699 rcu_sched_clock_irq (kbuild/src/consumer/kernel/rcu/tree_plugin.h:699 kbuild/src/consumer/kernel/rcu/tree.c:2649)
kern :warn : [ 107.498080] Modules linked in: nft_compat nf_tables nfnetlink esp4_offload psample esp4 cls_u32 sch_htb nf_conntrack_broadcast nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 rpcsec_gss_krb5 auth_rpcgss nfsv4 dns_resolver btrfs blake2b_generic xor zstd_compress raid6_pq libcrc32c sd_mod t10_pi sg mei_wdt ipmi_devintf ipmi_msghandler intel_rapl_msr intel_rapl_common x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel rapl intel_cstate i915 hp_wmi sparse_keymap rfkill wmi_bmof ahci libahci mei_me intel_uncore i2c_i801 mei i2c_smbus serio_raw libata intel_pch_thermal intel_gtt ie31200_edac wmi video intel_pmc_core acpi_pad tpm_infineon ip_tables [last unloaded: netdevsim]
kern :warn : [ 107.564155] CPU: 0 PID: 4897 Comm: iptables Not tainted 5.12.0-rc6-02036-gd509b127ccf0 #1
kern :warn : [ 107.572590] Hardware name: HP HP Z238 Microtower Workstation/8183, BIOS N51 Ver. 01.63 10/05/2017
kern :warn : [ 107.581764] RIP: 0010:rcu_sched_clock_irq (kbuild/src/consumer/kernel/rcu/tree_plugin.h:699 kbuild/src/consumer/kernel/rcu/tree.c:2649)
kern :warn : [ 107.586974] Code: 30 0b bf 00 e9 cb fd ff ff 69 c0 e8 03 00 00 8d 84 40 98 3a 00 00 48 98 e9 28 fc ff ff 4c 89 e7 e8 69 bc ff ff e9 f6 f8 ff ff <0f> 0b e9 d6 f8 ff ff e8 78 29 ff ff 84 c0 0f 85 9d fc ff ff e9 a6
All code
========
0: 30 0b xor %cl,(%rbx)
2: bf 00 e9 cb fd mov $0xfdcbe900,%edi
7: ff (bad)
8: ff 69 c0 ljmp *-0x40(%rcx)
b: e8 03 00 00 8d callq 0xffffffff8d000013
10: 84 40 98 test %al,-0x68(%rax)
13: 3a 00 cmp (%rax),%al
15: 00 48 98 add %cl,-0x68(%rax)
18: e9 28 fc ff ff jmpq 0xfffffffffffffc45
1d: 4c 89 e7 mov %r12,%rdi
20: e8 69 bc ff ff callq 0xffffffffffffbc8e
25: e9 f6 f8 ff ff jmpq 0xfffffffffffff920
2a:* 0f 0b ud2 <-- trapping instruction
2c: e9 d6 f8 ff ff jmpq 0xfffffffffffff907
31: e8 78 29 ff ff callq 0xffffffffffff29ae
36: 84 c0 test %al,%al
38: 0f 85 9d fc ff ff jne 0xfffffffffffffcdb
3e: e9 .byte 0xe9
3f: a6 cmpsb %es:(%rdi),%ds:(%rsi)

Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: e9 d6 f8 ff ff jmpq 0xfffffffffffff8dd
7: e8 78 29 ff ff callq 0xffffffffffff2984
c: 84 c0 test %al,%al
e: 0f 85 9d fc ff ff jne 0xfffffffffffffcb1
14: e9 .byte 0xe9
15: a6 cmpsb %es:(%rdi),%ds:(%rsi)
kern :warn : [ 107.606374] RSP: 0018:ffffc90000003e88 EFLAGS: 00010086
kern :warn : [ 107.611815] RAX: 0000000000000000 RBX: 00000000ffffffff RCX: 0000000000000000
kern :warn : [ 107.619167] RDX: 0000000000000000 RSI: ffffffff828a6c35 RDI: ffffffff82823c4e
kern :warn : [ 107.626557] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
kern :warn : [ 107.633990] R10: ffff888439890000 R11: 0000000000000000 R12: ffff888439890000
kern :warn : [ 107.641393] R13: 00000000ffffffff R14: 0000000000000001 R15: 0000000000000001
kern :warn : [ 107.648839] FS: 00007f5d95a17740(0000) GS:ffff88843f400000(0000) knlGS:0000000000000000
kern :warn : [ 107.657198] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
kern :warn : [ 107.663128] CR2: 00007ffdd18f6084 CR3: 00000002371ac005 CR4: 00000000003706f0
kern :warn : [ 107.670518] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
kern :warn : [ 107.677960] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
kern :warn : [ 107.685334] Call Trace:
kern :warn : [ 107.687880] <IRQ>
kern :warn : [ 107.690014] update_process_times (kbuild/src/consumer/arch/x86/include/asm/preempt.h:27 kbuild/src/consumer/kernel/time/timer.c:1798)
kern :warn : [ 107.694356] tick_sched_handle+0x1f/0x60
kern :warn : [ 107.699067] tick_sched_timer (kbuild/src/consumer/kernel/time/tick-sched.c:1374)
kern :warn : [ 107.703040] ? tick_sched_do_timer (kbuild/src/consumer/kernel/time/tick-sched.c:1356)
kern :warn : [ 107.707483] __hrtimer_run_queues (kbuild/src/consumer/kernel/time/hrtimer.c:1537 kbuild/src/consumer/kernel/time/hrtimer.c:1601)
kern :warn : [ 107.712090] hrtimer_interrupt (kbuild/src/consumer/kernel/time/hrtimer.c:1666)
kern :warn : [ 107.716416] __sysvec_apic_timer_interrupt (kbuild/src/consumer/arch/x86/include/asm/jump_label.h:25 kbuild/src/consumer/include/linux/jump_label.h:200 kbuild/src/consumer/arch/x86/include/asm/trace/irq_vectors.h:41 kbuild/src/consumer/arch/x86/kernel/apic/apic.c:1107)
kern :warn : [ 107.721645] sysvec_apic_timer_interrupt (kbuild/src/consumer/arch/x86/kernel/apic/apic.c:1100 (discriminator 14))
kern :warn : [ 107.726628] </IRQ>
kern :warn : [ 107.728876] asm_sysvec_apic_timer_interrupt (kbuild/src/consumer/arch/x86/include/asm/idtentry.h:632)
kern :warn : [ 107.734190] RIP: 0010:report_bug (kbuild/src/consumer/lib/bug.c:59 kbuild/src/consumer/lib/bug.c:135 kbuild/src/consumer/lib/bug.c:150)
kern :warn : [ 107.738511] Code: 40 67 72 83 48 3d f4 7a 74 83 73 33 48 63 05 0b 52 02 02 48 c7 c3 40 67 72 83 48 05 40 67 72 83 49 39 c4 75 0d eb 23 48 63 03 <48> 01 d8 49 39 c4 74 18 48 83 c3 0c 48 81 fb f4 7a 74 83 72 e8 4c
All code
========
0: 40 rex
1: 67 72 83 addr32 jb 0xffffffffffffff87
4: 48 3d f4 7a 74 83 cmp $0xffffffff83747af4,%rax
a: 73 33 jae 0x3f
c: 48 63 05 0b 52 02 02 movslq 0x202520b(%rip),%rax # 0x202521e
13: 48 c7 c3 40 67 72 83 mov $0xffffffff83726740,%rbx
1a: 48 05 40 67 72 83 add $0xffffffff83726740,%rax
20: 49 39 c4 cmp %rax,%r12
23: 75 0d jne 0x32
25: eb 23 jmp 0x4a
27: 48 63 03 movslq (%rbx),%rax
2a:* 48 01 d8 add %rbx,%rax <-- trapping instruction
2d: 49 39 c4 cmp %rax,%r12
30: 74 18 je 0x4a
32: 48 83 c3 0c add $0xc,%rbx
36: 48 81 fb f4 7a 74 83 cmp $0xffffffff83747af4,%rbx
3d: 72 e8 jb 0x27
3f: 4c rex.WR

Code starting with the faulting instruction
===========================================
0: 48 01 d8 add %rbx,%rax
3: 49 39 c4 cmp %rax,%r12
6: 74 18 je 0x20
8: 48 83 c3 0c add $0xc,%rbx
c: 48 81 fb f4 7a 74 83 cmp $0xffffffff83747af4,%rbx
13: 72 e8 jb 0xfffffffffffffffd
15: 4c rex.WR
kern :warn : [ 107.757968] RSP: 0018:ffffc90000f576a8 EFLAGS: 00000283
kern :warn : [ 107.763365] RAX: fffffffffdac8932 RBX: ffffffff8372d004 RCX: ffffffff82000fb7
kern :warn : [ 107.770759] RDX: 00007ffffffff000 RSI: ffffc90000f57708 RDI: ffffffff812276c4
kern :warn : [ 107.778119] RBP: ffffc90000f57708 R08: 0000000000000000 R09: 0000000000000000
kern :warn : [ 107.785470] R10: 0000000000000000 R11: 0000000000000000 R12: ffffffff812276c4
kern :warn : [ 107.792913] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
kern :warn : [ 107.800312] ? __rcu_read_unlock (kbuild/src/consumer/kernel/rcu/tree_plugin.h:404 kbuild/src/consumer/kernel/rcu/tree_plugin.h:392)
kern :warn : [ 107.804698] ? native_iret (kbuild/src/consumer/arch/x86/entry/entry_64.S:644)
kern :warn : [ 107.808241] ? __rcu_read_unlock (kbuild/src/consumer/kernel/rcu/tree_plugin.h:404 kbuild/src/consumer/kernel/rcu/tree_plugin.h:392)
kern :warn : [ 107.812599] ? report_bug (kbuild/src/consumer/lib/bug.c:147)
kern :warn : [ 107.816390] handle_bug (kbuild/src/consumer/arch/x86/kernel/traps.c:239)
kern :warn : [ 107.819905] exc_invalid_op (kbuild/src/consumer/arch/x86/kernel/traps.c:259 (discriminator 1))
kern :warn : [ 107.823718] asm_exc_invalid_op (kbuild/src/consumer/arch/x86/include/asm/idtentry.h:575)
kern :warn : [ 107.827905] RIP: 0010:__rcu_read_unlock (kbuild/src/consumer/kernel/rcu/tree_plugin.h:404 kbuild/src/consumer/kernel/rcu/tree_plugin.h:392)
kern :warn : [ 107.832929] Code: 81 e2 00 00 0f 00 0f 85 d2 00 00 00 4d 85 ed 74 40 84 c0 74 3c bf 09 00 00 00 e8 87 9c f5 ff e8 a2 b9 09 00 fb e9 43 ff ff ff <0f> 0b 5b 5d 41 5c 41 5d c3 e8 8e ba 09 00 66 85 db 0f 85 6f ff ff
All code
========
0: 81 e2 00 00 0f 00 and $0xf0000,%edx
6: 0f 85 d2 00 00 00 jne 0xde
c: 4d 85 ed test %r13,%r13
f: 74 40 je 0x51
11: 84 c0 test %al,%al
13: 74 3c je 0x51
15: bf 09 00 00 00 mov $0x9,%edi
1a: e8 87 9c f5 ff callq 0xfffffffffff59ca6
1f: e8 a2 b9 09 00 callq 0x9b9c6
24: fb sti
25: e9 43 ff ff ff jmpq 0xffffffffffffff6d
2a:* 0f 0b ud2 <-- trapping instruction
2c: 5b pop %rbx
2d: 5d pop %rbp
2e: 41 5c pop %r12
30: 41 5d pop %r13
32: c3 retq
33: e8 8e ba 09 00 callq 0x9bac6
38: 66 85 db test %bx,%bx
3b: 0f .byte 0xf
3c: 85 6f ff test %ebp,-0x1(%rdi)
3f: ff .byte 0xff

Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: 5b pop %rbx
3: 5d pop %rbp
4: 41 5c pop %r12
6: 41 5d pop %r13
8: c3 retq
9: e8 8e ba 09 00 callq 0x9ba9c
e: 66 85 db test %bx,%bx
11: 0f .byte 0xf
12: 85 6f ff test %ebp,-0x1(%rdi)
15: ff .byte 0xff


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


Attachments:
(No filename) (16.97 kB)
config-5.12.0-rc6-02036-gd509b127ccf0 (176.19 kB)
job-script (7.09 kB)
kmsg.xz (63.71 kB)
kernel-selftests (132.72 kB)
job.yaml (6.13 kB)
reproduce (272.00 B)
Download all attachments