WARNING: refcount bug in find_key_to_update

[syzbot]

Hello,

syzbot found the following crash on:

HEAD commit: bc88f85c kthread: make __kthread_queue_delayed_work static
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=1730584b600000
kernel config: https://syzkaller.appspot.com/x/.config?x=e0ac4d9b35046343
dashboard link: https://syzkaller.appspot.com/bug?extid=6455648abc28dbdd1e7f
compiler: gcc (GCC) 9.0.0 20181231 (experimental)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=11c8adab600000

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+645564...@syzkaller.appspotmail.com

------------[ cut here ]------------
refcount_t: increment on 0; use-after-free.
WARNING: CPU: 1 PID: 9064 at lib/refcount.c:156 refcount_inc_checked
lib/refcount.c:156 [inline]
WARNING: CPU: 1 PID: 9064 at lib/refcount.c:156
refcount_inc_checked+0x61/0x70 lib/refcount.c:154
Kernel panic - not syncing: panic_on_warn set ...
CPU: 1 PID: 9064 Comm: syz-executor.5 Not tainted 5.4.0-rc3+ #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x172/0x1f0 lib/dump_stack.c:113
panic+0x2e3/0x75c kernel/panic.c:221
__warn.cold+0x2f/0x35 kernel/panic.c:582
report_bug+0x289/0x300 lib/bug.c:195
fixup_bug arch/x86/kernel/traps.c:179 [inline]
fixup_bug arch/x86/kernel/traps.c:174 [inline]
do_error_trap+0x11b/0x200 arch/x86/kernel/traps.c:272
do_invalid_op+0x37/0x50 arch/x86/kernel/traps.c:291
invalid_op+0x23/0x30 arch/x86/entry/entry_64.S:1028
RIP: 0010:refcount_inc_checked lib/refcount.c:156 [inline]
RIP: 0010:refcount_inc_checked+0x61/0x70 lib/refcount.c:154
Code: 1d 58 46 7e 06 31 ff 89 de e8 0b cb 2e fe 84 db 75 dd e8 c2 c9 2e fe
48 c7 c7 40 ad e6 87 c6 05 38 46 7e 06 01 e8 67 0c 00 fe <0f> 0b eb c1 90
90 90 90 90 90 90 90 90 90 90 55 48 89 e5 41 57 41
RSP: 0018:ffff888081447c68 EFLAGS: 00010286
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
RDX: 0000000000000000 RSI: ffffffff815cb646 RDI: ffffed1010288f7f
RBP: ffff888081447c78 R08: ffff8880a231a080 R09: ffffed1015d26159
R10: ffffed1015d26158 R11: ffff8880ae930ac7 R12: ffff8880a4518940
R13: 0000000000000000 R14: ffff888081447e10 R15: ffff8880a4518c40
__key_get include/linux/key.h:281 [inline]
find_key_to_update+0x8b/0xc0 security/keys/keyring.c:1127
key_create_or_update+0x588/0xbe0 security/keys/key.c:905
__do_sys_add_key security/keys/keyctl.c:132 [inline]
__se_sys_add_key security/keys/keyctl.c:72 [inline]
__x64_sys_add_key+0x2bd/0x4f0 security/keys/keyctl.c:72
do_syscall_64+0xfa/0x760 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x459a59
Code: fd b7 fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 48 89 f8 48 89 f7
48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff
ff 0f 83 cb b7 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f22e3171c78 EFLAGS: 00000246 ORIG_RAX: 00000000000000f8
RAX: ffffffffffffffda RBX: 0000000000000005 RCX: 0000000000459a59
RDX: 0000000020000440 RSI: 0000000020000000 RDI: 0000000020000040
RBP: 000000000075bf20 R08: fffffffffffffffe R09: 0000000000000000
R10: 0000000000000001 R11: 0000000000000246 R12: 00007f22e31726d4
R13: 00000000004bfab8 R14: 00000000004d1ad8 R15: 00000000ffffffff
Kernel Offset: disabled
Rebooting in 86400 seconds..


