From owner-freebsd-current@FreeBSD.ORG Tue Sep 27 19:46:08 2011 Return-Path: Delivered-To: freebsd-current@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id A6D91106564A; Tue, 27 Sep 2011 19:46:08 +0000 (UTC) (envelope-from freebsd-listen@fabiankeil.de) Received: from smtprelay01.ispgateway.de (smtprelay01.ispgateway.de [80.67.31.35]) by mx1.freebsd.org (Postfix) with ESMTP id 1EDCD8FC08; Tue, 27 Sep 2011 19:46:07 +0000 (UTC) Received: from [78.34.155.34] (helo=fabiankeil.de) by smtprelay01.ispgateway.de with esmtpsa (TLSv1:AES128-SHA:128) (Exim 4.68) (envelope-from ) id 1R8dbS-0002qo-7H; Tue, 27 Sep 2011 21:46:06 +0200 Date: Tue, 27 Sep 2011 21:46:03 +0200 From: Fabian Keil To: "Kenneth D. Merry" Message-ID: <20110927214603.427e6992@fabiankeil.de> In-Reply-To: <20110926225842.GA88443@nargothrond.kdm.org> References: <20110922193305.GA24939@nargothrond.kdm.org> <20110924212722.4ce229e9@fabiankeil.de> <20110926225842.GA88443@nargothrond.kdm.org> Mime-Version: 1.0 Content-Type: multipart/signed; micalg=PGP-SHA1; boundary="Sig_/BkW9mtLYPW0bkeFNxJVT/ms"; protocol="application/pgp-signature" X-Df-Sender: Nzc1MDY3 Cc: freebsd-current@freebsd.org Subject: Re: SCSI descriptor sense changes, testing needed X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 27 Sep 2011 19:46:08 -0000 --Sig_/BkW9mtLYPW0bkeFNxJVT/ms Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: quoted-printable "Kenneth D. Merry" wrote: > On Sat, Sep 24, 2011 at 21:27:22 +0200, Fabian Keil wrote: > > "Kenneth D. Merry" wrote: > >=20 > > > I have attached a set of patches against head that implement SCSI > > > descriptor sense support for CAM. > >=20 > > > 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 wou= ld > > > be better to find them now. :) > >=20 > > 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. > >=20 > > I didn't notice it while using the patch, but it looks like the > > kernel wasn't able to pick up cd0 anymore: >=20 > Hmm. I don't think any of the changes would have caused this, but > evidently something did... >=20 > Let's see if we can debug it... >=20 > I have attached a patch to add some debugging output, and I see at least > one interesting thing in the logs below. >=20 > 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=3D900us status=3D00= 000113 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=3D1000us status=3D0= 0000113 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: at usbus0 Sep 27 20:39:24 r500 kernel: uhub0: on usbus0 Sep 27 20:39:24 r500 kernel: ugen1.1: at usbus1 Sep 27 20:39:24 r500 kernel: uhub1: on usbus1 Sep 27 20:39:24 r500 kernel: ugen2.1: at usbus2 Sep 27 20:39:24 r500 kernel: uhub2: on usbus2 Sep 27 20:39:24 r500 kernel: ugen3.1: at usbus3 Sep 27 20:39:24 r500 kernel: uhub3: on usbus3 Sep 27 20:39:24 r500 kernel: ugen4.1: at usbus4 Sep 27 20:39:24 r500 kernel: uhub4: on usbus4 Sep 27 20:39:24 r500 kernel: ugen5.1: at usbus5 Sep 27 20:39:24 r500 kernel: uhub5: on usbus5 Sep 27 20:39:24 r500 kernel: ugen6.1: at usbus6 Sep 27 20:39:24 r500 kernel: uhub6: on usbus6 Sep 27 20:39:24 r500 kernel: ugen7.1: at usbus7 Sep 27 20:39:24 r500 kernel: uhub7: 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=3D1000us status=3D0= 0000113 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=20 Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): CAM status: CCB reque= st 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=3D1000us status=3D0= 0000113 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=20 Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): CAM status: CCB reque= st 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=3D1000us status=3D0= 0000113 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=20 Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): CAM status: CCB reque= st 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=3D1000us status=3D0= 0000113 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=20 Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): CAM status: CCB reque= st 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=3D1000us status=3D0= 0000113 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=20 Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): CAM status: CCB reque= st 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=3D1000us status=3D0= 0000113 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=20 Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): CAM status: CCB reque= st 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=3D1000us status=3D0= 0000113 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=20 Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): CAM status: CCB reque= st 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=3D1000us status=3D0= 0000113 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=20 Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): CAM status: CCB reque= st 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=3D1000us status=3D0= 0000113 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=20 Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): CAM status: CCB reque= st 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=3D1000us status=3D0= 0000113 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=20 Sep 27 20:39:24 r500 kernel: (aprobe1:ahcich1:0:0:0): CAM status: CCB reque= st 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: 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: 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: 16= H 63S/T 16383C) Sep 27 20:39:24 r500 kernel: ada0: Previously was known as ad4 Fabian --Sig_/BkW9mtLYPW0bkeFNxJVT/ms Content-Type: application/pgp-signature; name=signature.asc Content-Disposition: attachment; filename=signature.asc -----BEGIN PGP SIGNATURE----- Version: GnuPG v2.0.18 (FreeBSD) iEYEARECAAYFAk6CJ/4ACgkQBYqIVf93VJ2CdwCfeDSkYbW+1Qra9h7zvBjRJNX9 CeoAoL+8hmy8gVSJTPBpPvCGbQX5Zcea =3/gT -----END PGP SIGNATURE----- --Sig_/BkW9mtLYPW0bkeFNxJVT/ms--