Bug 9267

Summary: qla2xxx: driver initialization does not complete when booting with Port connected
Product: SCSI Drivers Reporter: Jan Brueckner (x01)
Component: QLOGIC QLA2XXXAssignee: Andrew Vasquez (andrew.vasquez)
Status: CLOSED OBSOLETE    
Severity: normal CC: alan
Priority: P1    
Hardware: All   
OS: Linux   
Kernel Version: 2.6.23.1 Subsystem:
Regression: No Bisected commit-id:

Description Jan Brueckner 2007-10-31 10:21:07 UTC 
Most recent kernel where this bug did not occur: unknown
Distribution: Debian Etch (x86)
Hardware Environment: Dual Opteron 246 on a Tyan K8SPro (S2882) with 4 GByte RAM, see below for details
Software Environment:
(gcc version 4.1.2 20061115 (prerelease) (Debian 4.1.1-21))

---
Product Qlogic: QLA2462
Bios: 1.24
FCode: 1.24
EFI: 1.08
Firmware: 4.0.0.26

The card is located on a separate PCI-Bus with no other devices sharing this bus.

Product Endpoint: Infortrend EonStor A16F-G2430
(Connected to Channel 0)
Settings: Loop only (as it is the only option given by EonStor)
Ch. 0 is assigned SCSI ID 0 (or any other up to 16)
A logical disk is exported to Ch. 0, ID 0 with LUN 0

Both endpoints detect 4GHz link propperly.
Qlogic Settings: Defaults for both ports.

+---------------+
|               |Ch.0        Port0 +------+
| EonStor       [<================>] HBA  |
|               |                  +------+
+---------------+

OS: Linux Kernel 2.6.23.1 (current stable)
qla2xxx: 8.02.00-k3
firmware: 4.0.0.27 (loaded)


Symptoms:

i) working situation
   - The connector on Port0 is _disconnected_ when booting the system
   - the system boots, loads the driver and the firmware
   - after the driver is loaded, the connector is plugged in to Port0 manually
   -> the device is propperly recognized 
   - subsequent unplugging / replugging (removing the scsi single device from the
     kernel first) works.

ii) not working situation
   - The connector on Port0 is _connected_ when booting the system, the RAID is
     ready
   - (the devices is propperly seen in Bios with <Alt-Q> )
   - the system boots, loads the driver and the firmware
   - right after qla2xxx "LOOP UP detected (4 Gbps)" recognition of any drive
     fails (relevant kernel messages attached)
   - subsequent unpluging / repluging  does not work either

   - when connected to HBA's Port1 instead of Port0 it sometimes works

Further observations, not necessarily having to do with the problem:

 - if only a single scsi id is assigned to EonStors Ch. 0 (say ID 2) the kernel
   recognizes the disk with target id 0 even if the scsi id given to Ch. 0
   is different (1, 2, 3, ...,)
   - the <Alt-Q> - Bios also lists the device with ID 0 

 - if two or more scsi id's are assigned to EonStors Ch. 0 (logical device is
   still exported to only one scsi id on that channel, say ID 2) the disk is
   propperly listed with that target id 2
   - in this case however the <Alt-Q> - Bios does not list anything when 
     scanning for devices.


It looks as if some initialization did not complete in case of failure ^^ an errorlog follows: (the captures still show qla2xxx V8.01.07-k7 from 2.6.22.9 but the described situation did not change in 2.6.23.X)