---
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 syzk...@googlegroups.com.

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

[syzbot]

syzbot has bisected this bug to:

commit 0570bc8b7c9b41deba6f61ac218922e7168ad648
Author: Linus Torvalds <torv...@linux-foundation.org>
Date: Thu Jul 18 19:26:59 2019 +0000

Merge tag 'riscv/for-v5.3-rc1' of
git://git.kernel.org/pub/scm/linux/kernel/git/riscv/linux

bisection log: https://syzkaller.appspot.com/x/bisect.txt?x=11b6e2bb600000
start commit: bc88f85c kthread: make __kthread_queue_delayed_work static
git tree: upstream
final crash: https://syzkaller.appspot.com/x/report.txt?x=13b6e2bb600000
console output: https://syzkaller.appspot.com/x/log.txt?x=15b6e2bb600000

kernel config: https://syzkaller.appspot.com/x/.config?x=e0ac4d9b35046343
dashboard link: https://syzkaller.appspot.com/bug?extid=6455648abc28dbdd1e7f

syz repro: https://syzkaller.appspot.com/x/repro.syz?x=11c8adab600000

Reported-by: syzbot+645564...@syzkaller.appspotmail.com
Fixes: 0570bc8b7c9b ("Merge tag 'riscv/for-v5.3-rc1' of
git://git.kernel.org/pub/scm/linux/kernel/git/riscv/linux")

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

[Hillf Danton]

On Wed, 16 Oct 2019 18:42:11 -0700

> Hello,
>
> syzbot found the following crash on:
>

> HEAD commit: bc88f85c kthread: make __kthread_queue_delayed_work static
> git tree: upstream
> console output: https://syzkaller.appspot.com/x/log.txt?x=1730584b600000

> kernel config: https://syzkaller.appspot.com/x/.config?x=e0ac4d9b35046343
> dashboard link: https://syzkaller.appspot.com/bug?extid=6455648abc28dbdd1e7f

Add tryget helper.

--- a/security/keys/keyring.c
+++ b/security/keys/keyring.c
@@ -1085,6 +1085,11 @@ error:
}
EXPORT_SYMBOL(keyring_restrict);

