[2500] in linux-scsi channel archive
Timeout aborts & resets
daemon@ATHENA.MIT.EDU (Jose Manuel Cerqueira Esteves)
Sat Sep 20 12:20:30 1997
Date: Sat, 20 Sep 1997 17:17:08 +0100 (WET DST)
From: Jose Manuel Cerqueira Esteves <jmce@titania.cii.fc.ul.pt>
To: linux-scsi@vger.rutgers.edu
cc: djsb@aeisel.aeisel.pt
Greetings
A recently acquired dual Pentium Pro is experiencing
timeout aborts and resets when under heavy hard disk usage.
This machine is currently composed of:
230W SinoTech power supply
ASUS P65UP5 motherboard with C-P6ND processor board
2 200MHz Pentium Pro CPUs (stepping 9)
256MB of parity RAM
Matrox MGA Millenium, 4Mb ram
SMC EtherPower PCI ethernet adapter (DS21041 Tulip)
DPT PM2144UW SCSI adapter (v07H.1) (configured for 20MHz max transfer rate)
SCSI cable originally provided with the DPT adapter
2 Seagate ST52160N hard disks (SCSI ids 0 and 1),
one of them (1) terminating the bus
2 cooling fans on each cpu, 1 case fan on the front and 2 on the back
Tests have been made with the 2.0.30 kernel and more recently with
2.0.31-pre9. Almost always with 2.0.30, and always with 2.0.31-pre9,
after hanging for some time, operation proceeds normally, no I/O errors
are reported by running programs and no file or file system corruption has
been noticed.
Most tests until now were done using Dario Ballabio's EATA driver
(it had been suggested that this would currently be the most stable one),
and today I also tried Michael Neuffer's EATA-DMA driver.
Following a recent suggestion, I changed some of the timeout definitions,
multiplying values by 10:
in drivers/scsi/sd.c:
#define SD_TIMEOUT (200 * HZ)
#define SD_MOD_TIMEOUT (250 * HZ)
in drivers/scsi/scsi_ioctl.c:
#define NORMAL_TIMEOUT (100 * HZ)
#define FORMAT_UNIT_TIMEOUT (20 * 60 * 60 * HZ)
#define START_STOP_TIMEOUT (600 * HZ)
#define MOVE_MEDIUM_TIMEOUT (50 * 60 * HZ)
#define READ_ELEMENT_STATUS_TIMEOUT (50 * 60 * HZ)
(some of these are now huge, I know... I just multiplied all of them by 10)
in drivers/scsi/scsi.c:
#ifdef DEBUG
#define SCSI_TIMEOUT (50*HZ)
#else
#define SCSI_TIMEOUT (20*HZ)
#endif
#ifdef DEBUG
#define SENSE_TIMEOUT SCSI_TIMEOUT
#define ABORT_TIMEOUT SCSI_TIMEOUT
#define RESET_TIMEOUT SCSI_TIMEOUT
#else
#define SENSE_TIMEOUT (50*HZ/10)
#define RESET_TIMEOUT (50*HZ/10)
#define ABORT_TIMEOUT (50*HZ/10)
#endif
The number of abort events may have been reduced only a little as a
result. When a timeout occurs... one has now to wait for a longer time
until normal operation is resumed.
I have also made tests with a non-SMP kernel, but the problem persisted.
With the DPT adapter configured for 10 MHz max transfer rate (instead of
20 MHz), timeouts are less frequent but still occur.
At the end of this message I reproduce 2 sets of kernel messages,
already obtained with the new larger timeout values above:
In the first test, using the EATA driver, there were 8 "tar tvf" processes
running, processing four 370MB tar files on /dev/sdb1 (a pair of "tar tvf"
for each file), two "cmp" processes each comparing one of those files with
an identical one on /dev/sda4, and one "cat /dev/sdb1 > /dev/null"
(/dev/sdb1 occupies the whole of the second disk).
This test, which had been repeated several times before, always caused
timeout aborts.
In the second test, using the EATA-DMA driver, I had only launched 4 "tar
tvf" processes and one "cmp" when the problem started. During the hang
(which lasted for several minutes), I looked at the DPT controller LEDs,
of which numbers 1 ("busy") and 3 ("Computer Bus Transfer From Adapter")
where permanently lit (all others were off).
I have tried to check all recent available information concerning these
timeouts (and the SCSI FAQs), but my knowledge on SCSI matters is
extremely limited. Although these timeouts only occur, apparently, with a
heavy I/O load and would therefore not cause much harm to the tasks
planned for this computer for now, I need to know, before starting normal
operation, if it is likely that this problem is due to some hardware fault
or can be explained purely in terms of driver problems.
Therefore I would like to know, from someone familiar with such problems,
if the kernel messages below (and the behavior I just described) could
suggest an hardware problem. I would also like to get opinions on the
following:
- Cables provided with DPT adapters: have they been reliable?
- Termination provided by a Seagate drive: is it reliable? Is it
advisable to use a separate terminator instead?
- Maybe we need a power supply for more than 230W (one has been ordered
already, anyway). Could some of these timeout be symptoms of an inadequate
power supply?
- I am aware that the SCSI cable should not pass near other wires and
even case metal parts (although it seems that a distance of 1.27mm should
be enough); there are some points along our cable where that
constraint may not be fully satisfied. It easily touches the side of the
(horizontal) processor card, and each processor there has 2 fans.
In your experience, how common are SCSI problems due to interference
from other components or impedance changes due to other conductors?
- What other known SCSI kernel code changes are known to solve
timeout aborts? Until now I couldn't find a detailed list of
suggested changes, apart from the following comment by Michael Neuffer:
"You can eliminate practically all those bogus aborts if you increase the
timeout values by a factor of ten. The current SCSI midlevel code is
horribly broken and Eric Youngdale and I are working on fixing it."
Thank you very, very much in advance for any suggestion
J. Esteves
-- FIRST TEST: ------------------------------------------------------------
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 101410, scsi0, channel 0, id 1, lun 0 Read (6) 1c 98 30 68
00
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 59, target
0.1:0, pid 101410.
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 59 is in
use.
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 101420, scsi0, channel 0, id 1, lun 0 Read (10) 00 00 2a 0b
d0 00 00 18 00
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 5, target
0.1:0, pid 101420.
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 5 is in
use.
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 101422, scsi0, channel 0, id 1, lun 0 Read (10) 00 00 2a 0b
e8 00 00 90 00
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 7, target
0.1:0, pid 101422.
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 7 is in
use.
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 101423, scsi0, channel 0, id 1, lun 0 Write (6) 00 00 5a 02
00
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 8, target
0.1:0, pid 101423.
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 8 is in
use.
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 101424, scsi0, channel 0, id 1, lun 0 Read (6) 1c 98 98 6a
00
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 9, target
0.1:0, pid 101424.
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 9 is in
use.
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 101425, scsi0, channel 0, id 1, lun 0 Read (6) 1c 99 12 18
00
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 10, target
0.1:0, pid 101425.
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 10 is in
use.
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 101426, scsi0, channel 0, id 1, lun 0 Read (6) 1c 99 2a 98
00
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 11, target
0.1:0, pid 101426.
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 11 is in
use.
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 101427, scsi0, channel 0, id 0, lun 0 Read (10) 00 00 24 5a
d0 00 00 98 00
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 12, target
0.0:0, pid 101427.
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 12 is in
use.
Sep 18 19:32:52 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 101428, scsi0, channel 0, id 1, lun 0 Read (6) 06 a1 68 08
00
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 13, target
0.1:0, pid 101428.
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 13 is in
use.
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 101429, scsi0, channel 0, id 1, lun 0 Read (6) 06 a1 80 48
00
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 14, target
0.1:0, pid 101429.
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 14 is in
use.
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 101430, scsi0, channel 0, id 1, lun 0 Read (6) 06 a1 78 08
00
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 15, target
0.1:0, pid 101430.
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 15 is in
use.
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 101431, scsi0, channel 0, id 1, lun 0 Read (6) 06 a1 c8 98
00
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 16, target
0.1:0, pid 101431.
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 16 is in
use.
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 101432, scsi0, channel 0, id 1, lun 0 Read (6) 06 a1 70 08
00
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 17, target
0.1:0, pid 101432.
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 17 is in
use.
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 101433, scsi0, channel 0, id 1, lun 0 Read (6) 18 f2 fc 0a
00
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 18, target
0.1:0, pid 101433.
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 18 is in
use.
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 101434, scsi0, channel 0, id 1, lun 0 Read (6) 03 14 36 78
00
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 19, target
0.1:0, pid 101434.
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: EATA0, abort, mbox 19 ready,
DID_ABORT, pid 101434 done.
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 101435, scsi0, channel 0, id 0, lun 0 Read (10) 00 00 21 5b
ec 00 00 02 00
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 20, target
0.0:0, pid 101435.
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: EATA0, abort, mbox 20 ready,
DID_ABORT, pid 101435 done.
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 101436, scsi0, channel 0, id 0, lun 0 Read (6) 16 68 8c 02
00
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 21, target
0.0:0, pid 101436.
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: EATA0, abort, mbox 21 ready,
DID_ABORT, pid 101436 done.
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 101410, scsi0, channel 0, id 1, lun 0 Read (6) 1c 98 30 68
00
Sep 18 19:32:53 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 59, target
0.1:0, pid 101410.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 59 is in
use.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: SCSI host 0 abort (pid 101410)
timed out - resetting
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: SCSI bus is being reset for
host 0 channel 0.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, enter, target
0.1:0, pid 101410, reset_flags 2.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 5 in reset,
pid 101420.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 7 in reset,
pid 101422.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 8 in reset,
pid 101423.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 9 in reset,
pid 101424.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 10 in
reset, pid 101425.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 11 in
reset, pid 101426.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 12 in
reset, pid 101427.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 13 in
reset, pid 101428.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 14 in
reset, pid 101429.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 15 in
reset, pid 101430.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 16 in
reset, pid 101431.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 17 in
reset, pid 101432.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 18 in
reset, pid 101433.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 22
aborting, pid 101434.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 23
aborting, pid 101435.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 24
aborting, pid 101436.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 25
aborting, pid 101437.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 26
aborting, pid 101438.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 27
aborting, pid 101439.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 28
aborting, pid 101440.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 29
aborting, pid 101441.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 59 in
reset, pid 101410.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, board reset
done, enabling interrupts.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: reset, interrupts
disabled, loops 49727009.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0, reset, mbox 5 locked,
DID_RESET, pid 101420 done.
Sep 18 19:32:54 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 8 is in
reset.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 13 is in
reset.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 17 is in
reset.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 15 is in
reset.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 12 is in
reset.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 14 is in
reset.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 16 is in
reset.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 18 is in
reset.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 59 is in
reset.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 9 is in
reset.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 10 is in
reset.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 11 is in
reset.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 5 unlocked,
count 101445.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 7 is in
reset.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0, reset, mbox 22
aborting, DID_RESET, pid 101434 done.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0, reset, mbox 23
aborting, DID_RESET, pid 101435 done.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0, reset, mbox 24
aborting, DID_RESET, pid 101436 done.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0, reset, mbox 25
aborting, DID_RESET, pid 101437 done.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0, reset, mbox 26
aborting, DID_RESET, pid 101438 done.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0, reset, mbox 27
aborting, DID_RESET, pid 101439 done.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0, reset, mbox 28
aborting, DID_RESET, pid 101440 done.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0, reset, mbox 29
aborting, DID_RESET, pid 101441 done.
Sep 18 19:32:55 ariel.cii.fc.ul.pt kernel: EATA0: reset, exit, success.
[normal operation was resumed here until...]
Sep 18 19:41:18 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 119740, scsi0, channel 0, id 1, lun 0 Read (10) 00 00 2a cc
00 00 00 18 00
Sep 18 19:41:18 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 57, target
0.1:0, pid 119740.
Sep 18 19:41:18 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 57 is in
use.
Sep 18 19:41:18 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 119742, scsi0, channel 0, id 1, lun 0 Read (10) 00 00 2a cc
18 00 00 90 00
Sep 18 19:41:18 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 59, target
0.1:0, pid 119742.
Sep 18 19:41:18 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 59 is in
use.
Sep 18 19:41:18 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 119747, scsi0, channel 0, id 1, lun 0 Read (6) 1e 91 38 94
00
Sep 18 19:41:18 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 0, target
0.1:0, pid 119747.
Sep 18 19:41:18 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 0 is in
use.
Sep 18 19:41:18 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 119749, scsi0, channel 0, id 1, lun 0 Read (6) 1e 92 7e 5a
00
Sep 18 19:41:18 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 2, target
0.1:0, pid 119749.
Sep 18 19:41:18 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 2 is in
use.
Sep 18 19:41:18 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 119750, scsi0, channel 0, id 1, lun 0 Read (6) 1e 93 38 10
00
Sep 18 19:41:18 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 3, target
0.1:0, pid 119750.
Sep 18 19:41:18 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 3 is in
use.
Sep 18 19:41:18 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 119751, scsi0, channel 0, id 1, lun 0 Read (6) 1e 93 58 06
00
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 4, target
0.1:0, pid 119751.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 4 is in
use.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 119752, scsi0, channel 0, id 1, lun 0 Read (6) 1e 93 5e 0a
00
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 5, target
0.1:0, pid 119752.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 5 is in
use.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 119769, scsi0, channel 0, id 1, lun 0 Read (6) 1e 93 78 10
00
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 22, target
0.1:0, pid 119769.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 22 is in
use.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 119772, scsi0, channel 0, id 1, lun 0 Read (6) 1e 93 98 10
00
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 27, target
0.1:0, pid 119772.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 27 is in
use.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 119773, scsi0, channel 0, id 1, lun 0 Read (6) 1e 93 b8 10
00
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 30, target
0.1:0, pid 119773.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 30 is in
use.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 119774, scsi0, channel 0, id 1, lun 0 Read (6) 1e 93 d8 10
00
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 31, target
0.1:0, pid 119774.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 31 is in
use.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 119775, scsi0, channel 0, id 1, lun 0 Read (6) 1e 93 f8 10
00
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 32, target
0.1:0, pid 119775.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 32 is in
use.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 119776, scsi0, channel 0, id 1, lun 0 Read (6) 1e 94 18 10
00
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 33, target
0.1:0, pid 119776.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0, abort, mbox 33 ready,
DID_ABORT, pid 119776 done.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 119777, scsi0, channel 0, id 1, lun 0 Read (6) 1e 94 38 10
00
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 34, target
0.1:0, pid 119777.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0, abort, mbox 34 ready,
DID_ABORT, pid 119777 done.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 119779, scsi0, channel 0, id 1, lun 0 Read (6) 03 93 3e 78
00
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 36, target
0.1:0, pid 119779.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0, abort, mbox 36 ready,
DID_ABORT, pid 119779 done.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 119778, scsi0, channel 0, id 1, lun 0 Read (6) 1e 94 58 1e
00
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 35, target
0.1:0, pid 119778.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0, abort, mbox 35 ready,
DID_ABORT, pid 119778 done.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 119780, scsi0, channel 0, id 0, lun 0 Write (10) 00 00 39
d8 92 00 00 02 00
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 37, target
0.0:0, pid 119780.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 37 is in
use.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 119740, scsi0, channel 0, id 1, lun 0 Read (10) 00 00 2a cc
00 00 00 18 00
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 57, target
0.1:0, pid 119740.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: EATA0: abort, mbox 57 is in
use.
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: SCSI host 0 abort (pid 119740)
timed out - resetting
Sep 18 19:41:19 ariel.cii.fc.ul.pt kernel: SCSI bus is being reset for
host 0 channel 0.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, enter, target
0.1:0, pid 119740, reset_flags 2.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 0 in reset,
pid 119747.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 2 in reset,
pid 119749.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 3 in reset,
pid 119750.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 4 in reset,
pid 119751.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 5 in reset,
pid 119752.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 22 in
reset, pid 119769.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 27 in
reset, pid 119772.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 30 in
reset, pid 119773.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 31 in
reset, pid 119774.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 32 in
reset, pid 119775.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 37 in
reset, pid 119780.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 38
aborting, pid 119781.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 39
aborting, pid 119776.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 40
aborting, pid 119777.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 41
aborting, pid 119779.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 42
aborting, pid 119778.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 43
aborting, pid 119782.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 44
aborting, pid 119783.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 57 in
reset, pid 119740.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, mbox 59 in
reset, pid 119742.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, board reset
done, enabling interrupts.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: reset, interrupts
disabled, loops 49734940.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0, reset, mbox 0 locked,
DID_RESET, pid 119747 done.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 37 is in
reset.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 0 unlocked,
count 119778.
Sep 18 19:41:20 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 2 is in
reset.
Sep 18 19:41:21 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 3 is in
reset.
Sep 18 19:41:21 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 4 is in
reset.
Sep 18 19:41:21 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 5 is in
reset.
Sep 18 19:41:21 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 22 is in
reset.
Sep 18 19:41:21 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 27 is in
reset.
Sep 18 19:41:21 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 30 is in
reset.
Sep 18 19:41:21 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 31 is in
reset.
Sep 18 19:41:21 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 32 is in
reset.
Sep 18 19:41:21 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 57 is in
reset.
Sep 18 19:41:21 ariel.cii.fc.ul.pt kernel: EATA0: ihdlr, mbox 59 is in
reset.
Sep 18 19:41:21 ariel.cii.fc.ul.pt kernel: EATA0, reset, mbox 38
aborting, DID_RESET, pid 119781 done.
Sep 18 19:41:21 ariel.cii.fc.ul.pt kernel: EATA0, reset, mbox 39
aborting, DID_RESET, pid 119776 done.
Sep 18 19:41:21 ariel.cii.fc.ul.pt kernel: EATA0, reset, mbox 40
aborting, DID_RESET, pid 119777 done.
Sep 18 19:41:21 ariel.cii.fc.ul.pt kernel: EATA0, reset, mbox 41
aborting, DID_RESET, pid 119779 done.
Sep 18 19:41:21 ariel.cii.fc.ul.pt kernel: EATA0, reset, mbox 42
aborting, DID_RESET, pid 119778 done.
Sep 18 19:41:21 ariel.cii.fc.ul.pt kernel: EATA0, reset, mbox 43
aborting, DID_RESET, pid 119782 done.
Sep 18 19:41:21 ariel.cii.fc.ul.pt kernel: EATA0, reset, mbox 44
aborting, DID_RESET, pid 119783 done.
Sep 18 19:41:21 ariel.cii.fc.ul.pt kernel: EATA0: reset, exit, success.
-- SECOND TEST: ------------------------------------------------------------
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 4041, scsi0, channel 0, id 1, lun 0 Read (6) 07 e9 ee 98
00
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: eata_abort called pid: 4041
target: 1 lun: 0 reason 3
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: Returning: SCSI_ABORT_BUSY
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 4042, scsi0, channel 0, id 1, lun 0 Read (6) 0a e3 74 72
00
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: eata_abort called pid: 4042
target: 1 lun: 0 reason 3
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: Returning: SCSI_ABORT_BUSY
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 4043, scsi0, channel 0, id 1, lun 0 Read (10) 00 00 23 53
be 00 00 38 00
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: eata_abort called pid: 4043
target: 1 lun: 0 reason 3
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: Returning: SCSI_ABORT_BUSY
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 4044, scsi0, channel 0, id 1, lun 0 Read (10) 00 00 23 53
f6 00 00 60 00
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: eata_abort called pid: 4044
target: 1 lun: 0 reason 3
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: Returning: SCSI_ABORT_BUSY
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 4045, scsi0, channel 0, id 1, lun 0 Read (6) 00 3d 88 70
00
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: eata_abort called pid: 4045
target: 1 lun: 0 reason 3
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: Returning: SCSI_ABORT_BUSY
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 4046, scsi0, channel 0, id 1, lun 0 Read (6) 00 3d f8 28
00
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: eata_abort called pid: 4046
target: 1 lun: 0 reason 3
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: Returning: SCSI_ABORT_BUSY
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 4047, scsi0, channel 0, id 1, lun 0 Read (6) 07 ea 86 38
00
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: eata_abort called pid: 4047
target: 1 lun: 0 reason 3
Sep 20 14:10:59 ariel.cii.fc.ul.pt kernel: Returning: SCSI_ABORT_BUSY
Sep 20 14:11:04 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 4048, scsi0, channel 0, id 1, lun 0 Write (6) 00 00 5a 02
00
Sep 20 14:11:04 ariel.cii.fc.ul.pt kernel: eata_abort called pid: 4048
target: 1 lun: 0 reason 3
Sep 20 14:11:04 ariel.cii.fc.ul.pt kernel: Returning: SCSI_ABORT_BUSY
Sep 20 14:11:05 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 4049, scsi0, channel 0, id 0, lun 0 Read (6) 17 5c 12 02
00
Sep 20 14:11:05 ariel.cii.fc.ul.pt kernel: eata_abort called pid: 4049
target: 0 lun: 0 reason 3
Sep 20 14:11:05 ariel.cii.fc.ul.pt kernel: Returning: SCSI_ABORT_BUSY
Sep 20 14:11:12 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 4050, scsi0, channel 0, id 0, lun 0 Read (6) 17 5c 4a 02
00
Sep 20 14:11:12 ariel.cii.fc.ul.pt kernel: eata_abort called pid: 4050
target: 0 lun: 0 reason 3
Sep 20 14:11:12 ariel.cii.fc.ul.pt kernel: Returning: SCSI_ABORT_BUSY
Sep 20 14:11:24 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 4051, scsi0, channel 0, id 0, lun 0 Read (6) 1d 16 d2 08
00
Sep 20 14:11:24 ariel.cii.fc.ul.pt kernel: eata_abort called pid: 4051
target: 0 lun: 0 reason 3
Sep 20 14:11:24 ariel.cii.fc.ul.pt kernel: Returning: SCSI_ABORT_BUSY
Sep 20 14:14:21 ariel.cii.fc.ul.pt kernel: scsi : aborting command due to
timeout : pid 4041, scsi0, channel 0, id 1, lun 0 Read (6) 07 e9 ee 98
00
Sep 20 14:14:21 ariel.cii.fc.ul.pt kernel: eata_abort called pid: 4041
target: 1 lun: 0 reason 3
Sep 20 14:14:21 ariel.cii.fc.ul.pt kernel: Returning: SCSI_ABORT_BUSY
Sep 20 14:14:21 ariel.cii.fc.ul.pt kernel: SCSI host 0 abort (pid 4041)
timed out - resetting
Sep 20 14:14:21 ariel.cii.fc.ul.pt kernel: SCSI bus is being reset for
host 0 channel 0.
Sep 20 14:14:21 ariel.cii.fc.ul.pt kernel: eata_reset called pid:4041
target: 1 lun: 0 reason 3
Sep 20 14:14:21 ariel.cii.fc.ul.pt kernel: eata_reset: slot 23 in reset,
pid 4041.
Sep 20 14:14:21 ariel.cii.fc.ul.pt kernel: eata_reset: slot 24 in reset,
pid 4042.
Sep 20 14:14:21 ariel.cii.fc.ul.pt kernel: eata_reset: slot 25 in reset,
pid 4043.
Sep 20 14:14:21 ariel.cii.fc.ul.pt kernel: eata_reset: slot 26 in reset,
pid 4044.
Sep 20 14:14:21 ariel.cii.fc.ul.pt kernel: eata_reset: slot 27 in reset,
pid 4045.
Sep 20 14:14:21 ariel.cii.fc.ul.pt kernel: eata_reset: slot 28 in reset,
pid 4046.
Sep 20 14:14:21 ariel.cii.fc.ul.pt kernel: eata_reset: slot 29 in reset,
pid 4047.
Sep 20 14:14:21 ariel.cii.fc.ul.pt kernel: eata_reset: slot 30 in reset,
pid 4048.
Sep 20 14:14:21 ariel.cii.fc.ul.pt kernel: eata_reset: slot 31 in reset,
pid 4049.
Sep 20 14:14:23 ariel.cii.fc.ul.pt kernel: eata_reset: slot 32 in reset,
pid 4050.
Sep 20 14:14:23 ariel.cii.fc.ul.pt kernel: eata_reset: slot 33 in reset,
pid 4051.
Sep 20 14:14:23 ariel.cii.fc.ul.pt kernel: eata_reset: board reset done,
enabling interrupts.
Sep 20 14:14:23 ariel.cii.fc.ul.pt kernel: eata_dma: int_handler, reseted
command pid 4049 returned
Sep 20 14:14:23 ariel.cii.fc.ul.pt kernel: eata_dma: int_handler, reseted
command pid 4050 returned
Sep 20 14:14:23 ariel.cii.fc.ul.pt kernel: eata_dma: int_handler, reseted
command pid 4041 returned
Sep 20 14:14:23 ariel.cii.fc.ul.pt kernel: eata_dma: int_handler, reseted
command pid 4051 returned
Sep 20 14:14:23 ariel.cii.fc.ul.pt kernel: eata_dma: int_handler, reseted
command pid 4042 returned
Sep 20 14:14:23 ariel.cii.fc.ul.pt kernel: eata_dma: int_handler, reseted
command pid 4043 returned
Sep 20 14:14:23 ariel.cii.fc.ul.pt kernel: eata_dma: int_handler, reseted
command pid 4044 returned
Sep 20 14:14:23 ariel.cii.fc.ul.pt kernel: eata_dma: int_handler, reseted
command pid 4045 returned
Sep 20 14:14:23 ariel.cii.fc.ul.pt kernel: eata_dma: int_handler, reseted
command pid 4046 returned
Sep 20 14:14:23 ariel.cii.fc.ul.pt kernel: eata_dma: int_handler, reseted
command pid 4047 returned
Sep 20 14:14:23 ariel.cii.fc.ul.pt kernel: eata_dma: int_handler, reseted
command pid 4048 returned
Sep 20 14:14:23 ariel.cii.fc.ul.pt kernel: eata_reset: interrupts
disabled again.
Sep 20 14:14:23 ariel.cii.fc.ul.pt kernel: eata_reset: exit, pending.
[normal operation was resumed here]