2020-10-14 09:25:22

by Naresh Kamboju

[permalink] [raw]
Subject: WARNING: at net/netfilter/nf_tables_api.c:622 lockdep_nfnl_nft_mutex_not_held+0x28/0x38 [nf_tables]

While running kselftest netfilter on arm64 hikey device on Linux next
20201013 the following
kernel warning noticed.

metadata:
git branch: master
git repo: https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git
git commit: f2fb1afc57304f9dd68c20a08270e287470af2eb
git describe: next-20201013
make_kernelversion: 5.9.0
kernel-config:
http://snapshots.linaro.org/openembedded/lkft/lkft/sumo/hikey/lkft/linux-next/879/config

steps to reproduce:
---------------------------
# cd /opt/kselftests/default-in-kernel/
# ./run_kselftest.sh -c netfilter

crash log:
----------------
# selftests: netfilter: nft_trans_stress.sh
[ 1913.862919] ------------[ cut here ]------------
[ 1913.869773] WARNING: CPU: 2 PID: 31416 at
/usr/src/kernel/net/netfilter/nf_tables_api.c:622
lockdep_nfnl_nft_mutex_not_held+0x28/0x38 [nf_tables]
[ 1913.885399] Modules linked in: nf_tables nfnetlink act_mirred
cls_u32 sch_etf xt_conntrack nf_conntrack nf_defrag_ipv4 libcrc32c
ip6_tables nf_defrag_ipv6 ip_tables x_tables netdevsim 8021q garp mrp
bridge stp llc sch_fq sch_ingress veth algif_hash wl18xx wlcore
mac80211 cfg80211 snd_soc_hdmi_codec hci_uart btqca btbcm crct10dif_ce
snd_soc_audio_graph_card snd_soc_simple_card_utils adv7511 wlcore_sdio
cec bluetooth kirin_drm lima rfkill dw_drm_dsi gpu_sched
drm_kms_helper drm fuse [last unloaded: test_blackhole_dev]
[ 1913.941924] CPU: 2 PID: 31416 Comm: nft Tainted: G W
5.9.0-next-20201013 #1
[ 1913.954131] Hardware name: HiKey Development Board (DT)
[ 1913.963342] pstate: 00000005 (nzcv daif -PAN -UAO -TCO BTYPE=--)
[ 1913.973483] pc : lockdep_nfnl_nft_mutex_not_held+0x28/0x38 [nf_tables]
[ 1913.984271] lr : lockdep_nfnl_nft_mutex_not_held+0x18/0x38 [nf_tables]
[ 1913.995018] sp : ffff800013bc3550
[ 1914.002559] x29: ffff800013bc3550 x28: ffff800013bc3930
[ 1914.012197] x27: 0000000000000001 x26: ffff000045dc4e00
[ 1914.021880] x25: 0000000000000001 x24: ffff000045dc4e00
[ 1914.031565] x23: ffff800013bc3930 x22: 0000000000000001
[ 1914.041298] x21: ffff800012750000 x20: ffff800013bc3668
[ 1914.051068] x19: ffff800012750000 x18: 0000000000000000
[ 1914.060876] x17: 0000000000000000 x16: 0000000000000000
[ 1914.070699] x15: 0000000000000000 x14: ffff800009996d48
[ 1914.080534] x13: ffffffffff000000 x12: 0000000000000028
[ 1914.090418] x11: 0101010101010101 x10: 7f7f7f7f7f7f7f7f
[ 1914.100355] x9 : fefefefefefefeff x8 : 7f7f7f7f7f7f7f7f
[ 1914.110325] x7 : fefeff53544f4d48 x6 : 0000000000007ab8
[ 1914.120339] x5 : 0000000000000005 x4 : 0000000000000001
[ 1914.130388] x3 : 0000000000000001 x2 : 0000000000000000
[ 1914.140454] x1 : 00000000ffffffff x0 : 0000000000000001
[ 1914.150529] Call trace:
[ 1914.157789] lockdep_nfnl_nft_mutex_not_held+0x28/0x38 [nf_tables]
[ 1914.168967] nft_chain_parse_hook+0x58/0x320 [nf_tables]
[ 1914.179342] nf_tables_addchain.isra.66+0xb8/0x510 [nf_tables]
[ 1914.190340] nf_tables_newchain+0x408/0x618 [nf_tables]
[ 1914.200734] nfnetlink_rcv_batch+0x4a0/0x610 [nfnetlink]
[ 1914.211284] nfnetlink_rcv+0x174/0x1a8 [nfnetlink]
[ 1914.221351] netlink_unicast+0x1dc/0x290
[ 1914.230589] netlink_sendmsg+0x2b8/0x3f8
[ 1914.239840] ____sys_sendmsg+0x288/0x2d0
[ 1914.249117] ___sys_sendmsg+0x90/0xd0
[ 1914.258154] __sys_sendmsg+0x78/0xd0
[ 1914.267140] __arm64_sys_sendmsg+0x2c/0x38
[ 1914.276705] el0_svc_common.constprop.3+0x7c/0x198
[ 1914.287041] do_el0_svc+0x34/0xa0
[ 1914.295928] el0_sync_handler+0x128/0x190
[ 1914.305567] el0_sync+0x140/0x180
[ 1914.314535] CPU: 2 PID: 31416 Comm: nft Tainted: G W
5.9.0-next-20201013 #1
[ 1914.328670] Hardware name: HiKey Development Board (DT)
[ 1914.339812] Call trace:
[ 1914.348184] dump_backtrace+0x0/0x1f0
[ 1914.357841] show_stack+0x2c/0x80
[ 1914.367181] dump_stack+0xf8/0x160
[ 1914.376615] __warn+0xac/0x168
[ 1914.385732] report_bug+0xcc/0x180
[ 1914.395242] bug_handler+0x24/0x78
[ 1914.404783] call_break_hook+0x80/0xa0
[ 1914.414725] brk_handler+0x28/0x68
[ 1914.424358] do_debug_exception+0xbc/0x128
[ 1914.434744] el1_sync_handler+0x7c/0x128
[ 1914.445017] el1_sync+0x7c/0x100
[ 1914.454625] lockdep_nfnl_nft_mutex_not_held+0x28/0x38 [nf_tables]
[ 1914.467351] nft_chain_parse_hook+0x58/0x320 [nf_tables]
[ 1914.479276] nf_tables_addchain.isra.66+0xb8/0x510 [nf_tables]
[ 1914.491818] nf_tables_newchain+0x408/0x618 [nf_tables]
[ 1914.503774] nfnetlink_rcv_batch+0x4a0/0x610 [nfnetlink]
[ 1914.515899] nfnetlink_rcv+0x174/0x1a8 [nfnetlink]
[ 1914.527525] netlink_unicast+0x1dc/0x290
[ 1914.538318] netlink_sendmsg+0x2b8/0x3f8
[ 1914.549125] ____sys_sendmsg+0x288/0x2d0
[ 1914.559959] ___sys_sendmsg+0x90/0xd0
[ 1914.570557] __sys_sendmsg+0x78/0xd0
[ 1914.581111] __arm64_sys_sendmsg+0x2c/0x38
[ 1914.592241] el0_svc_common.constprop.3+0x7c/0x198
[ 1914.604152] do_el0_svc+0x34/0xa0
[ 1914.614497] el0_sync_handler+0x128/0x190
[ 1914.625540] el0_sync+0x140/0x180
[ 1914.635652] irq event stamp: 0
[ 1914.645091] hardirqs last enabled at (0): [<0000000000000000>] 0x0
[ 1914.657471] hardirqs last disabled at (0): [<ffff80001008975c>]
copy_process+0x68c/0x1910
[ 1914.671402] softirqs last enabled at (0): [<ffff80001008975c>]
copy_process+0x68c/0x1910
[ 1914.685201] softirqs last disabled at (0): [<0000000000000000>] 0x0
[ 1914.696977] ---[ end trace 180274a5ab806f4e ]---
[ 1917.244483] hisi_thermal f7030700.tsensor: sensor <2> THERMAL
ALARM: 66385 > 65000

