Hard drive udma-33 reset problem in var/log/messages

v00d00101 · 01-21-2008, 05:41 AM

I was wondering if anyone would know what these messages are and if possible how to stop them happening.

I suspect they are something to do with either the Via SATA driver or the JMicron SATA driver.

The problem is identifiable by the fact my mouse starts behaving really laggy, like as if i was using keyboard mouse emulation, with a .5ms delay on mouse movement. It has been happening on and off for over a year. Through about 7+ kernel revisions (and thats when i noticed it). So for me since 2.6.16 on Fedora 5,6,7,8.

Hard drive functionality varies between the drive dying and hanging the system, and everything continuing on as normal. The only real way to cure it is to reboot the machine.

Output of uname -a.

Code:

Linux Shadow1 2.6.23.9-85.fc8 #1 SMP Fri Dec 7 15:49:59 EST 2007 i686 athlon i386 GNU/Linux

The error found in /var/log/messages. I used tail to get the last 300 lines, because the actual error happened about 5am GMT today (6 hrs ago).

Code:

Jan 21 11:25:55 Shadow1 kernel: ata6: soft resetting port
Jan 21 11:25:55 Shadow1 kernel: ata6.00: configured for UDMA/33
Jan 21 11:25:55 Shadow1 kernel: ata6: EH complete
Jan 21 11:26:05 Shadow1 kernel: ata6.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Jan 21 11:26:05 Shadow1 kernel: ata6.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0x1e data 0 
Jan 21 11:26:05 Shadow1 kernel:          res 40/00:03:00:00:20/00:00:00:00:00/a0 Emask 0x4 (timeout)
Jan 21 11:26:05 Shadow1 kernel: ata6: soft resetting port
Jan 21 11:26:06 Shadow1 kernel: ata6.00: configured for UDMA/33
Jan 21 11:26:06 Shadow1 kernel: ata6: EH complete
Jan 21 11:26:16 Shadow1 kernel: ata6.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Jan 21 11:26:16 Shadow1 kernel: ata6.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0x1e data 0 
Jan 21 11:26:16 Shadow1 kernel:          res 40/00:03:00:00:20/00:00:00:00:00/a0 Emask 0x4 (timeout)
Jan 21 11:26:16 Shadow1 kernel: ata6: soft resetting port
Jan 21 11:26:16 Shadow1 kernel: ata6.00: configured for UDMA/33
Jan 21 11:26:16 Shadow1 kernel: ata6: EH complete
Jan 21 11:26:26 Shadow1 kernel: ata6.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Jan 21 11:26:26 Shadow1 kernel: ata6.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0x1e data 0 
Jan 21 11:26:26 Shadow1 kernel:          res 40/00:03:00:00:20/00:00:00:00:00/a0 Emask 0x4 (timeout)
Jan 21 11:26:26 Shadow1 kernel: ata6: soft resetting port
Jan 21 11:26:27 Shadow1 kernel: ata6.00: configured for UDMA/33
Jan 21 11:26:27 Shadow1 kernel: ata6: EH complete
Jan 21 11:26:27 Shadow1 kernel: sr 5:0:0:0: ioctl_internal_command return code = 8000002
Jan 21 11:26:27 Shadow1 kernel:    : Sense Key : Aborted Command [current] [descriptor]
Jan 21 11:26:27 Shadow1 kernel:    : Add. Sense: No additional sense information
Jan 21 11:26:57 Shadow1 kernel: ata6.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Jan 21 11:26:57 Shadow1 kernel: ata6.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
Jan 21 11:26:57 Shadow1 kernel:          res 40/00:03:00:00:20/00:00:00:00:00/a0 Emask 0x4 (timeout)
Jan 21 11:26:57 Shadow1 kernel: ata6: soft resetting port
Jan 21 11:26:57 Shadow1 kernel: ata6.00: configured for UDMA/33
Jan 21 11:26:57 Shadow1 kernel: ata6: EH complete
Jan 21 11:27:27 Shadow1 kernel: ata6.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Jan 21 11:27:27 Shadow1 kernel: ata6.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
Jan 21 11:27:27 Shadow1 kernel:          res 40/00:03:00:00:20/00:00:00:00:00/a0 Emask 0x4 (timeout)
Jan 21 11:27:27 Shadow1 kernel: ata6: soft resetting port
Jan 21 11:27:28 Shadow1 kernel: ata6.00: configured for UDMA/33
Jan 21 11:27:28 Shadow1 kernel: ata6: EH complete
Jan 21 11:27:58 Shadow1 kernel: ata6.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Jan 21 11:27:58 Shadow1 kernel: ata6.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
Jan 21 11:27:58 Shadow1 kernel:          res 40/00:03:00:00:20/00:00:00:00:00/a0 Emask 0x4 (timeout)
Jan 21 11:27:58 Shadow1 kernel: ata6: soft resetting port
Jan 21 11:27:58 Shadow1 kernel: ata6.00: configured for UDMA/33
Jan 21 11:27:58 Shadow1 kernel: ata6: EH complete
Jan 21 11:28:28 Shadow1 kernel: ata6.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
Jan 21 11:28:28 Shadow1 kernel: ata6.00: cmd a0/00:00:00:00:20/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
Jan 21 11:28:28 Shadow1 kernel:          res 40/00:03:00:00:20/00:00:00:00:00/a0 Emask 0x4 (timeout)
Jan 21 11:28:28 Shadow1 kernel: ata6: soft resetting port
Jan 21 11:28:29 Shadow1 kernel: ata6.00: configured for UDMA/33
Jan 21 11:28:29 Shadow1 kernel: ata6: EH complete

