WARNING in debug_print_object

[syzbot]

Hello,

syzbot hit the following crash on upstream commit
255442c93843f52b6891b21d0b485bf2c97f93c3 (Thu Feb 1 03:25:25 2018 +0000)
Merge tag 'docs-4.16' of git://git.lwn.net/linux

So far this crash happened 2 times on mmots, upstream.
C reproducer is attached.
syzkaller reproducer is attached.
Raw console output is attached.
compiler: gcc (GCC) 7.1.1 20170620
.config is attached.

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+19c097...@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.

------------[ cut here ]------------
ODEBUG: activate active (active state 1) object type: rcu_head
hint: (null)
WARNING: CPU: 0 PID: 5989 at lib/debugobjects.c:291
debug_print_object+0x166/0x220 lib/debugobjects.c:288
Kernel panic - not syncing: panic_on_warn set ...

CPU: 0 PID: 5989 Comm: syzkaller148927 Not tainted 4.15.0+ #290
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x194/0x257 lib/dump_stack.c:53
panic+0x1e4/0x41c kernel/panic.c:183
__warn+0x1dc/0x200 kernel/panic.c:547
report_bug+0x211/0x2d0 lib/bug.c:184
fixup_bug.part.11+0x37/0x80 arch/x86/kernel/traps.c:178
fixup_bug arch/x86/kernel/traps.c:247 [inline]
do_error_trap+0x2d7/0x3e0 arch/x86/kernel/traps.c:296
do_invalid_op+0x1b/0x20 arch/x86/kernel/traps.c:315
invalid_op+0x22/0x40 arch/x86/entry/entry_64.S:1097
RIP: 0010:debug_print_object+0x166/0x220 lib/debugobjects.c:288
RSP: 0018:ffff8801d82df400 EFLAGS: 00010082
RAX: dffffc0000000008 RBX: 0000000000000003 RCX: ffffffff815a4e0e
RDX: 0000000000000000 RSI: 1ffff1003b05be3b RDI: ffff8801db41f6d0
RBP: ffff8801d82df440 R08: 0000000000000000 R09: 1ffff1003b05be0d
R10: ffff8801d82df300 R11: ffffffff86b39018 R12: 0000000000000001
R13: ffffffff86b41f20 R14: ffffffff86012ae0 R15: 0000000000000000
debug_object_activate+0x49b/0x730 lib/debugobjects.c:444
debug_rcu_head_queue kernel/rcu/rcu.h:129 [inline]
__call_rcu.constprop.67+0xf2/0xef0 kernel/rcu/tree.c:3021
call_rcu_sched+0x12/0x20 kernel/rcu/tree.c:3100
pppol2tp_release+0x34d/0x560 net/l2tp/l2tp_ppp.c:496
sock_release+0x8d/0x1e0 net/socket.c:595
sock_close+0x16/0x20 net/socket.c:1149
__fput+0x327/0x7e0 fs/file_table.c:209
____fput+0x15/0x20 fs/file_table.c:243
task_work_run+0x199/0x270 kernel/task_work.c:113
exit_task_work include/linux/task_work.h:22 [inline]
do_exit+0x9bb/0x1ad0 kernel/exit.c:865
do_group_exit+0x149/0x400 kernel/exit.c:968
SYSC_exit_group kernel/exit.c:979 [inline]
SyS_exit_group+0x1d/0x20 kernel/exit.c:977
entry_SYSCALL_64_fastpath+0x29/0xa0
RIP: 0033:0x440cc9
RSP: 002b:00007ffefac52e48 EFLAGS: 00000206 ORIG_RAX: 00000000000000e7
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000440cc9
RDX: 0000000000440cc9 RSI: 000000000000002e RDI: 0000000000000000
RBP: 0000000000008561 R08: 0000000000000000 R09: 0000000000001759
R10: 0000000000000000 R11: 0000000000000206 R12: 0000000000000000
R13: 0000000000000003 R14: 00000000006cf050 R15: 00000000004a260e

