Bug 62901 - I have error message "exception Emask 0x50 SAct 0x0 SErr 0x4090800 action 0xe frozen" for all sata devices in system
Summary: I have error message "exception Emask 0x50 SAct 0x0 SErr 0x4090800 action 0xe...
Status: REOPENED
Alias: None
Product: IO/Storage
Classification: Unclassified
Component: Serial ATA (show other bugs)
Hardware: All Linux
: P1 normal
Assignee: Jeff Garzik
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2013-10-13 09:40 UTC by Mikhail
Modified: 2016-03-19 17:02 UTC (History)
5 users (show)

See Also:
Kernel Version: 3.11
Subsystem:
Regression: No
Bisected commit-id:


Attachments
dmesg with ESI Juli@ soud card (161.22 KB, text/plain)
2013-10-13 09:40 UTC, Mikhail
Details
dmesg without ESI Juli@ soud card (90.71 KB, text/plain)
2013-10-13 09:41 UTC, Mikhail
Details
dmesg with ESI Juli@ soud card (146.47 KB, text/plain)
2013-10-13 19:01 UTC, Mikhail
Details
dmesg output on debug kernel (203.74 KB, text/plain)
2013-10-15 05:29 UTC, Mikhail
Details
system log when system became unbottable (147.26 KB, text/x-log)
2013-10-15 06:04 UTC, Mikhail
Details
photo of screen when displayed errors (471.40 KB, image/jpeg)
2013-10-15 06:07 UTC, Mikhail
Details
screenshot of rescue mode (364.07 KB, image/png)
2013-10-15 15:34 UTC, Mikhail
Details
dmesg output of rescue mode (58.14 KB, text/plain)
2013-10-15 15:35 UTC, Mikhail
Details
BIOS - Advanced CPU Core Setings (340.41 KB, image/jpeg)
2013-10-16 21:00 UTC, Mikhail
Details
BIOS - Power Management (281.45 KB, image/jpeg)
2013-10-16 21:01 UTC, Mikhail
Details
system log with intel_iommu=off and disable CPU power saving states (hope contain any usefull info) (293.08 KB, text/x-log)
2013-10-16 21:09 UTC, Mikhail
Details
dmesg with Audigy 2 SB240 soud card (244.32 KB, text/plain)
2013-10-19 16:47 UTC, Mikhail
Details
system log (119.13 KB, application/x-bzip)
2013-10-19 17:03 UTC, Mikhail
Details
dmesg with Audigy 2 SB240 soud card and Toughpower XT 775W (248.35 KB, text/plain)
2013-10-20 13:54 UTC, Mikhail
Details
boot screen (235.43 KB, image/jpeg)
2013-10-20 19:53 UTC, Mikhail
Details
dmesg with Audigy 2 SB240 soud card and HDD in external SATA controller (89.38 KB, text/plain)
2013-10-20 21:12 UTC, Mikhail
Details
dmesg output with 3.12 kernel (117.19 KB, text/plain)
2013-11-18 04:21 UTC, Mikhail
Details
dmesg kernel 3.12 (76.89 KB, text/plain)
2013-11-20 17:48 UTC, Mikhail
Details
Memory also work fine (203.18 KB, image/jpeg)
2013-11-20 17:58 UTC, Mikhail
Details
gigabyte support answer (133.56 KB, image/png)
2014-03-19 06:51 UTC, Mikhail
Details

Description Mikhail 2013-10-13 09:40:28 UTC
Created attachment 110841 [details]
dmesg with ESI Juli@ soud card

I have periodicity error message "exception Emask 0x50 SAct 0x0 SErr 0x4090800 action 0xe frozen" for all sata devices in system when I insert sound card ESI Juli@.
Comment 1 Mikhail 2013-10-13 09:41:00 UTC
Created attachment 110851 [details]
dmesg without ESI Juli@ soud card
Comment 2 Mikhail 2013-10-13 09:42:03 UTC
Very strange but without sound card I have trouble with USB

[16945.101322] usb 2-5: USB disconnect, device number 21
[16945.101436] usb 2-5: Set SEL for device-initiated U1 failed.
[16945.101438] usb 2-5: Set SEL for device-initiated U2 failed.
[16945.648501] usb 2-5: new SuperSpeed USB device number 22 using xhci_hcd
[16945.661603] usb 2-5: New USB device found, idVendor=2109, idProduct=0811
[16945.661606] usb 2-5: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[16945.661607] usb 2-5: Product: 4-Port USB 3.0 Hub
[16945.661607] usb 2-5: Manufacturer: VIA Labs, Inc.
[16945.663313] hub 2-5:1.0: USB hub found
[16945.663420] hub 2-5:1.0: 4 ports detected
[16950.460216] usb 2-5: USB disconnect, device number 22
[16950.460492] usb 2-5: Set SEL for device-initiated U1 failed.
[16950.460498] usb 2-5: Set SEL for device-initiated U2 failed.
[16951.007784] usb 2-5: new SuperSpeed USB device number 23 using xhci_hcd
[16951.020475] usb 2-5: New USB device found, idVendor=2109, idProduct=0811
[16951.020483] usb 2-5: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[16951.020488] usb 2-5: Product: 4-Port USB 3.0 Hub
[16951.020492] usb 2-5: Manufacturer: VIA Labs, Inc.
[16951.022553] hub 2-5:1.0: USB hub found
[16951.022641] hub 2-5:1.0: 4 ports detected
[16955.636186] usb 2-5: USB disconnect, device number 23
[16955.636295] usb 2-5: Set SEL for device-initiated U1 failed.
[16955.636297] usb 2-5: Set SEL for device-initiated U2 failed.
[16956.183718] usb 2-5: new SuperSpeed USB device number 24 using xhci_hcd
[16956.196528] usb 2-5: New USB device found, idVendor=2109, idProduct=0811
[16956.196537] usb 2-5: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[16956.196541] usb 2-5: Product: 4-Port USB 3.0 Hub
[16956.196546] usb 2-5: Manufacturer: VIA Labs, Inc.
[16956.198498] hub 2-5:1.0: USB hub found
[16956.198583] hub 2-5:1.0: 4 ports detected
Comment 3 Mikhail 2013-10-13 09:42:45 UTC
[mikhail@localhost ~]$ lspci
00:00.0 Host bridge: Intel Corporation 4th Gen Core Processor DRAM Controller (rev 06)
00:02.0 VGA compatible controller: Intel Corporation Xeon E3-1200 v3/4th Gen Core Processor Integrated Graphics Controller (rev 06)
00:03.0 Audio device: Intel Corporation Xeon E3-1200 v3/4th Gen Core Processor HD Audio Controller (rev 06)
00:14.0 USB controller: Intel Corporation 8 Series/C220 Series Chipset Family USB xHCI (rev 04)
00:16.0 Communication controller: Intel Corporation 8 Series/C220 Series Chipset Family MEI Controller #1 (rev 04)
00:1b.0 Audio device: Intel Corporation 8 Series/C220 Series Chipset High Definition Audio Controller (rev 04)
00:1c.0 PCI bridge: Intel Corporation 8 Series/C220 Series Chipset Family PCI Express Root Port #1 (rev d4)
00:1c.2 PCI bridge: Intel Corporation 8 Series/C220 Series Chipset Family PCI Express Root Port #3 (rev d4)
00:1c.3 PCI bridge: Intel Corporation 82801 PCI Bridge (rev d4)
00:1c.4 PCI bridge: Intel Corporation 8 Series/C220 Series Chipset Family PCI Express Root Port #5 (rev d4)
00:1f.0 ISA bridge: Intel Corporation Z87 Express LPC Controller (rev 04)
00:1f.2 SATA controller: Intel Corporation 8 Series/C220 Series Chipset Family 6-port SATA Controller 1 [AHCI mode] (rev 04)
00:1f.3 SMBus: Intel Corporation 8 Series/C220 Series Chipset Family SMBus Controller (rev 04)
02:00.0 Ethernet controller: Realtek Semiconductor Co., Ltd. RTL8111/8168/8411 PCI Express Gigabit Ethernet Controller (rev 06)
03:00.0 PCI bridge: Intel Corporation 82801 PCI Bridge (rev 41)
04:00.0 Multimedia audio controller: VIA Technologies Inc. VT1720/24 [Envy24PT/HT] PCI Multi-Channel Audio Controller (rev 01)
05:00.0 Audio device: Creative Labs Device 0012 (rev 01)

