2019-11-21 14:49:39

by syzbot

[permalink] [raw]
Subject: INFO: rcu detected stall in hub_event

Hello,

syzbot found the following crash on:

HEAD commit: 46178223 usb: gadget: add raw-gadget interface
git tree: https://github.com/google/kasan.git usb-fuzzer
console output: https://syzkaller.appspot.com/x/log.txt?x=15a05836e00000
kernel config: https://syzkaller.appspot.com/x/.config?x=99c88c44660624e7
dashboard link: https://syzkaller.appspot.com/bug?extid=ec5f884c4a135aa0dbb9
compiler: gcc (GCC) 9.0.0 20181231 (experimental)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=1061395ae00000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=13653d1ce00000

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

rcu: INFO: rcu_sched self-detected stall on CPU
rcu: 0-....: (10499 ticks this GP) idle=8ea/1/0x4000000000000002
softirq=1810/1810 fqs=5108
(t=10500 jiffies g=1553 q=595)
NMI backtrace for cpu 0
CPU: 0 PID: 12 Comm: kworker/0:1 Not tainted 5.4.0-rc6+ #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Workqueue: usb_hub_wq hub_event
Call Trace:
<IRQ>
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0xca/0x13e lib/dump_stack.c:113
nmi_cpu_backtrace.cold+0x55/0x96 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x1b0/0x1c7 lib/nmi_backtrace.c:62
trigger_single_cpu_backtrace include/linux/nmi.h:164 [inline]
rcu_dump_cpu_stacks+0x169/0x1b3 kernel/rcu/tree_stall.h:254
print_cpu_stall kernel/rcu/tree_stall.h:455 [inline]
check_cpu_stall kernel/rcu/tree_stall.h:529 [inline]
rcu_pending kernel/rcu/tree.c:2795 [inline]
rcu_sched_clock_irq.cold+0x4da/0x936 kernel/rcu/tree.c:2244
update_process_times+0x25/0x60 kernel/time/timer.c:1726
tick_sched_handle+0x9b/0x180 kernel/time/tick-sched.c:167
tick_sched_timer+0x42/0x130 kernel/time/tick-sched.c:1299
__run_hrtimer kernel/time/hrtimer.c:1514 [inline]
__hrtimer_run_queues+0x303/0xc60 kernel/time/hrtimer.c:1576
hrtimer_interrupt+0x2e8/0x730 kernel/time/hrtimer.c:1638
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1110 [inline]
smp_apic_timer_interrupt+0xf5/0x500 arch/x86/kernel/apic/apic.c:1135
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:830
</IRQ>
RIP: 0010:hid_apply_multiplier drivers/hid/hid-core.c:1058 [inline]
RIP: 0010:hid_setup_resolution_multiplier+0x33b/0x990
drivers/hid/hid-core.c:1114
Code: e8 2a 96 ed fc 48 8d 7d 04 48 89 f8 48 c1 e8 03 42 0f b6 14 38 48 89
f8 83 e0 07 83 c0 03 38 d0 7c 08 84 d2 0f 85 0c 05 00 00 <44> 8b 6d 04 bf
02 00 00 00 44 89 ee e8 64 97 ed fc 41 83 fd 02 74
RSP: 0018:ffff8881da226cd8 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff13
RAX: 0000000000000007 RBX: 0000000000000000 RCX: ffffffff8450902c
RDX: 0000000000000000 RSI: ffffffff84509036 RDI: ffff8881d4df1204
RBP: ffff8881d4df1200 R08: ffff8881da211800 R09: ffffc900004770cc
R10: fffff5200009241b R11: ffffc900004920db R12: ffff8881c6640000
R13: 0000000000000000 R14: ffff8881d4df1200 R15: dffffc0000000000
hid_open_report+0x438/0x640 drivers/hid/hid-core.c:1225
hid_parse include/linux/hid.h:1017 [inline]
ms_probe+0x12d/0x4d0 drivers/hid/hid-microsoft.c:388
hid_device_probe+0x2be/0x3f0 drivers/hid/hid-core.c:2212
really_probe+0x281/0x6d0 drivers/base/dd.c:548
driver_probe_device+0x104/0x210 drivers/base/dd.c:721
__device_attach_driver+0x1c2/0x220 drivers/base/dd.c:828
bus_for_each_drv+0x162/0x1e0 drivers/base/bus.c:430
__device_attach+0x217/0x360 drivers/base/dd.c:894
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:490
device_add+0xae6/0x16f0 drivers/base/core.c:2202
hid_add_device drivers/hid/hid-core.c:2368 [inline]
hid_add_device+0x33c/0x9a0 drivers/hid/hid-core.c:2317
usbhid_probe+0xa81/0xfa0 drivers/hid/usbhid/hid-core.c:1386
usb_probe_interface+0x305/0x7a0 drivers/usb/core/driver.c:361
really_probe+0x281/0x6d0 drivers/base/dd.c:548
driver_probe_device+0x104/0x210 drivers/base/dd.c:721
__device_attach_driver+0x1c2/0x220 drivers/base/dd.c:828
bus_for_each_drv+0x162/0x1e0 drivers/base/bus.c:430
__device_attach+0x217/0x360 drivers/base/dd.c:894
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:490
device_add+0xae6/0x16f0 drivers/base/core.c:2202
usb_set_configuration+0xdf6/0x1670 drivers/usb/core/message.c:2023
generic_probe+0x9d/0xd5 drivers/usb/core/generic.c:210
usb_probe_device+0x99/0x100 drivers/usb/core/driver.c:266
really_probe+0x281/0x6d0 drivers/base/dd.c:548
driver_probe_device+0x104/0x210 drivers/base/dd.c:721
__device_attach_driver+0x1c2/0x220 drivers/base/dd.c:828
bus_for_each_drv+0x162/0x1e0 drivers/base/bus.c:430
__device_attach+0x217/0x360 drivers/base/dd.c:894
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:490
device_add+0xae6/0x16f0 drivers/base/core.c:2202
usb_new_device.cold+0x6a4/0xe79 drivers/usb/core/hub.c:2537
hub_port_connect drivers/usb/core/hub.c:5184 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5324 [inline]
port_event drivers/usb/core/hub.c:5470 [inline]
hub_event+0x1df8/0x3800 drivers/usb/core/hub.c:5552
process_one_work+0x92b/0x1530 kernel/workqueue.c:2269
process_scheduled_works kernel/workqueue.c:2331 [inline]
worker_thread+0x7ab/0xe20 kernel/workqueue.c:2417
kthread+0x318/0x420 kernel/kthread.c:255
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352


