Re: Re: [PATCH] ahci: libahci: clear pending interrupt status

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



On 8/22/23 16:41, Niklas Cassel wrote: 
>
>On Mon, Aug 14, 2023 at 12:17:20PM +0800, Szuying Chen wrote:
>> On 8/10/23 17:59, Damien Le Moal wrote: 
>> >On 8/10/23 18:31, Szuying Chen wrote:
>> >>> On 8/10/23 14:12, Damien Le Moal wrote: 
>> >>>    On 8/10/23 14:05, Szuying Chen wrote:
>> >>>    > When ISR handle interface fatal error with error recovery after clear PxIS
>> >>>    > and PxIE. Another FIS(SDB FIS with err) that set PxIS.IFS to 1 is recevied
>> >>>    > during error recovery, which causing the HBA not issue any new commands
>> >>>    > after cmd.ST set 1.
>> >>>
>> >>>    This is not very clear. If there was a fatal error, the drive should be in
>> >>>    error state and no other SDB FIS can be received as the drive does absolutely
>> >>>    nothing while in error state (it only waits for a read log 10h command to be>
>> >>>    issued to get it out of error state). So if you are seeing 2 SDB FIS with
>> >>>    errors one after the other, you have a buggy device...
>> >>>
>> >>>    However, I may be misunderstanding your issue here. Could you provide more
>> >>>    details and a dmesg output example of the issue ?
>> >> 
>> >> According to AHCI 1.3.1 specification ch6.1.9, when an R_ERR is 
>> >> received on an H2D Data FIS in normal operation, the HBA sets 
>> >> PxIS.IFS to 1 (fatal error) and halts operation. Referring to SATA 
>> >> 3.0 specification we know the device will halt queued command 
>> >> processing and transmit SDB FIS to host with ERR bit in Status field set to one(set PxIS.TFES to 1).
>> >
>> >Sure, but that SBD FIS should be completely ignored by the adapter 
>> >since it stopped operation. If you see it, then it means that the 
>> >handling of the first error was incomplete.
>> >
>> The SDB FIS  happens between pxIS.IE was cleared and PxCMD.ST not 
>> cleared to 0. Because the PxCMD.ST still setting, so the SDB FIS can't ignored.
>> 
>> >> In our case, the ISR handles fatal errors(PxIS.IFS) and enters 
>> >> error recovery after cleaning up PxIS and PxIE. Then a SDB FIS is 
>> >> received with interrupt bit(PxIS.TFES) set to 1. According to AHCI 
>> >> 1.3.1 specification ch6.2.2, HBA can't issue(cmd.ST set to 1) any 
>> >> new commands under PxIS.TFES alive during error recovery.
>> >
>> >But how come you see a new command being issued ? This entire 
>> >situation should result in a port reset with the first error. I do not see how this is possible.
>> >Are you saying that the port reset is not cleaning things up properly 
>> >? Could you share the dmesg output of this case ?
>> >
>> >
>> dmesg:
>> [  654.244958] nouveau 0000:09:00.0: AMD-Vi: Event logged 
>> [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  654.460522] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  656.180375] ata7.00: 
>> exception Emask 0x10 SAct 0x7c0 SErr 0x200100
>
>Hello Szuying Chen,
>
>From your logs we can see that SErr 0x200100:
>This means that PxSERR.DIAG.C was set.
>
>This means that:
>"Calculated Different CRC than Received: When this occurs, the HBA returns R_ERR and returns to idle."
>
>(Since PxIS.IFS is set, we know that it was a D2H Data FIS that had invalid CRC. (If it was a D2H non-Data FIS PxIS.INFS would have been set instead.))
>
>
>So your commit message is wrong. In your case it is the HBA that sends a R_ERR to the device, so you should look at "6.1.10 CRC error in received FIS" and not "6.1.9 Device responds to FIS with R_ERR".
>
>"When a CRC error occurs on a D2H Data FIS, the HBA sets PxIS.IFS to ‘1’.
>After a CRC error on a D2H Data FIS, the device may send a D2H Register FIS to indicate the reason for the error. The host should allow posting of non-Data FISes before PxCMD.ST is cleared to ‘0’."
>
>Looking at the state machine "5.3.11.2 DR:Receive" you will jump to state ERR:Fatal. (Meaning that we need to clear PxCMD.ST in order to issue new
>commands.)
>
>
>The HBA should this trigger an error irq when noticing the bad CRC.
>
>It is possible that the HBA triggers another error IRQ when receiving a D2H with TFES bit set, if it is received before PxCMD.ST is cleared to 0, see NDR:Accept:
>FIS Type is D2H Register and PxCMD.ST=0, jump to P:RegFISUpdate, which does not trigger any IRQ.
>If PxCMD.ST is set, the state machine will instead jump to RegFIS:Entry.
>
>
>So, in order to understand what is going on, can you please add unconditional prints in ahci_error_intr(), so we can actually see how many times this is called. (Right now it seems to only be called once). Please also print when PxCMD.ST is cleared to 0.
>(So that we can verify that ahci_error_intr() is never called after that). Also please remove all prints from other drivers, e.g. nouveau.
>
>
>Kind regards,
>Niklas
>
>
Hi Niklas,