======================================================
WARNING: possible circular locking dependency detected
4.15.0+ #290 Not tainted
------------------------------------------------------
syzkaller148927/5989 is trying to acquire lock:
((console_sem).lock){..-.}, at: [<00000000c7e85caf>]
down_trylock+0x13/0x70 kernel/locking/semaphore.c:136

but task is already holding lock:
(&obj_hash[i].lock){-.-.}, at: [<000000003d0dc721>]
debug_object_activate+0x1d7/0x730 lib/debugobjects.c:432

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #3 (&obj_hash[i].lock){-.-.}:
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x96/0xc0 kernel/locking/spinlock.c:152
__debug_object_init+0x109/0x1040 lib/debugobjects.c:343
debug_object_init+0x17/0x20 lib/debugobjects.c:391
debug_hrtimer_init kernel/time/hrtimer.c:411 [inline]
debug_init kernel/time/hrtimer.c:459 [inline]
hrtimer_init+0x8c/0x410 kernel/time/hrtimer.c:1260
init_dl_task_timer+0x1b/0x50 kernel/sched/deadline.c:1060
__sched_fork+0x2c4/0xb70 kernel/sched/core.c:2189
init_idle+0x75/0x820 kernel/sched/core.c:5333
sched_init+0xb19/0xc43 kernel/sched/core.c:6030
start_kernel+0x452/0x819 init/main.c:585
x86_64_start_reservations+0x2a/0x2c arch/x86/kernel/head64.c:378
x86_64_start_kernel+0x77/0x7a arch/x86/kernel/head64.c:359
secondary_startup_64+0xa5/0xb0 arch/x86/kernel/head_64.S:237

-> #2 (&rq->lock){-.-.}:
__raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
_raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:144
rq_lock kernel/sched/sched.h:1758 [inline]
task_fork_fair+0x7a/0x690 kernel/sched/fair.c:9450
sched_fork+0x435/0xc00 kernel/sched/core.c:2405
copy_process.part.37+0x1758/0x4b60 kernel/fork.c:1746
copy_process kernel/fork.c:1589 [inline]
_do_fork+0x1f7/0xfe0 kernel/fork.c:2068
kernel_thread+0x34/0x40 kernel/fork.c:2130
rest_init+0x22/0xf0 init/main.c:402
start_kernel+0x7f1/0x819 init/main.c:716
x86_64_start_reservations+0x2a/0x2c arch/x86/kernel/head64.c:378
x86_64_start_kernel+0x77/0x7a arch/x86/kernel/head64.c:359
secondary_startup_64+0xa5/0xb0 arch/x86/kernel/head_64.S:237

-> #1 (&p->pi_lock){-.-.}:
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x96/0xc0 kernel/locking/spinlock.c:152
try_to_wake_up+0xbc/0x1600 kernel/sched/core.c:1989
wake_up_process+0x10/0x20 kernel/sched/core.c:2152
__up.isra.0+0x1cc/0x2c0 kernel/locking/semaphore.c:262
up+0x13b/0x1d0 kernel/locking/semaphore.c:187
__up_console_sem+0xb2/0x1a0 kernel/printk/printk.c:245
console_unlock+0x538/0xd70 kernel/printk/printk.c:2248
vprintk_emit+0x4ad/0x590 kernel/printk/printk.c:1757
vprintk_default+0x28/0x30 kernel/printk/printk.c:1796
vprintk_func+0x57/0xc0 kernel/printk/printk_safe.c:379
printk+0xaa/0xca kernel/printk/printk.c:1829
regdb_fw_cb+0x1d7/0x220 net/wireless/reg.c:886
request_firmware_work_func+0x151/0x2c0
drivers/base/firmware_class.c:1365
process_one_work+0xbbf/0x1af0 kernel/workqueue.c:2113
worker_thread+0x223/0x1990 kernel/workqueue.c:2247
kthread+0x33c/0x400 kernel/kthread.c:238
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:542

