根據北京研精畢智信息咨詢發佈的調查報告，2018-2021年，全球數據存儲量由30ZB上升至55ZB左右，年平均增長率約為27.8%。到2022年，數據總存儲量進一步增加至65ZB以上，較2021年同期新增了約10ZB，同比增長18.2%。各市場主體對數據的重視程度不斷提升，數據應用逐步由批量處理向 ...
[20231023]為什麼刷新緩存後輸出記錄順序發生變化6.txt
--//前幾天做了單表刷新緩存後輸出記錄順序發生變化的情況，測試2個表的情況時遇到一個奇怪的現象。
--//我前面的測試18c，如果使用10046跟蹤看不到我遇到的情況，我想使用strace跟蹤，發現該機器配置使用asm,strace跟蹤無法看到一
--//些細節問題。換一臺19c的文件型資料庫測試看看。
1.環境：
[email protected]:1521/orcl> @ ver1
[email protected]:1521/orcl> @ pr
==============================
PORT_STRING : x86_64/Linux 2.4.xx
VERSION : 19.0.0.0.0
BANNER : Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
BANNER_FULL : Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.3.0.0.0
BANNER_LEGACY : Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
CON_ID : 0
PL/SQL procedure successfully completed.
2.建立測試例子：
create table t1 tablespace users pctfree 99 as select level id, lpad(level, 3500, 'T1') vc from dual connect by level <= 500 order by dbms_random.random;
create table t2 tablespace users pctfree 99 as select level id, lpad(level, 3500, 'T2') vc from dual connect by level <= 500 order by dbms_random.random;
--//建立的表T1,T2非常特殊1塊1條記錄,這樣便於後面的分析。
create index i_t1_id on t1(id) ;
create index i_t2_id on t2(id) ;
exec dbms_stats.gather_table_stats(null, 'T1', cascade=>true);
exec dbms_stats.gather_table_stats(null, 'T2', cascade=>true);
3.測試:
--//由於測試要多次刷新數據緩存,也許會對生產系統有影響，我想測試移動到dg上進行.但是我發現我還是測試不出來,在備庫好像刷新
--//數據緩存無效.
[email protected]:1521/orcldg> alter system flush buffer_cache;
System altered.
[email protected]:1521/orcldg> SELECT /*+ leading (t1 t2) use_nl(t2) */ t1.id,substr(t1.vc,3496,5) vc1,substr(t2.vc,3496,5) vc2 FROM t1 , t2 WHERE t1.id = t2.id AND t1.id between 1 and 10;
ID VC1 VC2
---------- ---------- ----------
1 1T1T1 2T2T1
2 1T1T2 2T2T2
3 1T1T3 2T2T3
4 1T1T4 2T2T4
5 1T1T5 2T2T5
6 1T1T6 2T2T6
7 1T1T7 2T2T7
8 1T1T8 2T2T8
9 1T1T9 2T2T9
10 1T110 2T210
10 rows selected.
--//奇怪dg下無法按照順序輸出的,另外寫一篇blog說明情況.
--//沒有辦法先在主庫測試看看.
[email protected]:1521/orcl> alter system flush buffer_cache;
System altered.
[email protected]:1521/orcl> SELECT /*+ leading (t1 t2) use_nl(t2) */ t1.id,substr(t1.vc,3496,5) vc1,substr(t2.vc,3496,5) vc2 FROM t1 , t2 WHERE t1.id = t2.id AND t1.id between 1 and 10;
ID VC1 VC2
---------- ---------- ----------
1 1T1T1 2T2T1
2 1T1T2 2T2T2
10 1T110 2T210
9 1T1T9 2T2T9
3 1T1T3 2T2T3
4 1T1T4 2T2T4
5 1T1T5 2T2T5
6 1T1T6 2T2T6
7 1T1T7 2T2T7
8 1T1T8 2T2T8
10 rows selected.
--//這次又與單表掃描不同id=10,9出現在前面.id=3,4出現在後面,再現我在18c上的測試.
--//在主庫上測試能夠再現我遇到的問題.
[email protected]:1521/orcl> alter system flush buffer_cache;
System altered.
[email protected]:1521/orcl> @ 10046on 12
Session altered.
[email protected]:1521/orcl> SELECT /*+ leading (t1 t2) use_nl(t2) */ t1.id,substr(t1.vc,3496,5) vc1,substr(t2.vc,3496,5) vc2 FROM t1 , t2 WHERE t1.id = t2.id AND t1.id between 1 and 10;
ID VC1 VC2
---------- ---------- ----------
1 1T1T1 2T2T1
2 1T1T2 2T2T2
3 1T1T3 2T2T3
10 1T110 2T210
4 1T1T4 2T2T4
5 1T1T5 2T2T5
6 1T1T6 2T2T6
7 1T1T7 2T2T7
8 1T1T8 2T2T8
9 1T1T9 2T2T9
10 rows selected.
--//一旦開啟10046跟蹤出現的順序就是僅僅id=10記錄在前.
[email protected]:1521/orcl> @ 10046off
Session altered.
[email protected]:1521/orcl> @ oid 245902,245903,245900,245901
owner object_name object_type SUBOBJECT_NAME CREATED LAST_DDL_TIME status DATA_OBJECT_ID OBJECT_ID
----- ----------- ----------- -------------- ------------------- ------------------- --------- -------------- ----------
SYS I_T1_ID INDEX 2023-10-23 08:33:08 2023-10-23 08:33:08 VALID 245902 245902
SYS I_T2_ID INDEX 2023-10-23 08:33:16 2023-10-23 08:33:16 VALID 245903 245903
SYS T1 TABLE 2023-10-23 08:33:00 2023-10-23 08:33:08 VALID 245900 245900
SYS T2 TABLE 2023-10-23 08:33:04 2023-10-23 08:33:16 VALID 245901 245901
4 rows selected.
[email protected]:1521/orcl> select /*+ index(t1) */ id,substr(vc,3498,3),rowid,dbms_rowid.ROWID_BLOCK_NUMBER(rowid) from t1 where id between 1 and 10;
ID SUBSTR ROWID DBMS_ROWID.ROWID_BLOCK_NUMBER(ROWID)
---------- ------ ------------------ ------------------------------------
1 1T1 AAA8CMAAHAAAErrAAA 19179
2 1T2 AAA8CMAAHAAAEpSAAA 19026
3 1T3 AAA8CMAAHAAAEqKAAA 19082
4 1T4 AAA8CMAAHAAAEoqAAA 18986
5 1T5 AAA8CMAAHAAAEs6AAA 19258
6 1T6 AAA8CMAAHAAAEobAAA 18971
7 1T7 AAA8CMAAHAAAEo/AAA 19007
8 1T8 AAA8CMAAHAAAEsPAAA 19215
9 1T9 AAA8CMAAHAAAErdAAA 19165
10 110 AAA8CMAAHAAAEtYAAA 19288
10 rows selected.
[email protected]:1521/orcl> select /*+ index(t2) */ id,substr(vc,3498,3),rowid,dbms_rowid.ROWID_BLOCK_NUMBER(rowid) from t2 where id between 1 and 10;
ID SUBSTR ROWID DBMS_ROWID.ROWID_BLOCK_NUMBER(ROWID)
---------- ------ ------------------ ------------------------------------
1 2T1 AAA8CNAAHAAAEnkAAA 18916
2 2T2 AAA8CNAAHAAAE4DAAA 19971
3 2T3 AAA8CNAAHAAAEyGAAA 19590
4 2T4 AAA8CNAAHAAAEyRAAA 19601
5 2T5 AAA8CNAAHAAAEwVAAA 19477
6 2T6 AAA8CNAAHAAAEztAAA 19693
7 2T7 AAA8CNAAHAAAE3nAAA 19943
8 2T8 AAA8CNAAHAAAE2WAAA 19862
9 2T9 AAA8CNAAHAAAE2mAAA 19878
10 210 AAA8CNAAHAAAEwJAAA 19465
10 rows selected.
--//跟蹤看到的情況如下:
$ egrep "FETCH|db file" /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_80563.trc
WAIT #140140023886360: nam='db file sequential read' ela= 22 file#=1 block#=321561 blocks=1 obj#=245902 tim=58766772230352 --//I_T1_ID 的root
WAIT #140140023886360: nam='db file sequential read' ela= 12 file#=1 block#=321562 blocks=1 obj#=245902 tim=58766772230436 --//I_T1_ID 的leaf
WAIT #140140023886360: nam='db file sequential read' ela= 16 file#=7 block#=19179 blocks=1 obj#=245900 tim=58766772230496 --//T1 id=1
WAIT #140140023886360: nam='db file sequential read' ela= 12 file#=1 block#=321569 blocks=1 obj#=245903 tim=58766772230563 --//I_T2_ID 的root
WAIT #140140023886360: nam='db file sequential read' ela= 12 file#=1 block#=321570 blocks=1 obj#=245903 tim=58766772230612 --//I_T2_ID 的leaf
WAIT #140140023886360: nam='db file sequential read' ela= 13 file#=7 block#=18916 blocks=1 obj#=245901 tim=58766772230665 --//T2 id=1
FETCH #140140023886360:c=451,e=451,p=6,cr=6,cu=0,mis=0,r=1,dep=0,og=1,plh=51221132,tim=58766772230726
WAIT #140140023886360: nam='db file sequential read' ela= 32 file#=7 block#=19026 blocks=1 obj#=245900 tim=58766772231503 --//T1 id=2
WAIT #140140023886360: nam='db file sequential read' ela= 12 file#=7 block#=19971 blocks=1 obj#=245901 tim=58766772231583 --//T2 id=2
WAIT #140140023886360: nam='db file sequential read' ela= 12 file#=7 block#=19082 blocks=1 obj#=245900 tim=58766772231688 --//T1 id=3
WAIT #140140023886360: nam='db file sequential read' ela= 13 file#=7 block#=19590 blocks=1 obj#=245901 tim=58766772231757 --//T2 id=3
WAIT #140140023886360: nam='db file parallel read' ela= 81 files=1 blocks=7 requests=7 obj#=245900 tim=58766772232174 --//T1 讀取id=4..10
WAIT #140140023886360: nam='db file sequential read' ela= 12 file#=7 block#=19465 blocks=1 obj#=245901 tim=58766772232260 --//T2 id=10
WAIT #140140023886360: nam='db file sequential read' ela= 14 file#=7 block#=19601 blocks=1 obj#=245901 tim=58766772232374 --//T2 id=4
WAIT #140140023886360: nam='db file sequential read' ela= 11 file#=7 block#=19477 blocks=1 obj#=245901 tim=58766772232460 --//T2 id=5
WAIT #140140023886360: nam='db file sequential read' ela= 11 file#=7 block#=19693 blocks=1 obj#=245901 tim=58766772232543 --//T2 id=6
WAIT #140140023886360: nam='db file sequential read' ela= 12 file#=7 block#=19943 blocks=1 obj#=245901 tim=58766772232626 --//T2 id=7
WAIT #140140023886360: nam='db file sequential read' ela= 10 file#=7 block#=19862 blocks=1 obj#=245901 tim=58766772232701 --//T2 id=8
WAIT #140140023886360: nam='db file sequential read' ela= 9 file#=7 block#=19878 blocks=1 obj#=245901 tim=58766772232775 --//T2 id=9
FETCH #140140023886360:c=975,e=1411,p=18,cr=26,cu=0,mis=0,r=9,dep=0,og=1,plh=51221132,tim=58766772232827
--//執行計劃如下:
Plan hash value: 51221132
-------------------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
-------------------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 33 (100)| | 10 |00:00:00.01 | 32 |
| 1 | NESTED LOOPS | | 1 | 9 | 63090 | 33 (0)| 00:00:01 | 10 |00:00:00.01 | 32 |
| 2 | NESTED LOOPS | | 1 | 10 | 63090 | 33 (0)| 00:00:01 | 10 |00:00:00.01 | 22 |
| 3 | TABLE ACCESS BY INDEX ROWID BATCHED| T1 | 1 | 10 | 35050 | 13 (0)| 00:00:01 | 10 |00:00:00.01 | 13 |
|* 4 | INDEX RANGE SCAN | I_T1_ID | 1 | 10 | | 2 (0)| 00:00:01 | 10 |00:00:00.01 | 3 |
|* 5 | INDEX RANGE SCAN | I_T2_ID | 10 | 1 | | 1 (0)| 00:00:01 | 10 |00:00:00.01 | 9 |
| 6 | TABLE ACCESS BY INDEX ROWID | T2 | 10 | 1 | 3505 | 2 (0)| 00:00:01 | 10 |00:00:00.01 | 10 |
-------------------------------------------------------------------------------------------------------------------------------------------
4.其它測試補充:
--//我打開statistics_level = all,也會看不到我前面觀察到的情況.
[email protected]:1521/orcl> @ sl all
alter session set statistics_level = all;
Session altered.
[email protected]:1521/orcl> alter system flush buffer_cache;
System altered.
[email protected]:1521/orcl> SELECT /*+ leading (t1 t2) use_nl(t2) */ t1.id,substr(t1.vc,3496,5) vc1,substr(t2.vc,3496,5) vc2 FROM t1 , t2 WHERE t1.id = t2.id AND t1.id between 1 and 10;
ID VC1 VC2
---------- ---------- ----------
1 1T1T1 2T2T1
2 1T1T2 2T2T2
3 1T1T3 2T2T3
10 1T110 2T210
4 1T1T4 2T2T4
5 1T1T5 2T2T5
6 1T1T6 2T2T6
7 1T1T7 2T2T7
8 1T1T8 2T2T8
9 1T1T9 2T2T9
10 rows selected.
--//如果採用dbms_monitor.session_trace_enable或者dbms_system.set_sql_trace_in_session跟蹤也是一樣.不再貼出.
--//下麵嘗試strace跟蹤看看。
5.使用strace跟蹤看看:
[email protected]:1521/orcl> @ spid
SID SERIAL# PROCESS SERVER SPID PID P_SERIAL# C50
---------- ---------- ------------------------ --------- ------ ------- ---------- --------------------------------------------------
34 44670 10706 DEDICATED 90782 48 101616 alter system kill session '34,44670' immediate;
--//記下spid =90782.
[email protected]:1521/orcl> alter system flush buffer_cache;
System altered.
[email protected]:1521/orcl> SELECT /*+ leading (t1 t2) use_nl(t2) */ t1.id,substr(t1.vc,3496,5) vc1,substr(t2.vc,3496,5) vc2 FROM t1 , t2 WHERE t1.id = t2.id AND t1.id between 1 and 10;
ID VC1 VC2
---------- ---------- ----------
1 1T1T1 2T2T1
2 1T1T2 2T2T2
10 1T110 2T210
9 1T1T9 2T2T9
3 1T1T3 2T2T3
4 1T1T4 2T2T4
5 1T1T5 2T2T5
6 1T1T6 2T2T6
7 1T1T7 2T2T7
8 1T1T8 2T2T8
10 rows selected.
--//再次出現id=10,9在前面的情況.
# strace -fp 90782 -e pread64 -o /tmp/aa.txt
strace: Process 90782 attached
^Cstrace: Process 90782 detached
# cat /tmp/aa.txt
90782 pread64(256, "\6\242\0\0\31\350D\0Q\5\257#\v\0\1\4^\222\0\0\2@F\0\216\300\3\0P\5\257#"..., 8192, 2634227712) = 8192
90782 pread64(256, "\6\242\0\0\32\350D\0Q\5\257#\v\0\2\4'R\0\0\2\0\0\0\216\300\3\0P\5\257#"..., 8192, 2634235904) = 8192
90782 pread64(257, "\6\242\0\0\353J\300\1!\375\256#\v\0\2\4\316\336\0\0\1\0\0\0\214\300\3\0\362\374\256#"..., 8192, 157114368) = 8192
90782 pread64(256, "\6\242\0\0!\350D\0\222\16\257#\v\0\1\4_\252\0\0\2@F\0\217\300\3\0\221\16\257#"..., 8192, 2634293248) = 8192
90782 pread64(256, "\6\242\0\0\"\350D\0\222\16\257#\v\0\2\4\200\351\0\0\2\0\0\0\217\300\3\0\221\16\257#"..., 8192, 2634301440) = 8192
90782 pread64(257, "\6\242\0\0\344I\300\1\216\0\257#\v\0\2\4\230\334\0\0\1\0\0\0\215\300\3\0x\0\257#"..., 8192, 154959872) = 8192
90782 pread64(257, "\6\242\0\0RJ\300\1\32\375\256#\v\0\2\4\366\335\0\0\1\0\0\0\214\300\3\0\362\374\256#"..., 8192, 155860992) = 8192
90782 pread64(257, "\6\242\0\0\3N\300\1\255\0\257#\v\0\2\4\246\336\0\0\1\0\0\0\215\300\3\0x\0\257#"..., 8192, 163602432) = 8192
90782 pread64(257, "\6\242\0\0\33J\300\1\32\375\256#\v\0\2\4\272\331\0\0\1\0\0\0\214\300\3\0\362\374\256#"..., 8192, 155410432) = 8192
90782 pread64(257, "\6\242\0\0*J\300\1\32\375\256#\v\0\2\4\211\333\0\0\1\0\0\0\214\300\3\0\362\374\256#"..., 8192, 155533312) = 8192
90782 pread64(257, "\6\242\0\0?J\300\1\32\375\256#\v\0\2\4\221\330\0\0\1\0\0\0\214\300\3\0\362\374\256#"..., 8192, 155705344) = 8192
90782 pread64(257, "\6\242\0\0\212J\300\1!\375\256#\v\0\2\4\250\334\0\0\1\0\0\0\214\300\3\0\362\374\256#"..., 8192, 156319744) = 8192
90782 pread64(257, "\6\242\0\0\335J\300\1!\375\256#\v\0\2\4\360\326\0\0\1\0\0\0\214\300\3\0\362\374\256#"..., 8192, 156999680) = 8192
90782 pread64(257, "\6\242\0\0\17K\300\1#\375\256#\v\0\2\4\240\327\0\0\1\0\0\0\214\300\3\0\362\374\256#"..., 8192, 157409280) = 8192
90782 pread64(257, "\6\242\0\0:K\300\1#\375\256#\v\0\2\4\232\332\0\0\1\0\0\0\214\300\3\0\362\374\256#"..., 8192, 157761536) = 8192
90782 pread64(257, "\6\242\0\0XK\300\1$\375\256#\v\0\2\4\221\337\0\0\1\0\0\0\214\300\3\0\362\374\256#"..., 8192, 158007296) = 8192
90782 pread64(257, "\6\242\0\0\tL\300\1\235\0\257#\v\0\2\4\311\334\0\0\1\0\0\0\215\300\3\0x\0\257#"..., 8192, 159457280) = 8192
90782 pread64(257, "\6\242\0\0\25L\300\1\235\0\257#\v\0\2\4\275\330\0\0\1\0\0\0\215\300\3\0x\0\257#"..., 8192, 159555584) = 8192
90782 pread64(257, "\6\242\0\0\206L\300\1\243\0\257#\v\0\2\4\244\337\0\0\1\0\0\0\215\300\3\0x\0\257#"..., 8192, 160481280) = 8192
90782 pread64(257, "\6\242\0\0\221L\300\1\244\0\257#\v\0\2\4\262\330\0\0\1\0\0\0\215\300\3\0x\0\257#"..., 8192, 160571392) = 8192
90782 pread64(257, "\6\242\0\0\355L\300\1\244\0\257#\v\0\2\4\315\332\0\0\1\0\0\0\215\300\3\0x\0\257#"..., 8192, 161325056) = 8192
90782 pread64(257, "\6\242\0\0\226M\300\1\255\0\257#\v\0\2\4\271\324\0\0\1\0\0\0\215\300\3\0x\0\257#"..., 8192, 162709504) = 8192
90782 pread64(257, "\6\242\0\0\246M\300\1\255\0\257#\v\0\2\4\212\325\0\0\1\0\0\0\215\300\3\0x\0\257#"..., 8192, 162840576) = 8192
90782 pread64(257, "\6\242\0\0\347M\300\1\255\0\257#\v\0\2\4\310\333\0\0\1\0\0\0\215\300\3\0x\0\257#"..., 8192, 163373056) = 8192
--//抽取第5個欄位就是偏移量，刪除)字元，然後除以8192換算從成塊號。
# awk '{print $5}' /tmp/aa.txt | sed 's/)$//' | xargs -IQ bash -c "echo Q/8192| bc"
321561 --//I_T1_ID 的root,註我的索引建立在system表空間上了，可以發現前面的文件句柄不同。
321562 --//I_T1_ID 的leaf
19179 --//T1 id=1
321569 --//I_T2_ID 的root
321570 --//I_T2_ID 的leaf
18916 --//T2 id=1
19026 --//T1 id=2
19971 --//T2 id=2
~~~~~~~~~~~~~~~~~~~~~~
18971 --//T1 id=6
18986 --//T1 id=4
19007 --//T1 id=7
19082 --//T1 id=3
19165 --//T1 id=9
19215 --//T1 id=8
19258 --//T1 id=5
19288 --//T1 id=10
--//以上8塊是db file parallel read ,id=3..10,你也可以發現實際上db file parallel read讀取的塊是離散的,但是按照從小到大順序讀取.
19465 --//T2 id=10
19477 --//T2 id=5
19590 --//T2 id=3
19601 --//T2 id=4
19693 --//T2 id=6
19862 --//T2 id=8
19878 --//T2 id=9
19943 --//T2 id=7
--//以上7塊還是是db file parallel read,我為什麼這麼猜測,有兩個原因.
--//補充:這裡巧合了T2 id=10的數據塊正好是這些塊中最小的數據塊.實際上T2 id=10的是db file sequential read.看我後面的補充測試.
--//1.讀取block順序按照從小到大排列
--//2.並沒有按照以前看到的nested loop 的輸出順序.
--//這樣如果驗證測試出現2次db file parallel read,就能證明我的判斷是否正確.
--//從跟蹤文件抽取訪問的塊號。
# egrep "db file" /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_80563.trc | awk '{print $10}' | cut -d"=" -f2
321561 --//I_T1_ID 的root
321562 --//I_T1_ID 的leaf
19179 --//T1 id=1
321569 --//I_T2_ID 的root
321570 --//I_T2_ID 的leaf
18916 --//T2 id=1
19026 --//T1 id=2
19971 --//T2 id=2
19082 --//T1 id=3
19590 --//T2 id=3
7 --//T1 讀取id=4..10,db file parallel read 這裡僅僅看到讀取7塊,10046跟蹤不知道具體那些塊.
19465 --//T2 id=10
19601 --//T2 id=4
19477 --//T2 id=5
19693 --//T2 id=6
19943 --//T2 id=7
19862 --//T2 id=8
19878 --//T2 id=9
--//開啟10046看到的情況.
6.驗證過程:
--//退出重新登錄:
--//session 1:
[email protected]:1521/orcl> @ spid
SID SERIAL# PROCESS SERVER SPID PID P_SERIAL# C50
---------- ---------- ------------------------ --------- ------ ------- ---------- --------------------------------------------------
864 10584 11060 DEDICATED 105105 51 72774 alter system kill session '864,10584' immediate;
--//在另外會話執行,session 2:
[email protected]:1521/orcl> alter system flush buffer_cache;
System altered.
[email protected]:1521/orcl> select * from V$SESSION_WAIT_HISTORY where sid=864 and event ='db file parallel read';
no rows selected
--//session 1:
[email protected]:1521/orcl> SELECT /*+ leading (t1 t2) use_nl(t2) */ t1.id,substr(t1.vc,3496,5) vc1,substr(t2.vc,3496,5) vc2 FROM t1 , t2 WHERE t1.id = t2.id AND t1.id between 1 and 10;
ID VC1 VC2
---------- ---------- ----------
1 1T1T1 2T2T1
2 1T1T2 2T2T2
10 1T110 2T210
9 1T1T9 2T2T9
3 1T1T3 2T2T3
4 1T1T4 2T2T4
5 1T1T5 2T2T5
6 1T1T6 2T2T6
7 1T1T7 2T2T7
8 1T1T8 2T2T8
10 rows selected.
[email protected]:1521/orcl> select * from V$SESSION_WAIT_HISTORY where sid=864 and event ='db file parallel read';
SID SEQ# EVENT# EVENT P1TEXT P1 P2TEXT P2 P3TEXT P3 WAIT_TIME WAIT_TIME_MICRO TIME_SINCE_LAST_WAIT_MICRO CON_ID
---------- ---------- ---------- ---------------------- ---------- ---------- ------- ---------- ---------- --- ---------- --------------- -------------------------- ----------
864 2 184 db file parallel read files 1 blocks 7 requests 7 0 115 255 0
864 5 184 db file parallel read files 1 blocks 8 requests 8 0 191 366 0
--//可以發現出現2次db file parallel read.
--//唯一判斷錯誤的地方就是一次requests=7,另外一次requests=8,為什麼?
--//測試statistics_level = all 與 statistics_level = TYPICAL的情況：
--//session 2:
[email protected]:1521/orcl> alter system flush buffer_cache;
System altered.
--//session 1:
[email protected]:1521/orcl> @ sl all
alter session set statistics_level = all;
Session altered.
[email protected]:1521/orcl> SELECT /*+ leading (t1 t2) use_nl(t2) */ t1.id,substr(t1.vc,3496,5) vc1,substr(t2.vc,3496,5) vc2 FROM t1 , t2 WHERE t1.id = t2.id AND t1.id between 1 and 10;
ID VC1 VC2
---------- ---------- ----------
1 1T1T1 2T2T1
2 1T1T2 2T2T2
3 1T1T3 2T2T3
10 1T110 2T210
4 1T1T4 2T2T4
5 1T1T5 2T2T5
6 1T1T6 2T2T6
7 1T1T7 2T2T7
8 1T1T8 2T2T8
9 1T1T9 2T2T9
10 rows selected.
--//打開statistics_level = all看不到我遇到的情況。
--//session 2:
[email protected]:1521/orcl> select * from V$SESSION_WAIT_HISTORY where sid=864 and event ='db file parallel read';
SID SEQ# EVENT# EVENT P1TEXT P1 P2TEXT P2 P3TEXT P3 WAIT_TIME WAIT_TIME_MICRO TIME_SINCE_LAST_WAIT_MICRO CON_ID
---------- ---------- ---------- --------------------- ---------- ---------- ------ ---------- ---------- --- ---------- --------------- -------------------------- ----------
864 8 184 db file parallel read files 1 blocks 7 requests 7 0 111 207 0
--//可以發現出現1次db file parallel read.
--//註意: V$SESSION_WAIT_HISTORY 僅僅保留最後10個等待事件,上面的測試應該不會錯過.
--//session 2:
[email protected]:1521/orcl> alter system flush buffer_cache;
System altered.
--//session 1:
[email protected]:1521/orcl> @ sl TYPICAL
alter session set statistics_level = TYPICAL;
Session altered.
[email protected]:1521/orcl> SELECT /*+ leading (t1 t2) use_nl(t2) */ t1.id,substr(t1.vc,3496,5) vc1,substr(t2.vc,3496,5) vc2 FROM t1 , t2 WHERE t1.id = t2.id AND t1.id between 1 and 10;
ID VC1 VC2
---------- ---------- ----------
1 1T1T1 2T2T1
2 1T1T2 2T2T2
10 1T110 2T210
9 1T1T9 2T2T9
3 1T1T3 2T2T3
4 1T1T4 2T2T4
5 1T1T5 2T2T5
6 1T1T6 2T2T6
7 1T1T7 2T2T7
8 1T1T8 2T2T8
10 rows selected.
--//session 2:
[email protected]:1521/orcl> select * from V$SESSION_WAIT_HISTORY where sid=864 and event ='db file parallel read';
SID SEQ# EVENT# EVENT P1TEXT P1 P2TEXT P2 P3TEXT P3 WAIT_TIME WAIT_TIME_MICRO TIME_SINCE_LAST_WAIT_MICRO CON_ID
---- ----- ------- --------------------- ------ -- ------ --- ---------- --- ---------- --------------- -------------------------- ----------
864 1 184 db file parallel read files 1 blocks 7 requests 7 0 133 139 0
864 4 184 db file parallel read files 1 blocks 8 requests 8 0 119 220 0
--//可以發現出現2次db file parallel read.
7.補充測試：
--//修改提示看看，先訪問T2表。
--//sesion 1:
[email protected]:1521/orcl> alter system flush buffer_cache;
System altered.
--//sesion 2:
[email protected]:1521/orcl> select * from V$SESSION_WAIT_HISTORY where sid=2866 and event ='db file parallel read';
no rows selected
--//sesion 1:
[email protected]:1521/orcl> SELECT /*+ leading (t2 t1) use_nl(t1) */ t1.id,substr(t1.vc,3496,5) vc1,substr(t2.vc,3496,5) vc2 FROM t1 , t2 WHERE t1.id = t2.id AND t1.id between 1 and 10;
ID VC1 VC2
--- ---------- ----------
1 1T1T1 2T2T1
2 1T1T2 2T2T2
10 1T110 2T210
9 1T1T9 2T2T9
3 1T1T3 2T2T3
4 1T1T4 2T2T4
5 1T1T5 2T2T5
6 1T1T6 2T2T6
7 1T1T7 2T2T7
8 1T1T8 2T2T8
10 rows selected.
--//效果一樣.
[email protected]:1521/orcl> select * from V$SESSION_WAIT_HISTORY where sid=2866 and event ='db file parallel read';
SID SEQ# EVENT# EVENT P1TEXT P1 P2TEXT P2 P3TEXT P3 WAIT_TIME WAIT_TIME_MICRO TIME_SINCE_LAST_WAIT_MICRO CON_ID
---- ----- ------- --------------------- ------ -- ------ -- -------- -- ---------- --------------- -------------------------- ----------
2866 1 184 db file parallel read files 1 blocks 7 requests 7 9 89661 359 0
2866 4 184 db file parallel read files 1 blocks 8 requests 8 15 151183 245 0
# strace -fp 80649 -e pread64 -o /tmp/aa1.txt
strace: Process 80649 attached
^Cstrace: Process 80649 detached
# cat /tmp/aa1.txt
80649 pread64(256, "\6\242\0\0!\350D\0\222\16\257#\v\0\1\4_\252\0\0\2@F\0\217\300\3\0\221\16\257#"..., 8192, 2634293248) = 8192
80649 pread64(256, "\6\242\0\0\"\350D\0\222\16\257#\v\0\2\4\200\351\0\0\2\0\0\0\217\300\3\0\221\16\257#"..., 8192, 2634301440) = 8192
80649 pread64(258, "\6\242\0\0\344I\300\1\216\0\257#\v\0\2\4\230\334\0\0\1\0\0\0\215\300\3\0x\0\257#"..., 8192, 154959872) = 8192
80649 pread64(256, "\6\242\0\0\31\350D\0Q\5\257#\v\0\1\4^\222\0\0\2@F\0\216\300\3\0P\5\257#"..., 8192, 2634227712) = 8192
80649 pread64(256, "\6\242\0\0\32\350D\0Q\5\257#\v\0\2\4'R\0\0\2\0\0\0\216\300\3\0P\5\257#"..., 8192, 2634235904) = 8192
80649 pread64(258, "\6\242\0\0\353J\300\1!\375\256#\v\0\2\4\316\336\0\0\1\0\0\0\214\300\3\0\362\374\256#"..., 8192, 157114368) = 8192
80649 pread64(258, "\6\242\0\0\3N\300\1\255\0\257#\v\0\2\4\246\336\0\0\1\0\0\0\215\300\3\0x\0\257#"..., 8192, 163602432) = 8192
80649 pread64(258, "\6\242\0\0RJ\300\1\32\375\256#\v\0\2\4\366\335\0\0\1\0\0\0\214\300\3\0\362\374\256#"..., 8192, 155860992) = 8192
80649 pread64(258, "\6\242\0\0\tL\300\1\235\0\257#\v\0\2\4\311\334\0\0\1\0\0\0\215\300\3\0x\0\257#"..., 8192, 159457280) = 8192
80649 pread64(258, "\6\242\0\0\25L\300\1\235\0\257#\v\0\2\4\275\330\0\0\1\0\0\0\215\300\3\0x\0\257#"..., 8192, 159555584) = 8192
80649 pread64(258, "\6\242\0\0\206L\300\1\243\0\257#\v\0\2\4\244\337\0\0\1\0\0\0\215\300\3\0x\0\257#"..., 8192, 160481280) = 8192
80649 pread64(258, "\6\242\0\0\221L\300\1\244\0\257#\v\0\2\4\262\330\0\0\1\0\0\0\215\300\3\0x\0\257#"..., 8192, 160571392) = 8192
80649 pread64(258, "\6\242\0\0\355L\300\1\244\0\257#\v\0\2\4\315\332\0\0\1\0\0\0\215\300\3\0x\0\257#"..., 8192, 161325056) = 8192
80649 pread64(258, "\6\242\0\0\226M\300\1\255\0\257#\v\0\2\4\271\324\0\0\1\0\0\0\215\300\3\0x\0\257#"..., 8192, 162709504) = 8192
80649 pread64(258, "\6\242\0\0\246M\300\1\255\0\257#\v\0\2\4\212\325\0\0\1\0\0\0\215\300\3\0x\0\257#"..., 8192, 162840576) = 8192
80649 pread64(258, "\6\242\0\0\347M\300\1\255\0\257#\v\0\2\4\310\333\0\0\1\0\0\0\215\300\3\0x\0\257#"..., 8192, 163373056) = 8192
80649 pread64(258, "\6\242\0\0XK\300\1$\375\256#\v\0\2\4\221\337\0\0\1\0\0\0\214\300\3\0\362\374\256#"..., 8192, 158007296) = 8192
80649 pread64(258, "\6\242\0\0\33J\300\1\32\375\256#\v\0\2\4\272\331\0\0\1\0\0\0\214\300\3\0\362\374\256#"..., 8192, 155410432) = 8192
80649 pread64(258, "\6\242\0\0*J\300\1\32\375\256#\v\0\2\4\211\333\0\0\1\0\0\0\214\300\3\0\362\374\256#"..., 8192, 155533312) = 8192
80649 pread64(258, "\6\242\0\0?J\300\1\32\375\256#\v\0\2\4\221\330\0\0\1\0\0\0\214\300\3\0\362\374\256#"..., 8192, 155705344) = 8192
80649 pread64(258, "\6\242\0\0\212J\300\1!\375\256#\v\0\2\4\250\334\0\0\1\0\0\0\214\300\3\0\362\374\256#"..., 8192, 156319744) = 8192
80649 pread64(258, "\6\242\0\0\335J\300\1!\375\256#\v\0\2\4\360\326\0\0\1\0\0\0\214\300\3\0\362\374\256#"..., 8192, 156999680) = 8192
80649 pread64(258, "\6\242\0\0\17K\300\1#\375\256#\v\0\2\4\240\327\0\0\1\0\0\0\214\300\3\0\362\374\256#"..., 8192, 157409280) = 8192
80649 pread64(258, "\6\242\0\0:K\300\1#\375\256#\v\0\2\4\232\332\0\0\1\0\0\0\214\300\3\0\362\374\256#"..., 8192, 157761536) = 8192
# awk '{print $5}' /tmp/aa1.txt | sed 's/)$//' | xargs -IQ bash -c "echo Q/8192| bc"
321569 --//I_T1_ID 的root,註我的索引建立在system表空間上了，可以發現前面的文件句柄不同。
321570 --//I_T1_ID 的leaf
18916 --//T2 id=1
321561 --//I_T2_ID 的root
321562 --//I_T2_ID 的leaf
19179 --//T1 id=1
19971 --//T2 id=2
19026 --//T1 id=2
~~~~~~~~~~~~~~~~~~~~
19465 --//T2 id=10
19477 --//T2 id=5
19590 --//T2 id=3
19601 --//T2 id=4
19693 --//T2 id=6
19862 --//T2 id=8
19878 --//T2 id=9
19943 --//T2 id=7
~~~~~~~~~~~~~~~~~~
--//以上8塊是db file parallel read ,id=3..10,你也可以發現實際上db file parallel read讀取的塊是離散的,但是按照從小到大順序讀取.
19288 --//T1 id=10
--//註意,T1=10的數據塊號是19288.也就是這塊應該是db file sequential read.
18971 --//T1 id=6
18986 --//T1 id=4
19007 --//T1 id=7
19082 --//T1 id=3
19165 --//T1 id=9
19215 --//T1 id=8
19258 --//T1 id=5
--//以上7塊是db file parallel read ,id=3..9,你也可以發現實際上db file parallel read讀取的塊是離散的,但是按照從小到大順序讀取.
--//我建立的表T2正好巧合T2=10的數據塊是id=3..10最小數據塊.
[email protected]:1521/orcl> select * from V$SESSION_WAIT_HISTORY where sid=2866 ;
SID SEQ# EVENT# EVENT P1TEXT P1 P2TEXT P2 P3TEXT P3 WAIT_TIME WAIT_TIME_MICRO TIME_SINCE_LAST_WAIT_MICRO CON_ID
---- ---- ------ --------------------------- --------- ---------- ------ ------ --------- -- ---------- --------------- -------------------------- ----------
2866 1 184 db file parallel read files 1 blocks 7 requests 7 0 1799 272 0
2866 2 562 PGA memory operation 1114112 2 0 0 144 70 0
2866 3 179 db file sequential read file# 7 block# 19288 blocks 1 0 79 76 0
2866 4 184 db file parallel read files 1 blocks 8 requests 8 0 1077 271 0
2866 5 562 PGA memory operation 1114112 1 0 0 48 34 0
2866 6 441 SQL*Net message to client driver id 1413697536 #bytes 1 0 0 1 48 0
2866 7 179 db file sequential read file# 7 block# 19026 blocks 1 0 81 71 0
2866 8 179 db file sequential read file# 7 block# 19971 blocks 1 0 140 115 0
2866 9 445 SQL*Net message from client driver id 1413697536 #bytes 1 0 0 626 139 0
2866 10 179 db file sequential read file# 7 block# 19179 blocks 1 0 73 39 0
10 rows selected.
--//因為V$SESSION_WAIT_HISTORY僅僅記錄會話最後10個等待事件,迴圈使用,db file parallel read 的blocks=7出現在前面很正常.
--//還有一個線索可以證明我的判斷,過濾event like 'db%',order by seq# desc,視乎出現等待事件從SEQ#=1開始插入.
[email protected]:1521/orcl> select * from V$SESSION_WAIT_HISTORY where sid=2866 and event like 'db%' order by seq# desc;
SID SEQ# EVENT# EVENT P1TEXT P1 P2TEXT P2 P3TEXT P3 WAIT_TIME WAIT_TIME_MICRO TIME_SINCE_LAST_WAIT_MICRO CON_ID
---- ---- ------ --------------------------- --------- ---------- ------ ------ --------- -- ---------- --------------- -------------------------- ----------
2866 10 179 db file sequential read file# 7 block# 19179 blocks 1 0 73 39 0
2866 8 179 db file sequential read file# 7 block# 19971 blocks 1 0 140 115 0
2866 7 179 db file sequential read file# 7 block# 19026 blocks 1 0 81 71 0
2866 4 184 db file parallel read files 1 blocks 8 requests 8 0 1077 271 0
2866 3 179 db file sequential read file# 7 block# 19288 blocks 1 0 79 76 0
2866 1 184 db file parallel read files 1 blocks 7 requests 7 0 1799 272 0
6 rows selected.
--//註意看訪問P2參數:
19179 --//T1 id=1
19971 --//T2 id=2
19026 --//T1 id=2
--//出現 db file parallel read 8塊.
19288 --//T1 id=10
--//出現 db file parallel read 7塊.
--//與strace跟蹤看到的順序一致.
5.解析:
--//測試到這裡,我沒給出解析.我前面給出的解析如下:
--//我當時做到這裡db file parallel read最大請求blocks的數量是127(註:這個很容易測試出來)，而且還與arraysize參數有關。
--//oracle執行時先從索引收集rowid,確定那些文件與數據塊要讀取,按照文件號與塊號排序,抽取數據塊進入緩存後,按照索引的讀取順
--//序數據塊(不然不是這樣的順序輸出),當然已經在數據緩存的塊記錄優先填充.當讀取數量達到arraysize或者沒有剩餘記錄時輸出結
--//果,而最後1條記錄會優先輸出,這樣就會出現前面id=10優先輸出的情況.
--//這樣t1.id=10做db file sequential read 連接取出另外t2個表的t2.id=10的記錄.
--//而第2次db file parallel read,id=3..9,這樣id=9的優先輸出,這樣就是了id=10,9在前面的情況.
--//總之,文字不是很好表達.....
