[20210926]並行執行計劃疑問.txt

lfree發表於2021-09-26

[20210926]並行執行計劃疑問.txt

--//問題來源於前幾天看awr報表遇到的奇怪問題.

$ cat sqlh.sql
column BEGIN_INTERVAL_TIME format a24
column END_INTERVAL_TIME format a24
prompt @ sqlh  sql_id [snap_id]
SELECT s.SNAP_ID
        ,s.instance_number
        ,s.PLAN_HASH_VALUE
        ,x.BEGIN_INTERVAL_TIME
        ,x.END_INTERVAL_TIME
        ,ELAPSED_TIME_DELTA
        ,CPU_TIME_DELTA
        ,EXECUTIONS_DELTA
        ,EXECUTIONS_TOTAL
        ,ROWS_PROCESSED_DELTA
        ,BUFFER_GETS_DELTA
        ,s.LOADED_VERSIONS
    FROM DBA_HIST_SQLSTAT s, DBA_HIST_SNAPSHOT x
   WHERE     s.sql_id = '&&1'
         AND s.snap_id = x.snap_id
         AND s.instance_number = x.instance_number
         AND s.snap_id >= nvl('&&2',0)
ORDER BY 1,2;

--//sql_id = 7ksrtc8rzpawc
SELECT a.object_name, c.sid,
       CASE TO_CHAR(b.locked_mode)
       WHEN '0' THEN 'NONE'
       WHEN '1' THEN 'NULL'
       WHEN '2' THEN 'ROW-S (RS)'
       WHEN '3' THEN 'ROW-X (RX)'
       WHEN '4' THEN 'SHARE (S)'
       WHEN '5' THEN 'S/ROW-X (SRX)'
       WHEN '6' THEN 'Exclusive (X)'
       ELSE TO_CHAR(b.locked_mode)
       END locked_mode, c.SERIAL#, b.process, c.program, c.SQL_ADDRESS
  FROM all_objects a, sys.gv_$locked_object b, sys.GV_$SESSION C
 WHERE a.object_id = b.object_id
   AND b.process   = c.process
 ORDER BY a.object_name

$ rlsql -s -l <<< "@ sqlh 7ksrtc8rzpawc 60360" | awk '$10>=0 || $10='0'{ print $0}'
   SNAP_ID INSTANCE_NUMBER PLAN_HASH_VALUE BEGIN_INTERVAL_TIME      END_INTERVAL_TIME        ELAPSED_TIME_DELTA CPU_TIME_DELTA EXECUTIONS_DELTA EXECUTIONS_TOTAL ROWS_PROCESSED_DELTA BUFFER_GETS_DELTA LOADED_VERSIONS
     60360               1      4164392588 2021-09-16 15:00:20.273  2021-09-16 16:00:27.666            17267146       16734456               12             9896                    0           2846404              22
     60360               1      3030673966 2021-09-16 15:00:20.273  2021-09-16 16:00:27.666             2497060        2323646                0                0                    0               252              20
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~    
     60361               1      3030673966 2021-09-16 16:00:27.666  2021-09-16 17:00:35.402             1244472        1042842                0                0                    0               103              24
     60361               1      4164392588 2021-09-16 16:00:27.666  2021-09-16 17:00:35.402            17467751       16113550               11             9907                    0           2935098              25
     60362               1      4164392588 2021-09-16 17:00:35.402  2021-09-16 18:00:42.710            17397997       16587478               12             9919                    0           3610294              37
     60362               1      3030673966 2021-09-16 17:00:35.402  2021-09-16 18:00:42.710             2771635        2699588                0                0                    0               268              35
....
--//有點奇怪的是EXECUTIONS_DELTA=0,為什麼ELAPSED_TIME_DELTA>0的情況出現.自己測試看看.

1.環境:
SYS@127.0.0.1:XXXX/yyyy> @ 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.測試:
SYS@127.0.0.1:XXXX/yyyy> select /*+ aaa1234 */ count(*) from gv_$session;
  COUNT(*)
----------
      9129

