2023-10-31 09:02:44

by syzbot

[permalink] [raw]
Subject: [syzbot] [usb?] INFO: rcu detected stall in raw_ioctl

Hello,

syzbot found the following issue on:

HEAD commit: 9b6db9a3a675 Merge tag 'thunderbolt-for-v6.7-rc1' of git:/..
git tree: https://git.kernel.org/pub/scm/linux/kernel/git/gregkh/usb.git usb-testing
console output: https://syzkaller.appspot.com/x/log.txt?x=13cae767680000
kernel config: https://syzkaller.appspot.com/x/.config?x=a6685a8ab59f5838
dashboard link: https://syzkaller.appspot.com/bug?extid=5f996b83575ef4058638
compiler: gcc (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils for Debian) 2.40

Unfortunately, I don't have any reproducer for this issue yet.

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/a7b1b6a564cc/disk-9b6db9a3.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/a091a2f990e1/vmlinux-9b6db9a3.xz
kernel image: https://storage.googleapis.com/syzbot-assets/5d14ab1c75e4/bzImage-9b6db9a3.xz

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: [email protected]

rcu: INFO: rcu_preempt detected expedited stalls on CPUs/tasks: {
1-....
} 2684 jiffies s: 17493 root: 0x2/.
rcu: blocking rcu_node structures (internal RCU debug):
Sending NMI from CPU 0 to CPUs 1:
lowmem_reserve[]: 0 0 3924 3924
NMI backtrace for cpu 1
CPU: 1 PID: 22191 Comm: syz-executor.1 Not tainted 6.6.0-rc6-syzkaller-00158-g9b6db9a3a675 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/09/2023
RIP: 0010:io_serial_out+0x8f/0xb0 drivers/tty/serial/8250/8250_port.c:424
Code: 48 8d 7d 40 44 89 e1 48 b8 00 00 00 00 00 fc ff df 48 89 fa d3 e3 48 c1 ea 03 80 3c 02 00 75 18 66 03 5d 40 44 89 e8 89 da ee <5b> 5d 41 5c 41 5d c3 e8 e5 49 16 ff eb a4 e8 3e 4a 16 ff eb e1 66
RSP: 0018:ffffc90000198388 EFLAGS: 00000006
RAX: 0000000000000000 RBX: 00000000000003f9 RCX: 0000000000000000
RDX: 00000000000003f9 RSI: ffffffff8283a005 RDI: ffffffff8c156d20
RBP: ffffffff8c156ce0 R08: 0000000000000001 R09: 000000000000001f
R10: 0000000000000000 R11: 205d314320202020 R12: 0000000000000000
R13: 0000000000000000 R14: ffffffff8c156d30 R15: 00000000000000c6
FS: 00007f0ea81f96c0(0000) GS:ffff8881f6700000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f0ea8217ff0 CR3: 000000011831a000 CR4: 00000000003506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<NMI>
</NMI>
<IRQ>
serial_out drivers/tty/serial/8250/8250.h:122 [inline]
serial8250_clear_IER+0x98/0xb0 drivers/tty/serial/8250/8250_port.c:717
serial8250_console_write+0x1e9/0x1060 drivers/tty/serial/8250/8250_port.c:3417
console_emit_next_record kernel/printk/printk.c:2910 [inline]
console_flush_all+0x4eb/0xfb0 kernel/printk/printk.c:2966
console_unlock+0x10c/0x260 kernel/printk/printk.c:3035
vprintk_emit+0x17f/0x5f0 kernel/printk/printk.c:2307
vprintk+0x7b/0x90 kernel/printk/printk_safe.c:45
_printk+0xc8/0x100 kernel/printk/printk.c:2332
show_free_areas+0x1257/0x2140 mm/show_mem.c:353
__show_mem+0x34/0x140 mm/show_mem.c:409
k_spec drivers/tty/vt/keyboard.c:667 [inline]
k_spec+0xea/0x140 drivers/tty/vt/keyboard.c:656
kbd_keycode drivers/tty/vt/keyboard.c:1524 [inline]
kbd_event+0xcc8/0x17c0 drivers/tty/vt/keyboard.c:1543
input_to_handler+0x382/0x4c0 drivers/input/input.c:132
input_pass_values.part.0+0x52f/0x7a0 drivers/input/input.c:161
input_pass_values drivers/input/input.c:148 [inline]
input_event_dispose+0x5ee/0x770 drivers/input/input.c:378
input_handle_event+0x11c/0xd80 drivers/input/input.c:406
input_repeat_key+0x251/0x340 drivers/input/input.c:2263
call_timer_fn+0x19e/0x580 kernel/time/timer.c:1700
expire_timers kernel/time/timer.c:1751 [inline]
__run_timers+0x764/0xb10 kernel/time/timer.c:2022
run_timer_softirq+0x58/0xd0 kernel/time/timer.c:2035
__do_softirq+0x20b/0x94e kernel/softirq.c:553
invoke_softirq kernel/softirq.c:427 [inline]
__irq_exit_rcu kernel/softirq.c:632 [inline]
irq_exit_rcu+0xa7/0x110 kernel/softirq.c:644
sysvec_apic_timer_interrupt+0x8e/0xb0 arch/x86/kernel/apic/apic.c:1074
</IRQ>
<TASK>
asm_sysvec_apic_timer_interrupt+0x1a/0x20 arch/x86/include/asm/idtentry.h:645
RIP: 0010:console_flush_all+0x9e0/0xfb0 kernel/printk/printk.c:2972
Code: 66 19 23 00 9c 5b 81 e3 00 02 00 00 31 ff 48 89 de e8 b4 68 1c 00 48 85 db 0f 85 97 03 00 00 e8 16 6d 1c 00 fb 48 8b 44 24 08 <48> 8b 14 24 0f b6 00 83 e2 07 38 d0 7f 08 84 c0 0f 85 08 05 00 00
RSP: 0018:ffffc9000d37faf0 EFLAGS: 00000293
RAX: fffff52001a6ff89 RBX: 0000000000000000 RCX: 0000000000000000
RDX: ffff888120331d00 RSI: ffffffff8131088a RDI: 0000000000000007
RBP: dffffc0000000000 R08: 0000000000000007 R09: 0000000000000000
R10: 0000000000000000 R11: 205d314320202020 R12: ffffffff88351760
R13: 0000000000000001 R14: ffffffff883517b8 R15: 0000000000000001
console_unlock+0x10c/0x260 kernel/printk/printk.c:3035
vprintk_emit+0x17f/0x5f0 kernel/printk/printk.c:2307
vprintk+0x7b/0x90 kernel/printk/printk_safe.c:45
_printk+0xc8/0x100 kernel/printk/printk.c:2332
usb_gadget_register_driver_owner+0x1c2/0x2d0 drivers/usb/gadget/udc/core.c:1695
raw_ioctl_run drivers/usb/gadget/legacy/raw_gadget.c:559 [inline]
raw_ioctl+0x172f/0x2b80 drivers/usb/gadget/legacy/raw_gadget.c:1266
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:871 [inline]
__se_sys_ioctl fs/ioctl.c:857 [inline]
__x64_sys_ioctl+0x18f/0x210 fs/ioctl.c:857
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x38/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x63/0xcd
RIP: 0033:0x7f0ea8eb884b
Code: 00 48 89 44 24 18 31 c0 48 8d 44 24 60 c7 04 24 10 00 00 00 48 89 44 24 08 48 8d 44 24 20 48 89 44 24 10 b8 10 00 00 00 0f 05 <89> c2 3d 00 f0 ff ff 77 1c 48 8b 44 24 18 64 48 2b 04 25 28 00 00
RSP: 002b:00007f0ea81f6fa0 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 0000000000000004 RCX: 00007f0ea8eb884b
RDX: 0000000000000000 RSI: 0000000000005501 RDI: 0000000000000004
RBP: 00007f0ea81f8070 R08: 0000000000000010 R09: 00312e6364755f79
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007f0ea81f7040 R14: 0000000020000080 R15: 00007f0ea90fcb88
</TASK>
Node 0 Normal free:2722092kB boost:0kB min:6108kB low:10124kB high:14140kB reserved_highatomic:0KB active_anon:56432kB inactive_anon:206832kB active_file:21556kB inactive_file:162020kB unevictable:0kB writepending:48kB present:5242880kB managed:4018384kB mlocked:0kB bounce:0kB free_pcp:6736kB local_pcp:2472kB free_cma:0kB
lowmem_reserve[]: 0 0 0 0
Node 0 DMA: 0*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (M) = 15360kB
Node 0 DMA32: 3*4kB (M) 1*8kB (M) 2*16kB (M) 3*32kB (M) 3*64kB (M) 3*128kB (M) 2*256kB (M) 2*512kB (M) 2*1024kB (M) 1*2048kB (M) 702*4096kB (M) = 2881748kB
Node 0 Normal: 833*4kB (ME) 497*8kB (UME) 242*16kB (ME) 124*32kB (UME) 42*64kB (UME) 9*128kB (ME) 1*256kB (E) 1*512kB (M) 3*1024kB (UME) 2*2048kB (UM) 658*4096kB (M) = 2722092kB
Node 0 hugepages_total=4 hugepages_free=4 hugepages_surp=0 hugepages_size=2048kB
101532 total pagecache pages
0 pages in swap cache
Free swap = 124996kB
Total swap = 124996kB
2097051 pages RAM
0 pages HighMem/MovableOnly
367316 pages reserved
iowarrior 2-1:0.0: iowarrior_callback - usb_submit_urb failed with result -19
Mem-Info:
active_anon:14108 inactive_anon:51414 isolated_anon:0
active_file:5389 inactive_file:40505 isolated_file:0
unevictable:0 dirty:0 writeback:0
slab_reclaimable:5350 slab_unreclaimable:84376
mapped:11391 shmem:55640 pagetables:388
sec_pagetables:0 bounce:0
kernel_misc_reclaimable:0
free:1412738 free_pcp:1798 free_cma:0
Node 0 active_anon:56432kB inactive_anon:205656kB active_file:21556kB inactive_file:162020kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:45564kB dirty:0kB writeback:0kB shmem:222560kB writeback_tmp:0kB kernel_stack:4020kB pagetables:1552kB sec_pagetables:0kB all_unreclaimable? no
Node 0 DMA free:15360kB boost:0kB min:20kB low:32kB high:44kB reserved_highatomic:0KB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15992kB managed:15360kB mlocked:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
lowmem_reserve[]: 0 2814 6738 6738
Node 0 DMA32 free:2881748kB boost:0kB min:4380kB low:7260kB high:10140kB reserved_highatomic:0KB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:3129332kB managed:2885196kB mlocked:0kB bounce:0kB free_pcp:3448kB local_pcp:3384kB free_cma:0kB
lowmem_reserve[]: 0 0 3924 3924
Node 0 Normal free:2753844kB boost:0kB min:6108kB low:10124kB high:14140kB reserved_highatomic:0KB active_anon:56432kB inactive_anon:205576kB active_file:21556kB inactive_file:162020kB unevictable:0kB writepending:0kB present:5242880kB managed:4018384kB mlocked:0kB bounce:0kB free_pcp:5844kB local_pcp:1464kB free_cma:0kB
lowmem_reserve[]: 0 0 0 0
Node 0 DMA: 0*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (M) = 15360kB
Node 0 DMA32: 3*4kB (M) 1*8kB (M) 2*16kB (M) 3*32kB (M) 3*64kB (M) 3*128kB (M) 2*256kB (M) 2*512kB (M) 2*1024kB (M) 1*2048kB (M) 702*4096kB (M) = 2881748kB
Node 0 Normal: 1173*4kB (UME) 658*8kB (UME) 453*16kB (UME) 398*32kB (UME) 131*64kB (UME) 61*128kB (UME) 11*256kB (UME) 5*512kB (UME) 3*1024kB (UME) 2*2048kB (UM) 658*4096kB (M) = 2753844kB
Node 0 hugepages_total=4 hugepages_free=4 hugepages_surp=0 hugepages_size=2048kB
101535 total pagecache pages
0 pages in swap cache
Free swap = 124996kB
Total swap = 124996kB
2097051 pages RAM
0 pages HighMem/MovableOnly
367316 pages reserved
iowarrior 2-1:0.0: iowarrior_callback - usb_submit_urb failed with result -19


