All of lore.kernel.org
 help / color / mirror / Atom feed
* [PATCH] lockdep: Show address of "struct lockdep_map" at print_lock().
@ 2018-03-26 10:18 Tetsuo Handa
  2018-03-26 13:19 ` Michal Hocko
  2018-03-26 16:05 ` Peter Zijlstra
  0 siblings, 2 replies; 11+ messages in thread
From: Tetsuo Handa @ 2018-03-26 10:18 UTC (permalink / raw)
  To: peterz, mingo
  Cc: linux-kernel, linux-mm, Tetsuo Handa, Borislav Petkov,
	David Rientjes, Michal Hocko, Thomas Gleixner

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

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [PATCH] lockdep: Show address of "struct lockdep_map" at print_lock().
  2018-03-26 10:18 [PATCH] lockdep: Show address of "struct lockdep_map" at print_lock() Tetsuo Handa
@ 2018-03-26 13:19 ` Michal Hocko
  2018-03-26 13:20   ` Michal Hocko
  2018-03-26 16:05 ` Peter Zijlstra
  1 sibling, 1 reply; 11+ messages in thread
From: Michal Hocko @ 2018-03-26 13:19 UTC (permalink / raw)
  To: Tetsuo Handa
  Cc: peterz, mingo, linux-kernel, linux-mm, Borislav Petkov,
	David Rientjes, Thomas Gleixner

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

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [PATCH] lockdep: Show address of "struct lockdep_map" at print_lock().
  2018-03-26 13:19 ` Michal Hocko
@ 2018-03-26 13:20   ` Michal Hocko
  0 siblings, 0 replies; 11+ messages in thread
From: Michal Hocko @ 2018-03-26 13:20 UTC (permalink / raw)
  To: Tetsuo Handa
  Cc: peterz, mingo, linux-kernel, linux-mm, Borislav Petkov,
	David Rientjes, Thomas Gleixner

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

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [PATCH] lockdep: Show address of "struct lockdep_map" at print_lock().
  2018-03-26 10:18 [PATCH] lockdep: Show address of "struct lockdep_map" at print_lock() Tetsuo Handa
  2018-03-26 13:19 ` Michal Hocko
@ 2018-03-26 16:05 ` Peter Zijlstra
  2018-03-26 20:58   ` Tetsuo Handa
  1 sibling, 1 reply; 11+ messages in thread
From: Peter Zijlstra @ 2018-03-26 16:05 UTC (permalink / raw)
  To: Tetsuo Handa
  Cc: mingo, linux-kernel, linux-mm, Borislav Petkov, David Rientjes,
	Michal Hocko, Thomas Gleixner

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.

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [PATCH] lockdep: Show address of "struct lockdep_map" at print_lock().
  2018-03-26 16:05 ` Peter Zijlstra
@ 2018-03-26 20:58   ` Tetsuo Handa
  2018-03-27 10:41     ` [PATCH v2] " Tetsuo Handa
  0 siblings, 1 reply; 11+ messages in thread
From: Tetsuo Handa @ 2018-03-26 20:58 UTC (permalink / raw)
  To: peterz; +Cc: mingo, linux-kernel, linux-mm, bp, rientjes, mhocko, tglx

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.

^ permalink raw reply	[flat|nested] 11+ messages in thread

* [PATCH v2] lockdep: Show address of "struct lockdep_map" at print_lock().
  2018-03-26 20:58   ` Tetsuo Handa
@ 2018-03-27 10:41     ` Tetsuo Handa
  2018-03-27 10:50       ` Michal Hocko
                         ` (3 more replies)
  0 siblings, 4 replies; 11+ messages in thread
From: Tetsuo Handa @ 2018-03-27 10:41 UTC (permalink / raw)
  To: peterz, mhocko; +Cc: mingo, linux-kernel, linux-mm, bp, rientjes, tglx

>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

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [PATCH v2] lockdep: Show address of "struct lockdep_map" at print_lock().
  2018-03-27 10:41     ` [PATCH v2] " Tetsuo Handa
