Project

General

Profile

Bug #2998

AHCI reports many "Illegal Request" with Intel C602 chipset

Added by Bob Friesenhahn over 8 years ago. Updated almost 8 years ago.

Status:
Feedback
Priority:
Normal
Assignee:
-
Category:
driver - device drivers
Start date:
2012-07-14
Due date:
% Done:

0%

Estimated time:
Difficulty:
Medium
Tags:
needs-triage
Gerrit CR:

Description

Observed with both OpenIndiana oi_151a4 and oi_151a5:

With two SATA disks from different vendors attached to 6 GB/s SATA links served by the Intel C602 chipset (SuperMicro X9DAi motherboard), many "Illegal Request" errors are tallied against each drive, but without incrementing "Soft Errors" or any other error count. An analysis of SCSI protocol transactions using scsi.d does not seem to reveal "Illegal Request" errors on the bus or any other error. I assume that there must be some issue inside the ahci driver. Substantial benchmarking does not show any unusual I/O behavior to the disks and there is no noticeable performance issue with the system.

The system did stop being able to talk to the first disk a few days ago ("I/O error") and was successfully replaced with a different model and manufacturer drive. The hardware supplier tested the returned disk and did not find a problem with it.


# cfgadm|grep sata
sata0/0::dsk/c3t0d0            disk         connected    configured   ok
sata0/1::dsk/c3t1d0            disk         connected    configured   ok
sata0/2::dsk/c3t2d0            cd/dvd       connected    configured   ok

# kstat -n sd1,err
module: sderr                           instance: 1
name:   sd1,err                         class:    device_error
        Device Not Ready                0
        Hard Errors                     0
        Illegal Request                 579
        Media Error                     0
        No Device                       0
        Predictive Failure Analysis     0
        Product                         ST1000NM0011    Revision
        Recoverable                     0
        Revision                        SN02
        Serial No                       Z1N21SQN
        Size                            1000204886016
        Soft Errors                     0
        Transport Errors                0
        Vendor                          ATA
        crtime                          4743.15789647
        snaptime                        144971.680727518

# kstat -n sd2,err
module: sderr                           instance: 2
name:   sd2,err                         class:    device_error
        Device Not Ready                0
        Hard Errors                     0
        Illegal Request                 594
        Media Error                     0
        No Device                       0
        Predictive Failure Analysis     0
        Product                         WDC WD5003ABYX-0Revision
        Recoverable                     0
        Revision                        1S02
        Serial No                       WD-WMAYP3661514
        Size                            500107862016
        Soft Errors                     0
        Transport Errors                0
        Vendor                          ATA
        crtime                          4743.21090549
        snaptime                        144974.148133619

#1

Updated by Bob Friesenhahn over 8 years ago

I am now seeing errors reported by scsi.d and one of the drives is incrementing the illegal request counter with a rate of about 12 per minute. The counts were incrementing before without these reports from scsi.d.

00492.393775171 ahci0:-> 0x00 TEST_UNIT_READY address 01:00, lba 0x000000, len 0x000000, control 0x00 timeout 60 CDBP ffffff22a8faf950 1 zpool(25986) cdb(6) 000000000000
00492.394206426 ahci0:-> 0x00 TEST_UNIT_READY address 01:00, lba 0x000000, len 0x000000, control 0x00 timeout 60 CDBP ffffff241a97c8d0 1 zpool(25986) cdb(6) 000000000000
00492.394551402 ahci0:-> 0x1a MODE_SENSE(6) address 01:00, lba 0x000300, len 0x000024, control 0x00 timeout 60 CDBP ffffff2965543650 1 zpool(25986) cdb(6) 1a0003002400
00492.394851927 ahci0:-> 0x08   READ(6) address 01:00, lba 0x000000, len 0x000001, control 0x00 timeout 60 CDBP ffffff23e2270bd0 1 zpool(25986) cdb(6) 080000000100
00492.395115770 ahci0:-> 0x08   READ(6) address 01:00, lba 0x000000, len 0x000001, control 0x00 timeout 60 CDBP ffffff2242020bd0 1 zpool(25986) cdb(6) 080000000100
00492.395377117 ahci0:-> 0x08   READ(6) address 01:00, lba 0x003ec2, len 0x000001, control 0x00 timeout 60 CDBP ffffff22a3f7c450 1 zpool(25986) cdb(6) 08003ec20100
00492.391249950 ahci0:<- 0x00 TEST_UNIT_READY address 01:00, lba 0x000000, len 0x000000, control 0x00 timeout 60 CDBP ffffff2224a01310, reason 0x0 (COMPLETED) pkt_state 0x17 state 0x0 Success Time 451us
00492.391694829 ahci0:<- 0x00 TEST_UNIT_READY address 01:00, lba 0x000000, len 0x000000, control 0x00 timeout 60 CDBP ffffff22a26d0150, reason 0x0 (COMPLETED) pkt_state 0x17 state 0x0 Success Time 321us
00492.394048858 ahci0:<- 0x00 TEST_UNIT_READY address 01:00, lba 0x000000, len 0x000000, control 0x00 timeout 60 CDBP ffffff22a8faf950, reason 0x0 (COMPLETED) pkt_state 0x17 state 0x0 Success Time 324us
00492.394449965 ahci0:<- 0x00 TEST_UNIT_READY address 01:00, lba 0x000000, len 0x000000, control 0x00 timeout 60 CDBP ffffff241a97c8d0, reason 0x0 (COMPLETED) pkt_state 0x17 state 0x0 Success Time 294us
00492.394685258 ahci0:ILL 0x1a MODE_SENSE(6) address 01:00, lba 0x000300, len 0x000024, control 0x00 timeout 60 CDBP ffffff2965543650 1 sched(0) cdb(6) 1a0003002400
00492.394763416 ahci0:<- 0x1a MODE_SENSE(6) address 01:00, lba 0x000300, len 0x000024, control 0x00 timeout 60 CDBP ffffff2965543650, reason 0x0 (COMPLETED) pkt_state 0x37 state 0x2 Check_Condition Time 258us
00492.392047411 ahci0:ILL 0x1a MODE_SENSE(6) address 01:00, lba 0x000300, len 0x000024, control 0x00 timeout 60 CDBP ffffff22a65e7310 1 sched(0) cdb(6) 1a0003002400
00492.392187885 ahci0:<- 0x1a MODE_SENSE(6) address 01:00, lba 0x000300, len 0x000024, control 0x00 timeout 60 CDBP ffffff22a65e7310, reason 0x0 (COMPLETED) pkt_state 0x37 state 0x2 Check_Condition Time 367us
#2

