linux-kernel - Re: [syzbot] [afs?] WARNING: lock held when returning to user space in afs_proc_addr_prefs

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <677be837.050a0220.3b3668.000d.GAE@google.com>
Date: Mon, 06 Jan 2025 06:27:03 -0800
From: syzbot <syzbot+76f33569875eb708e575@...kaller.appspotmail.com>
To: dhowells@...hat.com, linux-afs@...ts.infradead.org, 
	linux-kernel@...r.kernel.org, marc.dionne@...istor.com, 
	syzkaller-bugs@...glegroups.com
Subject: Re: [syzbot] [afs?] WARNING: lock held when returning to user space
 in afs_proc_addr_prefs_write

Hello,

syzbot tried to test the proposed patch but the build/boot failed:

 page owner found early allocated 19843 pages
[    2.071960][    T0] Kernel/User page tables isolation: enabled
[    2.075149][    T0] Dynamic Preempt: full
[    2.077132][    T0] Running RCU self tests
[    2.078106][    T0] Running RCU synchronous self tests
[    2.079907][    T0] rcu: Preemptible hierarchical RCU implementation.
[    2.081445][    T0] rcu: 	RCU lockdep checking is enabled.
[    2.083588][    T0] rcu: 	RCU restricting CPUs from NR_CPUS=8 to nr_cpu_ids=2.
[    2.085399][    T0] rcu: 	RCU callback double-/use-after-free debug is enabled.
[    2.087450][    T0] rcu: 	RCU debug extended QS entry/exit.
[    2.088523][    T0] 	All grace periods are expedited (rcu_expedited).
[    2.090346][    T0] 	Trampoline variant of Tasks RCU enabled.
[    2.091376][    T0] 	Tracing variant of Tasks RCU enabled.
[    2.092797][    T0] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    2.094823][    T0] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2
[    2.096481][    T0] Running RCU synchronous self tests
[    2.097771][    T0] RCU Tasks: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2.
[    2.099560][    T0] RCU Tasks Trace: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2.
[    2.247806][    T0] NR_IRQS: 4352, nr_irqs: 440, preallocated irqs: 16
[    2.250263][    T0] rcu: srcu_init: Setting srcu_struct sizes based on contention.
[    2.252270][    T0] kfence: initialized - using 2097152 bytes for 255 objects at 0xffff88823be00000-0xffff88823c000000
[    2.255249][    T0] Console: colour VGA+ 80x25
[    2.256184][    T0] printk: legacy console [ttyS0] enabled
[    2.256184][    T0] printk: legacy console [ttyS0] enabled
[    2.258337][    T0] printk: legacy bootconsole [earlyser0] disabled
[    2.258337][    T0] printk: legacy bootconsole [earlyser0] disabled
[    2.260621][    T0] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
[    2.262203][    T0] ... MAX_LOCKDEP_SUBCLASSES:  8
[    2.262945][    T0] ... MAX_LOCK_DEPTH:          48
[    2.263988][    T0] ... MAX_LOCKDEP_KEYS:        8192
[    2.265553][    T0] ... CLASSHASH_SIZE:          4096
[    2.267023][    T0] ... MAX_LOCKDEP_ENTRIES:     1048576
[    2.267977][    T0] ... MAX_LOCKDEP_CHAINS:      1048576
[    2.268789][    T0] ... CHAINHASH_SIZE:          524288
[    2.269562][    T0]  memory used by lock dependency info: 106625 kB
[    2.270554][    T0]  memory used for stack traces: 8320 kB
[    2.271461][    T0]  per task-struct memory footprint: 1920 bytes
[    2.273329][    T0] mempolicy: Enabling automatic NUMA balancing. Configure with numa_balancing= or the kernel.numa_balancing sysctl
[    2.275805][    T0] ACPI: Core revision 20240827
[    2.277665][    T0] APIC: Switch to symmetric I/O mode setup
[    2.279420][    T0] x2apic enabled
[    2.284009][    T0] APIC: Switched APIC routing to: physical x2apic
[    2.291502][    T0] ..TIMER: vector=0x30 apic1=0 pin1=0 apic2=-1 pin2=-1
[    2.294252][    T0] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x1fb6f965d9b, max_idle_ns: 440795282877 ns
[    2.298627][    T0] Calibrating delay loop (skipped) preset value.. 4400.42 BogoMIPS (lpj=22002100)
[    2.301057][    T0] Last level iTLB entries: 4KB 64, 2MB 8, 4MB 8
[    2.302645][    T0] Last level dTLB entries: 4KB 64, 2MB 0, 4MB 0, 1GB 4
[    2.304079][    T0] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
[    2.305738][    T0] Spectre V2 : Spectre BHI mitigation: SW BHB clearing on syscall and VM exit
[    2.307226][    T0] Spectre V2 : Mitigation: IBRS
[    2.308628][    T0] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
[    2.310524][    T0] Spectre V2 : Spectre v2 / SpectreRSB : Filling RSB on VMEXIT
[    2.311803][    T0] RETBleed: Mitigation: IBRS
[    2.312526][    T0] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
[    2.313856][    T0] Spectre V2 : User space: Mitigation: STIBP via prctl
[    2.315073][    T0] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
[    2.316603][    T0] MDS: Mitigation: Clear CPU buffers
[    2.317473][    T0] TAA: Mitigation: Clear CPU buffers
[    2.318622][    T0] MMIO Stale Data: Vulnerable: Clear CPU buffers attempted, no microcode
[    2.320919][    T0] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
[    2.322382][    T0] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
[    2.323635][    T0] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
[    2.324822][    T0] x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256
[    2.325946][    T0] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format.
[    2.592952][    T0] Freeing SMP alternatives memory: 124K
[    2.594208][    T0] pid_max: default: 32768 minimum: 301
[    2.595787][    T0] LSM: initializing lsm=lockdown,capability,landlock,yama,safesetid,tomoyo,apparmor,bpf,ima,evm
[    2.598213][    T0] landlock: Up and running.
[    2.598628][    T0] Yama: becoming mindful.
[    2.599717][    T0] TOMOYO Linux initialized
[    2.601324][    T0] AppArmor: AppArmor initialized
[    2.604240][    T0] LSM support for eBPF active
[    2.611042][    T0] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc hugepage)
[    2.615317][    T0] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc hugepage)
[    2.617873][    T0] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc)
[    2.618918][    T0] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc)
[    2.624503][    T0] Running RCU synchronous self tests
[    2.625906][    T0] Running RCU synchronous self tests
[    2.750053][    T1] smpboot: CPU0: Intel(R) Xeon(R) CPU @ 2.20GHz (family: 0x6, model: 0x4f, stepping: 0x0)
[    2.756899][    T1] Running RCU Tasks wait API self tests
[    2.859036][    T1] Running RCU Tasks Trace wait API self tests
[    2.860455][    T1] Performance Events: unsupported p6 CPU model 79 no PMU driver, software events only.
[    2.862568][    T1] signal: max sigframe size: 1776
[    2.864222][    T1] rcu: Hierarchical SRCU implementation.
[    2.865500][    T1] rcu: 	Max phase no-delay instances is 1000.
[    2.867279][    T1] Timer migration: 1 hierarchy levels; 8 children per group; 0 crossnode level
[    2.873416][    T1] NMI watchdog: Perf NMI watchdog permanently disabled
[    2.875521][    T1] smp: Bringing up secondary CPUs ...
[    2.878815][    T1] smpboot: x86: Booting SMP configuration:
[    2.880304][    T1] .... node  #0, CPUs:      #1
[    2.880519][   T15] Callback from call_rcu_tasks_trace() invoked.
[    2.883042][   T22] ------------[ cut here ]------------
[    2.883042][   T22] workqueue: work disable count underflowed
[    2.883042][   T22] WARNING: CPU: 1 PID: 22 at kernel/workqueue.c:4317 enable_work+0x2fa/0x340
[    2.883042][   T22] Modules linked in:
[    2.883554][   T22] CPU: 1 UID: 0 PID: 22 Comm: cpuhp/1 Not tainted 6.13.0-rc6-syzkaller-g9d89551994a4-dirty #0
[    2.885161][   T22] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 09/13/2024
[    2.887278][   T22] RIP: 0010:enable_work+0x2fa/0x340
[    2.888264][   T22] Code: 89 ee e8 e9 59 36 00 45 84 ed 0f 85 28 fe ff ff e8 3b 5f 36 00 c6 05 c9 96 a2 0e 01 90 48 c7 c7 20 d3 4b 8b e8 a7 22 f7 ff 90 <0f> 0b 90 90 e9 05 fe ff ff 48 89 ef e8 85 c7 98 00 e9 a9 fe ff ff
[    2.888609][   T22] RSP: 0000:ffffc900001c7ca0 EFLAGS: 00010082
[    2.888609][   T22] RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffffffff815a1789
[    2.888609][   T22] RDX: ffff88801d2f3c00 RSI: ffffffff815a1796 RDI: 0000000000000001
[    2.888609][   T22] RBP: ffff8880b8738660 R08: 0000000000000001 R09: 0000000000000000
[    2.888609][   T22] R10: 0000000000000000 R11: 0000000000000001 R12: 1ffff92000038f95
[    2.888609][   T22] R13: 0000000000000000 R14: 00000000000000c4 R15: ffffffff81db22a0
[    2.888609][   T22] FS:  0000000000000000(0000) GS:ffff8880b8700000(0000) knlGS:0000000000000000
[    2.888609][   T22] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[    2.888609][   T22] CR2: 0000000000000000 CR3: 000000000db7e000 CR4: 00000000003506f0
[    2.888609][   T22] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[    2.888609][   T22] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[    2.888609][   T22] Call Trace:
[    2.888609][   T22]  <TASK>
[    2.888609][   T22]  ? __warn+0xea/0x3c0
[    2.888609][   T22]  ? enable_work+0x2fa/0x340
[    2.888609][   T22]  ? report_bug+0x3c0/0x580
[    2.888609][   T22]  ? handle_bug+0x54/0xa0
[    2.888609][   T22]  ? exc_invalid_op+0x17/0x50
[    2.888609][   T22]  ? asm_exc_invalid_op+0x1a/0x20
[    2.888609][   T22]  ? __pfx_vmstat_cpu_online+0x10/0x10
[    2.888609][   T22]  ? __warn_printk+0x199/0x350
[    2.888609][   T22]  ? __warn_printk+0x1a6/0x350
[    2.888609][   T22]  ? enable_work+0x2fa/0x340
[    2.888609][   T22]  ? __pfx_enable_work+0x10/0x10
[    2.888609][   T22]  vmstat_cpu_online+0x83/0xf0
[    2.888609][   T22]  cpuhp_invoke_callback+0x3d0/0xa10
[    2.888609][   T22]  ? __pfx_vmstat_cpu_online+0x10/0x10
[    2.888609][   T22]  ? lock_acquire.part.0+0x2e0/0x380
[    2.888609][   T22]  ? cpuhp_next_state+0x100/0x1c0
[    2.888609][   T22]  cpuhp_thread_fun+0x480/0x6f0
[    2.888609][   T22]  ? __pfx_cpuhp_thread_fun+0x10/0x10
[    2.888609][   T22]  ? __pfx_cpuhp_thread_fun+0x10/0x10
[    2.888609][   T22]  ? smpboot_thread_fn+0x59d/0xa30
[    2.888609][   T22]  smpboot_thread_fn+0x661/0xa30
[    2.888609][   T22]  ? __kthread_parkme+0x148/0x220
[    2.888609][   T22]  ? __pfx_smpboot_thread_fn+0x10/0x10
[    2.888609][   T22]  kthread+0x2c1/0x3a0
[    2.888609][   T22]  ? _raw_spin_unlock_irq+0x23/0x50
[    2.888609][   T22]  ? __pfx_kthread+0x10/0x10
[    2.888609][   T22]  ret_from_fork+0x45/0x80
[    2.888609][   T22]  ? __pfx_kthread+0x10/0x10
[    2.888609][   T22]  ret_from_fork_asm+0x1a/0x30
[    2.888609][   T22]  </TASK>
[    2.888609][   T22] Kernel panic - not syncing: kernel: panic_on_warn set ...
[    2.888609][   T22] CPU: 1 UID: 0 PID: 22 Comm: cpuhp/1 Not tainted 6.13.0-rc6-syzkaller-g9d89551994a4-dirty #0
[    2.888609][   T22] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 09/13/2024
[    2.888609][   T22] Call Trace:
[    2.888609][   T22]  <TASK>
[    2.888609][   T22]  dump_stack_lvl+0x3d/0x1f0
[    2.888609][   T22]  panic+0x71d/0x800
[    2.888609][   T22]  ? __pfx_panic+0x10/0x10
[    2.888609][   T22]  ? show_trace_log_lvl+0x29d/0x3d0
[    2.888609][   T22]  ? check_panic_on_warn+0x1f/0xb0
[    2.888609][   T22]  ? enable_work+0x2fa/0x340
[    2.888609][   T22]  check_panic_on_warn+0xab/0xb0
[    2.888609][   T22]  __warn+0xf6/0x3c0
[    2.888609][   T22]  ? enable_work+0x2fa/0x340
[    2.888609][   T22]  report_bug+0x3c0/0x580
[    2.888609][   T22]  handle_bug+0x54/0xa0
[    2.888609][   T22]  exc_invalid_op+0x17/0x50
[    2.888609][   T22]  asm_exc_invalid_op+0x1a/0x20
[    2.888609][   T22] RIP: 0010:enable_work+0x2fa/0x340
[    2.888609][   T22] Code: 89 ee e8 e9 59 36 00 45 84 ed 0f 85 28 fe ff ff e8 3b 5f 36 00 c6 05 c9 96 a2 0e 01 90 48 c7 c7 20 d3 4b 8b e8 a7 22 f7 ff 90 <0f> 0b 90 90 e9 05 fe ff ff 48 89 ef e8 85 c7 98 00 e9 a9 fe ff ff
[    2.888609][   T22] RSP: 0000:ffffc900001c7ca0 EFLAGS: 00010082
[    2.888609][   T22] RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffffffff815a1789
[    2.888609][   T22] RDX: ffff88801d2f3c00 RSI: ffffffff815a1796 RDI: 0000000000000001
[    2.888609][   T22] RBP: ffff8880b8738660 R08: 0000000000000001 R09: 0000000000000000
[    2.888609][   T22] R10: 0000000000000000 R11: 0000000000000001 R12: 1ffff92000038f95
[    2.888609][   T22] R13: 0000000000000000 R14: 00000000000000c4 R15: ffffffff81db22a0
[    2.888609][   T22]  ? __pfx_vmstat_cpu_online+0x10/0x10
[    2.888609][   T22]  ? __warn_printk+0x199/0x350
[    2.888609][   T22]  ? __warn_printk+0x1a6/0x350
[    2.888609][   T22]  ? __pfx_enable_work+0x10/0x10
[    2.888609][   T22]  vmstat_cpu_online+0x83/0xf0
[    2.888609][   T22]  cpuhp_invoke_callback+0x3d0/0xa10
[    2.888609][   T22]  ? __pfx_vmstat_cpu_online+0x10/0x10
[    2.888609][   T22]  ? lock_acquire.part.0+0x2e0/0x380
[    2.888609][   T22]  ? cpuhp_next_state+0x100/0x1c0
[    2.888609][   T22]  cpuhp_thread_fun+0x480/0x6f0
[    2.888609][   T22]  ? __pfx_cpuhp_thread_fun+0x10/0x10
[    2.888609][   T22]  ? __pfx_cpuhp_thread_fun+0x10/0x10
[    2.888609][   T22]  ? smpboot_thread_fn+0x59d/0xa30
[    2.888609][   T22]  smpboot_thread_fn+0x661/0xa30
[    2.888609][   T22]  ? __kthread_parkme+0x148/0x220
[    2.888609][   T22]  ? __pfx_smpboot_thread_fn+0x10/0x10
[    2.888609][   T22]  kthread+0x2c1/0x3a0
[    2.888609][   T22]  ? _raw_spin_unlock_irq+0x23/0x50
[    2.888609][   T22]  ? __pfx_kthread+0x10/0x10
[    2.888609][   T22]  ret_from_fork+0x45/0x80
[    2.888609][   T22]  ? __pfx_kthread+0x10/0x10
[    2.888609][   T22]  ret_from_fork_asm+0x1a/0x30
[    2.888609][   T22]  </TASK>
[    2.888609][   T22] 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/linux/gopath/pkg/mod'
GONOPROXY=''
GONOSUMDB=''
GOOS='linux'
GOPATH='/syzkaller/jobs/linux/gopath'
GOPRIVATE=''
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/usr/local/go'
GOSUMDB='sum.golang.org'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/usr/local/go/pkg/tool/linux_amd64'
GOVCS=''
GOVERSION='go1.22.7'
GCCGO='gccgo'
GOAMD64='v1'
AR='ar'
CC='gcc'
CXX='g++'
CGO_ENABLED='1'
GOMOD='/syzkaller/jobs/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 -ffile-prefix-map=/tmp/go-build1808338263=/tmp/go-build -gno-record-gcc-switches'

