[20231026]enq TX - allocate ITL entry的测试4.txt
[20231026]enq TX - allocate ITL entry的测试4.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条记录.
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 $(echo &&1/5 | bc -l ),保证执行按照自己定义的顺序插入数据,这样可以按照顺序使用ITL槽。
--//整个测试需要至少3000+34秒，需要足够的耐心。
$ cat itl_test.sh
#! /bin/bash
# test enq TX - allocate ITL entry
zzdate | tee /tmp/itl.txt
zzdate | tee /tmp/itl_trace.txt
# 169/5 = 33.8秒后,保证全部回话执行itl_3.txt的脚本执行到select * from t where x = &&1 for update ;
seq 169 | xargs -IQ echo "sqlplus -s -l scott/book @itl_3.txt Q &" | bash | tee -a /tmp/itl.txt > /dev/null &
echo sleep 35
sleep 35
# sleep 35,保证前面的全部回话执行itl_3.txt的脚本执行到select * from t where x = &&1 for update ;
sqlplus -s -l scott/book <<EOF | tee -a /tmp/itl_trace.txt
@ spid
@ t
@ 10046on 8
select x from t where x =170 for update ;
@ xid
commit;
@10046off
EOF
zzdate | tee -a /tmp/itl.txt
zzdate | tee -a /tmp/itl_trace.txt
3.测试:
$ source itl_test.sh
trunc(sysdate)+09/24+39/1440+23/86400 == 2023/11/01 09:39:23 == timestamp'2023-11-01 09:39:23'
trunc(sysdate)+09/24+39/1440+23/86400 == 2023/11/01 09:39:23 == timestamp'2023-11-01 09:39:23'
sleep 35
SID SERIAL# PROCESS SERVER SPID PID P_SERIAL# C50
---------- ---------- ------------------------ --------- ------ ------- ---------- --------------------------------------------------
91 55 25087 DEDICATED 25089 197 5 alter system kill session '91,55' immediate;
TRACEFILE
----------------------------------------------------------------------------
/u01/app/oracle/diag/rdbms/book/book/trace/book_ora_25089.trc
Session altered.
X
----
170
XIDUSN_XIDSLOT_XIDSQN
------------------------------
45.3.7
--//45 = 0x002d
Commit complete.
Session altered.
trunc(sysdate)+10/24+29/1440+31/86400 == 2023/11/01 10:29:31 == timestamp'2023-11-01 10:29:31'
trunc(sysdate)+10/24+29/1440+31/86400 == 2023/11/01 10:29:31 == timestamp'2023-11-01 10:29:31'
--//总共监测 (21+29)*60+31-23 = 3008秒.
4.分析:
$ grep "^WAIT.*TX" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_25089.trc | head -24
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000407 name|mode=1415053316 usn<<16 | slot=7929870 sequence=6 obj#=90609 tim=1698802799316318
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000918 name|mode=1415053316 usn<<16 | slot=393246 sequence=1961 obj#=90609 tim=1698802800317339
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000900 name|mode=1415053316 usn<<16 | slot=7798795 sequence=7 obj#=90609 tim=1698802801318328
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000901 name|mode=1415053316 usn<<16 | slot=7995413 sequence=6 obj#=90609 tim=1698802802319338
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000927 name|mode=1415053316 usn<<16 | slot=10223627 sequence=6 obj#=90609 tim=1698802803320356
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000873 name|mode=1415053316 usn<<16 | slot=720922 sequence=8 obj#=90609 tim=1698802804321325
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000887 name|mode=1415053316 usn<<16 | slot=1900561 sequence=6 obj#=90609 tim=1698802805322315
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000928 name|mode=1415053316 usn<<16 | slot=8650762 sequence=6 obj#=90609 tim=1698802806323334
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000887 name|mode=1415053316 usn<<16 | slot=9830430 sequence=6 obj#=90609 tim=1698802807324312
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000929 name|mode=1415053316 usn<<16 | slot=4587521 sequence=6 obj#=90609 tim=1698802808325329
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000891 name|mode=1415053316 usn<<16 | slot=8978450 sequence=6 obj#=90609 tim=1698802809326329
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000886 name|mode=1415053316 usn<<16 | slot=9175053 sequence=7 obj#=90609 tim=1698802810327358
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000840 name|mode=1415053316 usn<<16 | slot=7929870 sequence=6 obj#=90609 tim=1698802812328346
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000871 name|mode=1415053316 usn<<16 | slot=393246 sequence=1961 obj#=90609 tim=1698802814329340
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000893 name|mode=1415053316 usn<<16 | slot=7798795 sequence=7 obj#=90609 tim=1698802816330325
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000870 name|mode=1415053316 usn<<16 | slot=7995413 sequence=6 obj#=90609 tim=1698802818331333
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000915 name|mode=1415053316 usn<<16 | slot=10223627 sequence=6 obj#=90609 tim=1698802820332338
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000866 name|mode=1415053316 usn<<16 | slot=720922 sequence=8 obj#=90609 tim=1698802822333335
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000880 name|mode=1415053316 usn<<16 | slot=1900561 sequence=6 obj#=90609 tim=1698802824334317
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000924 name|mode=1415053316 usn<<16 | slot=8650762 sequence=6 obj#=90609 tim=1698802826335354
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000916 name|mode=1415053316 usn<<16 | slot=9830430 sequence=6 obj#=90609 tim=1698802828336371
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000882 name|mode=1415053316 usn<<16 | slot=4587521 sequence=6 obj#=90609 tim=1698802830337350
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000849 name|mode=1415053316 usn<<16 | slot=8978450 sequence=6 obj#=90609 tim=1698802832338333
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000932 name|mode=1415053316 usn<<16 | slot=9175053 sequence=7 obj#=90609 tim=1698802834339354
--//12槽为一组.
--//9175053 = /2^16 %2^16 (Type | Mode) = 140,13 = 0x8c000d
$ grep "^WAIT.*TX" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_25089.trc | awk '{print $10}'| paste -d" " $(seq 12 | xargs -IQ echo -n '- ')| nl
1 1000407 1000918 1000900 1000901 1000927 1000873 1000887 1000928 1000887 1000929 1000891 1000886
2 2000840 2000871 2000893 2000870 2000915 2000866 2000880 2000924 2000916 2000882 2000849 2000932
3 4001884 4001875 4001872 4001900 4001865 4001919 4002212 4001491 4001936 4001829 4001924 4001915
4 5001806 5001468 5001826 5001736 5001620 5001112 5001547 5002083 5001348 5002039 5001970 8002990
5 5001867 5001801 5001269 5001847 5001460 5001975 5001386 5001465 5001977 5001714 5001539 16005303
6 5001826 5001967 5001567 5001507 5001982 5001929 5001495 5001237 5001301 5002015 5001135 32010213
7 5001894 5001902 5001864 5001975 5001976 5001123 5001649 5001535 5001341 5001872 5001274 64001768
8 5001932 5001610 5002056 5001540 5001098 5001564 5001232 5001658 5002011 5001905 5001477 128002522
9 5001835 5001984 5001898 5001394 5001308 5001787 5001488 5001185 5001334 5001643 5001776 256005557
10 5001782 5002029 5001286 5001470 5001506 5001608 5001279 5001257 5001456 5001717 5001950 512010920
11 5001683 5001591 5001846 5002061 5001197 5001463 5001404 5001496 5001972 5001636 5001700 1430211940
--//取出ela= NNNN数值。
--//最大12个ITL槽为1组,开始1秒,然后2秒,然后4秒,然后5秒,最后1个ITL等待秒数是 2^(迭代次数-1).再然后都是5秒,最后1个ITL等待秒数
--//总是 2^(迭代次数-1),在迭代10次以后,第11次迭代,其它ITL等待5秒,最后1个ITL槽无限等待下去.
$ grep "^WAIT.*TX" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_25089.trc | awk '{print $10}'|paste -sd'+' | bc | xargs -IQ echo Q/1000000 | bc -l
2970.43913200000000000000
--//最早出现：
--//WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000407 name|mode=1415053316 usn<<16 | slot=7929870 sequence=6 obj#=90609 tim=1698802799316318
--//tim=1698802799316318
$ xdate 1698802799316318/1000000 1
2023-11-01 09:39:59.316318000
--//trunc(sysdate)+10/24+29/1440+31/86400 == 2023/11/01 10:29:31 == timestamp'2023-11-01 10:29:31'
--//从出现enq: TX - allocate ITL entry到结束测试的时间间隔
--//(21+29)*60+31-59 = 2972,还给加上1秒. 实际上是2973秒.
--//换一个思路，在3000秒sleep里面，扣除(169-39)/5，以及35-169/5 = 1.2秒。
--//3000-(169-39)/5 -(35-169/5) = 2972.8，有将近2.4秒的误差，应该在其它方面的消耗,在正常范围。
--//trunc(sysdate)+09/24+39/1440+23/86400 == 2023/11/01 09:39:23 == timestamp'2023-11-01 09:39:23'
--//trunc(sysdate)+10/24+29/1440+31/86400 == 2023/11/01 10:29:31 == timestamp'2023-11-01 10:29:31'
--//总共监测 (21+29)*60+31-23 = 3008秒。实际上等待ITL39回话的事务完成，释放对应ITL槽。
--//3000+35-(169-39)/5 = 3009秒，非常接近。
--//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
*****************
SCOTT@book> @wcy trunc(sysdate)+09/24+39/1440+23/86400 trunc(sysdate)+10/24+29/1440+31/86400 "event='enq: TX - allocate ITL entry'"
-- Display ASH Wait Chain Signatures script v0.7 by Tanel Poder ( http://blog.tanelpoder.com )
%This SECONDS AAS WAIT_CHAIN FIRST_SEEN LAST_SEEN
------ ---------- ---------- ------------------------------------------------------------------------------- ------------------- -------------------
83% 2450 .8 -> 302,53,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,302,53] 2023-11-01 09:40:10 2023-11-01 10:29:30
2% 47 0 -> 141,53,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,141,53] 2023-11-01 09:40:02 2023-11-01 10:05:05
2% 47 0 -> 57,75,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,57,75] 2023-11-01 09:40:05 2023-11-01 10:05:20
2% 47 0 -> 364,69,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,364,69] 2023-11-01 09:40:09 2023-11-01 10:05:40
2% 47 0 -> 246,49,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,246,49] 2023-11-01 09:40:01 2023-11-01 10:05:00
2% 47 0 -> 85,177,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,85,177] 2023-11-01 09:40:00 2023-11-01 10:04:55
2% 47 0 -> 199,75,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,199,75] 2023-11-01 09:40:04 2023-11-01 10:05:15
2% 47 0 -> 117,49,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,117,49] 2023-11-01 09:39:59 2023-11-01 10:04:50
2% 47 0 -> 160,39,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,160,39] 2023-11-01 09:40:07 2023-11-01 10:05:30
2% 47 0 -> 178,55,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,178,55] 2023-11-01 09:40:03 2023-11-01 10:05:10
2% 46 0 -> 282,59,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,282,59] 2023-11-01 09:40:08 2023-11-01 10:05:35
2% 46 0 -> 230,61,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,230,61] 2023-11-01 09:40:06 2023-11-01 10:05:25
12 rows selected.
--//前面11个槽47秒,很容易验证 1+2+4+5*8 = 47.
--//阻塞会话的sid是 302 141 57 364 246 85 199 117 160 178 282 230 .
$ awk '/ITL/{print }' /tmp/itl.txt | head | nl
1 ITL1 38 55 23731 DEDICATED 23764
2 ITL2 167 45 23733 DEDICATED 23765
3 ITL3 218 71 23734 DEDICATED 23768
4 ITL4 56 67 23737 DEDICATED 23771
5 ITL5 180 33 23739 DEDICATED 23774
6 ITL6 78 57 23740 DEDICATED 23777
7 ITL7 244 63 23743 DEDICATED 23785
8 ITL8 235 33 23744 DEDICATED 23784
9 ITL9 111 85 23747 DEDICATED 23780
10 ITL10 145 47 23749 DEDICATED 23786
--//我按照顺序执行的,ITL1的sid=38等于插入1的会话.
$ awk '/ITL/{print $2,$1}' /tmp/itl.txt | egrep -n "^302 |^141 |^57 |^364 |^246 |^85 |^199 |^117 |^160 |^178 |^282 |^230 "
28:117 ITL28
29:85 ITL29
30:246 ITL30
31:141 ITL31
32:178 ITL32
33:199 ITL33
34:57 ITL34
35:230 ITL35
36:160 ITL36
37:282 ITL37
38:364 ITL38
39:302 ITL39
--//前面都能对上.如果你结合前面前面@wcy的输出,可以推断使用ITL槽从小到大看看那个槽没有事务就是使用它.
--//将@wcy的输出保存为/tmp/itl3.txt
--//28 = 0x1c 7929870 = /2^16 %2^16 (Type | Mode) = 121,14 = 0x79000e
--//39 = 0x27
$ grep TX /tmp/itl3.txt | sort -k16 | awk '{print $5}' | sed 's/,.*$//'
117
85
246
141
178
199
57
230
160
282
364
302
--//前面说明sort -k16按照FIRST_SEEN的时分秒排序,然后awk '{print $5}'取出阻塞的会话部分,sed 's/,.*$//'删除后面多余的部分从,开始.
--//顺序完全跟前面的对上.
--//我不知道出现阻塞时,随机选取1段ITL槽尝试还是别的,感觉是随机选择.最大选择12个ITL槽,然后轮询探查.
5.转储数据块看看:
SCOTT@book> select rowid,x from t where rownum=1;
ROWID X
------------------ ------------
AAAWHxAAEAAAAIkAAA 1
SCOTT@book> @ rowid AAAWHxAAEAAAAIkAAA
OBJECT FILE BLOCK ROW ROWID_DBA DBA TEXT
---------- ---------- ---------- ---------- -------------------- -------------------- ----------------------------------------
90609 4 548 0 0x1000224 4,548 alter system dump datafile 4 block 548 ;
SCOTT@book> alter system dump datafile 4 block 548 ;
System altered.
Block header dump: 0x01000224
Object id on Block? Y
seg/obj: 0x161f1 csc: 0x03.1773e952 itc: 169 flg: E typ: 1 - DATA
brn: 0 bdba: 0x1000220 ver: 0x01 opc: 0
inc: 0 exflg: 0
Itl Xid Uba Flag Lck Scn/Fsc
0x01 0x0031.013.00000006 0x00c007d5.000a.06 C--- 0 scn 0x0003.1773e2d5
0x02 0x002d.003.00000007 0x00c00a56.000c.08 C--- 0 scn 0x0003.1773e0c7
++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
0x03 0x0099.011.00000006 0x00c01114.0002.0b ---- 1 fsc 0x0000.00000000
0x04 0x0072.007.00000006 0x00c00eac.0001.09 C--- 0 scn 0x0003.1773e02b.
...
0x1c 0x0087.01b.00000005 0x00c00ffd.0001.08 C--- 0 scn 0x0003.1773e08d
------------
0x1d 0x0079.00e.00000006 0x00c00f1e.0001.06 C--- 0 scn 0x0003.1773e091 --//slot=7929870 = /2^16 %2^16 = 121,14 = 0x79000e
0x1e 0x0006.01e.000007a9 0x00c005e6.036e.07 C--- 0 scn 0x0003.1773e095 --//slot=393246 = /2^16 %2^16 = 6,30 = 0x6001e
0x1f 0x0077.00b.00000007 0x00c006c3.0009.03 C--- 0 scn 0x0003.1773e099 --//slot=7798795 = /2^16 %2^16 = 119,11 = 0x77000b
0x20 0x007a.015.00000006 0x00c0066f.0003.04 C--- 0 scn 0x0003.1773e09e --//slot=7995413 = /2^16 %2^16 = 122,21 = 0x7a0015
0x21 0x009c.00b.00000006 0x00c01142.000b.02 C--- 0 scn 0x0003.1773e0a2 --//slot=10223627= /2^16 %2^16 = 156,11 = 0x9c000b
0x22 0x000b.01a.00000008 0x00c00735.000e.04 C--- 0 scn 0x0003.1773e0a6 --//slot=720922 = /2^16 %2^16 = 11,26 = 0xb001a
0x23 0x001d.011.00000006 0x00c00952.0002.09 C--- 0 scn 0x0003.1773e0aa --//slot=1900561 = /2^16 %2^16 = 29,17 = 0x1d0011
0x24 0x0084.00a.00000006 0x00c01099.0008.0b C--- 0 scn 0x0003.1773e0ae --//slot=8650762 = /2^16 %2^16 = 132,10 = 0x84000a
0x25 0x0096.01e.00000006 0x00c010e6.0007.04 C--- 0 scn 0x0003.1773e0b2 --//slot=9830430 = /2^16 %2^16 = 150,30 = 0x96001e
0x26 0x0046.001.00000006 0x00c00be1.0002.09 C--- 0 scn 0x0003.1773e0b6 --//slot=4587521 = /2^16 %2^16 = 70,1 = 0x460001
0x27 0x0089.012.00000006 0x00c01012.0006.03 C--- 0 scn 0x0003.1773e0ba --//slot=8978450 = /2^16 %2^16 = 137,18 = 0x890012
0x28 0x008c.00d.00000007 0x00c0104c.000d.08 C--- 0 scn 0x0003.1773e0bf --//slot=9175053 = /2^16 %2^16 = 140,13 = 0x8c000d
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
----//使用以上12个ITL槽
0x29 0x00a0.01e.00000005 0x00c00478.0003.04 C--- 0 scn 0x0003.1773e0c3
0x2a 0x0017.01d.00000006 0x00c006f1.0005.04 C--- 0 scn 0x0003.1773e0cb
0x2b 0x000a.017.00005437 0x00c002a7.0f90.16 C--- 0 scn 0x0003.1773e0cf
...
0xa8 0x002e.00e.00000006 0x00c004c2.0004.0e C--- 0 scn 0x0003.1773e2cd
0xa9 0x006f.00f.00000006 0x00c0043e.0002.0a C--- 0 scn 0x0003.1773e2d1
bdba: 0x01000224
data_block_dump,data header at 0x7f4ccac5ca0c
===============
tsiz: 0xff0
hsiz: 0x168
pbl: 0x7f4ccac5ca0c
76543210
flag=--------
ntab=1
nrow=171
frre=-1
fsbo=0x168
fseo=0x44e
avsp=0x2e6
tosp=0x2e6
0xe:pti[0] nrow=171 offs=0
0x12:pri[0] offs=0x44e
0x14:pri[1] offs=0x45f
...
0x166:pri[170] offs=0xfde
block_row_dump:
tab 0, row 0, @0x44e
tl: 17 fb: --H-FL-- lb: 0x0 cc: 2
col 0: [ 2] c1 02
col 1: [10] 2a 2a 2a 2a 2a 2a 2a 2a 2a 2a
tab 0, row 1, @0x45f
tl: 17 fb: --H-FL-- lb: 0x0 cc: 2
col 0: [ 2] c1 03
col 1: [10] 2a 2a 2a 2a 2a 2a 2a 2a 2a 2a
tab 0, row 2, @0x470
tl: 17 fb: --H-FL-- lb: 0x0 cc: 2
col 0: [ 2] c1 04
col 1: [10] 2a 2a 2a 2a 2a 2a 2a 2a 2a 2a
tab 0, row 3, @0x481
...
tl: 18 fb: --H-FL-- lb: 0x3 cc: 2
col 0: [ 3] c2 02 47
col 1: [10] 2a 2a 2a 2a 2a 2a 2a 2a 2a 2a
tab 0, row 170, @0xfde
tl: 18 fb: --H-FL-- lb: 0x0 cc: 2
col 0: [ 3] c2 02 48
col 1: [10] 2a 2a 2a 2a 2a 2a 2a 2a 2a 2a
end_of_block_dump
End dump data blocks tsn: 4 file#: 4 minblk 548 maxblk 548
--//注意看下划线最后事务使用该ITL槽完成插入.
--//WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000886 name|mode=1415053316 usn<<16 | slot=9175053 sequence=7 obj#=90609 tim=1698802810327358
--//9175053 = /2^16 %2^16 (Type | Mode) = 140,13 = 0x8c000d
--//0x28 = 40,使用40 ITL槽,我前面ITL39,因为前面的insert已经使用itl 0x01槽(可以看前面Scn/Fsc列确定,当前是最大scn，说明已
--//经覆盖)
--//还有一个细节，虽然是等待itl=0x28的事务结束释放，但是实际上该事务使用的ITL槽是0x02。
0x02 0x002d.003.00000007 0x00c00a56.000c.08 C--- 0 scn 0x0003.1773e0c7
--//你可以从前面@xid的输出确定。
XIDUSN_XIDSLOT_XIDSQN
------------------------------
45.3.7
--//45 = 0x002d
--//也就是oracle在等待itl=0x28事务槽释放后，还是选择没有使用的scn最小的事务槽，使用它。
$ awk '/ITL/{print $2,$1}' /tmp/itl.txt | egrep -n "^302 |^141 |^57 |^364 |^246 |^85 |^199 |^117 |^160 |^178 |^282 |^230 "| tail -1
39:302 ITL39
--//通过bbed观察:
BBED> set dba 4,548
DBA 0x01000224 (16777764 4,548)
BBED> map
File: /mnt/ramdisk/book/users01.dbf (4)
Block: 548 Dba:0x01000224
------------------------------------------------------------
KTB Data Block (Table/Cluster)
struct kcbh, 20 bytes @0
struct ktbbh, 4080 bytes @20
struct kdbh, 14 bytes @4108
struct kdbt[1], 4 bytes @4122
sb2 kdbr[171] @4126
ub1 freespace[742] @4468
ub1 rowdata[2978] @5210
ub4 tailchk @8188
6.总结:
--//我重复一年前的测试,主要遇到一些不理解问题，实际上它并没有使用等待的itl槽，而是最后等待它释放后，
--//选择没有使用的scn最小的事务槽.
7.附上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
--//以前做过测试，自己竟然有点看不明白，再次验证看看。
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条记录.
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 $(echo &&1/5 | bc -l ),保证执行按照自己定义的顺序插入数据,这样可以按照顺序使用ITL槽。
--//整个测试需要至少3000+34秒，需要足够的耐心。
$ cat itl_test.sh
#! /bin/bash
# test enq TX - allocate ITL entry
zzdate | tee /tmp/itl.txt
zzdate | tee /tmp/itl_trace.txt
# 169/5 = 33.8秒后,保证全部回话执行itl_3.txt的脚本执行到select * from t where x = &&1 for update ;
seq 169 | xargs -IQ echo "sqlplus -s -l scott/book @itl_3.txt Q &" | bash | tee -a /tmp/itl.txt > /dev/null &
echo sleep 35
sleep 35
# sleep 35,保证前面的全部回话执行itl_3.txt的脚本执行到select * from t where x = &&1 for update ;
sqlplus -s -l scott/book <<EOF | tee -a /tmp/itl_trace.txt
@ spid
@ t
@ 10046on 8
select x from t where x =170 for update ;
@ xid
commit;
@10046off
EOF
zzdate | tee -a /tmp/itl.txt
zzdate | tee -a /tmp/itl_trace.txt
3.测试:
$ source itl_test.sh
trunc(sysdate)+09/24+39/1440+23/86400 == 2023/11/01 09:39:23 == timestamp'2023-11-01 09:39:23'
trunc(sysdate)+09/24+39/1440+23/86400 == 2023/11/01 09:39:23 == timestamp'2023-11-01 09:39:23'
sleep 35
SID SERIAL# PROCESS SERVER SPID PID P_SERIAL# C50
---------- ---------- ------------------------ --------- ------ ------- ---------- --------------------------------------------------
91 55 25087 DEDICATED 25089 197 5 alter system kill session '91,55' immediate;
TRACEFILE
----------------------------------------------------------------------------
/u01/app/oracle/diag/rdbms/book/book/trace/book_ora_25089.trc
Session altered.
X
----
170
XIDUSN_XIDSLOT_XIDSQN
------------------------------
45.3.7
--//45 = 0x002d
Commit complete.
Session altered.
trunc(sysdate)+10/24+29/1440+31/86400 == 2023/11/01 10:29:31 == timestamp'2023-11-01 10:29:31'
trunc(sysdate)+10/24+29/1440+31/86400 == 2023/11/01 10:29:31 == timestamp'2023-11-01 10:29:31'
--//总共监测 (21+29)*60+31-23 = 3008秒.
4.分析:
$ grep "^WAIT.*TX" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_25089.trc | head -24
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000407 name|mode=1415053316 usn<<16 | slot=7929870 sequence=6 obj#=90609 tim=1698802799316318
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000918 name|mode=1415053316 usn<<16 | slot=393246 sequence=1961 obj#=90609 tim=1698802800317339
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000900 name|mode=1415053316 usn<<16 | slot=7798795 sequence=7 obj#=90609 tim=1698802801318328
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000901 name|mode=1415053316 usn<<16 | slot=7995413 sequence=6 obj#=90609 tim=1698802802319338
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000927 name|mode=1415053316 usn<<16 | slot=10223627 sequence=6 obj#=90609 tim=1698802803320356
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000873 name|mode=1415053316 usn<<16 | slot=720922 sequence=8 obj#=90609 tim=1698802804321325
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000887 name|mode=1415053316 usn<<16 | slot=1900561 sequence=6 obj#=90609 tim=1698802805322315
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000928 name|mode=1415053316 usn<<16 | slot=8650762 sequence=6 obj#=90609 tim=1698802806323334
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000887 name|mode=1415053316 usn<<16 | slot=9830430 sequence=6 obj#=90609 tim=1698802807324312
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000929 name|mode=1415053316 usn<<16 | slot=4587521 sequence=6 obj#=90609 tim=1698802808325329
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000891 name|mode=1415053316 usn<<16 | slot=8978450 sequence=6 obj#=90609 tim=1698802809326329
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000886 name|mode=1415053316 usn<<16 | slot=9175053 sequence=7 obj#=90609 tim=1698802810327358
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000840 name|mode=1415053316 usn<<16 | slot=7929870 sequence=6 obj#=90609 tim=1698802812328346
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000871 name|mode=1415053316 usn<<16 | slot=393246 sequence=1961 obj#=90609 tim=1698802814329340
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000893 name|mode=1415053316 usn<<16 | slot=7798795 sequence=7 obj#=90609 tim=1698802816330325
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000870 name|mode=1415053316 usn<<16 | slot=7995413 sequence=6 obj#=90609 tim=1698802818331333
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000915 name|mode=1415053316 usn<<16 | slot=10223627 sequence=6 obj#=90609 tim=1698802820332338
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000866 name|mode=1415053316 usn<<16 | slot=720922 sequence=8 obj#=90609 tim=1698802822333335
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000880 name|mode=1415053316 usn<<16 | slot=1900561 sequence=6 obj#=90609 tim=1698802824334317
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000924 name|mode=1415053316 usn<<16 | slot=8650762 sequence=6 obj#=90609 tim=1698802826335354
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000916 name|mode=1415053316 usn<<16 | slot=9830430 sequence=6 obj#=90609 tim=1698802828336371
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000882 name|mode=1415053316 usn<<16 | slot=4587521 sequence=6 obj#=90609 tim=1698802830337350
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000849 name|mode=1415053316 usn<<16 | slot=8978450 sequence=6 obj#=90609 tim=1698802832338333
WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 2000932 name|mode=1415053316 usn<<16 | slot=9175053 sequence=7 obj#=90609 tim=1698802834339354
--//12槽为一组.
--//9175053 = /2^16 %2^16 (Type | Mode) = 140,13 = 0x8c000d
$ grep "^WAIT.*TX" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_25089.trc | awk '{print $10}'| paste -d" " $(seq 12 | xargs -IQ echo -n '- ')| nl
1 1000407 1000918 1000900 1000901 1000927 1000873 1000887 1000928 1000887 1000929 1000891 1000886
2 2000840 2000871 2000893 2000870 2000915 2000866 2000880 2000924 2000916 2000882 2000849 2000932
3 4001884 4001875 4001872 4001900 4001865 4001919 4002212 4001491 4001936 4001829 4001924 4001915
4 5001806 5001468 5001826 5001736 5001620 5001112 5001547 5002083 5001348 5002039 5001970 8002990
5 5001867 5001801 5001269 5001847 5001460 5001975 5001386 5001465 5001977 5001714 5001539 16005303
6 5001826 5001967 5001567 5001507 5001982 5001929 5001495 5001237 5001301 5002015 5001135 32010213
7 5001894 5001902 5001864 5001975 5001976 5001123 5001649 5001535 5001341 5001872 5001274 64001768
8 5001932 5001610 5002056 5001540 5001098 5001564 5001232 5001658 5002011 5001905 5001477 128002522
9 5001835 5001984 5001898 5001394 5001308 5001787 5001488 5001185 5001334 5001643 5001776 256005557
10 5001782 5002029 5001286 5001470 5001506 5001608 5001279 5001257 5001456 5001717 5001950 512010920
11 5001683 5001591 5001846 5002061 5001197 5001463 5001404 5001496 5001972 5001636 5001700 1430211940
--//取出ela= NNNN数值。
--//最大12个ITL槽为1组,开始1秒,然后2秒,然后4秒,然后5秒,最后1个ITL等待秒数是 2^(迭代次数-1).再然后都是5秒,最后1个ITL等待秒数
--//总是 2^(迭代次数-1),在迭代10次以后,第11次迭代,其它ITL等待5秒,最后1个ITL槽无限等待下去.
$ grep "^WAIT.*TX" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_25089.trc | awk '{print $10}'|paste -sd'+' | bc | xargs -IQ echo Q/1000000 | bc -l
2970.43913200000000000000
--//最早出现：
--//WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000407 name|mode=1415053316 usn<<16 | slot=7929870 sequence=6 obj#=90609 tim=1698802799316318
--//tim=1698802799316318
$ xdate 1698802799316318/1000000 1
2023-11-01 09:39:59.316318000
--//trunc(sysdate)+10/24+29/1440+31/86400 == 2023/11/01 10:29:31 == timestamp'2023-11-01 10:29:31'
--//从出现enq: TX - allocate ITL entry到结束测试的时间间隔
--//(21+29)*60+31-59 = 2972,还给加上1秒. 实际上是2973秒.
--//换一个思路，在3000秒sleep里面，扣除(169-39)/5，以及35-169/5 = 1.2秒。
--//3000-(169-39)/5 -(35-169/5) = 2972.8，有将近2.4秒的误差，应该在其它方面的消耗,在正常范围。
--//trunc(sysdate)+09/24+39/1440+23/86400 == 2023/11/01 09:39:23 == timestamp'2023-11-01 09:39:23'
--//trunc(sysdate)+10/24+29/1440+31/86400 == 2023/11/01 10:29:31 == timestamp'2023-11-01 10:29:31'
--//总共监测 (21+29)*60+31-23 = 3008秒。实际上等待ITL39回话的事务完成，释放对应ITL槽。
--//3000+35-(169-39)/5 = 3009秒，非常接近。
--//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
*****************
SCOTT@book> @wcy trunc(sysdate)+09/24+39/1440+23/86400 trunc(sysdate)+10/24+29/1440+31/86400 "event='enq: TX - allocate ITL entry'"
-- Display ASH Wait Chain Signatures script v0.7 by Tanel Poder ( http://blog.tanelpoder.com )
%This SECONDS AAS WAIT_CHAIN FIRST_SEEN LAST_SEEN
------ ---------- ---------- ------------------------------------------------------------------------------- ------------------- -------------------
83% 2450 .8 -> 302,53,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,302,53] 2023-11-01 09:40:10 2023-11-01 10:29:30
2% 47 0 -> 141,53,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,141,53] 2023-11-01 09:40:02 2023-11-01 10:05:05
2% 47 0 -> 57,75,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,57,75] 2023-11-01 09:40:05 2023-11-01 10:05:20
2% 47 0 -> 364,69,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,364,69] 2023-11-01 09:40:09 2023-11-01 10:05:40
2% 47 0 -> 246,49,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,246,49] 2023-11-01 09:40:01 2023-11-01 10:05:00
2% 47 0 -> 85,177,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,85,177] 2023-11-01 09:40:00 2023-11-01 10:04:55
2% 47 0 -> 199,75,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,199,75] 2023-11-01 09:40:04 2023-11-01 10:05:15
2% 47 0 -> 117,49,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,117,49] 2023-11-01 09:39:59 2023-11-01 10:04:50
2% 47 0 -> 160,39,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,160,39] 2023-11-01 09:40:07 2023-11-01 10:05:30
2% 47 0 -> 178,55,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,178,55] 2023-11-01 09:40:03 2023-11-01 10:05:10
2% 46 0 -> 282,59,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,282,59] 2023-11-01 09:40:08 2023-11-01 10:05:35
2% 46 0 -> 230,61,@1=>91,55,@1=>enq: TX - allocate ITL entry -> [idle blocker 1,230,61] 2023-11-01 09:40:06 2023-11-01 10:05:25
12 rows selected.
--//前面11个槽47秒,很容易验证 1+2+4+5*8 = 47.
--//阻塞会话的sid是 302 141 57 364 246 85 199 117 160 178 282 230 .
$ awk '/ITL/{print }' /tmp/itl.txt | head | nl
1 ITL1 38 55 23731 DEDICATED 23764
2 ITL2 167 45 23733 DEDICATED 23765
3 ITL3 218 71 23734 DEDICATED 23768
4 ITL4 56 67 23737 DEDICATED 23771
5 ITL5 180 33 23739 DEDICATED 23774
6 ITL6 78 57 23740 DEDICATED 23777
7 ITL7 244 63 23743 DEDICATED 23785
8 ITL8 235 33 23744 DEDICATED 23784
9 ITL9 111 85 23747 DEDICATED 23780
10 ITL10 145 47 23749 DEDICATED 23786
--//我按照顺序执行的,ITL1的sid=38等于插入1的会话.
$ awk '/ITL/{print $2,$1}' /tmp/itl.txt | egrep -n "^302 |^141 |^57 |^364 |^246 |^85 |^199 |^117 |^160 |^178 |^282 |^230 "
28:117 ITL28
29:85 ITL29
30:246 ITL30
31:141 ITL31
32:178 ITL32
33:199 ITL33
34:57 ITL34
35:230 ITL35
36:160 ITL36
37:282 ITL37
38:364 ITL38
39:302 ITL39
--//前面都能对上.如果你结合前面前面@wcy的输出,可以推断使用ITL槽从小到大看看那个槽没有事务就是使用它.
--//将@wcy的输出保存为/tmp/itl3.txt
--//28 = 0x1c 7929870 = /2^16 %2^16 (Type | Mode) = 121,14 = 0x79000e
--//39 = 0x27
$ grep TX /tmp/itl3.txt | sort -k16 | awk '{print $5}' | sed 's/,.*$//'
117
85
246
141
178
199
57
230
160
282
364
302
--//前面说明sort -k16按照FIRST_SEEN的时分秒排序,然后awk '{print $5}'取出阻塞的会话部分,sed 's/,.*$//'删除后面多余的部分从,开始.
--//顺序完全跟前面的对上.
--//我不知道出现阻塞时,随机选取1段ITL槽尝试还是别的,感觉是随机选择.最大选择12个ITL槽,然后轮询探查.
5.转储数据块看看:
SCOTT@book> select rowid,x from t where rownum=1;
ROWID X
------------------ ------------
AAAWHxAAEAAAAIkAAA 1
SCOTT@book> @ rowid AAAWHxAAEAAAAIkAAA
OBJECT FILE BLOCK ROW ROWID_DBA DBA TEXT
---------- ---------- ---------- ---------- -------------------- -------------------- ----------------------------------------
90609 4 548 0 0x1000224 4,548 alter system dump datafile 4 block 548 ;
SCOTT@book> alter system dump datafile 4 block 548 ;
System altered.
Block header dump: 0x01000224
Object id on Block? Y
seg/obj: 0x161f1 csc: 0x03.1773e952 itc: 169 flg: E typ: 1 - DATA
brn: 0 bdba: 0x1000220 ver: 0x01 opc: 0
inc: 0 exflg: 0
Itl Xid Uba Flag Lck Scn/Fsc
0x01 0x0031.013.00000006 0x00c007d5.000a.06 C--- 0 scn 0x0003.1773e2d5
0x02 0x002d.003.00000007 0x00c00a56.000c.08 C--- 0 scn 0x0003.1773e0c7
++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
0x03 0x0099.011.00000006 0x00c01114.0002.0b ---- 1 fsc 0x0000.00000000
0x04 0x0072.007.00000006 0x00c00eac.0001.09 C--- 0 scn 0x0003.1773e02b.
...
0x1c 0x0087.01b.00000005 0x00c00ffd.0001.08 C--- 0 scn 0x0003.1773e08d
------------
0x1d 0x0079.00e.00000006 0x00c00f1e.0001.06 C--- 0 scn 0x0003.1773e091 --//slot=7929870 = /2^16 %2^16 = 121,14 = 0x79000e
0x1e 0x0006.01e.000007a9 0x00c005e6.036e.07 C--- 0 scn 0x0003.1773e095 --//slot=393246 = /2^16 %2^16 = 6,30 = 0x6001e
0x1f 0x0077.00b.00000007 0x00c006c3.0009.03 C--- 0 scn 0x0003.1773e099 --//slot=7798795 = /2^16 %2^16 = 119,11 = 0x77000b
0x20 0x007a.015.00000006 0x00c0066f.0003.04 C--- 0 scn 0x0003.1773e09e --//slot=7995413 = /2^16 %2^16 = 122,21 = 0x7a0015
0x21 0x009c.00b.00000006 0x00c01142.000b.02 C--- 0 scn 0x0003.1773e0a2 --//slot=10223627= /2^16 %2^16 = 156,11 = 0x9c000b
0x22 0x000b.01a.00000008 0x00c00735.000e.04 C--- 0 scn 0x0003.1773e0a6 --//slot=720922 = /2^16 %2^16 = 11,26 = 0xb001a
0x23 0x001d.011.00000006 0x00c00952.0002.09 C--- 0 scn 0x0003.1773e0aa --//slot=1900561 = /2^16 %2^16 = 29,17 = 0x1d0011
0x24 0x0084.00a.00000006 0x00c01099.0008.0b C--- 0 scn 0x0003.1773e0ae --//slot=8650762 = /2^16 %2^16 = 132,10 = 0x84000a
0x25 0x0096.01e.00000006 0x00c010e6.0007.04 C--- 0 scn 0x0003.1773e0b2 --//slot=9830430 = /2^16 %2^16 = 150,30 = 0x96001e
0x26 0x0046.001.00000006 0x00c00be1.0002.09 C--- 0 scn 0x0003.1773e0b6 --//slot=4587521 = /2^16 %2^16 = 70,1 = 0x460001
0x27 0x0089.012.00000006 0x00c01012.0006.03 C--- 0 scn 0x0003.1773e0ba --//slot=8978450 = /2^16 %2^16 = 137,18 = 0x890012
0x28 0x008c.00d.00000007 0x00c0104c.000d.08 C--- 0 scn 0x0003.1773e0bf --//slot=9175053 = /2^16 %2^16 = 140,13 = 0x8c000d
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
----//使用以上12个ITL槽
0x29 0x00a0.01e.00000005 0x00c00478.0003.04 C--- 0 scn 0x0003.1773e0c3
0x2a 0x0017.01d.00000006 0x00c006f1.0005.04 C--- 0 scn 0x0003.1773e0cb
0x2b 0x000a.017.00005437 0x00c002a7.0f90.16 C--- 0 scn 0x0003.1773e0cf
...
0xa8 0x002e.00e.00000006 0x00c004c2.0004.0e C--- 0 scn 0x0003.1773e2cd
0xa9 0x006f.00f.00000006 0x00c0043e.0002.0a C--- 0 scn 0x0003.1773e2d1
bdba: 0x01000224
data_block_dump,data header at 0x7f4ccac5ca0c
===============
tsiz: 0xff0
hsiz: 0x168
pbl: 0x7f4ccac5ca0c
76543210
flag=--------
ntab=1
nrow=171
frre=-1
fsbo=0x168
fseo=0x44e
avsp=0x2e6
tosp=0x2e6
0xe:pti[0] nrow=171 offs=0
0x12:pri[0] offs=0x44e
0x14:pri[1] offs=0x45f
...
0x166:pri[170] offs=0xfde
block_row_dump:
tab 0, row 0, @0x44e
tl: 17 fb: --H-FL-- lb: 0x0 cc: 2
col 0: [ 2] c1 02
col 1: [10] 2a 2a 2a 2a 2a 2a 2a 2a 2a 2a
tab 0, row 1, @0x45f
tl: 17 fb: --H-FL-- lb: 0x0 cc: 2
col 0: [ 2] c1 03
col 1: [10] 2a 2a 2a 2a 2a 2a 2a 2a 2a 2a
tab 0, row 2, @0x470
tl: 17 fb: --H-FL-- lb: 0x0 cc: 2
col 0: [ 2] c1 04
col 1: [10] 2a 2a 2a 2a 2a 2a 2a 2a 2a 2a
tab 0, row 3, @0x481
...
tl: 18 fb: --H-FL-- lb: 0x3 cc: 2
col 0: [ 3] c2 02 47
col 1: [10] 2a 2a 2a 2a 2a 2a 2a 2a 2a 2a
tab 0, row 170, @0xfde
tl: 18 fb: --H-FL-- lb: 0x0 cc: 2
col 0: [ 3] c2 02 48
col 1: [10] 2a 2a 2a 2a 2a 2a 2a 2a 2a 2a
end_of_block_dump
End dump data blocks tsn: 4 file#: 4 minblk 548 maxblk 548
--//注意看下划线最后事务使用该ITL槽完成插入.
--//WAIT #140430939097200: nam='enq: TX - allocate ITL entry' ela= 1000886 name|mode=1415053316 usn<<16 | slot=9175053 sequence=7 obj#=90609 tim=1698802810327358
--//9175053 = /2^16 %2^16 (Type | Mode) = 140,13 = 0x8c000d
--//0x28 = 40,使用40 ITL槽,我前面ITL39,因为前面的insert已经使用itl 0x01槽(可以看前面Scn/Fsc列确定,当前是最大scn，说明已
--//经覆盖)
--//还有一个细节，虽然是等待itl=0x28的事务结束释放，但是实际上该事务使用的ITL槽是0x02。
0x02 0x002d.003.00000007 0x00c00a56.000c.08 C--- 0 scn 0x0003.1773e0c7
--//你可以从前面@xid的输出确定。
XIDUSN_XIDSLOT_XIDSQN
------------------------------
45.3.7
--//45 = 0x002d
--//也就是oracle在等待itl=0x28事务槽释放后，还是选择没有使用的scn最小的事务槽，使用它。
$ awk '/ITL/{print $2,$1}' /tmp/itl.txt | egrep -n "^302 |^141 |^57 |^364 |^246 |^85 |^199 |^117 |^160 |^178 |^282 |^230 "| tail -1
39:302 ITL39
--//通过bbed观察:
BBED> set dba 4,548
DBA 0x01000224 (16777764 4,548)
BBED> map
File: /mnt/ramdisk/book/users01.dbf (4)
Block: 548 Dba:0x01000224
------------------------------------------------------------
KTB Data Block (Table/Cluster)
struct kcbh, 20 bytes @0
struct ktbbh, 4080 bytes @20
struct kdbh, 14 bytes @4108
struct kdbt[1], 4 bytes @4122
sb2 kdbr[171] @4126
ub1 freespace[742] @4468
ub1 rowdata[2978] @5210
ub4 tailchk @8188
6.总结:
--//我重复一年前的测试,主要遇到一些不理解问题，实际上它并没有使用等待的itl槽，而是最后等待它释放后，
--//选择没有使用的scn最小的事务槽.
7.附上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
