Thinking Out Loud

December 8, 2021

Find Statistics and SQL Using Index

Filed under: 11g,oracle,performance — mdinh @ 10:05 pm

Database is facing issues with enq: TX – allocate ITL entry.

Research to find Troubleshooting waits for ‘enq: TX – allocate ITL entry’ (Doc ID 1472175.1)

Index DINH.INFO_IX1 was rebuilt.

To find SQL using index DINH.INFO_IX1- https://github.com/jkstill/oracle-script-lib/blob/master/sql/find-index-sql.sql

After running find-index-sql.sql, get execution statistics and history for a SQL using Doc ID 1371778.1.

The document illustrates how to get execution statistics and history for a SQL using sql_id using Data Dictionary queries for both queries in memory and those in the AWR.

DEMO:

-- Find SQL where an index has been used

SQL> @find-index-sql.sql

old   2:    :b_index_owner := '&&v_index_owner';
new   2:    :b_index_owner := 'DINH';
old   3:    :b_index_name := '&&v_index_name';
new   3:    :b_index_name := 'INFO_IX1';

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.00


SQL_ID        PLAN_HASH_VALUE
------------- ---------------
272kpc0q766tx      1690776192
7wd9njg9sy9mk      1635894828
gu9t5kgmy3pp6       698638001

Elapsed: 00:00:46.75

SQL>

======================================================================
--- sql_history.sql for SQL_ID: 272kpc0q766tx using index DINH.INFO_IX1
======================================================================

SQL> @sql_history.sql

--- From Memory

Enter value for sql_id: 272kpc0q766tx
old  16: where sql_id = '&sql_id'
new  16: where sql_id = '272kpc0q766tx'

SQL_ID        CHILD_NUMBER PLAN_HASH_VALUE FIRST_LOAD_TIME      LAST_LOAD_TIME       OUTLINE_CATEGORY     SQL_PROFILE                      EXECUTIONS
------------- ------------ --------------- -------------------- -------------------- -------------------- -------------------------------- ----------
272kpc0q766tx            0      1690776192 2018-10-23/11:20:35  2021-10-21/05:55:23                                                                29
272kpc0q766tx            1      1690776192 2018-10-23/11:20:35  2021-07-29/19:55:22                                                          29268833
272kpc0q766tx            3      1690776192 2018-10-23/11:20:35  2021-12-08/08:00:26                                                               441
272kpc0q766tx            4      1690776192 2018-10-23/11:20:35  2021-05-07/05:16:48                                                              3583
272kpc0q766tx            6      1690776192 2018-10-23/11:20:35  2021-12-01/21:18:11                                                            413747
272kpc0q766tx            8      1690776192 2018-10-23/11:20:35  2021-12-01/22:07:51                                                               164
272kpc0q766tx           37      1690776192 2018-10-23/11:20:35  2021-04-24/10:51:28                                                           3394967
272kpc0q766tx           38      1690776192 2018-10-23/11:20:35  2021-04-24/16:02:52                                                             43383
272kpc0q766tx           49      1690776192 2018-10-23/11:20:35  2021-07-21/18:27:05                                                            466811
272kpc0q766tx           51      1690776192 2018-10-23/11:20:35  2021-07-21/22:27:11                                                              5238
272kpc0q766tx           54      1690776192 2018-10-23/11:20:35  2021-08-07/22:48:03                                                           3286771
272kpc0q766tx           56      1690776192 2018-10-23/11:20:35  2021-08-08/05:01:11                                                              9835
272kpc0q766tx           67      1690776192 2018-10-23/11:20:35  2021-10-02/06:52:24                                                            126753
272kpc0q766tx           68      1690776192 2018-10-23/11:20:35  2021-10-02/10:41:18                                                               138

14 rows selected.

--- From AWR

Enter value for sql_id: 272kpc0q766tx
old  15: where sql_id = '&sql_id'
new  15: where sql_id = '272kpc0q766tx'

SQL_ID           SNAP_ID PLAN_HASH_VALUE SQL_PROFILE                      EXECUTIONS_TOTAL
------------- ---------- --------------- -------------------------------- ----------------
272kpc0q766tx     353952      1690776192                                          35878169
272kpc0q766tx     355246      1690776192                                          37443248

SQL>

======================================================================
--- sql_history.sql for SQL_ID: 7wd9njg9sy9mk using index DINH.INFO_IX1
======================================================================