I have no idea what is ata6, but i currently run 2x SATA Hard Drives (non-RAID) on the SATA2 interface, and 1x SATA DVD-RW on the SATA1 interface.

Thanks in advance.

amanhecer · 01-21-2008, 08:42 PM

I am experiencing the same problem.

I have four disk in a raid-5 array with lvm on top.

smart reports no disk errors. Motherboard tests fine. memtest reports no errros.
but yet I still get these messages. It's almost like the whole Jmicron controller is resetting.

Anybody have any ideas?

ubuntu@ubuntu:~$ lspci |grep -i JMi
03:00.0 SATA controller: JMicron Technologies, Inc. JMicron 20360/20363 AHCI Controller (rev 02)
03:00.1 IDE interface: JMicron Technologies, Inc. JMicron 20360/20363 AHCI Controller (rev 02)
04:00.0 SATA controller: JMicron Technologies, Inc. JMicron 20360/20363 AHCI Controller (rev 02)
04:00.1 IDE interface: JMicron Technologies, Inc. JMicron 20360/20363 AHCI Controller (rev 02)

Jan 22 02:20:10 ubuntu kernel: [ 3067.149657] sd 8:0:0:0: [sdc] Write Protect is off
Jan 22 02:20:10 ubuntu kernel: [ 3067.149659] sd 8:0:0:0: [sdc] Mode Sense: 00 3a 00 00
Jan 22 02:20:10 ubuntu kernel: [ 3067.150284] sd 8:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Jan 22 02:20:23 ubuntu kernel: [ 3079.720702] ata9.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2
Jan 22 02:20:23 ubuntu kernel: [ 3079.720708] ata9.00: (BMDMA stat 0x26)
Jan 22 02:20:23 ubuntu kernel: [ 3079.720713] ata9.00: cmd 35/00:70:4f:40:f5/00:00:19:00:00/e0 tag 0 cdb 0x0 data 57344 out
Jan 22 02:20:23 ubuntu kernel: [ 3079.720715] res 51/84:50:6f:40:f5/84:00:19:00:00/e0 Emask 0x30 (host bus error)
Jan 22 02:20:23 ubuntu kernel: [ 3079.720722] ata9: soft resetting port
Jan 22 02:20:23 ubuntu kernel: [ 3079.777125] ata10.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2
Jan 22 02:20:23 ubuntu kernel: [ 3079.777129] ata10.00: (BMDMA stat 0x26)
Jan 22 02:20:23 ubuntu kernel: [ 3079.777135] ata10.00: cmd 35/00:50:bf:0d:d6/00:03:19:00:00/e0 tag 0 cdb 0x0 data 434176 out
Jan 22 02:20:23 ubuntu kernel: [ 3079.777137] res 51/84:e0:2f:0e:d6/84:02:19:00:00/e0 Emask 0x30 (host bus error)
Jan 22 02:20:23 ubuntu kernel: [ 3079.777148] ata10: soft resetting port

unSpawn · 02-08-2008, 08:07 AM

Related to bad SATA controller chipsets. See for instance the LKML discussions on Silicon Image (sata_sil) and equally "bad" chipsets. It's ongoing work and the fixes improve with about each kernel release (for me at least).

v00d00101 · 02-14-2008, 09:45 PM

Thanks unSpawn. I suspected it was something like that.

Now with the new released kernel for Fedora 8, i have weird IRQ problems, but the hard drive problems seem to have ended for now.

I guess you cant win.