---
This bug 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 bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
syzbot can test patches for this bug, for details see:
https://goo.gl/tpsmEJ#testing-patches


2019-11-22 16:53:25

by Alan Stern

[permalink] [raw]
Subject: Re: INFO: rcu detected stall in hub_event

On Thu, 21 Nov 2019, syzbot wrote:

> Hello,
>
> syzbot found the following crash on:
>
> HEAD commit: 46178223 usb: gadget: add raw-gadget interface
> git tree: https://github.com/google/kasan.git usb-fuzzer
> console output: https://syzkaller.appspot.com/x/log.txt?x=15a05836e00000
> kernel config: https://syzkaller.appspot.com/x/.config?x=99c88c44660624e7
> dashboard link: https://syzkaller.appspot.com/bug?extid=ec5f884c4a135aa0dbb9
> compiler: gcc (GCC) 9.0.0 20181231 (experimental)
> syz repro: https://syzkaller.appspot.com/x/repro.syz?x=1061395ae00000
> C reproducer: https://syzkaller.appspot.com/x/repro.c?x=13653d1ce00000
>
> IMPORTANT: if you fix the bug, please add the following tag to the commit:
> Reported-by: [email protected]
>
> rcu: INFO: rcu_sched self-detected stall on CPU

> RIP: 0010:hid_apply_multiplier drivers/hid/hid-core.c:1058 [inline]
> RIP: 0010:hid_setup_resolution_multiplier+0x33b/0x990
> drivers/hid/hid-core.c:1114

Diagnostic patch.

#syz test: https://github.com/google/kasan.git 46178223

drivers/hid/hid-core.c | 17 +++++++++++++++--
1 file changed, 15 insertions(+), 2 deletions(-)

Index: usb-devel/drivers/hid/hid-core.c
===================================================================
--- usb-devel.orig/drivers/hid/hid-core.c
+++ usb-devel/drivers/hid/hid-core.c
@@ -1055,8 +1055,13 @@ static void hid_apply_multiplier(struct
*/
multiplier_collection = &hid->collection[multiplier->usage->collection_index];
while (multiplier_collection->parent_idx != -1 &&
- multiplier_collection->type != HID_COLLECTION_LOGICAL)
+ multiplier_collection->type != HID_COLLECTION_LOGICAL) {
+ hid_info(hid, "collection %d %px parent %d\n",
+ multiplier_collection - hid->collection, multiplier_collection,
+ multiplier_collection->parent_idx);
multiplier_collection = &hid->collection[multiplier_collection->parent_idx];
+ }
+ hid_info(hid, "Got collection\n");