---
This report is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at [email protected].

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

If the bug is already fixed, let syzbot know by replying with:
#syz fix: exact-commit-title

If you want to overwrite bug's subsystems, reply with:
#syz set subsystems: new-subsystem
(See the list of subsystem names on the web dashboard)

If the bug is a duplicate of another bug, reply with:
#syz dup: exact-subject-of-another-report

If you want to undo deduplication, reply with:
#syz undup


2024-06-09 00:28:41

by syzbot

[permalink] [raw]
Subject: Re: [syzbot] [usb?] INFO: rcu detected stall in raw_ioctl

syzbot has found a reproducer for the following issue on:

HEAD commit: 8867bbd4a056 mm: arm64: Fix the out-of-bounds issue in con..
git tree: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git for-kernelci
console output: https://syzkaller.appspot.com/x/log.txt?x=10961932980000
kernel config: https://syzkaller.appspot.com/x/.config?x=3b4350cf56c61c80
dashboard link: https://syzkaller.appspot.com/bug?extid=5f996b83575ef4058638
compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
userspace arch: arm64
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=15be6dce980000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=101ca30a980000

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/6ea21f50498b/disk-8867bbd4.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/e2fed09364aa/vmlinux-8867bbd4.xz
kernel image: https://storage.googleapis.com/syzbot-assets/4860173c7a18/Image-8867bbd4.gz.xz

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: [email protected]