+static inline bool key_tryget(struct key *key)
+{
+ return refcount_inc_not_zero(&key->usage);
+}
+
/*
* Search the given keyring for a key that might be updated.
*
@@ -1122,11 +1127,10 @@ key_ref_t find_key_to_update(key_ref_t k
found:
key = keyring_ptr_to_key(object);
if (key->flags & ((1 << KEY_FLAG_INVALIDATED) |
- (1 << KEY_FLAG_REVOKED))) {
+ (1 << KEY_FLAG_REVOKED)) || !key_tryget(key)) {
kleave(" = NULL [x]");
return NULL;
}
- __key_get(key);
kleave(" = {%d}", key->serial);
return make_key_ref(key, is_key_possessed(keyring_ref));
}

[Linus Torvalds]

On Wed, Oct 16, 2019 at 7:42 PM syzbot
<syzbot+645564...@syzkaller.appspotmail.com> wrote:
>
> syzbot has bisected this bug to 0570bc8b7c9b ("Merge tag
> 'riscv/for-v5.3-rc1' ...")

Yeah, that looks unlikely. The only non-riscv changes are from
documentation updates and moving a config variable around.

Looks like the crash is quite unlikely, and only happens in one out of
ten runs for the ones it has happened to.

The backtrace looks simple enough, though:

RIP: 0010:refcount_inc_checked+0x2b/0x30 lib/refcount.c:156
__key_get include/linux/key.h:281 [inline]
find_key_to_update+0x67/0x80 security/keys/keyring.c:1127
key_create_or_update+0x4e5/0xb20 security/keys/key.c:905

__do_sys_add_key security/keys/keyctl.c:132 [inline]
__se_sys_add_key security/keys/keyctl.c:72 [inline]

__x64_sys_add_key+0x219/0x3f0 security/keys/keyctl.c:72
do_syscall_64+0xd0/0x540 arch/x86/entry/common.c:296
entry_SYSCALL_64_after_hwframe+0x49/0xbe

which to me implies that there's some locking bug, and somebody
released the key without holding a lock.

That code looks a bit confused to me. Releasing a key without holding
a lock looks permitted, but if that's the case then __key_get() is
complete garbage. It would need to use 'refcount_inc_not_zero()' and
failure would require failing the caller.

But I haven't followed the key locking rules, so who knows. That "put
without lock" scenario would explain the crash, though.

David?

Linus

[Eric Biggers]

Yes this is a bogus bisection.

The key is supposed to have refcount >= 1 since it's in a keyring.
So some bug is causing it to have refcount 0. Perhaps some place calling
key_put() too many times.

Unfortunately I can't get the reproducer to work locally.

Note that there are 2 other syzbot reports that look related.
No reproducers for them, though:

Title: KASAN: use-after-free Read in key_put
Last occurred: 1 day ago
Reported: 28 days ago
Branches: Mainline
Dashboard link: https://syzkaller.appspot.com/bug?id=f13750b1124e01191250cf930086dcc40740fa30
Original thread: https://lore.kernel.org/lkml/0000000000008c...@google.com/T/#u

Title: KASAN: use-after-free Read in keyring_compare_object
Last occurred: 49 days ago
Reported: 84 days ago
Branches: Mainline
Dashboard link: https://syzkaller.appspot.com/bug?id=529ab6a98286c2a97c445988a62760a58d4a1d4b
Original thread: https://lore.kernel.org/lkml/00000000000003...@google.com/T/#u

- Eric

[Tetsuo Handa]

On 2019/10/18 1:00, Eric Biggers wrote:
> The key is supposed to have refcount >= 1 since it's in a keyring.
> So some bug is causing it to have refcount 0. Perhaps some place calling
> key_put() too many times.
>
> Unfortunately I can't get the reproducer to work locally.
>
> Note that there are 2 other syzbot reports that look related.
> No reproducers for them, though:
>
> Title: KASAN: use-after-free Read in key_put
> Last occurred: 1 day ago
> Reported: 28 days ago
> Branches: Mainline
> Dashboard link: https://syzkaller.appspot.com/bug?id=f13750b1124e01191250cf930086dcc40740fa30
> Original thread: https://lore.kernel.org/lkml/0000000000008c...@google.com/T/#u
>
> Title: KASAN: use-after-free Read in keyring_compare_object
> Last occurred: 49 days ago
> Reported: 84 days ago
> Branches: Mainline
> Dashboard link: https://syzkaller.appspot.com/bug?id=529ab6a98286c2a97c445988a62760a58d4a1d4b
> Original thread: https://lore.kernel.org/lkml/00000000000003...@google.com/T/#u
>

I don't know about keys, but I rather suspect lack of serialization locks between
"looking up for checking existing keys" versus "looking up for garbage collection".
Can we dump locks held by current thread when panic() is called?

[David Howells]

Linus Torvalds <torv...@linux-foundation.org> wrote:

> The backtrace looks simple enough, though:
>
> RIP: 0010:refcount_inc_checked+0x2b/0x30 lib/refcount.c:156
> __key_get include/linux/key.h:281 [inline]
> find_key_to_update+0x67/0x80 security/keys/keyring.c:1127
> key_create_or_update+0x4e5/0xb20 security/keys/key.c:905
> __do_sys_add_key security/keys/keyctl.c:132 [inline]
> __se_sys_add_key security/keys/keyctl.c:72 [inline]
> __x64_sys_add_key+0x219/0x3f0 security/keys/keyctl.c:72
> do_syscall_64+0xd0/0x540 arch/x86/entry/common.c:296
> entry_SYSCALL_64_after_hwframe+0x49/0xbe
>
> which to me implies that there's some locking bug, and somebody
> released the key without holding a lock.
>
> That code looks a bit confused to me. Releasing a key without holding
> a lock looks permitted, but if that's the case then __key_get() is
> complete garbage. It would need to use 'refcount_inc_not_zero()' and
> failure would require failing the caller.

find_key_to_update() must be called with the keyring-to-be-searched locked, as
stated in the comment on that function.

If a key-to-be-updated can be found in that keyring, then the keyring must be
holding a ref on that key already, so it's refcount must be > 0, so it
shouldn't be necessary to use refcount_inc_not_zero().

There shouldn't be a race with key_link(), key_unlink(), key_move(),
keyring_clear() or keyring_gc() (garbage collection) as all of those take a
write-lock on the keyring.

> But I haven't followed the key locking rules, so who knows. That "put
> without lock" scenario would explain the crash, though.

That shouldn't explain it. When key_put() reduces the refcount to 0, it just
schedules the garbage collector. It doesn't touch the key again directly.

I would guess that something incorrectly put a ref when it shouldn't have. Do
we know which type of key is involved? Looking at the syzkaller reproducer,
it's adding an encrypted key and a user key to the process keyring -
presumably repeating the procedure within the same process, hence how it finds
something to update.

David

[David Howells]

Tetsuo Handa <penguin...@I-love.SAKURA.ne.jp> wrote:

> I don't know about keys, but I rather suspect lack of serialization locks
> between "looking up for checking existing keys" versus "looking up for
> garbage collection".

The garbage collector holds key_serial_lock when walking key_serial_tree
looking for keys to destroy.

As the gc is the *only* thing that is permitted to remove a key from
key_serial_tree, it can safely keep a cursor pointer to the node it was
looking at when it drops the lock - and then resume scanning once it has taken
the lock again.

When find_key_to_update() is looking for a key that might be updated, the
caller *must* be holding the destination keyring lock and every key in the
keyring should have at least one ref on it held by the keyring - so none of
them should get destroyed by the garbage collector.

David

[David Howells]

Hillf Danton <hda...@sina.com> wrote:

> - (1 << KEY_FLAG_REVOKED))) {
> + (1 << KEY_FLAG_REVOKED)) || !key_tryget(key)) {
> kleave(" = NULL [x]");
> return NULL;
> }
> - __key_get(key);

That should be ineffective and ought not to fix the bug.

David

[David Howells]

syzbot <syzbot+645564...@syzkaller.appspotmail.com> wrote:

> syz repro: https://syzkaller.appspot.com/x/repro.syz?x=11c8adab600000

How do I tell what's been passed into the add_key for the encrypted key?

David

[Dmitry Vyukov]

Hi David,

The easiest and most reliable would be to run it and dump the data in
the kernel function.

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer still triggered
crash:
KASAN: use-after-free Read in find_key_to_update

Bad refcount user syz
==================================================================
BUG: KASAN: use-after-free in atomic_read
include/asm-generic/atomic-instrumented.h:26 [inline]
BUG: KASAN: use-after-free in refcount_inc_not_zero_checked+0x81/0x200
lib/refcount.c:123
Read of size 4 at addr ffff888099bfb000 by task syz-executor.1/27415

CPU: 0 PID: 27415 Comm: syz-executor.1 Not tainted 5.4.0-rc3+ #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x172/0x1f0 lib/dump_stack.c:113

print_address_description.constprop.0.cold+0xd4/0x30b mm/kasan/report.c:374
__kasan_report.cold+0x1b/0x41 mm/kasan/report.c:506
kasan_report+0x12/0x20 mm/kasan/common.c:634
check_memory_region_inline mm/kasan/generic.c:185 [inline]
check_memory_region+0x134/0x1a0 mm/kasan/generic.c:192
__kasan_check_read+0x11/0x20 mm/kasan/common.c:92
atomic_read include/asm-generic/atomic-instrumented.h:26 [inline]
refcount_inc_not_zero_checked+0x81/0x200 lib/refcount.c:123
refcount_inc_checked+0x17/0x70 lib/refcount.c:156
__key_get include/linux/key.h:281 [inline]
find_key_to_update+0xe3/0x110 security/keys/keyring.c:1130
key_create_or_update+0x588/0xbe0 security/keys/key.c:905

__do_sys_add_key security/keys/keyctl.c:132 [inline]
__se_sys_add_key security/keys/keyctl.c:72 [inline]

__x64_sys_add_key+0x2bd/0x4f0 security/keys/keyctl.c:72
do_syscall_64+0xfa/0x760 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe

RIP: 0033:0x459a59
Code: fd b7 fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 48 89 f8 48 89 f7
48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff
ff 0f 83 cb b7 fb ff c3 66 2e 0f 1f 84 00 00 00 00

RSP: 002b:00007f526ca0dc78 EFLAGS: 00000246 ORIG_RAX: 00000000000000f8

RAX: ffffffffffffffda RBX: 0000000000000005 RCX: 0000000000459a59
RDX: 0000000020000440 RSI: 0000000020000000 RDI: 0000000020000040
RBP: 000000000075bf20 R08: fffffffffffffffe R09: 0000000000000000

R10: 0000000000000001 R11: 0000000000000246 R12: 00007f526ca0e6d4

R13: 00000000004bfab8 R14: 00000000004d1ad8 R15: 00000000ffffffff

Allocated by task 27415:
save_stack+0x23/0x90 mm/kasan/common.c:69
set_track mm/kasan/common.c:77 [inline]
__kasan_kmalloc mm/kasan/common.c:510 [inline]
__kasan_kmalloc.constprop.0+0xcf/0xe0 mm/kasan/common.c:483
kasan_slab_alloc+0xf/0x20 mm/kasan/common.c:518
slab_post_alloc_hook mm/slab.h:584 [inline]
slab_alloc mm/slab.c:3319 [inline]
kmem_cache_alloc+0x121/0x710 mm/slab.c:3483
kmem_cache_zalloc include/linux/slab.h:680 [inline]
key_alloc+0x426/0x1110 security/keys/key.c:276
key_create_or_update+0x652/0xbe0 security/keys/key.c:924

__do_sys_add_key security/keys/keyctl.c:132 [inline]
__se_sys_add_key security/keys/keyctl.c:72 [inline]

__x64_sys_add_key+0x2bd/0x4f0 security/keys/keyctl.c:72
do_syscall_64+0xfa/0x760 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe

Freed by task 5:
save_stack+0x23/0x90 mm/kasan/common.c:69
set_track mm/kasan/common.c:77 [inline]
kasan_set_free_info mm/kasan/common.c:332 [inline]
__kasan_slab_free+0x102/0x150 mm/kasan/common.c:471
kasan_slab_free+0xe/0x10 mm/kasan/common.c:480
__cache_free mm/slab.c:3425 [inline]
kmem_cache_free+0x86/0x320 mm/slab.c:3693
key_gc_unused_keys.constprop.0+0x194/0x5b0 security/keys/gc.c:157
key_garbage_collector+0x3f3/0x940 security/keys/gc.c:292
process_one_work+0x9af/0x1740 kernel/workqueue.c:2269
worker_thread+0x98/0xe40 kernel/workqueue.c:2415
kthread+0x361/0x430 kernel/kthread.c:255
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352

The buggy address belongs to the object at ffff888099bfb000
which belongs to the cache key_jar of size 312
The buggy address is located 0 bytes inside of
312-byte region [ffff888099bfb000, ffff888099bfb138)
The buggy address belongs to the page:
page:ffffea000266fec0 refcount:1 mapcount:0 mapping:ffff88821bc4f000
index:0x0
flags: 0x1fffc0000000200(slab)
raw: 01fffc0000000200 ffffea0002022048 ffffea00025ed788 ffff88821bc4f000
raw: 0000000000000000 ffff888099bfb000 000000010000000a 0000000000000000
page dumped because: kasan: bad access detected

Memory state around the buggy address:
ffff888099bfaf00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fc
ffff888099bfaf80: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
> ffff888099bfb000: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
^
ffff888099bfb080: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
ffff888099bfb100: fb fb fb fb fb fb fb fc fc fc fc fc fc fc fc fc
==================================================================


Tested on:

commit: 7f002fe7 keys: Attempt to debug syzcaller-induced refcount..
git tree:
git://git.kernel.org/pub/scm/linux/kernel/git/dhowells/linux-fs.git
console output: https://syzkaller.appspot.com/x/log.txt?x=165c8d64e00000

[syzbot]

Hello,

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

Reported-and-tested-by:
syzbot+645564...@syzkaller.appspotmail.com

Tested on:

commit: 0e5bbd42 keys: Attempt to debug syzcaller-induced refcount..
git tree:
git://git.kernel.org/pub/scm/linux/kernel/git/dhowells/linux-fs.git

kernel config: https://syzkaller.appspot.com/x/.config?x=e0ac4d9b35046343
dashboard link: https://syzkaller.appspot.com/bug?extid=6455648abc28dbdd1e7f
compiler: gcc (GCC) 9.0.0 20181231 (experimental)

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

[David Howells]

Linus Torvalds <torv...@linux-foundation.org> wrote:

> > syzbot has bisected this bug to 0570bc8b7c9b ("Merge tag
> > 'riscv/for-v5.3-rc1' ...")
>
> Yeah, that looks unlikely. The only non-riscv changes are from
> documentation updates and moving a config variable around.
>
> Looks like the crash is quite unlikely, and only happens in one out of
> ten runs for the ones it has happened to.
>
> The backtrace looks simple enough, though:
>
> RIP: 0010:refcount_inc_checked+0x2b/0x30 lib/refcount.c:156
> __key_get include/linux/key.h:281 [inline]
> find_key_to_update+0x67/0x80 security/keys/keyring.c:1127
> key_create_or_update+0x4e5/0xb20 security/keys/key.c:905
> __do_sys_add_key security/keys/keyctl.c:132 [inline]
> __se_sys_add_key security/keys/keyctl.c:72 [inline]
> __x64_sys_add_key+0x219/0x3f0 security/keys/keyctl.c:72
> do_syscall_64+0xd0/0x540 arch/x86/entry/common.c:296
> entry_SYSCALL_64_after_hwframe+0x49/0xbe
>
> which to me implies that there's some locking bug, and somebody
> released the key without holding a lock.

I'm wondering if this is actually a bug in the error handling in the encrypted
key type. Looking in the syzbot console log, there's a lot of output from
there prior to the crash, of which the following is an excerpt:

[ 248.516746][T27381] encrypted_key: key user:syz not found
[ 248.524392][T27382] encrypted_key: key user:syz not found
[ 248.616141][T27392] encrypted_key: key user:syz not found
[ 248.618890][T27393] encrypted_key: key user:syz not found
[ 248.690844][T27404] encrypted_key: key user:syz not found
[ 248.739405][T27403] encrypted_key: key user:syz not found
[ 248.804881][T27417] encrypted_key: key user:syz not found
[ 248.828354][T27418] encrypted_key: keyword 'new' not allowed when called from .update method
[ 248.925249][T27427] encrypted_key: keyword 'new' not allowed when called from .update method
[ 248.928200][T27415] Bad refcount user syz
[ 248.934043][T27428] encrypted_key: key user:syz not found
[ 248.939502][T27429] encrypted_key: key user:syz not found
[ 248.968744][T27434] encrypted_key: key user:syz not found
[ 248.982201][T27415] ==================================================================
[ 248.996072][T27415] BUG: KASAN: use-after-free in refcount_inc_not_zero_checked+0x81/0x200

Note that the "Bad refcount user syz" is a bit I patched in to print the type
and description of the key that incurred the error.

It's a tad difficult to say exactly what's going on since I've no idea what
the syzbot reproducer is actually doing.

#{"threaded":true,"collide":true,"repeat":true,"procs":6,"sandbox":"namespace","fault_call":-1,"tun":true,"netdev":true,"resetnet":true,"cgroups":true,"binfmt_misc":true,"close_fds":true,"tmpdir":true,"segv":true}
perf_event_open(&(0x7f000001d000)={0x1, 0x70, 0x0, 0x0, 0x0, 0x0, 0x0, 0x7f, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x7, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, @perf_config_ext}, 0x0, 0xffffffffffffffff, 0xffffffffffffffff, 0x0)
keyctl$instantiate(0xc, 0x0, &(0x7f0000000100)=ANY=[@ANYBLOB='new default user:syz 04096'], 0x1, 0x0)
r0 = add_key(&(0x7f0000000140)='encrypted\x00', &(0x7f0000000180)={'syz'}, &(0x7f0000000100), 0xca, 0xfffffffffffffffe)
add_key$user(&(0x7f0000000040)='user\x00', &(0x7f0000000000)={'syz'}, &(0x7f0000000440)='X', 0x1, 0xfffffffffffffffe)
keyctl$read(0xb, r0, &(0x7f0000000240)=""/112, 0x349b7f55)

However, it looks like the encrypted key type is trying to access a user key,
so maybe there's an overput there? I'm trying to insert more debugging, but
the test doesn't always fail.

syzbot <syzbot+645564...@syzkaller.appspotmail.com> wrote:

> HEAD commit: bc88f85c kthread: make __kthread_queue_delayed_work static
> git tree: upstream
> console output: https://syzkaller.appspot.com/x/log.txt?x=1730584b600000

> kernel config: https://syzkaller.appspot.com/x/.config?x=e0ac4d9b35046343
> dashboard link: https://syzkaller.appspot.com/bug?extid=6455648abc28dbdd1e7f

> compiler: gcc (GCC) 9.0.0 20181231 (experimental)
> syz repro: https://syzkaller.appspot.com/x/repro.syz?x=11c8adab600000

David

[syzbot]

Hello,

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

Reported-and-tested-by:
syzbot+645564...@syzkaller.appspotmail.com

Tested on:

commit: 0e5bbd42 keys: Attempt to debug syzcaller-induced refcount..
git tree:
git://git.kernel.org/pub/scm/linux/kernel/git/dhowells/linux-fs.git

kernel config: https://syzkaller.appspot.com/x/.config?x=e0ac4d9b35046343
dashboard link: https://syzkaller.appspot.com/bug?extid=6455648abc28dbdd1e7f
compiler: gcc (GCC) 9.0.0 20181231 (experimental)

[syzbot]

Hello,

syzbot has tested the proposed patch but the reproducer still triggered
crash:

WARNING: refcount bug in find_key_to_update

Bad refcount user syz

------------[ cut here ]------------
refcount_t: increment on 0; use-after-free.

WARNING: CPU: 1 PID: 1582 at lib/refcount.c:156 refcount_inc_checked
lib/refcount.c:156 [inline]
WARNING: CPU: 1 PID: 1582 at lib/refcount.c:156

refcount_inc_checked+0x61/0x70 lib/refcount.c:154
Kernel panic - not syncing: panic_on_warn set ...

CPU: 1 PID: 1582 Comm: syz-executor.2 Not tainted 5.4.0-rc3+ #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x172/0x1f0 lib/dump_stack.c:113

panic+0x2e3/0x75c kernel/panic.c:221
__warn.cold+0x2f/0x35 kernel/panic.c:582
report_bug+0x289/0x300 lib/bug.c:195
fixup_bug arch/x86/kernel/traps.c:179 [inline]
fixup_bug arch/x86/kernel/traps.c:174 [inline]
do_error_trap+0x11b/0x200 arch/x86/kernel/traps.c:272
do_invalid_op+0x37/0x50 arch/x86/kernel/traps.c:291
invalid_op+0x23/0x30 arch/x86/entry/entry_64.S:1028
RIP: 0010:refcount_inc_checked lib/refcount.c:156 [inline]
RIP: 0010:refcount_inc_checked+0x61/0x70 lib/refcount.c:154

Code: 1d 38 46 7e 06 31 ff 89 de e8 ab c9 2e fe 84 db 75 dd e8 62 c8 2e fe
48 c7 c7 c0 ad e6 87 c6 05 18 46 7e 06 01 e8 07 0b 00 fe <0f> 0b eb c1 90

90 90 90 90 90 90 90 90 90 90 55 48 89 e5 41 57 41

RSP: 0018:ffff88807d147c60 EFLAGS: 00010282

RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000

RDX: 0000000000000000 RSI: ffffffff815cb646 RDI: ffffed100fa28f7e
RBP: ffff88807d147c70 R08: ffff888096c70140 R09: ffffed1015d24101
R10: ffffed1015d24100 R11: ffff8880ae920807 R12: ffff8880a59436c0
R13: ffffffff892cb640 R14: ffff88808fc14ec0 R15: ffff8880a5da5940

__key_get include/linux/key.h:281 [inline]
find_key_to_update+0xe3/0x110 security/keys/keyring.c:1130

key_create_or_update+0x588/0xbe0 security/keys/key.c:905

__do_sys_add_key security/keys/keyctl.c:132 [inline]
__se_sys_add_key security/keys/keyctl.c:72 [inline]

__x64_sys_add_key+0x2bd/0x4f0 security/keys/keyctl.c:72
do_syscall_64+0xfa/0x760 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x459a59
Code: fd b7 fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 48 89 f8 48 89 f7
48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff
ff 0f 83 cb b7 fb ff c3 66 2e 0f 1f 84 00 00 00 00

RSP: 002b:00007f9c4e077c78 EFLAGS: 00000246 ORIG_RAX: 00000000000000f8

RAX: ffffffffffffffda RBX: 0000000000000005 RCX: 0000000000459a59
RDX: 0000000020000440 RSI: 0000000020000000 RDI: 0000000020000040
RBP: 000000000075bf20 R08: fffffffffffffffe R09: 0000000000000000

R10: 0000000000000001 R11: 0000000000000246 R12: 00007f9c4e0786d4

R13: 00000000004bfab8 R14: 00000000004d1ad8 R15: 00000000ffffffff

Kernel Offset: disabled
Rebooting in 86400 seconds..

Tested on:

commit: 0e5bbd42 keys: Attempt to debug syzcaller-induced refcount..
git tree:
git://git.kernel.org/pub/scm/linux/kernel/git/dhowells/linux-fs.git

console output: https://syzkaller.appspot.com/x/log.txt?x=16e6c3d8e00000

[David Howells]

Okay, I managed to catch a backtrace for this line:

encrypted_key: key user:syz not found (-126)

looking like:

CPU: 0 PID: 8878 Comm: syz-executor.0 Not tainted 5.4.0-rc3+ #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:

dump_stack+0x172/0x1f0
request_master_key.isra.0.cold+0x62/0xc3
encrypted_read+0x221/0x830
? get_derived_key+0xf0/0xf0
? keyctl_read_key+0x1c2/0x2b0
? __kasan_check_write+0x14/0x20
? down_read+0x109/0x430
? security_key_permission+0x8d/0xc0
? down_read_killable+0x490/0x490
? key_task_permission+0x1b5/0x3a0
keyctl_read_key+0x231/0x2b0
__x64_sys_keyctl+0x171/0x470
do_syscall_64+0xfa/0x760
entry_SYSCALL_64_after_hwframe+0x49/0xbe

So something somewhere is calling keyctl_read() in userspace on the encrypted
key and that is then referring across to the user key added.

Also, the encrypted key is being given the following payload:

ENCRYPTED: 'new default user:syz 04096'

in at least one of the cases that encrypted_update() being called.

David

[syzbot]

Auto-closing this bug as obsolete.
No recent activity, existing reproducers are no longer triggering the issue.