Re: [syzbot] [netfilter?] WARNING in __nf_unregister_net_hook (6)
From: syzbot
Date: Sun Nov 19 2023 - 01:20:01 EST
Hello,
syzbot tried to test the proposed patch but the build/boot failed:
36819][ T1] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
[ 4.642425][ T1] NET: Registered PF_INET protocol family
[ 4.653180][ T1] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, vmalloc)
[ 4.673990][ T1] tcp_listen_portaddr_hash hash table entries: 4096 (order: 6, 294912 bytes, vmalloc)
[ 4.679141][ T1] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, vmalloc)
[ 4.686154][ T1] TCP established hash table entries: 65536 (order: 7, 524288 bytes, vmalloc)
[ 4.702134][ T1] TCP bind hash table entries: 65536 (order: 11, 9437184 bytes, vmalloc hugepage)
[ 4.715835][ T1] TCP: Hash tables configured (established 65536 bind 65536)
[ 4.725918][ T1] MPTCP token hash table entries: 8192 (order: 7, 720896 bytes, vmalloc)
[ 4.735121][ T1] UDP hash table entries: 4096 (order: 7, 655360 bytes, vmalloc)
[ 4.742928][ T1] UDP-Lite hash table entries: 4096 (order: 7, 655360 bytes, vmalloc)
[ 4.748791][ T1] NET: Registered PF_UNIX/PF_LOCAL protocol family
[ 4.755767][ T1] RPC: Registered named UNIX socket transport module.
[ 4.757922][ T1] RPC: Registered udp transport module.
[ 4.759137][ T1] RPC: Registered tcp transport module.
[ 4.760533][ T1] RPC: Registered tcp-with-tls transport module.
[ 4.762569][ T1] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 4.770304][ T1] NET: Registered PF_XDP protocol family
[ 4.771660][ T1] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
[ 4.772804][ T1] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
[ 4.774225][ T1] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
[ 4.775706][ T1] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfefff window]
[ 4.779891][ T1] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[ 4.781720][ T1] PCI: CLS 0 bytes, default 64
[ 4.783062][ T1] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[ 4.785627][ T1] software IO TLB: mapped [mem 0x00000000b5800000-0x00000000b9800000] (64MB)
[ 4.787580][ T1] ACPI: bus type thunderbolt registered
[ 4.801824][ T59] kworker/u4:3 (59) used greatest stack depth: 28288 bytes left
[ 4.803556][ T57] kworker/u4:3 (57) used greatest stack depth: 27936 bytes left
[ 4.807247][ T1] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer
[ 4.836525][ T1] kvm_amd: CPU 0 isn't AMD or Hygon
[ 4.838378][ T1] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x1fb6feccdd0, max_idle_ns: 440795259471 ns
[ 4.840308][ T1] clocksource: Switched to clocksource tsc
[ 4.841701][ T60] kworker/u4:4 (60) used greatest stack depth: 27488 bytes left
[ 7.942031][ T1] Initialise system trusted keyrings
[ 7.950098][ T1] workingset: timestamp_bits=40 max_order=21 bucket_order=0
[ 7.953009][ T1] zbud: loaded
[ 7.964477][ T1] DLM installed
[ 7.971427][ T1] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[ 7.981282][ T1] NFS: Registering the id_resolver key type
[ 7.982457][ T1] Key type id_resolver registered
[ 7.983292][ T1] Key type id_legacy registered
[ 7.984197][ T1] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 7.985996][ T1] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
[ 7.999168][ T1] Key type cifs.spnego registered
[ 8.001028][ T1] Key type cifs.idmap registered
[ 8.002981][ T1] ntfs: driver 2.1.32 [Flags: R/W].
[ 8.004816][ T1] ntfs3: Max link count 4000
[ 8.005624][ T1] ntfs3: Enabled Linux POSIX ACLs support
[ 8.006545][ T1] ntfs3: Read-only LZX/Xpress compression included
[ 8.008379][ T1] efs: 1.0a - http://aeschi.ch.eu.org/efs/
[ 8.009817][ T1] jffs2: version 2.2. (NAND) (SUMMARY) © 2001-2006 Red Hat, Inc.
[ 8.014805][ T1] romfs: ROMFS MTD (C) 2007 Red Hat, Inc.
[ 8.016201][ T1] QNX4 filesystem 0.2.3 registered.
[ 8.017663][ T1] qnx6: QNX6 filesystem 1.0.0 registered.
[ 8.019893][ T1] fuse: init (API version 7.39)
[ 8.024969][ T1] orangefs_debugfs_init: called with debug mask: :none: :0:
[ 8.028357][ T1] orangefs_init: module version upstream loaded
[ 8.030312][ T1] JFS: nTxBlock = 8192, nTxLock = 65536
[ 8.063381][ T1] SGI XFS with ACLs, security attributes, realtime, quota, no debug enabled
[ 8.072453][ T1] 9p: Installing v9fs 9p2000 file system support
[ 8.074784][ T1] NILFS version 2 loaded
[ 8.075542][ T1] befs: version: 0.9.3
[ 8.077453][ T1] ocfs2: Registered cluster interface o2cb
[ 8.079215][ T1] ocfs2: Registered cluster interface user
[ 8.081170][ T1] OCFS2 User DLM kernel interface loaded
[ 8.103497][ T1] gfs2: GFS2 installed
[ 8.118728][ T1] ceph: loaded (mds proto 32)
[ 8.122243][ T1]
[ 8.122768][ T1] ============================================
[ 8.123835][ T1] WARNING: possible recursive locking detected
[ 8.124729][ T1] 6.6.0-rc3-syzkaller-dirty #0 Not tainted
[ 8.125560][ T1] --------------------------------------------
[ 8.126518][ T1] swapper/0/1 is trying to acquire lock:
[ 8.126735][ T1] ffffffff8e69c268 (nf_hook_mutex){+.+.}-{3:3}, at: nf_hook_entries_grow+0x580/0x8b0
[ 8.126735][ T1]
[ 8.126735][ T1] but task is already holding lock:
[ 8.126735][ T1] ffffffff8e69c268 (nf_hook_mutex){+.+.}-{3:3}, at: __nf_register_net_hook+0xef/0x830
[ 8.126735][ T1]
[ 8.126735][ T1] other info that might help us debug this:
[ 8.126735][ T1] Possible unsafe locking scenario:
[ 8.126735][ T1]
[ 8.126735][ T1] CPU0
[ 8.126735][ T1] ----
[ 8.126735][ T1] lock(nf_hook_mutex);
[ 8.126735][ T1] lock(nf_hook_mutex);
[ 8.126735][ T1]
[ 8.126735][ T1] *** DEADLOCK ***
[ 8.126735][ T1]
[ 8.126735][ T1] May be due to missing lock nesting notation
[ 8.126735][ T1]
[ 8.126735][ T1] 2 locks held by swapper/0/1:
[ 8.126735][ T1] #0: ffffffff8e5e4190 (pernet_ops_rwsem){+.+.}-{3:3}, at: register_pernet_subsys+0x19/0x40
[ 8.126735][ T1] #1: ffffffff8e69c268 (nf_hook_mutex){+.+.}-{3:3}, at: __nf_register_net_hook+0xef/0x830
[ 8.126735][ T1]
[ 8.126735][ T1] stack backtrace:
[ 8.126735][ T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 6.6.0-rc3-syzkaller-dirty #0
[ 8.126735][ T1] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 11/10/2023
[ 8.126735][ T1] Call Trace:
[ 8.126735][ T1] <TASK>
[ 8.126735][ T1] dump_stack_lvl+0xd9/0x1b0
[ 8.126735][ T1] __lock_acquire+0x2971/0x5de0
[ 8.126735][ T1] ? lockdep_hardirqs_on_prepare+0x410/0x410
[ 8.126735][ T1] lock_acquire+0x1ae/0x510
[ 8.126735][ T1] ? nf_hook_entries_grow+0x580/0x8b0
[ 8.126735][ T1] ? lock_sync+0x190/0x190
[ 8.126735][ T1] ? lock_acquire+0x1ae/0x510
[ 8.126735][ T1] ? preempt_count_sub+0x150/0x150
[ 8.126735][ T1] __mutex_lock+0x181/0x1340
[ 8.126735][ T1] ? nf_hook_entries_grow+0x580/0x8b0
[ 8.126735][ T1] ? nf_hook_entries_grow+0x580/0x8b0
[ 8.126735][ T1] ? preempt_count_sub+0x150/0x150
[ 8.126735][ T1] ? mutex_lock_io_nested+0x11a0/0x11a0
[ 8.126735][ T1] ? trace_contention_end+0xd6/0x100
[ 8.126735][ T1] ? __mutex_lock+0x25b/0x1340
[ 8.126735][ T1] ? __lock_acquire+0x182f/0x5de0
[ 8.126735][ T1] ? mutex_lock_io_nested+0x11a0/0x11a0
[ 8.126735][ T1] ? nf_hook_entries_grow+0x580/0x8b0
[ 8.126735][ T1] nf_hook_entries_grow+0x580/0x8b0
[ 8.126735][ T1] ? lockdep_hardirqs_on_prepare+0x410/0x410
[ 8.166836][ T1] __nf_register_net_hook+0x142/0x830
[ 8.166836][ T1] nf_register_net_hook+0x101/0x150
[ 8.166836][ T1] nf_register_net_hooks+0x5d/0xc0
[ 8.166836][ T1] ? selinux_nf_unregister+0x30/0x30
[ 8.166836][ T1] ops_init+0xb9/0x650
[ 8.166836][ T1] register_pernet_operations+0x34b/0x820
[ 8.166836][ T1] ? cleanup_net+0xb20/0xb20
[ 8.166836][ T1] ? rng_is_initialized+0x40/0x40
[ 8.166836][ T1] ? selinux_init+0x320/0x320
[ 8.166836][ T1] register_pernet_subsys+0x28/0x40
[ 8.166836][ T1] selinux_nf_ip_init+0x35/0x80
[ 8.166836][ T1] do_one_initcall+0x117/0x630
[ 8.166836][ T1] ? trace_event_raw_event_initcall_level+0x200/0x200
[ 8.166836][ T1] kernel_init_freeable+0x5c2/0x900
[ 8.166836][ T1] ? rest_init+0x2b0/0x2b0
[ 8.166836][ T1] kernel_init+0x1c/0x2a0
[ 8.166836][ T1] ? rest_init+0x2b0/0x2b0
[ 8.166836][ T1] ret_from_fork+0x45/0x80
[ 8.166836][ T1] ? rest_init+0x2b0/0x2b0
[ 8.166836][ T1] ret_from_fork_asm+0x11/0x20
[ 8.166836][ T1] </TASK>
[ 286.966884][ T28] INFO: task swapper/0:1 blocked for more than 143 seconds.
[ 286.969104][ T28] Not tainted 6.6.0-rc3-syzkaller-dirty #0
[ 286.971304][ T28] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 286.973620][ T28] task:swapper/0 state:D stack:23024 pid:1 ppid:0 flags:0x00004000
[ 286.976023][ T28] Call Trace:
[ 286.976678][ T28] <TASK>
[ 286.977696][ T28] __schedule+0xee1/0x5a10
[ 286.978895][ T28] ? rcu_is_watching+0x12/0xb0
[ 286.980008][ T28] ? trace_irq_enable.constprop.0+0xd0/0x100
[ 286.981277][ T28] ? irqentry_enter+0x2c/0x50
[ 286.982136][ T28] ? rcu_is_watching+0x12/0xb0
[ 286.982834][ T28] ? io_schedule_timeout+0x150/0x150
[ 286.983837][ T28] ? rcu_is_watching+0x12/0xb0
[ 286.984537][ T28] ? __mutex_lock+0x964/0x1340
[ 286.985252][ T28] ? do_raw_spin_lock+0x12e/0x2b0
[ 286.985953][ T28] ? spin_bug+0x1d0/0x1d0
[ 286.986683][ T28] schedule+0xe7/0x1b0
[ 286.987309][ T28] schedule_preempt_disabled+0x13/0x20
[ 286.992893][ T28] __mutex_lock+0x969/0x1340
[ 286.997691][ T28] ? nf_hook_entries_grow+0x580/0x8b0
[ 287.003162][ T28] ? preempt_count_sub+0x150/0x150
[ 287.008617][ T28] ? mutex_lock_io_nested+0x11a0/0x11a0
[ 287.014340][ T28] ? trace_contention_end+0xd6/0x100
[ 287.019881][ T28] ? __mutex_lock+0x25b/0x1340
[ 287.024740][ T28] ? __lock_acquire+0x182f/0x5de0
[ 287.029819][ T28] ? mutex_lock_io_nested+0x11a0/0x11a0
[ 287.035385][ T28] ? nf_hook_entries_grow+0x580/0x8b0
[ 287.041001][ T28] nf_hook_entries_grow+0x580/0x8b0
[ 287.046464][ T28] ? lockdep_hardirqs_on_prepare+0x410/0x410
[ 287.052618][ T28] __nf_register_net_hook+0x142/0x830
[ 287.058143][ T28] nf_register_net_hook+0x101/0x150
[ 287.063352][ T28] nf_register_net_hooks+0x5d/0xc0
[ 287.068504][ T28] ? selinux_nf_unregister+0x30/0x30
[ 287.073863][ T28] ops_init+0xb9/0x650
[ 287.078000][ T28] register_pernet_operations+0x34b/0x820
[ 287.083725][ T28] ? cleanup_net+0xb20/0xb20
[ 287.088364][ T28] ? rng_is_initialized+0x40/0x40
[ 287.093503][ T28] ? selinux_init+0x320/0x320
[ 287.098308][ T28] register_pernet_subsys+0x28/0x40
[ 287.103675][ T28] selinux_nf_ip_init+0x35/0x80
[ 287.108677][ T28] do_one_initcall+0x117/0x630
[ 287.113475][ T28] ? trace_event_raw_event_initcall_level+0x200/0x200
[ 287.120835][ T28] kernel_init_freeable+0x5c2/0x900
[ 287.126412][ T28] ? rest_init+0x2b0/0x2b0
[ 287.130885][ T28] kernel_init+0x1c/0x2a0
[ 287.135437][ T28] ? rest_init+0x2b0/0x2b0
[ 287.139959][ T28] ret_from_fork+0x45/0x80
[ 287.144525][ T28] ? rest_init+0x2b0/0x2b0
[ 287.149056][ T28] ret_from_fork_asm+0x11/0x20
[ 287.153819][ T28] </TASK>
[ 287.157157][ T28] INFO: lockdep is turned off.
[ 287.161893][ T28] Kernel panic - not syncing: hung_task: blocked tasks
[ 287.167099][ T28] CPU: 0 PID: 28 Comm: khungtaskd Not tainted 6.6.0-rc3-syzkaller-dirty #0
[ 287.167099][ T28] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 11/10/2023
[ 287.167099][ T28] Call Trace:
[ 287.167099][ T28] <TASK>
[ 287.167099][ T28] dump_stack_lvl+0xd9/0x1b0
[ 287.167099][ T28] panic+0x6a6/0x750
[ 287.167099][ T28] ? panic_smp_self_stop+0xa0/0xa0
[ 287.167099][ T28] ? preempt_count_sub+0x150/0x150
[ 287.167099][ T28] ? watchdog+0xd3e/0x1210
[ 287.167099][ T28] watchdog+0xd4f/0x1210
[ 287.167099][ T28] ? proc_dohung_task_timeout_secs+0x90/0x90
[ 287.167099][ T28] ? lockdep_hardirqs_on+0x7d/0x100
[ 287.167099][ T28] ? __kthread_parkme+0x14b/0x220
[ 287.167099][ T28] ? proc_dohung_task_timeout_secs+0x90/0x90
[ 287.167099][ T28] kthread+0x33c/0x440
[ 287.167099][ T28] ? _raw_spin_unlock_irq+0x23/0x50
[ 287.167099][ T28] ? kthread_complete_and_exit+0x40/0x40
[ 287.167099][ T28] ret_from_fork+0x45/0x80
[ 287.167099][ T28] ? kthread_complete_and_exit+0x40/0x40
[ 287.167099][ T28] ret_from_fork_asm+0x11/0x20
[ 287.167099][ T28] </TASK>
[ 287.167099][ T28] Kernel Offset: disabled
[ 287.167099][ T28] Rebooting in 86400 seconds..
syzkaller build log:
go env (err=<nil>)
GO111MODULE="auto"
GOARCH="amd64"
GOBIN=""
GOCACHE="/syzkaller/.cache/go-build"
GOENV="/syzkaller/.config/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/syzkaller/jobs-2/linux/gopath/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/syzkaller/jobs-2/linux/gopath"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct";
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="go1.20.1"
GCCGO="gccgo"
GOAMD64="v1"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/syzkaller/jobs-2/linux/gopath/src/github.com/google/syzkaller/go.mod"
GOWORK=""
CGO_CFLAGS="-O2 -g"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-O2 -g"
CGO_FFLAGS="-O2 -g"
CGO_LDFLAGS="-O2 -g"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -Wl,--no-gc-sections -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build1107752955=/tmp/go-build -gno-record-gcc-switches"
git status (err=<nil>)
HEAD detached at 0b6a67ac4
nothing to commit, working tree clean
tput: No value for $TERM and no -T specified
tput: No value for $TERM and no -T specified
Makefile:32: run command via tools/syz-env for best compatibility, see:
Makefile:33: https://github.com/google/syzkaller/blob/master/docs/contributing.md#using-syz-env
go list -f '{{.Stale}}' ./sys/syz-sysgen | grep -q false || go install ./sys/syz-sysgen
make .descriptions
tput: No value for $TERM and no -T specified
tput: No value for $TERM and no -T specified
bin/syz-sysgen
touch .descriptions
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=0b6a67ac4b0dc26f43030c5edd01c9175f13b784 -X 'github.com/google/syzkaller/prog.gitRevisionDate=20230913-073137'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-fuzzer github.com/google/syzkaller/syz-fuzzer
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=0b6a67ac4b0dc26f43030c5edd01c9175f13b784 -X 'github.com/google/syzkaller/prog.gitRevisionDate=20230913-073137'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-execprog github.com/google/syzkaller/tools/syz-execprog
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=0b6a67ac4b0dc26f43030c5edd01c9175f13b784 -X 'github.com/google/syzkaller/prog.gitRevisionDate=20230913-073137'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-stress github.com/google/syzkaller/tools/syz-stress
mkdir -p ./bin/linux_amd64
gcc -o ./bin/linux_amd64/syz-executor executor/executor.cc \
-m64 -O2 -pthread -Wall -Werror -Wparentheses -Wunused-const-variable -Wframe-larger-than=16384 -Wno-stringop-overflow -Wno-array-bounds -Wno-format-overflow -Wno-unused-but-set-variable -Wno-unused-command-line-argument -static-pie -fpermissive -w -DGOOS_linux=1 -DGOARCH_amd64=1 \
-DHOSTGOOS_linux=1 -DGIT_REVISION=\"0b6a67ac4b0dc26f43030c5edd01c9175f13b784\"
Error text is too large and was truncated, full error text is at:
https://syzkaller.appspot.com/x/error.txt?x=15d5cd10e80000
Tested on:
commit: 6465e260 Linux 6.6-rc3
git tree: https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
kernel config: https://syzkaller.appspot.com/x/.config?x=8d7d7928f78936aa
dashboard link: https://syzkaller.appspot.com/bug?extid=de4025c006ec68ac56fc
compiler: gcc (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils for Debian) 2.40
patch: https://syzkaller.appspot.com/x/patch.diff?x=10b3d658e80000