Using AWR for SQL Analysis

Michael R. Ault Oracle Guru Texas Memory Systems Using AWR For SQL Analysis

Michael R. Ault Oracle Guru Nuclear Navy 6 years Nuclear Chemist/Programmer 10 years Kennedy Western University Graduate Bachelors Degree Computer Science Certified in all Oracle Versions Since 6 Oracle DBA, author, since 1990

Introduction Many times a developer may be given the task of helping the DBA find and resolve an applications poorly performing code. Of course first one must define what constitutes poor performance. Is poor performance a certain number of logical or physical IO’s? Is it a certain number of consistent reads? Ideally it is when all actions require the fewest resources to execute. However, you must determine what is good enough performance

Introduction For example, in an order entry situation inserts should be expected to be sub-second. Another example would be that in a customer service application the customer information screen should be expected to be populated within less than seven seconds. Yet another would be that a decision support system needs to return results within 15 minutes. Each of these applications has different expectations for performance and each must be tuned using that expectation set in mind.

Introduction Another key concept when tuning is the concept of enough is enough. This concept means to set specific tuning goals and when you reach them, go on to the next problem. Tuning Oracle has been likened to a video game with infinite levels, there is always a way to get a few more milliseconds or microseconds of performance from Oracle, you have to know when to quit! In this presentation we will look at using the statspack, and by extension the AWR, tool for finding and correcting bad SQL in an application.

What We Will Discuss Using Statspack and AWR to Track Code Sorts SQL Review Commenting Code

Why Should Developers Tune? DBAs are responsible for tuning…right? Wrong! Everyone is! Oracle and third party tools make it easy. (Well, almost!)

Available Tools Explain Plan Trace and TKPROF DBMS_PROFILER Events Statspack and AWR Enterprise Manager

Let’s Look at Statspack Installation, from SYS user: Make sure dbms_jobs and dbms_shared_pool are installed in the system. Review the spcreate.sql series of called scripts and eliminate the calls to install the packages in step 1. Create a perfstat tablespace Run the spcreate.sql script, usually in the $ORACLE_HOME/rdbms/admin directory Use the statspack.snap procedure to test the install Start automated statistics runs with spauto.sql

AWR Usage In 10g we now have AWR. The Automatic Workload Repository (AWR) defaults to a collection interval every 30 minutes AWR is like STATSPACK, especially the level-5 STATSPACK collection mechanism where top SQL is collected every hour. In addition to the SQL, AWR collects detailed run-time statistics on the top SQL (disk reads, executions, consistent gets, etc) and uses this information to adjust the rolling collection threshold. AWR takes advantage of new Oracle10 and 11 to gather its statistics using non-SQL based collection techniques. The awrrpt.sql script is used to generate the reports that take the place of the Statspack reports in 10/11g.

Testing Using Statspack or AWR Statspack and AWR are simply statistics capture tools that also provide a report that shows you performance related statistics. Part of the statistics are several listings of SQL statements sliced and diced by number of consistent gets, number of physical reads, number of parses, number of executions and number of versions. Of course for a statement to appear there, it must have been run!

Testing SQL Using Statspack or AWR Statspack process will only capture what is currently going on in the database. It takes snapshots of the current state and allows you to choose two snapshots to compare. In the case of the SQL statements, if they are still in the shared pool between the two statspack runs, then your changes may be masked by old code runs. For testing purposes you need to flush the shared pool, execute a snapshot, then test your changes and execute another snapshot

Testing Using Statspack or AWR Use the “ALTER SYSTEM FLUSH SHARED_POOL;” command to flush old SQL from the pool. Execute the command “execute statspack.snap;” to begin a statspack capture window. Run your test code Execute the command “execute statspack.snap;” to end the statspack capture window. Run the spreport.sql script to generate a report based on the time interval between steps 2 and 4.

Testing Using Statspack or AWR If you don’t already know what SQL is causing issues use the automated statspack gathering (spauto.sql) to capture a profile of statspack runs across the time periods when the users have the problems. Running statspack off hours probably won’t tell you a lot, you need to run it when the problem is occurring! AWR (unless you turn it off) runs continuously and retains 7 days of data by default