effective_multiplier = hid_calculate_multiplier(hid, multiplier);

@@ -1069,6 +1074,7 @@ static void hid_apply_multiplier(struct
effective_multiplier);
}
}
+ hid_info(hid, "Applied multiplier\n");
}

/*
@@ -1103,16 +1109,23 @@ void hid_setup_resolution_multiplier(str

rep_enum = &hid->report_enum[HID_FEATURE_REPORT];
list_for_each_entry(rep, &rep_enum->report_list, list) {
+ hid_info(hid, "Start report %px maxfield %d\n",
+ rep, rep->maxfield);
for (i = 0; i < rep->maxfield; i++) {
/* Ignore if report count is out of bounds. */
if (rep->field[i]->report_count < 1)
continue;

+ hid_info(hid, "Field %d %px maxusage %d\n",
+ i, rep->field[i], rep->field[i]->maxusage);
for (j = 0; j < rep->field[i]->maxusage; j++) {
usage = &rep->field[i]->usage[j];
- if (usage->hid == HID_GD_RESOLUTION_MULTIPLIER)
+ if (usage->hid == HID_GD_RESOLUTION_MULTIPLIER) {
+ hid_info(hid, "Usage %d %px\n",
+ j, usage);
hid_apply_multiplier(hid,
rep->field[i]);
+ }
}
}
}

2019-11-22 21:35:13

by Andrey Konovalov

[permalink] [raw]
Subject: Re: INFO: rcu detected stall in hub_event

On Sat, Nov 23, 2019 at 1:51 AM Alan Stern <[email protected]> wrote:
>
> On Thu, 21 Nov 2019, syzbot wrote:
>
> > Hello,
> >
> > syzbot found the following crash on:
> >
> > HEAD commit: 46178223 usb: gadget: add raw-gadget interface
> > git tree: https://github.com/google/kasan.git usb-fuzzer
> > console output: https://syzkaller.appspot.com/x/log.txt?x=15a05836e00000
> > kernel config: https://syzkaller.appspot.com/x/.config?x=99c88c44660624e7
> > dashboard link: https://syzkaller.appspot.com/bug?extid=ec5f884c4a135aa0dbb9
> > compiler: gcc (GCC) 9.0.0 20181231 (experimental)
> > syz repro: https://syzkaller.appspot.com/x/repro.syz?x=1061395ae00000
> > C reproducer: https://syzkaller.appspot.com/x/repro.c?x=13653d1ce00000
> >
> > IMPORTANT: if you fix the bug, please add the following tag to the commit:
> > Reported-by: [email protected]
> >
> > rcu: INFO: rcu_sched self-detected stall on CPU
>
> > RIP: 0010:hid_apply_multiplier drivers/hid/hid-core.c:1058 [inline]
> > RIP: 0010:hid_setup_resolution_multiplier+0x33b/0x990
> > drivers/hid/hid-core.c:1114

I'm not sure, but the stack trace reminds me of this issue, so this
report might be related:

https://groups.google.com/d/msg/syzkaller-bugs/X0zVbh8aFEM/NsPcshjxBgAJ