-> #0 ((console_sem).lock){..-.}:
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:3920
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x96/0xc0 kernel/locking/spinlock.c:152
down_trylock+0x13/0x70 kernel/locking/semaphore.c:136
__down_trylock_console_sem+0xa2/0x1e0 kernel/printk/printk.c:228
console_trylock+0x15/0x100 kernel/printk/printk.c:2065
vprintk_emit+0x49b/0x590 kernel/printk/printk.c:1756
vprintk_default+0x28/0x30 kernel/printk/printk.c:1796
vprintk_func+0x57/0xc0 kernel/printk/printk_safe.c:379
printk+0xaa/0xca kernel/printk/printk.c:1829
__warn_printk+0x90/0xf0 kernel/panic.c:599
debug_print_object+0x166/0x220 lib/debugobjects.c:288
debug_object_activate+0x49b/0x730 lib/debugobjects.c:444
debug_rcu_head_queue kernel/rcu/rcu.h:129 [inline]
__call_rcu.constprop.67+0xf2/0xef0 kernel/rcu/tree.c:3021
call_rcu_sched+0x12/0x20 kernel/rcu/tree.c:3100
pppol2tp_release+0x34d/0x560 net/l2tp/l2tp_ppp.c:496
sock_release+0x8d/0x1e0 net/socket.c:595
sock_close+0x16/0x20 net/socket.c:1149
__fput+0x327/0x7e0 fs/file_table.c:209
____fput+0x15/0x20 fs/file_table.c:243
task_work_run+0x199/0x270 kernel/task_work.c:113
exit_task_work include/linux/task_work.h:22 [inline]
do_exit+0x9bb/0x1ad0 kernel/exit.c:865
do_group_exit+0x149/0x400 kernel/exit.c:968
SYSC_exit_group kernel/exit.c:979 [inline]
SyS_exit_group+0x1d/0x20 kernel/exit.c:977
entry_SYSCALL_64_fastpath+0x29/0xa0

other info that might help us debug this:

Chain exists of:
(console_sem).lock --> &rq->lock --> &obj_hash[i].lock

Possible unsafe locking scenario:

CPU0 CPU1
---- ----
lock(&obj_hash[i].lock);
lock(&rq->lock);
lock(&obj_hash[i].lock);
lock((console_sem).lock);

*** DEADLOCK ***

2 locks held by syzkaller148927/5989:
#0: (sk_lock-AF_PPPOX){+.+.}, at: [<0000000075d2b1cc>] lock_sock
include/net/sock.h:1461 [inline]
#0: (sk_lock-AF_PPPOX){+.+.}, at: [<0000000075d2b1cc>]
pppol2tp_release+0x96/0x560 net/l2tp/l2tp_ppp.c:472
#1: (&obj_hash[i].lock){-.-.}, at: [<000000003d0dc721>]
debug_object_activate+0x1d7/0x730 lib/debugobjects.c:432

