[PATCH] lockdep: Show address of "struct lockdep_map" at print_lock().

[PATCH] lockdep: Show address of "struct lockdep_map" at print_lock().

[Tetsuo Handa]

Currently, print_lock() is printing hlock->acquire_ip field in both
"[<%px>]" and "%pS" format. But "[<%px>]" is little useful nowadays, for
we use scripts/faddr2line which receives "%pS" for finding the location
in the source code.

Since "struct lockdep_map" is embedded into lock objects, we can know
which instance of a lock object is acquired using hlock->instance field.
This will help finding which threads are causing a lock contention when
e.g. the OOM reaper failed to acquire an OOM victim's mmap_sem for read.

Thus, this patch replaces "[<%px>]" for printing hlock->acquire_ip field
with "[%px]" for printing hlock->instance field.

----------------------------------------
[  561.490202] Out of memory: Kill process 58945 (anacron) score 0 or sacrifice child
[  561.494119] Killed process 58945 (anacron) total-vm:123220kB, anon-rss:232kB, file-rss:4kB, shmem-rss:0kB
(...snipped...)
[  562.208348] Out of memory: Kill process 636 (atd) score 0 or sacrifice child
[  562.212077] Killed process 636 (atd) total-vm:25868kB, anon-rss:204kB, file-rss:0kB, shmem-rss:0kB
(...snipped...)
[  562.944890] Out of memory: Kill process 971 (agetty) score 0 or sacrifice child
[  562.948586] Killed process 971 (agetty) total-vm:110056kB, anon-rss:124kB, file-rss:4kB, shmem-rss:0kB
(...snipped...)
[  563.599714] Out of memory: Kill process 116521 (a.out) score 0 or sacrifice child
[  563.603599] Killed process 118444 (a.out) total-vm:4176kB, anon-rss:88kB, file-rss:0kB, shmem-rss:0kB
[  564.664223] oom_reaper: unable to reap pid:118444 (a.out)
[  564.667311]
[  564.667311] Showing all locks held in the system:
(...snipped...)
[  564.731611] 1 lock held by kswapd0/76:
[  564.734415]  #0: [ffffa3b4f2c52ac0] (&mapping->i_mmap_rwsem){++++}, at: rmap_walk_file+0x1d9/0x2a0
(...snipped...)
[  564.864860] 1 lock held by atd/636:
[  564.868524]  #0: [ffffa3b4f2c52ac0] (&mapping->i_mmap_rwsem){++++}, at: unlink_file_vma+0x28/0x50
[  564.874354] 1 lock held by agetty/971:
[  564.878085]  #0: [ffffa3b4f2c52ac0] (&mapping->i_mmap_rwsem){++++}, at: unlink_file_vma+0x28/0x50
(...snipped...)
[  564.977497] 1 lock held by anacron/58945:
[  564.981365]  #0: [ffffa3b4f2c52ac0] (&mapping->i_mmap_rwsem){++++}, at: unlink_file_vma+0x28/0x50
(...snipped...)
[  569.866283] 3 locks held by a.out/118444:
[  569.869992]  #0: [ffffa3b4df1c0c88] (&mm->mmap_sem){++++}, at: copy_process.part.40+0x1090/0x1fa0
[  569.876392]  #1: [ffffa3b4dfeaae48] (&mm->mmap_sem/1){+.+.}, at: copy_process.part.40+0x10b9/0x1fa0
[  569.882393]  #2: [ffffa3b4f2c52ac0] (&mapping->i_mmap_rwsem){++++}, at: copy_process.part.40+0x12ad/0x1fa0
(...snipped...)
[  581.237572] 3 locks held by a.out/121276:
[  581.241318]  #0: [ffffa3b40cd071c8] (&mm->mmap_sem){++++}, at: copy_process.part.40+0x1090/0x1fa0
[  581.247326]  #1: [ffffa3b465bb44c8] (&mm->mmap_sem/1){+.+.}, at: copy_process.part.40+0x10b9/0x1fa0
[  581.253370]  #2: [ffffa3b4f2c52ac0] (&mapping->i_mmap_rwsem){++++}, at: rmap_walk_file+0x1d9/0x2a0
(...snipped...)
[  589.357139] 1 lock held by a.out/122960:
[  589.363224]  #0: [ffffa3b4f2c52ac0] (&mapping->i_mmap_rwsem){++++}, at: rmap_walk_file+0x1d9/0x2a0
(...snipped...)
[  594.255168] 3 locks held by a.out/124002:
[  594.258956]  #0: [ffffa3b42fead008] (&mm->mmap_sem){++++}, at: copy_process.part.40+0x1090/0x1fa0
[  594.265047]  #1: [ffffa3b4e7b52308] (&mm->mmap_sem/1){+.+.}, at: copy_process.part.40+0x10b9/0x1fa0
[  594.271051]  #2: [ffffa3b4f2c52ac0] (&mapping->i_mmap_rwsem){++++}, at: copy_process.part.40+0x12ad/0x1fa0
(...snipped...)
[  594.286952] 3 locks held by a.out/124004:
[  594.290884]  #0: [ffffa3b42feac4c8] (&mm->mmap_sem){++++}, at: copy_process.part.40+0x1090/0x1fa0
[  594.296956]  #1: [ffffa3b3db86db48] (&mm->mmap_sem/1){+.+.}, at: copy_process.part.40+0x10b9/0x1fa0
[  594.303139]  #2: [ffffa3b4f2c52ac0] (&mapping->i_mmap_rwsem){++++}, at: rmap_walk_file+0x1d9/0x2a0
(...snipped...)
[  604.765878] 2 locks held by a.out/126388:
[  604.769899]  #0: [ffffa3b3c70cb988] (&mm->mmap_sem){++++}, at: __do_page_fault+0x16f/0x4d0
[  604.775890]  #1: [ffffa3b4f2c52ac0] (&mapping->i_mmap_rwsem){++++}, at: rmap_walk_file+0x1d9/0x2a0
(...snipped...)
[  614.240787] 2 locks held by a.out/128585:
[  614.244655]  #0: [ffffa3b461e1a308] (&mm->mmap_sem){++++}, at: __do_page_fault+0x16f/0x4d0
[  614.250489]  #1: [ffffa3b4f2c52ac0] (&mapping->i_mmap_rwsem){++++}, at: rmap_walk_file+0x1d9/0x2a0
(...snipped...)
[  628.863629] 2 locks held by a.out/1165:
[  628.867533]  #0: [ffffa3b438472e48] (&mm->mmap_sem){++++}, at: __do_page_fault+0x16f/0x4d0
[  628.873570]  #1: [ffffa3b4f2c52ac0] (&mapping->i_mmap_rwsem){++++}, at: rmap_walk_file+0x1d9/0x2a0
----------------------------------------