cdc_wdm 1-1:1.0: nonzero urb status received: -71
cdc_wdm 1-1:1.0: wdm_int_callback - 0 bytes
cdc_wdm 1-1:1.0: nonzero urb status received: -71
cdc_wdm 1-1:1.0: wdm_int_callback - 0 bytes
watchdog: BUG: soft lockup - CPU#0 stuck for 26s! [syz-executor782:6625]
CPU#0 Utilization every 4s during lockup:
#1: 98% system, 0% softirq, 3% hardirq, 0% idle
#2: 98% system, 0% softirq, 3% hardirq, 0% idle
#3: 98% system, 0% softirq, 3% hardirq, 0% idle
#4: 98% system, 0% softirq, 3% hardirq, 0% idle
#5: 98% system, 1% softirq, 3% hardirq, 0% idle
Modules linked in:
irq event stamp: 73096
hardirqs last enabled at (73095): [<ffff80008037bc00>] console_emit_next_record kernel/printk/printk.c:2935 [inline]
hardirqs last enabled at (73095): [<ffff80008037bc00>] console_flush_all+0x650/0xb74 kernel/printk/printk.c:2994
hardirqs last disabled at (73096): [<ffff80008af10b00>] __el1_irq arch/arm64/kernel/entry-common.c:533 [inline]
hardirqs last disabled at (73096): [<ffff80008af10b00>] el1_interrupt+0x24/0x68 arch/arm64/kernel/entry-common.c:551
softirqs last enabled at (73048): [<ffff8000801ea530>] softirq_handle_end kernel/softirq.c:400 [inline]
softirqs last enabled at (73048): [<ffff8000801ea530>] handle_softirqs+0xa60/0xc34 kernel/softirq.c:582
softirqs last disabled at (73043): [<ffff800080020de8>] __do_softirq+0x14/0x20 kernel/softirq.c:588
CPU: 0 PID: 6625 Comm: syz-executor782 Tainted: G W 6.10.0-rc2-syzkaller-g8867bbd4a056 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 04/02/2024
pstate: 80400005 (Nzcv daif +PAN -UAO -TCO -DIT -SSBS BTYPE=--)
pc : __daif_local_irq_restore arch/arm64/include/asm/irqflags.h:176 [inline]
pc : arch_local_irq_restore arch/arm64/include/asm/irqflags.h:195 [inline]
pc : console_emit_next_record kernel/printk/printk.c:2935 [inline]
pc : console_flush_all+0x67c/0xb74 kernel/printk/printk.c:2994
lr : console_emit_next_record kernel/printk/printk.c:2935 [inline]
lr : console_flush_all+0x678/0xb74 kernel/printk/printk.c:2994
sp : ffff800097d67380
x29: ffff800097d67480 x28: ffff800097d67530 x27: 0000000000000001
x26: ffff80009090b530 x25: ffff80009090b520 x24: dfff800000000000
x23: 1ffff000121216af x22: dfff800000000000 x21: ffff80009090b578
x20: 0000000000000000 x19: 00000000000000c0 x18: ffff800097d672b8
x17: 6965636572207375 x16: ffff80008033878c x15: 0000000000000001
x14: 1ffff00011e379c8 x13: 0000000000000000 x12: 0000000000000003
x11: 0000000000000001 x10: 0000000000ff0100 x9 : 0000000000000000
x8 : ffff0000cdc05ac0 x7 : ffff800080381d44 x6 : 0000000000000000
x5 : 0000000000000001 x4 : 0000000000000001 x3 : 0000000000000000
x2 : 0000000000000006 x1 : 0000000000000080 x0 : 0000000000000000
Call trace:
__daif_local_irq_restore arch/arm64/include/asm/irqflags.h:175 [inline]
arch_local_irq_restore arch/arm64/include/asm/irqflags.h:195 [inline]
console_emit_next_record kernel/printk/printk.c:2935 [inline]
console_flush_all+0x67c/0xb74 kernel/printk/printk.c:2994
console_unlock+0xec/0x3d4 kernel/printk/printk.c:3063
vprintk_emit+0x1ec/0x350 kernel/printk/printk.c:2345
vprintk_default+0xa0/0xe4 kernel/printk/printk.c:2360
vprintk+0x200/0x2d4 kernel/printk/printk_safe.c:45
_printk+0xdc/0x128 kernel/printk/printk.c:2370
usb_gadget_register_driver_owner+0x1f0/0x224 drivers/usb/gadget/udc/core.c:1711
raw_ioctl_run drivers/usb/gadget/legacy/raw_gadget.c:595 [inline]
raw_ioctl+0x10c0/0x33bc drivers/usb/gadget/legacy/raw_gadget.c:1306
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:907 [inline]
__se_sys_ioctl fs/ioctl.c:893 [inline]
__arm64_sys_ioctl+0x14c/0x1c8 fs/ioctl.c:893
__invoke_syscall arch/arm64/kernel/syscall.c:34 [inline]
invoke_syscall+0x98/0x2b8 arch/arm64/kernel/syscall.c:48
el0_svc_common+0x130/0x23c arch/arm64/kernel/syscall.c:133
do_el0_svc+0x48/0x58 arch/arm64/kernel/syscall.c:152
el0_svc+0x54/0x168 arch/arm64/kernel/entry-common.c:712
el0t_64_sync_handler+0x84/0xfc arch/arm64/kernel/entry-common.c:730
el0t_64_sync+0x190/0x194 arch/arm64/kernel/entry.S:598


---
If you want syzbot to run the reproducer, reply with:
#syz test: git://repo/address.git branch-or-commit-hash
If you attach or paste a git patch, syzbot will apply it before testing.

2024-06-09 01:57:45

by Alan Stern

[permalink] [raw]
Subject: Re: [syzbot] [usb?] INFO: rcu detected stall in raw_ioctl