>
> Diagnostic patch.
>
> #syz test: https://github.com/google/kasan.git 46178223
>
> drivers/hid/hid-core.c | 17 +++++++++++++++--
> 1 file changed, 15 insertions(+), 2 deletions(-)
>
> Index: usb-devel/drivers/hid/hid-core.c
> ===================================================================
> --- usb-devel.orig/drivers/hid/hid-core.c
> +++ usb-devel/drivers/hid/hid-core.c
> @@ -1055,8 +1055,13 @@ static void hid_apply_multiplier(struct
> */
> multiplier_collection = &hid->collection[multiplier->usage->collection_index];
> while (multiplier_collection->parent_idx != -1 &&
> - multiplier_collection->type != HID_COLLECTION_LOGICAL)
> + multiplier_collection->type != HID_COLLECTION_LOGICAL) {
> + hid_info(hid, "collection %d %px parent %d\n",
> + multiplier_collection - hid->collection, multiplier_collection,
> + multiplier_collection->parent_idx);
> multiplier_collection = &hid->collection[multiplier_collection->parent_idx];
> + }
> + hid_info(hid, "Got collection\n");
>
> effective_multiplier = hid_calculate_multiplier(hid, multiplier);
>
> @@ -1069,6 +1074,7 @@ static void hid_apply_multiplier(struct
> effective_multiplier);
> }
> }
> + hid_info(hid, "Applied multiplier\n");
> }
>
> /*
> @@ -1103,16 +1109,23 @@ void hid_setup_resolution_multiplier(str
>
> rep_enum = &hid->report_enum[HID_FEATURE_REPORT];
> list_for_each_entry(rep, &rep_enum->report_list, list) {
> + hid_info(hid, "Start report %px maxfield %d\n",
> + rep, rep->maxfield);
> for (i = 0; i < rep->maxfield; i++) {
> /* Ignore if report count is out of bounds. */
> if (rep->field[i]->report_count < 1)
> continue;
>
> + hid_info(hid, "Field %d %px maxusage %d\n",
> + i, rep->field[i], rep->field[i]->maxusage);
> for (j = 0; j < rep->field[i]->maxusage; j++) {
> usage = &rep->field[i]->usage[j];
> - if (usage->hid == HID_GD_RESOLUTION_MULTIPLIER)
> + if (usage->hid == HID_GD_RESOLUTION_MULTIPLIER) {
> + hid_info(hid, "Usage %d %px\n",
> + j, usage);
> hid_apply_multiplier(hid,
> rep->field[i]);
> + }
> }
> }
> }
>

2019-11-23 20:21:27

by syzbot

[permalink] [raw]
Subject: Re: INFO: rcu detected stall in hub_event

Hello,

syzbot has tested the proposed patch but the reproducer still triggered
crash:
INFO: rcu detected stall in hub_event