Full test log link,
https://qa-reports.linaro.org/lkft/linux-next-master/build/next-20201013/testrun/3302070/suite/linux-log-parser/test/check-kernel-warning-1839079/log


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


2020-10-14 22:41:54

by Naresh Kamboju

[permalink] [raw]
Subject: Re: WARNING: at net/netfilter/nf_tables_api.c:622 lockdep_nfnl_nft_mutex_not_held+0x28/0x38 [nf_tables]

On Wed, 14 Oct 2020 at 12:20, Naresh Kamboju <[email protected]> wrote:
>
> While running kselftest netfilter on arm64 hikey device on Linux next
> 20201013 the following
> kernel warning noticed.

Same issue noticed on i386.

# selftests: netfilter: nft_trans_stress.sh
[ 1092.615814] ------------[ cut here ]------------
[ 1092.620454] WARNING: CPU: 0 PID: 4504 at
/usr/src/kernel/net/netfilter/nf_tables_api.c:622
lockdep_nfnl_nft_mutex_not_held+0x20/0x30 [nf_tables]
[ 1092.633405] Modules linked in: nf_tables act_mirred cls_u32
mpls_iptunnel mpls_router sch_etf xt_conntrack nf_conntrack
nf_defrag_ipv4 libcrc32c ip6_tables nf_defrag_ipv6 ip_tables netdevsim
vrf 8021q bridge stp llc sch_fq veth algif_hash x86_pkg_temp_thermal
fuse [last unloaded: test_blackhole_dev]
[ 1092.659896] CPU: 0 PID: 4504 Comm: nft Tainted: G W
5.9.0-next-20201013 #1
[ 1092.668078] Hardware name: Supermicro SYS-5019S-ML/X11SSH-F, BIOS
2.0b 07/27/2017
[ 1092.675558] EIP: lockdep_nfnl_nft_mutex_not_held+0x20/0x30 [nf_tables]
[ 1092.682091] Code: 26 00 31 c0 5d c3 8d 74 26 00 3e 8d 74 26 00 55
b8 0a 00 00 00 89 e5 e8 3e 1a 90 e2 84 c0 75 0a 5d c3 90 8d b4 26 00
00 00 00 <0f> 0b 5d c3 8d b6 00 00 00 00 8d bf 00 00 00 00 3e 8d 74 26
00 55
[ 1092.700837] EAX: 00000001 EBX: c3d76300 ECX: 00000001 EDX: ffffffff
[ 1092.707105] ESI: e4ec7a7c EDI: e4ec7c84 EBP: e4ec7a00 ESP: e4ec7a00
[ 1092.713377] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 EFLAGS: 00010202
[ 1092.720173] CR0: 80050033 CR2: b7b85002 CR3: 03616000 CR4: 003506d0
[ 1092.726441] Call Trace:
[ 1092.728901] nft_chain_parse_hook+0x3f/0x2b0 [nf_tables]
[ 1092.734221] ? prep_new_page+0x12a/0x130
[ 1092.738146] ? get_page_from_freelist+0xdc5/0xf50
[ 1092.742850] ? lock_acquire+0x191/0x330
[ 1092.746692] nf_tables_addchain.constprop.68+0xb3/0x630 [nf_tables]
[ 1092.752957] ? nft_chain_lookup.part.38+0x19d/0x350 [nf_tables]
[ 1092.758883] nf_tables_newchain+0x408/0x660 [nf_tables]
[ 1092.764122] ? nf_tables_addchain.constprop.68+0x630/0x630 [nf_tables]
[ 1092.770654] nfnetlink_rcv_batch+0x4fc/0x740
[ 1092.774930] ? security_capable+0x33/0x50
[ 1092.778950] ? __nla_parse+0x1e/0x30
[ 1092.782536] nfnetlink_rcv+0x10d/0x130
[ 1092.786288] netlink_unicast+0x195/0x250
[ 1092.790215] netlink_sendmsg+0x27d/0x430
[ 1092.794141] ? netlink_unicast+0x250/0x250
[ 1092.798238] sock_sendmsg+0x5c/0x60
[ 1092.801733] ____sys_sendmsg+0x199/0x1e0
[ 1092.805659] ? __vma_adjust+0x28e/0x8e0
[ 1092.809497] ___sys_sendmsg+0x5e/0xa0
[ 1092.813164] ? lock_acquire+0x191/0x330
[ 1092.817004] ? __local_bh_enable_ip+0x78/0xd0
[ 1092.821370] ? __local_bh_enable_ip+0x78/0xd0
[ 1092.825730] ? _raw_spin_unlock_bh+0x2a/0x30
[ 1092.830002] ? trace_hardirqs_on+0x48/0xd0
[ 1092.834102] ? __local_bh_enable_ip+0x78/0xd0
[ 1092.838458] ? release_sock+0x71/0xa0
[ 1092.842126] ? _raw_spin_unlock_bh+0x2a/0x30
[ 1092.846400] ? release_sock+0x71/0xa0
[ 1092.850071] ? lock_acquire+0x191/0x330
[ 1092.853914] ? sock_setsockopt+0x54f/0xf80
[ 1092.858013] ? ktime_get_coarse_real_ts64+0xde/0xf0
[ 1092.862889] ? ktime_get_coarse_real_ts64+0xde/0xf0
[ 1092.867769] __sys_sendmsg+0x3e/0x80
[ 1092.871352] __ia32_sys_socketcall+0x20a/0x340
[ 1092.875806] __do_fast_syscall_32+0x54/0x90
[ 1092.880000] do_fast_syscall_32+0x29/0x60
[ 1092.884012] do_SYSENTER_32+0x15/0x20
[ 1092.887677] entry_SYSENTER_32+0x9f/0xf2
[ 1092.891603] EIP: 0xb7f3b549
[ 1092.894401] Code: b8 01 10 06 03 74 b4 01 10 07 03 74 b0 01 10 08
03 74 d8 01 00 00 00 00 00 00 00 00 00 00 00 00 00 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
[ 1092.913147] EAX: ffffffda EBX: 00000010 ECX: bff259a4 EDX: 00000000
[ 1092.919412] ESI: 00000000 EDI: 00000006 EBP: bff26ad8 ESP: bff25990
[ 1092.925677] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b EFLAGS: 00000282
[ 1092.932466] CPU: 0 PID: 4504 Comm: nft Tainted: G W
5.9.0-next-20201013 #1
[ 1092.940643] Hardware name: Supermicro SYS-5019S-ML/X11SSH-F, BIOS
2.0b 07/27/2017
[ 1092.948112] Call Trace:
[ 1092.950558] dump_stack+0x6d/0x8b
[ 1092.953877] ? lockdep_nfnl_nft_mutex_not_held+0x20/0x30 [nf_tables]
[ 1092.960228] __warn+0x7a/0xe0
[ 1092.963195] ? lockdep_nfnl_nft_mutex_not_held+0x20/0x30 [nf_tables]
[ 1092.969546] report_bug+0xa9/0x150
[ 1092.972953] ? exc_overflow+0x40/0x40
[ 1092.976617] handle_bug+0x2d/0x60
[ 1092.979927] exc_invalid_op+0x1b/0x70
[ 1092.983584] handle_exception+0x140/0x140
[ 1092.987589] EIP: lockdep_nfnl_nft_mutex_not_held+0x20/0x30 [nf_tables]
[ 1092.994106] Code: 26 00 31 c0 5d c3 8d 74 26 00 3e 8d 74 26 00 55
b8 0a 00 00 00 89 e5 e8 3e 1a 90 e2 84 c0 75 0a 5d c3 90 8d b4 26 00
00 00 00 <0f> 0b 5d c3 8d b6 00 00 00 00 8d bf 00 00 00 00 3e 8d 74 26
00 55
[ 1093.012850] EAX: 00000001 EBX: c3d76300 ECX: 00000001 EDX: ffffffff
[ 1093.019108] ESI: e4ec7a7c EDI: e4ec7c84 EBP: e4ec7a00 ESP: e4ec7a00
[ 1093.025364] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 EFLAGS: 00010202
[ 1093.032144] ? exc_overflow+0x40/0x40
[ 1093.035811] ? lockdep_nfnl_nft_mutex_not_held+0x20/0x30 [nf_tables]
[ 1093.042161] nft_chain_parse_hook+0x3f/0x2b0 [nf_tables]
[ 1093.047465] ? prep_new_page+0x12a/0x130
[ 1093.051390] ? get_page_from_freelist+0xdc5/0xf50
[ 1093.056087] ? lock_acquire+0x191/0x330
[ 1093.059922] nf_tables_addchain.constprop.68+0xb3/0x630 [nf_tables]
[ 1093.066187] ? nft_chain_lookup.part.38+0x19d/0x350 [nf_tables]
[ 1093.072112] nf_tables_newchain+0x408/0x660 [nf_tables]
[ 1093.077349] ? nf_tables_addchain.constprop.68+0x630/0x630 [nf_tables]
[ 1093.083872] nfnetlink_rcv_batch+0x4fc/0x740
[ 1093.088140] ? security_capable+0x33/0x50
[ 1093.092152] ? __nla_parse+0x1e/0x30
[ 1093.095729] nfnetlink_rcv+0x10d/0x130
[ 1093.099483] netlink_unicast+0x195/0x250
[ 1093.103406] netlink_sendmsg+0x27d/0x430
[ 1093.107324] ? netlink_unicast+0x250/0x250
[ 1093.111414] sock_sendmsg+0x5c/0x60
[ 1093.114897] ____sys_sendmsg+0x199/0x1e0
[ 1093.118818] ? __vma_adjust+0x28e/0x8e0
[ 1093.122654] ___sys_sendmsg+0x5e/0xa0
[ 1093.126312] ? lock_acquire+0x191/0x330
[ 1093.130142] ? __local_bh_enable_ip+0x78/0xd0
[ 1093.134493] ? __local_bh_enable_ip+0x78/0xd0
[ 1093.138843] ? _raw_spin_unlock_bh+0x2a/0x30
[ 1093.143106] ? trace_hardirqs_on+0x48/0xd0
[ 1093.147199] ? __local_bh_enable_ip+0x78/0xd0
[ 1093.151550] ? release_sock+0x71/0xa0
[ 1093.155216] ? _raw_spin_unlock_bh+0x2a/0x30
[ 1093.159486] ? release_sock+0x71/0xa0
[ 1093.163143] ? lock_acquire+0x191/0x330
[ 1093.166977] ? sock_setsockopt+0x54f/0xf80
[ 1093.171074] ? ktime_get_coarse_real_ts64+0xde/0xf0
[ 1093.175945] ? ktime_get_coarse_real_ts64+0xde/0xf0
[ 1093.180816] __sys_sendmsg+0x3e/0x80
[ 1093.184396] __ia32_sys_socketcall+0x20a/0x340
[ 1093.188842] __do_fast_syscall_32+0x54/0x90
[ 1093.193026] do_fast_syscall_32+0x29/0x60
[ 1093.197029] do_SYSENTER_32+0x15/0x20
[ 1093.200686] entry_SYSENTER_32+0x9f/0xf2
[ 1093.204604] EIP: 0xb7f3b549
[ 1093.207396] Code: b8 01 10 06 03 74 b4 01 10 07 03 74 b0 01 10 08
03 74 d8 01 00 00 00 00 00 00 00 00 00 00 00 00 00 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
[ 1093.226140] EAX: ffffffda EBX: 00000010 ECX: bff259a4 EDX: 00000000
[ 1093.232397] ESI: 00000000 EDI: 00000006 EBP: bff26ad8 ESP: bff25990
[ 1093.238653] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b EFLAGS: 00000282
[ 1093.245453] irq event stamp: 0
[ 1093.248510] hardirqs last enabled at (0): [<00000000>] 0x0
[ 1093.254086] hardirqs last disabled at (0): [<d9af07cb>]
copy_process+0x41b/0x1870
[ 1093.261563] softirqs last enabled at (0): [<d9af07cb>]
copy_process+0x41b/0x1870
[ 1093.269042] softirqs last disabled at (0): [<00000000>] 0x0
[ 1093.274615] ---[ end trace 57d0b79ceae71310 ]---


> Full test log link,
> https://qa-reports.linaro.org/lkft/linux-next-master/build/next-20201013/testrun/3302070/suite/linux-log-parser/test/check-kernel-warning-1839079/log
>
>
> --
> Linaro LKFT
> https://lkft.linaro.org