BUG: MAX_STACK_TRACE_ENTRIES too low! (2)

BUG: MAX_STACK_TRACE_ENTRIES too low! (2)

[syzbot]

Hello,

syzbot found the following crash on:

HEAD commit:    1a9df9e2 Merge git://git.kernel.org/pub/scm/linux/kernel/g..
git tree:       upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=14dc2f2b200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=8dcdce25ea72bedf
dashboard link: https://syzkaller.appspot.com/bug?extid=6f39a9deb697359fe520
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)

Unfortunately, I don't have any reproducer for this crash yet.

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

XFS (loop4): Invalid superblock magic number
BUG: MAX_STACK_TRACE_ENTRIES too low!
turning off the locking correctness validator.
CPU: 0 PID: 1067 Comm: syz-executor.4 Not tainted 5.1.0-rc2+ #40
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
  save_trace kernel/locking/lockdep.c:467 [inline]
  save_trace.cold+0x14/0x19 kernel/locking/lockdep.c:437
  check_prev_add.constprop.0+0x8dc/0x23c0 kernel/locking/lockdep.c:2268
  check_prevs_add kernel/locking/lockdep.c:2333 [inline]
  validate_chain kernel/locking/lockdep.c:2714 [inline]
  __lock_acquire+0x239c/0x3fb0 kernel/locking/lockdep.c:3701
  lock_acquire+0x16f/0x3f0 kernel/locking/lockdep.c:4211
  flush_workqueue+0x126/0x14c0 kernel/workqueue.c:2774
  drain_workqueue+0x1b4/0x470 kernel/workqueue.c:2939
  destroy_workqueue+0x21/0x700 kernel/workqueue.c:4320
  xfs_destroy_mount_workqueues+0xc5/0x1c0 fs/xfs/xfs_super.c:904
  xfs_fs_fill_super+0x8e9/0x1670 fs/xfs/xfs_super.c:1786
  mount_bdev+0x307/0x3c0 fs/super.c:1346
  xfs_fs_mount+0x35/0x40 fs/xfs/xfs_super.c:1834
  legacy_get_tree+0xf2/0x200 fs/fs_context.c:584
  vfs_get_tree+0x123/0x450 fs/super.c:1481
  do_new_mount fs/namespace.c:2622 [inline]
  do_mount+0x1436/0x2c40 fs/namespace.c:2942
  ksys_mount+0xdb/0x150 fs/namespace.c:3151
  __do_sys_mount fs/namespace.c:3165 [inline]
  __se_sys_mount fs/namespace.c:3162 [inline]
  __x64_sys_mount+0xbe/0x150 fs/namespace.c:3162
  do_syscall_64+0x103/0x610 arch/x86/entry/common.c:290
  entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x45ac7a
Code: b8 a6 00 00 00 0f 05 48 3d 01 f0 ff ff 0f 83 2d 8e fb ff c3 66 2e 0f  
1f 84 00 00 00 00 00 66 90 49 89 ca b8 a5 00 00 00 0f 05 <48> 3d 01 f0 ff  
ff 0f 83 0a 8e fb ff c3 66 0f 1f 84 00 00 00 00 00
RSP: 002b:00007f5a0187aa88 EFLAGS: 00000206 ORIG_RAX: 00000000000000a5
RAX: ffffffffffffffda RBX: 00007f5a0187ab40 RCX: 000000000045ac7a
RDX: 00007f5a0187aae0 RSI: 00000000200006c0 RDI: 00007f5a0187ab00
RBP: 0000000000000000 R08: 00007f5a0187ab40 R09: 00007f5a0187aae0
R10: 0000000000000000 R11: 0000000000000206 R12: 0000000000000003
R13: 00000000004c6bd2 R14: 00000000004dc5b0 R15: 00000000ffffffff


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

syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

Re: BUG: MAX_STACK_TRACE_ENTRIES too low! (2)

[syzbot]

syzbot has found a reproducer for the following crash on:

HEAD commit:    0e40da3e Merge tag 'kbuild-fixes-v5.1' of git://git.kernel..
git tree:       upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=14d9123f200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=8dcdce25ea72bedf
dashboard link: https://syzkaller.appspot.com/bug?extid=6f39a9deb697359fe520
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
userspace arch: i386
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=1244591f200000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=12611c73200000

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