[mikhail@localhost ~]$ lsusb
Bus 002 Device 014: ID 2109:0811  
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 004: ID 12d1:1506 Huawei Technologies Co., Ltd. Modem/Networkcard
Bus 001 Device 007: ID 0a12:0001 Cambridge Silicon Radio, Ltd Bluetooth Dongle (HCI mode)
Bus 001 Device 006: ID 046d:c52b Logitech, Inc. Unifying Receiver
Bus 001 Device 008: ID 04d9:1503 Holtek Semiconductor, Inc. Shortboard Lefty
Bus 001 Device 005: ID 05e3:0608 Genesys Logic, Inc. USB-2.0 4-Port HUB
Bus 001 Device 003: ID 1a40:0201 Terminus Technology Inc. FE 2.1 7-port Hub
Bus 001 Device 002: ID 2109:0811  
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
[mikhail@localhost ~]$
Comment 4 Tejun Heo 2013-10-13 17:07:50 UTC
The controller is reporting PHY events, meaning that the connection between the controller and your drive is experiencing communication glitches. SATA connections tend to be fairly sensitive to interferences. After all, the cables are unshielded and running at very high frequency. I don't think there's much the driver can do to address the root issue. It's most likely an electrical problem.

* Try to force lower connection speed using libata.force kernel parameter.

* Move the audio card to a different slot and rearrange the cables.

Thanks.
Comment 5 Mikhail 2013-10-13 19:00:31 UTC
How can we explain this? just a coincidence? Why the error happens on all USB and SATA devices simultaneously?

[12095.221788] usb 2-5: USB disconnect, device number 14
[12095.221899] usb 2-5: Set SEL for device-initiated U1 failed.
[12095.221901] usb 2-5: Set SEL for device-initiated U2 failed.
[12095.647490] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
[12095.648474] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
[12095.659647] ata2.00: configured for UDMA/133
[12095.659650] ata2: EH complete
[12095.670155] ata1.00: configured for UDMA/133
[12095.670161] ata1: EH complete
Comment 6 Mikhail 2013-10-13 19:01:04 UTC
Created attachment 110891 [details]
dmesg with ESI Juli@ soud card
Comment 7 Tejun Heo 2013-10-13 19:04:01 UTC
It looks like your sound card is messing up the system electronically. I don't really think there's much can be done from software side. Contact the manufacturer / try different power supply / try to shield the device somehow / etc...
Comment 8 Mikhail 2013-10-13 19:14:43 UTC
Ok but why without sound card we see this:

https://bugzilla.kernel.org/show_bug.cgi?id=62901#c2
Comment 9 Mikhail 2013-10-15 05:29:25 UTC
Created attachment 111021 [details]
dmesg output on debug kernel
Comment 10 Mikhail 2013-10-15 06:02:53 UTC
> * Move the audio card to a different slot

When I Move the audio card to a different slot system became unbottable, please see this video:
https://docs.google.com/file/d/0B0nwzlfiB4aQeUQxaDlZbF9xUGM/edit?usp=sharing
Comment 11 Mikhail 2013-10-15 06:04:45 UTC
Created attachment 111041 [details]
system log when system became unbottable
Comment 12 Mikhail 2013-10-15 06:07:53 UTC
Created attachment 111051 [details]
photo of screen when displayed errors
Comment 13 Mikhail 2013-10-15 11:04:57 UTC
seems hangs occurs after it:

окт 15 16:18:20 localhost.localdomain libvirtd[610]: libvirt version: 1.1.3, package: 2.fc20 (Fedora Project, 2013-10-06-19:24:41, buildvm-11.phx2.fedoraproject.org)

mean that in system log no more records and last record is above.

I am sure this is software bug , because in rescue mode system not hangs when sound card inserted in problem slot.
Comment 14 Tejun Heo 2013-10-15 12:37:42 UTC
Boot fails because your drive goes away before boot is finished. It's still the same problem, just happening faster. Also, fedora rescue mode doesn't mount or use the hard drive once the kernel and initrd are loaded, so the drive failure going away doesn't really indicate much.

Your dmesg is also showing a single bit corruption in slab red zone, which may be caused by several things, but looking at the cluster of failures, I think it's likely that your machine is having serious hardware issues with that audio controller.

From the information you've posted so far, it seems highly unlikely this is something which is caused by software. Unrelated devices can't normally cause PHY events on SATA connections through driver issues. I'd strongly suggest taking the offending device out of the system.
Comment 15 Mikhail 2013-10-15 15:33:43 UTC
Very strange because this controller works fine with another motherboard asrock.com/mb/Intel/H61MU3S3

Problem begins after upgrade to Haswell desktop http://www.gigabyte.com/products/product-page.aspx?pid=4486

Fedora in rescue mode mount all partitions difference between usual operation that for audio uses dummy output (no loaded audio driver) and for video used llvmpipe (software video). Maybe audio and video driver contain bug which changed registers or DMA which used by SATA controller?
Comment 16 Mikhail 2013-10-15 15:34:50 UTC
Created attachment 111131 [details]
screenshot of rescue mode
Comment 17 Mikhail 2013-10-15 15:35:28 UTC
Created attachment 111141 [details]
dmesg output of rescue mode
Comment 18 Tejun Heo 2013-10-15 15:42:36 UTC
Hmmm... so if you boot the system normally and unload the sound driver, are things okay? I have no idea why the new system is having problem with the audio controller, but the nature of the problem seems very low level. It is possible that the audio driver can do something to put it in a different mode or whatever to work around it but my general feeling is something is going wrong at a very low hardware level.

Just a hunch but haswell systems reportedly have issues with certain power supplies because of its idle consumption gets too low. Does disabling all CPU powersaving states from BIOS change anything?

Thanks.
Comment 19 Mikhail 2013-10-15 20:15:40 UTC
Very interesting notice! I just added module snd-ice1724 to black list and problem was gone (mean that system with sound card was booted and work properly), but of course sound card not work.

# Cat / etc / modprobe.d / blacklist.conf
blacklist snd-ice1724


What does this mean? snd-ice1724 is buggy driver?
Comment 20 Tejun Heo 2013-10-15 20:18:39 UTC
cc'ing Takashi.

Mikhail, it might be that there's something the driver can do to resolve the issue but I'm still much more inclined towards actual hardware problem which can't be worked around from driver side.

BTW, have you tried disabling all CPU power saving states from BIOS?

Thank.s
Comment 21 Takashi Iwai 2013-10-16 05:45:20 UTC
I don't know of any issue with snd-ice1724 and Juli@ now, so very likely it's an issue triggered by the special hardware combination.  Do you have any other PCI sound card (not PCI-e) to check whether it works with this mobo?

Also for Haswell, you may try intel_iommu=off boot option.  I saw quite a few bugs related with Intel IOMMU on Haswell on DIY machines.
Comment 22 Mikhail 2013-10-16 20:58:42 UTC
> BTW, have you tried disabling all CPU power saving states from BIOS?

I found in BIOS follow options and disable their:
CPU Enhanced Halt(C1E)
C3 State Support
C6/C7 State Support
RC6(Render Standby)
But it not helps and system hangs during boot, if sound card module unblacklisted.

