巧用DBA_HIST_ACTIVE_SESS_HISTORY
dba_hist_active_sess_history这个视图功能比较强大,可以查找过去数据库信息,有几个字段比如BLOCKING_SESSION、event、sql_id、SAMPLE_TIME可以查询数据库过去时间事件,对故障处理是有作用的。
dba_hist_active_sess_history:是视图v$active_session_history的历史数据,DBA_HIST_ACTIVE_SESS_HISTORY视图默认每十秒收集一次信息储存在磁盘中,保存7天,这也是组成AWR一个重要的试图。
附一下AWR相关试图
DBA_HIST_WR_CONTROL:查看当前快照收集的相关设置
v$active_session_history:由ASH自动在内存中维护,以每秒一次的频率收集当前系统中活动session的信息
dba_hist_active_sess_history:是视图v$active_session_history的历史数据,保存在硬盘上
dba_hist_database_instance:显示数据库是实例的信息
dba_hist_snapshot:当前数据库收集到的快照信息
这里直接用案例,来说明。
先用roger一组GES死锁导致。
数据库出现故障,导致数据库HANG住。分析步骤1 查看alert.log Global Enqueue Services Deadlock detected. More info in file
/oracle/admin/cmsdb1/bdump/cmsdb11_lmd0_3705.trc
这时查看trc文件, master 0 gl owner 54111aeb8 possible pid 28756 xid 1005-005B-00009AFE bast 0 rseq 6 mseq 0 history 0x14951495
open opt KJUSERDEADLOCK。分析出为相互堵塞。及下来就要分析堵塞的SID及sqltext。
1 SQL> select SNAP_ID,to_char(BEGIN_INTERVAL_TIME,‘yyyymmdd hh24:mi:ss‘) BEGIN_INTERVAL_TIME from WRM$_SNAPSHOT where BEGIN_INTERVAL_TIME between to_date(‘20101202 10‘,‘yyyymmdd hh24‘) and to_date(‘20101202 18‘,‘yyyymmdd hh24‘) and INSTANCE_NUMBER=1 order by 2; 其实这里不用查snap_id对应的时间,在dba_hist_active_sess_history里有一个时间字段SAMPLE_TIME,一样可以查找你想要时间里的相关内容。
2 根据快照ID 查询故障时间段内的异常等待事件
select INSTANCE_NUMBER,event,to_char(SAMPLE_TIME,‘yyyymmdd hh24:mi:ss‘),count(*) from DBA_HIST_ACTIVE_SESS_HISTORY
where snap_id=22549 and WAIT_CLASS<>‘Idle‘ and event=‘enq: TX - row lock contention‘group by INSTANCE_NUMBER,event,to_char(SAMPLE_TIME,‘yyyymmdd hh24:mi:ss‘) order by 1,3;
3 根据等待事件查sid
select instance_number,BLOCKING_SESSION,count(*),event from DBA_HIST_ACTIVE_SESS_HISTORY where snap_id=22549 and
to_char(SAMPLE_TIME,‘yyyymmdd hh24:mi:ss‘)=‘&time‘ and WAIT_CLASS<>‘Idle‘ and event=‘enq: TX - row lock contention‘
group by instance_number,BLOCKING_SESSION,event
order by 1,2;
从这里我们可以看到 死锁session均来自一个节点,输入告警里面的时间,查询可的出sid为351,577为互为死锁,最多查sql便能查出来相关语句,发生死锁一般是要从开发业务做调整。
下面在是关于数据库HANG住时通过这分析DBA_HIST_ACTIVE_SESS_HISTORY
来自一米的分析
前台应用已经反映完全无法使用了
我们使用CRT远程进程操作 已经很困难了 几乎无法操作
因为情况比较急 所以
首先 查看当前系统的情况
SQL> select BLOCKING_SESSION,count(*) from DBA_HIST_ACTIVE_SESS_HISTORY where snap_id=25604 and
2 to_char(SAMPLE_TIME,‘yyyymmdd hh24:mi:ss‘)=‘20100115 18:30:35‘ and WAIT_CLASS<>‘Idle‘
3 and event=‘enq: SQ - contention‘
4 group by BLOCKING_SESSION
5 order by 2;
BLOCKING_SESSION COUNT(*)
---------------- ----------
6412 1
6003 2
6042 14
6437 14
5535 15
3455 150
3033 233
7 rows selected.
从上面我们可以看出 3455和30332个session就阻塞了 差不多400个会话
下面接着查 看看3455和3033 分别是被谁阻塞
SQL> select SESSION_ID,USER_ID,SQL_ID,BLOCKING_SESSION,event,SAMPLE_TIME from DBA_HIST_ACTIVE_SESS_HISTORY where snap_id=25604 and
to_char(SAMPLE_TIME,‘yyyymmdd hh24:mi:ss‘)<‘20100115 18:30:35 2 ‘ and WAIT_CLASS<>‘Idle‘
and SESSION_ID =3 3 033 order by SAMPLE_TIME desc
4 ;
SESSION_ID USER_ID SQL_ID BLOCKING_SESSION EVENT SAMPLE_TIME
---------- ---------- ------------- ---------------- ----------------------------------- ---------------------------------------------
3033 34 2f1jw97anaudf row cache lock 15-JAN-10 06.30.25.781 PM
3033 34 2f1jw97anaudf 3358 enq: SQ - contention 15-JAN-10 06.30.15.608 PM
3033 34 2f1jw97anaudf 4633 enq: SQ - contention 15-JAN-10 06.30.05.296 PM
通过类似的查询分析
4633 别谁堵塞。对于3045也是一样的分析,最后的出可以发现也其它语句堵塞。找到该语句就可解决。处理该问题也要查看相就的trace文件。
接下来的菜是通过DBA_HIST_ACTIVE_SESS_HISTORY 来分析出来一个数据库bug
该文章来自天堂向左,DBA向右的文章
今天遇到个问题,客户说某天的11:45开始,系统遇到了大量的cursor pin s wait on X,经历一个小时后自动消失,需要查找原因。
这报错一般是某个会话需要申请S模式的mutex,而mutex被其他会话以X模式占有了。查holder也很容易,11g版本前看p2raw的前8位,将16进制转换成10进制即为holder的sid,在11g之后只需直接看blocking_session即可。
在11g中,我们有ash,这个很方便能查到过去发生的一切。
(1)根据客户反馈的情况,cursor pin S wait on X最严重的一个时间段为12:25~12:35,取这个时间段为例。发现cursor: pin S wait on X的进程都被sid为2的进程堵塞。
2wheresample_time>=to_timestamp(‘2013-06-24 12:25:00‘,‘yyyy-mm-dd hh24:mi:ss‘)
3andsample_time<=to_timestamp(‘2013-06-24 12:35:00‘,‘yyyy-mm-dd hh24:mi:ss‘)
4andevent=‘cursor: pin S wait on X‘
5groupbyevent,blocking_session,sql_id
6 /
EVENTBLOCKING_SESSIONSQL_IDCOUNT(*)
---------------------------------------------------------------- ---------------- ------------- ----------
cursor: pinSwaitonX28duehra3kdx621050
--cursor: pinSwaitonX的SQL为:
SQL> selectsql_textfromv$sqlwheresql_id=‘8duehra3kdx62‘;
SQL_TEXT
--------------------------------------------------------------------------------
insert into mytable_a1_p1_h1 select * from mytable_a2_p2_h2
(2)SID为2的进程被sid为1129的进程堵塞:
2wheresample_time>=to_timestamp(‘2013-06-24 12:25:00‘,‘yyyy-mm-dd hh24:mi:ss‘)
3andsample_time<=to_timestamp(‘2013-06-24 12:35:00‘,‘yyyy-mm-dd hh24:mi:ss‘)
4andash.session_id=2
5groupbyevent,blocking_session,sql_id
6 /
EVENTBLOCKING_SESSIONSQL_IDCOUNT(*)
---------------------------------------------------------------- ---------------- ------------- ----------
librarycachelock11298duehra3kdx6260
SQL>
(3)sid为1129的进程被sid 951的堵塞:
2wheresample_time>=to_timestamp(‘2013-06-24 12:25:00‘,‘yyyy-mm-dd hh24:mi:ss‘)
3andsample_time<=to_timestamp(‘2013-06-24 12:35:00‘,‘yyyy-mm-dd hh24:mi:ss‘)
4andash.session_id=1129
5groupbyevent,blocking_session,sql_id
6 /
EVENTBLOCKING_SESSIONSQL_IDCOUNT(*)
---------------------------------------------------------------- ---------------- ------------- ----------
rowcachelock9515nkcsttxny4wz60
SQL>
--而sid1129的sql为:
SQL> selectsql_textfromv$sqlwheresql_id=‘5nkcsttxny4wz‘;
SQL_TEXT
--------------------------------------------------------------------------------
truncate table mytable_a2_p2_h2
SQL>
(4)sid 951的进程被Wnnn的进程堵塞:
2wheresample_time>=to_timestamp(‘2013-06-24 12:25:00‘,‘yyyy-mm-dd hh24:mi:ss‘)
3andsample_time<=to_timestamp(‘2013-06-24 12:35:00‘,‘yyyy-mm-dd hh24:mi:ss‘)
4andash.session_id=951
5groupbyevent,blocking_session,sql_id,program
6 /
EVENTBLOCKING_SESSIONSQL_IDPROGRAMCOUNT(*)
---------------------------------------------------------------- ---------------- ------------- ---------------------------------------------------------------- ----------
oracle@g4as1010(W004)8
logfilesequentialreadoracle@g4as1010(W004)52
(5)最终的堵塞进程为Wnnn。
Wnnn是11g新的进程,有SMCO进程spawn出来,用于主动空间的管理(It perform proactive space allocation and space reclaimation)。
从上述SQL看,由于有insert又有truncate,因此空间清理将有SMCO和Wnnn进程介入。在操作的过程中,堵塞其他的进程的操作。
到这里,我们可以有个初步的解决方案:
既然是Wnnn进程堵塞了其他进程的操作,那么我们禁用这个11g的新功能,禁用SMCO的空间管理 “Tablespace-level space(Extent)pre-allocation”,即可避免该问题的发生。
还原的反向操作为:
注:
* 1 To enable tablespace extension.
* 2 To enable segment growth.
* 3 To enable extent growth.
* 4 To enable chunk allocation.
但是我们到这里也会问一个问题,为什么Wnnn的操作没有blocking_session,却要操作那么久的时间。这时一个不常见的等待事件映入眼帘:log file sequential read 。
log file sequential read 一般是在恢复或者logmnr的时候,才将redo log file的内容顺序的读入到内存中,此时为什么需要做log file sequential read?
根据上述的时间点,我们进一步结合alertlog看,我们发现在对应的时间点,都有关于w004的ora600的报错。
Errors in file /aabb/sx/kgg/data/app/oracle/diag/rdbms/kgg/kgg/trace/kgg_w007_8283.trc (incident=104227):
ORA-00600: internal error code, arguments: [ktecgsc:kcbz_objdchk], [0], [0], [1], [], [], [], [], [], [], [], []
Incident details in: /aabb/sx/kgg/data/app/oracle/diag/rdbms/kgg/kgg/incident/incdir_104227/kgg_w007_8283_i104227.trc
……
结合ora -600 [ktecgsc:kcbz_objdchk]查询MOS,我们可以定位到一个11.2.0.2的bug 10237773,并且从该bug的Rediscovery Note中,也可以看到:The problem is likely to occur in a Wnnn background process ktssupd_segment_extblks_bkg is likely to appear on the stack.
如果想看该内容可以到其本人的博客中查看,这时只想表明通过dba_hist_active_sess_history ,可以查明到会话的等待事件,其数据库中出现HNAG住还是前台某个操作过慢问题,基本都是 语句问题,一个语句因为一些原因堵塞其它语句,导致其它语句发生等待,就像公路上车祸一样,有一个车横在路上,会导致整个路上排起长队,所以在分析数据库变慢情况下,一定到抓到根源,通过 根源看到底是BUG,还是语句写的有问题,还是业务设计有问题。
最后也是比较有用的一个sql语句,
巧用dba_hist_active_sess_history跟踪某个时间段内SQL
select to_char(b.begin_interval_time,‘yyyy-mm-dd hh24:mi:ss‘) update_time,c.sql_text sql_text
from dba_hist_active_sess_history a,DBA_HIST_SNAPSHOT b,v$sqlarea c
where a.snap_id=b.snap_id
and a.sql_id=c.sql_id
and b.begin_interval_time>=to_date(‘2011-12-28‘,‘yyyy-mm-dd‘) and b.begin_interval_time < to_date(‘2011-12-29‘,‘yyyy-mm-dd‘)
and lower(c.sql_text) like ‘%update%dj_sz%‘
order by update_time
作用是查询2011-12-28日对dj_sz表的update语句。
郑重声明:本站内容如果来自互联网及其他传播媒体,其版权均属原媒体及文章作者所有。转载目的在于传递更多信息及用于网络分享,并不代表本站赞同其观点和对其真实性负责,也不构成任何其他建议。