KASAN: use-after-free Read in binder_release_work

[syzbot]

Hello,

syzbot hit the following crash on upstream commit
f2d285669aae656dfeafa0bf25e86bbbc5d22329 (Tue Apr 3 17:45:39 2018 +0000)
Merge tag 'pm-4.17-rc1' of
git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm
syzbot dashboard link:
https://syzkaller.appspot.com/bug?extid=0cf1f1aa154f56ff2e8d

So far this crash happened 4 times on upstream.
C reproducer: https://syzkaller.appspot.com/x/repro.c?id=4827186146050048
syzkaller reproducer:
https://syzkaller.appspot.com/x/repro.syz?id=6025869373997056
Raw console output:
https://syzkaller.appspot.com/x/log.txt?id=4772918563176448
Kernel config: https://syzkaller.appspot.com/x/.config?id=686016073509112605
compiler: gcc (GCC) 7.1.1 20170620

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+0cf1f1...@syzkaller.appspotmail.com
It will help syzbot understand when the bug is fixed. See footer for
details.
If you forward the report, please keep this part and the footer.

binder: 4616:4618 transaction failed 29189/-3, size 0-0 line 2963
binder: release 4616:4618 transaction 114 in, still active
binder: send failed reply for transaction 114 to 4616:4618
binder: 4620:4621 ioctl 400448c8 20000200 returned -22
==================================================================
BUG: KASAN: use-after-free in __list_del_entry_valid+0x144/0x150
lib/list_debug.c:54
Read of size 8 at addr ffff8801d39a4210 by task kworker/1:2/1891

CPU: 1 PID: 1891 Comm: kworker/1:2 Not tainted 4.16.0+ #378
binder: release 4620:4621 transaction 118 out, still active
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Workqueue: events binder_deferred_func
Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x1a7/0x27d lib/dump_stack.c:53
binder: release 4620:4621 transaction 117 in, still active
print_address_description+0x73/0x250 mm/kasan/report.c:256
binder: undelivered TRANSACTION_COMPLETE
kasan_report_error mm/kasan/report.c:354 [inline]
kasan_report+0x23c/0x360 mm/kasan/report.c:412
__asan_report_load8_noabort+0x14/0x20 mm/kasan/report.c:433
binder: BINDER_SET_CONTEXT_MGR already set
__list_del_entry_valid+0x144/0x150 lib/list_debug.c:54
binder: 4620:4622 ioctl 40046207 0 returned -16
__list_del_entry include/linux/list.h:117 [inline]
list_del_init include/linux/list.h:159 [inline]
binder_dequeue_work_head_ilocked drivers/android/binder.c:893 [inline]
binder_dequeue_work_head drivers/android/binder.c:913 [inline]
binder_release_work+0x163/0x4b0 drivers/android/binder.c:4191
binder: 4620:4621 ioctl c0306201 20004000 returned -14
binder: 4620:4621 ioctl 400448c8 20000200 returned -22
binder_thread_release+0x4e1/0x730 drivers/android/binder.c:4396
binder_alloc: binder_alloc_mmap_handler: 4620 2000c000-2000e000 already
mapped failed -16
binder_deferred_release drivers/android/binder.c:4939 [inline]
binder_deferred_func+0x4f4/0x1350 drivers/android/binder.c:5022
binder_alloc: 4620: binder_alloc_buf, no vma
binder: 4620:4623 transaction failed 29189/-3, size 0-0 line 2963
process_one_work+0xc97/0x1c40 kernel/workqueue.c:2113
binder_alloc: 4620: binder_alloc_buf, no vma
binder: 4620:4621 transaction failed 29189/-3, size 0-0 line 2963
binder: release 4620:4622 transaction 118 in, still active
binder: release 4620:4622 transaction 117 out, still active
worker_thread+0x1c3/0x1380 kernel/workqueue.c:2247
binder: send failed reply for transaction 118, target dead
binder: send failed reply for transaction 117, target dead
binder: BINDER_SET_CONTEXT_MGR already set
binder: 4624:4625 ioctl 40046207 0 returned -16
kthread+0x33c/0x400 kernel/kthread.c:238
binder: 4624:4625 ioctl 400448c8 20000200 returned -22
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:411