Which other BIOS options I should to disable (please see my photos)?
Comment 23 Mikhail 2013-10-16 21:00:23 UTC
Created attachment 111391 [details]
BIOS - Advanced CPU Core Setings
Comment 24 Mikhail 2013-10-16 21:01:44 UTC
Created attachment 111401 [details]
BIOS - Power Management
Comment 25 Mikhail 2013-10-16 21:03:41 UTC
> Also for Haswell, you may try intel_iommu=off boot option.  I saw quite a few
> bugs related with Intel IOMMU on Haswell on DIY machines.

Also I tried and this option but without any success.
Comment 26 Mikhail 2013-10-16 21:09:24 UTC
Created attachment 111411 [details]
system log with intel_iommu=off and disable CPU power saving states (hope contain any usefull info)
Comment 27 Mikhail 2013-10-19 16:46:36 UTC
> Do you have any other PCI sound card (not PCI-e) to check whether it works
> with this mobo?

I inserted my old Audigy 2 SB240 soundcard in problem slot. I can boot my system but I see again:

6750.482787] ata1: exception Emask 0x50 SAct 0x0 SErr 0x4090800 action 0xe frozen
[ 6750.482791] ata1: irq_stat 0x00400040, connection status changed
[ 6750.482794] ata1: SError: { HostInt PHYRdyChg 10B8B DevExch }
[ 6750.482798] ata1: hard resetting link
[ 6750.482829] ata2: exception Emask 0x50 SAct 0x0 SErr 0x4090800 action 0xe frozen
[ 6750.482831] ata2: irq_stat 0x00400040, connection status changed
[ 6750.482832] ata2: SError: { HostInt PHYRdyChg 10B8B DevExch }
[ 6750.482835] ata2: hard resetting link
[ 6751.206141] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 6751.207147] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 6751.229030] ata1.00: configured for UDMA/33
[ 6751.229035] ata1: EH complete
[ 6751.326282] ata2.00: configured for UDMA/33
[ 6751.326287] ata2: EH complete
[ 6751.571611] ata1: exception Emask 0x50 SAct 0x0 SErr 0x4090800 action 0xe frozen
[ 6751.571616] ata1: irq_stat 0x00400040, connection status changed
[ 6751.571618] ata1: SError: { HostInt PHYRdyChg 10B8B DevExch }
[ 6751.571623] ata1: hard resetting link
[ 6751.571655] ata2: exception Emask 0x50 SAct 0x0 SErr 0x4090800 action 0xe frozen
[ 6751.571657] ata2: irq_stat 0x00400040, connection status changed
[ 6751.571659] ata2: SError: { HostInt PHYRdyChg 10B8B DevExch }
[ 6751.571661] ata2: hard resetting link
[ 6752.294551] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 6752.294588] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 6752.317522] ata1.00: configured for UDMA/33
[ 6752.317527] ata1: EH complete
[ 6752.385676] ata2.00: configured for UDMA/33
[ 6752.385682] ata2: EH complete
Comment 28 Mikhail 2013-10-19 16:47:30 UTC
Created attachment 111621 [details]
dmesg with Audigy 2 SB240 soud card
Comment 29 Mikhail 2013-10-19 17:03:54 UTC
Created attachment 111631 [details]
system log
Comment 30 Mikhail 2013-10-20 06:29:45 UTC
[root@localhost ~]# smartctl -Ai /dev/sda
smartctl 6.2 2013-07-26 r3841 [x86_64-linux-3.11.5-302.fc20.x86_64+debug] (local build)
Copyright (C) 2002-13, Bruce Allen, Christian Franke, www.smartmontools.org

=== START OF INFORMATION SECTION ===
Model Family:     SandForce Driven SSDs
Device Model:     OCZ-VERTEX3
Serial Number:    OCZ-H3AU140C2BGX1269
LU WWN Device Id: 5 e83a97 eef5a6138
Firmware Version: 2.15
User Capacity:    90,028,302,336 bytes [90.0 GB]
Sector Size:      512 bytes logical/physical
Rotation Rate:    Solid State Device
Device is:        In smartctl database [for details use: -P show]
ATA Version is:   ATA8-ACS, ACS-2 T13/2015-D revision 3
SATA Version is:  SATA 3.0, 6.0 Gb/s (current: 1.5 Gb/s)
Local Time is:    Sun Oct 20 12:28:13 2013 YEKT
SMART support is: Available - device has SMART capability.
SMART support is: Enabled

=== START OF READ SMART DATA SECTION ===
SMART Attributes Data Structure revision number: 10
Vendor Specific SMART Attributes with Thresholds:
ID# ATTRIBUTE_NAME          FLAG     VALUE WORST THRESH TYPE      UPDATED  WHEN_FAILED RAW_VALUE
  1 Raw_Read_Error_Rate     0x000f   120   120   050    Pre-fail  Always       -       0/0
  5 Retired_Block_Count     0x0033   100   100   003    Pre-fail  Always       -       0
  9 Power_On_Hours_and_Msec 0x0032   089   089   000    Old_age   Always       -       10200h+17m+51.210s
 12 Power_Cycle_Count       0x0032   100   100   000    Old_age   Always       -       181
171 Program_Fail_Count      0x0032   000   000   000    Old_age   Always       -       0
172 Erase_Fail_Count        0x0032   000   000   000    Old_age   Always       -       0
174 Unexpect_Power_Loss_Ct  0x0030   000   000   000    Old_age   Offline      -       67
177 Wear_Range_Delta        0x0000   000   000   000    Old_age   Offline      -       1
181 Program_Fail_Count      0x0032   000   000   000    Old_age   Always       -       0
182 Erase_Fail_Count        0x0032   000   000   000    Old_age   Always       -       0
187 Reported_Uncorrect      0x0032   100   100   000    Old_age   Always       -       0
194 Temperature_Celsius     0x0022   030   030   000    Old_age   Always       -       30 (Min/Max 30/30)
195 ECC_Uncorr_Error_Count  0x001c   100   100   000    Old_age   Offline      -       0/0
196 Reallocated_Event_Count 0x0033   100   100   003    Pre-fail  Always       -       0
201 Unc_Soft_Read_Err_Rate  0x001c   100   100   000    Old_age   Offline      -       0/0
204 Soft_ECC_Correct_Rate   0x001c   100   100   000    Old_age   Offline      -       0/0
230 Life_Curve_Status       0x0013   100   100   000    Pre-fail  Always       -       100
231 SSD_Life_Left           0x0013   100   100   010    Pre-fail  Always       -       0
233 SandForce_Internal      0x0000   000   000   000    Old_age   Offline      -       2795
234 SandForce_Internal      0x0032   000   000   000    Old_age   Always       -       5608
241 Lifetime_Writes_GiB     0x0032   000   000   000    Old_age   Always       -       5608
242 Lifetime_Reads_GiB      0x0032   000   000   000    Old_age   Always       -       6670

[root@localhost ~]# smartctl -Ai /dev/sdb
smartctl 6.2 2013-07-26 r3841 [x86_64-linux-3.11.5-302.fc20.x86_64+debug] (local build)
Copyright (C) 2002-13, Bruce Allen, Christian Franke, www.smartmontools.org

=== START OF INFORMATION SECTION ===
Model Family:     Seagate Barracuda 7200.14 (AF)
Device Model:     ST3000DM001-9YN166
Serial Number:    W1F0N4VT
LU WWN Device Id: 5 000c50 05258d1fe
Firmware Version: CC4C
User Capacity:    3,000,592,982,016 bytes [3.00 TB]
Sector Sizes:     512 bytes logical, 4096 bytes physical
Rotation Rate:    7200 rpm
Device is:        In smartctl database [for details use: -P show]
ATA Version is:   ATA8-ACS T13/1699-D revision 4
SATA Version is:  SATA 3.0, 6.0 Gb/s (current: 1.5 Gb/s)
Local Time is:    Sun Oct 20 12:28:40 2013 YEKT

