FCoE CNA - Solaris 10 Panic Due to qlge Driver

Asset ID:	1-72-1931097.1
Update Date:	2018-03-07
Keywords:

Solution Type Problem Resolution Sure

Solution 1931097.1 : FCoE CNA - Solaris 10 Panic Due to qlge Driver - mutex_enter: bad mutex

Applies to:

SPARC T4-4 - Version Not Applicable and later
Sun Storage FCoE CNA - Version Not Applicable and later
Qlogic FC HBA - Version Not Applicable and later
Solaris SPARC Operating System - Version 8.0 and later
Information in this document applies to any platform.

Symptoms

Solaris 10 server boot and with no other action get panic like this:

Sep 13 02:37:31 server01 qlge: [ID 463881 kern.info] NOTICE: tx_ring 8, size 1024, rss_ring 8, size 1024
Sep 13 02:37:31 server01 qlge: [ID 128846 kern.info] NOTICE: qlge(2) intr available 16, request 16, actual 16
Sep 13 02:37:31 server01 qlge: [ID 798029 kern.info] NOTICE: qlge(2) tx 8, rss 8, stride 0
Sep 13 02:37:37 server01 px: [ID 952403 kern.warning] WARNING: px1: px_ib_ino_add_intr: pending sysino 0x509(ino 0x9) timeout
Sep 13 02:37:37 server01 unix: [ID 836849 kern.notice]
Sep 13 02:37:37 server01 ^Mpanic[cpu5]/thread=30087622b20:
Sep 13 02:37:37 server01 unix: [ID 103648 kern.notice] mutex_enter: bad mutex, lp=3007df51a00 owner=30087622b20 thread=30087622b20
Sep 13 02:37:37 server01 unix: [ID 100000 kern.notice]
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f666f0 qlge:ql_refill_lbuf_free_list+18 (3007df51a00, 1, 4, ff00, 0, 3007df518b0) <<--- the key here is qlge function
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 00000000bfffffff 0000000000000000 0000000087622b20 0000030062fbc000
Sep 13 02:37:37 server01 %l4-7: 000003007df24000 0000000000000001 0000000000003fff 0000000000000000
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f667a0 genunix:dblk_lastfree_desb+10 (300770fbec0, 300770de900, 1, f, 30066140340, 7b311c38)
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 0000000000000100 0000000000000020 000000000194af40 000000000194ac00
Sep 13 02:37:37 server01 %l4-7: 0000000000080000 0000000000000000 0000000000003006 0000000000003000
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f66850 genunix:freemsg+9c (0, 11bd070, 0, 1, 30012302000, 193c400)
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 0000000000000160 000000000000002c 000000000194af40 00000300770de900
Sep 13 02:37:37 server01 %l4-7: 0000000000000000 000000000193c730 0000000000000001 0000000000003000
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f66900 qlge:ql_free_lbq_buffers+58 (3007df518b0, 30004189cd0, 30062fbc000, 0, 400, 0)
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 0000000000000000 000003007df53e04 00000000000415bc 0000000000000000
Sep 13 02:37:37 server01 %l4-7: 0000000000000000 0000000000000001 0000000000000001 0000000000000001
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f669b0 qlge:ql_free_rx_buffers+48 (41400, 10, 3007df655bc, 415bc, 41400, 3007df24000)
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 000003007df518b0 0000000000000001 00000000000415bc 0000000000000004
Sep 13 02:37:37 server01 %l4-7: 0000000000000000 0000000000000000 000000000002d8b0 000000000002d800
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f66a60 qlge:ql_free_mem_resources+4c (3007df24000, 1400, 140, 3, 30072fd9b40, 3007df25480)
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 00000000000003f8 000000000000007f 000000000194af40 000000000194ac00
Sep 13 02:37:37 server01 %l4-7: 000003007df640b0 00000000000400b0 0000000000003006 0000000000001478
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f66b10 qlge:ql_free_resources+204 (3007df24000, 3007df25670, 1400, 0, 1670, 1400)
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 000003007df25678 0000000000001678 0000000000001400 000003007df2566c
Sep 13 02:37:37 server01 %l4-7: 000000000000166c 000003007df25678 0000000000001678 0000000000000080
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f66bc0 qlge:ql_attach+798 (0, 0, 3007df24000, ffffffffffffffff, 0, 0)
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 000000007b329400 0000000000000000 0000000000000000 0000000000000000
Sep 13 02:37:37 server01 %l4-7: 00000000000015d8 0000000000001528 000000007b329400 000000007b329400
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f66c80 genunix:devi_attach+ac (30004189cd0, 0, 300029d6810, 300029ce000, 0, 7b31b228)
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 00000300028c99b8 0000000000000137 0000000001937978 0000000000008810
Sep 13 02:37:37 server01 %l4-7: 00000300028c9000 00000000000009b8 0000000000000004 0000000000000003
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f66d50 genunix:attach_node+9c (30004189cd0, 1, 0, 0, 0, 30004189d38)
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 0000000000000003 00000000019d8400 0000060026a671a0 00000000fffeffff
Sep 13 02:37:37 server01 %l4-7: 00000000fffefc00 0000000050010000 0000000010000000 0000000040010000
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f66e00 genunix:i_ndi_config_node+110 (30004189cd0, 11c, 1102908, 10, 1937c00, 1102800)
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 0000000000000000 0000000000000006 0000000001937c40 0000000000000000
Sep 13 02:37:37 server01 %l4-7: 0000000001937c00 00000000019d7da0 0000000000003006 0000000000000004
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f66eb0 genunix:i_ddi_attachchild+38 (30004189cd0, 30087622b20, 0, 0, 0, 10000000)
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 000003000418c2f0 0000000000000001 000003000418c2f0 0000000000000000
Sep 13 02:37:37 server01 %l4-7: 0000000000000001 000000000190d400 00000300001201b0 0000030000120340
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f66f60 genunix:devi_attach_node+84 (30004189cd0, 4000, 2a103f67539, 30004189d38, 4000, 10000000)
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 000003000418c2f0 0000000000000011 0000000000000100 0000000000000000
Sep 13 02:37:37 server01 %l4-7: 0000000000000001 0000000000000001 0000000000000004 0000000000000010
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f67010 genunix:devi_config_one+300 (3000418c288, 2, 0, 0, 0, 0)
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 0000000000004000 000002a103f67539 0000030004189cd0 0000000000000040
Sep 13 02:37:37 server01 %l4-7: 0000000000000000 000003000418c2f0 0000000000000000 0000000000000068
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f670f0 genunix:ndi_devi_config_one+d8 (3000418c288, 2a103f67530, 2a103f67270, 4000, 3a000000, 4000)
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 0000000000000000 000000000000000b 000003007f48f958 0000000000000000
Sep 13 02:37:37 server01 %l4-7: 0000000000004000 0000000000000000 0000000000000000 0000060021523840
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f671a0 devfs:dv_find+1f0 (3008765a8b0, 2a103f67530, 2a103f67528, 4000, 60021523840, 30083501048)
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 000003008765a8c8 0000000000000000 0000000000000001 0000000000000000
Sep 13 02:37:37 server01 %l4-7: 000003000418c288 000000000190d458 00000000019a52a8 000002a103f6753a
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f67280 devfs:devfs_lookup+1c (3008763b5c0, 2a103f67530, 2a103f67528, 2a103f677f0, 0, 60021523840)
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 0000000000000038 0000000000000007 000000000194af40 000000000194ac00
Sep 13 02:37:37 server01 %l4-7: 0000060021523240 0000000000000000 0000000000003006 0000000000003000
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f67340 genunix:fop_lookup+28 (3008763b5c0, 2a103f67530, 2a103f67528, 12bb5f0, 0, 6002156ad80)
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 0000060021602b00 0000000000000000 0000000000002000 00000000000c5ac1
Sep 13 02:37:37 server01 %l4-7: 00000000000ccbed 00000000000ccbec 000003003faf88a8 0000060021532578
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f67400 genunix:lookuppnvp+354 (2a103f677f0, 0, 0, 2a103f67528, 2a103f67530, 60021523840)
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 000000000198e5b0 000003008763b5c0 0000000000000001 0000000000000000
Sep 13 02:37:37 server01 %l4-7: 0000030083501048 0000060021523840 0000000000000001 0000000000000002
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f67640 genunix:lookuppnat+120 (60021523840, 0, 1, 0, 2a103f67930, 0)
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 000000000000005b 000000000000002f 0000060021523840 000000000000005a
Sep 13 02:37:37 server01 %l4-7: 0000000000000009 0000000000000064 0000030083501048 000002a103f677f0
Sep 13 02:37:37 server01 genunix: [ID 723222 kern.notice] 000002a103f67700 genunix:lookupnameat+5c (0, 0, 1, 0, 2a103f67930, 0)
Sep 13 02:37:37 server01 genunix: [ID 179002 kern.notice] %l0-3: 0000000000000001 0000000000003000 00000300074361d8 0000000000000000
Sep 13 02:37:37 server01 %l4-7: 00000000ffbff1e0 000002a103f677f0 0000000000000000 000000000198e400
Sep 13 02:37:38 server01 genunix: [ID 723222 kern.notice] 000002a103f67810 genunix:vn_openat+16c (3, 0, 1, 0, 3, 7fffffff)
Sep 13 02:37:38 server01 genunix: [ID 179002 kern.notice] %l0-3: 0000000000000000 0000000000000002 0000000000000000 0000000000000000
Sep 13 02:37:38 server01 %l4-7: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
Sep 13 02:37:38 server01 genunix: [ID 723222 kern.notice] 000002a103f679d0 genunix:copen+260 (ffffffffffd19553, ffbff1e0, 0, ffffffffff312f0c, 0, 3)
Sep 13 02:37:38 server01 genunix: [ID 179002 kern.notice] %l0-3: 0000000000000000 0000000000000000 000000005a480000 0000000000000000
Sep 13 02:37:38 server01 %l4-7: 000000000198e400 0000000000000f0c 0000000000000012 0000030080a96d10
Sep 13 02:37:38 server01 unix: [ID 100000 kern.notice]
Sep 13 02:37:38 server01 genunix: [ID 672855 kern.notice] syncing file systems...
Sep 13 02:37:38 server01 genunix: [ID 904073 kern.notice] done
Sep 13 02:37:39 server01 genunix: [ID 111219 kern.notice] dumping to /dev/zvol/dsk/rpool/dump, offset 65536, content: kernel
Sep 13 02:38:10 server01 genunix: [ID 100000 kern.notice]
Sep 13 02:38:10 server01 genunix: [ID 665016 kern.notice] ^M100% done: 341778 pages dumped,
Sep 13 02:38:10 server01 genunix: [ID 851671 kern.notice] dump succeeded
Sep 13 03:35:07 server01 genunix: [ID 540533 kern.notice] ^MSunOS Release 5.10 Version Generic_147440-19 64-bit

