在前兩篇的基礎上，對於一個環境中存在的奇怪並行程式問題進行了初步的分析。
初步排除了是透過scheduler的job執行導致的，一方面因為執行的時間會有延遲，甚至有很大的差別。所以分析和排查按照scheduler的時間點沒有辦法抓到任何規律。
排除了scheduler的影響之後，在分析ash之後無果，最後無奈使用了自定義指令碼來排查問題。當然這個也確實需要點時間。
透過指令碼跟蹤的方式還是針對性要強一些，有些明細資訊在ash報告中也體現不到，比如啟用了多少的並行程式，那些語句走了大量的並行等等。
檢視今天早晨的日誌，發現竟然還有SYS的使用者在做並行查詢，先來說說這個問題。
抓取到的日誌資訊如下：
17 19257 SYS statdb96.cyou.com oracle@statdb96.test.com (P013) oracle INACTIVE 2015-09-02 02:03:01 5vf4b6p4v79rm ENABLED DISABLED ENABLED
29 64027 SYS statdb96.cyou.com oracle@statdb96.test.com (P056) oracle INACTIVE 2015-09-02 02:03:01 5vf4b6p4v79rm ENABLED DISABLED ENABLED
可以讀取到SYS在執行sql_id 為5vf4b6p4v79rm 的sql語句，而且走了並行，我們來看看這個語句到底是怎麼樣的。
因為之前透過v$sql,dba_sql_hist的方式去查詢parallel相關的語句，也沒有找到讓人信服的sql語句，這種守株待兔的方式得到的語句還是值得信任的。
語句內容如下：
SELECT SERV_GROUP, CN_GUID, MAX(USER_CLASS) MCLASS, MAX(END_TIME) LASTTIME, MIN(END_TIME) FIRSTTIME
FROM TESTUSER.TEST_BILLDETAIL WHERE END_TIME >= :B2 AND END_TIME < :B1 AND CN_GUID > 0 GROUP BY SERV_GROUP,CN_GUID

這個語句中沒有任何的並行hint，但是確確實實走了並行，而且並行度還很高。
檢視一下執行計劃,發現一個很明顯的全表掃描。這個表的資料量過億，這個全表掃描的代價還是很高的。
-------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes |
-------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1186K| 30M|
|* 1 | PX COORDINATOR | | | |
| 2 | PX SEND QC (RANDOM) | :TQ10001 | 1186K| 30M|
| 3 | HASH GROUP BY | | 1186K| 30M|
| 4 | PX RECEIVE | | 1186K| 30M|
| 5 | PX SEND HASH | :TQ10000 | 1186K| 30M|
|* 6 | FILTER | | | |
| 7 | PX BLOCK ITERATOR | | 1186K| 30M|
|* 8 | TABLE ACCESS FULL| TEST_BILLDETAIL | 1186K| 30M|
-------------------------------------------------------------------

但是檢視語句，也不是一個很複雜的語句，我們來看看為什麼走了全表掃描，而怎麼沒有考慮到索引掃描。
INDEX_NAME TABLESPACE INDEX_TYPE UNIQUENES PAR COLUMN_LIST
------------------------------ ---------- ---------- --------- --- --------------
IND_TEST_BILLDETAIL_CN NORMAL NONUNIQUE YES CN
IND_TEST_BILLDETAIL_END_TIME NORMAL NONUNIQUE YES END_TIME

這個時候可以很i明顯看到有一個索引是在欄位END_TIME上的，所以說索引確確實實在哪兒，但是查詢卻壓根沒有走索引，而走了一個基於並行的圈全表掃描。
我們來看看索引的情況，這個索引是個分割槽索引，所以可以檢視選擇性的檢視一部分索引資訊。
INDEX_NAME PAR_NAME PAR_POS STATUS
-------------------- --------------- ---------- ------- --------
IND_TEST_BILLDETAIL_CN TEST_BILLDETAIL_ 20091201 1 UNUSABLE

