Re: AHCI/ADA regression?

On Tue, 24 May 2016 10:41:25 -0400
"Kenneth D. Merry" <ken_at_FreeBSD.ORG> wrote:

> > The question in my mind is - why are "empty" multiplier ports being
> > probed with the new code but not with the old code?  
> 
> If the HBA says that it supports port multipliers, the kernel should always
> look for them.  It probes the port multiplier first, before moving on to
> look for regular targets.
> 
> So, from that standpoint, it should not be any different.  It sounds like
> we're either getting further in the port multiplier probe process, or there
> is something different about the way things are behaving.
> 
> If you can determine which commands are timing out, that may give us an
> idea about where it is in the probe process.
> 
> Here is one way we may be able to track things down...  Build a kernel with
> these options:
> 
> options	CAMDEBUG
> options CAM_DEBUG_FLAGS=CAM_DEBUG_PROBE
> 
> If you build a kernel before and after the change with those options, it
> will hopefully allow us to compare the probe sequence and get a clue about
> where to look for the problem.
> 

OK, both the old and new kernel versions do an extremely fast intial
probe with these results (note: obtained with grep over dmesg.boot):

(aprobe0:ahcich0:0:15:0): Probe started
(aprobe0:ahcich0:0:15:0): Probe PROBE_INVALID to PROBE_RESET
(aprobe1:ahcich1:0:15:0): Probe started
(aprobe1:ahcich1:0:15:0): Probe PROBE_INVALID to PROBE_RESET
(aprobe2:ahcich2:0:15:0): Probe started
(aprobe2:ahcich2:0:15:0): Probe PROBE_INVALID to PROBE_RESET
(aprobe3:ahcich3:0:15:0): Probe started
(aprobe3:ahcich3:0:15:0): Probe PROBE_INVALID to PROBE_RESET
(aprobe4:ahcich4:0:15:0): Probe started
(aprobe4:ahcich4:0:15:0): Probe PROBE_INVALID to PROBE_RESET
(aprobe5:ahcich5:0:15:0): Probe started
(aprobe5:ahcich5:0:15:0): Probe PROBE_INVALID to PROBE_RESET
(aprobe4:ahcich4:0:15:0): Probe PROBE_RESET to PROBE_RESET
(aprobe4:ahcich4:0:15:0): Probe PROBE_RESET to PROBE_INVALID
(aprobe4:ahcich4:0:15:0): Probe completed
(aprobe4:ahcich4:0:0:0): Probe started
(aprobe4:ahcich4:0:0:0): Probe PROBE_INVALID to PROBE_RESET
(aprobe4:ahcich4:0:0:0): Probe PROBE_RESET to PROBE_INVALID
(aprobe4:ahcich4:0:0:0): Probe completed
(aprobe0:ahcich0:0:15:0): Probe PROBE_RESET to PROBE_RESET
(aprobe2:ahcich2:0:15:0): Probe PROBE_RESET to PROBE_RESET
(aprobe0:ahcich0:0:15:0): SIGNATURE: 0000
(aprobe0:ahcich0:0:15:0): Probe PROBE_RESET to PROBE_INVALID
(aprobe0:ahcich0:0:15:0): Probe completed
(aprobe2:ahcich2:0:15:0): SIGNATURE: 0000
(aprobe2:ahcich2:0:15:0): Probe PROBE_RESET to PROBE_INVALID
(aprobe2:ahcich2:0:15:0): Probe completed
(aprobe0:ahcich0:0:0:0): Probe started
(aprobe0:ahcich0:0:0:0): Probe PROBE_INVALID to PROBE_RESET
(aprobe2:ahcich2:0:0:0): Probe started
(aprobe2:ahcich2:0:0:0): Probe PROBE_INVALID to PROBE_RESET
(aprobe3:ahcich3:0:15:0): Probe PROBE_RESET to PROBE_RESET
(aprobe5:ahcich5:0:15:0): Probe PROBE_RESET to PROBE_RESET
(aprobe0:ahcich0:0:0:0): SIGNATURE: 0000
(aprobe0:ahcich0:0:0:0): Probe PROBE_RESET to PROBE_IDENTIFY
(aprobe2:ahcich2:0:0:0): SIGNATURE: 0000
(aprobe2:ahcich2:0:0:0): Probe PROBE_RESET to PROBE_IDENTIFY
(aprobe1:ahcich1:0:15:0): Probe PROBE_RESET to PROBE_RESET
(aprobe3:ahcich3:0:15:0): SIGNATURE: 0000
(aprobe3:ahcich3:0:15:0): Probe PROBE_RESET to PROBE_INVALID
(aprobe3:ahcich3:0:15:0): Probe completed
(aprobe5:ahcich5:0:15:0): SIGNATURE: 0000
(aprobe5:ahcich5:0:15:0): Probe PROBE_RESET to PROBE_INVALID
(aprobe5:ahcich5:0:15:0): Probe completed
(aprobe1:ahcich1:0:15:0): SIGNATURE: eb14
(aprobe1:ahcich1:0:15:0): Probe PROBE_RESET to PROBE_INVALID
(aprobe1:ahcich1:0:15:0): Probe completed
(aprobe1:ahcich3:0:0:0): Probe started
(aprobe1:ahcich3:0:0:0): Probe PROBE_INVALID to PROBE_RESET
(aprobe3:ahcich5:0:0:0): Probe started
(aprobe3:ahcich5:0:0:0): Probe PROBE_INVALID to PROBE_RESET
(aprobe4:ahcich1:0:0:0): Probe started
(aprobe4:ahcich1:0:0:0): Probe PROBE_INVALID to PROBE_RESET
(aprobe1:ahcich3:0:0:0): SIGNATURE: 0000
(aprobe1:ahcich3:0:0:0): Probe PROBE_RESET to PROBE_IDENTIFY
(aprobe3:ahcich5:0:0:0): SIGNATURE: 0000
(aprobe3:ahcich5:0:0:0): Probe PROBE_RESET to PROBE_IDENTIFY
(aprobe4:ahcich1:0:0:0): SIGNATURE: eb14
(aprobe4:ahcich1:0:0:0): Probe PROBE_RESET to PROBE_IDENTIFY
(aprobe0:ahcich0:0:0:0): Probe PROBE_IDENTIFY to PROBE_SETMODE
(aprobe1:ahcich3:0:0:0): Probe PROBE_IDENTIFY to PROBE_SETMODE
(aprobe3:ahcich5:0:0:0): Probe PROBE_IDENTIFY to PROBE_SETMODE
(aprobe0:ahcich0:0:0:0): Probe PROBE_SETMODE to PROBE_SET_MULTI
(aprobe1:ahcich3:0:0:0): Probe PROBE_SETMODE to PROBE_SETDMAAA
(aprobe3:ahcich5:0:0:0): Probe PROBE_SETMODE to PROBE_SETDMAAA
(aprobe0:ahcich0:0:0:0): Probe PROBE_SET_MULTI to PROBE_DONE
(aprobe0:ahcich0:0:0:0): Probe completed
(aprobe1:ahcich3:0:0:0): Probe PROBE_SETDMAAA to PROBE_SET_MULTI
(aprobe4:ahcich1:0:0:0): Probe PROBE_IDENTIFY to PROBE_SETMODE
(aprobe3:ahcich5:0:0:0): Probe PROBE_SETDMAAA to PROBE_SET_MULTI
(aprobe1:ahcich3:0:0:0): Probe PROBE_SET_MULTI to PROBE_DONE
(aprobe1:ahcich3:0:0:0): Probe completed
(aprobe3:ahcich5:0:0:0): Probe PROBE_SET_MULTI to PROBE_DONE
(aprobe3:ahcich5:0:0:0): Probe completed
(aprobe2:ahcich2:0:0:0): Probe PROBE_IDENTIFY to PROBE_SETMODE
(aprobe4:ahcich1:0:0:0): Probe PROBE_SETMODE to PROBE_INQUIRY
(aprobe2:ahcich2:0:0:0): Probe PROBE_SETMODE to PROBE_SETDMAAA
(aprobe2:ahcich2:0:0:0): Probe PROBE_SETDMAAA to PROBE_SET_MULTI
(aprobe2:ahcich2:0:0:0): Probe PROBE_SET_MULTI to PROBE_DONE
(aprobe2:ahcich2:0:0:0): Probe completed
(aprobe4:ahcich1:0:0:0): Probe PROBE_INQUIRY to PROBE_FULL_INQUIRY
(aprobe4:ahcich1:0:0:0): Probe PROBE_FULL_INQUIRY to PROBE_DONE
(aprobe4:ahcich1:0:0:0): Probe completed

it looks like the code is basically checking to see how many ports are
on a multiplier since it looks at port 0 and port 15.

[I don't have a dmesg.boot for the "broken" kernel, but I saw the
probe messages going shooting past and it was obviuos that they
were the same]

The old code stops there.

The new code starts probing for what appear to be random ports on a
multiplier, like 0, 7, 20, 17, etc.  These always result in timeouts.

These probes always start with "Probe PROBE_INVALID to PROBE_IDENTIFY"
Why the new code doesn't accept the PROBE_INVALID and skip over it
I don't understand.

After I noticed that the same ports had been probed several times on
achich2 with no apparent end in sight I rebooted.  This behavior is
extremely poor.

-- 
Gary Jennejohn