[20141203]分析語句導致阻塞分析表，分析表導致阻塞sql語句執行分析.txt

--我們知道如果語句連線的表很多，會消耗大量的CPU資源。
http://blog.itpub.net/267265/viewspace-1298186/

--分析sql語句還會導致什麼問題呢？昨天看了一篇blog，
--重複測試看看。

SCOTT@test> @ver1

PORT_STRING VERSION BANNER
------------------------------ -------------- --------------------------------------------------------------------------------
x86_64/Linux 2.4.xx 11.2.0.3.0 Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production

--可以下載作者的sql指令碼：
1.建立表：
drop table t1 purge;
drop table t2 purge;
create table t1 as select * from dba_tables;
create table t2 as select * from dba_tables;

2.開啟3個會話：
--session 1執行如下：
set linesize 1000
set pagesize 1000
set echo on
set termout on

spool chain1.log

set timing on

-- explain plan on query that takes a long time to parse

-- try joining a bunch of tables together so it takes
-- a long time to try all the join orders
-- only two real tables

explain plan into plan_table for
select
count(*)
from
     t1,
     t2,
     t2 t3,
     t2 t4,
     t2 t5,
     t2 t6,
     t2 t7,
     t2 t8,
     t2 t9,
     t2 t10,
     t2 t11,
     t2 t12,
     t2 t13,
     t2 t14,
     t2 t15,
     t2 t16,
     t2 t17,
     t2 t18,
     t2 t19,
     t2 t20,
     t2 t21,
     t2 t22,
     t2 t23,
     t2 t24,
     t2 t25,
     t2 t26,
     t2 t27,
     t2 t28,
     t2 t29,
     t2 t30,
     t2 t31,
     t2 t32,
     t2 t33,
     t2 t34,
     t2 t35,
     t2 t36,
     t2 t37,
     t2 t38,
     t2 t39,
     t2 t40,
     t2 t41,
     t2 t42,
     t2 t43,
     t2 t44,
     t2 t45,
     t2 t46,
     t2 t47,
     t2 t48,
     t2 t49,
     t2 t50,
     t2 t51,
     t2 t52,
     t2 t53,
     t2 t54,
     t2 t55,
     t2 t56,
     t2 t57,
     t2 t58,
     t2 t59,
     t2 t60,
     t2 t61,
     t2 t62,
     t2 t63,
     t2 t64,
     t2 t65,
     t2 t66,
     t2 t67,
     t2 t68,
     t2 t69,
     t2 t70,
     t2 t71,
     t2 t72,
     t2 t73,
     t2 t74,
     t2 t75,
     t2 t76,
     t2 t77,
     t2 t78,
     t2 t79,
     t2 t80,
     t2 t81,
     t2 t82,
     t2 t83,
     t2 t84,
     t2 t85,
     t2 t86,
     t2 t87,
     t2 t88,
     t2 t89,
     t2 t90,
     t2 t91,
     t2 t92,
     t2 t93,
     t2 t94,
     t2 t95,
     t2 t96,
     t2 t97,
     t2 t98,
     t2 t99,
     t2 t100
where
t1.owner=t2.owner and
t1.owner=t3.owner and
t1.owner=t4.owner and
t1.owner=t5.owner and
t1.owner=t6.owner and
t1.owner=t7.owner and
t1.owner=t8.owner and
t1.owner=t9.owner and
t1.owner=t10.owner and
t1.owner=t11.owner and
t1.owner=t12.owner and
t1.owner=t13.owner and
t1.owner=t14.owner and
t1.owner=t15.owner and
t1.owner=t16.owner and
t1.owner=t17.owner and
t1.owner=t18.owner and
t1.owner=t19.owner and
t1.owner=t20.owner and
t1.owner=t21.owner and
t1.owner=t22.owner and
t1.owner=t23.owner and
t1.owner=t24.owner and
t1.owner=t25.owner and
t1.owner=t26.owner and
t1.owner=t27.owner and
t1.owner=t28.owner and
t1.owner=t29.owner and
t1.owner=t30.owner and
t1.owner=t31.owner and
t1.owner=t32.owner and
t1.owner=t33.owner and
t1.owner=t34.owner and
t1.owner=t35.owner and
t1.owner=t36.owner and
t1.owner=t37.owner and
t1.owner=t38.owner and
t1.owner=t39.owner and
t1.owner=t40.owner and
t1.owner=t41.owner and
t1.owner=t42.owner and
t1.owner=t43.owner and
t1.owner=t44.owner and
t1.owner=t45.owner and
t1.owner=t46.owner and
t1.owner=t47.owner and
t1.owner=t48.owner and
t1.owner=t49.owner and
t1.owner=t50.owner and
t1.owner=t51.owner and
t1.owner=t52.owner and
t1.owner=t53.owner and
t1.owner=t54.owner and
t1.owner=t55.owner and
t1.owner=t56.owner and
t1.owner=t57.owner and
t1.owner=t58.owner and
t1.owner=t59.owner and
t1.owner=t60.owner and
t1.owner=t61.owner and
t1.owner=t62.owner and
t1.owner=t63.owner and
t1.owner=t64.owner and
t1.owner=t65.owner and
t1.owner=t66.owner and
t1.owner=t67.owner and
t1.owner=t68.owner and
t1.owner=t69.owner and
t1.owner=t70.owner and
t1.owner=t71.owner and
t1.owner=t72.owner and
t1.owner=t73.owner and
t1.owner=t74.owner and
t1.owner=t75.owner and
t1.owner=t76.owner and
t1.owner=t77.owner and
t1.owner=t78.owner and
t1.owner=t79.owner and
t1.owner=t80.owner and
t1.owner=t81.owner and
t1.owner=t82.owner and
t1.owner=t83.owner and
t1.owner=t84.owner and
t1.owner=t85.owner and
t1.owner=t86.owner and
t1.owner=t87.owner and
t1.owner=t88.owner and
t1.owner=t89.owner and
t1.owner=t90.owner and
t1.owner=t91.owner and
t1.owner=t92.owner and
t1.owner=t93.owner and
t1.owner=t94.owner and
t1.owner=t95.owner and
t1.owner=t96.owner and
t1.owner=t97.owner and
t1.owner=t98.owner and
t1.owner=t99.owner and
t1.owner=t100.owner
/

VARIABLE monitored_sid number;

begin

SELECT sid into :monitored_sid from v$session where audsid=USERENV('SESSIONID');

end;
/

-- cpu usage in seconds

SELECT VALUE/100 "CPU in seconds"
FROM V$SESSION a, V$SESSTAT b
where a.SID = b.SID
and a.SID = :monitored_sid
and b.STATISTIC# = (SELECT STATISTIC# FROM V$STATNAME WHERE NAME='CPU used by this session');

spool off
exit

--session 2執行如下：
set linesize 1000
set pagesize 1000
set echo on
set termout on

spool chain2.log

set timing on

execute dbms_stats.gather_table_stats(NULL,'T1');

VARIABLE monitored_sid number;

begin

SELECT sid into :monitored_sid from v$session where audsid=USERENV('SESSIONID');

end;
/

-- show library cache lock wait time in seconds

SELECT TIME_WAITED/100 "Library cache lock in seconds"
FROM V$SESSION_EVENT a, V$SESSION b
WHERE
a.SID = b.SID and
a.SID= :monitored_sid and
a.event='library cache lock';

spool off

--session 3執行如下：
set linesize 1000
set pagesize 1000
set echo on
set termout on

spool chain3.log

set timing on

select /* comment to force hard parse */ count(*) from T1;

VARIABLE monitored_sid number;

begin

SELECT sid into :monitored_sid from v$session where audsid=USERENV('SESSIONID');

end;
/

-- show library cache lock wait time in seconds

SELECT TIME_WAITED/100 "Library cache lock in seconds"
FROM V$SESSION_EVENT a, V$SESSION b
WHERE
a.SID = b.SID and
a.SID= :monitored_sid and
a.event='library cache lock';

spool off

2.測試1：

--如果在session1 單獨執行分割槽語句：

Elapsed: 00:00:43.78 <=我的測試機器比他的還差！

SCOTT@40> SELECT VALUE/100 "CPU in seconds"
2 FROM V$SESSION a, V$SESSTAT b
3 where a.SID = b.SID
4 and a.SID = :monitored_sid
5 and b.STATISTIC# = (SELECT STATISTIC# FROM V$STATNAME WHERE NAME='CPU used by this session');
CPU in seconds
--------------
43.63

--可以發現主要消耗在'CPU used by this session'.

3.測試2:
--在session1 和session 2執行指令碼，session1先執行，馬上切換到session2執行。
--session1 結果如下：
Elapsed: 00:00:44.96
SCOTT@40> SELECT VALUE/100 "CPU in seconds"
2 FROM V$SESSION a, V$SESSTAT b
3 where a.SID = b.SID
4 and a.SID = :monitored_sid
5 and b.STATISTIC# = (SELECT STATISTIC# FROM V$STATNAME WHERE NAME='CPU used by this session');
CPU in seconds
--------------
44.97

--session2 結果如下：
SCOTT@40> SELECT TIME_WAITED/100 "Library cache lock in seconds"
2 FROM V$SESSION_EVENT a, V$SESSION b
3 WHERE
4 a.SID = b.SID and
5 a.SID= :monitored_sid and
6 a.event='library cache lock';
Library cache lock in seconds
-----------------------------
40.53

--可以發現session1的分析sql語句阻塞了session2的分析表，導致session 2大量的時間花在'library cache lock'。
--必須等待session1 完成分析，session2才能獲取library cache lock，完成分析表的過程。

4.測試3：
--在session1 和session 3執行指令碼，session1先執行，馬上切換到session3執行。
--session1 結果如下:
Elapsed: 00:00:44.58
SCOTT@40> SELECT VALUE/100 "CPU in seconds"
2 FROM V$SESSION a, V$SESSTAT b
3 where a.SID = b.SID
4 and a.SID = :monitored_sid
5 and b.STATISTIC# = (SELECT STATISTIC# FROM V$STATNAME WHERE NAME='CPU used by this session');
CPU in seconds
--------------
44.56

--session3 結果如下：
Elapsed: 00:00:00.18

--可以發現session 3馬上執行完成。也就是講分析sql語句並不會阻塞其他相關sql語句的執行。

5.測試4:
--在session1 ,session2和session 3執行指令碼，session1先執行，再執行session2 ,再session3執行。
--session1 結果如下:
Elapsed: 00:00:42.91
SCOTT@40> SELECT VALUE/100 "CPU in seconds"
2 FROM V$SESSION a, V$SESSTAT b
3 where a.SID = b.SID
4 and a.SID = :monitored_sid
5 and b.STATISTIC# = (SELECT STATISTIC# FROM V$STATNAME WHERE NAME='CPU used by this session');
CPU in seconds
--------------
         42.98

--session2 結果如下:
Elapsed: 00:00:38.33
SCOTT@40> SELECT TIME_WAITED/100 "Library cache lock in seconds"
2 FROM V$SESSION_EVENT a, V$SESSION b
3 WHERE
4 a.SID = b.SID and
5 a.SID= :monitored_sid and
6 a.event='library cache lock';
Library cache lock in seconds
-----------------------------
                        37.01

--session3 結果如下:
Elapsed: 00:00:30.01
SCOTT@40> SELECT TIME_WAITED/100 "Library cache lock in seconds"
2 FROM V$SESSION_EVENT a, V$SESSION b
3 WHERE
4 a.SID = b.SID and
5 a.SID= :monitored_sid and
6 a.event='library cache lock';
Library cache lock in seconds
-----------------------------
30.01

--可以發現session1的分析sql語句阻塞了session2的分析表，導致session 2大量的時間花在'library cache lock'。
--而session2分析表要獲取'library cache lock'，導致session3 的sql語句也出現'library cache lock'。

當然在實際上這種情況在實際的生產系統很難遇到。不過還是要特別注意複雜sql導致的分析時間太長的問題。
另外也學習一個判斷分析sql的方法，explain plan，雖然可能執行計劃不可信。

$cat a.sql
explain plan for SELECT   f.constraint_name, f.owner, f.r_owner, p.table_name, SYS.all_cons_columns.column_name, f.delete_rule
    FROM SYS.all_constraints f, SYS.all_cons_columns, SYS.all_constraints p
   WHERE f.owner = 'SCOTT'
     AND f.table_name = 'EMP'
     AND f.constraint_type = 'R'
     AND SYS.all_cons_columns.constraint_name = f.constraint_name
     AND SYS.all_cons_columns.table_name = 'EMP'
     AND SYS.all_cons_columns.owner = 'SCOTT'
     AND p.owner = f.r_owner
     AND p.constraint_name = f.r_constraint_name
ORDER BY f.constraint_name, SYS.all_cons_columns.POSITION;

SCOTT@test> set timing on
SCOTT@test> @a
Explained.
Elapsed: 00:00:03.83

SCOTT@test> @a
Explained.
Elapsed: 00:00:03.81

SCOTT@test> @a
Explained.
Elapsed: 00:00:03.87

--每次都是3.XX秒。

$cat b.sql
explain plan for SELECT /*+ OPTIMIZER_FEATURES_ENABLE('8.0.4') */ f.constraint_name, f.owner, f.r_owner, p.table_name, SYS.all_cons_columns.column_name, f.delete_rule
    FROM SYS.all_constraints f, SYS.all_cons_columns, SYS.all_constraints p
   WHERE f.owner = 'SCOTT'
     AND f.table_name = 'EMP'
     AND f.constraint_type = 'R'
     AND SYS.all_cons_columns.constraint_name = f.constraint_name
     AND SYS.all_cons_columns.table_name = 'EMP'
     AND SYS.all_cons_columns.owner = 'SCOTT'
     AND p.owner = f.r_owner
     AND p.constraint_name = f.r_constraint_name
ORDER BY f.constraint_name, SYS.all_cons_columns.POSITION;

SCOTT@test> set timing on
SCOTT@test> @b
Explained.
Elapsed: 00:00:00.27

SCOTT@test> @b
Explained.
Elapsed: 00:00:00.25

SCOTT@test> @b
Explained.
Elapsed: 00:00:00.26

--可以發現加入提示後很快。僅僅0.2X秒。

[20141203]分析語句導致阻塞分析表.txt

相關文章