SQL> @sql_history.sql

--- From Memory

Enter value for sql_id: 7wd9njg9sy9mk
old  16: where sql_id = '&sql_id'
new  16: where sql_id = '7wd9njg9sy9mk'

no rows selected

--- From AWR

Enter value for sql_id: 7wd9njg9sy9mk
old  15: where sql_id = '&sql_id'
new  15: where sql_id = '7wd9njg9sy9mk'

no rows selected

SQL>

======================================================================
--- sql_history.sql for SQL_ID: gu9t5kgmy3pp6 using index DINH.INFO_IX1
======================================================================

SQL> @sql_history.sql

--- From Memory

Enter value for sql_id: gu9t5kgmy3pp6
old  16: where sql_id = '&sql_id'
new  16: where sql_id = 'gu9t5kgmy3pp6'

SQL_ID        CHILD_NUMBER PLAN_HASH_VALUE FIRST_LOAD_TIME      LAST_LOAD_TIME       OUTLINE_CATEGORY     SQL_PROFILE                      EXECUTIONS
------------- ------------ --------------- -------------------- -------------------- -------------------- -------------------------------- ----------
gu9t5kgmy3pp6            0       698638001 2018-10-23/11:20:27  2021-12-08/08:05:10                                                               268
gu9t5kgmy3pp6            1       698638001 2018-10-23/11:20:27  2021-08-07/23:19:17                                                           5343273
gu9t5kgmy3pp6            5       698638001 2018-10-23/11:20:27  2021-12-01/18:42:33                                                            190004
gu9t5kgmy3pp6           23       698638001 2018-10-23/11:20:27  2021-04-24/14:27:12                                                           5512867
gu9t5kgmy3pp6           32       698638001 2018-10-23/11:20:27  2021-07-21/19:22:08                                                           2831328
gu9t5kgmy3pp6           39       698638001 2018-10-23/11:20:27  2021-10-02/04:16:50                                                            287105

6 rows selected.

--- From AWR

Enter value for sql_id: gu9t5kgmy3pp6
old  15: where sql_id = '&sql_id'
new  15: where sql_id = 'gu9t5kgmy3pp6'

no rows selected

SQL>

UPDATE for sql_id 7wd9njg9sy9mk:

sql_id 7wd9njg9sy9mk exist from gv$sql_plan and dba_hist_sql_plan (using find-index-sql.sql)

but not from v$sql and dba_hist_sqlstat (using Doc ID 1371778.1) which is strange.

Manually checking using DBMS_XPLAN.display_cursor and dbms_xplan.display_awr shows:

SQL> SELECT * FROM TABLE(DBMS_XPLAN.display_cursor(sql_id=>'7wd9njg9sy9mk',format=>'ALLSTATS LAST +cost +bytes')); 

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------
SQL_ID: 7wd9njg9sy9mk, child number: 0 cannot be found


Elapsed: 00:00:00.00

SQL>

SQL> SELECT * FROM TABLE(dbms_xplan.display_awr('7wd9njg9sy9mk'));

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------
SQL_ID 7wd9njg9sy9mk
--------------------
An uncaught error happened in prepare_sql_statement : ORA-01403: no data found

Plan hash value: 1635894828

-----------------------------------------------------------------------------------------------
| Id  | Operation           | Name                    | Rows  | Bytes | Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------------------
|   0 | DELETE STATEMENT    |                         |       |       |   538 (100)|          |
|   1 |  DELETE             | *******_UPDATE_INFO     |       |       |            |          |
|   2 |   COUNT STOPKEY     |                         |       |       |            |          |
|   3 |    NESTED LOOPS     |                         |    50M|   958M|   538 (100)| 00:00:07 |
|   4 |     INDEX FULL SCAN | SYS_C00137313           |    50M|   620M|     4   (0)| 00:00:01 |
|   5 |     INDEX RANGE SCAN| **************_INFO_IX1 |     1 |     7 |     1   (0)| 00:00:01 |
-----------------------------------------------------------------------------------------------

Note
-----
   - dynamic sampling used for this statement (level=2)


21 rows selected.

Elapsed: 00:00:00.03

SQL>

Leave a Comment »

No comments yet.

RSS feed for comments on this post. TrackBack URI

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s

This site uses Akismet to reduce spam. Learn how your comment data is processed.

Create a free website or blog at WordPress.com.

%d bloggers like this: