trusted online casino malaysia

Archive for the ‘Tuning’ Category.

Explain Plan Lies

The Oracle Explain Plan command is widely used to evaluate the plan that the Oracle optimizer will choose for a given SQL statement. Unfortunately, it doesn’t always tell the truth. This is due to the fact that the Explain Plan statement does not go through the same code path that the optimizer uses when determining a plan for execution. One of the simplest examples of this behavior is the case where bind variables are used in a statement. Explain plan ignores them while the optimizer uses them to determine the plan. Here’s an example.

SQL> @test_bind
SQL> var how_many number
SQL> accept col1 -
>        prompt 'Enter value for col1: '
SQL>
SQL> DECLARE
2  x number;
3  BEGIN
4
5  :how_many := 0;
6  x := &col1;
7
8  select avg(pk_col) into :how_many
9  from kso.skew
10  where col1 = x;
11
12  dbms_output.put_line(trunc(:how_many)||' records.');
13
14  END;
15  /
16487500 records.

PL/SQL procedure successfully completed.

SQL>
SQL> undef col1
SQL> undef how_many
SQL>
SQL> @find_sql
Enter value for sql_text: select avg(pk_col) from kso.skew where col1 =%
Enter value for sql_id:

SQL_ID         CHILD  PLAN_HASH      EXECS     AVG_ETIME      AVG_LIO SQL_TEXT
------------- ------ ---------- ---------- ------------- ------------ -----------------------------------------
7rf1jw8jsw0v7      0  568322376          1         48.32      173,734 SELECT AVG(PK_COL) FROM KSO.SKEW WHERE COL1 = :B1

SQL> -- Only 1 plan for this statement
SQL>
SQL>@dplan
Enter value for sql_id: 7rf1jw8jsw0v7
Enter value for child_no: 0

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  7rf1jw8jsw0v7, child number 0
-------------------------------------
SELECT AVG(PK_COL) FROM KSO.SKEW WHERE COL1 = :B1

Plan hash value: 568322376

---------------------------------------------------------------------------
| Id  | Operation          | Name | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      |       |       | 31720 (100)|          |
|   1 |  SORT AGGREGATE    |      |     1 |    11 |            |          |
|*  2 |   TABLE ACCESS FULL| SKEW |  3150K|    33M| 31720  (37)| 00:00:43 |
---------------------------------------------------------------------------

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

2 - filter("COL1"=:B1)

19 rows selected.

SQL> -- It did a full table scan expecting 3M rows
SQL>-- Now lets see what Explain Plan thinks it should have done
SQL>
SQL> explain plan for select avg(pk_col) from kso.skew where col1 = :b1;

Explained.

SQL> @xplan

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 3723858078

------------------------------------------------------------------------------------------
| Id  | Operation                    | Name      | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |           |     1 |    11 |    53   (2)| 00:00:01 |
|   1 |  SORT AGGREGATE              |           |     1 |    11 |            |          |
|   2 |   TABLE ACCESS BY INDEX ROWID| SKEW      |    53 |   583 |    53   (2)| 00:00:01 |
|*  3 |    INDEX RANGE SCAN          | SKEW_COL1 |    54 |       |     3   (0)| 00:00:01 |
------------------------------------------------------------------------------------------

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

1 - SEL$1
2 - SEL$1 / SKEW@SEL$1
3 - SEL$1 / SKEW@SEL$1

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

3 - access("COL1"=TO_NUMBER(:B1))

Column Projection Information (identified by operation id):
-----------------------------------------------------------