==> WARNING: A firmware update for this drive is available,
see the following Seagate web pages:
http://knowledge.seagate.com/articles/en_US/FAQ/207931en
http://knowledge.seagate.com/articles/en_US/FAQ/223651en

SMART support is: Available - device has SMART capability.
SMART support is: Enabled

=== START OF READ SMART DATA SECTION ===
SMART Attributes Data Structure revision number: 10
Vendor Specific SMART Attributes with Thresholds:
ID# ATTRIBUTE_NAME          FLAG     VALUE WORST THRESH TYPE      UPDATED  WHEN_FAILED RAW_VALUE
  1 Raw_Read_Error_Rate     0x000f   116   083   006    Pre-fail  Always       -       114294736
  3 Spin_Up_Time            0x0003   094   092   000    Pre-fail  Always       -       0
  4 Start_Stop_Count        0x0032   100   100   020    Old_age   Always       -       179
  5 Reallocated_Sector_Ct   0x0033   100   100   036    Pre-fail  Always       -       0
  7 Seek_Error_Rate         0x000f   084   060   030    Pre-fail  Always       -       302132984
  9 Power_On_Hours          0x0032   089   089   000    Old_age   Always       -       10102
 10 Spin_Retry_Count        0x0013   100   100   097    Pre-fail  Always       -       0
 12 Power_Cycle_Count       0x0032   100   100   020    Old_age   Always       -       170
183 Runtime_Bad_Block       0x0032   001   001   000    Old_age   Always       -       141
184 End-to-End_Error        0x0032   100   100   099    Old_age   Always       -       0
187 Reported_Uncorrect      0x0032   001   001   000    Old_age   Always       -       2719
188 Command_Timeout         0x0032   098   092   000    Old_age   Always       -       19 19 3147
189 High_Fly_Writes         0x003a   099   099   000    Old_age   Always       -       1
190 Airflow_Temperature_Cel 0x0022   058   051   045    Old_age   Always       -       42 (Min/Max 41/42)
191 G-Sense_Error_Rate      0x0032   100   100   000    Old_age   Always       -       0
192 Power-Off_Retract_Count 0x0032   100   100   000    Old_age   Always       -       117
193 Load_Cycle_Count        0x0032   099   099   000    Old_age   Always       -       3461
194 Temperature_Celsius     0x0022   042   049   000    Old_age   Always       -       42 (0 22 0 0 0)
197 Current_Pending_Sector  0x0012   100   001   000    Old_age   Always       -       0
198 Offline_Uncorrectable   0x0010   100   001   000    Old_age   Offline      -       0
199 UDMA_CRC_Error_Count    0x003e   200   200   000    Old_age   Always       -       10
240 Head_Flying_Hours       0x0000   100   253   000    Old_age   Offline      -       9318h+00m+56.120s
241 Total_LBAs_Written      0x0000   100   253   000    Old_age   Offline      -       47163341890975
242 Total_LBAs_Read         0x0000   100   253   000    Old_age   Offline      -       274444924102865

[root@localhost ~]#
Comment 31 Mikhail 2013-10-20 13:53:14 UTC
Also replace power supply to Toughpower XT 775W, but it's not solve problem :(

http://www.thermaltake.com/products-model.aspx?id=c_00001571
Comment 32 Mikhail 2013-10-20 13:54:04 UTC
Created attachment 111711 [details]
dmesg with Audigy 2 SB240 soud card and Toughpower XT 775W
Comment 33 Mikhail 2013-10-20 19:52:44 UTC
Checking operation with an external SATA controller failed. After connected SSD to an external SATA controller, system can not boot. I see on screen "Reached target Basic System." and nothings happens.
Comment 34 Mikhail 2013-10-20 19:53:36 UTC
Created attachment 111761 [details]
boot screen
Comment 35 Mikhail 2013-10-20 21:11:06 UTC
I flashed ROM BIOS of external SATA controller and after it controller begin recognize SATA devices under Linux. Next experiment I plug HDD to external SATA controller and leave SDD in internal MB controller so I see in dmesg messages only for internal controller.
Comment 36 Mikhail 2013-10-20 21:12:25 UTC
Created attachment 111771 [details]
dmesg with Audigy 2 SB240 soud card and HDD in external SATA controller
Comment 37 Mikhail 2013-10-21 20:49:44 UTC
Now I am sure this messages added each time after ALSA captures the sound card for play

[  999.183471] ata4: exception Emask 0x50 SAct 0x0 SErr 0x4090800 action 0xe frozen
[  999.183474] ata4: irq_stat 0x00400040, connection status changed
[  999.183475] ata4: SError: { HostInt PHYRdyChg 10B8B DevExch }
[  999.183478] ata4: hard resetting link
[  999.905244] ata4: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[  999.928388] ata4.00: configured for UDMA/133
[  999.928393] ata4: EH complete

Anybody hear me?
Comment 38 Takashi Iwai 2013-10-22 07:44:53 UTC
The fact that both two individual sound cards cause the same problem implies that the problem is generically in the PCI slot specific on your hardware.
I guess a similar problem may be triggered by other PCI cards, not only by sound cards, too.
Comment 39 Mikhail 2013-10-22 07:49:47 UTC
This means this problem in PCI or SATA controller.
Comment 40 Andy 2013-10-24 18:10:45 UTC
I have a very similar problem:

Oct 24 14:02:59 localhost kernel: [  201.429135] ata1: exception Emask 0x50 SAct 0x0 SErr 0x4090800 action 0xe frozen
Oct 24 14:02:59 localhost kernel: [  201.429138] ata1: irq_stat 0x00400040, connection status changed
Oct 24 14:02:59 localhost kernel: [  201.429141] ata1: SError: { HostInt PHYRdyChg 10B8B DevExch }
Oct 24 14:02:59 localhost kernel: [  201.429145] ata1: hard resetting link
Oct 24 14:03:00 localhost kernel: [  202.157561] ata1: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
Oct 24 14:03:00 localhost kernel: [  202.158454] ata1.00: configured for UDMA/100
Oct 24 14:03:00 localhost kernel: [  202.158457] ata1: EH complete

Lots of log files on the RH bugzilla:

https://bugzilla.redhat.com/show_bug.cgi?id=989070

I don't have a sound card in this box, but I can trigger the error by spiking CPU.  Just running glxgears will cause the error to repeat one after another, idle back down and they almost completely disappear.  Only seeming to reappear when CPU spikes a bit.

Intel(R) Xeon(R) CPU E3-1270 v3 @ 3.50GHz, Supermicro X10SLM-F.  I've tried swapping in known good SSDs, and spinning hard drives, swapping memory, power supplies, SATA cables etc.

Current kernel is 3.11.4-201.fc19.x86_64, but I've tried 3.11 from Linus's tree and the current RC6 from 3.12, all the same errors.

intel_iommu=off has no effect on the errors.  Memtest86+ runs for hours without errors.
Comment 41 Andy 2013-10-31 12:39:59 UTC
After discussion with Supermicro, this SATA dropping issue is a known design bug with my particular MB model.  They sent me a revised version and the problem as disappeared.
Comment 42 Mikhail 2013-10-31 12:50:26 UTC
My problem is not same because my controller is SATA controller: Intel Corporation 8 Series/C220 Series Chipset Family 6-port SATA Controller 1 [AHCI mode] (rev 04)
Comment 43 Mikhail 2013-11-03 13:54:54 UTC
It was possible to reproduce the problem with an empty PCI slot, when you connect the USB stick to the USB port.

Look here:

