Oracle全表掃描導致的direct path read第一次慢第二次以後變快
阿新 • • 發佈：2021-10-21
Oracle全表掃描導致的direct path read第一次慢第二次以後變快
發現一個有趣的問題，表zkm.zkm_nocompress是我建立的一張測試表，表上沒有任何索引。
有SQL語句：select count(*) from zkm.zkm_nocompress，執行的話理所當然就是走全表掃描了。
在我的環境上，這個SQL語句是每次都會進行物理讀的，等待事件是”direct path read“，不經過db buffer cache。
如標題所講的，這條SQL語句第一次執行差不多需要13s左右，但是第二次以後無論是不是新開會話去執行都在3s多。
也就是第二次以後更快一點。
並且每隔一段時間之後這個現象又會重新開始。
如果會話開啟statistics_level=all然後兩次執行這條SQL會發現，都是進行物理讀。
這就奇怪了，由於是全表掃描並且第二次以後不快取，可以確定是使用了直接路徑讀的方式，
但是都是物理讀，物理讀的大小又不變為啥第二次就快了？
09:10:16 SYS@testdb01(1924)> select count(*) from zkm.zkm_nocompress; COUNT(*) ---------- 1592893 Elapsed: 00:00:12.23 09:10:55 SYS@testdb01(1924)> select * from table(dbms_xplan.display_cursor(null,null,'allstats last')); PLAN_TABLE_OUTPUT --------------------------------------------------------------------------------------------------------- SQL_ID 6q9uvh9vct64n, child number 0 ------------------------------------- select count(*) from zkm.zkm_nocompress Plan hash value: 3202340046 --------------------------------------------------------------------------------------------------------| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | Reads | -------------------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | | 1 |00:00:12.21 | 310K| 310K| | 1 | SORT AGGREGATE | | 1 | 1 | 1 |00:00:12.21 | 310K| 310K| | 2 | TABLE ACCESS FULL| ZKM_NOCOMPRESS | 1 | 1592K| 1592K|00:00:12.13 | 310K| 310K| -------------------------------------------------------------------------------------------------------- 14 rows selected. Elapsed: 00:00:00.03 09:11:04 SYS@testdb01(1924)> select count(*) from zkm.zkm_nocompress; COUNT(*) ---------- 1592893 Elapsed: 00:00:03.22 09:11:10 SYS@testdb01(1924)> select * from table(dbms_xplan.display_cursor(null,null,'allstats last')); PLAN_TABLE_OUTPUT ------------------------------------------------------------------------------------------------------- SQL_ID 6q9uvh9vct64n, child number 0 ------------------------------------- select count(*) from zkm.zkm_nocompress Plan hash value: 3202340046 -------------------------------------------------------------------------------------------------------- | Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | Reads | -------------------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | | 1 |00:00:03.22 | 310K| 310K| | 1 | SORT AGGREGATE | | 1 | 1 | 1 |00:00:03.22 | 310K| 310K| | 2 | TABLE ACCESS FULL| ZKM_NOCOMPRESS | 1 | 1592K| 1592K|00:00:03.14 | 310K| 310K| -------------------------------------------------------------------------------------------------------- 14 rows selected. Elapsed: 00:00:00.02
於是前後兩次會同樣的會話統計發生過的等待事件以及事件發生的次數和平均時間。
查詢檢視v$session_event，結果如下：
（PS：需要注意，在不支援快速計時機制的平臺上，v$session_event.TIME_WAITED和v$session_event.AVERAGE_WAIT列將包含零值。如果您在這些平臺之一上執行並且希望此列反映真實的等待時間，則必須在引數檔案中設定TIMED_STATISTICS為true。請記住，這樣做會對系統性能產生很小的負面影響。我的環境預設就是true的值。）
（PS：AVERAGE_WAIT，會話等待事件的平均時間（以百分之一秒為單位））
第一次執行後： 09:49:35 SYS@testdb01(1997)> select event,total_waits,average_wait from v$session_event where sid=1924; EVENT TOTAL_WAITS AVERAGE_WAIT ----------------------------------- ----------- ------------ Disk file operations I/O 20 .01 enq: KO - fast object checkpoint 3 .02 gc current block 2-way 4 .03 direct path read 1874 .64 library cache pin 2 .02 library cache lock 2 .05 SQL*Net message to client 8 0 SQL*Net message from client 7 863.77 events in waitclass Other 1 .22 9 rows selected. Elapsed: 00:00:00.00 SID=1924的會話重新登入進行第二次執行（快速登出登入的SID不會變）： 09:50:47 SYS@testdb01(1997)> select event,total_waits,average_wait from v$session_event where sid=1924; EVENT TOTAL_WAITS AVERAGE_WAIT ----------------------------------- ----------- ------------ Disk file operations I/O 19 .01 enq: KO - fast object checkpoint 3 .03 direct path read 2425 .08 SQL*Net message to client 8 0 SQL*Net message from client 7 182.1 events in waitclass Other 1 .18 6 rows selected. Elapsed: 00:00:00.00
其中，第一次執行的等待事件"direct path read"的總時間為1874*0.64=1199.36，實際上就是TIME_WAITED欄位的值，1199.36也就是11.9936s。
而第二次"direct path read"的總時間2425*0.08=194=1.94s。
可以看出，主要時間是花在direct path read上，然而這是為啥？都是物理讀為啥第二次的要比第一次的要快？
難道是兩次SQL執行過程中每次的"direct path read"進行多塊讀的時候塊數不一樣導致的？
那也不應該，第二次的"direct path read"次數2425比第一次1874還多，"direct path read"發生次數少至少說明平均起來的多塊讀塊數要多於第二次的，那應該是第一次更快才是。
還是做了一次10046看情況：
第一次：
WAIT #140307048128352: nam='direct path read' ela= 4032 file number=103 first dba=694144 block cnt=128 obj#=289939 tim=1634698487631159 WAIT #140307048128352: nam='direct path read' ela= 21069 file number=101 first dba=687873 block cnt=127 obj#=289939 tim=1634698487652742 WAIT #140307048128352: nam='direct path read' ela= 17696 file number=80 first dba=637185 block cnt=127 obj#=289939 tim=1634698487671430 WAIT #140307048128352: nam='direct path read' ela= 14427 file number=74 first dba=615553 block cnt=127 obj#=289939 tim=1634698487687156 WAIT #140307048128352: nam='direct path read' ela= 2004 file number=69 first dba=751489 block cnt=127 obj#=289939 tim=1634698487690035 WAIT #140307048128352: nam='direct path read' ela= 5011 file number=68 first dba=752256 block cnt=128 obj#=289939 tim=1634698487695448 WAIT #140307048128352: nam='direct path read' ela= 8843 file number=10 first dba=1660288 block cnt=128 obj#=289939 tim=1634698487705309 WAIT #140307048128352: nam='direct path read' ela= 22152 file number=105 first dba=1895809 block cnt=127 obj#=289939 tim=1634698487727882 WAIT #140307048128352: nam='direct path read' ela= 8268 file number=101 first dba=688129 block cnt=127 obj#=289939 tim=1634698487737025 WAIT #140307048128352: nam='direct path read' ela= 6492 file number=98 first dba=683264 block cnt=128 obj#=289939 tim=1634698487744008 WAIT #140307048128352: nam='direct path read' ela= 11333 file number=79 first dba=639104 block cnt=128 obj#=289939 tim=1634698487756289 WAIT #140307048128352: nam='direct path read' ela= 560 file number=74 first dba=615681 block cnt=127 obj#=289939 tim=1634698487757164 WAIT #140307048128352: nam='direct path read' ela= 9948 file number=73 first dba=614656 block cnt=128 obj#=289939 tim=1634698487767617 WAIT #140307048128352: nam='direct path read' ela= 6914 file number=69 first dba=751617 block cnt=127 obj#=289939 tim=1634698487775311 WAIT #140307048128352: nam='direct path read' ela= 9914 file number=20 first dba=2468865 block cnt=127 obj#=289939 tim=1634698487786094 WAIT #140307048128352: nam='direct path read' ela= 5982 file number=10 first dba=1663232 block cnt=128 obj#=289939 tim=1634698487792658 WAIT #140307048128352: nam='direct path read' ela= 2576 file number=105 first dba=1895937 block cnt=127 obj#=289939 tim=1634698487796115 WAIT #140307048128352: nam='direct path read' ela= 6034 file number=103 first dba=694912 block cnt=128 obj#=289939 tim=1634698487802656 WAIT #140307048128352: nam='direct path read' ela= 5909 file number=101 first dba=689921 block cnt=127 obj#=289939 tim=1634698487809347 WAIT #140307048128352: nam='direct path read' ela= 8411 file number=98 first dba=687488 block cnt=128 obj#=289939 tim=1634698487818256 WAIT #140307048128352: nam='direct path read' ela= 3733 file number=80 first dba=647041 block cnt=127 obj#=289939 tim=1634698487822741 WAIT #140307048128352: nam='direct path read' ela= 8669 file number=79 first dba=639360 block cnt=128 obj#=289939 tim=1634698487831905 WAIT #140307048128352: nam='direct path read' ela= 930 file number=74 first dba=616065 block cnt=127 obj#=289939 tim=1634698487833495 WAIT #140307048128352: nam='direct path read' ela= 10385 file number=73 first dba=615296 block cnt=128 obj#=289939 tim=1634698487844450 WAIT #140307048128352: nam='direct path read' ela= 1095 file number=69 first dba=751745 block cnt=127 obj#=289939 tim=1634698487846292 WAIT #140307048128352: nam='direct path read' ela= 10472 file number=68 first dba=752512 block cnt=128 obj#=289939 tim=1634698487857264 WAIT #140307048128352: nam='direct path read' ela= 21744 file number=10 first dba=1663488 block cnt=128 obj#=289939 tim=1634698487880397 WAIT #140307048128352: nam='direct path read' ela= 10407 file number=103 first dba=699904 block cnt=128 obj#=289939 tim=1634698487892083 WAIT #140307048128352: nam='direct path read' ela= 772 file number=101 first dba=692737 block cnt=127 obj#=289939 tim=1634698487893573 WAIT #140307048128352: nam='direct path read' ela= 6903 file number=98 first dba=690432 block cnt=128 obj#=289939 tim=1634698487901142 WAIT #140307048128352: nam='direct path read' ela= 5351 file number=80 first dba=648321 block cnt=127 obj#=289939 tim=1634698487907174 WAIT #140307048128352: nam='direct path read' ela= 3275 file number=79 first dba=645632 block cnt=128 obj#=289939 tim=1634698487911170 WAIT #140307048128352: nam='direct path read' ela= 6376 file number=74 first dba=620417 block cnt=127 obj#=289939 tim=1634698487918287 WAIT #140307048128352: nam='direct path read' ela= 1094 file number=73 first dba=619264 block cnt=128 obj#=289939 tim=1634698487920144 WAIT #140307048128352: nam='direct path read' ela= 7396 file number=69 first dba=751873 block cnt=127 obj#=289939 tim=1634698487928237 WAIT #140307048128352: nam='direct path read' ela= 4123 file number=68 first dba=752640 block cnt=128 obj#=289939 tim=1634698487933128 WAIT #140307048128352: nam='direct path read' ela= 6368 file number=20 first dba=2469121 block cnt=127 obj#=289939 tim=1634698487940150 WAIT #140307048128352: nam='direct path read' ela= 4715 file number=10 first dba=1666048 block cnt=128 obj#=289939 tim=1634698487945645 WAIT #140307048128352: nam='direct path read' ela= 5093 file number=105 first dba=1896193 block cnt=127 obj#=289939 tim=1634698487951385 WAIT #140307048128352: nam='direct path read' ela= 7545 file number=103 first dba=701568 block cnt=128 obj#=289939 tim=1634698487959672 WAIT #140307048128352: nam='direct path read' ela= 3648 file number=101 first dba=695937 block cnt=127 obj#=289939 tim=1634698487964059 WAIT #140307048128352: nam='direct path read' ela= 4575 file number=98 first dba=692352 block cnt=128 obj#=289939 tim=1634698487969245 WAIT #140307048128352: nam='direct path read' ela= 6237 file number=80 first dba=650753 block cnt=127 obj#=289939 tim=1634698487976187 WAIT #140307048128352: nam='direct path read' ela= 4244 file number=79 first dba=647552 block cnt=128 obj#=289939 tim=1634698487981165 WAIT #140307048128352: nam='direct path read' ela= 7558 file number=74 first dba=622209 block cnt=127 obj#=289939 tim=1634698487989509 WAIT #140307048128352: nam='direct path read' ela= 6728 file number=73 first dba=620544 block cnt=128 obj#=289939 tim=1634698487996993 WAIT #140307048128352: nam='direct path read' ela= 1627 file number=69 first dba=752001 block cnt=127 obj#=289939 tim=1634698487999235 WAIT #140307048128352: nam='direct path read' ela= 5020 file number=68 first dba=752768 block cnt=128 obj#=289939 tim=1634698488004972 WAIT #140307048128352: nam='direct path read' ela= 4299 file number=20 first dba=2469505 block cnt=127 obj#=289939 tim=1634698488009895 WAIT #140307048128352: nam='direct path read' ela= 13577 file number=105 first dba=1896321 block cnt=127 obj#=289939 tim=1634698488024766 WAIT #140307048128352: nam='direct path read' ela= 1301 file number=103 first dba=703744 block cnt=128 obj#=289939 tim=1634698488026779 WAIT #140307048128352: nam='direct path read' ela= 14033 file number=101 first dba=697345 block cnt=127 obj#=289939 tim=1634698488041502
第二次：
WAIT #140307048128352: nam='direct path read' ela= 867 file number=79 first dba=741632 block cnt=128 obj#=289939 tim=1634698533969008 WAIT #140307048128352: nam='direct path read' ela= 808 file number=74 first dba=723841 block cnt=127 obj#=289939 tim=1634698533970297 WAIT #140307048128352: nam='direct path read' ela= 920 file number=73 first dba=722688 block cnt=128 obj#=289939 tim=1634698533971630 WAIT #140307048128352: nam='direct path read' ela= 2063 file number=69 first dba=758529 block cnt=127 obj#=289939 tim=1634698533973943 WAIT #140307048128352: nam='direct path read' ela= 1457 file number=68 first dba=759296 block cnt=128 obj#=289939 tim=1634698533975863 WAIT #140307048128352: nam='direct path read' ela= 1158 file number=20 first dba=2476673 block cnt=127 obj#=289939 tim=1634698533977809 WAIT #140307048128352: nam='direct path read' ela= 844 file number=10 first dba=1764608 block cnt=128 obj#=289939 tim=1634698533979110 WAIT #140307048128352: nam='direct path read' ela= 888 file number=105 first dba=1902849 block cnt=127 obj#=289939 tim=1634698533980419 WAIT #140307048128352: nam='direct path read' ela= 842 file number=103 first dba=815488 block cnt=128 obj#=289939 tim=1634698533981759 WAIT #140307048128352: nam='direct path read' ela= 769 file number=101 first dba=808961 block cnt=127 obj#=289939 tim=1634698533983064 WAIT #140307048128352: nam='direct path read' ela= 784 file number=98 first dba=806144 block cnt=128 obj#=289939 tim=1634698533984380 WAIT #140307048128352: nam='direct path read' ela= 831 file number=80 first dba=745089 block cnt=127 obj#=289939 tim=1634698533985676 WAIT #140307048128352: nam='direct path read' ela= 937 file number=79 first dba=742272 block cnt=128 obj#=289939 tim=1634698533987047 WAIT #140307048128352: nam='direct path read' ela= 548 file number=74 first dba=727041 block cnt=127 obj#=289939 tim=1634698533988282 WAIT #140307048128352: nam='direct path read' ela= 858 file number=73 first dba=723072 block cnt=128 obj#=289939 tim=1634698533989604 WAIT #140307048128352: nam='direct path read' ela= 788 file number=69 first dba=758657 block cnt=127 obj#=289939 tim=1634698533990864 WAIT #140307048128352: nam='direct path read' ela= 825 file number=68 first dba=759424 block cnt=128 obj#=289939 tim=1634698533992169 WAIT #140307048128352: nam='direct path read' ela= 795 file number=20 first dba=2476801 block cnt=127 obj#=289939 tim=1634698533993422 WAIT #140307048128352: nam='direct path read' ela= 844 file number=10 first dba=1766144 block cnt=128 obj#=289939 tim=1634698533994725 WAIT #140307048128352: nam='direct path read' ela= 859 file number=105 first dba=1902978 block cnt=126 obj#=289939 tim=1634698533995997 WAIT #140307048128352: nam='direct path read' ela= 930 file number=103 first dba=816384 block cnt=128 obj#=289939 tim=1634698533997326 WAIT #140307048128352: nam='direct path read' ela= 704 file number=101 first dba=810369 block cnt=127 obj#=289939 tim=1634698533998595 WAIT #140307048128352: nam='direct path read' ela= 887 file number=98 first dba=807296 block cnt=128 obj#=289939 tim=1634698533999864 WAIT #140307048128352: nam='direct path read' ela= 881 file number=80 first dba=745473 block cnt=127 obj#=289939 tim=1634698534001139 WAIT #140307048128352: nam='direct path read' ela= 924 file number=79 first dba=742400 block cnt=128 obj#=289939 tim=1634698534002441 WAIT #140307048128352: nam='direct path read' ela= 791 file number=74 first dba=728449 block cnt=127 obj#=289939 tim=1634698534003725 WAIT #140307048128352: nam='direct path read' ela= 868 file number=73 first dba=726912 block cnt=128 obj#=289939 tim=1634698534005008 WAIT #140307048128352: nam='direct path read' ela= 885 file number=69 first dba=758785 block cnt=127 obj#=289939 tim=1634698534006283 WAIT #140307048128352: nam='direct path read' ela= 929 file number=68 first dba=759552 block cnt=128 obj#=289939 tim=1634698534007595 WAIT #140307048128352: nam='direct path read' ela= 809 file number=20 first dba=2476929 block cnt=127 obj#=289939 tim=1634698534008864 WAIT #140307048128352: nam='direct path read' ela= 897 file number=10 first dba=1767680 block cnt=128 obj#=289939 tim=1634698534010189 WAIT #140307048128352: nam='direct path read' ela= 814 file number=105 first dba=1903105 block cnt=127 obj#=289939 tim=1634698534011436 WAIT #140307048128352: nam='direct path read' ela= 888 file number=103 first dba=817536 block cnt=128 obj#=289939 tim=1634698534012736 WAIT #140307048128352: nam='direct path read' ela= 839 file number=101 first dba=811137 block cnt=127 obj#=289939 tim=1634698534014017 WAIT #140307048128352: nam='direct path read' ela= 885 file number=98 first dba=810368 block cnt=128 obj#=289939 tim=1634698534015305 WAIT #140307048128352: nam='direct path read' ela= 847 file number=80 first dba=745857 block cnt=127 obj#=289939 tim=1634698534016592 WAIT #140307048128352: nam='direct path read' ela= 855 file number=79 first dba=742784 block cnt=128 obj#=289939 tim=1634698534017901 WAIT #140307048128352: nam='direct path read' ela= 874 file number=74 first dba=728577 block cnt=127 obj#=289939 tim=1634698534019176 WAIT #140307048128352: nam='direct path read' ela= 863 file number=73 first dba=729088 block cnt=128 obj#=289939 tim=1634698534020448 WAIT #140307048128352: nam='direct path read' ela= 842 file number=69 first dba=758913 block cnt=127 obj#=289939 tim=1634698534021739 WAIT #140307048128352: nam='direct path read' ela= 862 file number=68 first dba=759680 block cnt=128 obj#=289939 tim=1634698534023025 WAIT #140307048128352: nam='direct path read' ela= 935 file number=20 first dba=2477057 block cnt=127 obj#=289939 tim=1634698534024345 WAIT #140307048128352: nam='direct path read' ela= 818 file number=10 first dba=1770368 block cnt=128 obj#=289939 tim=1634698534025612 WAIT #140307048128352: nam='direct path read' ela= 866 file number=105 first dba=1903233 block cnt=127 obj#=289939 tim=1634698534026880 WAIT #140307048128352: nam='direct path read' ela= 902 file number=103 first dba=821760 block cnt=128 obj#=289939 tim=1634698534028186
可以看出，每次”direct path read“中cnt基本都在128，但是每次的ela（單位：微秒）裡邊第二次明顯比第一次要更少。
那麼新的問題來了，為啥？這物理讀已經不經過記憶體做快取了，每次cnt還差不多為啥速度會這麼大差別？？
其實這個影響因素已經不再Oracle資料庫層面了，去和儲存瞭解了下。
這個資料庫的儲存是有用了SSD盤做了快取盤，實際上是儲存層面的快取了。
對於Oracle來說它還是物理讀，但由於短時間內在儲存層面這些資料被快取到SSD快取盤上，固態盤顯然更快，因此雖然對Oracle來說還是物理讀，但是顯然速度有明顯提升。
至此。