[20250126]21C下测试CBC latch相关测试3.txt

[20250126]21C下测试CBC latch相关测试3.txt

--//元旦前别人问的问题,看vage的<oracle内核技术揭秘>,里面提到的各种情况,实际上从11.2.0.4开始全表扫描,唯一索引,rowid
--//模式以及快速全索引扫描的读读模式下(共享模式)基本不会出现cbc latch,如果出现也许不巧遇到读取cbc latch链时其它 sql 语
--//句修改或者某种操作读取其链表上其它数据块,出现cbc latch。

--//我看了我以前的测试笔记,在21c验证看看是否存在一些变化。
--//最后的结论:21c下基本在读读模式下基本不会出现cbc latch等待事件。

1.环境:
SCOTT@book01p> @ ver2
==============================
PORT_STRING                   : x86_64/Linux 2.4.xx
VERSION                       : 21.0.0.0.0
BANNER                        : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
BANNER_FULL                   : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
Version 21.3.0.0.0
BANNER_LEGACY                 : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
CON_ID                        : 0
PL/SQL procedure successfully completed.

2.建立测试环境:
SCOTT@book01p> create table job_times (sid number, time_ela number,method varchar2(20));
Table created.

SCOTT@book01p> create table t as select rownum id ,cast('test' as varchar2(10)) name from dual ;
Table created.

SCOTT@book01p> alter table t modify ( id  not null );
Table altered.

SCOTT@book01p> create index i_t_id on t(id);
Index created.
--//create unique index i_t_id on t(id);
--//分析表略。

SCOTT@book01p> select rowid from t;

ROWID
------------------
AAAYbIAAMAAAAEDAAA

SCOTT@book01p> @ rowid AAAYbIAAMAAAAEDAAA

DATA_OBJECT_ID       FILE      BLOCK        ROW ROWID_DBA            DBA                  TEXT
-------------- ---------- ---------- ---------- -------------------- -------------------- --------------------------------------------------
        100040         12        259          0  0x3000103           12,259               alter system dump datafile 12 block 259 ;

$ nl loop.txt
     1  declare
     2  v_id number;
     3  v_d date;
     4  begin
     5      for i in 1 .. &&1 loop
     6          select /*+ full(t) &&3 */ count (name) into v_id from t ;
     7          --select /*+ ROWID(t) &&3 */ count (name) into v_id from t where rowid='AAAYbIAAMAAAAEDAAA';
     8          --select /*+ index(t) &&3 */ count (name) into v_id from t ;
     9          --select /*+ index(t) &&3 */ count (name) into v_id from t where id=1;
    10          --select /*+ index_ffs(t) &&3 */ count (*) into v_id from t ;
    11          --select /*+ index_ffs(t) &&3 */ count (name) into v_id from t ;
    12          --select /*+ ROWID(t) &&3 */ count (name) into v_id from t where rowid between 'AAAYbIAAMAAAAEDAAA' and 'AAAYbIAAMAAAAEDAAB';
    13      end loop;
    14  end ;
    15  /

$ cp loop.txt loop.org
--//做1个备份。

$ cat record.txt
set verify off
variable v_method varchar2(20)
exec :v_method := '&&2';

define t=&&1;

@@ loop.txt 5 &&2

insert into job_times values ( sys_context ('userenv', 'sid') ,dbms_utility.get_time ,'&&2') ;
commit ;

@@ loop.txt &&t &&2

update job_times set time_ela = dbms_utility.get_time - time_ela where sid=sys_context ('userenv', 'sid') and method= :v_method;
commit;
quit

--//简单说明:
--//每次测试前我都单独执行要测试sql语句5次。
--//注:唯一索引与非唯一索引分开测试。在提示中加入 &&3,主要避免出现cursor: pin S等待事件。
--//以前测试时分别注解上面的部分,这次通过编写脚本1次完成,事后分析。

