Performance monitoring or tuning tool for SQL query taking long time using various tools

 

In that post,I will explain using various method or tool to investigate performance problem of particular sql query.

Let me create a test case first

 

create table test_c(id number,name char(100),address char(100),create_date date);
create table test_p(id number,name char(100));

declare
 v_m number;
 begin
 for i in 1..10000000 loop
 select round(dbms_random.value() * 44444444444) + 1 into v_m from dual t;
 insert into test_c values (i, 'My _name'||dbms_random.value(),'My _name'||dbms_random.value(),sysdate);
 end loop;
 commit;
 end;

declare
 v_m number;
 begin
 for i in 1..10000000 loop
 select round(dbms_random.value() * 44444444444) + 1 into v_m from dual t;
 insert into test_p values (i, 'My _name'||dbms_random.value());
 commit;
 end loop;
 end;

SQL> create index i1_test_c on test_c(id);

SQL> create index i1_test_p on test_p(id);

1.Run time analysis

 

1.1. Analysis by different options of explain plan and execution plan.

Here I used GATHER_PLAN_STATISTICS hint to capture E-rows (Estimated rows) and A-rows (Actual Rows).

Please use the below query for simulating the test case when bind variable can cause change of explain plan hence execution time.user will complain why one query is fast yesterday but slow today.one of cause may be bind variable change causing your query to take different execution plan in run time.this is sometimes default behavior or sometimes abnormal.my intention is to show how to use different method to check what may causes changes in BEHAVIOR.

The following query may pick adaptive plan.But this depend on your environment.

1.1.1 First I will test with id between 1 and 1000 .We will note the execution plan.

 

SQL> variable var1 number;
SQL> variable var2 number;

SQL> exec :var1:=1;

PL/SQL procedure successfully completed.

SQL> exec :var2:=1000;

PL/SQL procedure successfully completed.

SQL> set autotrace traceonly;
SQL> select /*+ gather_plan_statistics */ a.name,a.address,b.id from test_c a,test_p b where a.id=b.id and b.id between :var1 and :var2 order by a.name;

1000 rows selected.

Please note that if adaptive plan is being used, then it means SQL plan  is being changed during execution because of cardinality mismatch on the fly.

Now we can use below method to identify what steps have been removed during run time execution by statistics collector.The steps marked in RED are deleted during on the fly execution plan generation.

 

SQL> SET LINESIZE 200 PAGESIZE 100
 SELECT * FROM TABLE(DBMS_XPLAN.display_cursor(format => 'allstats last adaptive'));

1.1.2 Now I am gathering statistics.After that I will run same statement.You may notice difference in cost calculation.

 

exec :var2:=1000;

SQL>set autotrace traceonly;

SQL> select /*+ gather_plan_statistics */ a.name,a.address,b.id from test_c a,test_p b where a.id=b.id and b.id between :var1 and :var2 order by a.name;
 1000 rows selected.

We can check  A-rows and E-rows which can show indication in cardinality mismatches.

 

SQL> set linesize 200 pagesize 100;
SQL> SELECT * FROM table(dbms_xplan.display_cursor('fwhp6ukwmb1fj', 0, 'iostats last'));

 

1.1.3 Now let me run the same query again.We will check different advanced options shown from explain plan.

 

exec :var2:=1000;

Elapsed: 00:02:02.74
 SQL> SELECT *  FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(format => 'ADVANCED')); 

PLAN_TABLE_OUTPUT
 --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 SQL_ID fwhp6ukwmb1fj, child number 2
 -------------------------------------
 select /*+ gather_plan_statistics */ a.name,a.address,b.id from test_c a,test_p b where a.id=b.id and b.id between :var1 and :var2 order by a.name

Plan hash value: 3508152348

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

1 – SEL$1
4 – SEL$1 / B@SEL$1
5 – SEL$1 / A@SEL$1
6 – SEL$1 / A@SEL$1

Outline Data
————-

/*+
BEGIN_OUTLINE_DATA
IGNORE_OPTIM_EMBEDDED_HINTS
OPTIMIZER_FEATURES_ENABLE(‘12.1.0.2’)
DB_VERSION(‘12.1.0.2’)
ALL_ROWS
OUTLINE_LEAF(@”SEL$1″)
INDEX_RS_ASC(@”SEL$1″ “A”@”SEL$1” (“TEST_C”.”ID”))
BATCH_TABLE_ACCESS_BY_ROWID(@”SEL$1″ “A”@”SEL$1″)
INDEX(@”SEL$1” “B”@”SEL$1” (“TEST_P”.”ID”))
LEADING(@”SEL$1″ “A”@”SEL$1” “B”@”SEL$1″)
USE_HASH(@”SEL$1” “B”@”SEL$1″)
SWAP_JOIN_INPUTS(@”SEL$1” “B”@”SEL$1”)
END_OUTLINE_DATA
*/