[160253.847876] usb 1-1: new high-speed USB device number 48 using xhci_hcd
[160253.869555] usb 1-1: New USB device found, idVendor=1005, idProduct=b113
[160253.869558] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[160253.869559] usb 1-1: Product: USB DISK 2.0
[160253.869560] usb 1-1: Manufacturer: www
[160253.869561] usb 1-1: SerialNumber: B48C1F000001
[160253.871886] usb-storage 1-1:1.0: USB Mass Storage device detected
[160253.872171] scsi2725 : usb-storage 1-1:1.0
[160254.876610] scsi 2725:0:0:0: Direct-Access     www      USB DISK 2.0     PMAP PQ: 0 ANSI: 0 CCS
[160254.878423] sd 2725:0:0:0: Attached scsi generic sg5 type 0
[160255.153141] sd 2725:0:0:0: [sde] 15654912 512-byte logical blocks: (8.01 GB/7.46 GiB)
[160255.153393] sd 2725:0:0:0: [sde] Write Protect is off
[160255.153395] sd 2725:0:0:0: [sde] Mode Sense: 23 00 00 00
[160255.153616] sd 2725:0:0:0: [sde] No Caching mode page found
[160255.153618] sd 2725:0:0:0: [sde] Assuming drive cache: write through
[160255.155973] sd 2725:0:0:0: [sde] No Caching mode page found
[160255.155976] sd 2725:0:0:0: [sde] Assuming drive cache: write through
[160255.156453]  sde: sde1
[160255.310246] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160255.326007] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160255.326010] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160255.485150] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160255.501076] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160255.501079] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160255.660032] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160255.675775] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160255.675779] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160255.834915] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160255.850699] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160255.850701] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160256.009848] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160256.025663] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160256.025666] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160256.185718] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160256.201561] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160256.201564] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160256.354615] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160256.370409] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160256.370411] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160256.529643] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160256.545263] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160256.545265] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160256.704504] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160256.720339] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160256.720342] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160256.879450] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160256.895116] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160256.895118] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160257.054241] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160257.070052] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160257.070055] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160257.229114] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160257.244908] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160257.244912] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160257.398142] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160257.413792] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160257.413795] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160257.572904] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160257.588866] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160257.588868] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160257.747820] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160257.763666] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160257.763669] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160257.923803] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160257.939481] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160257.939485] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160258.098727] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160258.114417] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160258.114421] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160258.273640] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160258.289353] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160258.289357] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160258.442456] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160258.458208] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160258.458211] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160258.618381] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160258.634136] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160258.634139] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160258.793299] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160258.809015] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160258.809017] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160258.968198] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160258.983916] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160258.983919] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160259.143027] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160259.158798] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160259.158801] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160259.318000] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160259.333732] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160259.333734] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160259.486886] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160259.502651] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160259.502654] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160259.661737] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160259.677651] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160259.677653] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160259.836737] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160259.852533] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160259.852536] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160260.011590] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160260.027352] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160260.027356] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160260.186580] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160260.202226] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160260.202230] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160260.361380] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160260.377106] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160260.377109] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160260.530297] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160260.546044] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160260.546047] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160260.705181] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160260.720955] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160260.720958] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160260.881077] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160260.896833] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160260.896835] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160261.055962] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160261.072804] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160261.072807] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160261.231853] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160261.248490] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160261.248492] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160261.407809] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160261.423517] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160261.423519] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160261.424120] sd 2725:0:0:0: [sde] READ CAPACITY failed
[160261.424122] sd 2725:0:0:0: [sde]  
[160261.424123] Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
[160261.424124] sd 2725:0:0:0: [sde] Sense not available.
[160261.576689] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160261.592356] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160261.592359] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160261.751749] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160261.767399] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160261.767402] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160261.926484] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160261.942311] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160261.942315] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160262.101314] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160262.117108] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160262.117111] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160262.276252] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160262.291949] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160262.291951] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160262.451196] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160262.466788] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160262.466791] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160262.620095] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160262.635958] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160262.635962] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160262.796014] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160262.811818] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160262.811821] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160262.971932] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160262.988668] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160262.988671] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160263.147779] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160263.163587] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160263.163590] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160263.322641] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160263.338448] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160263.338452] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160263.497549] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160263.513389] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160263.513392] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160263.667450] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160263.683219] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160263.683222] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160263.842351] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160263.858256] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160263.858259] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160264.017241] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160269.025125] usb 1-1: device descriptor read/8, error -110
[160274.134207] usb 1-1: device descriptor read/8, error -110
[160274.389136] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160279.397137] usb 1-1: device descriptor read/8, error -110
[160284.507169] usb 1-1: device descriptor read/8, error -110
[160284.761125] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160289.009522] usb 2-5: USB disconnect, device number 66
[160289.010347] usb 2-5: Set SEL for device-initiated U1 failed.
[160289.010364] usb 2-5: Set SEL for device-initiated U2 failed.
[160289.769102] usb 1-1: device descriptor read/8, error -110
[160294.878133] usb 1-1: device descriptor read/8, error -110
[160295.133125] usb 1-1: reset high-speed USB device number 48 using xhci_hcd
[160300.141155] usb 1-1: device descriptor read/8, error -110
[160305.250213] usb 1-1: device descriptor read/8, error -110
[160305.351133] sd 2725:0:0:0: Device offlined - not ready after error recovery
[160305.351182] sd 2725:0:0:0: rejecting I/O to offline device
[160305.351184] sd 2725:0:0:0: killing request
[160305.351266] sd 2725:0:0:0: [sde] Asking for cache data failed
[160305.351268] sd 2725:0:0:0: [sde] Assuming drive cache: write through
[160305.351288] sd 2725:0:0:0: [sde] Attached SCSI removable disk
[160305.751745] usb 2-5: new SuperSpeed USB device number 67 using xhci_hcd
[160305.766532] usb 2-5: New USB device found, idVendor=2109, idProduct=0811
[160305.766535] usb 2-5: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[160305.766537] usb 2-5: Product: 4-Port USB 3.0 Hub
[160305.766539] usb 2-5: Manufacturer: VIA Labs, Inc.
[160305.770056] hub 2-5:1.0: USB hub found
[160305.770191] hub 2-5:1.0: 4 ports detected
[160305.773101] usb 1-1: USB disconnect, device number 48
[160305.781897] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597018
[160305.781900] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88061f597058
[160305.939685] usb 1-1: new high-speed USB device number 49 using xhci_hcd
[160306.001549] usb 1-1: device descriptor read/8, error -71
[160306.317910] usb 1-1: device descriptor read/8, error -71
[160306.571458] usb 1-1: new high-speed USB device number 50 using xhci_hcd
[160306.728496] usb 1-1: device descriptor read/8, error -71
[160306.893259] usb 1-1: device descriptor read/8, error -71
[160307.148103] usb 1-1: new high-speed USB device number 51 using xhci_hcd
[160312.156215] usb 1-1: device descriptor read/8, error -110
[160317.265186] usb 1-1: device descriptor read/8, error -110
[160317.518931] usb 1-1: new high-speed USB device number 52 using xhci_hcd
[160322.527117] usb 1-1: device descriptor read/8, error -110
[160327.636147] usb 1-1: device descriptor read/8, error -110
[160327.737378] hub 1-0:1.0: unable to enumerate USB device on port 1
[160396.419966] BUG: sleeping function called from invalid context at mm/slub.c:935
[160396.419969] in_atomic(): 1, irqs_disabled(): 1, pid: 662, name: Xorg
[160396.419970] INFO: lockdep is turned off.
[160396.419971] irq event stamp: 384112
[160396.419971] hardirqs last  enabled at (384111): [<ffffffff81731b36>] _raw_spin_unlock_irqrestore+0x36/0x70
[160396.419990] hardirqs last disabled at (384112): [<ffffffff8173235b>] _raw_spin_lock_irqsave+0x2b/0xa0
[160396.419992] softirqs last  enabled at (384052): [<ffffffff8107b461>] __do_softirq+0x1a1/0x410
[160396.419995] softirqs last disabled at (384043): [<ffffffff8173d63c>] call_softirq+0x1c/0x30
[160396.419999] CPU: 6 PID: 662 Comm: Xorg Tainted: G        W    3.11.6-301.fc20.x86_64+debug #1
[160396.420000] Hardware name: Gigabyte Technology Co., Ltd. Z87M-D3H/Z87M-D3H, BIOS F8 08/03/2013
[160396.420001]  ffffffff81a2e2bb ffff8807e562dd18 ffffffff817289cc 0000000000000000
[160396.420003]  ffff8807e562dd40 ffffffff810ad9e9 00000000000000d0 00000000000000d0
[160396.420005]  0000000000000009 ffff8807e562dd98 ffffffff811d1ef7 ffffffff815a497d
[160396.420007] Call Trace:
[160396.420009]  [<ffffffff817289cc>] dump_stack+0x54/0x74
[160396.420012]  [<ffffffff810ad9e9>] __might_sleep+0x179/0x230
[160396.420014]  [<ffffffff811d1ef7>] __kmalloc+0x67/0x3b0
[160396.420018]  [<ffffffff815a497d>] ? hid_dump_input+0x7d/0x90
[160396.420019]  [<ffffffff815a670a>] hid_alloc_report_buf+0x2a/0x30
[160396.420023]  [<ffffffffa00067f5>] logi_dj_ll_input_event+0xa5/0x1a0 [hid_logitech_dj]
[160396.420027]  [<ffffffff8154a30e>] input_handle_event+0x8e/0x530
[160396.420029]  [<ffffffff8154a9d0>] input_inject_event+0x1b0/0x250
[160396.420031]  [<ffffffff8154a863>] ? input_inject_event+0x43/0x250
[160396.420032]  [<ffffffff8154f08f>] evdev_write+0xef/0x150
[160396.420036]  [<ffffffff811f1e80>] vfs_write+0xc0/0x1f0
[160396.420039]  [<ffffffff8121137c>] ? fget_light+0x28c/0x510
[160396.420041]  [<ffffffff811f28fc>] SyS_write+0x4c/0xa0
[160396.420044]  [<ffffffff8173bcd9>] system_call_fastpath+0x16/0x1b
[160480.112700] ata4.00: exception Emask 0x10 SAct 0xc SErr 0x400100 action 0x6 frozen
[160480.112704] ata4.00: irq_stat 0x08000000, interface fatal error
[160480.112706] ata4: SError: { UnrecovData Handshk }
[160480.112708] ata4.00: failed command: WRITE FPDMA QUEUED
[160480.112712] ata4.00: cmd 61/40:10:b8:0c:ec/00:00:9d:00:00/40 tag 2 ncq 32768 out
         res 40/00:08:50:30:cd/00:00:8d:00:00/40 Emask 0x10 (ATA bus error)
