[ltp] OT - Linux Thinkcentre...

Sat, 31 Jul 2010 12:21:33 -0400

On Tue, 20 Jul 2010 22:00:00 +1200 zed wrote:

>> > On 18 July 2010 00:53, John Jason Jordan <johnxj@comcast.net> wrote:
>> > What does dmesg tell you?
>Deciphering the result of the dmesg command, which is given below, is
>beyond my level of competence, so I seek your assistance to point out
>any errors which could lead to a slow boot time.  As a matter of
>interest, the machine is a 2.53GHz, not a 1.7 GHz as I reported.
>
>

Have you tried booting without the Hitachi and USB drive(s) connected..?
Not sure the WD boot disk is good either...

You may be dealing with multiple HD problems which are always more
difficult to diagnose.  I'd suggest trying a single new HD only to see if
there are other h/w issues.

HTH.  Good luck,
Pierre

Some items of interest in your dmesg...

OK...  the boot sector was read, which pointed to /boot/grub/menu.lst:
>[    0.000000] Kernel command line:
>BOOT_IMAGE=/boot/vmlinuz-2.6.32-21-generic

Loading kernel... 

so we know the WD HD can be read (w/o interrupts)...

Checking h/w & initializing...
>[    0.000000] Detected 2526.959 MHz processor.

>[    0.351199] Trying to unpack rootfs image as initramfs...

Setting up disk interrupts...
>[    0.485438] ata1: PATA max UDMA/100 cmd 0x1f0 ctl 0x3f6 bmdma 0x1810
>irq 14
>[    0.485443] ata2: PATA max UDMA/100 cmd 0x170 ctl 0x376 bmdma 0x1818
>irq 15

Setting up USB/devices, etc...

Not sure what this failure is:
>[    0.530642] PM: Resume from disk failed.

Devices with different bus speeds?: 
>[    0.694364] ata2.00: configured for UDMA/33
>[    0.716453] ata2.01: configured for UDMA/100

Now the system starts seeing problems (note 5-sec timeouts):
>[    5.708017] ata1: link is slow to respond, please be patient (ready=0)
>[   10.524015] ata1: SRST failed (errno=-16)
>[   15.720013] ata1: link is slow to respond, please be patient (ready=0)
>[   20.536013] ata1: SRST failed (errno=-16)
>[   25.732013] ata1: link is slow to respond, please be patient (ready=0)

...and 30-sec timeouts on WD drive:
>[   50.540066] ata1.01: link status unknown, clearing UNKNOWN to NONE
>[   50.572439] ata1.00: ATA-6: WDC WD400BB-23FJA0, 13.03G13, max UDMA/100
>[   50.572444] ata1.00: 78156288 sectors, multi 16: LBA 
>[   50.588361] ata1.00: configured for UDMA/100
>[   50.588557] scsi 0:0:0:0: Direct-Access     ATA      WDC WD400BB-23FJ
>13.0 PQ: 0 ANSI: 5
>[   50.588812] sd 0:0:0:0: Attached scsi generic sg0 type 0

40GB Western Digital HD:
>[   50.589131] sd 0:0:0:0: [sda] 78156288 512-byte logical blocks: (40.0
>GB/37.2 GiB)
>[   50.589648] sd 0:0:0:0: [sda] Write Protect is off
>[   50.589654] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
>[   50.589816] sd 0:0:0:0: [sda] Write cache: enabled, read cache:
>enabled, doesn't support DPO or FUA

CDROM (this line was earlier):
>[   50.589258] scsi 1:0:0:0: CD-ROM            JLMS     XJ-HD166S       
>DUS1 PQ: 0 ANSI: 5

Something doesn't look right...  "sda:sr0"?
>[   50.590390]  sda:sr0: scsi3-mmc drive: 48x/48x cd/rw xa/form2 cdda
>tray [   50.591278] Uniform CD-ROM driver Revision: 3.20
>[   50.591458] sr 1:0:0:0: Attached scsi CD-ROM sr0
>[   50.591569] sr 1:0:0:0: Attached scsi generic sg1 type 5

Hitachi 80GB HD: (Hitachi 0A30358 HDS728080-PLA380 80 GB)
>[   50.591780] scsi 1:0:1:0: Direct-Access     ATA      HDS728080PLAT20 
>PF2O PQ: 0 ANSI: 5
>[   50.592114] sd 1:0:1:0: Attached scsi generic sg2 type 0
>[   50.592283] sd 1:0:1:0: [sdb] 156312576 512-byte logical blocks: (80.0
>GB/74.5 GiB)
>[   50.592383] sd 1:0:1:0: [sdb] Write Protect is off
>[   50.592388] sd 1:0:1:0: [sdb] Mode Sense: 00 3a 00 00
>[   50.592431] sd 1:0:1:0: [sdb] Write cache: enabled, read cache:
>enabled, doesn't support DPO or FUA
with 4 partitions:
>[   50.592708]  sdb: sda1 sda2 sda3 sda4

>[   50.617539] sd 0:0:0:0: [sda] Attached SCSI disk
>[   80.816025] ata2: lost interrupt (Status 0x58)
30-sec timer popped:  ^^^^^^^^^^^^^^

>[   80.820003] ata2: drained 32768 bytes to clear DRQ.
>[   80.883112] ata2.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
>frozen
 ^^^^^^
>[   80.883119] ata2.01: failed command: READ DMA
                         ^^^^^^^^^^^^^^
