Re: [patch] voluntary-preempt-2.6.8-rc2-O2

Re: [patch] voluntary-preempt-2.6.8-rc2-O2

[Shane Shrybman]

I was unable to boot -O2. It seemed to hang up when it got to the
aic7xxx(29160) scsi controller.

Boot messages copied by hand:

IRQ #16 thread started up.
delay 5 -10 secs
IRQ #19 thread started up.
delay 5 -10 secs
ahc_intr: HOST_MSG_LOOP bad phase 0x0
(repeats every 10-20 secs)
Waited a few minutes here before giving up and hitting reset.

Here is /proc/interrupts in 2.6.7-mm7
           CPU0       
  0:     740456    IO-APIC-edge  timer
  1:       1417    IO-APIC-edge  i8042
  8:          4    IO-APIC-edge  rtc
  9:          0   IO-APIC-level  acpi
 14:         14    IO-APIC-edge  ide0
 15:         14    IO-APIC-edge  ide1
 16:        178   IO-APIC-level  ide3, EMU10K1
 17:       2491   IO-APIC-level  eth0
 19:      10335   IO-APIC-level  aic7xxx, bttv0, Bt87x audio
 21:      29074   IO-APIC-level  uhci_hcd, uhci_hcd, uhci_hcd, uhci_hcd
 22:          0   IO-APIC-level  VIA8233
NMI:          0 
LOC:     740415 
ERR:          0
MIS:          0

Also, had to turn of parport in the config to get it to compile.

drivers/parport/share.c:77: unknown field `generic_enable_irq' specified
in initializer
drivers/parport/share.c:78: unknown field `generic_disable_irq'
specified in initializer

Regards,

Shane

Re: [patch] voluntary-preempt-2.6.8-rc2-O2

[Ingo Molnar]

On Mon, 2 Aug 2004, Shane Shrybman wrote:

> I was unable to boot -O2. It seemed to hang up when it got to the
> aic7xxx(29160) scsi controller.

does it boot with voluntary-preempt=2 on the boot command line? (or with 
voluntary-preempt=1)?

if it boots this way you can turn it back on runtime by changing
/proc/sys/kernel/voluntary_preemption back to 3 and turning on IRQ
threading for each interrupt via /proc/irq/*/threaded.

	Ingo

Re: [patch] voluntary-preempt-2.6.8-rc2-O2

[Shane Shrybman]

On Tue, 2004-08-03 at 05:19, Ingo Molnar wrote:
> On Mon, 2 Aug 2004, Shane Shrybman wrote:
> 
> > I was unable to boot -O2. It seemed to hang up when it got to the
> > aic7xxx(29160) scsi controller.
> 
> does it boot with voluntary-preempt=2 on the boot command line? (or with 
> voluntary-preempt=1)?
> 

Nope, didn't boot with either voluntary-preempt=1 or 2 on the boot
command line. Booting stopped at the scsi controller again.

It did boot with just acpi=off.

> if it boots this way you can turn it back on runtime by changing
> /proc/sys/kernel/voluntary_preemption back to 3 and turning on IRQ
> threading for each interrupt via /proc/irq/*/threaded.
> 
> 	Ingo
> 

Regards,

Shane

Re: [patch] voluntary-preempt-2.6.8-rc2-O2

[Ingo Molnar]

On Tue, 3 Aug 2004, Shane Shrybman wrote:

> > > I was unable to boot -O2. It seemed to hang up when it got to the
> > > aic7xxx(29160) scsi controller.
> > 
> > does it boot with voluntary-preempt=2 on the boot command line? (or with 
> > voluntary-preempt=1)?
> > 
> 
> Nope, didn't boot with either voluntary-preempt=1 or 2 on the boot
> command line. Booting stopped at the scsi controller again.
> 
> It did boot with just acpi=off.

does the non-patched kernel boot?

	Ingo

Re: [patch] voluntary-preempt-2.6.8-rc2-O2

[Ingo Molnar]

On Mon, 2 Aug 2004, Shane Shrybman wrote:

> Also, had to turn of parport in the config to get it to compile.
> 
> drivers/parport/share.c:77: unknown field `generic_enable_irq' specified
> in initializer
> drivers/parport/share.c:78: unknown field `generic_disable_irq'
> specified in initializer

thx - i fixed this in -O3.

	Ingo

Re: [patch] voluntary-preempt-2.6.8-rc2-O2

[Shane Shrybman]

