[20210114]toad檢視真實執行計劃問題.txt

[20210114]toad檢視真實執行計劃問題.txt

--//昨天使用toad最佳化sql語句,我發現toad檢視真實的執行計劃出現一些怪異的問題,自己分析看看.
1.環境:
SYS@192.168.XX.Y:1521/aaa430> @ ver1

PORT_STRING                    VERSION        BANNER
------------------------------ -------------- --------------------------------------------------------------------------------
x86_64/Linux 2.4.xx            11.2.0.3.0     Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production

2.分析:
--//sql語句如下:
SELECT /*+  gather_plan_statistics */
        MS_CF01.FYCK AS XMDM2
        ,COUNT (DISTINCT MS_CF01.CFSB) AS CFS
    FROM YF_MZFYMX, MS_CF01
   WHERE     (YF_MZFYMX.CFSB = MS_CF01.CFSB)
         AND (MS_CF01.YFSB = 166 )
         AND (MS_CF01.FYRQ >= TO_DATE ( '2020-12-01 00:00:00' ,'yyyy-mm-dd hh24:mi:ss'))
         AND (MS_CF01.FYRQ <= TO_DATE ( '2020-12-31 00:00:00' ,'yyyy-mm-dd hh24:mi:ss'))
         
         AND EXISTS
                (  SELECT /*+ unnest */ CFSB, YPXH, SUM (YPSL)
                     FROM YF_MZFYMX
                    WHERE     FYRQ >= TO_DATE ( '2020-12-01 00:00:00' ,'yyyy-mm-dd hh24:mi:ss')
                          AND FYRQ <= TO_DATE ( '2020-12-31 00:00:00' ,'yyyy-mm-dd hh24:mi:ss')
                          AND YFSB = 166
            --            AND YF_MZFYMX.CFSB = MS_CF01.CFSB
                 GROUP BY CFSB, YPXH
                   HAVING SUM (YF_MZFYMX.YPSL) > 0)
GROUP BY MS_CF01.FYCK
ORDER BY MS_CF01.FYCK ASC;

--//我帶入了引數,注意開發少寫了AND YF_MZFYMX.CFSB = MS_CF01.CFSB在exists內部.最佳化問題先放一下.
--//在toad下執行,並且使用toad自帶的SQL Tracker跟蹤sql語句:
--//在跟蹤介面看到的內容如下:

declare
  v_ignore raw(100);
  v_oldhash number;
  v_hash number;
begin
  v_hash := dbms_utility.get_sql_hash(:SQLText || chr(0), v_ignore, v_oldhash);
  :outHash := v_hash;
end;