binder_alloc: 4620: binder_alloc_buf, no vma
Allocated by task 4618:
save_stack+0x43/0xd0 mm/kasan/kasan.c:447
set_track mm/kasan/kasan.c:459 [inline]
kasan_kmalloc+0xad/0xe0 mm/kasan/kasan.c:552
binder: 4624:4626 transaction failed 29189/-3, size 0-0 line 2963
kmem_cache_alloc_trace+0x136/0x740 mm/slab.c:3608
kmalloc include/linux/slab.h:512 [inline]
kzalloc include/linux/slab.h:701 [inline]
binder_transaction+0x13d2/0x8200 drivers/android/binder.c:2900
binder_thread_write+0xcf1/0x38b0 drivers/android/binder.c:3513
binder_ioctl_write_read.isra.39+0x261/0xcb0 drivers/android/binder.c:4451
binder_ioctl+0xb72/0x1417 drivers/android/binder.c:4591
binder: undelivered TRANSACTION_ERROR: 29189
vfs_ioctl fs/ioctl.c:46 [inline]
do_vfs_ioctl+0x1b1/0x1520 fs/ioctl.c:686
ksys_ioctl+0x94/0xb0 fs/ioctl.c:701
SYSC_ioctl fs/ioctl.c:708 [inline]
SyS_ioctl+0x24/0x30 fs/ioctl.c:706
do_syscall_64+0x281/0x940 arch/x86/entry/common.c:287
entry_SYSCALL_64_after_hwframe+0x42/0xb7
binder: 4624:4626 ioctl c0306201 20004000 returned -14

Freed by task 1891:
save_stack+0x43/0xd0 mm/kasan/kasan.c:447
set_track mm/kasan/kasan.c:459 [inline]
__kasan_slab_free+0x11a/0x170 mm/kasan/kasan.c:520
kasan_slab_free+0xe/0x10 mm/kasan/kasan.c:527
__cache_free mm/slab.c:3486 [inline]
kfree+0xd9/0x260 mm/slab.c:3801
binder: BINDER_SET_CONTEXT_MGR already set
binder_free_transaction+0x6a/0xa0 drivers/android/binder.c:1966
binder_send_failed_reply+0x1c9/0x380 drivers/android/binder.c:2005
binder_thread_release+0x4cc/0x730 drivers/android/binder.c:4395
binder_deferred_release drivers/android/binder.c:4939 [inline]
binder_deferred_func+0x4f4/0x1350 drivers/android/binder.c:5022
process_one_work+0xc97/0x1c40 kernel/workqueue.c:2113
worker_thread+0x1c3/0x1380 kernel/workqueue.c:2247
kthread+0x33c/0x400 kernel/kthread.c:238
binder: 4624:4627 ioctl 40046207 0 returned -16
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:411

The buggy address belongs to the object at ffff8801d39a4200
which belongs to the cache kmalloc-192 of size 192
The buggy address is located 16 bytes inside of
192-byte region [ffff8801d39a4200, ffff8801d39a42c0)
The buggy address belongs to the page:
page:ffffea00074e6900 count:1 mapcount:0 mapping:ffff8801d39a4000 index:0x0
binder: 4624:4626 ioctl 400448c8 20000200 returned -22
flags: 0x2fffc0000000100(slab)
raw: 02fffc0000000100 ffff8801d39a4000 0000000000000000 0000000100000010
raw: ffffea000738fbe0 ffffea00074e6a60 ffff8801dac00040 0000000000000000
page dumped because: kasan: bad access detected

binder_alloc: binder_alloc_mmap_handler: 4624 2000c000-2000e000 already
mapped failed -16
Memory state around the buggy address:
ffff8801d39a4100: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
ffff8801d39a4180: 00 00 00 00 00 00 00 fc fc fc fc fc fc fc fc fc
> ffff8801d39a4200: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
^
ffff8801d39a4280: fb fb fb fb fb fb fb fb fc fc fc fc fc fc fc fc
binder_alloc: 4620: binder_alloc_buf, no vma
ffff8801d39a4300: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
==================================================================


---
This bug is generated by a dumb bot. It may contain errors.
See https://goo.gl/tpsmEJ for details.
Direct all questions to syzk...@googlegroups.com.

