Messages in this thread | | | Date | Wed, 10 Jul 2019 10:21:23 -0700 | From | Eric Biggers <> | Subject | Re: BUG: MAX_STACK_TRACE_ENTRIES too low! (2) |
| |
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
| |