stack backtrace:
CPU: 0 PID: 5989 Comm: syzkaller148927 Not tainted 4.15.0+ #290
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x194/0x257 lib/dump_stack.c:53
print_circular_bug.isra.38+0x2cd/0x2dc kernel/locking/lockdep.c:1223
check_prev_add kernel/locking/lockdep.c:1863 [inline]
check_prevs_add kernel/locking/lockdep.c:1976 [inline]
validate_chain kernel/locking/lockdep.c:2417 [inline]
__lock_acquire+0x30a8/0x3e00 kernel/locking/lockdep.c:3431
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:3920
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x96/0xc0 kernel/locking/spinlock.c:152
down_trylock+0x13/0x70 kernel/locking/semaphore.c:136
__down_trylock_console_sem+0xa2/0x1e0 kernel/printk/printk.c:228
console_trylock+0x15/0x100 kernel/printk/printk.c:2065
vprintk_emit+0x49b/0x590 kernel/printk/printk.c:1756
vprintk_default+0x28/0x30 kernel/printk/printk.c:1796
vprintk_func+0x57/0xc0 kernel/printk/printk_safe.c:379
printk+0xaa/0xca kernel/printk/printk.c:1829
__warn_printk+0x90/0xf0 kernel/panic.c:599
debug_print_object+0x166/0x220 lib/debugobjects.c:288
debug_object_activate+0x49b/0x730 lib/debugobjects.c:444
debug_rcu_head_queue kernel/rcu/rcu.h:129 [inline]
__call_rcu.constprop.67+0xf2/0xef0 kernel/rcu/tree.c:3021
call_rcu_sched+0x12/0x20 kernel/rcu/tree.c:3100
pppol2tp_release+0x34d/0x560 net/l2tp/l2tp_ppp.c:496
sock_release+0x8d/0x1e0 net/socket.c:595
sock_close+0x16/0x20 net/socket.c:1149
__fput+0x327/0x7e0 fs/file_table.c:209
____fput+0x15/0x20 fs/file_table.c:243
task_work_run+0x199/0x270 kernel/task_work.c:113
exit_task_work include/linux/task_work.h:22 [inline]
do_exit+0x9bb/0x1ad0 kernel/exit.c:865
do_group_exit+0x149/0x400 kernel/exit.c:968
SYSC_exit_group kernel/exit.c:979 [inline]
SyS_exit_group+0x1d/0x20 kernel/exit.c:977
entry_SYSCALL_64_fastpath+0x29/0xa0
RIP: 0033:0x440cc9
RSP: 002b:00007ffefac52e48 EFLAGS: 00000206 ORIG_RAX: 00000000000000e7
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000440cc9
RDX: 0000000000440cc9 RSI: 000000000000002e RDI: 0000000000000000
RBP: 0000000000008561 R08: 0000000000000000 R09: 0000000000001759
R10: 0000000000000000 R11: 0000000000000206 R12: 0000000000000000
R13: 0000000000000003 R14: 00000000006cf050 R15: 00000000004a260e
Shutting down cpus with NMI
Dumping ftrace buffer:
(ftrace buffer empty)
Kernel Offset: disabled
Rebooting in 86400 seconds..


---
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.

[syzbot]

> #syz test:
> https://git.kernel.org/pub/scm/linux/kernel/git/davem/net-next.git

Your 'test:' command is accepted, but please keep
syzkall...@googlegroups.com mailing list in CC next time. It serves as
a history of what happened with each bug report. Thank you.

> master

> On 1 February 2018 at 15:10, syzbot

[syzbot]

Hello,

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

IPVS: ftp: loaded support on port[0] = 21
IPVS: ftp: loaded support on port[0] = 21
==================================================================
BUG: KASAN: use-after-free in pppol2tp_put_sk+0xa8/0xb0
net/l2tp/l2tp_ppp.c:457
Read of size 8 at addr ffff8801ccf9a708 by task syz-executor/4399

CPU: 0 PID: 4399 Comm: syz-executor Not tainted 4.15.0+ #30
IPVS: ftp: loaded support on port[0] = 21

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

<IRQ>

__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x194/0x257 lib/dump_stack.c:53