Updated by Bob Friesenhahn over 8 years ago

The system is still up and zfs pool is still working ok. No soft/hard/transport errors have been reported. The behavior with the second drive (12 illegal request counts per minute) still persists while the count increment has stopped entirely on the first drive:

sd1       Soft Errors: 0 Hard Errors: 0 Transport Errors: 0
Vendor: ATA      Product: ST1000NM0011     Revision: SN02 Serial No: Z1N21SQN
Size: 1000.20GB <1000204886016 bytes>
Media Error: 0 Device Not Ready: 0 No Device: 0 Recoverable: 0
Illegal Request: 637 Predictive Failure Analysis: 0
sd2       Soft Errors: 0 Hard Errors: 0 Transport Errors: 0
Vendor: ATA      Product: WDC WD5003ABYX-0 Revision: 1S02 Serial No: WD-WMAYP3661514
Size: 500.11GB <500107862016 bytes>
Media Error: 0 Device Not Ready: 0 No Device: 0 Recoverable: 0
Illegal Request: 137353 Predictive Failure Analysis: 0

Richard Elling tells me that he has a system which is exhibiting a similar problem.

#3

Updated by Bob Friesenhahn over 8 years ago

Another status update to observed behavior since behavior has changed again. As of sometime yesterday, the illegal request count on sd2 stopped incrementing. It had been incrementing at 12 counts per minute. Now neither drive is actively counting illegal request errors.

% uptime
 08:09am  up 18 days  9:14,  10 users,  load average: 0.05, 0.05, 0.05

sd1       Soft Errors: 0 Hard Errors: 0 Transport Errors: 0
Vendor: ATA      Product: ST1000NM0011     Revision: SN02 Serial No: Z1N21SQN
Size: 1000.20GB <1000204886016 bytes>
Media Error: 0 Device Not Ready: 0 No Device: 0 Recoverable: 0
Illegal Request: 637 Predictive Failure Analysis: 0
sd2       Soft Errors: 0 Hard Errors: 0 Transport Errors: 0
Vendor: ATA      Product: WDC WD5003ABYX-0 Revision: 1S02 Serial No: WD-WMAYP3661514
Size: 500.11GB <500107862016 bytes>
Media Error: 0 Device Not Ready: 0 No Device: 0 Recoverable: 0
Illegal Request: 200849 Predictive Failure Analysis: 0
#4

Updated by Bob Friesenhahn about 8 years ago

As of a about a week ago, the system is no longer producing large numbers of illegal request errors. The two SATA drives have produced only 3 and 4 illegal requests, respectively, in two days of uptime. Perhaps the improvement is due to OpenIndiana updates.

#5

Updated by Bob Friesenhahn almost 8 years ago

With OpenIndiana oi_151a7 I am only seeing a tiny number of illegal requests (<= 10) so I am closing this report.

#6

Updated by Bob Friesenhahn almost 8 years ago

  • Status changed from New to In Progress
  • Assignee set to Bob Friesenhahn
#7

Updated by Bob Friesenhahn almost 8 years ago

  • Status changed from In Progress to Feedback
  • Assignee deleted (Bob Friesenhahn)

Also available in: Atom PDF