On Tue, 2004-08-03 at 10:09, Ingo Molnar wrote:
> On Tue, 3 Aug 2004, Shane Shrybman wrote:
> 
> > > > I was unable to boot -O2. It seemed to hang up when it got to the
> > > > aic7xxx(29160) scsi controller.
> > > 
> > > does it boot with voluntary-preempt=2 on the boot command line? (or with 
> > > voluntary-preempt=1)?
> > > 
> > 
> > Nope, didn't boot with either voluntary-preempt=1 or 2 on the boot
> > command line. Booting stopped at the scsi controller again.
> > 
> > It did boot with just acpi=off.
> 
> does the non-patched kernel boot?
> 

I am in vanilla 2.6.8-rc2 now and it seems to be fine.

> 	Ingo
> 

Regards,

Shane

Re: [patch] voluntary-preempt-2.6.8-rc2-O2

[Ingo Molnar]

On Tue, 3 Aug 2004, Shane Shrybman wrote:

> > > Nope, didn't boot with either voluntary-preempt=1 or 2 on the boot
> > > command line. Booting stopped at the scsi controller again.
> > > 
> > > It did boot with just acpi=off.
> > 
> > does the non-patched kernel boot?
> > 
> 
> I am in vanilla 2.6.8-rc2 now and it seems to be fine.

does it boot fine with the patch applied but the APIC turned off in the 
.config?

	Ingo

Re: [patch] voluntary-preempt-2.6.8-rc2-O2

[Shane Shrybman]

On Tue, 2004-08-03 at 12:29, Ingo Molnar wrote:
> On Tue, 3 Aug 2004, Shane Shrybman wrote:
> 
> > > > Nope, didn't boot with either voluntary-preempt=1 or 2 on the boot
> > > > command line. Booting stopped at the scsi controller again.
> > > > 
> > > > It did boot with just acpi=off.
> > > 
> > > does the non-patched kernel boot?
> > > 
> > 
> > I am in vanilla 2.6.8-rc2 now and it seems to be fine.
> 
> does it boot fine with the patch applied but the APIC turned off in the 
> .config?
> 

Yes it does.

> 	Ingo
> 

Shane

Re: [patch] voluntary-preempt-2.6.8-rc2-O2

[Rudo Thomas]

> thx - i fixed this in -O3.

Hi, Ingo.

I just wanted to report that O3 (+preempt-timing-O2) locks up hard at random
occasions, even with voluntary-preempt=2 preempt=1 set at boot time.
I never changed any of /proc/irq/*/threaded.

I will provide any information needed to hunt this down.

Rudo.

Re: [patch] voluntary-preempt-2.6.8-rc2-O2

[Ingo Molnar]

On Wed, 4 Aug 2004, Rudo Thomas wrote:

> > thx - i fixed this in -O3.
> 
> Hi, Ingo.
> 
> I just wanted to report that O3 (+preempt-timing-O2) locks up hard at
> random occasions, even with voluntary-preempt=2 preempt=1 set at boot
> time. I never changed any of /proc/irq/*/threaded.
> 
> I will provide any information needed to hunt this down.

could you check whether it works with all APIC options turned off in the
.config?

	Ingo

Re: [patch] voluntary-preempt-2.6.8-rc2-O2

[Peter Zijlstra]

Rudo Thomas wrote:

>>thx - i fixed this in -O3.
>>    
>>
>
>Hi, Ingo.
>
>I just wanted to report that O3 (+preempt-timing-O2) locks up hard at random
>occasions, even with voluntary-preempt=2 preempt=1 set at boot time.
>I never changed any of /proc/irq/*/threaded.
>
>I will provide any information needed to hunt this down.
>
>Rudo.
>  
>
Hi Igno,

I have the same troubles with O3 at home on my SMP machine, however
since the same kernel (2.6.8-rc2-mm2-O3) works flawlessly here at work
on a UP P4 I thought it to be SMP related.

I also tried booting my dual athlon with noapic but that did not solve
the problem.

I have not had enough time yet to file a proper bug report but seeing
this message I wanted to second it.

Are there any known SMP related problems with your patches?

and would my dmesg and .config from home be enough ?

kind regards,

Peter Zijlstra

Re: [patch] voluntary-preempt-2.6.8-rc2-mm2-O3

[Peter Zijlstra]

Rudo Thomas wrote:

>>thx - i fixed this in -O3.
>>    
>>
>
>Hi, Ingo.
>
>I just wanted to report that O3 (+preempt-timing-O2) locks up hard at random
>occasions, even with voluntary-preempt=2 preempt=1 set at boot time.
>I never changed any of /proc/irq/*/threaded.
>
>I will provide any information needed to hunt this down.
>
>Rudo.
>  
>
Hi Igno,

I have the same troubles with O3 at home on my SMP machine, however
since the same kernel (2.6.8-rc2-mm2-O3) works flawlessly here at work
on a UP P4 I thought it to be SMP related.

