1.  检查alert日志，发现数据库没有任何异常，直接是由于主机宕机导致数据库宕机

Wed Jun 12 02:12:58 2013

Thread 1 advanced to log sequence 114384 (LGWR switch)

  Current log# 1 seq# 114384 mem# 0: /dev/md/oracle_dg/rdsk/d315

  Current log# 1 seq# 114384 mem# 1: /dev/md/oracle_dg/rdsk/d316

Wed Jun 12 02:19:43 2013

Thread 1 advanced to log sequence 114385 (LGWR switch)

  Current log# 6 seq# 114385 mem# 0: /dev/md/oracle_dg/rdsk/d325

  Current log# 6 seq# 114385 mem# 1: /dev/md/oracle_dg/rdsk/d326

Wed Jun 12 02:26:21 2013

Thread 1 advanced to log sequence 114386 (LGWR switch)

  Current log# 2 seq# 114386 mem# 0: /dev/md/oracle_dg/rdsk/d317

  Current log# 2 seq# 114386 mem# 1: /dev/md/oracle_dg/rdsk/d318

Wed Jun 12 09:50:58 2013

Starting ORACLE instance (normal)

Wed Jun 12 09:50:58 2013

Specified value of sga_max_size is too small, bumping to 17582522368

Wed Jun 12 09:51:29 2013

LICENSE_MAX_SESSION = 0

LICENSE_SESSIONS_WARNING = 0

Picked latch-free SCN scheme 3

Autotune of undo retention is turned off.

2.  检查后台进程，用户进程的 trc文件，未发现任何进程有异常报告

3.  检查系统日志

a)    节点在02:27:30发生panic

b)    节点发生panic时，CPU2存在异常

c)    发生异常的函数为mod_rele_dev_by_major，异常的设备类别ID为85

Jun 12 02:27:30 bimsnewdb1 cl_dlpitrans: [ID 624622 kern.notice] Notifying cluster that this node is panicking

Jun 12 02:27:30 bimsnewdb1 unix: [ID 836849 kern.notice]

Jun 12 02:27:30 bimsnewdb1 ^Mpanic[cpu2]/thread=3008b8a41e0:

Jun 12 02:27:30 bimsnewdb1 unix: [ID 644039 kern.notice] mod_rele_dev_by_major: Unheld driver: major number <85>

Jun 12 02:27:30 bimsnewdb1 unix: [ID 100000 kern.notice]

4.  ID为85的设备类别为md，本系统就是使用软RAID后的磁盘做成磁盘卷，然后划分为逻辑盘，提供给数据库用作裸设备

oracle@bimsnewdb1 $ cat /etc/name_to_major |grep " 85$"

md 85

5.  分析主机工程师从dump中解析出的act.5文件。故障发生时，CPU2上的进程为6278，其是一个Oracle数据库的服务器端进程，其是凌晨1点开始的RMAN备份的一个递归子进程

6.  查看该RMAN的日志，发现RMAN任务是直接终止，RMAN无任何报错。也就是说，RMAN在指定过程中没有遇到如何报错，也不可能主动重启节点

通道 c2: 正在启动段 1 于 2013-06-12 02:18:53

通道 c2: 已完成段 1 于 2013-06-12 02:24:18

段句柄=/dbbak/rmandbbak/backupset/lev1_db_NEWBIMS_20130612_t817870733_s65165_p1 标记=LEVEL_1 注释=NONE

通道 c2: 备份集已完成, 经过时间:00:05:25

通道 c2: 启动增量级别 1 数据文件备份集

通道 c2: 正在指定备份集中的数据文件

输入数据文件 fno=00035 name=/dev/md/oracle_dg/rdsk/d392

输入数据文件 fno=00064 name=/dev/md/oracle_dg/rdsk/d426

输入数据文件 fno=00093 name=/dev/md/oracle_dg/rdsk/d455

输入数据文件 fno=00122 name=/dev/md/oracle_dg/rdsk/d484

输入数据文件 fno=00151 name=/dev/md/oracle_dg/rdsk/d513

输入数据文件 fno=00180 name=/dev/md/oracle_dg/rdsk/d542

输入数据文件 fno=00209 name=/dev/md/oracle_dg/rdsk/d573

通道 c2: 正在启动段 1 于 2013-06-12 02:24:20