Peeked Binds (identified by position):
————————————–

1 – :VAR1 (NUMBER): 1
2 – :VAR2 (NUMBER): 1000

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

2 – filter(:VAR2>=:VAR1)
3 – access(“A”.”ID”=”B”.”ID”)
4 – access(“B”.”ID”>=:VAR1 AND “B”.”ID”<=:VAR2)
6 – access(“A”.”ID”>=:VAR1 AND “A”.”ID”<=:VAR2)

Column Projection Information (identified by operation id):
———————————————————–

1 – (#keys=1) “A”.”NAME”[CHARACTER,100], “B”.”ID”[NUMBER,22],
“A”.”ADDRESS”[CHARACTER,100]
2 – “B”.”ID”[NUMBER,22], “A”.”ADDRESS”[CHARACTER,100], “A”.”NAME”[CHARACTER,100]
3 – (#keys=1) “B”.”ID”[NUMBER,22], “A”.”ADDRESS”[CHARACTER,100],
“A”.”NAME”[CHARACTER,100]
4 – “B”.”ID”[NUMBER,22]
5 – “A”.”ID”[NUMBER,22], “A”.”NAME”[CHARACTER,100], “A”.”ADDRESS”[CHARACTER,100]
6 – “A”.ROWID[ROWID,10], “A”.”ID”[NUMBER,22]

73 rows selected.

 

1.2 You can view run time performance of a query by writing SQL query which takes data from v$sql

 

select sql_text,sql_id,executions,users_executing,invalidations,disk_reads,buffer_gets,optimizer_cost,cpu_time,elapsed_time,rows_processed,is_bind_sensitive from v$sql where sql_id='fwhp6ukwmb1fj'

Please note disk_reads,buffer_gets.Sudden rise of these values may indicate problem.It also evident that query has 2 child cursors with different optimizer_cost.Users_executing shows 1 when the query is being executed.The rows_processed column shows how much rows the query has already fetched.

1.3 Checking run time performance using SQL monitor.

http://www.oracle.com/technetwork/database/manageability/owp-sql-monitoring-128746.pdf

 

SELECT DBMS_SQLTUNE.report_sql_monitor(sql_id => ‘fwhp6ukwmb1fj’, type => ‘HTML’, report_level => ‘ALL’) AS report FROM dual;

After the execution finises,it will show as below:-

 

2.historical analysis

 

2.1 Analysis using AWR history to check plan flip

Now there is another option to check what plans were used during execution of particular SQL_ID from AWR. This is good option for historical analysis OF PLAN FLIP.

 

SQL> select * from table(dbms_xplan.display_awr('fwhp6ukwmb1fj'));

2.2 Analysis using SQLHC report (Light wight version of SQLT report)

 

For more details:-

 

 

sqlhc_20180403_233101_fwhp6ukwmb1fj\sqlhc_20180403_233101_fwhp6ukwmb1fj_3_execution_plans.html

This html is important to understand possible plan flip

 

A)

 B)

 

C:\Project\sql_tuning\sqlhc_20180403_233101_fwhp6ukwmb1fj\sqlhc_20180403_233101_fwhp6ukwmb1fj_2_diagnostics.html

This html is very important to compare different metrics to pin point the issue.

 

2.3 Analysis using awrsqlrpt report

 

How to generate AWR SQL report:-

 

sqlplus / as sysdba

SQL> @?/rdbms/admin/awrsqrpt.sql

Type Specified: html

Enter value for num_days: 1

Enter value for begin_snap: 11949
 Begin Snapshot Id specified: 11949

Enter value for end_snap: 11957
 End Snapshot Id specified: 11957

Specify the SQL Id
 ~~~~~~~~~~~~~~~~~~
 Enter value for sql_id:Enter SQL_ID to check

The following section is showing possible plan change

 

The below sections shows plan change and effects on execution details:-

 

 

Leave a Reply

Your email address will not be published. Required fields are marked *