gadgetfs WARNING at drivers/usb/gadget/udc/dummy_hcd.c:674

[Vegard Nossum]

Hi again Marek,

With your two patches on top of latest mainline I've run into this warning:

gadgetfs: connected
gadgetfs: disconnected
------------[ cut here ]------------
WARNING: CPU: 0 PID: 35 at drivers/usb/gadget/udc/dummy_hcd.c:674 
dummy_free_request+0x92/0xa0()
CPU: 0 PID: 35 Comm: afl-fuzz Not tainted 4.5.0-rc2 #1
 ffff8800003b6900 ffff88000c847d00 ffffffff8133f0e2 ffff88000c847d40
 ffffffff8108d4bf ffffffff8152b062 ffff88000032d430 ffff88000032d420
 ffff88000032d430 ffffffff8185fc80 ffff8800001caf08 ffff88000c847d50
Call Trace:
 [<ffffffff8133f0e2>] dump_stack+0x19/0x27
 [<ffffffff8108d4bf>] warn_slowpath_common+0xaf/0x110
 [<ffffffff8152b062>] ? dummy_free_request+0x92/0xa0
 [<ffffffff8108d6b5>] warn_slowpath_null+0x15/0x20
 [<ffffffff8152b062>] dummy_free_request+0x92/0xa0
 [<ffffffff81536484>] gadgetfs_unbind+0x194/0x210
 [<ffffffff815362f0>] ? destroy_ep_files+0x560/0x560
 [<ffffffff81520b6c>] usb_gadget_remove_driver+0x1dc/0x460
 [<ffffffff81523951>] usb_gadget_unregister_driver+0x151/0x240
 [<ffffffff81533b2a>] dev_release+0x7a/0x160
 [<ffffffff811f0ccb>] __fput+0x11b/0x490
 [<ffffffff811f10a9>] ____fput+0x9/0x10
 [<ffffffff810c8881>] task_work_run+0xf1/0x190
 [<ffffffff811ea9ea>] ? filp_close+0x8a/0xe0
 [<ffffffff81001c3c>] exit_to_usermode_loop+0xec/0x100
 [<ffffffff81002531>] syscall_return_slowpath+0x91/0xc0
 [<ffffffff817a42c9>] int_ret_from_sys_call+0x25/0x8f
---[ end trace e6edc2c9995ff81b ]---

To be specific, it's the

WARN_ON(!list_empty(&req->queue));

that is triggering. I think it's probably not related to your patches, 
but rather more bugs which were hidden until now :-)

Some time later it also shows:

usb 1-1: new high-speed USB device number 7 using dummy_hcd
BUG: unable to handle kernel NULL pointer dereference at           (null)
IP: [<          (null)>]           (null)
PGD c830067 PUD c854067 PMD 0
Oops: 0010 [#1] DEBUG_PAGEALLOC KASAN
CPU: 0 PID: 0 Comm: swapper Tainted: G        W       4.5.0-rc2 #1
task: ffffffff8192d680 ti: ffffffff81910000 task.ti: ffffffff81910000
RIP: 0010:[<0000000000000000>]  [<          (null)>]           (null)
RSP: 0018:ffffffff81946c08  EFLAGS: 00010046
RAX: dffffc0000000000 RBX: ffff88000032d2d0 RCX: ffff88000032d2c0
RDX: 1ffff10000065a60 RSI: ffff88000032d2d0 RDI: ffff8800001ca070
RBP: ffffffff81946c20 R08: ffff88000032d2c0 R09: 000000000000319e
R10: ffffffff81946e80 R11: 0000000000000001 R12: ffff8800001ca070
R13: 0000000000000000 R14: ffff8800001ca030 R15: dffffc0000000000
FS:  0000000000000000(0000) GS:ffffffff8193f000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000000000000 CR3: 000000000c850000 CR4: 00000000001406b0
Stack:
 ffffffff81522226 ffff88000032d2c0 0000000000000080 ffffffff81946e00
 ffffffff8152d09b ffff88000027a448 0000000000000246 ffff8800001caf20
 1ffffffff0328daf 0000000000000001 ffff8800003b6900 0000000000000086
Call Trace:
 <IRQ>
 [<ffffffff81522226>] ? usb_gadget_giveback_request+0x36/0x50
 [<ffffffff8152d09b>] dummy_timer+0x202b/0x2980
 [<ffffffff810e1a26>] ? enqueue_task_fair+0x1f6/0x580
 [<ffffffff810dd7c5>] ? sched_clock_cpu+0x45/0x60
 [<ffffffff8152b070>] ? dummy_free_request+0xa0/0xa0
 [<ffffffff81115df0>] ? process_cpu_nsleep+0x10/0x10
 [<ffffffff81109280>] ? detach_if_pending+0x350/0x350
 [<ffffffff8152b070>] ? dummy_free_request+0xa0/0xa0
 [<ffffffff81109566>] call_timer_fn.isra.5+0x16/0x70
 [<ffffffff8152b070>] ? dummy_free_request+0xa0/0xa0
 [<ffffffff81109a85>] run_timer_softirq+0x365/0x590
 [<ffffffff81070ce6>] ? kvm_clock_get_cycles+0x16/0x20
 [<ffffffff81109720>] ? cascade.constprop.6+0x160/0x160
 [<ffffffff81070cc6>] ? kvm_clock_read+0x16/0x20
 [<ffffffff810dd5fc>] ? sched_clock_local.constprop.4+0xc/0x80
 [<ffffffff81096329>] __do_softirq+0x199/0x400
 [<ffffffff81096710>] irq_exit+0xa0/0xc0
 [<ffffffff81061ad5>] smp_trace_apic_timer_interrupt+0x95/0xd0
 [<ffffffff81061b19>] smp_apic_timer_interrupt+0x9/0x10
 [<ffffffff817a4d0d>] apic_timer_interrupt+0x7d/0x90
 <EOI>
 [<ffffffff81071066>] ? native_safe_halt+0x6/0x10
 [<ffffffff81013ff9>] default_idle+0x9/0x10
 [<ffffffff81014cda>] arch_cpu_idle+0xa/0x10
 [<ffffffff810e8496>] default_idle_call+0x46/0x60
 [<ffffffff810e86dd>] cpu_startup_entry+0x22d/0x310
 [<ffffffff810d5945>] ? finish_task_switch+0x135/0x450
 [<ffffffff810e84b0>] ? default_idle_call+0x60/0x60
 [<ffffffff81799ff1>] ? __schedule+0x451/0xd50
 [<ffffffff8179aa26>] ? schedule+0xc6/0x180
 [<ffffffff8179760a>] rest_init+0x9a/0xa0
 [<ffffffff81a4b2ab>] start_kernel+0x3fa/0x422
 [<ffffffff81a4aeb1>] ? thread_info_cache_init+0x6/0x6
 [<ffffffff81a8c906>] ? memblock_reserve+0x4a/0x4f
 [<ffffffff81a4a120>] ? early_idt_handler_array+0x120/0x120
 [<ffffffff81a4a31c>] x86_64_start_reservations+0x2a/0x2c
 [<ffffffff81a4a408>] x86_64_start_kernel+0xea/0xf7
Code:  Bad RIP value.
RIP  [<          (null)>]           (null)
 RSP <ffffffff81946c08>
CR2: 0000000000000000
---[ end trace f62ab933aa78d176 ]---
Kernel panic - not syncing: Fatal exception in interrupt

This one I did see before and I think it's just req->complete which is
NULL (but I have no idea why).


Vegard