Changes

Server was shutdown to replace an Oracle Emulex FC HBA and on the next reboot, we hit this issue.

There is not technical relation between the Oracle Emulex FC HBA and this other FCoE CNA card.

Cause

This is explained by this bug:

Bug 15773603 : SUNBT7146423 QLGE DRIVER ATTACH FAILED DUE TO PX INTERRUPT-HANDLER ISSUES
--> Fix delivered in patch 148322-06 --> this patch is not installed on Solaris 10 T4-4 sparc server01

The panic stack is the same as the one described on the bug above

void unix:panicsys+0x48((const char *)0x10c00f0, (va_list)0x2a103f66778, (struct regs *)0x1913440, (int)1, 0x4480001604, , , , , , , , 0x10c00f0, 0x2a103f66778)
unix:vpanic_common+0x78(0x10c00f0, 0x2a103f66778, 0, 0x40, 8, 0)
void unix:panic+0x1c((const char *)0x10c00f0, (void *)0x1849130, 0x3007df51a00, 0x30087622b20, 0x30087622b20, 0, ...)
unix:mutex_enter(0x3007df51a00) - frame recycled
void qlge:ql_refill_lbuf_free_list+0x18((struct bq_desc *)0x30062fbc000?, (boolean_t))
qlge:ql_release_to_lbuf_free_list((caddr_t)0x30062fbc000) - frame recycled
void genunix:dblk_lastfree_desb+0x10((mblk_t *), (dblk_t *)0x300770de900)
void genunix:freemsg+0x9c((mblk_t *))
void qlge:ql_free_lbq_buffers+0x58((struct rx_ring *)0x3007df518b0)
void qlge:ql_free_rx_buffers+0x48((qlge_t *)0x3007df24000)
void qlge:ql_free_mem_resources+0x4c((qlge_t *)0x3007df24000)
void qlge:ql_free_resources+0x204((qlge_t *)0x3007df24000)
int qlge:ql_attach+0x798((dev_info_t *)0x30004189cd0, (ddi_attach_cmd_t)0)
int genunix:devi_attach+0xac((dev_info_t *)0x30004189cd0, (ddi_attach_cmd_t)0)
int genunix:attach_node+0x9c((dev_info_t *)0x30004189cd0)
int genunix:i_ndi_config_node+0x110((dev_info_t *)0x30004189cd0, (ddi_node_state_t)6, (uint_t)0)
int genunix:i_ddi_attachchild+0x38((dev_info_t *)0x30004189cd0)
int genunix:devi_attach_node+0x84((dev_info_t *)0x30004189cd0, (uint_t)0x4000)
int genunix:devi_config_one+0x300((dev_info_t *)0x3000418c288, (char *)0x2a103f67530, (dev_info_t **)0x2a103f67270, (uint_t)0x4000, (clock_t))
int genunix:ndi_devi_config_one+0xd8((dev_info_t *)0x3000418c288, (char *)0x2a103f67530, (dev_info_t **)0x2a103f67270, (int)0x4000)
int devfs:dv_find+0x1f0((struct dv_node *)0x3008765a8b0, (char *)0x2a103f67530, (struct vnode **)0x2a103f67528, (struct pathname *)0x2a103f677f0, (struct vnode *)0x60021523840, (struct cred *)0x30083501048, (uint_t)0)
int devfs:devfs_lookup+0x1c((struct vnode *)0x3008763b5c0, (char *)0x2a103f67530, (struct vnode **)0x2a103f67528, (struct pathname *)0x2a103f677f0, (int)0, (struct vnode *)0x60021523840, (struct cred *))
int genunix:fop_lookup+0x28((vnode_t *)0x3008763b5c0, (char *)0x2a103f67530, (vnode_t **)0x2a103f67528, (pathname_t *)0x2a103f677f0, (int)0, (vnode_t *)0x60021523840, (cred_t *))
int genunix:lookuppnvp+0x354((struct pathname *)0x2a103f677f0, (struct pathname *)0, (int)1, (struct vnode **)0, (struct vnode **)0x2a103f67930, (vnode_t *)0x60021523840, (vnode_t *)0x60021523840, (cred_t *)0x30083501048)
int genunix:lookuppnat+0x120((struct pathname *)0x2a103f677f0, (struct pathname *)0, (enum symfollow)1, (struct vnode **)0, (struct vnode **)0x2a103f67930, (vnode_t *)0)
int genunix:lookupnameat+0x5c((char *)0xffbff1e0, (enum uio_seg)0, (enum symfollow)1, (struct vnode **)0, (struct vnode **)0x2a103f67930, (vnode_t *)0)
int genunix:vn_openat+0x16c((char *)0xffbff1e0, (enum uio_seg)0, (int)3, (int)0xf0c, (struct vnode **)0x2a103f67a98, (enum create)0, (mode_t)0x12, (struct vnode *)0)
int genunix:copen+0x260((int), (char *), (int), (int))
unix:syscall_trap32+0xcc()
-- switch to user thread's user stack --

The analysis of panic show it was triggered by this command "/usr/sbin/dladm show-link", related with ethernet NICs , the server had just started 5 min 15 secs ago:

time of crash: Sat Sep 13 06:37:37 UTC 2014
age of system: 5 minutes 15 second

==== panic user (LWP_SYS) thread: 0x30087622b20 PID: 3630 on CPU: 5 ====
cmd: /usr/sbin/dladm show-link <<---

Solution

Solaris 10 SPARC: Install qlge patch 148322-06 (or later)

Solaris 10 x86: Install qlge patch 148323-06 (or later)

Note. If you are not sure if you are hitting this issue or not,
please open a SR with Oracle Support and provide a explorer of Solaris server
and the Solaris crash dump for analysis:
How to verify if a Solaris crash dump was created properly after a panic and find possible causes for known issues. (Doc ID 1549180.1)

References

<BUG:15773603> - SUNBT7146423 QLGE DRIVER ATTACH FAILED DUE TO PX INTERRUPT-HANDLER ISSUES
<NOTE:1549180.1> - How to verify if a Solaris crash dump was created properly after a panic and find possible causes for known issues.

Attachments

This solution has no attachment