1 - (#keys=0) AVG("PK_COL")[22]
2 - "PK_COL"[NUMBER,22]
3 - "SKEW".ROWID[ROWID,10]

29 rows selected.

SQL> -- It thinks it will use an index (and that it will get only 54 rows - even though the histogram knows better
SQL>
SQL> select count(*) from kso.skew where col1=1;

COUNT(*)
----------
3199971

10g has a very nice utility (DBMS_XPLAN) to display plans from various locations (AWR, V$SQL_PLAN and Plan Tables). It has been expanded in 11g to work with Plan Baselines as well. So stop using Explain Plan and start looking at the real plan that the optimizer comes up with.

  • Just execute the statement (it’s Ok to hit control-C if it’s a long running statement, it will still be in the shared pool)
  • Find the SQL ID for the statement (I use find_sql.sql for this step)
  • Then use dbms_xplan.display_cursor to see the plan (I use dplan.sql for this this step).

There is are a couple of great posts by Rob Van Wijk and Jonathan Lewis on DBMS_XPLAN.DISPLAY_CURSOR on their blogs. Also the Oracle Optimizer Development Group Blog has a good post on the subject which includes 11g options.

Unstable Plans (Oracle Plan Stability/Instability)

One of the most frustrating things about the Cost Based Optimizer in Oracle is the sometimes erratic performance. It can seem almost random at times. Resolving these issues can also be challenging. It’s a little like taking your car to the mechanic when it makes a funny noise. It never seems to make the noise when the mechanic is there. Fortunately we have ASH/AWR which captures a ton of information about what our databases are doing.

Here’s a couple of scripts that I find useful.

The first one can be used to show statements that have experienced significant variances in execution time (it can be modified to look for variances in the amount of logical i/o, but I’ll leave it as an exercise for the reader).  I called the script unstable_plans.sql. It uses an analytic function to calculate a standard deviation on the average elapsed time by plan. So the statements that have multiple plans with wild variations in the response time between plans will be returned by the script. The script prompts for a couple of values. The first is minimum number of standard deviations. The second is the minimum elapsed time (I usually don’t care if a statement executes sometimes in .005 seconds and sometimes in .02 seconds, even though this is a large swing statistically). Both these inputs are defaulted by the way.

Continue reading ‘Unstable Plans (Oracle Plan Stability/Instability)’ »

SQL Tuning Advisor

I recently had a very positive experience with Oracle’s SQL Tuning Advisor. I was asked to assist with a 10gR2 RAC database that was performing badly. The database was spending a lot of time waiting on gc buffer busy waits and was doing a lot of physical i/o. These however turned out to be red herrings. A quick check showed transfer times on the inter-connect were not an issue. The disk access times were also not out of line. The real problem was that a handful of statements were doing an excessive amount of logical i/o.  We were able to identify the point in time when the performance issue began so we had a look at the AWR tables to see if there had been any plan changes for the “bad” statements around that time. Here is a snippet from the log showing changes in the plan_hash_value for one of the statements which produced substantially worse results than the previous plan(s).

SQL> @awr_plan_change
Enter value for sql_id: 2mkw0zbja4t6g

   SNAP_ID BEGIN_INTERVAL_TIME            SQL_ID        PLAN_HASH_VALUE        ETIME          LIO
---------- ------------------------------ ------------- --------------- ------------ ------------
     35519 18-JUL-08 09.00.35.521 AM      2mkw0zbja4t6g      3485252631        .0288        748.4
     35519 18-JUL-08 08.59.49.706 AM      2mkw0zbja4t6g                        .0288        748.4
     35519 18-JUL-08 09.00.35.521 AM      2mkw0zbja4t6g      4125764560       6.8601     86,933.8
     35519 18-JUL-08 08.59.49.706 AM      2mkw0zbja4t6g                       3.3464     66,720.2
     35519 18-JUL-08 09.00.35.521 AM      2mkw0zbja4t6g       593567772        .1594      8,232.7
     35519 18-JUL-08 08.59.49.706 AM      2mkw0zbja4t6g                        .1594      8,232.7
     35519 18-JUL-08 09.00.35.521 AM      2mkw0zbja4t6g      4125764560       3.3464     66,720.2
     35519 18-JUL-08 08.59.49.706 AM      2mkw0zbja4t6g                       6.8601     86,933.8
     35538 18-JUL-08 06.29.58.999 PM      2mkw0zbja4t6g       593567772        .0420      8,012.1
     35538 18-JUL-08 06.30.44.800 PM      2mkw0zbja4t6g                        .0420      8,012.1
     35539 18-JUL-08 07.00.05.767 PM      2mkw0zbja4t6g                        .0426      8,016.7
     35539 18-JUL-08 07.00.51.579 PM      2mkw0zbja4t6g                        .0426      8,016.7
     35540 18-JUL-08 07.30.12.654 PM      2mkw0zbja4t6g                        .0429      8,024.2
     35540 18-JUL-08 07.30.58.419 PM      2mkw0zbja4t6g                        .0429      8,024.2
     35545 18-JUL-08 10.00.32.175 PM      2mkw0zbja4t6g      3526031842      92.8685    203,058.3
     35545 18-JUL-08 09.59.46.365 PM      2mkw0zbja4t6g                      53.5655    136,190.0
     35545 18-JUL-08 10.00.32.175 PM      2mkw0zbja4t6g                      53.5655    136,190.0
     35545 18-JUL-08 09.59.46.365 PM      2mkw0zbja4t6g                      92.8685    203,058.3
     35546 18-JUL-08 10.30.39.168 PM      2mkw0zbja4t6g                     108.2104    220,259.1
     35546 18-JUL-08 10.29.53.369 PM      2mkw0zbja4t6g                     138.8346    217,732.0
     35546 18-JUL-08 10.30.39.168 PM      2mkw0zbja4t6g                     138.8346    217,732.0
     35546 18-JUL-08 10.29.53.369 PM      2mkw0zbja4t6g                     108.2104    220,259.1
     35547 18-JUL-08 11.00.00.396 PM      2mkw0zbja4t6g                     121.4556    217,735.0
     35547 18-JUL-08 11.00.46.148 PM      2mkw0zbja4t6g                     121.4556    217,735.0
     35548 18-JUL-08 11.30.04.018 PM      2mkw0zbja4t6g                     108.4236    217,739.0
     35548 18-JUL-08 11.30.50.076 PM      2mkw0zbja4t6g                     108.4236    217,739.0
     35557 19-JUL-08 04.00.10.812 AM      2mkw0zbja4t6g                     115.0718    217,731.0
     35557 19-JUL-08 04.00.56.631 AM      2mkw0zbja4t6g                     115.0718    217,731.0
     35558 19-JUL-08 04.29.17.277 AM      2mkw0zbja4t6g                     127.8277    217,731.0
     35558 19-JUL-08 04.30.03.100 AM      2mkw0zbja4t6g                     127.8277    217,731.0
     35559 19-JUL-08 04.59.24.163 AM      2mkw0zbja4t6g                     112.7978    198,768.6
     35559 19-JUL-08 05.00.09.945 AM      2mkw0zbja4t6g                     112.7978    198,768.6
     35560 19-JUL-08 05.29.31.269 AM      2mkw0zbja4t6g                     107.6025    193,642.2
     35560 19-JUL-08 05.30.17.076 AM      2mkw0zbja4t6g                     107.6025    193,642.2
     35561 19-JUL-08 06.00.24.094 AM      2mkw0zbja4t6g                     184.9285    217,598.2
     35561 19-JUL-08 05.59.38.289 AM      2mkw0zbja4t6g                     145.1714    204,952.2

The log showed a couple of things:

  1. The “bad” plan first showed up around 10:00 PM on July 18th (plan hash value 3526031842).
  2. The “bad” plan did orders of magnitude more logical i/o than the previous plans.
  3. The plan for this statement had been experiencing instability even prior to the problem (this was due to bind variable peeking).

Since this was a production system, the goal was to return to the original performance as quickly as possible. The major difference between the two plans was that the “bad” plan had a full table scan on a 14M row table while the good plan used an index. My first thought was to force Oracle to use the plan I wanted via hints as the problem was severely impacting the users and it was a relatively simple query. Also, the majority of the query was buried in a view so it would be a simple matter to modify the view without having to roll out any new code. While I started down that path, an enterprising member of the team (Rick Miners), created a SQL Tuning Set out of one of the queries and let Oracle recommend a “fix”. This was done with the DBMS_SQLTUNE package. The recommendation offered was to create a SQL Profile that resulted in the exact plan we wanted – it eliminated the full table scan in favor of the index just as the “good” plan had. We accepted the proposed SQL Profile and watched as the long running versions completed while the new executions picked up the new plan. The same process was repeated for several other troublesome queries – all with the same excellent results.

The success came as quite a shock to me as my previous experiences with this advisor had not been good. Specifically, I was involved in an incident where a DBA had implemented several recommendations which brought a production server to its knees. Note that OEM has an easy point and shoot interface to implement recommendations (often a SQL Profile) with the push of a button. Unfortunately it seems that the shooting sometimes occurs before the pointing. It’s easy to see how that can happen. Imagine yourself in a high pressure production support situation where you know a certain SQL statement is behaving really badly and you’re looking at an OEM screen that says – yeah that SQL statement is a problem and I know how to fix it. Not only that but here’s a bunch of technical sounding supporting data and a 6 digit estimate of the percentage improvement you’ll get if you just push this button. And there is the button … just begging to be clicked. And you think to yourself, “Well it can’t get much worse”, so you click the button.

At any rate, this most recent experience has made me completely rethink my position on Oracle’s Tuning Advisors. While they are certainly not perfect, I think that they can serve a purpose – an extra wrench in the old tool kit if you will.

The easiest/quickest way to use this advisor is of course with OEM/Grid control. However, I don’t always have access to that tool. Also, since I am a performance addict, I don’t really want to be tempted to click the button without doing my homework first. So here are the basic steps to do it from the command line (i.e. sqlplus):

  1. Create a tuning task
    • Creating a task for a single sql statement makes the most sense to me.
    • There are actually 3 parts to this – creating the tuning task, executing it, and then reporting on it
      • DBMS_SQLTUNE.CREATE_TUNING_TASK
      • DBMS_SQLTUNE.EXECUTE_TUNING_TASK
      • DBMS_SQLTUNE.REPORT_TUNING_TASK
    • See create_tuning_task.sql
    • Note the default time limit for the execute part is 30 minutes so you may want to reduce that (the create_tuning_task script prompts you for a value in seconds). By the way, the reason it can take so long is that the advisor can actually execute parts of the statement to get better estimates of the number of rows returned by a particular step.
    • Primary recommendations are often to accept a SQL Profile but there may be other recommendations such as creating indexes, etc..
    • The report output shows the old plan and the proposed new plan.
  2. Review recommendations
    • Never, ever, ever (I really mean it) blindly accept a recommendation – Duh!
    • Look at the new plan as proposed by REPORT_TUNING_TASK
    • Specifically – evaluate the proposed plan and if possible and time permits, test it
  3. Prepare a script to disable the SQL Profile that will be created.
    • You do have a back out plan right?
    • It is very easy to disable a profile, however once a plan is selected it will not be changed. That execution will continue to use that plan until it finishes, or hell freezes over, which ever happens first.
    • See disable_sql_profile.sql
  4. Accept the SQL Profile
  5. Confirm the performance improvement
    • Existing active cursors will continue processing
    • A new child will be created using the profile and subsequent executions will use it
    • You can compare the performance of the old plan and the new
    • See find_sql.sql, find_sql_stats.sql, dplan.sql
  6. Consider creating an Outline for the statement
    • SQL Profiles do not lock the execution plan
    • Outlines do lock the plan
    • You can create an outline on a plan that is using a profile
    • You should disable the profile after enabling the outline
    • See create_outline.sql
  7. Figure out why the plan went crazy in the first place

Jonathan Lewis has a couple of notes about SQL Profiles on his site here SQL Profiles (10g) and here SQL Profiles – 2 that are worth a look. I totally agree with his advice to make sure you know what the profile is going to do before implementing it. You can do this by looking at the proposed plan and the hints to be applied to get there (see tuning_task_hints.sql or sql_profile_hints.sql). Also be aware that profiles will tend to sour on you over time. As things change, the estimates that the CBO comes up with for particular operations can and will change. One of the main techniques used by profiles is to modify cardinality estimates of operations by applying a scaling factor. Once the factor is defined it remains fixed, however, the CBO’s estimate may change for many reasons – new stats, histograms, etc… Therefore, I don’t believe that profiles are a good choice as a long term solution.