BUG: [2.4.18+] IDE Race Condition

DISCUSSION Ross Biro 3 participants 10 messages Jan 27, 2003 – Jan 30, 2003

Share & tools

Ross Biro

author

2003-01-27 17:02 UTC #0 lore raw

There is at least one more IDE race condition in 2.4.18 and 2.4.21-pre3. Basically the interrupt for the controller being serviced is left on while setting up the next command. I'm not sure how much trouble it can cause but it does lead to some interesting stack traces.

The condition
if (masked_irq && hwif->irq != masked_irq)
in ide_do_request should be replaced with
if (!masked_irq || hwif->irq != masked_irq)
in two places.

This doesn't totally eliminate the race conditions, but it does minimize them some more. I can still see a race in 2.4.18. I'll say more about it once I've tracked it down.

Ross

Ross Biro

author

2003-01-27 17:25 UTC #1 lore raw

The net effect of this race condition and the other one I spotted is that you may see some interesting messages in your log file and you can detect the race condition if you look for it hard enough. I don't currently see any bad effects.

Ross

Quoted 9 lines · Ross Biro

There is at least one more IDE race condition in 2.4.18 and 2.4.21-pre3. Basically the interrupt for the controller being serviced is left on while setting up the next command. I'm not sure how much trouble it can cause but it does lead to some interesting stack traces.
The condition
if (masked_irq && hwif->irq != masked_irq)
in ide_do_request should be replaced with
if (!masked_irq || hwif->irq != masked_irq)
in two places.

Andre Hedrick

2003-01-28 02:42 UTC #2 lore raw

Okay, how do you reproduce it to see the effects?

Quoted 23 lines · Ross Biro

The net effect of this race condition and the other one I spotted is that you may see some interesting messages in your log file and you can detect the race condition if you look for it hard enough. I don't currently see any bad effects.
Ross
Quoted 6 lines · Ross Biro
There is at least one more IDE race condition in 2.4.18 and 2.4.21-pre3. Basically the interrupt for the controller being serviced is left on while setting up the next command. I'm not sure how much trouble it can cause but it does lead to some interesting stack traces.
Quoted 6 lines
The condition
if (masked_irq && hwif->irq != masked_irq)
in ide_do_request should be replaced with
if (!masked_irq || hwif->irq != masked_irq)
in two places.

Quoted 6 lines

-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Andre Hedrick
LAD Storage Consulting Group

Ross Biro

author

2003-01-28 16:40 UTC #3 lore raw

Easy, it happens all the time, there are just no tests in place to see it.

We are keeping a histogram of how long every IDE DMA transfer takes place. In ide_intr we record the time and set the start time in ide_drive_t to 0. In ide_dma_proc, ide_dma_begin right AFTER activating the dma, we store the current value of jiffies in start time in ide_drive_t.

In both those places we check to make sure that the value of start_time is sensible. In ide_dma_begin, we make sure it's 0 and in ide_dma_intr, we make sure its non-zero. Because of this race condition, we often saw DMAs finish before they began.

In the normal kernel, the only thing I can see that could go wrong would be that the printk

printk("%s: ide_intr: huh? expected NULL handler on exit\n", drive->name);

in ide_intr could be triggered. I've never seen it happen, but I believe with enough effort, it could be made to occur.

Ross

Quoted 38 lines · Andre Hedrick

Okay, how do you reproduce it to see the effects?
Quoted 18 lines · Ross Biro
The net effect of this race condition and the other one I spotted is that you may see some interesting messages in your log file and you can detect the race condition if you look for it hard enough. I don't currently see any bad effects.
Ross
Quoted 10 lines · Ross Biro
There is at least one more IDE race condition in 2.4.18 and 2.4.21-pre3. Basically the interrupt for the controller being serviced is left on while setting up the next command. I'm not sure how much trouble it can cause but it does lead to some interesting stack traces.
The condition
if (masked_irq && hwif->irq != masked_irq)
in ide_do_request should be replaced with
if (!masked_irq || hwif->irq != masked_irq)
in two places.
Quoted 8 lines
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Andre Hedrick
LAD Storage Consulting Group

Andre Hedrick

2003-01-28 17:25 UTC #4 lore raw

Ross,

How did you create the sub-microsecond timers to profile the device/driver behavior? I had been working on this for a while but little success. This is one of the key methods to predict device failure.