In our case, receiving D2H with TFES bit set(PxIS.TFES set to 1) doesn't
triggers aother error IRQ before PxCMD.ST is cleared. Because IRQ was 
turn off(PxIE=0).

After received D2H with TFES bit set, port is restart(clearing PxCMD.ST to 
'0' and then setting PxCMD.ST to '1').In the dmesg output, device is lose 
after the port restart 3 times. Durring this time, the TFES bit was not 
cleared.

The Linux kernel dmesg output as shown below:
 [   40.251795] ahci_error_intr start (irq_stat 0x08000000) ****
[   40.251799] ahci_error_intr: interface fatal error
[   40.251800] ahci_error_intr: freeze (set pxIE to 0)
[   40.251805] ahci_error_intr end (PORT_IRQ_MASK = 0x00000000 )****
[   40.298113] ata8.00: exception Emask 0x10 SAct 0x70e000 SErr 0x280100 
action 0x6 frozen
[   40.298117] ata8.00: irq_stat 0x08000000, interface fatal error
[   40.298119] ata8: SError: { UnrecovData 10B8B BadCRC }
[   40.298121] ata8.00: failed command: READ FPDMA QUEUED
[   40.298122] ata8.00: cmd 60/b8:68:c0:c3:03/08:00:00:00:00/40 tag 13 
ncq dma 1142784 in
         res 40/00:ff:00:00:00/00:00:00:00:00/00 Emask 0x10 (ATA bus error)
[   40.298126] ata8.00: status: { DRDY }
[   40.298128] ata8.00: failed command: READ FPDMA QUEUED
[   40.298129] ata8.00: cmd 60/b8:70:78:cc:03/05:00:00:00:00/40 tag 14 
ncq dma 749568 in
         res 40/00:ff:00:00:00/00:00:00:00:00/00 Emask 0x10 (ATA bus error)
[   40.298132] ata8.00: status: { DRDY }
[   40.298133] ata8.00: failed command: READ FPDMA QUEUED
[   40.298134] ata8.00: cmd 60/00:78:30:d2:03/0a:00:00:00:00/40 tag 15 
ncq dma 1310720 in
         res 40/00:ff:00:00:00/00:00:00:00:00/00 Emask 0x10 (ATA bus error)
[   40.298137] ata8.00: status: { DRDY }
[   40.298138] ata8.00: failed command: READ FPDMA QUEUED
[   40.298139] ata8.00: cmd 60/00:a0:30:dc:03/0a:00:00:00:00/40 tag 20 
ncq dma 1310720 in
         res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x10 (ATA bus error)
[   40.298142] ata8.00: status: { DRDY }
[   40.298143] ata8.00: failed command: READ FPDMA QUEUED
[   40.298144] ata8.00: cmd 60/40:a8:30:e6:03/08:00:00:00:00/40 tag 21 
ncq dma 1081344 in
         res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x10 (ATA bus error)