On Sat, Jun 08, 2024 at 05:28:26PM -0700, syzbot wrote:
> syzbot has found a reproducer for the following issue on:
>
> HEAD commit: 8867bbd4a056 mm: arm64: Fix the out-of-bounds issue in con..
> git tree: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git for-kernelci
> console output: https://syzkaller.appspot.com/x/log.txt?x=10961932980000
> kernel config: https://syzkaller.appspot.com/x/.config?x=3b4350cf56c61c80
> dashboard link: https://syzkaller.appspot.com/bug?extid=5f996b83575ef4058638
> compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
> userspace arch: arm64
> syz repro: https://syzkaller.appspot.com/x/repro.syz?x=15be6dce980000
> C reproducer: https://syzkaller.appspot.com/x/repro.c?x=101ca30a980000
>
> Downloadable assets:
> disk image: https://storage.googleapis.com/syzbot-assets/6ea21f50498b/disk-8867bbd4.raw.xz
> vmlinux: https://storage.googleapis.com/syzbot-assets/e2fed09364aa/vmlinux-8867bbd4.xz
> kernel image: https://storage.googleapis.com/syzbot-assets/4860173c7a18/Image-8867bbd4.gz.xz
>
> IMPORTANT: if you fix the issue, please add the following tag to the commit:
> Reported-by: [email protected]
>
> cdc_wdm 1-1:1.0: nonzero urb status received: -71
> cdc_wdm 1-1:1.0: wdm_int_callback - 0 bytes
> cdc_wdm 1-1:1.0: nonzero urb status received: -71
> cdc_wdm 1-1:1.0: wdm_int_callback - 0 bytes
> watchdog: BUG: soft lockup - CPU#0 stuck for 26s! [syz-executor782:6625]

#syz test: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git 8867bbd4a056

