LKML Archive on lore.kernel.org
help / color / mirror / Atom feed
* Fwd: oprofile lockdep warning on rc1
@ 2007-02-28  0:46 Dave Jones
  2007-03-16 11:36 ` [PATCH] " Jarek Poplawski
  0 siblings, 1 reply; 2+ messages in thread
From: Dave Jones @ 2007-02-28  0:46 UTC (permalink / raw)
  To: Linux Kernel

[-- Attachment #1: Type: text/plain, Size: 79 bytes --]

This happened on a 2.6.21rc1 kernel.

		Dave

-- 
http://www.codemonkey.org.uk

[-- Attachment #2: Type: message/rfc822, Size: 8041 bytes --]

From: Richard Hughes <hughsient@gmail.com>
To: Development discussions related to Fedora Core <fedora-devel-list@redhat.com>
Subject: Re: XOrg weirdness
Date: Tue, 27 Feb 2007 21:59:07 +0000
Message-ID: <1172613547.2699.2.camel@localhost.localdomain>

On Tue, 2007-02-27 at 14:52 -0500, Adam Jackson wrote:
> 
> 
> Well it's at least partly Xorg's fault, but it would be helpful to
> know
> what the slow path is there; so if you do file a bug against Xorg,
> please accompany it with oprofile goodness.

Well, I get this:

CPU: Core Solo / Duo, speed 1662.57 MHz (estimated)
Counted CPU_CLK_UNHALTED events (Unhalted clock cycles) with a unit mask
of 0x00 (Unhalted core cycles) count 860000
CPU_CLK_UNHALT...|
  samples|      %|
------------------
    12704 82.6330 /usr/bin/Xorg
        CPU_CLK_UNHALT...|
          samples|      %|
        ------------------
            12066 94.9780 /usr/lib/xorg/modules/libfb.so
              286  2.2513 /usr/bin/Xorg
              216  1.7003 /usr/lib/xorg/modules/drivers/nv_drv.so
               75  0.5904 /lib/libc-2.5.90.so
               48  0.3778 /usr/lib/xorg/modules/libxaa.so
                6  0.0472 /usr/lib/xorg/modules/extensions/libextmod.so
                3  0.0236 /lib/librt-2.5.90.so
                1  0.0079 /usr/lib/libXfont.so.1.4.1
                1  0.0079 /usr/lib/xorg/modules/input/mouse_drv.so
                1  0.0079 /usr/lib/xorg/modules/input/synaptics_drv.so
                1  0.0079 /usr/lib/xorg/modules/libramdac.so

But also I get this (!!!):

oprofile: using NMI interrupt.

=================================
[ INFO: inconsistent lock state ]
2.6.20-1.2949.fc7 #1
---------------------------------
inconsistent {hardirq-on-W} -> {in-hardirq-W} usage.
swapper/0 [HC1[1]:SC0[0]:HE0:SE1] takes:
 (oprofilefs_lock){+-..}, at: [<f8c6db5e>] nmi_cpu_setup+0x15/0x4f
[oprofile]
{hardirq-on-W} state was registered at:
  [<c0442440>] __lock_acquire+0x448/0xba4
  [<c0442f8e>] lock_acquire+0x56/0x6f
  [<c0614949>] _spin_lock+0x2b/0x38
  [<f8c6d33c>] oprofilefs_ulong_from_user+0x4e/0x74 [oprofile]
  [<f8c6d38c>] ulong_write_file+0x2a/0x38 [oprofile]
  [<c047e20b>] vfs_write+0xaf/0x163
  [<c047e859>] sys_write+0x3d/0x61
  [<c0405134>] syscall_call+0x7/0xb
  [<ffffffff>] 0xffffffff
irq event stamp: 23424902
hardirqs last  enabled at (23424901): [<c0614d4d>]
_spin_unlock_irqrestore+0x36/0x3c
hardirqs last disabled at (23424902): [<c0405bb5>]
call_function_interrupt+0x29/0x38
softirqs last  enabled at (23424892): [<c042c0d8>] __do_softirq
+0xdc/0xe2
softirqs last disabled at (23424885): [<c04074dc>] do_softirq+0x61/0xd0

other info that might help us debug this:
no locks held by swapper/0.

stack backtrace:
 [<c04062a5>] show_trace_log_lvl+0x1a/0x2f
 [<c0406869>] show_trace+0x12/0x14
 [<c04068ed>] dump_stack+0x16/0x18
 [<c0440f67>] print_usage_bug+0x141/0x14b
 [<c0441620>] mark_lock+0xa2/0x419
 [<c04423b1>] __lock_acquire+0x3b9/0xba4
 [<c0442f8e>] lock_acquire+0x56/0x6f
 [<c0614949>] _spin_lock+0x2b/0x38
 [<f8c6db5e>] nmi_cpu_setup+0x15/0x4f [oprofile]
 [<c0417e6a>] smp_call_function_interrupt+0x3f/0x5b
 [<c0405bbf>] call_function_interrupt+0x33/0x38
 [<c0614896>] _spin_unlock+0x16/0x20
 [<c043ded6>] clockevents_notify+0x3e/0x42
 [<c0532f67>] acpi_state_timer_broadcast+0x2e/0x31
 [<c05338e8>] acpi_processor_idle+0x285/0x419
 [<c040348e>] cpu_idle+0xb7/0xdd
 [<c0418eef>] start_secondary+0x330/0x338
 [<00000000>] 0x0
 =======================

Why do the simplest bugs always turn into the most complicated ones ;-)

Richard.


-- 
fedora-devel-list mailing list
fedora-devel-list@redhat.com
https://www.redhat.com/mailman/listinfo/fedora-devel-list

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

* [PATCH] Re: Fwd: oprofile lockdep warning on rc1
  2007-02-28  0:46 Fwd: oprofile lockdep warning on rc1 Dave Jones
@ 2007-03-16 11:36 ` Jarek Poplawski
  0 siblings, 0 replies; 2+ messages in thread