git status (err=<nil>)
HEAD detached at d7f584ee3c
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:31: run command via tools/syz-env for best compatibility, see:
Makefile:32: 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
Makefile:31: run command via tools/syz-env for best compatibility, see:
Makefile:32: https://github.com/google/syzkaller/blob/master/docs/contributing.md#using-syz-env
bin/syz-sysgen
go fmt ./sys/... >/dev/null
touch .descriptions
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=d7f584ee3c24504bb07d04526a23b7d8df38b8ed -X 'github.com/google/syzkaller/prog.gitRevisionDate=20241220-210006'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-execprog github.com/google/syzkaller/tools/syz-execprog
mkdir -p ./bin/linux_amd64
g++ -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 -std=c++17 -I. -Iexecutor/_include -fpermissive -w -DGOOS_linux=1 -DGOARCH_amd64=1 \
	-DHOSTGOOS_linux=1 -DGIT_REVISION=\"d7f584ee3c24504bb07d04526a23b7d8df38b8ed\"
/usr/bin/ld: /tmp/ccNZxct1.o: in function `Connection::Connect(char const*, char const*)':
executor.cc:(.text._ZN10Connection7ConnectEPKcS1_[_ZN10Connection7ConnectEPKcS1_]+0x104): warning: Using 'gethostbyname' in statically linked applications requires at runtime the shared libraries from the glibc version used for linking


Error text is too large and was truncated, full error text is at:
https://syzkaller.appspot.com/x/error.txt?x=121736f8580000


Tested on:

commit:         9d895519 Linux 6.13-rc6
git tree:       upstream
kernel config:  https://syzkaller.appspot.com/x/.config?x=ad08f7f48e13abcd
dashboard link: https://syzkaller.appspot.com/bug?extid=76f33569875eb708e575
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=11671edf980000