rcu: INFO: rcu_sched self-detected stall on CPU
rcu: 1-...!: (10494 ticks this GP) idle=5aa/1/0x4000000000000002
softirq=3913/3913 fqs=1
(t=10500 jiffies g=2825 q=35)
rcu: RCU grace-period kthread stack dump:
running task
29704 10 2 0x80004000
Call Trace:
schedule+0xca/0x250 kernel/sched/core.c:4136
schedule_timeout+0x440/0xb20 kernel/time/timer.c:1895
rcu_gp_fqs_loop kernel/rcu/tree.c:1639 [inline]
rcu_gp_kthread+0xaff/0x29e0 kernel/rcu/tree.c:1799
kthread+0x318/0x420 kernel/kthread.c:255
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Workqueue: usb_hub_wq hub_event
Call Trace:
nmi_cpu_backtrace.cold+0x55/0x96 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x1b0/0x1c7 lib/nmi_backtrace.c:62
trigger_single_cpu_backtrace include/linux/nmi.h:164 [inline]
rcu_dump_cpu_stacks+0x169/0x1b3 kernel/rcu/tree_stall.h:254
print_cpu_stall kernel/rcu/tree_stall.h:455 [inline]
check_cpu_stall kernel/rcu/tree_stall.h:529 [inline]
rcu_pending kernel/rcu/tree.c:2795 [inline]
rcu_sched_clock_irq.cold+0x4da/0x936 kernel/rcu/tree.c:2244
update_process_times+0x25/0x60 kernel/time/timer.c:1726
tick_sched_handle+0x9b/0x180 kernel/time/tick-sched.c:167
tick_sched_timer+0x42/0x130 kernel/time/tick-sched.c:1299
__run_hrtimer kernel/time/hrtimer.c:1514 [inline]
__hrtimer_run_queues+0x303/0xc60 kernel/time/hrtimer.c:1576
hrtimer_interrupt+0x2e8/0x730 kernel/time/hrtimer.c:1638
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1110 [inline]
smp_apic_timer_interrupt+0xf5/0x500 arch/x86/kernel/apic/apic.c:1135
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:830
</IRQ>
Code: 00 83 fb ff 75 d6 e9 db fc ff ff e8 9d 7b 15 00 e8 68 a8 1a 00 41 56
9d e9 b1 fd ff ff e8 8b 7b 15 00 e8 56 a8 1a 00 41 56 9d <e9> 2a ff ff ff
0f 1f 40 00 66 2e 0f 1f 84 00 00 00 00 00 55 48 89
RSP: 0018:ffff8881d932e908 EFLAGS: 00000293 ORIG_RAX: ffffffffffffff13
RDX: 0000000000000000 RSI: ffff8881da24e918 RDI: ffff8881da24e84c
R10: fffffbfff11aadad R11: ffffffff88d56d6f R12: 0000000000000045
R13: ffff8881da211800 R14: 0000000000000293 R15: 0000000000000000
dev_vprintk_emit+0x4fc/0x541 drivers/base/core.c:3315
dev_printk_emit+0xba/0xf1 drivers/base/core.c:3326
__dev_printk+0x1db/0x203 drivers/base/core.c:3338
_dev_info+0xd7/0x109 drivers/base/core.c:3384
hid_parse include/linux/hid.h:1017 [inline]
ms_probe+0x12d/0x4d0 drivers/hid/hid-microsoft.c:388
hid_device_probe+0x2be/0x3f0 drivers/hid/hid-core.c:2225
driver_probe_device+0x104/0x210 drivers/base/dd.c:721
__device_attach+0x217/0x360 drivers/base/dd.c:894
device_add+0xae6/0x16f0 drivers/base/core.c:2202
hid_add_device drivers/hid/hid-core.c:2381 [inline]
hid_add_device+0x33c/0x9a0 drivers/hid/hid-core.c:2330
usb_probe_interface+0x305/0x7a0 drivers/usb/core/driver.c:361
driver_probe_device+0x104/0x210 drivers/base/dd.c:721
__device_attach_driver+0x1c2/0x220 drivers/base/dd.c:828
bus_for_each_drv+0x162/0x1e0 drivers/base/bus.c:430
__device_attach+0x217/0x360 drivers/base/dd.c:894
usb_set_configuration+0xdf6/0x1670 drivers/usb/core/message.c:2023
generic_probe+0x9d/0xd5 drivers/usb/core/generic.c:210
usb_probe_device+0x99/0x100 drivers/usb/core/driver.c:266
driver_probe_device+0x104/0x210 drivers/base/dd.c:721
__device_attach_driver+0x1c2/0x220 drivers/base/dd.c:828
bus_for_each_drv+0x162/0x1e0 drivers/base/bus.c:430
__device_attach+0x217/0x360 drivers/base/dd.c:894
bus_probe_device+0x1e4/0x290 drivers/base/bus.c:490
device_add+0xae6/0x16f0 drivers/base/core.c:2202
usb_new_device.cold+0x6a4/0xe79 drivers/usb/core/hub.c:2537
hub_port_connect drivers/usb/core/hub.c:5184 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5324 [inline]
port_event drivers/usb/core/hub.c:5470 [inline]
hub_event+0x1df8/0x3800 drivers/usb/core/hub.c:5552
process_one_work+0x92b/0x1530 kernel/workqueue.c:2269
process_scheduled_works kernel/workqueue.c:2331 [inline]
worker_thread+0x7ab/0xe20 kernel/workqueue.c:2417
kthread+0x318/0x420 kernel/kthread.c:255


Tested on:

commit: 46178223 usb: gadget: add raw-gadget interface
git tree: https://github.com/google/kasan.git
console output: https://syzkaller.appspot.com/x/log.txt?x=12ee73cee00000
kernel config: https://syzkaller.appspot.com/x/.config?x=99c88c44660624e7
dashboard link: https://syzkaller.appspot.com/bug?extid=ec5f884c4a135aa0dbb9
compiler: gcc (GCC) 9.0.0 20181231 (experimental)
patch: https://syzkaller.appspot.com/x/patch.diff?x=14d21c22e00000

2019-11-24 16:22:27

by Alan Stern

[permalink] [raw]
Subject: Re: INFO: rcu detected stall in hub_event

Another diagnostic patch.

Alan Stern

#syz test: https://github.com/google/kasan.git 46178223

