trusted online casino malaysia

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)’ »

Got a MAC

Well I guess I have officially  joined the cool crowd since I am now the proud poppa of a bouncing baby MAC.

 

 

The best things about it so far are:

  1. It runs windows so I still have a safety net if I get to feeling totally lost. I’m using VMWare which allows me to jump back and forth.
  2. It runs some flavor of unix as it’s operating system. (so I can run top, ps, sar, etc… – it’ BSD but it beats the crap out of DOS)
  3. It’s about a million pounds lighter and half the size of my old Sony laptop.
  4. It’s faster than my old laptop.
  5. At 4G, it’s got 4 times the memory my old laptop had.
  6. The video iChat thing is pretty cool.
  7. It’s the worlds biggest iPod.

It is pretty cool but I just hate the process of going from one machine to another. Even without the frustration of the keyboard changes that the Mac inflicts, changing just makes for some amount of unproductive time. I have to do a presentation next week in Fort Worth at an Oracle Technology Luncheon thing (here’s a link to the presentation: 11g Advanced Features) So anyway, I am working on the Power Point slides using the MAC and it makes me feel like I’m typing with mittens on. I’m sure that will get better over time. I am finding that there are a lot of options with this setup though. Almost everything I am doing can be done in more than one way. Like I can do my calendar stuff in MS Office or in iCal (or on my phone for that matter).  

 

 

I have to admit that old laptop was starting to have a lot of problems. Wireless was flakey, it would freeze every other day or so, and last week the keyboard quit working. Kind of reminded me of the PC/MAC commercial where the PC was sick.

Anyway, so far so good. Now if I can just figure out how to make the F11 key work in windows instead of turning on the speaker I should be in good shape.

Flush A Single SQL Statement

In 11g, the DBMS_SHARED_POOL package has a couple of new procedures. One of them is the PURGE procedure which allows individual objects to be flushed from the shared pool. The create statement for this package can be found in the $ORACLE_HOME/rdbms/admin/dbmspool.sql script. I first ran across this about a year ago on Fairlie Rego’s Blog. The modification history shows that the PURGE procedure was written back in Aug, 2006 – so it’s been around for a while. The PURGE procedure can be used to dump objects from the shared pool including code (procedure/package/function), sequences, type definitions, triggers, and cursors (i.e. SQL statments). The ability to flush a single SQL statement is what caught my eye. Unfortunately, the option to purge cursors is not in the 11.1 documentation but it is documented (lightly) in the header of the package definition as you can see here.

Continue reading ‘Flush A Single SQL Statement’ »

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.

My First Blog

Kerry Osborne

Kerry Osborne

 

So I decided to finally join the 21st century. For the past several years I haven’t listened to any music to speak of. The radio went fuzzy in my car about three years ago and since I have a high tolerance for pain and was basically always busy doing things that were more important to me, I never got it fixed. Also, I moved a couple of years ago and still haven’t hooked up any sort of stereo at the new house. So this year I got a new car with a working radio. It’s one of those Toyota FJ cruisers that look like the old Land Cruisers.

 

 

Toyota FJ Cruiser

It was a demo unit that the dealership had put a fancy radio / GPS system in. I really only bought it for the radio. It was pretty expensive for a radio, but it has a nice blue paint job and doesn’t take up any space in the new house. But I digress, the fancy unit in the dash has AM/FM and satellite (XM) radio, a cd player, a DVD player, blue tooth phone integration, traffic information, and a griddle for making french toast while you’re driving. You know, basically everything the 21st century has to offer. It even has a hard disk recorder that can automatically record CD’s while you’re playing them so you can play the songs later in case you loose the CD I guess. Oh, and the ability to load up your own image files to display when you reach a favorite location (remember the GPS) or just for a pretty background while listening to the radio. The best part about it is the XM radio though. Of course I can’t hear it if I go in a parking garage or if it gets really cloudy, because it looses reception, but other than that it’s great. No commercials, except for XM’s own plugs for themselves, but that’s to be expected. No harm in a little self-promotion I guess. Although, you’d think the people hearing the ads would already be subscribers.

Anyway, after a few years of not listening to any music I found out that I really like listening to the stuff on the way to and from work. For several weeks I’d come busting into the office and grab the first person I’d see and tell them about the cool music I heard on the way to work. Usually they would take the ear buds out of their ears and then give me that look like I was from another planet. I imagine it’s the look Rip Van Winkle got after his 20 year nap. After a while I stopped telling people about it and just kept the joy to myself.

Here’s a picture of one of my co-workers who’s pissed because he had to take his ear buds out to listen to me drone on about music.

 

While I was at it I decided to buy an ipod. Wow! It’s a lot better than the Walkman I had back in the 80’s! My new car stereo let me hook it up so I could control it and play it through the system. So I basically keep it in the glove box all the time. I mostly listen to it when I’m in a garage, or it’s really cloudy, or when I can’t find anything good on the 170 or so stations provided by the satellite radio guys. Or when I just have a particular song or artist I want to listen to, but that doesn’t happen that often.

 

Anyway, now that I have joined the 21st century from a music stand point, I decided that maybe I should check out this blog thing. At first I didn’t see much that interested me, but lately I have started to see some value in it. I plan on mainly using it for work related stuff. I work for a small consulting company that focuses on Oracle databases (Enkitec) and I am fortunate to get to work on interesting things (for me anyway) on a fairly regular basis. I’m hoping this blog will provide a convenient way to share some of the stuff that I’ve learned and get some feedback as well. So, here’s to the 21st century.