Re: [syzbot] [usb?] INFO: task hung in usb_port_suspend

From: syzbot
Date: Fri Oct 11 2024 - 10:35:24 EST


Hello,

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

ice)
[ 3.002225][ T1] ACPI: Added _OSI(3.0 _SCP Extensions)
[ 3.003059][ T1] ACPI: Added _OSI(Processor Aggregator Device)
[ 3.085420][ T12] Callback from call_rcu_tasks() invoked.
[ 3.276952][ T1] ACPI: 2 ACPI AML tables successfully acquired and loaded
[ 3.314462][ T1] ACPI: _OSC evaluation for CPUs failed, trying _PDC
[ 3.348039][ T1] ACPI: Interpreter enabled
[ 3.350335][ T1] ACPI: PM: (supports S0 S3 S4 S5)
[ 3.352134][ T1] ACPI: Using IOAPIC for interrupt routing
[ 3.354599][ T1] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[ 3.355296][ T1] PCI: Ignoring E820 reservations for host bridge windows
[ 3.367249][ T1] ACPI: Enabled 16 GPEs in block 00 to 0F
[ 3.746048][ T1] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
[ 3.747443][ T1] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3]
[ 3.749086][ T1] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI]
[ 3.753239][ T1] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended configuration space under this bridge
[ 3.790190][ T1] PCI host bridge to bus 0000:00
[ 3.791637][ T1] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
[ 3.792856][ T1] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
[ 3.794311][ T1] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
[ 3.795302][ T1] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfefff window]
[ 3.797357][ T1] pci_bus 0000:00: root bus resource [bus 00-ff]
[ 3.800192][ T1] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 conventional PCI endpoint
[ 3.811190][ T1] pci 0000:00:01.0: [8086:7110] type 00 class 0x060100 conventional PCI endpoint
[ 3.851850][ T1] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 conventional PCI endpoint
[ 3.879292][ T1] pci 0000:00:01.3: quirk: [io 0xb000-0xb03f] claimed by PIIX4 ACPI
[ 3.890132][ T1] pci 0000:00:03.0: [1af4:1004] type 00 class 0x000000 conventional PCI endpoint
[ 3.902150][ T1] pci 0000:00:03.0: BAR 0 [io 0xc000-0xc03f]
[ 3.912077][ T1] pci 0000:00:03.0: BAR 1 [mem 0xfe800000-0xfe80007f]
[ 3.943377][ T1] pci 0000:00:04.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
[ 3.955285][ T1] pci 0000:00:04.0: BAR 0 [io 0xc040-0xc07f]
[ 3.963126][ T1] pci 0000:00:04.0: BAR 1 [mem 0xfe801000-0xfe80107f]
[ 3.989371][ T1] pci 0000:00:05.0: [1ae0:a002] type 00 class 0x030000 conventional PCI endpoint
[ 3.999276][ T1] pci 0000:00:05.0: BAR 0 [mem 0xfe000000-0xfe7fffff]
[ 4.030695][ T1] pci 0000:00:05.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
[ 4.040832][ T1] pci 0000:00:06.0: [1af4:1002] type 00 class 0x00ff00 conventional PCI endpoint
[ 4.052403][ T1] pci 0000:00:06.0: BAR 0 [io 0xc080-0xc09f]
[ 4.083310][ T1] pci 0000:00:07.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
[ 4.098317][ T1] pci 0000:00:07.0: BAR 0 [io 0xc0a0-0xc0bf]
[ 4.107225][ T1] pci 0000:00:07.0: BAR 1 [mem 0xfe802000-0xfe80203f]
[ 4.200337][ T1] ACPI: PCI: Interrupt link LNKA configured for IRQ 10
[ 4.213761][ T1] ACPI: PCI: Interrupt link LNKB configured for IRQ 10
[ 4.227312][ T1] ACPI: PCI: Interrupt link LNKC configured for IRQ 11
[ 4.241372][ T1] ACPI: PCI: Interrupt link LNKD configured for IRQ 11
[ 4.248294][ T1] ACPI: PCI: Interrupt link LNKS configured for IRQ 9
[ 4.283168][ T1] iommu: Default domain type: Translated
[ 4.284430][ T1] iommu: DMA domain TLB invalidation policy: lazy mode
[ 4.291847][ T1] SCSI subsystem initialized
[ 4.298163][ T1] ACPI: bus type USB registered
[ 4.300417][ T1] usbcore: registered new interface driver usbfs
[ 4.302000][ T1] usbcore: registered new interface driver hub
[ 4.303838][ T1] usbcore: registered new device driver usb
[ 4.308961][ T1] mc: Linux media interface: v0.10
[ 4.310673][ T1] videodev: Linux video capture interface: v2.00
[ 4.314068][ T1] pps_core: LinuxPPS API ver. 1 registered
[ 4.315288][ T1] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@xxxxxxxx>
[ 4.317429][ T1] PTP clock support registered
[ 4.321082][ T1] EDAC MC: Ver: 3.0.0
[ 4.331906][ T1] Advanced Linux Sound Architecture Driver Initialized.
[ 4.345666][ T1] Bluetooth: Core ver 2.22
[ 4.347724][ T1] NET: Registered PF_BLUETOOTH protocol family
[ 4.349885][ T1] Bluetooth: HCI device and connection manager initialized
[ 4.352264][ T1] Bluetooth: HCI socket layer initialized
[ 4.353522][ T1] Bluetooth: L2CAP socket layer initialized
[ 4.355359][ T1] Bluetooth: SCO socket layer initialized
[ 4.357435][ T1] NET: Registered PF_ATMPVC protocol family
[ 4.359810][ T1] NET: Registered PF_ATMSVC protocol family
[ 4.362356][ T1] NetLabel: Initializing
[ 4.363887][ T1] NetLabel: domain hash size = 128
[ 4.365276][ T1] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO
[ 4.368668][ T1] NetLabel: unlabeled traffic allowed by default
[ 4.375910][ T1] nfc: nfc_init: NFC Core ver 0.1
[ 4.378232][ T1] NET: Registered PF_NFC protocol family
[ 4.380020][ T1] PCI: Using ACPI for IRQ routing
[ 4.383469][ T1] pci 0000:00:05.0: vgaarb: setting as boot VGA device
[ 4.385257][ T1] pci 0000:00:05.0: vgaarb: bridge control possible
[ 4.385257][ T1] pci 0000:00:05.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
[ 4.385284][ T1] vgaarb: loaded
[ 4.406926][ T1] clocksource: Switched to clocksource kvm-clock
[ 4.415109][ T1] VFS: Disk quotas dquot_6.6.0
[ 4.415313][ T1] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[ 4.420224][ T1] pnp: PnP ACPI init
[ 4.469015][ T1] pnp: PnP ACPI: found 7 devices
[ 4.555551][ T1] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
[ 4.571683][ T1] NET: Registered PF_INET protocol family
[ 4.577543][ T1] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[ 4.593539][ T1] ------------[ cut here ]------------
[ 4.595293][ T1] refcount_t: decrement hit 0; leaking memory.
[ 4.596951][ T1] WARNING: CPU: 0 PID: 1 at lib/refcount.c:31 refcount_warn_saturate+0x1ed/0x210
[ 4.599957][ T1] Modules linked in:
[ 4.601156][ T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 6.9.0-rc2-syzkaller-00078-g920e7522e3ba #0
[ 4.603368][ T1] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 09/13/2024
[ 4.606363][ T1] RIP: 0010:refcount_warn_saturate+0x1ed/0x210
[ 4.609070][ T1] Code: 87 e8 27 0e ce fe 90 0f 0b 90 90 e9 c3 fe ff ff e8 d8 d6 07 ff c6 05 11 98 b3 07 01 90 48 c7 c7 40 02 26 87 e8 04 0e ce fe 90 <0f> 0b 90 90 e9 a0 fe ff ff 48 89 ef e8 42 f7 5c ff e9 44 fe ff ff
[ 4.613673][ T1] RSP: 0000:ffffc9000001fba0 EFLAGS: 00010282
[ 4.614899][ T1] RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffffffff811a05b9
[ 4.616158][ T1] RDX: ffff8881012a8000 RSI: ffffffff811a05c6 RDI: 0000000000000001
[ 4.618038][ T1] RBP: ffff88810a6a06cc R08: 0000000000000001 R09: 0000000000000000
[ 4.619549][ T1] R10: 0000000000000000 R11: 0000000000000001 R12: ffff88810a6a06cc
[ 4.620938][ T1] R13: 0000000000000000 R14: 0000000000d60059 R15: ffff8881068d5f28
[ 4.622631][ T1] FS: 0000000000000000(0000) GS:ffff8881f5800000(0000) knlGS:0000000000000000
[ 4.624581][ T1] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 4.625763][ T1] CR2: ffff88823ffff000 CR3: 000000000889e000 CR4: 00000000003506f0
[ 4.627528][ T1] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 4.628776][ T1] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 4.631108][ T1] Call Trace:
[ 4.631680][ T1] <TASK>
[ 4.632515][ T1] ? show_regs+0x8c/0xa0
[ 4.633661][ T1] ? __warn+0xe5/0x3c0
[ 4.635168][ T1] ? __wake_up_klogd.part.0+0x99/0xf0
[ 4.636612][ T1] ? refcount_warn_saturate+0x1ed/0x210
[ 4.637520][ T1] ? report_bug+0x3c0/0x580
[ 4.638548][ T1] ? handle_bug+0x3d/0x70
[ 4.639596][ T1] ? exc_invalid_op+0x17/0x50
[ 4.640935][ T1] ? asm_exc_invalid_op+0x1a/0x20
[ 4.642371][ T1] ? __warn_printk+0x199/0x350
[ 4.643107][ T1] ? __warn_printk+0x1a6/0x350
[ 4.644886][ T1] ? refcount_warn_saturate+0x1ed/0x210
[ 4.645992][ T1] __reset_page_owner+0x2ea/0x370
[ 4.646949][ T1] __free_pages_ok+0x5db/0xbf0
[ 4.648332][ T1] ? __split_page_owner+0xdd/0x120
[ 4.649331][ T1] make_alloc_exact+0x165/0x260
[ 4.650432][ T1] alloc_large_system_hash+0x4e0/0x640
[ 4.651653][ T1] inet_hashinfo2_init+0x4b/0xd0
[ 4.653240][ T1] tcp_init+0xba/0x9f0
[ 4.654195][ T1] inet_init+0x419/0x6f0
[ 4.655067][ T1] ? __pfx_inet_init+0x10/0x10
[ 4.656148][ T1] do_one_initcall+0x128/0x700
[ 4.657254][ T1] ? __pfx_do_one_initcall+0x10/0x10
[ 4.658290][ T1] ? trace_kmalloc+0x2d/0xe0
[ 4.659168][ T1] ? __kmalloc+0x213/0x400
[ 4.659995][ T1] kernel_init_freeable+0x69d/0xca0
[ 4.661086][ T1] ? __pfx_kernel_init+0x10/0x10
[ 4.662386][ T1] kernel_init+0x1c/0x2b0
[ 4.663173][ T1] ? __pfx_kernel_init+0x10/0x10
[ 4.664120][ T1] ret_from_fork+0x45/0x80
[ 4.665027][ T1] ? __pfx_kernel_init+0x10/0x10
[ 4.665837][ T1] ret_from_fork_asm+0x1a/0x30
[ 4.666808][ T1] </TASK>
[ 4.667817][ T1] Kernel panic - not syncing: kernel: panic_on_warn set ...
[ 4.669094][ T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 6.9.0-rc2-syzkaller-00078-g920e7522e3ba #0
[ 4.670996][ T1] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 09/13/2024
[ 4.672099][ T1] Call Trace:
[ 4.672099][ T1] <TASK>
[ 4.672099][ T1] dump_stack_lvl+0x3d/0x1f0
[ 4.672099][ T1] panic+0x6f5/0x7a0
[ 4.672099][ T1] ? __pfx_panic+0x10/0x10
[ 4.672099][ T1] ? show_trace_log_lvl+0x363/0x500
[ 4.672099][ T1] ? check_panic_on_warn+0x1f/0xb0
[ 4.672099][ T1] ? refcount_warn_saturate+0x1ed/0x210
[ 4.672099][ T1] check_panic_on_warn+0xab/0xb0
[ 4.672099][ T1] __warn+0xf1/0x3c0
[ 4.672099][ T1] ? __wake_up_klogd.part.0+0x99/0xf0
[ 4.672099][ T1] ? refcount_warn_saturate+0x1ed/0x210
[ 4.672099][ T1] report_bug+0x3c0/0x580
[ 4.672099][ T1] handle_bug+0x3d/0x70
[ 4.672099][ T1] exc_invalid_op+0x17/0x50
[ 4.672099][ T1] asm_exc_invalid_op+0x1a/0x20
[ 4.672099][ T1] RIP: 0010:refcount_warn_saturate+0x1ed/0x210
[ 4.672099][ T1] Code: 87 e8 27 0e ce fe 90 0f 0b 90 90 e9 c3 fe ff ff e8 d8 d6 07 ff c6 05 11 98 b3 07 01 90 48 c7 c7 40 02 26 87 e8 04 0e ce fe 90 <0f> 0b 90 90 e9 a0 fe ff ff 48 89 ef e8 42 f7 5c ff e9 44 fe ff ff
[ 4.672099][ T1] RSP: 0000:ffffc9000001fba0 EFLAGS: 00010282
[ 4.672099][ T1] RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffffffff811a05b9
[ 4.672099][ T1] RDX: ffff8881012a8000 RSI: ffffffff811a05c6 RDI: 0000000000000001
[ 4.672099][ T1] RBP: ffff88810a6a06cc R08: 0000000000000001 R09: 0000000000000000
[ 4.672099][ T1] R10: 0000000000000000 R11: 0000000000000001 R12: ffff88810a6a06cc
[ 4.672099][ T1] R13: 0000000000000000 R14: 0000000000d60059 R15: ffff8881068d5f28
[ 4.672099][ T1] ? __warn_printk+0x199/0x350
[ 4.672099][ T1] ? __warn_printk+0x1a6/0x350
[ 4.672099][ T1] __reset_page_owner+0x2ea/0x370
[ 4.672099][ T1] __free_pages_ok+0x5db/0xbf0
[ 4.672099][ T1] ? __split_page_owner+0xdd/0x120
[ 4.672099][ T1] make_alloc_exact+0x165/0x260
[ 4.672099][ T1] alloc_large_system_hash+0x4e0/0x640
[ 4.672099][ T1] inet_hashinfo2_init+0x4b/0xd0
[ 4.672099][ T1] tcp_init+0xba/0x9f0
[ 4.672099][ T1] inet_init+0x419/0x6f0
[ 4.672099][ T1] ? __pfx_inet_init+0x10/0x10
[ 4.672099][ T1] do_one_initcall+0x128/0x700
[ 4.672099][ T1] ? __pfx_do_one_initcall+0x10/0x10
[ 4.672099][ T1] ? trace_kmalloc+0x2d/0xe0
[ 4.721681][ T1] ? __kmalloc+0x213/0x400
[ 4.721681][ T1] kernel_init_freeable+0x69d/0xca0
[ 4.721681][ T1] ? __pfx_kernel_init+0x10/0x10
[ 4.721681][ T1] kernel_init+0x1c/0x2b0
[ 4.721681][ T1] ? __pfx_kernel_init+0x10/0x10
[ 4.721681][ T1] ret_from_fork+0x45/0x80
[ 4.721681][ T1] ? __pfx_kernel_init+0x10/0x10
[ 4.721681][ T1] ret_from_fork_asm+0x1a/0x30
[ 4.721681][ T1] </TASK>
[ 4.721681][ 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-2/linux/gopath/pkg/mod'
GONOPROXY=''
GONOSUMDB=''
GOOS='linux'
GOPATH='/syzkaller/jobs-2/linux/gopath'
GOPRIVATE=''
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/syzkaller/jobs-2/linux/gopath/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.1.linux-amd64'
GOSUMDB='sum.golang.org'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/syzkaller/jobs-2/linux/gopath/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.1.linux-amd64/pkg/tool/linux_amd64'
GOVCS=''
GOVERSION='go1.22.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 -ffile-prefix-map=/tmp/go-build204408742=/tmp/go-build -gno-record-gcc-switches'

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


Tested on:

commit: 920e7522 usb: gadget: function: Remove usage of the de..
git tree: https://git.kernel.org/pub/scm/linux/kernel/git/gregkh/usb.git
kernel config: https://syzkaller.appspot.com/x/.config?x=5508c3b3c58f53
dashboard link: https://syzkaller.appspot.com/bug?extid=f342ea16c9d06d80b585
compiler: gcc (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils for Debian) 2.40

Note: no patches were applied.