I'm having some trouble with lockstat. I've enabled CONFIG_LOCK_STATS
and then run the following commands to collect the lock statistics for
the futex_lock test case. I expect this test case to generate a fair
amount of contention on the futex hash bucket locks, but they don't show
up in the stats (in fact, nothing shows up in the stats). I have seen
much longer lock_stat files when I forgot to clear them before the test,
but no hb locks showed up there either.
Is my usage below incorrect? Do I have to somehow annotate the hb->lock
in order for lockstat to track it?
This is as of:
commit a3d3203e4bb40f253b1541e310dc0f9305be7c84
Merge: f937331... ec28dcc...
Author: Linus Torvalds <[email protected]>
Date: Sun Mar 14 20:29:21 2010 -0700
# echo 0 > /proc/lock_stat; echo 1 > /proc/sys/kernel/lock_stat;
./futex_lock -i10000000 -p1000 -d20; cat /proc/lock_stat >
lock.lockstat; echo 0 > /proc/sys/kernel/lock_stat
futex_lock: Measure FUTEX_LOCK operations per second
Arguments: iterations=10000000 threads=256 adaptive=no
period=1000 duty-cycle=20%
Result: 731 Kiter/s
# cat lock.lockstat
lock_stat version 0.3
*WARNING* lock debugging disabled!! - possibly due to a lockdep warning
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
class name con-bounces contentions
waittime-min waittime-max waittime-total acq-bounces
acquisitions holdtime-min holdtime-max holdtime-total
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
#
Thanks,
--
Darren Hart
IBM Linux Technology Center
Real-Time Linux Team
On Wed, Apr 21, 2010 at 11:26:07PM -0700, Darren Hart wrote:
> I'm having some trouble with lockstat. I've enabled
> CONFIG_LOCK_STATS and then run the following commands to collect the
> lock statistics for the futex_lock test case. I expect this test
> case to generate a fair amount of contention on the futex hash
> bucket locks, but they don't show up in the stats (in fact, nothing
> shows up in the stats). I have seen much longer lock_stat files when
> I forgot to clear them before the test, but no hb locks showed up
> there either.
>
> Is my usage below incorrect? Do I have to somehow annotate the
> hb->lock in order for lockstat to track it?
IMHO, you don't need to do that.
> lock.lockstat; echo 0 > /proc/sys/kernel/lock_stat
> futex_lock: Measure FUTEX_LOCK operations per second
> Arguments: iterations=10000000 threads=256 adaptive=no
> period=1000 duty-cycle=20%
> Result: 731 Kiter/s
>
> # cat lock.lockstat
> lock_stat version 0.3
> *WARNING* lock debugging disabled!! - possibly due to a lockdep warning
This means lockdep has detect there is something wrong.
Can you show your 'dmesg'?
Thanks,
Yong
> -----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
> class name con-bounces
> contentions waittime-min waittime-max waittime-total
> acq-bounces acquisitions holdtime-min holdtime-max
> holdtime-total
> -----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
> #
>
> Thanks,
>
> --
> Darren Hart
> IBM Linux Technology Center
> Real-Time Linux Team
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/
Yong Zhang wrote:
> On Wed, Apr 21, 2010 at 11:26:07PM -0700, Darren Hart wrote:
>> I'm having some trouble with lockstat. I've enabled
>> CONFIG_LOCK_STATS and then run the following commands to collect the
>> lock statistics for the futex_lock test case. I expect this test
>> case to generate a fair amount of contention on the futex hash
>> bucket locks, but they don't show up in the stats (in fact, nothing
>> shows up in the stats). I have seen much longer lock_stat files when
>> I forgot to clear them before the test, but no hb locks showed up
>> there either.
>>
>> Is my usage below incorrect? Do I have to somehow annotate the
>> hb->lock in order for lockstat to track it?
>
> IMHO, you don't need to do that.
>
>> lock.lockstat; echo 0 > /proc/sys/kernel/lock_stat
>> futex_lock: Measure FUTEX_LOCK operations per second
>> Arguments: iterations=10000000 threads=256 adaptive=no
>> period=1000 duty-cycle=20%
>> Result: 731 Kiter/s
>>
>> # cat lock.lockstat
>> lock_stat version 0.3
>> *WARNING* lock debugging disabled!! - possibly due to a lockdep warning
>
> This means lockdep has detect there is something wrong.
> Can you show your 'dmesg'?
dmesg includes the following during bootup, but nothing new while
running the tests:
BUG: key ffff88024e657858 not in .data!
------------[ cut here ]------------
WARNING: at kernel/lockdep.c:2706 lockdep_init_map+0x226/0x5c0()
Hardware name: BladeCenter LS21 -[7971AC1]-
Pid: 1, comm: swapper Not tainted 2.6.34-rc1dvhv4ls #32
Call Trace:
[<ffffffff81078446>] ? lockdep_init_map+0x226/0x5c0
[<ffffffff81048687>] warn_slowpath_common+0x87/0xb0
[<ffffffff810486c4>] warn_slowpath_null+0x14/0x20
[<ffffffff81078446>] lockdep_init_map+0x226/0x5c0
[<ffffffff81077f53>] ? lock_release_holdtime+0x83/0xf0
[<ffffffff8115e5a1>] sysfs_add_file_mode+0x71/0xd0
[<ffffffff8115e611>] sysfs_add_file+0x11/0x20
[<ffffffff8115e650>] sysfs_create_file+0x30/0x40
[<ffffffff814995d9>] device_create_file+0x19/0x20
[<ffffffff813afe55>] ipmi_register_smi+0xba5/0xfc0
[<ffffffff81498877>] ? put_device+0x17/0x20
[<ffffffff810670d0>] ? autoremove_wake_function+0x0/0x40
[<ffffffff813b3a12>] try_smi_init+0x5d2/0xa20
[<ffffffff818d5b72>] init_ipmi_si+0x432/0xb80
[<ffffffff818d5740>] ? init_ipmi_si+0x0/0xb80
[<ffffffff810001dd>] do_one_initcall+0x3d/0x180
[<ffffffff822d5a6c>] kernel_init+0x16c/0x200
[<ffffffff81003c14>] kernel_thread_helper+0x4/0x10
[<ffffffff822d5900>] ? kernel_init+0x0/0x200
[<ffffffff81003c10>] ? kernel_thread_helper+0x0/0x10
---[ end trace 30838b0dc5ec48e4 ]---
Several more "BUG: key fffXXXXXXXXXXXX not in .data!" lines show up
throughout the boot process.
I vaguely recall this being normal for lockstat at initial boot.
--
Darren
>
> Thanks,
> Yong
>
>> -----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>> class name con-bounces
>> contentions waittime-min waittime-max waittime-total
>> acq-bounces acquisitions holdtime-min holdtime-max
>> holdtime-total
>> -----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>>
>> #
>>
>> Thanks,
>>
>> --
>> Darren Hart
>> IBM Linux Technology Center
>> Real-Time Linux Team
>> --
>> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
>> the body of a message to [email protected]
>> More majordomo info at http://vger.kernel.org/majordomo-info.html
>> Please read the FAQ at http://www.tux.org/lkml/
--
Darren Hart
IBM Linux Technology Center
Real-Time Linux Team
On Thu, 22 Apr 2010, Darren Hart wrote:
> dmesg includes the following during bootup, but nothing new while running the
> tests:
>
> BUG: key ffff88024e657858 not in .data!
> ------------[ cut here ]------------
> WARNING: at kernel/lockdep.c:2706 lockdep_init_map+0x226/0x5c0()
> Hardware name: BladeCenter LS21 -[7971AC1]-
> Pid: 1, comm: swapper Not tainted 2.6.34-rc1dvhv4ls #32
> Call Trace:
> [<ffffffff81078446>] ? lockdep_init_map+0x226/0x5c0
> [<ffffffff81048687>] warn_slowpath_common+0x87/0xb0
> [<ffffffff810486c4>] warn_slowpath_null+0x14/0x20
> [<ffffffff81078446>] lockdep_init_map+0x226/0x5c0
> [<ffffffff81077f53>] ? lock_release_holdtime+0x83/0xf0
> [<ffffffff8115e5a1>] sysfs_add_file_mode+0x71/0xd0
> [<ffffffff8115e611>] sysfs_add_file+0x11/0x20
> [<ffffffff8115e650>] sysfs_create_file+0x30/0x40
> [<ffffffff814995d9>] device_create_file+0x19/0x20
> [<ffffffff813afe55>] ipmi_register_smi+0xba5/0xfc0
> [<ffffffff81498877>] ? put_device+0x17/0x20
> [<ffffffff810670d0>] ? autoremove_wake_function+0x0/0x40
> [<ffffffff813b3a12>] try_smi_init+0x5d2/0xa20
> [<ffffffff818d5b72>] init_ipmi_si+0x432/0xb80
> [<ffffffff818d5740>] ? init_ipmi_si+0x0/0xb80
> [<ffffffff810001dd>] do_one_initcall+0x3d/0x180
> [<ffffffff822d5a6c>] kernel_init+0x16c/0x200
> [<ffffffff81003c14>] kernel_thread_helper+0x4/0x10
> [<ffffffff822d5900>] ? kernel_init+0x0/0x200
> [<ffffffff81003c10>] ? kernel_thread_helper+0x0/0x10
> ---[ end trace 30838b0dc5ec48e4 ]---
>
> Several more "BUG: key fffXXXXXXXXXXXX not in .data!" lines show up throughout
> the boot process.
This should be fixed by commit c7df670b (contained first in 2.6.34-rc2).
Do you still see this even with this patch applied?
--
Jiri Kosina
SUSE Labs, Novell Inc.
Jiri Kosina wrote:
> On Thu, 22 Apr 2010, Darren Hart wrote:
>
>> dmesg includes the following during bootup, but nothing new while running the
>> tests:
>>
>> BUG: key ffff88024e657858 not in .data!
>> ------------[ cut here ]------------
>> WARNING: at kernel/lockdep.c:2706 lockdep_init_map+0x226/0x5c0()
>> Hardware name: BladeCenter LS21 -[7971AC1]-
>> Pid: 1, comm: swapper Not tainted 2.6.34-rc1dvhv4ls #32
>> Call Trace:
>> [<ffffffff81078446>] ? lockdep_init_map+0x226/0x5c0
>> [<ffffffff81048687>] warn_slowpath_common+0x87/0xb0
>> [<ffffffff810486c4>] warn_slowpath_null+0x14/0x20
>> [<ffffffff81078446>] lockdep_init_map+0x226/0x5c0
>> [<ffffffff81077f53>] ? lock_release_holdtime+0x83/0xf0
>> [<ffffffff8115e5a1>] sysfs_add_file_mode+0x71/0xd0
>> [<ffffffff8115e611>] sysfs_add_file+0x11/0x20
>> [<ffffffff8115e650>] sysfs_create_file+0x30/0x40
>> [<ffffffff814995d9>] device_create_file+0x19/0x20
>> [<ffffffff813afe55>] ipmi_register_smi+0xba5/0xfc0
>> [<ffffffff81498877>] ? put_device+0x17/0x20
>> [<ffffffff810670d0>] ? autoremove_wake_function+0x0/0x40
>> [<ffffffff813b3a12>] try_smi_init+0x5d2/0xa20
>> [<ffffffff818d5b72>] init_ipmi_si+0x432/0xb80
>> [<ffffffff818d5740>] ? init_ipmi_si+0x0/0xb80
>> [<ffffffff810001dd>] do_one_initcall+0x3d/0x180
>> [<ffffffff822d5a6c>] kernel_init+0x16c/0x200
>> [<ffffffff81003c14>] kernel_thread_helper+0x4/0x10
>> [<ffffffff822d5900>] ? kernel_init+0x0/0x200
>> [<ffffffff81003c10>] ? kernel_thread_helper+0x0/0x10
>> ---[ end trace 30838b0dc5ec48e4 ]---
>>
>> Several more "BUG: key fffXXXXXXXXXXXX not in .data!" lines show up throughout
>> the boot process.
>
> This should be fixed by commit c7df670b (contained first in 2.6.34-rc2).
> Do you still see this even with this patch applied?
After updating to the latest linus git lockstats started working as
expected. Thanks for the pointer.
--
Darren Hart
IBM Linux Technology Center
Real-Time Linux Team