Re: AHCI controller reports success but reads no data
Posted: Thu Nov 16, 2023 12:59 pm
Looks like my command line matches yours, and I enabled the extra tracing, thanks for the tip.
I've just tried it in QEMU with a slight change (setting SUD and POD after the COMRESET instead of before, as that's what you did). Same result but the trace shows something very strange:
We see near the top that it resets the port and puts in the signature 0x101 which is what we expect.
Next we see it reading PI thanks to which it discovers that port 0 is implemented.
We then see it progress through ahciStopCmd() with a bunch of reads from PxCMD,
Then it sets PxCMD.ICC = ACTIVE, reads PxCAP to find that staggered spin-up is not suported, and then sets PxCMD.SUD and PxCMD.POD (with no effect, they're already set).
It then writes all 1's to PxSERR, reads PxSSTS to find that DET=OK and IPM=ACTIVE, so proceeds to read the signature.
Now it reads the signature and the log indicates it returned 0xFFFFFFFF, even though it showed previously that the signature was set correctly. It shows that we have read the PxSIG port as we should.
I can see from the logs that none of the memory accesses were optimized out. Not really sure why it reports this... Maybe it's related to the problem on physical hardware.
EDIT: If I dump the TFD register at this point, its value is 0x7F, which is also the reset value. As if the reset is somehow not fully complete...
Looking at QEMU's code (hw/ide/ahci.c), pr->sig gets set in ahci_reset_port() to 0xFFFFFFFF, then later calls ahci_init_d2h() which sets pr->sig to the correct signature. The signature logged by QEMU is the one set in the IDE state, not in the PxSIG register. It only sets pr->sig if ahci_write_fis_d2h() succeeds; but it can fail if FRE is not set (which it isn't), implying I need to be able to receive FIS'es before I can read the signature.
I've just tried it in QEMU with a slight change (setting SUD and POD after the COMRESET instead of before, as that's what you did). Same result but the trace shows something very strange:
Code: Select all
ahci_reset ahci(0x55b23a7ab300): HBA reset
ahci_reset_port ahci(0x55b23a7ab300)[0]: reset port
ahci_set_signature ahci(0x55b23a7ab300)[0]: set signature sector:0x01 nsector:0x01 lcyl:0x00 hcyl:0x00 (cumulatively: 0x00000101)
ahci_reset_port ahci(0x55b23a7ab300)[1]: reset port
ahci_reset_port ahci(0x55b23a7ab300)[2]: reset port
ahci_reset_port ahci(0x55b23a7ab300)[3]: reset port
ahci_reset_port ahci(0x55b23a7ab300)[4]: reset port
ahci_reset_port ahci(0x55b23a7ab300)[5]: reset port
ahci_mem_write_host ahci(0x55b23a7ab300) write4 [reg:GHC] @ 0x4: 0x0000000080000001
ahci_mem_read_32_host ahci(0x55b23a7ab300): mem read [reg:GHC] @ 0x4: 0x80000000
ahci_mem_read_32 ahci(0x55b23a7ab300): mem read @ 0x4: 0x80000000
ahci_mem_read ahci(0x55b23a7ab300): read4 @ 0x4: 0x0000000080000000
ahci_mem_read_32_host ahci(0x55b23a7ab300): mem read [reg:PI] @ 0xc: 0x0000003f
ahci_mem_read_32 ahci(0x55b23a7ab300): mem read @ 0xc: 0x0000003f
ahci_mem_read ahci(0x55b23a7ab300): read4 @ 0xc: 0x000000000000003f
ahci_port_read ahci(0x55b23a7ab300)[0]: port read [reg:PxCMD] @ 0x18: 0x00000006
ahci_mem_read_32 ahci(0x55b23a7ab300): mem read @ 0x118: 0x00000006
ahci_mem_read ahci(0x55b23a7ab300): read4 @ 0x118: 0x0000000000000006
ahci_mem_write ahci(0x55b23a7ab300): write4 @ 0x118: 0x0000000000000006
ahci_port_write ahci(0x55b23a7ab300)[0]: port write [reg:PxCMD] @ 0x18: 0x00000006
ahci_port_read ahci(0x55b23a7ab300)[0]: port read [reg:PxCMD] @ 0x18: 0x00000006
ahci_mem_read_32 ahci(0x55b23a7ab300): mem read @ 0x118: 0x00000006
ahci_mem_read ahci(0x55b23a7ab300): read4 @ 0x118: 0x0000000000000006
ahci_port_read ahci(0x55b23a7ab300)[0]: port read [reg:PxCMD] @ 0x18: 0x00000006
ahci_mem_read_32 ahci(0x55b23a7ab300): mem read @ 0x118: 0x00000006
ahci_mem_read ahci(0x55b23a7ab300): read4 @ 0x118: 0x0000000000000006
ahci_mem_write ahci(0x55b23a7ab300): write4 @ 0x118: 0x0000000000000006
ahci_port_write ahci(0x55b23a7ab300)[0]: port write [reg:PxCMD] @ 0x18: 0x00000006
ahci_port_read ahci(0x55b23a7ab300)[0]: port read [reg:PxCMD] @ 0x18: 0x00000006
ahci_mem_read_32 ahci(0x55b23a7ab300): mem read @ 0x118: 0x00000006
ahci_mem_read ahci(0x55b23a7ab300): read4 @ 0x118: 0x0000000000000006
ahci_port_read ahci(0x55b23a7ab300)[0]: port read [reg:PxCMD] @ 0x18: 0x00000006
ahci_mem_read_32 ahci(0x55b23a7ab300): mem read @ 0x118: 0x00000006
ahci_mem_read ahci(0x55b23a7ab300): read4 @ 0x118: 0x0000000000000006
ahci_mem_write ahci(0x55b23a7ab300): write4 @ 0x118: 0x0000000010000006
ahci_port_write ahci(0x55b23a7ab300)[0]: port write [reg:PxCMD] @ 0x18: 0x10000006
ahci_mem_read_32_host ahci(0x55b23a7ab300): mem read [reg:CAP] @ 0x0: 0xc0141f05
ahci_mem_read_32 ahci(0x55b23a7ab300): mem read @ 0x0: 0xc0141f05
ahci_mem_read ahci(0x55b23a7ab300): read4 @ 0x0: 0x00000000c0141f05
ahci_port_read ahci(0x55b23a7ab300)[0]: port read [reg:PxCMD] @ 0x18: 0x00000006
ahci_mem_read_32 ahci(0x55b23a7ab300): mem read @ 0x118: 0x00000006
ahci_mem_read ahci(0x55b23a7ab300): read4 @ 0x118: 0x0000000000000006
ahci_mem_write ahci(0x55b23a7ab300): write4 @ 0x118: 0x0000000000000006
ahci_port_write ahci(0x55b23a7ab300)[0]: port write [reg:PxCMD] @ 0x18: 0x00000006
ahci_mem_write ahci(0x55b23a7ab300): write4 @ 0x130: 0x00000000ffffffff
ahci_port_write ahci(0x55b23a7ab300)[0]: port write [reg:PxSERR] @ 0x30: 0xffffffff
ahci_port_read ahci(0x55b23a7ab300)[0]: port read [reg:PxSSTS] @ 0x28: 0x00000113
ahci_mem_read_32 ahci(0x55b23a7ab300): mem read @ 0x128: 0x00000113
ahci_mem_read ahci(0x55b23a7ab300): read4 @ 0x128: 0x0000000000000113
ahci_port_read ahci(0x55b23a7ab300)[0]: port read [reg:PxSIG] @ 0x24: 0xffffffff
ahci_mem_read_32 ahci(0x55b23a7ab300): mem read @ 0x124: 0xffffffff
ahci_mem_read ahci(0x55b23a7ab300): read4 @ 0x124: 0x00000000ffffffff
ahci_mem_read_32_host ahci(0x55b23a7ab300): mem read [reg:PI] @ 0xc: 0x0000003f
Next we see it reading PI thanks to which it discovers that port 0 is implemented.
We then see it progress through ahciStopCmd() with a bunch of reads from PxCMD,
Then it sets PxCMD.ICC = ACTIVE, reads PxCAP to find that staggered spin-up is not suported, and then sets PxCMD.SUD and PxCMD.POD (with no effect, they're already set).
It then writes all 1's to PxSERR, reads PxSSTS to find that DET=OK and IPM=ACTIVE, so proceeds to read the signature.
Now it reads the signature and the log indicates it returned 0xFFFFFFFF, even though it showed previously that the signature was set correctly. It shows that we have read the PxSIG port as we should.
I can see from the logs that none of the memory accesses were optimized out. Not really sure why it reports this... Maybe it's related to the problem on physical hardware.
EDIT: If I dump the TFD register at this point, its value is 0x7F, which is also the reset value. As if the reset is somehow not fully complete...
Looking at QEMU's code (hw/ide/ahci.c), pr->sig gets set in ahci_reset_port() to 0xFFFFFFFF, then later calls ahci_init_d2h() which sets pr->sig to the correct signature. The signature logged by QEMU is the one set in the IDE state, not in the PxSIG register. It only sets pr->sig if ahci_write_fis_d2h() succeeds; but it can fail if FRE is not set (which it isn't), implying I need to be able to receive FIS'es before I can read the signature.