$ cat /usr/local/bin/zzdate
#! /bin/bash
#date +"trunc(sysdate)+%H/24+%M/1440+%S/86400 == %Y/%m/%d %T == \"timestamp'%Y-%m-%d %T'\""
oflag=${1:-0}
if [ "$oflag" == "0" ]
then
    /bin/date +"trunc(sysdate)+%H/24+%M/1440+%S/86400 %s.%N"
else
    /bin/date +"trunc(sysdate)+%H/24+%M/1440+%S/86400 == %Y/%m/%d %T === %Y-%m-%d %T == \"timestamp'%Y-%m-%d %T'\" == %s.%N"
fi

$ cat cbc.sh
#! /bin/bash
zzdate ;seq 50 | xargs -I{} -P 50 sqlplus -s -l scott/book@book01p @record.txt 1e5 p1full=50 {} >/dev/null         ; zzdate  ; sleep 3
sed  -e "7s/ --select/ select/;6s/ select/ --select/" loop.org >| loop.txt ; sleep 3
zzdate ;seq 50 | xargs -I{} -P 50 sqlplus -s -l scott/book@book01p @record.txt 1e5 p1rowid=50 {} >/dev/null        ; zzdate  ; sleep 3
sed  -e "8s/ --select/ select/;6s/ select/ --select/" loop.org >| loop.txt ; sleep 3
zzdate ;seq 50 | xargs -I{} -P 50 sqlplus -s -l scott/book@book01p @record.txt 1e5 p1index_fs=50 {} >/dev/null     ; zzdate  ; sleep 3
sed  -e "9s/ --select/ select/;6s/ select/ --select/" loop.org >| loop.txt ; sleep 3
zzdate ;seq 50 | xargs -I{} -P 50 sqlplus -s -l scott/book@book01p @record.txt 1e5 p1not_uniindex=50 {} >/dev/null ; zzdate  ; sleep 3

sqlplus -s -l scott/book@book01p <<EOF > /dev/null
drop index i_t_id;
create unique index i_t_id on t(id);
quit
EOF
sleep 3

sed  -e "9s/ --select/ select/;6s/ select/ --select/" loop.org >| loop.txt ; sleep 3
zzdate ;seq 50 | xargs -I{} -P 50 sqlplus -s -l scott/book@book01p @record.txt 1e5 p1uniindex=50 {} >/dev/null     ; zzdate  ; sleep 3
sed  -e "10s/ --select/ select/;6s/ select/ --select/" loop.org >| loop.txt ; sleep 3
zzdate ;seq 50 | xargs -I{} -P 50 sqlplus -s -l scott/book@book01p @record.txt 1e5 p1indexffs=50 {} >/dev/null     ; zzdate  ; sleep 3
sed  -e "11s/ --select/ select/;6s/ select/ --select/" loop.org >| loop.txt ; sleep 3
zzdate ;seq 50 | xargs -I{} -P 50 sqlplus -s -l scott/book@book01p @record.txt 1e5 p1indexffs_name=50 {} >/dev/null; zzdate  ; sleep 3
sed  -e "12s/ --select/ select/;6s/ select/ --select/" loop.org >| loop.txt ; sleep 3
zzdate ;seq 50 | xargs -I{} -P 50 sqlplus -s -l scott/book@book01p @record.txt 1e5 p1rowidbetween=50 {} >/dev/null ; zzdate  ; sleep 3

3.测试:

$ ./cbc.sh
trunc(sysdate)+10/24+02/1440+17/86400 1737856937.538492067 --//p1full=50
trunc(sysdate)+10/24+02/1440+51/86400 1737856971.080736611 --//p1full=50
trunc(sysdate)+10/24+02/1440+57/86400 1737856977.104675637 --//p1rowid=50
trunc(sysdate)+10/24+03/1440+18/86400 1737856998.830892448 --//p1rowid=50
trunc(sysdate)+10/24+03/1440+24/86400 1737857004.857847072 --//p1index_fs=50
trunc(sysdate)+10/24+03/1440+51/86400 1737857031.926570616 --//p1index_fs=50
trunc(sysdate)+10/24+03/1440+58/86400 1737857038.025721712 --//p1not_uniindex=50
trunc(sysdate)+10/24+04/1440+25/86400 1737857065.447614390 --//p1not_uniindex=50
trunc(sysdate)+10/24+04/1440+34/86400 1737857074.939554813 --//p1uniindex=50
trunc(sysdate)+10/24+04/1440+59/86400 1737857099.305470088 --//p1uniindex=50
trunc(sysdate)+10/24+05/1440+05/86400 1737857105.335346726 --//p1indexffs=50
trunc(sysdate)+10/24+05/1440+35/86400 1737857135.209955032 --//p1indexffs=50
trunc(sysdate)+10/24+05/1440+41/86400 1737857141.237311933 --//p1indexffs_name=50
trunc(sysdate)+10/24+06/1440+08/86400 1737857168.105481296 --//p1indexffs_name=50
trunc(sysdate)+10/24+06/1440+14/86400 1737857174.136546278 --//p1rowidbetween=50
trunc(sysdate)+10/24+07/1440+05/86400 1737857225.854915004 --//p1rowidbetween=50

SCOTT@book01p> Select method,count(*),round(avg(TIME_ELA),2),sum(TIME_ELA) from job_times group by method order by 3 ;
METHOD                 COUNT(*) ROUND(AVG(TIME_ELA),2) SUM(TIME_ELA)
-------------------- ---------- ---------------------- -------------
p1rowid=50                   50                1701.36         85068
p1uniindex=50                50                1947.46         97373
p1indexffs_name=50           50                2207.38        110369
p1index_fs=50                50                2227.10        111355
p1not_uniindex=50            50                2232.82        111641
p1indexffs=50                50                2498.16        124908
p1full=50                    50                2806.38        140319
p1rowidbetween=50            50                4670.06        233503
8 rows selected.

SYS@book> @ ashtop event 1=1 trunc(sysdate)+10/24+02/1440+17/86400 trunc(sysdate)+10/24+07/1440+05/86400
    Total                                                                                                      Distinct Distinct    Distinct
  Seconds     AAS %This   EVENT                                      FIRST_SEEN          LAST_SEEN           Execs Seen  Tstamps Execs Seen1
--------- ------- ------- ------------------------------------------ ------------------- ------------------- ---------- -------- -----------
    10083    35.0   99% |                                            2025-01-26 10:02:18 2025-01-26 10:07:04       6165      254        6415
       41      .1    0% | latch: cache buffers chains                2025-01-26 10:04:56 2025-01-26 10:04:56         41        1          41
       28      .1    0% | log file sync                              2025-01-26 10:02:19 2025-01-26 10:06:15          1       24          24
       18      .1    0% | log file parallel write                    2025-01-26 10:02:19 2025-01-26 10:06:07          1       16          16
        3      .0    0% | buffer busy waits                          2025-01-26 10:02:46 2025-01-26 10:03:50          3        3           3
        3      .0    0% | db file async I/O submit                   2025-01-26 10:03:38 2025-01-26 10:04:07          1        3           3
        2      .0    0% | LGWR all worker groups                     2025-01-26 10:03:58 2025-01-26 10:04:52          1        2           2
        2      .0    0% | control file parallel write                2025-01-26 10:03:58 2025-01-26 10:04:37          1        2           2
        2      .0    0% | library cache lock                         2025-01-26 10:05:07 2025-01-26 10:05:41          1        2           2
        1      .0    0% | LGWR any worker group                      2025-01-26 10:03:51 2025-01-26 10:03:51          1        1           1
10 rows selected.
--//注意出现latch: cache buffers chains实际上是例外,注意看出现时间FIRST_SEEN,LAST_SEEN都是2025-01-26 10:04:56,结合前面的测试
--//出现在p1uniindex=50测试的中间,一定是某种情况下其他sql语句dml相应的其链表上其它数据块。按照以前测试唯一索引的情况不
--//可能出现cbc latch的情况。
--//另外注意p1indexffs_name执行计划没有走INDEX FAST FULL SCAN,实测走INDEX FULL SCAN。与p1index_fs=50执行计划一样,两者
--//执行时间很近。