[160480.112713] ata4.00: status: { DRDY }
[160480.112715] ata4.00: failed command: READ FPDMA QUEUED
[160480.112718] ata4.00: cmd 60/28:18:70:79:e3/00:00:01:01:00/40 tag 3 ncq 20480 in
         res 40/00:08:50:30:cd/00:00:8d:00:00/40 Emask 0x10 (ATA bus error)
[160480.112719] ata4.00: status: { DRDY }
[160480.112723] ata4: hard resetting link
[160480.418451] ata4: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[160480.483190] ata4.00: configured for UDMA/133
[160480.483203] ata4: EH complete


Sorry, but seem USB controller also conflict with SATA controller!!! What's happens?
Comment 44 Mikhail 2013-11-18 04:17:45 UTC
[68768.667386] ata4.00: exception Emask 0x0 SAct 0xf SErr 0x0 action 0x6 frozen
[68768.667390] ata4.00: failed command: READ FPDMA QUEUED
[68768.667393] ata4.00: cmd 60/20:00:d8:af:3a/00:00:f7:00:00/40 tag 0 ncq 16384 in
         res 40/00:00:00:4f:c2/00:00:00:00:00/40 Emask 0x4 (timeout)
[68768.667394] ata4.00: status: { DRDY }
[68768.667395] ata4.00: failed command: READ FPDMA QUEUED
[68768.667397] ata4.00: cmd 60/20:08:20:d6:c6/00:00:20:01:00/40 tag 1 ncq 16384 in
         res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[68768.667398] ata4.00: status: { DRDY }
[68768.667399] ata4.00: failed command: READ FPDMA QUEUED
[68768.667400] ata4.00: cmd 60/20:10:60:eb:22/00:00:12:01:00/40 tag 2 ncq 16384 in
         res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[68768.667401] ata4.00: status: { DRDY }
[68768.667402] ata4.00: failed command: READ FPDMA QUEUED
[68768.667404] ata4.00: cmd 60/20:18:80:eb:22/00:00:12:01:00/40 tag 3 ncq 16384 in
         res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[68768.667405] ata4.00: status: { DRDY }
[68768.667408] ata4: hard resetting link
[68768.972048] ata4: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[68768.976093] ata4.00: configured for UDMA/133
[68768.976097] ata4.00: device reported invalid CHS sector 0
[68768.976099] ata4.00: device reported invalid CHS sector 0
[68768.976100] ata4.00: device reported invalid CHS sector 0
[68768.976101] ata4.00: device reported invalid CHS sector 0
[68768.976112] ata4: EH complete
[69490.070624] =============================================================================
[69490.070627] BUG filp (Not tainted): Poison overwritten
[69490.070628] -----------------------------------------------------------------------------

[69490.070629] Disabling lock debugging due to kernel taint
[69490.070630] INFO: 0xffff8805352c4e26-0xffff8805352c4e26. First byte 0x69 instead of 0x6b
[69490.070634] INFO: Allocated in get_empty_filp+0x61/0x250 age=9755 cpu=1 pid=2465
[69490.070637] 	__slab_alloc+0x3eb/0x4fe
[69490.070639] 	kmem_cache_alloc+0x294/0x340
[69490.070640] 	get_empty_filp+0x61/0x250
[69490.070642] 	path_openat+0x3d/0x6a0
[69490.070643] 	do_filp_open+0x3a/0x90
[69490.070645] 	do_sys_open+0x12e/0x210
[69490.070647] 	SyS_open+0x1e/0x20
[69490.070648] 	system_call_fastpath+0x16/0x1b
[69490.070650] INFO: Freed in file_free_rcu+0x43/0x60 age=9723 cpu=1 pid=2465
[69490.070651] 	__slab_free+0x3a/0x382
[69490.070652] 	kmem_cache_free+0x356/0x370
[69490.070653] 	file_free_rcu+0x43/0x60
[69490.070655] 	rcu_process_callbacks+0x20a/0x7e0
[69490.070658] 	__do_softirq+0x107/0x410
[69490.070659] 	call_softirq+0x1c/0x30
[69490.070661] 	do_softirq+0x85/0xc0
[69490.070662] 	irq_exit+0xc5/0xd0
[69490.070664] 	smp_apic_timer_interrupt+0x45/0x60
[69490.070665] 	apic_timer_interrupt+0x72/0x80
[69490.070667] 	selinux_ptrace_access_check+0x95/0x200
[69490.070670] 	security_ptrace_access_check+0x13/0x20
[69490.070671] 	__ptrace_may_access+0x1f9/0x4e0
[69490.070673] 	ptrace_may_access+0x2e/0x50
[69490.070675] 	do_task_stat+0x81/0xb60
[69490.070676] 	proc_tid_stat+0x11/0x20
[69490.070677] INFO: Slab 0xffffea0014d4b100 objects=23 used=23 fp=0x          (null) flags=0x5ff00000004080
[69490.070678] INFO: Object 0xffff8805352c4dc0 @offset=3520 fp=0xffff8805352c58c0