BUG: MAX_STACK_TRACE_ENTRIES too low!
turning off the locking correctness validator.
CPU: 0 PID: 678 Comm: syz-executor519 Not tainted 5.1.0-rc2+ #43
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
  save_trace kernel/locking/lockdep.c:467 [inline]
  save_trace.cold+0x14/0x19 kernel/locking/lockdep.c:437
  mark_lock+0x2fb/0x1380 kernel/locking/lockdep.c:3410
  __lock_acquire+0x548/0x3fb0 kernel/locking/lockdep.c:3657
  lock_acquire+0x16f/0x3f0 kernel/locking/lockdep.c:4211
  flush_workqueue+0x126/0x14c0 kernel/workqueue.c:2774
  drain_workqueue+0x1b4/0x470 kernel/workqueue.c:2939
  destroy_workqueue+0x21/0x700 kernel/workqueue.c:4320
  ucma_close+0x289/0x320 drivers/infiniband/core/ucma.c:1786
  __fput+0x2e5/0x8d0 fs/file_table.c:278
  ____fput+0x16/0x20 fs/file_table.c:309
  task_work_run+0x14a/0x1c0 kernel/task_work.c:113
  tracehook_notify_resume include/linux/tracehook.h:188 [inline]
  exit_to_usermode_loop+0x273/0x2c0 arch/x86/entry/common.c:166
  prepare_exit_to_usermode arch/x86/entry/common.c:197 [inline]
  syscall_return_slowpath arch/x86/entry/common.c:268 [inline]
  do_syscall_32_irqs_on arch/x86/entry/common.c:341 [inline]
  do_fast_syscall_32+0xa9d/0xc98 arch/x86/entry/common.c:397
  entry_SYSENTER_compat+0x70/0x7f arch/x86/entry/entry_64_compat.S:139
RIP: 0023:0xf7fc4869
Code: 85 d2 74 02 89 0a 5b 5d c3 8b 04 24 c3 8b 14 24 c3 8b 3c 24 c3 90 90  
90 90 90 90 90 90 90 90 90 90 51 52 55 89 e5 0f 34 cd 80 <5d> 5a 59 c3 90  
90 90 90 eb 0d 90 90 90 90 90 90 90 90 90 90 90 90
RSP: 002b:00000000ffc382bc EFLAGS: 00000246 ORIG_RAX: 0000000000000006
RAX: 0000000000000000 RBX: 0000000000000003 RCX: 00000000200002c0
RDX: 0000000000000004 RSI: 00000000080bc36e RDI: 00000000200002d8
RBP: 00000000ffc38308 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000

Re: BUG: MAX_STACK_TRACE_ENTRIES too low! (2)

[syzbot]

syzbot has bisected this bug to:

commit 669de8bda87b92ab9a2fc663b3f5743c2ad1ae9f
Author: Bart Van Assche <bvanassche@acm.org>
Date:   Thu Feb 14 23:00:54 2019 +0000

     kernel/workqueue: Use dynamic lockdep keys for workqueues

bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=17f1bacd200000
start commit:   0e40da3e Merge tag 'kbuild-fixes-v5.1' of git://git.kernel..
git tree:       upstream
final crash:    https://syzkaller.appspot.com/x/report.txt?x=1409bacd200000
console output: https://syzkaller.appspot.com/x/log.txt?x=1009bacd200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=8dcdce25ea72bedf
dashboard link: https://syzkaller.appspot.com/bug?extid=6f39a9deb697359fe520
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=10e1bacd200000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=1120fe0f200000