--//你可以反复测试,注意几点测试前删除job_times历史记录,或者将p1full=50里面的p1换成p2,其他类似。
--//cp loop.org loop.txt
--//删除唯一索引建立非唯一索引。
SCOTT@book01p> drop index I_T_id;
Index dropped.

SCOTT@book01p> create index i_t_id on t(id);
Index created.
--//再次重复测试。

$ ./cbc.sh
trunc(sysdate)+10/24+29/1440+54/86400 1737858594.555119387   --//p1full=50
trunc(sysdate)+10/24+30/1440+27/86400 1737858627.969930537   --//p1full=50
trunc(sysdate)+10/24+30/1440+33/86400 1737858633.990790800   --//p1rowid=50
trunc(sysdate)+10/24+30/1440+55/86400 1737858655.643774464   --//p1rowid=50
trunc(sysdate)+10/24+31/1440+01/86400 1737858661.666324298   --//p1index_fs=50
trunc(sysdate)+10/24+31/1440+28/86400 1737858688.959980423   --//p1index_fs=50
trunc(sysdate)+10/24+31/1440+34/86400 1737858694.990671347   --//p1not_uniindex=50
trunc(sysdate)+10/24+32/1440+02/86400 1737858722.545533124   --//p1not_uniindex=50
trunc(sysdate)+10/24+32/1440+11/86400 1737858731.927879180   --//p1uniindex=50
trunc(sysdate)+10/24+32/1440+36/86400 1737858756.155145726   --//p1uniindex=50
trunc(sysdate)+10/24+32/1440+42/86400 1737858762.185372947   --//p1indexffs=50
trunc(sysdate)+10/24+33/1440+11/86400 1737858791.988325479   --//p1indexffs=50
trunc(sysdate)+10/24+33/1440+18/86400 1737858798.011357505   --//p1indexffs_name=50
trunc(sysdate)+10/24+33/1440+44/86400 1737858824.918728561   --//p1indexffs_name=50
trunc(sysdate)+10/24+33/1440+50/86400 1737858830.936238984   --//p1rowidbetween=50
trunc(sysdate)+10/24+34/1440+42/86400 1737858882.943849645   --//p1rowidbetween=50

SCOTT@book01p> Select method,count(*),round(avg(TIME_ELA),2),sum(TIME_ELA) from job_times group by method order by 3 ;
METHOD                 COUNT(*) ROUND(AVG(TIME_ELA),2) SUM(TIME_ELA)
-------------------- ---------- ---------------------- -------------
p2rowid=50                   50                1652.76         82638
p2uniindex=50                50                1927.50         96375
p2indexffs_name=50           50                2207.94        110397
p2index_fs=50                50                2216.12        110806
p2not_uniindex=50            50                2258.60        112930
p2indexffs=50                50                2495.88        124794
p2full=50                    50                2853.44        142672
p2rowidbetween=50            50                4640.62        232031
8 rows selected.

SYS@book> @ ashtop event 1=1 trunc(sysdate)+10/24+29/1440+54/86400 trunc(sysdate)+10/24+34/1440+42/86400
    Total                                                                                                      Distinct Distinct    Distinct
  Seconds     AAS %This   EVENT                                      FIRST_SEEN          LAST_SEEN           Execs Seen  Tstamps Execs Seen1
--------- ------- ------- ------------------------------------------ ------------------- ------------------- ---------- -------- -----------
    10101    35.1  100% |                                            2025-01-26 10:29:55 2025-01-26 10:34:41       6113      238        6347
       20      .1    0% | log file sync                              2025-01-26 10:29:55 2025-01-26 10:33:42          1       17          17
        4      .0    0% | log file parallel write                    2025-01-26 10:32:01 2025-01-26 10:33:42          1        4           4
        1      .0    0% | buffer busy waits                          2025-01-26 10:33:09 2025-01-26 10:33:09          1        1           1
        1      .0    0% | oracle thread bootstrap                    2025-01-26 10:31:05 2025-01-26 10:31:05          1        1           1
        1      .0    0% | os thread creation                         2025-01-26 10:31:05 2025-01-26 10:31:05          1        1           1
