Tuesday, April 30, 2019

Using RULE Based Optimizer When Querying GV$ Views

I had a complaint from one of the readers that dbalarm script for monitoring the DB is taking very long time to run against one RAC DB [11.2.0.3] especially in the part of reporting locked sessions on the database, when I dug deeper found that most of time is getting consumed by this statement:

select
substr(s.INST_ID||'|'||s.OSUSER||'/'||s.USERNAME||'| '||s.sid||','||s.serial#||' |'||substr(s.MACHINE,1,22)||'|'||substr(s.MODULE,1,18),1,75)"I|OS/DB USER|SID,SER|MACHN|MOD"
,substr(s.status||'|'||round(w.WAIT_TIME_MICRO/1000000)||'|'||LAST_CALL_ET||'|'||to_char(LOGON_TIME,'ddMon HH24:MI'),1,34) "ST|WAITD|ACT_SINC|LOGIN"
,substr(w.event,1,24) "EVENT"
,s.PREV_SQL_ID||'|'||s.SQL_ID||'|'||round(w.TIME_REMAINING_MICRO/1000000) "PREV|CURRENT_SQL|REMAIN_SEC"
from    gv$session s, gv$session_wait w
where   s.sid in (select distinct FINAL_BLOCKING_SESSION from gv$session where FINAL_BLOCKING_SESSION is not null)
and     s.USERNAME is not null
and     s.sid=w.sid
and     s.FINAL_BLOCKING_SESSION is null
/

Elapsed: 00:00:11.34

Execution plan was showing this:
-------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation        | Name | Rows  | Bytes | Cost (%CPU)| Time |    TQ  |IN-OUT| PQ Distrib |
-------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT        | |     1 |   271 |     1 (100)| 00:00:01 |   | |       |
|*  1 |  FILTER        | | | |       | |   | |       |
|*  2 |   HASH JOIN        | |   100 | 27100 |     1 (100)| 00:00:01 |   | |       |
|   3 |    PX COORDINATOR        | |     1 |   198 |     0   (0)| 00:00:01 |   | |       |
|   4 |     PX SEND QC (RANDOM)        | :TQ20000 |     1 |   270 |     0   (0)| 00:00:01 |  Q2,00 | P->S | QC (RAND)  |
|*  5 |      VIEW        | GV$SESSION | | |       | |  Q2,00 | PCWP |       |
|   6 |       NESTED LOOPS        | |     1 |   270 |     0   (0)| 00:00:01 |  Q2,00 | PCWP |       |
|   7 |        NESTED LOOPS        | |     1 |   257 |     0   (0)| 00:00:01 |  Q2,00 | PCWP |       |
|*  8 | FIXED TABLE FULL       | X$KSUSE |     1 |   231 |     0   (0)| 00:00:01 |  Q2,00 | PCWP |       |
|*  9 | FIXED TABLE FIXED INDEX| X$KSLWT (ind:1) |     1 |    26 |     0   (0)| 00:00:01 |  Q2,00 | PCWP |       |
|* 10 |        FIXED TABLE FIXED INDEX | X$KSLED (ind:2) |     1 |    13 |     0   (0)| 00:00:01 |  Q2,00 | PCWP |       |
|  11 |    PX COORDINATOR        | |   100 |  7300 |     0   (0)| 00:00:01 |   | |       |
|  12 |     PX SEND QC (RANDOM)        | :TQ30000 |   100 | 12500 |     0   (0)| 00:00:01 |  Q3,00 | P->S | QC (RAND)  |
|  13 |      VIEW        | GV$SESSION_WAIT | | |       | |  Q3,00 | PCWP |       |
|  14 |       NESTED LOOPS        | |   100 | 12500 |     0   (0)| 00:00:01 |  Q3,00 | PCWP |       |
|  15 |        FIXED TABLE FULL        | X$KSLWT |   100 |  7800 |     0   (0)| 00:00:01 |  Q3,00 | PCWP |       |
|* 16 |        FIXED TABLE FIXED INDEX | X$KSLED (ind:2) |     1 |    47 |     0   (0)| 00:00:01 |  Q3,00 | PCWP |       |
|  17 |   PX COORDINATOR        | |     1 |    13 |     0   (0)| 00:00:01 |   | |       |
|  18 |    PX SEND QC (RANDOM)        | :TQ10000 |     1 |    91 |     0   (0)| 00:00:01 |  Q1,00 | P->S | QC (RAND)  |
|* 19 |     VIEW        | GV$SESSION | | |       | |  Q1,00 | PCWP |       |
|  20 |      NESTED LOOPS        | |     1 |    91 |     0   (0)| 00:00:01 |  Q1,00 | PCWP |       |
|  21 |       NESTED LOOPS        | |     1 |    78 |     0   (0)| 00:00:01 |  Q1,00 | PCWP |       |
|* 22 |        FIXED TABLE FULL        | X$KSUSE |     1 |    52 |     0   (0)| 00:00:01 |  Q1,00 | PCWP |       |
|* 23 |        FIXED TABLE FIXED INDEX | X$KSLWT (ind:1) |     1 |    26 |     0   (0)| 00:00:01 |  Q1,00 | PCWP |       |
|* 24 |       FIXED TABLE FIXED INDEX  | X$KSLED (ind:2) |     1 |    13 |     0   (0)| 00:00:01 |  Q1,00 | PCWP |       |
-------------------------------------------------------------------------------------------------------------------------------

When traced the session found the following in the trace:

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         0          0          0  FILTER  (cr=0 pr=0 pw=0 time=11647894 us)
      2818       2818       2818   HASH JOIN  (cr=0 pr=0 pw=0 time=74814 us cost=1 size=27100 card=100)
      1875       1875       1875    PX COORDINATOR  (cr=0 pr=0 pw=0 time=35972 us cost=0 size=198 card=1)
         0          0          0     PX SEND QC (RANDOM) :TQ20000 (cr=0 pr=0 pw=0 time=0 us cost=0 size=270 card=1)
         0          0          0      VIEW  GV$SESSION (cr=0 pr=0 pw=0 time=0 us)
         0          0          0       NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us cost=0 size=270 card=1)
         0          0          0        NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us cost=0 size=257 card=1)
         0          0          0         FIXED TABLE FULL X$KSUSE (cr=0 pr=0 pw=0 time=0 us cost=0 size=231 card=1)
         0          0          0         FIXED TABLE FIXED INDEX X$KSLWT (ind:1) (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)
         0          0          0        FIXED TABLE FIXED INDEX X$KSLED (ind:2) (cr=0 pr=0 pw=0 time=0 us cost=0 size=13 card=1)
      2018       2018       2018    PX COORDINATOR  (cr=0 pr=0 pw=0 time=5021 us cost=0 size=7300 card=100)
         0          0          0     PX SEND QC (RANDOM) :TQ30000 (cr=0 pr=0 pw=0 time=0 us cost=0 size=12500 card=100)
         0          0          0      VIEW  GV$SESSION_WAIT (cr=0 pr=0 pw=0 time=0 us)
         0          0          0       NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us cost=0 size=12500 card=100)
         0          0          0        FIXED TABLE FULL X$KSLWT (cr=0 pr=0 pw=0 time=0 us cost=0 size=7800 card=100)
         0          0          0        FIXED TABLE FIXED INDEX X$KSLED (ind:2) (cr=0 pr=0 pw=0 time=0 us cost=0 size=47 card=1)
         0          0          0   PX COORDINATOR  (cr=0 pr=0 pw=0 time=11562142 us cost=0 size=13 card=1)
         0          0          0    PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=7157212 us cost=0 size=91 card=1)
         0          0          0     VIEW  GV$SESSION (cr=0 pr=0 pw=0 time=7156047 us)
   1488896    1488896    1488896      NESTED LOOPS  (cr=0 pr=0 pw=0 time=6553126 us cost=0 size=91 card=1)
   1488896    1488896    1488896       NESTED LOOPS  (cr=0 pr=0 pw=0 time=5569809 us cost=0 size=78 card=1)
   1488896    1488896    1488896        FIXED TABLE FULL X$KSUSE (cr=0 pr=0 pw=0 time=3967204 us cost=0 size=52 card=1)
   1488896    1488896    1488896        FIXED TABLE FIXED INDEX X$KSLWT (ind:1) (cr=0 pr=0 pw=0 time=1142831 us cost=0 size=26 card=1)
   1488896    1488896    1488896       FIXED TABLE FIXED INDEX X$KSLED (ind:2) (cr=0 pr=0 pw=0 time=567563 us cost=0 size=13 card=1)

Ok. Now I can see that most of the time is getting consumed on the fixed tables in red color.

Now, let's check executing the same statement but using RULE Based Optimizer (RBO) this time:

select  /*+RULE*/
substr(s.INST_ID||'|'||s.OSUSER||'/'||s.USERNAME||'| '||s.sid||','||s.serial#||' |'||substr(s.MACHINE,1,22)||'|'||substr(s.MODULE,1,18),1,75)"I|OS/DB USER|SID,SER|MACHN|MOD"
,substr(s.status||'|'||round(w.WAIT_TIME_MICRO/1000000)||'|'||LAST_CALL_ET||'|'||to_char(LOGON_TIME,'ddMon HH24:MI'),1,34) "ST|WAITD|ACT_SINC|LOGIN"
,substr(w.event,1,24) "EVENT"
,s.PREV_SQL_ID||'|'||s.SQL_ID||'|'||round(w.TIME_REMAINING_MICRO/1000000) "PREV|CURRENT_SQL|REMAIN_SEC"
from    gv$session s, gv$session_wait w
where   s.sid in (select distinct FINAL_BLOCKING_SESSION from gv$session where FINAL_BLOCKING_SESSION is not null)
and     s.USERNAME is not null
and     s.sid=w.sid
and     s.FINAL_BLOCKING_SESSION is null
/


Elapsed: 00:00:00.09

Wow, RULE Based Optimizer (RBO) runs the statement in 9 centiseconds much faster than CBO which ran it in 11 seconds. How this happened?

The following was the execution plan when using RBO
------------------------------------------------------------------------------------
| Id  | Operation     | Name       |    TQ  |IN-OUT| PQ Distrib |
------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT     |       |        |      |    |
|   1 |  MERGE JOIN     |       |        |      |    |
|   2 |   MERGE JOIN     |       |        |      |    |
|   3 |    SORT JOIN     |       |        |      |    |
|   4 |     PX COORDINATOR     |       |        |      |    |
|   5 |      PX SEND QC (RANDOM)    | :TQ10000       |  Q1,00 | P->S | QC (RAND)  |
|   6 |       VIEW     | GV$SESSION_WAIT |  Q1,00 | PCWP |    |
|   7 |        MERGE JOIN     |       |  Q1,00 | PCWP |    |
|   8 | FIXED TABLE FULL    | X$KSLED       |  Q1,00 | PCWP |    |
|*  9 | SORT JOIN     |       |  Q1,00 | PCWP |    |
|  10 | FIXED TABLE FULL   | X$KSLWT       |  Q1,00 | PCWP |    |
|* 11 |    SORT JOIN     |       |        |      |    |
|  12 |     PX COORDINATOR     |       |        |      |    |
|  13 |      PX SEND QC (RANDOM)    | :TQ20000       |  Q2,00 | P->S | QC (RAND)  |
|* 14 |       VIEW     | GV$SESSION      |  Q2,00 | PCWP |    |
|  15 |        MERGE JOIN     |       |  Q2,00 | PCWP |    |
|  16 | SORT JOIN     |       |  Q2,00 | PCWP |    |
|  17 | MERGE JOIN     |       |  Q2,00 | PCWP |    |
|  18 |   SORT JOIN     |       |  Q2,00 | PCWP |    |
|  19 |    FIXED TABLE FULL | X$KSLWT       |  Q2,00 | PCWP |    |
|* 20 |   SORT JOIN     |       |  Q2,00 | PCWP |    |
|  21 |    FIXED TABLE FULL | X$KSLED       |  Q2,00 | PCWP |    |
|* 22 | SORT JOIN     |       |  Q2,00 | PCWP |    |
|* 23 | FIXED TABLE FULL   | X$KSUSE       |  Q2,00 | PCWP |    |
|* 24 |   SORT JOIN     |       |        |      |    |
|  25 |    VIEW     | VW_NSO_1       |        |      |    |
|  26 |     SORT UNIQUE     |       |        |      |    |
|  27 |      PX COORDINATOR     |       |        |      |    |
|  28 |       PX SEND QC (RANDOM)   | :TQ30000       |  Q3,00 | P->S | QC (RAND)  |
|* 29 |        VIEW     | GV$SESSION      |  Q3,00 | PCWP |    |
|  30 | MERGE JOIN     |       |  Q3,00 | PCWP |    |
|  31 | SORT JOIN     |       |  Q3,00 | PCWP |    |
|  32 |   MERGE JOIN     |       |  Q3,00 | PCWP |    |
|  33 |    SORT JOIN     |       |  Q3,00 | PCWP |    |
|  34 |     FIXED TABLE FULL| X$KSLWT       |  Q3,00 | PCWP |    |
|* 35 |    SORT JOIN     |       |  Q3,00 | PCWP |    |
|  36 |     FIXED TABLE FULL| X$KSLED       |  Q3,00 | PCWP |    |
|* 37 | SORT JOIN     |       |  Q3,00 | PCWP |    |
|* 38 |   FIXED TABLE FULL  | X$KSUSE       |  Q3,00 | PCWP |    |
------------------------------------------------------------------------------------

Checking the trace for the execution time when using RBO:

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         0          0          0  MERGE JOIN  (cr=0 pr=0 pw=0 time=87623 us)
         1          1          1   MERGE JOIN  (cr=0 pr=0 pw=0 time=65256 us)
         7          7          7    SORT JOIN (cr=0 pr=0 pw=0 time=23492 us)
      2024       2024       2024     PX COORDINATOR  (cr=0 pr=0 pw=0 time=14913 us)
         0          0          0      PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=0 us)
         0          0          0       VIEW  GV$SESSION_WAIT (cr=0 pr=0 pw=0 time=0 us)
         0          0          0        MERGE JOIN  (cr=0 pr=0 pw=0 time=0 us)
         0          0          0         FIXED TABLE FULL X$KSLED (cr=0 pr=0 pw=0 time=0 us)
         0          0          0         SORT JOIN (cr=0 pr=0 pw=0 time=0 us)
         0          0          0          FIXED TABLE FULL X$KSLWT (cr=0 pr=0 pw=0 time=0 us)
         1          1          1    SORT JOIN (cr=0 pr=0 pw=0 time=41766 us)
      1877       1877       1877     PX COORDINATOR  (cr=0 pr=0 pw=0 time=29246 us)
         0          0          0      PX SEND QC (RANDOM) :TQ20000 (cr=0 pr=0 pw=0 time=0 us)
         0          0          0       VIEW  GV$SESSION (cr=0 pr=0 pw=0 time=0 us)
         0          0          0        MERGE JOIN  (cr=0 pr=0 pw=0 time=0 us)
         0          0          0         SORT JOIN (cr=0 pr=0 pw=0 time=0 us)
         0          0          0          MERGE JOIN  (cr=0 pr=0 pw=0 time=0 us)
         0          0          0           SORT JOIN (cr=0 pr=0 pw=0 time=0 us)
         0          0          0            FIXED TABLE FULL X$KSLWT (cr=0 pr=0 pw=0 time=0 us)
         0          0          0           SORT JOIN (cr=0 pr=0 pw=0 time=0 us)
         0          0          0            FIXED TABLE FULL X$KSLED (cr=0 pr=0 pw=0 time=0 us)
         0          0          0         SORT JOIN (cr=0 pr=0 pw=0 time=0 us)
         0          0          0          FIXED TABLE FULL X$KSUSE (cr=0 pr=0 pw=0 time=0 us)
         0          0          0   SORT JOIN (cr=0 pr=0 pw=0 time=22335 us)
         0          0          0    VIEW  VW_NSO_1 (cr=0 pr=0 pw=0 time=22327 us)
         0          0          0     SORT UNIQUE (cr=0 pr=0 pw=0 time=22325 us)
         0          0          0      PX COORDINATOR  (cr=0 pr=0 pw=0 time=22293 us)
         0          0          0       PX SEND QC (RANDOM) :TQ30000 (cr=0 pr=0 pw=0 time=0 us)
         0          0          0        VIEW  GV$SESSION (cr=0 pr=0 pw=0 time=0 us)
         0          0          0         MERGE JOIN  (cr=0 pr=0 pw=0 time=0 us)
         0          0          0          SORT JOIN (cr=0 pr=0 pw=0 time=0 us)
         0          0          0           MERGE JOIN  (cr=0 pr=0 pw=0 time=0 us)
         0          0          0            SORT JOIN (cr=0 pr=0 pw=0 time=0 us)
         0          0          0             FIXED TABLE FULL X$KSLWT (cr=0 pr=0 pw=0 time=0 us)
         0          0          0            SORT JOIN (cr=0 pr=0 pw=0 time=0 us)
         0          0          0             FIXED TABLE FULL X$KSLED (cr=0 pr=0 pw=0 time=0 us)
         0          0          0          SORT JOIN (cr=0 pr=0 pw=0 time=0 us)
         0          0          0           FIXED TABLE FULL X$KSUSE (cr=0 pr=0 pw=0 time=0 us)

Querying fixed objects (X$KSLWT, X$KSLED, X$KSUSE) with RBO took less than second.

When tried to check the statistics date on referenced fixed objects found no statistics:

SQL> select OWNER, TABLE_NAME, LAST_ANALYZED from DBA_TAB_STATISTICS where TABLE_NAME in ('X$KSUSE','X$KSLWT','X$KSLED');

OWNER  TABLE_NAME               LAST_ANALYZED
------------------  ------------------------------ --------------------
SYS   X$KSLED
SYS   X$KSLWT
SYS   X$KSUSE

OK, this may explain why CBO was producing a bad plan when querying those fixed objects. Statistics are the eyes of the CBO if they are not exist CBO will generate plans based on Dynamic Sampling which may generate inaccurate plans.

Now let's prove this by gathering fixed objects statistics while the DB is highly used in order to get accurate statistics on X$ tables representing the actual load:

Check this link to know more about Fixed Objects Statistics and how to gather:
http://dba-tips.blogspot.com/2012/11/all-about-statistics-in-oracle.html

SQL> exec dbms_stats.gather_fixed_objects_stats; 

Let's check if the new Fixed Objects statistics will make the difference:

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         0          0          0  FILTER  (cr=0 pr=0 pw=0 time=14075373 us)
      3882       3882       3882   HASH JOIN  (cr=0 pr=0 pw=0 time=104766 us cost=1 size=262 card=1)
      2376       2376       2376    PX COORDINATOR  (cr=0 pr=0 pw=0 time=54948 us cost=0 size=198 card=1)
         0          0          0     PX SEND QC (RANDOM) :TQ20000 (cr=0 pr=0 pw=0 time=0 us cost=0 size=243 card=1)
         0          0          0      VIEW  GV$SESSION (cr=0 pr=0 pw=0 time=0 us)
         0          0          0       NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us cost=0 size=243 card=1)
         0          0          0        NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us cost=0 size=239 card=1)
         0          0          0         FIXED TABLE FULL X$KSUSE (cr=0 pr=0 pw=0 time=0 us cost=0 size=231 card=1)
         0          0          0         FIXED TABLE FIXED INDEX X$KSLWT (ind:1) (cr=0 pr=0 pw=0 time=0 us cost=0 size=8 card=1)
         0          0          0        FIXED TABLE FIXED INDEX X$KSLED (ind:2) (cr=0 pr=0 pw=0 time=0 us cost=0 size=4 card=1)
      2525       2525       2525    PX COORDINATOR  (cr=0 pr=0 pw=0 time=8645 us cost=0 size=85376 card=1334)
         0          0          0     PX SEND QC (RANDOM) :TQ30000 (cr=0 pr=0 pw=0 time=0 us cost=0 size=77372 card=1334)
         0          0          0      VIEW  GV$SESSION_WAIT (cr=0 pr=0 pw=0 time=0 us)
         0          0          0       NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us cost=0 size=77372 card=1334)
         0          0          0        FIXED TABLE FULL X$KSLWT (cr=0 pr=0 pw=0 time=0 us cost=0 size=37352 card=1334)
         0          0          0        FIXED TABLE FIXED INDEX X$KSLED (ind:2) (cr=0 pr=0 pw=0 time=0 us cost=0 size=30 card=1)
         0          0          0   PX COORDINATOR  (cr=0 pr=0 pw=0 time=13959372 us cost=0 size=13 card=1)
         0          0          0    PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=10443626 us cost=0 size=64 card=1)
         0          0          0     VIEW  GV$SESSION (cr=0 pr=0 pw=0 time=10442090 us)
   2339876    2339876    2339876      NESTED LOOPS  (cr=0 pr=0 pw=0 time=10767975 us cost=0 size=64 card=1)
   2339876    2339876    2339876       NESTED LOOPS  (cr=0 pr=0 pw=0 time=9109717 us cost=0 size=60 card=1)
   2339876    2339876    2339876        FIXED TABLE FULL X$KSUSE (cr=0 pr=0 pw=0 time=6389468 us cost=0 size=52 card=1)
   2339876    2339876    2339876        FIXED TABLE FIXED INDEX X$KSLWT (ind:1) (cr=0 pr=0 pw=0 time=1872304 us cost=0 size=8 card=1)
   2339876    2339876    2339876       FIXED TABLE FIXED INDEX X$KSLED (ind:2) (cr=0 pr=0 pw=0 time=962703 us cost=0 size=4 card=1)

Theoretically, this is embarrassing :-) No big improvement after gathering statistics on fixed objects.
RULE Based Optimizer managed to beat CBO  when querying V$ views at least in this scenario.

Conclusion:
- RULE Based Optimizer can produce better plans than CBO when querying V$/GV$ views.
- It's always recommended to have good statistics on fixed objects representing the real system load to help CBO produce good execution plans when V$ views are queried, this can also improve the performance of your monitoring tools, RMAN, Enterprise Manager performance as well as they are heavily dependant on querying V$/GV$ views.

Above experiment was done on 11.2.0.3 but I've experienced the same on 11.2.0.4 and 12c as well.

Update: I've opened an SR with Oracle Support to get an explanation for this behavior and after going through many actions plans they finally suggested to use RULE Based Optimizer.

No comments:

Post a Comment