Extremely poor interactive performance under heavy i/o

[Marc Michelsen <marc u washington edu>]

Hi,

I have a new Tyan S4882 quad opteron system with 16GB of ram and RHEL4AS 
x86_64 installed -
academic edition so no support which is why I post here. All the RHEL-4 
updates have been applied.
The system also has 4 3ware cards with 40 400GB Hitachi drives and 2 WD 
Raptors
on the SiI onboard SATA controller for a mirrored system disk. All 
filesystems are ext3.

Ok, I was just doing a really basic i/o benchmark like this:
time dd if=/dev/zero of=x bs=1024k count=20000
which writes out 20GB of zeroes to a file in your current directory.
If I do this the interactive performance of the machine becomes horribly 
slow
to unusable. It doesnt matter if I'm writing to a 3ware disk or a SiI disk.
I had a window running top while doing it and eventually it would just stop
updating for minutes at a time. Each time I ran it I would see some output
in the system log like this:

Mar  3 12:53:43 challenger kernel: warning: many lost ticks.
Mar  3 12:53:43 challenger kernel: Your time source seems to be instable 
or some driver is hogging interupts
Mar  3 12:53:43 challenger kernel: rip __do_softirq+0x4d/0xd0
Mar  3 12:56:54 challenger crond(pam_unix)[4351]: session opened for 
user root by (uid=0)
Mar  3 12:57:37 challenger kernel: X: page allocation failure. order:0, 
mode:0x50
Mar  3 12:57:37 challenger kernel:
Mar  3 12:57:37 challenger kernel: Call 
Trace:<ffffffff80157ba6>{__alloc_pages+768} 
<ffffffff80157c3a>{__get_free_pages+11}
Mar  3 12:57:37 challenger kernel:        
<ffffffff8015aab4>{kmem_getpages+36} 
<ffffffff8015b24f>{cache_alloc_refill+615}
Mar  3 12:57:37 challenger kernel:        
<ffffffff8015af87>{kmem_cache_alloc+90} 
<ffffffffa006646b>{:jbd:journal_start+132}
Mar  3 12:57:37 challenger kernel:        
<ffffffffa007bab0>{:ext3:ext3_ordered_writepage+127}
Mar  3 12:57:37 challenger kernel:        
<ffffffff8015eb02>{shrink_zone+3102} <ffffffff801309d8>{move_tasks+186}
Mar  3 12:57:37 challenger kernel:        
<ffffffff8013057d>{finish_task_switch+55} 
<ffffffff802f78d6>{thread_return+41}
Mar  3 12:57:37 challenger kernel:        
<ffffffff8013d038>{del_timer_sync+31} 
<ffffffff8013d0d8>{del_singleshot_timer_sync+21}
Mar  3 13:00:09 challenger crond(pam_unix)[4394]: session opened for 
user root by (uid=0)
Mar  3 13:00:09 challenger crond(pam_unix)[4393]: session opened for 
user root by (uid=0)
Mar  3 13:02:02 challenger kernel:        
<ffffffff802f7f39>{schedule_timeout+252} 
<ffffffff8015f0e6>{try_to_free_pages+297}
Mar  3 13:02:03 challenger crond(pam_unix)[4403]: session opened for 
user root by (uid=0)
Mar  3 13:02:03 challenger crond(pam_unix)[4351]: session closed for 
user root
Mar  3 13:04:33 challenger kernel:        
<ffffffff8013302c>{autoremove_wake_function+0} 
<ffffffff80157ab5>{__alloc_pages+527}
Mar  3 13:04:33 challenger kernel:        
<ffffffff80157c3a>{__get_free_pages+11} <ffffffff80183997>{__pollwait+58}
Mar  3 13:04:34 challenger kernel:        
<ffffffff802f3a5b>{unix_poll+35} <ffffffff80183ca8>{do_select+656}
Mar  3 13:04:34 challenger kernel:        
<ffffffff8018395d>{__pollwait+0} <ffffffff80184142>{sys_select+820}
Mar  3 13:04:34 challenger kernel:        
<ffffffff8011000e>{system_call+126}
Mar  3 13:04:34 challenger kernel: ntpd: page allocation failure. 
order:0, mode:0x50
Mar  3 13:04:34 challenger kernel:
Mar  3 13:04:34 challenger kernel: Call 
Trace:<ffffffff80157ba6>{__alloc_pages+768} 
<ffffffff80157c3a>{__get_free_pages+11}
Mar  3 13:04:34 challenger kernel:        
<ffffffff8015aab4>{kmem_getpages+36} 
<ffffffff8015b24f>{cache_alloc_refill+615}
Mar  3 13:04:34 challenger kernel:        
<ffffffff8015af87>{kmem_cache_alloc+90} 
<ffffffffa006646b>{:jbd:journal_start+132}
Mar  3 13:04:34 challenger crond(pam_unix)[4403]: session closed for 
user root
Mar  3 13:04:34 challenger kernel:        
<ffffffffa007bab0>{:ext3:ext3_ordered_writepage+127}
Mar  3 13:04:34 challenger crond(pam_unix)[4394]: session closed for 
user root
Mar  3 13:04:34 challenger kernel:        
<ffffffff8015eb02>{shrink_zone+3102} 
<ffffffff802a3230>{neigh_resolve_output+578}
Mar  3 13:04:34 challenger kernel:        
<ffffffff8013057d>{finish_task_switch+55} 
<ffffffff802f78d6>{thread_return+41}
Mar  3 13:04:34 challenger kernel:        
<ffffffff8013d038>{del_timer_sync+31} 
<ffffffff8013d0d8>{del_singleshot_timer_sync+21}
Mar  3 13:04:34 challenger kernel:        
<ffffffff802f7f39>{schedule_timeout+252} 
<ffffffff8015f0e6>{try_to_free_pages+297}
Mar  3 13:04:34 challenger kernel:        
<ffffffff8013302c>{autoremove_wake_function+0} 
<ffffffff80157ab5>{__alloc_pages+527}
Mar  3 13:04:34 challenger kernel:        
<ffffffff80157c3a>{__get_free_pages+11} <ffffffff80183997>{__pollwait+58}
Mar  3 13:04:34 challenger kernel:        
<ffffffff8029b7aa>{datagram_poll+39} <ffffffff8029b783>{datagram_poll+0}
Mar  3 13:04:34 challenger kernel:        
<ffffffff8029b783>{datagram_poll+0} <ffffffff80183ca8>{do_select+656}
Mar  3 13:04:34 challenger kernel:        
<ffffffff8018395d>{__pollwait+0} <ffffffff80184142>{sys_select+820}
Mar  3 13:04:34 challenger kernel:        
<ffffffff8010fe5b>{sys_rt_sigreturn+532} <ffffffff8011000e>{system_call+126}

Since 2.6.11 just came out I decided to try that. I copied over 
/boot/config-2.6.9-5.0.3.ELsmp
to .config and make oldconfig and just hit return at all the new things.
It fixes the problem! The system remains very interactive while doing 
huge amounts of i/o.
No messages in the system log either. The only issue I have with this 
setup is that during boot up
it waits about 12 minutes in start_udev. So I would like to see what 
ever fixed it get into the RHEL-4 kernel.
I wondered if it had something to do with > 4GB and the IOMMU so I 
removed all but 2GB
of ram. It wasnt as bad but it still had the problem. As I added more 
ram back the problem
becomes more severe. Please fix this bug. Thanks

Marc