Signed-off-by: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: Thomas Gleixner <tglx@linutronix.de>
Cc: David Rientjes <rientjes@google.com>
Cc: Michal Hocko <mhocko@suse.com>
---
 kernel/locking/lockdep.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
index 12a2805..7835233 100644
--- a/kernel/locking/lockdep.c
+++ b/kernel/locking/lockdep.c
@@ -556,9 +556,9 @@ static void print_lock(struct held_lock *hlock)
 		return;
 	}
 
+	printk(KERN_CONT "[%px]", hlock->instance);
 	print_lock_name(lock_classes + class_idx - 1);
-	printk(KERN_CONT ", at: [<%px>] %pS\n",
-		(void *)hlock->acquire_ip, (void *)hlock->acquire_ip);
+	printk(KERN_CONT ", at: %pS\n", (void *)hlock->acquire_ip);
 }
 
 static void lockdep_print_held_locks(struct task_struct *curr)
-- 
1.8.3.1

Re: [PATCH] lockdep: Show address of "struct lockdep_map" at print_lock().

[Michal Hocko]

On Mon 26-03-18 19:18:33, Tetsuo Handa wrote:
> Currently, print_lock() is printing hlock->acquire_ip field in both
> "[<%px>]" and "%pS" format. But "[<%px>]" is little useful nowadays, for
> we use scripts/faddr2line which receives "%pS" for finding the location
> in the source code.
> 
> Since "struct lockdep_map" is embedded into lock objects, we can know
> which instance of a lock object is acquired using hlock->instance field.
> This will help finding which threads are causing a lock contention when
> e.g. the OOM reaper failed to acquire an OOM victim's mmap_sem for read.