syzbot will keep track of this bug report.
If you forgot to add the Reported-by tag, once the fix for this bug is
merged
into any tree, please reply to this email with:
#syz fix: exact-commit-title
If you want to test a patch for this bug, please reply with:
#syz test: git://repo/address.git branch
and provide the patch inline or as an attachment.
To mark this as a duplicate of another syzbot report, please reply with:
#syz dup: exact-subject-of-another-report
If it's a one-off invalid bug report, please reply with:
#syz invalid
Note: if the crash happens again, it will cause creation of a new bug
report.
Note: all commands must start from beginning of the line in the email body.

[Eric Biggers]

Martijn, this is going to be fixed by
https://patchwork.kernel.org/patch/10312345/
("ANDROID: binder: prevent transactions into own process"), right?
The syzbot bug ID in that patch is for a bug that is already closed,
so if it's not too late you should use this one.

- Eric

[Martijn Coenen]

On Thu, Apr 19, 2018 at 11:35 PM, Eric Biggers <ebig...@gmail.com> wrote:
> Martijn, this is going to be fixed by
> https://patchwork.kernel.org/patch/10312345/
> ("ANDROID: binder: prevent transactions into own process"), right?
> The syzbot bug ID in that patch is for a bug that is already closed,
> so if it's not too late you should use this one.

Yeah that should fix it. Why was it closed? I think the syzbot bug ID
I used in that patch was from the original report to LKML. Greg
mentioned the patch was already in his queue.

Thanks,
Martijn

>
> - Eric

[Dmitry Vyukov]

Hi Martijn,

In short: too many bugs in kernel + long turnaround time for fixes.
Originally it was detected as "KASAN: use-after-free Read in
__list_del_entry_valid (3)":
https://syzkaller.appspot.com/bug?extid=09e05aba06723a94d43d
and that happened in binder. But then syzkaller found a reproducer for
it, but it turned out to be in rdma subsystem. It's generally not
possible to properly distinguish different bugs that look similar, and
if syzbot does more sensitive bug classification, then it will also
inevitably report more duplicates. So that bug was closed as an rdma
bug.
Now syzbot already skips list_del frame and takes the next one, so it
should become slightly better.

Let's close this one with the binder fix (since that one was closed
with an rdma fix):

#syz fix: ANDROID: binder: prevent transactions into own process.

[Martijn Coenen]

On Mon, Apr 23, 2018 at 11:28 AM, Dmitry Vyukov <dvy...@google.com> wrote:
> https://syzkaller.appspot.com/bug?extid=09e05aba06723a94d43d
> and that happened in binder. But then syzkaller found a reproducer for
> it, but it turned out to be in rdma subsystem. It's generally not
> possible to properly distinguish different bugs that look similar, and
> if syzbot does more sensitive bug classification, then it will also
> inevitably report more duplicates. So that bug was closed as an rdma
> bug.

Thanks for the clarification! It looks like I sent the patch with the
original reported-by tag after it was closed as an rdma issue; would
it help if syzbot sent a reply saying this bug was already marked as
closed with a different commit, or are there other complications with
that?

Thanks,
Martijn

[Dmitry Vyukov]

On Mon, Apr 23, 2018 at 11:41 AM, Martijn Coenen <ma...@android.com> wrote:
> On Mon, Apr 23, 2018 at 11:28 AM, Dmitry Vyukov <dvy...@google.com> wrote:
>> https://syzkaller.appspot.com/bug?extid=09e05aba06723a94d43d
>> and that happened in binder. But then syzkaller found a reproducer for
>> it, but it turned out to be in rdma subsystem. It's generally not
>> possible to properly distinguish different bugs that look similar, and
>> if syzbot does more sensitive bug classification, then it will also
>> inevitably report more duplicates. So that bug was closed as an rdma
>> bug.
>
> Thanks for the clarification! It looks like I sent the patch with the
> original reported-by tag after it was closed as an rdma issue; would
> it help if syzbot sent a reply saying this bug was already marked as
> closed with a different commit, or are there other complications with
> that?

Since it's already in Greg's queue, it's not worth bothering. We can
fix up things here with these "#syz fix" tags in emails, which
associate fixes with bugs.

[Martijn Coenen]

On Mon, Apr 23, 2018 at 11:49 AM, Dmitry Vyukov <dvy...@google.com> wrote:
> Since it's already in Greg's queue, it's not worth bothering. We can
> fix up things here with these "#syz fix" tags in emails, which
> associate fixes with bugs.