SYS@127.0.0.1:XXXX/yyyy> @ hash
HASH_VALUE SQL_ID        CHILD_NUMBER HASH_HEX
---------- ------------- ------------ ---------
3330167945 47jvwgv37wp49            0  c67e5489

SYS@127.0.0.1:XXXX/yyyy> @ tpt/sql_id 47jvwgv37wp49 %
Show SQL text, child cursors and execution stats for SQLID 47jvwgv37wp49 child %
HASH_VALUE  CH# SQL_TEXT
---------- ---- -----------------------------------------------
3330167945    0 select /*+ aaa1234 */ count(*) from gv_$session

 CH# PARENT_HANDLE    OBJECT_HANDLE     PLAN_HASH     PARSES   H_PARSES EXECUTIONS    FETCHES ROWS_PROCESSED     CPU_MS     ELA_MS       LIOS       PIOS      SORTS USERS_EXECUTING
---- ---------------- ---------------- ---------- ---------- ---------- ---------- ---------- -------------- ---------- ---------- ---------- ---------- ---------- ---------------
   0 0000001305051800 0000001301B45EB0 1117094054          2          1          1          1              1     26.995     31.968          2          0          0               0

--//你可以發現執行1次.切換到另外的例項檢視發現:

SYS@127.0.0.1:ZZZZ/dbcn> @ tpt/sql_id 47jvwgv37wp49 %
Show SQL text, child cursors and execution stats for SQLID 47jvwgv37wp49 child %
HASH_VALUE  CH# SQL_TEXT
---------- ---- -----------------------------------------------
3330167945    0 select /*+ aaa1234 */ count(*) from gv_$session

 CH# PARENT_HANDLE    OBJECT_HANDLE     PLAN_HASH     PARSES   H_PARSES EXECUTIONS    FETCHES ROWS_PROCESSED     CPU_MS     ELA_MS       LIOS       PIOS      SORTS USERS_EXECUTING
---- ---------------- ---------------- ---------- ---------- ---------- ---------- ---------- -------------- ---------- ---------- ---------- ---------- ---------- ---------------
   0 000000132CBFA450 00000000B93ED610 1117094054          1          1          0          0              0      6.999      6.531          2          0          0               0

--//可以發現執行次數0,而實際上CPU_MS,ELA_MS有值.這樣查詢sqlh.sql語句出現EXECUTIONS_DELTA=0,ELAPSED_TIME_DELTA>0的情況就不奇怪了.

3.繼續:
SYS@127.0.0.1:XXXX/yyyy> select /*+ rule aaa1234 */ count(*) from gv$session;

  COUNT(*)
----------
      9138

SYS@127.0.0.1:XXXX/yyyy> @ hash
HASH_VALUE SQL_ID        CHILD_NUMBER HASH_HEX
---------- ------------- ------------ ---------
3793980144 f2psczrj272rh            0  e2238af0

SYS@127.0.0.1:XXXX/yyyy> select /*+ rule aaa1234 */ count(*) from gv$session;
  COUNT(*)
----------
      9127

SYS@127.0.0.1:XXXX/yyyy> @ dpc '' ''
PLAN_TABLE_OUTPUT
-------------------------------------
SQL_ID  f2psczrj272rh, child number 0
-------------------------------------
select /*+ rule aaa1234 */ count(*) from gv$session

Plan hash value: 3390655029

-------------------------------------------------------------------------------------------------------
| Id  | Operation                | Name       |    TQ  |IN-OUT| PQ Distrib |  OMem |  1Mem | Used-Mem |
-------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT         |            |        |      |            |       |       |          |
|   1 |  SORT AGGREGATE          |            |        |      |            |       |       |          |
|   2 |   PX COORDINATOR         |            |        |      |            |       |       |          |
|   3 |    PX SEND QC (RANDOM)   | :TQ10000   |  Q1,00 | P->S | QC (RAND)  |       |       |          |
|   4 |     VIEW                 | GV$SESSION |  Q1,00 | PCWP |            |       |       |          |
|   5 |      MERGE JOIN          |            |  Q1,00 | PCWP |            |       |       |          |
|   6 |       SORT JOIN          |            |  Q1,00 | PCWP |            |   372K|   372K|  330K (0)|
|   7 |        MERGE JOIN        |            |  Q1,00 | PCWP |            |       |       |          |
|   8 |         SORT JOIN        |            |  Q1,00 | PCWP |            |   232K|   232K|  206K (0)|
|   9 |          FIXED TABLE FULL| X$KSLWT    |  Q1,00 | PCWP |            |       |       |          |
|* 10 |         SORT JOIN        |            |  Q1,00 | PCWP |            | 31744 | 31744 |28672  (0)|
|  11 |          FIXED TABLE FULL| X$KSLED    |  Q1,00 | PCWP |            |       |       |          |
|* 12 |       SORT JOIN          |            |  Q1,00 | PCWP |            |   267K|   267K|  237K (0)|
|* 13 |        FIXED TABLE FULL  | X$KSUSE    |  Q1,00 | PCWP |            |       |       |          |
-------------------------------------------------------------------------------------------------------

Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------

   1 - SEL$1
   2 - SEL$2 / GV$SESSION@SEL$1
   5 - SEL$2
   9 - SEL$2 / W@SEL$2
  11 - SEL$2 / E@SEL$2
  13 - SEL$2 / S@SEL$2

Predicate Information (identified by operation id):
---------------------------------------------------

  10 - access("W"."KSLWTEVT"="E"."INDX")
       filter("W"."KSLWTEVT"="E"."INDX")
  12 - access("S"."INDX"="W"."KSLWTSID")
       filter("S"."INDX"="W"."KSLWTSID")
  13 - filter((BITAND("S"."KSUSEFLG",1)<>0 AND BITAND("S"."KSSPAFLG",1)<>0))

Note
-----
   - rule based optimizer used (consider using cbo)
   - statement not queuable: gv$ statement
   - Warning: basic plan statistics not available. These are only collected when:
       * hint 'gather_plan_statistics' is used for the statement or
       * parameter 'statistics_level' is set to 'ALL', at session or system level


SYS@127.0.0.1:XXXX/yyyy> @ tpt/sql_id f2psczrj272rh %
Show SQL text, child cursors and execution stats for SQLID f2psczrj272rh child %
HASH_VALUE  CH# SQL_TEXT
---------- ---- ---------------------------------------------------
3793980144    0 select /*+ rule aaa1234 */ count(*) from gv$session

 CH# PARENT_HANDLE    OBJECT_HANDLE     PLAN_HASH     PARSES   H_PARSES EXECUTIONS    FETCHES ROWS_PROCESSED     CPU_MS     ELA_MS       LIOS       PIOS      SORTS USERS_EXECUTING
---- ---------------- ---------------- ---------- ---------- ---------- ---------- ---------- -------------- ---------- ---------- ---------- ---------- ---------- ---------------
   0 00000001B57EFBE0 00000001B57F0648 3390655029          4          1          2          2              2     62.991    177.895          0          0          8               0

--//在另外的例項查詢,實際上即使提示rule也是並行查詢.
SYS@127.0.0.1:ZZZZ/dbcn> @ tpt/sql_id f2psczrj272rh %
Show SQL text, child cursors and execution stats for SQLID f2psczrj272rh child %
HASH_VALUE  CH# SQL_TEXT
---------- ---- ---------------------------------------------------
3793980144    0 select /*+ rule aaa1234 */ count(*) from gv$session

 CH# PARENT_HANDLE    OBJECT_HANDLE     PLAN_HASH     PARSES   H_PARSES EXECUTIONS    FETCHES ROWS_PROCESSED     CPU_MS     ELA_MS       LIOS       PIOS      SORTS USERS_EXECUTING
---- ---------------- ---------------- ---------- ---------- ---------- ---------- ---------- -------------- ---------- ---------- ---------- ---------- ---------- ---------------
   0 000000133C691C78 000000133C691B08 3390655029          2          1          0          0              0     14.998     15.475          0          0          8               0

--//從以上測試可以發現該語句出現EXECUTIONS_DELTA=0,ELAPSED_TIME_DELTA>0的情況就是正常的,

來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/267265/viewspace-2793886/,如需轉載,請註明出處,否則將追究法律責任。

相關文章