[69490.070680] Bytes b4 ffff8805352c4db0: 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a  ZZZZZZZZZZZZZZZZ
[69490.070681] Object ffff8805352c4dc0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070682] Object ffff8805352c4dd0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070682] Object ffff8805352c4de0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070683] Object ffff8805352c4df0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070684] Object ffff8805352c4e00: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070685] Object ffff8805352c4e10: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070686] Object ffff8805352c4e20: 6b 6b 6b 6b 6b 6b 69 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkikkkkkkkkk
[69490.070686] Object ffff8805352c4e30: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070687] Object ffff8805352c4e40: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070688] Object ffff8805352c4e50: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070689] Object ffff8805352c4e60: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070690] Object ffff8805352c4e70: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070690] Object ffff8805352c4e80: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070691] Object ffff8805352c4e90: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070692] Object ffff8805352c4ea0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070693] Object ffff8805352c4eb0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070694] Object ffff8805352c4ec0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070694] Object ffff8805352c4ed0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070695] Object ffff8805352c4ee0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070696] Object ffff8805352c4ef0: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070697] Object ffff8805352c4f00: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070698] Object ffff8805352c4f10: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b  kkkkkkkkkkkkkkkk
[69490.070698] Object ffff8805352c4f20: 6b 6b 6b 6b 6b 6b 6b a5                          kkkkkkk.
[69490.070699] Redzone ffff8805352c4f28: bb bb bb bb bb bb bb bb                          ........
[69490.070700] Padding ffff8805352c5068: 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a 5a  ZZZZZZZZZZZZZZZZ
[69490.070701] Padding ffff8805352c5078: 5a 5a 5a 5a 5a 5a 5a 5a                          ZZZZZZZZ
[69490.070702] CPU: 2 PID: 2465 Comm: htop Tainted: G    B        3.12.0-2.fc21.x86_64+debug #1
[69490.070703] Hardware name: Gigabyte Technology Co., Ltd. Z87M-D3H/Z87M-D3H, BIOS F8 08/03/2013
[69490.070704]  ffff8805352c4dc0 ffff8807bca77b78 ffffffff81742e92 ffff88081e81a1c0
[69490.070707]  ffff8807bca77bb8 ffffffff811d368d 0000000000000018 ffff880500000001
[69490.070709]  ffff8805352c4e27 ffff88081e81a1c0 000000000000006b ffff8805352c4dc0
[69490.070710] Call Trace:
[69490.070712]  [<ffffffff81742e92>] dump_stack+0x54/0x74
[69490.070714]  [<ffffffff811d368d>] print_trailer+0x14d/0x200
[69490.070715]  [<ffffffff811d387f>] check_bytes_and_report+0xcf/0x110
[69490.070717]  [<ffffffff811d46f7>] check_object+0x1d7/0x250
[69490.070718]  [<ffffffff811f8201>] ? get_empty_filp+0x61/0x250
[69490.070720]  [<ffffffff81740613>] alloc_debug_processing+0x76/0x118
[69490.070722]  [<ffffffff8174124e>] __slab_alloc+0x3eb/0x4fe
[69490.070724]  [<ffffffff8174c0f7>] ? _raw_spin_unlock+0x27/0x40
[69490.070725]  [<ffffffff811d5c34>] ? deactivate_slab+0x544/0x630
[69490.070726]  [<ffffffff811f8201>] ? get_empty_filp+0x61/0x250
[69490.070728]  [<ffffffff811d6244>] kmem_cache_alloc+0x294/0x340
[69490.070729]  [<ffffffff811f8201>] ? get_empty_filp+0x61/0x250
[69490.070731]  [<ffffffff811f8201>] get_empty_filp+0x61/0x250
[69490.070732]  [<ffffffff8120725d>] path_openat+0x3d/0x6a0
[69490.070735]  [<ffffffff810f242d>] ? trace_hardirqs_on+0xd/0x10
[69490.070737]  [<ffffffff81021b45>] ? native_sched_clock+0x15/0x80
[69490.070738]  [<ffffffff810eebdd>] ? trace_hardirqs_off+0xd/0x10
[69490.070740]  [<ffffffff81207ffa>] do_filp_open+0x3a/0x90
[69490.070741]  [<ffffffff8174c0f7>] ? _raw_spin_unlock+0x27/0x40
[69490.070744]  [<ffffffff8121724f>] ? __alloc_fd+0xaf/0x200
[69490.070746]  [<ffffffff811f57fe>] do_sys_open+0x12e/0x210
[69490.070747]  [<ffffffff811f5914>] SyS_openat+0x14/0x20
[69490.070749]  [<ffffffff81756229>] system_call_fastpath+0x16/0x1b
[69490.070750] FIX filp: Restoring 0xffff8805352c4e26-0xffff8805352c4e26=0x6b

[69490.070751] FIX filp: Marking all objects used
Comment 45 Mikhail 2013-11-18 04:21:06 UTC
Created attachment 115011 [details]
dmesg output with 3.12 kernel
Comment 46 Mikhail 2013-11-20 17:47:48 UTC
[75767.329715] ata4.00: exception Emask 0x10 SAct 0x7ff03 SErr 0x0 action 0x6 frozen
[75767.329718] ata4.00: irq_stat 0x08000000, interface fatal error
[75767.329720] ata4.00: failed command: READ FPDMA QUEUED
[75767.329722] ata4.00: cmd 60/20:00:38:ec:c8/00:00:08:01:00/40 tag 0 ncq 16384 in
         res 40/00:38:b8:ea:c8/00:00:08:01:00/40 Emask 0x10 (ATA bus error)
[75767.329723] ata4.00: status: { DRDY }
[75767.329724] ata4.00: failed command: READ FPDMA QUEUED
[75767.329726] ata4.00: cmd 60/20:08:58:ec:c8/00:00:08:01:00/40 tag 1 ncq 16384 in
         res 40/00:38:b8:ea:c8/00:00:08:01:00/40 Emask 0x10 (ATA bus error)
[75767.329727] ata4.00: status: { DRDY }
[75767.329728] ata4.00: failed command: READ FPDMA QUEUED
[75767.329730] ata4.00: cmd 60/20:40:d8:ea:c8/00:00:08:01:00/40 tag 8 ncq 16384 in
         res 40/00:38:b8:ea:c8/00:00:08:01:00/40 Emask 0x10 (ATA bus error)
[75767.329731] ata4.00: status: { DRDY }
[75767.329732] ata4.00: failed command: READ FPDMA QUEUED
[75767.329734] ata4.00: cmd 60/20:48:f8:ea:c8/00:00:08:01:00/40 tag 9 ncq 16384 in
         res 40/00:38:b8:ea:c8/00:00:08:01:00/40 Emask 0x10 (ATA bus error)
[75767.329735] ata4.00: status: { DRDY }
[75767.329736] ata4.00: failed command: READ FPDMA QUEUED
[75767.329738] ata4.00: cmd 60/20:50:18:eb:c8/00:00:08:01:00/40 tag 10 ncq 16384 in
         res 40/00:38:b8:ea:c8/00:00:08:01:00/40 Emask 0x10 (ATA bus error)
[75767.329739] ata4.00: status: { DRDY }
[75767.329739] ata4.00: failed command: READ FPDMA QUEUED
[75767.329741] ata4.00: cmd 60/20:58:38:eb:c8/00:00:08:01:00/40 tag 11 ncq 16384 in
         res 40/00:38:b8:ea:c8/00:00:08:01:00/40 Emask 0x10 (ATA bus error)
