2005-10-04 08:43:43

by Ingo Molnar

[permalink] [raw]
Subject: 2.6.14-rc3-rt2


i have released the 2.6.14-rc3-rt2 tree, which can be downloaded from
the usual place:

http://redhat.com/~mingo/realtime-preempt/

the biggest change in this release is the long-anticipated merge of a
streamlined version of the "robust futexes/mutexes with priority
queueing and priority inheritance" code into the -rt tree. The original
upstream patch is from Todd Kneisel, with further improvements, cleanups
and -RT integration done by David Singleton.

robustness is handled by extending the futex framework with
registering/unregistering ops and extended wait/wake ops. Priority
queueing and inheritance is implemented by embedding the rt_mutex object
into the robust-futex structure. This approach made the patches
significantly simpler and smaller (but still not trivial at all) than
e.g. the fusyn patchset was.

the intent of this merge is to provide a testing basis for the new futex
code, with a goal of merging it upstream. The userspace APIs might still
change. These changes should not affect existing futex users. (To make
use of the new capabilities, additional glibc patches are needed.)

Changes since 2.6.14-rc2-rt1:

- robust/PI mutexes/futexes (Todd Kneisel, David Singleton)

- ktimer update (Thomas Gleixner)

- change boot-time locking in the IDE layer, to make mode-setting safer

- mkiss.c build fix (reported by Felix Oxley)

to build a 2.6.14-rc3-rt2 tree, the following patches should be applied:

http://kernel.org/pub/linux/kernel/v2.6/linux-2.6.13.tar.bz2
http://kernel.org/pub/linux/kernel/v2.6/testing/patch-2.6.14-rc3.bz2
http://redhat.com/~mingo/realtime-preempt/patch-2.6.14-rc3-rt2

Ingo


2005-10-04 12:51:56

by K.R. Foley

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

Ingo Molnar wrote:
> i have released the 2.6.14-rc3-rt2 tree, which can be downloaded from
> the usual place:
>
> http://redhat.com/~mingo/realtime-preempt/
>

Ingo,

This one seems to be missing some pieces :-)

http://people.redhat.com/mingo/realtime-preempt/patch-2.6.14-rc3-rt5

--
kr

2005-10-04 12:59:51

by Ingo Molnar

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


* K.R. Foley <[email protected]> wrote:

> Ingo Molnar wrote:
> >i have released the 2.6.14-rc3-rt2 tree, which can be downloaded from
> >the usual place:
> >
> > http://redhat.com/~mingo/realtime-preempt/
> >
>
> Ingo,
>
> This one seems to be missing some pieces :-)
>
> http://people.redhat.com/mingo/realtime-preempt/patch-2.6.14-rc3-rt5

ugh. uploaded -rt6.

Ingo

2005-10-04 13:46:25

by Steven Rostedt

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


On Tue, 4 Oct 2005, Ingo Molnar wrote:

>
> ugh. uploaded -rt6.
>
> Ingo

Hmm Ingo,

Looks like -rt6 got rid of all the _nort defines, but it's still used
throughout the kernel.

-- Steve

2005-10-04 14:25:36

by Steven Rostedt

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


Also the inclusion of ktimer (I believe) has made a dependency with
mpparse and IO_APIC. Since now mpparse.c calls setup_IO_APIC_early which
is defined only if X86_IO_APIC is, the kernel wont link without.
So, is the following patch sufficient? Or does mpparse.c need to be
different, that is should we not call setup_IO_APIC_early if X86_IO_APIC
is not set?

I haven't looked too deep into this, and wont until -rt6 gets fixed.
Better yet, Thomas is probably better at looking into this.

-- Steve

--- linux-2.6.14-rc3-rt6/arch/i386/Kconfig.debug.orig 2005-10-04 10:05:19.000000000 -0400
+++ linux-2.6.14-rc3-rt6/arch/i386/Kconfig.debug 2005-10-04 10:06:02.000000000 -0400
@@ -71,7 +71,7 @@ config X86_FIND_SMP_CONFIG

config X86_MPPARSE
bool
- depends on X86_LOCAL_APIC && !X86_VISWS
+ depends on X86_LOCAL_APIC && X86_IO_APIC && !X86_VISWS
default y

endmenu

2005-10-04 14:26:57

by Ingo Molnar

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


* Steven Rostedt <[email protected]> wrote:

> On Tue, 4 Oct 2005, Ingo Molnar wrote:
>
> >
> > ugh. uploaded -rt6.
> >
> > Ingo
>
> Hmm Ingo,
>
> Looks like -rt6 got rid of all the _nort defines, but it's still used
> throughout the kernel.

yeah, -rt7 should fix this.

Ingo

2005-10-04 15:09:08

by Dinakar Guniguntala

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Tue, Oct 04, 2005 at 04:27:18PM +0200, Ingo Molnar wrote:
>
> > Hmm Ingo,
> >
> > Looks like -rt6 got rid of all the _nort defines, but it's still used
> > throughout the kernel.
>
> yeah, -rt7 should fix this.
>


I get a lot of these with -rt7 (One every minute)

BUG: auditd:3596, possible softlockup detected on CPU#3!
[<c0144c48>] softlockup_detected+0x39/0x46 (8)
[<c0144d26>] softlockup_tick+0xd1/0xd3 (20)
[<c0111252>] smp_apic_timer_ipi_interrupt+0x4d/0x56 (24)
[<c010396c>] apic_timer_ipi_interrupt+0x1c/0x24 (12)
[<c0102e7f>] sysenter_past_esp+0x24/0x75 (44)


-Dinakar

2005-10-04 15:31:52

by Ingo Molnar

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


.config please.

Ingo

* Dinakar Guniguntala <[email protected]> wrote:

> On Tue, Oct 04, 2005 at 04:27:18PM +0200, Ingo Molnar wrote:
> >
> > > Hmm Ingo,
> > >
> > > Looks like -rt6 got rid of all the _nort defines, but it's still used
> > > throughout the kernel.
> >
> > yeah, -rt7 should fix this.
> >
>
>
> I get a lot of these with -rt7 (One every minute)
>
> BUG: auditd:3596, possible softlockup detected on CPU#3!
> [<c0144c48>] softlockup_detected+0x39/0x46 (8)
> [<c0144d26>] softlockup_tick+0xd1/0xd3 (20)
> [<c0111252>] smp_apic_timer_ipi_interrupt+0x4d/0x56 (24)
> [<c010396c>] apic_timer_ipi_interrupt+0x1c/0x24 (12)
> [<c0102e7f>] sysenter_past_esp+0x24/0x75 (44)
>
>
> -Dinakar

2005-10-04 15:33:01

by Thomas Gleixner

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Tue, 2005-10-04 at 20:46 +0530, Dinakar Guniguntala wrote:

> I get a lot of these with -rt7 (One every minute)
>
> BUG: auditd:3596, possible softlockup detected on CPU#3!
> [<c0144c48>] softlockup_detected+0x39/0x46 (8)
> [<c0144d26>] softlockup_tick+0xd1/0xd3 (20)
> [<c0111252>] smp_apic_timer_ipi_interrupt+0x4d/0x56 (24)
> [<c010396c>] apic_timer_ipi_interrupt+0x1c/0x24 (12)
> [<c0102e7f>] sysenter_past_esp+0x24/0x75 (44)
>

Can you send me your .config please ?

tglx


2005-10-04 15:42:47

by Dinakar Guniguntala

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Tue, Oct 04, 2005 at 05:32:08PM +0200, Ingo Molnar wrote:
>
> .config please.
>
> * Dinakar Guniguntala <[email protected]> wrote:
>
> > I get a lot of these with -rt7 (One every minute)
> >
> > BUG: auditd:3596, possible softlockup detected on CPU#3!
> > [<c0144c48>] softlockup_detected+0x39/0x46 (8)
> > [<c0144d26>] softlockup_tick+0xd1/0xd3 (20)
> > [<c0111252>] smp_apic_timer_ipi_interrupt+0x4d/0x56 (24)
> > [<c010396c>] apic_timer_ipi_interrupt+0x1c/0x24 (12)
> > [<c0102e7f>] sysenter_past_esp+0x24/0x75 (44)
> >


.config attached this time

-Dinakar


Attachments:
(No filename) (575.00 B)
config (32.05 kB)
Download all attachments

2005-10-04 15:45:28

by Thomas Gleixner

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Tue, 2005-10-04 at 21:20 +0530, Dinakar Guniguntala wrote:
> > > BUG: auditd:3596, possible softlockup detected on CPU#3!
> > > [<c0144c48>] softlockup_detected+0x39/0x46 (8)
> > > [<c0144d26>] softlockup_tick+0xd1/0xd3 (20)
> > > [<c0111252>] smp_apic_timer_ipi_interrupt+0x4d/0x56 (24)
> > > [<c010396c>] apic_timer_ipi_interrupt+0x1c/0x24 (12)
> > > [<c0102e7f>] sysenter_past_esp+0x24/0x75 (44)
> > >
>
>
> .config attached this time

Can you try with high resolution timers disabled ?

tglx


2005-10-04 16:01:50

by Dinakar Guniguntala

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Tue, Oct 04, 2005 at 05:46:33PM +0200, Thomas Gleixner wrote:
> On Tue, 2005-10-04 at 21:20 +0530, Dinakar Guniguntala wrote:
> > > > BUG: auditd:3596, possible softlockup detected on CPU#3!
> > > > [<c0144c48>] softlockup_detected+0x39/0x46 (8)
> > > > [<c0144d26>] softlockup_tick+0xd1/0xd3 (20)
> > > > [<c0111252>] smp_apic_timer_ipi_interrupt+0x4d/0x56 (24)
> > > > [<c010396c>] apic_timer_ipi_interrupt+0x1c/0x24 (12)
> > > > [<c0102e7f>] sysenter_past_esp+0x24/0x75 (44)
> > > >
> >
> >
> > .config attached this time
>
> Can you try with high resolution timers disabled ?
>

Hi, I tried with CONFIG_HIGH_RES_TIMERS off, doesnt seem to help.
I get the same messages

-Dinakar

2005-10-04 16:09:44

by Daniel Walker

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Tue, 2005-10-04 at 20:46 +0530, Dinakar Guniguntala wrote:
> On Tue, Oct 04, 2005 at 04:27:18PM +0200, Ingo Molnar wrote:
> >
> > > Hmm Ingo,
> > >
> > > Looks like -rt6 got rid of all the _nort defines, but it's still used
> > > throughout the kernel.
> >
> > yeah, -rt7 should fix this.
> >
>
>
> I get a lot of these with -rt7 (One every minute)
>
> BUG: auditd:3596, possible softlockup detected on CPU#3!
> [<c0144c48>] softlockup_detected+0x39/0x46 (8)
> [<c0144d26>] softlockup_tick+0xd1/0xd3 (20)
> [<c0111252>] smp_apic_timer_ipi_interrupt+0x4d/0x56 (24)
> [<c010396c>] apic_timer_ipi_interrupt+0x1c/0x24 (12)
> [<c0102e7f>] sysenter_past_esp+0x24/0x75 (44)


Woops, forgot to CC LKML ..

Index: linux-2.6.13/arch/i386/kernel/apic.c
===================================================================
--- linux-2.6.13.orig/arch/i386/kernel/apic.c
+++ linux-2.6.13/arch/i386/kernel/apic.c
@@ -1153,6 +1153,16 @@ fastcall notrace void smp_apic_timer_ipi
#if 0
profile_tick(CPU_PROFILING, regs);
#endif
+
+ /*
+ * If the task is currently running in user mode, don't
+ * detect soft lockups. If CONFIG_DETECT_SOFTLOCKUP is not
+ * configured, this should be optimized out.
+ */
+ if (user_mode(regs))
+ touch_light_softlockup_watchdog();
+
+
update_process_times(user_mode_vm(regs));
irq_exit();



2005-10-04 16:33:25

by Steven Rostedt

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2



On Tue, 4 Oct 2005, Daniel Walker wrote:

> On Tue, 2005-10-04 at 20:46 +0530, Dinakar Guniguntala wrote:
> >
> > I get a lot of these with -rt7 (One every minute)
> >
> > BUG: auditd:3596, possible softlockup detected on CPU#3!
> > [<c0144c48>] softlockup_detected+0x39/0x46 (8)
> > [<c0144d26>] softlockup_tick+0xd1/0xd3 (20)
> > [<c0111252>] smp_apic_timer_ipi_interrupt+0x4d/0x56 (24)
> > [<c010396c>] apic_timer_ipi_interrupt+0x1c/0x24 (12)
> > [<c0102e7f>] sysenter_past_esp+0x24/0x75 (44)
>

Daniel,

If it works then sure. That would also show that the offending CPU is not
taking any normal interrupts (non-ipi).

Ingo, do you get the same on your 8x machine? Or is this just somthing
strange with Dinakar's machine?

Dinakar, can you try Daniel's patch, and let us know if it works or not?

Thanks,

-- Steve

2005-10-04 16:44:31

by Mark Knecht

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On 10/4/05, Ingo Molnar <[email protected]> wrote:
>
> * K.R. Foley <[email protected]> wrote:
>
> > Ingo Molnar wrote:
> > >i have released the 2.6.14-rc3-rt2 tree, which can be downloaded from
> > >the usual place:
> > >
> > > http://redhat.com/~mingo/realtime-preempt/
> > >
> >
> > Ingo,
> >
> > This one seems to be missing some pieces :-)
> >
> > http://people.redhat.com/mingo/realtime-preempt/patch-2.6.14-rc3-rt5
>
> ugh. uploaded -rt6.
>
> Ingo

Hi Ingo,
OK, I'm up and running 2.6.14-rc3-rt7. I see no run-time problems
yet, but I am seeing the machine hang when shutting down. It seems to
happen about 50% of the time and happened also on 2.6.14-rc3-rt1,
always at:

Unloading Alsa modules

It just sits there and never moves on. If I power cycle the box
then I sometimes have to do an fsck on the next boot.

This may possibly be caused by some stranded Jack process or
something I haven't noticed yet. I'll keep looking.

My working config is attached. Maybe it will help when looking at
someone's who's isn't working yet. Comments on better config are
always welcome from anyone reading this.

Cheers,
Mark


Attachments:
(No filename) (1.11 kB)
knecht.config-2.6.14-rc3-rt7.bz2 (6.36 kB)
Download all attachments

2005-10-04 16:46:13

