27 January, 2022

SQL Execution Statistics -- 1 : A Quick Introduction

 A couple of quick examples of how to obtain SQL Execution Statistics using the GATHER_PLAN_STATISTICS Hint


Here's how you get the Statisitics for an SQL executed from the same session.
SQL> Run query with /*+ gather_plan_statistics */ hint
SQL> Get execution statistics with dbms_xplan.display_cursor(FORMAT=>'ALLSTATS LAST');

For an SQL from another session, you will have to pass the SQL_ID (and, if necessary, the CHILD_NUMBER) as a parameter(s) to the DISPLAY_CURSOR function.

I present a query on DEPARTMENTS and EMPLOYEES with a three different execution plans.  The first is the one automatically generated by the Optimizer and using a Hash Join.  The next two use Nested Loop(s) but differently based on how I specify the LEADING and USE_NL Hints.


The first one using a HASH JOIN :


SQL> select /*+ gather_plan_statistics   */
  2  d.department_id, d.department_name, e.first_name, e.last_name
  3  from hr.departments d join hr.employees e
  4  on d.department_id=e.department_id
  5  order by 1,2,4,3
  6  /

DEPARTMENT_ID DEPARTMENT_NAME                FIRST_NAME           LAST_NAME
------------- ------------------------------ -------------------- -------------------------
           10 Administration                 Jennifer             Whalen
           20 Marketing                      Pat                  Fay
           20 Marketing                      Michael              Hartstein
           30 Purchasing                     Shelli               Baida
           30 Purchasing                     Karen                Colmenares
           30 Purchasing                     Guy                  Himuro
           30 Purchasing                     Alexander            Khoo
           30 Purchasing                     Den                  Raphaely
           30 Purchasing                     Sigal                Tobias
           40 Human Resources                Susan                Mavris
           50 Shipping                       Mozhe                Atkinson
....
....  Intermediate rows deleted from the output presented here
....
          100 Finance                        Ismael               Sciarra
          100 Finance                        Jose Manuel          Urman
          110 Accounting                     William              Gietz
          110 Accounting                     Shelley              Higgins
          280 New Department                 Hemant               Chitale

107 rows selected.

SQL>
SQL> @show_last_sql_statistics.sql
SQL> select * from table(dbms_xplan.display_cursor(format=>'ALLSTATS LAST'))
  2  /

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  59vduj8s28fhn, child number 0
-------------------------------------
select /*+ gather_plan_statistics   */ d.department_id,
d.department_name, e.first_name, e.last_name from hr.departments d join
hr.employees e on d.department_id=e.department_id order by 1,2,4,3

Plan hash value: 207737665

-----------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                | Name              | Starts | E-Rows | A-Rows |   A-Time   | Buffers |  OMem |  1Mem | Used-Mem |
-----------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT         |                   |      1 |        |    107 |00:00:00.01 |      14 |       |       |          |
|   1 |  SORT ORDER BY           |                   |      1 |    107 |    107 |00:00:00.01 |      14 | 18432 | 18432 |16384  (0)|
|*  2 |   HASH JOIN              |                   |      1 |    107 |    107 |00:00:00.01 |      14 |  1572K|  1572K| 1652K (0)|
|   3 |    TABLE ACCESS FULL     | DEPARTMENTS       |      1 |     29 |     29 |00:00:00.01 |       6 |       |       |          |
|   4 |    VIEW                  | index$_join$_002  |      1 |    108 |    107 |00:00:00.01 |       8 |       |       |          |
|*  5 |     HASH JOIN            |                   |      1 |        |    107 |00:00:00.01 |       8 |  1610K|  1610K| 1681K (0)|
|   6 |      INDEX FAST FULL SCAN| EMP_DEPARTMENT_IX |      1 |    108 |    107 |00:00:00.01 |       4 |       |       |          |
|   7 |      INDEX FAST FULL SCAN| EMP_NAME_IX       |      1 |    108 |    108 |00:00:00.01 |       4 |       |       |          |
-----------------------------------------------------------------------------------------------------------------------------------

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

   2 - access("D"."DEPARTMENT_ID"="E"."DEPARTMENT_ID")
   5 - access(ROWID=ROWID)


27 rows selected.

SQL> SQL>




The second one with a simple NESTED LOOP using  DEPARTMENTS as the "Outer" table :

