isp(4) - kernel panic on initialization of driver

Wed Aug 27 15:27:53 UTC 2008

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: <Qlogic ISP 2432 PCI FC-AL Adapter> 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: <Qlogic ISP 2432 PCI FC-AL Adapter> 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 <Config Wait->Ready>
isp1: Firmware State <Config Wait->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: <HP HSV200 6110> 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: <HP HSV200 6110> 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: <HP HSV200 6110> 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: <HP HSV200 6110> 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

-- 