IND_TEST_BILLDETAIL_CN TEST_BILLDETAIL_ 20091202 1 UNUSABLE
隨便抓取了幾條，仔細一看，發現有很多索引都是unusable狀態了，這個時候問題似乎有了很大的轉機，索引失效導致的索引掃描沒有啟用，而走了全表掃描。
而對於這個問題的修復相對來說就簡單多了,重新做rebuild即可，為了不影響線上業務，可以做一個小的嘗試，拿一個資料比較早的分割槽來做一個測試，看看rebuild index partition之後，是否索引會正常啟用。
SQL> alter index ldj.IND_TEST_BILLDETAIL_END_TIME rebuild partition TEST_BILLDETAIL_20091201;
Index altered.
這個時候驗證語句就類似下面的形式,同時把並行的影響也取消了。
SELECT /*+no_parallel*/ SERV_GROUP, CN_GUID, MAX(USER_CLASS) MCLASS, MAX(END_TIME) LASTTIME, MIN(END_TIME) FIRSTTIME
FROM LDJ.SWD_BILLDETAIL partition(TEST_BILLDETAIL_20091201) WHERE END_TIME >= :B2 AND END_TIME < :B1 AND CN_GUID > 0 GROUP BY SERV_GROUP,CN_GUID
rebuild index partition之前的執行計劃如下：
-------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes |
-------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 57 | 1197 |
| 1 | HASH GROUP BY | | 57 | 1197 |
|* 2 | FILTER | | | |
| 3 | PARTITION RANGE SINGLE| | 57 | 1197 |
|* 4 | TABLE ACCESS FULL | TEST_BILLDETAIL | 57 | 1197 |
-------------------------------------------------------------------

rebuild index partition之後的執行計劃如下：
--------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes |
--------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 57 | 1197 |
| 1 | HASH GROUP BY | | 57 | 1197 |
|* 2 | FILTER | | | |
| 3 | PARTITION RANGE SINGLE | | 57 | 1197 |
|* 4 | TABLE ACCESS BY LOCAL INDEX ROWID| TEST_BILLDETAIL | 57 | 1197 |
|* 5 | INDEX RANGE SCAN | IND_TEST_BILLDETAIL_END_TIME | 103 | |
--------------------------------------------------------------------------------------------

可以看到索引是能夠正常啟用的，這個時候並行的影響就可以基本排除了。
最後我們來簡單說一說這個並行。
SQL>select degree,table_name,owner from dba_tables where table_name='SWD_BILLDETAIL'
DEGREE TABLE_NAME OWNER
-------------------- ------------------------------ ------------------------------
DEFAULT TEST_BILLDETAIL TESTDB
這種default的方式其實還有有些奇怪，如果要較真，會發現這個DEFAULT左邊還是有一些空格的。
SQL> select degree from dba_tables where degree=' DEFAULT' and rownum<2;
DEGREE
--------------------
DEFAULT
這個是在物件級開了並行，至於並行度的情況，還是和引數parallel_threads_per_cpu,cpu_count,parallel_execution_message_size有一些關係，我們先不細談。
到此為止，我們發現了奇怪的並行問題其實和一個全表掃描相關，在這個基礎上，繼續分析發現索引沒有啟用，再進一步分析，發現對應的分割槽索引失效了。

這些問題都是一環套一環，缺一不可。
我們之前也分析過ASH報告中沒有找到有效的資訊，至於這個問題，其實是人為操作誤導。

這一點還是需要特別說明一下,可以看看下面的操作結果說明了什麼
$ echo $ORACLE_SID
testdb1
$ sqlplus testdba/testdba@testdb1
SQL> select count(*)from v$session;
COUNT(*)
----------
39
SQL> conn / as sysdba
Connected.
SQL> select count(*)from v$session;
COUNT(*)
----------
165
SQL> show parameter uniq
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
db_unique_name string testdb96
這個奇怪問題的原因就在於我們使用原來的db_name連線到的實際上是備庫，所以抓取的ash報告中沒有任何的有效資訊。
而這個問題的根源還是在於之前做了一次主從切換。結果從庫變成了主庫，使用的原來的Uniq_name也還是保留了原來的樣子。tns這邊也還是保留了原來的格式，結果在透過tns連線的時候就連線到了備庫
當然事後也做了驗證，發現ash在問題的時間點內抓取的報告還是很有效的，相關的問題sql都會抓取到。所以ASH報告還是很靠譜的。
透過這個案例我們可以看到對於一個很細小的問題進行深究會發現其實還是存在著一些潛在問題，問題的發生都是有原因的，效能的抖動也是有一些需要我們去關注的細節。
細節決定成敗，說的也就是這個意思吧。

關於奇怪的並行程式分析(三)

相關文章