SQL> select /*+ gather_plan_statistics  leading(d) use_nl(e) */
  2  d.department_id, d.department_name, e.first_name, e.last_name
  3  from hr.departments d join hr.employees e
  4  on d.department_id=e.department_id
  5  order by 1,2,4,3
  6  /

DEPARTMENT_ID DEPARTMENT_NAME                FIRST_NAME           LAST_NAME
------------- ------------------------------ -------------------- -------------------------
           10 Administration                 Jennifer             Whalen
           20 Marketing                      Pat                  Fay
           20 Marketing                      Michael              Hartstein
           30 Purchasing                     Shelli               Baida
           30 Purchasing                     Karen                Colmenares
           30 Purchasing                     Guy                  Himuro
           30 Purchasing                     Alexander            Khoo
           30 Purchasing                     Den                  Raphaely
           30 Purchasing                     Sigal                Tobias
           40 Human Resources                Susan                Mavris
           50 Shipping                       Mozhe                Atkinson
....
....  Intermediate rows deleted from the output presented here
....
          100 Finance                        Ismael               Sciarra
          100 Finance                        Jose Manuel          Urman
          110 Accounting                     William              Gietz
          110 Accounting                     Shelley              Higgins
          280 New Department                 Hemant               Chitale

107 rows selected.


SQL>
SQL> @show_last_sql_statistics.sql
SQL> select * from table(dbms_xplan.display_cursor(format=>'ALLSTATS LAST'))
  2  /

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  8q08zbr367cgg, child number 0
-------------------------------------
select /*+ gather_plan_statistics  leading(d) use_nl(e) */
d.department_id, d.department_name, e.first_name, e.last_name from
hr.departments d join hr.employees e on d.department_id=e.department_id
order by 1,2,4,3

Plan hash value: 2178791499

----------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                     | Name              | Starts | E-Rows | A-Rows |   A-Time   | Buffers |  OMem |  1Mem | Used-Mem |
----------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |                   |      1 |        |    107 |00:00:00.01 |      19 |       |       |          |
|   1 |  SORT ORDER BY                |                   |      1 |    107 |    107 |00:00:00.01 |      19 | 22528 | 22528 |20480  (0)|
|   2 |   NESTED LOOPS                |                   |      1 |    107 |    107 |00:00:00.01 |      19 |       |       |          |
|   3 |    NESTED LOOPS               |                   |      1 |    261 |    107 |00:00:00.01 |       9 |       |       |          |
|   4 |     TABLE ACCESS FULL         | DEPARTMENTS       |      1 |     29 |     29 |00:00:00.01 |       6 |       |       |          |
|*  5 |     INDEX RANGE SCAN          | EMP_DEPARTMENT_IX |     29 |      9 |    107 |00:00:00.01 |       3 |       |       |          |
|   6 |    TABLE ACCESS BY INDEX ROWID| EMPLOYEES         |    107 |      4 |    107 |00:00:00.01 |      10 |       |       |          |
----------------------------------------------------------------------------------------------------------------------------------------

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

   5 - access("D"."DEPARTMENT_ID"="E"."DEPARTMENT_ID")


26 rows selected.

SQL> SQL>


And the third, more complicated, Execution Plan for a slightly different SQL :

SQL> select /*+ gather_plan_statistics  leading(e) use_nl(d) */
  2  d.department_id, d.department_name, e.first_name, e.last_name
  3  from hr.departments d join hr.employees e
  4  on d.department_id=e.department_id
  5  order by 1,2,4,3
  6  /

DEPARTMENT_ID DEPARTMENT_NAME                FIRST_NAME           LAST_NAME
------------- ------------------------------ -------------------- -------------------------
           10 Administration                 Jennifer             Whalen
           20 Marketing                      Pat                  Fay
           20 Marketing                      Michael              Hartstein
           30 Purchasing                     Shelli               Baida
           30 Purchasing                     Karen                Colmenares
           30 Purchasing                     Guy                  Himuro
           30 Purchasing                     Alexander            Khoo
           30 Purchasing                     Den                  Raphaely
           30 Purchasing                     Sigal                Tobias
           40 Human Resources                Susan                Mavris
           50 Shipping                       Mozhe                Atkinson
....
....  Intermediate rows deleted from the output presented here
....
          100 Finance                        Ismael               Sciarra
          100 Finance                        Jose Manuel          Urman
          110 Accounting                     William              Gietz
          110 Accounting                     Shelley              Higgins
          280 New Department                 Hemant               Chitale

107 rows selected.