Evaluating Statspack or AWR for Code Issues A number of sections devoted entirely to code. There are sections devoted to waits and one to latches. Use a cross-mix between waits, latches and the reported SQL to isolate correct the problem SQL. Start with the major hitters If a SQL shows up in the top ten in both the consistent gets and disk reads area then it is a good candidate. For this presentation we will be using example outputs from actual Statspack/AWR reports.

SQL Areas in AWR/Statspack Reports SQL ordered by CPU Time – Sorting, bad paths SQL ordered by Gets – Excessive logical IO SQL ordered by Reads – Cache starvation, FTS SQL ordered by Parse Calls – Cursor sharing, cursor caching SQL ordered by Version Count – Versioning is usually due to a bug, check with support SQL Detailed Listing – Shows full code (may not be in all reports) Tune SQL that appears in more than one of these areas Tune SQL at the top of these sections

Evaluating Statspack or AWR for Code Issues Don’t tune one-offs, unless that is the code you are tuning. Let’s look at some actual statspack/AWR outputs and see what we can determine from them about the code they contain.

Example Top 5 events Snap Id Snap Time Sessions Curs/Sess Comment ------- ------------------ -------- --------- ------------------- Begin Snap: 1240 26-May-05 15:00:02 34 5.0 End Snap: 1241 26-May-05 16:00:02 33 4.9 Elapsed: 60.00 (mins) Top 5 Timed Events ~~~~~~~~~~~~~~~~~~ % Total Event Waits Time (s) Ela Time -------------------------------------------- ------------ ----------- -------- db file sequential read 320,448 4,588 32.25 direct path read 58,652 2,988 21.00 CPU time 2,182 15.34 PX Deq: Execute Reply 1,428 1,257 8.83 db file scattered read 11,406 1,020 7.17 -------------------------------------------------------------