[75767.329742] ata4.00: status: { DRDY }
[75767.329743] ata4.00: failed command: READ FPDMA QUEUED
[75767.329745] ata4.00: cmd 60/20:60:58:eb:c8/00:00:08:01:00/40 tag 12 ncq 16384 in
         res 40/00:38:b8:ea:c8/00:00:08:01:00/40 Emask 0x10 (ATA bus error)
[75767.329746] ata4.00: status: { DRDY }
[75767.329747] ata4.00: failed command: READ FPDMA QUEUED
[75767.329748] ata4.00: cmd 60/20:68:78:eb:c8/00:00:08:01:00/40 tag 13 ncq 16384 in
         res 40/00:38:b8:ea:c8/00:00:08:01:00/40 Emask 0x10 (ATA bus error)
[75767.329749] ata4.00: status: { DRDY }
[75767.329750] ata4.00: failed command: READ FPDMA QUEUED
[75767.329752] ata4.00: cmd 60/20:70:98:eb:c8/00:00:08:01:00/40 tag 14 ncq 16384 in
         res 40/00:38:b8:ea:c8/00:00:08:01:00/40 Emask 0x10 (ATA bus error)
[75767.329753] ata4.00: status: { DRDY }
[75767.329754] ata4.00: failed command: READ FPDMA QUEUED
[75767.329756] ata4.00: cmd 60/20:78:b8:eb:c8/00:00:08:01:00/40 tag 15 ncq 16384 in
         res 40/00:38:b8:ea:c8/00:00:08:01:00/40 Emask 0x10 (ATA bus error)
[75767.329757] ata4.00: status: { DRDY }
[75767.329758] ata4.00: failed command: READ FPDMA QUEUED
[75767.329759] ata4.00: cmd 60/20:80:d8:eb:c8/00:00:08:01:00/40 tag 16 ncq 16384 in
         res 40/00:38:b8:ea:c8/00:00:08:01:00/40 Emask 0x10 (ATA bus error)
[75767.329760] ata4.00: status: { DRDY }
[75767.329761] ata4.00: failed command: READ FPDMA QUEUED
[75767.329763] ata4.00: cmd 60/20:88:f8:eb:c8/00:00:08:01:00/40 tag 17 ncq 16384 in
         res 40/00:38:b8:ea:c8/00:00:08:01:00/40 Emask 0x10 (ATA bus error)
[75767.329764] ata4.00: status: { DRDY }
[75767.329765] ata4.00: failed command: READ FPDMA QUEUED
[75767.329767] ata4.00: cmd 60/20:90:18:ec:c8/00:00:08:01:00/40 tag 18 ncq 16384 in
         res 40/00:38:b8:ea:c8/00:00:08:01:00/40 Emask 0x10 (ATA bus error)
[75767.329768] ata4.00: status: { DRDY }
[75767.329770] ata4: hard resetting link
[75767.634031] ata4: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[75767.754311] ata4.00: configured for UDMA/133
[75767.754338] ata4: EH complete
Comment 47 Mikhail 2013-11-20 17:48:49 UTC
Created attachment 115321 [details]
dmesg kernel 3.12
Comment 48 Tejun Heo 2013-11-20 17:52:18 UTC
Mikhail, your problem doesn't seem to be a software issue. You're experiencing a host of *electric* problems on your machine. Those external links fail first because they get affected the most but even the memory bits seem to be flipping. Can you please try put on a different power supply?

Thanks.
Comment 49 Mikhail 2013-11-20 17:55:00 UTC
> try put on a different power supply?
Yes, I try a few known good power supplys.
Comment 50 Mikhail 2013-11-20 17:58:00 UTC
Created attachment 115331 [details]
Memory also work fine
Comment 51 Tejun Heo 2013-11-20 18:03:43 UTC
Hmm... too bad. I have no idea what's going on but the machine seems screwed up in the layer way below where the OS can do anything. I'd try to contact the hardware manufacturer. If it's a custom build, maybe try RMA the motherboard? But, at any rate, you need an electronics engineer instead of an os dev.

And, yeah, your ram sticks are likely fine in isolation but when all the stuff are going on, the kernel also reports errors which are highly likely results of bit flips. It's likely that the internal buses are being affected too.

Thanks and good luck.
Comment 52 Mikhail 2013-11-22 04:30:49 UTC
[115463.382992] ata4.00: exception Emask 0x0 SAct 0xf SErr 0x0 action 0x6 frozen
[115463.382996] ata4.00: failed command: WRITE FPDMA QUEUED
[115463.382999] ata4.00: cmd 61/40:00:80:77:18/00:00:9e:00:00/40 tag 0 ncq 32768 out
         res 40/00:00:00:4f:c2/00:00:00:00:00/40 Emask 0x4 (timeout)
[115463.383001] ata4.00: status: { DRDY }
[115463.383002] ata4.00: failed command: READ FPDMA QUEUED
[115463.383004] ata4.00: cmd 60/28:08:18:fc:64/00:00:13:01:00/40 tag 1 ncq 20480 in
         res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[115463.383005] ata4.00: status: { DRDY }
[115463.383006] ata4.00: failed command: WRITE FPDMA QUEUED
[115463.383008] ata4.00: cmd 61/50:10:d8:24:84/00:00:ae:00:00/40 tag 2 ncq 40960 out
         res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[115463.383010] ata4.00: status: { DRDY }
[115463.383011] ata4.00: failed command: WRITE FPDMA QUEUED
[115463.383013] ata4.00: cmd 61/10:18:d8:fc:b6/00:00:9d:00:00/40 tag 3 ncq 8192 out
         res 40/00:28:a0:ee:65/00:00:0b:01:00/40 Emask 0x4 (timeout)
[115463.383014] ata4.00: status: { DRDY }
[115463.383017] ata4: hard resetting link
[115463.687794] ata4: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[115463.715289] ata4.00: configured for UDMA/133
[115463.715292] ata4.00: device reported invalid CHS sector 0
[115463.715294] ata4.00: device reported invalid CHS sector 0
[115463.715295] ata4.00: device reported invalid CHS sector 0
[115463.715308] ata4: EH complete
Comment 53 Alan 2013-12-18 14:43:56 UTC

*** This bug has been marked as a duplicate of bug 64521 ***
Comment 54 Mikhail 2014-03-19 06:51:20 UTC
Please do not leave me with this problem!!!



Question: 	I have m/b Gigabyte Z87M-D3H with latest F10 BIOS. When I insert into PCI slot ESI Juli@ sound card my Linux Fedora 20 became unbottable. Red Hat kernel team said that this is hardware problem. https://bugzilla.redhat.com/show_bug.cgi?id=989070 	3/13/2014 5:00 AM
Attachments: 	dsc01958.jpg  
Answer: 	

Good day!

Thank you for contacting GBT Tech Support.

Gigabyte motherboards passes the appropriate certification to be compatible with Microsoft operation systems (certified Windows Hardware Quality Labs / WHQL) Information about the compatibility can be found on the website Microsoft: http://www.microsoft.com/windows/compatibility/windows-7/en-us/Search.aspx?l=en-us&type=Hardware&s=gigabyte&results=50&page=2. All Gigabyte products, all software is developed and tested only for Microsoft operation systems.

In your case, GA-Z87M-D3H (rev. 1.x) supports Microsoft Windows 8/7.
Also we notify our users that: "Due to different Linux support condition provided by chipset vendors, please download Linux driver from chipset vendors' website or 3rd party website." This information contained on our website.

Thus, we can not guarantee stable operation of computer using the operating system Linux

Best Regards,
GIGABYTE Technology
Comment 55 Mikhail 2014-03-19 06:51:47 UTC
Created attachment 130011 [details]
gigabyte support answer

Note You need to log in before you can comment on or make changes to this bug.