How? All I can see is that we can match which instances are the same.
This would be an interesting thing to know AFAICS because you can tell
different instances of lock apart. So the patch makes some sense to me,
I am just not sure about changelog.
-- 
Michal Hocko
SUSE Labs

Re: [PATCH] lockdep: Show address of "struct lockdep_map" at print_lock().

[Michal Hocko]

On Mon 26-03-18 15:19:11, Michal Hocko wrote:
> On Mon 26-03-18 19:18:33, Tetsuo Handa wrote:
> > Currently, print_lock() is printing hlock->acquire_ip field in both
> > "[<%px>]" and "%pS" format. But "[<%px>]" is little useful nowadays, for
> > we use scripts/faddr2line which receives "%pS" for finding the location
> > in the source code.
> > 
> > Since "struct lockdep_map" is embedded into lock objects, we can know
> > which instance of a lock object is acquired using hlock->instance field.
> > This will help finding which threads are causing a lock contention when
> > e.g. the OOM reaper failed to acquire an OOM victim's mmap_sem for read.
> 
> How? All I can see is that we can match which instances are the same.
> This would be an interesting thing to know AFAICS because you can tell
> different instances of lock apart. So the patch makes some sense to me,
> I am just not sure about changelog.

Also, are you sure that %px is appropriate? Can this be abused to leak
the kernel pointer and infere other useful data from it? %p should be
sufficient to tell different lock instances even with the hashed
addresses.
-- 
Michal Hocko
SUSE Labs

Re: [PATCH] lockdep: Show address of "struct lockdep_map" at print_lock().

[Peter Zijlstra]

On Mon, Mar 26, 2018 at 07:18:33PM +0900, Tetsuo Handa wrote:
> [  628.863629] 2 locks held by a.out/1165:
> [  628.867533]  #0: [ffffa3b438472e48] (&mm->mmap_sem){++++}, at: __do_page_fault+0x16f/0x4d0
> [  628.873570]  #1: [ffffa3b4f2c52ac0] (&mapping->i_mmap_rwsem){++++}, at: rmap_walk_file+0x1d9/0x2a0

Maybe change the string a little, because from the above it's not at all
effident that the [] thing is the lock instance.

> diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
> index 12a2805..7835233 100644
> --- a/kernel/locking/lockdep.c
> +++ b/kernel/locking/lockdep.c
> @@ -556,9 +556,9 @@ static void print_lock(struct held_lock *hlock)
>  		return;
>  	}
>  
> +	printk(KERN_CONT "[%px]", hlock->instance);

And yeah, what Michal said, that wants to be %p, we're fine with the
thing being hashed, all we want to do is equivalience, which can be done
with hashed pinters too.

>  	print_lock_name(lock_classes + class_idx - 1);
> -	printk(KERN_CONT ", at: [<%px>] %pS\n",
> -		(void *)hlock->acquire_ip, (void *)hlock->acquire_ip);
> +	printk(KERN_CONT ", at: %pS\n", (void *)hlock->acquire_ip);
>  }

Otherwise no real objection to the patch.

Re: [PATCH] lockdep: Show address of "struct lockdep_map" at print_lock().

[Tetsuo Handa]