[   40.298147] ata8.00: status: { DRDY }
[   40.298148] ata8.00: failed command: READ FPDMA QUEUED
[   40.298149] ata8.00: cmd 60/90:b0:70:ee:03/09:00:00:00:00/40 tag 22 
ncq dma 1253376 in
         res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x10 (ATA bus error)
[   40.298151] ata8.00: status: { DRDY }
[   40.298154] ata8: hard resetting link
[   40.298155] ata8: ahci_hardreset *****
[   40.298160] ahci 0000:6f:00.0: ahci_stop_engine start *** 
( PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004d517) 
[   40.298166] ahci 0000:6f:00.0: ahci_stop_engine: setting HBA to idle  
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) 
[   40.298167] ahci 0000:6f:00.0: ahci_stop_engine end *** 
[   40.608009] ahci 0000:6f:00.0: ahci_start_engine start 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) ***
[   40.608031] ahci 0000:6f:00.0: ahci_start_engine end 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) ***
[   40.608041] ata8: ahci_softreset *****
[   40.608049] ahci 0000:6f:00.0: ahci_stop_engine start *** 
( PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) 
[   40.608059] ahci 0000:6f:00.0: ahci_stop_engine: setting HBA to idle  
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) 
[   40.608064] ahci 0000:6f:00.0: ahci_stop_engine end *** 
[   40.608069] ahci 0000:6f:00.0: ahci_start_engine start 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) ***
[   40.608079] ahci 0000:6f:00.0: ahci_start_engine end 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) ***
[   50.199215] ahci 0000:6f:00.0: ahci_stop_engine start *** 
( PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) 
[   50.199236] ahci 0000:6f:00.0: ahci_stop_engine: setting HBA to idle  
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) 
[   50.199242] ahci 0000:6f:00.0: ahci_stop_engine end *** 
[   50.199254] ahci 0000:6f:00.0: ahci_start_engine start 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) ***
[   50.199264] ahci 0000:6f:00.0: ahci_start_engine end 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) ***
[   50.199269] ata8: softreset failed (1st FIS failed)
[   50.199278] ata8: hard resetting link
[   50.199283] ata8: ahci_hardreset *****
[   50.199289] ahci 0000:6f:00.0: ahci_stop_engine start *** 
( PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) 
[   50.199298] ahci 0000:6f:00.0: ahci_stop_engine: setting HBA to idle  
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) 
[   50.199302] ahci 0000:6f:00.0: ahci_stop_engine end *** 
[   50.514443] ahci 0000:6f:00.0: ahci_start_engine start 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) ***
[   50.514464] ahci 0000:6f:00.0: ahci_start_engine end 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) ***
[   50.514474] ata8: ahci_softreset *****
[   50.514482] ahci 0000:6f:00.0: ahci_stop_engine start *** 
( PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) 
[   50.514492] ahci 0000:6f:00.0: ahci_stop_engine: setting HBA to idle  
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) 
[   50.514496] ahci 0000:6f:00.0: ahci_stop_engine end *** 
[   50.514502] ahci 0000:6f:00.0: ahci_start_engine start 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) ***
[   50.514511] ahci 0000:6f:00.0: ahci_start_engine end 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) ***
[   60.173000] ahci 0000:6f:00.0: ahci_stop_engine start *** 
( PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) 
[   60.173020] ahci 0000:6f:00.0: ahci_stop_engine: setting HBA to idle  
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) 
[   60.173026] ahci 0000:6f:00.0: ahci_stop_engine end *** 
[   60.173038] ahci 0000:6f:00.0: ahci_start_engine start 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) ***
[   60.173048] ahci 0000:6f:00.0: ahci_start_engine end 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) ***
[   60.173053] ata8: softreset failed (1st FIS failed)
[   60.173063] ata8: hard resetting link
[   60.173067] ata8: ahci_hardreset *****
[   60.173073] ahci 0000:6f:00.0: ahci_stop_engine start *** 
( PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) 
[   60.173082] ahci 0000:6f:00.0: ahci_stop_engine: setting HBA to idle  
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) 
[   60.173086] ahci 0000:6f:00.0: ahci_stop_engine end *** 
[   60.488241] ahci 0000:6f:00.0: ahci_start_engine start 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) ***
[   60.488262] ahci 0000:6f:00.0: ahci_start_engine end 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) ***
[   60.488272] ata8: ahci_softreset *****
[   60.488280] ahci 0000:6f:00.0: ahci_stop_engine start *** 
( PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) 
[   60.488289] ahci 0000:6f:00.0: ahci_stop_engine: setting HBA to idle  
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) 
[   60.488294] ahci 0000:6f:00.0: ahci_stop_engine end *** 
[   60.488300] ahci 0000:6f:00.0: ahci_start_engine start 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) ***
[   60.488309] ahci 0000:6f:00.0: ahci_start_engine end 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) ***
[   95.144383] ahci 0000:6f:00.0: ahci_stop_engine start *** 
( PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) 
[   95.144402] ahci 0000:6f:00.0: ahci_stop_engine: setting HBA to idle  
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) 
[   95.144409] ahci 0000:6f:00.0: ahci_stop_engine end *** 
[   95.144420] ahci 0000:6f:00.0: ahci_start_engine start 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) ***
[   95.144430] ahci 0000:6f:00.0: ahci_start_engine end 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) ***
[   95.144435] ata8: softreset failed (1st FIS failed)
[   95.144450] ata8: limiting SATA link speed to 3.0 Gbps
[   95.144454] ata8: hard resetting link
[   95.144458] ata8: ahci_hardreset *****
[   95.144464] ahci 0000:6f:00.0: ahci_stop_engine start *** 
( PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) 
[   95.144473] ahci 0000:6f:00.0: ahci_stop_engine: setting HBA to idle  
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) 
[   95.144477] ahci 0000:6f:00.0: ahci_stop_engine end *** 
[   95.459765] ahci 0000:6f:00.0: ahci_start_engine start 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) ***
[   95.459785] ahci 0000:6f:00.0: ahci_start_engine end 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) ***
[   95.459795] ata8: ahci_softreset *****
[   95.459803] ahci 0000:6f:00.0: ahci_stop_engine start *** 
( PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) 
[   95.459813] ahci 0000:6f:00.0: ahci_stop_engine: setting HBA to idle  
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) 
[   95.459817] ahci 0000:6f:00.0: ahci_stop_engine end *** 
[   95.459823] ahci 0000:6f:00.0: ahci_start_engine start 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) ***
[   95.459832] ahci 0000:6f:00.0: ahci_start_engine end 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) ***
[  100.142968] ahci 0000:6f:00.0: ahci_stop_engine start *** 
( PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) 
[  100.142987] ahci 0000:6f:00.0: ahci_stop_engine: setting HBA to idle  
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) 
[  100.142993] ahci 0000:6f:00.0: ahci_stop_engine end *** 
[  100.143005] ahci 0000:6f:00.0: ahci_start_engine start 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) ***
[  100.143015] ahci 0000:6f:00.0: ahci_start_engine end 
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c017) ***
[  100.143020] ata8: softreset failed (1st FIS failed)
[  100.143035] ata8: reset failed, giving up
[  100.143040] ata8.00: disable device
[  100.143073] ahci 0000:6f:00.0: ahci_stop_engine: setting HBA to idle  
(PORT_IRQ_STAT 0x00000000 PORT_CMD 0x00044016) 
[  100.143079] ahci 0000:6f:00.0: ahci_stop_engine end *** 
[  100.143095] ata8: EH complete
[  100.143157] sd 7:0:0:0: [sdb] tag#13 FAILED Result: hostbyte=DID_BAD_TARGET 
driverbyte=DRIVER_OK cmd_age=60s
[  100.143166] sd 7:0:0:0: [sdb] tag#13 CDB: Read(10) 28 00 00 03 c3 c0 00 
 08 b8 00
