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
