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

Re: BUG: MAX_STACK_TRACE_ENTRIES too low! (2)

[Bart Van Assche]

On 7/9/19 10:30 PM, Eric Biggers wrote:
> [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?

The last two paragraphs do not make sense to me. My changes do not 
increase the number of stack traces that get recorded by the lockdep code.

Bart.

Re: BUG: MAX_STACK_TRACE_ENTRIES too low! (2)

[Eric Biggers]

On Wed, Jul 10, 2019 at 07:19:55AM -0700, Bart Van Assche wrote:
> On 7/9/19 10:30 PM, Eric Biggers wrote:
> > [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?
> 
> The last two paragraphs do not make sense to me. My changes do not increase
> the number of stack traces that get recorded by the lockdep code.
> 
> Bart.
> 

Interesting.  How do we explain that repeatedly allocating and freeing a
workqueue is causing the number of lockdep stack trace entries to grow without
bound, though?

This can be reproduced with the following (which I simplified from the C
reproducer that syzbot generated and used for its bisection):

	#include <fcntl.h>
	#include <unistd.h>

	int main()
	{
		for (;;) {
			int fd = open("/dev/infiniband/rdma_cm", O_RDWR);

			close(fd);
		}
	}

The workqueue is allocated in ucma_open() and freed in ucma_close().  If I run
'grep stack-trace /proc/lockdep_stats' while reproducer is running, I can see
the number is growing continuously until it hits the limit.

There is also a reproducer using io_uring instead of rdma_cm
(https://syzkaller.appspot.com/text?tag=ReproC&x=16483bf8600000).
In both cases the workqueue is associated with a file descriptor; the workqueue
is allocated and freed as the file descriptor is opened and closed.

Anyone have any ideas?

- Eric

Re: BUG: MAX_STACK_TRACE_ENTRIES too low! (2)

[Eric Biggers]

On Wed, Jul 10, 2019 at 10:00:59AM -0700, Eric Biggers wrote:
> On Wed, Jul 10, 2019 at 07:19:55AM -0700, Bart Van Assche wrote:
> > On 7/9/19 10:30 PM, Eric Biggers wrote:
> > > [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?
> > 
> > The last two paragraphs do not make sense to me. My changes do not increase
> > the number of stack traces that get recorded by the lockdep code.
> > 
> > Bart.
> > 
> 
> Interesting.  How do we explain that repeatedly allocating and freeing a
> workqueue is causing the number of lockdep stack trace entries to grow without
> bound, though?
> 
> This can be reproduced with the following (which I simplified from the C
> reproducer that syzbot generated and used for its bisection):
> 
> 	#include <fcntl.h>
> 	#include <unistd.h>
> 
> 	int main()
> 	{
> 		for (;;) {
> 			int fd = open("/dev/infiniband/rdma_cm", O_RDWR);
> 
> 			close(fd);
> 		}
> 	}
> 
> The workqueue is allocated in ucma_open() and freed in ucma_close().  If I run
> 'grep stack-trace /proc/lockdep_stats' while reproducer is running, I can see
> the number is growing continuously until it hits the limit.
> 
> There is also a reproducer using io_uring instead of rdma_cm
> (https://syzkaller.appspot.com/text?tag=ReproC&x=16483bf8600000).
> In both cases the workqueue is associated with a file descriptor; the workqueue
> is allocated and freed as the file descriptor is opened and closed.
> 
> Anyone have any ideas?
> 
> - Eric

With my simplified reproducer, on commit 669de8bda87b ("kernel/workqueue: Use
dynamic lockdep keys for workqueues") I see:

	WARNING: CPU: 3 PID: 189 at kernel/locking/lockdep.c:747 register_lock_class+0x4f6/0x580

and then somewhat later:

	BUG: MAX_LOCKDEP_KEYS too low!

If on top of that I cherry pick commit 28d49e282665 ("locking/lockdep: Shrink
struct lock_class_key"), I see instead:

	BUG: MAX_STACK_TRACE_ENTRIES too low!

I also see that on mainline.

Alternatively, if I check out 669de8bda87b and revert it, I don't see anything.

- Eric

Re: BUG: MAX_STACK_TRACE_ENTRIES too low! (2)

[Bart Van Assche]

On 7/10/19 10:21 AM, Eric Biggers wrote:
> With my simplified reproducer, on commit 669de8bda87b ("kernel/workqueue: Use
> dynamic lockdep keys for workqueues") I see:
> 
> 	WARNING: CPU: 3 PID: 189 at kernel/locking/lockdep.c:747 register_lock_class+0x4f6/0x580
> 
> and then somewhat later:
> 
> 	BUG: MAX_LOCKDEP_KEYS too low!
> 
> If on top of that I cherry pick commit 28d49e282665 ("locking/lockdep: Shrink
> struct lock_class_key"), I see instead:
> 
> 	BUG: MAX_STACK_TRACE_ENTRIES too low!
> 
> I also see that on mainline.
> 
> Alternatively, if I check out 669de8bda87b and revert it, I don't see anything.

Hi Eric,

Is the rdma_ucm code the only code that triggers the "BUG:
MAX_STACK_TRACE_ENTRIES too low!" complaint or is this complaint also
triggered by other kernel code? I'm asking this because I think that
fixing this would require to implement garbage collection for the
stack_trace[] array in the lockdep code. That would make the lockdep
code slower. I don't think that making the lockdep code slower would be
welcome.

Bart.

Re: BUG: MAX_STACK_TRACE_ENTRIES too low! (2)

[Eric Biggers]

On Wed, Jul 10, 2019 at 10:46:00AM -0700, Bart Van Assche wrote:
> On 7/10/19 10:21 AM, Eric Biggers wrote:
> > With my simplified reproducer, on commit 669de8bda87b ("kernel/workqueue: Use
> > dynamic lockdep keys for workqueues") I see:
> > 
> > 	WARNING: CPU: 3 PID: 189 at kernel/locking/lockdep.c:747 register_lock_class+0x4f6/0x580
> > 
> > and then somewhat later:
> > 
> > 	BUG: MAX_LOCKDEP_KEYS too low!
> > 
> > If on top of that I cherry pick commit 28d49e282665 ("locking/lockdep: Shrink
> > struct lock_class_key"), I see instead:
> > 
> > 	BUG: MAX_STACK_TRACE_ENTRIES too low!
> > 
> > I also see that on mainline.
> > 
> > Alternatively, if I check out 669de8bda87b and revert it, I don't see anything.
> 
> Hi Eric,
> 
> Is the rdma_ucm code the only code that triggers the "BUG:
> MAX_STACK_TRACE_ENTRIES too low!" complaint or is this complaint also
> triggered by other kernel code? I'm asking this because I think that
> fixing this would require to implement garbage collection for the
> stack_trace[] array in the lockdep code. That would make the lockdep
> code slower. I don't think that making the lockdep code slower would be
> welcome.
> 
> Bart.

I already mentioned that io_uring triggers it too.

Those are just 2 cases that syzbot happened to generate reproducers for.  I
expect there are many others too, since many places in the kernel allocate
workqueues.  AFAICS most are placed in static or global variables which avoids
this issue, but there are still many cases where a workqueue is owned by some
dynamic structure that can have a much shorter lifetime.

You can also check the other syzbot reports that look similar
(https://lore.kernel.org/lkml/20190710055838.GC2152@sol.localdomain/).
Two of them have C reproducers too.

- Eric

Re: BUG: MAX_STACK_TRACE_ENTRIES too low! (2)

[Bart Van Assche]

On 7/10/19 11:02 AM, Eric Biggers wrote:
> I already mentioned that io_uring triggers it too.
> 
> Those are just 2 cases that syzbot happened to generate reproducers for.  I
> expect there are many others too, since many places in the kernel allocate
> workqueues.  AFAICS most are placed in static or global variables which avoids
> this issue, but there are still many cases where a workqueue is owned by some
> dynamic structure that can have a much shorter lifetime.
> 
> You can also check the other syzbot reports that look similar
> (https://lore.kernel.org/lkml/20190710055838.GC2152@sol.localdomain/).
> Two of them have C reproducers too.

As you may know lockdep cannot use dynamic memory allocation because
doing so would introduce a circular dependency between lockdep and the
memory allocator. Hence the fixed size arrays in the lockdep code.
Additionally, as far as I know lockdep works fine for human kernel
developers and only syzbot runs code that triggers the lockdep limits.
So I think it's up to the syzbot authors to come up with a solution. I
mean another solution than finger pointing at kernel developers.

Bart.

Re: BUG: MAX_STACK_TRACE_ENTRIES too low! (2)

[Eric Dumazet]

On 7/10/19 8:36 PM, Bart Van Assche wrote:
> On 7/10/19 11:02 AM, Eric Biggers wrote:
>> I already mentioned that io_uring triggers it too.
>>
>> Those are just 2 cases that syzbot happened to generate reproducers for.  I
>> expect there are many others too, since many places in the kernel allocate
>> workqueues.  AFAICS most are placed in static or global variables which avoids
>> this issue, but there are still many cases where a workqueue is owned by some
>> dynamic structure that can have a much shorter lifetime.
>>
>> You can also check the other syzbot reports that look similar
>> (https://lore.kernel.org/lkml/20190710055838.GC2152@sol.localdomain/).
>> Two of them have C reproducers too.
> 
> As you may know lockdep cannot use dynamic memory allocation because
> doing so would introduce a circular dependency between lockdep and the
> memory allocator. Hence the fixed size arrays in the lockdep code.
> Additionally, as far as I know lockdep works fine for human kernel
> developers and only syzbot runs code that triggers the lockdep limits.
> So I think it's up to the syzbot authors to come up with a solution. I
> mean another solution than finger pointing at kernel developers.

This is silly, syzbot simply uses kernel standard system calls.

If anything using workqueues in dynamically allocated objects can turn off lockdep,
we have a serious issue.

Please work on this issue instead of trying to blame someone else.

Thank you.

Re: BUG: MAX_STACK_TRACE_ENTRIES too low! (2)

[Bart Van Assche]

On 7/10/19 11:44 AM, Eric Dumazet wrote:
> If anything using workqueues in dynamically allocated objects can turn off lockdep,
> we have a serious issue.

As far as I know that issue is only hit by syzbot tests. Anyway, I see
two possible paths forward:
* Revert the patch that makes workqueues use dynamic lockdep keys and
thereby reintroduce the false positives that lockdep reports if
different workqueues share a lockdep key. I think there is agreement
that having to analyze lockdep false positives is annoying, time
consuming and something nobody likes.
* Modify lockdep such that space in its fixed size arrays that is no
longer in use gets reused. Since the stack traces saved in the
stack_trace[] array have a variable size that array will have to be
compacted to avoid fragmentation.

Did I overlook anything?

Bart.

Re: BUG: MAX_STACK_TRACE_ENTRIES too low! (2)

[Eric Dumazet]

On 7/10/19 9:09 PM, Bart Van Assche wrote:
> On 7/10/19 11:44 AM, Eric Dumazet wrote:
>> If anything using workqueues in dynamically allocated objects can turn off lockdep,
>> we have a serious issue.
> 
> As far as I know that issue is only hit by syzbot tests.



> Anyway, I see
> two possible paths forward:
> * Revert the patch that makes workqueues use dynamic lockdep keys and
> thereby reintroduce the false positives that lockdep reports if
> different workqueues share a lockdep key. I think there is agreement
> that having to analyze lockdep false positives is annoying, time
> consuming and something nobody likes.
> * Modify lockdep such that space in its fixed size arrays that is no
> longer in use gets reused. Since the stack traces saved in the
> stack_trace[] array have a variable size that array will have to be
> compacted to avoid fragmentation.
> 

Can not destroy_workqueue() undo what alloc_workqueue() did ?

Re: BUG: MAX_STACK_TRACE_ENTRIES too low! (2)

[Bart Van Assche]

On 7/10/19 1:47 PM, Eric Dumazet wrote:
> 
> 
> On 7/10/19 9:09 PM, Bart Van Assche wrote:
>> On 7/10/19 11:44 AM, Eric Dumazet wrote:
>>> If anything using workqueues in dynamically allocated objects can turn off lockdep,
>>> we have a serious issue.
>>
>> As far as I know that issue is only hit by syzbot tests.
> 
> 
> 
>> Anyway, I see
>> two possible paths forward:
>> * Revert the patch that makes workqueues use dynamic lockdep keys and
>> thereby reintroduce the false positives that lockdep reports if
>> different workqueues share a lockdep key. I think there is agreement
>> that having to analyze lockdep false positives is annoying, time
>> consuming and something nobody likes.
>> * Modify lockdep such that space in its fixed size arrays that is no
>> longer in use gets reused. Since the stack traces saved in the
>> stack_trace[] array have a variable size that array will have to be
>> compacted to avoid fragmentation.
>>
> 
> Can not destroy_workqueue() undo what alloc_workqueue() did ?

destroy_workqueue() already calls lockdep_unregister_key(). If that
wouldn't happen then sooner or later one of the warning statements in
the lockdep code would be triggered, e.g. the WARN_ON_ONCE() statement
in lockdep_register_key(). I think the root cause is that
lockdep_unregister_key() does not free the stack traces recorded by the
lockdep save_trace() function. save_trace() is called every time a lock
is acquired and lockdep encounters a new lock dependency chain.

As one can see in remove_class_from_lock_chain() there is already code
present in lockdep for compacting the chain_hlocks[] array. Similar code
is not yet available for the stack_trace[] array because I had not
encountered any overflows of that array during my tests.

Bart.

Re: BUG: MAX_STACK_TRACE_ENTRIES too low! (2)

[Peter Zijlstra]

On Wed, Jul 10, 2019 at 02:23:39PM -0700, Bart Van Assche wrote:
> As one can see in remove_class_from_lock_chain() there is already code
> present in lockdep for compacting the chain_hlocks[] array. Similar code
> is not yet available for the stack_trace[] array because I had not
> encountered any overflows of that array during my tests.

One thing I mentioned when Thomas did the unwinder API changes was
trying to move lockdep over to something like stackdepot.

We can't directly use stackdepot as is, because it uses locks and memory
allocation, but we could maybe add a lower level API to it and use that
under the graph_lock() on static storage or something.

Otherwise we'll have to (re)implement something like it.

I've not looked at it in detail.

Re: BUG: MAX_STACK_TRACE_ENTRIES too low! (2)

[Bart Van Assche]

On 7/10/19 3:09 PM, Peter Zijlstra wrote:
> One thing I mentioned when Thomas did the unwinder API changes was
> trying to move lockdep over to something like stackdepot.
> 
> We can't directly use stackdepot as is, because it uses locks and memory
> allocation, but we could maybe add a lower level API to it and use that
> under the graph_lock() on static storage or something.
> 
> Otherwise we'll have to (re)implement something like it.
> 
> I've not looked at it in detail.

Hi Peter,

Is something like the untested patch below perhaps what you had in mind?

Thanks,

Bart.

diff --git a/include/linux/lockdep.h b/include/linux/lockdep.h
index 57baa27f238c..a5c7c1813d35 100644
--- a/include/linux/lockdep.h
+++ b/include/linux/lockdep.h
@@ -66,10 +66,7 @@ struct lock_class_key {

  extern struct lock_class_key __lockdep_no_validate__;

-struct lock_trace {
-	unsigned int		nr_entries;
-	unsigned int		offset;
-};
+struct lock_trace;

  #define LOCKSTAT_POINTS		4

@@ -105,7 +102,7 @@ struct lock_class {
  	 * IRQ/softirq usage tracking bits:
  	 */
  	unsigned long			usage_mask;
-	struct lock_trace		usage_traces[XXX_LOCK_USAGE_STATES];
+	const struct lock_trace		*usage_traces[XXX_LOCK_USAGE_STATES];

  	/*
  	 * Generation counter, when doing certain classes of graph walking,
@@ -193,7 +190,7 @@ struct lock_list {
  	struct list_head		entry;
  	struct lock_class		*class;
  	struct lock_class		*links_to;
-	struct lock_trace		trace;
+	const struct lock_trace		*trace;
  	int				distance;

  	/*
diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
index 341f52117f88..c3022367ba2a 100644
--- a/kernel/locking/lockdep.c
+++ b/kernel/locking/lockdep.c
@@ -449,33 +449,72 @@ static void print_lockdep_off(const char *bug_msg)
  unsigned long nr_stack_trace_entries;

  #if defined(CONFIG_TRACE_IRQFLAGS) && defined(CONFIG_PROVE_LOCKING)
+/**
+ * struct lock_trace - single stack backtrace
+ * @hash_entry:	Entry in a stack_trace_hash[] list.
+ * @hash:	jhash() of @entries.
+ * @nr_entries:	Number of entries in @entries.
+ * @entries:	Actual stack backtrace.
+ */
+struct lock_trace {
+	struct hlist_node	hash_entry;
+	u32			hash;
+	u32			nr_entries;
+	unsigned long		entries[0] __aligned(sizeof(unsigned long));
+};
+#define LOCK_TRACE_SIZE_IN_LONGS				\
+	(sizeof(struct lock_trace) / sizeof(unsigned long))
  /*
- * Stack-trace: tightly packed array of stack backtrace
- * addresses. Protected by the graph_lock.
+ * Stack-trace: sequence of lock_trace structures. Protected by the graph_lock.
   */
  static unsigned long stack_trace[MAX_STACK_TRACE_ENTRIES];
+static struct hlist_head stack_trace_hash[STACK_TRACE_HASH_SIZE];
+
+static bool traces_identical(struct lock_trace *t1, struct lock_trace *t2)
+{
+	return t1->hash == t2->hash && t1->nr_entries == t2->nr_entries &&
+		memcmp(t1->entries, t2->entries,
+		       t1->nr_entries * sizeof(t1->entries[0])) == 0;
+}

-static int save_trace(struct lock_trace *trace)
+static struct lock_trace *save_trace(void)
  {
-	unsigned long *entries = stack_trace + nr_stack_trace_entries;
+	struct lock_trace *trace, *t2;
+	struct hlist_head *hash_head;
+	u32 hash;
  	unsigned int max_entries;

-	trace->offset = nr_stack_trace_entries;
-	max_entries = MAX_STACK_TRACE_ENTRIES - nr_stack_trace_entries;
-	trace->nr_entries = stack_trace_save(entries, max_entries, 3);
-	nr_stack_trace_entries += trace->nr_entries;
+	BUILD_BUG_ON_NOT_POWER_OF_2(STACK_TRACE_HASH_SIZE);
+	BUILD_BUG_ON(LOCK_TRACE_SIZE_IN_LONGS >= MAX_STACK_TRACE_ENTRIES);
+
+	trace = (struct lock_trace *)(stack_trace + nr_stack_trace_entries);
+	max_entries = MAX_STACK_TRACE_ENTRIES - nr_stack_trace_entries -
+		LOCK_TRACE_SIZE_IN_LONGS;
+	trace->nr_entries = stack_trace_save(trace->entries, max_entries, 3);

-	if (nr_stack_trace_entries >= MAX_STACK_TRACE_ENTRIES-1) {
+	if (nr_stack_trace_entries >= MAX_STACK_TRACE_ENTRIES -
+	    LOCK_TRACE_SIZE_IN_LONGS - 1) {
  		if (!debug_locks_off_graph_unlock())
-			return 0;
+			return NULL;

  		print_lockdep_off("BUG: MAX_STACK_TRACE_ENTRIES too low!");
  		dump_stack();

-		return 0;
+		return NULL;
  	}

-	return 1;
+	hash = jhash(trace->entries, trace->nr_entries *
+		     sizeof(trace->entries[0]), 0);
+	trace->hash = hash;
+	hash_head = stack_trace_hash + (hash & (STACK_TRACE_HASH_SIZE - 1));
+	hlist_for_each_entry(t2, hash_head, hash_entry) {
+		if (traces_identical(trace, t2))
+			return t2;
+	}
+	nr_stack_trace_entries += LOCK_TRACE_SIZE_IN_LONGS + trace->nr_entries;
+	hlist_add_head(&trace->hash_entry, hash_head);
+	
+	return trace;
  }
  #endif

@@ -1235,7 +1274,7 @@ static struct lock_list *alloc_list_entry(void)
  static int add_lock_to_list(struct lock_class *this,
  			    struct lock_class *links_to, struct list_head *head,
  			    unsigned long ip, int distance,
-			    struct lock_trace *trace)
+			    const struct lock_trace *trace)
  {
  	struct lock_list *entry;
  	/*
@@ -1249,7 +1288,7 @@ static int add_lock_to_list(struct lock_class *this,
  	entry->class = this;
  	entry->links_to = links_to;
  	entry->distance = distance;
-	entry->trace = *trace;
+	entry->trace = trace;
  	/*
  	 * Both allocation and removal are done under the graph lock; but
  	 * iteration is under RCU-sched; see look_up_lock_class() and
@@ -1470,11 +1509,10 @@ static inline int __bfs_backwards(struct lock_list *src_entry,

  }

-static void print_lock_trace(struct lock_trace *trace, unsigned int spaces)
+static void print_lock_trace(const struct lock_trace *trace,
+			     unsigned int spaces)
  {
-	unsigned long *entries = stack_trace + trace->offset;
-
-	stack_trace_print(entries, trace->nr_entries, spaces);
+	stack_trace_print(trace->entries, trace->nr_entries, spaces);
  }

  /*
@@ -1489,7 +1527,7 @@ print_circular_bug_entry(struct lock_list *target, int depth)
  	printk("\n-> #%u", depth);
  	print_lock_name(target->class);
  	printk(KERN_CONT ":\n");
-	print_lock_trace(&target->trace, 6);
+	print_lock_trace(target->trace, 6);
  }

  static void
@@ -1592,7 +1630,8 @@ static noinline void print_circular_bug(struct lock_list *this,
  	if (!debug_locks_off_graph_unlock() || debug_locks_silent)
  		return;

-	if (!save_trace(&this->trace))
+	this->trace = save_trace();
+	if (!this->trace)
  		return;

  	depth = get_lock_depth(target);
@@ -1715,7 +1754,7 @@ check_path(struct lock_class *target, struct lock_list *src_entry,
   */
  static noinline int
  check_noncircular(struct held_lock *src, struct held_lock *target,
-		  struct lock_trace *trace)
+		  struct lock_trace **const trace)
  {
  	int ret;
  	struct lock_list *uninitialized_var(target_entry);
@@ -1729,13 +1768,13 @@ check_noncircular(struct held_lock *src, struct held_lock *target,
  	ret = check_path(hlock_class(target), &src_entry, &target_entry);

  	if (unlikely(!ret)) {
-		if (!trace->nr_entries) {
+		if (!*trace) {
  			/*
  			 * If save_trace fails here, the printing might
  			 * trigger a WARN but because of the !nr_entries it
  			 * should not do bad things.
  			 */
-			save_trace(trace);
+			*trace = save_trace();
  		}

  		print_circular_bug(&src_entry, target_entry, src, target);
@@ -1859,7 +1898,7 @@ static void print_lock_class_header(struct lock_class *class, int depth)

  			len += printk("%*s   %s", depth, "", usage_str[bit]);
  			len += printk(KERN_CONT " at:\n");
-			print_lock_trace(class->usage_traces + bit, len);
+			print_lock_trace(class->usage_traces[bit], len);
  		}
  	}
  	printk("%*s }\n", depth, "");
@@ -1884,7 +1923,7 @@ print_shortest_lock_dependencies(struct lock_list *leaf,
  	do {
  		print_lock_class_header(entry->class, depth);
  		printk("%*s ... acquired at:\n", depth, "");
-		print_lock_trace(&entry->trace, 2);
+		print_lock_trace(entry->trace, 2);
  		printk("\n");

  		if (depth == 0 && (entry != root)) {
@@ -1995,14 +2034,14 @@ print_bad_irq_dependency(struct task_struct *curr,
  	print_lock_name(backwards_entry->class);
  	pr_warn("\n... which became %s-irq-safe at:\n", irqclass);

-	print_lock_trace(backwards_entry->class->usage_traces + bit1, 1);
+	print_lock_trace(backwards_entry->class->usage_traces[bit1], 1);

  	pr_warn("\nto a %s-irq-unsafe lock:\n", irqclass);
  	print_lock_name(forwards_entry->class);
  	pr_warn("\n... which became %s-irq-unsafe at:\n", irqclass);
  	pr_warn("...");

-	print_lock_trace(forwards_entry->class->usage_traces + bit2, 1);
+	print_lock_trace(forwards_entry->class->usage_traces[bit2], 1);

  	pr_warn("\nother info that might help us debug this:\n\n");
  	print_irq_lock_scenario(backwards_entry, forwards_entry,
@@ -2011,13 +2050,15 @@ print_bad_irq_dependency(struct task_struct *curr,
  	lockdep_print_held_locks(curr);

  	pr_warn("\nthe dependencies between %s-irq-safe lock and the holding lock:\n", irqclass);
-	if (!save_trace(&prev_root->trace))
+	prev_root->trace = save_trace();
+	if (!prev_root->trace)
  		return;
  	print_shortest_lock_dependencies(backwards_entry, prev_root);

  	pr_warn("\nthe dependencies between the lock to be acquired");
  	pr_warn(" and %s-irq-unsafe lock:\n", irqclass);
-	if (!save_trace(&next_root->trace))
+	next_root->trace = save_trace();
+	if (!next_root->trace)
  		return;
  	print_shortest_lock_dependencies(forwards_entry, next_root);

@@ -2369,7 +2410,8 @@ check_deadlock(struct task_struct *curr, struct held_lock *next)
   */
  static int
  check_prev_add(struct task_struct *curr, struct held_lock *prev,
-	       struct held_lock *next, int distance, struct lock_trace *trace)
+	       struct held_lock *next, int distance,
+	       struct lock_trace **const trace)
  {
  	struct lock_list *entry;
  	int ret;
@@ -2444,8 +2486,11 @@ check_prev_add(struct task_struct *curr, struct held_lock *prev,
  		return ret;
  #endif

-	if (!trace->nr_entries && !save_trace(trace))
-		return 0;
+	if (!*trace) {
+		*trace = save_trace();
+		if (!*trace)
+			return 0;
+	}

  	/*
  	 * Ok, all validations passed, add the new lock
@@ -2453,14 +2498,14 @@ check_prev_add(struct task_struct *curr, struct held_lock *prev,
  	 */
  	ret = add_lock_to_list(hlock_class(next), hlock_class(prev),
  			       &hlock_class(prev)->locks_after,
-			       next->acquire_ip, distance, trace);
+			       next->acquire_ip, distance, *trace);

  	if (!ret)
  		return 0;

  	ret = add_lock_to_list(hlock_class(prev), hlock_class(next),
  			       &hlock_class(next)->locks_before,
-			       next->acquire_ip, distance, trace);
+			       next->acquire_ip, distance, *trace);
  	if (!ret)
  		return 0;

@@ -2476,7 +2521,7 @@ check_prev_add(struct task_struct *curr, struct held_lock *prev,
  static int
  check_prevs_add(struct task_struct *curr, struct held_lock *next)
  {
-	struct lock_trace trace = { .nr_entries = 0 };
+	struct lock_trace *trace = NULL;
  	int depth = curr->lockdep_depth;
  	struct held_lock *hlock;

@@ -3015,7 +3060,7 @@ print_usage_bug(struct task_struct *curr, struct held_lock *this,
  	print_lock(this);

  	pr_warn("{%s} state was registered at:\n", usage_str[prev_bit]);
-	print_lock_trace(hlock_class(this)->usage_traces + prev_bit, 1);
+	print_lock_trace(hlock_class(this)->usage_traces[prev_bit], 1);

  	print_irqtrace_events(curr);
  	pr_warn("\nother info that might help us debug this:\n");
@@ -3096,7 +3141,8 @@ print_irq_inversion_bug(struct task_struct *curr,
  	lockdep_print_held_locks(curr);

  	pr_warn("\nthe shortest dependencies between 2nd lock and 1st lock:\n");
-	if (!save_trace(&root->trace))
+	root->trace = save_trace();
+	if (!root->trace)
  		return;
  	print_shortest_lock_dependencies(other, root);

@@ -3580,7 +3626,7 @@ static int mark_lock(struct task_struct *curr, struct held_lock *this,

  	hlock_class(this)->usage_mask |= new_mask;

-	if (!save_trace(hlock_class(this)->usage_traces + new_bit))
+	if (!(hlock_class(this)->usage_traces[new_bit] = save_trace()))
  		return 0;

  	switch (new_bit) {
@@ -5158,6 +5204,12 @@ void __init lockdep_init(void)
  		) / 1024
  		);

+#if defined(CONFIG_TRACE_IRQFLAGS) && defined(CONFIG_PROVE_LOCKING)
+	printk(" memory used for stack traces: %zu kB\n",
+	       (sizeof(stack_trace) + sizeof(stack_trace_hash)) / 1024
+	       );
+#endif
+
  	printk(" per task-struct memory footprint: %zu bytes\n",
  	       sizeof(((struct task_struct *)NULL)->held_locks));
  }
diff --git a/kernel/locking/lockdep_internals.h b/kernel/locking/lockdep_internals.h
index cc83568d5012..92c472fb838f 100644
--- a/kernel/locking/lockdep_internals.h
+++ b/kernel/locking/lockdep_internals.h
@@ -92,6 +92,7 @@ static const unsigned long LOCKF_USED_IN_IRQ_READ =
  #define MAX_LOCKDEP_ENTRIES	16384UL
  #define MAX_LOCKDEP_CHAINS_BITS	15
  #define MAX_STACK_TRACE_ENTRIES	262144UL
+#define STACK_TRACE_HASH_SIZE	8192
  #else
  #define MAX_LOCKDEP_ENTRIES	32768UL

@@ -102,6 +103,7 @@ static const unsigned long LOCKF_USED_IN_IRQ_READ =
   * addresses. Protected by the hash_lock.
   */
  #define MAX_STACK_TRACE_ENTRIES	524288UL
+#define STACK_TRACE_HASH_SIZE	16384
  #endif

  #define MAX_LOCKDEP_CHAINS	(1UL << MAX_LOCKDEP_CHAINS_BITS)

Re: BUG: MAX_STACK_TRACE_ENTRIES too low! (2)

[Peter Zijlstra]

On Thu, Jul 11, 2019 at 11:53:12AM -0700, Bart Van Assche wrote:
> On 7/10/19 3:09 PM, Peter Zijlstra wrote:
> > One thing I mentioned when Thomas did the unwinder API changes was
> > trying to move lockdep over to something like stackdepot.
> > 
> > We can't directly use stackdepot as is, because it uses locks and memory
> > allocation, but we could maybe add a lower level API to it and use that
> > under the graph_lock() on static storage or something.
> > 
> > Otherwise we'll have to (re)implement something like it.
> > 
> > I've not looked at it in detail.
> 
> Hi Peter,
> 
> Is something like the untested patch below perhaps what you had in mind?

Most excellent, yes! Now I suppose the $64000 question is if it actually
reduces the amount of storage we use for stack traces..

Seems to boot just fine.. :-)

Re: BUG: MAX_STACK_TRACE_ENTRIES too low! (2)

[Bart Van Assche]

On 7/12/19 1:55 AM, Peter Zijlstra wrote:
> On Thu, Jul 11, 2019 at 11:53:12AM -0700, Bart Van Assche wrote:
>> On 7/10/19 3:09 PM, Peter Zijlstra wrote:
>>> One thing I mentioned when Thomas did the unwinder API changes was
>>> trying to move lockdep over to something like stackdepot.
>>>
>>> We can't directly use stackdepot as is, because it uses locks and memory
>>> allocation, but we could maybe add a lower level API to it and use that
>>> under the graph_lock() on static storage or something.
>>>
>>> Otherwise we'll have to (re)implement something like it.
>>>
>>> I've not looked at it in detail.
>>
>> Hi Peter,
>>
>> Is something like the untested patch below perhaps what you had in mind?
> 
> Most excellent, yes! Now I suppose the $64000 question is if it actually
> reduces the amount of storage we use for stack traces..
> 
> Seems to boot just fine.. :-)

Hi Peter,

On my setup after some time the space occupied by stack traces stabilizes
to the following:

# grep stack /proc/lockdep_stats
  stack-trace entries:                169456 [max: 524288]
  number of stack traces:        9073
  number of stack hash chains:   6980

I think these numbers show that there are some but not too many hash
collisions (the code for the hash statistics was added after I e-mailed my
patch).

Bart.