Re: Timeout regression introduced by 242f9dcb8ba6f68fcd217a119a7648a4f69290e9

[Tejun Heo <tj@kernel.org>]

James Bottomley wrote:
> On Sun, 2008-10-26 at 18:46 +0900, Tejun Heo wrote:
>> Hello, Jens.
>>
>> Commit 242f9dcb8ba6f68fcd217a119a7648a4f69290e9 introduces a strange
>> regression for libata.  The second timeout gives puts different
>> pointer from the issued command onto eh_cmd_q breaking libata EH
>> command matching which triggers WARN_ON() in ata_eh_finish() and hangs
>> command processing or causes oops later depending on circumstances.
>>
>> Here are logs with induced timeouts (patch attached).  In commit
>> 242f9dcb8, the XXX messages for the second timeout shows different
>> scsi_cmd pointers for eh_cmd_q and qc->scmd which is initialized by
>> ata_scsi_qc_new() during command translation.
> 
> I can't see a way we could be getting a different command passed in from
> the actual one, since the only way to lose the command from the request
> is to go through the command completion routines which free it (and end
> the request).

I have no idea either.  It's something in the timeout logic because on
the issue path the scmd pointer is identical but on tiemout pointer
for another scmd is queued on eh_cmd_q, which doesn't make much sense.

> However, since the WARN_ON is specifically comparing the command with
> the one found by the active tag, could this actually be a problem caused
> by block tags?  I note that libata still uses its own array of
> outstanding tags (ap->qcmd[tag]) instead of finding them using
> blk_queue_find_tag() (or scsi_find_tag()).

Nope, the tested commits are before the block queue tag transition and
I tested two consecutive commits.  242f9dcb^ is okay.  242f9dcb is
not.

Thanks.

-- 
tejun