6 rows selected.
--//这次测试不出现cbc latch等待事件。

4.总结:
--//从执行时间上可以看出在读读模式下,21c oracle改进算法,基本不会存在cbc latch等待事件。
--//基本在读读模式下以逻辑读数量决定执行的快慢,出现index full scan比index fast full scan快的情况,因为前者逻辑读更少。
--//另外index fast full scan,看到的4个逻辑读,有点意外:

SCOTT@book01p> select /*+ index_ffs(t) &&3 */ count (*) into_v_id from t ;
 INTO_V_ID
----------
         1

SCOTT@book01p> @dpc '' '' ''
PLAN_TABLE_OUTPUT
-------------------------------------
SQL_ID  48312yp9wvpsz, child number 0
-------------------------------------
select /*+ index_ffs(t)  */ count (*) into_v_id from t
Plan hash value: 3548397654
------------------------------------------------------------------------------------------------------------------
| Id  | Operation             | Name   | Starts | E-Rows | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |
------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT      |        |      1 |        |     2 (100)|          |      1 |00:00:00.02 |       4 |
|   1 |  SORT AGGREGATE       |        |      1 |      1 |            |          |      1 |00:00:00.02 |       4 |
|   2 |   INDEX FAST FULL SCAN| I_T_ID |      1 |      1 |     2   (0)| 00:00:01 |      1 |00:00:00.02 |       4 |
------------------------------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
   1 - SEL$1
   2 - SEL$1 / "T"@"SEL$1"
Hint Report (identified by operation id / Query Block Name / Object Alias):
Total hints for statement: 1
---------------------------------------------------------------------------
   2 -  SEL$1 / "T"@"SEL$1"
           -  index_ffs(t)
27 rows selected.
--//11g下是3个逻辑读。

--//以前11.2.0.4在读读模式,看到cbc latch更多的应该是索引段,而且执行计划可能是索引范围扫描,非唯一索引,索引全扫描.
--//贴一个11g下的测试:
SCOTT@book> Select method,count(*),round(avg(TIME_ELA),0),sum(TIME_ELA) from scott.job_times group by method order by 3 ;
METHOD                 COUNT(*) ROUND(AVG(TIME_ELA),0) SUM(TIME_ELA)
-------------------- ---------- ---------------------- -------------
p1rowid=150                 150                   2280        341990
p1uniindex=150              150                   2382        357225
p1indexffs_name=150         150                   2669        400324
p1indexffs=150              150                   2698        404737
p1full=150                  150                   2769        415285
p1rowidbetween=150          150                   4357        653557
p1index_fs=150              150                   6748       1012159
p1not_uniindex=150          150                   7046       1056924
8 rows selected.
--//很明显11g select /*+ index(t) &&3 */ count (name) into v_id from t where id=1;,非唯一索引很慢。
--//实际上我总有一种感觉11g下存在"bug",非唯一索引对比唯一索引差距太大了,或者讲这样的情况下cbc latch对性能影响很大。
--//p1rowidbetween,p1index_fs,p1not_uniindex的测试在11g下都存在cbc latch等待事情。

5.补充:
--//利用前面写的fetch21.gdb脚本看看为什么rowid between与rowid范围存在3倍的性能差距。
--//session 1:
SCOTT@book01p> @ spid
==============================
SID                           : 278
SERIAL#                       : 55091
PROCESS                       : 5204
SERVER                        : DEDICATED
SPID                          : 5206
PID                           : 62
P_SERIAL#                     : 8
KILL_COMMAND                  : alter system kill session '278,55091' immediate;
PL/SQL procedure successfully completed.

SCOTT@book01p> @ 46on 1
Session altered.

