Bug 906532 - Hard freezes with ASMedia SATA (1b21:0612) (PCIe) and Optical Drive (iHBS112) (WORKAROUND = 'libata.atapi_passthru16=0')
Summary: Hard freezes with ASMedia SATA (1b21:0612) (PCIe) and Optical Drive (iHBS112)...
Keywords:
Status: CLOSED INSUFFICIENT_DATA
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: 21
Hardware: x86_64
OS: Linux
unspecified
high
Target Milestone: ---
Assignee: Kernel Maintainer List
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2013-01-31 19:49 UTC by Reartes Guillermo
Modified: 2019-02-26 23:03 UTC (History)
9 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2015-02-24 16:14:24 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
messages of the freeze and the next boot (134.60 KB, text/plain)
2013-01-31 19:53 UTC, Reartes Guillermo
no flags Details
testing with growisofs and a dvd+rw (34.60 KB, text/plain)
2013-01-31 20:47 UTC, Reartes Guillermo
no flags Details
blkparse output of the optical drive attached to the asmedia controller (19.18 KB, text/plain)
2013-10-01 16:33 UTC, Reartes Guillermo
no flags Details

Description Reartes Guillermo 2013-01-31 19:49:52 UTC
Description of problem:

When using my optical drive iHBS112, the machine hard freezes. One must push the reset switch of power-cycle the system.

I recently installed a PCIe 1X SATA Controller on a free PCIe Slot:

# lspci -nn
06:00.0 SATA controller [0106]: ASMedia Technology Inc. Device [1b21:0612] (rev 01)
        Subsystem: ASMedia Technology Inc. Device [1b21:1060]
        Kernel driver in use: ahci

Which corresponds to:
        
# lsscsi
[11:0:0:0]   cd/dvd  ATAPI    iHBS112   2      CL0K  /dev/sr0

DMESG:
[    3.441070] ata12: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[    3.444902] ata12.00: ATAPI: ATAPI   iHBS112   2, CL0K, max UDMA/100
[    3.446528] ata12.00: configured for UDMA/100

[    2.091681] ata11: SATA max UDMA/133 abar m512@0xfe510000 port 0xfe510100 irq 73
[    2.091683] ata12: SATA max UDMA/133 abar m512@0xfe510000 port 0xfe510180 irq 73

Under: 3.7.3-101.fc17.x86_64 (Fedora 17 X86_64)

HW: FX-6100 on 990FX (Asus Sabertooth 990FX, Bios: 1604)

On the ASMedia controller, one port goes to the BluRay Writer (iHBS112) and
the other port goes to the chassis eSATA port (not tested yet).

I planed to use this controller for two sata hotswap bays but the sata cables
were short and did not reach the pcie card, so i was only able to plug both the
optical drive and the chassis esata port on this controller.

The optical drive is detected, but when i first tried to burn a bluray, it gave
an i/o error (since i was diagnosing a previous growisofs bug-report i got a strace) then i ejected and reinserted the media and the system froze. 

Then i reset it, but it froze again when the disc was inserted. Then i power it off and on again and inserted a blank dvd+rw this time to burn a regular dvd+ but it also froze...

It does not froze if the optical drive is empty. This writer worked ok while it was connected to the on-board sb950 sata controller.

Later tests showed that it is not bluray specific, it can be easyly reproduced with just dvd+r. The first burn (of dvd+r at least) works ok, later attempts are not guaranteed to success. 

I monitored the logs remotely and this happens at the moment of the freeze:

Jan 25 18:56:45 ulquiorra dbus-daemon[1174]: ** Message: No devices in use, exit
Jan 25 19:06:40 ulquiorra udevd[497]: worker [711] timeout, kill it
Jan 25 19:06:40 ulquiorra udevd[497]: seq 2760 '/devices/pci0000:00/0000:00:0d.0/0000:06:00.0/ata12/host11/target11:0:0/11:0:0:0/block/sr0' killed
Jan 25 19:06:40 ulquiorra udevd[497]: worker [711] terminated by signal 9 (Killed)
Jan 25 19:06:41 ulquiorra kernel: [ 3901.881021] ata12.00: exception Emask 0x52 SAct 0x0 SErr 0xffffffff action 0xe frozen
Jan 25 19:06:41 ulquiorra kernel: [ 3901.881043] ata12: SError: { RecovData RecovComm UnrecovData Persist Proto HostInt PHYRdyChg PHYInt CommWake 10B8B Dispar BadCRC Handshk LinkSeq TrStaTrns UnrecFIS DevExch }
Jan 25 19:06:41 ulquiorra kernel: [ 3901.881051] ata12.00: failed command: IDENTIFY PACKET DEVICE
Jan 25 19:06:41 ulquiorra kernel: [ 3901.881063] ata12.00: cmd a1/00:01:00:00:00/00:00:00:00:00/00 tag 0 pio 512 in
Jan 25 19:06:41 ulquiorra kernel: [ 3901.881063]          res 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x56 (ATA bus error)
Jan 25 19:06:41 ulquiorra kernel: [ 3901.881069] ata12.00: status: { DRDY }
Jan 25 19:06:41 ulquiorra kernel: [ 3901.881079] ata12: hard resetting link


Version-Release number of selected component (if applicable):
F17, kernel: 3.7.4-104.fc17.x86_64 (and older)

How reproducible:
always

Steps to Reproduce:
1. insert a blank dvd+r
2. burn something (i used K3b with verify writen data option set). The first
time after poweron it works always ok.
3. if previous step was successful, insert another dvd+r and burn something.
4. sometimes is the second time, sometimes the third, but the system will hard freeze.
  
Actual results:
hard freeze, reset or power-cycle is needed (pressing the physical button).
the 'freeze' seems to ocur after inserting a blank media (step 3).

Expected results:
no freeze and being able to burn whatever the writer does support. 

Additional info:

Comment 1 Reartes Guillermo 2013-01-31 19:53:04 UTC
Created attachment 691202 [details]
messages of the freeze and the next boot

These are not shown in the attached messages but were obtained from a remote ssh session which was monitoring the messages file.

Jan 31 16:20:33 ulquiorra udevd[497]: worker [676] terminated by signal 9 (Killed)
Jan 31 16:20:34 ulquiorra kernel: [209962.926209] ata12.00: exception Emask 0x52 SAct 0x0 SErr 0xffffffff action 0xe frozen
Jan 31 16:20:34 ulquiorra kernel: [209962.926220] ata12: SError: { RecovData RecovComm UnrecovData Persist Proto HostInt PHYRdyChg PHYInt CommWake 10B8B Dispar BadCRC Handshk LinkSeq TrStaTrns UnrecFIS DevExch }
Jan 31 16:20:34 ulquiorra kernel: [209962.926228] ata12.00: failed command: IDENTIFY PACKET DEVICE
Jan 31 16:20:34 ulquiorra kernel: [209962.926239] ata12.00: cmd a1/00:01:00:00:00/00:00:00:00:00/00 tag 0 pio 512 in
Jan 31 16:20:34 ulquiorra kernel: [209962.926239]          res 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x56 (ATA bus error)

Also after boot, there are errors in sr0, the same media that triggered the freeze is still inserted.

# dvd+rw-mediainfo /dev/sr0
INQUIRY:                [ATAPI   ][iHBS112   2     ][CL0K]
GET [CURRENT] CONFIGURATION:
 Mounted Media:         1Bh, DVD+R
 Current Write Speed:   16.0x1385=22160KB/s
 Write Speed #0:        16.0x1385=22160KB/s
 Write Speed #1:        12.0x1385=16620KB/s
 Write Speed #2:        8.0x1385=11080KB/s
 Write Speed #3:        6.0x1385=8310KB/s
 Speed Descriptor#0:    00/2295103 R=22160KB/s W=22160KB/s