by Daniel Walker

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Tue, 2005-10-04 at 12:32 -0400, Steven Rostedt wrote:
>
> On Tue, 4 Oct 2005, Daniel Walker wrote:
>
> > On Tue, 2005-10-04 at 20:46 +0530, Dinakar Guniguntala wrote:
> > >
> > > I get a lot of these with -rt7 (One every minute)
> > >
> > > BUG: auditd:3596, possible softlockup detected on CPU#3!
> > > [<c0144c48>] softlockup_detected+0x39/0x46 (8)
> > > [<c0144d26>] softlockup_tick+0xd1/0xd3 (20)
> > > [<c0111252>] smp_apic_timer_ipi_interrupt+0x4d/0x56 (24)
> > > [<c010396c>] apic_timer_ipi_interrupt+0x1c/0x24 (12)
> > > [<c0102e7f>] sysenter_past_esp+0x24/0x75 (44)
> >
>
> Daniel,
>
> If it works then sure. That would also show that the offending CPU is not
> taking any normal interrupts (non-ipi).

Could we move that check into update_process_times() , and do the if
statement off user_tick ? Cause otherwise the touch call will have to be
copied to bunch more functions ..

Daniel

2005-10-04 17:50:47

by Dinakar Guniguntala

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Tue, Oct 04, 2005 at 09:09:40AM -0700, Daniel Walker wrote:
> On Tue, 2005-10-04 at 20:46 +0530, Dinakar Guniguntala wrote:
> >
> > BUG: auditd:3596, possible softlockup detected on CPU#3!
> > [<c0144c48>] softlockup_detected+0x39/0x46 (8)
> > [<c0144d26>] softlockup_tick+0xd1/0xd3 (20)
> > [<c0111252>] smp_apic_timer_ipi_interrupt+0x4d/0x56 (24)
> > [<c010396c>] apic_timer_ipi_interrupt+0x1c/0x24 (12)
> > [<c0102e7f>] sysenter_past_esp+0x24/0x75 (44)
>
>
> Woops, forgot to CC LKML ..
>
> Index: linux-2.6.13/arch/i386/kernel/apic.c
> ===================================================================
> --- linux-2.6.13.orig/arch/i386/kernel/apic.c
> +++ linux-2.6.13/arch/i386/kernel/apic.c
> @@ -1153,6 +1153,16 @@ fastcall notrace void smp_apic_timer_ipi
> #if 0
> profile_tick(CPU_PROFILING, regs);
> #endif
> +
> + /*
> + * If the task is currently running in user mode, don't
> + * detect soft lockups. If CONFIG_DETECT_SOFTLOCKUP is not
> + * configured, this should be optimized out.
> + */
> + if (user_mode(regs))
> + touch_light_softlockup_watchdog();
> +
> +
> update_process_times(user_mode_vm(regs));
> irq_exit();
>

Nope doesnt help. I booted with this code change and I get the
same message.

I saw that the code change is in #ifdef CONFIG_HIGH_RES_TIMERS.
I have already disabled CONFIG_HIGH_RES_TIMERS as Thomas Gleixner
suggested

-Dinakar

2005-10-04 17:54:35

by Daniel Walker

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Tue, 2005-10-04 at 23:28 +0530, Dinakar Guniguntala wrote:

> Nope doesnt help. I booted with this code change and I get the
> same message.
>
> I saw that the code change is in #ifdef CONFIG_HIGH_RES_TIMERS.
> I have already disabled CONFIG_HIGH_RES_TIMERS as Thomas Gleixner
> suggested

Which code is #ifdef'd ?

Is there any diversity in these messages , or is it always the same? Is
the CPU# ever different?

Daniel

2005-10-04 18:05:54

by Dinakar Guniguntala

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Tue, Oct 04, 2005 at 10:54:30AM -0700, Daniel Walker wrote:
> On Tue, 2005-10-04 at 23:28 +0530, Dinakar Guniguntala wrote:
>
> > Nope doesnt help. I booted with this code change and I get the
> > same message.
> >
> > I saw that the code change is in #ifdef CONFIG_HIGH_RES_TIMERS.
> > I have already disabled CONFIG_HIGH_RES_TIMERS as Thomas Gleixner
> > suggested
>
> Which code is #ifdef'd ?

Your code was in function smp_apic_timer_ipi_interrupt (right?) that
is under CONFIG_HIGH_RES_TIMERS which was disabled.

>
> Is there any diversity in these messages , or is it always the same? Is
> the CPU# ever different?
>

Sorry I should have put this up before.


BUG: auditd:3587, possible softlockup detected on CPU#2!
[<c0144448>] softlockup_detected+0x39/0x46 (8)
[<c0144526>] softlockup_tick+0xd1/0xd3 (20)
[<c01112c7>] smp_apic_timer_interrupt+0xc0/0xcc (24)
[<c010396c>] apic_timer_interrupt+0x1c/0x24 (24)
[<c0102e8a>] sysenter_past_esp+0x2f/0x75 (44)
BUG: auditd:3587, possible softlockup detected on CPU#3!
[<c0144448>] softlockup_detected+0x39/0x46 (8)
[<c0144526>] softlockup_tick+0xd1/0xd3 (20)
[<c01112c7>] smp_apic_timer_interrupt+0xc0/0xcc (24)
[<c010396c>] apic_timer_interrupt+0x1c/0x24 (24)
BUG: auditd:3587, possible softlockup detected on CPU#2!
[<c0144448>] softlockup_detected+0x39/0x46 (8)
[<c0144526>] softlockup_tick+0xd1/0xd3 (20)
[<c01112c7>] smp_apic_timer_interrupt+0xc0/0xcc (24)
[<c010396c>] apic_timer_interrupt+0x1c/0x24 (24)
BUG: auditd:3587, possible softlockup detected on CPU#3!
[<c0144448>] softlockup_detected+0x39/0x46 (8)
[<c0144526>] softlockup_tick+0xd1/0xd3 (20)
[<c01112c7>] smp_apic_timer_interrupt+0xc0/0xcc (24)
[<c010396c>] apic_timer_interrupt+0x1c/0x24 (24)
BUG: auditd:3587, possible softlockup detected on CPU#2!
[<c0144448>] softlockup_detected+0x39/0x46 (8)
[<c0144526>] softlockup_tick+0xd1/0xd3 (20)
[<c01112c7>] smp_apic_timer_interrupt+0xc0/0xcc (24)
[<c010396c>] apic_timer_interrupt+0x1c/0x24 (24)
BUG: auditd:3587, possible softlockup detected on CPU#3!
[<c0144448>] softlockup_detected+0x39/0x46 (8)
[<c0144526>] softlockup_tick+0xd1/0xd3 (20)
[<c01112c7>] smp_apic_timer_interrupt+0xc0/0xcc (24)
[<c010396c>] apic_timer_interrupt+0x1c/0x24 (24)


-Dinakar

2005-10-04 18:11:34

by Mark Knecht

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On 10/4/05, Mark Knecht <[email protected]> wrote:
> On 10/4/05, Ingo Molnar <[email protected]> wrote:
<SNIP>
> >
> > ugh. uploaded -rt6.
> >
> > Ingo
>
> Hi Ingo,
> OK, I'm up and running 2.6.14-rc3-rt7. I see no run-time problems yet...
<SNIP>

I have now had one burst of xruns. As best I can tell I was
downloading some video files for mplayer to look at, or possibly
running one of them. I see this in qjackctl:

configuring for 44100Hz, period = 128 frames, buffer = 2 periods
nperiods = 2 for capture
nperiods = 2 for playback
09:59:12.079 Server configuration saved to "/home/mark/.jackdrc".
09:59:12.079 Statistics reset.
09:59:12.224 Client activated.
09:59:12.226 Audio connection change.
09:59:12.242 Audio connection graph change.
09:59:17.819 Audio connection graph change.
09:59:17.927 Audio connection change.
09:59:19.985 Audio connection graph change.
10:09:22.377 XRUN callback (1).
**** alsa_pcm: xrun of at least 0.336 msecs
10:09:28.450 XRUN callback (2).
**** alsa_pcm: xrun of at least 0.306 msecs
10:11:33.241 XRUN callback (3).
**** alsa_pcm: xrun of at least 4.058 msecs
subgraph starting at qjackctl-8560 timed out (subgraph_wait_fd=17,
status = 0, state = Finished)
10:12:02.490 XRUN callback (4).
**** alsa_pcm: xrun of at least 3.135 msecs
subgraph starting at qjackctl-8560 timed out (subgraph_wait_fd=17,
status = 0, state = Finished)
10:16:22.910 XRUN callback (5).
**** alsa_pcm: xrun of at least 1.848 msecs

There have been no more xruns since that burst about an hour ago.

Looking in the logs there is a suspicious 1394 access problem:

Oct 4 10:00:40 lightning ieee1394.agent[8630]: ... no drivers for
IEEE1394 product 0x/0x/0x
Oct 4 10:04:32 lightning kjournald starting. Commit interval 5 seconds
Oct 4 10:04:32 lightning EXT3 FS on sdc2, internal journal
Oct 4 10:04:32 lightning EXT3-fs: mounted filesystem with ordered data mode.
Oct 4 10:09:05 lightning attempt to access beyond end of device
Oct 4 10:09:05 lightning sdb1: rw=0, want=5621502224, limit=117210177
Oct 4 10:09:05 lightning attempt to access beyond end of device
Oct 4 10:09:05 lightning sdb1: rw=0, want=8263631504, limit=117210177
Oct 4 10:09:05 lightning attempt to access beyond end of device
Oct 4 10:09:05 lightning sdb1: rw=0, want=27135269176, limit=117210177
Oct 4 10:09:05 lightning attempt to access beyond end of device
Oct 4 10:09:05 lightning sdb1: rw=0, want=25260813976, limit=117210177
Oct 4 10:09:05 lightning attempt to access beyond end of device
Oct 4 10:09:05 lightning sdb1: rw=0, want=5621502224, limit=117210177
Oct 4 10:10:02 lightning cron[8737]: (root) CMD (test -x
/usr/sbin/run-crons && /usr/sbin/run-crons )
Oct 4 10:20:01 lightning cron[8762]: (root) CMD (test -x
/usr/sbin/run-crons && /usr/sbin/run-crons )
Oct 4 10:30:01 lightning cron[8800]: (root) CMD (test -x
/usr/sbin/run-crons && /usr/sbin/run-crons )
Oct 4 10:40:01 lightning cron[8847]: (root) CMD (test -x
/usr/sbin/run-crons && /usr/sbin/run-crons )


/dev/sdb1 in this case holds a 50GB ogg-based music library. It's been
streaming since I brought the kernel up.

1394 problems????

Thanks,
Mark

2005-10-04 18:19:14

by Thomas Gleixner

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Tue, 2005-10-04 at 11:11 -0700, Mark Knecht wrote:

> I have now had one burst of xruns. As best I can tell I was
> downloading some video files for mplayer to look at, or possibly
> running one of them. I see this in qjackctl:
>

I guess its related to the priority leak I'm tracking down right now.
Can you please set following config options and check if you get a bug
similar to this ?

BUG: init/1: leaked RT prio 98 (116)?

Steven, it goes away when deadlock detection is enabled. Any pointers ?

tglx


# Kernel hacking
#
# CONFIG_PRINTK_TIME is not set
# CONFIG_PRINTK_IGNORE_LOGLEVEL is not set
CONFIG_DEBUG_KERNEL=y
CONFIG_MAGIC_SYSRQ=y
CONFIG_LOG_BUF_SHIFT=17
# CONFIG_DETECT_SOFTLOCKUP is not set
# CONFIG_SCHEDSTATS is not set
# CONFIG_DEBUG_SLAB is not set
CONFIG_DEBUG_PREEMPT=y
CONFIG_DEBUG_IRQ_FLAGS=y
# CONFIG_WAKEUP_TIMING is not set
CONFIG_PREEMPT_TRACE=y
# CONFIG_CRITICAL_PREEMPT_TIMING is not set
# CONFIG_CRITICAL_IRQSOFF_TIMING is not set
# CONFIG_RT_DEADLOCK_DETECT is not set
# CONFIG_DEBUG_RT_LOCKING_MODE is not set
# CONFIG_DEBUG_KOBJECT is not set
CONFIG_DEBUG_BUGVERBOSE=y
CONFIG_DEBUG_INFO=y
# CONFIG_DEBUG_FS is not set
# CONFIG_USE_FRAME_POINTER is not set
# CONFIG_EARLY_PRINTK is not set
# CONFIG_DEBUG_STACKOVERFLOW is not set
# CONFIG_KPROBES is not set
# CONFIG_DEBUG_STACK_USAGE is not set
# CONFIG_DEBUG_PAGEALLOC is not set
# CONFIG_4KSTACKS is not set
CONFIG_X86_FIND_SMP_CONFIG=y
CONFIG_X86_MPPARSE=y


2005-10-04 18:27:51

by Daniel Walker

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Tue, 2005-10-04 at 23:41 +0530, Dinakar Guniguntala wrote:
> On Tue, Oct 04, 2005 at 10:54:30AM -0700, Daniel Walker wrote:
> > On Tue, 2005-10-04 at 23:28 +0530, Dinakar Guniguntala wrote:
> >
> > > Nope doesnt help. I booted with this code change and I get the
> > > same message.
> > >
> > > I saw that the code change is in #ifdef CONFIG_HIGH_RES_TIMERS.
> > > I have already disabled CONFIG_HIGH_RES_TIMERS as Thomas Gleixner
> > > suggested
> >
> > Which code is #ifdef'd ?
>
> Your code was in function smp_apic_timer_ipi_interrupt (right?) that
> is under CONFIG_HIGH_RES_TIMERS which was disabled.

Yeah, I see what your saying now ..

> >
> > Is there any diversity in these messages , or is it always the same? Is
> > the CPU# ever different?
> >
>
> Sorry I should have put this up before.
>
>
> BUG: auditd:3587, possible softlockup detected on CPU#2!
> [<c0144448>] softlockup_detected+0x39/0x46 (8)
> [<c0144526>] softlockup_tick+0xd1/0xd3 (20)
> [<c01112c7>] smp_apic_timer_interrupt+0xc0/0xcc (24)
> [<c010396c>] apic_timer_interrupt+0x1c/0x24 (24)
> [<c0102e8a>] sysenter_past_esp+0x2f/0x75 (44)

This patch should handle both cases . I would think if this doesn't
silence it, then it's something else..

Index: linux-2.6.13/arch/i386/kernel/apic.c
===================================================================
--- linux-2.6.13.orig/arch/i386/kernel/apic.c
+++ linux-2.6.13/arch/i386/kernel/apic.c
@@ -1153,6 +1153,14 @@ fastcall notrace void smp_apic_timer_ipi
#if 0
profile_tick(CPU_PROFILING, regs);
#endif
+ /*
+ * If the task is currently running in user mode, don't
+ * detect soft lockups. If CONFIG_DETECT_SOFTLOCKUP is not
+ * configured, this should be optimized out.
+ */
+ if (user_mode(regs))
+ touch_light_softlockup_watchdog();
+
update_process_times(user_mode_vm(regs));
irq_exit();