Peter Zijlstra wrote:
> On Mon, Mar 26, 2018 at 07:18:33PM +0900, Tetsuo Handa wrote:
> > [  628.863629] 2 locks held by a.out/1165:
> > [  628.867533]  #0: [ffffa3b438472e48] (&mm->mmap_sem){++++}, at: __do_page_fault+0x16f/0x4d0
> > [  628.873570]  #1: [ffffa3b4f2c52ac0] (&mapping->i_mmap_rwsem){++++}, at: rmap_walk_file+0x1d9/0x2a0
> 
> Maybe change the string a little, because from the above it's not at all
> effident that the [] thing is the lock instance.
> 
> > diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
> > index 12a2805..7835233 100644
> > --- a/kernel/locking/lockdep.c
> > +++ b/kernel/locking/lockdep.c
> > @@ -556,9 +556,9 @@ static void print_lock(struct held_lock *hlock)
> >  		return;
> >  	}
> >  
> > +	printk(KERN_CONT "[%px]", hlock->instance);
> 
> And yeah, what Michal said, that wants to be %p, we're fine with the
> thing being hashed, all we want to do is equivalience, which can be done
> with hashed pinters too.
> 
> >  	print_lock_name(lock_classes + class_idx - 1);
> > -	printk(KERN_CONT ", at: [<%px>] %pS\n",
> > -		(void *)hlock->acquire_ip, (void *)hlock->acquire_ip);
> > +	printk(KERN_CONT ", at: %pS\n", (void *)hlock->acquire_ip);
> >  }
> 
> Otherwise no real objection to the patch.
> 

I see. What about plain

-	printk(KERN_CONT "[%px]", hlock->instance);
+	printk(KERN_CONT "%p", hlock->instance);

because we don't need to use [] ?

I'm trying to remove "[<%px>]" for hlock->acquire_ip field in order to
reduce amount of output, for debug_show_all_locks() prints a lot.

[PATCH v2] lockdep: Show address of "struct lockdep_map" at print_lock().

[Tetsuo Handa]

>From 91c081c4c5f6a99402542951e7de661c38f928ab Mon Sep 17 00:00:00 2001
From: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
Date: Tue, 27 Mar 2018 19:38:33 +0900
Subject: [PATCH v2] lockdep: Show address of "struct lockdep_map" at print_lock().

Since "struct lockdep_map" is embedded into lock objects, we can know
which instance of a lock object is acquired using hlock->instance field.
This will help finding which threads are causing a lock contention.

Currently, print_lock() is printing hlock->acquire_ip field in both
"[<%px>]" and "%pS" format. But "[<%px>]" is little useful nowadays, for
we use scripts/faddr2line which receives "%pS" for finding the location
in the source code. And I want to reduce amount of output, for
debug_show_all_locks() might print a lot.

Therefore, this patch replaces "[<%px>]" for printing hlock->acquire_ip
field with "%p" for printing hlock->instance field.

[  251.305475] 3 locks held by a.out/31106:
[  251.308949]  #0: 00000000b0f753ba (&mm->mmap_sem){++++}, at: copy_process.part.41+0x10d5/0x1fe0
[  251.314283]  #1: 00000000ef64d539 (&mm->mmap_sem/1){+.+.}, at: copy_process.part.41+0x10fe/0x1fe0
[  251.319618]  #2: 00000000b41a282e (&mapping->i_mmap_rwsem){++++}, at: copy_process.part.41+0x12f2/0x1fe0

Signed-off-by: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: Thomas Gleixner <tglx@linutronix.de>
Cc: David Rientjes <rientjes@google.com>
Cc: Michal Hocko <mhocko@suse.com>
---
 kernel/locking/lockdep.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
index 12a2805..0233863 100644
--- a/kernel/locking/lockdep.c
+++ b/kernel/locking/lockdep.c
@@ -556,9 +556,9 @@ static void print_lock(struct held_lock *hlock)
 		return;
 	}
 
+	printk(KERN_CONT "%p", hlock->instance);
 	print_lock_name(lock_classes + class_idx - 1);
-	printk(KERN_CONT ", at: [<%px>] %pS\n",
-		(void *)hlock->acquire_ip, (void *)hlock->acquire_ip);
+	printk(KERN_CONT ", at: %pS\n", (void *)hlock->acquire_ip);
 }
 
 static void lockdep_print_held_locks(struct task_struct *curr)
-- 
1.8.3.1

Re: [PATCH v2] lockdep: Show address of "struct lockdep_map" at print_lock().

[Michal Hocko]