I also tried booting my dual athlon with noapic but that did not solve
the problem.

I have not had enough time yet to file a proper bug report but seeing
this message I wanted to second it.

Are there any known SMP related problems with your patches?

and would my dmesg and .config from home be enough ?

kind regards,

Peter Zijlstra

Re: [patch] voluntary-preempt-2.6.8-rc2-O2

[Rudo Thomas]

> > I just wanted to report that O3 (+preempt-timing-O2) locks up hard at
> > random occasions, even with voluntary-preempt=2 preempt=1 set at boot
> > time. I never changed any of /proc/irq/*/threaded.
> 
> could you check whether it works with all APIC options turned off in the
> .config?

It appears to. With APIC on, it crashed after 10 and 25 minutes. Without APIC,
it survived two hours.

Hope that helps.

Rudo.

Re: [patch] voluntary-preempt-2.6.8-rc2-O2

[Thomas Charbonnel]

Ingo Molnar wrote :
> On Mon, 2 Aug 2004, Shane Shrybman wrote:
> 
> > Also, had to turn of parport in the config to get it to compile.
> > 
> > drivers/parport/share.c:77: unknown field `generic_enable_irq' specified
> > in initializer
> > drivers/parport/share.c:78: unknown field `generic_disable_irq'
> > specified in initializer
> 
> thx - i fixed this in -O3.
> 
> 	Ingo

In the end I found the cause of those latency spikes I was seeing every
~8 seconds. They are caused by ACPI. I tried to narrow the problem down,
and they're here whenever I compile ACPI in (even with no option and no
additional module) unless I specify acpi=off or acpi=ht (I don't have a
HT cpu, but it could be a clue as the ACPI interpreter is disabled in
this mode). I don't really hope that this will ever get fixed as my
toshiba laptop model is known to have a buggy bios WRT ACPI (I already
tried an alternate dsdt table that fixed a battery status reporting
issue, but the latency problem was still there).

Using your updated version of wli's preempt-timing patch on top of -O2,
here are the results :

On X startup :

Aug  2 15:40:08 satellite (X/4647): 1587us non-preemptible critical
section violated 1000 us preempt threshold starting at
voluntary_resched+0x3e/0x70 and ending at sys_ioctl+0xdd/0x2a0
Aug  2 15:40:08 satellite [<c010574e>] dump_stack+0x1e/0x30
Aug  2 15:40:08 satellite [<c011723e>] dec_preempt_count+0x3e/0x50
Aug  2 15:40:08 satellite [<c016956d>] sys_ioctl+0xdd/0x2a0
Aug  2 15:40:08 satellite [<c01051a5>] sysenter_past_esp+0x52/0x71


While accessing the file system (this one is very frequent):

Aug  2 15:32:24 satellite (bash/5298): 1095us non-preemptible critical
section violated 1000 us preempt threshold starting at
search_by_key+0x120/0x1140 and ending at voluntary_resched+0x1a/0x70
Aug  2 15:32:24 satellite [<c010574e>] dump_stack+0x1e/0x30
Aug  2 15:32:24 satellite [<c01171a6>] touch_preempt_timing+0x36/0x50
Aug  2 15:32:24 satellite [<c042856a>] voluntary_resched+0x1a/0x70
Aug  2 15:32:24 satellite [<c0158c44>] __getblk+0x44/0x70
Aug  2 15:32:24 satellite [<c01ae348>] search_by_key+0x78/0x1140
Aug  2 15:32:24 satellite [<c01af4bc>]
search_for_position_by_key+0xac/0x3f0
Aug  2 15:32:24 satellite [<c019e0c4>]
reiserfs_allocate_blocks_for_region+0x354/0x15b0
Aug  2 15:32:24 satellite [<c01a0c4c>] reiserfs_file_write+0x61c/0x8d0
Aug  2 15:32:24 satellite [<c0155e2f>] vfs_write+0xcf/0x140
Aug  2 15:32:24 satellite [<c0155f3f>] sys_write+0x3f/0x60
Aug  2 15:32:24 satellite [<c01051a5>] sysenter_past_esp+0x52/0x71


Mounting a reiserfs volume :

Aug  2 15:26:22 satellite (mount/2965): 2462us non-preemptible critical
section
violated 1000 us preempt threshold starting at
voluntary_resched+0x3e/0x70 and ending at voluntary_resched+0x1a/0x70
Aug  2 15:26:22 satellite [<c010574e>] dump_stack+0x1e/0x30
Aug  2 15:26:22 satellite [<c01171a6>] touch_preempt_timing+0x36/0x50
Aug  2 15:26:22 satellite [<c042856a>] voluntary_resched+0x1a/0x70
Aug  2 15:26:22 satellite [<c0158c44>] __getblk+0x44/0x70
Aug  2 15:26:22 satellite [<c0158cef>] __bread+0x1f/0x40
Aug  2 15:26:22 satellite [<c01b6d05>] journal_read+0xa5/0x520
Aug  2 15:26:22 satellite [<c01b7b8c>] journal_init+0x6ac/0x7f0
Aug  2 15:26:22 satellite [<c01a772c>] reiserfs_fill_super+0x27c/0x6e0
Aug  2 15:26:22 satellite [<c015d17e>] get_sb_bdev+0x13e/0x170
Aug  2 15:26:22 satellite [<c01a7bff>] get_super_block+0x2f/0x40
Aug  2 15:26:22 satellite [<c015d3f5>] do_kern_mount+0xa5/0x180
Aug  2 15:26:22 satellite [<c0174721>] do_new_mount+0x71/0xb0
Aug  2 15:26:22 satellite [<c0174e09>] do_mount+0x169/0x1b0
Aug  2 15:26:22 satellite [<c0175250>] sys_mount+0xb0/0x140
Aug  2 15:26:22 satellite [<c01051a5>] sysenter_past_esp+0x52/0x71



Another problem I had while trying the preempt-timing patch is that
using clock=pmtmr flooded my logs because the resolution of the detected
violations was 1ms, as shown below :

Aug  2 15:22:35 satellite (pdflush/43): 1000us non-preemptible critical
section
violated 1000 us preempt threshold starting at
voluntary_resched+0x3e/0x70 and ending at do_journal_end+0x4cf/0xb80
Aug  2 15:22:35 satellite [<c010574e>] dump_stack+0x1e/0x30
Aug  2 15:22:35 satellite [<c01171a6>] touch_preempt_timing+0x36/0x50
Aug  2 15:22:35 satellite [<c01b99ef>] do_journal_end+0x4cf/0xb80
Aug  2 15:22:35 satellite [<c01b8acc>] journal_end_sync+0x4c/0x90
Aug  2 15:22:35 satellite [<c01a514e>] reiserfs_sync_fs+0x5e/0xb0
Aug  2 15:22:35 satellite [<c015c7bc>] sync_supers+0xfc/0x110
Aug  2 15:22:35 satellite [<c013d911>] wb_kupdate+0x31/0x110
Aug  2 15:22:35 satellite [<c013e466>] __pdflush+0xd6/0x200
Aug  2 15:22:35 satellite [<c013e5b8>] pdflush+0x28/0x30
Aug  2 15:22:35 satellite [<c012d96a>] kthread+0xaa/0xb0
Aug  2 15:22:35 satellite [<c01032f5>] kernel_thread_helper+0x5/0x10
Aug  2 15:22:43 satellite printk: 5 messages suppressed.
(I also had 2000us, 3000us, and 4000us violations)

Using clock=tsc worked just fine.

Thanks for all the work you've done and are still doing on this,
Thomas

Re: [patch] voluntary-preempt-2.6.8-rc2-O2

[Paulo Marques]

Thomas Charbonnel wrote:
>....
> While accessing the file system (this one is very frequent):
> 
> Aug  2 15:32:24 satellite (bash/5298): 1095us non-preemptible critical
> section violated 1000 us preempt threshold starting at
> search_by_key+0x120/0x1140 and ending at voluntary_resched+0x1a/0x70
> Aug  2 15:32:24 satellite [<c010574e>] dump_stack+0x1e/0x30
> Aug  2 15:32:24 satellite [<c01171a6>] touch_preempt_timing+0x36/0x50
> Aug  2 15:32:24 satellite [<c042856a>] voluntary_resched+0x1a/0x70
> Aug  2 15:32:24 satellite [<c0158c44>] __getblk+0x44/0x70
> Aug  2 15:32:24 satellite [<c01ae348>] search_by_key+0x78/0x1140
> Aug  2 15:32:24 satellite [<c01af4bc>]
> search_for_position_by_key+0xac/0x3f0
> Aug  2 15:32:24 satellite [<c019e0c4>]
> reiserfs_allocate_blocks_for_region+0x354/0x15b0
> Aug  2 15:32:24 satellite [<c01a0c4c>] reiserfs_file_write+0x61c/0x8d0
                                          ^^^^^^^^
I remember some discussion on a "voluntary preempt" thread, about 
reiserfs being bad for latency.

You might search the archives for this, but as far as I remember, ext3 
was a better alternative, latency-wise.

-- 
Paulo Marques - www.grupopie.com
"In a world without walls and fences who needs windows and gates?"