Re: SCSI descriptor sense changes, testing needed

From: Fabian Keil <freebsd-listen_at_fabiankeil.de>
Date: Tue, 27 Sep 2011 21:46:03 +0200
"Kenneth D. Merry" <ken_at_freebsd.org> wrote:

> On Sat, Sep 24, 2011 at 21:27:22 +0200, Fabian Keil wrote:
> > "Kenneth D. Merry" <ken_at_freebsd.org> wrote:
> > 
> > > I have attached a set of patches against head that implement SCSI
> > > descriptor sense support for CAM.
> > 
> > > Anyway, I'd appreciate any testing and feedback on these changes.  As I
> > > said, they will probably be in 9.0, so if there are any issues it would
> > > be better to find them now. :)
> > 
> > I've been using the patch on a ThinkPad R500 since yesterday and
> > just reverted it today again to get my kernel closer to HEAD before
> > looking into some (probably unrelated) panics.
> > 
> > I didn't notice it while using the patch, but it looks like the
> > kernel wasn't able to pick up cd0 anymore:
> 
> Hmm.  I don't think any of the changes would have caused this, but
> evidently something did...
> 
> Let's see if we can debug it...
> 
> I have attached a patch to add some debugging output, and I see at least
> one interesting thing in the logs below.
> 
> Can you re-apply the descriptor sense patch, and then try the attached
> debugging patch as well?

Sure.