@@ -1247,6 +1255,14 @@ inline void smp_local_timer_interrupt(st
per_cpu(prof_counter, cpu);
}
#ifdef CONFIG_SMP
+ /*
+ * If the task is currently running in user mode, don't
+ * detect soft lockups. If CONFIG_DETECT_SOFTLOCKUP is not
+ * configured, this should be optimized out.
+ */
+ if (user_mode(regs))
+ touch_light_softlockup_watchdog();
+
update_process_times(user_mode_vm(regs));
#endif
}


2005-10-04 18:58:47

by Mark Knecht

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On 10/4/05, Thomas Gleixner <[email protected]> wrote:
> On Tue, 2005-10-04 at 11:11 -0700, Mark Knecht wrote:
>
> > I have now had one burst of xruns. As best I can tell I was
> > downloading some video files for mplayer to look at, or possibly
> > running one of them. I see this in qjackctl:
> >
>
> I guess its related to the priority leak I'm tracking down right now.
> Can you please set following config options and check if you get a bug
> similar to this ?
>
> BUG: init/1: leaked RT prio 98 (116)?
>
> Steven, it goes away when deadlock detection is enabled. Any pointers ?
>
> tglx
>
>
> # Kernel hacking
> #
> # CONFIG_PRINTK_TIME is not set
> # CONFIG_PRINTK_IGNORE_LOGLEVEL is not set
> CONFIG_DEBUG_KERNEL=y
> CONFIG_MAGIC_SYSRQ=y
> CONFIG_LOG_BUF_SHIFT=17
> # CONFIG_DETECT_SOFTLOCKUP is not set
> # CONFIG_SCHEDSTATS is not set
> # CONFIG_DEBUG_SLAB is not set
> CONFIG_DEBUG_PREEMPT=y
> CONFIG_DEBUG_IRQ_FLAGS=y
> # CONFIG_WAKEUP_TIMING is not set
> CONFIG_PREEMPT_TRACE=y
> # CONFIG_CRITICAL_PREEMPT_TIMING is not set
> # CONFIG_CRITICAL_IRQSOFF_TIMING is not set
> # CONFIG_RT_DEADLOCK_DETECT is not set
> # CONFIG_DEBUG_RT_LOCKING_MODE is not set
> # CONFIG_DEBUG_KOBJECT is not set
> CONFIG_DEBUG_BUGVERBOSE=y
> CONFIG_DEBUG_INFO=y
> # CONFIG_DEBUG_FS is not set
> # CONFIG_USE_FRAME_POINTER is not set
> # CONFIG_EARLY_PRINTK is not set
> # CONFIG_DEBUG_STACKOVERFLOW is not set
> # CONFIG_KPROBES is not set
> # CONFIG_DEBUG_STACK_USAGE is not set
> # CONFIG_DEBUG_PAGEALLOC is not set
> # CONFIG_4KSTACKS is not set
> CONFIG_X86_FIND_SMP_CONFIG=y
> CONFIG_X86_MPPARSE=y

Strange, but I don't have all the config options that you have, or I
cannot yet find the right things to turn them on. Specifically I'm
missing

> CONFIG_DEBUG_BUGVERBOSE=y
> CONFIG_DEBUG_INFO=y
<SNIP>
> CONFIG_X86_FIND_SMP_CONFIG=y
> CONFIG_X86_MPPARSE=y

#
My current Kernel hacking section:

#
# Kernel hacking
#
# CONFIG_PRINTK_TIME is not set
# CONFIG_PRINTK_IGNORE_LOGLEVEL is not set
CONFIG_DEBUG_KERNEL=y
CONFIG_MAGIC_SYSRQ=y
CONFIG_LOG_BUF_SHIFT=17
# CONFIG_DETECT_SOFTLOCKUP is not set
# CONFIG_SCHEDSTATS is not set
# CONFIG_DEBUG_SLAB is not set
CONFIG_DEBUG_PREEMPT=y
CONFIG_DEBUG_IRQ_FLAGS=y
# CONFIG_WAKEUP_TIMING is not set
CONFIG_PREEMPT_TRACE=y
# CONFIG_CRITICAL_PREEMPT_TIMING is not set
# CONFIG_CRITICAL_IRQSOFF_TIMING is not set
# CONFIG_RT_DEADLOCK_DETECT is not set
# CONFIG_DEBUG_RT_LOCKING_MODE is not set
# CONFIG_DEBUG_KOBJECT is not set
# CONFIG_DEBUG_INFO is not set
# CONFIG_DEBUG_FS is not set
# CONFIG_USE_FRAME_POINTER is not set
# CONFIG_INIT_DEBUG is not set
# CONFIG_IOMMU_DEBUG is not set
# CONFIG_KPROBES is not set

I'll build this way for now. Send back some info on what you think I
need to turn on. I'm using make menuconfig. Maybe that's the problem?

Thanks,
Mark

2005-10-04 19:55:29

by Dinakar Guniguntala

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Tue, Oct 04, 2005 at 11:27:46AM -0700, Daniel Walker wrote:
>
> This patch should handle both cases . I would think if this doesn't
> silence it, then it's something else..


Daniel, This works for me !
Thanks for fixing this

-Dinakar


>
> Index: linux-2.6.13/arch/i386/kernel/apic.c
> ===================================================================
> --- linux-2.6.13.orig/arch/i386/kernel/apic.c
> +++ linux-2.6.13/arch/i386/kernel/apic.c
> @@ -1153,6 +1153,14 @@ fastcall notrace void smp_apic_timer_ipi
> #if 0
> profile_tick(CPU_PROFILING, regs);
> #endif
> + /*
> + * If the task is currently running in user mode, don't
> + * detect soft lockups. If CONFIG_DETECT_SOFTLOCKUP is not
> + * configured, this should be optimized out.
> + */
> + if (user_mode(regs))
> + touch_light_softlockup_watchdog();
> +
> update_process_times(user_mode_vm(regs));
> irq_exit();
>
> @@ -1247,6 +1255,14 @@ inline void smp_local_timer_interrupt(st
> per_cpu(prof_counter, cpu);
> }
> #ifdef CONFIG_SMP
> + /*
> + * If the task is currently running in user mode, don't
> + * detect soft lockups. If CONFIG_DETECT_SOFTLOCKUP is not
> + * configured, this should be optimized out.
> + */
> + if (user_mode(regs))
> + touch_light_softlockup_watchdog();
> +
> update_process_times(user_mode_vm(regs));
> #endif
> }
>
>

2005-10-04 20:38:32

by Mark Knecht

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On 10/4/05, Thomas Gleixner <[email protected]> wrote:
> On Tue, 2005-10-04 at 11:11 -0700, Mark Knecht wrote:
>
> > I have now had one burst of xruns. As best I can tell I was
> > downloading some video files for mplayer to look at, or possibly
> > running one of them. I see this in qjackctl:
> >
>
> I guess its related to the priority leak I'm tracking down right now.
> Can you please set following config options and check if you get a bug
> similar to this ?
>
> BUG: init/1: leaked RT prio 98 (116)?
>

Thomas,
As per the config options I could actually get turned on I see
something different:

Detected 12.564 MHz APIC timer.
Brought up 1 CPUs
time.c: Using PIT/TSC based timekeeping.
testing NMI watchdog ... OK.
NET: Registered protocol family 16
ACPI: bus type pci registered
PCI: Using configuration type 1
PCI: Using MMCONFIG at e0000000
ACPI: Subsystem revision 20050902
BUG: swapper/1: spin-unlock irq flags assymetry?

Call Trace:<ffffffff80400e59>{_spin_unlock_irqrestore+89}
<ffffffff802695f6>{acpi_ev_create_gpe_block+642}
<ffffffff80263236>{acpi_os_wait_semaphore+135}
<ffffffff802697a2>{acpi_ev_gpe_initialize+109}
<ffffffff80266dcc>{acpi_ev_initialize_events+151}
<ffffffff802791c2>{acpi_enable_subsystem+69}
<ffffffff806086de>{acpi_init+86} <ffffffff80604cda>{init_bio+266}
<ffffffff8010b25a>{init+506} <ffffffff8010ed16>{child_rip+8}
<ffffffff8010b060>{init+0} <ffffffff8010ed0e>{child_rip+0}

---------------------------
| preempt count: 00000000 ]
| 0-level deep critical section nesting:
----------------------------------------

WARNING: swapper/1 changed soft IRQ-flags.

Call Trace:<ffffffff801534ea>{local_irq_enable+26}
<ffffffff80400e65>{_spin_unlock_irqrestore+101}
<ffffffff802695f6>{acpi_ev_create_gpe_block+642}
<ffffffff80263236>{acpi_os_wait_semaphore+135}
<ffffffff802697a2>{acpi_ev_gpe_initialize+109}
<ffffffff80266dcc>{acpi_ev_initialize_events+151}
<ffffffff802791c2>{acpi_enable_subsystem+69}
<ffffffff806086de>{acpi_init+86}
<ffffffff80604cda>{init_bio+266} <ffffffff8010b25a>{init+506}
<ffffffff8010ed16>{child_rip+8} <ffffffff8010b060>{init+0}
<ffffffff8010ed0e>{child_rip+0}
---------------------------
| preempt count: 00000000 ]
| 0-level deep critical section nesting:
----------------------------------------

ACPI: Interpreter enabled
ACPI: Using IOAPIC for interrupt routing
ACPI: PCI Root Bridge [PCI0] (0000:00)
PCI: Probing PCI hardware (bus 00)

I'll do a bit more testing and wait to hear about the data above.

Cheers,
Mark

2005-10-04 20:43:52

by Thomas Gleixner

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Tue, 2005-10-04 at 11:58 -0700, Mark Knecht wrote:
> > I guess its related to the priority leak I'm tracking down right now.
> > Can you please set following config options and check if you get a bug
> > similar to this ?
> >
> > BUG: init/1: leaked RT prio 98 (116)?
> >
> > Steven, it goes away when deadlock detection is enabled. Any pointers

Thats actually a red hering caused by asymetric accounting which only
happens when

CONFIG_DEBUG_PREEMPT=y
and
# CONFIG_RT_DEADLOCK_DETECT is not set

tglx


Index: linux-2.6.14-rc3-rt8-ep/kernel/rt.c
===================================================================
--- linux-2.6.14-rc3-rt8-ep.orig/kernel/rt.c
+++ linux-2.6.14-rc3-rt8-ep/kernel/rt.c
@@ -295,6 +295,21 @@ void check_preempt_wakeup(struct task_st
dump_stack();
}
}
+
+static inline void account_mutex_owner_down(struct rt_mutex *lock)
+{
+ current->owned_lock[current->lock_count] = lock;
+ current->lock_count++;
+}
+
+static inline void account_mutex_owner_up(struct rt_mutex *lock)
+{
+ current->lock_count--;
+ current->owned_lock[current->lock_count] = NULL;
+}
+
+#else
+#define account_mutex_owner(l) do { } while(0)
#endif