From: Jarek Poplawski @ 2007-03-16 11:36 UTC (permalink / raw)
  To: Dave Jones, Linux Kernel; +Cc: Richard Hughes, Philippe Elie, oprofile-list

On 28-02-2007 01:46, Dave Jones wrote:
> This happened on a 2.6.21rc1 kernel.
...
> Richard Hughes <hughsient@gmail.com>
> Date:
> Tue, 27 Feb 2007 21:59:07 +0000
> To:
> Development discussions related to Fedora Core 
> <fedora-devel-list@redhat.com>
...
> But also I get this (!!!):
> 
> oprofile: using NMI interrupt.
> 
> =================================
> [ INFO: inconsistent lock state ]
> 2.6.20-1.2949.fc7 #1
> ---------------------------------
> inconsistent {hardirq-on-W} -> {in-hardirq-W} usage.
> swapper/0 [HC1[1]:SC0[0]:HE0:SE1] takes:
>  (oprofilefs_lock){+-..}, at: [<f8c6db5e>] nmi_cpu_setup+0x15/0x4f
> [oprofile]
> {hardirq-on-W} state was registered at:
>   [<c0442440>] __lock_acquire+0x448/0xba4
>   [<c0442f8e>] lock_acquire+0x56/0x6f
>   [<c0614949>] _spin_lock+0x2b/0x38
>   [<f8c6d33c>] oprofilefs_ulong_from_user+0x4e/0x74 [oprofile]
>   [<f8c6d38c>] ulong_write_file+0x2a/0x38 [oprofile]
>   [<c047e20b>] vfs_write+0xaf/0x163
>   [<c047e859>] sys_write+0x3d/0x61
>   [<c0405134>] syscall_call+0x7/0xb
>   [<ffffffff>] 0xffffffff
> irq event stamp: 23424902
> hardirqs last  enabled at (23424901): [<c0614d4d>]
> _spin_unlock_irqrestore+0x36/0x3c
> hardirqs last disabled at (23424902): [<c0405bb5>]
> call_function_interrupt+0x29/0x38
> softirqs last  enabled at (23424892): [<c042c0d8>] __do_softirq
> +0xdc/0xe2
> softirqs last disabled at (23424885): [<c04074dc>] do_softirq+0x61/0xd0
> 
> other info that might help us debug this:
> no locks held by swapper/0.
> 
> stack backtrace:
>  [<c04062a5>] show_trace_log_lvl+0x1a/0x2f
>  [<c0406869>] show_trace+0x12/0x14
>  [<c04068ed>] dump_stack+0x16/0x18
>  [<c0440f67>] print_usage_bug+0x141/0x14b
>  [<c0441620>] mark_lock+0xa2/0x419
>  [<c04423b1>] __lock_acquire+0x3b9/0xba4
>  [<c0442f8e>] lock_acquire+0x56/0x6f
>  [<c0614949>] _spin_lock+0x2b/0x38
>  [<f8c6db5e>] nmi_cpu_setup+0x15/0x4f [oprofile]
>  [<c0417e6a>] smp_call_function_interrupt+0x3f/0x5b
>  [<c0405bbf>] call_function_interrupt+0x33/0x38
>  [<c0614896>] _spin_unlock+0x16/0x20
>  [<c043ded6>] clockevents_notify+0x3e/0x42
>  [<c0532f67>] acpi_state_timer_broadcast+0x2e/0x31
>  [<c05338e8>] acpi_processor_idle+0x285/0x419
>  [<c040348e>] cpu_idle+0xb7/0xdd
>  [<c0418eef>] start_secondary+0x330/0x338
>  [<00000000>] 0x0
>  =======================
> 
> Why do the simplest bugs always turn into the most complicated ones ;-)
> 
> Richard.

