[20141203]分析语句导致阻塞分析表，分析表导致阻塞sql语句执行分析.txt
--我们知道如果语句连接的表很多，会消耗大量的CPU资源。
http://blog.itpub.net/267265/viewspace-1298186/
--分析sql语句还会导致什么问题呢？昨天看了一篇bloghttp://www.bobbydurrettdba.com/2014/11/24/parsing-blocks-stats-blocks-parsing/，
--重复测试看看。
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秒。