print_address_description+0x73/0x250 mm/kasan/report.c:252
kasan_report_error mm/kasan/report.c:351 [inline]
kasan_report+0x25b/0x340 mm/kasan/report.c:409
__asan_report_load8_noabort+0x14/0x20 mm/kasan/report.c:430
pppol2tp_put_sk+0xa8/0xb0 net/l2tp/l2tp_ppp.c:457
__rcu_reclaim kernel/rcu/rcu.h:172 [inline]
rcu_do_batch kernel/rcu/tree.c:2674 [inline]
invoke_rcu_callbacks kernel/rcu/tree.c:2933 [inline]
__rcu_process_callbacks kernel/rcu/tree.c:2900 [inline]
rcu_process_callbacks+0xd6c/0x17f0 kernel/rcu/tree.c:2917
IPVS: ftp: loaded support on port[0] = 21
__do_softirq+0x2d7/0xb85 kernel/softirq.c:285
IPVS: ftp: loaded support on port[0] = 21
invoke_softirq kernel/softirq.c:365 [inline]
irq_exit+0x1cc/0x200 kernel/softirq.c:405
exiting_irq arch/x86/include/asm/apic.h:541 [inline]
smp_apic_timer_interrupt+0x16b/0x700 arch/x86/kernel/apic/apic.c:1052
apic_timer_interrupt+0xa9/0xb0 arch/x86/entry/entry_64.S:938
</IRQ>
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:777
[inline]
RIP: 0010:kmem_cache_free+0x17c/0x2a0 mm/slab.c:3744
RSP: 0018:ffff8801ad8ef218 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff11
RAX: 0000000000000007 RBX: ffff8801cf52a630 RCX: 0000000000000000
RDX: 0000000000000000 RSI: 0000000000000001 RDI: 0000000000000282
RBP: ffff8801ad8ef238 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: ffff8801da9c1840
R13: 0000000000000282 R14: ffffffff819e1652 R15: 000000000000104a
IPVS: ftp: loaded support on port[0] = 21
remove_vma+0x162/0x1b0 mm/mmap.c:176
exit_mmap+0x311/0x500 mm/mmap.c:3049
__mmput kernel/fork.c:966 [inline]
mmput+0x223/0x6c0 kernel/fork.c:987
IPVS: ftp: loaded support on port[0] = 21
exit_mm kernel/exit.c:544 [inline]
do_exit+0x90a/0x1ad0 kernel/exit.c:852
IPVS: ftp: loaded support on port[0] = 21
do_group_exit+0x149/0x400 kernel/exit.c:968
get_signal+0x73a/0x16d0 kernel/signal.c:2469
do_signal+0x90/0x1eb0 arch/x86/kernel/signal.c:809
exit_to_usermode_loop+0x258/0x2f0 arch/x86/entry/common.c:161
prepare_exit_to_usermode arch/x86/entry/common.c:195 [inline]
syscall_return_slowpath+0x490/0x550 arch/x86/entry/common.c:264
entry_SYSCALL_64_fastpath+0x9e/0xa0
RIP: 0033:0x453299
RSP: 002b:00007fc49a74ece8 EFLAGS: 00000246 ORIG_RAX: 00000000000000ca
RAX: fffffffffffffe00 RBX: 000000000071bf80 RCX: 0000000000453299
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 000000000071bf80
RBP: 000000000071bf80 R08: 0000000000000000 R09: 000000000071bf58
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007fff45cc9fdf R14: 00007fc49a74f9c0 R15: 0000000000000002

Allocated by task 4389:
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:551
__do_kmalloc mm/slab.c:3705 [inline]
__kmalloc+0x162/0x760 mm/slab.c:3714
kmalloc include/linux/slab.h:517 [inline]
kzalloc include/linux/slab.h:701 [inline]
l2tp_session_create+0x100/0xe50 net/l2tp/l2tp_core.c:1738
pppol2tp_session_prep+0x2fc/0xa40 net/l2tp/l2tp_ppp.c:711
pppol2tp_connect+0x74a/0x1550 net/l2tp/l2tp_ppp.c:856
SYSC_connect+0x213/0x4a0 net/socket.c:1639
SyS_connect+0x24/0x30 net/socket.c:1620
entry_SYSCALL_64_fastpath+0x29/0xa0

Freed by task 4399:
save_stack+0x43/0xd0 mm/kasan/kasan.c:447
set_track mm/kasan/kasan.c:459 [inline]
kasan_slab_free+0x71/0xc0 mm/kasan/kasan.c:524
__cache_free mm/slab.c:3485 [inline]
kfree+0xd6/0x260 mm/slab.c:3800
pppol2tp_put_sk+0x4c/0xb0 net/l2tp/l2tp_ppp.c:456
__rcu_reclaim kernel/rcu/rcu.h:172 [inline]
rcu_do_batch kernel/rcu/tree.c:2674 [inline]
invoke_rcu_callbacks kernel/rcu/tree.c:2933 [inline]
__rcu_process_callbacks kernel/rcu/tree.c:2900 [inline]
rcu_process_callbacks+0xd6c/0x17f0 kernel/rcu/tree.c:2917
__do_softirq+0x2d7/0xb85 kernel/softirq.c:285

