Re: [syzbot] [audit?] [bpf?] INFO: rcu detected stall in kauditd_thread (4)

From: syzbot
Date: Fri Mar 29 2024 - 13:08:12 EST


Hello,

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

onnector registered
[ 8.925501][ T1] [drm] Initialized vgem 1.0.0 20120112 for vgem on minor 0
[ 8.936918][ T1] [drm] Initialized vkms 1.0.0 20180514 for vkms on minor 1
[ 9.031871][ T1] Console: switching to colour frame buffer device 128x48
[ 9.049570][ T1] platform vkms: [drm] fb0: vkmsdrmfb frame buffer device
[ 9.050924][ T1] usbcore: registered new interface driver udl
[ 9.140069][ T1] brd: module loaded
[ 9.257049][ T1] loop: module loaded
[ 9.412333][ T1] zram: Added device: zram0
[ 9.424889][ T1] null_blk: disk nullb0 created
[ 9.425718][ T1] null_blk: module loaded
[ 9.427782][ T1] Guest personality initialized and is inactive
[ 9.429970][ T1] VMCI host device registered (name=vmci, major=10, minor=118)
[ 9.431095][ T1] Initialized host personality
[ 9.432024][ T1] usbcore: registered new interface driver rtsx_usb
[ 9.433983][ T1] usbcore: registered new interface driver viperboard
[ 9.435713][ T1] usbcore: registered new interface driver dln2
[ 9.437613][ T1] usbcore: registered new interface driver pn533_usb
[ 9.445487][ T1] nfcsim 0.2 initialized
[ 9.446814][ T1] usbcore: registered new interface driver port100
[ 9.448211][ T1] usbcore: registered new interface driver nfcmrvl
[ 9.455761][ T1] Loading iSCSI transport class v2.0-870.
[ 9.481077][ T1] virtio_scsi virtio0: 1/0/0 default/read/poll queues
[ 9.491184][ T1] ------------[ cut here ]------------
[ 9.491949][ T1] refcount_t: decrement hit 0; leaking memory.
[ 9.493197][ T1] WARNING: CPU: 0 PID: 1 at lib/refcount.c:31 refcount_warn_saturate+0x1ed/0x210
[ 9.494503][ T1] Modules linked in:
[ 9.495197][ T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 6.9.0-rc1-syzkaller-00178-g317c7bc0ef03-dirty #0
[ 9.496752][ T1] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 03/27/2024
[ 9.498118][ T1] RIP: 0010:refcount_warn_saturate+0x1ed/0x210
[ 9.499016][ T1] Code: 8b e8 d7 34 d2 fc 90 0f 0b 90 90 e9 c3 fe ff ff e8 c8 c6 0f fd c6 05 fa f0 4c 0b 01 90 48 c7 c7 80 e5 8e 8b e8 b4 34 d2 fc 90 <0f> 0b 90 90 e9 a0 fe ff ff 48 89 ef e8 e2 f2 6a fd e9 44 fe ff ff
[ 9.501796][ T1] RSP: 0000:ffffc900000673c0 EFLAGS: 00010286
[ 9.502670][ T1] RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffffffff814fe149
[ 9.503753][ T1] RDX: ffff888016ec0000 RSI: ffffffff814fe156 RDI: 0000000000000001
[ 9.504990][ T1] RBP: ffff888147a9da7c R08: 0000000000000001 R09: 0000000000000000
[ 9.506141][ T1] R10: 0000000000000000 R11: 0000000000000001 R12: ffff888147a9da7c
[ 9.507308][ T1] R13: 0000000000000000 R14: 00000000034c00b9 R15: ffff88801687cd88
[ 9.508457][ T1] FS: 0000000000000000(0000) GS:ffff8880b9200000(0000) knlGS:0000000000000000
[ 9.509770][ T1] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 9.510753][ T1] CR2: ffff88823ffff000 CR3: 000000000d97a000 CR4: 00000000003506f0
[ 9.511894][ T1] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 9.513054][ T1] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 9.514199][ T1] Call Trace:
[ 9.514874][ T1] <TASK>
[ 9.515320][ T1] ? show_regs+0x8c/0xa0
[ 9.515938][ T1] ? __warn+0xe5/0x3c0
[ 9.516504][ T1] ? __wake_up_klogd.part.0+0x99/0xf0
[ 9.517289][ T1] ? refcount_warn_saturate+0x1ed/0x210
[ 9.518112][ T1] ? report_bug+0x3c0/0x580
[ 9.518784][ T1] ? handle_bug+0x3d/0x70
[ 9.519418][ T1] ? exc_invalid_op+0x17/0x50
[ 9.520133][ T1] ? asm_exc_invalid_op+0x1a/0x20
[ 9.520890][ T1] ? __warn_printk+0x199/0x350
[ 9.521627][ T1] ? __warn_printk+0x1a6/0x350
[ 9.522359][ T1] ? refcount_warn_saturate+0x1ed/0x210
[ 9.523209][ T1] __reset_page_owner+0x2ea/0x370
[ 9.523932][ T1] __free_pages_ok+0x5a9/0xbf0
[ 9.524704][ T1] ? __split_page_owner+0xdd/0x120
[ 9.525413][ T1] make_alloc_exact+0x165/0x260
[ 9.526180][ T1] vring_alloc_queue+0xc1/0x110
[ 9.527000][ T1] vring_alloc_queue_split+0x186/0x510
[ 9.527845][ T1] ? __pfx_vring_alloc_queue_split+0x10/0x10
[ 9.528704][ T1] ? kasan_save_stack+0x42/0x60
[ 9.529397][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 9.530249][ T1] vring_create_virtqueue_split+0xe8/0x280
[ 9.531109][ T1] ? __pfx_vp_notify+0x10/0x10
[ 9.531838][ T1] ? __pfx_vring_create_virtqueue_split+0x10/0x10
[ 9.532706][ T1] ? virtio_scsi_init+0x75/0x100
[ 9.533384][ T1] ? do_one_initcall+0x128/0x700
[ 9.534078][ T1] ? kernel_init_freeable+0x69d/0xca0
[ 9.534939][ T1] vring_create_virtqueue+0xd7/0x140
[ 9.535789][ T1] ? __pfx_vp_notify+0x10/0x10
[ 9.536450][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 9.537233][ T1] setup_vq+0x123/0x2f0
[ 9.537807][ T1] ? __pfx_vp_notify+0x10/0x10
[ 9.538463][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 9.539325][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 9.540143][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 9.540960][ T1] vp_setup_vq+0xb1/0x380
[ 9.541628][ T1] ? iowrite16+0x55/0x80
[ 9.542223][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 9.542989][ T1] vp_find_vqs_msix+0x661/0xe30
[ 9.543719][ T1] vp_find_vqs+0x58/0x560
[ 9.544394][ T1] virtscsi_init+0x459/0x9f0
[ 9.545082][ T1] ? __pfx_virtscsi_init+0x10/0x10
[ 9.545805][ T1] ? __pfx_default_calc_sets+0x10/0x10
[ 9.546590][ T1] ? ioread8+0x4e/0xa0
[ 9.547161][ T1] ? vp_get+0xf6/0x140
[ 9.547727][ T1] virtscsi_probe+0x3b2/0xdd0
[ 9.548378][ T1] ? __pfx_virtscsi_probe+0x10/0x10
[ 9.549118][ T1] ? trace_raw_output_sched_pi_setprio+0xad/0x150
[ 9.550033][ T1] ? vring_transport_features+0x49/0xb0
[ 9.550796][ T1] virtio_dev_probe+0x5ff/0x9b0
[ 9.551467][ T1] ? __pfx_virtio_dev_probe+0x10/0x10
[ 9.552207][ T1] really_probe+0x23e/0xa90
[ 9.552833][ T1] __driver_probe_device+0x1de/0x440
[ 9.553620][ T1] ? _raw_spin_unlock_irqrestore+0x52/0x80
[ 9.554433][ T1] driver_probe_device+0x4c/0x1b0
[ 9.555130][ T1] __driver_attach+0x283/0x580
[ 9.555809][ T1] ? __pfx___driver_attach+0x10/0x10
[ 9.556553][ T1] bus_for_each_dev+0x13c/0x1d0
[ 9.557221][ T1] ? __pfx_bus_for_each_dev+0x10/0x10
[ 9.557958][ T1] bus_add_driver+0x2ed/0x640
[ 9.558607][ T1] driver_register+0x15c/0x4b0
[ 9.559261][ T1] ? __pfx_virtio_scsi_init+0x10/0x10
[ 9.560012][ T1] ? __pfx_virtio_scsi_init+0x10/0x10
[ 9.560746][ T1] virtio_scsi_init+0x75/0x100
[ 9.561401][ T1] do_one_initcall+0x128/0x700
[ 9.562065][ T1] ? __pfx_do_one_initcall+0x10/0x10
[ 9.562813][ T1] ? trace_kmalloc+0x2d/0xe0
[ 9.563451][ T1] ? __kmalloc+0x218/0x440
[ 9.564063][ T1] kernel_init_freeable+0x69d/0xca0
[ 9.564821][ T1] ? __pfx_kernel_init+0x10/0x10
[ 9.565561][ T1] kernel_init+0x1c/0x2b0
[ 9.566160][ T1] ? __pfx_kernel_init+0x10/0x10
[ 9.566837][ T1] ret_from_fork+0x45/0x80
[ 9.567453][ T1] ? __pfx_kernel_init+0x10/0x10
[ 9.568132][ T1] ret_from_fork_asm+0x1a/0x30
[ 9.568792][ T1] </TASK>
[ 9.569217][ T1] Kernel panic - not syncing: kernel: panic_on_warn set ...
[ 9.570203][ T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 6.9.0-rc1-syzkaller-00178-g317c7bc0ef03-dirty #0
[ 9.571565][ T1] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 03/27/2024
[ 9.572900][ T1] Call Trace:
[ 9.573380][ T1] <TASK>
[ 9.573813][ T1] dump_stack_lvl+0x3d/0x1f0
[ 9.574451][ T1] panic+0x6f5/0x7a0
[ 9.574804][ T1] ? __pfx_panic+0x10/0x10
[ 9.574804][ T1] ? show_trace_log_lvl+0x363/0x500
[ 9.574804][ T1] ? check_panic_on_warn+0x1f/0xb0
[ 9.574804][ T1] ? refcount_warn_saturate+0x1ed/0x210
[ 9.574804][ T1] check_panic_on_warn+0xab/0xb0
[ 9.574804][ T1] __warn+0xf1/0x3c0
[ 9.574804][ T1] ? __wake_up_klogd.part.0+0x99/0xf0
[ 9.574804][ T1] ? refcount_warn_saturate+0x1ed/0x210
[ 9.574804][ T1] report_bug+0x3c0/0x580
[ 9.574804][ T1] handle_bug+0x3d/0x70
[ 9.574804][ T1] exc_invalid_op+0x17/0x50
[ 9.574804][ T1] asm_exc_invalid_op+0x1a/0x20
[ 9.574804][ T1] RIP: 0010:refcount_warn_saturate+0x1ed/0x210
[ 9.574804][ T1] Code: 8b e8 d7 34 d2 fc 90 0f 0b 90 90 e9 c3 fe ff ff e8 c8 c6 0f fd c6 05 fa f0 4c 0b 01 90 48 c7 c7 80 e5 8e 8b e8 b4 34 d2 fc 90 <0f> 0b 90 90 e9 a0 fe ff ff 48 89 ef e8 e2 f2 6a fd e9 44 fe ff ff
[ 9.574804][ T1] RSP: 0000:ffffc900000673c0 EFLAGS: 00010286
[ 9.574804][ T1] RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffffffff814fe149
[ 9.574804][ T1] RDX: ffff888016ec0000 RSI: ffffffff814fe156 RDI: 0000000000000001
[ 9.574804][ T1] RBP: ffff888147a9da7c R08: 0000000000000001 R09: 0000000000000000
[ 9.574804][ T1] R10: 0000000000000000 R11: 0000000000000001 R12: ffff888147a9da7c
[ 9.574804][ T1] R13: 0000000000000000 R14: 00000000034c00b9 R15: ffff88801687cd88
[ 9.574804][ T1] ? __warn_printk+0x199/0x350
[ 9.574804][ T1] ? __warn_printk+0x1a6/0x350
[ 9.574804][ T1] __reset_page_owner+0x2ea/0x370
[ 9.574804][ T1] __free_pages_ok+0x5a9/0xbf0
[ 9.574804][ T1] ? __split_page_owner+0xdd/0x120
[ 9.574804][ T1] make_alloc_exact+0x165/0x260
[ 9.574804][ T1] vring_alloc_queue+0xc1/0x110
[ 9.574804][ T1] vring_alloc_queue_split+0x186/0x510
[ 9.574804][ T1] ? __pfx_vring_alloc_queue_split+0x10/0x10
[ 9.574804][ T1] ? kasan_save_stack+0x42/0x60
[ 9.574804][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 9.574804][ T1] vring_create_virtqueue_split+0xe8/0x280
[ 9.574804][ T1] ? __pfx_vp_notify+0x10/0x10
[ 9.574804][ T1] ? __pfx_vring_create_virtqueue_split+0x10/0x10
[ 9.574804][ T1] ? virtio_scsi_init+0x75/0x100
[ 9.574804][ T1] ? do_one_initcall+0x128/0x700
[ 9.574804][ T1] ? kernel_init_freeable+0x69d/0xca0
[ 9.574804][ T1] vring_create_virtqueue+0xd7/0x140
[ 9.574804][ T1] ? __pfx_vp_notify+0x10/0x10
[ 9.574804][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 9.574804][ T1] setup_vq+0x123/0x2f0
[ 9.574804][ T1] ? __pfx_vp_notify+0x10/0x10
[ 9.574804][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 9.574804][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 9.574804][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 9.574804][ T1] vp_setup_vq+0xb1/0x380
[ 9.574804][ T1] ? iowrite16+0x55/0x80
[ 9.574804][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 9.574804][ T1] vp_find_vqs_msix+0x661/0xe30
[ 9.574804][ T1] vp_find_vqs+0x58/0x560
[ 9.574804][ T1] virtscsi_init+0x459/0x9f0
[ 9.574804][ T1] ? __pfx_virtscsi_init+0x10/0x10
[ 9.574804][ T1] ? __pfx_default_calc_sets+0x10/0x10
[ 9.574804][ T1] ? ioread8+0x4e/0xa0
[ 9.574804][ T1] ? vp_get+0xf6/0x140
[ 9.574804][ T1] virtscsi_probe+0x3b2/0xdd0
[ 9.574804][ T1] ? __pfx_virtscsi_probe+0x10/0x10
[ 9.574804][ T1] ? trace_raw_output_sched_pi_setprio+0xad/0x150
[ 9.574804][ T1] ? vring_transport_features+0x49/0xb0
[ 9.574804][ T1] virtio_dev_probe+0x5ff/0x9b0
[ 9.574804][ T1] ? __pfx_virtio_dev_probe+0x10/0x10
[ 9.574804][ T1] really_probe+0x23e/0xa90
[ 9.574804][ T1] __driver_probe_device+0x1de/0x440
[ 9.574804][ T1] ? _raw_spin_unlock_irqrestore+0x52/0x80
[ 9.574804][ T1] driver_probe_device+0x4c/0x1b0
[ 9.574804][ T1] __driver_attach+0x283/0x580
[ 9.574804][ T1] ? __pfx___driver_attach+0x10/0x10
[ 9.574804][ T1] bus_for_each_dev+0x13c/0x1d0
[ 9.574804][ T1] ? __pfx_bus_for_each_dev+0x10/0x10
[ 9.574804][ T1] bus_add_driver+0x2ed/0x640
[ 9.574804][ T1] driver_register+0x15c/0x4b0
[ 9.574804][ T1] ? __pfx_virtio_scsi_init+0x10/0x10
[ 9.574804][ T1] ? __pfx_virtio_scsi_init+0x10/0x10
[ 9.574804][ T1] virtio_scsi_init+0x75/0x100
[ 9.574804][ T1] do_one_initcall+0x128/0x700
[ 9.574804][ T1] ? __pfx_do_one_initcall+0x10/0x10
[ 9.574804][ T1] ? trace_kmalloc+0x2d/0xe0
[ 9.574804][ T1] ? __kmalloc+0x218/0x440
[ 9.574804][ T1] kernel_init_freeable+0x69d/0xca0
[ 9.574804][ T1] ? __pfx_kernel_init+0x10/0x10
[ 9.574804][ T1] kernel_init+0x1c/0x2b0
[ 9.574804][ T1] ? __pfx_kernel_init+0x10/0x10
[ 9.574804][ T1] ret_from_fork+0x45/0x80
[ 9.574804][ T1] ? __pfx_kernel_init+0x10/0x10
[ 9.574804][ T1] ret_from_fork_asm+0x1a/0x30
[ 9.574804][ T1] </TASK>
[ 9.574804][ T1] Kernel Offset: disabled
[ 9.574804][ T1] 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.21.4'
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-build932799495=/tmp/go-build -gno-record-gcc-switches'

git status (err=<nil>)
HEAD detached at 454571b6a
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=454571b6a16598f5a6e015b9fb1a04932bce7ab9 -X 'github.com/google/syzkaller/prog.gitRevisionDate=20240326-163935'" "-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=454571b6a16598f5a6e015b9fb1a04932bce7ab9 -X 'github.com/google/syzkaller/prog.gitRevisionDate=20240326-163935'" "-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=454571b6a16598f5a6e015b9fb1a04932bce7ab9 -X 'github.com/google/syzkaller/prog.gitRevisionDate=20240326-163935'" "-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=\"454571b6a16598f5a6e015b9fb1a04932bce7ab9\"


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


Tested on:

commit: 317c7bc0 Merge tag 'mmc-v6.9-rc1' of git://git.kernel...
git tree: https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master
kernel config: https://syzkaller.appspot.com/x/.config?x=f64ec427e98bccd7
dashboard link: https://syzkaller.appspot.com/bug?extid=81f5ca46b043d4a1b789
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=17287791180000