Sep 27 20:39:24 r500 kernel: ahcich0: AHCI reset...
Sep 27 20:39:24 r500 kernel: ahcich0: SATA connect time=900us status=00000113
Sep 27 20:39:24 r500 kernel: ahcich0: AHCI reset: device found
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset...
Sep 27 20:39:24 r500 kernel: ahcich1: SATA connect time=1000us status=00000113
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device found
Sep 27 20:39:24 r500 kernel: battery0: battery initialization start
Sep 27 20:39:24 r500 kernel: ugen0.1: <Intel> at usbus0
Sep 27 20:39:24 r500 kernel: uhub0: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus0
Sep 27 20:39:24 r500 kernel: ugen1.1: <Intel> at usbus1
Sep 27 20:39:24 r500 kernel: uhub1: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus1
Sep 27 20:39:24 r500 kernel: ugen2.1: <Intel> at usbus2
Sep 27 20:39:24 r500 kernel: uhub2: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus2
Sep 27 20:39:24 r500 kernel: ugen3.1: <Intel> at usbus3
Sep 27 20:39:24 r500 kernel: uhub3: <Intel EHCI root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus3
Sep 27 20:39:24 r500 kernel: ugen4.1: <Intel> at usbus4
Sep 27 20:39:24 r500 kernel: uhub4: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus4
Sep 27 20:39:24 r500 kernel: ugen5.1: <Intel> at usbus5
Sep 27 20:39:24 r500 kernel: uhub5: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus5
Sep 27 20:39:24 r500 kernel: ugen6.1: <Intel> at usbus6
Sep 27 20:39:24 r500 kernel: uhub6: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus6
Sep 27 20:39:24 r500 kernel: ugen7.1: <Intel> at usbus7
Sep 27 20:39:24 r500 kernel: uhub7: <Intel EHCI root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus7
Sep 27 20:39:24 r500 kernel: acpi_acad0: acline initialization start
Sep 27 20:39:24 r500 kernel: battery0: battery initialization done, tried 1 times
Sep 27 20:39:24 r500 kernel: acpi_acad0: On Line
Sep 27 20:39:24 r500 kernel: acpi_acad0: acline initialization done, tried 1 times
Sep 27 20:39:24 r500 kernel: ahcich0: AHCI reset: device ready after 100ms
Sep 27 20:39:24 r500 kernel: (aprobe0:ahcich0:0:0:0): SIGNATURE: 0000
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device ready after 100ms
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): SIGNATURE: eb14
Sep 27 20:39:24 r500 kernel: ahci_end_transaction: got AHCI_ERR_INVALID!
Sep 27 20:39:24 r500 kernel: ahci_end_transaction: op 12 dxfer_len 36 sense_len 18 sense_resid 0
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset...
Sep 27 20:39:24 r500 kernel: ahcich1: SATA connect time=1000us status=00000113
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device found
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): INQUIRY. CDB: 12 0 0 24 0 0 
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): CAM status: CCB request was invalid
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device ready after 100ms
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): SIGNATURE: eb14
Sep 27 20:39:24 r500 kernel: ahci_end_transaction: got AHCI_ERR_INVALID!
Sep 27 20:39:24 r500 kernel: ahci_end_transaction: op 12 dxfer_len 36 sense_len 18 sense_resid 0
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset...
Sep 27 20:39:24 r500 kernel: ahcich1: SATA connect time=1000us status=00000113
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device found
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): INQUIRY. CDB: 12 0 0 24 0 0 
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): CAM status: CCB request was invalid
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device ready after 100ms
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): SIGNATURE: eb14
Sep 27 20:39:24 r500 kernel: ahci_end_transaction: got AHCI_ERR_INVALID!
Sep 27 20:39:24 r500 kernel: ahci_end_transaction: op 12 dxfer_len 36 sense_len 18 sense_resid 0
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset...
Sep 27 20:39:24 r500 kernel: ahcich1: SATA connect time=1000us status=00000113
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device found
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): INQUIRY. CDB: 12 0 0 24 0 0 
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): CAM status: CCB request was invalid
Sep 27 20:39:24 r500 kernel: uhub0: 2 ports with 2 removable, self powered
Sep 27 20:39:24 r500 kernel: uhub1: 2 ports with 2 removable, self powered
Sep 27 20:39:24 r500 kernel: uhub2: 2 ports with 2 removable, self powered
Sep 27 20:39:24 r500 kernel: uhub4: 2 ports with 2 removable, self powered
Sep 27 20:39:24 r500 kernel: uhub5: 2 ports with 2 removable, self powered
Sep 27 20:39:24 r500 kernel: uhub6: 2 ports with 2 removable, self powered
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device ready after 200ms
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): SIGNATURE: eb14
Sep 27 20:39:24 r500 kernel: ahci_end_transaction: got AHCI_ERR_INVALID!
Sep 27 20:39:24 r500 kernel: ahci_end_transaction: op 12 dxfer_len 36 sense_len 18 sense_resid 0
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset...
Sep 27 20:39:24 r500 kernel: ahcich1: SATA connect time=1000us status=00000113
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device found
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): INQUIRY. CDB: 12 0 0 24 0 0 
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): CAM status: CCB request was invalid
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device ready after 200ms
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): SIGNATURE: eb14
Sep 27 20:39:24 r500 kernel: ahci_end_transaction: got AHCI_ERR_INVALID!
Sep 27 20:39:24 r500 kernel: ahci_end_transaction: op 12 dxfer_len 36 sense_len 18 sense_resid 0
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset...
Sep 27 20:39:24 r500 kernel: ahcich1: SATA connect time=1000us status=00000113
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device found
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): INQUIRY. CDB: 12 0 0 24 0 0 
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): CAM status: CCB request was invalid
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device ready after 100ms
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): SIGNATURE: eb14
Sep 27 20:39:24 r500 kernel: ahci_end_transaction: got AHCI_ERR_INVALID!
Sep 27 20:39:24 r500 kernel: ahci_end_transaction: op 12 dxfer_len 36 sense_len 18 sense_resid 0
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset...
Sep 27 20:39:24 r500 kernel: ahcich1: SATA connect time=1000us status=00000113
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device found
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): INQUIRY. CDB: 12 0 0 24 0 0 
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): CAM status: CCB request was invalid
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device ready after 100ms
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): SIGNATURE: eb14
Sep 27 20:39:24 r500 kernel: ahci_end_transaction: got AHCI_ERR_INVALID!
Sep 27 20:39:24 r500 kernel: ahci_end_transaction: op 12 dxfer_len 36 sense_len 18 sense_resid 0
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset...
Sep 27 20:39:24 r500 kernel: ahcich1: SATA connect time=1000us status=00000113
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device found
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): INQUIRY. CDB: 12 0 0 24 0 0 
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): CAM status: CCB request was invalid
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device ready after 200ms
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): SIGNATURE: eb14
Sep 27 20:39:24 r500 kernel: ahci_end_transaction: got AHCI_ERR_INVALID!
Sep 27 20:39:24 r500 kernel: ahci_end_transaction: op 12 dxfer_len 36 sense_len 18 sense_resid 0
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset...
Sep 27 20:39:24 r500 kernel: ahcich1: SATA connect time=1000us status=00000113
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device found
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): INQUIRY. CDB: 12 0 0 24 0 0 
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): CAM status: CCB request was invalid
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device ready after 200ms
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): SIGNATURE: eb14
Sep 27 20:39:24 r500 kernel: ahci_end_transaction: got AHCI_ERR_INVALID!
Sep 27 20:39:24 r500 kernel: ahci_end_transaction: op 12 dxfer_len 36 sense_len 18 sense_resid 0
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset...
Sep 27 20:39:24 r500 kernel: ahcich1: SATA connect time=1000us status=00000113
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device found
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): INQUIRY. CDB: 12 0 0 24 0 0 
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): CAM status: CCB request was invalid
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device ready after 200ms
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): SIGNATURE: eb14
Sep 27 20:39:24 r500 kernel: ahci_end_transaction: got AHCI_ERR_INVALID!
Sep 27 20:39:24 r500 kernel: ahci_end_transaction: op 12 dxfer_len 36 sense_len 18 sense_resid 0
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset...
Sep 27 20:39:24 r500 kernel: ahcich1: SATA connect time=1000us status=00000113
Sep 27 20:39:24 r500 kernel: ahcich1: AHCI reset: device found
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): INQUIRY. CDB: 12 0 0 24 0 0 
Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): CAM status: CCB request was invalid
Sep 27 20:39:24 r500 kernel: pass0 at ahcich0 bus 0 scbus0 target 0 lun 0
Sep 27 20:39:24 r500 kernel: pass0: <HITACHI HTS543225L9SA00 FBEZC4EC> ATA-8 SATA 1.x device
Sep 27 20:39:24 r500 kernel: pass0: Serial Number 090509FB2F32LLEY6D8A
Sep 27 20:39:24 r500 kernel: pass0: 150.000MB/s transfers (SATA 1.x, UDMA5, PIO 8192bytes)
Sep 27 20:39:24 r500 kernel: pass0: Command Queueing enabled
Sep 27 20:39:24 r500 kernel: ada0 at ahcich0 bus 0 scbus0 target 0 lun 0
Sep 27 20:39:24 r500 kernel: GEOM: new disk ada0
Sep 27 20:39:24 r500 kernel: ada0: <HITACHI HTS543225L9SA00 FBEZC4EC> ATA-8 SATA 1.x device
Sep 27 20:39:24 r500 kernel: ada0: Serial Number 090509FB2F32LLEY6D8A
Sep 27 20:39:24 r500 kernel: ada0: 150.000MB/s transfers (SATA 1.x, UDMA5, PIO 8192bytes)
Sep 27 20:39:24 r500 kernel: ada0: Command Queueing enabled
Sep 27 20:39:24 r500 kernel: ada0: 238475MB (488397168 512 byte sectors: 16H 63S/T 16383C)
Sep 27 20:39:24 r500 kernel: ada0: Previously was known as ad4

Fabian
Received on Tue Sep 27 2011 - 17:46:08 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:40:18 UTC