The buggy address belongs to the object at ffff8801ccf9a480
which belongs to the cache kmalloc-1024 of size 1024
The buggy address is located 648 bytes inside of
1024-byte region [ffff8801ccf9a480, ffff8801ccf9a880)
The buggy address belongs to the page:
page:ffffea000733e680 count:1 mapcount:0 mapping:ffff8801ccf9a000 index:0x0
compound_mapcount: 0
flags: 0x2fffc0000008100(slab|head)
raw: 02fffc0000008100 ffff8801ccf9a000 0000000000000000 0000000100000007
raw: ffffea00073221a0 ffffea0007321b20 ffff8801db000ac0 0000000000000000
page dumped because: kasan: bad access detected

Memory state around the buggy address:
ffff8801ccf9a600: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
ffff8801ccf9a680: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> ffff8801ccf9a700: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
^
ffff8801ccf9a780: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
ffff8801ccf9a800: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
==================================================================


Tested on
https://git.kernel.org/pub/scm/linux/kernel/git/davem/net-next.git/master
commit
617aebe6a97efa539cc4b8a52adccd89596e6be0 (Sun Feb 4 00:25:42 2018 +0000)
Merge tag 'usercopy-v4.16-rc1' of
git://git.kernel.org/pub/scm/linux/kernel/git/kees/linux

compiler: gcc (GCC) 7.1.1 20170620

Patch is attached.
Kernel config is attached.

[syzbot]

> #syz test:
> https://git.kernel.org/pub/scm/linux/kernel/git/davem/net-next.git

Your 'test:' command is accepted, but please keep
syzkall...@googlegroups.com mailing list in CC next time. It serves as
a history of what happened with each bug report. Thank you.

> master

> On 7 February 2018 at 14:20, syzbot

[syzbot]

Hello,

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

KASAN: use-after-free Read in l2tp_tunnel_del_work

==================================================================
BUG: KASAN: use-after-free in l2tp_tunnel_del_work+0x22e/0x240
net/l2tp/l2tp_core.c:1292
Read of size 8 at addr ffff8801cd99c660 by task kworker/u4:3/87

CPU: 1 PID: 87 Comm: kworker/u4:3 Not tainted 4.15.0+ #34

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

Workqueue: l2tp l2tp_tunnel_del_work
Call Trace:

__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x194/0x257 lib/dump_stack.c:53
print_address_description+0x73/0x250 mm/kasan/report.c:252
kasan_report_error mm/kasan/report.c:351 [inline]
kasan_report+0x25b/0x340 mm/kasan/report.c:409
__asan_report_load8_noabort+0x14/0x20 mm/kasan/report.c:430

l2tp_tunnel_del_work+0x22e/0x240 net/l2tp/l2tp_core.c:1292

process_one_work+0xbbf/0x1af0 kernel/workqueue.c:2113
worker_thread+0x223/0x1990 kernel/workqueue.c:2247
kthread+0x33c/0x400 kernel/kthread.c:238
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:542

Allocated by task 25324:

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:551

kasan_slab_alloc+0x12/0x20 mm/kasan/kasan.c:489
kmem_cache_alloc+0x12e/0x760 mm/slab.c:3541
sock_alloc_inode+0x70/0x300 net/socket.c:244
alloc_inode+0x65/0x180 fs/inode.c:209
new_inode_pseudo+0x69/0x190 fs/inode.c:891
sock_alloc+0x41/0x270 net/socket.c:565
__sock_create+0x148/0x850 net/socket.c:1249
sock_create net/socket.c:1325 [inline]
SYSC_socket net/socket.c:1355 [inline]
SyS_socket+0xeb/0x1d0 net/socket.c:1335
entry_SYSCALL_64_fastpath+0x29/0xa0

