FreeBSD and SATA Port Multipliers

[Steve Polyack]

Alexander Motin wrote:
>> If your conditions permit, you can try to upgrade to recent HEAD to look
>> how will it go with newer code. I am periodically merging my work there
>> from Perforce. Also I am going to generate new test patch for HEAD,
>> which includes reworked PMP support, tomorrow.
>>     
>
> You can try this patch against today's HEAD:
> http://people.freebsd.org/~mav/cam-ata.20091022.patch
>
>   
I tried the patch this morning against a fresh checkout of HEAD.  
Immediately after boot only one device per PM was detected (I have two 
hooked up at the moment, 5 drives on one, 1 on the other).  However, 
about two minutes later all of the drives showed up!

camcontrol also rescans the entire bus *very* quickly now, and discovers 
all changes (new/missing disks and port multipliers).

Here's some verbose info from /var/log/messages immediately after boot:
Oct 22 10:52:03 lovepod kernel: siisch0: Timeout on slot 27
Oct 22 10:52:03 lovepod kernel: siisch0: siis_timeout is 00000000 ss 
08000000 rs 08000000 es 00000000 sts 801b2000 serr 00000000
Oct 22 10:52:03 lovepod kernel: siisch0: ready wait time=1ms
Oct 22 10:52:03 lovepod kernel: siisch0: ready wait time=1ms
Oct 22 10:52:03 lovepod kernel: siisch0: SIIS reset...
Oct 22 10:52:03 lovepod kernel: siisch0: ready wait time=1ms
Oct 22 10:52:03 lovepod kernel: siisch0: hardware reset ...
Oct 22 10:52:03 lovepod kernel: siisch0: SATA connect timeout 
status=00000001
Oct 22 10:52:03 lovepod kernel: siisch0: SIIS reset done: phy reset 
found no device
Oct 22 10:52:03 lovepod kernel: (aprobe0:siisch0:0:1:0): Command timed out
Oct 22 10:52:03 lovepod kernel: (aprobe0:siisch0:0:1:0): error 5
Oct 22 10:52:03 lovepod kernel: (aprobe0:siisch0:0:1:0): Retries Exhausted
Oct 22 10:52:03 lovepod kernel: siisch0: DISCONNECT requested
Oct 22 10:52:05 lovepod kernel: siisch0: CONNECT requested
Oct 22 10:52:05 lovepod kernel: siisch0: SIIS reset...
Oct 22 10:52:05 lovepod kernel: siisch0: ready wait time=1ms
Oct 22 10:52:05 lovepod kernel: siisch0: hardware reset ...
Oct 22 10:52:05 lovepod kernel: siisch0: SATA connect time=0ms 
status=00000123
Oct 22 10:52:05 lovepod kernel: siisch0: ready wait time=0ms
Oct 22 10:52:05 lovepod kernel: siisch0: SIIS reset done: devices=00000001
Oct 22 10:52:33 lovepod kernel: siisch0: Timeout on slot 28
Oct 22 10:52:33 lovepod kernel: siisch0: siis_timeout is 00000000 ss 
10000000 rs 10000000 es 00000000 sts 801c2000 serr 00000000
Oct 22 10:52:33 lovepod kernel: siisch0: ready wait time=1ms
Oct 22 10:52:33 lovepod kernel: siisch0: ready wait time=1ms
Oct 22 10:52:33 lovepod kernel: siisch0: SIIS reset...
Oct 22 10:52:33 lovepod kernel: siisch0: ready wait time=1ms
Oct 22 10:52:33 lovepod kernel: siisch0: hardware reset ...
Oct 22 10:52:33 lovepod kernel: siisch0: SATA connect timeout 
status=00000001
Oct 22 10:52:33 lovepod kernel: siisch0: SIIS reset done: phy reset 
found no device
Oct 22 10:52:33 lovepod kernel: (aprobe0:siisch0:0:2:0): Command timed out
Oct 22 10:52:33 lovepod kernel: (aprobe0:siisch0:0:2:0): error 5
Oct 22 10:52:33 lovepod kernel: (aprobe0:siisch0:0:2:0): Retries Exhausted
Oct 22 10:52:33 lovepod kernel: siisch0: DISCONNECT requested
Oct 22 10:52:35 lovepod kernel: siisch0: CONNECT requested
Oct 22 10:52:35 lovepod kernel: siisch0: SIIS reset...
Oct 22 10:52:35 lovepod kernel: siisch0: ready wait time=1ms
Oct 22 10:52:35 lovepod kernel: siisch0: hardware reset ...
Oct 22 10:52:35 lovepod kernel: siisch0: SATA connect time=0ms 
status=00000123
Oct 22 10:52:35 lovepod kernel: siisch0: ready wait time=0ms
Oct 22 10:52:35 lovepod kernel: siisch0: SIIS reset done: devices=00000001
Oct 22 10:53:03 lovepod kernel: siisch0: Timeout on slot 29
Oct 22 10:53:03 lovepod kernel: siisch0: siis_timeout is 00000000 ss 
20000000 rs 20000000 es 00000000 sts 801d2000 serr 00000000
Oct 22 10:53:03 lovepod kernel: siisch0: ready wait time=1ms
Oct 22 10:53:03 lovepod kernel: siisch0: ready wait time=1ms
Oct 22 10:53:03 lovepod kernel: siisch0: SIIS reset...
Oct 22 10:53:03 lovepod kernel: siisch0: ready wait time=1ms
Oct 22 10:53:03 lovepod kernel: siisch0: hardware reset ...
Oct 22 10:53:03 lovepod kernel: siisch0: SATA connect timeout 
status=00000001
Oct 22 10:53:03 lovepod kernel: siisch0: SIIS reset done: phy reset 
found no device
Oct 22 10:53:03 lovepod kernel: (aprobe0:siisch0:0:3:0): Command timed out
Oct 22 10:53:03 lovepod kernel: (aprobe0:siisch0:0:3:0): error 5
Oct 22 10:53:03 lovepod kernel: (aprobe0:siisch0:0:3:0): Retries Exhausted
Oct 22 10:53:03 lovepod kernel: siisch0: DISCONNECT requested
Oct 22 10:53:05 lovepod kernel: siisch0: CONNECT requested
Oct 22 10:53:05 lovepod kernel: siisch0: SIIS reset...
Oct 22 10:53:05 lovepod kernel: siisch0: ready wait time=1ms
Oct 22 10:53:05 lovepod kernel: siisch0: hardware reset ...
Oct 22 10:53:05 lovepod kernel: siisch0: SATA connect time=0ms 
status=00000123
Oct 22 10:53:05 lovepod kernel: siisch0: ready wait time=0ms
Oct 22 10:53:05 lovepod kernel: siisch0: SIIS reset done: devices=00000001
Oct 22 10:53:34 lovepod kernel: siisch0: Timeout on slot 30
Oct 22 10:53:34 lovepod kernel: siisch0: siis_timeout is 00000000 ss 
40000000 rs 40000000 es 00000000 sts 801e2000 serr 00000000
Oct 22 10:53:34 lovepod kernel: siisch0: ready wait time=1ms
Oct 22 10:53:34 lovepod kernel: siisch0: ready wait time=1ms
Oct 22 10:53:34 lovepod kernel: siisch0: SIIS reset...
Oct 22 10:53:34 lovepod kernel: siisch0: ready wait time=1ms
Oct 22 10:53:34 lovepod kernel: siisch0: hardware reset ...
Oct 22 10:53:34 lovepod kernel: siisch0: SATA connect timeout 
status=00000001
Oct 22 10:53:34 lovepod kernel: siisch0: SIIS reset done: phy reset 
found no device
Oct 22 10:53:34 lovepod kernel: (aprobe0:siisch0:0:4:0): Command timed out
Oct 22 10:53:34 lovepod kernel: (aprobe0:siisch0:0:4:0): error 5
Oct 22 10:53:34 lovepod kernel: (aprobe0:siisch0:0:4:0): Retries Exhausted
Oct 22 10:53:34 lovepod kernel: siisch0: DISCONNECT requested
Oct 22 10:53:36 lovepod kernel: siisch0: CONNECT requested
Oct 22 10:53:36 lovepod kernel: siisch0: SIIS reset...
Oct 22 10:53:36 lovepod kernel: siisch0: ready wait time=1ms
Oct 22 10:53:36 lovepod kernel: siisch0: hardware reset ...
Oct 22 10:53:36 lovepod kernel: siisch0: SATA connect time=0ms 
status=00000123
Oct 22 10:53:36 lovepod kernel: siisch0: ready wait time=0ms
Oct 22 10:53:36 lovepod kernel: siisch0: SIIS reset done: devices=00000001
Oct 22 10:53:36 lovepod kernel: PMP freeze: 0
Oct 22 10:53:36 lovepod kernel: PMP freeze: 1
Oct 22 10:53:36 lovepod kernel: PMP freeze: 2
Oct 22 10:53:36 lovepod kernel: PMP freeze: 3
Oct 22 10:53:36 lovepod kernel: PMP freeze: 4
Oct 22 10:53:51 lovepod kernel: PM ports: 5
Oct 22 10:53:51 lovepod kernel: PM RESET 0
Oct 22 10:53:51 lovepod kernel: PM RESET 1
Oct 22 10:53:51 lovepod kernel: PM RESET 2
Oct 22 10:53:51 lovepod kernel: siisch0: SNTF 0x0000
Oct 22 10:53:51 lovepod kernel: siisch0: SNTF 0x0000
Oct 22 10:53:51 lovepod kernel: PM RESET 3
Oct 22 10:53:51 lovepod kernel: PM RESET 4
Oct 22 10:53:51 lovepod kernel: siisch0: SNTF 0x0000
Oct 22 10:53:51 lovepod kernel: siisch0: SNTF 0x0000
Oct 22 10:53:51 lovepod kernel: PM reset done
Oct 22 10:53:51 lovepod kernel: PM connect done
Oct 22 10:53:51 lovepod kernel: PM status: 0 - 00000123
Oct 22 10:53:51 lovepod kernel: PM status: 1 - 00000123
Oct 22 10:53:51 lovepod kernel: PM status: 2 - 00000123
Oct 22 10:53:51 lovepod kernel: PM status: 3 - 00000123
Oct 22 10:53:51 lovepod kernel: PM status: 4 - 00000123
Oct 22 10:53:51 lovepod kernel: PMP release: 0
Oct 22 10:53:51 lovepod kernel: (aprobe0:siisch0:0:0:0): SIGNATURE: 0000
Oct 22 10:53:51 lovepod kernel: pass4 at siisch0 bus 0 scbus0 target 0 lun 0
Oct 22 10:53:51 lovepod kernel: pass4: <ST31500341AS CC1H> ATA/ATAPI-8 
SATA 2.x device
Oct 22 10:53:51 lovepod kernel: pass4: Serial Number 9VS2FJJR
Oct 22 10:53:51 lovepod kernel: pass4: 300.000MB/s transfers
Oct 22 10:53:51 lovepod kernel: ada2 at siisch0 bus 0 scbus0 target 0 
lun 0GEOM: new disk ada2
Oct 22 10:53:51 lovepod kernel: ada2:
Oct 22 10:53:51 lovepod kernel: <ST31500341AS CC1H> ATA/ATAPI-8 SATA 2.x 
device
Oct 22 10:53:51 lovepod kernel: ada2: Serial Number 9VS2FJJR
Oct 22 10:53:51 lovepod kernel: ada2: 300.000MB/s transfers
Oct 22 10:53:51 lovepod kernel: ada2: 1430799MB (2930277168 512 byte 
sectors: 16H 63S/T 16383C)
Oct 22 10:53:51 lovepod kernel: ada2: Native Command Queueing enabled
Oct 22 10:53:51 lovepod kernel: PMP release: 1
Oct 22 10:53:51 lovepod kernel: (aprobe0:siisch0:0:1:0): SIGNATURE: 0000
Oct 22 10:53:51 lovepod kernel: pass5 at siisch0 bus 0 scbus0 target 1 lun 0
Oct 22 10:53:51 lovepod kernel: pass5: <ST31500341AS CC1H> ATA/ATAPI-8 
SATA 2.x device
Oct 22 10:53:51 lovepod kernel: pass5: Serial Number 9VS2DYEQ
Oct 22 10:53:51 lovepod kernel: pass5: 300.000MB/s transfers
Oct 22 10:53:51 lovepod kernel: ada3 at siisch0 bus 0 scbus0 target 1 lun 0
Oct 22 10:53:51 lovepod kernel: ada3: <ST31500341AS CC1H> ATA/ATAPI-8 
SATA 2.x device
Oct 22 10:53:51 lovepod kernel: ada3: Serial Number 9VS2DYEQ
Oct 22 10:53:51 lovepod kernel: ada3: 300.000MB/s transfers
Oct 22 10:53:36 lovepod kernel: PMP freeze: 4
Oct 22 10:53:51 lovepod kernel: PM ports: 5
Oct 22 10:53:51 lovepod kernel: PM RESET 0
Oct 22 10:53:51 lovepod kernel: PM RESET 1
Oct 22 10:53:51 lovepod kernel: PM RESET 2
Oct 22 10:53:51 lovepod kernel: siisch0: SNTF 0x0000
Oct 22 10:53:51 lovepod kernel: siisch0: SNTF 0x0000
Oct 22 10:53:51 lovepod kernel: PM RESET 3
Oct 22 10:53:51 lovepod kernel: PM RESET 4
Oct 22 10:53:51 lovepod kernel: siisch0: SNTF 0x0000
Oct 22 10:53:51 lovepod kernel: siisch0: SNTF 0x0000
Oct 22 10:53:51 lovepod kernel: PM reset done
Oct 22 10:53:51 lovepod kernel: PM connect done
Oct 22 10:53:51 lovepod kernel: PM status: 0 - 00000123
Oct 22 10:53:51 lovepod kernel: PM status: 1 - 00000123
Oct 22 10:53:51 lovepod kernel: PM status: 2 - 00000123
Oct 22 10:53:51 lovepod kernel: PM status: 3 - 00000123
Oct 22 10:53:51 lovepod kernel: PM status: 4 - 00000123
Oct 22 10:53:51 lovepod kernel: PMP release: 0
Oct 22 10:53:51 lovepod kernel: (aprobe0:siisch0:0:0:0): SIGNATURE: 0000
Oct 22 10:53:51 lovepod kernel: pass4 at siisch0 bus 0 scbus0 target 0 lun 0
Oct 22 10:53:51 lovepod kernel: pass4: <ST31500341AS CC1H> ATA/ATAPI-8 
SATA 2.x device
Oct 22 10:53:51 lovepod kernel: pass4: Serial Number 9VS2FJJR
Oct 22 10:53:51 lovepod kernel: pass4: 300.000MB/s transfers
Oct 22 10:53:51 lovepod kernel: ada2 at siisch0 bus 0 scbus0 target 0 
lun 0GEOM: new disk ada2
Oct 22 10:53:51 lovepod kernel: ada2:
Oct 22 10:53:51 lovepod kernel: <ST31500341AS CC1H> ATA/ATAPI-8 SATA 2.x 
device
Oct 22 10:53:51 lovepod kernel: ada2: Serial Number 9VS2FJJR
Oct 22 10:53:51 lovepod kernel: ada2: 300.000MB/s transfers
Oct 22 10:53:51 lovepod kernel: ada2: 1430799MB (2930277168 512 byte 
sectors: 16H 63S/T 16383C)
Oct 22 10:53:51 lovepod kernel: ada2: Native Command Queueing enabled
Oct 22 10:53:51 lovepod kernel: PMP release: 1
Oct 22 10:53:51 lovepod kernel: (aprobe0:siisch0:0:1:0): SIGNATURE: 0000
Oct 22 10:53:51 lovepod kernel: pass5 at siisch0 bus 0 scbus0 target 1 lun 0
Oct 22 10:53:51 lovepod kernel: pass5: <ST31500341AS CC1H> ATA/ATAPI-8 
SATA 2.x device
Oct 22 10:53:51 lovepod kernel: pass5: Serial Number 9VS2DYEQ
Oct 22 10:53:51 lovepod kernel: pass5: 300.000MB/s transfers
Oct 22 10:53:51 lovepod kernel: ada3 at siisch0 bus 0 scbus0 target 1 lun 0
Oct 22 10:53:51 lovepod kernel: ada3: <ST31500341AS CC1H> ATA/ATAPI-8 
SATA 2.x device
Oct 22 10:53:51 lovepod kernel: ada3: Serial Number 9VS2DYEQ
Oct 22 10:53:51 lovepod kernel: ada3: 300.000MB/s transfers
Oct 22 10:53:51 lovepod kernel: ada3: 1430799MB (2930277168 512 byte 
sectors: 16H 63S/T 16383C)
Oct 22 10:53:51 lovepod kernel: ada3: Native Command Queueing enabled
Oct 22 10:53:51 lovepod kernel: PMP release: 2
Oct 22 10:53:51 lovepod kernel: (aprobe0:siisch0:0:2:0): SIGNATURE: 0000
Oct 22 10:53:51 lovepod kernel: pass6 at siisch0 bus 0 scbus0 target 2 lun 0
Oct 22 10:53:51 lovepod kernel: pass6: <ST31500341AS CC1H> ATA/ATAPI-8 
SATA 2.x device
Oct 22 10:53:51 lovepod kernel: pass6: Serial Number 9VS2FJQ0
Oct 22 10:53:51 lovepod kernel: pass6: 300.000MB/s transfers
Oct 22 10:53:51 lovepod kernel: ada4 at siisch0 bus 0 scbus0 target 2 lun 0
Oct 22 10:53:51 lovepod kernel: ada4: <ST31500341AS CC1H> ATA/ATAPI-8 
SATA 2.x device
Oct 22 10:53:51 lovepod kernel: ada4: Serial Number 9VS2FJQ0
Oct 22 10:53:51 lovepod kernel: ada4: 300.000MB/s transfers
Oct 22 10:53:51 lovepod kernel: ada4: 1430799MB (2930277168 512 byte 
sectors: 16H 63S/T 16383C)
Oct 22 10:53:51 lovepod kernel: ada4: Native Command Queueing enabled
Oct 22 10:53:51 lovepod kernel: PMP release: 3
Oct 22 10:53:51 lovepod kernel: (aprobe0:siisch0:0:3:0): SIGNATURE: 0000
Oct 22 10:53:51 lovepod kernel: pass7 at siisch0 bus 0 scbus0 target 3 lun 0
Oct 22 10:53:51 lovepod kernel: pass7: <ST31500341AS CC1H> ATA/ATAPI-8 
SATA 2.x device
Oct 22 10:53:51 lovepod kernel: pass7: Serial Number 9VS2FG9C
Oct 22 10:53:51 lovepod kernel: pass7: 300.000MB/s transfers
Oct 22 10:53:51 lovepod kernel: ada5 at siisch0 bus 0 scbus0 target 3 lun 0
Oct 22 10:53:51 lovepod kernel: ada5: <ST31500341AS CC1H> ATA/ATAPI-8 
SATA 2.x device
Oct 22 10:53:51 lovepod kernel: ada5: Serial Number 9VS2FG9C
Oct 22 10:53:51 lovepod kernel: ada5: 300.000MB/s transfers
Oct 22 10:53:51 lovepod kernel: ada5: 1430799MB (2930277168 512 byte 
sectors: 16H 63S/T 16383C)
Oct 22 10:53:51 lovepod kernel: ada5: Native Command Queueing enabled
Oct 22 10:53:51 lovepod kernel: PMP release: 4
Oct 22 10:53:51 lovepod kernel: (aprobe0:siisch0:0:4:0): SIGNATURE: 0000
Oct 22 10:53:51 lovepod kernel: pass8 at siisch0 bus 0 scbus0 target 4 lun 0
Oct 22 10:53:51 lovepod kernel: pass8: <ST31500341AS CC1H> ATA/ATAPI-8 
SATA 2.x device
Oct 22 10:53:51 lovepod kernel: pass8: Serial Number 9VS2DH15
Oct 22 10:53:51 lovepod kernel: pass8: 300.000MB/s transfers
Oct 22 10:53:51 lovepod kernel: ada6 at siisch0 bus 0 scbus0 target 4 lun 0
Oct 22 10:53:51 lovepod kernel: ada6: <ST31500341AS CC1H> ATA/ATAPI-8 
SATA 2.x device
Oct 22 10:53:51 lovepod kernel: ada6: Serial Number 9VS2DH15
Oct 22 10:53:51 lovepod kernel: ada6: 300.000MB/s transfers
Oct 22 10:53:51 lovepod kernel: ada6: 1430799MB (2930277168 512 byte 
sectors: 16H 63S/T 16383C)
Oct 22 10:53:51 lovepod kernel: ada6: Native Command Queueing enabled
Oct 22 10:53:51 lovepod kernel: GEOM: new disk ada3
Oct 22 10:53:51 lovepod kernel: GEOM: new disk ada4
Oct 22 10:53:51 lovepod kernel: GEOM: new disk ada5
Oct 22 10:53:51 lovepod kernel: GEOM: new disk ada6