数据库hang住解决总结

在很多情况下如果数据库HANG住则无法登陆sqlplus，

这时如果想要对系统进行hanganalyze可以加参数登录sqlplus 具体语法如下：

[oracle@SHDBService01 ~]$ sqlplus -prelim /nolog

SQL*Plus: Release 10.2.0.4.0 - Production on Fri Aug 21 15:42:23 2009

SQL> conn /as sysdba

Prelim connection established

SQL>

prelim参数只对10g 以后的版本有效。登录以后不允许执行SQL语句可允许shutdown abort操作

为什么要使用hanganalyze

Oracle 数据库“真的”hang住了，可以理解为数据库内部发生死锁。因为普通的DML死锁，oracle服务器会自动监测他们的依赖关系，并回滚其中一个操作，终止这种相互等待的局面。

而当这种死锁发生在争夺内核级别的资源（比如说是pins或latches）时，Oracle并不能自动的监测并处理这种死锁。其实很多时候数据库并没有hang住，而只是由于数据库的性能问题，处理的时间比较长而已。

Hanganalyze工具使用内核调用检测会话在等待什么资源，报告出占有者和等待者的相互关系。另外，它还会将一些比较”interesting”的进程状态dump出来，这个取决于我们使用hanganalyze的分析级别。

hanganalyze工具从oracle8i第二版开始提供，到9i增强了诊断RAC环境下的“集群范围”的信息，这意味着它将会报告出整个集群下的所有会话的信息。

目前有三种使用hanganalyze的方法:

一种是会话级别的：

SQL>ALTER SESSION SET EVENTS 'immediate trace name HANGANALYZE level <level>';

一种是实例级别:

SQL>ORADEBUG hanganalyze <level>

一种是集群范围的：

SQL>ORADEBUG setmypid

SQL>ORADEBUG setinst all

SQL>ORADEBUG -g def hanganalyze <level>

各个level的含义如下：

1-2:只有hanganalyze输出，不dump任何进程

3：Level2+Dump出在IN_HANG状态的进程

4：Level3+Dump出在等待链里面的blockers(状态为LEAF/LEAF_NW/IGN_DMP)

5：Level4+Dump出所有在等待链中的进程（状态为NLEAF）

Oracle官方建议不要超过level 3，一般level 3也能够解决问题，超过level 3会给系统带来额外负担。

更简单的办法是使用ass109.awk分析。。

hanganalyze实验

1.session1更新行数据

SQL> conn cqwr/cqwr

Connected.

SQL> create table tb_hang(id number,remark varchar2(20));

Table created.

SQL> insert into tb_hang values(1,'test');

1 row created.

SQL> commit;

Commit complete.

SQL> select USERENV('sid') from dual;

USERENV('SID')

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

159

SQL>

SQL> update tb_hang set remark='hang' where id=1;

1 row updated.

这个时候不提交

2.session2同样更新session1更新的行

SQL> conn cqwr/cqwr

Connected.

SQL> select USERENV('sid') from dual;

USERENV('SID')

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

146

SQL> update tb_hang set remark='hang' where id=1;

这个时候已经hang住了

3.session3使用hangalyze生成trace文件

SQL> connect / as sysdba

Connected.

SQL> oradebug hanganalyze 3;

Hang Analysis in /u01/oracle/admin/orcl/udump/orcl_ora_15029.trc

SQL> host

[oracle@txy orcl]$ more /u01/oracle/admin/orcl/udump/orcl_ora_15029.trc

/u01/oracle/admin/orcl/udump/orcl_ora_15029.trc

Oracle Database 10g Enterprise Edition Release 10.2.0.5.0 - 64bit Production

With the Partitioning, OLAP, Data Mining and Real Application Testing options

ORACLE_HOME = /u01/oracle/product/10.2.0/db_1

System name: Linux

Node name: txy.whty.com.cn

Release: 2.6.32-431.el6.x86_64

Version: #1 SMP Fri Nov 22 03:15:09 UTC 2013

Machine: x86_64

Instance name: orcl

Redo thread mounted by this instance: 1

Oracle process number: 23

Unix process pid: 15029, image: oracle@txy.whty.com.cn (TNS V1-V3)

*** ACTION NAME:() 2015-01-23 13:46:31.572