通道 c1: 已完成段 1 于 2013-06-12 02:24:23

段句柄=/dbbak/rmandbbak/backupset/lev1_db_NEWBIMS_20130612_t817870732_s65164_p1 标记=LEVEL_1 注释=NONE

通道 c1: 备份集已完成, 经过时间:00:05:31

-----------------------------------------------------------------------------

++++++++++++++++++ Begin RMAN Level 1 DB Backup ++++++++++++++++++ Thu Jun 13 01:00:00 CST 2013

-----------------------------------------------------------------------------

7.  在act.5中分析该进程的堆栈

###

CPU 0x2 is RUNNING READY CONFIGURED ENABLED             ### CPU=0x2 (2) ###

###

PANIC occurred on this CPU

a)    在CPU2上发生了PANIC

cpu addr 0x3000659e000

running thread addr 3008b8a41e0

pause thread addr 2a100c87ca0

dispatched thread addr 3008b8a41e0

interrupt stack is 2a100c8ff50

interrupt thread list starts at 2a100c97ca0

in_prom 0

PANIC occurred on this thread

b)    发生PANIC的thread地址为3008b8a41e0，接下来会dump该线程信息

***

process id 6278 is

oraclenewbims (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))

, parent process is 6227

uid is 0x64 0t100, gid is 0x65 0t101

thread addr 3008b8a41e0, proc addr 3005f5784c0, lwp addr 30041f048d8

Thread bound to cpu id 0x2

t_state is 0x4 - TS_ONPROC

Scheduling info:

t_pri is 0x3c, t_epri is 0, t_cid is 0x1

scheduling class is: TS

t_disp_time: is 0x11fa96bfb, 0t4826164219

last switched: 6 mins 44 secs ago on cpu 0x2

pc is 1071ef0, sp is 187bbb0, t_stk 2a10a745ae0

stack trace is:

unix: setjmp (?)

unix: panicsys+0x48 (0x3008b8a41e0,0x30060406e80,kmem_bigtsb_default_arena+0x138

,page_retire_kstat+0x210)

unix: vpanic+0xcc (0x127cc30,0x2a10a744eb0)

genunix: cmn_err+0x98 (3,

"mod_rele_dev_by_major: Unheld driver: major number <%u>",0x55)

genunix: mod_rele_dev_by_major+0x88 (0x55)

genunix: dev_to_instance+0x7c (0x55)

genunix:e_ddi_hold_devi_by_dev +0x14 (0x550000212d,0)

specfs: spec_open+0x84 (0x2a10a745278,0x2001,0x30060406e80)

genunix: fop_open+0x78 (0x2a10a745278,0x2001,0x30060406e80)

pxfs:

__1cMio_repl_implEopen6MinH_A_out_4nHpxfs_v1Efobj_Cpn0C___rn0BJfobj_info_pnGsolo

bjEcred_rnFCORBALEnvironment__v_+0xd0 (0x3003781c540,0x2001,0x2a10a745340,

0x2a10a745610,0x3002ed71688,0x2a10a745680)

pxfs:

__1cNdevice_serverXget_open_device_fobj_v26MrknHpxfs_v1Gpvnode_ipnGsolobjEcred_n

H_A_out_4n0BEfobj_Cpn0F___rn0BJfobj_info_rnFCORBALEnvironment__v_+0x1fc (

0x600380b28f0,0x2a10a7456e8,0x2001,0x3002ed71688,0x2a10a745410,0x2a10a745610,

0x2a10a745680)

pxfs:

__1cXdevice_server_repl_implXget_open_device_fobj_v26MrknHpxfs_v1Gpvnode_ipnGsol

objEcred_nH_A_out_4n0BEfobj_Cpn0F___rn0BJfobj_info_rnFCORBALEnvironment__v_+0x28

 (0x600380b28e8,0x2a10a7456e8,0x2001,?,0x2a10a7454e0,?,0x2a10a745680)

cl_dcs:

__1cDmdcSdevice_server_stubXget_open_device_fobj_v26MrknHpxfs_v1Gpvnode_ipnGsolo

bjEcred_nH_A_out_4n0CEfobj_Cpn0G___rn0CJfobj_info_rnFCORBALEnvironment__v_+0xe0

 (0x6004716a808,0x2a10a7456e8,0x2001,0x3002ed71688,0x2a10a745670,0x2a10a745610,

0x2a10a745680)

pxfs: __1cJpxspecialEopen6MppnFvnode_ipnEcred__i_+0x368 (0x3008374fcc8,

0x2a10a745930,0x2001,0x30060406e80)

genunix: fop_open+0x78 (0x2a10a745930,0x2001,0x30060406e80)

genunix: vn_openat+0x500 (0x8039830f0,UIO_USERSPACE,0x2001,0xc00,0x2a10a745a98,

CRCREAT,0x12,0)

genunix: copen+0x260 (0x12?,0x8039830f0,0x2001?,0x7ffffc00)

unix: syscall_trap+0xac ()

c)    这里是最重要的进程发生问题时的堆栈信息

Ø   发生错误的函数为mod_rele_dev_by_major

Ø   从pxfs部分来看，故障原因和vnode资源有关

Ø   从较高级的函数来看，copen，vn_openat，fop_open，这是在打开文件时发生的异常

Ø   Oracle进程调用底层函数报错，不可能是Oracle的问题，而是底层函数调用上存在问题

8.  查询SUN的资料，发现：mod_rele_dev_by_major函数的作用是，根据参数major，在devnamesp中执行查找。找到后在资源上执行操作。devnamesp对应的结构为dev_ops，该结构为：

struct dev_ops {

int devo_rev

int devo_refcnt

(function returning) int *devo_getinfo

(function returning) int *devo_identify

(function returning) int *devo_probe

(function returning) int *devo_attach

(function returning) int *devo_detach

(function returning) int *devo_reset

struct cb_ops *devo_cb_ops

struct bus_ops *devo_bus_ops

(function returning) int *devo_power

}

9.  在mod_rele_dev_by_major函数中，存在这样一段代码：

#define DEV_OPS_HELD(opsp) ((opsp)->devo_refcnt > 0)

if (!DEV_OPS_HELD(ops)) {

    cmn_err(CE_PANIC,

        "mod_rele_dev_by_major: Unheld driver: major number <%u>",

        (uint_t)major);

}

该段代码的意思为：

a)    dev_ops结构中的devo_refcnt为reference count，是一个计数值

b)    当devo_refcnt小于0是，将发起panic。

c)    devo_refcnt最大值为0x7fffffff，一旦超过该值，将被解析为负

10. 在中心库主机上用如下dtrace脚本监控devo_refcnt值

$ cat  devbymajor.d

#!/usr/sbin/dtrace -qs

fbt::mod_rele_dev_by_major:entry

    {

         @modcnt[arg0,"dec"] = count() ;

         @ktest[arg0,"dec",execname,stack()] = count() ;

    }

fbt::mod_hold_dev_by_major:entry

   {

        @modcnt[arg0,"inc"] = count() ;

        @ktest[arg0,"inc",execname,stack()] = count() ;

   }

dtrace:::END

   {

        printa("%d\t%s\t=\t%@d\n",@modcnt);

        printf("-x-x-x- Stacks and counts -x-x-x-\n");

        printa("%d\t%s\t%@d\t%s\t%k\n",@ktest);

   }

# ./devbymajor.d > devbymajor.txt

11. 脚本在newbims主机中执行15分钟后，获得结果发现（截取部分，详见附录）

32      dec     =       3

32      inc     =       3

118     dec     =       4

118     inc     =       4

85      inc     =       13664

85      inc     6832    oracle 

genunix`ddi_hold_installed_driver+0x4

pxfs`__1cNdevice_serverLmake_specvp6FrknHpxfs_v1Gpvnode_pnEcred__pnFvnode__+0x4c

pxfs`__1cNdevice_serverXget_open_device_fobj_v26MrknHpxfs_v1Gpvnode_ipnGsolobjEcred_nH_A_out_4n0BEfobj_Cpn0F___rn0BJfobj_info_rnFCORBALEnvironment__v_+0x10c

pxfs`__1cXdevice_server_repl_implXget_open_device_fobj_v26MrknHpxfs_v1Gpvnode_ipnGsolobjEcred_nH_A_out_4n0BEfobj_Cpn0F___rn0BJfobj_info_rnFCORBALEnvironment__v_+0x28

cl_dcs`__1cDmdcSdevice_server_stubXget_open_device_fobj_v26MrknHpxfs_v1Gpvnode_ipnGsolobjEcred_nH_A_out_4n0CEfobj_Cpn0G___rn0CJfobj_info_rnFCORBALEnvironment__v_+0xe0

pxfs`__1cJpxspecialEopen6MppnFvnode_ipnEcred__i_+0x368

genunix`fop_open+0x78

genunix`vn_openat+0x500

genunix`copen+0x260

unix`syscall_trap+0xac

85      inc     6832    oracle 

genunix`ddi_hold_installed_driver+0x4

pxfs`__1cJpxspecialEopen6MppnFvnode_ipnEcred__i_+0x5c

genunix`fop_open+0x78

genunix`vn_openat+0x500

genunix`copen+0x260

unix`syscall_trap+0xac

a)    设备种类85的devo_refcnt增加了13664，减少了0，资源存在泄露

b)    其他种类资源获取释放正常

c)    调用mod_rele_dev_by_major函数的函数有：

Ø   e_ddi_hold_devi_by_dev：可增可减

Ø   ddi_hold_installed_driver：只增

d)   系统调用了ddi_hold_installed_driver函数增加了devo_refcnt，那必须通过调用ddi_rele_driver来减少devo_refcnt

e)   从跟踪来看，并未发现对ddi_rele_driver的调用

f)   根据SUN的说法，在开发文档中只说明了通过ddi_hold_installed_driver函数获得资源，而没有提到需要使用ddi_rele_driver释放资源。那么在第三方驱动开发时，可能导致问题。当前中心库正好使用了sun cluster附带的磁盘管理软件

12.  同时，我们对成都AAA主机进行了监控，该主机没有安装SUN Cluster，所以，没有观察到Oracle对ddi_hold_installed_driver函数的调用

root@cdradius # ./devbymajor.d

^C

-x-x-x- Stacks and counts -x-x-x-

23      dec     =       2

23      inc     =       3

-x-x-x- Stacks and counts -x-x-x-

23      dec     1       sshd   

genunix`e_ddi_hold_devi_by_dev+0xe0

specfs`spec_clone+0x148

specfs`spec_open+0x238

genunix`fop_open+0x78

genunix`vn_openat+0x500

genunix`copen+0x260

unix`syscall_trap32+0xcc

23      dec     1       sshd   

genunix`dev_to_instance+0x7c

genunix`e_ddi_hold_devi_by_dev+0x14

specfs`spec_clone+0x148

specfs`spec_open+0x238

genunix`fop_open+0x78

genunix`vn_openat+0x500

genunix`copen+0x260

unix`syscall_trap32+0xcc

23      inc     1       sshd   

genunix`e_ddi_hold_devi_by_dev+0x34

specfs`spec_clone+0x148

specfs`spec_open+0x238

genunix`fop_open+0x78

genunix`vn_openat+0x500

genunix`copen+0x260

unix`syscall_trap32+0xcc

23      inc     1       sshd   

genunix`ddi_hold_installed_driver+0x4

clone`clnopen+0x54

genunix`qattach+0x128

genunix`stropen+0x4fc

specfs`spec_open+0x1bc

genunix`fop_open+0x78

genunix`vn_openat+0x500

genunix`copen+0x260

unix`syscall_trap32+0xcc

23      inc     1       sshd   

genunix`dev_to_instance+0x2c

genunix`e_ddi_hold_devi_by_dev+0x14

specfs`spec_clone+0x148

specfs`spec_open+0x238

genunix`fop_open+0x78

genunix`vn_openat+0x500

genunix`copen+0x260

unix`syscall_trap32+0xcc

13.  查询了SUN的BUG库，怀疑命中该参考了SUN的Bug 15736437 : SUNBT7080718-3.3U2 PANIC: "MOD_RELE_DEV_BY_MAJOR: UNHELD DRIVER: MAJOR NUMBER <#

a)    报错的堆栈相同

b)    当前系统的sun cluster版本3.2.0上，存在该BUG

c)    但bug描述不是太清晰，没有说明是cluster自身内核的问题，还是进程调用导致的问题。但是从分析来看，cluster内核自身问题较大

14.  该补丁包含在144221-09中。7080718 panic: "mod_rele_dev_by_major: Unheld driver: major number <#>"，当前3.2版本，包含了该补丁的最新补丁集为 144221-12