Reported-by: syzbot+6f39a9deb697359fe520@syzkaller.appspotmail.com
Fixes: 669de8bda87b ("kernel/workqueue: Use dynamic lockdep keys for  
workqueues")

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

Re: BUG: MAX_STACK_TRACE_ENTRIES too low! (2)

[Bart Van Assche]

On 3/30/19 2:58 PM, syzbot wrote:
> syzbot has bisected this bug to:
> 
> commit 669de8bda87b92ab9a2fc663b3f5743c2ad1ae9f
> Author: Bart Van Assche <bvanassche@acm.org>
> Date:   Thu Feb 14 23:00:54 2019 +0000
> 
>      kernel/workqueue: Use dynamic lockdep keys for workqueues
> 
> bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=17f1bacd200000
> start commit:   0e40da3e Merge tag 'kbuild-fixes-v5.1' of 
> git://git.kernel..
> git tree:       upstream
> final crash:    https://syzkaller.appspot.com/x/report.txt?x=1409bacd200000
> console output: https://syzkaller.appspot.com/x/log.txt?x=1009bacd200000
> kernel config:  https://syzkaller.appspot.com/x/.config?x=8dcdce25ea72bedf
> dashboard link: 
> https://syzkaller.appspot.com/bug?extid=6f39a9deb697359fe520
> syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=10e1bacd200000
> C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=1120fe0f200000
> 
> Reported-by: syzbot+6f39a9deb697359fe520@syzkaller.appspotmail.com
> Fixes: 669de8bda87b ("kernel/workqueue: Use dynamic lockdep keys for 
> workqueues")
> 
> For information about bisection process see: 
> https://goo.gl/tpsmEJ#bisection

Hi Dmitry,

This bisection result doesn't make sense to me. As one can see, the 
message "BUG: MAX_STACK_TRACE_ENTRIES too low!" does not occur in the 
console output the above console output URL points at.

Bart.

Re: BUG: MAX_STACK_TRACE_ENTRIES too low! (2)

[Eric Biggers]

[Moved most people to Bcc; syzbot added way too many random people to this.]

Hi Bart,

On Sat, Mar 30, 2019 at 07:17:09PM -0700, Bart Van Assche wrote:
> On 3/30/19 2:58 PM, syzbot wrote:
> > syzbot has bisected this bug to:
> > 
> > commit 669de8bda87b92ab9a2fc663b3f5743c2ad1ae9f
> > Author: Bart Van Assche <bvanassche@acm.org>
> > Date:   Thu Feb 14 23:00:54 2019 +0000
> > 
> >      kernel/workqueue: Use dynamic lockdep keys for workqueues
> > 
> > bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=17f1bacd200000
> > start commit:   0e40da3e Merge tag 'kbuild-fixes-v5.1' of
> > git://git.kernel..
> > git tree:       upstream
> > final crash:    https://syzkaller.appspot.com/x/report.txt?x=1409bacd200000
> > console output: https://syzkaller.appspot.com/x/log.txt?x=1009bacd200000
> > kernel config:  https://syzkaller.appspot.com/x/.config?x=8dcdce25ea72bedf
> > dashboard link:
> > https://syzkaller.appspot.com/bug?extid=6f39a9deb697359fe520
> > syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=10e1bacd200000
> > C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=1120fe0f200000
> > 
> > Reported-by: syzbot+6f39a9deb697359fe520@syzkaller.appspotmail.com
> > Fixes: 669de8bda87b ("kernel/workqueue: Use dynamic lockdep keys for
> > workqueues")
> > 
> > For information about bisection process see:
> > https://goo.gl/tpsmEJ#bisection
> 
> Hi Dmitry,
> 
> This bisection result doesn't make sense to me. As one can see, the message
> "BUG: MAX_STACK_TRACE_ENTRIES too low!" does not occur in the console output
> the above console output URL points at.
> 
> Bart.

This is still happening on mainline, and I think this bisection result is
probably correct.  syzbot did start hitting something different at the very end
of the bisection ("WARNING: CPU: 0 PID: 9153 at kernel/locking/lockdep.c:747")
but that seems to be just because your commit had a lot of bugs in it, which had
to be fixed by later commits.  In particular, the WARNING seems to have been
fixed by commit 28d49e282665e ("locking/lockdep: Shrink struct lock_class_key").

What seems to still be happening is that the dynamic lockdep keys which you
added make it possible for an unbounded number of entries to be added to the
fixed length stack_trace[] array in kernel/locking/lockdep.c.  Hence the "BUG:
MAX_STACK_TRACE_ENTRIES too low!".

Am I understanding it correctly?  How did you intend this to work?

- Eric