Here is my patch proposal for testing.

Regards,
Jarek P.

lockdep found oprofilefs_lock is taken both in process
context (oprofilefs_ulong_from_user()) and from hardirq
(nmi_cpu_setup()), so the lockup is possible.

Reported-by: Richard Hughes <hughsient@gmail.com>
Signed-off-by: Jarek Poplawski <jarkao2@o2.pl>

---

diff -Nurp linux-2.6.21-rc1-/drivers/oprofile/oprofilefs.c linux-2.6.21-rc1/drivers/oprofile/oprofilefs.c
--- linux-2.6.21-rc1-/drivers/oprofile/oprofilefs.c	2007-02-27 10:47:38.000000000 +0100
+++ linux-2.6.21-rc1/drivers/oprofile/oprofilefs.c	2007-03-16 11:36:30.000000000 +0100
@@ -65,6 +65,7 @@ ssize_t oprofilefs_ulong_to_user(unsigne
 int oprofilefs_ulong_from_user(unsigned long * val, char const __user * buf, size_t count)
 {
 	char tmpbuf[TMPBUFSIZE];
+	unsigned long flags;
 
 	if (!count)
 		return 0;
@@ -77,9 +78,9 @@ int oprofilefs_ulong_from_user(unsigned 
 	if (copy_from_user(tmpbuf, buf, count))
 		return -EFAULT;
 
-	spin_lock(&oprofilefs_lock);
+	spin_lock_irqsave(&oprofilefs_lock, flags);
 	*val = simple_strtoul(tmpbuf, NULL, 0);
-	spin_unlock(&oprofilefs_lock);
+	spin_unlock_irqrestore(&oprofilefs_lock, flags);
 	return 0;
 }
 

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

end of thread, other threads:[~2007-03-16 11:31 UTC | newest]

Thread overview: 2+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2007-02-28  0:46 Fwd: oprofile lockdep warning on rc1 Dave Jones
2007-03-16 11:36 ` [PATCH] " Jarek Poplawski

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).