isp issues on recent -STABLE

[Eric Anderson]

On 08/10/06 14:35, Eric Anderson wrote:
> Lately (the past week or so), I've been having a lot of trouble with one 
>   of my servers.  The system has two QLogic (2312) cards in it, only one 
> connected to the storage (via fiber channel switch).
> 
> Basically, under heavy disk load, I get mass warnings to the console, 
> and then the system hangs, unpingable.  Hitting the power button 
> (sending ACPI power down) doesn't do anything, except for a warning.
> 
> I'm running -STABLE as of about 2 days ago, but prior to that I was 
> running from about early June time frame.
> 
> The lock-up happens nearly daily, when my backups are running (using 
> rsync), so I'm sure it will happen again tonight.  I've got the debugger 
> and all enabled in the kernel, but I couldn't seem to break into it last 
> time it died.
> 
> I know there have been recent changes to the isp driver, so I'm 
> wondering if it's related.  I may try reverting back to older -stable 
> and see if it goes away.  In the mean time, any suggestions for debugging?
> 
> Eric
> 
> 


Just to follow up with more details, here's the messages I get before 
the lock up:

[..snip..]
Aug  9 23:02:10 snapshot1 kernel: isp0: command timed out for 0.2.2
Aug  9 23:02:10 snapshot1 kernel: (da8:isp0:0:2:2): Command timed out
Aug  9 23:02:10 snapshot1 kernel: (da8:isp0:0:2:2): Retrying Command
Aug  9 23:26:58 snapshot1 kernel: (da3:isp0:0:1:0): Queue Full
Aug  9 23:26:58 snapshot1 kernel: (da3:isp0:0:1:0): tagged openings now 254
Aug  9 23:26:58 snapshot1 kernel: (da3:isp0:0:1:0): Retrying Command
Aug  9 23:26:58 snapshot1 kernel: (da3:isp0:0:1:0): Queue Full
Aug  9 23:26:58 snapshot1 kernel: (da3:isp0:0:1:0): tagged openings now 253
Aug  9 23:26:58 snapshot1 kernel: (da3:isp0:0:1:0): Retrying Command
Aug  9 23:26:58 snapshot1 kernel: (da3:isp0:0:1:0): Queue Full
Aug  9 23:26:58 snapshot1 kernel: (da3:isp0:0:1:0): tagged openings now 252
[..continuing in this pattern..]
Aug 10 00:46:10 snapshot1 kernel: isp0: command timed out for 0.2.2
Aug 10 00:46:10 snapshot1 kernel: (da8:isp0:0:2:2): Command timed out
Aug 10 00:46:10 snapshot1 kernel: (da8:isp0:0:2:2): Retrying Command
Aug 10 00:52:18 snapshot1 kernel: (da8:isp0:0:2:2): Queue Full
Aug 10 00:52:18 snapshot1 kernel: (da8:isp0:0:2:2): tagged openings now 96
[..snip..]
Aug 10 00:52:18 snapshot1 kernel: (da8:isp0:0:2:2): Retrying Command
Aug 10 00:52:18 snapshot1 kernel: (da8:isp0:0:2:2): Queue Full
Aug 10 00:52:18 snapshot1 kernel: (da8:isp0:0:2:2): tagged openings now 12
Aug 10 00:52:18 snapshot1 kernel: (da8:isp0:0:2:2): Retrying Command
Aug 10 01:07:30 snapshot1 kernel: isp0: command timed out for 0.2.1
Aug 10 01:07:30 snapshot1 kernel: (da7:isp0:0:2:1): Command timed out
Aug 10 01:07:30 snapshot1 kernel: (da7:isp0:0:2:1): Retrying Command
Aug 10 01:07:30 snapshot1 kernel: isp0: command timed out for 0.2.1
Aug 10 01:07:30 snapshot1 kernel: (da7:isp0:0:2:1): Command timed out
Aug 10 01:07:30 snapshot1 kernel: (da7:isp0:0:2:1): Retrying Command
Aug 10 01:24:16 snapshot1 kernel: (da2:isp0:0:0:2): Queue Full
Aug 10 01:24:16 snapshot1 kernel: (da2:isp0:0:0:2): tagged openings now 254
Aug 10 01:24:16 snapshot1 kernel: (da2:isp0:0:0:2): Retrying Command
Aug 10 01:24:16 snapshot1 kernel: (da2:isp0:0:0:2): Queue Full
Aug 10 01:24:16 snapshot1 kernel: (da2:isp0:0:0:2): tagged openings now 253
Aug 10 01:24:16 snapshot1 kernel: (da2:isp0:0:0:2): Retrying Command
Aug 10 02:00:24 snapshot1 kernel: isp0: command timed out for 0.2.1
Aug 10 02:00:24 snapshot1 kernel: (da7:isp0:0:2:1): Command timed out
Aug 10 02:00:24 snapshot1 kernel: (da7:isp0:0:2:1): Retrying Command
Aug 10 02:00:24 snapshot1 kernel: isp0: command timed out for 0.2.1
Aug 10 02:00:24 snapshot1 kernel: (da7:isp0:0:2:1): Command timed out
Aug 10 02:00:24 snapshot1 kernel: (da7:isp0:0:2:1): Retrying Command
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): Queue Full
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): tagged openings now 254
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): Retrying Command
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): Queue Full
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): tagged openings now 253
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): Retrying Command
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): Queue Full
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): tagged openings now 252
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): Retrying Command
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): Queue Full
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): tagged openings now 251
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): Retrying Command
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): Queue Full
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): tagged openings now 250
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): Retrying Command
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): Queue Full
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): tagged openings now 249
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): Retrying Command
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): Queue Full
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): tagged openings now 248
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): Retrying Command
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): Queue Full
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): tagged openings now 247
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): Retrying Command
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): Queue Full
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): tagged openings now 246
Aug 10 02:27:53 snapshot1 kernel: (da5:isp0:0:1:2): Retrying Command
Aug 10 02:31:38 snapshot1 kernel: isp0: command timed out for 0.2.2
Aug 10 02:31:38 snapshot1 kernel: (da8:isp0:0:2:2): Command timed out
Aug 10 02:31:38 snapshot1 kernel: (da8:isp0:0:2:2): Retrying Command
Aug 10 02:31:38 snapshot1 kernel: isp0: command timed out for 0.2.2
Aug 10 02:31:38 snapshot1 kernel: (da8:isp0:0:2:2): Command timed out
Aug 10 02:31:38 snapshot1 kernel: (da8:isp0:0:2:2): Retrying Command
Aug 10 02:42:14 snapshot1 kernel: isp0: command timed out for 0.2.1
Aug 10 02:42:14 snapshot1 kernel: (da7:isp0:0:2:1): Command timed out
Aug 10 02:42:14 snapshot1 kernel: (da7:isp0:0:2:1): Retrying Command
[..machine locks up around 03:08..]

This happened while doing an fsck on one of the filesystems on one of 
these devices (I can't recall which).

Eric


-- 
------------------------------------------------------------------------
Eric Anderson        Sr. Systems Administrator        Centaur Technology
Anything that works is better than anything that doesn't.
------------------------------------------------------------------------