Hello,
I've got the following report while running syzkaller fuzzer on
093b995e3b55a0ae0670226ddfcb05bfbf0099ae. Not the preceding injected
kmalloc failure, most likely it's the root cause.
FAULT_INJECTION: forcing a failure.
name failslab, interval 1, probability 0, space 0, times 0
CPU: 0 PID: 3348 Comm: syz-executor7 Not tainted 4.11.0-rc3+ #364
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:16 [inline]
dump_stack+0x1b8/0x28d lib/dump_stack.c:52
fail_dump lib/fault-inject.c:45 [inline]
should_fail+0x78a/0x870 lib/fault-inject.c:154
should_failslab+0xec/0x120 mm/failslab.c:31
slab_pre_alloc_hook mm/slab.h:434 [inline]
slab_alloc mm/slab.c:3394 [inline]
__do_kmalloc mm/slab.c:3734 [inline]
__kmalloc+0x220/0x730 mm/slab.c:3745
kmalloc include/linux/slab.h:495 [inline]
kzalloc include/linux/slab.h:663 [inline]
rh_call_control drivers/usb/core/hcd.c:522 [inline]
rh_urb_enqueue drivers/usb/core/hcd.c:843 [inline]
usb_hcd_submit_urb+0x693/0x1e40 drivers/usb/core/hcd.c:1646
usb_submit_urb+0x8d4/0x1030 drivers/usb/core/urb.c:542
usb_start_wait_urb+0x135/0x320 drivers/usb/core/message.c:56
usb_internal_control_msg drivers/usb/core/message.c:100 [inline]
usb_control_msg+0x330/0x460 drivers/usb/core/message.c:151
get_port_status drivers/usb/core/hub.c:554 [inline]
hub_ext_port_status+0x122/0x440 drivers/usb/core/hub.c:571
hub_port_status drivers/usb/core/hub.c:593 [inline]
hub_activate+0x3ea/0x1650 drivers/usb/core/hub.c:1068
hub_resume+0x3c/0x50 drivers/usb/core/hub.c:3595
usb_resume_interface.isra.5+0x149/0x380 drivers/usb/core/driver.c:1260
usb_resume_both+0x1c2/0x710 drivers/usb/core/driver.c:1402
usb_runtime_resume+0x1e/0x30 drivers/usb/core/driver.c:1856
__rpm_callback+0x338/0xa50 drivers/base/power/runtime.c:334
rpm_callback+0x18a/0x220 drivers/base/power/runtime.c:464
rpm_resume+0xe9d/0x1880 drivers/base/power/runtime.c:818
__pm_runtime_resume+0xa2/0x130 drivers/base/power/runtime.c:1039
pm_runtime_get_sync include/linux/pm_runtime.h:237 [inline]
usb_autoresume_device+0x23/0x60 drivers/usb/core/driver.c:1581
usbdev_open+0x25b/0xa50 drivers/usb/core/devio.c:1011
chrdev_open+0x257/0x730 fs/char_dev.c:392
do_dentry_open+0x710/0xc80 fs/open.c:751
vfs_open+0x105/0x220 fs/open.c:864
do_last fs/namei.c:3349 [inline]
path_openat+0x1151/0x35b0 fs/namei.c:3490
do_filp_open+0x249/0x370 fs/namei.c:3525
do_sys_open+0x502/0x6d0 fs/open.c:1051
SYSC_open fs/open.c:1069 [inline]
SyS_open+0x2d/0x40 fs/open.c:1064
entry_SYSCALL_64_fastpath+0x1f/0xc2
==================================================================
BUG: KASAN: use-after-free in __list_add_valid+0xc6/0xd0
lib/list_debug.c:26 at addr ffff88003c377a20
Read of size 8 by task syz-executor7/3348
CPU: 3 PID: 3348 Comm: syz-executor7 Not tainted 4.11.0-rc3+ #364
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:16 [inline]
dump_stack+0x1b8/0x28d lib/dump_stack.c:52
kasan_object_err+0x1c/0x70 mm/kasan/report.c:166
print_address_description mm/kasan/report.c:210 [inline]
kasan_report_error mm/kasan/report.c:294 [inline]
kasan_report.part.2+0x1be/0x480 mm/kasan/report.c:316
kasan_report mm/kasan/report.c:337 [inline]
__asan_report_load8_noabort+0x29/0x30 mm/kasan/report.c:337
__list_add_valid+0xc6/0xd0 lib/list_debug.c:26
__list_add include/linux/list.h:59 [inline]
list_add_tail include/linux/list.h:92 [inline]
usb_hcd_link_urb_to_ep+0x281/0x4e0 drivers/usb/core/hcd.c:1275
rh_call_control drivers/usb/core/hcd.c:502 [inline]
rh_urb_enqueue drivers/usb/core/hcd.c:843 [inline]
usb_hcd_submit_urb+0x403/0x1e40 drivers/usb/core/hcd.c:1646
usb_submit_urb+0x8d4/0x1030 drivers/usb/core/urb.c:542
usb_start_wait_urb+0x135/0x320 drivers/usb/core/message.c:56
usb_internal_control_msg drivers/usb/core/message.c:100 [inline]
usb_control_msg+0x330/0x460 drivers/usb/core/message.c:151
get_port_status drivers/usb/core/hub.c:554 [inline]
hub_ext_port_status+0x122/0x440 drivers/usb/core/hub.c:571
hub_port_status drivers/usb/core/hub.c:593 [inline]
hub_activate+0x3ea/0x1650 drivers/usb/core/hub.c:1068
hub_resume+0x3c/0x50 drivers/usb/core/hub.c:3595
usb_resume_interface.isra.5+0x149/0x380 drivers/usb/core/driver.c:1260
usb_resume_both+0x1c2/0x710 drivers/usb/core/driver.c:1402
usb_runtime_resume+0x1e/0x30 drivers/usb/core/driver.c:1856
__rpm_callback+0x338/0xa50 drivers/base/power/runtime.c:334
rpm_callback+0x18a/0x220 drivers/base/power/runtime.c:464
rpm_resume+0xe9d/0x1880 drivers/base/power/runtime.c:818
__pm_runtime_resume+0xa2/0x130 drivers/base/power/runtime.c:1039
pm_runtime_get_sync include/linux/pm_runtime.h:237 [inline]
usb_autoresume_device+0x23/0x60 drivers/usb/core/driver.c:1581
usbdev_open+0x25b/0xa50 drivers/usb/core/devio.c:1011
chrdev_open+0x257/0x730 fs/char_dev.c:392
do_dentry_open+0x710/0xc80 fs/open.c:751
vfs_open+0x105/0x220 fs/open.c:864
do_last fs/namei.c:3349 [inline]
path_openat+0x1151/0x35b0 fs/namei.c:3490
do_filp_open+0x249/0x370 fs/namei.c:3525
do_sys_open+0x502/0x6d0 fs/open.c:1051
SYSC_open fs/open.c:1069 [inline]
SyS_open+0x2d/0x40 fs/open.c:1064
entry_SYSCALL_64_fastpath+0x1f/0xc2
RIP: 0033:0x40b3f1
RSP: 002b:00007f642ad93410 EFLAGS: 00000293 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: cccccccccccccccd RCX: 000000000040b3f1
RDX: 0000000000000000 RSI: 00000000001cd000 RDI: 00007f642ad93440
RBP: 0000000000000086 R08: 0000000000000000 R09: 00000000000000fb
R10: ffffffffffffffff R11: 0000000000000293 R12: 00000000004a7e31
R13: 0000000000000000 R14: 00007f642ad93618 R15: 00007f642ad93788
Object at ffff88003c377a00, in cache kmalloc-192 size: 192
Allocated:
PID = 3348
save_stack_trace+0x16/0x20 arch/x86/kernel/stacktrace.c:59
save_stack+0x43/0xd0 mm/kasan/kasan.c:517
set_track mm/kasan/kasan.c:529 [inline]
kasan_kmalloc+0xbc/0xf0 mm/kasan/kasan.c:620
__do_kmalloc mm/slab.c:3736 [inline]
__kmalloc+0x13c/0x730 mm/slab.c:3745
kmalloc include/linux/slab.h:495 [inline]
usb_alloc_urb+0x24/0x50 drivers/usb/core/urb.c:73
usb_internal_control_msg drivers/usb/core/message.c:93 [inline]
usb_control_msg+0x1d7/0x460 drivers/usb/core/message.c:151
get_port_status drivers/usb/core/hub.c:554 [inline]
hub_ext_port_status+0x122/0x440 drivers/usb/core/hub.c:571
hub_port_status drivers/usb/core/hub.c:593 [inline]
hub_activate+0x3ea/0x1650 drivers/usb/core/hub.c:1068
hub_resume+0x3c/0x50 drivers/usb/core/hub.c:3595
usb_resume_interface.isra.5+0x149/0x380 drivers/usb/core/driver.c:1260
usb_resume_both+0x1c2/0x710 drivers/usb/core/driver.c:1402
usb_runtime_resume+0x1e/0x30 drivers/usb/core/driver.c:1856
__rpm_callback+0x338/0xa50 drivers/base/power/runtime.c:334
rpm_callback+0x18a/0x220 drivers/base/power/runtime.c:464
rpm_resume+0xe9d/0x1880 drivers/base/power/runtime.c:818
__pm_runtime_resume+0xa2/0x130 drivers/base/power/runtime.c:1039
pm_runtime_get_sync include/linux/pm_runtime.h:237 [inline]
usb_autoresume_device+0x23/0x60 drivers/usb/core/driver.c:1581
usbdev_open+0x25b/0xa50 drivers/usb/core/devio.c:1011
chrdev_open+0x257/0x730 fs/char_dev.c:392
do_dentry_open+0x710/0xc80 fs/open.c:751
vfs_open+0x105/0x220 fs/open.c:864
do_last fs/namei.c:3349 [inline]
path_openat+0x1151/0x35b0 fs/namei.c:3490
do_filp_open+0x249/0x370 fs/namei.c:3525
do_sys_open+0x502/0x6d0 fs/open.c:1051
SYSC_open fs/open.c:1069 [inline]
SyS_open+0x2d/0x40 fs/open.c:1064
entry_SYSCALL_64_fastpath+0x1f/0xc2
Freed:
PID = 3348
save_stack_trace+0x16/0x20 arch/x86/kernel/stacktrace.c:59
save_stack+0x43/0xd0 mm/kasan/kasan.c:517
set_track mm/kasan/kasan.c:529 [inline]
kasan_slab_free+0x81/0xc0 mm/kasan/kasan.c:593
__cache_free mm/slab.c:3514 [inline]
kfree+0xd7/0x250 mm/slab.c:3831
urb_destroy+0x4a/0xa0 drivers/usb/core/urb.c:26
kref_put include/linux/kref.h:72 [inline]
usb_free_urb+0x30/0x40 drivers/usb/core/urb.c:96
usb_start_wait_urb+0x234/0x320 drivers/usb/core/message.c:78
usb_internal_control_msg drivers/usb/core/message.c:100 [inline]
usb_control_msg+0x330/0x460 drivers/usb/core/message.c:151
get_port_status drivers/usb/core/hub.c:554 [inline]
hub_ext_port_status+0x122/0x440 drivers/usb/core/hub.c:571
hub_port_status drivers/usb/core/hub.c:593 [inline]
hub_activate+0x3ea/0x1650 drivers/usb/core/hub.c:1068
hub_resume+0x3c/0x50 drivers/usb/core/hub.c:3595
usb_resume_interface.isra.5+0x149/0x380 drivers/usb/core/driver.c:1260
usb_resume_both+0x1c2/0x710 drivers/usb/core/driver.c:1402
usb_runtime_resume+0x1e/0x30 drivers/usb/core/driver.c:1856
__rpm_callback+0x338/0xa50 drivers/base/power/runtime.c:334
rpm_callback+0x18a/0x220 drivers/base/power/runtime.c:464
rpm_resume+0xe9d/0x1880 drivers/base/power/runtime.c:818
__pm_runtime_resume+0xa2/0x130 drivers/base/power/runtime.c:1039
pm_runtime_get_sync include/linux/pm_runtime.h:237 [inline]
usb_autoresume_device+0x23/0x60 drivers/usb/core/driver.c:1581
usbdev_open+0x25b/0xa50 drivers/usb/core/devio.c:1011
chrdev_open+0x257/0x730 fs/char_dev.c:392
do_dentry_open+0x710/0xc80 fs/open.c:751
vfs_open+0x105/0x220 fs/open.c:864
do_last fs/namei.c:3349 [inline]
path_openat+0x1151/0x35b0 fs/namei.c:3490
do_filp_open+0x249/0x370 fs/namei.c:3525
do_sys_open+0x502/0x6d0 fs/open.c:1051
SYSC_open fs/open.c:1069 [inline]
SyS_open+0x2d/0x40 fs/open.c:1064
entry_SYSCALL_64_fastpath+0x1f/0xc2
Memory state around the buggy address:
ffff88003c377900: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
ffff88003c377980: fb fb fb fb fb fb fb fb fc fc fc fc fc fc fc fc
>ffff88003c377a00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
^
ffff88003c377a80: fb fb fb fb fb fb fb fb fc fc fc fc fc fc fc fc
ffff88003c377b00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
==================================================================
On Thu, 23 Mar 2017, Dmitry Vyukov wrote:
> Hello,
>
> I've got the following report while running syzkaller fuzzer on
> 093b995e3b55a0ae0670226ddfcb05bfbf0099ae. Not the preceding injected
> kmalloc failure, most likely it's the root cause.
I find this bug report puzzling. Maybe I don't understand it
correctly -- it appears that the so-called use-after-free actually
occurs _before_ the memory is deallocated!
> FAULT_INJECTION: forcing a failure.
Skipping this part. Is it relevant? It seems to refer to a different
memory buffer.
> ==================================================================
> BUG: KASAN: use-after-free in __list_add_valid+0xc6/0xd0
> lib/list_debug.c:26 at addr ffff88003c377a20
> Read of size 8 by task syz-executor7/3348
> CPU: 3 PID: 3348 Comm: syz-executor7 Not tainted 4.11.0-rc3+ #364
> Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
> Call Trace:
Here are the revelant pieces of the stack traces. Everything below
these parts is the same, and everything above them is unimportant.
(And everything happened in the same process.) The use-after-free
access occurred within this call:
> usb_start_wait_urb+0x135/0x320 drivers/usb/core/message.c:56
> usb_internal_control_msg drivers/usb/core/message.c:100 [inline]
Here's where the allocation call occurred:
> Allocated:
> PID = 3348
...
> usb_internal_control_msg drivers/usb/core/message.c:93 [inline]
And here's where the buffer was deallocated:
> Freed:
> PID = 3348
...
> usb_start_wait_urb+0x234/0x320 drivers/usb/core/message.c:78
> usb_internal_control_msg drivers/usb/core/message.c:100 [inline]
Putting these together:
The memory was allocated in usb_internal_control_msg() line 93.
The later events occurred within the call in line 100 to
usb_start_wait_urb().
The invalid access occurred within usb_start_wait_urb() line 56.
The memory was deallocated within usb_start_wait_urb() line 78.
Since these routines don't involve any loops or backward jumps, this
says that the invalid access occurred before the memory was
deallocated! So why is it reported as a problem?
Alan
On Thu, Mar 23, 2017 at 3:34 PM, Alan Stern <[email protected]> wrote:
> On Thu, 23 Mar 2017, Dmitry Vyukov wrote:
>
>> Hello,
>>
>> I've got the following report while running syzkaller fuzzer on
>> 093b995e3b55a0ae0670226ddfcb05bfbf0099ae. Not the preceding injected
>> kmalloc failure, most likely it's the root cause.
>
> I find this bug report puzzling. Maybe I don't understand it
> correctly -- it appears that the so-called use-after-free actually
> occurs _before_ the memory is deallocated!
>
>> FAULT_INJECTION: forcing a failure.
> Skipping this part. Is it relevant? It seems to refer to a different
> memory buffer.
>
>> ==================================================================
>> BUG: KASAN: use-after-free in __list_add_valid+0xc6/0xd0
>> lib/list_debug.c:26 at addr ffff88003c377a20
>> Read of size 8 by task syz-executor7/3348
>> CPU: 3 PID: 3348 Comm: syz-executor7 Not tainted 4.11.0-rc3+ #364
>> Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
>> Call Trace:
>
> Here are the revelant pieces of the stack traces. Everything below
> these parts is the same, and everything above them is unimportant.
> (And everything happened in the same process.) The use-after-free
> access occurred within this call:
>
>> usb_start_wait_urb+0x135/0x320 drivers/usb/core/message.c:56
>> usb_internal_control_msg drivers/usb/core/message.c:100 [inline]
>
>
> Here's where the allocation call occurred:
>
>> Allocated:
>> PID = 3348
> ...
>> usb_internal_control_msg drivers/usb/core/message.c:93 [inline]
>
>
> And here's where the buffer was deallocated:
>
>> Freed:
>> PID = 3348
> ...
>> usb_start_wait_urb+0x234/0x320 drivers/usb/core/message.c:78
>> usb_internal_control_msg drivers/usb/core/message.c:100 [inline]
>
> Putting these together:
>
> The memory was allocated in usb_internal_control_msg() line 93.
> The later events occurred within the call in line 100 to
> usb_start_wait_urb().
>
> The invalid access occurred within usb_start_wait_urb() line 56.
>
> The memory was deallocated within usb_start_wait_urb() line 78.
>
> Since these routines don't involve any loops or backward jumps, this
> says that the invalid access occurred before the memory was
> deallocated! So why is it reported as a problem?
My first guess would be that pid 3348 did 2 calls to open and the urb
was somehow referenced across these calls. Is it possible?
On Thu, 23 Mar 2017, Dmitry Vyukov wrote:
> > Putting these together:
> >
> > The memory was allocated in usb_internal_control_msg() line 93.
> > The later events occurred within the call in line 100 to
> > usb_start_wait_urb().
> >
> > The invalid access occurred within usb_start_wait_urb() line 56.
> >
> > The memory was deallocated within usb_start_wait_urb() line 78.
> >
> > Since these routines don't involve any loops or backward jumps, this
> > says that the invalid access occurred before the memory was
> > deallocated! So why is it reported as a problem?
>
>
> My first guess would be that pid 3348 did 2 calls to open and the urb
> was somehow referenced across these calls. Is it possible?
I don't think so. The URB gets allocated and deallocated separately
for each call. You can see this very plainly by reading the source
code for usb_internal_control_msg() and usb_start_wait_urb().
It's possible that the same memory location was allocated and
deallocated for two different calls at different times. That wouldn't
fool syzkaller, would it?
Alan Stern
On Thu, Mar 23, 2017 at 4:04 PM, Alan Stern <[email protected]> wrote:
> On Thu, 23 Mar 2017, Dmitry Vyukov wrote:
>
>> > Putting these together:
>> >
>> > The memory was allocated in usb_internal_control_msg() line 93.
>> > The later events occurred within the call in line 100 to
>> > usb_start_wait_urb().
>> >
>> > The invalid access occurred within usb_start_wait_urb() line 56.
>> >
>> > The memory was deallocated within usb_start_wait_urb() line 78.
>> >
>> > Since these routines don't involve any loops or backward jumps, this
>> > says that the invalid access occurred before the memory was
>> > deallocated! So why is it reported as a problem?
>>
>>
>> My first guess would be that pid 3348 did 2 calls to open and the urb
>> was somehow referenced across these calls. Is it possible?
>
> I don't think so. The URB gets allocated and deallocated separately
> for each call. You can see this very plainly by reading the source
> code for usb_internal_control_msg() and usb_start_wait_urb().
>
> It's possible that the same memory location was allocated and
> deallocated for two different calls at different times. That wouldn't
> fool syzkaller, would it?
Generally it does not fool KASAN because of heap memory quarantine.
I will take a closer look tomorrow.
Thanks for looking into this.
On Thu, Mar 23, 2017 at 4:22 PM, Dmitry Vyukov <[email protected]> wrote:
>> On Thu, 23 Mar 2017, Dmitry Vyukov wrote:
>>
>>> > Putting these together:
>>> >
>>> > The memory was allocated in usb_internal_control_msg() line 93.
>>> > The later events occurred within the call in line 100 to
>>> > usb_start_wait_urb().
>>> >
>>> > The invalid access occurred within usb_start_wait_urb() line 56.
>>> >
>>> > The memory was deallocated within usb_start_wait_urb() line 78.
>>> >
>>> > Since these routines don't involve any loops or backward jumps, this
>>> > says that the invalid access occurred before the memory was
>>> > deallocated! So why is it reported as a problem?
>>>
>>>
>>> My first guess would be that pid 3348 did 2 calls to open and the urb
>>> was somehow referenced across these calls. Is it possible?
>>
>> I don't think so. The URB gets allocated and deallocated separately
>> for each call. You can see this very plainly by reading the source
>> code for usb_internal_control_msg() and usb_start_wait_urb().
>>
>> It's possible that the same memory location was allocated and
>> deallocated for two different calls at different times. That wouldn't
>> fool syzkaller, would it?
>
>
> Generally it does not fool KASAN because of heap memory quarantine.
> I will take a closer look tomorrow.
> Thanks for looking into this.
The bug looks real to me and it can be easily reproduced by executing:
mmap(&(0x7f0000000000/0xfff000)=nil, (0xfff000), 0x3, 0x32,
0xffffffffffffffff, 0x0)
syz_open_dev$usb(&(0x7f0000001000-0x15)="2f6465762f6275732f7573622f3030232f30302300",
0x1ff, 0x200)
syz_open_dev$usb(&(0x7f0000002000-0x15)="2f6465762f6275732f7573622f3030232f30302300",
0x3f, 0x0)
and failing 7-th malloc in the first one, this one:
kzalloc include/linux/slab.h:663 [inline]
rh_call_control drivers/usb/core/hcd.c:522 [inline]
>From the report:
(from the failure stack)
kmalloc in rh_call_control fails, and it straight returns -ENOMEM
without calling usb_hcd_unlink_urb_from_ep(hcd, urb) leaving urb
linked into hcd (and that's probably the root problem)
consequently:
rh_urb_enqueue return -ENOMEM
usb_hcd_submit_urb does INIT_LIST_HEAD(&urb->urb_list), but the urb is
still linked, so we got corrupted list
(from the free stack)
eventually usb_start_wait_urb frees the still linked urb by calling usb_free_urb
(form the use-after-free stack)
the subsequent open links a new urb into the corrupted list in
usb_hcd_link_urb_to_ep
bang!
On Fri, 24 Mar 2017, Dmitry Vyukov wrote:
> On Thu, Mar 23, 2017 at 4:22 PM, Dmitry Vyukov <[email protected]> wrote:
> >> On Thu, 23 Mar 2017, Dmitry Vyukov wrote:
> >>
> >>> > Putting these together:
> >>> >
> >>> > The memory was allocated in usb_internal_control_msg() line 93.
> >>> > The later events occurred within the call in line 100 to
> >>> > usb_start_wait_urb().
> >>> >
> >>> > The invalid access occurred within usb_start_wait_urb() line 56.
> >>> >
> >>> > The memory was deallocated within usb_start_wait_urb() line 78.
> >>> >
> >>> > Since these routines don't involve any loops or backward jumps, this
> >>> > says that the invalid access occurred before the memory was
> >>> > deallocated! So why is it reported as a problem?
> >>>
> >>>
> >>> My first guess would be that pid 3348 did 2 calls to open and the urb
> >>> was somehow referenced across these calls. Is it possible?
> >>
> >> I don't think so. The URB gets allocated and deallocated separately
> >> for each call. You can see this very plainly by reading the source
> >> code for usb_internal_control_msg() and usb_start_wait_urb().
> >>
> >> It's possible that the same memory location was allocated and
> >> deallocated for two different calls at different times. That wouldn't
> >> fool syzkaller, would it?
> >
> >
> > Generally it does not fool KASAN because of heap memory quarantine.
> > I will take a closer look tomorrow.
> > Thanks for looking into this.
>
>
> The bug looks real to me and it can be easily reproduced by executing:
>
> mmap(&(0x7f0000000000/0xfff000)=nil, (0xfff000), 0x3, 0x32,
> 0xffffffffffffffff, 0x0)
> syz_open_dev$usb(&(0x7f0000001000-0x15)="2f6465762f6275732f7573622f3030232f30302300",
> 0x1ff, 0x200)
> syz_open_dev$usb(&(0x7f0000002000-0x15)="2f6465762f6275732f7573622f3030232f30302300",
> 0x3f, 0x0)
(Incidentally, those ASCII strings say "/dev/bus/usb/00#/00#", which is
a rather unusual name for a USB device node. Where did it come from?)
>
> and failing 7-th malloc in the first one, this one:
>
> kzalloc include/linux/slab.h:663 [inline]
> rh_call_control drivers/usb/core/hcd.c:522 [inline]
>
> From the report:
>
> (from the failure stack)
> kmalloc in rh_call_control fails, and it straight returns -ENOMEM
> without calling usb_hcd_unlink_urb_from_ep(hcd, urb) leaving urb
> linked into hcd (and that's probably the root problem)
Ah, very good detective work! I agree.
> consequently:
> rh_urb_enqueue return -ENOMEM
> usb_hcd_submit_urb does INIT_LIST_HEAD(&urb->urb_list), but the urb is
> still linked, so we got corrupted list
> (from the free stack)
> eventually usb_start_wait_urb frees the still linked urb by calling usb_free_urb
> (form the use-after-free stack)
> the subsequent open links a new urb into the corrupted list in
> usb_hcd_link_urb_to_ep
> bang!
Here's a patch to fix the problem; let me know how it works.
Alan
Index: usb-4.x/drivers/usb/core/hcd.c
===================================================================
--- usb-4.x.orig/drivers/usb/core/hcd.c
+++ usb-4.x/drivers/usb/core/hcd.c
@@ -520,8 +520,10 @@ static int rh_call_control (struct usb_h
*/
tbuf_size = max_t(u16, sizeof(struct usb_hub_descriptor), wLength);
tbuf = kzalloc(tbuf_size, GFP_KERNEL);
- if (!tbuf)
- return -ENOMEM;
+ if (!tbuf) {
+ status = -ENOMEM;
+ goto err_alloc;
+ }
bufp = tbuf;
@@ -734,6 +736,7 @@ error:
}
kfree(tbuf);
+ err_alloc:
/* any errors get returned through the urb completion */
spin_lock_irq(&hcd_root_hub_lock);
On Fri, Mar 24, 2017 at 3:27 PM, Alan Stern <[email protected]> wrote:
> On Fri, 24 Mar 2017, Dmitry Vyukov wrote:
>
>> On Thu, Mar 23, 2017 at 4:22 PM, Dmitry Vyukov <[email protected]> wrote:
>> >> On Thu, 23 Mar 2017, Dmitry Vyukov wrote:
>> >>
>> >>> > Putting these together:
>> >>> >
>> >>> > The memory was allocated in usb_internal_control_msg() line 93.
>> >>> > The later events occurred within the call in line 100 to
>> >>> > usb_start_wait_urb().
>> >>> >
>> >>> > The invalid access occurred within usb_start_wait_urb() line 56.
>> >>> >
>> >>> > The memory was deallocated within usb_start_wait_urb() line 78.
>> >>> >
>> >>> > Since these routines don't involve any loops or backward jumps, this
>> >>> > says that the invalid access occurred before the memory was
>> >>> > deallocated! So why is it reported as a problem?
>> >>>
>> >>>
>> >>> My first guess would be that pid 3348 did 2 calls to open and the urb
>> >>> was somehow referenced across these calls. Is it possible?
>> >>
>> >> I don't think so. The URB gets allocated and deallocated separately
>> >> for each call. You can see this very plainly by reading the source
>> >> code for usb_internal_control_msg() and usb_start_wait_urb().
>> >>
>> >> It's possible that the same memory location was allocated and
>> >> deallocated for two different calls at different times. That wouldn't
>> >> fool syzkaller, would it?
>> >
>> >
>> > Generally it does not fool KASAN because of heap memory quarantine.
>> > I will take a closer look tomorrow.
>> > Thanks for looking into this.
>>
>>
>> The bug looks real to me and it can be easily reproduced by executing:
>>
>> mmap(&(0x7f0000000000/0xfff000)=nil, (0xfff000), 0x3, 0x32,
>> 0xffffffffffffffff, 0x0)
>> syz_open_dev$usb(&(0x7f0000001000-0x15)="2f6465762f6275732f7573622f3030232f30302300",
>> 0x1ff, 0x200)
>> syz_open_dev$usb(&(0x7f0000002000-0x15)="2f6465762f6275732f7573622f3030232f30302300",
>> 0x3f, 0x0)
>
> (Incidentally, those ASCII strings say "/dev/bus/usb/00#/00#", which is
> a rather unusual name for a USB device node. Where did it come from?)
We use "/dev/bus/usb/00#/00#" to enumerate all devices in the
syzkaller (# are later replaced by some numbers).
>> and failing 7-th malloc in the first one, this one:
>>
>> kzalloc include/linux/slab.h:663 [inline]
>> rh_call_control drivers/usb/core/hcd.c:522 [inline]
>>
>> From the report:
>>
>> (from the failure stack)
>> kmalloc in rh_call_control fails, and it straight returns -ENOMEM
>> without calling usb_hcd_unlink_urb_from_ep(hcd, urb) leaving urb
>> linked into hcd (and that's probably the root problem)
>
> Ah, very good detective work! I agree.
>
>> consequently:
>> rh_urb_enqueue return -ENOMEM
>> usb_hcd_submit_urb does INIT_LIST_HEAD(&urb->urb_list), but the urb is
>> still linked, so we got corrupted list
>> (from the free stack)
>> eventually usb_start_wait_urb frees the still linked urb by calling usb_free_urb
>> (form the use-after-free stack)
>> the subsequent open links a new urb into the corrupted list in
>> usb_hcd_link_urb_to_ep
>> bang!
>
> Here's a patch to fix the problem; let me know how it works.
Yes, this works.
Tested-by: Dmitry Vyukov <[email protected]>
Thanks!
> Alan
>
>
> Index: usb-4.x/drivers/usb/core/hcd.c
> ===================================================================
> --- usb-4.x.orig/drivers/usb/core/hcd.c
> +++ usb-4.x/drivers/usb/core/hcd.c
> @@ -520,8 +520,10 @@ static int rh_call_control (struct usb_h
> */
> tbuf_size = max_t(u16, sizeof(struct usb_hub_descriptor), wLength);
> tbuf = kzalloc(tbuf_size, GFP_KERNEL);
> - if (!tbuf)
> - return -ENOMEM;
> + if (!tbuf) {
> + status = -ENOMEM;
> + goto err_alloc;
> + }
>
> bufp = tbuf;
>
> @@ -734,6 +736,7 @@ error:
> }
>
> kfree(tbuf);
> + err_alloc:
>
> /* any errors get returned through the urb completion */
> spin_lock_irq(&hcd_root_hub_lock);
>