On Tue 27-03-18 19:41:41, Tetsuo Handa wrote:
> >From 91c081c4c5f6a99402542951e7de661c38f928ab Mon Sep 17 00:00:00 2001
> From: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
> Date: Tue, 27 Mar 2018 19:38:33 +0900
> Subject: [PATCH v2] lockdep: Show address of "struct lockdep_map" at print_lock().
> 
> Since "struct lockdep_map" is embedded into lock objects, we can know
> which instance of a lock object is acquired using hlock->instance field.
> This will help finding which threads are causing a lock contention.
> 
> Currently, print_lock() is printing hlock->acquire_ip field in both
> "[<%px>]" and "%pS" format. But "[<%px>]" is little useful nowadays, for
> we use scripts/faddr2line which receives "%pS" for finding the location
> in the source code. And I want to reduce amount of output, for
> debug_show_all_locks() might print a lot.
> 
> Therefore, this patch replaces "[<%px>]" for printing hlock->acquire_ip
> field with "%p" for printing hlock->instance field.
> 
> [  251.305475] 3 locks held by a.out/31106:
> [  251.308949]  #0: 00000000b0f753ba (&mm->mmap_sem){++++}, at: copy_process.part.41+0x10d5/0x1fe0
> [  251.314283]  #1: 00000000ef64d539 (&mm->mmap_sem/1){+.+.}, at: copy_process.part.41+0x10fe/0x1fe0
> [  251.319618]  #2: 00000000b41a282e (&mapping->i_mmap_rwsem){++++}, at: copy_process.part.41+0x12f2/0x1fe0
> 
> Signed-off-by: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
> Cc: Peter Zijlstra <peterz@infradead.org>
> Cc: Ingo Molnar <mingo@redhat.com>
> Cc: Borislav Petkov <bp@suse.de>
> Cc: Thomas Gleixner <tglx@linutronix.de>
> Cc: David Rientjes <rientjes@google.com>
> Cc: Michal Hocko <mhocko@suse.com>

Looks good to me. Feel free to add
Acked-by: Michal Hocko <mhocko@suse.com>
-- 
Michal Hocko
SUSE Labs

Re: [PATCH v2] lockdep: Show address of "struct lockdep_map" at print_lock().

[David Rientjes]

On Tue, 27 Mar 2018, Tetsuo Handa wrote:

> Since "struct lockdep_map" is embedded into lock objects, we can know
> which instance of a lock object is acquired using hlock->instance field.
> This will help finding which threads are causing a lock contention.
> 
> Currently, print_lock() is printing hlock->acquire_ip field in both
> "[<%px>]" and "%pS" format. But "[<%px>]" is little useful nowadays, for
> we use scripts/faddr2line which receives "%pS" for finding the location
> in the source code. And I want to reduce amount of output, for
> debug_show_all_locks() might print a lot.
> 
> Therefore, this patch replaces "[<%px>]" for printing hlock->acquire_ip
> field with "%p" for printing hlock->instance field.
> 
> [  251.305475] 3 locks held by a.out/31106:
> [  251.308949]  #0: 00000000b0f753ba (&mm->mmap_sem){++++}, at: copy_process.part.41+0x10d5/0x1fe0
> [  251.314283]  #1: 00000000ef64d539 (&mm->mmap_sem/1){+.+.}, at: copy_process.part.41+0x10fe/0x1fe0
> [  251.319618]  #2: 00000000b41a282e (&mapping->i_mmap_rwsem){++++}, at: copy_process.part.41+0x12f2/0x1fe0
> 
> Signed-off-by: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
> Cc: Peter Zijlstra <peterz@infradead.org>
> Cc: Ingo Molnar <mingo@redhat.com>
> Cc: Borislav Petkov <bp@suse.de>
> Cc: Thomas Gleixner <tglx@linutronix.de>
> Cc: David Rientjes <rientjes@google.com>
> Cc: Michal Hocko <mhocko@suse.com>

Acked-by: David Rientjes <rientjes@google.com>

Re: [PATCH v2] lockdep: Show address of "struct lockdep_map" at print_lock().

[Tetsuo Handa]

