Bug 684599

Summary: failed command: IDENTIFY PACKET DEVICE
Product: [Fedora] Fedora Reporter: rick <rick.hendricksen>
Component: kernelAssignee: Kernel Maintainer List <kernel-maint>
Status: CLOSED WONTFIX QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 16CC: antoine, davidz, fedora, gansalmon, harald, itamar, jgarzik, john.mora, jonathan, kernel-maint, madhu.chinakonda, md
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-02-13 15:33:35 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
Hardware information none

Description rick 2011-03-13 18:40:26 UTC
Description of problem:
Boot pauses for a while, after which the following error is shown:
[   71.776103] ata2.00: failed command: IDENTIFY PACKET DEVICE

From dmesg:
[code]
[   71.776063] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[   71.776103] ata2.00: failed command: IDENTIFY PACKET DEVICE
[   71.776132] ata2.00: cmd a1/00:01:00:00:00/00:00:00:00:00/00 tag 0 pio 512 in
[   71.776133]          res 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
[   71.776201] ata2.00: status: { DRDY }
[   71.776222] ata2: hard resetting link
[   72.236064] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[   73.038369] ata2.00: configured for PIO4
[   73.838986] ata2: EH complete
[/code]

Version-Release number of selected component (if applicable):
$ uname -a
Linux rickPC 2.6.38-0.rc8.git0.1.fc15.x86_64 #1 SMP Tue Mar 8 08:22:15 UTC 2011 x86_64 x86_64 x86_64 GNU/Linux

$ udevd --version
166

How reproducible:
Always

Steps to Reproduce:
1. Boot
2. dmesg
  
Actual results:
Boot pauses for a while, with error

Expected results:
Boot continues normally

Additional info:
At the archlinux forums they have a topic about this (and a workaround).
https://bbs.archlinux.org/viewtopic.php?pid=894147

Comment 1 Harald Hoyer 2011-03-14 13:44:08 UTC
David, any idea about this?