SQL>
SQL> @show_last_sql_statistics.sql
SQL> select * from table(dbms_xplan.display_cursor(format=>'ALLSTATS LAST'))
  2  /

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  2kbc7rcpjcu0w, child number 0
-------------------------------------
select /*+ gather_plan_statistics  leading(e) use_nl(d) */
d.department_id, d.department_name, e.first_name, e.last_name from
hr.departments d join hr.employees e on d.department_id=e.department_id
order by 1,2,4,3

Plan hash value: 2010582952

----------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                     | Name              | Starts | E-Rows | A-Rows |   A-Time   | Buffers |  OMem |  1Mem | Used-Mem |
----------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |                   |      1 |        |    107 |00:00:00.01 |     119 |       |       |          |
|   1 |  SORT ORDER BY                |                   |      1 |    107 |    107 |00:00:00.01 |     119 | 18432 | 18432 |16384  (0)|
|   2 |   NESTED LOOPS                |                   |      1 |    107 |    107 |00:00:00.01 |     119 |       |       |          |
|   3 |    NESTED LOOPS               |                   |      1 |    108 |    107 |00:00:00.01 |      12 |       |       |          |
|   4 |     VIEW                      | index$_join$_002  |      1 |    108 |    107 |00:00:00.01 |       8 |       |       |          |
|*  5 |      HASH JOIN                |                   |      1 |        |    107 |00:00:00.01 |       8 |  1610K|  1610K| 1539K (0)|
|   6 |       INDEX FAST FULL SCAN    | EMP_DEPARTMENT_IX |      1 |    108 |    107 |00:00:00.01 |       4 |       |       |          |
|   7 |       INDEX FAST FULL SCAN    | EMP_NAME_IX       |      1 |    108 |    108 |00:00:00.01 |       4 |       |       |          |
|*  8 |     INDEX UNIQUE SCAN         | DEPT_ID_PK        |    107 |      1 |    107 |00:00:00.01 |       4 |       |       |          |
|   9 |    TABLE ACCESS BY INDEX ROWID| DEPARTMENTS       |    107 |      1 |    107 |00:00:00.01 |     107 |       |       |          |
----------------------------------------------------------------------------------------------------------------------------------------

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

   5 - access(ROWID=ROWID)
   8 - access("D"."DEPARTMENT_ID"="E"."DEPARTMENT_ID")


30 rows selected.

SQL> SQL>


All three executions return exactly the same Result Set.  What are different are the Execution Plans and the Logical Reads.
The first Execution Plan (using a HASH JOIN) required 14 Logical Reads (Buffer Gets).
Note how the Second Execution required 19 Logical Reads  while the Third Execution required 119 Logical Reads  having queried the DEPARTMENTS Table via the Rows from the Nested Loop driven by the intermdiate "view" index$_join$_001  107 times (reading 1 Block each time).  

Since these are extremely small tables, the Actual Time is less than 1second but what matters in the comparison is the number of Logical Reads

("Starts" is the number of times that particular Step (Id) was actually executed, 
"E-Rows" is the Estimated Rows for the Execution Plan,
"A-Rows" is the *Actual* number of Rows retrieved at Runtime,
"A-Time" is the *Actual* Time in Hours:Minutes:Seconds,
"0mem" is the "Estimated Optimal Memory Usage", 
"1mem" is the Estimated 1-pass (one write to temp) Memory Usage 
"Used-Mem" is the Actual Memory Used)


SQL> select table_name, blocks, num_rows
  2  from dba_tables
  3  where owner = 'HR'
  4  and table_name in ('DEPARTMENTS','EMPLOYEES')
  5  order by 1
  6  /

TABLE_NAME                         BLOCKS   NUM_ROWS
------------------------------ ---------- ----------
DEPARTMENTS                             5         29
EMPLOYEES                               5        108

SQL>


Given the sizes of the two tables, I am sure that all the blocks are cached in the Buffer Cache, so I am not interested in Physical I/O statistics and Wait Times.  The Logical Reads consume CPU time.

This is an example of how to read SQL Execution Statistics.  

You may extrapolate to tables with thousands of blocks and tens of thousands of rows.  

Also, consider Memory Usage for the operations when you may have dozens of hundreds of sessions concurrently doing HASH JOINs and SORTs and being limited by PGA_AGGREGATE_TARGET.  Some Memory operations may overflow to the TEMP Tablespace, noticeably increasing total execution time.

No comments: