From owner-freebsd-scsi@FreeBSD.ORG Wed Aug 27 15:27:53 2008 Return-Path: Delivered-To: freebsd-scsi@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id E0AB5106566C for ; Wed, 27 Aug 2008 15:27:52 +0000 (UTC) (envelope-from westr@connection.ca) Received: from nc-tor-mail2.connection.ca (nc-tor-mail2.connection.ca [205.207.122.27]) by mx1.freebsd.org (Postfix) with ESMTP id A4CBC8FC08 for ; Wed, 27 Aug 2008 15:27:52 +0000 (UTC) (envelope-from westr@connection.ca) Received: from localhost (external.tor.connection.ca [216.234.38.18]) by nc-tor-mail2.connection.ca (Postfix) with ESMTP id 8E87B74E5C8 for ; Wed, 27 Aug 2008 11:27:51 -0400 (EDT) Date: Wed, 27 Aug 2008 11:27:51 -0400 From: Ross Organization: Network Connection X-Priority: 3 (Normal) Message-ID: <86689256.20080827112751@connection.ca> To: freebsd-scsi@freebsd.org In-Reply-To: <3c0b01820808270743n5fd40995u6e9506b772f2b03c@mail.gmail.com> References: <13710393234.20080826164158@connection.ca> <48B46EE1.8060408@samsco.org> <3c0b01820808270743n5fd40995u6e9506b772f2b03c@mail.gmail.com> MIME-Version: 1.0 Content-Type: text/plain; charset=iso-8859-1 Content-Transfer-Encoding: 8bit Subject: Re[2]: isp(4) - kernel panic on initialization of driver X-BeenThere: freebsd-scsi@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: Ross List-Id: SCSI subsystem List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 27 Aug 2008 15:27:53 -0000 AS> So one question I have is why doesn't the isp driver load the AS> firmware in ispfw? [...clip...] By any chance do you have AS> "hint.isp.0.fwload_disable" set? I'm not saying that will fix your AS> problem but I just noticed this. The card came with 4.00.90 which is newer than the firmware included in ispfw (4.00.20) - but to answer your question, yes, fwload_disable is set for the cards. I believe that got set since there was some kind of problem that we ran into at one point. I'll do some testing on that. AS> WARNING: this is pure speculation on my part from quickly looking at AS> it. I'm just wondering if this is a bug in isp allowing the ASYNC AS> events occuring before a complete attach has been performed. Apologies if it didn't come across in my previous message, that's basically what I'm saying too. I have about a 50/50 chance of the card booting successfully, and when it does, the output from the debug lines is different, and it looks like the ASYNC event is executing before it's time. (See the end of this message for the full output from isp[01]: for a clean boot, since it's a long output.) AS> Yes but its not clear to me the bug is REALLY in CAM...yet. It might AS> be ISP letting asynchronous events in before its really ready which AS> means its a driver problem. I have a 24xx card in the lab, maybe I AS> can test this if I get a chance too. That's what I'm assuming as well. AS> I'm assuming all you are doing is booting 7.0-RELEASE off the SAN? That is correct. We're just using the i386 image at the current time (eventually going to amd64, but not now). It's been trimmed of the fat, but nothing special/custom added in. AS> As Scott asked, can you get a dump or a trace of the crash? See my other message to freebsd-scsi/Scott for that. Thanks for looking at the issue! Ross. -= start of clean boot output. isp0: port 0x4000-0x40ff mem 0xfdff0000-0xfdff3fff irq 18 at device 0.0 on pci16 isp0: set PCI latency to 64 isp0: [ITHREAD] isp0: Board Type 2422, Chip Revision 0x2, resident F/W Revision 4.0.90 isp0: 2K Logins Supported isp0: Last F/W revision was 4.0.90 isp0: 4096 max I/O command limit set isp0: line 1207: markportdb isp0: Starting Initial Loop Down Timer isp1: port 0x4400-0x44ff mem 0xfdfe0000-0xfdfe3fff irq 19 at device 0.1 on pci16 isp1: set PCI latency to 64 isp1: [ITHREAD] isp1: Board Type 2422, Chip Revision 0x2, resident F/W Revision 4.0.90 isp1: 2K Logins Supported isp1: Last F/W revision was 4.0.90 isp1: 4096 max I/O command limit set isp1: line 1207: markportdb isp1: Starting Initial Loop Down Timer ... [other driver startup and then eventually we get] ... isp0: line 5271: markportdb isp0: LIP Received isp1: line 5271: markportdb isp1: LIP Received isp0: line 5333: markportdb isp0: LOOP Reset isp1: line 5333: markportdb isp1: LOOP Reset isp0: line 5271: markportdb isp0: LIP Received isp1: line 5271: markportdb isp1: LIP Received isp0: line 5271: markportdb isp0: LIP Received isp1: line 5271: markportdb isp1: LIP Received isp0: line 5333: markportdb isp0: LOOP Reset isp1: line 5333: markportdb isp1: LOOP Reset isp0: line 5360: markportdb isp0: Stopping Loop Down Timer isp0: Other Change Notify isp0: Point-to-Point mode isp1: line 5360: markportdb isp1: Stopping Loop Down Timer isp1: Other Change Notify isp1: Point-to-Point mode isp0: line 5307: markportdb isp0: Loop UP isp1: line 5307: markportdb isp1: Loop UP isp0: line 5345: markportdb isp0: Port Database Changed isp1: line 5345: markportdb isp1: Port Database Changed isp0: line 5345: markportdb isp0: Port Database Changed isp1: line 5345: markportdb isp1: Port Database Changed isp0: line 5345: markportdb isp0: Port Database Changed isp1: line 5345: markportdb isp1: Port Database Changed isp0: isp_kthread: checking FC state isp0: FC Link Test Entry isp0: line 2460: markportdb isp1: isp_kthread: checking FC state isp1: FC Link Test Entry isp1: line 2460: markportdb isp0: Firmware State Ready> isp1: Firmware State Ready> isp1: Register FC4 Type accepted isp0: Register FC4 Type accepted isp1: 4Gb link speed/s isp1: HBA PortID 0x030100 N-Port Handle 0, Connection Topology 'F Port' isp1: HBA WWNN 0x5001438002211547 HBA WWPN 0x5001438002211546 isp1: FC Link Test Complete isp1: FC Scan Fabric isp0: 4Gb link speed/s isp0: HBA PortID 0x020100 N-Port Handle 0, Connection Topology 'F Port' isp0: HBA WWNN 0x5001438002211545 HBA WWPN 0x5001438002211544 isp0: FC Link Test Complete isp0: FC Scan Fabric isp1: got 12 ports back from name server isp1: skip ourselves @ PortID 0x030100 isp1: Checking Fabric Port 0x030200 isp0: got 13 ports back from name server isp0: skip ourselves @ PortID 0x020100 isp0: Checking Fabric Port 0x020200 isp1: Fabric Port 0x030200 is New Entry isp1: Checking Fabric Port 0x030300 isp0: Fabric Port 0x020200 is New Entry isp0: Checking Fabric Port 0x020300 isp1: Fabric Port 0x030300 is New Entry isp1: Checking Fabric Port 0x030d00 isp0: Fabric Port 0x020300 is New Entry isp0: Checking Fabric Port 0x020d00 isp1: Fabric Port 0x030d00 is New Entry isp1: Checking Fabric Port 0x030e00 isp0: Fabric Port 0x020d00 is New Entry isp0: Checking Fabric Port 0x020e00 isp1: Fabric Port 0x030e00 is New Entry isp1: Checking Fabric Port 0x031000 isp1: Fabric Port 0x031100 is New Entry isp1: Checking Fabric Port 0x050100 isp0: Fabric Port 0x021100 is New Entry isp0: Checking Fabric Port 0x040100 isp1: Fabric Port 0x050100 is New Entry isp1: Checking Fabric Port 0x050200 isp0: Fabric Port 0x040100 is New Entry isp0: Checking Fabric Port 0x040200 isp1: Fabric Port 0x050200 is New Entry isp1: Checking Fabric Port 0x050800 isp0: Fabric Port 0x040200 is New Entry isp0: Checking Fabric Port 0x040800 isp1: Fabric Port 0x050800 is New Entry isp1: Checking Fabric Port 0x050e00 isp0: Fabric Port 0x040800 is New Entry isp0: Checking Fabric Port 0x040e00 isp1: Fabric Port 0x050e00 is New Entry isp1: Checking Fabric Port 0x051100 isp0: Fabric Port 0x040e00 is New Entry isp0: Checking Fabric Port 0x041100 isp1: Fabric Port 0x051100 is New Entry isp1: FC Scan Fabric Done isp1: Synchronizing PDBs isp1: PortID 0x030200 handle 0x1 role Initiator arrived WWNN 0x5001438001fff1df WWPN 0x5001438001fff1de isp1: PortID 0x030300 handle 0x2 role Initiator arrived WWNN 0x5001438002211a1f WWPN 0x5001438002211a1e isp1: PortID 0x030d00 handle 0x3 role Initiator arrived WWNN 0x5001438001fff22f WWPN 0x5001438001fff22e isp1: PortID 0x030e00 handle 0x4 role Initiator arrived WWNN 0x50014380022110c7 WWPN 0x50014380022110c6 isp1: PortID 0x031000 handle 0x5 role Initiator arrived WWNN 0x5001438001fff22b WWPN 0x5001438001fff22a isp1: PortID 0x031100 handle 0x6 role Target arrived at tgt 0 WWNN 0x50001fe150103510 WWPN 0x50001fe15010351d isp1: PortID 0x050100 handle 0x7 role Initiator arrived WWNN 0x5001438002211a6f WWPN 0x5001438002211a6e isp1: PortID 0x050200 handle 0x8 role Initiator arrived WWNN 0x5001438002211aab WWPN 0x5001438002211aaa isp1: PortID 0x050800 handle 0x9 role Initiator arrived WWNN 0x5001438002211a9b WWPN 0x5001438002211a9a isp1: PortID 0x050e00 handle 0xa role Initiator arrived WWNN 0x5001438001fff267 WWPN 0x5001438001fff266 isp1: PortID 0x051100 handle 0xb role Target arrived at tgt 1 WWNN 0x50001fe150103510 WWPN 0x50001fe150103518 isp1: PortID 0xfffffe handle 0x7fe role (none) stayed WWNN 0x100000051e092a5e WWPN 0x200100051e092a5e isp1: isp_kthread: FC state OK isp1: isp_kthread: releasing simq isp1: isp_kthread: sleep time 0 isp0: Fabric Port 0x041100 is New Entry isp0: Checking Fabric Port 0x041300 isp0: Fabric Port 0x041300 is New Entry isp0: FC Scan Fabric Done isp0: Synchronizing PDBs isp0: PortID 0x020200 handle 0x1 role Initiator arrived WWNN 0x5001438001fff1dd WWPN 0x5001438001fff1dc isp0: PortID 0x020300 handle 0x2 role Initiator arrived WWNN 0x5001438002211a1d WWPN 0x5001438002211a1c isp0: PortID 0x020d00 handle 0x3 role Initiator arrived WWNN 0x5001438001fff22d WWPN 0x5001438001fff22c isp0: PortID 0x020e00 handle 0x4 role Initiator arrived WWNN 0x50014380022110c5 WWPN 0x50014380022110c4 isp0: PortID 0x021000 handle 0x5 role Initiator arrived WWNN 0x5001438001fff229 WWPN 0x5001438001fff228 isp0: PortID 0x021100 handle 0x6 role Target arrived at tgt 0 WWNN 0x50001fe150103510 WWPN 0x50001fe150103519 isp0: PortID 0x040100 handle 0x7 role Initiator arrived WWNN 0x5001438002211a6d WWPN 0x5001438002211a6c isp0: PortID 0x040200 handle 0x8 role Initiator arrived WWNN 0x5001438002211aa9 WWPN 0x5001438002211aa8 isp0: PortID 0x040800 handle 0x9 role Initiator arrived WWNN 0x5001438002211a99 WWPN 0x5001438002211a98 isp0: PortID 0x040e00 handle 0xa role Initiator arrived WWNN 0x5001438001fff265 WWPN 0x5001438001fff264 isp0: PortID 0x041100 handle 0xb role Target arrived at tgt 1 WWNN 0x50001fe150103510 WWPN 0x50001fe15010351c isp0: PortID 0x041300 handle 0xc role Initiator arrived WWNN 0x200000e08b8b962d WWPN 0x210000e08b8b962d isp0: PortID 0xfffffe handle 0x7fe role (none) stayed WWNN 0x100000051e092a7c WWPN 0x200100051e092a7c isp0: isp_kthread: FC state OK isp0: isp_kthread: releasing simq isp0: isp_kthread: sleep time 0 da0 at isp0 bus 0 target 0 lun 1 da0: Fixed Direct Access SCSI-5 device da0: 400.000MB/s transfers da0: Command Queueing Enabled da0: 51200MB (104857600 512 byte sectors: 255H 63S/T 6527C) da1 at isp0 bus 0 target 1 lun 1 da1: Fixed Direct Access SCSI-5 device da1: 400.000MB/s transfers WWNN 0x5001438002211a1d WWPN 0x5001438002211a1c PortID 0x20300 da1: Command Queueing Enabled da1: 51200MB (104857600 512 byte sectors: 255H 63S/T 6527C) da2 at isp1 bus 0 target 0 lun 1 da2: Fixed Direct Access SCSI-5 device da2: 400.000MB/s transfers da2: Command Queueing Enabled da2: 51200MB (104857600 512 byte sectors: 255H 63S/T 6527C) da3 at isp1 bus 0 target 1 lun 1 da3: Fixed Direct Access SCSI-5 device da3: 400.000MB/s transfers WWNN 0x5001438002211a1f WWPN 0x5001438002211a1e PortID 0x30300 da3: Command Queueing Enabled da3: 51200MB (104857600 512 byte sectors: 255H 63S/T 6527C) GEOM_MULTIPATH: adding da0 to bootsys/cdbc7869-2d76-11dd-8fe6-001e0bc7e1d0 GEOM_MULTIPATH: da0 now active path in bootsys SMP: AP CPU #1 Launched! SMP: AP CPU #3 Launched! SMP: AP CPU #2 Launched! GEOM_MULTIPATH: adding da1 to bootsys/cdbc7869-2d76-11dd-8fe6-001e0bc7e1d0 GEOM_MULTIPATH: adding da2 to bootsys/cdbc7869-2d76-11dd-8fe6-001e0bc7e1d0 GEOM_MULTIPATH: adding da3 to bootsys/cdbc7869-2d76-11dd-8fe6-001e0bc7e1d0 Trying to mount root from ufs:/dev/multipath/bootsyss1a [... successful boot at this point ...] -= end --