Freed by task 25324:

save_stack+0x43/0xd0 mm/kasan/kasan.c:447
set_track mm/kasan/kasan.c:459 [inline]
kasan_slab_free+0x71/0xc0 mm/kasan/kasan.c:524
__cache_free mm/slab.c:3485 [inline]

kmem_cache_free+0x83/0x2a0 mm/slab.c:3743
sock_destroy_inode+0x56/0x70 net/socket.c:274
destroy_inode+0x15d/0x200 fs/inode.c:266
evict+0x57e/0x920 fs/inode.c:571
iput_final fs/inode.c:1516 [inline]
iput+0x7b9/0xaf0 fs/inode.c:1543
dentry_unlink_inode+0x4b0/0x5e0 fs/dcache.c:371
__dentry_kill+0x3de/0x700 fs/dcache.c:575
dentry_kill fs/dcache.c:616 [inline]
dput.part.21+0x6fb/0x830 fs/dcache.c:826
dput+0x1f/0x30 fs/dcache.c:790
__fput+0x51c/0x7e0 fs/file_table.c:227

____fput+0x15/0x20 fs/file_table.c:243
task_work_run+0x199/0x270 kernel/task_work.c:113
exit_task_work include/linux/task_work.h:22 [inline]
do_exit+0x9bb/0x1ad0 kernel/exit.c:865

do_group_exit+0x149/0x400 kernel/exit.c:968
get_signal+0x73a/0x16d0 kernel/signal.c:2469
do_signal+0x90/0x1eb0 arch/x86/kernel/signal.c:809
exit_to_usermode_loop+0x258/0x2f0 arch/x86/entry/common.c:161
prepare_exit_to_usermode arch/x86/entry/common.c:195 [inline]
syscall_return_slowpath+0x490/0x550 arch/x86/entry/common.c:264
entry_SYSCALL_64_fastpath+0x9e/0xa0

The buggy address belongs to the object at ffff8801cd99c640
which belongs to the cache sock_inode_cache of size 992
The buggy address is located 32 bytes inside of
992-byte region [ffff8801cd99c640, ffff8801cd99ca20)

The buggy address belongs to the page:

page:ffffea0007366700 count:1 mapcount:0 mapping:ffff8801cd99c1c0
index:0xffff8801cd99cffd
flags: 0x2fffc0000000100(slab)
raw: 02fffc0000000100 ffff8801cd99c1c0 ffff8801cd99cffd 0000000100000003
raw: ffffea000741f4a0 ffffea000736eb20 ffff8801d980d9c0 0000000000000000

page dumped because: kasan: bad access detected

Memory state around the buggy address:

ffff8801cd99c500: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
ffff8801cd99c580: fb fb fb fb fc fc fc fc fc fc fc fc fc fc fc fc
> ffff8801cd99c600: fc fc fc fc fc fc fc fc fb fb fb fb fb fb fb fb
^
ffff8801cd99c680: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
ffff8801cd99c700: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb

[James Chapman]

#syz test: https://git.kernel.org/pub/scm/linux/kernel/git/davem/net-next.git
master


On 7 February 2018 at 15:24, syzbot

[syzbot]

Hello,

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

possible deadlock in pppol2tp_session_free


============================================
WARNING: possible recursive locking detected
4.15.0+ #37 Not tainted
--------------------------------------------
syzkaller163597/27635 is trying to acquire lock:
(sk_lock-AF_PPPOX){+.+.}, at: [<0000000011240b7f>] lock_sock
include/net/sock.h:1463 [inline]
(sk_lock-AF_PPPOX){+.+.}, at: [<0000000011240b7f>]
pppol2tp_session_free+0x88/0x1d0 net/l2tp/l2tp_ppp.c:469

but task is already holding lock:

(sk_lock-AF_PPPOX){+.+.}, at: [<000000009bf8de9a>] lock_sock
include/net/sock.h:1463 [inline]
(sk_lock-AF_PPPOX){+.+.}, at: [<000000009bf8de9a>]
pppol2tp_connect+0x14e/0x1550 net/l2tp/l2tp_ppp.c:786

other info that might help us debug this:

Possible unsafe locking scenario:

CPU0

----
lock(sk_lock-AF_PPPOX);
lock(sk_lock-AF_PPPOX);

*** DEADLOCK ***

May be due to missing lock nesting notation

1 lock held by syzkaller163597/27635:
#0: (sk_lock-AF_PPPOX){+.+.}, at: [<000000009bf8de9a>] lock_sock
include/net/sock.h:1463 [inline]
#0: (sk_lock-AF_PPPOX){+.+.}, at: [<000000009bf8de9a>]
pppol2tp_connect+0x14e/0x1550 net/l2tp/l2tp_ppp.c:786

stack backtrace:
CPU: 1 PID: 27635 Comm: syzkaller163597 Not tainted 4.15.0+ #37

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

Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x194/0x257 lib/dump_stack.c:53

print_deadlock_bug kernel/locking/lockdep.c:1761 [inline]
check_deadlock kernel/locking/lockdep.c:1805 [inline]
validate_chain kernel/locking/lockdep.c:2401 [inline]
__lock_acquire+0xe8f/0x3e00 kernel/locking/lockdep.c:3431
lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:3920
lock_sock_nested+0xc2/0x110 net/core/sock.c:2777
lock_sock include/net/sock.h:1463 [inline]
pppol2tp_session_free+0x88/0x1d0 net/l2tp/l2tp_ppp.c:469
l2tp_session_free+0x151/0x2b0 net/l2tp/l2tp_core.c:1627
l2tp_session_dec_refcount net/l2tp/l2tp_core.h:281 [inline]
pppol2tp_connect+0xfb5/0x1550 net/l2tp/l2tp_ppp.c:892

SYSC_connect+0x213/0x4a0 net/socket.c:1639
SyS_connect+0x24/0x30 net/socket.c:1620
entry_SYSCALL_64_fastpath+0x29/0xa0

RIP: 0033:0x440ca9
RSP: 002b:00007ffe501872e8 EFLAGS: 00000206 ORIG_RAX: 000000000000002a
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000440ca9
RDX: 000000000000002e RSI: 0000000020e77000 RDI: 0000000000000004
RBP: 0000000000074be3 R08: 0000000000000000 R09: 0000000000000000

R10: 0000000000000000 R11: 0000000000000206 R12: 0000000000000000

R13: 0000000000000003 R14: 00000000006cf050 R15: 00000000004a25db

[syzbot]

> #syz test:
> https://git.kernel.org/pub/scm/linux/kernel/git/davem/net-next.git

Your 'test:' command is accepted, but please keep
syzkall...@googlegroups.com mailing list in CC next time. It serves as
a history of what happened with each bug report. Thank you.

> master

> On 8 February 2018 at 15:26, syzbot

[syzbot]

Hello,

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

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

Note: the tag will also help syzbot to understand when the bug is fixed.

Tested on
https://git.kernel.org/pub/scm/linux/kernel/git/davem/net-next.git/master
commit
617aebe6a97efa539cc4b8a52adccd89596e6be0 (Sun Feb 4 00:25:42 2018 +0000)
Merge tag 'usercopy-v4.16-rc1' of
git://git.kernel.org/pub/scm/linux/kernel/git/kees/linux

compiler: gcc (GCC) 7.1.1 20170620
Patch is attached.
Kernel config is attached.

---
There is no WARRANTY for the result, to the extent permitted by applicable
law.
Except when otherwise stated in writing syzbot provides the result "AS IS"
without warranty of any kind, either expressed or implied, but not limited
to,
the implied warranties of merchantability and fittness for a particular
purpose.
The entire risk as to the quality of the result is with you. Should the
result
prove defective, you assume the cost of all necessary servicing, repair or
correction.