linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* x86_64: 5.6.0: locking/lockdep.c:1155 lockdep_register_key
@ 2020-04-07  9:57 Naresh Kamboju
  2020-04-10 20:50 ` Cong Wang
  0 siblings, 1 reply; 4+ messages in thread
From: Naresh Kamboju @ 2020-04-07  9:57 UTC (permalink / raw)
  To: open list, open list:KERNEL SELFTEST FRAMEWORK
  Cc: Borislav Petkov, Netdev, Peter Zijlstra, Brian Gerst,
	lkft-triage, Alexei Starovoitov, Andrii Nakryiko

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

^ permalink raw reply	[flat|nested] 4+ messages in thread

* Re: x86_64: 5.6.0: locking/lockdep.c:1155 lockdep_register_key
  2020-04-07  9:57 x86_64: 5.6.0: locking/lockdep.c:1155 lockdep_register_key Naresh Kamboju
@ 2020-04-10 20:50 ` Cong Wang
  2020-04-16 17:45   ` Naresh Kamboju
  0 siblings, 1 reply; 4+ messages in thread
From: Cong Wang @ 2020-04-10 20:50 UTC (permalink / raw)
  To: Naresh Kamboju
  Cc: open list, open list:KERNEL SELFTEST FRAMEWORK, Borislav Petkov,
	Netdev, Peter Zijlstra, Brian Gerst, lkft-triage,
	Alexei Starovoitov, Andrii Nakryiko

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.

^ permalink raw reply	[flat|nested] 4+ messages in thread

* Re: x86_64: 5.6.0: locking/lockdep.c:1155 lockdep_register_key
  2020-04-10 20:50 ` Cong Wang
@ 2020-04-16 17:45   ` Naresh Kamboju
  2020-05-13 17:00     ` Naresh Kamboju
  0 siblings, 1 reply; 4+ messages in thread
From: Naresh Kamboju @ 2020-04-16 17:45 UTC (permalink / raw)
  To: Cong Wang
  Cc: open list, open list:KERNEL SELFTEST FRAMEWORK, Borislav Petkov,
	Netdev, Peter Zijlstra, Brian Gerst, lkft-triage,
	Alexei Starovoitov, Andrii Nakryiko

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

^ permalink raw reply	[flat|nested] 4+ messages in thread

* Re: x86_64: 5.6.0: locking/lockdep.c:1155 lockdep_register_key
  2020-04-16 17:45   ` Naresh Kamboju
@ 2020-05-13 17:00     ` Naresh Kamboju
  0 siblings, 0 replies; 4+ messages in thread
From: Naresh Kamboju @ 2020-05-13 17:00 UTC (permalink / raw)
  To: Cong Wang
  Cc: open list, open list:KERNEL SELFTEST FRAMEWORK, Borislav Petkov,
	Netdev, Peter Zijlstra, Brian Gerst, lkft-triage,
	Alexei Starovoitov, Andrii Nakryiko

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


-- 
Linaro LKFT
https://lkft.linaro.org

^ permalink raw reply	[flat|nested] 4+ messages in thread

end of thread, other threads:[~2020-05-13 17:00 UTC | newest]

Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-04-07  9:57 x86_64: 5.6.0: locking/lockdep.c:1155 lockdep_register_key Naresh Kamboju
2020-04-10 20:50 ` Cong Wang
2020-04-16 17:45   ` Naresh Kamboju
2020-05-13 17:00     ` Naresh Kamboju

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).