>[   80.883127] ata2.01: cmd c8/00:08:00:00:00/00:00:00:00:00/f0 tag 0 dma
>4096 in
>[   80.883129]          res 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4
>(timeout)
>[   80.883133] ata2.01: status: { DRDY }
>[   80.883166] ata2: soft resetting link
>[   81.053407] ata2.00: configured for UDMA/33
>[   81.076389] ata2.01: configured for UDMA/100
>[   81.076608] ata2.01: device reported invalid CHS sector 0
>[   81.076622] ata2: EH complete
>[  111.816022] ata2: lost interrupt (Status 0x58)
30-sec timer popped:  ^^^^^^^^^^^^^^ again.

>[  111.820004] ata2: drained 32768 bytes to clear DRQ.
>[  111.883104] ata2.01: limiting speed to UDMA/66:PIO4
>[  111.883110] ata2.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
>frozen
>[  111.883116] ata2.01: failed command: READ DMA
>[  111.883123] ata2.01: cmd c8/00:08:00:00:00/00:00:00:00:00/f0 tag 0 dma
>4096 in
>[  111.883125]          res 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4
>(timeout)
>[  111.883129] ata2.01: status: { DRDY }
>[  111.883158] ata2: soft resetting link
>[  112.053406] ata2.00: configured for UDMA/33
>[  112.076389] ata2.01: configured for UDMA/66
>[  112.076598] ata2.01: device reported invalid CHS sector 0
>[  112.076610] ata2: EH complete
>[  142.816025] ata2: lost interrupt (Status 0x58)
and again...          ^^^^^^^^^^^^^^

>[  142.820004] ata2: drained 32768 bytes to clear DRQ.
>[  142.883105] ata2.01: limiting speed to UDMA/33:PIO4
>[  142.883111] ata2.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
>frozen
>[  142.883116] ata2.01: failed command: READ DMA
>[  142.883124] ata2.01: cmd c8/00:08:00:00:00/00:00:00:00:00/f0 tag 0 dma
>4096 in
>[  142.883126]          res 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4
>(timeout)
>[  142.883130] ata2.01: status: { DRDY }
>[  142.883159] ata2: soft resetting link
>[  143.053397] ata2.00: configured for UDMA/33
>[  143.076389] ata2.01: configured for UDMA/33
>[  143.076597] ata2.01: device reported invalid CHS sector 0
>[  143.076610] ata2: EH complete
>[  173.816025] ata2: lost interrupt (Status 0x58)
again...              ^^^^^^^^^^^^^^

>[  173.820004] ata2: drained 32768 bytes to clear DRQ.
>[  173.883102] ata2.01: limiting speed to PIO4
>[  173.883107] ata2.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
>frozen
>[  173.883112] ata2.01: failed command: READ DMA
>[  173.883119] ata2.01: cmd c8/00:08:00:00:00/00:00:00:00:00/f0 tag 0 dma
>4096 in
>[  173.883121]          res 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4
>(timeout)
>[  173.883125] ata2.01: status: { DRDY }
>[  173.883153] ata2: soft resetting link
>[  174.053385] ata2.00: configured for UDMA/33
>[  174.076388] ata2.01: configured for PIO4
>[  174.076588] ata2.01: device reported invalid CHS sector 0
>[  174.076599] ata2: EH complete
>[  174.085229]  unknown partition table
                 ^^^^^^^^^^^^^^^^^^^^^^^

>[  174.085586] sd 1:0:1:0: [sdb] Attached SCSI disk
>[  174.085610] Freeing unused kernel memory: 656k freed
>[  174.086413] Write protecting the kernel text: 4676k
>[  174.086451] Write protecting the kernel read-only data: 1840k
>[  174.088226] sdb: detected capacity change from 0 to 80032038912
>[  174.088446] sdb: detected capacity change from 0 to 80032038912
this doesn't look good: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

>[  176.017132] EXT4-fs (sda2): mounted filesystem with ordered data mode

At the 3-minute mark...

>[  185.702469] Adding 522104k swap on /dev/sda3.  Priority:-1 extents:1
>across:522104k 

Coming up on 4 minutes...

>[  234.098797] Initializing USB Mass Storage driver...
                             ^^^^^^^^^^^^^^^^
>[  234.099029] scsi2 : SCSI emulation for USB Mass Storage devices
>[  234.099431] usbcore: registered new interface driver usb-storage
>[  234.099438] USB Mass Storage support registered.
>[  234.110793] usb-storage: device found at 4
>[  234.110798] usb-storage: waiting for device to settle before scanning
>[  239.108229] usb-storage: device scan complete
>[  239.108954] scsi 2:0:0:0: Direct-Access     USBDisk  RunDisk         
>1.00 PQ: 0 ANSI: 2
>[  239.115011] sd 2:0:0:0: Attached scsi generic sg3 type 0
>[  239.118079] sd 2:0:0:0: [sdc] 16039872 512-byte logical blocks: (8.21
>GB/7.64 GiB)
>[  239.118572] sd 2:0:0:0: [sdc] Write Protect is off
>[  239.118579] sd 2:0:0:0: [sdc] Mode Sense: 0b 00 00 08
>[  239.118583] sd 2:0:0:0: [sdc] Assuming drive cache: write through
>[  239.131947] sd 2:0:0:0: [sdc] Assuming drive cache: write through
>[  239.131961]  sdc: sdc1
>[  239.283055] sd 2:0:0:0: [sdc] Assuming drive cache: write through
>[  239.283068] sd 2:0:0:0: [sdc] Attached SCSI removable disk
>
>I look forward to your analysis.
>
>Zed