Index: usb-devel/drivers/hid/hid-core.c
===================================================================
--- usb-devel.orig/drivers/hid/hid-core.c
+++ usb-devel/drivers/hid/hid-core.c
@@ -175,7 +175,8 @@ static int open_collection(struct hid_pa
collection->level = parser->collection_stack_ptr - 1;
collection->parent_idx = (collection->level == 0) ? -1 :
parser->collection_stack[collection->level - 1];
-
+ hid_info(parser->device, "New collection %px: idx %d parent %d type %d\n",
+ collection, (int) collection_index, collection->parent_idx, type);
if (type == HID_COLLECTION_APPLICATION)
parser->device->maxapplication++;

@@ -1046,8 +1047,18 @@ static void hid_apply_multiplier(struct
*/
multiplier_collection = &hid->collection[multiplier->usage->collection_index];
while (multiplier_collection->parent_idx != -1 &&
- multiplier_collection->type != HID_COLLECTION_LOGICAL)
+ multiplier_collection->type != HID_COLLECTION_LOGICAL) {
+ hid_info(hid, "collection %d %px type %d parent %d\n",
+ (int) (multiplier_collection - hid->collection), multiplier_collection,
+ multiplier_collection->type, multiplier_collection->parent_idx);
+ if (multiplier_collection->parent_idx >=
+ multiplier_collection - hid->collection) {
+ hid_info(hid, "BUG: found invalid parent_idx\n");
+ return;
+ }
multiplier_collection = &hid->collection[multiplier_collection->parent_idx];
+ }
+ hid_info(hid, "Got collection\n");

effective_multiplier = hid_calculate_multiplier(hid, multiplier);

@@ -1060,6 +1071,7 @@ static void hid_apply_multiplier(struct
effective_multiplier);
}
}
+ hid_info(hid, "Applied multiplier\n");
}

/*
@@ -1094,16 +1106,23 @@ void hid_setup_resolution_multiplier(str

rep_enum = &hid->report_enum[HID_FEATURE_REPORT];
list_for_each_entry(rep, &rep_enum->report_list, list) {
+ hid_info(hid, "Start report %px maxfield %d\n",
+ rep, rep->maxfield);
for (i = 0; i < rep->maxfield; i++) {
/* Ignore if report count is out of bounds. */
if (rep->field[i]->report_count < 1)
continue;

+ hid_info(hid, "Field %d %px maxusage %d\n",
+ i, rep->field[i], rep->field[i]->maxusage);
for (j = 0; j < rep->field[i]->maxusage; j++) {
usage = &rep->field[i]->usage[j];
- if (usage->hid == HID_GD_RESOLUTION_MULTIPLIER)
+ if (usage->hid == HID_GD_RESOLUTION_MULTIPLIER) {
+ hid_info(hid, "Usage %d %px\n",
+ j, usage);
hid_apply_multiplier(hid,
rep->field[i]);
+ }
}
}
}



2019-11-25 09:41:12

by syzbot

[permalink] [raw]
Subject: Re: INFO: rcu detected stall in hub_event

Hello,

syzbot has tested the proposed patch but the reproducer still triggered
crash:
BUG: found invalid parent_idx

microsoft 0003:045E:07DA.0001: Field 0 ffff8881c0e00000 maxusage 4899
microsoft 0003:045E:07DA.0001: Usage 72 ffff8881c0e00730
microsoft 0003:045E:07DA.0001: collection 0 ffff8881d91be200 type 0 parent 0
microsoft 0003:045E:07DA.0001: BUG: found invalid parent_idx
microsoft 0003:045E:07DA.0001: Start report ffff8881cb82e000 maxfield 1
microsoft 0003:045E:07DA.0001: Field 0 ffff8881c0e00000 maxusage 4899
microsoft 0003:045E:07DA.0001: Usage 72 ffff8881c0e00730
microsoft 0003:045E:07DA.0001: collection 0 ffff8881d91be200 type 0 parent 0
microsoft 0003:045E:07DA.0001: BUG: found invalid parent_idx
microsoft 0003:045E:07DA.0001: No inputs registered, leaving
microsoft 0003:045E:07DA.0001: hidraw0: USB HID v0.00 Device [HID
045e:07da] on usb-dummy_hcd.5-1/input0
microsoft 0003:045E:07DA.0001: no inputs found
microsoft 0003:045E:07DA.0001: could not initialize ff, continuing anyway
usb 6-1: USB disconnect, device number 3


Tested on:

commit: 46178223 usb: gadget: add raw-gadget interface
git tree: https://github.com/google/kasan.git
console output: https://syzkaller.appspot.com/x/log.txt?x=14bb93cee00000
kernel config: https://syzkaller.appspot.com/x/.config?x=99c88c44660624e7
dashboard link: https://syzkaller.appspot.com/bug?extid=ec5f884c4a135aa0dbb9
compiler: gcc (GCC) 9.0.0 20181231 (experimental)
patch: https://syzkaller.appspot.com/x/patch.diff?x=11c28d5ee00000

2019-11-25 18:54:03

by Alan Stern

[permalink] [raw]
Subject: Re: INFO: rcu detected stall in hub_event