plain:
-------------------------Start----------------------------------------------------------
Oct  7 23:35:07 t-host kernel: ACPI: PCI Interrupt 0000:01:03.0[A] -> GSI 28 (level, low) -> IRQ 21
Oct  7 23:35:07 t-host kernel: qla2xxx 0000:01:03.0: Found an ISP2422, irq 21, iobase 0xf8cc8000
Oct  7 23:35:07 t-host kernel: qla2xxx 0000:01:03.0: Configuring PCI space...
Oct  7 23:35:07 t-host kernel: qla2xxx 0000:01:03.0: Configure NVRAM parameters...
Oct  7 23:35:07 t-host kernel: qla2xxx 0000:01:03.0: Verifying loaded RISC code...
Oct  7 23:35:07 t-host kernel: qla2xxx 0000:01:03.0: Allocated (64 KB) for EFT...
Oct  7 23:35:07 t-host kernel: qla2xxx 0000:01:03.0: Allocated (1413 KB) for firmware dump...
Oct  7 23:35:07 t-host kernel: scsi1 : qla2xxx
Oct  7 23:35:07 t-host kernel: qla2xxx 0000:01:03.0: 
Oct  7 23:35:07 t-host kernel:  QLogic Fibre Channel HBA Driver: 8.01.07-k7
Oct  7 23:35:07 t-host kernel:   QLogic QLA2462 - PCI-X 2.0 to 4Gb FC, Dual Channel
Oct  7 23:35:07 t-host kernel:   ISP2422: PCI-X Mode 1 (133 MHz) @ 0000:01:03.0 hdma-, host#=1, fw=4.00.27 [IP] 
Oct  7 23:35:07 t-host kernel: ACPI: PCI Interrupt 0000:01:03.1[B] -> GSI 29 (level, low) -> IRQ 22
Oct  7 23:35:07 t-host kernel: qla2xxx 0000:01:03.1: Found an ISP2422, irq 22, iobase 0xf8cf4000
Oct  7 23:35:07 t-host kernel: qla2xxx 0000:01:03.1: Configuring PCI space...
Oct  7 23:35:07 t-host kernel: qla2xxx 0000:01:03.1: Configure NVRAM parameters...
Oct  7 23:35:07 t-host kernel: qla2xxx 0000:01:03.1: Verifying loaded RISC code...
Oct  7 23:35:07 t-host kernel: qla2xxx 0000:01:03.1: Allocated (64 KB) for EFT...
Oct  7 23:35:07 t-host kernel: qla2xxx 0000:01:03.1: Allocated (1413 KB) for firmware dump...
Oct  7 23:35:07 t-host kernel: scsi2 : qla2xxx
Oct  7 23:35:07 t-host kernel: qla2xxx 0000:01:03.1: 
Oct  7 23:35:07 t-host kernel:  QLogic Fibre Channel HBA Driver: 8.01.07-k7
Oct  7 23:35:07 t-host kernel:   QLogic QLA2462 - PCI-X 2.0 to 4Gb FC, Dual Channel
Oct  7 23:35:07 t-host kernel:   ISP2422: PCI-X Mode 1 (133 MHz) @ 0000:01:03.1 hdma-, host#=2, fw=4.00.27 [IP] 
Oct  7 23:35:07 t-host kernel: qla2xxx 0000:01:03.0: LIP reset occured (f8f7).
Oct  7 23:35:07 t-host kernel: qla2xxx 0000:01:03.0: LIP occured (f8f7).
Oct  7 23:35:07 t-host kernel: qla2xxx 0000:01:03.0: LOOP UP detected (4 Gbps).
Oct  7 23:35:07 t-host kernel: ohci_hcd 0000:03:00.0: auto-stop root hub
Oct  7 23:35:07 t-host kernel: ohci_hcd 0000:03:00.1: auto-stop root hub
Oct  7 23:35:07 t-host kernel: scsi 1:0:0:0: Direct-Access     transtec PV610F16R1C      348B PQ: 0 ANSI: 4
Oct  7 23:35:07 t-host kernel: kobject_add failed for 1:0:0:0 with -EEXIST, don't try to register things with the same name in the same directory.
Oct  7 23:35:07 t-host kernel:  [<c022c841>] kobject_shadow_add+0x111/0x190
Oct  7 23:35:07 t-host kernel:  [<c0286814>] device_add+0xc4/0x570
Oct  7 23:35:07 t-host kernel:  [<c02c90ce>] scsi_adjust_queue_depth+0x9e/0xf0
Oct  7 23:35:07 t-host kernel:  [<c02249b2>] __blk_queue_init_tags+0x32/0x70
Oct  7 23:35:07 t-host kernel:  [<c02d302f>] scsi_sysfs_add_sdev+0x4f/0x230
Oct  7 23:35:07 t-host kernel:  [<f8d93421>] qla2xxx_slave_configure+0x71/0x100 [qla2xxx]
Oct  7 23:35:07 t-host kernel:  [<c02d0ecf>] scsi_probe_and_add_lun+0xa5f/0xb40
Oct  7 23:35:07 t-host kernel:  [<c02d1559>] __scsi_scan_target+0xd9/0x6c0
Oct  7 23:35:07 t-host kernel:  [<c03a5be1>] schedule+0x2e1/0x950
Oct  7 23:35:07 t-host kernel:  [<c02d21f9>] scsi_scan_target+0xa9/0xe0
Oct  7 23:35:07 t-host kernel:  [<c02d5640>] fc_scsi_scan_rport+0x0/0x80
Oct  7 23:35:07 t-host kernel:  [<c02d56a9>] fc_scsi_scan_rport+0x69/0x80
Oct  7 23:35:07 t-host kernel:  [<c012b032>] run_workqueue+0x72/0x100
Oct  7 23:35:07 t-host kernel:  [<c012e8d0>] prepare_to_wait+0x20/0x70
Oct  7 23:35:07 t-host kernel:  [<c012b8c0>] worker_thread+0x0/0x100
Oct  7 23:35:07 t-host kernel:  [<c012b964>] worker_thread+0xa4/0x100
Oct  7 23:35:07 t-host kernel:  [<c012e720>] autoremove_wake_function+0x0/0x50
Oct  7 23:35:07 t-host kernel:  [<c012b8c0>] worker_thread+0x0/0x100
Oct  7 23:35:07 t-host kernel:  [<c012e462>] kthread+0x42/0x70
Oct  7 23:35:07 t-host kernel:  [<c012e420>] kthread+0x0/0x70
Oct  7 23:35:07 t-host kernel:  [<c0103573>] kernel_thread_helper+0x7/0x14
Oct  7 23:35:07 t-host kernel:  =======================
Oct  7 23:35:07 t-host kernel: error 1
=========================END============================================================

with ql2xextended_error_logging=1
-------------------------Start----------------------------------------------------------
Oct  7 23:23:07 t-host kernel: QLogic Fibre Channel HBA Driver
Oct  7 23:23:07 t-host kernel: ACPI: PCI Interrupt 0000:01:03.0[A] -> GSI 28 (level, low) -> IRQ 21
Oct  7 23:23:07 t-host kernel: qla2xxx 0000:01:03.0: Found an ISP2422, irq 21, iobase 0xf8cf4000
Oct  7 23:23:07 t-host kernel: qla2xxx 0000:01:03.0: Configuring PCI space...
Oct  7 23:23:07 t-host kernel: qla2xxx 0000:01:03.0: Configure NVRAM parameters...
Oct  7 23:23:07 t-host kernel: qla2xxx 0000:01:03.0: Verifying loaded RISC code...
Oct  7 23:23:07 t-host kernel: scsi(5): **** Load RISC code ****
Oct  7 23:23:07 t-host kernel: scsi(5): Verifying Checksum of loaded RISC code.
Oct  7 23:23:07 t-host kernel: scsi(5): Checksum OK, start firmware.
Oct  7 23:23:07 t-host kernel: qla2xxx 0000:01:03.0: Allocated (64 KB) for EFT...
Oct  7 23:23:07 t-host kernel: qla2xxx 0000:01:03.0: Allocated (1413 KB) for firmware dump...
Oct  7 23:23:07 t-host kernel: scsi(5): Issue init firmware.
Oct  7 23:23:07 t-host kernel: DEBUG: detect hba 5 at address = f6d942f8
Oct  7 23:23:07 t-host kernel: scsi5 : qla2xxx
Oct  7 23:23:07 t-host kernel: BUG: unable to handle kernel NULL pointer dereference at virtual address 00000000
Oct  7 23:23:07 t-host kernel:  printing eip:
Oct  7 23:23:07 t-host kernel: 00000000
Oct  7 23:23:07 t-host kernel: *pde = 00000000
Oct  7 23:23:07 t-host kernel: Oops: 0000 [#1]
Oct  7 23:23:07 t-host kernel: SMP 
Oct  7 23:23:07 t-host kernel: Modules linked in: qla2xxx k8temp hwmon i2c_amd756 i2c_amd8111 i2c_core ohci_hcd usbcore thermal pro cessor fan
Oct  7 23:23:07 t-host kernel: CPU:    1
Oct  7 23:23:07 t-host kernel: EIP:    0060:[<00000000>]    Not tainted VLI
Oct  7 23:23:07 t-host kernel: EFLAGS: 00010246   (2.6.22.9-jb-lx1.007 #1)
Oct  7 23:23:07 t-host kernel: EIP is at run_init_process+0x3fefff40/0x20
Oct  7 23:23:07 t-host kernel: eax: f7c7d830   ebx: f7c7d830   ecx: f8db6424   edx: f6d940ec
Oct  7 23:23:07 t-host kernel: esi: 00000044   edi: f6d94000   ebp: f6d94258   esp: f6da7ce8
Oct  7 23:23:07 t-host kernel: ds: 007b   es: 007b   fs: 00d8  gs: 0033  ss: 0068
Oct  7 23:23:07 t-host kernel: Process modprobe (pid: 5720, ti=f6da6000 task=c3192a70 task.ti=f6da6000)
Oct  7 23:23:07 t-host kernel: Stack: c028bcbf 00008080 00000004 00000004 f6d941a4 c028be70 f6d940ec f728e840 
Oct  7 23:23:07 t-host kernel:        f6d940ec 00000044 f6d94000 f6d94258 c02d2dbd f6d940b1 f6d94000 00000000 
Oct  7 23:23:07 t-host kernel:        f6d940ec c02ca528 f6d940b1 00000014 c042dbdc 00000005 f6d94258 f6d954e4 
Oct  7 23:23:07 t-host kernel: Call Trace:
Oct  7 23:23:07 t-host kernel:  [<c028bcbf>] attribute_container_add_device+0x5f/0x130
Oct  7 23:23:07 t-host kernel:  [<c028be70>] transport_setup_classdev+0x0/0x30
Oct  7 23:23:07 t-host kernel:  [<c02d2dbd>] scsi_sysfs_add_host+0xfd/0x110
Oct  7 23:23:07 t-host kernel:  [<c02ca528>] scsi_add_host+0xd8/0x1c0
Oct  7 23:23:07 t-host kernel:  [<f8d92aed>] qla2x00_probe_one+0xbed/0x11a0 [qla2xxx]
Oct  7 23:23:07 t-host kernel:  [<c0115768>] __wake_up+0x38/0x50
Oct  7 23:23:07 t-host kernel:  [<c01a2a1f>] sysfs_make_dirent+0x2f/0x50
Oct  7 23:23:07 t-host kernel:  [<c01a399e>] sysfs_create_link+0x6e/0x160
Oct  7 23:23:07 t-host kernel:  [<c023e503>] pci_match_device+0x13/0xb0
Oct  7 23:23:07 t-host kernel:  [<c023e616>] pci_device_probe+0x56/0x80
Oct  7 23:23:07 t-host kernel:  [<c0288c92>] driver_probe_device+0x92/0x1a0
Oct  7 23:23:07 t-host kernel:  [<c03a5163>] klist_next+0x53/0xa0
Oct  7 23:23:07 t-host kernel:  [<c0288eea>] __driver_attach+0x7a/0x80
Oct  7 23:23:07 t-host kernel:  [<c028809a>] bus_for_each_dev+0x3a/0x60
Oct  7 23:23:07 t-host kernel:  [<c0288b06>] driver_attach+0x16/0x20
Oct  7 23:23:07 t-host kernel:  [<c0288e70>] __driver_attach+0x0/0x80
Oct  7 23:23:07 t-host kernel:  [<c028845a>] bus_add_driver+0x8a/0x1a0
Oct  7 23:23:07 t-host kernel:  [<c023e7c3>] __pci_register_driver+0x53/0xa0
Oct  7 23:23:07 t-host kernel:  [<f8cc708d>] qla2x00_module_init+0x8d/0xef [qla2xxx]
Oct  7 23:23:07 t-host kernel:  [<c013b4d1>] sys_init_module+0x151/0x1aa0
Oct  7 23:23:07 t-host kernel:  [<c022d60f>] prio_tree_insert+0x1f/0x240
Oct  7 23:23:07 t-host kernel:  [<c015585a>] do_mmap_pgoff+0x58a/0x7d0
Oct  7 23:23:07 t-host kernel:  [<c01029ba>] syscall_call+0x7/0xb
Oct  7 23:23:07 t-host kernel:  =======================
Oct  7 23:23:07 t-host kernel: Code:  Bad EIP value.
Oct  7 23:23:07 t-host kernel: EIP: [<00000000>] run_init_process+0x3fefff40/0x20 SS:ESP 0068:f6da7ce8
Oct  7 23:23:07 t-host kernel: scsi(5): Asynchronous LIP RESET (f8f7).
Oct  7 23:23:07 t-host kernel: qla2xxx 0000:01:03.0: LIP reset occured (f8f7).
Oct  7 23:23:07 t-host kernel: scsi(5): LIP occured (f8f7).
Oct  7 23:23:07 t-host kernel: qla2xxx 0000:01:03.0: LIP occured (f8f7).
Oct  7 23:23:07 t-host kernel: scsi(5): Asynchronous LOOP UP (4 Gbps).
Oct  7 23:23:07 t-host kernel: qla2xxx 0000:01:03.0: LOOP UP detected (4 Gbps).
Oct  7 23:23:07 t-host kernel: scsi(5): Asynchronous PORT UPDATE.
Oct  7 23:23:07 t-host kernel: scsi(5): Port database changed ffff 0006 0000.
Oct  7 23:23:08 t-host kernel: scsi(5): qla2x00_reset_marker()
Oct  7 23:23:08 t-host kernel: scsi(5): qla2x00_loop_resync()
Oct  7 23:23:08 t-host kernel: scsi(5): F/W Ready - OK 
Oct  7 23:23:08 t-host kernel: scsi(5): fw_state=3 curr time=16a2.
Oct  7 23:23:08 t-host kernel: scsi(5): Configure loop -- dpc flags =0x4080060
Oct  7 23:23:08 t-host kernel: qla2xxx 0000:01:03.0: iIDMA adjusted to 4 GB/s on 210000d023200001.
Oct  7 23:23:08 t-host kernel: ERROR: FC host 'qla2xxx' attempted to flush work, when no workqueue created.
Oct  7 23:23:08 t-host kernel:  [<c02d70e1>] fc_remote_port_add+0x31/0x400
Oct  7 23:23:08 t-host kernel:  [<c028cf20>] dma_pool_free+0xc0/0x140
Oct  7 23:23:08 t-host kernel:  [<f8d9436c>] qla2x00_update_fcport+0x38c/0x520 [qla2xxx]
Oct  7 23:23:08 t-host kernel:  [<f8d94d0a>] qla2x00_configure_loop+0x77a/0x1640 [qla2xxx]
Oct  7 23:23:08 t-host kernel:  [<c0277910>] vt_console_print+0x0/0x2b0
Oct  7 23:23:08 t-host kernel:  [<c011c3b1>] __call_console_drivers+0x51/0x60
Oct  7 23:23:08 t-host kernel:  [<f8d9aa50>] qla2x00_get_firmware_state+0x40/0x90 [qla2xxx]
Oct  7 23:23:08 t-host kernel:  [<f8d971af>] qla2x00_loop_resync+0xaf/0xe0 [qla2xxx]
Oct  7 23:23:08 t-host kernel:  [<c011ccdb>] printk+0x1b/0x20
Oct  7 23:23:08 t-host kernel:  [<f8d91bed>] qla2x00_do_dpc+0x36d/0x540 [qla2xxx]
Oct  7 23:23:08 t-host kernel:  [<c01156af>] complete+0x3f/0x60
Oct  7 23:23:08 t-host kernel:  [<f8d91880>] qla2x00_do_dpc+0x0/0x540 [qla2xxx]
Oct  7 23:23:08 t-host kernel:  [<c012e462>] kthread+0x42/0x70
Oct  7 23:23:08 t-host kernel:  [<c012e420>] kthread+0x0/0x70
Oct  7 23:23:08 t-host kernel:  [<c0103573>] kernel_thread_helper+0x7/0x14
Oct  7 23:23:08 t-host kernel:  =======================
Oct  7 23:23:08 t-host kernel: BUG: unable to handle kernel NULL pointer dereference at virtual address 00000000
Oct  7 23:23:08 t-host kernel:  printing eip:
Oct  7 23:23:08 t-host kernel: c02d70fe
Oct  7 23:23:08 t-host kernel: *pde = 00000000
Oct  7 23:23:08 t-host kernel: Oops: 0000 [#2]
Oct  7 23:23:08 t-host kernel: SMP 
Oct  7 23:23:08 t-host kernel: Modules linked in: qla2xxx k8temp hwmon i2c_amd756 i2c_amd8111 i2c_core ohci_hcd usbcore thermal pro cessor fan
Oct  7 23:23:08 t-host kernel: CPU:    1
Oct  7 23:23:08 t-host kernel: EIP:    0060:[<c02d70fe>]    Not tainted VLI
Oct  7 23:23:08 t-host kernel: EFLAGS: 00010046   (2.6.22.9-jb-lx1.007 #1)
Oct  7 23:23:08 t-host kernel: EIP is at fc_remote_port_add+0x4e/0x400
Oct  7 23:23:08 t-host kernel: eax: 00000000   ebx: 00000000   ecx: f6d94000   edx: f7fc9400
Oct  7 23:23:08 t-host kernel: esi: 23000000   edi: 21000000   ebp: ffffffc0   esp: f784fdb4
Oct  7 23:23:08 t-host kernel: ds: 007b   es: 007b   fs: 00d8  gs: 0000  ss: 0068
Oct  7 23:23:08 t-host kernel: Process qla2xxx_5_dpc (pid: 5730, ti=f784e000 task=c30fea70 task.ti=f784e000)
Oct  7 23:23:08 t-host kernel: Stack: 00000206 c028cf20 f784fe58 00000000 f6d94000 f79f5400 f7fc9400 00000292 
Oct  7 23:23:08 t-host kernel:        00000000 23000000 21000000 dfeb2940 f8d9436c f8dab130 f8dae8e5 dfc41900 
Oct  7 23:23:08 t-host kernel:        f8daecb7 00000021 00000000 00000000 000000d0 00000023 00000020 00000000 
Oct  7 23:23:08 t-host kernel: Call Trace:
Oct  7 23:23:08 t-host kernel: Call Trace:
Oct  7 23:23:08 t-host kernel:  [<c028cf20>] dma_pool_free+0xc0/0x140
Oct  7 23:23:08 t-host kernel:  [<f8d9436c>] qla2x00_update_fcport+0x38c/0x520 [qla2xxx]
Oct  7 23:23:08 t-host kernel:  [<f8d94d0a>] qla2x00_configure_loop+0x77a/0x1640 [qla2xxx]
Oct  7 23:23:08 t-host kernel:  [<c0277910>] vt_console_print+0x0/0x2b0
Oct  7 23:23:08 t-host kernel:  [<c011c3b1>] __call_console_drivers+0x51/0x60
Oct  7 23:23:08 t-host kernel:  [<f8d9aa50>] qla2x00_get_firmware_state+0x40/0x90 [qla2xxx]
Oct  7 23:23:08 t-host kernel:  [<f8d971af>] qla2x00_loop_resync+0xaf/0xe0 [qla2xxx]
Oct  7 23:23:08 t-host kernel:  [<c011ccdb>] printk+0x1b/0x20
Oct  7 23:23:08 t-host kernel:  [<f8d91bed>] qla2x00_do_dpc+0x36d/0x540 [qla2xxx]
Oct  7 23:23:08 t-host kernel:  [<c01156af>] complete+0x3f/0x60
Oct  7 23:23:08 t-host kernel:  [<f8d91880>] qla2x00_do_dpc+0x0/0x540 [qla2xxx]
Oct  7 23:23:08 t-host kernel:  [<c012e462>] kthread+0x42/0x70
Oct  7 23:23:08 t-host kernel:  [<c012e420>] kthread+0x0/0x70
Oct  7 23:23:08 t-host kernel:  [<c0103573>] kernel_thread_helper+0x7/0x14
Oct  7 23:23:08 t-host kernel:  =======================
Oct  7 23:23:08 t-host kernel: Code: 92 f4 02 00 00 89 54 24 18 e8 2f dc ff ff 8b 4c 24 10 8b 41 2c e8 a3 09 0d 00 8b 54 24 18 89 44 24 1c 8b 82 d0 02 00 00 8d 68 c0 <8b> 7d 40 0f 18 07 90 81 c2 d0 02 00 00 39 d0 89 14 24 0f 84 69 
Oct  7 23:23:08 t-host kernel: EIP: [<c02d70fe>] fc_remote_port_add+0x4e/0x400 SS:ESP 0068:f784fdb4
=========================END============================================================