#ifdef CONFIG_RT_DEADLOCK_DETECT
@@ -1241,13 +1256,13 @@ static int __grab_lock(struct rt_mutex *
list_del_init(&lock->held_list);
#endif
#if defined(CONFIG_DEBUG_PREEMPT) && defined(CONFIG_PREEMPT_RT)
+ owner->lock_count--;
if (owner->lock_count < 0 || owner->lock_count >= MAX_LOCK_STACK) {
TRACE_OFF();
printk("BUG: %s/%d: lock count of %u\n",
owner->comm, owner->pid, owner->lock_count);
dump_stack();
}
- owner->lock_count--;
owner->owned_lock[owner->lock_count] = NULL;
#endif
return 1;
@@ -1579,13 +1594,13 @@ ____up_mutex(struct rt_mutex *lock, int
lock->owner = NULL;
_raw_spin_unlock(&lock->wait_lock);
#if defined(CONFIG_DEBUG_PREEMPT) && defined(CONFIG_PREEMPT_RT)
+ current->lock_count--;
if (current->lock_count < 0 || current->lock_count >= MAX_LOCK_STACK) {
TRACE_OFF();
printk("BUG: %s/%d: lock count of %u\n",
current->comm, current->pid, current->lock_count);
dump_stack();
}
- current->lock_count--;
current->owned_lock[current->lock_count] = NULL;
if (!current->lock_count && !rt_prio(current->normal_prio) &&
rt_prio(current->prio)) {
@@ -1638,6 +1653,8 @@ static inline void __down_mutex_inline(s

if (unlikely(cmpxchg(&lock->owner, NULL, ti)))
___down_mutex(lock __EIP__);
+ else
+ account_mutex_owner_down(lock);
}

static inline void __down_inline(struct rt_mutex *lock __EIP_DECL__)
@@ -1646,6 +1663,8 @@ static inline void __down_inline(struct

if (unlikely(cmpxchg(&lock->owner, NULL, ti)))
___down(lock __EIP__);
+ else
+ account_mutex_owner_down(lock);
}

void __sched __down_mutex(struct rt_mutex *lock __EIP_DECL__)
@@ -1697,6 +1716,8 @@ static inline void

if (unlikely(cmpxchg(&lock->owner, ti, NULL) != ti))
___up_mutex_savestate(lock __EIP__);
+ else
+ account_mutex_owner_up(lock);
}

void __sched __up_mutex_savestate(struct rt_mutex *lock __EIP_DECL__)
@@ -1711,6 +1732,8 @@ __up_mutex_nosavestate_inline(struct rt_

if (unlikely(cmpxchg(&lock->owner, ti, NULL) != ti))
___up_mutex_nosavestate(lock __EIP__);
+ else
+ account_mutex_owner_up(lock);
}

void __sched __up_mutex_nosavestate(struct rt_mutex *lock __EIP_DECL__)
@@ -2869,6 +2892,9 @@ void fastcall rt_mutex_set_owner(struct
*/
#ifdef CONFIG_DEBUG_PREEMPT
current->lock_count--;
+ current->owned_lock[current->lock_count] = NULL;
+ t->task->owned_lock[t->task->lock_count] = lock;
+ t->task->lock_count++;
#endif
lock->owner = t;
}



2005-10-04 20:49:46

by Thomas Gleixner

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Tue, 2005-10-04 at 22:45 +0200, Thomas Gleixner wrote:
> On Tue, 2005-10-04 at 11:58 -0700, Mark Knecht wrote:
> > > I guess its related to the priority leak I'm tracking down right now.
> > > Can you please set following config options and check if you get a bug
> > > similar to this ?
> > >
> > > BUG: init/1: leaked RT prio 98 (116)?
> > >
> > > Steven, it goes away when deadlock detection is enabled. Any pointers
>
> Thats actually a red hering caused by asymetric accounting which only
> happens when
>
> CONFIG_DEBUG_PREEMPT=y
> and
> # CONFIG_RT_DEADLOCK_DETECT is not set

Sorry, did not refresh before sending

tglx

---

Index: linux-2.6.14-rc3-rt8-ep/kernel/rt.c
===================================================================
--- linux-2.6.14-rc3-rt8-ep.orig/kernel/rt.c
+++ linux-2.6.14-rc3-rt8-ep/kernel/rt.c
@@ -295,6 +295,22 @@ void check_preempt_wakeup(struct task_st
dump_stack();
}
}
+
+static inline void account_mutex_owner_down(struct rt_mutex *lock)
+{
+ current->owned_lock[current->lock_count] = lock;
+ current->lock_count++;
+}
+
+static inline void account_mutex_owner_up(struct rt_mutex *lock)
+{
+ current->lock_count--;
+ current->owned_lock[current->lock_count] = NULL;
+}
+
+#else
+#define account_mutex_owner_down(l) do { } while(0)
+#define account_mutex_owner_up(l) do { } while(0)
#endif

#ifdef CONFIG_RT_DEADLOCK_DETECT
@@ -1241,13 +1257,13 @@ static int __grab_lock(struct rt_mutex *
list_del_init(&lock->held_list);
#endif
#if defined(CONFIG_DEBUG_PREEMPT) && defined(CONFIG_PREEMPT_RT)
+ owner->lock_count--;
if (owner->lock_count < 0 || owner->lock_count >= MAX_LOCK_STACK) {
TRACE_OFF();
printk("BUG: %s/%d: lock count of %u\n",
owner->comm, owner->pid, owner->lock_count);
dump_stack();
}
- owner->lock_count--;
owner->owned_lock[owner->lock_count] = NULL;
#endif
return 1;
@@ -1579,13 +1595,13 @@ ____up_mutex(struct rt_mutex *lock, int
lock->owner = NULL;
_raw_spin_unlock(&lock->wait_lock);
#if defined(CONFIG_DEBUG_PREEMPT) && defined(CONFIG_PREEMPT_RT)
+ current->lock_count--;
if (current->lock_count < 0 || current->lock_count >= MAX_LOCK_STACK) {
TRACE_OFF();
printk("BUG: %s/%d: lock count of %u\n",
current->comm, current->pid, current->lock_count);
dump_stack();
}
- current->lock_count--;
current->owned_lock[current->lock_count] = NULL;
if (!current->lock_count && !rt_prio(current->normal_prio) &&
rt_prio(current->prio)) {
@@ -1638,6 +1654,8 @@ static inline void __down_mutex_inline(s

if (unlikely(cmpxchg(&lock->owner, NULL, ti)))
___down_mutex(lock __EIP__);
+ else
+ account_mutex_owner_down(lock);
}

static inline void __down_inline(struct rt_mutex *lock __EIP_DECL__)
@@ -1646,6 +1664,8 @@ static inline void __down_inline(struct

if (unlikely(cmpxchg(&lock->owner, NULL, ti)))
___down(lock __EIP__);
+ else
+ account_mutex_owner_down(lock);
}

void __sched __down_mutex(struct rt_mutex *lock __EIP_DECL__)
@@ -1697,6 +1717,8 @@ static inline void

if (unlikely(cmpxchg(&lock->owner, ti, NULL) != ti))
___up_mutex_savestate(lock __EIP__);
+ else
+ account_mutex_owner_up(lock);
}

void __sched __up_mutex_savestate(struct rt_mutex *lock __EIP_DECL__)
@@ -1711,6 +1733,8 @@ __up_mutex_nosavestate_inline(struct rt_

if (unlikely(cmpxchg(&lock->owner, ti, NULL) != ti))
___up_mutex_nosavestate(lock __EIP__);
+ else
+ account_mutex_owner_up(lock);
}

void __sched __up_mutex_nosavestate(struct rt_mutex *lock __EIP_DECL__)
@@ -2869,6 +2893,9 @@ void fastcall rt_mutex_set_owner(struct
*/
#ifdef CONFIG_DEBUG_PREEMPT
current->lock_count--;
+ current->owned_lock[current->lock_count] = NULL;
+ t->task->owned_lock[t->task->lock_count] = lock;
+ t->task->lock_count++;
#endif
lock->owner = t;
}


2005-10-04 20:49:12

by Mark Knecht

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On 10/4/05, Thomas Gleixner <[email protected]> wrote:
> On Tue, 2005-10-04 at 11:58 -0700, Mark Knecht wrote:
> > > I guess its related to the priority leak I'm tracking down right now.
> > > Can you please set following config options and check if you get a bug
> > > similar to this ?
> > >
> > > BUG: init/1: leaked RT prio 98 (116)?
> > >
> > > Steven, it goes away when deadlock detection is enabled. Any pointers
>
> Thats actually a red hering caused by asymetric accounting which only
> happens when
>
> CONFIG_DEBUG_PREEMPT=y
> and
> # CONFIG_RT_DEADLOCK_DETECT is not set

OK. I'll keep testing then.

Are you asking me to apply the code you sent or is that for someone else?

Thanks,
Mark

2005-10-04 20:52:25

by Thomas Gleixner

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Tue, 2005-10-04 at 13:49 -0700, Mark Knecht wrote:
> On 10/4/05, Thomas Gleixner <[email protected]> wrote:
> > On Tue, 2005-10-04 at 11:58 -0700, Mark Knecht wrote:
> > > > I guess its related to the priority leak I'm tracking down right now.
> > > > Can you please set following config options and check if you get a bug
> > > > similar to this ?
> > > >
> > > > BUG: init/1: leaked RT prio 98 (116)?
> > > >
> > > > Steven, it goes away when deadlock detection is enabled. Any pointers
> >
> > Thats actually a red hering caused by asymetric accounting which only
> > happens when
> >
> > CONFIG_DEBUG_PREEMPT=y
> > and
> > # CONFIG_RT_DEADLOCK_DETECT is not set
>
> OK. I'll keep testing then.
>
> Are you asking me to apply the code you sent or is that for someone else?

Please apply, but the second version I sent :(

Pilot error. Will not solve the other problem you are seeing. Looking
into this right now.

tglx


2005-10-04 21:21:10

by Mark Knecht

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On 10/4/05, Thomas Gleixner <[email protected]> wrote:
> On Tue, 2005-10-04 at 13:49 -0700, Mark Knecht wrote:
> > On 10/4/05, Thomas Gleixner <[email protected]> wrote:
> > > On Tue, 2005-10-04 at 11:58 -0700, Mark Knecht wrote:
> > > > > I guess its related to the priority leak I'm tracking down right now.
> > > > > Can you please set following config options and check if you get a bug
> > > > > similar to this ?
> > > > >
> > > > > BUG: init/1: leaked RT prio 98 (116)?
> > > > >
> > > > > Steven, it goes away when deadlock detection is enabled. Any pointers
> > >
> > > Thats actually a red hering caused by asymetric accounting which only
> > > happens when
> > >
> > > CONFIG_DEBUG_PREEMPT=y
> > > and
> > > # CONFIG_RT_DEADLOCK_DETECT is not set
> >
> > OK. I'll keep testing then.
> >
> > Are you asking me to apply the code you sent or is that for someone else?
>
> Please apply, but the second version I sent :(
>
> Pilot error. Will not solve the other problem you are seeing. Looking
> into this right now.
>
> tglx

Will try. I'm a guitar player, nopt a developer.

Save it as a file.
patch -p1 --dry-run <patch-file

(or maybe p0?)

I'll give it a shot.

Thanks,
Mark

2005-10-05 07:12:30

by Steven Rostedt

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


First, Please don't send to my kihontech.com account. That's my email
that my customers use and I would really like to keep the spam noise down
an that account. Thanks!

On Tue, 4 Oct 2005, Thomas Gleixner wrote:

> On Tue, 2005-10-04 at 11:58 -0700, Mark Knecht wrote:
> > > I guess its related to the priority leak I'm tracking down right now.
> > > Can you please set following config options and check if you get a bug
> > > similar to this ?
> > >
> > > BUG: init/1: leaked RT prio 98 (116)?
> > >
> > > Steven, it goes away when deadlock detection is enabled. Any pointers
>
> Thats actually a red hering caused by asymetric accounting which only
> happens when
>
> CONFIG_DEBUG_PREEMPT=y
> and
> # CONFIG_RT_DEADLOCK_DETECT is not set
>

Yep, I was going let you know but it seems you already figured it out :-)
The CONFIG_RT_DEADLOCK_DETECT turns on the trace_lock which makes all
locks run serially. Without CONFIG_RT_DEADLOCK_DETECT, the importance of
the pi_lock of the task is greater. So If something was changed that
didn't properly lock the pi_lock, then there could be problems with the
locking.

So looking at the patch you sent, are you saying that the leak was a false
positive?

I'm just starting to look at -rt7, and will be testing it today.

-- Steve

2005-10-05 07:39:37

by Ingo Molnar

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


* Steven Rostedt <[email protected]> wrote:

> Also the inclusion of ktimer (I believe) has made a dependency with
> mpparse and IO_APIC. Since now mpparse.c calls setup_IO_APIC_early
> which is defined only if X86_IO_APIC is, the kernel wont link without.
> So, is the following patch sufficient? Or does mpparse.c need to be
> different, that is should we not call setup_IO_APIC_early if
> X86_IO_APIC is not set?

> config X86_MPPARSE
> bool
> - depends on X86_LOCAL_APIC && !X86_VISWS
> + depends on X86_LOCAL_APIC && X86_IO_APIC && !X86_VISWS
> default y

thanks, applied.

Ingo

2005-10-05 07:37:11

by Ingo Molnar

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


* Dinakar Guniguntala <[email protected]> wrote:

> On Tue, Oct 04, 2005 at 11:27:46AM -0700, Daniel Walker wrote:
> >
> > This patch should handle both cases . I would think if this doesn't
> > silence it, then it's something else..
>
>
> Daniel, This works for me !
> Thanks for fixing this

great - i have applied it to my tree.

Ingo

2005-10-05 07:40:38

by Ingo Molnar

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


* Thomas Gleixner <[email protected]> wrote:

> > > BUG: init/1: leaked RT prio 98 (116)?
> > >
> > > Steven, it goes away when deadlock detection is enabled. Any pointers
>
> Thats actually a red hering caused by asymetric accounting which only
> happens when
>
> CONFIG_DEBUG_PREEMPT=y
> and
> # CONFIG_RT_DEADLOCK_DETECT is not set

> #if defined(CONFIG_DEBUG_PREEMPT) && defined(CONFIG_PREEMPT_RT)
> + owner->lock_count--;
> if (owner->lock_count < 0 || owner->lock_count >= MAX_LOCK_STACK) {
> TRACE_OFF();
> printk("BUG: %s/%d: lock count of %u\n",
> owner->comm, owner->pid, owner->lock_count);
> dump_stack();
> }
> - owner->lock_count--;
> owner->owned_lock[owner->lock_count] = NULL;

ouch. Brown paperbag for me! Patch applied.

Ingo

2005-10-05 10:55:35

by Ingo Molnar

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


* Mark Knecht <[email protected]> wrote:

> On 10/4/05, Thomas Gleixner <[email protected]> wrote:
> > On Tue, 2005-10-04 at 11:58 -0700, Mark Knecht wrote:
> > > > I guess its related to the priority leak I'm tracking down right now.
> > > > Can you please set following config options and check if you get a bug
> > > > similar to this ?
> > > >
> > > > BUG: init/1: leaked RT prio 98 (116)?
> > > >
> > > > Steven, it goes away when deadlock detection is enabled. Any pointers
> >
> > Thats actually a red hering caused by asymetric accounting which only
> > happens when
> >
> > CONFIG_DEBUG_PREEMPT=y
> > and
> > # CONFIG_RT_DEADLOCK_DETECT is not set
>
> OK. I'll keep testing then.
>
> Are you asking me to apply the code you sent or is that for someone
> else?

could you try the -rt8 kernel, with the same .config that previously
produced those messages - do the messages still occur?

Ingo

2005-10-05 13:37:11

by Steven Rostedt

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


Hi Ingo,

I just notice that I get the following output:

BUG: gdm:4351 task might have lost a preemption check!
[<c010433f>] dump_stack+0x1f/0x30 (20)
[<c011c06f>] preempt_enable_no_resched+0x5f/0x70 (20)
[<c011b6c9>] sys_sched_yield+0x69/0xb0 (24)
[<c01033d6>] syscall_call+0x7/0xb (-8116)
---------------------------
| preempt count: 00000000 ]
| 0-level deep critical section nesting:
----------------------------------------

------------------------------
| showing all locks held by: | (gdm/4351 [dbb727a0, 118]):
------------------------------


I looked at this a little and the offending code is here in
sys_sched_yield:

/*
* Since we are going to call schedule() anyway, there's
* no need to preempt or enable interrupts:
*/
spin_unlock_no_resched(&rq->lock);

__schedule();

So what's the reason for the message? Is it to detect when a preemption
count goes to zero and isn't rescheduled? At least in this part of the
kernel it's ok because it is just about to call schedule. So is there
some way to flag this call to not produce the message? Since the message
is only outputed once, it seems useless if it only gets outputted on a
false positive.

-- Steve


2005-10-05 14:30:04

by Steven Rostedt

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

Hmm, Ingo,

Do you know why time goes backwards when I run hackbench as a realtime
process? I added the output of start and stop and it does seem to go
backwards.

Thomas?

Oh and this is with -rt8.

-- Steve



2005-10-05 14:41:06

by Ingo Molnar

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


* Steven Rostedt <[email protected]> wrote:

> Hi Ingo,
>
> I just notice that I get the following output:
>
> BUG: gdm:4351 task might have lost a preemption check!
> [<c010433f>] dump_stack+0x1f/0x30 (20)
> [<c011c06f>] preempt_enable_no_resched+0x5f/0x70 (20)
> [<c011b6c9>] sys_sched_yield+0x69/0xb0 (24)
> [<c01033d6>] syscall_call+0x7/0xb (-8116)
> ---------------------------
> | preempt count: 00000000 ]
> | 0-level deep critical section nesting:
> ----------------------------------------
>
> ------------------------------
> | showing all locks held by: | (gdm/4351 [dbb727a0, 118]):
> ------------------------------
>
>
> I looked at this a little and the offending code is here in
> sys_sched_yield:
>
> /*
> * Since we are going to call schedule() anyway, there's
> * no need to preempt or enable interrupts:
> */
> spin_unlock_no_resched(&rq->lock);
>
> __schedule();
>
> So what's the reason for the message? Is it to detect when a
> preemption count goes to zero and isn't rescheduled? At least in this
> part of the kernel it's ok because it is just about to call schedule.
> So is there some way to flag this call to not produce the message?
> Since the message is only outputed once, it seems useless if it only
> gets outputted on a false positive.

the patch below should solve this. I've added the warning to
preempt_enable_no_resched() because we had bugs in this area, and i
wanted to have a chance to review all 'potentially problematic' places.
So i'm changing them to __preempt_enable_no_resched() when they turn out
to be safe. (In the future we'll likely remove the debugging message and
get rid of __preempt_enable_no_resched().)

Ingo

Index: linux/include/linux/spinlock_api_up.h
===================================================================
--- linux.orig/include/linux/spinlock_api_up.h
+++ linux/include/linux/spinlock_api_up.h
@@ -45,7 +45,7 @@
do { preempt_enable(); __release(lock); (void)(lock); } while (0)

#define __UNLOCK_NO_RESCHED(lock) \
- do { preempt_enable_no_resched(); __release(lock); (void)(lock); } while (0)
+ do { __preempt_enable_no_resched(); __release(lock); (void)(lock); } while (0)

#define __UNLOCK_BH(lock) \
do { preempt_enable_no_resched(); local_bh_enable(); __release(lock); (void)(lock); } while (0)

2005-10-05 14:48:56

by Thomas Gleixner

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Wed, 2005-10-05 at 03:12 -0400, Steven Rostedt wrote:
> First, Please don't send to my kihontech.com account. That's my email
> that my customers use and I would really like to keep the spam noise down
> an that account. Thanks!

Sorry. Fixed

>
> So looking at the patch you sent, are you saying that the leak was a false
> positive?

Right. The task->lock_count accounting was screwed.

tglx


2005-10-05 15:42:38

by Daniel Walker

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Wed, 2005-10-05 at 10:29 -0400, Steven Rostedt wrote:
> Hmm, Ingo,
>
> Do you know why time goes backwards when I run hackbench as a realtime
> process? I added the output of start and stop and it does seem to go
> backwards.
>
> Thomas?
>
> Oh and this is with -rt8.

I've seen reports of this on non-RT , but SMP systems . When load goes
up gettimeofdays() will go backwards . Have you tested with RT off?

Daniel

2005-10-05 15:47:33

by Thomas Gleixner

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Wed, 2005-10-05 at 10:29 -0400, Steven Rostedt wrote:
> Hmm, Ingo,
>
> Do you know why time goes backwards when I run hackbench as a realtime
> process? I added the output of start and stop and it does seem to go
> backwards.
>
> Thomas?

Yes. Thats happening. I moved the priority of softirq-timer above
hackbench priority and the problem goes away. I look into this further.

tglx


2005-10-05 15:58:08

by David Singleton

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


On Oct 5, 2005, at 8:48 AM, Thomas Gleixner wrote:

> On Wed, 2005-10-05 at 10:29 -0400, Steven Rostedt wrote:
>> Hmm, Ingo,
>>
>> Do you know why time goes backwards when I run hackbench as a realtime
>> process? I added the output of start and stop and it does seem to go
>> backwards.
>>
>> Thomas?
>
> Yes. Thats happening. I moved the priority of softirq-timer above
> hackbench priority and the problem goes away. I look into this further.

I had to set the threaded softirqs to real time priorities with the hi
thread at 24,
the timer thread at 23, net_rx at 22, etc. I wanted their priorities
just below the IRQ threads.

The problem was the timer thread. Other real time threads got in its
way and held off timers.

And I had to make a note if any higher priority apps depended on timers
that the timer
thread had to be boosted in priority to match that real time threads
priority. It's like
the softirqd's timer thread needs priority inheritance.

David
>
> tglx
>
>

2005-10-05 15:58:31

by Ingo Molnar

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


* Thomas Gleixner <[email protected]> wrote:

> On Wed, 2005-10-05 at 10:29 -0400, Steven Rostedt wrote:
> > Hmm, Ingo,
> >
> > Do you know why time goes backwards when I run hackbench as a realtime
> > process? I added the output of start and stop and it does seem to go
> > backwards.
> >
> > Thomas?
>
> Yes. Thats happening. I moved the priority of softirq-timer above
> hackbench priority and the problem goes away. I look into this
> further.

wouldnt hackbench then permanently starve run_timer_softirq(), and
update_times() in particular?

Ingo

2005-10-05 16:08:27

by Steven Rostedt

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


On Wed, 5 Oct 2005, Ingo Molnar wrote:

>
> * Thomas Gleixner <[email protected]> wrote:
>
> > On Wed, 2005-10-05 at 10:29 -0400, Steven Rostedt wrote:
> > > Hmm, Ingo,
> > >
> > > Do you know why time goes backwards when I run hackbench as a realtime
> > > process? I added the output of start and stop and it does seem to go
> > > backwards.
> > >
> > > Thomas?
> >
> > Yes. Thats happening. I moved the priority of softirq-timer above
> > hackbench priority and the problem goes away. I look into this
> > further.
>
> wouldnt hackbench then permanently starve run_timer_softirq(), and
> update_times() in particular?
>

It seems that the problem comes down to the call to getnstimeofday in
do_gettimeofday.

void getnstimeofday(struct timespec *ts)
{
nsec_t delta;
unsigned long seq;

/* atomically read __monotonic_clock() */
do {
seq = read_seqbegin(&system_time_lock);

delta = __monotonic_clock() - xtime_last_update;
*ts = xtime_last_update_ts;

} while (read_seqretry(&system_time_lock, seq));

set_normalized_timespec(ts,
ts->tv_sec,
ts->tv_nsec + (long) delta);

}


I found that xtime_last_update is not updated while hackbench is running,
and the delta ends up being 16 billion and some change. So the call to
set_normalized_timespec overflows with the (long) delta.

-- Steve

2005-10-05 16:07:55

by Thomas Gleixner

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Wed, 2005-10-05 at 08:58 -0700, david singleton wrote:
> >
> > Yes. Thats happening. I moved the priority of softirq-timer above
> > hackbench priority and the problem goes away. I look into this further.
>
> I had to set the threaded softirqs to real time priorities with the hi
> thread at 24,
> the timer thread at 23, net_rx at 22, etc. I wanted their priorities
> just below the IRQ threads.
>
> The problem was the timer thread. Other real time threads got in its
> way and held off timers.
>
> And I had to make a note if any higher priority apps depended on timers
> that the timer
> thread had to be boosted in priority to match that real time threads
> priority. It's like
> the softirqd's timer thread needs priority inheritance.

Well, we had implemented this in one of the previous -rt versions for
the high resolution timers. It was a bit hacky and I did not come around
to reimplement it on top of ktimers. This is only a problem for itimers
and posix interval timers at the moment. The nanosleep variants do not
suffer from this problem as the wakeup happens directly from the hr
timer interrupt. That way we have only one instead of two task switches.

tglx




2005-10-05 16:13:37

by David Singleton

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


On Oct 5, 2005, at 9:08 AM, Thomas Gleixner wrote:

> On Wed, 2005-10-05 at 08:58 -0700, david singleton wrote:
>>>
>>> Yes. Thats happening. I moved the priority of softirq-timer above
>>> hackbench priority and the problem goes away. I look into this
>>> further.
>>
>> I had to set the threaded softirqs to real time priorities with the hi
>> thread at 24,
>> the timer thread at 23, net_rx at 22, etc. I wanted their
>> priorities
>> just below the IRQ threads.
>>
>> The problem was the timer thread. Other real time threads got in
>> its
>> way and held off timers.
>>
>> And I had to make a note if any higher priority apps depended on
>> timers
>> that the timer
>> thread had to be boosted in priority to match that real time threads
>> priority. It's like
>> the softirqd's timer thread needs priority inheritance.
>
> Well, we had implemented this in one of the previous -rt versions for
> the high resolution timers. It was a bit hacky and I did not come
> around
> to reimplement it on top of ktimers. This is only a problem for itimers
> and posix interval timers at the moment. The nanosleep variants do not
> suffer from this problem as the wakeup happens directly from the hr
> timer interrupt. That way we have only one instead of two task
> switches.

When I finally got the IRQ threads priorities straight and the softirqd
priorities
matched to be right underneath the IRQ priorities the system would run
any benchmark I could throw at it with no problems, modulo the strange
app that wanted to run at priority 99 and depended on itimers or
sigarlm . . .

For that case I had to match the softirq timer thread to that of the
app before
it would run with no problems.

David
>
> tglx
>
>
>
>

2005-10-05 17:14:23

by Mark Knecht

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On 10/5/05, Ingo Molnar <[email protected]> wrote:
>
> * Mark Knecht <[email protected]> wrote:
>
> > On 10/4/05, Thomas Gleixner <[email protected]> wrote:
> > > On Tue, 2005-10-04 at 11:58 -0700, Mark Knecht wrote:
> > > > > I guess its related to the priority leak I'm tracking down right now.
> > > > > Can you please set following config options and check if you get a bug
> > > > > similar to this ?
> > > > >
> > > > > BUG: init/1: leaked RT prio 98 (116)?
> > > > >
> > > > > Steven, it goes away when deadlock detection is enabled. Any pointers
> > >
> > > Thats actually a red hering caused by asymetric accounting which only
> > > happens when
> > >
> > > CONFIG_DEBUG_PREEMPT=y
> > > and
> > > # CONFIG_RT_DEADLOCK_DETECT is not set
> >
> > OK. I'll keep testing then.
> >
> > Are you asking me to apply the code you sent or is that for someone
> > else?
>
> could you try the -rt8 kernel, with the same .config that previously
> produced those messages - do the messages still occur?
>
> Ingo
>

Hi Ingo,
By the time I go there it was already -rt9. Unfortunately I still
get the same message. Possibly the continued discussion is addressing
this? I haven't tried to read it all yet.

>From dmesg:

PCI: Using configuration type 1
PCI: Using MMCONFIG at e0000000
ACPI: Subsystem revision 20050902
BUG: swapper/1: spin-unlock irq flags assymetry?

Call Trace:<ffffffff80400d19>{_spin_unlock_irqrestore+89}
<ffffffff802694d6>{acpi_ev_create_gpe_block+642}
<ffffffff80263116>{acpi_os_wait_semaphore+135}
<ffffffff80269682>{acpi_ev_gpe_initialize+109}
<ffffffff80266cac>{acpi_ev_initialize_events+151}
<ffffffff802790a2>{acpi_enable_subsystem+69}
<ffffffff806086de>{acpi_init+86} <ffffffff80604cda>{init_bio+266}
<ffffffff8010b25a>{init+506} <ffffffff8010ed16>{child_rip+8}
<ffffffff8010b060>{init+0} <ffffffff8010ed0e>{child_rip+0}

---------------------------
| preempt count: 00000000 ]
| 0-level deep critical section nesting:
----------------------------------------

WARNING: swapper/1 changed soft IRQ-flags.

Call Trace:<ffffffff8015336a>{local_irq_enable+26}
<ffffffff80400d25>{_spin_unlock_irqrestore+101}
<ffffffff802694d6>{acpi_ev_create_gpe_block+642}
<ffffffff80263116>{acpi_os_wait_semaphore+135}
<ffffffff80269682>{acpi_ev_gpe_initialize+109}
<ffffffff80266cac>{acpi_ev_initialize_events+151}
<ffffffff802790a2>{acpi_enable_subsystem+69}
<ffffffff806086de>{acpi_init+86}
<ffffffff80604cda>{init_bio+266} <ffffffff8010b25a>{init+506}
<ffffffff8010ed16>{child_rip+8} <ffffffff8010b060>{init+0}
<ffffffff8010ed0e>{child_rip+0}
---------------------------
| preempt count: 00000000 ]
| 0-level deep critical section nesting:
----------------------------------------

