暂无图片
暂无图片
暂无图片
暂无图片
暂无图片

重现enq: JI – contention等待事件

原创 黄宸宁 2013-06-02
1560

今天在分析一台生产库归档日志突然增加的时候,发现了enq:JI - contention事件,过去从来没见过该等待事件,查了下资料,描述如下:

JI enqueue is used to serialize the refresh of an materialized view object,
JI enqueue is acquired when a materialized view refresh is being
performed on an aggregate join view (AJV),
is used to ensure that two or more refresh processes do not try to refresh the same object.

If the JI enqueue holder is an intended refresh session,
the other session(s) that intend to refresh the same mview may just need to wait until the first one finishes.

根据说明,应该是在一个物化视图同时被多个会话同时刷新的时候才会出现,为此做了个实验来证明这点,实验内容如下:

1、创建测试表,给予相关权限

SQL> 
SQL> create table hcn.en_test as select * from dba_objects;

Table created.

SQL>

SQL>
SQL> alter table en_test add constraint pk_id primary key (object_id);

Table altered.

SQL>
SQL>
SQL> GRANT CREATE MATERIALIZED VIEW TO hcn;

Grant succeeded.

SQL>



2、创建测试物化视图


SQL> 
SQL> create materialized view hcn.mv_en_test refresh FORCE on commit as
2 select * from hcn.en_test;

Materialized view created.

SQL>



没有创建物化视图日志,所以在每次刷新的时候都会全量刷新物化视图


3、简单测试下物化视图能否正常工作


SQL> 
SQL> select count(*) from hcn.mv_en_test;

COUNT(*)
----------
50611

SQL>
SQL>
SQL> select max(object_id) from en_test;

MAX(OBJECT_ID)
--------------
53050

SQL>
SQL>
SQL> select count(*) from en_test;

COUNT(*)
----------
50611

SQL>
SQL>
SQL> delete en_test where object_id=53050;

1 row deleted.

SQL>
SQL>
SQL> select count(*) from mv_en_test;

COUNT(*)
----------
50611

SQL>
SQL> commit;

Commit complete.

SQL>
SQL> select count(*) from mv_en_test;

COUNT(*)
----------
50610

SQL>
SQL>

----由于指定的是on commit方式,所以原表的DML操作完成后,物化视图会跟着刷新



4、重现enq JI-contention等待事件


--先编写了一个脚本来观察event
[oracle@ora10g dbmonitor]$
[oracle@ora10g dbmonitor]$ cat dbwait.sh
while [ 1 ]
do
echo $1 "SESSION EVENT WAIT LIST ";date
sqlplus -s "/as sysdba"<<EOF
set pagesize 2000
set linesize 800
set echo off
set verify off
set scan on
col event for a35
col program for a45
col wait_class for a10
col "SESS:SQL_HASH:SQL_ID" for a35
col username for a11
col client for a31
col "OSUSER@MACHINE@PROCEE@SPID" for a35
SELECT s.event event,
S.WAIT_CLASS,
SUBSTR (s.program, 1, 39) program,
s.sid
|| ':'
|| DECODE (sql_hash_value, 0, prev_hash_value, sql_hash_value)
|| ':'
|| decode (sql_id,null,prev_sql_id,sql_id)
"SESS:SQL_HASH:SQL_ID",
s.username,
SUBSTR (
s.osuser || '@' || s.machine || '@' || s.process || '@' || p.spid,
1,
31)
"OSUSER@MACHINE@PROCEE@SPID",
TO_CHAR (s.logon_time, 'mm-dd hh24:mi') logon_time
FROM v$session s,v$process p
where S.PADDR= P.ADDR
and s.wait_class<>'Idle';
exit
EOF
sleep 2
done
[oracle@ora10g dbmonitor]$


---先执行该脚本,执行后用hcn用户连接四个会话
[oracle@ora10g dbmonitor]$
[oracle@ora10g dbmonitor]$ ksh dbwait.sh
SESSION EVENT WAIT LIST
Sun Jun 2 22:29:24 CST 2013

EVENT WAIT_CLASS PROGRAM SESS:SQL_HASH:SQL_ID USERNAME OSUSER@MACHINE@PROCEE@SPID LOGON_TIME
----------------------------------- ---------- --------------------------------------------- ----------------------------------- ----------- ----------------------------------- -----------
SQL*Net message to client Network sqlplus@ora10g.oracle.com (TNS V1-V3) 154:3282303964:2h5cqmg1u7yyw SYS oracle@ora10g.oracle.com@5439@5 06-02 22:29

SESSION EVENT WAIT LIST
Sun Jun 2 22:29:26 CST 2013

EVENT WAIT_CLASS PROGRAM SESS:SQL_HASH:SQL_ID USERNAME OSUSER@MACHINE@PROCEE@SPID LOGON_TIME
----------------------------------- ---------- --------------------------------------------- ----------------------------------- ----------- ----------------------------------- -----------
SQL*Net message to client Network sqlplus@ora10g.oracle.com (TNS V1-V3) 154:3282303964:2h5cqmg1u7yyw SYS oracle@ora10g.oracle.com@5443@5 06-02 22:29

SESSION EVENT WAIT LIST
Sun Jun 2 22:29:28 CST 2013

EVENT WAIT_CLASS PROGRAM SESS:SQL_HASH:SQL_ID USERNAME OSUSER@MACHINE@PROCEE@SPID LOGON_TIME
----------------------------------- ---------- --------------------------------------------- ----------------------------------- ----------- ----------------------------------- -----------
SQL*Net message to client Network sqlplus@ora10g.oracle.com (TNS V1-V3) 154:3282303964:2h5cqmg1u7yyw SYS oracle@ora10g.oracle.com@5447@5 06-02 22:29

