为什么忘记commit也会造成select查询的性能问题
今天遇到一個很有意思的問題,一個開發人員反饋在測試服務器ORACLE數據庫執行的一條簡單SQL語句非常緩慢,他寫的一個SQL沒有返回任何數據,但是耗費了幾分鐘的時間。讓我檢查分析一下原因,分析解決過后,發現事情的真相有點讓人哭笑不得,但是也是非常有意思的。我們先簡單構造一下類似的案例,當然只是簡單模擬。
?
假設一個同事A,創建了一個表并初始化了數據(實際環境數據量較大,有1G多的數據),但是他忘記提交了。我們簡單模擬如下:
SQL> create?table test_uncommit? 2? as? 3? select * from dba_objects where 1=0;?Table created.?SQL> declare rowIndex number;? 2? begin? 3???? for rowIndex in 1..70 loop? 4???? insert into test_uncommit? 5???? select * from dba_objects;? 6???? end loop;? 7? end;? 8? /?PL/SQL?procedure successfully completed.?SQL>
?
另外一個同事B對這個表做一些簡單查詢操作,但是他不知道同事A的沒有提交INSERT語句,如下所示,查詢時間用了大概5秒多(這個因為構造的數據量不是非常大的緣故。實際場景耗費了幾分鐘)
SQL> SET TIMING ON;SQL> SET AUTOTRACE ON;SQL> SELECT?COUNT(1) FROM SYS.TEST_UNCOMMIT WHERE OBJECT_ID=39;?? COUNT(1)----------???????? 0?Elapsed: 00:00:05.38?Execution Plan----------------------------------------------------------Plan hash value: 970680813?------------------------------------------------------------------------------------| Id? | Operation????????? | Name????????? | Rows? | Bytes | Cost (%CPU)| Time???? |------------------------------------------------------------------------------------|?? 0 | SELECT STATEMENT?? |?????????????? |???? 1 |??? 13 |? 6931?? (3)| 00:00:10 ||?? 1 |? SORT AGGREGATE??? |?????????????? |???? 1 |??? 13 |??????????? |????????? ||*? 2 |?? TABLE ACCESS FULL| TEST_UNCOMMIT |???? 1 |??? 13 |? 6931?? (3)| 00:00:10 |------------------------------------------------------------------------------------Predicate Information (identified by?operation id):---------------------------------------------------?? 2 - filter("OBJECT_ID"=39)?Note-----?? - dynamic sampling used for this statement??Statistics----------------------------------------------------------????????? 4? recursive calls????????? 0? db block gets???? 229304? consistent gets????? 61611? physical reads??? 3806792? redo size??????? 514? bytes sent via SQL*Net to client??????? 492? bytes received via SQL*Net from client????????? 2? SQL*Net roundtrips to/from client????????? 0? sorts (memory)????????? 0? sorts (disk)????????? 1? rows processed?SQL>
?
當時是在SQL Developer工具里面分析SQL的執行計劃,并沒有注意到redo size非常大的情況。剛開始懷疑是統計信息不準確導致,手工收集了一下該表的統計信息,執行的時間和執行計劃依然如此,沒有任何變化。 如果我們使用SQL*Plus,查看執行計劃,就會看到redo size異常大,你就會有所察覺(見后面分析)
?
SQL> exec dbms_stats.gather_table_stats('SYS','TEST_UNCOMMIT');?PL/SQL?procedure successfully completed.?Elapsed: 00:00:12.29?
?
因為ORACLE里面的寫不阻塞讀,所以不可能是因為SQL阻塞的緣故,然后我想查看這個表到底有多少記錄,結果亮瞎了我的眼睛,記錄數為0,但是空間用掉了852 個數據塊
SQL> SELECT TABLE_NAME, NUM_ROWS, BLOCKS FROM DBA_TABLES WHERE TABLE_NAME='TEST_UNCOMMIT';?TABLE_NAME?????????????????????? NUM_ROWS???? BLOCKS------------------------------ ---------- ----------TEST_UNCOMMIT?????????????????????????? 0??????? 852?SQL>
?
于是我使用Tom大師的show_space腳本檢查、確認該表的空間使用情況,如下所示,該表確實使用852個數據塊。
SQL> set serverout on;SQL> exec show_space('TEST_UNCOMMIT');Free Blocks.............................???????????? 852Total Blocks............................???????????? 896Total Bytes.............................?????? 7,340,032Total MBytes............................?????????????? 7Unused Blocks...........................????????????? 43Unused Bytes............................???????? 352,256Last Used Ext FileId....................?????????????? 1Last Used Ext BlockId...................????????? 88,201Last Used Block.........................????????????? 85?PL/SQL?procedure successfully completed.?SQL>
?
分析到這里,那么肯定是遇到了插入數據操作,卻沒有提交的緣故。用下面腳本檢查發現一個會話ID為883的對這個表有一個ROW級排他鎖,而且會話還有一個事務排他鎖,那么可以肯定這個會話執行了DML操作,但是沒有提交。
SET linesize 190 COL osuser format a15 COL username format a20 wrap COL object_name format a20 wrap COL terminal format a25 wrap COL req_mode format a20 SELECT B.SID, ?????? C.USERNAME, ?????? C.OSUSER, ?????? C.TERMINAL, ?????? DECODE(B.ID2, 0, A.OBJECT_NAME, ???????????????????? 'TRANS-'????????????????????? ||TO_CHAR(B.ID1)) OBJECT_NAME, ?????? B.TYPE, ?????? DECODE(B.LMODE, 0, 'WAITING', ?????????????????????? 1, 'NULL', ?????????????????????? 2, 'Row-S(SS)', ?????????????????????? 3, 'ROW-X(SX)', ?????????????????????? 4, 'SHARE', ?????????????????????? 5, 'S/ROW-X(SSX)', ?????????????????????? 6, 'EXCLUSIVE', ?????????????????????? ' OTHER')?????? "LOCK MODE", ?????? DECODE(B.REQUEST, 0, '', ???????????????????????? 1, 'NULL', ???????????????????????? 2, 'Row-S(SS)', ???????????????????????? 3, 'ROW-X(SX)', ???????????????????????? 4, 'SHARE', ???????????????????????? 5, 'S/ROW-X(SSX)', ???????????????????????? 6, 'EXCLUSIVE', ???????????????????????? 'OTHER')????? "REQ_MODE" FROM?? DBA_OBJECTS A, ?????? V$LOCK B, ?????? V$SESSION C WHERE? A.OBJECT_ID(+) = B.ID1 ?????? AND B.SID = C.SID ?????? AND C.USERNAME IS?NOT?NULL?ORDER? BY B.SID, ????????? B.ID2;
?
我們在會話里面提交后,然后重新執行這個SQL,你會發現執行計劃里面redo size為0,這是因為redo size表示DML生成的redo log的大小,其實從上面的執行計劃分析redo size異常,就應該了解到一個七七八八了,因為一個正常的SELECT查詢是不會在redo log里面生成相關信息的。那么肯定是遇到了DML操作,但是沒有提交。
?
分析到這里,我們已經知道事情的前因后果了,解決也很容易,找到那個會話的信息,然后定位到哪個同事,讓其提交即可解決。但是,為什么沒有提交與提交過后的差距那么大呢?是什么原因呢? 我們可以在這個案例,提交前與提交后跟蹤執行的SQL語句,如下所示。
SQL> ALTER?SESSION?SET SQL_TRACE=TRUE;?Session altered.?SQL> SELECT?COUNT(1) FROM SYS.TEST_UNCOMMIT WHERE OBJECT_ID=39;?? COUNT(1)----------???????? 0SQL> ?SQL> ALTER?SESSION?SET SQL_TRACE=FALSE;?Session altered.?
?
提交前上面SQL生成的跟蹤文件為scm2_ora_8444.trc,我們使用TKPROF格式化如下: tkprof scm2_ora_8444.trc out_uncommit.txt 如下所示
提交后,在另外一個會話執行上面的SQL,然后格式化跟蹤文件如下所示:
?
我們發現提交前與提交后兩者的物理讀、一致性讀有較大差別(尤其是一致性讀相差3倍多)。這個主要是因為ORACLE的一致性讀需要構造cr塊,產生了大量的邏輯讀的緣故。相關理論與概念如下:
?
為什么要一致性讀,為了保持數據的一致性。如果一個事務需要修改數據塊中數據,會先在回滾段中保存一份修改前數據和SCN的數據塊,然后再更新Buffer Cache中的數據塊的數據及其SCN,并標識其為“臟”數據。
當其他進程讀取數據塊時,會先比較數據塊上的SCN和進程自己的SCN。如果數據塊上的SCN小于等于進程本身的SCN,則直接讀取數據塊上的數據;
如果數據塊上的SCN大于進程本身的SCN,則會從回滾段中找出修改前的數據塊讀取數據。通常,普通查詢都是一致性讀。
一致性讀什么時候需要cr塊呢,那就是select語句在發現所查詢的時間點對應的scn,與數據塊當前所的scn不一致的時候。構造cr塊的時候,首先去data buffer中去找包含數據庫前鏡像的undo塊,如果有直接取出構建CR塊,這時候是邏輯讀,產生邏輯IO;但是data buffer將undo信息寫出后,就沒有需要的undo信息,就會去undo段找所需要的前鏡像的undo信息,這時候從磁盤上讀出block到buffer中,這時候產生物理讀(物理IO)
總結
以上是生活随笔為你收集整理的为什么忘记commit也会造成select查询的性能问题的全部內容,希望文章能夠幫你解決所遇到的問題。
- 上一篇: 双网卡绑定之负载均衡高可用(bond)
- 下一篇: Python的线程/进程间通讯对象分析