SQLText=['SELECT /*+  gather_plan_statistics */
        MS_CF01.FYCK AS XMDM2
        ,COUNT (DISTINCT MS_CF01.CFSB) AS CFS
    FROM YF_MZFYMX, MS_CF01
   WHERE     (YF_MZFYMX.CFSB = MS_CF01.CFSB)
         AND (MS_CF01.YFSB = 166 )
         AND (MS_CF01.FYRQ >= TO]
outHash=[0.145428042e+010]
~~~~~~~~~~~~~~~~~~~~~~~~~

Elapsed time: 0.002

--------------------------------------------------------------------------------
Timestamp: 2021/1/14 8:48:02

Select *
from v$sql_plan
Where hash_value = '1454280429'
and child_number =0
order by id

sqlhv=['1454280429']
cn=[0]


Elapsed time: 0.002

--------------------------------------------------------------------------------
Timestamp: 2021/1/14 8:48:02

alter session set current_schema = PORTAL_HIS


Elapsed time: 0.001

--------------------------------------------------------------------------------
Timestamp: 2021/1/14 8:48:02

explain plan set statement_id='Administrator:011421084802' into SYS.PLAN_TABLE$ For SELECT /*+  gather_plan_statistics */
        MS_CF01.FYCK AS XMDM2
        ,COUNT (DISTINCT MS_CF01.CFSB) AS CFS
    FROM YF_MZFYMX, MS_CF01
   WHERE     (YF_MZFYMX.CFSB = MS_CF01.CFSB)
         AND (MS_CF01.YFSB = 166 )
         AND (MS_CF01.FYRQ >= TO_DATE ( '2020-12-01 00:00:00' ,'yyyy-mm-dd hh24:mi:ss'))
         AND (MS_CF01.FYRQ <= TO_DATE ( '2020-12-31 00:00:00' ,'yyyy-mm-dd hh24:mi:ss'))
         
         AND EXISTS
                (  SELECT /*+ unnest */ CFSB, YPXH, SUM (YPSL)
                     FROM YF_MZFYMX
                    WHERE     FYRQ >= TO_DATE ( '2020-12-01 00:00:00' ,'yyyy-mm-dd hh24:mi:ss')
                          AND FYRQ <= TO_DATE ( '2020-12-31 00:00:00' ,'yyyy-mm-dd hh24:mi:ss')
                          AND YFSB = 166
            --              AND YF_MZFYMX.CFSB = MS_CF01.CFSB
                 GROUP BY CFSB, YPXH
                   HAVING SUM (YF_MZFYMX.YPSL) > 0)
GROUP BY MS_CF01.FYCK
ORDER BY MS_CF01.FYCK ASC

Elapsed time: 0.093
--------------------------------------------------------------------------------
Timestamp: 2021/1/14 8:48:02

--//很明顯跟蹤看到的sql語句使用explain plan解析的,自然看不到A-rows資訊.
--//你可以看下劃線內容,可以發現帶入的SQLText僅僅是一部分,這樣解析就不對了嗎?
SQLText=['SELECT /*+  gather_plan_statistics */
        MS_CF01.FYCK AS XMDM2
        ,COUNT (DISTINCT MS_CF01.CFSB) AS CFS
    FROM YF_MZFYMX, MS_CF01
   WHERE     (YF_MZFYMX.CFSB = MS_CF01.CFSB)
         AND (MS_CF01.YFSB = 166 )
         AND (MS_CF01.FYRQ >= TO]
outHash=[0.145428042e+010]
--//我開始以為是擷取錯誤,仔細我想不大可能,我也寫一個註解很長的語句,執行計劃可以發現A-rows的情況.
--//我掃描共享池才發現Hash Value=2826919549,與toad下計算結果不一樣.

SYS@192.168.XX.Y:1521/aaa430> select sql_text c200 from v$sql where hash_value=2826919549;
C200
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SELECT /*+  gather_plan_statistics */         MS_CF01.FYCK AS XMDM2         ,COUNT (DISTINCT MS_CF01.CFSB) AS CFS     FROM YF_MZFYMX, MS_CF01    WHERE     (YF_MZFYMX.CFSB = MS_CF01.CFSB)          AND
(MS_CF01.YFSB = :"SYS_B_00" )          AND (MS_CF01.FYRQ >= TO_DATE ( :"SYS_B_01" ,:"SYS_B_02"))          AND (MS_CF01.FYRQ <= TO_DATE ( :"SYS_B_03" ,:"SYS_B_04"))                    AND EXISTS
          (  SELECT /*+ unnest */ CFSB, YPXH, SUM (YPSL)                      FROM YF_MZFYMX                     WHERE     FYRQ >= TO_DATE ( :"SYS_B_05" ,:"SYS_B_06")                           AND FYR
Q <= TO_DATE ( :"SYS_B_07" ,:"SYS_B_08")                           AND YFSB = :"SYS_B_09"             --              AND YF_MZFYMX.CFSB = MS_CF01.CFSB                  GROUP BY CFSB, YPXH
        HAVING SUM (YF_MZFYMX.YPSL) > :"SYS_B_10") GROUP BY MS_CF01.FYCK ORDER BY MS_CF01.FYCK ASC
--//噢,會不會我設定cursor_sharing=FORCE的緣故呢.馬上在toad下執行:
alter session set cursor_sharing=exact;
--//然後在執行sql語句就可以獲得正確的執行計劃了.包含 Starts , A-Rows 資訊,也就是使用dbms_xplan.display_cursor解析的執行
--//計劃.

SYS@192.168.XX.Y:1521/aaa430> show spparameter cursor_sharing
SID      NAME                          TYPE       VALUE
-------- ----------------------------- ---------- -------------
*        cursor_sharing                string
--//嗯,並沒有設定引數cursor_sharing在spfile裡面,仔細檢查系統觸發器,發現如下程式碼:

CREATE OR REPLACE TRIGGER SYS.LOGIN_ON_RECORD_IP
   AFTER LOGON
   ON DATABASE
DECLARE
   v_client_info   v$session.client_info%TYPE;
BEGIN
   v_client_info := SYS_CONTEXT ('userenv', 'ip_address');
   DBMS_APPLICATION_INFO.set_client_info (v_client_info);
   DBMS_SESSION.set_identifier (v_client_info);

   EXECUTE IMMEDIATE 'alter session set cursor_sharing =force';
END;
/

--//順便修改如下:
CREATE OR REPLACE TRIGGER SYS.LOGIN_ON_RECORD_IP
   AFTER LOGON
   ON DATABASE
DECLARE
   v_client_info   v$session.client_info%TYPE;
BEGIN
   v_client_info := NVL (SYS_CONTEXT ('userenv', 'ip_address'), '127.0.0.1');
   DBMS_APPLICATION_INFO.set_client_info (v_client_info);
   DBMS_SESSION.set_identifier (v_client_info);

   EXECUTE IMMEDIATE 'alter session set cursor_sharing =force';
END;
/

--//很奇怪我發現跟蹤檔案並沒有類似IP地址之類的資訊.另外寫一篇blog分析.
SYS@192.168.XX.Y:1521/aaa430> @ pp
TRACEFILE
--------------------------------------------------------------------------------
/u01/app/oracle/diag/rdbms/aaa430/aaa430/trace/aaa430_ora_11757.trc

總結:
--//總之造成這樣情況的主要原因toad會話cursor_sharing=force,而toad獲得hash vale並沒有把常量變成:"SYS_B_00"的情況,
--//導致計算錯誤,無法獲得真實的執行計劃.