I meant, when I sent the original patch a month or so ago, could
syzbot have replied saying "The reported-by tag you used belongs to a
bug that was already marked as closed by this other commit?".

[Dmitry Vyukov]

On Mon, Apr 23, 2018 at 12:00 PM, Martijn Coenen <ma...@android.com> wrote:
> On Mon, Apr 23, 2018 at 11:49 AM, Dmitry Vyukov <dvy...@google.com> wrote:
>> Since it's already in Greg's queue, it's not worth bothering. We can
>> fix up things here with these "#syz fix" tags in emails, which
>> associate fixes with bugs.
>
> I meant, when I sent the original patch a month or so ago, could
> syzbot have replied saying "The reported-by tag you used belongs to a
> bug that was already marked as closed by this other commit?".

syzbot does not extract this info from patch emails.
First of all, it's not possible to discover them all.
Second, a mailed patch does not mean committed patch. v2 can be resent
and potentially change title too.

syzbot takes this info from commits in the tree it tests. It probably
could extract some emails from the commit. But they can come months
later, so their value will be questionable. Also consider that 2
commits in different trees mention the same bug. syzbot generally
overwrites old info with new info, because that's the only way to fix
up things. Now this can lead to infinite stream of emails saying that
this commit fixes this bug, no that commit fixes this bug, no this
commit fixes this bug, etc.
Also consider that a bug is first marked as fixed with some commit,
bug later is marked as dup of another or re-marked as fixed with
another commit. You won't get a notification, because the whole
sequence looks reasonable.
This can also lead to problems when commits backported to
android/chromeos trees that syzbot also tests. There these fix tags
look plain bogus because they reference upstream bug, not
android/chromeos bugs.

By default we try to keep syzbot silent and non-spammy. And we do not
seem to have lots of such cases where things are somewhat messed. And
in all cases it should come to eventual consistency. If something is
marked as fixed prematurely, syzbot will open another bug. If
something is not marked as fixed (or marked as fixed with a
non-existent commit), then these bugs still hang on the dashboard and
visible.

[Martijn Coenen]

On Mon, Apr 23, 2018 at 12:17 PM, Dmitry Vyukov <dvy...@google.com> wrote:
> syzbot does not extract this info from patch emails.

Ok so IIUC, Reported-By tags will only be considered when they are
actually part of commits in one of the tested trees - makes sense. So
does sending "#syz fix: xyz" cause syzbot to look inside all the trees
it analyzes for xyz and mark it as closed if found? Does it look
immediately or on some schedule, and does it retry? In this case, I
think my patch wasn't in any tree yet when you sent "#syz fix", only
in Greg's queue (Greg actually pushed it half an hour after your
message). Just want to make sure I do the right thing next time.

Thanks,
Martijn

[Dmitry Vyukov]

On Mon, Apr 23, 2018 at 3:28 PM, Martijn Coenen <ma...@android.com> wrote:
> On Mon, Apr 23, 2018 at 12:17 PM, Dmitry Vyukov <dvy...@google.com> wrote:
>> syzbot does not extract this info from patch emails.
>
> Ok so IIUC, Reported-By tags will only be considered when they are
> actually part of commits in one of the tested trees - makes sense. So
> does sending "#syz fix: xyz" cause syzbot to look inside all the trees
> it analyzes for xyz and mark it as closed if found? Does it look
> immediately or on some schedule, and does it retry? In this case, I
> think my patch wasn't in any tree yet when you sent "#syz fix", only
> in Greg's queue (Greg actually pushed it half an hour after your
> message). Just want to make sure I do the right thing next time.

When syzbot web app receives "syz fix" it notes the association. You
can now see it here:
https://syzkaller.appspot.com/bug?id=952e31f49f15c6de449295b8920dcc4ed935ebbf

Commits: ANDROID: binder: prevent transactions into own process.

Then, when test machines pull/build kernel, they send to the web app
which of the pending commits they see in own tree.
On the dashboard you can now see this line:

Patched on: [], missing on: [ci-upstream-bpf-next-kasan-gce
ci-upstream-kasan-gce ci-upstream-kasan-gce-386
ci-upstream-kasan-gce-root ci-upstream-kmsan-gce
ci-upstream-net-kasan-gce]

which means that no tested kernel yet have this commit.
Later the "Patched on" list will be populates as the commit reaches
the trees and test machines rebuild kernels. When all trees are
patched, the bug will be closed.