[PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Hitoshi Mitake]

Hi,

I wrote a test patch which add information of counts processes acquired how many spinlocks to schedstat.
After applied this patch, /proc/<PID>/sched will change like this,

init (1, #threads: 1)
---------------------------------------------------------
se.exec_start                      :        482130.851458
se.vruntime                        :         26883.107980
se.sum_exec_runtime                :          2316.651816
se.avg_overlap                     :             0.480053
se.avg_wakeup                      :            14.999993
....
se.nr_wakeups_passive              :                    1
se.nr_wakeups_idle                 :                    0
se.nr_acquired_spinlock            :                74483
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
avg_atom                           :             2.181404
avg_per_cpu                        :           772.217272
nr_switches                        :                 1062
...

The line underlined with ^^^ is new one.
This means init process acquired spinlock 74483 times.
Today, spinlock is an importatnt factor for scalability.
This information must be useful for people working on multicore.

If you think this is useful, I would like to add more information related to spinlocks,
like average waiting time(or cycle count), max waiting time, etc...

But this patch has a point to consider, the line
        current->se.nr_acquired_spinlock++;
This breaks convention that incrementing member of sched_entity related to SCHEDSTAT
with schedstat_inc.
I couldn't write the point with schedstat_inc because of the structure of sched_stats.h.

How do you think about this?

Signed-off-by: Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp>

diff --git a/include/linux/sched.h b/include/linux/sched.h
index 0085d75..f63b11f 100644
--- a/include/linux/sched.h
+++ b/include/linux/sched.h
@@ -1127,6 +1127,8 @@ struct sched_entity {
 	u64			nr_wakeups_affine_attempts;
 	u64			nr_wakeups_passive;
 	u64			nr_wakeups_idle;
+
+	u64			nr_acquired_spinlock;
 #endif
 
 #ifdef CONFIG_FAIR_GROUP_SCHED
diff --git a/kernel/sched_debug.c b/kernel/sched_debug.c
index 70c7e0b..792b0f7 100644
--- a/kernel/sched_debug.c
+++ b/kernel/sched_debug.c
@@ -426,6 +426,7 @@ void proc_sched_show_task(struct task_struct *p, struct seq_file *m)
 	P(se.nr_wakeups_affine_attempts);
 	P(se.nr_wakeups_passive);
 	P(se.nr_wakeups_idle);
+	P(se.nr_acquired_spinlock);
 
 	{
 		u64 avg_atom, avg_per_cpu;
@@ -500,6 +501,7 @@ void proc_sched_set_task(struct task_struct *p)
 	p->se.nr_wakeups_affine_attempts	= 0;
 	p->se.nr_wakeups_passive		= 0;
 	p->se.nr_wakeups_idle			= 0;
+	p->se.nr_acquired_spinlock		= 0;
 	p->sched_info.bkl_count			= 0;
 #endif
 	p->se.sum_exec_runtime			= 0;
diff --git a/kernel/spinlock.c b/kernel/spinlock.c
index 7932653..92c1ed6 100644
--- a/kernel/spinlock.c
+++ b/kernel/spinlock.c
@@ -181,6 +181,10 @@ void __lockfunc _spin_lock(spinlock_t *lock)
 	preempt_disable();
 	spin_acquire(&lock->dep_map, 0, 0, _RET_IP_);
 	LOCK_CONTENDED(lock, _raw_spin_trylock, _raw_spin_lock);
+
+#ifdef CONFIG_SCHEDSTATS
+	current->se.nr_acquired_spinlock++;
+#endif
 }
 
 EXPORT_SYMBOL(_spin_lock);

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Ingo Molnar]

* Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> wrote:

> Hi,
> 
> I wrote a test patch which add information of counts processes 
> acquired how many spinlocks to schedstat. After applied this 
> patch, /proc/<PID>/sched will change like this,
> 
> init (1, #threads: 1)
> ---------------------------------------------------------
> se.exec_start                      :        482130.851458
> se.vruntime                        :         26883.107980
> se.sum_exec_runtime                :          2316.651816
> se.avg_overlap                     :             0.480053
> se.avg_wakeup                      :            14.999993
> ....
> se.nr_wakeups_passive              :                    1
> se.nr_wakeups_idle                 :                    0
> se.nr_acquired_spinlock            :                74483
> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

Looks potentially useful - but it would be nice and go one step 
further and add lock acquire stats as a software-counter.

Perfcounters is a feature of the latest upstream kernel, there's a 
(still very small) Wiki page about it at:

   http://perf.wiki.kernel.org

With perfcounters we can instrument various software properties of 
the kernel as well, for example the number of page-faults in the 
system per second:

  $ perf stat -a -e page-faults sleep 1

  Performance counter stats for 'sleep 1':

          294387  page-faults             

     1.022318527  seconds time elapsed

Now, it would be nice to have a lock-acquire software-counter as 
well, which would output things like:

  $ perf stat -a -e lock-acquires sleep 1

  Performance counter stats for 'sleep 1':

          294387  lock-acquires

     1.022318527  seconds time elapsed

Furthermore, beyond plain counts, doing this would also allow the 
profiling of lock acquire places: perf record -e lock-acquires and 
perf report would work fine.

It is really easy to add a new sw counter, check how it is done for 
the pagefault counter(s), see the uses of PERF_COUNT_SW_PAGE_FAULTS 
in the following files:

  $ git grep -l PERF_COUNT_SW_PAGE_FAULTS

  arch/powerpc/mm/fault.c
  arch/x86/mm/fault.c
  include/linux/perf_counter.h
  kernel/perf_counter.c
  tools/perf/builtin-stat.c
  tools/perf/design.txt

Would you be interested in having a look at this?

	Ingo

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Hitoshi Mitake]

From: Ingo Molnar <mingo@elte.hu>
Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
Date: Wed, 1 Jul 2009 09:31:39 +0200

> 
> * Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> wrote:
> 
> > Hi,
> > 
> > I wrote a test patch which add information of counts processes 
> > acquired how many spinlocks to schedstat. After applied this 
> > patch, /proc/<PID>/sched will change like this,
> > 
> > init (1, #threads: 1)
> > ---------------------------------------------------------
> > se.exec_start                      :        482130.851458
> > se.vruntime                        :         26883.107980
> > se.sum_exec_runtime                :          2316.651816
> > se.avg_overlap                     :             0.480053
> > se.avg_wakeup                      :            14.999993
> > ....
> > se.nr_wakeups_passive              :                    1
> > se.nr_wakeups_idle                 :                    0
> > se.nr_acquired_spinlock            :                74483
> > ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
> 
> Looks potentially useful - but it would be nice and go one step 
> further and add lock acquire stats as a software-counter.
> 
> Perfcounters is a feature of the latest upstream kernel, there's a 
> (still very small) Wiki page about it at:
> 
>    http://perf.wiki.kernel.org
> 

Thanks for your information.
I've never heard about this. This is a useful software for me.

> Now, it would be nice to have a lock-acquire software-counter as 
> well, which would output things like:
> 
>   $ perf stat -a -e lock-acquires sleep 1
> 
>   Performance counter stats for 'sleep 1':
> 
>           294387  lock-acquires
> 
>      1.022318527  seconds time elapsed
> 
> Furthermore, beyond plain counts, doing this would also allow the 
> profiling of lock acquire places: perf record -e lock-acquires and 
> perf report would work fine.
> 
> It is really easy to add a new sw counter, check how it is done for 
> the pagefault counter(s), see the uses of PERF_COUNT_SW_PAGE_FAULTS 
> in the following files:
> 
>   $ git grep -l PERF_COUNT_SW_PAGE_FAULTS
> 
>   arch/powerpc/mm/fault.c
>   arch/x86/mm/fault.c
>   include/linux/perf_counter.h
>   kernel/perf_counter.c
>   tools/perf/builtin-stat.c
>   tools/perf/design.txt
> 
> Would you be interested in having a look at this?

Of course, I want to do this!
If I got progress, I'll send a patch to you.

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Frederic Weisbecker]

On Wed, Jul 01, 2009 at 09:31:39AM +0200, Ingo Molnar wrote:
> 
> * Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> wrote:
> 
> > Hi,
> > 
> > I wrote a test patch which add information of counts processes 
> > acquired how many spinlocks to schedstat. After applied this 
> > patch, /proc/<PID>/sched will change like this,
> > 
> > init (1, #threads: 1)
> > ---------------------------------------------------------
> > se.exec_start                      :        482130.851458
> > se.vruntime                        :         26883.107980
> > se.sum_exec_runtime                :          2316.651816
> > se.avg_overlap                     :             0.480053
> > se.avg_wakeup                      :            14.999993
> > ....
> > se.nr_wakeups_passive              :                    1
> > se.nr_wakeups_idle                 :                    0
> > se.nr_acquired_spinlock            :                74483
> > ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
> 
> Looks potentially useful - but it would be nice and go one step 
> further and add lock acquire stats as a software-counter.
> 
> Perfcounters is a feature of the latest upstream kernel, there's a 
> (still very small) Wiki page about it at:
> 
>    http://perf.wiki.kernel.org
> 
> With perfcounters we can instrument various software properties of 
> the kernel as well, for example the number of page-faults in the 
> system per second:
> 
>   $ perf stat -a -e page-faults sleep 1
> 
>   Performance counter stats for 'sleep 1':
> 
>           294387  page-faults             
> 
>      1.022318527  seconds time elapsed
> 
> Now, it would be nice to have a lock-acquire software-counter as 
> well, which would output things like:
> 
>   $ perf stat -a -e lock-acquires sleep 1
> 
>   Performance counter stats for 'sleep 1':
> 
>           294387  lock-acquires
> 
>      1.022318527  seconds time elapsed
> 
> Furthermore, beyond plain counts, doing this would also allow the 
> profiling of lock acquire places: perf record -e lock-acquires and 
> perf report would work fine.
> 
> It is really easy to add a new sw counter, check how it is done for 
> the pagefault counter(s), see the uses of PERF_COUNT_SW_PAGE_FAULTS 
> in the following files:
> 
>   $ git grep -l PERF_COUNT_SW_PAGE_FAULTS
> 
>   arch/powerpc/mm/fault.c
>   arch/x86/mm/fault.c
>   include/linux/perf_counter.h
>   kernel/perf_counter.c
>   tools/perf/builtin-stat.c
>   tools/perf/design.txt


Indeed, the raw number of lock acquired may be useful for a perf profiling
especially in the case of profile comparison.

But IMHO, this information is too much orphan and lonesome.
We would gain a lot if this information is provided per lock. Another
useful info would be the rate of the time spent in a contended state
for a given lock.

Which makes me think it may be better to use the existing ftrace lock
events as softwares counters for that, which takes into account the
following events:

- lock_acquire
- lock_release
- lock_contended
- lock_acquired

And these events are per lock.

Now the missing piece is the sampling count for events...

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Ingo Molnar]

* Frederic Weisbecker <fweisbec@gmail.com> wrote:

> On Wed, Jul 01, 2009 at 09:31:39AM +0200, Ingo Molnar wrote:
> > 
> > * Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> wrote:
> > 
> > > Hi,
> > > 
> > > I wrote a test patch which add information of counts processes 
> > > acquired how many spinlocks to schedstat. After applied this 
> > > patch, /proc/<PID>/sched will change like this,
> > > 
> > > init (1, #threads: 1)
> > > ---------------------------------------------------------
> > > se.exec_start                      :        482130.851458
> > > se.vruntime                        :         26883.107980
> > > se.sum_exec_runtime                :          2316.651816
> > > se.avg_overlap                     :             0.480053
> > > se.avg_wakeup                      :            14.999993
> > > ....
> > > se.nr_wakeups_passive              :                    1
> > > se.nr_wakeups_idle                 :                    0
> > > se.nr_acquired_spinlock            :                74483
> > > ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
> > 
> > Looks potentially useful - but it would be nice and go one step 
> > further and add lock acquire stats as a software-counter.
> > 
> > Perfcounters is a feature of the latest upstream kernel, there's a 
> > (still very small) Wiki page about it at:
> > 
> >    http://perf.wiki.kernel.org
> > 
> > With perfcounters we can instrument various software properties of 
> > the kernel as well, for example the number of page-faults in the 
> > system per second:
> > 
> >   $ perf stat -a -e page-faults sleep 1
> > 
> >   Performance counter stats for 'sleep 1':
> > 
> >           294387  page-faults             
> > 
> >      1.022318527  seconds time elapsed
> > 
> > Now, it would be nice to have a lock-acquire software-counter as 
> > well, which would output things like:
> > 
> >   $ perf stat -a -e lock-acquires sleep 1
> > 
> >   Performance counter stats for 'sleep 1':
> > 
> >           294387  lock-acquires
> > 
> >      1.022318527  seconds time elapsed
> > 
> > Furthermore, beyond plain counts, doing this would also allow the 
> > profiling of lock acquire places: perf record -e lock-acquires and 
> > perf report would work fine.
> > 
> > It is really easy to add a new sw counter, check how it is done for 
> > the pagefault counter(s), see the uses of PERF_COUNT_SW_PAGE_FAULTS 
> > in the following files:
> > 
> >   $ git grep -l PERF_COUNT_SW_PAGE_FAULTS
> > 
> >   arch/powerpc/mm/fault.c
> >   arch/x86/mm/fault.c
> >   include/linux/perf_counter.h
> >   kernel/perf_counter.c
> >   tools/perf/builtin-stat.c
> >   tools/perf/design.txt
> 
> 
> Indeed, the raw number of lock acquired may be useful for a perf 
> profiling especially in the case of profile comparison.
> 
> But IMHO, this information is too much orphan and lonesome. We 
> would gain a lot if this information is provided per lock. Another 
> useful info would be the rate of the time spent in a contended 
> state for a given lock.
> 
> Which makes me think it may be better to use the existing ftrace 
> lock events as softwares counters for that, which takes into 
> account the following events:
> 
> - lock_acquire
> - lock_release
> - lock_contended
> - lock_acquired
> 
> And these events are per lock.
> 
> Now the missing piece is the sampling count for events...

Yeah, this is an even better idea. It gets the acquire counts - and 
much more.

	Ingo

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[mitake]

From: Ingo Molnar <mingo@elte.hu>
Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
Date: Wed, 1 Jul 2009 15:50:32 +0200

>  
> > Which makes me think it may be better to use the existing ftrace 
> > lock events as softwares counters for that, which takes into 
> > account the following events:
> > 
> > - lock_acquire
> > - lock_release
> > - lock_contended
> > - lock_acquired
> > 
> > And these events are per lock.
> > 
> > Now the missing piece is the sampling count for events...
> 
> Yeah, this is an even better idea. It gets the acquire counts - and 
> much more.
> 

Is there another way to implement more easily?
Fortunately or unfortunately, I didn't start implementing
because my x86_64 box died suddenly :-(
So I'll need a few days to fix, sorry...

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Andi Kleen]

Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> writes:

> Hi,
>
> I wrote a test patch which add information of counts processes acquired how many spinlocks to schedstat.
> After applied this patch, /proc/<PID>/sched will change like this,

The problem is that spinlocks are very common and schedstats is enabled commonly
in production kernels. You would need to demonstrate that such a change doesn't
have significant performance impact. For me it looks like it has.

Also I'm not sure exactly what good such a metric is. Do you have 
a concrete use case?

The normal way to check for lock contention or lock bouncingis to
simply profile cycles or time and see if there is a lot of CPU time in
locks.

-Andi

-- 
ak@linux.intel.com -- Speaking for myself only.

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Hitoshi Mitake]

From: Andi Kleen <andi@firstfloor.org>
Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
Date: Wed, 01 Jul 2009 09:38:04 +0200

> Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> writes:
> 
> > Hi,
> >
> > I wrote a test patch which add information of counts processes acquired how many spinlocks to schedstat.
> > After applied this patch, /proc/<PID>/sched will change like this,
> 
> The problem is that spinlocks are very common and schedstats is enabled commonly
> in production kernels. You would need to demonstrate that such a change doesn't
> have significant performance impact. For me it looks like it has.

I agree with your opinion about performance impact.
I thought this will make no problem,
because schedstat is categorized as "Kernel hacking" section.
But according to you, many production kernels enable it
so my patch will make widespread performance degradation.
I didn't know that, sorry.

> 
> Also I'm not sure exactly what good such a metric is. Do you have 
> a concrete use case?
> 

I want to know about behavior of Apache.
Because Apache uses sendfile() system call,
and according to this paper, sendfile() acquires many spinlocks

http://www.usenix.org/events/vm04/tech/uhlig.html

And spinlocks may cause terrible performance problem when Linux is running on VM.

> The normal way to check for lock contention or lock bouncingis to
> simply profile cycles or time and see if there is a lot of CPU time in
> locks.

According to Ingo's advice, I'll try to add lock counter to perfcounter.

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Ingo Molnar]

* Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> wrote:

> From: Andi Kleen <andi@firstfloor.org>
> Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> Date: Wed, 01 Jul 2009 09:38:04 +0200
> 
> > Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> writes:
> > 
> > > Hi,
> > >
> > > I wrote a test patch which add information of counts processes acquired how many spinlocks to schedstat.
> > > After applied this patch, /proc/<PID>/sched will change like this,
> > 
> > The problem is that spinlocks are very common and schedstats is 
> > enabled commonly in production kernels. You would need to 
> > demonstrate that such a change doesn't have significant 
> > performance impact. For me it looks like it has.
> 
> I agree with your opinion about performance impact.
> I thought this will make no problem,
> because schedstat is categorized as "Kernel hacking" section.
> But according to you, many production kernels enable it
> so my patch will make widespread performance degradation.
> I didn't know that, sorry.

His arguments are bogus: both lockstat and perfcounters are optional 
(and default off), and the sw counter can be made near zero cost 
even if both perfcounters and lockstat is enabled. Also, sw counters 
are generally per CPU, etc. so not a performance issue.

The only (small) overhead will be when the lock-acquire sw counter 
is actively enabled because you run 'perf stat -e lock-acquire' - 
but that is expected and inherent in pretty much any kind of 
instrumentation.

The feature you are working on has the chance to be a very useful 
and popular piece of instrumentation. Being able to tell the lock 
acquire stats on a per task, per workload, per CPU or system-wide 
basis is a unique capability no other tool can offer right now.

Andi is often trolling perfcounters related (and other) threads, 
please dont let yourself be deterred by that and feel free to ignore 
him.

	Ingo

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Hitoshi Mitake]

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #1: Type: Text/Plain; charset=utf-8, Size: 3002 bytes --]

From: Ingo Molnar <mingo@elte.hu>
Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
Date: Wed, 1 Jul 2009 11:07:49 +0200

> 
> * Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> wrote:
> 
> > From: Andi Kleen <andi@firstfloor.org>
> > Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> > Date: Wed, 01 Jul 2009 09:38:04 +0200
> > 
> > > Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> writes:
> > > 
> > > > Hi,
> > > >
> > > > I wrote a test patch which add information of counts processes acquired how many spinlocks to schedstat.
> > > > After applied this patch, /proc/<PID>/sched will change like this,
> > > 
> > > The problem is that spinlocks are very common and schedstats is 
> > > enabled commonly in production kernels. You would need to 
> > > demonstrate that such a change doesn't have significant 
> > > performance impact. For me it looks like it has.
> > 
> > I agree with your opinion about performance impact.
> > I thought this will make no problem,
> > because schedstat is categorized as "Kernel hacking" section.
> > But according to you, many production kernels enable it
> > so my patch will make widespread performance degradation.
> > I didn't know that, sorry.
> 
> His arguments are bogus: both lockstat and perfcounters are optional 
> (and default off), and the sw counter can be made near zero cost 
> even if both perfcounters and lockstat is enabled. Also, sw counters 
> are generally per CPU, etc. so not a performance issue.
> 
> The only (small) overhead will be when the lock-acquire sw counter 
> is actively enabled because you run 'perf stat -e lock-acquire' - 
> but that is expected and inherent in pretty much any kind of 
> instrumentation.
> 
> The feature you are working on has the chance to be a very useful 
> and popular piece of instrumentation. Being able to tell the lock 
> acquire stats on a per task, per workload, per CPU or system-wide 
> basis is a unique capability no other tool can offer right now.
> 
> Andi is often trolling perfcounters related (and other) threads, 
> please dont let yourself be deterred by that and feel free to ignore 
> him.
OK, at least it is truth that
counter in perfcounters makes only valid overhead.

And I have a question,
I tried to build perf, but I got a build error,

util/symbol.c: In function ‘dso__load_sym’:
util/symbol.c:466: error: ‘ELF_C_READ_MMAP’ undeclared (first use in this function)
util/symbol.c:466: error: (Each undeclared identifier is reported only once
util/symbol.c:466: error: for each function it appears in.)

I used this libelf,
http://www.mr511.de/software/english.html
but constant ELF_C_READ_MMAP is not provided...

which "libelf" should I use?
It seems that there are some libelf implementations.
ÿôèº{.nÇ+‰·Ÿ®‰­†+%ŠËÿ±éݶ\x17¥Šwÿº{.nÇ+‰·¥Š{±þG«éÿŠ{ayº\x1dʇڙë,j\a­¢f£¢·hšïêÿ‘êçz_è®\x03(­éšŽŠÝ¢j"ú\x1a¶^[m§ÿÿ¾\a«þG«éÿ¢¸?™¨è­Ú&£ø§~á¶iO•æ¬z·švØ^\x14\x04\x1a¶^[m§ÿÿÃ\fÿ¶ìÿ¢¸?–I¥

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Ingo Molnar]

* Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> wrote:

> From: Ingo Molnar <mingo@elte.hu>
> Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> Date: Wed, 1 Jul 2009 11:07:49 +0200
> 
> > 
> > * Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> wrote:
> > 
> > > From: Andi Kleen <andi@firstfloor.org>
> > > Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> > > Date: Wed, 01 Jul 2009 09:38:04 +0200
> > > 
> > > > Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> writes:
> > > > 
> > > > > Hi,
> > > > >
> > > > > I wrote a test patch which add information of counts processes acquired how many spinlocks to schedstat.
> > > > > After applied this patch, /proc/<PID>/sched will change like this,
> > > > 
> > > > The problem is that spinlocks are very common and schedstats is 
> > > > enabled commonly in production kernels. You would need to 
> > > > demonstrate that such a change doesn't have significant 
> > > > performance impact. For me it looks like it has.
> > > 
> > > I agree with your opinion about performance impact.
> > > I thought this will make no problem,
> > > because schedstat is categorized as "Kernel hacking" section.
> > > But according to you, many production kernels enable it
> > > so my patch will make widespread performance degradation.
> > > I didn't know that, sorry.
> > 
> > His arguments are bogus: both lockstat and perfcounters are optional 
> > (and default off), and the sw counter can be made near zero cost 
> > even if both perfcounters and lockstat is enabled. Also, sw counters 
> > are generally per CPU, etc. so not a performance issue.
> > 
> > The only (small) overhead will be when the lock-acquire sw counter 
> > is actively enabled because you run 'perf stat -e lock-acquire' - 
> > but that is expected and inherent in pretty much any kind of 
> > instrumentation.
> > 
> > The feature you are working on has the chance to be a very useful 
> > and popular piece of instrumentation. Being able to tell the lock 
> > acquire stats on a per task, per workload, per CPU or system-wide 
> > basis is a unique capability no other tool can offer right now.
> > 
> > Andi is often trolling perfcounters related (and other) threads, 
> > please dont let yourself be deterred by that and feel free to ignore 
> > him.
> OK, at least it is truth that
> counter in perfcounters makes only valid overhead.
> 
> And I have a question,
> I tried to build perf, but I got a build error,
> 
> util/symbol.c: In function ‘dso__load_sym’:
> util/symbol.c:466: error: ‘ELF_C_READ_MMAP’ undeclared (first use in this function)
> util/symbol.c:466: error: (Each undeclared identifier is reported only once
> util/symbol.c:466: error: for each function it appears in.)
> 
> I used this libelf,
> http://www.mr511.de/software/english.html
> but constant ELF_C_READ_MMAP is not provided...
> 
> which "libelf" should I use?
> It seems that there are some libelf implementations.

I use the elfutils-libelf* packages:

 elfutils-libelf-devel-static-0.141-1.fc10.i386
 elfutils-0.141-1.fc10.i386
 elfutils-libelf-0.141-1.fc10.i386
 elfutils-libs-0.141-1.fc10.i386
 elfutils-libelf-devel-0.141-1.fc10.i386

do they work fine or you?

	Ingo

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Hitoshi Mitake]

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #1: Type: Text/Plain; charset=utf-8, Size: 3939 bytes --]

From: Ingo Molnar <mingo@elte.hu>
Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
Date: Wed, 1 Jul 2009 13:06:20 +0200

> 
> * Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> wrote:
> 
> > From: Ingo Molnar <mingo@elte.hu>
> > Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> > Date: Wed, 1 Jul 2009 11:07:49 +0200
> > 
> > > 
> > > * Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> wrote:
> > > 
> > > > From: Andi Kleen <andi@firstfloor.org>
> > > > Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> > > > Date: Wed, 01 Jul 2009 09:38:04 +0200
> > > > 
> > > > > Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> writes:
> > > > > 
> > > > > > Hi,
> > > > > >
> > > > > > I wrote a test patch which add information of counts processes acquired how many spinlocks to schedstat.
> > > > > > After applied this patch, /proc/<PID>/sched will change like this,
> > > > > 
> > > > > The problem is that spinlocks are very common and schedstats is 
> > > > > enabled commonly in production kernels. You would need to 
> > > > > demonstrate that such a change doesn't have significant 
> > > > > performance impact. For me it looks like it has.
> > > > 
> > > > I agree with your opinion about performance impact.
> > > > I thought this will make no problem,
> > > > because schedstat is categorized as "Kernel hacking" section.
> > > > But according to you, many production kernels enable it
> > > > so my patch will make widespread performance degradation.
> > > > I didn't know that, sorry.
> > > 
> > > His arguments are bogus: both lockstat and perfcounters are optional 
> > > (and default off), and the sw counter can be made near zero cost 
> > > even if both perfcounters and lockstat is enabled. Also, sw counters 
> > > are generally per CPU, etc. so not a performance issue.
> > > 
> > > The only (small) overhead will be when the lock-acquire sw counter 
> > > is actively enabled because you run 'perf stat -e lock-acquire' - 
> > > but that is expected and inherent in pretty much any kind of 
> > > instrumentation.
> > > 
> > > The feature you are working on has the chance to be a very useful 
> > > and popular piece of instrumentation. Being able to tell the lock 
> > > acquire stats on a per task, per workload, per CPU or system-wide 
> > > basis is a unique capability no other tool can offer right now.
> > > 
> > > Andi is often trolling perfcounters related (and other) threads, 
> > > please dont let yourself be deterred by that and feel free to ignore 
> > > him.
> > OK, at least it is truth that
> > counter in perfcounters makes only valid overhead.
> > 
> > And I have a question,
> > I tried to build perf, but I got a build error,
> > 
> > util/symbol.c: In function ‘dso__load_sym’:
> > util/symbol.c:466: error: ‘ELF_C_READ_MMAP’ undeclared (first use in this function)
> > util/symbol.c:466: error: (Each undeclared identifier is reported only once
> > util/symbol.c:466: error: for each function it appears in.)
> > 
> > I used this libelf,
> > http://www.mr511.de/software/english.html
> > but constant ELF_C_READ_MMAP is not provided...
> > 
> > which "libelf" should I use?
> > It seems that there are some libelf implementations.
> 
> I use the elfutils-libelf* packages:
> 
>  elfutils-libelf-devel-static-0.141-1.fc10.i386
>  elfutils-0.141-1.fc10.i386
>  elfutils-libelf-0.141-1.fc10.i386
>  elfutils-libs-0.141-1.fc10.i386
>  elfutils-libelf-devel-0.141-1.fc10.i386
> 
> do they work fine or you?

I'm a Debian user, so I build this library from source

https://fedorahosted.org/releases/e/l/elfutils/elfutils-0.141.tar.bz2

And I succeed to build perf, thanks!
ÿôèº{.nÇ+‰·Ÿ®‰­†+%ŠËÿ±éݶ\x17¥Šwÿº{.nÇ+‰·¥Š{±þG«éÿŠ{ayº\x1dʇڙë,j\a­¢f£¢·hšïêÿ‘êçz_è®\x03(­éšŽŠÝ¢j"ú\x1a¶^[m§ÿÿ¾\a«þG«éÿ¢¸?™¨è­Ú&£ø§~á¶iO•æ¬z·švØ^\x14\x04\x1a¶^[m§ÿÿÃ\fÿ¶ìÿ¢¸?–I¥

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Frederic Weisbecker]

On Wed, Jul 01, 2009 at 09:53:04PM +0900, Hitoshi Mitake wrote:
> From: Ingo Molnar <mingo@elte.hu>
> Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> Date: Wed, 1 Jul 2009 13:06:20 +0200
> 
> > 
> > * Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> wrote:
> > 
> > > From: Ingo Molnar <mingo@elte.hu>
> > > Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> > > Date: Wed, 1 Jul 2009 11:07:49 +0200
> > > 
> > > > 
> > > > * Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> wrote:
> > > > 
> > > > > From: Andi Kleen <andi@firstfloor.org>
> > > > > Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> > > > > Date: Wed, 01 Jul 2009 09:38:04 +0200
> > > > > 
> > > > > > Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> writes:
> > > > > > 
> > > > > > > Hi,
> > > > > > >
> > > > > > > I wrote a test patch which add information of counts processes acquired how many spinlocks to schedstat.
> > > > > > > After applied this patch, /proc/<PID>/sched will change like this,
> > > > > > 
> > > > > > The problem is that spinlocks are very common and schedstats is 
> > > > > > enabled commonly in production kernels. You would need to 
> > > > > > demonstrate that such a change doesn't have significant 
> > > > > > performance impact. For me it looks like it has.
> > > > > 
> > > > > I agree with your opinion about performance impact.
> > > > > I thought this will make no problem,
> > > > > because schedstat is categorized as "Kernel hacking" section.
> > > > > But according to you, many production kernels enable it
> > > > > so my patch will make widespread performance degradation.
> > > > > I didn't know that, sorry.
> > > > 
> > > > His arguments are bogus: both lockstat and perfcounters are optional 
> > > > (and default off), and the sw counter can be made near zero cost 
> > > > even if both perfcounters and lockstat is enabled. Also, sw counters 
> > > > are generally per CPU, etc. so not a performance issue.
> > > > 
> > > > The only (small) overhead will be when the lock-acquire sw counter 
> > > > is actively enabled because you run 'perf stat -e lock-acquire' - 
> > > > but that is expected and inherent in pretty much any kind of 
> > > > instrumentation.
> > > > 
> > > > The feature you are working on has the chance to be a very useful 
> > > > and popular piece of instrumentation. Being able to tell the lock 
> > > > acquire stats on a per task, per workload, per CPU or system-wide 
> > > > basis is a unique capability no other tool can offer right now.
> > > > 
> > > > Andi is often trolling perfcounters related (and other) threads, 
> > > > please dont let yourself be deterred by that and feel free to ignore 
> > > > him.
> > > OK, at least it is truth that
> > > counter in perfcounters makes only valid overhead.
> > > 
> > > And I have a question,
> > > I tried to build perf, but I got a build error,
> > > 
> > > util/symbol.c: In function ‘dso__load_sym’:
> > > util/symbol.c:466: error: ‘ELF_C_READ_MMAP’ undeclared (first use in this function)
> > > util/symbol.c:466: error: (Each undeclared identifier is reported only once
> > > util/symbol.c:466: error: for each function it appears in.)
> > > 
> > > I used this libelf,
> > > http://www.mr511.de/software/english.html
> > > but constant ELF_C_READ_MMAP is not provided...
> > > 
> > > which "libelf" should I use?
> > > It seems that there are some libelf implementations.
> > 
> > I use the elfutils-libelf* packages:
> > 
> >  elfutils-libelf-devel-static-0.141-1.fc10.i386
> >  elfutils-0.141-1.fc10.i386
> >  elfutils-libelf-0.141-1.fc10.i386
> >  elfutils-libs-0.141-1.fc10.i386
> >  elfutils-libelf-devel-0.141-1.fc10.i386
> > 
> > do they work fine or you?
> 
> I'm a Debian user, so I build this library from source
> 
> https://fedorahosted.org/releases/e/l/elfutils/elfutils-0.141.tar.bz2
> 
> And I succeed to build perf, thanks!


You could also just

apt-get install libelf-dev

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[mitake]

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #1: Type: Text/Plain; charset=utf-8, Size: 7934 bytes --]

From: Frederic Weisbecker <fweisbec@gmail.com>
Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
Date: Wed, 1 Jul 2009 17:44:51 +0200

> On Wed, Jul 01, 2009 at 09:53:04PM +0900, Hitoshi Mitake wrote:
> > From: Ingo Molnar <mingo@elte.hu>
> > Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> > Date: Wed, 1 Jul 2009 13:06:20 +0200
> > 
> > > 
> > > * Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> wrote:
> > > 
> > > > From: Ingo Molnar <mingo@elte.hu>
> > > > Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> > > > Date: Wed, 1 Jul 2009 11:07:49 +0200
> > > > 
> > > > > 
> > > > > * Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> wrote:
> > > > > 
> > > > > > From: Andi Kleen <andi@firstfloor.org>
> > > > > > Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> > > > > > Date: Wed, 01 Jul 2009 09:38:04 +0200
> > > > > > 
> > > > > > > Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> writes:
> > > > > > > 
> > > > > > > > Hi,
> > > > > > > >
> > > > > > > > I wrote a test patch which add information of counts processes acquired how many spinlocks to schedstat.
> > > > > > > > After applied this patch, /proc/<PID>/sched will change like this,
> > > > > > > 
> > > > > > > The problem is that spinlocks are very common and schedstats is 
> > > > > > > enabled commonly in production kernels. You would need to 
> > > > > > > demonstrate that such a change doesn't have significant 
> > > > > > > performance impact. For me it looks like it has.
> > > > > > 
> > > > > > I agree with your opinion about performance impact.
> > > > > > I thought this will make no problem,
> > > > > > because schedstat is categorized as "Kernel hacking" section.
> > > > > > But according to you, many production kernels enable it
> > > > > > so my patch will make widespread performance degradation.
> > > > > > I didn't know that, sorry.
> > > > > 
> > > > > His arguments are bogus: both lockstat and perfcounters are optional 
> > > > > (and default off), and the sw counter can be made near zero cost 
> > > > > even if both perfcounters and lockstat is enabled. Also, sw counters 
> > > > > are generally per CPU, etc. so not a performance issue.
> > > > > 
> > > > > The only (small) overhead will be when the lock-acquire sw counter 
> > > > > is actively enabled because you run 'perf stat -e lock-acquire' - 
> > > > > but that is expected and inherent in pretty much any kind of 
> > > > > instrumentation.
> > > > > 
> > > > > The feature you are working on has the chance to be a very useful 
> > > > > and popular piece of instrumentation. Being able to tell the lock 
> > > > > acquire stats on a per task, per workload, per CPU or system-wide 
> > > > > basis is a unique capability no other tool can offer right now.
> > > > > 
> > > > > Andi is often trolling perfcounters related (and other) threads, 
> > > > > please dont let yourself be deterred by that and feel free to ignore 
> > > > > him.
> > > > OK, at least it is truth that
> > > > counter in perfcounters makes only valid overhead.
> > > > 
> > > > And I have a question,
> > > > I tried to build perf, but I got a build error,
> > > > 
> > > > util/symbol.c: In function ‘dso__load_sym’:
> > > > util/symbol.c:466: error: ‘ELF_C_READ_MMAP’ undeclared (first use in this function)
> > > > util/symbol.c:466: error: (Each undeclared identifier is reported only once
> > > > util/symbol.c:466: error: for each function it appears in.)
> > > > 
> > > > I used this libelf,
> > > > http://www.mr511.de/software/english.html
> > > > but constant ELF_C_READ_MMAP is not provided...
> > > > 
> > > > which "libelf" should I use?
> > > > It seems that there are some libelf implementations.
> > > 
> > > I use the elfutils-libelf* packages:
> > > 
> > >  elfutils-libelf-devel-static-0.141-1.fc10.i386
> > >  elfutils-0.141-1.fc10.i386
> > >  elfutils-libelf-0.141-1.fc10.i386
> > >  elfutils-libs-0.141-1.fc10.i386
> > >  elfutils-libelf-devel-0.141-1.fc10.i386
> > > 
> > > do they work fine or you?
> > 
> > I'm a Debian user, so I build this library from source
> > 
> > https://fedorahosted.org/releases/e/l/elfutils/elfutils-0.141.tar.bz2
> > 
> > And I succeed to build perf, thanks!
> 
> 
> You could also just
> 
> apt-get install libelf-dev
> 
> 
Thanks. I could install libelf with your way.

And sorry for my late response.
Because adding counting spin lock to perfcounters is more difficult
than I excepted...

When the process watched by perf tries to lock a spinlock
this will be the nest of spinlock,
because perfcounters subsystem also uses spinlock.

Is there any way to avoid the nest of lock?
I want any advice...

This is the temporal patch I wrote,

diff --git a/include/linux/perf_counter.h b/include/linux/perf_counter.h
index 5e970c7..f65a473 100644
--- a/include/linux/perf_counter.h
+++ b/include/linux/perf_counter.h
@@ -102,6 +102,7 @@ enum perf_sw_ids {
 	PERF_COUNT_SW_CPU_MIGRATIONS		= 4,
 	PERF_COUNT_SW_PAGE_FAULTS_MIN		= 5,
 	PERF_COUNT_SW_PAGE_FAULTS_MAJ		= 6,
+	PERF_COUNT_SW_LOCK_ACQUIRES		= 7,
 
 	PERF_COUNT_SW_MAX,			/* non-ABI */
 };
diff --git a/kernel/perf_counter.c b/kernel/perf_counter.c
index d55a50d..0261f9f 100644
--- a/kernel/perf_counter.c
+++ b/kernel/perf_counter.c
@@ -3754,6 +3754,7 @@ static const struct pmu *sw_perf_counter_init(struct perf_counter *counter)
 	case PERF_COUNT_SW_PAGE_FAULTS_MAJ:
 	case PERF_COUNT_SW_CONTEXT_SWITCHES:
 	case PERF_COUNT_SW_CPU_MIGRATIONS:
+	case PERF_COUNT_SW_LOCK_ACQUIRES:
 		if (!counter->parent) {
 			atomic_inc(&perf_swcounter_enabled[event]);
 			counter->destroy = sw_perf_counter_destroy;
diff --git a/kernel/spinlock.c b/kernel/spinlock.c
index 7932653..394fc2d 100644
--- a/kernel/spinlock.c
+++ b/kernel/spinlock.c
@@ -20,6 +20,7 @@
 #include <linux/interrupt.h>
 #include <linux/debug_locks.h>
 #include <linux/module.h>
+#include <linux/perf_counter.h>
 
 int __lockfunc _spin_trylock(spinlock_t *lock)
 {
@@ -181,6 +182,9 @@ void __lockfunc _spin_lock(spinlock_t *lock)
 	preempt_disable();
 	spin_acquire(&lock->dep_map, 0, 0, _RET_IP_);
 	LOCK_CONTENDED(lock, _raw_spin_trylock, _raw_spin_lock);
+	perf_swcounter_event(PERF_COUNT_SW_LOCK_ACQUIRES,
+			     1, 1, NULL, 0);
+
 }
 
 EXPORT_SYMBOL(_spin_lock);
diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c
index 2e03524..87511c0 100644
--- a/tools/perf/builtin-stat.c
+++ b/tools/perf/builtin-stat.c
@@ -52,6 +52,7 @@ static struct perf_counter_attr default_attrs[] = {
   { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_CONTEXT_SWITCHES},
   { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_CPU_MIGRATIONS	},
   { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_PAGE_FAULTS	},
+  { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_LOCK_ACQUIRES	},
 
   { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_CPU_CYCLES	},
   { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_INSTRUCTIONS	},
diff --git a/tools/perf/util/parse-events.c b/tools/perf/util/parse-events.c
index 4d042f1..0cd4985 100644
--- a/tools/perf/util/parse-events.c
+++ b/tools/perf/util/parse-events.c
@@ -38,6 +38,7 @@ static struct event_symbol event_symbols[] = {
   { CSW(PAGE_FAULTS_MAJ),	"major-faults",		""		},
   { CSW(CONTEXT_SWITCHES),	"context-switches",	"cs"		},
   { CSW(CPU_MIGRATIONS),	"cpu-migrations",	"migrations"	},
+  { CSW(LOCK_ACQUIRES),         "lock-acquires",	"lock"	},
 };
 
 #define __PERF_COUNTER_FIELD(config, name) \
@@ -66,6 +67,7 @@ static char *sw_event_names[] = {
 	"CPU-migrations",
 	"minor-faults",
 	"major-faults",
+	"lock-acquires",
 };
 
 #define MAX_ALIASES 8


ÿôèº{.nÇ+‰·Ÿ®‰­†+%ŠËÿ±éݶ\x17¥Šwÿº{.nÇ+‰·¥Š{±þG«éÿŠ{ayº\x1dʇڙë,j\a­¢f£¢·hšïêÿ‘êçz_è®\x03(­éšŽŠÝ¢j"ú\x1a¶^[m§ÿÿ¾\a«þG«éÿ¢¸?™¨è­Ú&£ø§~á¶iO•æ¬z·švØ^\x14\x04\x1a¶^[m§ÿÿÃ\fÿ¶ìÿ¢¸?–I¥

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Peter Zijlstra]

On Mon, 2009-07-06 at 14:20 +0900, mitake@dcl.info.waseda.ac.jp wrote:

> Thanks. I could install libelf with your way.
> 
> And sorry for my late response.
> Because adding counting spin lock to perfcounters is more difficult
> than I excepted...
> 
> When the process watched by perf tries to lock a spinlock
> this will be the nest of spinlock,
> because perfcounters subsystem also uses spinlock.
> 
> Is there any way to avoid the nest of lock?
> I want any advice...

swcounters should be able to deal with this recursion, but I have other
concerns with this.. see below.

> This is the temporal patch I wrote,
> 
> diff --git a/include/linux/perf_counter.h b/include/linux/perf_counter.h
> index 5e970c7..f65a473 100644
> --- a/include/linux/perf_counter.h
> +++ b/include/linux/perf_counter.h
> @@ -102,6 +102,7 @@ enum perf_sw_ids {
>  	PERF_COUNT_SW_CPU_MIGRATIONS		= 4,
>  	PERF_COUNT_SW_PAGE_FAULTS_MIN		= 5,
>  	PERF_COUNT_SW_PAGE_FAULTS_MAJ		= 6,
> +	PERF_COUNT_SW_LOCK_ACQUIRES		= 7,
>  
>  	PERF_COUNT_SW_MAX,			/* non-ABI */
>  };
> diff --git a/kernel/perf_counter.c b/kernel/perf_counter.c
> index d55a50d..0261f9f 100644
> --- a/kernel/perf_counter.c
> +++ b/kernel/perf_counter.c
> @@ -3754,6 +3754,7 @@ static const struct pmu *sw_perf_counter_init(struct perf_counter *counter)
>  	case PERF_COUNT_SW_PAGE_FAULTS_MAJ:
>  	case PERF_COUNT_SW_CONTEXT_SWITCHES:
>  	case PERF_COUNT_SW_CPU_MIGRATIONS:
> +	case PERF_COUNT_SW_LOCK_ACQUIRES:
>  		if (!counter->parent) {
>  			atomic_inc(&perf_swcounter_enabled[event]);
>  			counter->destroy = sw_perf_counter_destroy;
> diff --git a/kernel/spinlock.c b/kernel/spinlock.c
> index 7932653..394fc2d 100644
> --- a/kernel/spinlock.c
> +++ b/kernel/spinlock.c
> @@ -20,6 +20,7 @@
>  #include <linux/interrupt.h>
>  #include <linux/debug_locks.h>
>  #include <linux/module.h>
> +#include <linux/perf_counter.h>
>  
>  int __lockfunc _spin_trylock(spinlock_t *lock)
>  {
> @@ -181,6 +182,9 @@ void __lockfunc _spin_lock(spinlock_t *lock)
>  	preempt_disable();
>  	spin_acquire(&lock->dep_map, 0, 0, _RET_IP_);
>  	LOCK_CONTENDED(lock, _raw_spin_trylock, _raw_spin_lock);
> +	perf_swcounter_event(PERF_COUNT_SW_LOCK_ACQUIRES,
> +			     1, 1, NULL, 0);
> +
>  }


Hrm.. very much the wrong place to put this hook..

Maybe re-use the LOCK_CONTENDED macros for this, but I'm not sure we
want to go there and put code like this on the lock hot-paths for !debug
kernels.

>  EXPORT_SYMBOL(_spin_lock);
> diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c
> index 2e03524..87511c0 100644
> --- a/tools/perf/builtin-stat.c
> +++ b/tools/perf/builtin-stat.c
> @@ -52,6 +52,7 @@ static struct perf_counter_attr default_attrs[] = {
>    { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_CONTEXT_SWITCHES},
>    { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_CPU_MIGRATIONS	},
>    { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_PAGE_FAULTS	},
> +  { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_LOCK_ACQUIRES	},
>  
>    { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_CPU_CYCLES	},
>    { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_INSTRUCTIONS	},
> diff --git a/tools/perf/util/parse-events.c b/tools/perf/util/parse-events.c
> index 4d042f1..0cd4985 100644
> --- a/tools/perf/util/parse-events.c
> +++ b/tools/perf/util/parse-events.c
> @@ -38,6 +38,7 @@ static struct event_symbol event_symbols[] = {
>    { CSW(PAGE_FAULTS_MAJ),	"major-faults",		""		},
>    { CSW(CONTEXT_SWITCHES),	"context-switches",	"cs"		},
>    { CSW(CPU_MIGRATIONS),	"cpu-migrations",	"migrations"	},
> +  { CSW(LOCK_ACQUIRES),         "lock-acquires",	"lock"	},
>  };
>  
>  #define __PERF_COUNTER_FIELD(config, name) \
> @@ -66,6 +67,7 @@ static char *sw_event_names[] = {
>  	"CPU-migrations",
>  	"minor-faults",
>  	"major-faults",
> +	"lock-acquires",
>  };
>  
>  #define MAX_ALIASES 8

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Andi Kleen]

> Maybe re-use the LOCK_CONTENDED macros for this, but I'm not sure we
> want to go there and put code like this on the lock hot-paths for !debug
> kernels.

My concern was similar.

I suspect it would be in theory ok for the slow spinning path, but I am 
somewhat concerned about the additional cache miss for checking
the global flag even in this case. This could hurt when
the kernel is running fully cache hold, in that the cache miss
might be far more expensive that  short spin.

Needs immediate value patching or just use a jumper kprobe when it's
really needed? I think I would prefer the later variant.

-Andi

-- 
ak@linux.intel.com -- Speaking for myself only.

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[mitake]

From: Andi Kleen <andi@firstfloor.org>
Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
Date: Mon, 6 Jul 2009 13:54:51 +0200

Thank you for your replying, Peter and Andi.

> > Maybe re-use the LOCK_CONTENDED macros for this, but I'm not sure we
> > want to go there and put code like this on the lock hot-paths for !debug
> > kernels.
> 
> My concern was similar.
> 
> I suspect it would be in theory ok for the slow spinning path, but I am 
> somewhat concerned about the additional cache miss for checking
> the global flag even in this case. This could hurt when
> the kernel is running fully cache hold, in that the cache miss
> might be far more expensive that  short spin.

Yes, there will be overhead. This is certain.
But there's the radical way to ignore this,
adding subcategory to Kconfig for measuring spinlocks and #ifdef to spinlock.c.
So people who wants to avoid this overhead can disable measurement of spinlocks completely.

And there's another way to avoid the overhead of measurement.
Making _spin_lock variable of function pointer.
When you don't want to measure spinlocks,
assign _spin_lock_raw() which is equals to current _spin_lock().
When you want to measure spinlocks,
assign _spin_lock_perf() which locks and measures.
This way will banish the cache miss problem you said.
I think this may be useful for avoiding problem of recursion.

> 
> Needs immediate value patching or just use a jumper kprobe when it's
> really needed? I think I would prefer the later variant.

What does "immediate value patching" mean?
I've never heard about this, so Googled but cannot find anything maybe you said.
Could you teach me about this?

But there's also spinlock recursion problem.. > kprobe

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Peter Zijlstra]

On Fri, 2009-07-10 at 21:45 +0900, mitake@dcl.info.waseda.ac.jp wrote:
> From: Andi Kleen <andi@firstfloor.org>
> Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> Date: Mon, 6 Jul 2009 13:54:51 +0200
> 
> Thank you for your replying, Peter and Andi.
> 
> > > Maybe re-use the LOCK_CONTENDED macros for this, but I'm not sure we
> > > want to go there and put code like this on the lock hot-paths for !debug
> > > kernels.
> > 
> > My concern was similar.
> > 
> > I suspect it would be in theory ok for the slow spinning path, but I am 
> > somewhat concerned about the additional cache miss for checking
> > the global flag even in this case. This could hurt when
> > the kernel is running fully cache hold, in that the cache miss
> > might be far more expensive that  short spin.
> 
> Yes, there will be overhead. This is certain.
> But there's the radical way to ignore this,
> adding subcategory to Kconfig for measuring spinlocks and #ifdef to spinlock.c.
> So people who wants to avoid this overhead can disable measurement of spinlocks completely.
> 
> And there's another way to avoid the overhead of measurement.
> Making _spin_lock variable of function pointer.
> When you don't want to measure spinlocks,
> assign _spin_lock_raw() which is equals to current _spin_lock().
> When you want to measure spinlocks,
> assign _spin_lock_perf() which locks and measures.
> This way will banish the cache miss problem you said.
> I think this may be useful for avoiding problem of recursion.

We already have that, its called CONFIG_LOCKDEP && CONFIG_EVENT_TRACING
&& CONFIG_EVENT_PROFILE, with those enabled you get tracepoints on every
lock acquire and lock release, and perf can already use those as event
sources.

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Ingo Molnar]

* Peter Zijlstra <a.p.zijlstra@chello.nl> wrote:

> On Fri, 2009-07-10 at 21:45 +0900, mitake@dcl.info.waseda.ac.jp wrote:
> > From: Andi Kleen <andi@firstfloor.org>
> > Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> > Date: Mon, 6 Jul 2009 13:54:51 +0200
> > 
> > Thank you for your replying, Peter and Andi.
> > 
> > > > Maybe re-use the LOCK_CONTENDED macros for this, but I'm not sure we
> > > > want to go there and put code like this on the lock hot-paths for !debug
> > > > kernels.
> > > 
> > > My concern was similar.
> > > 
> > > I suspect it would be in theory ok for the slow spinning path, but I am 
> > > somewhat concerned about the additional cache miss for checking
> > > the global flag even in this case. This could hurt when
> > > the kernel is running fully cache hold, in that the cache miss
> > > might be far more expensive that  short spin.
> > 
> > Yes, there will be overhead. This is certain.
> > But there's the radical way to ignore this,
> > adding subcategory to Kconfig for measuring spinlocks and #ifdef to spinlock.c.
> > So people who wants to avoid this overhead can disable measurement of spinlocks completely.
> > 
> > And there's another way to avoid the overhead of measurement. 
> > Making _spin_lock variable of function pointer. When you don't 
> > want to measure spinlocks, assign _spin_lock_raw() which is 
> > equals to current _spin_lock(). When you want to measure 
> > spinlocks, assign _spin_lock_perf() which locks and measures. 
> > This way will banish the cache miss problem you said. I think 
> > this may be useful for avoiding problem of recursion.
> 
> We already have that, its called CONFIG_LOCKDEP && 
> CONFIG_EVENT_TRACING && CONFIG_EVENT_PROFILE, with those enabled 
> you get tracepoints on every lock acquire and lock release, and 
> perf can already use those as event sources.

Yes, that could be reused for this facility too.

	Ingo

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Frederic Weisbecker]

On Fri, Jul 10, 2009 at 03:43:07PM +0200, Ingo Molnar wrote:
> 
> * Peter Zijlstra <a.p.zijlstra@chello.nl> wrote:
> 
> > On Fri, 2009-07-10 at 21:45 +0900, mitake@dcl.info.waseda.ac.jp wrote:
> > > From: Andi Kleen <andi@firstfloor.org>
> > > Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> > > Date: Mon, 6 Jul 2009 13:54:51 +0200
> > > 
> > > Thank you for your replying, Peter and Andi.
> > > 
> > > > > Maybe re-use the LOCK_CONTENDED macros for this, but I'm not sure we
> > > > > want to go there and put code like this on the lock hot-paths for !debug
> > > > > kernels.
> > > > 
> > > > My concern was similar.
> > > > 
> > > > I suspect it would be in theory ok for the slow spinning path, but I am 
> > > > somewhat concerned about the additional cache miss for checking
> > > > the global flag even in this case. This could hurt when
> > > > the kernel is running fully cache hold, in that the cache miss
> > > > might be far more expensive that  short spin.
> > > 
> > > Yes, there will be overhead. This is certain.
> > > But there's the radical way to ignore this,
> > > adding subcategory to Kconfig for measuring spinlocks and #ifdef to spinlock.c.
> > > So people who wants to avoid this overhead can disable measurement of spinlocks completely.
> > > 
> > > And there's another way to avoid the overhead of measurement. 
> > > Making _spin_lock variable of function pointer. When you don't 
> > > want to measure spinlocks, assign _spin_lock_raw() which is 
> > > equals to current _spin_lock(). When you want to measure 
> > > spinlocks, assign _spin_lock_perf() which locks and measures. 
> > > This way will banish the cache miss problem you said. I think 
> > > this may be useful for avoiding problem of recursion.
> > 
> > We already have that, its called CONFIG_LOCKDEP && 
> > CONFIG_EVENT_TRACING && CONFIG_EVENT_PROFILE, with those enabled 
> > you get tracepoints on every lock acquire and lock release, and 
> > perf can already use those as event sources.
> 
> Yes, that could be reused for this facility too.
> 
> 	Ingo


I wonder if the lock_*() events should become independant from lockdep
so that we don't need to always enable lockdep to get the lock events at the
same time.

It could be a separate option.

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Ingo Molnar]

* Frederic Weisbecker <fweisbec@gmail.com> wrote:

> On Fri, Jul 10, 2009 at 03:43:07PM +0200, Ingo Molnar wrote:
> > 
> > * Peter Zijlstra <a.p.zijlstra@chello.nl> wrote:
> > 
> > > On Fri, 2009-07-10 at 21:45 +0900, mitake@dcl.info.waseda.ac.jp wrote:
> > > > From: Andi Kleen <andi@firstfloor.org>
> > > > Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> > > > Date: Mon, 6 Jul 2009 13:54:51 +0200
> > > > 
> > > > Thank you for your replying, Peter and Andi.
> > > > 
> > > > > > Maybe re-use the LOCK_CONTENDED macros for this, but I'm not sure we
> > > > > > want to go there and put code like this on the lock hot-paths for !debug
> > > > > > kernels.
> > > > > 
> > > > > My concern was similar.
> > > > > 
> > > > > I suspect it would be in theory ok for the slow spinning path, but I am 
> > > > > somewhat concerned about the additional cache miss for checking
> > > > > the global flag even in this case. This could hurt when
> > > > > the kernel is running fully cache hold, in that the cache miss
> > > > > might be far more expensive that  short spin.
> > > > 
> > > > Yes, there will be overhead. This is certain.
> > > > But there's the radical way to ignore this,
> > > > adding subcategory to Kconfig for measuring spinlocks and #ifdef to spinlock.c.
> > > > So people who wants to avoid this overhead can disable measurement of spinlocks completely.
> > > > 
> > > > And there's another way to avoid the overhead of measurement. 
> > > > Making _spin_lock variable of function pointer. When you don't 
> > > > want to measure spinlocks, assign _spin_lock_raw() which is 
> > > > equals to current _spin_lock(). When you want to measure 
> > > > spinlocks, assign _spin_lock_perf() which locks and measures. 
> > > > This way will banish the cache miss problem you said. I think 
> > > > this may be useful for avoiding problem of recursion.
> > > 
> > > We already have that, its called CONFIG_LOCKDEP && 
> > > CONFIG_EVENT_TRACING && CONFIG_EVENT_PROFILE, with those enabled 
> > > you get tracepoints on every lock acquire and lock release, and 
> > > perf can already use those as event sources.
> > 
> > Yes, that could be reused for this facility too.
> > 
> > 	Ingo
> 
> 
> I wonder if the lock_*() events should become independant from 
> lockdep so that we don't need to always enable lockdep to get the 
> lock events at the same time.
> 
> It could be a separate option.

They already should be to a large degree if CONFIG_LOCK_STAT is 
enabled but CONFIG_PROVE_LOCKING is off. In theory :-)

	Ingo

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Peter Zijlstra]

On Fri, 2009-07-10 at 15:50 +0200, Ingo Molnar wrote:

> > I wonder if the lock_*() events should become independant from 
> > lockdep so that we don't need to always enable lockdep to get the 
> > lock events at the same time.
> > 
> > It could be a separate option.
> 
> They already should be to a large degree if CONFIG_LOCK_STAT is 
> enabled but CONFIG_PROVE_LOCKING is off. In theory :-)

Right, you don't need CONFIG_PROVE_LOCKING in order to get the
tracepoints. Also, you can always boot with prove_locking=0 or runtime
disable it using: echo 0 > /sys/module/lockdep/parameters/prove_locking

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Hitoshi Mitake]

From: Peter Zijlstra <a.p.zijlstra@chello.nl>
Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
Date: Fri, 10 Jul 2009 14:52:16 +0200

> On Fri, 2009-07-10 at 21:45 +0900, mitake@dcl.info.waseda.ac.jp wrote:
> > From: Andi Kleen <andi@firstfloor.org>
> > Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> > Date: Mon, 6 Jul 2009 13:54:51 +0200
> > 
> > Thank you for your replying, Peter and Andi.
> > 
> > > > Maybe re-use the LOCK_CONTENDED macros for this, but I'm not sure we
> > > > want to go there and put code like this on the lock hot-paths for !debug
> > > > kernels.
> > > 
> > > My concern was similar.
> > > 
> > > I suspect it would be in theory ok for the slow spinning path, but I am 
> > > somewhat concerned about the additional cache miss for checking
> > > the global flag even in this case. This could hurt when
> > > the kernel is running fully cache hold, in that the cache miss
> > > might be far more expensive that  short spin.
> > 
> > Yes, there will be overhead. This is certain.
> > But there's the radical way to ignore this,
> > adding subcategory to Kconfig for measuring spinlocks and #ifdef to spinlock.c.
> > So people who wants to avoid this overhead can disable measurement of spinlocks completely.
> > 
> > And there's another way to avoid the overhead of measurement.
> > Making _spin_lock variable of function pointer.
> > When you don't want to measure spinlocks,
> > assign _spin_lock_raw() which is equals to current _spin_lock().
> > When you want to measure spinlocks,
> > assign _spin_lock_perf() which locks and measures.
> > This way will banish the cache miss problem you said.
> > I think this may be useful for avoiding problem of recursion.
> 
> We already have that, its called CONFIG_LOCKDEP && CONFIG_EVENT_TRACING
> && CONFIG_EVENT_PROFILE, with those enabled you get tracepoints on every
> lock acquire and lock release, and perf can already use those as event
> sources.
> 
> 
> 
> 

Thanks, I understood your advice. Using infrastructure of ftrace is good idea, so I'll use it.

But I have a question.
I can't enable CONFIG_EVENT_PROFILE because it depends on CONFIG_EVENT_TRACER.
And CONFIG_EVENT_TRACER seems something never enabled.

% git grep EVENT_TRACER
arch/arm/configs/cm_x300_defconfig:# CONFIG_EVENT_TRACER is not set
arch/arm/configs/davinci_all_defconfig:# CONFIG_EVENT_TRACER is not set
arch/arm/configs/ep93xx_defconfig:# CONFIG_EVENT_TRACER is not set
...
arch/x86/configs/i386_defconfig:# CONFIG_EVENT_TRACER is not set
arch/x86/configs/x86_64_defconfig:# CONFIG_EVENT_TRACER is not set
init/Kconfig:   depends on PERF_COUNTERS && EVENT_TRACER

In addition, this is the output of searching this on menuconfig
    Symbol: EVENT_TRACER [=EVENT_TRACER]          
and, there is a log in git

commit a7abe97fd8e7a6ccabba5a04a9f17be9211d418c
Author: Steven Rostedt <srostedt@redhat.com>
Date:   Mon Apr 20 10:59:34 2009 -0400

    tracing: rename EVENT_TRACER config to ENABLE_EVENT_TRACING

    Currently we have two configs: EVENT_TRACING and EVENT_TRACER.
    All tracers enable EVENT_TRACING. The EVENT_TRACER is only a
    convenience to enable the EVENT_TRACING when no other tracers
    are enabled.

Does EVENT_TRACER make any sense?
If doesn't, can I remove dependency of CONFIG_EVENT_PROFILE?

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Peter Zijlstra]

On Sun, 2009-07-12 at 16:23 +0900, Hitoshi Mitake wrote:

> Thanks, I understood your advice. Using infrastructure of ftrace is good idea, so I'll use it.
> 
> But I have a question.
> I can't enable CONFIG_EVENT_PROFILE because it depends on CONFIG_EVENT_TRACER.
> And CONFIG_EVENT_TRACER seems something never enabled.
> 
> % git grep EVENT_TRACER
> arch/arm/configs/cm_x300_defconfig:# CONFIG_EVENT_TRACER is not set
> arch/arm/configs/davinci_all_defconfig:# CONFIG_EVENT_TRACER is not set
> arch/arm/configs/ep93xx_defconfig:# CONFIG_EVENT_TRACER is not set
> ....
> arch/x86/configs/i386_defconfig:# CONFIG_EVENT_TRACER is not set
> arch/x86/configs/x86_64_defconfig:# CONFIG_EVENT_TRACER is not set
> init/Kconfig:   depends on PERF_COUNTERS && EVENT_TRACER
> 
> In addition, this is the output of searching this on menuconfig
>     Symbol: EVENT_TRACER [=EVENT_TRACER]          
> and, there is a log in git
> 
> commit a7abe97fd8e7a6ccabba5a04a9f17be9211d418c
> Author: Steven Rostedt <srostedt@redhat.com>
> Date:   Mon Apr 20 10:59:34 2009 -0400
> 
>     tracing: rename EVENT_TRACER config to ENABLE_EVENT_TRACING
> 
>     Currently we have two configs: EVENT_TRACING and EVENT_TRACER.
>     All tracers enable EVENT_TRACING. The EVENT_TRACER is only a
>     convenience to enable the EVENT_TRACING when no other tracers
>     are enabled.
> 
> Does EVENT_TRACER make any sense?
> If doesn't, can I remove dependency of CONFIG_EVENT_PROFILE?

Yeah, steve broke it, but then Jason fixed it again, but his patches
might not have made it in yet.

  http://lkml.org/lkml/2009/7/6/313

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Hitoshi Mitake]

From: Peter Zijlstra <a.p.zijlstra@chello.nl>
Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
Date: Sun, 12 Jul 2009 15:24:05 +0200

> On Sun, 2009-07-12 at 16:23 +0900, Hitoshi Mitake wrote:
> 
> > Thanks, I understood your advice. Using infrastructure of ftrace is good idea, so I'll use it.
> > 
> > But I have a question.
> > I can't enable CONFIG_EVENT_PROFILE because it depends on CONFIG_EVENT_TRACER.
> > And CONFIG_EVENT_TRACER seems something never enabled.
> > 
> > % git grep EVENT_TRACER
> > arch/arm/configs/cm_x300_defconfig:# CONFIG_EVENT_TRACER is not set
> > arch/arm/configs/davinci_all_defconfig:# CONFIG_EVENT_TRACER is not set
> > arch/arm/configs/ep93xx_defconfig:# CONFIG_EVENT_TRACER is not set
> > ....
> > arch/x86/configs/i386_defconfig:# CONFIG_EVENT_TRACER is not set
> > arch/x86/configs/x86_64_defconfig:# CONFIG_EVENT_TRACER is not set
> > init/Kconfig:   depends on PERF_COUNTERS && EVENT_TRACER
> > 
> > In addition, this is the output of searching this on menuconfig
> >     Symbol: EVENT_TRACER [=EVENT_TRACER]          
> > and, there is a log in git
> > 
> > commit a7abe97fd8e7a6ccabba5a04a9f17be9211d418c
> > Author: Steven Rostedt <srostedt@redhat.com>
> > Date:   Mon Apr 20 10:59:34 2009 -0400
> > 
> >     tracing: rename EVENT_TRACER config to ENABLE_EVENT_TRACING
> > 
> >     Currently we have two configs: EVENT_TRACING and EVENT_TRACER.
> >     All tracers enable EVENT_TRACING. The EVENT_TRACER is only a
> >     convenience to enable the EVENT_TRACING when no other tracers
> >     are enabled.
> > 
> > Does EVENT_TRACER make any sense?
> > If doesn't, can I remove dependency of CONFIG_EVENT_PROFILE?
> 
> Yeah, steve broke it, but then Jason fixed it again, but his patches
> might not have made it in yet.
> 
>   http://lkml.org/lkml/2009/7/6/313
> 
> 

Wow! I can obtain lock_acquire with Jason's patch,

% perf stat -e lockdep:lock_acquire sleep 1

 Performance counter stats for 'sleep 1':

           1420  lockdep:lock_acquire

    1.004953591  seconds time elapsed

I wanted this.
So I don't have nothing to do.., but thanks Jason!

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Ingo Molnar]

* Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> wrote:

> > Yeah, steve broke it, but then Jason fixed it again, but his 
> > patches might not have made it in yet.
> > 
> >   http://lkml.org/lkml/2009/7/6/313
> 
> Wow! I can obtain lock_acquire with Jason's patch,
> 
> % perf stat -e lockdep:lock_acquire sleep 1
> 
>  Performance counter stats for 'sleep 1':
> 
>            1420  lockdep:lock_acquire
> 
>     1.004953591  seconds time elapsed
> 
> I wanted this.
> So I don't have nothing to do.., but thanks Jason!

I gave some review feedback about those patches, see:

   http://lkml.org/lkml/2009/7/13/360

Once they are addressed we can try them in -tip.

	Ingo

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Hitoshi Mitake]

From: Ingo Molnar <mingo@elte.hu>
Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
Date: Mon, 13 Jul 2009 10:51:19 +0200

> X-Mew-Uidl: 4144 3205
> Return-Path: <mingo@elte.hu>
> Received: from murder ([unix socket])
> 	 by ns.dcl.info.waseda.ac.jp (Cyrus v2.3.8-OS X Server 10.5:	9F33) with LMTPA;
> 	 Mon, 13 Jul 2009 17:51:35 +0900
> X-Sieve: CMU Sieve 2.3
> Received: from localhost (localhost [127.0.0.1])
> 	by ns.dcl.info.waseda.ac.jp (Postfix) with ESMTP id 418376729D2
> 	for <mitake@dcl.info.waseda.ac.jp>; Mon, 13 Jul 2009 17:51:35 +0900 (JST)
> X-Virus-Scanned: amavisd-new at dcl.info.waseda.ac.jp
> Received: from ns.dcl.info.waseda.ac.jp ([127.0.0.1])
> 	by localhost (ns.dcl.info.waseda.ac.jp [127.0.0.1]) (amavisd-new, port 10024)
> 	with ESMTP id 4VNvZ6jG1jE9 for <mitake@dcl.info.waseda.ac.jp>;
> 	Mon, 13 Jul 2009 17:51:34 +0900 (JST)
> Received: from mx3.mail.elte.hu (mx3.mail.elte.hu [157.181.1.138])
> 	by ns.dcl.info.waseda.ac.jp (Postfix) with ESMTP id C08246729C2
> 	for <mitake@dcl.info.waseda.ac.jp>; Mon, 13 Jul 2009 17:51:33 +0900 (JST)
> Received: from elvis.elte.hu ([157.181.1.14])
> 	by mx3.mail.elte.hu with esmtp (Exim)
> 	id 1MQHFr-0003wM-HT
> 	from <mingo@elte.hu>; Mon, 13 Jul 2009 10:51:28 +0200
> Received: by elvis.elte.hu (Postfix, from userid 1004)
> 	id 115B83E22CE; Mon, 13 Jul 2009 10:51:21 +0200 (CEST)
> Message-ID: <20090713085119.GA6757@elte.hu>
> References: <1247230336.7529.34.camel@twins> <20090712.162337.287595819039280884.mitake@dcl.info.waseda.ac.jp> <1247405045.6733.2.camel@laptop> <20090713.150612.886429910823138064.mitake@dcl.info.waseda.ac.jp>
> MIME-Version: 1.0
> In-Reply-To: <20090713.150612.886429910823138064.mitake@dcl.info.waseda.ac.jp>
> X-ELTE-SpamScore: -1.5
> X-ELTE-SpamLevel: 
> X-ELTE-SpamCheck: no
> X-ELTE-SpamVersion: ELTE 2.0 
> X-ELTE-SpamCheck-Details: score=-1.5 required=5.9 tests=BAYES_00 autolearn=no SpamAssassin version=3.2.5	-1.5 BAYES_00               BODY: Bayesian spam probability is 0 to 1%	[score: 0.0000]
> Content-Type: text/plain; charset=us-ascii
> Content-Disposition: inline
> Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> From: Ingo Molnar <mingo@elte.hu>
> To: Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp>
> Cc: a.p.zijlstra@chello.nl, andi@firstfloor.org, fweisbec@gmail.com,
> 	acme@redhat.com, linux-kernel@vger.kernel.org,
> 	Jason Baron <jbaron@redhat.com>
> Date: Mon, 13 Jul 2009 10:51:19 +0200
> User-Agent: Mutt/1.5.18 (2008-05-17)
> Received-SPF: neutral (mx3: 157.181.1.14 is neither permitted nor denied by domain of elte.hu) client-ip=157.181.1.14; envelope-from=mingo@elte.hu; helo=elvis.elte.hu;
> X-Mew: tab/spc characters on Subject: are simplified.
> 
> 
> * Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> wrote:
> 
> > > Yeah, steve broke it, but then Jason fixed it again, but his 
> > > patches might not have made it in yet.
> > > 
> > >   http://lkml.org/lkml/2009/7/6/313
> > 
> > Wow! I can obtain lock_acquire with Jason's patch,
> > 
> > % perf stat -e lockdep:lock_acquire sleep 1
> > 
> >  Performance counter stats for 'sleep 1':
> > 
> >            1420  lockdep:lock_acquire
> > 
> >     1.004953591  seconds time elapsed
> > 
> > I wanted this.
> > So I don't have nothing to do.., but thanks Jason!
> 
> I gave some review feedback about those patches, see:
> 
>    http://lkml.org/lkml/2009/7/13/360
> 
> Once they are addressed we can try them in -tip.

Thanks! I'll try new features of perfcounters. It's interesting.
But I told "not found" by lkml.org.
Is the post you attempted to point http://lkml.org/lkml/2009/7/13/36 ?

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Ingo Molnar]

* Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> wrote:

> From: Ingo Molnar <mingo@elte.hu>
> Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> Date: Mon, 13 Jul 2009 10:51:19 +0200
> 
> > X-Mew-Uidl: 4144 3205
> > Return-Path: <mingo@elte.hu>
> > Received: from murder ([unix socket])
> > 	 by ns.dcl.info.waseda.ac.jp (Cyrus v2.3.8-OS X Server 10.5:	9F33) with LMTPA;
> > 	 Mon, 13 Jul 2009 17:51:35 +0900
> > X-Sieve: CMU Sieve 2.3
> > Received: from localhost (localhost [127.0.0.1])
> > 	by ns.dcl.info.waseda.ac.jp (Postfix) with ESMTP id 418376729D2
> > 	for <mitake@dcl.info.waseda.ac.jp>; Mon, 13 Jul 2009 17:51:35 +0900 (JST)
> > X-Virus-Scanned: amavisd-new at dcl.info.waseda.ac.jp
> > Received: from ns.dcl.info.waseda.ac.jp ([127.0.0.1])
> > 	by localhost (ns.dcl.info.waseda.ac.jp [127.0.0.1]) (amavisd-new, port 10024)
> > 	with ESMTP id 4VNvZ6jG1jE9 for <mitake@dcl.info.waseda.ac.jp>;
> > 	Mon, 13 Jul 2009 17:51:34 +0900 (JST)
> > Received: from mx3.mail.elte.hu (mx3.mail.elte.hu [157.181.1.138])
> > 	by ns.dcl.info.waseda.ac.jp (Postfix) with ESMTP id C08246729C2
> > 	for <mitake@dcl.info.waseda.ac.jp>; Mon, 13 Jul 2009 17:51:33 +0900 (JST)
> > Received: from elvis.elte.hu ([157.181.1.14])
> > 	by mx3.mail.elte.hu with esmtp (Exim)
> > 	id 1MQHFr-0003wM-HT
> > 	from <mingo@elte.hu>; Mon, 13 Jul 2009 10:51:28 +0200
> > Received: by elvis.elte.hu (Postfix, from userid 1004)
> > 	id 115B83E22CE; Mon, 13 Jul 2009 10:51:21 +0200 (CEST)
> > Message-ID: <20090713085119.GA6757@elte.hu>
> > References: <1247230336.7529.34.camel@twins> <20090712.162337.287595819039280884.mitake@dcl.info.waseda.ac.jp> <1247405045.6733.2.camel@laptop> <20090713.150612.886429910823138064.mitake@dcl.info.waseda.ac.jp>
> > MIME-Version: 1.0
> > In-Reply-To: <20090713.150612.886429910823138064.mitake@dcl.info.waseda.ac.jp>
> > X-ELTE-SpamScore: -1.5
> > X-ELTE-SpamLevel: 
> > X-ELTE-SpamCheck: no
> > X-ELTE-SpamVersion: ELTE 2.0 
> > X-ELTE-SpamCheck-Details: score=-1.5 required=5.9 tests=BAYES_00 autolearn=no SpamAssassin version=3.2.5	-1.5 BAYES_00               BODY: Bayesian spam probability is 0 to 1%	[score: 0.0000]
> > Content-Type: text/plain; charset=us-ascii
> > Content-Disposition: inline
> > Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> > From: Ingo Molnar <mingo@elte.hu>
> > To: Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp>
> > Cc: a.p.zijlstra@chello.nl, andi@firstfloor.org, fweisbec@gmail.com,
> > 	acme@redhat.com, linux-kernel@vger.kernel.org,
> > 	Jason Baron <jbaron@redhat.com>
> > Date: Mon, 13 Jul 2009 10:51:19 +0200
> > User-Agent: Mutt/1.5.18 (2008-05-17)
> > Received-SPF: neutral (mx3: 157.181.1.14 is neither permitted nor denied by domain of elte.hu) client-ip=157.181.1.14; envelope-from=mingo@elte.hu; helo=elvis.elte.hu;
> > X-Mew: tab/spc characters on Subject: are simplified.
> > 
> > 
> > * Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> wrote:
> > 
> > > > Yeah, steve broke it, but then Jason fixed it again, but his 
> > > > patches might not have made it in yet.
> > > > 
> > > >   http://lkml.org/lkml/2009/7/6/313
> > > 
> > > Wow! I can obtain lock_acquire with Jason's patch,
> > > 
> > > % perf stat -e lockdep:lock_acquire sleep 1
> > > 
> > >  Performance counter stats for 'sleep 1':
> > > 
> > >            1420  lockdep:lock_acquire
> > > 
> > >     1.004953591  seconds time elapsed
> > > 
> > > I wanted this.
> > > So I don't have nothing to do.., but thanks Jason!
> > 
> > I gave some review feedback about those patches, see:
> > 
> >    http://lkml.org/lkml/2009/7/13/360
> > 
> > Once they are addressed we can try them in -tip.
> 
> Thanks! I'll try new features of perfcounters. It's interesting.
> But I told "not found" by lkml.org.
>
> Is the post you attempted to point 
> http://lkml.org/lkml/2009/7/13/36 ?

yeah. The first post should be:

 http://lkml.org/lkml/2009/7/6/313

	Ingo

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Andi Kleen]

> His arguments are bogus: both lockstat and perfcounters are optional 

The patch was for schedstat, not lockstat.

> (and default off), and the sw counter can be made near zero cost 

My understanding was that perfcounters was supposed to 
be enabled on production kernels?

If not it would be fairly useless to most people who
don't recompile their kernels.

> even if both perfcounters and lockstat is enabled. Also, sw counters 
> are generally per CPU, etc. so not a performance issue.

Uncontended spinlock is still a hotpath and adding code
to it will add overhead. 

Without cache line bouncing it might not be fatal, but 
making very fundamental micro operations like that slower
in production kernels doesn't seem like a good idea to me.

It would be especially sad since now in the x86 world we're
getting CPUs with fast LOCK prefix widely deplouyed and wasting
these improvements in Linux specific overhead again wouldn't
seem like the right direction to me.

Especially if it's quite dubious if the information gotten
through this counter is actually useful (or in the few cases
you really need it you can easily get with one of the
dynamic probing solutions)

One potential useful alternative metric I could imagine might
be useful be possible number of spins. I wouldn't have a problem with
that because spinning is already a slower path in the common
case. It might still cost a bit of SMT, but probably not fatal.
Still I suspect you can relatively easily get equivalent information
with a normal cycle profiler.

Benchmark numbers would be still a good idea of course.

> Andi is often trolling perfcounters related (and other) threads, 

It's an interesting insight into your way of thinking that you now 
consistently started to describe code review as trolling.

FYI I generally don't enjoy doing code review but do it anyways because I 
think it's important to do to keep code quality up. Even if it doesn't
seem to be appreciated by people like you.

-Andi

-- 
ak@linux.intel.com -- Speaking for myself only.

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat II

[Andi Kleen]

On Wed, Jul 01, 2009 at 11:07:49AM +0200, Ingo Molnar wrote:
> His arguments are bogus: both lockstat and perfcounters are optional 
> (and default off), and the sw counter can be made near zero cost 
> even if both perfcounters and lockstat is enabled. Also, sw counters 
> are generally per CPU, etc. so not a performance issue.

BTW I looked through the code generated by this again.  As far as I 
can see it still uses a global flag word to enable/disable the counter.

The standard problem -- discussed a lot -- with that set up used to be that 
if the kernel is entered cache cold then you end up with a potential full cache
miss (200-1000 cycles) just to access that global variable. The old LTT
had a neat optimization to patch in immediate values to avoid this problem.

Has this been considered for these counters? With such a change
it might be indeed a "small" cost even in the worst cases.

-Andi

-- 
ak@linux.intel.com -- Speaking for myself only.

Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat

[Andi Kleen]

On Wed, Jul 01, 2009 at 05:42:26PM +0900, Hitoshi Mitake wrote:
> From: Andi Kleen <andi@firstfloor.org>
> Subject: Re: [PATCH][RFC] Adding information of counts processes acquired how many spinlocks to schedstat
> Date: Wed, 01 Jul 2009 09:38:04 +0200
> 
> > Hitoshi Mitake <mitake@dcl.info.waseda.ac.jp> writes:
> > 
> > > Hi,
> > >
> > > I wrote a test patch which add information of counts processes acquired how many spinlocks to schedstat.
> > > After applied this patch, /proc/<PID>/sched will change like this,
> > 
> > The problem is that spinlocks are very common and schedstats is enabled commonly
> > in production kernels. You would need to demonstrate that such a change doesn't
> > have significant performance impact. For me it looks like it has.
> 
> I agree with your opinion about performance impact.
> I thought this will make no problem,
> because schedstat is categorized as "Kernel hacking" section.
> But according to you, many production kernels enable it

Yes it's used by some performance management tools.

It might be still appropiate with a separate CONFIG option,
assuming the metric is actually useful (which is somewhat
questionable)

BTW I did spinlock counter statistics in the past with systemtap
(they're quite easy to do with it without any code changes), but I didn't find
them very useful to be honest.

> > Also I'm not sure exactly what good such a metric is. Do you have 
> > a concrete use case?
> > 
> 
> I want to know about behavior of Apache.

Spinlocks are mainly interesting when they use up CPU time.
This typically happens when they bounce cache lines or are
contended. On the other hand on modern CPUs "local only"
spinlocks that are not contended are quite cheap and 
not very interesting to optimize. For useful optimization
you need to distingush all these cases, and your 
simple counter doesn't help with that.

So I would suggest you just take a look at any of the 
standard kernel profilers (oprofile etc.) or at lockstat

> And spinlocks may cause terrible performance problem when Linux is running on VM.

Assuming a modern CPU the "uncontended lock spinlock" case shouldn't
be particularly expensive in VMs either.

> 
> > The normal way to check for lock contention or lock bouncingis to
> > simply profile cycles or time and see if there is a lot of CPU time in
> > locks.
> 
> According to Ingo's advice, I'll try to add lock counter to perfcounter.

Well that would have the same problem if that perfcounter is enabled.

-Andi

-- 
ak@linux.intel.com -- Speaking for myself only.