cvs commit: src/sys/kern kern_intr.c src/sys/sys interrupt.h

[Nate Lawson]

Nate Lawson wrote:
> John Baldwin wrote:
>> On Wednesday 02 May 2007 03:07:07 am Darren Reed wrote:
>>> On Wed, May 02, 2007 at 06:15:13AM +0000, Nate Lawson wrote:
>>>> njl         2007-05-02 06:15:13 UTC
>>>>
>>>>   FreeBSD src repository
>>>>
>>>>   Modified files:        (Branch: RELENG_6)
>>>>     sys/kern             kern_intr.c 
>>>>     sys/sys              interrupt.h 
>>>>   Log:
>>>>   MFC: rate-check the interrupt storm message and bump the counter 500 -> 
>> 1000
>>> Is this number, "500" or "1000" somehow "magical" for modern hardware?
>>>
>>> If I had a 500MHZ, 1GHz, 1.5GHz, 2GHz, 2.5GHz machines, each with the
>>> appropriate architecture, what would the correct value for this be?
>>> Is i always 1000 or should it be calculated?
>> It's a SWAG and tunable for machines where it doesn't work.  In practice the 
>> old setting seemed to be a bit too trigger-happy as I know my printer always 
>> triggered it, for example.
>>
> 
> There's more to it than just your Ghz number.  It's a counter of the
> number of times an interrupt has triggered while the previous one was
> being serviced.  The faster your kernel, the lower the number could be.
> 
> I have a slow early SMP Celeron system with a dc(4) adapter with 4 ports
> sharing an irq with my ata.  At 3 am, the nightly script kicks off
> enough IO that it triggers a bug in my dc(4) card that causes it to mask
> the interrupt too long.  Then, the irq storm suppression logic kicked
> in, causing ata to timeout the request.  The drive is on a mirror so I'd
> lose half the mirror, then rebuild in the morning.  With this value
> bumped, I don't have that problem any more but the real issue is why
> dc(4) is being so quirky under heavy shared irq load.
> 

This is on 6.x btw.  Is there any reason why our retries is so low?

sys/dev/ata/ata-disk.c:    request->retries = 2;

Here are the dc(4) and ata devices, note that they're sharing irq 18:
dc0: <Intel 21143 10/100BaseTX> port 0xc000-0xc07f mem
0xd5000000-0xd50003ff irq 19 at device 4.0 on pci2
miibus0: <MII bus> on dc0
ukphy0: <Generic IEEE 802.3u media interface> on miibus0
ukphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
dc0: Ethernet address: 00:80:c8:cd:36:85
dc1: <Intel 21143 10/100BaseTX> port 0xc400-0xc47f mem
0xd5001000-0xd50013ff irq 16 at device 5.0 on pci2
miibus1: <MII bus> on dc1
ukphy1: <Generic IEEE 802.3u media interface> on miibus1
ukphy1:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
dc1: Ethernet address: 00:80:c8:cd:36:86
dc2: <Intel 21143 10/100BaseTX> port 0xc800-0xc87f mem
0xd5002000-0xd50023ff irq 17 at device 6.0 on pci2
miibus2: <MII bus> on dc2
ukphy2: <Generic IEEE 802.3u media interface> on miibus2
ukphy2:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
dc2: Ethernet address: 00:80:c8:cd:36:87
dc3: <Intel 21143 10/100BaseTX> port 0xcc00-0xcc7f mem
0xd5003000-0xd50033ff irq 18 at device 7.0 on pci2
miibus3: <MII bus> on dc3
ukphy3: <Generic IEEE 802.3u media interface> on miibus3
ukphy3:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
dc3: Ethernet address: 00:80:c8:cd:36:88
pci0: <display, VGA> at device 15.0 (no driver attached)
atapci1: <HighPoint HPT366 UDMA66 controller> port
0xd400-0xd407,0xd800-0xd803,0xdc00-0xdcff irq 18 at device 19.0 on pci0
ata2: <ATA channel 0> on atapci1
atapci2: <HighPoint HPT366 UDMA66 controller> port
0xe000-0xe007,0xe400-0xe403,0xe800-0xe8ff irq 18 at device 19.1 on pci0
ata3: <ATA channel 0> on atapci2

And here are the error messages:
Apr 27 03:03:56 bento kernel: dc0: TX underrun -- increasing TX threshold
Apr 27 03:05:01 bento kernel: Interrupt storm detected on "irq18:";
throttling interrupt source
Apr 27 03:05:16 bento kernel: ad6: TIMEOUT - READ_DMA48 retrying (1
retry left) LBA=294226271
Apr 27 03:05:16 bento kernel: ad6: TIMEOUT - READ_DMA48 retrying (0
retries left) LBA=294226271
Apr 27 03:05:16 bento kernel: ad6: FAILURE - READ_DMA48 timed out
LBA=294226271
Apr 27 03:05:16 bento kernel: GEOM_MIRROR: Request failed (error=5).
ad6[READ(offset=150643850752, length=8192)]
Apr 27 03:05:16 bento kernel: GEOM_MIRROR: Device gm0: provider ad6
disconnected.

There appears to be no delay between resubmitting the requests each time
the TIMEOUT message occurs.  It all happens in 1 second.  Would it be
possible to schedule retries from a callout or thread to allow more
delay before failing them a second time?

I then rebuilt the array:

Apr 27 17:25:43 bento kernel: GEOM_MIRROR: Device gm0: provider ad6
detected.
Apr 27 17:25:43 bento kernel: GEOM_MIRROR: Device gm0: rebuilding
provider ad6.
Apr 27 17:36:58 bento kernel: dc0: TX underrun -- increasing TX threshold
Apr 27 18:12:25 bento kernel: dc0: TX underrun -- increasing TX threshold
Apr 27 18:20:59 bento kernel: dc1: TX underrun -- increasing TX threshold
Apr 27 19:41:32 bento kernel: GEOM_MIRROR: Device gm0: rebuilding
provider ad6 finished.
Apr 27 19:41:32 bento kernel: GEOM_MIRROR: Device gm0: provider ad6
activated.
Apr 28 04:22:04 bento kernel: ad6: TIMEOUT - READ_DMA retrying (1 retry
left) LBA=9894431

Note that I still got a timeout but it succeeded without error.  I think
this is a combination of the dc(4) and highpoint hpt366 driver
interaction.  dc(4) is probably holding Giant or something too long and
ata is being too sensitive to the slow hw.

Comments?

-- 
Nate