ACPI: Interpreter enabled
ACPI: Using IOAPIC for interrupt routing
ACPI: PCI Root Bridge [PCI0] (0000:00)
PCI: Probing PCI hardware (bus 00)
PCI: Transparent bridge - 0000:00:09.0

mark@lightning ~ $ uname -a
Linux lightning 2.6.14-rc3-rt9 #1 SMP PREEMPT Wed Oct 5 09:16:16 PDT
2005 x86_64 AMD Athlon(tm) 64 Processor 3000+ AuthenticAMD GNU/Linux
mark@lightning ~ $

The previous -rt7 kernel, even with this message, has been the best
one I've tested so far on this machine, at least for my work load.
I'll test -rt9 more starting now and will watch this thread for any
instructions or requests.

If you want or need my current config file let me know.

Cheers,
Mark

2005-10-05 20:24:46

by Esben Nielsen

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2



On Tue, 4 Oct 2005, Ingo Molnar wrote:

>
> i have released the 2.6.14-rc3-rt2 tree, which can be downloaded from
> the usual place:
>
> http://redhat.com/~mingo/realtime-preempt/
>
> the biggest change in this release is the long-anticipated merge of a
> streamlined version of the "robust futexes/mutexes with priority
> queueing and priority inheritance" code into the -rt tree. The original
> upstream patch is from Todd Kneisel, with further improvements, cleanups
> and -RT integration done by David Singleton.
>
> robustness is handled by extending the futex framework with
> registering/unregistering ops and extended wait/wake ops. Priority
> queueing and inheritance is implemented by embedding the rt_mutex object
> into the robust-futex structure. This approach made the patches
> significantly simpler and smaller (but still not trivial at all) than
> e.g. the fusyn patchset was.
>

This is great! Priority inheritance in user-space!
I try to follow this development a little when I get time. You might
already have addresses this on the list, but let me raise these two "buts"
anyway:
1) The rt_mutex can promote mutex-deadlocks to raw_spinlock deadlocks
according to the comment in the top of rt.c). Doesn't that mean that a
user-space mutex deadlock can become a raw_spinlock deadlock?
2) The PI traversal for nested interrupts is done with interrupts
disabled. I.e. you can increase the overall system latency by an arbitrary
amount of time by constructing a code with deep enough lock-nesting.

