WARNING in debug_print

Title	Replies (including bot)	Last reply
[PATCH 3.16 000/410] 3.16.57-rc1 review	426 (426)	2018/11/12 17:42
[PATCH 4.15 000/122] 4.15.8-stable review	135 (135)	2018/03/08 17:51
[PATCH net 0/5] l2tp: fix API races discovered by syzbot	7 (7)	2018/02/26 17:21
[PATCH net-next v2 00/16] l2tp: fix API races discovered by syzbot	27 (27)	2018/02/15 08:23
[PATCH net-next v3 00/16] l2tp: fix API races discovered by syzbot	18 (18)	2018/02/12 19:00
[PATCH net-next 00/16] l2tp: fix API races discovered by syzbot	18 (18)	2018/02/12 03:37
WARNING in debug_print_object	0 (1)	2018/02/01 15:10

Kernel	Title	Repro	Cause bisect	Fix bisect	Count	Last	Reported	Patched	Status
upstream	WARNING in debug_print_object (3) ppp				1	2218d	2216d	0/26	auto-closed as invalid on 2019/02/22 10:04
upstream	WARNING in debug_print_object (2) rdma				1	2232d	2231d	0/26	closed as invalid on 2018/03/19 10:07

upstream

WARNING in debug_print_object (3) ppp

2218d

2216d

0/26

auto-closed as invalid on 2019/02/22 10:04

upstream

WARNING in debug_print_object (2) rdma

2232d

2231d

0/26

closed as invalid on 2018/03/19 10:07

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

Crashes (2):
Time	Kernel	Commit	Syzkaller	Config	Log	Report	Syz repro	C repro	VM info	Assets (help?)	Manager	Title
2018/02/01 15:06	upstream	255442c93843	02553e22	.config	console log	report	syz	C			ci-upstream-kasan-gce
2018/01/16 19:39	mmots	ce3c209f6733	4198e588	.config	console log	report					ci-upstream-mmots-kasan-gce

Crashes (2):

Assets (help?)