Comment 2 David Zeuthen 2011-03-15 14:58:45 UTC
(In reply to comment #1)
> David, any idea about this?

Yes, it's most probably caused by this commit

 http://git.kernel.org/?p=linux/hotplug/udev.git;a=commitdiff;h=560de575148b7efda3b34a7f7073abd483c5f08e

Looks to me like a hardware problem, not sure how to best work around it... let's start with investigate and get more details from the reporter...

Reporter: what kind of hardware do you see this problem with?

Comment 3 rick 2011-03-15 15:51:08 UTC
Created attachment 485532 [details]
Hardware information

Comment 4 David Zeuthen 2011-03-15 16:32:36 UTC
(In reply to comment #3)
> Created attachment 485532 [details]
> Hardware information

OK, so it's a TSSTcorp CDDVDW SH-S223C	. Looks like a run of the mill

Btw, please stick to textual information in the future - it's much easier to deal with that way!

Please try running

 /lib/udev/ata_id /dev/sr0

as root and paste the result here. Thanks!

Comment 5 David Zeuthen 2011-03-15 16:35:35 UTC
(In reply to comment #4)
> (In reply to comment #3)
> > Created attachment 485532 [details]
> > Hardware information
> 
> OK, so it's a TSSTcorp CDDVDW SH-S223C . Looks like a run of the mill
> 
> Btw, please stick to textual information in the future - it's much easier to
> deal with that way!
> 
> Please try running
> 
>  /lib/udev/ata_id /dev/sr0
> 
> as root and paste the result here. Thanks!

Sorry, I forgot the --export option. Please run

 /lib/udev/ata_id --export /dev/sr0

as root and paste the result. Thanks!

Comment 6 rick 2011-03-15 17:16:35 UTC
[root@rickPC ~]# time /lib/udev/ata_id --export /dev/sr0 
ID_ATA=1
ID_TYPE=cd
ID_BUS=ata
ID_MODEL=TSSTcorp_CDDVDW_SH
ID_MODEL_ENC=TSSTcorp\x20CDDVDW\x20SH
ID_REVISION=SB05
ID_SERIAL=TSSTcorp_CDDVDW_SH_R4136GHZC20180
ID_SERIAL_SHORT=R4136GHZC20180

real    0m32.848s
user    0m0.000s
sys     0m0.003s

Comment 7 David Zeuthen 2011-03-15 19:20:06 UTC
(In reply to comment #6)
> [root@rickPC ~]# time /lib/udev/ata_id --export /dev/sr0 
> ID_ATA=1
> ID_TYPE=cd
> ID_BUS=ata
> ID_MODEL=TSSTcorp_CDDVDW_SH
> ID_MODEL_ENC=TSSTcorp\x20CDDVDW\x20SH
> ID_REVISION=SB05
> ID_SERIAL=TSSTcorp_CDDVDW_SH_R4136GHZC20180
> ID_SERIAL_SHORT=R4136GHZC20180
> 
> real    0m32.848s
> user    0m0.000s
> sys     0m0.003s

Interesting. So we basically get the information we request, it just takes a lot of time. What is logged to dmesg while doing this?

(Hmm, we really need better debugging infrastructure in ata_id - I'll try to write a patch for that.)

Comment 8 rick 2011-03-15 19:34:12 UTC
From /var/log/messages, same info in dmesg but without timestamps.

Mar 15 20:32:00 rickPC kernel: [12878.752119] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
Mar 15 20:32:00 rickPC kernel: [12878.752133] ata2.00: failed command: IDENTIFY PACKET DEVICE
Mar 15 20:32:00 rickPC kernel: [12878.752150] ata2.00: cmd a1/00:01:00:00:00/00:00:00:00:00/00 tag 0 pio 512 in
Mar 15 20:32:00 rickPC kernel: [12878.752154]          res 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
Mar 15 20:32:00 rickPC kernel: [12878.752163] ata2.00: status: { DRDY }
Mar 15 20:32:00 rickPC kernel: [12878.752176] ata2: hard resetting link
Mar 15 20:32:00 rickPC kernel: [12879.212095] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
Mar 15 20:32:01 rickPC kernel: [12880.015050] ata2.00: configured for PIO4
Mar 15 20:32:02 rickPC kernel: [12880.815639] ata2: EH complete

Comment 9 David Zeuthen 2011-03-15 20:51:12 UTC
Jeff (or other kernel hackers with ATA expereince) : any idea what is going on here? Thanks

Comment 10 Chuck Ebbert 2011-03-17 06:29:25 UTC
I found this thread:
https://bbs.archlinux.org/viewtopic.php?pid=895404

which says that some devices may not support 16-byte ATA commands. For our kernel, you would disable them by adding "libata.atapi_passthru16=0" to the kernel boot options, though this is just a workaround.

Comment 11 Fedora Admin XMLRPC Client 2011-10-20 16:08:29 UTC
This package has changed ownership in the Fedora Package Database.  Reassigning to the new owner of this component.

Comment 12 Fedora Admin XMLRPC Client 2011-10-20 16:10:40 UTC
This package has changed ownership in the Fedora Package Database.  Reassigning to the new owner of this component.

Comment 13 Fedora Admin XMLRPC Client 2011-10-20 16:12:52 UTC
This package has changed ownership in the Fedora Package Database.  Reassigning to the new owner of this component.

Comment 14 Fedora Admin XMLRPC Client 2011-10-20 16:17:18 UTC
This package has changed ownership in the Fedora Package Database.  Reassigning to the new owner of this component.

Comment 15 Jeff Garzik 2012-07-19 01:38:17 UTC
Reassigning to kernel pkg, as this appears to be a kernel problem.

TSSTcorp devices have special workarounds in the kernel.  In ata_device_blacklist[] we see

        /* Maybe we should just blacklist TSSTcorp... */
        { "TSSTcorp CDDVDW SH-S202[HJN]", "SB0[01]",  ATA_HORKAGE_IVB, },

It is worth attempting to emulate what the above workaround attempts to accomplish with ATA_HORKAGE_IVB, which is to force the cable type.

Kernel module "libata" accepts the "force" module parameter.

Try setting libata.force=40c to force a 40c cable type.

Comment 16 Dave Jones 2012-10-23 15:31:33 UTC
# Mass update to all open bugs.

Kernel 3.6.2-1.fc16 has just been pushed to updates.
This update is a significant rebase from the previous version.

Please retest with this kernel, and let us know if your problem has been fixed.

In the event that you have upgraded to a newer release and the bug you reported
is still present, please change the version field to the newest release you have
encountered the issue with.  Before doing so, please ensure you are testing the
latest kernel update in that release and attach any new and relevant information
you may have gathered.

If you are not the original bug reporter and you still experience this bug,
please file a new report, as it is possible that you may be seeing a
different problem. 
(Please don't clone this bug, a fresh bug referencing this bug in the comment is sufficient).

Comment 17 rick 2012-10-23 16:26:38 UTC
Problem persists.

[root@xuplin rick]# uname -a
Linux xuplin 3.6.2-1-ARCH #1 SMP PREEMPT Fri Oct 12 23:58:58 CEST 2012 x86_64 GNU/Linux

[root@xuplin rick]# udevd --version
194

[root@xuplin rick]# time /lib/udev/ata_id --export /dev/sr0 
ID_ATA=1
ID_TYPE=cd
ID_BUS=ata
ID_MODEL=TSSTcorp_CDDVDW_SH____________________qQ
ID_MODEL_ENC=TSSTcorp\x20CDDVDW\x20SH\x21\x08\x3e\x04\x27\x3e\x3e\x98\x21\x08\x3e\x84\x27\x3e\x3e\x98\x21\x08\x3e\x84qQ
ID_REVISION=SB05
ID_SERIAL=TSSTcorp_CDDVDW_SH____________________qQ_R4136GHZC20180
ID_SERIAL_SHORT=R4136GHZC20180

real    0m33.045s
user    0m0.000s
sys     0m0.000s

Comment 18 Antoine Martin 2012-11-14 12:30:32 UTC
$ time /lib/udev/ata_id --export /dev/sr0 
ID_ATA=1
ID_TYPE=cd
ID_BUS=ata
ID_MODEL=TSSTcorp_CDDVDW_SHA___4_
ID_MODEL_ENC=TSSTcorp\x20CDDVDW\x20SHA\x29\xfd\x604\x19
ID_REVISION=SB04
ID_SERIAL=TSSTcorp_CDDVDW_SHA___4__R78U6GEZ707218
ID_SERIAL_SHORT=R78U6GEZ707218
ID_ATA_WRITE_CACHE=1
ID_ATA_WRITE_CACHE_ENABLED=1
ID_ATA_FEATURE_SET_HPA=1
ID_ATA_FEATURE_SET_HPA_ENABLED=1
ID_ATA_FEATURE_SET_PM=1
ID_ATA_FEATURE_SET_PM_ENABLED=0
ID_ATA_FEATURE_SET_SMART=1
ID_ATA_FEATURE_SET_SMART_ENABLED=0
ID_ATA_SATA=1
0.00user 0.00system 0:32.78elapsed 0%CPU (0avgtext+0avgdata 692maxresident)k
56inputs+0outputs (1major+210minor)pagefaults 0swaps

$ uname -a
Linux desktop 3.6.6-1.fc17.x86_64 #1 SMP Mon Nov 5 21:59:35 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux

$ /usr/lib/udev/udevd --version
182

Comment 19 Miro Halas 2012-11-18 05:16:22 UTC
Hello,

I was able to solve this issue on my configuration so I hope this will help somebody. Recently I have migrated my CentOS 6.3 server from Intel based  motherboard Gigabyte GA-P55-UD3L (rev. 1.0) to AMD based motherboard MSI 790FX-GD70. The only change in the system was the motherboard, cpu and memory, the rest of the configuration stayed the same. Immediately after migration I have started experiencing this exact issue

During boot I was getting errors

Nov 17 23:41:12 storage kernel: ata6.00: qc timeout (cmd 0xec)
Nov 17 23:41:12 storage kernel: ata6.00: failed to IDENTIFY (I/O error, err_mask=0x5)
Nov 17 23:41:12 storage kernel: ata6.00: revalidation failed (errno=-5)
Nov 17 23:41:12 storage kernel: ata6: hard resetting link
Nov 17 23:41:13 storage kernel: ata6: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Nov 17 23:41:13 storage kernel: ata6.00: configured for UDMA/133
Nov 17 23:41:13 storage kernel: sd 5:0:0:0: [sdb] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Nov 17 23:41:13 storage kernel: sd 5:0:0:0: [sdb] Sense Key : Aborted Command [current] [descriptor]
Nov 17 23:41:13 storage kernel: Descriptor sense data with sense descriptors (in hex):
Nov 17 23:41:13 storage kernel:        72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00 
Nov 17 23:41:13 storage kernel:        91 40 16 4e 
Nov 17 23:41:13 storage kernel: sd 5:0:0:0: [sdb] Add. Sense: No additional sense information
Nov 17 23:41:13 storage kernel: sd 5:0:0:0: [sdb] CDB: Read(10): 28 00 91 40 1b 4f 00 00 c0 00
Nov 17 23:41:13 storage kernel: ata6: EH complete
N

After boot this error transformed to

Nov 17 21:05:26 storage kernel: ata6.00: qc timeout (cmd 0xec)
Nov 17 21:05:26 storage kernel: ata6.00: failed to IDENTIFY (I/O error, err_mask=0x4)
Nov 17 21:05:26 storage kernel: ata6.00: revalidation failed (errno=-5)
Nov 17 21:05:26 storage kernel: ata6: hard resetting link
Nov 17 21:05:27 storage kernel: ata6: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
Nov 17 21:05:27 storage kernel: ata6.00: configured for UDMA/33
Nov 17 21:05:27 storage kernel: ata6: EH complete
Nov 17 21:06:26 storage kernel: ata6.00: exception Emask 0x50 SAct 0x1 SErr 0x280900 action 0x6 frozen
Nov 17 21:06:26 storage kernel: ata6.00: irq_stat 0x08000000, interface fatal error
Nov 17 21:06:26 storage kernel: ata6: SError: { UnrecovData HostInt 10B8B BadCRC }
Nov 17 21:06:26 storage kernel: ata6.00: failed command: READ FPDMA QUEUED
Nov 17 21:06:26 storage kernel: ata6.00: cmd 60/30:00:3f:9b:cc/00:00:8e:00:00/40 tag 0 ncq 24576 in
Nov 17 21:06:26 storage kernel:         res 40/00:00:3f:9b:cc/00:00:8e:00:00/40 Emask 0x50 (ATA bus error)
Nov 17 21:06:26 storage kernel: ata6.00: status: { DRDY }
Nov 17 21:06:26 storage kernel: ata6: hard resetting link
Nov 17 21:06:31 storage kernel: ata6: SATA link up 1.5 Gbps (SStatus 113 SControl 310)

In case it matters, these are the disks used in the system
Nov 17 23:53:58 storage kernel: ata6.00: ATA-8: ST31500341AS, SD1B, max UDMA/133
Nov 17 23:53:58 storage kernel: ata5.00: ATA-8: WDC WD20EADS-00S2B0, 01.00A01, max UDMA/133
Nov 17 23:53:58 storage kernel: ata7.00: ATA-6: ST380011A, 3.16, max UDMA/100
Nov 17 23:53:58 storage kernel: ata7.01: ATA-6: ST380011A, 3.16, max UDMA/100


I was able to completely eliminate this issue by
1. disabling NCQ
2. limiting the speed of SATA to 1.5GB

I have done so by modifying my /boot/grub/grub.conf and adding

 libata.force=noncq,1.5G

at the end of my kernel line. This bug also seems to be related or is duplicate of Bug 549981.

Comment 20 Fedora End Of Life 2013-01-16 14:29:57 UTC
This message is a reminder that Fedora 16 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 16. 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 '16'.

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 16'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 16 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 to click on 
"Clone This Bug" and open it against that version of Fedora.

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.

The process we are following is described here: 
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Comment 21 Antoine Martin 2013-01-16 16:18:11 UTC
FWIW: I've moved this cdrom device to another SATA port on the motherboard so that I could then change the configuration in the BIOS for this port to not use AHCI and the problem has gone.

Comment 22 Fedora End Of Life 2013-02-13 15:33:38 UTC
Fedora 16 changed to end-of-life (EOL) status on 2013-02-12. Fedora 16 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.