Jiri:

On Sat, 23 Nov 2019, Andrey Konovalov wrote:

> I'm not sure, but the stack trace reminds me of this issue, so this
> report might be related:
>
> https://groups.google.com/d/msg/syzkaller-bugs/X0zVbh8aFEM/NsPcshjxBgAJ

No, the issue is quite different, although it is also a bug in the HID
parser. The big problem is that the parser assumes all usages will
belong to a collection.

There's also a second, smaller bug: hid_apply_multipler() assumes every
Resolution Multiplier control is associated with a Logical Collection
(i.e., there's no way the routine can ever set multiplier_collection to
NULL) even though there's a big quotation from the HID Usage Table
manual at the start of the function saying that they don't have to be.
This bug can be fixed easily, though.

The first bug is more troublesome. hid_add_usage() explicitly sets the
parser->local.collection_index[] entry to 0 if the current collection
stack is empty. But there's no way to distinguish this 0 from a
genuine index value that happens to point to the first collection!

So what should happen when a usage appears outside of all collections?
Is it a bug in the report descriptor (the current code suggests that it
is not)?

Or should we use a different sentinel value for the collection_index[]
entry, one that cannot be confused with a genuine value, such as
UINT_MAX?

Awaiting your suggestion...

Alan Stern

2019-11-25 21:25:39

by Alan Stern

[permalink] [raw]
Subject: Re: INFO: rcu detected stall in hub_event

#syz test: https://github.com/google/kasan.git 46178223