READ DVD STRUCTURE[#0h]:
 Media Book Type:       00h, DVD-ROM book [revision 0]
 Media ID:              CMC MAG/M01
 Legacy lead-out at:    2295104*2KB=4700372992
READ DISC INFORMATION:
 Disc status:           blank
 Number of Sessions:    1
 State of Last Session: empty
 "Next" Track:          1
 Number of Tracks:      1
READ TRACK INFORMATION[#1]:
 Track State:           blank
 Track Start Address:   0*2KB
 Next Writable Address: 0*2KB
 Free Blocks:           2295104*2KB
 Track Size:            2295104*2KB
 ROM Compatibility LBA: 270336
READ CAPACITY:          0*2048=0


Jan 31 16:20:34 ulquiorra kernel: [209962.926246] ata12.00: status: { DRDY }
Jan 31 16:20:34 ulquiorra kernel: [209962.926255] ata12: hard resetting link

Comment 2 Reartes Guillermo 2013-01-31 20:47:53 UTC
Created attachment 691217 [details]
testing with growisofs and a dvd+rw

I tested with a dvd+rw, burn, eject, insert, burn, etc.

This time, it burned two times ok. After finishing the second time, i pressed the 'eject' button on the writer and the disc was not ejected. So i executed an 'eject' from the laptop and the system got frozen. (this time on eject).

Jan 31 17:36:03 ulquiorra udevd[495]: worker [1176] timeout, kill it
Jan 31 17:36:03 ulquiorra udevd[495]: seq 2743 '/devices/pci0000:00/0000:00:0d.0/0000:06:00.0/ata12/host11/target11:0:0/11:0:0:0/block/sr0' killed
Jan 31 17:36:03 ulquiorra udevd[495]: worker [1176] terminated by signal 9 (Killed)
Jan 31 17:36:04 ulquiorra kernel: [ 2153.336897] ata12.00: exception Emask 0x52 SAct 0x0 SErr 0xffffffff action 0xe frozen
Jan 31 17:36:04 ulquiorra kernel: [ 2153.336907] ata12: SError: { RecovData RecovComm UnrecovData Persist Proto HostInt PHYRdyChg PHYInt CommWake 10B8B Dispar BadCRC Handshk LinkSeq TrStaTrns UnrecFIS DevExch }
Jan 31 17:36:04 ulquiorra kernel: [ 2153.336914] ata12.00: failed command: IDENTIFY PACKET DEVICE
Jan 31 17:36:04 ulquiorra kernel: [ 2153.336923] ata12.00: cmd a1/00:01:00:00:00/00:00:00:00:00/00 tag 0 pio 512 in
Jan 31 17:36:04 ulquiorra kernel: [ 2153.336923]          res 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x56 (ATA bus error)
Jan 31 17:36:04 ulquiorra kernel: [ 2153.336931] ata12.00: status: { DRDY }
Jan 31 17:36:04 ulquiorra kernel: [ 2153.336948] ata12: hard resetting link
Jan 31 17:36:04 ulquiorra kernel: [ 2153.546404] Clocksource tsc unstable (delta = -209589539 ns)
Jan 31 17:36:04 ulquiorra kernel: [ 2153.756711] Switching to clocksource hpet

Comment 3 Reartes Guillermo 2013-02-02 15:41:39 UTC
There is some interesting information (and a workaround) there:

https://bbs.archlinux.org/viewtopic.php?id=136050
https://bbs.archlinux.org/viewtopic.php?id=135758
https://bbs.archlinux.org/viewtopic.php?pid=895404
https://bbs.archlinux.org/viewtopic.php?pid=1045415

Workaround:

Add the kernel boot parameter 'libata.atapi_passthru16=0'

I burned several media (dvd+rw, dvd-rw, dvd+r, and one bd-r)
and i did not experience any hard freezes nor any sata error.

Comment 4 Reartes Guillermo 2013-03-14 16:41:12 UTC
I can confirm that the workaround does work.

I burned a lot of media (dvd+rw, dvd-rw, dvd+r, bd-r) and i did not experience any hard freezes nor any sata error.

Comment 5 Fedora End Of Life 2013-07-03 23:35:06 UTC
This message is a reminder that Fedora 17 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 17. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '17'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 17's end of life.

Bug Reporter:  Thank you for reporting this issue and we are sorry that 
we may not be able to fix it before Fedora 17 is end of life. If you 
would still like  to see this bug fixed and are able to reproduce it 
against a later version  of Fedora, you are encouraged  change the 
'version' to a later Fedora version prior to Fedora 17's end of life.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 6 Fedora End Of Life 2013-08-01 02:24:09 UTC
Fedora 17 changed to end-of-life (EOL) status on 2013-07-30. Fedora 17 is 
no longer maintained, which means that it will not receive any further 
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of 
Fedora please feel free to reopen this bug against that version.

Thank you for reporting this bug and we are sorry it could not be fixed.

Comment 7 Reartes Guillermo 2013-09-09 19:00:55 UTC
I just started to migrate to F19 and reproduced it.

I it worse with F19, as it does not even need a disc inserted, it happens with an empty drive some seconds after booting, not long enough to even edit default/grub and running grub2-mkconfig. I had to manually type it at grub2 boot menu.

Comment 8 Josh Boyer 2013-09-18 20:55:16 UTC
*********** MASS BUG UPDATE **************

We apologize for the inconvenience.  There is a large number of bugs to go through and several of them have gone stale.  Due to this, we are doing a mass bug update across all of the Fedora 19 kernel bugs.

Fedora 19 has now been rebased to 3.11.1-200.fc19.  Please test this kernel update and let us know if you issue has been resolved or if it is still present with the newer kernel.

If you experience different issues, please open a new bug report for those.

Comment 9 Reartes Guillermo 2013-09-28 19:35:15 UTC
I re-tested it with current F19 OS.

The method i used here was to insert a disk, eject it and re-insert it.

# uname -r
3.11.1-200.fc19.x86_64

* Inserted a BD-R, it was recognized correctly.
* executed a dvd+rw-mediainfo on the optical drive.
* Ejected the BD-R (via button) and reinserted it. System got frozen.

From a remote system connected via ssh running 'journalctl -f' i got:

Sep 28 16:14:27 ulquiorra.espada kernel: ata12.00: exception Emask 0x52 SAct 0x0 SErr 0xffffffff action 0xe frozen
Sep 28 16:14:27 ulquiorra.espada kernel: ata12: SError: { RecovData RecovComm UnrecovData Persist Proto HostInt PHYRdyChg PHYInt CommWake 10B8B Dispar BadC... DevExch }
Sep 28 16:14:27 ulquiorra.espada kernel: ata12.00: failed command: IDENTIFY PACKET DEVICE
Sep 28 16:14:27 ulquiorra.espada kernel: [142B blob data]
Sep 28 16:14:27 ulquiorra.espada kernel: ata12.00: status: { DRDY }
Sep 28 16:14:27 ulquiorra.espada kernel: ata12: hard resetting link

Additional info: 

[    3.587586] ata12: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[    3.588578] ata12.00: ATAPI: ATAPI   iHBS112   2, PL06, max UDMA/100
[    3.590273] ata12.00: configured for UDMA/100
[    3.597365] scsi 11:0:0:0: CD-ROM            ATAPI    iHBS112   2      PL06 PQ: 0 ANSI: 5
[    3.600620] sr0: scsi3-mmc drive: 153x/153x writer dvd-ram cd/rw xa/form2 cdda tray
[    3.600626] cdrom: Uniform CD-ROM driver Revision: 3.20
[    3.600813] sr 11:0:0:0: Attached scsi CD-ROM sr0
[    3.600971] sr 11:0:0:0: Attached scsi generic sg6 type 5

I have updated the device firmware to PL06. 
Also please note that this is another device (same model) that i swapped with my other system. 
Both optical drives are running the latest firmware.

From the same remote system conneced via ssh running 'journalctl -f' but after applying the
'libata.atapi_passthru16=0' workaround i got:

No system freezes happened, but some ata errors were still logged.	

Sep 28 16:29:35 ulquiorra.espada udisksd[2269]: Error probing device: Error sending ATA command IDENTIFY PACKET DEVICE to /dev/sr0: Unexpected sense data returned:
Sep 28 16:29:56 ulquiorra.espada udisksd[2269]: Error probing device: Error sending ATA command IDENTIFY PACKET DEVICE to /dev/sr0: Unexpected sense data returned:
Sep 28 16:29:56 ulquiorra.espada udisksd[2269]: Error probing device: Error sending ATA command IDENTIFY PACKET DEVICE to /dev/sr0: Unexpected sense data returned:
Sep 28 16:30:01 ulquiorra.espada CROND[2803]: (root) CMD (/usr/lib64/sa/sa1 1 1)
Sep 28 16:30:13 ulquiorra.espada udisksd[2269]: Error probing device: Error sending ATA command IDENTIFY PACKET DEVICE to /dev/sr0: Unexpected sense data returned:
Sep 28 16:30:23 ulquiorra.espada udisksd[2269]: Error probing device: Error sending ATA command IDENTIFY PACKET DEVICE to /dev/sr0: Unexpected sense data returned:
Sep 28 16:30:23 ulquiorra.espada udisksd[2269]: Error probing device: Error sending ATA command IDENTIFY PACKET DEVICE to /dev/sr0: Unexpected sense data returned:
Sep 28 16:30:23 ulquiorra.espada udisksd[2269]: Error probing device: Error sending ATA command IDENTIFY PACKET DEVICE to /dev/sr0: Unexpected sense data returned:
Sep 28 16:31:12 ulquiorra.espada udisksd[2269]: Error probing device: Error sending ATA command IDENTIFY PACKET DEVICE to /dev/sr0: Unexpected sense data returned:

Comment 10 Reartes Guillermo 2013-10-01 16:33:56 UTC
Created attachment 806087 [details]
blkparse output of the optical drive attached to the asmedia controller

Ejected and inserted a blank BD-R to the optical drive:

Oct 01 13:25:53 ulquiorra.espada udisksd[2132]: Error probing device: Error sending ATA command IDENTIFY PACKET DEVICE to /dev/sr0: Unexpected sense data returned:

Note: The system was booted with 'libata.atapi_passthru16=0' boot parameter, so no freeze nor hang.

Comment 11 Justin M. Forbes 2014-01-03 22:10:22 UTC
*********** MASS BUG UPDATE **************

We apologize for the inconvenience.  There is a large number of bugs to go through and several of them have gone stale.  Due to this, we are doing a mass bug update across all of the Fedora 19 kernel bugs.

Fedora 19 has now been rebased to 3.12.6-200.fc19.  Please test this kernel update (or newer) and let us know if you issue has been resolved or if it is still present with the newer kernel.

If you have moved on to Fedora 20, and are still experiencing this issue, please change the version to Fedora 20.

If you experience different issues, please open a new bug report for those.

Comment 12 Justin M. Forbes 2014-03-10 14:43:21 UTC
*********** MASS BUG UPDATE **************

This bug has been in a needinfo state for more than 1 month and is being closed with insufficient data due to inactivity. If this is still an issue with Fedora 19, please feel free to reopen the bug and provide the additional information requested.

Comment 13 Reartes Guillermo 2014-03-10 16:53:53 UTC
This is still an issue.

Kernel: 3.13.5-103.fc19.x86_64


r 10 13:46:30 ulquiorra.espada systemd-udevd[424]: worker [1989] /devices/pci0000:00/0000:00:15.0/0000:08:00.0/ata12/host11/target11:0:0/11:0...kill it
Mar 10 13:46:30 ulquiorra.espada systemd-udevd[424]: seq 2630 '/devices/pci0000:00/0000:00:15.0/0000:08:00.0/ata12/host11/target11:0:0/11:0:0:0... killed
Mar 10 13:46:30 ulquiorra.espada systemd-udevd[424]: worker [1989] terminated by signal 9 (Killed)
Mar 10 13:46:30 ulquiorra.espada kernel: ata12.00: exception Emask 0x52 SAct 0x0 SErr 0xffffffff action 0xe frozen
Mar 10 13:46:30 ulquiorra.espada kernel: ata12: SError: { RecovData RecovComm UnrecovData Persist Proto HostInt PHYRdyChg PHYInt CommWake 10B...DevExch }
Mar 10 13:46:30 ulquiorra.espada kernel: ata12.00: failed command: IDENTIFY PACKET DEVICE
Mar 10 13:46:30 ulquiorra.espada kernel: [142B blob data]
Mar 10 13:46:30 ulquiorra.espada kernel: ata12.00: status: { DRDY }
Mar 10 13:46:30 ulquiorra.espada kernel: ata12: hard resetting link
Mar 10 13:46:30 ulquiorra.espada kernel: Clocksource tsc unstable (delta = -209654687 ns)
Mar 10 13:46:31 ulquiorra.espada kernel: Switched to clocksource hpet

The workaround is still the same: Use 'libata.atapi_passthru16=0' kernel boot parameter.

Re-opening.

Comment 14 Justin M. Forbes 2014-05-21 19:29:54 UTC
*********** MASS BUG UPDATE **************

We apologize for the inconvenience.  There is a large number of bugs to go through and several of them have gone stale.  Due to this, we are doing a mass bug update across all of the Fedora 19 kernel bugs.

Fedora 19 has now been rebased to 3.14.4-100.fc19.  Please test this kernel update (or newer) and let us know if you issue has been resolved or if it is still present with the newer kernel.

If you have moved on to Fedora 20, and are still experiencing this issue, please change the version to Fedora 20.

If you experience different issues, please open a new bug report for those.

Comment 15 Justin M. Forbes 2014-06-23 14:40:31 UTC
*********** MASS BUG UPDATE **************
This bug is being closed with INSUFFICIENT_DATA as there has not been a response in 4 weeks. If you are still experiencing this issue, please reopen and attach the relevant data from the latest kernel you are running and any data that might have been requested previously.

Comment 16 Reartes Guillermo 2014-12-13 23:19:46 UTC
It does still happen with F21.

I installed F21 KDE Spin, on the first boot the system froze at the ssdm screen.
I later confirmed that it does still happen. I used the same workaround.

Comment 17 Justin M. Forbes 2015-01-27 15:01:40 UTC
*********** MASS BUG UPDATE **************

We apologize for the inconvenience.  There are a large number of bugs to go through and several of them have gone stale.  Due to this, we are doing a mass bug update across all of the Fedora 21 kernel bugs.

Fedora 21 has now been rebased to 3.18.3-201.fc21.  Please test this kernel update (or newer) and let us know if you issue has been resolved or if it is still present with the newer kernel.

If you experience different issues, please open a new bug report for those.

Comment 18 Fedora Kernel Team 2015-02-24 16:14:24 UTC
*********** MASS BUG UPDATE **************
This bug is being closed with INSUFFICIENT_DATA as there has not been a response in over 3 weeks. If you are still experiencing this issue, please reopen and attach the relevant data from the latest kernel you are running and any data that might have been requested previously.

Comment 19 Mark Johnson 2015-04-12 23:56:31 UTC
Still broke on 3.19.3-200.fc21.

It's not just the ASM1061, I've got an ASM1062 that is not a happy camper with an LG BD Rewriter connected:

# lspci -nn
08:00.0 SATA controller [0106]: ASMedia Technology Inc. ASM1062 Serial ATA Controller [1b21:0612] (rev 02)

Hangs at boot, similar to this situation (failed IDENTIFY PACKET DEVICE):

http://askubuntu.com/questions/230396/can-i-prevent-an-identify-packet-device-command-to-a-specific-device-at-boot

Comment 20 Mark Johnson 2015-04-13 00:41:21 UTC
The installer hung.  I unplugged the optical drive and installed.  Updated the kernel to 3.19.3-200.fc21.  Plugged the drive back in, boot hangs.


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