@ 2018-03-27 10:50       ` Michal Hocko
  2018-03-27 20:23       ` David Rientjes
                         ` (2 subsequent siblings)
  3 siblings, 0 replies; 11+ messages in thread
From: Michal Hocko @ 2018-03-27 10:50 UTC (permalink / raw)
  To: Tetsuo Handa; +Cc: peterz, mingo, linux-kernel, linux-mm, bp, rientjes, tglx

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

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [PATCH v2] lockdep: Show address of "struct lockdep_map" at print_lock().
  2018-03-27 10:41     ` [PATCH v2] " Tetsuo Handa
  2018-03-27 10:50       ` Michal Hocko
@ 2018-03-27 20:23       ` David Rientjes
  2018-03-29 10:26       ` Tetsuo Handa
  2018-03-29 12:45       ` [tip:locking/core] lockdep: Make the lock debug output more useful tip-bot for Tetsuo Handa
  3 siblings, 0 replies; 11+ messages in thread
From: David Rientjes @ 2018-03-27 20:23 UTC (permalink / raw)
  To: Tetsuo Handa; +Cc: peterz, mhocko, mingo, linux-kernel, linux-mm, bp, tglx

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>

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [PATCH v2] lockdep: Show address of "struct lockdep_map" at print_lock().
  2018-03-27 10:41     ` [PATCH v2] " Tetsuo Handa
  2018-03-27 10:50       ` Michal Hocko
  2018-03-27 20:23       ` David Rientjes
@ 2018-03-29 10:26       ` Tetsuo Handa
  2018-03-29 12:01         ` Peter Zijlstra
  2018-03-29 12:45       ` [tip:locking/core] lockdep: Make the lock debug output more useful tip-bot for Tetsuo Handa
  3 siblings, 1 reply; 11+ messages in thread
From: Tetsuo Handa @ 2018-03-29 10:26 UTC (permalink / raw)
  To: akpm; +Cc: peterz, mhocko, mingo, linux-kernel, linux-mm, bp, rientjes, tglx

>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

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: [PATCH v2] lockdep: Show address of "struct lockdep_map" at print_lock().
  2018-03-29 10:26       ` Tetsuo Handa
@ 2018-03-29 12:01         ` Peter Zijlstra
  0 siblings, 0 replies; 11+ messages in thread
From: Peter Zijlstra @ 2018-03-29 12:01 UTC (permalink / raw)
  To: Tetsuo Handa
  Cc: akpm, mhocko, mingo, linux-kernel, linux-mm, bp, rientjes, tglx

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
> 

^ permalink raw reply	[flat|nested] 11+ messages in thread

* [tip:locking/core] lockdep: Make the lock debug output more useful
  2018-03-27 10:41     ` [PATCH v2] " Tetsuo Handa
                         ` (2 preceding siblings ...)
  2018-03-29 10:26       ` Tetsuo Handa
@ 2018-03-29 12:45       ` tip-bot for Tetsuo Handa
  3 siblings, 0 replies; 11+ messages in thread
From: tip-bot for Tetsuo Handa @ 2018-03-29 12:45 UTC (permalink / raw)
  To: linux-tip-commits
  Cc: linux-kernel, peterz, rientjes, penguin-kernel, bp, mingo, hpa,
	mhocko, tglx

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)

^ permalink raw reply	[flat|nested] 11+ messages in thread

end of thread, other threads:[~2018-03-29 12:46 UTC | newest]

Thread overview: 11+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2018-03-26 10:18 [PATCH] lockdep: Show address of "struct lockdep_map" at print_lock() Tetsuo Handa
2018-03-26 13:19 ` Michal Hocko
2018-03-26 13:20   ` Michal Hocko
2018-03-26 16:05 ` Peter Zijlstra
2018-03-26 20:58   ` Tetsuo Handa
2018-03-27 10:41     ` [PATCH v2] " Tetsuo Handa
2018-03-27 10:50       ` Michal Hocko
2018-03-27 20:23       ` David Rientjes
2018-03-29 10:26       ` Tetsuo Handa
2018-03-29 12:01         ` Peter Zijlstra
2018-03-29 12:45       ` [tip:locking/core] lockdep: Make the lock debug output more useful tip-bot for Tetsuo Handa

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.