2022-09-18 15:53:40

by Tetsuo Handa

[permalink] [raw]
Subject: [PATCH] lockdep: report name and key when look_up_lock_class() got confused

Printing this information will be helpful.

------------[ cut here ]------------
class->name=slock-AF_INET6 lock->name=l2tp_sock lock->key=l2tp_socket_class
WARNING: CPU: 2 PID: 9237 at kernel/locking/lockdep.c:940 look_up_lock_class+0xcc/0x140
Modules linked in:
CPU: 2 PID: 9237 Comm: a.out Not tainted 6.0.0-rc5-00094-ga335366bad13-dirty #860
Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
RIP: 0010:look_up_lock_class+0xcc/0x140

Signed-off-by: Tetsuo Handa <[email protected]>
---
kernel/locking/lockdep.c | 6 ++++--
1 file changed, 4 insertions(+), 2 deletions(-)

diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
index 64a13eb56078..a22469dbeeee 100644
--- a/kernel/locking/lockdep.c
+++ b/kernel/locking/lockdep.c
@@ -934,8 +934,10 @@ look_up_lock_class(const struct lockdep_map *lock, unsigned int subclass)
* Huh! same key, different name? Did someone trample
* on some memory? We're most confused.
*/
- WARN_ON_ONCE(class->name != lock->name &&
- lock->key != &__lockdep_no_validate__);
+ WARN_ONCE(class->name != lock->name &&
+ lock->key != &__lockdep_no_validate__,
+ "class->name=%s lock->name=%s lock->key=%ps\n",
+ class->name, lock->name, lock->key);
return class;
}
}
--
2.34.1


2022-09-18 18:48:23

by Boqun Feng

[permalink] [raw]
Subject: Re: [PATCH] lockdep: report name and key when look_up_lock_class() got confused

On Mon, Sep 19, 2022 at 12:01:30AM +0900, Tetsuo Handa wrote:
> Printing this information will be helpful.
>
> ------------[ cut here ]------------
> class->name=slock-AF_INET6 lock->name=l2tp_sock lock->key=l2tp_socket_class
> WARNING: CPU: 2 PID: 9237 at kernel/locking/lockdep.c:940 look_up_lock_class+0xcc/0x140
> Modules linked in:
> CPU: 2 PID: 9237 Comm: a.out Not tainted 6.0.0-rc5-00094-ga335366bad13-dirty #860
> Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> RIP: 0010:look_up_lock_class+0xcc/0x140
>
> Signed-off-by: Tetsuo Handa <[email protected]>
> ---
> kernel/locking/lockdep.c | 6 ++++--
> 1 file changed, 4 insertions(+), 2 deletions(-)
>
> diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
> index 64a13eb56078..a22469dbeeee 100644
> --- a/kernel/locking/lockdep.c
> +++ b/kernel/locking/lockdep.c
> @@ -934,8 +934,10 @@ look_up_lock_class(const struct lockdep_map *lock, unsigned int subclass)
> * Huh! same key, different name? Did someone trample
> * on some memory? We're most confused.
> */
> - WARN_ON_ONCE(class->name != lock->name &&
> - lock->key != &__lockdep_no_validate__);
> + WARN_ONCE(class->name != lock->name &&
> + lock->key != &__lockdep_no_validate__,
> + "class->name=%s lock->name=%s lock->key=%ps\n",
> + class->name, lock->name, lock->key);

Maybe more human readable information like:

"Looking for class \"%s\" with key %ps, but found a different class \"%s\" with the same key\n"
lock->name, lock->key, class->name);

?

Regards,
Boqun

> return class;
> }
> }
> --
> 2.34.1
>

2022-09-19 01:06:14

by Tetsuo Handa

[permalink] [raw]
Subject: [PATCH v2] lockdep: report name and key when look_up_lock_class() got confused

Printing this information will be helpful.

------------[ cut here ]------------
Looking for class "l2tp_sock" with key l2tp_socket_class, but found a different class "slock-AF_INET6" with the same key
WARNING: CPU: 1 PID: 14195 at kernel/locking/lockdep.c:940 look_up_lock_class+0xcc/0x140
Modules linked in:
CPU: 1 PID: 14195 Comm: a.out Not tainted 6.0.0-rc6-dirty #863
Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
RIP: 0010:look_up_lock_class+0xcc/0x140

Signed-off-by: Tetsuo Handa <[email protected]>
---
Changes in v2:
Make message more human readable, suggested by Boqun Feng <[email protected]>.

kernel/locking/lockdep.c | 6 ++++--
1 file changed, 4 insertions(+), 2 deletions(-)

diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
index 64a13eb56078..e3375bc40dad 100644
--- a/kernel/locking/lockdep.c
+++ b/kernel/locking/lockdep.c
@@ -934,8 +934,10 @@ look_up_lock_class(const struct lockdep_map *lock, unsigned int subclass)
* Huh! same key, different name? Did someone trample
* on some memory? We're most confused.
*/
- WARN_ON_ONCE(class->name != lock->name &&
- lock->key != &__lockdep_no_validate__);
+ WARN_ONCE(class->name != lock->name &&
+ lock->key != &__lockdep_no_validate__,
+ "Looking for class \"%s\" with key %ps, but found a different class \"%s\" with the same key\n",
+ lock->name, lock->key, class->name);
return class;
}
}
--
2.34.1

