On 1/15/23 03:01, marius@xxxxxxxxxxxxxx wrote:
> Do you need any more tests?
Sorry for the late followup. I have been busy with many different things.
Let me try to patch something for you to test.
>
>
> December 9, 2022 8:30 PM, marius@xxxxxxxxxxxxxx wrote:
>
>> December 9, 2022 11:28 AM, "Damien Le Moal" <damien.lemoal@xxxxxxxxxxxxxxxxxx> wrote:
>>
>>>> [ 19.006105][ T113] Reconfig spd
>>>
>>> Which function did you add this message to ?
>>
>> sata_link_hardreset(), inside if(sata_set_spd_needed(link)){} condition,
>> but I replaced it with detailed debug inside sata_set_spd_needed() and ___sata_set_spd_needed()
>>
>> I ran the tests again with the new debug messages.
>> These are kernel boot logs with eSATA cable already connected.
>> I selected only the interesting lines to make it easy to read.
>>
>> ---- force 1.5Gbps ----
>>
>> [ 4.362670][ T1] ahci-mvebu f10a8000.sata: AHCI 0001.0000 32 slots 2 ports 6 Gbps 0x3 impl platform
>> mode
>> [ 4.372489][ T1] ahci-mvebu f10a8000.sata: flags: 64bit ncq sntf led only pmp fbs pio slum part sxs
>> [ 4.501238][ T1] ata1: SCR_CONTROL = 0x0
>> [ 4.505468][ T1] ata1: SATA max UDMA/133 mmio [mem 0xf10a8000-0xf10a9fff] port 0x100 irq 42
>> [ 4.514123][ T1] ata2: SCR_CONTROL = 0x0
>> [ 4.518345][ T1] ata2: FORCE: PHY spd limit set to 1.5Gbps
>> [ 4.524121][ T1] ata2: SATA max UDMA/133 mmio [mem 0xf10a8000-0xf10a9fff] port 0x180 irq 42
>> [ 4.533000][ T1] driver: 'ahci-mvebu': driver_bound: bound to device 'f10a8000.sata'
>> [ 4.533531][ T107] hardreset, Online=>Offline
>> [ 4.541075][ T107] sata_set_spd_needed, scontrol=0x0
>> [ 4.545587][ T107] __sata_set_spd_needed, initial limit=0xFFFFFFFF
>> [ 4.559662][ T107] __sata_set_spd_needed, corrected limit=0xFFFFFFFF
>> [ 4.559667][ T107] __sata_set_spd_needed, target=0x0
>> [ 4.559671][ T107] __sata_set_spd_needed, spd=0x0
>> [ 4.559675][ T107] __sata_set_spd_needed, final *scontrol=0x0
>> [ 4.560898][ T107] resume, do loop
>> [ 4.571158][ T112] hardreset, Online=>Offline
>> [ 4.582480][ T112] sata_set_spd_needed, scontrol=0x0
>> [ 4.593173][ T112] __sata_set_spd_needed, initial limit=0x1
>> [ 4.601251][ T112] __sata_set_spd_needed, corrected limit=0x1
>> [ 4.611322][ T112] __sata_set_spd_needed, target=0x1
>> [ 4.627598][ T112] __sata_set_spd_needed, spd=0x0
>> [ 4.627602][ T112] __sata_set_spd_needed, final *scontrol=0x10
>> [ 4.627608][ T112] __sata_set_spd_needed, initial limit=0x1 <--- why does it run twice?
>> [ 4.627611][ T112] __sata_set_spd_needed, corrected limit=0x1
>> [ 4.627615][ T112] __sata_set_spd_needed, target=0x1
>> [ 4.627619][ T112] __sata_set_spd_needed, spd=0x0
>> [ 4.627622][ T112] __sata_set_spd_needed, final *scontrol=0x314
>> [ 4.628702][ T112] resume, do loop
>> [ 4.794479][ T107] resume, after do loop
>> [ 4.800859][ T107] debounce, SCR=0x0 <---- T107 is probably ata1, not connected
>> [ 4.805936][ T107] debounce, SCR=0x0
>> [ 4.814690][ T107] debounce, SCR=0x0
>> [ 4.822841][ T107] debounce, SCR=0x0
>> [ 4.836237][ T107] debounce, SCR=0x0
>> [ 4.845368][ T107] debounce, SCR=0x0
>> [ 4.855008][ T107] debounce, SCR=0x0
>> [ 4.864502][ T112] resume, after do loop
>> [ 4.869198][ T107] debounce, SCR=0x0
>> [ 4.877867][ T112] debounce, SCR=0x113 <---- T112 is probably ata2, link detected
>> [ 4.886183][ T107] debounce, SCR=0x0
>> [ 4.894861][ T107] resume, return at end of function
>> [ 4.903009][ T107] hardreset, ata_phys_link_offline check failed
>> [ 4.913867][ T107] ata1: SATA link down (SStatus 0 SControl 300)
>> [ 4.924894][ T112] debounce, SCR=0x113
>> ...
>> [ 5.867867][ T112] ata2.00: SCR_CONTROL = 0x300
>> [ 5.872520][ T112] ata2.00: FORCE: PHY spd limit set to 1.5Gbps
>> [ 5.883284][ T112] ata2.01: SCR_CONTROL = 0x300
>> [ 5.887960][ T112] ata2.01: FORCE: PHY spd limit set to 1.5Gbps
>> [ 5.888111][ T112] ata2.02: SCR_CONTROL = 0x300
>> [ 5.901206][ T112] ata2.02: FORCE: PHY spd limit set to 1.5Gbps
>> [ 5.919553][ T112] ata2.03: SCR_CONTROL = 0x300
>> [ 5.930054][ T112] ata2.03: FORCE: PHY spd limit set to 1.5Gbps
>> [ 5.956888][ T112] ata2.04: SCR_CONTROL = 0x300
>> [ 5.968103][ T112] ata2.04: FORCE: PHY spd limit set to 1.5Gbps
>> [ 5.984053][ T112] ata2.05: SCR_CONTROL = 0x300
>> [ 5.988735][ T112] ata2.05: FORCE: PHY spd limit set to 1.5Gbps
>> [ 5.988858][ T112] ata2.06: SCR_CONTROL = 0x300
>> [ 5.988865][ T112] ata2.06: FORCE: PHY spd limit set to 1.5Gbps
>> [ 5.988947][ T112] ata2.07: SCR_CONTROL = 0x300
>> [ 5.988953][ T112] ata2.07: FORCE: PHY spd limit set to 1.5Gbps
>> [ 5.997728][ T112] ata2.00: hard resetting link
>> [ 6.008378][ T112] hardreset, Online=>Offline
>> [ 6.025110][ T112] sata_set_spd_needed, scontrol=0x300
>> [ 6.039361][ T112] __sata_set_spd_needed, initial limit=0x1
>> [ 6.049281][ T112] __sata_set_spd_needed, corrected limit=0x1
>> [ 6.064930][ T112] __sata_set_spd_needed, target=0x1
>> [ 6.064935][ T112] __sata_set_spd_needed, spd=0x0
>> [ 6.064939][ T112] __sata_set_spd_needed, final *scontrol=0x310
>> [ 6.097506][ T112] __sata_set_spd_needed, initial limit=0x1
>> [ 6.108372][ T112] __sata_set_spd_needed, corrected limit=0x1
>> [ 6.118892][ T112] __sata_set_spd_needed, target=0x1
>> [ 6.118897][ T112] __sata_set_spd_needed, spd=0x0
>> [ 6.129664][ T112] __sata_set_spd_needed, final *scontrol=0x310
>> [ 6.153117][ T112] resume, do loop
>> [ 6.387397][ T112] resume, after do loop
>> [ 6.394052][ T112] debounce, SCR=0x123
>> [ 6.414455][ T112] debounce, SCR=0x123
>> [ 6.427772][ T112] debounce, SCR=0x123
>> [ 6.436940][ T112] debounce, SCR=0x123
>> [ 6.446566][ T112] debounce, SCR=0x123
>> [ 6.456201][ T112] debounce, SCR=0x123
>> [ 6.461379][ T112] debounce, SCR=0x123
>> [ 6.470664][ T112] debounce, SCR=0x123
>> [ 6.494546][ T112] debounce, SCR=0x123
>> [ 6.497712][ T112] resume, return at end of function
>> [ 6.512188][ T112] hardreset, Offline=>Online
>> [ 6.527056][ T112] hardreset, after check_ready
>> [ 6.538540][ T112] ata2.00: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
>>
>> ---- force 3.0Gbps ----
>>
>> [ 4.364181][ T1] ahci-mvebu f10a8000.sata: AHCI 0001.0000 32 slots 2 ports 6 Gbps 0x3 impl platform
>> mode
>> [ 4.374001][ T1] ahci-mvebu f10a8000.sata: flags: 64bit ncq sntf led only pmp fbs pio slum part sxs
>> [ 4.501990][ T1] ata1: SCR_CONTROL = 0x0
>> [ 4.506221][ T1] ata1: SATA max UDMA/133 mmio [mem 0xf10a8000-0xf10a9fff] port 0x100 irq 42
>> [ 4.514896][ T1] ata2: SCR_CONTROL = 0x0
>> [ 4.519102][ T1] ata2: FORCE: PHY spd limit set to 3.0Gbps
>> [ 4.524894][ T1] ata2: SATA max UDMA/133 mmio [mem 0xf10a8000-0xf10a9fff] port 0x180 irq 42
>> [ 4.533679][ T1] driver: 'ahci-mvebu': driver_bound: bound to device 'f10a8000.sata'
>> [ 4.541836][ T1] bus: 'platform': really_probe: bound device f10a8000.sata to driver ahci-mvebu
>> [ 4.544628][ T107] hardreset, Online=>Offline
>> [ 4.550844][ T107] sata_set_spd_needed, scontrol=0x0
>> [ 4.555435][ T107] __sata_set_spd_needed, initial limit=0xFFFFFFFF
>> [ 4.565341][ T107] __sata_set_spd_needed, corrected limit=0xFFFFFFFF
>> [ 4.576197][ T107] __sata_set_spd_needed, target=0x0
>> [ 4.576202][ T107] __sata_set_spd_needed, spd=0x0
>> [ 4.576206][ T107] __sata_set_spd_needed, final *scontrol=0x0
>> [ 4.590311][ T107] resume, do loop
>> [ 4.598257][ T112] hardreset, Online=>Offline
>> [ 4.615265][ T112] sata_set_spd_needed, scontrol=0x0
>> [ 4.629198][ T112] __sata_set_spd_needed, initial limit=0x3
>> [ 4.640664][ T112] __sata_set_spd_needed, corrected limit=0x3
>> [ 4.640668][ T112] __sata_set_spd_needed, target=0x2
>> [ 4.640672][ T112] __sata_set_spd_needed, spd=0x0
>> [ 4.652837][ T112] __sata_set_spd_needed, final *scontrol=0x20
>> [ 4.663171][ T112] __sata_set_spd_needed, initial limit=0x3
>> [ 4.674127][ T112] __sata_set_spd_needed, corrected limit=0x3
>> [ 4.687268][ T112] __sata_set_spd_needed, target=0x2
>> [ 4.687273][ T112] __sata_set_spd_needed, spd=0x0
>> [ 4.687277][ T112] __sata_set_spd_needed, final *scontrol=0x324
>> [ 4.688355][ T112] resume, do loop
>> [ 4.824481][ T107] resume, after do loop
>> [ 4.833744][ T107] debounce, SCR=0x0
>> ...
>> [ 4.916944][ T107] debounce, SCR=0x0
>> [ 4.924448][ T112] resume, after do loop
>> [ 4.930813][ T107] debounce, SCR=0x0
>> [ 4.940447][ T107] resume, return at end of function
>> [ 4.948608][ T107] hardreset, ata_phys_link_offline check failed
>> [ 4.958306][ T107] ata1: SATA link down (SStatus 0 SControl 300)
>> [ 4.958766][ T112] debounce, SCR=0x100
>> [ 4.974540][ T112] debounce, SCR=0x100
>> [ 4.984450][ T112] debounce, SCR=0x100
>> [ 4.998528][ T112] debounce, SCR=0x100
>> [ 5.006870][ T112] debounce, SCR=0x101
>> [ 5.016032][ T112] debounce, SCR=0x100
>>
>> ---- nolpm ----
>>
>> [ 4.364384][ T1] ahci-mvebu f10a8000.sata: AHCI 0001.0000 32 slots 2 ports 6 Gbps 0x3 impl platform
>> mode
>> [ 4.374205][ T1] ahci-mvebu f10a8000.sata: flags: 64bit ncq sntf led only pmp fbs pio slum part sxs
>> [ 4.502855][ T1] ata1: SCR_CONTROL = 0x0
>> [ 4.507087][ T1] ata1: SATA max UDMA/133 mmio [mem 0xf10a8000-0xf10a9fff] port 0x100 irq 42
>> [ 4.515761][ T1] ata2: SCR_CONTROL = 0x0
>> [ 4.519968][ T1] ata2: SATA max UDMA/133 mmio [mem 0xf10a8000-0xf10a9fff] port 0x180 irq 42
>> [ 4.528704][ T1] driver: 'ahci-mvebu': driver_bound: bound to device 'f10a8000.sata'
>> [ 4.536860][ T1] bus: 'platform': really_probe: bound device f10a8000.sata to driver ahci-mvebu
>> [ 4.544628][ T107] hardreset, Online=>Offline
>> [ 4.545867][ T107] sata_set_spd_needed, scontrol=0x0
>> [ 4.550348][ T107] __sata_set_spd_needed, initial limit=0xFFFFFFFF
>> [ 4.560435][ T107] __sata_set_spd_needed, corrected limit=0xFFFFFFFF
>> [ 4.571308][ T107] __sata_set_spd_needed, target=0x0
>> [ 4.583386][ T107] __sata_set_spd_needed, spd=0x0
>> [ 4.599648][ T107] __sata_set_spd_needed, final *scontrol=0x0
>> [ 4.615974][ T107] resume, do loop
>> [ 4.627876][ T112] hardreset, Online=>Offline
>> [ 4.638396][ T112] sata_set_spd_needed, scontrol=0x0
>> [ 4.647521][ T112] __sata_set_spd_needed, initial limit=0xFFFFFFFF
>> [ 4.660915][ T112] __sata_set_spd_needed, corrected limit=0xFFFFFFFF
>> [ 4.673702][ T112] __sata_set_spd_needed, target=0x0
>> [ 4.686663][ T112] __sata_set_spd_needed, spd=0x0
>> [ 4.686668][ T112] __sata_set_spd_needed, final *scontrol=0x0
>> [ 4.688105][ T112] resume, do loop
>> [ 4.854467][ T107] resume, after do loop
>> [ 4.863650][ T107] debounce, SCR=0x0
>> [ 4.873874][ T107] debounce, SCR=0x0
>> [ 4.882559][ T107] debounce, SCR=0x0
>> [ 4.891306][ T107] debounce, SCR=0x0
>> [ 4.901119][ T107] debounce, SCR=0x0
>> [ 4.910367][ T107] debounce, SCR=0x0
>> [ 4.915322][ T112] resume, after do loop
>> [ 4.920379][ T107] debounce, SCR=0x0
>> [ 4.927643][ T112] debounce, SCR=0x100
>> [ 4.936031][ T107] debounce, SCR=0x0
>> [ 4.944728][ T112] debounce, SCR=0x100
>> [ 4.953532][ T107] debounce, SCR=0x0
>> [ 4.962475][ T107] resume, return at end of function
>> [ 4.970650][ T107] hardreset, ata_phys_link_offline check failed
>> [ 4.980376][ T107] ata1: SATA link down (SStatus 0 SControl 300)
>> [ 4.991536][ T112] debounce, SCR=0x100
>> [ 5.007097][ T112] debounce, SCR=0x100
>> [ 5.016660][ T112] debounce, SCR=0x100
>> [ 5.025693][ T112] debounce, SCR=0x100
>> [ 5.030094][ T112] resume, return at end of function
>> [ 5.033962][ T112] hardreset, ata_phys_link_offline check failed
>> [ 5.043999][ T112] ata2: SATA link down (SStatus 101 SControl 300)
>> [ 5.054652][ T112] hardreset, Online=>Offline
>> [ 5.067061][ T112] sata_set_spd_needed, scontrol=0x300
>> [ 5.067066][ T112] __sata_set_spd_needed, initial limit=0xFFFFFFFF
>> [ 5.076006][ T112] __sata_set_spd_needed, corrected limit=0xFFFFFFFF
>> [ 5.076010][ T112] __sata_set_spd_needed, target=0x0
>> [ 5.076014][ T112] __sata_set_spd_needed, spd=0x0
>> [ 5.076018][ T112] __sata_set_spd_needed, final *scontrol=0x300
>> [ 5.077276][ T112] resume, do loop
>> [ 5.314471][ T112] resume, after do loop
>> [ 5.364488][ T112] debounce, SCR=0x100
>> ... and doesn't work.
>>
>> Marius Dinu
>
--
Damien Le Moal
Western Digital Research