[  100.143170] I/O error, dev sdb, sector 246720 op 0x0:(READ) flags 0x4000 
phys_seg 168 prio class 2
[  100.143196] sd 7:0:0:0: [sdb] tag#14 FAILED Result: hostbyte=DID_BAD_TARGET 
driverbyte=DRIVER_OK cmd_age=60s
[  100.143201] sd 7:0:0:0: [sdb] tag#14 CDB: Read(10) 28 00 00 03 cc 78 00 05 
b8 00
[  100.143204] I/O error, dev sdb, sector 248952 op 0x0:(READ) flags 0x0 phys_seg
 88 prio class 2
[  100.143226] sd 7:0:0:0: [sdb] tag#24 FAILED Result: hostbyte=DID_BAD_TARGET 
driverbyte=DRIVER_OK cmd_age=0s
[  100.143238] sd 7:0:0:0: [sdb] tag#24 CDB: ATA command pass through(16) 85 06 
 20 00 00 00 00 00 00 00 00 00 00 00 e5 00
[  100.143279] sd 7:0:0:0: [sdb] tag#15 FAILED Result: hostbyte=DID_BAD_TARGET 
driverbyte=DRIVER_OK cmd_age=60s
[  100.143287] sd 7:0:0:0: [sdb] tag#15 CDB: Read(10) 28 00 00 03 d2 30 00 
 0a 00 00