>From 91c081c4c5f6a99402542951e7de661c38f928ab Mon Sep 17 00:00:00 2001
From: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
Date: Tue, 27 Mar 2018 19:38:33 +0900
Subject: [PATCH v2] lockdep: Show address of "struct lockdep_map" at print_lock().

Since "struct lockdep_map" is embedded into lock objects, we can know
which instance of a lock object is acquired using hlock->instance field.
This will help finding which threads are causing a lock contention.

Currently, print_lock() is printing hlock->acquire_ip field in both
"[<%px>]" and "%pS" format. But "[<%px>]" is little useful nowadays, for
we use scripts/faddr2line which receives "%pS" for finding the location
in the source code. And I want to reduce amount of output, for
debug_show_all_locks() might print a lot.

Therefore, this patch replaces "[<%px>]" for printing hlock->acquire_ip
field with "%p" for printing hlock->instance field.

[  251.305475] 3 locks held by a.out/31106:
[  251.308949]  #0: 00000000b0f753ba (&mm->mmap_sem){++++}, at: copy_process.part.41+0x10d5/0x1fe0
[  251.314283]  #1: 00000000ef64d539 (&mm->mmap_sem/1){+.+.}, at: copy_process.part.41+0x10fe/0x1fe0
[  251.319618]  #2: 00000000b41a282e (&mapping->i_mmap_rwsem){++++}, at: copy_process.part.41+0x12f2/0x1fe0

Signed-off-by: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
Acked-by: Michal Hocko <mhocko@suse.com>
Acked-by: David Rientjes <rientjes@google.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: Thomas Gleixner <tglx@linutronix.de>
---
 kernel/locking/lockdep.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
index 12a2805..0233863 100644
--- a/kernel/locking/lockdep.c
+++ b/kernel/locking/lockdep.c
@@ -556,9 +556,9 @@ static void print_lock(struct held_lock *hlock)
 		return;
 	}
 
+	printk(KERN_CONT "%p", hlock->instance);
 	print_lock_name(lock_classes + class_idx - 1);
-	printk(KERN_CONT ", at: [<%px>] %pS\n",
-		(void *)hlock->acquire_ip, (void *)hlock->acquire_ip);
+	printk(KERN_CONT ", at: %pS\n", (void *)hlock->acquire_ip);
 }
 
 static void lockdep_print_held_locks(struct task_struct *curr)
-- 
1.8.3.1

Re: [PATCH v2] lockdep: Show address of "struct lockdep_map" at print_lock().

[Peter Zijlstra]

On Thu, Mar 29, 2018 at 07:26:52PM +0900, Tetsuo Handa wrote:
> >From 91c081c4c5f6a99402542951e7de661c38f928ab Mon Sep 17 00:00:00 2001
> From: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
> Date: Tue, 27 Mar 2018 19:38:33 +0900
> Subject: [PATCH v2] lockdep: Show address of "struct lockdep_map" at print_lock().
> 
> Since "struct lockdep_map" is embedded into lock objects, we can know
> which instance of a lock object is acquired using hlock->instance field.
> This will help finding which threads are causing a lock contention.
> 
> Currently, print_lock() is printing hlock->acquire_ip field in both
> "[<%px>]" and "%pS" format. But "[<%px>]" is little useful nowadays, for
> we use scripts/faddr2line which receives "%pS" for finding the location
> in the source code. And I want to reduce amount of output, for
> debug_show_all_locks() might print a lot.
> 
> Therefore, this patch replaces "[<%px>]" for printing hlock->acquire_ip
> field with "%p" for printing hlock->instance field.
> 
> [  251.305475] 3 locks held by a.out/31106:
> [  251.308949]  #0: 00000000b0f753ba (&mm->mmap_sem){++++}, at: copy_process.part.41+0x10d5/0x1fe0
> [  251.314283]  #1: 00000000ef64d539 (&mm->mmap_sem/1){+.+.}, at: copy_process.part.41+0x10fe/0x1fe0
> [  251.319618]  #2: 00000000b41a282e (&mapping->i_mmap_rwsem){++++}, at: copy_process.part.41+0x12f2/0x1fe0
> 
> Signed-off-by: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
> Acked-by: Michal Hocko <mhocko@suse.com>
> Acked-by: David Rientjes <rientjes@google.com>