2022-09-19 11:29:10

by Peter Zijlstra

[permalink] [raw]
Subject: Re: [PATCH v2] lockdep: report name and key when look_up_lock_class() got confused

On Mon, Sep 19, 2022 at 09:52:13AM +0900, Tetsuo Handa wrote:
> Printing this information will be helpful.
>
> ------------[ cut here ]------------
> Looking for class "l2tp_sock" with key l2tp_socket_class, but found a different class "slock-AF_INET6" with the same key
> WARNING: CPU: 1 PID: 14195 at kernel/locking/lockdep.c:940 look_up_lock_class+0xcc/0x140
> Modules linked in:
> CPU: 1 PID: 14195 Comm: a.out Not tainted 6.0.0-rc6-dirty #863
> Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> RIP: 0010:look_up_lock_class+0xcc/0x140
>
> Signed-off-by: Tetsuo Handa <[email protected]>

Urgh, you hitting that WARN enough times to want to improve it seems to
suggest your machine is quite sick.

Anyway, patch is ok I suppose.

2022-09-19 14:11:22

by Tetsuo Handa

[permalink] [raw]
Subject: Re: [PATCH v2] lockdep: report name and key when look_up_lock_class() got confused

On 2022/09/19 19:48, Peter Zijlstra wrote:
> On Mon, Sep 19, 2022 at 09:52:13AM +0900, Tetsuo Handa wrote:
>> Printing this information will be helpful.
>>
>> ------------[ cut here ]------------
>> Looking for class "l2tp_sock" with key l2tp_socket_class, but found a different class "slock-AF_INET6" with the same key
>> WARNING: CPU: 1 PID: 14195 at kernel/locking/lockdep.c:940 look_up_lock_class+0xcc/0x140
>> Modules linked in:
>> CPU: 1 PID: 14195 Comm: a.out Not tainted 6.0.0-rc6-dirty #863
>> Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
>> RIP: 0010:look_up_lock_class+0xcc/0x140
>>
>> Signed-off-by: Tetsuo Handa <[email protected]>
>
> Urgh, you hitting that WARN enough times to want to improve it seems to
> suggest your machine is quite sick.

My machine is not sick at all. I just wanted this hint for debugging
https://syzkaller.appspot.com/bug?extid=94cc2a66fc228b23f360 .

In a world of debugging without vmcore, printing as much hint as possible is
important. Therefore, WARN_ONCE() is more appreciated than WARN_ON_ONCE().

>
> Anyway, patch is ok I suppose.

Thank you. Please send this patch and
https://lkml.kernel.org/r/[email protected]
via your tree.

Subject: [tip: locking/core] locking/lockdep: Print more debug information - report name and key when look_up_lock_class() got confused

The following commit has been merged into the locking/core branch of tip:

Commit-ID: 76e64c73db9542ff4bae8a60f4f32e38f3799b95
Gitweb: https://git.kernel.org/tip/76e64c73db9542ff4bae8a60f4f32e38f3799b95
Author: Tetsuo Handa <[email protected]>
AuthorDate: Mon, 19 Sep 2022 09:52:13 +09:00
Committer: Ingo Molnar <[email protected]>
CommitterDate: Wed, 21 Sep 2022 09:58:21 +02:00

locking/lockdep: Print more debug information - report name and key when look_up_lock_class() got confused

Printing this information will be helpful:

------------[ cut here ]------------
Looking for class "l2tp_sock" with key l2tp_socket_class, but found a different class "slock-AF_INET6" with the same key
WARNING: CPU: 1 PID: 14195 at kernel/locking/lockdep.c:940 look_up_lock_class+0xcc/0x140
Modules linked in:
CPU: 1 PID: 14195 Comm: a.out Not tainted 6.0.0-rc6-dirty #863
Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
RIP: 0010:look_up_lock_class+0xcc/0x140

Signed-off-by: Tetsuo Handa <[email protected]>
Signed-off-by: Ingo Molnar <[email protected]>
Link: https://lore.kernel.org/r/[email protected]
---
kernel/locking/lockdep.c | 6 ++++--
1 file changed, 4 insertions(+), 2 deletions(-)

diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
index 64a13eb..e3375bc 100644
--- a/kernel/locking/lockdep.c
+++ b/kernel/locking/lockdep.c
@@ -934,8 +934,10 @@ look_up_lock_class(const struct lockdep_map *lock, unsigned int subclass)
* Huh! same key, different name? Did someone trample
* on some memory? We're most confused.
*/
- WARN_ON_ONCE(class->name != lock->name &&
- lock->key != &__lockdep_no_validate__);
+ WARN_ONCE(class->name != lock->name &&
+ lock->key != &__lockdep_no_validate__,
+ "Looking for class \"%s\" with key %ps, but found a different class \"%s\" with the same key\n",
+ lock->name, lock->key, class->name);
return class;
}
}