--分别执行下面语句


delete en_test where object_id between 100 and 200;


delete en_test where object_id between 300 and 400;


delete en_test where object_id between 500 and 600;

delete en_test where object_id between 700 and 800;


---然后分别快速的执行commit

--会话一:
22:22:35 SQL>
22:22:35 SQL> delete en_test where object_id between 100 and 200;

100 rows deleted.

22:29:50 SQL> commit
22:30:06 2 /

Commit complete.

22:30:23 SQL>

--会话二:
SQL> set time on
22:23:37 SQL>
22:23:38 SQL> delete en_test where object_id between 300 and 400;

92 rows deleted.

22:29:52 SQL> commit
22:30:07 2 /

Commit complete.

22:30:24 SQL>

--会话三:
22:23:48 SQL>
22:23:48 SQL> delete en_test where object_id between 500 and 600;

89 rows deleted.

22:29:53 SQL> commit
22:30:08 2 /


Commit complete.

22:30:28 SQL>
22:30:28 SQL>

--会话四:
22:23:52 SQL>
22:23:52 SQL> delete en_test where object_id between 700 and 800;

98 rows deleted.

22:29:54 SQL> commit
22:30:08 2 /

Commit complete.

22:30:31 SQL>

5、查看4个会话执行期间的等待事件


SESSION EVENT WAIT LIST 
Sun Jun 2 22:30:22 CST 2013

EVENT WAIT_CLASS PROGRAM SESS:SQL_HASH:SQL_ID USERNAME OSUSER@MACHINE@PROCEE@SPID LOGON_TIME
----------------------------------- ---------- --------------------------------------------- ----------------------------------- ----------- ----------------------------------- -----------
log file switch completion Configurat sqlplus@ora10g.oracle.com (TNS V1-V3) 158:3914538088:gcb9vjbnp6738 HCN oracle@ora10g.oracle.com@5318@5 06-02 22:09
ion

SQL*Net message to client Network sqlplus@ora10g.oracle.com (TNS V1-V3) 136:3282303964:2h5cqmg1u7yyw SYS oracle@ora10g.oracle.com@5555@5 06-02 22:30

SESSION EVENT WAIT LIST
Sun Jun 2 22:30:24 CST 2013

EVENT WAIT_CLASS PROGRAM SESS:SQL_HASH:SQL_ID USERNAME OSUSER@MACHINE@PROCEE@SPID LOGON_TIME
----------------------------------- ---------- --------------------------------------------- ----------------------------------- ----------- ----------------------------------- -----------
SQL*Net message to client Network sqlplus@ora10g.oracle.com (TNS V1-V3) 154:3282303964:2h5cqmg1u7yyw SYS oracle@ora10g.oracle.com@5561@5 06-02 22:30
log file switch completion Configurat sqlplus@ora10g.oracle.com (TNS V1-V3) 144:1339845116:bv0znrp7xsugw HCN oracle@ora10g.oracle.com@5372@5 06-02 22:22
ion

log file sequential read System I/O oracle@ora10g.oracle.com (ARC0) 152:0: oracle@ora10g.oracle.com@5109@5 06-02 21:40
enq: JI - contention Other sqlplus@ora10g.oracle.com (TNS V1-V3) 146:1404615020:7tj4q9p9vjfbc HCN oracle@ora10g.oracle.com@5397@5 06-02 22:23

SESSION EVENT WAIT LIST
Sun Jun 2 22:30:26 CST 2013

EVENT WAIT_CLASS PROGRAM SESS:SQL_HASH:SQL_ID USERNAME OSUSER@MACHINE@PROCEE@SPID LOGON_TIME
----------------------------------- ---------- --------------------------------------------- ----------------------------------- ----------- ----------------------------------- -----------
SQL*Net message to client Network sqlplus@ora10g.oracle.com (TNS V1-V3) 136:3282303964:2h5cqmg1u7yyw SYS oracle@ora10g.oracle.com@5565@5 06-02 22:30
log file switch (checkpoint incompl Configurat sqlplus@ora10g.oracle.com (TNS V1-V3) 146:1404615020:7tj4q9p9vjfbc HCN oracle@ora10g.oracle.com@5397@5 06-02 22:23
ete)

根据会话执行的时间区间,生成了一份ASH报告,其中可以看到以下内容:


image


image


Top Event中的p2代表了发生enq JI-contention事件的object_id,因此可以查出下面的结果:


SQL> col owner for a20
SQL> col object_name for a20
SQL> col object_type for a20
SQL> select owner,object_name,object_type from dba_objects where object_id=53052;

OWNER OBJECT_NAME OBJECT_TYPE
-------------------- -------------------- --------------------
HCN MV_EN_TEST TABLE

由此可见,当多个会话同时对相同的物化视图对象进行刷新操作的时候,就会出现enq JI-contention事件。


既然找到了原因想要避免无非就是不让同一时刻有多个会话对同一个物化视图进行操作了,O(∩_∩)O哈!,具体的方法就自己想了。

「喜欢这篇文章,您的关注和赞赏是给作者最好的鼓励」
关注作者
【版权声明】本文为墨天轮用户原创内容,转载时必须标注文章的来源(墨天轮),文章链接,文章作者等基本信息,否则作者和墨天轮有权追究责任。如果您发现墨天轮中有涉嫌抄袭或者侵权的内容,欢迎发送邮件至:contact@modb.pro进行举报,并提供相关证据,一经查实,墨天轮将立刻删除相关内容。

评论