Message-ID: <671762c7.050a0220.10f4f4.0114.GAE@google.com>
Date: Tue, 22 Oct 2024 01:31:03 -0700
From: syzbot <syzbot+a234c2d63e0c171ca10e@...kaller.appspotmail.com>
To: eadavis@...com, linux-kernel@...r.kernel.org, 
	syzkaller-bugs@...glegroups.com
Subject: Re: [syzbot] [serial?] BUG: soft lockup in debug_check_no_obj_freed

Hello,

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

653] 1 lock held by syz-execprog/2653:
[   61.434232][ T2653]  #0: ffff888112418958 (&sighand->siglock){....}-{2:2}, at: get_signal+0x25a/0x2770
[   61.443766][ T2653] irq event stamp: 48556
[   61.448017][ T2653] hardirqs last  enabled at (48555): [<ffffffff86eea633>] irqentry_exit_to_user_mode+0x113/0x240
[   61.458527][ T2653] hardirqs last disabled at (48556): [<ffffffff86f0d365>] _raw_spin_lock_irq+0x45/0x50
[   61.468174][ T2653] softirqs last  enabled at (48542): [<ffffffff811caf83>] handle_softirqs+0x5a3/0x8d0
[   61.477893][ T2653] softirqs last disabled at (48537): [<ffffffff811cb9ec>] irq_exit_rcu+0xac/0x110
[   61.487192][ T2653] Preemption disabled at:
[   61.487201][ T2653] [<0000000000000000>] 0x0
[   61.496255][ T2653] CPU: 1 UID: 0 PID: 2653 Comm: syz-execprog Tainted: G        W          6.12.0-rc4-syzkaller-gc6d9e43954bf-dirty #0
[   61.508883][ T2653] Tainted: [W]=WARN
[   61.512710][ T2653] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 09/13/2024
[   61.522769][ T2653] Call Trace:
[   61.526056][ T2653]  <TASK>
[   61.528996][ T2653]  dump_stack_lvl+0x116/0x1f0
[   61.533718][ T2653]  __might_resched+0x3c0/0x5e0
[   61.538585][ T2653]  ? mark_lock+0xb5/0xc60
[   61.542930][ T2653]  ? __pfx___might_resched+0x10/0x10
[   61.548267][ T2653]  ? __pfx_mark_lock+0x10/0x10
[   61.553043][ T2653]  debug_check_no_obj_freed+0x1d9/0x620
[   61.558627][ T2653]  ? __pfx_debug_check_no_obj_freed+0x10/0x10
[   61.564815][ T2653]  ? put_ucounts+0x1e4/0x290
[   61.569459][ T2653]  kmem_cache_free+0x27d/0x480
[   61.574418][ T2653]  ? collect_signal+0x315/0x630
[   61.579304][ T2653]  collect_signal+0x315/0x630
[   61.584620][ T2653]  dequeue_signal+0x27e/0x720
[   61.589657][ T2653]  ? do_raw_spin_lock+0x12d/0x2c0
[   61.594772][ T2653]  ? __pfx_dequeue_signal+0x10/0x10
[   61.600066][ T2653]  ? __pfx_do_raw_spin_lock+0x10/0x10
[   61.605530][ T2653]  ? lock_acquire+0x2f/0xb0
[   61.610044][ T2653]  ? get_signal+0x25a/0x2770
[   61.614641][ T2653]  get_signal+0x5fb/0x2770
[   61.619071][ T2653]  ? __pfx_get_signal+0x10/0x10
[   61.624016][ T2653]  ? ktime_get+0xfb/0x1a0
[   61.628439][ T2653]  arch_do_signal_or_restart+0x90/0x7e0
[   61.634093][ T2653]  ? __pfx_arch_do_signal_or_restart+0x10/0x10
[   61.640364][ T2653]  irqentry_exit_to_user_mode+0x136/0x240
[   61.646182][ T2653]  asm_sysvec_reschedule_ipi+0x1a/0x20
[   61.651680][ T2653] RIP: 0033:0x41a8cb
[   61.655579][ T2653] Code: 8b 50 20 48 c1 e2 0d 48 89 d6 48 c1 ea 06 48 8b 78 68 48 c1 ef 03 4c 8b 40 18 4c 01 c6 48 29 d6 4c 29 c3 48 89 d9 48 c1 eb 09 <48> c1 e9 03 48 89 ca 83 e2 3f 4c 8d 04 3a 4c 8d 0c de 90 90 48 8d
[   61.675288][ T2653] RSP: 002b:000000c001e35e58 EFLAGS: 00000207
[   61.681359][ T2653] RAX: 00007ffa93044e58 RBX: 0000000000000009 RCX: 00000000000013e0
[   61.689336][ T2653] RDX: 0000000000000080 RSI: 000000c002547f80 RDI: 0000000000000006
[   61.697310][ T2653] RBP: 000000c001e35e70 R08: 000000c002546000 R09: 000000c000066508
[   61.705378][ T2653] R10: 000000c001ca5800 R11: 0000000000000024 R12: 000000c001e35f00
[   61.713369][ T2653] R13: 0000000000000001 R14: 000000c001c77c00 R15: 000000c0020bd0e8
[   61.721354][ T2653]  </TASK>
[   61.893622][   T29] kauditd_printk_skb: 9 callbacks suppressed
[   61.893645][   T29] audit: type=1400 audit(1729585852.299:102): avc:  denied  { execmem } for  pid=2660 comm="syz-executor" scontext=root:sysadm_r:sysadm_t tcontext=root:sysadm_r:sysadm_t tclass=process permissive=1
[   61.969213][   T29] audit: type=1400 audit(1729585852.359:103): avc:  denied  { read } for  pid=2665 comm="syz-executor" dev="nsfs" ino=4026531840 scontext=root:sysadm_r:sysadm_t tcontext=system_u:object_r:nsfs_t tclass=file permissive=1
[   62.017211][   T29] audit: type=1400 audit(1729585852.359:104): avc:  denied  { open } for  pid=2665 comm="syz-executor" path="net:[4026531840]" dev="nsfs" ino=4026531840 scontext=root:sysadm_r:sysadm_t tcontext=system_u:object_r:nsfs_t tclass=file permissive=1
[   62.097311][   T29] audit: type=1400 audit(1729585852.359:105): avc:  denied  { mounton } for  pid=2665 comm="syz-executor" path="/" dev="sda1" ino=2 scontext=root:sysadm_r:sysadm_t tcontext=system_u:object_r:root_t tclass=dir permissive=1
[   62.169505][   T29] audit: type=1400 audit(1729585852.379:106): avc:  denied  { create } for  pid=2664 comm="syz-executor" scontext=root:sysadm_r:sysadm_t tcontext=root:sysadm_r:sysadm_t tclass=user_namespace permissive=1
[   62.196383][ T2665] soft_limit_in_bytes is deprecated and will be removed. Please report your usecase to linux-mm@...ck.org if you depend on this functionality.
[   62.237242][   T29] audit: type=1400 audit(1729585852.399:107): avc:  denied  { sys_admin } for  pid=2664 comm="syz-executor" capability=21  scontext=root:sysadm_r:sysadm_t tcontext=root:sysadm_r:sysadm_t tclass=cap_userns permissive=1
[   62.298760][   T29] audit: type=1400 audit(1729585852.419:108): avc:  denied  { mounton } for  pid=2665 comm="syz-executor" path="/root/syzkaller.CmWlf6/syz-tmp" dev="sda1" ino=1945 scontext=root:sysadm_r:sysadm_t tcontext=root:object_r:user_home_t tclass=dir permissive=1
[   62.363987][   T29] audit: type=1400 audit(1729585852.419:109): avc:  denied  { mount } for  pid=2665 comm="syz-executor" name="/" dev="tmpfs" ino=1 scontext=root:sysadm_r:sysadm_t tcontext=system_u:object_r:tmpfs_t tclass=filesystem permissive=1
[   62.408172][   T29] audit: type=1400 audit(1729585852.419:110): avc:  denied  { mounton } for  pid=2665 comm="syz-executor" path="/root/syzkaller.CmWlf6/syz-tmp/newroot/dev" dev="tmpfs" ino=3 scontext=root:sysadm_r:sysadm_t tcontext=root:object_r:user_tmpfs_t tclass=dir permissive=1
[   62.416550][ T1356] BUG: sleeping function called from invalid context at lib/debugobjects.c:978
[   62.442502][ T1356] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid: 1356, name: kworker/u8:7
[   62.451716][ T1356] preempt_count: 1, expected: 0
[   62.456779][ T1356] RCU nest depth: 0, expected: 0
[   62.461726][ T1356] 3 locks held by kworker/u8:7/1356:
[   62.467108][ T1356]  #0: ffff888100089148 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work+0x129b/0x1ba0
[   62.478473][ T1356]  #1: ffffc900026afd80 ((work_completion)(&sub_info->work)){+.+.}-{0:0}, at: process_one_work+0x921/0x1ba0
[   62.490007][ T1356]  #2: ffffffff88c0a098 (tasklist_lock){.+.+}-{2:2}, at: release_task+0x20c/0x1b00
[   62.499451][ T1356] irq event stamp: 15692
[   62.503787][ T1356] hardirqs last  enabled at (15691): [<ffffffff86f0d633>] _raw_spin_unlock_irq+0x23/0x50
[   62.513611][ T1356] hardirqs last disabled at (15692): [<ffffffff86f0da65>] _raw_write_lock_irq+0x45/0x50
[   62.523347][ T1356] softirqs last  enabled at (7630): [<ffffffff811caf83>] handle_softirqs+0x5a3/0x8d0
[   62.532827][ T1356] softirqs last disabled at (7533): [<ffffffff811cb9ec>] irq_exit_rcu+0xac/0x110
[   62.541954][ T1356] Preemption disabled at:
[   62.541965][ T1356] [<0000000000000000>] 0x0
[   62.550730][ T1356] CPU: 1 UID: 0 PID: 1356 Comm: kworker/u8:7 Tainted: G        W          6.12.0-rc4-syzkaller-gc6d9e43954bf-dirty #0
[   62.563074][ T1356] Tainted: [W]=WARN
[   62.566885][ T1356] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 09/13/2024
[   62.576956][ T1356] Workqueue: events_unbound call_usermodehelper_exec_work
[   62.584103][ T1356] Call Trace:
[   62.587392][ T1356]  <TASK>
[   62.590335][ T1356]  dump_stack_lvl+0x116/0x1f0
[   62.595041][ T1356]  __might_resched+0x3c0/0x5e0
[   62.599838][ T1356]  ? __pfx___might_resched+0x10/0x10
[   62.605599][ T1356]  debug_check_no_obj_freed+0x1d9/0x620
[   62.611180][ T1356]  ? __pfx_debug_check_no_obj_freed+0x10/0x10
[   62.617279][ T1356]  ? find_held_lock+0x2d/0x110
[   62.622068][ T1356]  ? release_task+0xd24/0x1b00
[   62.626860][ T1356]  kmem_cache_free+0x27d/0x480
[   62.631646][ T1356]  ? __cleanup_sighand+0x73/0xa0
[   62.636613][ T1356]  __cleanup_sighand+0x73/0xa0
[   62.641397][ T1356]  release_task+0xd2c/0x1b00
[   62.646017][ T1356]  ? __pfx_release_task+0x10/0x10
[   62.651067][ T1356]  ? mark_held_locks+0x9f/0xe0
[   62.655952][ T1356]  wait_consider_task+0x1812/0x4100
[   62.661187][ T1356]  ? rcu_is_watching+0x12/0xc0
[   62.665972][ T1356]  ? __pfx_wait_consider_task+0x10/0x10
[   62.671565][ T1356]  ? do_wait+0x1e9/0x570
[   62.675838][ T1356]  __do_wait+0x744/0x890
[   62.680131][ T1356]  ? do_wait+0x1e9/0x570
[   62.684493][ T1356]  do_wait+0x219/0x570
[   62.688588][ T1356]  kernel_wait+0xa0/0x160
[   62.693208][ T1356]  ? __pfx_kernel_wait+0x10/0x10
[   62.698178][ T1356]  ? __pfx_child_wait_callback+0x10/0x10
[   62.703948][ T1356]  ? lock_acquire+0x2f/0xb0
[   62.708481][ T1356]  call_usermodehelper_exec_work+0xf1/0x170
[   62.714439][ T1356]  process_one_work+0x9c5/0x1ba0
[   62.719521][ T1356]  ? __pfx_lock_acquire.part.0+0x10/0x10
[   62.725190][ T1356]  ? __pfx_process_one_work+0x10/0x10
[   62.730949][ T1356]  ? assign_work+0x1a0/0x250
[   62.735658][ T1356]  worker_thread+0x6c8/0xf00
[   62.740297][ T1356]  ? __kthread_parkme+0x148/0x220
[   62.745435][ T1356]  ? __pfx_worker_thread+0x10/0x10
[   62.750664][ T1356]  kthread+0x2c1/0x3a0
[   62.754751][ T1356]  ? _raw_spin_unlock_irq+0x23/0x50
[   62.759972][ T1356]  ? __pfx_kthread+0x10/0x10
[   62.764597][ T1356]  ret_from_fork+0x45/0x80
[   62.769132][ T1356]  ? __pfx_kthread+0x10/0x10
[   62.773833][ T1356]  ret_from_fork_asm+0x1a/0x30
[   62.779002][ T1356]  </TASK>
[   62.782387][   T29] audit: type=1400 audit(1729585852.429:111): avc:  denied  { mount } for  pid=2665 comm="syz-executor" name="/" dev="proc" ino=1 scontext=root:sysadm_r:sysadm_t tcontext=system_u:object_r:proc_t tclass=filesystem permissive=1
[   63.412330][ T2647] BUG: sleeping function called from invalid context at lib/debugobjects.c:978
[   63.421682][ T2647] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 2647, name: syz-execprog
[   63.430982][ T2647] preempt_count: 1, expected: 0
[   63.435870][ T2647] RCU nest depth: 0, expected: 0
[   63.440891][ T2647] no locks held by syz-execprog/2647.
[   63.446309][ T2647] Preemption disabled at:
[   63.446326][ T2647] [<ffffffff86ef85c0>] schedule+0xe0/0x350
[   63.456663][ T2647] CPU: 0 UID: 0 PID: 2647 Comm: syz-execprog Tainted: G        W          6.12.0-rc4-syzkaller-gc6d9e43954bf-dirty #0
[   63.469062][ T2647] Tainted: [W]=WARN
[   63.472905][ T2647] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 09/13/2024
[   63.483092][ T2647] Call Trace:
[   63.486409][ T2647]  <TASK>
[   63.489380][ T2647]  dump_stack_lvl+0x16c/0x1f0
[   63.494153][ T2647]  __might_resched+0x3c0/0x5e0
[   63.498995][ T2647]  ? __pfx___might_resched+0x10/0x10
[   63.504347][ T2647]  debug_check_no_obj_freed+0x1d9/0x620
[   63.509957][ T2647]  ? page_ext_put+0x3e/0xd0
[   63.514521][ T2647]  ? __pfx_debug_check_no_obj_freed+0x10/0x10
[   63.520741][ T2647]  ? page_ext_put+0x48/0xd0
[   63.525322][ T2647]  free_unref_page+0x1cc/0xb50
[   63.530155][ T2647]  __mmdrop+0xd5/0x460
[   63.534294][ T2647]  finish_task_switch.isra.0+0x584/0xa40
[   63.539995][ T2647]  ? __switch_to+0x749/0x1180
[   63.544828][ T2647]  __schedule+0x1067/0x34b0
[   63.549406][ T2647]  ? __pfx___schedule+0x10/0x10
[   63.554322][ T2647]  ? schedule+0x298/0x350
[   63.558719][ T2647]  ? __pfx_lock_release+0x10/0x10
[   63.563806][ T2647]  ? trace_lock_acquire+0x14a/0x1d0
[   63.569156][ T2647]  ? lock_acquire+0x2f/0xb0
[   63.573822][ T2647]  ? schedule+0x1fd/0x350
[   63.578214][ T2647]  ? do_nanosleep+0x18a/0x510
[   63.583000][ T2647]  schedule+0xe7/0x350
[   63.587126][ T2647]  do_nanosleep+0x216/0x510
[   63.591767][ T2647]  ? __pfx___debug_object_init+0x10/0x10
[   63.597475][ T2647]  ? __pfx_do_nanosleep+0x10/0x10
[   63.602559][ T2647]  ? __asan_memset+0x23/0x50
[   63.607303][ T2647]  ? __hrtimer_init+0x106/0x2c0
[   63.612237][ T2647]  hrtimer_nanosleep+0x146/0x370
[   63.617262][ T2647]  ? __pfx_hrtimer_nanosleep+0x10/0x10
[   63.622788][ T2647]  ? __pfx_hrtimer_wakeup+0x10/0x10
[   63.628143][ T2647]  ? __pfx_get_timespec64+0x10/0x10
[   63.633406][ T2647]  ? __x64_sys_futex+0x1e1/0x4c0
[   63.638398][ T2647]  ? __x64_sys_futex+0x1ea/0x4c0
[   63.643396][ T2647]  __x64_sys_nanosleep+0x21d/0x2b0
[   63.648582][ T2647]  ? __pfx___x64_sys_nanosleep+0x10/0x10
[   63.654297][ T2647]  do_syscall_64+0xcd/0x250
[   63.658881][ T2647]  entry_SYSCALL_64_after_hwframe+0x77/0x7f
[   63.664844][ T2647] RIP: 0033:0x475d57
[   63.668792][ T2647] Code: 8b 44 24 20 b9 40 42 0f 00 f7 f1 48 89 04 24 b8 e8 03 00 00 f7 e2 48 89 44 24 08 48 89 e7 be 00 00 00 00 b8 23 00 00 00 0f 05 <48> 83 c4 10 5d c3 cc cc cc b8 ba 00 00 00 0f 05 89 44 24 08 c3 cc
[   63.688549][ T2647] RSP: 002b:000000c00005ff18 EFLAGS: 00000202 ORIG_RAX: 0000000000000023
[   63.697029][ T2647] RAX: ffffffffffffffda RBX: 0000000000002710 RCX: 0000000000475d57
[   63.705056][ T2647] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 000000c00005ff18
[   63.713088][ T2647] RBP: 000000c00005ff28 R08: 0000000000001c52 R09: 00007ffad9faf080
[   63.721114][ T2647] R10: 0000000000000001 R11: 0000000000000202 R12: 000000c00005ff18
[   63.729176][ T2647] R13: 000000c00007c008 R14: 000000c000006540 R15: 0fffffffffffffff
[   63.737225][ T2647]  </TASK>


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-build1854706326=/tmp/go-build -gno-record-gcc-switches'

git status (err=<nil>)
HEAD detached at cd6fc0a301
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=cd6fc0a3018e5d793bdcca6530622493f5e88307 -X 'github.com/google/syzkaller/prog.gitRevisionDate=20241018-123137'" "-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=\"cd6fc0a3018e5d793bdcca6530622493f5e88307\"
/usr/bin/ld: /tmp/ccRbnj4N.o: in function `test_cover_filter()':
executor.cc:(.text+0x1424b): warning: the use of `tempnam' is dangerous, better use `mkstemp'
/usr/bin/ld: /tmp/ccRbnj4N.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=17f28a5f980000


Tested on:

commit:         c6d9e439 Merge 6.12-rc4 into usb-next
git tree:       https://git.kernel.org/pub/scm/linux/kernel/git/gregkh/usb.git usb-testing
kernel config:  https://syzkaller.appspot.com/x/.config?x=4a2bb21f91d75c65
dashboard link: https://syzkaller.appspot.com/bug?extid=a234c2d63e0c171ca10e
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=13a390a7980000

Powered by blists - more mailing lists