Acked-by: Peter Zijlstra (Intel) <peterz@infradead.org>

Ingo, can you merge this?

> Cc: Ingo Molnar <mingo@redhat.com>
> Cc: Borislav Petkov <bp@suse.de>
> Cc: Thomas Gleixner <tglx@linutronix.de>
> ---
>  kernel/locking/lockdep.c | 4 ++--
>  1 file changed, 2 insertions(+), 2 deletions(-)
> 
> diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
> index 12a2805..0233863 100644
> --- a/kernel/locking/lockdep.c
> +++ b/kernel/locking/lockdep.c
> @@ -556,9 +556,9 @@ static void print_lock(struct held_lock *hlock)
>  		return;
>  	}
>  
> +	printk(KERN_CONT "%p", hlock->instance);
>  	print_lock_name(lock_classes + class_idx - 1);
> -	printk(KERN_CONT ", at: [<%px>] %pS\n",
> -		(void *)hlock->acquire_ip, (void *)hlock->acquire_ip);
> +	printk(KERN_CONT ", at: %pS\n", (void *)hlock->acquire_ip);
>  }
>  
>  static void lockdep_print_held_locks(struct task_struct *curr)
> -- 
> 1.8.3.1
> 

[tip:locking/core] lockdep: Make the lock debug output more useful

[tip-bot for Tetsuo Handa]

Commit-ID:  b3c39758c8a6972f02b43f83dba7fe7a352371b9
Gitweb:     https://git.kernel.org/tip/b3c39758c8a6972f02b43f83dba7fe7a352371b9
Author:     Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
AuthorDate: Tue, 27 Mar 2018 19:41:41 +0900
Committer:  Thomas Gleixner <tglx@linutronix.de>
CommitDate: Thu, 29 Mar 2018 14:41:40 +0200

lockdep: Make the lock debug output more useful

The lock debug output in print_lock() has a few shortcomings:

 - It prints the hlock->acquire_ip field in %px and %pS format. That's
   redundant information.

 - It lacks information about the lock object itself. The lock class is
   not helpful to identify a particular instance of a lock.

Change the output so it prints:

 - hlock->instance to allow identification of a particular lock instance.

 - only the %pS format of hlock->ip_acquire which is sufficient to decode
   the actual code line with faddr2line.

The resulting output is:

3 locks held by a.out/31106:
#0: 00000000b0f753ba (&mm->mmap_sem){++++}, at: copy_process.part.41+0x10d5/0x1fe0
#1: 00000000ef64d539 (&mm->mmap_sem/1){+.+.}, at: copy_process.part.41+0x10fe/0x1fe0
#2: 00000000b41a282e (&mapping->i_mmap_rwsem){++++}, at: copy_process.part.41+0x12f2/0x1fe0

[ tglx: Massaged changelog ]

Signed-off-by: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Acked-by: Michal Hocko <mhocko@suse.com>
Acked-by: David Rientjes <rientjes@google.com>
Acked-by: Peter Zijlstra <peterz@infradead.org>
Cc: linux-mm@kvack.org
Cc: Borislav Petkov <bp@suse.de>
Link: https://lkml.kernel.org/r/201803271941.GBE57310.tVSOJLQOFFOHFM@I-love.SAKURA.ne.jp

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

diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
index 12a2805dd64a..023386338269 100644
--- a/kernel/locking/lockdep.c
+++ b/kernel/locking/lockdep.c
@@ -556,9 +556,9 @@ static void print_lock(struct held_lock *hlock)
 		return;
 	}
 
+	printk(KERN_CONT "%p", hlock->instance);
 	print_lock_name(lock_classes + class_idx - 1);
-	printk(KERN_CONT ", at: [<%px>] %pS\n",
-		(void *)hlock->acquire_ip, (void *)hlock->acquire_ip);
+	printk(KERN_CONT ", at: %pS\n", (void *)hlock->acquire_ip);
 }
 
 static void lockdep_print_held_locks(struct task_struct *curr)