A year ago, roughly, I worked on PI-mutex for the -RT branch. I didn't
finish it fast enough for Ingo not to do his own. It was based on some of
the first principles as Ingo's. One of the ideas (which wasn't included in
the patch I send to the list) was to do the PI traversal in steps while
unlocking all the held spinlocks before going to the next depth in the
chain. I used get_task_struct() and put_task_struct() to make sure the
next task in the traversal didn't get deleted during the periods where no
locks where held.
I'll try to cook something up based on this idea, but to be honest I don't
have any time for it :-(

Esben

2005-10-06 07:54:41

by Steven Rostedt

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


On Wed, 5 Oct 2005, Mark Knecht wrote:

> Hi Ingo,
> By the time I go there it was already -rt9. Unfortunately I still
> get the same message. Possibly the continued discussion is addressing
> this? I haven't tried to read it all yet.
>
> >From dmesg:
>
> PCI: Using configuration type 1
> PCI: Using MMCONFIG at e0000000
> ACPI: Subsystem revision 20050902
> BUG: swapper/1: spin-unlock irq flags assymetry?
>
> Call Trace:<ffffffff80400d19>{_spin_unlock_irqrestore+89}
> <ffffffff802694d6>{acpi_ev_create_gpe_block+642}
> <ffffffff80263116>{acpi_os_wait_semaphore+135}
> <ffffffff80269682>{acpi_ev_gpe_initialize+109}
> <ffffffff80266cac>{acpi_ev_initialize_events+151}
> <ffffffff802790a2>{acpi_enable_subsystem+69}
> <ffffffff806086de>{acpi_init+86} <ffffffff80604cda>{init_bio+266}
> <ffffffff8010b25a>{init+506} <ffffffff8010ed16>{child_rip+8}
> <ffffffff8010b060>{init+0} <ffffffff8010ed0e>{child_rip+0}
>
> ---------------------------
> | preempt count: 00000000 ]
> | 0-level deep critical section nesting:
> ----------------------------------------
>

The acpi code is filled with macro hell (and craziness like using a void
pointer for a spinlock). Do you have the following turned on?

CONFIG_USE_FRAME_POINTER=y
CONFIG_FRAME_POINTER=y


The back trace looks a little suspicious. But I'm looking into the acpi
code to see if I can locate the bad flags.

-- Steve

2005-10-06 08:06:29

by Steven Rostedt

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


Found the problem. You're using a 64 bit machine and flags in the acpi
code is defined as u32 and not unsigned long. Ingo's tests put some
checks in the flags at the MSBs and these are being truncated.

Mark, try this patch against -rt9 and see if the problem goes away, or
at least moves. I only did the one file, and there are probable others.

-- Steve