[  100.143291] I/O error, dev sdb, sector 250416 op 0x0:(READ) flags 0x4000 
phys_seg 112 prio class 2
[  100.143313] sd 7:0:0:0: [sdb] tag#16 FAILED Result: 
hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK cmd_age=60s
[  100.143322] sd 7:0:0:0: [sdb] tag#16 CDB: Read(10) 28 00 00 03 dc 30 00
 0a 00 00
[  100.143327] I/O error, dev sdb, sector 252976 op 0x0:(READ) flags 0x4000 
phys_seg 81 prio class 2
[  100.143346] sd 7:0:0:0: [sdb] tag#17 FAILED Result: 
hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK cmd_age=60s
[  100.143353] sd 7:0:0:0: [sdb] tag#17 CDB: Read(10) 28 00 00 03 e6
 30 00 08
 40 00
[  100.143357] I/O error, dev sdb, sector 255536 op 0x0:(READ) flags
 0x4000 phys_seg 65 prio class 2
[  100.143499] sd 7:0:0:0: [sdb] tag#18 FAILED Result:
 hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK cmd_age=60s
[  100.143508] sd 7:0:0:0: [sdb] tag#18 CDB: Read(10) 28 00 00 03 ee 70 00
 09 90 00
[  100.143513] I/O error, dev sdb, sector 257648 op 0x0:(READ) flags 0x0
 phys_seg 70 prio class 2
 

The Linux(add clear pending interrupt) kernel dmesg output as shown below:

[  331.569303] ahci_error_intr start (irq_stat 0x08000000) ****
[  331.569320] ahci_error_intr: interface fatal error
[  331.569324] ahci_error_intr: freeze (set pxIE to 0)
[  331.569345] ahci_error_intr end (PORT_IRQ_MASK = 0x00000000 )****
[  331.599010] ata8.00: exception Emask 0x10 SAct 0x18 SErr 0x280100 
action 0x6 frozen
[  331.599026] ata8.00: irq_stat 0x08000000, interface fatal error
[  331.599032] ata8: SError: { UnrecovData 10B8B BadCRC }
[  331.599042] ata8.00: failed command: READ FPDMA QUEUED
[  331.599047] ata8.00: cmd 60/00:18:e0:3d:19/0a:00:00:00:00/40 tag 3 
ncq dma 1310720 in
        res 40/00:ff:00:00:00/00:00:00:00:00/00 Emask 0x10 (ATA bus error)
[  331.599064] ata8.00: status: { DRDY }
[  331.599070] ata8.00: failed command: READ FPDMA QUEUED
[  331.599074] ata8.00: cmd 60/90:20:e0:47:19/06:00:00:00:00/40 tag 4 
ncq dma 860160 in
        res 40/00:ff:00:00:00/00:00:00:00:00/00 Emask 0x10 (ATA bus error)
