[20231023]为什么刷新缓存后输出记录顺序发生变化6.txt --//前几天做了单表刷新缓存后输出记录顺序发生变化的情况,测试2个表的情况时遇到一个奇怪的现象。 --//我前面的测试18c,如果使用10046跟踪看不到我遇到的情况,我想使用strace跟踪,发现该机器配置使用asm,strace跟踪无法看到一 --//些细节问题。换一台19c的文件型数据库测试看看。 1.环境: SYS@192.168.100.235:1521/orcl> @ ver1 SYS@192.168.100.235: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上进行.但是我发现我还是测试不出来,在备库好像刷新 --//数据缓存无效. SYS@192.168.100.237:1521/orcldg> alter system flush buffer_cache; System altered. SYS@192.168.100.237: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说明情况. --//没有办法先在主库测试看看. SYS@192.168.100.235:1521/orcl> alter system flush buffer_cache; System altered. SYS@192.168.100.235: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上的测试. --//在主库上测试能够再现我遇到的问题. SYS@192.168.100.235:1521/orcl> alter system flush buffer_cache; System altered. SYS@192.168.100.235:1521/orcl> @ 10046on 12 Session altered. SYS@192.168.100.235: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记录在前. SYS@192.168.100.235:1521/orcl> @ 10046off Session altered. SYS@192.168.100.235: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. SYS@192.168.100.235: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. SYS@192.168.100.235: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,也会看不到我前面观察到的情况. SYS@192.168.100.235:1521/orcl> @ sl all alter session set statistics_level = all; Session altered. SYS@192.168.100.235:1521/orcl> alter system flush buffer_cache; System altered. SYS@192.168.100.235: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跟踪看看: SYS@192.168.100.235: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. SYS@192.168.100.235:1521/orcl> alter system flush buffer_cache; System altered. SYS@192.168.100.235: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: SYS@192.168.100.235: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: SYS@192.168.100.235:1521/orcl> alter system flush buffer_cache; System altered. SYS@192.168.100.235:1521/orcl> select * from V$SESSION_WAIT_HISTORY where sid=864 and event ='db file parallel read'; no rows selected --//session 1: SYS@192.168.100.235: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. SYS@192.168.100.235: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: SYS@192.168.100.235:1521/orcl> alter system flush buffer_cache; System altered. --//session 1: SYS@192.168.100.235:1521/orcl> @ sl all alter session set statistics_level = all; Session altered. SYS@192.168.100.235: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: SYS@192.168.100.235: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: SYS@192.168.100.235:1521/orcl> alter system flush buffer_cache; System altered. --//session 1: SYS@192.168.100.235:1521/orcl> @ sl TYPICAL alter session set statistics_level = TYPICAL; Session altered. SYS@192.168.100.235: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: SYS@192.168.100.235: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: SYS@192.168.100.235:1521/orcl> alter system flush buffer_cache; System altered. --//sesion 2: SYS@192.168.100.235:1521/orcl> select * from V$SESSION_WAIT_HISTORY where sid=2866 and event ='db file parallel read'; no rows selected --//sesion 1: SYS@192.168.100.235: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. --//效果一样. SYS@192.168.100.235: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最小数据块. SYS@192.168.100.235: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开始插入. SYS@192.168.100.235: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在前面的情况. --//总之,文字不是很好表达.....
[20231023]为什么刷新缓存后输出记录顺序发生变化6.txt
来源:这里教程网
时间:2026-03-03 19:00:56
作者:
编辑推荐:
- [20231023]为什么刷新缓存后输出记录顺序发生变化6.txt03-03
- [20231026]enq TX - allocate ITL entry的测试4.txt03-03
- [20231027]Index ITL Limit 3.txt03-03
- [20231101]tmux环境变量的继承问题.txt03-03
- [20231031]Index ITL Limit 4.txt03-03
- [20231101]记录自己工作中1次失误.txt03-03
- [20231023]生成bbed的执行脚本(bash shell).txt03-03
- [20231101]使用tpt seg2.sql脚本问题.txt03-03
下一篇:
相关推荐
-
雷神推出 MIX PRO II 迷你主机:基于 Ultra 200H,玻璃上盖 + ARGB 灯效
2 月 9 日消息,雷神 (THUNDEROBOT) 现已宣布推出基于英
-
制造商 Musnap 推出彩色墨水屏电纸书 Ocean C:支持手写笔、第三方安卓应用
2 月 10 日消息,制造商 Musnap 现已在海外推出一款 Oce
热文推荐
- 阿里大文娱整合背后,行业产业化周期正式开启
阿里大文娱整合背后,行业产业化周期正式开启
26-03-03 - 记一次rac TNS-12541,ORA-12520,ORA-12521 错误处理
- ORA-02354 ORA-01555 ORA-22924
ORA-02354 ORA-01555 ORA-22924
26-03-03 - 修改主机时区对Oracle的影响分析
修改主机时区对Oracle的影响分析
26-03-03 - Oracle 标准审计功能及开启
Oracle 标准审计功能及开启
26-03-03 - 研究Oracle 延迟块清除(defered block cleanout)
- ORACLE下一次奇怪的job停止问题分析及处理
ORACLE下一次奇怪的job停止问题分析及处理
26-03-03 - Oracle标准审计,关闭AUDIT
Oracle标准审计,关闭AUDIT
26-03-03 - Oracle 在查询的where子句中,索引的索引列/前导列是否作为单个表谓词提供列进行匹配
- Oracle 标准审计,设置AUDIT_SYSLOG _LEVEL参数
Oracle 标准审计,设置AUDIT_SYSLOG _LEVEL参数
26-03-03
