On Linux mainline kernel 5.6.0 running kselftest on i386 kernel running on x86_64 devices we have noticed this kernel warning.
[ 0.000000] Linux version 5.6.0 (oe-user@oe-host) (gcc version 7.3.0 (GCC)) #1 SMP Mon Apr 6 17:31:22 UTC 2020 <> [ 143.321511] ------------[ cut here ]------------ [ 143.326180] WARNING: CPU: 1 PID: 1515 at /usr/src/kernel/kernel/locking/lockdep.c:1155 lockdep_register_key+0x150/0x180 [ 143.336958] Modules linked in: sch_ingress veth algif_hash x86_pkg_temp_thermal fuse [ 143.344698] CPU: 1 PID: 1515 Comm: ip Tainted: G W 5.6.0 #1 [ 143.351562] Hardware name: Supermicro SYS-5019S-ML/X11SSH-F, BIOS 2.0b 07/27/2017 [ 143.359034] EIP: lockdep_register_key+0x150/0x180 [ 143.363739] Code: ff ff a1 88 4c 2a dc 85 c0 0f 85 ef fe ff ff 68 27 02 f9 db 68 a5 7a f7 db e8 0c 5b fa ff 0f 0b 59 58 e9 d7 fe ff ff 8d 76 00 <0f> 0b 8d 65 f8 5b 5e 5d c3 8d b4 26 00 00 00 00 89 c2 b8 68 68 99 [ 143.382485] EAX: 00000001 EBX: dc329ea8 ECX: 00000001 EDX: dc3299a8 [ 143.388751] ESI: 00000001 EDI: c7316000 EBP: c610fe10 ESP: c610fe08 [ 143.395014] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 EFLAGS: 00010202 [ 143.401792] CR0: 80050033 CR2: b7dd70c0 CR3: 20672000 CR4: 003406d0 [ 143.408051] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000 [ 143.414315] DR6: fffe0ff0 DR7: 00000400 [ 143.418144] Call Trace: [ 143.420592] alloc_netdev_mqs+0xc6/0x3c0 [ 143.424520] __ip_tunnel_create+0xa1/0x1d0 [ 143.428614] ? ipgre_tap_setup+0x50/0x50 [ 143.432535] ? mutex_lock_nested+0x19/0x20 [ 143.436634] ip_tunnel_init_net+0x125/0x340 [ 143.440823] erspan_init_net+0x1d/0x20 [ 143.444580] ops_init+0x34/0x180 [ 143.447815] setup_net+0xe7/0x230 [ 143.451134] copy_net_ns+0xe0/0x210 [ 143.454625] create_new_namespaces+0xf5/0x290 [ 143.458984] unshare_nsproxy_namespaces+0x47/0xa0 [ 143.463691] ksys_unshare+0x19e/0x330 [ 143.467354] ? __might_fault+0x41/0x80 [ 143.471102] __ia32_sys_unshare+0xf/0x20 [ 143.475026] do_fast_syscall_32+0x7f/0x330 [ 143.479126] entry_SYSENTER_32+0xaa/0x102 [ 143.483135] EIP: 0xb7f77ce1 [ 143.485926] Code: 5e 5d c3 8d b6 00 00 00 00 b8 40 42 0f 00 eb c1 8b 04 24 c3 8b 1c 24 c3 8b 34 24 c3 8b 3c 24 c3 90 51 52 55 89 e5 0f 34 cd 80 <5d> 5a 59 c3 90 90 90 90 8d 76 00 58 b8 77 00 00 00 cd 80 90 8d 76 [ 143.504662] EAX: ffffffda EBX: 40000000 ECX: 080a8b31 EDX: 00000000 [ 143.510920] ESI: 00000001 EDI: bf833230 EBP: bf830fc0 ESP: bf830f7c [ 143.517177] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b EFLAGS: 00000292 [ 143.523959] irq event stamp: 5894 [ 143.527275] hardirqs last enabled at (5893): [<dbc0225a>] _raw_spin_unlock_irqrestore+0x2a/0x50 [ 143.536054] hardirqs last disabled at (5894): [<dae019dc>] trace_hardirqs_off_thunk+0xc/0x10 [ 143.544487] softirqs last enabled at (5882): [<dba45069>] inet6_fill_ifla6_attrs+0x3b9/0x400 [ 143.553004] softirqs last disabled at (5880): [<dba4504b>] inet6_fill_ifla6_attrs+0x39b/0x400 [ 143.561514] ---[ end trace dbec531a9fb3b99c ]---
Full test log, https://lkft.validation.linaro.org/scheduler/job/1341969#L5766
On Tue, Apr 7, 2020 at 2:58 AM Naresh Kamboju naresh.kamboju@linaro.org wrote:
On Linux mainline kernel 5.6.0 running kselftest on i386 kernel running on x86_64 devices we have noticed this kernel warning.
[ 0.000000] Linux version 5.6.0 (oe-user@oe-host) (gcc version 7.3.0 (GCC)) #1 SMP Mon Apr 6 17:31:22 UTC 2020 <> [ 143.321511] ------------[ cut here ]------------ [ 143.326180] WARNING: CPU: 1 PID: 1515 at /usr/src/kernel/kernel/locking/lockdep.c:1155 lockdep_register_key+0x150/0x180 [ 143.336958] Modules linked in: sch_ingress veth algif_hash x86_pkg_temp_thermal fuse [ 143.344698] CPU: 1 PID: 1515 Comm: ip Tainted: G W 5.6.0 #1 [ 143.351562] Hardware name: Supermicro SYS-5019S-ML/X11SSH-F, BIOS 2.0b 07/27/2017 [ 143.359034] EIP: lockdep_register_key+0x150/0x180 [ 143.363739] Code: ff ff a1 88 4c 2a dc 85 c0 0f 85 ef fe ff ff 68 27 02 f9 db 68 a5 7a f7 db e8 0c 5b fa ff 0f 0b 59 58 e9 d7 fe ff ff 8d 76 00 <0f> 0b 8d 65 f8 5b 5e 5d c3 8d b4 26 00 00 00 00 89 c2 b8 68 68 99 [ 143.382485] EAX: 00000001 EBX: dc329ea8 ECX: 00000001 EDX: dc3299a8 [ 143.388751] ESI: 00000001 EDI: c7316000 EBP: c610fe10 ESP: c610fe08 [ 143.395014] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 EFLAGS: 00010202 [ 143.401792] CR0: 80050033 CR2: b7dd70c0 CR3: 20672000 CR4: 003406d0 [ 143.408051] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000 [ 143.414315] DR6: fffe0ff0 DR7: 00000400 [ 143.418144] Call Trace: [ 143.420592] alloc_netdev_mqs+0xc6/0x3c0
This is odd, the warning complains a lockdep key is static, but all of the 3 lockdep keys in netdev_register_lockdep_key() are dynamic. I don't see how this warning could happen.
Thanks.
On Sat, 11 Apr 2020 at 02:20, Cong Wang xiyou.wangcong@gmail.com wrote:
On Tue, Apr 7, 2020 at 2:58 AM Naresh Kamboju naresh.kamboju@linaro.org wrote:
On Linux mainline kernel 5.6.0 running kselftest on i386 kernel running on x86_64 devices we have noticed this kernel warning.
This is odd, the warning complains a lockdep key is static, but all of the 3 lockdep keys in netdev_register_lockdep_key() are dynamic. I don't see how this warning could happen.
I request to provide a debug patch which prints a detailed log. Happy to test it again with your debug patch and will provide more information.
- Naresh
On Thu, 16 Apr 2020 at 23:15, Naresh Kamboju naresh.kamboju@linaro.org wrote:
On Sat, 11 Apr 2020 at 02:20, Cong Wang xiyou.wangcong@gmail.com wrote:
On Tue, Apr 7, 2020 at 2:58 AM Naresh Kamboju naresh.kamboju@linaro.org wrote:
On Linux mainline kernel 5.6.0 running kselftest on i386 kernel running on x86_64 devices we have noticed this kernel warning.
This is odd, the warning complains a lockdep key is static, but all of the 3 lockdep keys in netdev_register_lockdep_key() are dynamic. I don't see how this warning could happen.
The reported kernel warning is still reproducible on stable rc 5.6 branch kernel on i386 kernel running on x86_64 hardware.
[ 543.896836] audit: type=1415 audit(1589376671.756:87534): op=SPD-add auid=4294967295 ses=4294967295 subj=kernel res=1 src=0000:0000:0000:0000:0000:0000:0000:0000 src_prefixlen=0 dst=0000:0000:0000:0000:0000:0000:0000:0000 dst_prefixlen=0 [ 543.924403] audit: type=1415 audit(1589376671.783:87535): op=SPD-add auid=4294967295 ses=4294967295 subj=kernel res=1 src=0000:0000:0000:0000:0000:0000:0000:0000 src_prefixlen=0 dst=0000:0000:0000:0000:0000:0000:0000:0000 dst_prefixlen=0 [ 544.111779] IPv6: ADDRCONF(NETDEV_CHANGE): veth_a: link becomes ready [ 544.315145] IPv6: ADDRCONF(NETDEV_CHANGE): veth_a: link becomes ready [ 544.340418] ------------[ cut here ]------------ [ 544.345049] WARNING: CPU: 3 PID: 17049 at /usr/src/kernel/kernel/locking/lockdep.c:1119 lockdep_register_key+0xb0/0xf0 [ 544.355738] Modules linked in: sit vrf test_printf(+) cls_bpf sch_fq 8021q veth algif_hash af_alg x86_pkg_temp_thermal fuse [last unloaded: test_blackhole_dev] [ 544.369994] CPU: 3 PID: 17049 Comm: ip Tainted: G D W 5.6.13-rc1 #1 [ 544.377376] Hardware name: Supermicro SYS-5019S-ML/X11SSH-F, BIOS 2.2 05/23/2018 [ 544.384763] EIP: lockdep_register_key+0xb0/0xf0 [ 544.389294] Code: 05 04 b8 8c d7 00 eb da 66 90 8b 04 95 00 68 7e d7 89 4b 04 89 03 85 c0 89 1c 95 00 68 7e d7 74 a5 89 58 04 eb a0 8d 74 26 00 <0f> 0b 8d 65 f8 5b 5e 5d c3 8d b4 26 00 00 00 00 e8 1b 9e 3c 00 85 [ 544.408031] EAX: 00000001 EBX: d79e367c ECX: 00000000 EDX: d79e31a4 [ 544.414288] ESI: 00000001 EDI: ffffffff EBP: f5a0fa24 ESP: f5a0fa1c [ 544.420545] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 EFLAGS: 00010202 [ 544.427324] CR0: 80050033 CR2: 0807e7c0 CR3: 20eac000 CR4: 003406d0 [ 544.433589] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000 [ 544.439855] DR6: fffe0ff0 DR7: 00000400 [ 544.443693] Call Trace: [ 544.446143] alloc_netdev_mqs+0xcb/0x3c0 [ 544.450067] rtnl_create_link+0x133/0x290 [ 544.454079] ? vti_newlink+0x60/0x60 [ 544.457659] __rtnl_newlink+0x637/0x8e0 [ 544.461504] ? mem_cgroup_throttle_swaprate+0x10/0x270 [ 544.466651] ? mem_cgroup_commit_charge+0x47/0x2c0 [ 544.471436] ? trace_hardirqs_on+0x43/0xf0 [ 544.475535] ? handle_mm_fault+0x931/0xcf0 [ 544.479656] rtnl_newlink+0x3c/0x60 [ 544.483152] ? __rtnl_newlink+0x8e0/0x8e0 [ 544.487158] rtnetlink_rcv_msg+0x24b/0x480 [ 544.491258] ? __rtnl_newlink+0x8e0/0x8e0 [ 544.495270] ? netlink_deliver_tap+0x86/0x3b0 [ 544.499630] ? validate_linkmsg+0x300/0x300 [ 544.503813] netlink_rcv_skb+0x6e/0xf0 [ 544.507562] rtnetlink_rcv+0x12/0x20 [ 544.511135] netlink_unicast+0x195/0x250 [ 544.515057] netlink_sendmsg+0x27d/0x430 [ 544.518984] ? netlink_unicast+0x250/0x250 [ 544.523078] sock_sendmsg+0x5c/0x60 [ 544.526564] ____sys_sendmsg+0x191/0x1e0 [ 544.530488] ? copy_msghdr_from_user+0xb9/0x150 [ 544.535016] ___sys_sendmsg+0x5e/0xa0 [ 544.538681] ? lock_page_memcg+0x5/0xe0 [ 544.542520] ? __unlock_page_memcg+0x2d/0xa0 [ 544.546793] ? __unlock_page_memcg+0x43/0xa0 [ 544.551065] ? page_add_file_rmap+0x58/0xa0 [ 544.555249] ? alloc_set_pte+0x10d/0x420 [ 544.559171] ? ktime_get_coarse_real_ts64+0x48/0xc0 [ 544.564056] __sys_sendmsg+0x3e/0x80 [ 544.567640] sys_socketcall+0x20a/0x340 [ 544.571482] ? __might_fault+0x41/0x80 [ 544.575236] do_fast_syscall_32+0x8e/0x340 [ 544.579337] entry_SYSENTER_32+0xaa/0x102 [ 544.583347] EIP: 0xb7f03c11 [ 544.586146] Code: 5e 5d c3 8d b6 00 00 00 00 b8 40 42 0f 00 eb be 8b 04 24 c3 8b 1c 24 c3 8b 34 24 c3 8b 3c 24 c3 90 51 52 55 89 e5 0f 34 cd 80 <5d> 5a 59 c3 90 90 90 90 8d 76 00 58 b8 77 00 00 00 cd 80 90 8d 76 [ 544.604891] EAX: ffffffda EBX: 00000010 ECX: bfab9c34 EDX: 00000000 [ 544.611154] ESI: 00000000 EDI: 080e52c0 EBP: 00000010 ESP: bfab9c20 [ 544.617412] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b EFLAGS: 00000286 [ 544.624196] irq event stamp: 0 [ 544.627258] hardirqs last enabled at (0): [<00000000>] 0x0 [ 544.632823] hardirqs last disabled at (0): [<d5eeb738>] copy_process+0x3e8/0x1810 [ 544.640300] softirqs last enabled at (0): [<d5eeb738>] copy_process+0x3e8/0x1810 [ 544.647770] softirqs last disabled at (0): [<00000000>] 0x0 [ 544.653335] ---[ end trace e7d4a168a647a827 ]--- [ 544.833114] IPv6: ADDRCONF(NETDEV_CHANGE): veth_b: link becomes ready [ 544.839733] IPv6: ADDRCONF(NETDEV_CHANGE): veth_a: link becomes ready [ 545.005827] ------------[ cut here ]------------ [ 545.010459] WARNING: CPU: 3 PID: 17131 at /usr/src/kernel/kernel/locking/lockdep.c:5179 lockdep_unregister_key+0xf0/0x130 [ 545.021399] Modules linked in: sit vrf test_printf(+) cls_bpf sch_fq 8021q veth algif_hash af_alg x86_pkg_temp_thermal fuse [last unloaded: test_blackhole_dev] [ 545.035642] CPU: 3 PID: 17131 Comm: ip Tainted: G D W 5.6.13-rc1 #1 [ 545.043031] Hardware name: Supermicro SYS-5019S-ML/X11SSH-F, BIOS 2.2 05/23/2018 [ 545.050417] EIP: lockdep_unregister_key+0xf0/0x130 [ 545.055208] Code: 05 04 b8 8c d7 00 eb d8 66 90 89 da 8b 02 8b 4a 04 85 c0 89 01 74 03 89 48 04 c7 42 04 22 01 00 00 eb 8b 8d b4 26 00 00 00 00 <0f> 0b 8d 65 f4 5b 5e 5f 5d c3 8d b6 00 00 00 00 e8 eb 9c 3c 00 85 [ 545.073947] EAX: 00000001 EBX: d79e667c ECX: 00000000 EDX: 00001439 [ 545.080211] ESI: d79e6000 EDI: d79e6034 EBP: ebb8dc7c ESP: ebb8dc70 [ 545.086475] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 EFLAGS: 00010202 [ 545.093253] CR0: 80050033 CR2: b7dcb0a0 CR3: 258c0000 CR4: 003406d0 [ 545.099510] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000 [ 545.105767] DR6: fffe0ff0 DR7: 00000400 [ 545.109598] Call Trace: [ 545.112046] free_netdev+0xf2/0x160 [ 545.115538] netdev_run_todo+0x237/0x2a0 [ 545.119464] ? valid_fdb_dump_legacy+0xc0/0xc0 [ 545.123907] rtnetlink_rcv_msg+0x252/0x480 [ 545.127999] ? valid_fdb_dump_legacy+0xc0/0xc0 [ 545.132447] ? netlink_deliver_tap+0x86/0x3b0 [ 545.136805] ? validate_linkmsg+0x300/0x300 [ 545.140989] netlink_rcv_skb+0x6e/0xf0 [ 545.144735] rtnetlink_rcv+0x12/0x20 [ 545.148314] netlink_unicast+0x195/0x250 [ 545.152238] netlink_sendmsg+0x27d/0x430 [ 545.156169] ? netlink_unicast+0x250/0x250 [ 545.160271] sock_sendmsg+0x5c/0x60 [ 545.163758] ____sys_sendmsg+0x191/0x1e0 [ 545.167682] ? copy_msghdr_from_user+0xb9/0x150 [ 545.172216] ___sys_sendmsg+0x5e/0xa0 [ 545.175887] ? destroy_inode+0x52/0x70 [ 545.179640] ? free_inode_nonrcu+0x20/0x20 [ 545.183737] ? ktime_get_coarse_real_ts64+0x48/0xc0 [ 545.188613] __sys_sendmsg+0x3e/0x80 [ 545.192197] sys_socketcall+0x20a/0x340 [ 545.196042] ? __might_fault+0x41/0x80 [ 545.199792] do_fast_syscall_32+0x8e/0x340 [ 545.203893] entry_SYSENTER_32+0xaa/0x102 [ 545.207903] EIP: 0xb7ef5c11 [ 545.210692] Code: 5e 5d c3 8d b6 00 00 00 00 b8 40 42 0f 00 eb be 8b 04 24 c3 8b 1c 24 c3 8b 34 24 c3 8b 3c 24 c3 90 51 52 55 89 e5 0f 34 cd 80 <5d> 5a 59 c3 90 90 90 90 8d 76 00 58 b8 77 00 00 00 cd 80 90 8d 76 [ 545.229430] EAX: ffffffda EBX: 00000010 ECX: bfdce2a4 EDX: 00000000 [ 545.235687] ESI: 00000000 EDI: 080e52c0 EBP: 00000010 ESP: bfdce290 [ 545.241944] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b EFLAGS: 00000282 [ 545.248726] irq event stamp: 0 [ 545.251781] hardirqs last enabled at (0): [<00000000>] 0x0 [ 545.257347] hardirqs last disabled at (0): [<d5eeb738>] copy_process+0x3e8/0x1810 [ 545.264823] softirqs last enabled at (0): [<d5eeb738>] copy_process+0x3e8/0x1810 [ 545.272293] softirqs last disabled at (0): [<00000000>] 0x0 [ 545.277857] ---[ end trace e7d4a168a647a828 ]--- [ 546.768756] IPv6: ADDRCONF(NETDEV_CHANGE): veth_A-R1: link becomes ready [ 546.799782] IPv6: ADDRCONF(NETDEV_CHANGE): veth_A-R2: link becomes ready [ 546.828383] IPv6: ADDRCONF(NETDEV_CHANGE): veth_B-R1: link becomes ready [ 546.857536] IPv6: ADDRCONF(NETDEV_CHANGE): veth_B-R2: link becomes ready [ 547.794885] IPv6: ADDRCONF(NETDEV_CHANGE): veth_R1-A: link becomes ready
ref: https://lkft.validation.linaro.org/scheduler/job/1430346#L14444
-
Cong Wang -
Naresh Kamboju