oracle分析性能问题实例

Posted 2021-01-23 windtalker

摘录于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,
TOTAL_WAITS,
TIME_WAITED,
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,
TOTAL_WAITS,
TIME_WAITED_MICRO,
ROUND(DECODE(TOTAL_WAITS, 0, 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, ‘YYYY-MM-DD HH24:MI:SS‘)
SAMPLE_TIME,
ASW.BLOCKING_SESSION SESSION_ID,
COUNT(*) "#WAITERS",
ASH.BLOCKING_SESSION,
ASH.TIME_WAITED,
DECODE(ASH.SESSION_STATE, NULL, ‘INACTIVE‘,
‘WAITING‘, ASH.EVENT, ‘CPU‘) ACTION,
TO_CHAR(SUBSTR(HST.SQL_TEXT, 1, 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,
ASH.BLOCKING_SESSION,
ASH.TIME_WAITED,
DECODE(ASH.SESSION_STATE, NULL, ‘INACTIVE‘,
‘WAITING‘, ASH.EVENT, ‘CPU‘),
TO_CHAR(SUBSTR(HST.SQL_TEXT, 1, 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 the
SAP 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 in
V$ACTIVE_SESSION_HISTORY, so that a mapping “work process <-> Oracle
session” is difficult if work processes were restarted since the problem happened.