Index: usb-devel/drivers/hid/hid-core.c
===================================================================
--- usb-devel.orig/drivers/hid/hid-core.c
+++ usb-devel/drivers/hid/hid-core.c
@@ -1057,6 +1057,8 @@ static void hid_apply_multiplier(struct
while (multiplier_collection->parent_idx != -1 &&
multiplier_collection->type != HID_COLLECTION_LOGICAL)
multiplier_collection = &hid->collection[multiplier_collection->parent_idx];
+ if (multiplier_collection->type != HID_COLLECTION_LOGICAL)
+ multiplier_collection = NULL;

effective_multiplier = hid_calculate_multiplier(hid, multiplier);

@@ -1191,6 +1193,9 @@ int hid_open_report(struct hid_device *d
}
device->collection_size = HID_DEFAULT_NUM_COLLECTIONS;

+ /* Needed for usages before the first collection */
+ device->collection[0].parent_idx = -1;
+
ret = -EINVAL;
while ((start = fetch_item(start, end, &item)) != NULL) {


2019-11-26 07:54:57

by Jiri Kosina

[permalink] [raw]
Subject: Re: INFO: rcu detected stall in hub_event

On Mon, 25 Nov 2019, Alan Stern wrote:

> #syz test: https://github.com/google/kasan.git 46178223

Alan, did you get a test result from syzbot on this patch? My mailbox
doesn't seem to have it.

Thanks,

--
Jiri Kosina
SUSE Labs

2019-11-26 17:53:36

by Alan Stern

[permalink] [raw]
Subject: Re: INFO: rcu detected stall in hub_event

On Tue, 26 Nov 2019, Jiri Kosina wrote:

> On Mon, 25 Nov 2019, Alan Stern wrote:
>
> > #syz test: https://github.com/google/kasan.git 46178223
>
> Alan, did you get a test result from syzbot on this patch? My mailbox
> doesn't seem to have it.

No response, not yet. syzbot seems to be very slow testing the patches
for this bug report. The earlier ones I submitted also took over a day
to finish.

BTW, even if this patch fixes the problem, I don't think setting
collection[0].parent_idx to -1 is a very good solution. It's brittle
and doesn't address the underlying ambiguity.

Alan Stern

2019-11-26 20:22:23

by syzbot

[permalink] [raw]
Subject: Re: INFO: rcu detected stall in hub_event

Hello,

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

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

Tested on:

commit: 46178223 usb: gadget: add raw-gadget interface
git tree: https://github.com/google/kasan.git
kernel config: https://syzkaller.appspot.com/x/.config?x=99c88c44660624e7
dashboard link: https://syzkaller.appspot.com/bug?extid=ec5f884c4a135aa0dbb9
compiler: gcc (GCC) 9.0.0 20181231 (experimental)
patch: https://syzkaller.appspot.com/x/patch.diff?x=1177cc0ee00000

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

2019-12-09 18:28:30

by Alan Stern

[permalink] [raw]
Subject: Re: INFO: rcu detected stall in hub_event

On Mon, 25 Nov 2019, Alan Stern wrote:

> Jiri:
>
> On Sat, 23 Nov 2019, Andrey Konovalov wrote:
>
> > I'm not sure, but the stack trace reminds me of this issue, so this
> > report might be related:
> >
> > https://groups.google.com/d/msg/syzkaller-bugs/X0zVbh8aFEM/NsPcshjxBgAJ
>
> No, the issue is quite different, although it is also a bug in the HID
> parser. The big problem is that the parser assumes all usages will
> belong to a collection.
>
> There's also a second, smaller bug: hid_apply_multipler() assumes every
> Resolution Multiplier control is associated with a Logical Collection
> (i.e., there's no way the routine can ever set multiplier_collection to
> NULL) even though there's a big quotation from the HID Usage Table
> manual at the start of the function saying that they don't have to be.
> This bug can be fixed easily, though.
>
> The first bug is more troublesome. hid_add_usage() explicitly sets the
> parser->local.collection_index[] entry to 0 if the current collection
> stack is empty. But there's no way to distinguish this 0 from a
> genuine index value that happens to point to the first collection!
>
> So what should happen when a usage appears outside of all collections?
> Is it a bug in the report descriptor (the current code suggests that it
> is not)?
>
> Or should we use a different sentinel value for the collection_index[]
> entry, one that cannot be confused with a genuine value, such as
> UINT_MAX?

On Tue, 26 Nov 2019, Jiri Kosina wrote:

> Alan, did you get a test result from syzbot on this patch? My mailbox
> doesn't seem to have it.

On Tue, 26 Nov 2019, syzbot wrote:

> Hello,
>
> syzbot has tested the proposed patch and the reproducer did not trigger
> crash:
>
> Reported-and-tested-by:
> [email protected]

Jiri:

Now we've got the answer. The current question is: What should I do
with the patch? It seems rather ad-hoc, not a proper solution to the
problem.

To refresh your memory, here is the patch that syzbot tested:

drivers/hid/hid-core.c | 5 +++++
1 file changed, 5 insertions(+)

Index: usb-devel/drivers/hid/hid-core.c
===================================================================
--- usb-devel.orig/drivers/hid/hid-core.c
+++ usb-devel/drivers/hid/hid-core.c
@@ -1057,6 +1057,8 @@ static void hid_apply_multiplier(struct
while (multiplier_collection->parent_idx != -1 &&
multiplier_collection->type != HID_COLLECTION_LOGICAL)
multiplier_collection = &hid->collection[multiplier_collection->parent_idx];
+ if (multiplier_collection->type != HID_COLLECTION_LOGICAL)
+ multiplier_collection = NULL;

effective_multiplier = hid_calculate_multiplier(hid, multiplier);

@@ -1191,6 +1193,9 @@ int hid_open_report(struct hid_device *d
}
device->collection_size = HID_DEFAULT_NUM_COLLECTIONS;

+ /* Needed for usages before the first collection */
+ device->collection[0].parent_idx = -1;
+
ret = -EINVAL;
while ((start = fetch_item(start, end, &item)) != NULL) {

Alan Stern

2022-07-30 10:35:27

by syzbot

[permalink] [raw]
Subject: Re: [syzbot] INFO: rcu detected stall in hub_event

syzbot has bisected this issue to:

commit 859bdc359567f5fa8e8dc780d7b5e53ea43d9ce9
Author: Mayank Rana <[email protected]>
Date: Wed May 18 18:12:52 2022 +0000

usb: dwc3: core: Add error log when core soft reset failed

bisection log: https://syzkaller.appspot.com/x/bisect.txt?x=144812f2080000
start commit: 6e2c0490769e Merge tag 'drm-fixes-2022-07-29' of git://ano..
git tree: upstream
final oops: https://syzkaller.appspot.com/x/report.txt?x=164812f2080000
console output: https://syzkaller.appspot.com/x/log.txt?x=124812f2080000
kernel config: https://syzkaller.appspot.com/x/.config?x=26034e6fe0075dad
dashboard link: https://syzkaller.appspot.com/bug?extid=ec5f884c4a135aa0dbb9
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=119bc436080000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=16c3c0f2080000

Reported-by: [email protected]
Fixes: 859bdc359567 ("usb: dwc3: core: Add error log when core soft reset failed")

For information about bisection process see: https://goo.gl/tpsmEJ#bisection