SCOTT@book01p> select /*+ ROWID(t) &&3 */ count (name) into_v_id from t where rowid between 'AAAYbIAAMAAAAEDAAA' and 'AAAYbIAAMAAAAEDAAB';
INTO_V_ID
----------
         1

--//window 1:
$ rlgdb -f -p 5206 -x fetch21.gdb
...
/usr/src/debug/glibc-2.17-c758a686/sysdeps/unix/syscall-template.S:81:3374:beg:0x7f6d4c1da480
Breakpoint 1 at 0x7f6d4bcd9bf9: __read_nocancel. (2 locations)
Breakpoint 2 at 0x14dd2840
Breakpoint 3 at 0x150bacb0
Breakpoint 4 at 0x14dd4740
Breakpoint 5 at 0x14f2a770
Breakpoint 6 at 0x14f5c760
Breakpoint 7 at 0x14f29780
Breakpoint 8 at 0x150a2220
(gdb) c
Continuing.
2025/01/26 11:04:49.077611860 :kteinpscan_int1 0x3000102 file#=12 block_no=258
2025/01/26 11:04:49.082696830 :kteinmap        0x3000102 file#=12 block_no=258
2025/01/26 11:04:49.088454039 :kdst_fetch      0x3000103 file#=12 block_no=259

--//session 1:
SCOTT@book01p> select /*+ ROWID(t) &&3 */ count (name) into_v_id from t where rowid='AAAYbIAAMAAAAEDAAA';
INTO_V_ID
----------
         1

--//window 1:
2025/01/26 11:05:53.253198785 :kdsgrp          0x3000103 file#=12 block_no=259
--//两者的访问方式完成不同。rowid between慢正常。

$ ./lookup.awk    kdsgrp
kdsgrp : kernel data seek/scan fetch by rowid get row piece

--//再来看看全表扫描
SCOTT@book01p> select /*+ full(t) &&3 */ count (name) into_v_id from t ;
 INTO_V_ID
----------
         1

--//window 1:
2025/01/26 11:08:42.287292888 :kteinpscan_int1 0x3000102 file#=12 block_no=258
2025/01/26 11:08:42.292047723 :kteinmap        0x3000102 file#=12 block_no=258
2025/01/26 11:08:42.297356754 :kdst_fetch      0x3000103 file#=12 block_no=259

--//index fast full scan
SCOTT@book01p> select /*+ index_ffs(t) &&3 */ count (*) into_v_id from t ;

 INTO_V_ID
----------
         1

--//window 1:
2025/01/26 11:13:32.991092039 :kteinpscan_int1 0x300010a file#=12 block_no=266
2025/01/26 11:13:32.995674582 :kteinmap        0x300010a file#=12 block_no=266
2025/01/26 11:13:33.000401776 :kteinpscan_int1 0x300010a file#=12 block_no=266
2025/01/26 11:13:33.004838100 :kteinmap        0x300010a file#=12 block_no=266
2025/01/26 11:13:33.009830359 :kdirfrs         0x300010b file#=12 block_no=267

--//index full scan
SCOTT@book01p> select /*+ index_ffs(t) &&3 */ count (name) into_v_id from t ;
INTO_V_ID
----------
         1

--//window 1:
2025/01/26 11:13:54.426074276 :kdifkc          0x300010b file#=12 block_no=267
2025/01/26 11:13:54.430829871 :kdifxs0         0x300010b file#=12 block_no=267
2025/01/26 11:13:54.435561435 :kdsgrp          0x3000103 file#=12 block_no=259



posted @   lfree  阅读(2)  评论(0编辑  收藏  举报
相关博文:
阅读排行:
· 本地部署 DeepSeek:小白也能轻松搞定!
· 传国玉玺易主,ai.com竟然跳转到国产AI
· 自己如何在本地电脑从零搭建DeepSeek!手把手教学,快来看看! (建议收藏)
· 我们是如何解决abp身上的几个痛点
· 如何基于DeepSeek开展AI项目
历史上的今天:
2023-01-26 [20230125]21c Force matching signature的计算.txt
点击右上角即可分享
微信分享提示