[20210220]gdb跟蹤邏輯讀2.txt
[20210220]gdb跟蹤邏輯讀2.txt
--//有了昨天的測試,連結如下:
--//http://blog.itpub.net/267265/viewspace-2757857/ =>[20210219]全表掃描邏輯讀問題.txt
--//http://blog.itpub.net/267265/viewspace-2757859/ => [20210220]全索引掃描快速索引掃描的邏輯讀.txt
--//知道這些函式,就可以寫出gdb指令碼,跟蹤那些邏輯讀.檢視register,以及某些暫存器的地址就可以知道帶入的引數,我主要想知道讀那
--//些資料塊. 過程略.我僅僅貼出gdb指令碼,肯定存在許多錯誤.
1.環境:
SYS@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
2.gdb指令碼:
$ cat gdb/fetch.gdb
break sntpread
set pagination off
commands
silent
set var a=0x0
set var b=0x0
continue
end
break kteinpscan
set pagination off
commands
silent
shell echo -n $( date +"%Y/%m/%d %T.%N : ")
printf "kteinpscan 0x%x\n", *($rdi+4)
continue
end
break kdst_fetch if *($rsi+28) != 0
set pagination off
commands
silent
shell echo -n $( date +"%Y/%m/%d %T.%N : ")
printf "kdst_fetch 0x%x\n", *($rsi+28)
continue
end
break kteinmap
set pagination off
commands
silent
shell echo -n $( date +"%Y/%m/%d %T.%N : ")
printf "kteinmap 0x%x\n", *($rdi+4)
continue
end
#set var a=0x0
break kdifxs if *($rdi+28) != a
set pagination off
commands
silent
shell echo -n $( date +"%Y/%m/%d %T.%N : ")
printf "kdifxs 0x%x\n", *($rdi+28)
set var a= *($rdi+28)
continue
end
#set var b=0x0
break kdsgrp if *($rdi+28) != b
set pagination off
commands
silent
shell echo -n $( date +"%Y/%m/%d %T.%N : ")
printf "kdsgrp 0x%x\n", *($rdi+28)
set var b= *($rdi+28)
continue
end
#break kdircys
#set pagination off
# commands
# silent
# shell echo -n $( date +"%Y/%m/%d %T.%N : ")
# printf "kdircys 0x%x\n", *($rdi+4)
# continue
# end
#break qeilbk
#set pagination off
# commands
# silent
# shell echo -n $( date +"%Y/%m/%d %T.%N : ")
# printf "qeilbk 0x%x\n", *($rsi+28)
# continue
# end
--//說明:qeilbk,kdircys函式無法跟蹤,我不知道為什麼? kdifxs 視乎每取1行呼叫1次,改寫成上面的樣子.邏輯讀統計肯定有問題的.特
--//別是設定array很小的情況.另外kdsgrp類似,估計臨近的塊算1個邏輯讀.
--//另外我還遇到kdst_fetch *($rsi+28) = 0的情況.我不跟蹤這樣的情況.
--//我多設定斷點break sntpread,主要目的是為了初始話a,b變數值為0,不然下次執行的sql記錄的是新的值,這樣可能會漏掉一些資訊.
3.測試前準備與說明:
--//注意測試前sql語句最好多次避免一些遞迴,還有一些大表可能採用直接路徑讀,繞過了oracle的資料快取,自然看不到.
--//還有唯一索引,索引root節點,分支節點跟蹤不到,或者使用的函式我不知道暫時放棄.
--//另外測試沒有考慮讀undo的情況,先暫時放棄.
--//sesion 1:
SCOTT@book> @ spid
SID SERIAL# PROCESS SERVER SPID PID P_SERIAL# C50
---------- ---------- ------------------------ --------- ------ ------- ---------- --------------------------------------------------
295 5 46722 DEDICATED 46723 21 3 alter system kill session '295,5' immediate;
--//sesion 2:
$ gdb -p 46723 -x ~/gdb/fetch.gdb
...
Breakpoint 1 at 0x994df72
Breakpoint 2 at 0xfcafda
Breakpoint 3 at 0x947da78
Breakpoint 4 at 0xfc97f0
Breakpoint 5 at 0x95ed0ca
Breakpoint 6 at 0x94471a4
(gdb)
4.測試:
--//測試結果以後面的gdb指令碼為準.
--//全表掃描:
select * from emp;
--//跟蹤檔案:
*** 2021-02-20 15:34:21.723
pin ktewh26: kteinpscan dba 0x1000092:4 time 2565022127
pin kdswh11: kdst_fetch dba 0x1000093:1 time 2565028245
pin kdswh11: kdst_fetch dba 0x1000094:1 time 2565033596
pin kdswh11: kdst_fetch dba 0x1000095:1 time 2565038986
pin kdswh11: kdst_fetch dba 0x1000096:1 time 2565044408
pin kdswh11: kdst_fetch dba 0x1000097:1 time 2565049667
pin kdswh11: kdst_fetch dba 0x1000097:1 time 2565070280
--//gdb:
2021/02/20 15:34:57.544337510 :kteinpscan 0x1000092
2021/02/20 15:34:57.549826022 :kteinmap 0x1000092
2021/02/20 15:34:57.555883105 :kdst_fetch 0x1000093
2021/02/20 15:34:57.561262392 :kdst_fetch 0x1000094
2021/02/20 15:34:57.566930570 :kdst_fetch 0x1000095
2021/02/20 15:34:57.572255586 :kdst_fetch 0x1000096
2021/02/20 15:34:57.591945115 :kdst_fetch 0x1000097
2021/02/20 15:34:57.597271327 :kdst_fetch 0x1000097
--//注extent僅僅1個的情況下,"_trace_pin_time"=1跟蹤看不到kteinmap,實際邏輯讀是7.
--//INDEX FULL SCAN:
select count(*) from emp;
--//跟蹤檔案:
*** 2021-02-20 15:35:35.428
pin qeilwhrp: qeilbk dba 0x100009b:1 time 2638727352
--//gdb:
2021/02/20 15:36:05.752024571 :kdifxs 0x100009b
--//INDEX FAST FULL SCAN
select /*+ index_ffs(emp) */ count(*) from emp;
--//跟蹤檔案:
*** 2021-02-20 15:36:45.413
pin ktewh26: kteinpscan dba 0x100009a:4 time 2708712237
pin kdiwh100: kdircys dba 0x100009b:1 time 2708717602
--//gdb顯示:
2021/02/20 15:36:45.400717820 :kteinpscan 0x100009a
2021/02/20 15:36:45.406515456 :kteinmap 0x100009a
2021/02/20 15:36:45.411622200 :kteinpscan 0x100009a
2021/02/20 15:36:45.416993772 :kteinmap 0x100009a
--// TABLE ACCESS BY USER ROWID
select * from emp where rowid='AAAVREAAEAAAACXAAA';
--//跟蹤檔案:
*** 2021-02-20 15:38:29.342
pin kdswh05: kdsgrp dba 0x1000097:1 time 2812641841
--//gdb顯示:
2021/02/20 15:38:29.334660926 :kdsgrp 0x1000097
--//這個結果使用上面的gdb指令碼:
--//INDEX RANGE SCAN
SCOTT@book> select * from emp where empno between 7788 and 7900;
EMPNO ENAME JOB MGR HIREDATE SAL COMM DEPTNO
---------- ---------- --------- ---------- ------------------- ---------- ---------- ----------
7788 SCOTT ANALYST 7566 1987-04-19 00:00:00 3000 20
7839 KING PRESIDENT 1981-11-17 00:00:00 5000 10
7844 TURNER SALESMAN 7698 1981-09-08 00:00:00 1500 0 30
7876 ADAMS CLERK 7788 1987-05-23 00:00:00 1100 20
7900 JAMES CLERK 7698 1981-12-03 00:00:00 950 30
--//跟蹤檔案:
*** 2021-02-20 15:46:16.744
pin qeilwhrp: qeilbk dba 0x100009b:1 time 3280043412
pin kdswh05: kdsgrp dba 0x1000097:1 time 3280070000
pin kdiwh16: kdifxs dba 0x100009b:1 time 3280096298
pin kdswh05: kdsgrp dba 0x1000097:1 time 3280108554
--//gdb顯示:
2021/02/20 15:46:16.749466318 :kdifxs 0x100009b
2021/02/20 15:46:16.762301302 :kdsgrp 0x1000097
2021/02/20 15:46:16.788847316 :kdifxs 0x100009b
2021/02/20 15:46:16.801327592 :kdsgrp 0x1000097
Plan hash value: 169057108
--------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
--------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 2 (100)| | 5 |00:00:00.03 | 4 |
| 1 | TABLE ACCESS BY INDEX ROWID| EMP | 1 | 5 | 190 | 2 (0)| 00:00:01 | 5 |00:00:00.03 | 4 |
|* 2 | INDEX RANGE SCAN | PK_EMP | 1 | 5 | | 1 (0)| 00:00:01 | 5 |00:00:00.01 | 2 |
--------------------------------------------------------------------------------------------------------------------------------
--//再找一條sql語句測試看看.
SCOTT@book> select /*+ index(t) */ CREATED from t where owner='SCOTT';
Plan hash value: 3696261165
--------------------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
--------------------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 2237 (100)| | 22 |00:00:00.20 | 18 |
| 1 | TABLE ACCESS BY INDEX ROWID| T | 1 | 2923 | 40922 | 2237 (0)| 00:00:27 | 22 |00:00:00.20 | 18 |
|* 2 | INDEX RANGE SCAN | I_T_OWNER_OBJ_NAME | 1 | 2923 | | 19 (0)| 00:00:01 | 22 |00:00:00.02 | 4 |
--------------------------------------------------------------------------------------------------------------------------------------------
--//跟蹤檔案:
*** 2021-02-20 15:51:01.925
pin qeilwhnp: qeilbk dba 0x1000e8f:1 time 3565224759
pin kdswh05: kdsgrp dba 0x100074c:1 time 3565254780
pin kdiwh16: kdifxs dba 0x1000e8f:1 time 3565290060
pin kdswh05: kdsgrp dba 0x1000755:1 time 3565302136
pin kdswh05: kdsgrp dba 0x100074c:1 time 3565314752
pin kdswh05: kdsgrp dba 0x1000755:1 time 3565327400
pin kdswh05: kdsgrp dba 0x100074c:1 time 3565340047
pin kdswh05: kdsgrp dba 0x1000755:1 time 3565354194
pin kdswh05: kdsgrp dba 0x100074d:1 time 3565367977
pin kdswh05: kdsgrp dba 0x1000755:1 time 3565380604
pin kdswh05: kdsgrp dba 0x100074c:1 time 3565394572
pin kdswh05: kdsgrp dba 0x1000755:1 time 3565409295
pin kdswh05: kdsgrp dba 0x100074c:1 time 3565423088
pin kdswh05: kdsgrp dba 0x100074d:1 time 3565436764
pin kdswh05: kdsgrp dba 0x100074c:1 time 3565450436
pin kdswh05: kdsgrp dba 0x1000755:1 time 3565463067
--//gdb顯示:
2021/02/20 15:51:26.825408913 :kdifxs 0x1000e8f
2021/02/20 15:51:26.837967584 :kdsgrp 0x100074c
2021/02/20 15:51:26.864101083 :kdifxs 0x1000e8f
2021/02/20 15:51:26.876209013 :kdsgrp 0x1000755
2021/02/20 15:51:26.888767163 :kdsgrp 0x100074c
2021/02/20 15:51:26.901400712 :kdsgrp 0x1000755
2021/02/20 15:51:26.913979815 :kdsgrp 0x100074c
2021/02/20 15:51:26.928021294 :kdsgrp 0x1000755
2021/02/20 15:51:26.941792597 :kdsgrp 0x100074d
2021/02/20 15:51:26.954469410 :kdsgrp 0x1000755
2021/02/20 15:51:26.968166227 :kdsgrp 0x100074c
2021/02/20 15:51:26.982954562 :kdsgrp 0x1000755
2021/02/20 15:51:26.996717134 :kdsgrp 0x100074c
2021/02/20 15:51:27.015716039 :kdsgrp 0x100074d
2021/02/20 15:51:27.029494844 :kdsgrp 0x100074c
2021/02/20 15:51:27.042042161 :kdsgrp 0x1000755
--//這樣看到的邏輯讀就很接近了.
--//0x1000e8f = set dba 4,3727 = alter system dump datefile 4 block 3727 = 16780943
SYS@book> @ which_obj 4 3727
SYS@book> @ prxx
==============================
OWNER : SCOTT
SEGMENT_NAME : I_T_OWNER_OBJ_NAME
PARTITION_NAME :
SEGMENT_TYPE : INDEX
TABLESPACE_NAME : USERS
EXTENT_ID : 17
FILE_ID : 4
BLOCK_ID : 3712
BYTES : 1048576
BLOCKS : 128
RELATIVE_FNO : 4
PL/SQL procedure successfully completed.
總結:
--//純粹無聊,自己也不熟悉gdb,不要在生產系統做這樣的測試與操作!!
--//寫這麼長,主要記錄自己學習和分析的過程,實際上的測試過程遠比上面寫的要曲折複雜的多,經過多次反覆.
來自 “ ITPUB部落格 ” ，連結：http://blog.itpub.net/267265/viewspace-2757990/，如需轉載，請註明出處，否則將追究法律責任。
相關文章
- [20210220]全索引掃描快速索引掃描的邏輯讀.txt索引
- [20241105]跟蹤library cache lock library cache pin使用gdb(11g)2.txt
- [20231025]跟蹤rename操作2.txt
- [20200818]12c 10046跟蹤時間戳2.txt時間戳
- [20240920]跟蹤library cache lock library cache pin使用gdb.txt
- [20240824]跟蹤library cache lock library cache pin使用gdb.txt
- Java原始碼跟蹤閱讀技巧Java原始碼
- oracle邏輯讀過程Oracle
- [20211013]閱讀ldd原始碼跟蹤.txt原始碼
- [20200417]跟蹤特定sql語句以及v$open_cursor檢視2.txtSQL
- [20241108]跟蹤library cache lock library cache pin使用gdb(11g)4.txt
- [20241108]跟蹤library cache lock library cache pin使用gdb(11g)3.txt
- 《底層邏輯》讀後感
- sql生成可讀性邏輯圖SQL
- 在Oracle中，什麼是物理讀和邏輯讀？Oracle
- sp_trace_setfilter sqlserver篩選跟蹤或跟蹤過濾FilterSQLServer
- [20231124]奇怪的高邏輯讀4.txt
- [20230216]奇怪的高邏輯讀3.txt
- 適當調大arraysize減少邏輯讀
- [20210224]fetch r=0算邏輯讀嗎.txt
- 主力跟蹤戰法
- 反跟蹤技術
- 合約量化跟單模式軟體開發邏輯詳情模式
- git的跟蹤分支和遠端跟蹤分支學習筆記Git筆記
- STM32啟動過程解讀與跟蹤驗證
- 深度解讀GaussDB邏輯解碼技術原理
- MySQL調優篇 | 邏輯架構解讀（1）MySql架構
- [20210301]為什麼邏輯讀這麼多.txt
- [20210219]全表掃描邏輯讀問題.txt
- 一次調整arraysize減少邏輯讀
- SQLServer進行SQL跟蹤SQLServer
- 會話跟蹤技術會話
- 除錯跟蹤利器---strace除錯
- [20190402]跟蹤vmstat.txt
- Linux 跟蹤器之選Linux
- 跟蹤執行命令T
- 邏輯題
- 像跟蹤分散式服務呼叫那樣跟蹤 Go 函式呼叫鏈分散式Go函式