--- linux-2.6.14-rc3-rt9/drivers/acpi/events/evgpeblk.c.orig 2005-10-06 04:00:34.000000000 -0400
+++ linux-2.6.14-rc3-rt9/drivers/acpi/events/evgpeblk.c 2005-10-06 04:00:58.000000000 -0400
@@ -136,7 +136,7 @@ acpi_status acpi_ev_walk_gpe_list(ACPI_G
struct acpi_gpe_block_info *gpe_block;
struct acpi_gpe_xrupt_info *gpe_xrupt_info;
acpi_status status = AE_OK;
- u32 flags;
+ unsigned long flags;

ACPI_FUNCTION_TRACE("ev_walk_gpe_list");

@@ -479,7 +479,7 @@ static struct acpi_gpe_xrupt_info *acpi_
struct acpi_gpe_xrupt_info *next_gpe_xrupt;
struct acpi_gpe_xrupt_info *gpe_xrupt;
acpi_status status;
- u32 flags;
+ unsigned long flags;

ACPI_FUNCTION_TRACE("ev_get_gpe_xrupt_block");

@@ -553,7 +553,7 @@ static acpi_status
acpi_ev_delete_gpe_xrupt(struct acpi_gpe_xrupt_info *gpe_xrupt)
{
acpi_status status;
- u32 flags;
+ unsigned long flags;

ACPI_FUNCTION_TRACE("ev_delete_gpe_xrupt");

@@ -610,7 +610,7 @@ acpi_ev_install_gpe_block(struct acpi_gp
struct acpi_gpe_block_info *next_gpe_block;
struct acpi_gpe_xrupt_info *gpe_xrupt_block;
acpi_status status;
- u32 flags;
+ unsigned long flags;

ACPI_FUNCTION_TRACE("ev_install_gpe_block");

@@ -663,7 +663,7 @@ acpi_ev_install_gpe_block(struct acpi_gp
acpi_status acpi_ev_delete_gpe_block(struct acpi_gpe_block_info *gpe_block)
{
acpi_status status;
- u32 flags;
+ unsigned long flags;

ACPI_FUNCTION_TRACE("ev_install_gpe_block");

2005-10-06 08:10:23

by Ingo Molnar

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


* Steven Rostedt <[email protected]> wrote:

> Found the problem. You're using a 64 bit machine and flags in the
> acpi code is defined as u32 and not unsigned long. Ingo's tests put
> some checks in the flags at the MSBs and these are being truncated.

ahh ... I would not be surprised if this caused actual problems on x64
in the upstream kernel too: using save_flags() over u32 will corrupt a
word on the stack ...

Andi?

Ingo

2005-10-06 08:29:55

by Steven Rostedt

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2



On Thu, 6 Oct 2005, Ingo Molnar wrote:

>
> * Steven Rostedt <[email protected]> wrote:
>
> > Found the problem. You're using a 64 bit machine and flags in the
> > acpi code is defined as u32 and not unsigned long. Ingo's tests put
> > some checks in the flags at the MSBs and these are being truncated.
>
> ahh ... I would not be surprised if this caused actual problems on x64
> in the upstream kernel too: using save_flags() over u32 will corrupt a
> word on the stack ...
>
> Andi?
>

So I guess these patches need to go upstream too?

Here's the rest of the u32 coversions. Not all the u32 flags were used for
spinlocks. Most were for the flags instance in the structure.

Note, this patch does _NOT_ include the previous patch that I sent. If
this needs to go upstream, I'll send the two together as one patch.

-- Steve

--- linux-2.6.14-rc3-rt9/drivers/acpi/events/evgpe.c.orig 2005-10-06 04:15:40.000000000 -0400
+++ linux-2.6.14-rc3-rt9/drivers/acpi/events/evgpe.c 2005-10-06 04:15:46.000000000 -0400
@@ -377,7 +377,7 @@ u32 acpi_ev_gpe_detect(struct acpi_gpe_x
struct acpi_gpe_register_info *gpe_register_info;
u32 status_reg;
u32 enable_reg;
- u32 flags;
+ unsigned long flags;
acpi_status status;
struct acpi_gpe_block_info *gpe_block;
acpi_native_uint i;
--- linux-2.6.14-rc3-rt9/drivers/acpi/events/evgpeblk.c.orig 2005-10-06 04:00:34.000000000 -0400
+++ linux-2.6.14-rc3-rt9/drivers/acpi/events/evgpeblk.c 2005-10-06 04:00:58.000000000 -0400
@@ -136,7 +136,7 @@ acpi_status acpi_ev_walk_gpe_list(ACPI_G
struct acpi_gpe_block_info *gpe_block;
struct acpi_gpe_xrupt_info *gpe_xrupt_info;
acpi_status status = AE_OK;
- u32 flags;
+ unsigned long flags;

ACPI_FUNCTION_TRACE("ev_walk_gpe_list");

@@ -479,7 +479,7 @@ static struct acpi_gpe_xrupt_info *acpi_
struct acpi_gpe_xrupt_info *next_gpe_xrupt;
struct acpi_gpe_xrupt_info *gpe_xrupt;
acpi_status status;
- u32 flags;
+ unsigned long flags;

ACPI_FUNCTION_TRACE("ev_get_gpe_xrupt_block");

@@ -553,7 +553,7 @@ static acpi_status
acpi_ev_delete_gpe_xrupt(struct acpi_gpe_xrupt_info *gpe_xrupt)
{
acpi_status status;
- u32 flags;
+ unsigned long flags;

ACPI_FUNCTION_TRACE("ev_delete_gpe_xrupt");

@@ -610,7 +610,7 @@ acpi_ev_install_gpe_block(struct acpi_gp
struct acpi_gpe_block_info *next_gpe_block;
struct acpi_gpe_xrupt_info *gpe_xrupt_block;
acpi_status status;
- u32 flags;
+ unsigned long flags;

ACPI_FUNCTION_TRACE("ev_install_gpe_block");

@@ -663,7 +663,7 @@ acpi_ev_install_gpe_block(struct acpi_gp
acpi_status acpi_ev_delete_gpe_block(struct acpi_gpe_block_info *gpe_block)
{
acpi_status status;
- u32 flags;
+ unsigned long flags;

ACPI_FUNCTION_TRACE("ev_install_gpe_block");

--- linux-2.6.14-rc3-rt9/drivers/acpi/events/evxface.c.orig 2005-10-06 04:16:27.000000000 -0400
+++ linux-2.6.14-rc3-rt9/drivers/acpi/events/evxface.c 2005-10-06 04:16:43.000000000 -0400
@@ -562,7 +562,7 @@ acpi_install_gpe_handler(acpi_handle gpe
struct acpi_gpe_event_info *gpe_event_info;
struct acpi_handler_info *handler;
acpi_status status;
- u32 flags;
+ unsigned long flags;

ACPI_FUNCTION_TRACE("acpi_install_gpe_handler");

@@ -653,7 +653,7 @@ acpi_remove_gpe_handler(acpi_handle gpe_
struct acpi_gpe_event_info *gpe_event_info;
struct acpi_handler_info *handler;
acpi_status status;
- u32 flags;
+ unsigned long flags;

ACPI_FUNCTION_TRACE("acpi_remove_gpe_handler");

2005-10-06 08:33:09

by Ingo Molnar

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


* Steven Rostedt <[email protected]> wrote:

> So I guess these patches need to go upstream too?
>
> Here's the rest of the u32 coversions. Not all the u32 flags were used
> for spinlocks. Most were for the flags instance in the structure.
>
> Note, this patch does _NOT_ include the previous patch that I sent.
> If this needs to go upstream, I'll send the two together as one patch.

in any case i've applied both patches to the -rt tree.

Ingo

2005-10-06 08:36:52

by Ingo Molnar

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


* Steven Rostedt <[email protected]> wrote:

> So I guess these patches need to go upstream too?
>
> Here's the rest of the u32 coversions. Not all the u32 flags were used
> for spinlocks. Most were for the flags instance in the structure.
>
> Note, this patch does _NOT_ include the previous patch that I sent.
> If this needs to go upstream, I'll send the two together as one patch.

(actually, it seems to include the previous patch too.)

Ingo

2005-10-06 08:37:31

by Steven Rostedt

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


On Thu, 6 Oct 2005, Ingo Molnar wrote:

>
> * Steven Rostedt <[email protected]> wrote:
>
> > Found the problem. You're using a 64 bit machine and flags in the
> > acpi code is defined as u32 and not unsigned long. Ingo's tests put
> > some checks in the flags at the MSBs and these are being truncated.
>
> ahh ... I would not be surprised if this caused actual problems on x64
> in the upstream kernel too: using save_flags() over u32 will corrupt a
> word on the stack ...
>

Actually, it's still safe upstream. The locks are taken via a function
defined as:

unsigned long acpi_os_acquire_lock(acpi_handle handle)
{
unsigned long flags;
spin_lock_irqsave((spinlock_t *) handle, flags);
return flags;
}

So a u32 flags with

flags = acpi_os_acquire_lock(lock);

would be safe, unless a 64 bit machine stored the value of IR in the upper
word, which I don't know of any archs that do that.

-- Steve

2005-10-06 08:44:56

by Steven Rostedt

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2



On Thu, 6 Oct 2005, Ingo Molnar wrote:

> >
> > Note, this patch does _NOT_ include the previous patch that I sent.
> > If this needs to go upstream, I'll send the two together as one patch.
>
> in any case i've applied both patches to the -rt tree.
>

Oops! I just noticed that the patch _did_ include the previous patch.
Sorry Ingo, you probably noticed when you applied the second patch. I
did a find . '*.orig' to determine what to diff and forgot that I still
had the first patch .orig there.

:-}

Sorry,

-- Steve

2005-10-06 08:48:45

by Ingo Molnar

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


* Steven Rostedt <[email protected]> wrote:

> > ahh ... I would not be surprised if this caused actual problems on x64
> > in the upstream kernel too: using save_flags() over u32 will corrupt a
> > word on the stack ...
> >
>
> Actually, it's still safe upstream. The locks are taken via a function
> defined as:
>
> unsigned long acpi_os_acquire_lock(acpi_handle handle)
> {
> unsigned long flags;
> spin_lock_irqsave((spinlock_t *) handle, flags);
> return flags;
> }
>
> So a u32 flags with
>
> flags = acpi_os_acquire_lock(lock);
>
> would be safe, unless a 64 bit machine stored the value of IR in the
> upper word, which I don't know of any archs that do that.

ok. But this still looks very volatile. Nowhere do we guarantee (or can
we guarantee) that silently zeroing out the upper 32 bits of flags is
safe!

Ingo

2005-10-06 09:36:33

by Andi Kleen

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Thu, Oct 06, 2005 at 10:10:55AM +0200, Ingo Molnar wrote:
>
> * Steven Rostedt <[email protected]> wrote:
>
> > Found the problem. You're using a 64 bit machine and flags in the
> > acpi code is defined as u32 and not unsigned long. Ingo's tests put
> > some checks in the flags at the MSBs and these are being truncated.
>
> ahh ... I would not be surprised if this caused actual problems on x64
> in the upstream kernel too: using save_flags() over u32 will corrupt a
> word on the stack ...
>
> Andi?

Yes it should be using unsigned long. The actual flag word is still
only 32bit, but the inline assembly expects 64bit. And save_flags
might corrupt the target if it's too small.

Normally you should get a warning from warn_if_not_ulong() though.
You didn't get it in that case? I don't remember any such warnings
from the ACPI code.

Which code does it exactly?

-Andi

2005-10-06 09:48:17

by Andi Kleen

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

[hrm - should read whole threads before replying]


>
> So a u32 flags with
>
> flags = acpi_os_acquire_lock(lock);
>
> would be safe, unless a 64 bit machine stored the value of IR in the upper
> word, which I don't know of any archs that do that.

At least on x86-64 it should be ok.

-Andi

2005-10-06 09:48:50

by Steven Rostedt

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2



On Thu, 6 Oct 2005, Ingo Molnar wrote:

>
> * Steven Rostedt <[email protected]> wrote:
>
> > > ahh ... I would not be surprised if this caused actual problems on x64
> > > in the upstream kernel too: using save_flags() over u32 will corrupt a
> > > word on the stack ...
> > >
> >
> > Actually, it's still safe upstream. The locks are taken via a function
> > defined as:
> >
> > unsigned long acpi_os_acquire_lock(acpi_handle handle)
> > {
> > unsigned long flags;
> > spin_lock_irqsave((spinlock_t *) handle, flags);
> > return flags;
> > }
> >
> > So a u32 flags with
> >
> > flags = acpi_os_acquire_lock(lock);
> >
> > would be safe, unless a 64 bit machine stored the value of IR in the
> > upper word, which I don't know of any archs that do that.
>
> ok. But this still looks very volatile. Nowhere do we guarantee (or can
> we guarantee) that silently zeroing out the upper 32 bits of flags is
> safe!
>

Andi,

So, should I send my patch upstream?

There's three files that need to be changed:

drivers/acpi/events/evgpe.c
drivers/acpi/events/evgpeblk.c
drivers/acpi/events/evxface.c

They store flags as u32, but it does it through acpi_os_acquire_lock, so
you won't get any warnings.

-- Steve

2005-10-06 10:04:19

by Andi Kleen

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Thursday 06 October 2005 11:48, Steven Rostedt wrote:
> On Thu, 6 Oct 2005, Ingo Molnar wrote:
> > * Steven Rostedt <[email protected]> wrote:
> > > > ahh ... I would not be surprised if this caused actual problems on
> > > > x64 in the upstream kernel too: using save_flags() over u32 will
> > > > corrupt a word on the stack ...
> > >
> > > Actually, it's still safe upstream. The locks are taken via a function
> > > defined as:
> > >
> > > unsigned long acpi_os_acquire_lock(acpi_handle handle)
> > > {
> > > unsigned long flags;
> > > spin_lock_irqsave((spinlock_t *) handle, flags);
> > > return flags;
> > > }
> > >
> > > So a u32 flags with
> > >
> > > flags = acpi_os_acquire_lock(lock);
> > >
> > > would be safe, unless a 64 bit machine stored the value of IR in the
> > > upper word, which I don't know of any archs that do that.
> >
> > ok. But this still looks very volatile. Nowhere do we guarantee (or can
> > we guarantee) that silently zeroing out the upper 32 bits of flags is
> > safe!
>
> Andi,
>
> So, should I send my patch upstream?

It's a theoretical only issue for mainline right now. The only architectures
using the ACPI code are i386,x86-64,ia64. The first two are ok with
truncating. The IA64 PSR is longer than 32bit, but unless I'm misreading the
code they only care about the "i" bit which is also in the lower 32bit (Tony
can probably confirm/deny)

Still might be good to clean up, but certainly not a urgent issue.

-Andi

2005-10-06 11:08:57

by Steven Rostedt

[permalink] [raw]
Subject: [PATCH] cleanup u32 flags in acpi spin_lock calls.


This is not an urgent issue, but was noticed in Ingo's RT kernel. There
are some places in ACPI that save flags as a u32 instead of a unsigned
long. This is done indirectly by calling acpi_os_acquire_lock, which uses
unsigned long, but the flags returned are saved in the acpi code as a u32.

Since todays archs that use acpi, only care about the LS 32 bits of the
word, this is not really an issue. But if there is an arch in the future
that changes that assumption, or (as RT does) some internal change in the
kernel that looks at the MSB of flags on a restore, this will be broken
for 64 bit machines.

This patch is just to make the ACPI code "clean". That is, to use the
proper type for flags.

-- Steve

Note: You may notice that this patch has an -rt in the names, it does
apply cleanly to 2.6.14-rc3.

Signed-off-by: Steven Rostedt <[email protected]>


--- linux-2.6.14-rc3-rt9/drivers/acpi/events/evgpe.c.orig 2005-10-06 04:15:40.000000000 -0400
+++ linux-2.6.14-rc3-rt9/drivers/acpi/events/evgpe.c 2005-10-06 04:15:46.000000000 -0400
@@ -377,7 +377,7 @@ u32 acpi_ev_gpe_detect(struct acpi_gpe_x
struct acpi_gpe_register_info *gpe_register_info;
u32 status_reg;
u32 enable_reg;
- u32 flags;
+ unsigned long flags;
acpi_status status;
struct acpi_gpe_block_info *gpe_block;
acpi_native_uint i;
--- linux-2.6.14-rc3-rt9/drivers/acpi/events/evgpeblk.c.orig 2005-10-06 04:00:34.000000000 -0400
+++ linux-2.6.14-rc3-rt9/drivers/acpi/events/evgpeblk.c 2005-10-06 04:00:58.000000000 -0400
@@ -136,7 +136,7 @@ acpi_status acpi_ev_walk_gpe_list(ACPI_G
struct acpi_gpe_block_info *gpe_block;
struct acpi_gpe_xrupt_info *gpe_xrupt_info;
acpi_status status = AE_OK;
- u32 flags;
+ unsigned long flags;

ACPI_FUNCTION_TRACE("ev_walk_gpe_list");

@@ -479,7 +479,7 @@ static struct acpi_gpe_xrupt_info *acpi_
struct acpi_gpe_xrupt_info *next_gpe_xrupt;
struct acpi_gpe_xrupt_info *gpe_xrupt;
acpi_status status;
- u32 flags;
+ unsigned long flags;

ACPI_FUNCTION_TRACE("ev_get_gpe_xrupt_block");

@@ -553,7 +553,7 @@ static acpi_status
acpi_ev_delete_gpe_xrupt(struct acpi_gpe_xrupt_info *gpe_xrupt)
{
acpi_status status;
- u32 flags;
+ unsigned long flags;

ACPI_FUNCTION_TRACE("ev_delete_gpe_xrupt");

@@ -610,7 +610,7 @@ acpi_ev_install_gpe_block(struct acpi_gp
struct acpi_gpe_block_info *next_gpe_block;
struct acpi_gpe_xrupt_info *gpe_xrupt_block;
acpi_status status;
- u32 flags;
+ unsigned long flags;

ACPI_FUNCTION_TRACE("ev_install_gpe_block");

@@ -663,7 +663,7 @@ acpi_ev_install_gpe_block(struct acpi_gp
acpi_status acpi_ev_delete_gpe_block(struct acpi_gpe_block_info *gpe_block)
{
acpi_status status;
- u32 flags;
+ unsigned long flags;

ACPI_FUNCTION_TRACE("ev_install_gpe_block");

--- linux-2.6.14-rc3-rt9/drivers/acpi/events/evxface.c.orig 2005-10-06 04:16:27.000000000 -0400
+++ linux-2.6.14-rc3-rt9/drivers/acpi/events/evxface.c 2005-10-06 04:16:43.000000000 -0400
@@ -562,7 +562,7 @@ acpi_install_gpe_handler(acpi_handle gpe
struct acpi_gpe_event_info *gpe_event_info;
struct acpi_handler_info *handler;
acpi_status status;
- u32 flags;
+ unsigned long flags;

ACPI_FUNCTION_TRACE("acpi_install_gpe_handler");

@@ -653,7 +653,7 @@ acpi_remove_gpe_handler(acpi_handle gpe_
struct acpi_gpe_event_info *gpe_event_info;
struct acpi_handler_info *handler;
acpi_status status;
- u32 flags;
+ unsigned long flags;

ACPI_FUNCTION_TRACE("acpi_remove_gpe_handler");

2005-10-06 14:36:57

by Lee Revell

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On Tue, 2005-10-04 at 20:20 +0200, Thomas Gleixner wrote:
> On Tue, 2005-10-04 at 11:11 -0700, Mark Knecht wrote:
>
> > I have now had one burst of xruns. As best I can tell I was
> > downloading some video files for mplayer to look at, or possibly
> > running one of them. I see this in qjackctl:
> >
>
> I guess its related to the priority leak I'm tracking down right now.
> Can you please set following config options and check if you get a bug
> similar to this ?
>
> BUG: init/1: leaked RT prio 98 (116)?

Sorry if this is old news, but I am getting them with 2.6.13-rt12.
Unlike previous occurrences, it appears that X does *not* end up
SCHED_FIFO.

BUG: Xorg/4094: leaked RT prio 98 (116)?
[<c0104919>] dump_stack+0x19/0x20 (20)
[<c01397fe>] up_mutex+0xbe/0x110 (36)
[<c02c2c29>] _spin_unlock_irqrestore+0x29/0x60 (12)
[<c011ab24>] __wake_up+0x34/0x60 (44)
[<c0130248>] __queue_work+0x48/0x60 (24)
[<c013029f>] queue_work+0x3f/0x70 (24)
[<c0130b64>] schedule_work+0x14/0x20 (8)
[<c0225202>] schedule_console_callback+0x12/0x20 (8)
[<c0225095>] kbd_event+0x45/0xe0 (16)
[<c02527db>] input_event+0xdb/0x420 (36)
[<c0223a6e>] kbd_rate+0x4e/0xb0 (40)
[<c022020a>] vt_ioctl+0x64a/0x1820 (104)
[<c021ae50>] tty_ioctl+0xc0/0x430 (40)
[<c017aeab>] do_ioctl+0x6b/0x80 (36)
[<c017b05f>] vfs_ioctl+0x5f/0x1f0 (40)
[<c017b24f>] sys_ioctl+0x5f/0x90 (40)
[<c01032d6>] syscall_call+0x7/0xb (-4020)

Lee

2005-10-06 15:01:37

by Steven Rostedt

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


Hi Lee,

Once again, Please replace the kihontech.com with goodmis.org (done here)
since the kihontech.com is for use with customers and potential customers
;-)


On Thu, 6 Oct 2005, Lee Revell wrote:

>
> Sorry if this is old news, but I am getting them with 2.6.13-rt12.
> Unlike previous occurrences, it appears that X does *not* end up
> SCHED_FIFO.
>

Yep old news, it was an accounting error that Thomas discovered. It's all
fixed in the latest release of -rt.

-- Steve

2005-10-06 15:26:14

by Steven Rostedt

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


Ingo, the following bug popped up.

BUG: scheduling while atomic: modprobe/0x00000001/3083
caller is schedule+0x84/0x111
[<c0103fe2>] dump_stack+0x1e/0x20 (20)
[<c0323402>] __schedule+0x742/0xa94 (84)
[<c03237d8>] schedule+0x84/0x111 (28)
[<c0324a7b>] __down_mutex+0x56b/0x83a (116)
[<c0326bcf>] _spin_lock+0x1f/0x44 (28)
[<c0155070>] __kmalloc+0x6c/0x11d (36)
[<c021e989>] soft_cursor+0x61/0x1a8 (76)
[<c02175c4>] bit_cursor+0x2d3/0x588 (164)
[<c0212b4e>] fbcon_cursor+0x1be/0x307 (76)
[<c0213529>] fbcon_scroll+0x84/0xf5d (80)
[<c026bafd>] scrup+0xce/0xd8 (40)
[<c026d1a5>] lf+0x50/0x5d (28)
[<c026f3ad>] vt_console_print+0x116/0x2bb (56)
[<c011e9c4>] __call_console_drivers+0x47/0x56 (32)
[<c011ea4a>] _call_console_drivers+0x77/0x7e (24)
[<c011eaf6>] call_console_drivers+0xa5/0x183 (44)
[<c011f0af>] release_console_sem+0x2e/0xeb (32)
[<c011ef85>] vprintk+0x2aa/0x312 (108)
[<c011ecd9>] printk+0x1b/0x1d (20)
[<f8c2f04a>] usb_register_bus+0xf1/0x137 [usbcore] (36)
[<f8c2feb2>] usb_add_hcd+0x7c/0x3b3 [usbcore] (64)
[<f8c3730b>] usb_hcd_pci_probe+0x1cb/0x2f9 [usbcore] (52)
[<c020b929>] pci_call_probe+0x19/0x1b (16)
[<c020b977>] __pci_device_probe+0x4c/0x57 (28)
[<c020b9ad>] pci_device_probe+0x2b/0x42 (24)
[<c027dfc7>] driver_probe_device+0x3e/0xab (36)
[<c027e102>] __driver_attach+0x41/0x51 (24)
[<c027d61b>] bus_for_each_dev+0x57/0x77 (44)
[<c027e13a>] driver_attach+0x28/0x2a (24)
[<c027dad2>] bus_add_driver+0x7a/0xdb (36)
[<c027e4d5>] driver_register+0x64/0x6b (32)
[<c020bbec>] pci_register_driver+0x8b/0xa9 (28)
[<f881d024>] init+0x24/0x2a [ehci_hcd] (12)
[<c0146780>] sys_init_module+0xb9/0x22e (28)
[<c01030ed>] syscall_call+0x7/0xb (-8116)
---------------------------
| preempt count: 00000001 ]
| 1-level deep critical section nesting:
----------------------------------------
.. [<c0140530>] .... add_preempt_count+0x1c/0x1e
.....[<c011ecf0>] .. ( <= vprintk+0x15/0x312)

------------------------------
| showing all locks held by: | (modprobe/3083 [f747f7d0, 118]):
------------------------------

#001: [cf480218] {(struct semaphore *)(&dev->sem)}
... acquired at: __driver_attach+0x18/0x51


I didn't know that down_mutex could cause the scheduling while atomic. It
seems that the driver inside the vt_console failed to grab a lock, and
this will output, since printk does a raw_spin_lock_irqsave that seems to
also do a preempt_disable. (the kmallocs are GFP_ATOMIC).

-- Steve


2005-10-06 16:04:05

by Mark Knecht

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On 10/6/05, Ingo Molnar <[email protected]> wrote:
>
> * Steven Rostedt <[email protected]> wrote:
>
> > So I guess these patches need to go upstream too?
> >
> > Here's the rest of the u32 coversions. Not all the u32 flags were used
> > for spinlocks. Most were for the flags instance in the structure.
> >
> > Note, this patch does _NOT_ include the previous patch that I sent.
> > If this needs to go upstream, I'll send the two together as one patch.
>
> in any case i've applied both patches to the -rt tree.
>
> Ingo
>

Ingo,
As of -rt10 this morning I am no longer getting my accounting bug
report in dmesg. Thanks!

- Mark

2005-10-06 16:26:22

by Tony Luck

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

> It's a theoretical only issue for mainline right now. The only architectures
> using the ACPI code are i386,x86-64,ia64. The first two are ok with
> truncating. The IA64 PSR is longer than 32bit, but unless I'm misreading the
> code they only care about the "i" bit which is also in the lower 32bit (Tony
> can probably confirm/deny)

Andi is right ... if you follow the "acpi_os_release_lock" trail, you
eventually get to include/asm-ia64/system.h with the following definition
for __local_irq_restore:

#define __local_irq_restore(x) ia64_intrin_local_irq_restore((x) & IA64_PSR_I)

and the IA64_PSR_I bit is bit 14 ... safely in the low 32 bits. So this is
a correct fix, but will have no effect on ia64.

-Tony

2005-10-06 16:47:13

by Todd Kneisel

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2

On 10/4/05, Ingo Molnar <[email protected]> wrote:
>
> i have released the 2.6.14-rc3-rt2 tree, which can be downloaded from
> the usual place:
>
> http://redhat.com/~mingo/realtime-preempt/
>
> the biggest change in this release is the long-anticipated merge of a
> streamlined version of the "robust futexes/mutexes with priority
> queueing and priority inheritance" code into the -rt tree. The original
> upstream patch is from Todd Kneisel, with further improvements, cleanups
> and -RT integration done by David Singleton.
>

My original patch implemented robust futexes using the existing futex
wait queue mechanisms, because the project I'm working on does not
need priority inheritance or other realtime features. David's changes
replaced the wait queue mechanisms with rt_mutexes. I'm working on
a patch to add my implementation back in, so the kernel will support
both robust wait-queue futexes and robust rt_mutex futexes. Does
anyone else see the need for this?

Also, my patch implemented only shared robust futexes. David's work
was based on mine, so the current code only supports shared robust
futexes that may or may not be priority inheritance. It doesn't support
priority inheritance mutexes that are not robust, or that are not shared.

Todd.

2005-10-06 17:18:15

by David Singleton

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


On Oct 6, 2005, at 9:47 AM, Todd Kneisel wrote:

> On 10/4/05, Ingo Molnar <[email protected]> wrote:
>>
>> i have released the 2.6.14-rc3-rt2 tree, which can be downloaded from
>> the usual place:
>>
>> http://redhat.com/~mingo/realtime-preempt/
>>
>> the biggest change in this release is the long-anticipated merge of a
>> streamlined version of the "robust futexes/mutexes with priority
>> queueing and priority inheritance" code into the -rt tree. The
>> original
>> upstream patch is from Todd Kneisel, with further improvements,
>> cleanups
>> and -RT integration done by David Singleton.
>>
>
> My original patch implemented robust futexes using the existing futex
> wait queue mechanisms, because the project I'm working on does not
> need priority inheritance or other realtime features. David's changes
> replaced the wait queue mechanisms with rt_mutexes. I'm working on
> a patch to add my implementation back in, so the kernel will support
> both robust wait-queue futexes and robust rt_mutex futexes. Does
> anyone else see the need for this?
>
> Also, my patch implemented only shared robust futexes. David's work
> was based on mine, so the current code only supports shared robust
> futexes that may or may not be priority inheritance. It doesn't support
> priority inheritance mutexes that are not robust, or that are not
> shared.


The latest changes to the 2.6.14-rc3-rt10 patch is to make robust and
priority inheritance independent. The code now supports mutexes
that are robust or priority inheriting or both.

I hope to have glibc patches out soon for the new separation of
robustness
and priority inheritance.

David

Please note that robust mutexes works with other flavors of kernel
besides
realtime. The code works with all flavors of kernel, PREEMPT_NONE,
PREEMPT_DESKTOP or PREEMPT_RT.



>
> Todd.

2005-10-07 11:08:17

by Steven Rostedt

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


Hi Ingo,

I was compiling a kernel in a shell that I set to a priority of 20, and it
locked up on the bit_spin_lock crap of jbd. Did you want me to send you
that patch again that adds another spinlock to the buffer head and uses
that instead of the bit_spins?

-- Steve


2005-10-07 11:06:06

by Steven Rostedt

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2



On Wed, 5 Oct 2005, Steven Rostedt wrote:

>
> It seems that the problem comes down to the call to getnstimeofday in
> do_gettimeofday.
>

OK, not sure if anyone looked into this more or not. But this patch seems
to at least fix the symptom if not the cure. I changed
set_normalize_timespec to take a nsec_t type as its last parameter.
Since I don't see a problem with overflowing a 64 bit number, this works
for now. But I still don't know the full extent of xtime_last_update not
updating during something like hackbench starving the timer softirq.

-- Steve

Index: linux-rt-quilt/include/linux/time.h
===================================================================
--- linux-rt-quilt.orig/include/linux/time.h 2005-10-07 05:11:00.000000000 -0400
+++ linux-rt-quilt/include/linux/time.h 2005-10-07 05:12:17.000000000 -0400
@@ -107,7 +107,7 @@
extern struct timespec timespec_trunc(struct timespec t, unsigned gran);

static inline void
-set_normalized_timespec (struct timespec *ts, time_t sec, long nsec)
+set_normalized_timespec (struct timespec *ts, time_t sec, nsec_t nsec)
{
while (nsec > NSEC_PER_SEC) {
nsec -= NSEC_PER_SEC;
Index: linux-rt-quilt/kernel/timeofday.c
===================================================================
--- linux-rt-quilt.orig/kernel/timeofday.c 2005-10-06 08:04:56.000000000 -0400
+++ linux-rt-quilt/kernel/timeofday.c 2005-10-07 05:14:58.000000000 -0400
@@ -174,12 +174,12 @@
goto full;
set_normalized_timespec(&mono_last_update_ts,
mono_last_update_ts.tv_sec,
- mono_last_update_ts.tv_nsec + (long) delta);
+ mono_last_update_ts.tv_nsec + delta);
if (unlikely(leapupdate))
set_normalized_timespec(&mono_wall_offset_ts,
mono_wall_offset_ts.tv_sec,
mono_wall_offset_ts.tv_nsec +
- (long) leapupdate);
+ leapupdate);
}
xtime_last_update = system_time;
set_normalized_timespec(&xtime,
@@ -266,7 +266,7 @@

set_normalized_timespec(ts,
mono_last_update_ts.tv_sec,
- mono_last_update_ts.tv_nsec + (long) delta);
+ mono_last_update_ts.tv_nsec + delta);
}

/**
@@ -359,7 +359,7 @@

set_normalized_timespec(ts,
ts->tv_sec,
- ts->tv_nsec + (long) delta);
+ ts->tv_nsec + delta);

}
EXPORT_SYMBOL(getnstimeofday);

2005-10-07 11:14:45

by Ingo Molnar

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


* Steven Rostedt <[email protected]> wrote:

>
>
> On Wed, 5 Oct 2005, Steven Rostedt wrote:
>
> >
> > It seems that the problem comes down to the call to getnstimeofday in
> > do_gettimeofday.
> >
>
> OK, not sure if anyone looked into this more or not. But this patch
> seems to at least fix the symptom if not the cure. I changed
> set_normalize_timespec to take a nsec_t type as its last parameter.
> Since I don't see a problem with overflowing a 64 bit number, this
> works for now. But I still don't know the full extent of
> xtime_last_update not updating during something like hackbench
> starving the timer softirq.

thanks, applied.

Ingo

2005-10-07 11:15:08

by Ingo Molnar

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


* Steven Rostedt <[email protected]> wrote:

> I was compiling a kernel in a shell that I set to a priority of 20,
> and it locked up on the bit_spin_lock crap of jbd. Did you want me to
> send you that patch again that adds another spinlock to the buffer
> head and uses that instead of the bit_spins?

yeah, please do.

Ingo

2005-10-07 12:38:34

by Steven Rostedt

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


On Fri, 7 Oct 2005, Ingo Molnar wrote:
>
> * Steven Rostedt <[email protected]> wrote:
>
> > I was compiling a kernel in a shell that I set to a priority of 20,
> > and it locked up on the bit_spin_lock crap of jbd. Did you want me to
> > send you that patch again that adds another spinlock to the buffer
> > head and uses that instead of the bit_spins?
>
> yeah, please do.
>

OK, here it is. I tested it out by doing what locked up the first time.
Compiling the kernel under a shell with a priority of 20.

It survived a "make clean; make -j2".

-- Steve

patched against 2.6.14-rc3-rt10

Index: linux-rt-quilt/fs/buffer.c
===================================================================
--- linux-rt-quilt.orig/fs/buffer.c 2005-10-06 08:04:55.000000000 -0400
+++ linux-rt-quilt/fs/buffer.c 2005-10-07 07:46:25.000000000 -0400
@@ -3055,6 +3055,7 @@
{
BUG_ON(!list_empty(&bh->b_assoc_buffers));
BUG_ON(spin_is_locked(&bh->b_uptodate_lock));
+ BUG_ON(spin_is_locked(&bh->b_state_lock));
kmem_cache_free(bh_cachep, bh);
get_cpu_var(bh_accounting).nr--;
recalc_bh_state();
@@ -3072,6 +3073,7 @@
memset(bh, 0, sizeof(*bh));
INIT_LIST_HEAD(&bh->b_assoc_buffers);
spin_lock_init(&bh->b_uptodate_lock);
+ spin_lock_init(&bh->b_state_lock);
}
}

Index: linux-rt-quilt/include/linux/buffer_head.h
===================================================================
--- linux-rt-quilt.orig/include/linux/buffer_head.h 2005-10-06 08:04:56.000000000 -0400
+++ linux-rt-quilt/include/linux/buffer_head.h 2005-10-07 07:46:25.000000000 -0400
@@ -62,6 +62,7 @@
void *b_private; /* reserved for b_end_io */
struct list_head b_assoc_buffers; /* associated with another mapping */
spinlock_t b_uptodate_lock;
+ spinlock_t b_state_lock;
};

/*
Index: linux-rt-quilt/include/linux/jbd.h
===================================================================
--- linux-rt-quilt.orig/include/linux/jbd.h 2005-10-06 08:04:00.000000000 -0400
+++ linux-rt-quilt/include/linux/jbd.h 2005-10-07 07:46:25.000000000 -0400
@@ -327,32 +327,32 @@

static inline void jbd_lock_bh_state(struct buffer_head *bh)
{
- bit_spin_lock(BH_State, &bh->b_state);
+ spin_lock(&bh->b_state_lock);
}

static inline int jbd_trylock_bh_state(struct buffer_head *bh)
{
- return bit_spin_trylock(BH_State, &bh->b_state);
+ return spin_trylock(&bh->b_state_lock);
}

static inline int jbd_is_locked_bh_state(struct buffer_head *bh)
{
- return bit_spin_is_locked(BH_State, &bh->b_state);
+ return spin_is_locked(&bh->b_state_lock);
}

static inline void jbd_unlock_bh_state(struct buffer_head *bh)
{
- bit_spin_unlock(BH_State, &bh->b_state);
+ spin_unlock(&bh->b_state_lock);
}

static inline void jbd_lock_bh_journal_head(struct buffer_head *bh)
{
- bit_spin_lock(BH_JournalHead, &bh->b_state);
+ spin_lock(&bh->b_uptodate_lock);
}

static inline void jbd_unlock_bh_journal_head(struct buffer_head *bh)
{
- bit_spin_unlock(BH_JournalHead, &bh->b_state);
+ spin_unlock(&bh->b_uptodate_lock);
}

struct jbd_revoke_table_s;

2005-10-07 13:25:31

by Ingo Molnar

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


* Steven Rostedt <[email protected]> wrote:

> On Fri, 7 Oct 2005, Ingo Molnar wrote:
> >
> > * Steven Rostedt <[email protected]> wrote:
> >
> > > I was compiling a kernel in a shell that I set to a priority of 20,
> > > and it locked up on the bit_spin_lock crap of jbd. Did you want me to
> > > send you that patch again that adds another spinlock to the buffer
> > > head and uses that instead of the bit_spins?
> >
> > yeah, please do.
> >
>
> OK, here it is. I tested it out by doing what locked up the first
> time. Compiling the kernel under a shell with a priority of 20.
>
> It survived a "make clean; make -j2".
>
> -- Steve
>
> patched against 2.6.14-rc3-rt10

thanks - applied.

Ingo

2005-10-11 08:01:19

by Ingo Molnar

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt2


* Steven Rostedt <[email protected]> wrote:

> Ingo, the following bug popped up.
>
> BUG: scheduling while atomic: modprobe/0x00000001/3083
> caller is schedule+0x84/0x111
> [<c0103fe2>] dump_stack+0x1e/0x20 (20)
> [<c0323402>] __schedule+0x742/0xa94 (84)
> [<c03237d8>] schedule+0x84/0x111 (28)
> [<c0324a7b>] __down_mutex+0x56b/0x83a (116)
> [<c0326bcf>] _spin_lock+0x1f/0x44 (28)
> [<c0155070>] __kmalloc+0x6c/0x11d (36)
> [<c021e989>] soft_cursor+0x61/0x1a8 (76)
> [<c02175c4>] bit_cursor+0x2d3/0x588 (164)
> [<c0212b4e>] fbcon_cursor+0x1be/0x307 (76)
> [<c0213529>] fbcon_scroll+0x84/0xf5d (80)
> [<c026bafd>] scrup+0xce/0xd8 (40)
> [<c026d1a5>] lf+0x50/0x5d (28)
> [<c026f3ad>] vt_console_print+0x116/0x2bb (56)
> [<c011e9c4>] __call_console_drivers+0x47/0x56 (32)
> [<c011ea4a>] _call_console_drivers+0x77/0x7e (24)
> [<c011eaf6>] call_console_drivers+0xa5/0x183 (44)
> [<c011f0af>] release_console_sem+0x2e/0xeb (32)
> [<c011ef85>] vprintk+0x2aa/0x312 (108)
> [<c011ecd9>] printk+0x1b/0x1d (20)
> [<f8c2f04a>] usb_register_bus+0xf1/0x137 [usbcore] (36)

> I didn't know that down_mutex could cause the scheduling while atomic.
> It seems that the driver inside the vt_console failed to grab a lock,
> and this will output, since printk does a raw_spin_lock_irqsave that
> seems to also do a preempt_disable. (the kmallocs are GFP_ATOMIC).

it's vprintk keeping preemption disabled, and then calling the console
drivers, which may reschedule. The patch below should solve this.

Ingo

Index: linux/kernel/printk.c
===================================================================
--- linux.orig/kernel/printk.c
+++ linux/kernel/printk.c
@@ -545,6 +545,7 @@ asmlinkage int vprintk(const char *fmt,
/* This stops the holder of console_sem just where we want him */
spin_lock_irqsave(&logbuf_lock, flags);
printk_cpu = smp_processor_id();
+ preempt_enable();

/* Emit the output into the temporary buffer */
printed_len = vscnprintf(printk_buf, sizeof(printk_buf), fmt, args);
@@ -637,7 +638,6 @@ asmlinkage int vprintk(const char *fmt,
spin_unlock_irqrestore(&logbuf_lock, flags);
}
out:
- preempt_enable();
return printed_len;
}
EXPORT_SYMBOL(printk);

2005-10-11 09:09:30

by Steven Rostedt

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt12


Ingo, I keep getting a "changed soft IRQ-flags" on sysrq-b. Would the
following patch be appropriate?

-- Steve

Index: linux-rt-quilt/drivers/char/sysrq.c
===================================================================
--- linux-rt-quilt.orig/drivers/char/sysrq.c 2005-10-07 15:57:57.000000000 -0400
+++ linux-rt-quilt/drivers/char/sysrq.c 2005-10-11 05:04:38.000000000 -0400
@@ -114,7 +114,7 @@
static void sysrq_handle_reboot(int key, struct pt_regs *pt_regs,
struct tty_struct *tty)
{
- local_irq_enable();
+ raw_local_irq_enable();
emergency_restart();
}


2005-10-11 09:12:15

by Ingo Molnar

[permalink] [raw]
Subject: Re: 2.6.14-rc3-rt12


* Steven Rostedt <[email protected]> wrote:

> Ingo, I keep getting a "changed soft IRQ-flags" on sysrq-b. Would the
> following patch be appropriate?

sure - applied.

Ingo