One of the goals of the prebuilder it find slam prebuild commands down the pipes to force breakages and races to show up.

So you have a possible solution?

Cheers,

Andre Hedrick
LAD Storage Consulting Group

Quoted 70 lines · Ross Biro

Easy, it happens all the time, there are just no tests in place to see it.
We are keeping a histogram of how long every IDE DMA transfer takes place. In ide_intr we record the time and set the start time in ide_drive_t to 0. In ide_dma_proc, ide_dma_begin right AFTER activating the dma, we store the current value of jiffies in start time in ide_drive_t.
In both those places we check to make sure that the value of start_time is sensible. In ide_dma_begin, we make sure it's 0 and in ide_dma_intr, we make sure its non-zero. Because of this race condition, we often saw DMAs finish before they began.
In the normal kernel, the only thing I can see that could go wrong would be that the printk
printk("%s: ide_intr: huh? expected NULL handler on exit\n", drive->name);
in ide_intr could be triggered. I've never seen it happen, but I believe with enough effort, it could be made to occur.
Ross
Quoted 44 lines · Andre Hedrick
Okay, how do you reproduce it to see the effects?
Quoted 24 lines · Ross Biro
The net effect of this race condition and the other one I spotted is that you may see some interesting messages in your log file and you can detect the race condition if you look for it hard enough. I don't currently see any bad effects.
Ross
Quoted 5 lines · Ross Biro
There is at least one more IDE race condition in 2.4.18 and 2.4.21-pre3. Basically the interrupt for the controller being serviced is left on while setting up the next command. I'm not sure how much trouble it can cause but it does lead to some interesting stack traces.
Quoted 8 lines
The condition
if (masked_irq && hwif->irq != masked_irq)
in ide_do_request should be replaced with
if (!masked_irq || hwif->irq != masked_irq)
in two places.
Quoted 8 lines
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Andre Hedrick
LAD Storage Consulting Group

Ross Biro

author

2003-01-28 17:33 UTC #5 lore raw

Sorry, we are not using sub-microsecond timers, we are just using the latest-greatest-bugiest hard drives and lots of them. We can see problems like this because we can run on so many machines at once. Even something that has a small percentage chance of showing up, we can see pretty quick.

We do have a bus analyzer that can time things down to about 4ns. That has been invaluable for tracking down some of these issues.

Ross

Quoted 90 lines · Andre Hedrick

Ross,
How did you create the sub-microsecond timers to profile the device/driver behavior? I had been working on this for a while but little success. This is one of the key methods to predict device failure.
One of the goals of the prebuilder it find slam prebuild commands down the pipes to force breakages and races to show up.
So you have a possible solution?
Cheers,
Andre Hedrick
LAD Storage Consulting Group
Quoted 66 lines · Ross Biro
Easy, it happens all the time, there are just no tests in place to see it.
We are keeping a histogram of how long every IDE DMA transfer takes place. In ide_intr we record the time and set the start time in ide_drive_t to 0. In ide_dma_proc, ide_dma_begin right AFTER activating the dma, we store the current value of jiffies in start time in ide_drive_t.
In both those places we check to make sure that the value of start_time is sensible. In ide_dma_begin, we make sure it's 0 and in ide_dma_intr, we make sure its non-zero. Because of this race condition, we often saw DMAs finish before they began.
In the normal kernel, the only thing I can see that could go wrong would be that the printk
printk("%s: ide_intr: huh? expected NULL handler on exit\n", drive->name);
in ide_intr could be triggered. I've never seen it happen, but I believe with enough effort, it could be made to occur.
Ross
Quoted 47 lines · Andre Hedrick
Okay, how do you reproduce it to see the effects?
Quoted 22 lines · Ross Biro
The net effect of this race condition and the other one I spotted is that you may see some interesting messages in your log file and you can detect the race condition if you look for it hard enough. I don't currently see any bad effects.
Ross
Quoted 12 lines · Ross Biro
There is at least one more IDE race condition in 2.4.18 and 2.4.21-pre3. Basically the interrupt for the controller being serviced is left on while setting up the next command. I'm not sure how much trouble it can cause but it does lead to some interesting stack traces.
The condition
if (masked_irq && hwif->irq != masked_irq)
in ide_do_request should be replaced with
if (!masked_irq || hwif->irq != masked_irq)
in two places.
Quoted 10 lines
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Andre Hedrick
LAD Storage Consulting Group

