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
--
Linaro LKFT
https://lkft.linaro.org
On Tue, Apr 7, 2020 at 2:58 AM Naresh Kamboju <[email protected]> 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 <[email protected]> wrote:
>
> On Tue, Apr 7, 2020 at 2:58 AM Naresh Kamboju <[email protected]> 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 <[email protected]> wrote:
>
> On Sat, 11 Apr 2020 at 02:20, Cong Wang <[email protected]> wrote:
> >
> > On Tue, Apr 7, 2020 at 2:58 AM Naresh Kamboju <[email protected]> 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
--
Linaro LKFT
https://lkft.linaro.org