Re: BUG: MAX_STACK_TRACE_ENTRIES too low!

Re: BUG: MAX_STACK_TRACE_ENTRIES too low!

[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=17dec757200000
start commit:   669de8bd kernel/workqueue: Use dynamic lockdep keys for wo..
git tree:       upstream
final crash:    https://syzkaller.appspot.com/x/report.txt?x=143ec757200000
console output: https://syzkaller.appspot.com/x/log.txt?x=103ec757200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=bd349f14600e1305
dashboard link: https://syzkaller.appspot.com/bug?extid=78923eea7cf44364f4fb
userspace arch: amd64
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=149c858d200000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=111aee33200000

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

Re: BUG: MAX_STACK_TRACE_ENTRIES too low!

[Bart Van Assche]

On Mon, 2019-03-11 at 06:26 -0700, 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=17dec757200000
> start commit:   669de8bd kernel/workqueue: Use dynamic lockdep keys for wo..
> git tree:       upstream
> final crash:    https://syzkaller.appspot.com/x/report.txt?x=143ec757200000
> console output: https://syzkaller.appspot.com/x/log.txt?x=103ec757200000
> kernel config:  https://syzkaller.appspot.com/x/.config?x=bd349f14600e1305
> dashboard link: https://syzkaller.appspot.com/bug?extid=78923eea7cf44364f4fb
> userspace arch: amd64
> syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=149c858d200000
> C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=111aee33200000
> 
> Reported-by: syzbot+78923eea7cf44364f4fb@syzkaller.appspotmail.com
> Fixes: 669de8bd ("kernel/workqueue: Use dynamic lockdep keys for  
> workqueues")

I think this issue has been fixed by a commit that went upstream yesterday. Hence:

#syz fix: workqueue, lockdep: Fix an alloc_workqueue() error path

Re: BUG: MAX_STACK_TRACE_ENTRIES too low!

[Linus Torvalds]

On Mon, Mar 11, 2019 at 8:19 AM Bart Van Assche <bvanassche@acm.org> wrote:
>
> I think this issue has been fixed by a commit that went upstream yesterday. Hence:
>
> #syz fix: workqueue, lockdep: Fix an alloc_workqueue() error path

Well, syzbot just reported a problem with that fix itself ("WARNING in
lockdep_unregister_key").

Looks like now the lockdep_unregister_key() cleanup might be called
even when the lockdep map was never initialized at all in that error
case. Hmm?

I _think_ you need to split that "err_free_wq" label into "just free
the wq" and "unregister lockdep and free wq".

But I didn't look any more closely, I might be misreading things.

                Linus

Re: BUG: MAX_STACK_TRACE_ENTRIES too low!

[Bart Van Assche]

On Mon, 2019-03-11 at 10:48 -0700, Linus Torvalds wrote:
> On Mon, Mar 11, 2019 at 8:19 AM Bart Van Assche <bvanassche@acm.org> wrote:
> > 
> > I think this issue has been fixed by a commit that went upstream yesterday. Hence:
> > 
> > #syz fix: workqueue, lockdep: Fix an alloc_workqueue() error path
> 
> Well, syzbot just reported a problem with that fix itself ("WARNING in
> lockdep_unregister_key").
> 
> Looks like now the lockdep_unregister_key() cleanup might be called
> even when the lockdep map was never initialized at all in that error
> case. Hmm?
> 
> I _think_ you need to split that "err_free_wq" label into "just free
> the wq" and "unregister lockdep and free wq".
> 
> But I didn't look any more closely, I might be misreading things.

Hi Linus,

>From the console output of the syzbot bug report at the start of this
e-mail thread:

WARNING: CPU: 1 PID: 7649 at kernel/locking/lockdep.c:747 register_lock_class+0x10de/0x2220

On line 747 in lockdep.c there is the following warning statement:

			WARN_ON_ONCE(class->name != lock->name);

My interpretation is that this means that a lockdep key got reregistered
without unregistration between the two registration calls. That's why I
posted my "#syz fix: workqueue, lockdep: Fix an alloc_workqueue() error
path" reply.

The latest syzbot complaint is different. In the console output of the latest
report I found the following:

WARNING: CPU: 1 PID: 6970 at kernel/locking/lockdep.c:4925 lockdep_unregister_key+0x21c/0x4e0

On line 4925 there is the following warning statement:

	WARN_ON_ONCE(!found);

In other words, lockdep_unregister_key() got called for a key that was never
registered.

I agree with your conclusion that the err_free_wq label needs to be split. I
will post a patch that realizes this.

Bart.