Andre Hedrick

2003-01-28 17:57 UTC #6 lore raw

Well if someone would drop a $16,000->$27,000 USD bus analyzer with switchable PODS, I could do wonders! Well I am not sure how to take this on the chin. Either "nice try, but you didn't get there" or "nice try, it is not possible to get there without more tools"; regardless, it needs to be fixed. So if you have an answer and a trace to support it ... bring it on!

Cheers,

Andre Hedrick
LAD Storage Consulting Group

Quoted 121 lines · Ross Biro

Sorry, we are not using sub-microsecond timers, we are just using the latest-greatest-bugiest hard drives and lots of them. We can see problems like this because we can run on so many machines at once. Even something that has a small percentage chance of showing up, we can see pretty quick.
We do have a bus analyzer that can time things down to about 4ns. That has been invaluable for tracking down some of these issues.
Ross
Quoted 104 lines · Andre Hedrick
Ross,
How did you create the sub-microsecond timers to profile the device/driver behavior? I had been working on this for a while but little success. This is one of the key methods to predict device failure.
One of the goals of the prebuilder it find slam prebuild commands down the pipes to force breakages and races to show up.
So you have a possible solution?
Cheers,
Andre Hedrick
LAD Storage Consulting Group
Quoted 80 lines · Ross Biro
Easy, it happens all the time, there are just no tests in place to see it.
We are keeping a histogram of how long every IDE DMA transfer takes place. In ide_intr we record the time and set the start time in ide_drive_t to 0. In ide_dma_proc, ide_dma_begin right AFTER activating the dma, we store the current value of jiffies in start time in ide_drive_t.
In both those places we check to make sure that the value of start_time is sensible. In ide_dma_begin, we make sure it's 0 and in ide_dma_intr, we make sure its non-zero. Because of this race condition, we often saw DMAs finish before they began.
In the normal kernel, the only thing I can see that could go wrong would be that the printk
printk("%s: ide_intr: huh? expected NULL handler on exit\n", drive->name);
in ide_intr could be triggered. I've never seen it happen, but I believe with enough effort, it could be made to occur.
Ross
Quoted 53 lines · Andre Hedrick
Okay, how do you reproduce it to see the effects?
Quoted 28 lines · Ross Biro
The net effect of this race condition and the other one I spotted is that you may see some interesting messages in your log file and you can detect the race condition if you look for it hard enough. I don't currently see any bad effects.
Ross
Quoted 5 lines · Ross Biro
There is at least one more IDE race condition in 2.4.18 and 2.4.21-pre3. Basically the interrupt for the controller being serviced is left on while setting up the next command. I'm not sure how much trouble it can cause but it does lead to some interesting stack traces.
Quoted 10 lines
The condition
if (masked_irq && hwif->irq != masked_irq)
in ide_do_request should be replaced with
if (!masked_irq || hwif->irq != masked_irq)
in two places.
Quoted 10 lines
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Andre Hedrick
LAD Storage Consulting Group

Alan Cox

2003-01-30 16:30 UTC #7 lore raw

In reply to Ross Biro

Quoted 5 lines · Ross Biro

The condition
if (masked_irq && hwif->irq != masked_irq)
in ide_do_request should be replaced with
if (!masked_irq || hwif->irq != masked_irq)
in two places.

Which would also shorten to if (hwif->irq != masked_irq) it seems

Ross Biro

author

2003-01-30 16:50 UTC #8 lore raw

Quoted 10 lines · Alan Cox

Quoted 5 lines
st should be replaced with
if (!masked_irq || hwif->irq != masked_irq)
in two places.
Which would also shorten to if (hwif->irq != masked_irq) it seems

With the assumption that hwif->irq != 0 which is implicit now. Perhaps we should make the assumption explicit,

if (unlikely(hwif->irq == 0)) {
BUG();
}
if (hwif->irq != masked_irq) ....

Ross

Alan Cox

2003-01-30 16:57 UTC #9 lore raw

Quoted 8 lines · Ross Biro

With the assumption that hwif->irq != 0 which is implicit now. Perhaps we should make the assumption explicit,
if (unlikely(hwif->irq == 0)) {
    BUG();
}
if (hwif->irq != masked_irq) ....

Actually I fixed the IRQ 0 assumption in that code while I was at it 8)