Index: usb-devel/drivers/usb/class/cdc-wdm.c
===================================================================
--- usb-devel.orig/drivers/usb/class/cdc-wdm.c
+++ usb-devel/drivers/usb/class/cdc-wdm.c
@@ -260,6 +260,9 @@ static void wdm_int_callback(struct urb
case -ESHUTDOWN:
case -ENOENT:
case -ECONNRESET:
+ case -EPROTO:
+ case -EILSEQ:
+ case -ETIME:
return; /* unplug */
case -EPIPE:
set_bit(WDM_INT_STALL, &desc->flags);

2024-06-09 04:41:17

by syzbot

[permalink] [raw]
Subject: Re: [syzbot] [usb?] INFO: rcu detected stall in raw_ioctl

Hello,

syzbot has tested the proposed patch and the reproducer did not trigger any issue:

Reported-and-tested-by: [email protected]

Tested on:

commit: 8867bbd4 mm: arm64: Fix the out-of-bounds issue in con..
git tree: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=11f0680a980000
kernel config: https://syzkaller.appspot.com/x/.config?x=3b4350cf56c61c80
dashboard link: https://syzkaller.appspot.com/bug?extid=5f996b83575ef4058638
compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
userspace arch: arm64
patch: https://syzkaller.appspot.com/x/patch.diff?x=118743fc980000

Note: testing is done by a robot and is best-effort only.

2024-06-10 17:25:06

by Alan Stern

[permalink] [raw]
Subject: Re: [syzbot] [usb?] INFO: rcu detected stall in raw_ioctl

On Sat, Jun 08, 2024 at 09:41:04PM -0700, syzbot wrote:
> Hello,
>
> syzbot has tested the proposed patch and the reproducer did not trigger any issue:
>
> Reported-and-tested-by: [email protected]
>
> Tested on:
>
> commit: 8867bbd4 mm: arm64: Fix the out-of-bounds issue in con..
> git tree: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git
> console output: https://syzkaller.appspot.com/x/log.txt?x=11f0680a980000
> kernel config: https://syzkaller.appspot.com/x/.config?x=3b4350cf56c61c80
> dashboard link: https://syzkaller.appspot.com/bug?extid=5f996b83575ef4058638
> compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
> userspace arch: arm64
> patch: https://syzkaller.appspot.com/x/patch.diff?x=118743fc980000
>
> Note: testing is done by a robot and is best-effort only.

I'd like to determine the reason behind this entire class of bugs. As
far as I can see, the design of dummy-hcd shouldn't allow them to occur.

Alan Stern

#syz test: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git 8867bbd4a056

Index: usb-devel/drivers/usb/gadget/udc/dummy_hcd.c
===================================================================
--- usb-devel.orig/drivers/usb/gadget/udc/dummy_hcd.c
+++ usb-devel/drivers/usb/gadget/udc/dummy_hcd.c
@@ -1826,6 +1826,7 @@ static void dummy_timer(struct timer_lis
break;
dum->ep[i].already_seen = 0;
}
+ dev_info(dummy_dev(dum_hcd), "Timer handler\n");

restart:
list_for_each_entry_safe(urbp, tmp, &dum_hcd->urbp_list, urbp_list) {
@@ -1835,6 +1836,9 @@ restart:
struct dummy_ep *ep = NULL;
int status = -EINPROGRESS;

+ dev_info(dummy_dev(dum_hcd), "urbp %p %x next_frame %p\n",
+ urbp, urbp->urb->pipe, dum_hcd->next_frame_urbp);
+
/* stop when we reach URBs queued after the timer interrupt */
if (urbp == dum_hcd->next_frame_urbp)
break;

2024-06-10 17:58:36

by syzbot

[permalink] [raw]
Subject: Re: [syzbot] [usb?] INFO: rcu detected stall in raw_ioctl

Hello,

syzbot has tested the proposed patch but the reproducer is still triggering an issue:
BUG: soft lockup in raw_ioctl

dummy_hcd dummy_hcd.0: urbp 000000006bf6c1dd 40409880 next_frame 0000000000000000
cdc_wdm 1-1:1.0: nonzero urb status received: -71
cdc_wdm 1-1:1.0: wdm_int_callback - 0 bytes
dummy_hcd dummy_hcd.0: urbp 000000003f481f40 40409880 next_frame 000000003f481f40
watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [syz-executor415:10796]
CPU#0 Utilization every 4s during lockup:
#1: 95% system, 1% softirq, 5% hardirq, 0% idle
#2: 95% system, 1% softirq, 5% hardirq, 0% idle
#3: 95% system, 2% softirq, 5% hardirq, 0% idle
#4: 95% system, 1% softirq, 5% hardirq, 0% idle
#5: 95% system, 2% softirq, 5% hardirq, 0% idle
Modules linked in:
irq event stamp: 223968
hardirqs last enabled at (223967): [<ffff80008037bc00>] console_emit_next_record kernel/printk/printk.c:2935 [inline]
hardirqs last enabled at (223967): [<ffff80008037bc00>] console_flush_all+0x650/0xb74 kernel/printk/printk.c:2994
hardirqs last disabled at (223968): [<ffff80008af10ec0>] __el1_irq arch/arm64/kernel/entry-common.c:533 [inline]
hardirqs last disabled at (223968): [<ffff80008af10ec0>] el1_interrupt+0x24/0x68 arch/arm64/kernel/entry-common.c:551
softirqs last enabled at (223962): [<ffff8000801ea530>] softirq_handle_end kernel/softirq.c:400 [inline]
softirqs last enabled at (223962): [<ffff8000801ea530>] handle_softirqs+0xa60/0xc34 kernel/softirq.c:582
softirqs last disabled at (223957): [<ffff800080020de8>] __do_softirq+0x14/0x20 kernel/softirq.c:588
CPU: 0 PID: 10796 Comm: syz-executor415 Tainted: G W 6.10.0-rc2-syzkaller-00003-g8867bbd4a056-dirty #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 04/02/2024
pstate: 80400005 (Nzcv daif +PAN -UAO -TCO -DIT -SSBS BTYPE=--)
pc : __daif_local_irq_restore arch/arm64/include/asm/irqflags.h:176 [inline]
pc : arch_local_irq_restore arch/arm64/include/asm/irqflags.h:195 [inline]
pc : console_emit_next_record kernel/printk/printk.c:2935 [inline]
pc : console_flush_all+0x67c/0xb74 kernel/printk/printk.c:2994
lr : console_emit_next_record kernel/printk/printk.c:2935 [inline]
lr : console_flush_all+0x678/0xb74 kernel/printk/printk.c:2994
sp : ffff80009c6d7380
x29: ffff80009c6d7480 x28: ffff80009c6d7530 x27: 0000000000000001
x26: ffff80009090b530 x25: ffff80009090b520 x24: dfff800000000000
x23: 1ffff000121216af x22: dfff800000000000 x21: ffff80009090b578
x20: 0000000000000000 x19: 00000000000000c0 x18: ffff80009c6d72b8
x17: 000000302e646368 x16: ffff80008033878c x15: 0000000000000001
x14: 1ffff00011e379c8 x13: 0000000000000000 x12: 0000000000000003
x11: 0000000000000001 x10: 0000000000ff0100 x9 : 0000000000000000
x8 : ffff0000dac7bc80 x7 : ffff800080381d44 x6 : 0000000000000000
x5 : 0000000000000001 x4 : 0000000000000001 x3 : 0000000000000000
x2 : 0000000000000006 x1 : 0000000000000080 x0 : 0000000000000000
Call trace:
__daif_local_irq_restore arch/arm64/include/asm/irqflags.h:175 [inline]
arch_local_irq_restore arch/arm64/include/asm/irqflags.h:195 [inline]
console_emit_next_record kernel/printk/printk.c:2935 [inline]
console_flush_all+0x67c/0xb74 kernel/printk/printk.c:2994
console_unlock+0xec/0x3d4 kernel/printk/printk.c:3063
vprintk_emit+0x1ec/0x350 kernel/printk/printk.c:2345
vprintk_default+0xa0/0xe4 kernel/printk/printk.c:2360
vprintk+0x200/0x2d4 kernel/printk/printk_safe.c:45
_printk+0xdc/0x128 kernel/printk/printk.c:2370
usb_gadget_register_driver_owner+0x1f0/0x224 drivers/usb/gadget/udc/core.c:1711
raw_ioctl_run drivers/usb/gadget/legacy/raw_gadget.c:595 [inline]
raw_ioctl+0x10c0/0x33bc drivers/usb/gadget/legacy/raw_gadget.c:1306
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:907 [inline]
__se_sys_ioctl fs/ioctl.c:893 [inline]
__arm64_sys_ioctl+0x14c/0x1c8 fs/ioctl.c:893
__invoke_syscall arch/arm64/kernel/syscall.c:34 [inline]
invoke_syscall+0x98/0x2b8 arch/arm64/kernel/syscall.c:48
el0_svc_common+0x130/0x23c arch/arm64/kernel/syscall.c:133
do_el0_svc+0x48/0x58 arch/arm64/kernel/syscall.c:152
el0_svc+0x54/0x168 arch/arm64/kernel/entry-common.c:712
el0t_64_sync_handler+0x84/0xfc arch/arm64/kernel/entry-common.c:730
el0t_64_sync+0x190/0x194 arch/arm64/kernel/entry.S:598
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 532 Comm: kworker/u8:6 Tainted: G W 6.10.0-rc2-syzkaller-00003-g8867bbd4a056-dirty #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 04/02/2024
Workqueue: bat_events batadv_nc_worker
pstate: 60400005 (nZCv daif +PAN -UAO -TCO -DIT -SSBS BTYPE=--)
pc : lock_release+0x500/0x9cc
lr : lockdep_recursion_finish kernel/locking/lockdep.c:467 [inline]
lr : lock_release+0x4c4/0x9cc kernel/locking/lockdep.c:5776
sp : ffff8000988e78e0
x29: ffff8000988e79b0 x28: ffff80008f1c76a0 x27: dfff800000000000
x26: 1fffe00018cc6517 x25: ffff0000c6632910 x24: ffff0000c6631e40
x23: ffff0000c66328b8 x22: 00000000ffe2000d x21: 73559e3b58d8591b
x20: 0000000000000002 x19: ffff0001b3db6000 x18: 1fffe000367b6bde
x17: ffff80008efed000 x16: ffff80008af15aa8 x15: 0000000000000001
x14: ffff80008eff0558 x13: dfff800000000000 x12: 000000001635a668
x11: 0000000061619286 x10: 0000000000ff0100 x9 : ffff80008ef36000
x8 : 0000000000000000 x7 : ffff80008ac4e1b0 x6 : 0000000000000000
x5 : 0000000000000000 x4 : 0000000000000000 x3 : 0000000000000002
x2 : 0000000000000008 x1 : 0000000000000080 x0 : 0000000000000001
Call trace:
__daif_local_irq_restore arch/arm64/include/asm/irqflags.h:175 [inline]
arch_local_irq_restore arch/arm64/include/asm/irqflags.h:195 [inline]
lock_release+0x500/0x9cc kernel/locking/lockdep.c:5777
rcu_lock_release+0x2c/0x38 include/linux/rcupdate.h:339
rcu_read_unlock include/linux/rcupdate.h:812 [inline]
batadv_nc_process_nc_paths+0x28c/0x324 net/batman-adv/network-coding.c:699
batadv_nc_worker+0x3c4/0x580 net/batman-adv/network-coding.c:728
process_one_work+0x7b0/0x15e8 kernel/workqueue.c:3231
process_scheduled_works kernel/workqueue.c:3312 [inline]
worker_thread+0x938/0xef4 kernel/workqueue.c:3393
kthread+0x288/0x310 kernel/kthread.c:389
ret_from_fork+0x10/0x20 arch/arm64/kernel/entry.S:860


Tested on:

commit: 8867bbd4 mm: arm64: Fix the out-of-bounds issue in con..
git tree: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=137ec67a980000
kernel config: https://syzkaller.appspot.com/x/.config?x=3b4350cf56c61c80
dashboard link: https://syzkaller.appspot.com/bug?extid=5f996b83575ef4058638
compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
userspace arch: arm64
patch: https://syzkaller.appspot.com/x/patch.diff?x=151eb522980000


2024-06-10 19:43:12

by Alan Stern

[permalink] [raw]
Subject: Re: [syzbot] [usb?] INFO: rcu detected stall in raw_ioctl

On Mon, Jun 10, 2024 at 10:58:02AM -0700, syzbot wrote:
> Hello,
>
> syzbot has tested the proposed patch but the reproducer is still triggering an issue:
> BUG: soft lockup in raw_ioctl
>
> dummy_hcd dummy_hcd.0: urbp 000000006bf6c1dd 40409880 next_frame 0000000000000000
> cdc_wdm 1-1:1.0: nonzero urb status received: -71
> cdc_wdm 1-1:1.0: wdm_int_callback - 0 bytes
> dummy_hcd dummy_hcd.0: urbp 000000003f481f40 40409880 next_frame 000000003f481f40
> watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [syz-executor415:10796]

The full console log shows that the cdc-wm and dummy-hcd loop uses less
than 60 microseconds out of every 2400 or so. That's not enough to
cause this. Something else must be going on.

> Call trace:
> __daif_local_irq_restore arch/arm64/include/asm/irqflags.h:175 [inline]
> arch_local_irq_restore arch/arm64/include/asm/irqflags.h:195 [inline]
> console_emit_next_record kernel/printk/printk.c:2935 [inline]
> console_flush_all+0x67c/0xb74 kernel/printk/printk.c:2994
> console_unlock+0xec/0x3d4 kernel/printk/printk.c:3063
> vprintk_emit+0x1ec/0x350 kernel/printk/printk.c:2345
> vprintk_default+0xa0/0xe4 kernel/printk/printk.c:2360
> vprintk+0x200/0x2d4 kernel/printk/printk_safe.c:45
> _printk+0xdc/0x128 kernel/printk/printk.c:2370
> usb_gadget_register_driver_owner+0x1f0/0x224 drivers/usb/gadget/udc/core.c:1711

Is this a coincidence? If CPU #0 is getting stuck, why here? Line 1711
is a mutex_unlock() call; it shouldn't take long. This doesn't seem to
make sense.

Let's try to find out what the CPU is really doing when this happens.

Alan Stern

#syz test: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git 8867bbd4a056

Index: usb-devel/drivers/usb/gadget/udc/dummy_hcd.c
===================================================================
--- usb-devel.orig/drivers/usb/gadget/udc/dummy_hcd.c
+++ usb-devel/drivers/usb/gadget/udc/dummy_hcd.c
@@ -1826,6 +1826,7 @@ static void dummy_timer(struct timer_lis
break;
dum->ep[i].already_seen = 0;
}
+ dev_info(dummy_dev(dum_hcd), "Timer handler\n");

restart:
list_for_each_entry_safe(urbp, tmp, &dum_hcd->urbp_list, urbp_list) {
@@ -1835,6 +1836,9 @@ restart:
struct dummy_ep *ep = NULL;
int status = -EINPROGRESS;

+ dev_info(dummy_dev(dum_hcd), "urbp %p %x next_frame %p\n",
+ urbp, urbp->urb->pipe, dum_hcd->next_frame_urbp);
+
/* stop when we reach URBs queued after the timer interrupt */
if (urbp == dum_hcd->next_frame_urbp)
break;
Index: usb-devel/drivers/usb/class/cdc-wdm.c
===================================================================
--- usb-devel.orig/drivers/usb/class/cdc-wdm.c
+++ usb-devel/drivers/usb/class/cdc-wdm.c
@@ -112,6 +112,7 @@ struct wdm_device {

enum wwan_port_type wwanp_type;
struct wwan_port *wwanp;
+ int alancount;
};

static struct usb_driver wdm_driver;
@@ -255,6 +256,14 @@ static void wdm_int_callback(struct urb
desc = urb->context;
dr = (struct usb_cdc_notification *)desc->sbuf;

+ if (status == -EPROTO) {
+ if (desc->alancount >= 1)
+ return;
+ ++desc->alancount;
+ dev_info(&desc->intf->dev, "Alan test\n");
+ dump_stack();
+ }
+
if (status) {
switch (status) {
case -ESHUTDOWN:

2024-06-10 20:12:14

by syzbot

[permalink] [raw]
Subject: Re: [syzbot] [usb?] INFO: rcu detected stall in raw_ioctl

Hello,

syzbot has tested the proposed patch and the reproducer did not trigger any issue:

Reported-and-tested-by: [email protected]

Tested on:

commit: 8867bbd4 mm: arm64: Fix the out-of-bounds issue in con..
git tree: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=15f51bce980000
kernel config: https://syzkaller.appspot.com/x/.config?x=3b4350cf56c61c80
dashboard link: https://syzkaller.appspot.com/bug?extid=5f996b83575ef4058638
compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
userspace arch: arm64
patch: https://syzkaller.appspot.com/x/patch.diff?x=151b5fce980000

Note: testing is done by a robot and is best-effort only.

2024-06-11 15:21:12

by Alan Stern

[permalink] [raw]
Subject: Re: [syzbot] [usb?] INFO: rcu detected stall in raw_ioctl

On Mon, Jun 10, 2024 at 01:12:03PM -0700, syzbot wrote:
> Hello,
>
> syzbot has tested the proposed patch and the reproducer did not trigger any issue:
>
> Reported-and-tested-by: [email protected]
>
> Tested on:
>
> commit: 8867bbd4 mm: arm64: Fix the out-of-bounds issue in con..
> git tree: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git
> console output: https://syzkaller.appspot.com/x/log.txt?x=15f51bce980000
> kernel config: https://syzkaller.appspot.com/x/.config?x=3b4350cf56c61c80
> dashboard link: https://syzkaller.appspot.com/bug?extid=5f996b83575ef4058638
> compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
> userspace arch: arm64
> patch: https://syzkaller.appspot.com/x/patch.diff?x=151b5fce980000
>
> Note: testing is done by a robot and is best-effort only.

That's not much use. Let's see what happens without all the error
messages filling up the log, and let's test how well the timer emulation
works.

The kernel config has CONFIG_HZ set to 100, which is not a very good
value for dummy-hcd although it should still work. But the
multiple-millisecond intervals between timer interrupts are worrisome.

Alan Stern

#syz test: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git 8867bbd4a056

Index: usb-devel/drivers/usb/class/cdc-wdm.c
===================================================================
--- usb-devel.orig/drivers/usb/class/cdc-wdm.c
+++ usb-devel/drivers/usb/class/cdc-wdm.c
@@ -265,18 +265,11 @@ static void wdm_int_callback(struct urb
set_bit(WDM_INT_STALL, &desc->flags);
dev_err(&desc->intf->dev, "Stall on int endpoint\n");
goto sw; /* halt is cleared in work */
- default:
- dev_err(&desc->intf->dev,
- "nonzero urb status received: %d\n", status);
- break;
}
}

- if (urb->actual_length < sizeof(struct usb_cdc_notification)) {
- dev_err(&desc->intf->dev, "wdm_int_callback - %d bytes\n",
- urb->actual_length);
+ if (urb->actual_length < sizeof(struct usb_cdc_notification))
goto exit;
- }

switch (dr->bNotificationType) {
case USB_CDC_NOTIFY_RESPONSE_AVAILABLE:
Index: usb-devel/drivers/usb/gadget/legacy/raw_gadget.c
===================================================================
--- usb-devel.orig/drivers/usb/gadget/legacy/raw_gadget.c
+++ usb-devel/drivers/usb/gadget/legacy/raw_gadget.c
@@ -596,8 +596,6 @@ static int raw_ioctl_run(struct raw_dev

spin_lock_irqsave(&dev->lock, flags);
if (ret) {
- dev_err(dev->dev,
- "fail, usb_gadget_register_driver returned %d\n", ret);
dev->state = STATE_DEV_FAILED;
goto out_unlock;
}
Index: usb-devel/drivers/usb/gadget/udc/core.c
===================================================================
--- usb-devel.orig/drivers/usb/gadget/udc/core.c
+++ usb-devel/drivers/usb/gadget/udc/core.c
@@ -1699,8 +1699,6 @@ int usb_gadget_register_driver_owner(str
mutex_lock(&udc_lock);
if (!driver->is_bound) {
if (driver->match_existing_only) {
- pr_warn("%s: couldn't find an available UDC or it's busy\n",
- driver->function);
ret = -EBUSY;
} else {
pr_info("%s: couldn't find an available UDC\n",
Index: usb-devel/drivers/usb/gadget/udc/dummy_hcd.c
===================================================================
--- usb-devel.orig/drivers/usb/gadget/udc/dummy_hcd.c
+++ usb-devel/drivers/usb/gadget/udc/dummy_hcd.c
@@ -989,12 +989,42 @@ static DEVICE_ATTR_RO(function);
* for each driver that registers: just add to a big root hub.
*/

+static struct timer_list alan_timer;
+static int alan_count;
+#define ALAN_MAX 20
+
+static void alan_callback(struct timer_list *t)
+{
+ if (++alan_count >= ALAN_MAX)
+ return;
+ mod_timer(&alan_timer, jiffies + msecs_to_jiffies(1));
+}
+
+static void test_alan_timer(void)
+{
+ int alan_prev;
+
+ alan_prev = alan_count = 0;
+ mod_timer(&alan_timer, jiffies + msecs_to_jiffies(1));
+ for (;;) {
+ if (alan_prev != alan_count) {
+ alan_prev = alan_count;
+ pr_info("alan_count %d\n", alan_prev);
+ if (alan_prev >= ALAN_MAX)
+ break;
+ }
+ cpu_relax();
+ }
+}
+
static int dummy_udc_start(struct usb_gadget *g,
struct usb_gadget_driver *driver)
{
struct dummy_hcd *dum_hcd = gadget_to_dummy_hcd(g);
struct dummy *dum = dum_hcd->dum;

+ test_alan_timer();
+
switch (g->speed) {
/* All the speeds we support */
case USB_SPEED_LOW:
@@ -2769,6 +2799,8 @@ static int __init dummy_hcd_init(void)
int i;
struct dummy *dum[MAX_NUM_UDC] = {};

+ timer_setup(&alan_timer, alan_callback, TIMER_PINNED);
+
if (usb_disabled())
return -ENODEV;


2024-06-11 15:53:19

by syzbot

[permalink] [raw]
Subject: Re: [syzbot] [usb?] INFO: rcu detected stall in raw_ioctl

Hello,

syzbot has tested the proposed patch and the reproducer did not trigger any issue:

Reported-and-tested-by: [email protected]

Tested on:

commit: 8867bbd4 mm: arm64: Fix the out-of-bounds issue in con..
git tree: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=11bcfa36980000
kernel config: https://syzkaller.appspot.com/x/.config?x=3b4350cf56c61c80
dashboard link: https://syzkaller.appspot.com/bug?extid=5f996b83575ef4058638
compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
userspace arch: arm64
patch: https://syzkaller.appspot.com/x/patch.diff?x=17790922980000

Note: testing is done by a robot and is best-effort only.

2024-06-11 17:26:30

by Alan Stern

[permalink] [raw]
Subject: Re: [syzbot] [usb?] INFO: rcu detected stall in raw_ioctl

On Tue, Jun 11, 2024 at 08:53:02AM -0700, syzbot wrote:
> Hello,
>
> syzbot has tested the proposed patch and the reproducer did not trigger any issue:
>
> Reported-and-tested-by: [email protected]
>
> Tested on:
>
> commit: 8867bbd4 mm: arm64: Fix the out-of-bounds issue in con..
> git tree: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git
> console output: https://syzkaller.appspot.com/x/log.txt?x=11bcfa36980000
> kernel config: https://syzkaller.appspot.com/x/.config?x=3b4350cf56c61c80
> dashboard link: https://syzkaller.appspot.com/bug?extid=5f996b83575ef4058638
> compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
> userspace arch: arm64
> patch: https://syzkaller.appspot.com/x/patch.diff?x=17790922980000
>
> Note: testing is done by a robot and is best-effort only.

The interval between adjacent timer interrupts is consistently 20 ms.
Longer than expected, but it shouldn't be deadly. Perhaps it would have
been smaller if I hadn't pinned all the interrupts to the same CPU.

Anyway, let's see what happens with the dev_err() calls in the interrupt
handler changed to dev_dbg(). That ought to reduce the overhead
considerably.

Alan Stern

#syz test: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git 8867bbd4a056

Index: usb-devel/drivers/usb/class/cdc-wdm.c
===================================================================
--- usb-devel.orig/drivers/usb/class/cdc-wdm.c
+++ usb-devel/drivers/usb/class/cdc-wdm.c
@@ -266,14 +266,14 @@ static void wdm_int_callback(struct urb
dev_err(&desc->intf->dev, "Stall on int endpoint\n");
goto sw; /* halt is cleared in work */
default:
- dev_err(&desc->intf->dev,
+ dev_dbg(&desc->intf->dev,
"nonzero urb status received: %d\n", status);
break;
}
}

if (urb->actual_length < sizeof(struct usb_cdc_notification)) {
- dev_err(&desc->intf->dev, "wdm_int_callback - %d bytes\n",
+ dev_dbg(&desc->intf->dev, "wdm_int_callback - %d bytes\n",
urb->actual_length);
goto exit;
}


2024-06-11 18:15:50

by syzbot

[permalink] [raw]
Subject: Re: [syzbot] [usb?] INFO: rcu detected stall in raw_ioctl

Hello,

syzbot has tested the proposed patch and the reproducer did not trigger any issue:

Reported-and-tested-by: [email protected]

Tested on:

commit: 8867bbd4 mm: arm64: Fix the out-of-bounds issue in con..
git tree: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=14e092de980000
kernel config: https://syzkaller.appspot.com/x/.config?x=3b4350cf56c61c80
dashboard link: https://syzkaller.appspot.com/bug?extid=5f996b83575ef4058638
compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
userspace arch: arm64
patch: https://syzkaller.appspot.com/x/patch.diff?x=137c697e980000

Note: testing is done by a robot and is best-effort only.

2024-06-12 14:38:22

by Alan Stern

[permalink] [raw]
Subject: Re: [syzbot] [usb?] INFO: rcu detected stall in raw_ioctl

On Tue, Jun 11, 2024 at 11:03:03AM -0700, syzbot wrote:
> Hello,
>
> syzbot has tested the proposed patch and the reproducer did not trigger any issue:
>
> Reported-and-tested-by: [email protected]
>
> Tested on:
>
> commit: 8867bbd4 mm: arm64: Fix the out-of-bounds issue in con..
> git tree: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git
> console output: https://syzkaller.appspot.com/x/log.txt?x=14e092de980000
> kernel config: https://syzkaller.appspot.com/x/.config?x=3b4350cf56c61c80
> dashboard link: https://syzkaller.appspot.com/bug?extid=5f996b83575ef4058638
> compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
> userspace arch: arm64
> patch: https://syzkaller.appspot.com/x/patch.diff?x=137c697e980000
>
> Note: testing is done by a robot and is best-effort only.

Let's try Greg's suggestion to replace dev_err() with
dev_err_ratelimited().

Alan Stern

Index: usb-devel/drivers/usb/class/cdc-wdm.c
===================================================================
--- usb-devel.orig/drivers/usb/class/cdc-wdm.c
+++ usb-devel/drivers/usb/class/cdc-wdm.c
@@ -266,14 +266,14 @@ static void wdm_int_callback(struct urb
dev_err(&desc->intf->dev, "Stall on int endpoint\n");
goto sw; /* halt is cleared in work */
default:
- dev_err(&desc->intf->dev,
+ dev_err_ratelimited(&desc->intf->dev,
"nonzero urb status received: %d\n", status);
break;
}
}

if (urb->actual_length < sizeof(struct usb_cdc_notification)) {
- dev_err(&desc->intf->dev, "wdm_int_callback - %d bytes\n",
+ dev_err_ratelimited(&desc->intf->dev, "wdm_int_callback - %d bytes\n",
urb->actual_length);
goto exit;
}


2024-06-13 01:23:31

by Alan Stern

[permalink] [raw]
Subject: Re: [syzbot] [usb?] INFO: rcu detected stall in raw_ioctl

Try again, with the "#syz test:" command present this time. Sigh.

On Tue, Jun 11, 2024 at 11:03:03AM -0700, syzbot wrote:
> Hello,
>
> syzbot has tested the proposed patch and the reproducer did not trigger any issue:
>
> Reported-and-tested-by: [email protected]
>
> Tested on:
>
> commit: 8867bbd4 mm: arm64: Fix the out-of-bounds issue in con..
> git tree: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git
> console output: https://syzkaller.appspot.com/x/log.txt?x=14e092de980000
> kernel config: https://syzkaller.appspot.com/x/.config?x=3b4350cf56c61c80
> dashboard link: https://syzkaller.appspot.com/bug?extid=5f996b83575ef4058638
> compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
> userspace arch: arm64
> patch: https://syzkaller.appspot.com/x/patch.diff?x=137c697e980000
>
> Note: testing is done by a robot and is best-effort only.

Let's try Greg's suggestion to replace dev_err() with
dev_err_ratelimited().

Alan Stern

#syz test: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git 8867bbd4a056

Index: usb-devel/drivers/usb/class/cdc-wdm.c
===================================================================
--- usb-devel.orig/drivers/usb/class/cdc-wdm.c
+++ usb-devel/drivers/usb/class/cdc-wdm.c
@@ -266,14 +266,14 @@ static void wdm_int_callback(struct urb
dev_err(&desc->intf->dev, "Stall on int endpoint\n");
goto sw; /* halt is cleared in work */
default:
- dev_err(&desc->intf->dev,
+ dev_err_ratelimited(&desc->intf->dev,
"nonzero urb status received: %d\n", status);
break;
}
}

if (urb->actual_length < sizeof(struct usb_cdc_notification)) {
- dev_err(&desc->intf->dev, "wdm_int_callback - %d bytes\n",
+ dev_err_ratelimited(&desc->intf->dev, "wdm_int_callback - %d bytes\n",
urb->actual_length);
goto exit;
}



2024-06-13 03:44:58

by syzbot

[permalink] [raw]
Subject: Re: [syzbot] [usb?] INFO: rcu detected stall in raw_ioctl

Hello,

syzbot has tested the proposed patch and the reproducer did not trigger any issue:

Reported-and-tested-by: [email protected]

Tested on:

commit: 8867bbd4 mm: arm64: Fix the out-of-bounds issue in con..
git tree: git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=179339ca980000
kernel config: https://syzkaller.appspot.com/x/.config?x=3b4350cf56c61c80
dashboard link: https://syzkaller.appspot.com/bug?extid=5f996b83575ef4058638
compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
userspace arch: arm64
patch: https://syzkaller.appspot.com/x/patch.diff?x=14ad2856980000

Note: testing is done by a robot and is best-effort only.