[  331.599089] ata8.00: status: { DRDY }
[  331.599096] ata8: hard resetting link
[  331.599100] ata8: ahci_hardreset *****
[  331.599107] ahci 0000:6f:00.0: ahci_stop_engine start *** 
( PORT_IRQ_STAT 0x40000008 PORT_CMD 0x0004c317) 
[  331.599118] ahci 0000:6f:00.0: ahci_stop_engine: setting HBA to idle  
(PORT_IRQ_STAT 0x40000008 PORT_CMD 0x00044016) 
[  331.599123] ahci 0000:6f:00.0: ahci_stop_engine end *** 
[  331.914440] ahci 0000:6f:00.0: ahci_start_engine: check 
PORT_SCR_ERR 0x00000000, and to clear
[  331.914447] ahci 0000:6f:00.0: ahci_start_engine: check 
PORT_IRQ_STAT 0x40000008, and to clear 
[  331.914456] ata8: ahci_softreset *****
[  331.914466] ahci 0000:6f:00.0: ahci_stop_engine: setting HBA to idle  
(PORT_IRQ_STAT 0x00000000 PORT_CMD 0x00044016) 
[  331.914470] ahci 0000:6f:00.0: ahci_stop_engine end *** 
[  331.914473] ahci 0000:6f:00.0: ahci_start_engine: check 
PORT_SCR_ERR 0x00000000, and to clear
[  331.914477] ahci 0000:6f:00.0: ahci_start_engine: check 
PORT_IRQ_STAT 0x00000000, and to clear 
[  332.075031] ata8: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[  332.075718] ata8.00: configured for UDMA/133
[  332.075739] ata8: EH complete

Thanks.

