Re: [syzbot] [xfs?] possible deadlock in xfs_buf_find_insert

syzbot
2025-02-03T07:55:02Z

Hello,

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

T0] rcu: Preemptible hierarchical RCU implementation.
[ 2.010612][ T0] rcu: RCU lockdep checking is enabled.
[ 2.011402][ T0] rcu: RCU restricting CPUs from NR_CPUS=8 to nr_cpu_ids=2.
[ 2.012353][ T0] rcu: RCU callback double-/use-after-free debug is enabled.
[ 2.013319][ T0] rcu: RCU debug extended QS entry/exit.
[ 2.014072][ T0] All grace periods are expedited (rcu_expedited).
[ 2.014984][ T0] Trampoline variant of Tasks RCU enabled.
[ 2.015740][ T0] Tracing variant of Tasks RCU enabled.
[ 2.016576][ T0] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[ 2.017799][ T0] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2
[ 2.019085][ T0] Running RCU synchronous self tests
[ 2.020120][ T0] RCU Tasks: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2.
[ 2.021528][ T0] RCU Tasks Trace: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=2.
[ 2.128414][ T0] NR_IRQS: 4352, nr_irqs: 440, preallocated irqs: 16
[ 2.130465][ T0] rcu: srcu_init: Setting srcu_struct sizes based on contention.
[ 2.131983][ T0] kfence: initialized - using 2097152 bytes for 255 objects at 0xffff88823be00000-0xffff88823c000000
[ 2.134701][ T0] Console: colour VGA+ 80x25
[ 2.135499][ T0] printk: legacy console [ttyS0] enabled
[ 2.135499][ T0] printk: legacy console [ttyS0] enabled
[ 2.137023][ T0] printk: legacy bootconsole [earlyser0] disabled
[ 2.137023][ T0] printk: legacy bootconsole [earlyser0] disabled
[ 2.138913][ T0] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
[ 2.140082][ T0] ... MAX_LOCKDEP_SUBCLASSES: 8
[ 2.140751][ T0] ... MAX_LOCK_DEPTH: 48
[ 2.141484][ T0] ... MAX_LOCKDEP_KEYS: 8192
[ 2.142184][ T0] ... CLASSHASH_SIZE: 4096
[ 2.142884][ T0] ... MAX_LOCKDEP_ENTRIES: 1048576
[ 2.143679][ T0] ... MAX_LOCKDEP_CHAINS: 1048576
[ 2.144453][ T0] ... CHAINHASH_SIZE: 524288
[ 2.145319][ T0] memory used by lock dependency info: 106625 kB
[ 2.146255][ T0] memory used for stack traces: 8320 kB
[ 2.147150][ T0] per task-struct memory footprint: 1920 bytes
[ 2.148349][ T0] mempolicy: Enabling automatic NUMA balancing. Configure with numa_balancing= or the kernel.numa_balancing sysctl
[ 2.150130][ T0] ACPI: Core revision 20240827
[ 2.151799][ T0] APIC: Switch to symmetric I/O mode setup
[ 2.153224][ T0] x2apic enabled
[ 2.157556][ T0] APIC: Switched APIC routing to: physical x2apic
[ 2.164292][ T0] ..TIMER: vector=0x30 apic1=0 pin1=0 apic2=-1 pin2=-1
[ 2.165656][ T0] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x1fb6cdb0489, max_idle_ns: 440795236064 ns
[ 2.168007][ T0] Calibrating delay loop (skipped) preset value.. 4400.32 BogoMIPS (lpj=22001640)
[ 2.170708][ T0] Last level iTLB entries: 4KB 64, 2MB 8, 4MB 8
[ 2.178063][ T0] Last level dTLB entries: 4KB 64, 2MB 0, 4MB 0, 1GB 4
[ 2.179278][ T0] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
[ 2.180882][ T0] Spectre V2 : Spectre BHI mitigation: SW BHB clearing on syscall and VM exit
[ 2.182464][ T0] Spectre V2 : Mitigation: IBRS
[ 2.183352][ T0] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
[ 2.185620][ T0] Spectre V2 : Spectre v2 / SpectreRSB : Filling RSB on VMEXIT
[ 2.187126][ T0] RETBleed: Mitigation: IBRS
[ 2.188042][ T0] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
[ 2.189783][ T0] Spectre V2 : User space: Mitigation: STIBP via prctl
[ 2.191308][ T0] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
[ 2.192767][ T0] MDS: Mitigation: Clear CPU buffers
[ 2.193900][ T0] TAA: Mitigation: Clear CPU buffers
[ 2.195007][ T0] MMIO Stale Data: Vulnerable: Clear CPU buffers attempted, no microcode
[ 2.196747][ T0] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
[ 2.198001][ T0] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
[ 2.199054][ T0] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
[ 2.200127][ T0] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256
[ 2.201210][ T0] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format.
[ 2.442880][ T0] Freeing SMP alternatives memory: 128K
[ 2.444580][ T0] pid_max: default: 32768 minimum: 301
[ 2.446296][ T0] LSM: initializing lsm=lockdown,capability,landlock,yama,safesetid,tomoyo,smack,bpf,ima,evm
[ 2.448422][ T0] landlock: Up and running.
[ 2.449554][ T0] Yama: becoming mindful.
[ 2.451102][ T0] TOMOYO Linux initialized
[ 2.452555][ T0] Smack: Initializing.
[ 2.453285][ T0] Smack: Netfilter enabled.
[ 2.454251][ T0] Smack: IPv6 Netfilter enabled.
[ 2.457026][ T0] LSM support for eBPF active
[ 2.463614][ T0] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, vmalloc hugepage)
[ 2.468234][ T0] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc hugepage)
[ 2.470255][ T0] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc)
[ 2.472020][ T0] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, vmalloc)
[ 2.477781][ T0] Running RCU synchronous self tests
[ 2.478011][ T0] Running RCU synchronous self tests
[ 2.601188][ T1] smpboot: CPU0: Intel(R) Xeon(R) CPU @ 2.20GHz (family: 0x6, model: 0x4f, stepping: 0x0)
[ 2.607820][ T1] Running RCU Tasks wait API self tests
[ 2.708457][ T1] Running RCU Tasks Trace wait API self tests
[ 2.709846][ T1] Performance Events: unsupported p6 CPU model 79 no PMU driver, software events only.
[ 2.712156][ T1] signal: max sigframe size: 1776
[ 2.714315][ T1] rcu: Hierarchical SRCU implementation.
[ 2.715360][ T1] rcu: Max phase no-delay instances is 1000.
[ 2.717463][ T1] Timer migration: 1 hierarchy levels; 8 children per group; 0 crossnode level
[ 2.723005][ T1] NMI watchdog: Perf NMI watchdog permanently disabled
[ 2.725256][ T1] smp: Bringing up secondary CPUs ...
[ 2.729771][ T1] smpboot: x86: Booting SMP configuration:
[ 2.730820][ T1] .... node #0, CPUs: #1
[ 2.731034][ T15] Callback from call_rcu_tasks_trace() invoked.
[ 2.733623][ T22] ------------[ cut here ]------------
[ 2.733623][ T22] workqueue: work disable count underflowed
[ 2.733623][ T22] WARNING: CPU: 1 PID: 22 at kernel/workqueue.c:4317 enable_work+0x34d/0x360
[ 2.733623][ T22] Modules linked in:
[ 2.733623][ T22] CPU: 1 UID: 0 PID: 22 Comm: cpuhp/1 Not tainted 6.13.0-rc6-syzkaller-00134-ga9ab28b3d21a #0
[ 2.735303][ T22] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 12/27/2024
[ 2.737287][ T22] RIP: 0010:enable_work+0x34d/0x360
[ 2.737989][ T22] Code: d8 5b 41 5c 41 5d 41 5e 41 5f 5d c3 cc cc cc cc e8 18 82 37 00 c6 05 4c c2 9a 0e 01 90 48 c7 c7 a0 d0 09 8c e8 44 25 f8 ff 90 <0f> 0b 90 90 e9 56 ff ff ff e8 e5 76 59 0a 0f 1f 44 00 00 90 90 90
[ 2.737989][ T22] RSP: 0000:ffffc900001c7bc0 EFLAGS: 00010046
[ 2.737989][ T22] RAX: 6282fd934c3ae400 RBX: 0000000000000000 RCX: ffff88801d2cbc00
[ 2.737989][ T22] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
[ 2.737989][ T22] RBP: ffffc900001c7c88 R08: ffffffff815ffac2 R09: 1ffffffff1cfa0f4
[ 2.737989][ T22] R10: dffffc0000000000 R11: fffffbfff1cfa0f5 R12: 1ffff92000038f7c
[ 2.737989][ T22] R13: 1ffff92000038f84 R14: 001fffffffc00001 R15: ffff8880b8738770
[ 2.737989][ T22] FS: 0000000000000000(0000) GS:ffff8880b8700000(0000) knlGS:0000000000000000
[ 2.737989][ T22] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 2.737989][ T22] CR2: 0000000000000000 CR3: 000000000e736000 CR4: 00000000003506f0
[ 2.737989][ T22] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 2.737989][ T22] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 2.737989][ T22] Call Trace:
[ 2.737989][ T22] <TASK>
[ 2.737989][ T22] ? __warn+0x165/0x4d0
[ 2.737989][ T22] ? enable_work+0x34d/0x360
[ 2.737989][ T22] ? report_bug+0x2b3/0x500
[ 2.737989][ T22] ? enable_work+0x34d/0x360
[ 2.737989][ T22] ? handle_bug+0x60/0x90
[ 2.737989][ T22] ? exc_invalid_op+0x1a/0x50
[ 2.737989][ T22] ? asm_exc_invalid_op+0x1a/0x20
[ 2.737989][ T22] ? __warn_printk+0x292/0x360
[ 2.737989][ T22] ? enable_work+0x34d/0x360
[ 2.737989][ T22] ? __pfx_enable_work+0x10/0x10
[ 2.737989][ T22] ? __pfx_vmstat_cpu_online+0x10/0x10
[ 2.737989][ T22] ? rcu_is_watching+0x15/0xb0
[ 2.737989][ T22] vmstat_cpu_online+0xbb/0xe0
[ 2.737989][ T22] ? __pfx_vmstat_cpu_online+0x10/0x10
[ 2.737989][ T22] cpuhp_invoke_callback+0x48d/0x830
[ 2.737989][ T22] ? __pfx_vmstat_cpu_online+0x10/0x10
[ 2.737989][ T22] cpuhp_thread_fun+0x41c/0x810
[ 2.737989][ T22] ? cpuhp_thread_fun+0x130/0x810
[ 2.737989][ T22] ? __pfx_cpuhp_thread_fun+0x10/0x10
[ 2.737989][ T22] ? _raw_spin_unlock_irqrestore+0xdd/0x140
[ 2.737989][ T22] ? __pfx_cpuhp_thread_fun+0x10/0x10
[ 2.737989][ T22] smpboot_thread_fn+0x544/0xa30
[ 2.737989][ T22] ? smpboot_thread_fn+0x4e/0xa30
[ 2.737989][ T22] ? __pfx_smpboot_thread_fn+0x10/0x10
[ 2.737989][ T22] kthread+0x2f0/0x390
[ 2.737989][ T22] ? __pfx_smpboot_thread_fn+0x10/0x10
[ 2.737989][ T22] ? __pfx_kthread+0x10/0x10
[ 2.737989][ T22] ret_from_fork+0x4b/0x80
[ 2.737989][ T22] ? __pfx_kthread+0x10/0x10
[ 2.737989][ T22] ret_from_fork_asm+0x1a/0x30
[ 2.737989][ T22] </TASK>
[ 2.737989][ T22] Kernel panic - not syncing: kernel: panic_on_warn set ...
[ 2.737989][ T22] CPU: 1 UID: 0 PID: 22 Comm: cpuhp/1 Not tainted 6.13.0-rc6-syzkaller-00134-ga9ab28b3d21a #0
[ 2.737989][ T22] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 12/27/2024
[ 2.737989][ T22] Call Trace:
[ 2.737989][ T22] <TASK>
[ 2.737989][ T22] dump_stack_lvl+0x241/0x360
[ 2.737989][ T22] ? __pfx_dump_stack_lvl+0x10/0x10
[ 2.737989][ T22] ? __pfx__printk+0x10/0x10
[ 2.737989][ T22] ? _printk+0xd5/0x120
[ 2.737989][ T22] ? __init_begin+0x41000/0x41000
[ 2.737989][ T22] ? vscnprintf+0x5d/0x90
[ 2.737989][ T22] panic+0x349/0x880
[ 2.737989][ T22] ? __warn+0x174/0x4d0
[ 2.737989][ T22] ? __pfx_panic+0x10/0x10
[ 2.737989][ T22] ? ret_from_fork_asm+0x1a/0x30
[ 2.737989][ T22] __warn+0x344/0x4d0
[ 2.737989][ T22] ? enable_work+0x34d/0x360
[ 2.737989][ T22] report_bug+0x2b3/0x500
[ 2.737989][ T22] ? enable_work+0x34d/0x360
[ 2.737989][ T22] handle_bug+0x60/0x90
[ 2.737989][ T22] exc_invalid_op+0x1a/0x50
[ 2.737989][ T22] asm_exc_invalid_op+0x1a/0x20
[ 2.737989][ T22] RIP: 0010:enable_work+0x34d/0x360
[ 2.737989][ T22] Code: d8 5b 41 5c 41 5d 41 5e 41 5f 5d c3 cc cc cc cc e8 18 82 37 00 c6 05 4c c2 9a 0e 01 90 48 c7 c7 a0 d0 09 8c e8 44 25 f8 ff 90 <0f> 0b 90 90 e9 56 ff ff ff e8 e5 76 59 0a 0f 1f 44 00 00 90 90 90
[ 2.737989][ T22] RSP: 0000:ffffc900001c7bc0 EFLAGS: 00010046
[ 2.737989][ T22] RAX: 6282fd934c3ae400 RBX: 0000000000000000 RCX: ffff88801d2cbc00
[ 2.737989][ T22] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
[ 2.737989][ T22] RBP: ffffc900001c7c88 R08: ffffffff815ffac2 R09: 1ffffffff1cfa0f4
[ 2.737989][ T22] R10: dffffc0000000000 R11: fffffbfff1cfa0f5 R12: 1ffff92000038f7c
[ 2.737989][ T22] R13: 1ffff92000038f84 R14: 001fffffffc00001 R15: ffff8880b8738770
[ 2.737989][ T22] ? __warn_printk+0x292/0x360
[ 2.737989][ T22] ? __pfx_enable_work+0x10/0x10
[ 2.737989][ T22] ? __pfx_vmstat_cpu_online+0x10/0x10
[ 2.737989][ T22] ? rcu_is_watching+0x15/0xb0
[ 2.737989][ T22] vmstat_cpu_online+0xbb/0xe0
[ 2.737989][ T22] ? __pfx_vmstat_cpu_online+0x10/0x10
[ 2.737989][ T22] cpuhp_invoke_callback+0x48d/0x830
[ 2.737989][ T22] ? __pfx_vmstat_cpu_online+0x10/0x10
[ 2.737989][ T22] cpuhp_thread_fun+0x41c/0x810
[ 2.737989][ T22] ? cpuhp_thread_fun+0x130/0x810
[ 2.737989][ T22] ? __pfx_cpuhp_thread_fun+0x10/0x10
[ 2.737989][ T22] ? _raw_spin_unlock_irqrestore+0xdd/0x140
[ 2.737989][ T22] ? __pfx_cpuhp_thread_fun+0x10/0x10
[ 2.737989][ T22] smpboot_thread_fn+0x544/0xa30
[ 2.737989][ T22] ? smpboot_thread_fn+0x4e/0xa30
[ 2.737989][ T22] ? __pfx_smpboot_thread_fn+0x10/0x10
[ 2.737989][ T22] kthread+0x2f0/0x390
[ 2.737989][ T22] ? __pfx_smpboot_thread_fn+0x10/0x10
[ 2.737989][ T22] ? __pfx_kthread+0x10/0x10
[ 2.737989][ T22] ret_from_fork+0x4b/0x80
[ 2.737989][ T22] ? __pfx_kthread+0x10/0x10
[ 2.737989][ T22] ret_from_fork_asm+0x1a/0x30
[ 2.737989][ T22] </TASK>
[ 2.737989][ 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-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=''
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-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 -ffile-prefix-map=/tmp/go-build348862417=/tmp/go-build -gno-record-gcc-switches'

git status (err=<nil>)
HEAD detached at 568559e4e6
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
touch .descriptions
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=568559e4e604140cecd9fc4835eaa0298a1cadcc -X 'github.com/google/syzkaller/prog.gitRevisionDate=20250201-125757'" -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 -DGOOS_linux=1 -DGOARCH_amd64=1 \
-DHOSTGOOS_linux=1 -DGIT_REVISION=\"568559e4e604140cecd9fc4835eaa0298a1cadcc\"
/usr/bin/ld: /tmp/ccNM92bn.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=13491764580000

Tested on:

commit: a9ab28b3 xfs: remove xfs_buf_cache.bc_lock
git tree: https://git.kernel.org/pub/scm/fs/xfs/xfs-linux.git/ for-next
kernel config: https://syzkaller.appspot.com/x/.config?x=c8502218c2b0a864
dashboard link: https://syzkaller.appspot.com/bug?extid=acb56162aef712929d3f
compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40

Note: no patches were applied.