Example Statements Physical Reads Executions Reads per Exec %Total Time (s) Time (s) Hash Value --------------- ------------ -------------- ------ -------- --------- ---------- 90,051 20,322 4.4 1.9 90.85 3506.03 2624188903 Module: SQL*Plus SELECT /*+ INDEX(p1 iu_pol_isc) */ t1.pol_tran_eff_dt FROM pol p1, pol_tran t1 WHERE p1.p ol_nbr = :b2 AND p1.ign_sys_cd = :b1 AND t1.pol_id = p1.pol_id A ND t1.pol_tran_typ_cd = 'CN' AND 1,466 1 1,466.0 0.0 10.10 13.08 3656618493 Module: SQLNav5.exe Select /*+ FIRST_ROWS */ Key||','||WRTN_PREM||','||WRTN_EXPSR|| ','||EARNED From ( Select /*+ INDEX(pcoopt POL_COVG_ON_OFF_PRE M_TRAN_IDX1) */ --/*+ INDEX(pcoopt POL_COVG_ON_OFF_PREM_TRAN_I DX1) */ --- /*+ INDEX(pcoopt PK_POL_COVG_ON_OFF_PREM_TRAN) */ pcoopt.pol_id||','||pcoopt.pol_tran_id||','||pcoop 852 1 852.0 0.0 11.15 12.26 656581566 Module: SQLNav5.exe Select /*+ FIRST_ROWS */ Key||','||WRTN_PREM||','||WRTN_EXPSR|| ','||EARNED From ( Select /*+ FIRST_ROWS */ --/*+ INDEX(pcoo pt POL_COVG_ON_OFF_PREM_TRAN_IDX1) */ --- /*+ INDEX(pcoopt PK_ POL_COVG_ON_OFF_PREM_TRAN) */ pcoopt.pol_id||','|| pcoopt.pol_tran_id||','||pcoopt.veh_unit_nbr||','||

Analysis The three SQL statements are application SQL statements, the other of the top 10 were all from monitoring tools. Of the three, two are limited to only a single execution however we have one SQL that was executed a whopping 20,322 times. Even though it only does 4.4 reads per execution, it does a great number of these. By tuning this SQL we can reduce the physical IO requirements of the application. That we are getting lots of small reads (4.4 IOs per execution) indicates that this may be the source of many of our sequential read waits reported in this period. Generally sequential read waits can be mitigated by more cache memory, we may not need to tune this query.

Analysis Direct path reads are due to sorts and some full scanning. We will look at sorting later

Analysis The scattered read waits are probably due to the monitoring SQL being generated by the monitoring reads. The problem here may also be memory related as the memory may not be large enough to hold the data needed by the application.

Analysis - Repeated Statements Physical Reads Executions Reads per Exec %Total Time (s) Time (s) Hash Value --------------- ------------ -------------- ------ -------- --------- ---------- 90,051 20,322 4.4 1.9 90.85 3506.03 2624188903 Module: SQL*Plus SELECT /*+ INDEX(p1 iu_pol_isc) */ t1.pol_tran_eff_dt FROM pol p1, pol_tran t1 WHERE p1.p ol_nbr = :b2 AND p1.ign_sys_cd = :b1 AND t1.pol_id = p1.pol_id A ND t1.pol_tran_typ_cd = 'CN' AND Buffer Gets Executions Gets per Exec %Total Time (s) Time (s) Hash Value --------------- ------------ -------------- ------ -------- --------- ---------- 796,391 20,322 39.2 2.0 90.85 3506.03 2624188903 Module: SQL*Plus SELECT /*+ INDEX(p1 iu_pol_isc) */ t1.pol_tran_eff_dt FROM pol p1, pol_tran t1 WHERE p1.p ol_nbr = :b2 AND p1.ign_sys_cd = :b1 AND t1.pol_id = p1.pol_id A ND t1.pol_tran_typ_cd = 'CN' AND

Analysis We know it is the same code, even though we can’t see all of it by the hash value: 2624188903 being identical. This is the SQL to analyse. We can obtain the entire SQL statement by extracting it from the V$SQLTEXT view using the hash value provided or with AWR it is provided in the report. Using this hash code, we can also (if we are in 9i or greater) extract the explain plan for the code from the V$SQL_PLAN table as well. Using the DBMS_XPLAN package makes getting explain plans a snap.

Recursive SQL Occurs whenever a SQL statement is parsed Is SQL executed on behalf of a client SQL against underlying data dictionary tables Determines table, index, column existence Determines permissions and grants Determines settings (initialization parameters and undoc settings)

Recursive SQL Snap Id Snap Time Sessions Curs/Sess Comment ------- ------------------ -------- --------- ------------------- Begin Snap: 12 07-Jun-04 17:53:55 117 8.2 End Snap: 13 07-Jun-04 18:03:18 107 7.4 Elapsed: 9.38(mins) Instance Efficiency Percentages (Target 100%) ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Buffer Nowait %: 100.00 Redo NoWait %: 99.98 Buffer Hit %: 98.55 In-memory Sort %: 100.00 Library Hit %: 99.51 Soft Parse %: 98.80 Execute to Parse %: 63.14 Latch Hit %: 99.90 Parse CPU to Parse Elapsd %: 68.58 % Non-Parse CPU: 99.45 Top 5 Timed Events ~~~~~~~~~~~~~~~~~~ % Total Event Waits Time (s) Ela Time ------------------------------------ ------------ --------- -------- CPU time 1,570 75.13 latch free 13,348 193 9.21 SQL*Net more data to client 327,015 147 7.03 log file sync 3,263 91 4.34 db file scattered read 191,897 44 2.13 -------------------------------------------------------------

Recursive SQL We see: lots of CPU time being used lots of buffer gets and lots of physical reads Our key waits are for SQL area (latch free) events. We can see that the various parse related ratios are very much less than 100% Soft parse is also an indicator This would indicate re-parsing (hard parsing) was occurring. Reparsing is generally caused by lack of bind variables. In some 10/11 releases versioning can also be an issue Fix versioning by using CURSOR_SHARING=FORCE or setting _sqlexec_progression_cost high

If we look at the Report We see a number of SQL statements that are not using bind variables and some that use a mix of literal and bind variables. In this situation we can apply the comparisons we used for the buffer reads and the physical reads as well as non-use of bind variables to find and repair the problem SQL statements. If you are unable to correct the non-use of bind variables, using the CURSOR_SHARING initialization parameter will help with the parse situation.

Sorts SQL doing sorts will effect performance Un-needed sorts can be caused by: DISTINCT ORDER BY GROUP BY CARTESIAN JOIN Monitor using Sort statistics

Sort Statistics Statistic Total per Second per Trans -------------------------------- ------------------ -------------- ------------- sorts (disk) 3,529 0.2 0.0 sorts (memory) 9,012,270 417.6 6.0 sorts (rows) 110,063,794,220 5,099,850.2 73,302.3 workarea executions - multipass 0 0.0 0.0 workarea executions - onepass 5,293 0.3 0.0 workarea executions - optimal 7,113,060 329.6 4.7 Tablespace IO Stats DB/Inst: CC1/cc1 Snaps: 84084-84108 -> ordered by IOs (Reads + Writes) desc Tablespace ------------------------------ Av Av Av Av Buffer Av Buf Reads Reads/s Rd(ms) Blks/Rd Writes Writes/s Waits Wt(ms) -------------- ------- ------ ------- ------------ -------- ---------- ------ TEMP 11,484,000 532 16.3 4.1 3,478,365 161 12,266 2.0 REPMAN_TEMP 1,703,767 79 27.2 8.2 1,457,241 68 0 0.0

Sort Statistics PGA Aggr Target Histogram DB/Inst: test/test Snaps: 84-108 -> Optimal Executions are purely in-memory operations Low High Optimal Optimal Total Execs Optimal Execs 1-Pass Execs M-Pass Execs ------- ------- -------------- -------------- ------------ ------------ 2K 4K 6,308,435 6,308,435 0 0 512K 1024K 353,344 353,344 0 0 1M 2M 201,558 201,558 0 0 2M 4M 22,468 22,468 0 0 4M 8M 21,796 21,725 71 0 8M 16M 28,892 28,714 178 0 16M 32M 30,478 30,346 132 0 32M 64M 19,898 18,690 1,208 0 64M 128M 9,080 7,284 1,796 0 128M 256M 1,682 732 950 0 256M 512M 734 179 555 0 512M 1024M 329 58 271 0 1G 2G 131 14 117 0 2G 4G 17 4 13 0 -------------------------------------------------------------

What SQL Areas Are SORTS Effecting? Logical IO Physical IO Longest Elapsed Time If you see the same SQL statement in several of the above areas, it is a candidate for reviewing sort activity I wish they would add an area showing SQL that are doing FTS and one with SQL that has IO to the temporary tablespace In AWR reports the Segment Statistics reports also help. Look for objects in the Direct IO report section and review SQL that address them

SQL Structure Issues Review the detailed code listings for: Insufficient joins: you need N-1 where N is number of tables Excessive tables in join: _MAX_OPTIMIZER_PERMUTATIONS is set to 2000, this means a maximum of 6 tables can be utilized optimally Improper use of hints (re-evaluate hints at every upgrade) Improper use of DISTINCT, may show lazy programmer syndrome (LPS) Proper use of bind variables

Identify SQL using Comments Placing a comment in each SQL statement that identifies the SQL. An example of this is: CURSOR get_latch IS SELECT /* DBA_UTIL.get_latch */ a.name,100.*b.sleeps/b.gets FROM v$latchname a, v$latch b WHERE a.latch# = b.latch# and b.sleeps > 0; You simply query the V$SQLAREA or V$SQLTEXT, or the V$SQL_PLAN VPT to find code entries with '%DBA_UTIL%' in the SQL_TEXT column. In addition, in any Statspack output, the code identifies itself.

Conclusion In this presentation I have tried to convey the importance of using statspack to help find and isolate SQL statements that need tuning. We have covered the installation and use of Statspack and have discussed AWR and its use along with statspack. DBAs and Developers should utilize statspack or AWR for point monitoring of development environments and for continued monitoring of production environments.

Questions? Mike Ault [email_address]

Using AWR for SQL Analysis

Recommended

More Related Content

What's hot (20)

Viewers also liked (20)

Similar to Using AWR for SQL Analysis (20)

Using AWR for SQL Analysis