摘录于SAP有关分析ORACLE数据性能事件的文档。
1、A check for the distribution of relevant Oracle server time revealed:
有关Oracle服务器时间分布的检查显示：
SELECT EVENT,TOTAL_WAITS,TIME_WAITED,AVG_MS,ROUND(RATIO_TO_REPORT(TIME_WAITED) OVER () * 100) PERCENT FROM ( SELECT SUBSTR(EVENT,1,30) EVENT,ROUND(TIME_WAITED_MICRO / TOTAL_WAITS / 1000,2) AVG_MS FROM V$SYstem_EVENT WHERE WAIT_CLASS != ‘Idle‘ AND EVENT NOT IN (‘db file parallel write‘,‘log file parallel write‘,‘log file sequential read‘,‘control file parallel write‘,‘control file sequential read‘,‘Log archive I/O‘) UNION SELECT ‘cpu‘ EVENT,NULL,VALUE,NULL FROM V$SYsstAT WHERE STATISTIC# = 12 ORDER BY 3 DESC) WHERE ROWNUM <= 10;
?? This check is a very useful step to get a first impression what happens
inside a database in terms of performance.
?? The “EVENT NOT IN” condition is necessary because some events are
additional idle events from an SAP perspective.
?? The new Oracle 10g categorization WAIT_CLASS = Idle was used in
order to make sure that uncritical idle wait events are not considered.
?? The results indicate that,since database startup,16 % of the relevant
Oracle server time was caused by TX enqueues.
?? This is much more than we usually want to see and can have significant
impact on the database performance for specific transactions or during
specific time frames.
2、In the following we check when there was an enqueue peak time:
SELECT TO_CHAR(END_INTERVAL_TIME,‘YYYY-MM-DD HH24:MI:SS‘) END_INTERVAL_TIME,TIME_WAITED_MICRO,ROUND(DECODE(TOTAL_WAITS,0,TIME_WAITED_MICRO / TOTAL_WAITS / 1000),2) AVG_WAIT_MS FROM ( SELECT HSS.END_INTERVAL_TIME,HSE.EVENT_NAME,HSE.TOTAL_WAITS - LAG(HSE.TOTAL_WAITS,1) OVER (ORDER BY HSS.SNAP_ID) TOTAL_WAITS,HSE.TIME_WAITED_MICRO - LAG(HSE.TIME_WAITED_MICRO,1) OVER (ORDER BY HSS.SNAP_ID) TIME_WAITED_MICRO FROM DBA_HIST_SYstem_EVENT HSE,DBA_HIST_SNAPSHOT HSS WHERE HSE.SNAP_ID = HSS.SNAP_ID AND HSE.EVENT_NAME = ‘enq: TX - row lock contention‘ ORDER BY HSS.SNAP_ID DESC ) WHERE TOTAL_WAITS >= 0;
?? DBA_HIST_SYstem_EVENT can show you (per default) on an hourly
basis which wait events were active,to what extent,and with which
average wait time.
?? Between 3 and 5 p.m. on 9th of May there is an obvIoUs peak in total and
average wait time for TX enqueues. So we should Now focus on this time
frame.
3、Now let’s see which enqueue waits happened during the peak time:
SELECT TO_CHAR(ASH.SAMPLE_TIME,‘YYYY-MM-DD HH24:MI:SS‘) SAMPLE_TIME,ASH.SESSION_ID,ASH.BLOCKING_SESSION,O.OBJECT_NAME,S.sql_TEXT FROM DBA_HIST_ACTIVE_SESS_HISTORY ASH,DBA_HIST_sqlTEXT S,DBA_OBJECTS O WHERE ASH.sql_ID = S.sql_ID (+) AND ASH.CURRENT_OBJ# = O.OBJECT_ID (+) AND ASH.EVENT like ‘enq: TX - row lock contention‘ AND ASH.SAMPLE_TIME BETWEEN TO_TIMESTAMP(‘09.05.2007 15:30:00‘,‘dd.mm.yyyy hh24:mi:ss‘) AND TO_TIMESTAMP(‘09.05.2007 16:30:00‘,‘dd.mm.yyyy hh24:mi:ss‘) AND ASH.SESSION_STATE = ‘WAITING‘ ORDER BY SAMPLE_TIME DESC;
?? DBA_HIST_ACTIVE_SESS_HISTORY contains information about active
sessions on a 10 seconds basis for the last 7 days.
?? It is a history view for V$ACTIVE_SESSION_HISTORY where information
about active sessions is stored on a 1 second basis for the last few hours.
4、What’s the “big picture” of the Oracle enqueue wait situation?
5、Let’s check the lock holders in the relevant time frame:
SELECT TO_CHAR(ASW.SAMPLE_TIME,ASW.BLOCKING_SESSION SESSION_ID,COUNT(*) "#WAITERS",ASH.TIME_WAITED,DECODE(ASH.SESSION_STATE,NULL,‘INACTIVE‘,‘WAITING‘,ASH.EVENT,‘cpu‘) ACTION,TO_CHAR(SUBSTR(HST.sql_TEXT,4000)) sql_TEXT FROM DBA_HIST_ACTIVE_SESS_HISTORY ASH,DBA_HIST_ACTIVE_SESS_HISTORY ASW,DBA_HIST_sqlTEXT HST WHERE ASH.sql_ID = HST.sql_ID (+) AND ASH.SAMPLE_TIME (+) = ASW.SAMPLE_TIME AND ASH.SESSION_ID (+) = ASW.BLOCKING_SESSION AND ASW.EVENT = ‘enq: TX - row lock contention‘ AND ASW.SESSION_STATE = ‘WAITING‘ GROUP BY TO_CHAR(ASW.SAMPLE_TIME,‘YYYY-MM-DD HH24:MI:SS‘),ASW.BLOCKING_SESSION,‘cpu‘),4000)) ORDER BY TO_CHAR(ASW.SAMPLE_TIME,‘YYYY-MM-DD HH24:MI:SS‘）
What do we kNow Now?1、We have a lot of information about the Oracle side lock dependencies.2、 But we don‘t kNow what happened on the SAP side at this point,because there is no“Active Session History” available for the SAP work processes.3、 So we can‘t say what the lock holding session 1110 was doing all the time.4、 This is a limiting factor for our analysis.5、 In this particular case we’re in luck because one SM66 snapshot was taken on theSAP side showing the work process activities (see next page).6、 Via V$SESSION we were able to map Oracle session 1110 to client process 233476(column PROCESS).7、 Unfortunately Oracle doesn‘t store the PROCESS column inV$ACTIVE_SESSION_HISTORY,so that a mapping “work process <-> Oraclesession” is difficult if work processes were restarted since the problem happened.