*** MODULE NAME:(sqlplus@txy.whty.com.cn (TNS V1-V3)) 2015-01-23 13:46:31.572

*** SERVICE NAME:(SYS$USERS) 2015-01-23 13:46:31.572

*** SESSION ID:(142.97) 2015-01-23 13:46:31.572

*** 2015-01-23 13:46:31.572

==============

HANG ANALYSIS:

==============

Open chains found:

Chain 1 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :

<0/159/5/0xbf308098/15021/SQL*Net message from client>

-- <0/146/63/0xbf30a078/15022/enq: TX - row lock contention>

Other chains found:

Chain 2 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :

<0/142/97/0xbf30c058/15029/No Wait>

Chain 3 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :

<0/145/2/0xbf30c850/14664/Streams AQ: qmn slave idle wait>

Chain 4 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :

<0/147/1/0xbf30b860/14654/Streams AQ: waiting for time man>

Chain 5 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :

<0/153/1/0xbf309880/14644/Streams AQ: qmn coordinator idle>

Extra information that will be dumped at higher levels:

[level 4] : 1 node dumps -- [REMOTE_WT] [LEAF] [LEAF_NW]

[level 5] : 4 node dumps -- [SINGLE_NODE] [SINGLE_NODE_NW] [IGN_DMP]

[level 6] : 1 node dumps -- [NLEAF]

[level 10] : 15 node dumps -- [IGN]

State of nodes

([nodenum]/cnode/sid/sess_srno/session/ospid/state/start/finish/[adjlist]/predecessor):

[141]/0/142/97/0xbf412780/15029/SINGLE_NODE_NW/1/2//none

[144]/0/145/2/0xbf4167e8/14664/SINGLE_NODE/3/4//none

[145]/0/146/63/0xbf417d60/15022/NLEAF/5/8/[158]/none

[146]/0/147/1/0xbf4192d8/14654/SINGLE_NODE/9/10//none

[148]/0/149/8/0xbf41bdc8/14658/IGN/11/12//none

[149]/0/150/1/0xbf41d340/14652/IGN/13/14//none

[152]/0/153/1/0xbf4213a8/14644/SINGLE_NODE/15/16//none

[154]/0/155/1/0xbf423e98/14642/IGN/17/18//none

[155]/0/156/1/0xbf425410/14640/IGN/19/20//none

[158]/0/159/5/0xbf429478/15021/LEAF/6/7//145

[159]/0/160/1/0xbf42a9f0/14632/IGN/21/22//none

[160]/0/161/1/0xbf42bf68/14630/IGN/23/24//none

[161]/0/162/1/0xbf42d4e0/14628/IGN/25/26//none

[162]/0/163/1/0xbf42ea58/14626/IGN/27/28//none

[163]/0/164/1/0xbf42ffd0/14624/IGN/29/30//none

[164]/0/165/1/0xbf431548/14622/IGN/31/32//none

[165]/0/166/1/0xbf432ac0/14620/IGN/33/34//none

[166]/0/167/1/0xbf434038/14618/IGN/35/36//none

[167]/0/168/1/0xbf4355b0/14616/IGN/37/38//none

[168]/0/169/1/0xbf436b28/14614/IGN/39/40//none

[169]/0/170/1/0xbf4380a0/14612/IGN/41/42//none

====================

END OF HANG ANALYSIS

====================

[oracle@txy orcl]$

[145]/0/146/63/0xbf417d60/15022/NLEAF/5/8/[158]/none

[158]对应的SID 159 阻止了 [145]对应的SID 146

[158]/0/159/5/0xbf429478/15021/LEAF/6/7//145

145 被 158 阻止了

可以查看一下这个被阻止的进程具体在做什么 146

SQL>SELECT machine,

status,

program,

sql_text

FROM v$session a, v$sqlarea b

WHERE a.sql_address = b.address AND a.sid = 146;

MACHINE STATUS PROGRAM SQL_TEXT

tan.ceshi.com ACTIVE sqlplus@tan.ceshi.com (TNS V1-V3) update tb_hang set remark='hang' where id=1

MACHINE STATUS PROGRA SQL_TEXT

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

txy.whty.com.cn ACTIVE sqlplus@txy.whty.com.cn (TNS V1-V3) update tb_hang set remark='hang' where id=1

SQL> select event from v$session_wait where sid=146;

EVENT

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

enq: TX - row lock contention

select B.SID,B.SERIAL#,B.SQL_ID from V$SESSION B where B.SID=535

杀掉进程 alter system kill session '159,5';

这个时候第二个session 更新语句提交了

SQL> conn cqwr/cqwr

Connected.

SQL> select USERENV('sid') from dual;

USERENV('SID')

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

146

SQL> update tb_hang set remark='hang' where id=1;

1 row updated.

SQL> commit;

Commit complete.

实际案例

执行一个split分区的脚本时长时间没有响应。登录上去查看，手工执行了split脚本，发现确实会hang住：

SQL>ALTER TABLE A_PDA_SP_STAT SPLIT PARTITIONP_MAXAT(20090609)

INTO (PARTITIONP_20090608 TABLESPACE TS_DATA_A,PARTITIONP_MAX TABLESPACE TS_DATA_A)

检查该session的等待事件：

EVENT P1 P2 P3

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

rowcachelock 8 0 5

查了网上的一些资料，说和sga的shared pool大小不足有关，或者和sequence的cache不大有关。经过分析，这2个原因应该都不是。因为1、如果是shared pool不足，这样的现象一般是某个sql执行的比较慢，但是还是会执行完，而不是像现在这样的挂住；2，只是执行split分区，并没有和 sequence相关。

在这里，我们用hanganalyze来进行分析。

我们现在来看看出来的trace文件：

SQL> select spid from v$session a,v$process b where a.paddr=b.addr and a.sid = 544

SPID

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

1841

这个是系统进程可以用 ps -ef| grep spid 即 ps – ef | grep 1841

SQL> oradebug SETOSPID 1841

Oracle pid: 235, Unix process pid: 19237, image: oracle@hl_rdb01 (TNS V1-V3)

SQL> oradebug hanganalyze 3;

Cycle 1: (0/295)

Cycle 2: (0/254)--(0/239)

Hang Analysis in /oracle/app/oracle/admin/hlreport/udump/hlreport_ora_25247.trc

SQL> !

$ more /oracle/app/oracle/admin/hlreport/udump/hlreport_ora_25247.trc

Dump file /oracle/app/oracle/admin/hlreport/udump/hlreport_ora_25247.trc

Oracle9i Enterprise Edition Release 9.2.0.6.0 - 64bit Production

With the Partitioning, OLAP and Oracle Data Mining options

JServer Release 9.2.0.6.0 - Production

ORACLE_HOME = /oracle/app/oracle/product/9.2.0

System name: HP-UX

Node name: hl_rdb01

Release: B.11.11

Version: U

Machine: 9000/800

Instance name: hlreport

Redo thread mounted by this instance: 1

Oracle process number: 157

Unix process pid: 25247, image: oracle@hl_rdb01 (TNS V1-V3)

*** SESSION ID:(312.10459) 2009-05-20 16:21:58.423

*** 2009-05-20 16:21:58.423

==============

HANG ANALYSIS:

==============

Cycle 1 :<cnode/sid/sess_srno/proc_ptr/ospid/wait_event>:

<0/329/43816/0x4d6b5638/23487/rowcachelock>

--<0/254/19761/0x4d687438/23307/librarycachelock>

Cycle 2 :<cnode/sid/sess_srno/proc_ptr/ospid/wait_event>:

<0/295/57125/0x4d6b8978/19237/rowcachelock>

Cycle 3 :<cnode/sid/sess_srno/proc_ptr/ospid/wait_event>:

<0/295/57125/0x4d6b8978/19237/rowcachelock>

Open chains found:

Other chains found:

Chain 1 :<cnode/sid/sess_srno/proc_ptr/ospid/wait_event>:

<0/312/10459/0x4d69f9b8/25247/NoWait>

Extra information that will be dumped at higher levels:

[level 3] : 4 node dumps -- [IN_HANG]

[level 5] : 1 node dumps -- [SINGLE_NODE] [SINGLE_NODE_NW] [IGN_DMP]

[level 10] : 223 node dumps -- [IGN]

State of nodes

([nodenum]/cnode/sid/sess_srno/session/ospid/state/start/finish/[adjlist]/predecessor):

[0]/0/1/1/0x4d7146c0/5132/IGN/1/2//none

……………………………………………………

[238]/0/239/57618/0x4d7b18a0/13476/IN_HANG/395/402/[294][238][328][253]/none

……………………………………………………

[253]/0/254/19761/0x4d7bb710/23307/IN_HANG/397/400/[328][238][294]/294

………………………………………………………………

[294]/0/295/57125/0x4d7d6820/19237/IN_HANG/396/401/[294][238][253]/238

[328]/0/329/43816/0x4d7ecf40/23487/IN_HANG/398/399/[253]/253

………………………………………………………………

Dumping System_State and Fixed_SGA in process with ospid 13476

Dumping Process information for process with ospid 13476

Dumping Process information for process with ospid 23307

Dumping Process information for process with ospid 19237

Dumping Process information for process with ospid 23487

====================

END OF HANG ANALYSIS

====================

*** 2009-05-20 16:48:20.686

现在我们来看看我们的trace出来的文件：

Cycle 1 ::

<0/329/43816/0x4d6b5638/23487/row cache lock>

— <0/254/19761/0x4d687438/23307/library cache lock>

Cycle 2 ::

<0/295/57125/0x4d6b8978/19237/row cache lock>

Cycle 3 ::

<0/295/57125/0x4d6b8978/19237/row cache lock>

cycle表示oracle内部确定的死锁。其中我们的当前手工执行split的295进程也在里面。我们观察其他的进程在做什么，如329：

SQL>select machine,status,program,sql_text from v$sessiona,v$sqlareab

2 where a.sql_address=b.address and a.sid=329;

MACHINE STATUS PROGRAM SQL_TEXT

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

hl_rdb01 ACTIVE sqlplus@hl_rdb01(TNSV1-V3) ALTER TABLEA_PDA_SP_STATS PLITPARTITION P_MAXAT(20090609) INTO(PARTITION P_20090608 TABLESPACETS_DATA_A ,PARTITION P_MAX TABLESPACETS_DATA_A)

SQL>select event from v$session_wait wheresid=329;

EVENT

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

row cache lock

发现也是在执行split语句，但是问了同事，他已经把之前运行失败的脚本完全kill掉了。估计在数据库中进程挂死了，没有完全的释放。

kill掉329号进程后，发现还是挂住，所以我们继续做hanganlyze：

==============

HANG ANALYSIS:

==============

Cycle 1 :<cnode/sid/sess_srno/proc_ptr/ospid/wait_event>:

<0/295/57125/0x4d6b8978/19237/rowcachelock>

Cycle 2 :<cnode/sid/sess_srno/proc_ptr/ospid/wait_event>:

<0/254/19761/0x4d687438/23307/librarycachelock>

--<0/239/57618/0x4d6b74f8/13476/rowcachelock>

我们继续把其他的进程杀掉。终于295的split执行成功。

SQL>ALTER TABLEA_PDA_SP_STAT SPLIT PARTITIONP_MAXAT(20090609)

INTO(PARTITIONP_20090608 TABLESPACETS_DATA_A ,PARTITION P_MAX TABLESPACETS_DATA_A)

Table altered.

Elapsed:00:31:03.21

继续执行split下一个分区，也很快完成。

SQL>ALTER TABLEA_PDA_SP_STATS PLITPARTITION P_MAXAT(20090610)

2 INTO(PARTITIONP_20090609 TABLESPACETS_DATA_A

3 ,PARTITIONP_MAX TABLESPACETS_DATA_A);

Table altered.

Elapsed:00:00:00.02

至此，问题解决.

[238]/0/239/57618/0x4d7b18a0/13476/IN_HANG/395/402/[294][238][328][253]/none

[253]/0/254/19761/0x4d7bb710/23307/IN_HANG/397/400/[328][238][294]/294

[294]/0/295/57125/0x4d7d6820/19237/IN_HANG/396/401/[294][238][253]/238

[328]/0/329/43816/0x4d7ecf40/23487/IN_HANG/398/399/[253]/253

329堵塞住了254

254堵塞住了295

295堵塞住了239

杀掉的应该是329,254,295

来自为知笔记(Wiz)

posted on 2015-01-23 14:13 夜拿水果刀阅读(1071) 评论(0) 编辑收藏举报

会员力量，点亮园子希望

刷新页面返回顶部

夜拿水果刀

数据库hang住解决总结

更简单的办法是使用ass109.awk分析。。

导航

公告