>
>> action 0x6 frozen
>> [  656.180384] ata7.00: irq_stat 0x08000000, interface fatal error [  
>> 656.180386] ata7: SError: { UnrecovData BadCRC } [  656.180389] 
>> ata7.00: failed command: READ FPDMA QUEUED [  656.180390] ata7.00: cmd 
>> 60/00:30:28:a9:9c/0a:00:01:00:00/40 tag 6 ncq dma 1310720 in
>> 	res 40/00:01:00:00:00/00:00:00:00:00/00 Emask 0x10 (ATA bus error) [  
>> 656.180395] ata7.00: status: { DRDY } [  656.180397] ata7.00: failed 
>> command: READ FPDMA QUEUED [  656.180398] ata7.00: cmd 
>> 60/00:38:28:b3:9c/0a:00:01:00:00/40 tag 7 ncq dma 1310720 in
>> 	res 40/00:ff:00:00:00/00:00:00:00:00/00 Emask 0x10 (ATA bus error) [  
>> 656.180402] ata7.00: status: { DRDY } [  656.180403] ata7.00: failed 
>> command: READ FPDMA QUEUED [  656.180404] ata7.00: cmd 
>> 60/00:40:28:bd:9c/0a:00:01:00:00/40 tag 8 ncq dma 1310720 in
>> 	res 40/00:ff:00:00:00/00:00:00:00:00/00 Emask 0x10 (ATA bus error) [  
>> 656.180408] ata7.00: status: { DRDY } [  656.180410] ata7.00: failed 
>> command: READ FPDMA QUEUED [  656.180411] ata7.00: cmd 
>> 60/00:48:28:c7:9c/0a:00:01:00:00/40 tag 9 ncq dma 1310720 in
>> 	res 40/00:ff:00:00:00/00:00:00:00:00/00 Emask 0x10 (ATA bus error) [  
>> 656.180414] ata7.00: status: { DRDY } [  656.180416] ata7.00: failed 
>> command: READ FPDMA QUEUED [  656.180417] ata7.00: cmd 
>> 60/00:50:28:d1:9c/0a:00:01:00:00/40 tag 10 ncq dma 1310720 in
>> 	res 40/00:ff:00:00:00/00:00:00:00:00/00 Emask 0x10 (ATA bus error) [  
>> 656.180421] ata7.00: status: { DRDY } [  656.180423] ata7: hard 
>> resetting link [  659.210328] amd_iommu_report_page_fault: 48 
>> callbacks suppressed [  659.210333] nouveau 0000:09:00.0: AMD-Vi: 
>> Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  659.210345] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  659.210352] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  659.811069] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  659.811080] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  659.811086] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  659.827669] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  659.827676] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  659.827680] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  659.878319] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  664.426805] 
>> amd_iommu_report_page_fault: 248 callbacks suppressed [  664.426809] 
>> nouveau 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  664.426819] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  664.426825] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  664.676294] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  664.676305] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  664.676313] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  664.693501] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  664.693513] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  664.693521] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  664.711480] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  666.180398] ata7: softreset 
>> failed (1st FIS failed) [  666.180405] ata7: hard resetting link [  
>> 670.054987] amd_iommu_report_page_fault: 99 callbacks suppressed [  
>> 670.054992] nouveau 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  670.055003] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000] [  670.055010] nouveau 
>> 0000:09:00.0: AMD-Vi: Event logged [IO_PAGE_FAULT
>> domain=0x0019 address=0x0 flags=0x0000]
>> 
>> 
>> dmesg (add clear pending Interrupt):
>> [  120.236847] ahci_error_intr: interface fatal error [  120.236854] 
>> ahci_error_intr: freeze (set PxIE to 0) [  120.265268] ata7: limiting 
>> SATA link speed to 3.0 Gbps [  120.265275] ata7.00: exception Emask 
>> 0x10 SAct 0x3f0 SErr 0x400000 action 0x6 frozen [  120.265279] 
>> ata7.00: irq_stat 0x08000000, interface fatal error [  120.265281] 
>> ata7: SError: { Handshk } [  120.265285] ata7.00: failed command: 
>> WRITE FPDMA QUEUED [  120.265287] ata7.00: cmd 
>> 61/00:20:a8:b9:50/0a:00:00:00:00/40 tag 4 ncq dma 1310720 ou
>> 	res 40/00:ff:00:00:00/00:00:00:00:00/00 Emask 0x10 (ATA bus error) [  
>> 120.265295] ata7.00: status: { DRDY } [  120.265297] ata7.00: failed 
>> command: WRITE FPDMA QUEUED [  120.265299] ata7.00: cmd 
>> 61/20:28:a8:c3:50/03:00:00:00:00/40 tag 5 ncq dma 409600 out
>> 	res 40/00:ff:00:00:00/00:00:00:00:00/00 Emask 0x10 (ATA bus error) [  
>> 120.265305] ata7.00: status: { DRDY } [  120.265307] ata7.00: failed 
>> command: WRITE FPDMA QUEUED [  120.265309] ata7.00: cmd 
>> 61/00:30:c8:c6:50/0a:00:00:00:00/40 tag 6 ncq dma 1310720 ou
>> 	res 40/00:ff:00:00:00/00:00:00:00:00/00 Emask 0x10 (ATA bus error) [  
>> 120.265314] ata7.00: status: { DRDY } [  120.265316] ata7.00: failed 
>> command: WRITE FPDMA QUEUED [  120.265318] ata7.00: cmd 
>> 61/00:38:c8:d0:50/0a:00:00:00:00/40 tag 7 ncq dma 1310720 ou
>> 	res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x10 (ATA bus error) [  
>> 120.265324] ata7.00: status: { DRDY } [  120.265325] ata7.00: failed 
>> command: WRITE FPDMA QUEUED [  120.265327] ata7.00: cmd 
>> 61/00:40:c8:da:50/0a:00:00:00:00/40 tag 8 ncq dma 1310720 ou
>> 	res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x10 (ATA bus error) [  
>> 120.265333] ata7.00: status: { DRDY } [  120.265334] ata7.00: failed 
>> command: WRITE FPDMA QUEUED [  120.265336] ata7.00: cmd 
>> 61/00:48:c8:e4:50/0a:00:00:00:00/40 tag 9 ncq dma 1310720 ou
>> 	res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x10 (ATA bus error) [  
>> 120.265342] ata7.00: status: { DRDY } [  120.265346] ata7: hard 
>> resetting link [  120.265348] ata7: ahci_hardreset ***** [  
>> 120.265352] ahci 0000:0a:00.0: ahci_stop_engine: PORT_IRQ_STAT 
>> 0x40000008 PORT_CMD 0x0004c617 [  120.265356] ahci 0000:0a:00.0: 
>> ahci_stop_engine: setting HBA to idle (setting PxCMD.ST to 0) [  
>> 120.937522] ahci 0000:0a:00.0: ahci_start_engine: check PORT_SCR_ERR 
>> 0x00000000, and to clear [  120.937534] ahci 0000:0a:00.0: 
>> ahci_start_engine: check PORT_IRQ_STAT 0x40000008, and to clear [  
>> 120.937544] ata7: ahci_softreset ***** [  120.937550] ahci 
>> 0000:0a:00.0: ahci_stop_engine: setting HBA to idle (setting PxCMD.ST 
>> to 0) [  120.937555] ahci 0000:0a:00.0: ahci_start_engine: check 
>> PORT_SCR_ERR 0x00000000, and to clear [  120.937559] ahci 
>> 0000:0a:00.0: ahci_start_engine: check PORT_IRQ_STAT 0x00000000, and 
>> to clear [  121.097231] ata7: SATA link up 3.0 Gbps (SStatus 123 
>> SControl 320) [  121.113493] ata7.00: configured for UDMA/133 [  
>> 121.113570] ata7: EH complete
>> 
>> I have printk PxIS & PxCMD values to check pending interrupt.
>> It SBD FIS with ERR to setting PxIS.TFES and PxIS.SDBS bit. 
>> 
>> >>
>> >>>    >
>> >>>    > Signed-off-by: Szuying Chen <Chloe_Chen@xxxxxxxxxxxxxx>
>> >>>    > ---
>> >>>    >  drivers/ata/libahci.c | 12 ++++++++++++
>> >>>    >  1 file changed, 12 insertions(+)
>> >>>    >
>> >>>    > diff --git a/drivers/ata/libahci.c b/drivers/ata/libahci.c
>> >>>    > index 06aec35f88f2..0ae51fd95d46 100644
>> >>>    > --- a/drivers/ata/libahci.c
>> >>>    > +++ b/drivers/ata/libahci.c
>> >>>    > @@ -679,9 +679,21 @@ static int ahci_scr_write(struct ata_link *link, unsigned int sc_reg, u32 val)
>> >>>    >
>> >>>    >  void ahci_start_engine(struct ata_port *ap)
>> >>>    >  {
>> >>>    > +     struct ahci_host_priv *hpriv = ap->host->private_data;
>> >>>    >       void __iomem *port_mmio = ahci_port_base(ap);
>> >>>    >       u32 tmp;
>> >>>    >
>> >>>    > +     /* clear SError */
>> >>>    > +     tmp = readl(port_mmio + PORT_SCR_ERR);
>> >>>    > +     writel(tmp, port_mmio + PORT_SCR_ERR);
>> >>>    > +
>> >>>    > +     /* clear port IRQ */
>> >>>    > +     tmp = readl(port_mmio + PORT_IRQ_STAT);
>> >>>    > +     if (tmp)
>> >>>    > +             writel(tmp, port_mmio + PORT_IRQ_STAT);
>> >>>    > +
>> >>>    > +     writel(1 << ap->port_no, hpriv->mmio + PORT_IRQ_STAT);
>> >>>    > +
>> >>>    >       /* start DMA */
>> >>>    >       tmp = readl(port_mmio + PORT_CMD);
>> >>>    >       tmp |= PORT_CMD_START;
>> >>>    > --
>> >>>    > 2.39.2
>> >>>   >
>> >>>
>> >>>   --
>> >>>   Damien Le Moal
>> >>>    Western Digital Research
>> >>>
>> >> Thanks.
>> >>
>> >
>> >--
>> >Damien Le Moal
>> >Western Digital Research
><p></p>
>



[Index of Archives]     [Linux Filesystems]     [Linux SCSI]     [Linux RAID]     [Git]     [Kernel Newbies]     [Linux Newbie]     [Security]     [Netfilter]     [Bugtraq]     [Yosemite News]     [MIPS Linux]     [ARM Linux]     [Linux Security]     [Samba]     [Device Mapper]

  Powered by Linux