标签：02 ITL 20220228 TX 08 28 enq
[20220228]enq TX - allocate ITL entry的测试3.txt
--//上个星期的测试有点乱,重新规划测试.
1.环境:
SCOTT@book> @ver1
PORT_STRING VERSION BANNER
------------------------------ -------------- --------------------------------------------------------------------------------
x86_64/Linux 2.4.xx 11.2.0.4.0 Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
create table t ( x int primary key, y varchar2(4000)) PCTFREE 0 INITRANS 169 TABLESPACE users;
insert into t (x,y) select rownum, rpad('*',10,'*') from dual connect by level <= 171;
commit ;
--//可以发现记录在同一块中,共171条记录.
--//前面的测试使用同一会话,最后死锁结束,换1个方式测试看看.
2.建立测试脚本:
$ cat itl_3.txt
set head off
set verify off
set feedback off
column x format 999999
host sleep $(echo &&1/5 | bc -l )
select 'ITL'||&1,s.sid,s.serial# ,s.process,s.server,p.spid from v$session s,v$process p where s.sid in (select sid from v$mystat where rownum=1) and s.paddr=p.addr;
select x from t where x = &&1 for update ;
host sleep 3000
commit ;
quit
--//注执行前加入sleep ,保证执行顺序.
$ zzdate
trunc(sysdate)+08/24+46/1440+37/86400 == 2022/02/28 08:46:37 == timestamp'2022-02-28 08:46:37'
$ seq 169 | xargs -IQ echo "sqlplus -s -l scott/book @itl_3.txt Q &" | bash | tee /tmp/itl.txt
--//等待169/5 = 33.8秒后,保证全部回话执行itl_3.txt的脚本执行到select * from t where x = &&1 for update ;
$ cat /tmp/itl.txt | awk '/ITL/{print $1}' | diff <(cut -c4- ) <(seq 169)
--//执行顺序一致.
--//打开新的会话执行如下:
SCOTT@book> @ spid
SID SERIAL# PROCESS SERVER SPID PID P_SERIAL# C50
---------- ---------- ------------------------ --------- ------ ------- ---------- --------------------------------------------------
60 21 51655 DEDICATED 51656 195 1 alter system kill session '60,21' immediate;
SCOTT@book> @ 10046on 8
Session altered.
SCOTT@book> select x from t where x =170 for update ;
--//挂起!!等待结束。
X
----------
170
SCOTT@book> @10046off
Session altered.
--//观察跟踪文件:
$ grep "WAIT.*TX" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_51656.trc
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 1001112 name|mode=1415053316 usn<<16 | slot=1900563 sequence=18 obj#=331601 tim=1646009349046308
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 1000919 name|mode=1415053316 usn<<16 | slot=11665439 sequence=19 obj#=331601 tim=1646009350047337
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 1000951 name|mode=1415053316 usn<<16 | slot=1966103 sequence=17 obj#=331601 tim=1646009351048375
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 1000814 name|mode=1415053316 usn<<16 | slot=6619164 sequence=16 obj#=331601 tim=1646009352049278
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 1000992 name|mode=1415053316 usn<<16 | slot=9764879 sequence=17 obj#=331601 tim=1646009353050390
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 1000752 name|mode=1415053316 usn<<16 | slot=4587537 sequence=18 obj#=331601 tim=1646009354051241
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 1001041 name|mode=1415053316 usn<<16 | slot=6946825 sequence=17 obj#=331601 tim=1646009355052378
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 1000757 name|mode=1415053316 usn<<16 | slot=12124181 sequence=19 obj#=331601 tim=1646009356053225
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 1000891 name|mode=1415053316 usn<<16 | slot=5373980 sequence=17 obj#=331601 tim=1646009357054247
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 1000920 name|mode=1415053316 usn<<16 | slot=9633805 sequence=19 obj#=331601 tim=1646009358055257
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 1000894 name|mode=1415053316 usn<<16 | slot=720926 sequence=3218 obj#=331601 tim=1646009359056243
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 1000908 name|mode=1415053316 usn<<16 | slot=9699359 sequence=18 obj#=331601 tim=1646009360057244
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 2000869 name|mode=1415053316 usn<<16 | slot=1900563 sequence=18 obj#=331601 tim=1646009362058240
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 2001151 name|mode=1415053316 usn<<16 | slot=11665439 sequence=19 obj#=331601 tim=1646009364059481
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 2000620 name|mode=1415053316 usn<<16 | slot=1966103 sequence=17 obj#=331601 tim=1646009366060191
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 2001026 name|mode=1415053316 usn<<16 | slot=6619164 sequence=16 obj#=331601 tim=1646009368061324
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 2000776 name|mode=1415053316 usn<<16 | slot=9764879 sequence=17 obj#=331601 tim=1646009370062232
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 2000903 name|mode=1415053316 usn<<16 | slot=4587537 sequence=18 obj#=331601 tim=1646009372063256
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 2000954 name|mode=1415053316 usn<<16 | slot=6946825 sequence=17 obj#=331601 tim=1646009374064326
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 2000872 name|mode=1415053316 usn<<16 | slot=12124181 sequence=19 obj#=331601 tim=1646009376065331
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 2000801 name|mode=1415053316 usn<<16 | slot=5373980 sequence=17 obj#=331601 tim=1646009378066263
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 2000842 name|mode=1415053316 usn<<16 | slot=9633805 sequence=19 obj#=331601 tim=1646009380067206
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 2001099 name|mode=1415053316 usn<<16 | slot=720926 sequence=3218 obj#=331601 tim=1646009382068420
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 2000769 name|mode=1415053316 usn<<16 | slot=9699359 sequence=18 obj#=331601 tim=1646009384069277
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 4002028 name|mode=1415053316 usn<<16 | slot=1900563 sequence=18 obj#=331601 tim=1646009388071418
--//观察最后1个ITL槽的情况。单独检索slot=9699359.
$ grep "WAIT.*TX" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_51656.trc | grep slot=9699359
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 1000908 name|mode=1415053316 usn<<16 | slot=9699359 sequence=18 obj#=331601 tim=1646009360057244
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 2000769 name|mode=1415053316 usn<<16 | slot=9699359 sequence=18 obj#=331601 tim=1646009384069277
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 4001984 name|mode=1415053316 usn<<16 | slot=9699359 sequence=18 obj#=331601 tim=1646009432093269
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 8002922 name|mode=1415053316 usn<<16 | slot=9699359 sequence=18 obj#=331601 tim=1646009495413338
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 16005839 name|mode=1415053316 usn<<16 | slot=9699359 sequence=18 obj#=331601 tim=1646009566712352
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 32010527 name|mode=1415053316 usn<<16 | slot=9699359 sequence=18 obj#=331601 tim=1646009653988243
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 64001553 name|mode=1415053316 usn<<16 | slot=9699359 sequence=18 obj#=331601 tim=1646009773352234
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 128002159 name|mode=1415053316 usn<<16 | slot=9699359 sequence=18 obj#=331601 tim=1646009956764292
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 256007845 name|mode=1415053316 usn<<16 | slot=9699359 sequence=18 obj#=331601 tim=1646010268113364
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 512010697 name|mode=1415053316 usn<<16 | slot=9699359 sequence=18 obj#=331601 tim=1646010835514244
WAIT #140362055751624: nam='enq: TX - allocate ITL entry' ela= 1337949215 name|mode=1415053316 usn<<16 | slot=9699359 sequence=18 obj#=331601 tim=1646012228784060
--//你可以发现一个特点.12个ITL槽为1组,开始1秒,然后2秒,然后4秒,然后5秒,最后1个ITL等待秒数是 2^(迭代次数-1).再然后还是5秒,最后1个ITL等待秒数是 2^(迭代次数-1),如此循环.
--//结束测试,注意最后1次不是2^10=102秒。
--//看看那些会话:
$ cat /tmp/itl.txt | awk '/ITL/{print $1}' | diff <(cut -c4- ) <(seq 169)
--//这次测试顺序一致，看看使用那些ITL槽。
SCOTT@book> @wcy trunc(sysdate)+08/24+46/1440+37/86400 sysdate "event='enq: TX - allocate ITL entry'"
-- Display ASH Wait Chain Signatures script v0.6 BETA by Tanel Poder ( http://blog.tanelpoder.com )
%This SECONDS AAS #Blkrs WAIT_CHAIN FIRST_SEEN LAST_SEEN
------ ---------- ---------- ------ ----------------------------------------------------------------------------- ------------------- -------------------
82% 2359 .6 1 -> 258,7,@1=>60,21,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,258,7] 2022-02-28 08:49:19 2022-02-28 09:37:08
2% 47 0 1 -> 88,11,@1=>60,21,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,88,11] 2022-02-28 08:49:10 2022-02-28 09:14:10
2% 47 0 1 -> 54,19,@1=>60,21,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,54,19] 2022-02-28 08:49:08 2022-02-28 09:14:00
2% 47 0 1 -> 173,7,@1=>60,21,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,173,7] 2022-02-28 08:49:14 2022-02-28 09:14:30
2% 47 0 1 -> 38,1,@1=>60,21,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,38,1] 2022-02-28 08:49:09 2022-02-28 09:14:05
2% 47 0 1 -> 224,7,@1=>60,21,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,224,7] 2022-02-28 08:49:18 2022-02-28 09:14:50
2% 47 0 1 -> 123,9,@1=>60,21,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,123,9] 2022-02-28 08:49:12 2022-02-28 09:14:20
2% 47 0 1 -> 139,7,@1=>60,21,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,139,7] 2022-02-28 08:49:15 2022-02-28 09:14:35
2% 47 0 1 -> 156,7,@1=>60,21,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,156,7] 2022-02-28 08:49:13 2022-02-28 09:14:25
2% 47 0 1 -> 190,7,@1=>60,21,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,190,7] 2022-02-28 08:49:16 2022-02-28 09:14:40
2% 47 0 1 -> 207,7,@1=>60,21,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,207,7] 2022-02-28 08:49:17 2022-02-28 09:14:45
2% 47 0 1 -> 71,13,@1=>60,21,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,71,13] 2022-02-28 08:49:11 2022-02-28 09:14:15
12 rows selected.
--//其它都是47秒。仅仅1个等待2359秒(也就是最后12ITL槽的最后1个ITL槽)。
WITH itl
AS ( SELECT TO_CHAR (sample_time, 'yyyy-mm-dd hh24:mi:ss') ss
,blocking_session
,blocking_session_serial#
FROM V$ACTIVE_SESSION_HISTORY
WHERE event = 'enq: TX - allocate ITL entry'
AND sample_time >= timestamp'2022-02-28 08:46:37'
ORDER BY sample_time)
SELECT blocking_session, blocking_session_serial#, COUNT (*)
FROM itl
GROUP BY blocking_session, blocking_session_serial#
ORDER BY 3;
BLOCKING_SESSION BLOCKING_SESSION_SERIAL# COUNT(*)
---------------- ------------------------ ----------
139 7 47
190 7 47
54 19 47
173 7 47
38 1 47
71 13 47
123 9 47
156 7 47
224 7 47
207 7 47
88 11 47
258 7 2359
12 rows selected.
--//你可以发现使用12个槽是固定的.
SELECT sample_time c30,blocking_session, blocking_session_serial#
FROM V$ACTIVE_SESSION_HISTORY
WHERE event = 'enq: TX - allocate ITL entry'
AND sample_time >= timestamp'2022-02-28 08:46:37'
ORDER BY sample_time;
C30 BLOCKING_SESSION BLOCKING_SESSION_SERIAL#
------------------------------ ---------------- ------------------------
2022-02-28 08:49:08.285 54 19
2022-02-28 08:49:09.285 38 1
2022-02-28 08:49:10.285 88 11
2022-02-28 08:49:11.285 71 13
2022-02-28 08:49:12.295 123 9
2022-02-28 08:49:13.295 156 7
2022-02-28 08:49:14.295 173 7
2022-02-28 08:49:15.295 139 7
2022-02-28 08:49:16.295 190 7
2022-02-28 08:49:17.295 207 7
2022-02-28 08:49:18.295 224 7
2022-02-28 08:49:19.305 258 7
2022-02-28 08:49:20.305 54 19
2022-02-28 08:49:21.305 54 19
2022-02-28 08:49:22.305 38 1
2022-02-28 08:49:23.305 38 1
2022-02-28 08:49:24.305 88 11
2022-02-28 08:49:25.305 88 11
2022-02-28 08:49:26.305 71 13
2022-02-28 08:49:27.305 71 13
2022-02-28 08:49:28.305 123 9
2022-02-28 08:49:29.332 123 9
2022-02-28 08:49:30.332 156 7
2022-02-28 08:49:31.342 156 7
2022-02-28 08:49:32.342 173 7
2022-02-28 08:49:33.342 173 7
2022-02-28 08:49:34.352 139 7
2022-02-28 08:49:35.352 139 7
2022-02-28 08:49:36.352 190 7
2022-02-28 08:49:37.352 190 7
2022-02-28 08:49:38.352 207 7
2022-02-28 08:49:39.352 207 7
2022-02-28 08:49:40.352 224 7
2022-02-28 08:49:41.352 224 7
2022-02-28 08:49:42.352 258 7
2022-02-28 08:49:43.352 258 7
2022-02-28 08:49:44.352 54 19
2022-02-28 08:49:45.352 54 19
2022-02-28 08:49:46.362 54 19
2022-02-28 08:49:47.362 54 19
....
...
--//监测会话sid = 54,38,88,71,123,156,173,139,190,207,224,258对应的ITL槽. 最后是258.
--//^54$|^38$|^88$|^71$|^123$|^156$|^173$|^139$|^190$|^207$|^224$|^258$
$ awk '/ITL/{print $2}' /tmp/itl.txt | egrep -n "^54$|^38$|^88$|^71$|^123$|^156$|^173$|^139$|^190$|^207$|^224$|^258$"
26:54
27:38
28:88
29:71
30:123
31:156
32:173
33:139
34:190
35:207
36:224
37:258
--//选择其中1段ITL槽，不知道算法。
--//这样http://antognini.ch/2011/04/itl-waits-changes-in-recent-releases/提供的伪码还是正确的,只不过itl.FIRST..itl.LAST
--//最多选择12个ITL槽.
iteration = 0
LOOP
iteration++
FOR i IN itl.FIRST..itl.LAST
LOOP
EXIT WHEN itl(i) IS FREE
IF i <> itl.LAST THEN
WAIT ON itl(i) FOR min(power(2,iteration-1),5) SECONDS
ELSIF iteration <= 10 THEN
WAIT ON itl(i) FOR power(2,iteration-1) SECONDS
ELSE
WAIT ON itl(i) FOREVER
END IF
END LOOP
EXIT WHEN free_itl_found
END LOOP
--//按照这个计算,迭代10次需要
--//12*1+12*2+12*4 = 84
--//11*5*7 = 385
--//8+16+32+64+128+256+512 = 1016
--//84+385+1016 = 1485
--//需要1485秒,也就是经过1485/60 = 24.75分钟,在最后1个ITL槽上无限等待它的释放.
--//经过1485+1024 = 2509 秒基本可以缺点算法。
--//附上wcy.sql脚本。
$ cat wcy.sql
@ tpt/ash/ash_wait_chains BLOCKING_SESSION||','||BLOCKING_SESSION_SERIAL#||',@'||BLOCKING_INST_ID||'=>'||session_id||','||SESSION_SERIAL#||',@'||inst_id||'=>'||event "&&3" &&1 &&2
标签：02,ITL,20220228,TX,08,28,enq 来源： https://www.cnblogs.com/lfree/p/15944529.html
本站声明： 1. iCode9 技术分享网（下文简称本站）提供的所有内容，仅供技术学习、探讨和分享； 2. 关于本站的所有留言、评论、转载及引用，纯属内容发起人的个人观点，与本站观点和立场无关； 3. 关于本站的所有言论和文字，纯属内容发起人的个人观点，与本站观点和立场无关； 4. 本站文章均是网友提供，不完全保证技术分享内容的完整性、准确性、时效性、风险性和版权归属；如您发现该文章侵犯了您的权益，可联系我们第一时间进行删除； 5. 本站为非盈利性的个人网站，所有内容不会用来进行牟利，也不会利用任何形式的广告来间接获益，纯粹是为了广大技术爱好者提供技术内容和技术思想的分享性交流网站。