In early January I wrote that I’m gonna start organizing the more serious and practical Oracle content into my new website and I’ll leave my blog for Oracle hacks, my (IT) observations and philosophy, general thoughts and just fun.

It’s time to publish the newsite now with an application demo rototype which gives some clue of what kind of features will there be in the secret project I’ve been working on for several months with my friend and business partner.

The website is located here:

http://tech.e2sn.com

E2SN does have a meaning, but I’ll leave it a secret for now ( you are free to guess ;-)

So, there’s not much technical content at the site yet, but there’s a cool online app which you should check if you deal with SQL tuning and execution plan analysis much.

It’s called PlanViz, Oracle Execution Plan Visualization app, you can check it out here:

http://tech.e2sn.com/apps/planviz

Oh, I’ve also created something called a “Living Book” into my website, where I will write about Oracle, performance, troubleshooting, etc. There is also a place where people can request what I should write about there!

And that’s all for today!

Tanel Poder Administration, Cool stuff, Internals, Oracle, Performance, Productivity, SQL, Tools

What you see below is a common problem. Someone sends you (or posts to a forum) a wide execution plan, which is unreadable because of wrapped lines. For example, this one below:

--------------------------------------------------------------------------------
-------------------

| Id  | Operation                   | Name                    | E-Rows |  OMem |
 1Mem | Used-Mem |

--------------------------------------------------------------------------------
-------------------

|   0 | SELECT STATEMENT            |                         |        |       |
 |          |

|   1 |  SORT AGGREGATE             |                         |      1 |       |
 |          |

|*  2 |   HASH JOIN                 |                         |     13 |  1102K|
 1102K|  355K (0)|

|*  3 |    HASH JOIN                |                         |     13 |   988K|
 988K|  367K (0)|

|*  4 |     HASH JOIN               |                         |     13 |   921K|
 921K|  621K (0)|

|*  5 |      HASH JOIN OUTER        |                         |     13 |   836K|
 836K| 1224K (0)|

|*  6 |       HASH JOIN             |                         |     13 |   821K|
 821K|  501K (0)|

|*  7 |        HASH JOIN            |                         |     13 |  1102K|
 1102K|  501K (0)|

|   8 |         MERGE JOIN CARTESIAN|                         |      1 |       |
 |          |

|*  9 |          TABLE ACCESS FULL  | PROFILE$                |      1 |       |
 |          |

|  10 |          BUFFER SORT        |                         |      1 | 73728 |
 73728 |          |

|* 11 |           TABLE ACCESS FULL | PROFILE$                |      1 |       |
 |          |

|* 12 |         TABLE ACCESS FULL   | USER$                   |     36 |       |
 |          |

|  13 |        TABLE ACCESS FULL    | PROFNAME$               |      1 |       |
 |          |

|* 14 |       TABLE ACCESS FULL     | RESOURCE_GROUP_MAPPING$ |      1 |       |
 |          |

|  15 |      TABLE ACCESS FULL      | TS$                     |      7 |       |
 |          |

|  16 |     TABLE ACCESS FULL       | TS$                     |      7 |       |
 |          |

|  17 |    TABLE ACCESS FULL        | USER_ASTATUS_MAP        |      9 |       |
 |          |

--------------------------------------------------------------------------------
-------------------

So now you either try to manually edit and fix the execution plan text so you could read it or ask the developer to send the execution plan again. Both approaches take time.

Well, sometimes things are easy – in this particular case I saved the above into a file called /tmp/x and ran the following command:

$ cat /tmp/x | awk '{ printf "%s", $0 ; if (NR % 3 == 0) print } END { print }'
---------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name                    | E-Rows |  OMem | 1Mem | Used-Mem |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |                         |        |       | |          |
|   1 |  SORT AGGREGATE             |                         |      1 |       | |          |
|*  2 |   HASH JOIN                 |                         |     13 |  1102K| 1102K|  355K (0)|
|*  3 |    HASH JOIN                |                         |     13 |   988K| 988K|  367K (0)|
|*  4 |     HASH JOIN               |                         |     13 |   921K| 921K|  621K (0)|
|*  5 |      HASH JOIN OUTER        |                         |     13 |   836K| 836K| 1224K (0)|
|*  6 |       HASH JOIN             |                         |     13 |   821K| 821K|  501K (0)|
|*  7 |        HASH JOIN            |                         |     13 |  1102K| 1102K|  501K (0)|
|   8 |         MERGE JOIN CARTESIAN|                         |      1 |       | |          |
|*  9 |          TABLE ACCESS FULL  | PROFILE$                |      1 |       | |          |
|  10 |          BUFFER SORT        |                         |      1 | 73728 | 73728 |          |
|* 11 |           TABLE ACCESS FULL | PROFILE$                |      1 |       | |          |
|* 12 |         TABLE ACCESS FULL   | USER$                   |     36 |       | |          |
|  13 |        TABLE ACCESS FULL    | PROFNAME$               |      1 |       | |          |
|* 14 |       TABLE ACCESS FULL     | RESOURCE_GROUP_MAPPING$ |      1 |       | |          |
|  15 |      TABLE ACCESS FULL      | TS$                     |      7 |       | |          |
|  16 |     TABLE ACCESS FULL       | TS$                     |      7 |       | |          |
|  17 |    TABLE ACCESS FULL        | USER_ASTATUS_MAP        |      9 |       | |          |
---------------------------------------------------------------------------------------------------

All I did here was that I stripped out line feeds from all lines except every 3rd line (which is the real end of the original line).

Note that if your linesize is very wide (and trimspool/trimout settings are ON) then this script would need some adjustment…

I’m sure this trivial approach doesn’t work in all situations, but with this article I wanted to illustrate that sometimes things which seem hard can be made much easier with a little scripting knowledge. If you are thinking which technology you should learn next – then better check out a Perl, Python or some shell+AWK book :)

By the way, if you want real flexibility displaying your execution plans (from library cache), then check this out:

http://blog.tanelpoder.com/2009/05/26/scripts-for-showing-execution-plans-via-plain-sql-and-also-in-oracle-9i/

Tanel Poder Administration, Oracle, Productivity, Tools, Unix/Linux

Tanel Poder Cool stuff, Internals, Oracle, Performance, Tools, Troubleshooting

I have added a links section into my blog where I put links to useful external documents and tools what I often refer to during my seminars and consulting.

I will make additions to that page over time…

To see the list, you can click on the “Seminar Links” in top right section of the blog page or just click here:

http://blog.tanelpoder.com/seminar/seminar-links/

Tanel Poder Administration, Oracle, Performance, Tools, Training, Troubleshooting

Hi all,

Here are few scripts which allow you to query SQL execution plans and their execution statistics out from V$SQL_PLAN and V$SQL_PLAN_STATISTICS yourself.

Why would you want to do this as there’s the DBMS_XPLAN.DISPLAY_CURSOR() function in Oracle 10g?

Well, my scripts work also on Oracle 9.2. Also they give you better detail (and flexibility) compared to DBMS_XPLAN.DISPLAY_CURSOR.

Of course in 9i there’s the DBMS_XPLAN.DISPLAY function which you can use in conjuction with EXPLAIN PLAN FOR command, but that approach has problems. EXPLAIN PLAN treats all bind variables as varchar2 datatype, possibly causing the reported execution plan to be different from reality. Also, if you have a long running report from last night and you run explain plan today morning, then if optimizer statistics have changed meanwhile, the explain plan command might come up with a different execution plan again, which is different from reality.

So that’s why in 10g we have the DBMS_XPLAN.DISPLAY_CURSOR which goes directly to required library cache child cursor and extracts (unparses) the execution plan from there. The function uses V$SQL_PLAN% views as its data source. And guess what – these views are there in version 9.2 already! And thats’ where my scripts come in:

Here’s an example. Let’s set statistics_level=all so we get rowsource level execution stats for the cursor (note that this parameter makes your query consume much more CPU so it should only be used at session level for troubleshooting a specific performance issue):

SQL> alter session set statistics_level = all;

Session altered.

SQL> select count(*) from all_users;

  COUNT(*)
----------
        36

I know the hash value of this query, so lets report its execution plan, directly from library cache. This is the REAL execution plan inside that child cursor, not some estimate like EXPLAIN PLAN command gives:

Read more…

Tanel Poder Oracle, Performance, SQL, Tools, Troubleshooting

Riyaj Shamsudeen wrote an excellent article about systematic latch contention troubleshooting.

Especially if the latch contention problem is ongoing, looking into system wide stats (like v$latch.sleep columns) is not the best idea in busy systems. This may sometimes lead you to fixing the wrong problem.

This is because sometimes the latch contention is not caused by some system wide inefficiency but rather by one or few sessions.

The right approach would be to measure the following things:

1. Which latch (and exact child latches) the problem session is waiting for (query v$session_wait, ASH, sql_trace)
2. Why is the problem session trying to get that latch so often (query v$sesstat counters for problem session and check execution plan if only single/few statements executed)
3. Why this latch is busy: who’s holding it (query v$latchholder, LatchProf)
4. Why is that someone holding the latch so much (query v$sesstat counters for that session or run LatchProfX)

Riyaj used this approach and successfully found out the troublemaker causing heavy library cache latch contention. He used my LatchProfX tool for part of the diagnosis (and I’m very happy to see that my advanced oracle troubleshooting tools find real world use in hands of other troubleshooters/tuners too!).

Here’s an excerpt from latchprofx output (from a little test case I put together), showing which session is holding which library cache latch how much, hold mode (shared/exclusive) and also the actual reason (function name) why the latch is held:

SQL> @latchprofx sid,name,laddr,ksllwnam,ksllwlbl,hmode 159 % 100000

-- LatchProfX 1.08 by Tanel Poder ( http://www.tanelpoder.com )

 SID NAME           LADDR            KSLLWNAM  KSLLWLBL  HMODE        Held  Gets  Held %  Held ms Avg hold ms
---- -------------- ---------------- --------- --------- ---------- ------ ----- ------- -------- -----------
 159 library cache  00000003A93513E0 kglic     child     exclusive   10044  9314   10.04  301.320        .032
 159 library cache  00000003A9351340 kglic     child     exclusive    9895  8458    9.90  296.850        .035
 159 library cache  00000003A9351660 kglic     child     exclusive    9761  8440    9.76  292.830        .035
 159 library cache  00000003A9351700 kglic     child     exclusive    9737  8924    9.74  292.110        .033
 159 library cache  00000003A9351480 kglic     child     exclusive    8999  7765    9.00  269.970        .035
 159 library cache  00000003A93515C0 kglic     child     exclusive    8553  7832    8.55  256.590        .033
 159 library cache  00000003A9351520 kglic     child     exclusive    6852  6828    6.85  205.560        .030

7 rows selected.

kglic means Kernel Generic Library cache Iterate Chain (AFAIK), it’s the function which is executed when you access most X$KGL tables. And this is where Riyaj got the evidence that the latch contention comes from inefficient scanning of library cache, caused by a session running queries against V$SQL_PLAN views with a bad plan.

So, check out Riyaj’s articele, my LatchProfX script, my Latch & Mutex contention troubleshooting conference slides and if you want more, then my Advanced Oracle Troubleshooting Seminar. I recently added Dallas, Denver, Salt Lake City and Hong-Kong to the list of cities where you can attend it this year!

Tanel Poder Internals, Oracle, Performance, Tools, Troubleshooting

Conferences & Slides

Here are the slides of my recent presentations at Hotsos Symposium and UTOUG events:

• Advanced Oracle Troubleshooting (and scripts I’ve used)
  
• Latch, Lock and Mutex Contention Troubleshooting
• Oracle SQL Plan Execution: How It Really Works

Advanced Oracle Troubleshooting Seminar

I have added Dallas, Salt Lake City, Denver and Hong-Kong to my Advanced Oracle Troubleshooting seminar list for first half of 2009, the full list is below. Check http://blog.tanelpoder.com/seminar/ for outline, scripts, example slides and details.

Seminar dates and locations 2009:

2-3. April – Miracle @ Utrecht, Netherlands – http://www.miraclebenelux.nl/tanel/

13-14. April – Oracle @ Singapore – http://www.oracle.com/education/apac/sg_tanel_poder.html

16-17. April – Oracle @ Sydney – http://www.oracle.com/education/apac/au_tanel_poder.html

20-21. April – Oracle @ Melbourne – http://www.oracle.com/education/apac/au_tanel_poder.html

23-24. April Oracle @ Hong-Kong – http://www.oracle.com/education/apac/hk_tanel_poder.html

27.-28. April – PiSec Ltd @ Edinburgh – http://www.pisec.org/index.php?option=com_content&view=article&id=6&Itemid=12

11-12. May – Oracle @ Spain – http://education.oracle.com/pls/web_prod-plq-dad/show_desc.redirect?dc=D70365_1060245&p_org_id=51&lang=E&source_call=

18-19. May – Miracle @ Denmark – http://www.miracleas.dk/index.php?option=com_content&view=article&id=100:advanced-oracle-troubleshooting&catid=19:info&Itemid=71

3.-5. June – Method-R @ Dallas, TX – http://www.method-r.com

10-12. June – Trutek @ Salt Lake City, UT – http://www.trutek.com/index.php?id=165

15-17. June – Trutek @ Denver, CO – http://www.trutek.com/index.php?id=165

Tanel Poder Cool stuff, Internals, Oracle, Oracle 11g, Performance, Tools, Troubleshooting

I have slowly moved towards performance visualization and system capacity planning world. Or at least this is my main focus (in addition to deep Oracle internals of course ;)

I’ve published an easy Oracle performance visualization tool, which is based on Excel and can visualize the resultset of any SQL query. It’s called PerfSheet (and I’ve blogged about it here).

Last December I spoke at CMG Conference in Las Vegas about a new method for visualizing database-wide performance while still being able to see session level performance profile. Having session level performance overview is important when diagnosing performance problems which only some users of the whole system are experiencing.

The paper I was talking about is accessible from here: http://arxiv.org/pdf/0809.2532

We wrote it together with Dr. Neil Gunther, the theoretical part was his idea and I helped to apply it in Oracle.

Neil received the prestigious A.A. Michelson’s award during that CMG event, so I was pretty honoured to even be at the same stage with him :)

I will be presenting some further peformance visualization and capacity planning related work during my “No slides” session at Hotsos Symposium this year. I’m excited as I will be showing some really cool (and useful!) things there ;)

Tanel Poder Cool stuff, Oracle, Performance, Tools

I have created a page where I have links to few slides, my scripts and also my Advanced Oracle Troubleshooting seminar logs (the sqlplus and shell commands I’ve executed and their output with some comments).

To get to that page you need to click on the “Seminar Files” link in the upper right corner of the browser window.

Or you can go directly here: http://blog.tanelpoder.com/seminar/seminar-files/

The slides I showed at RMOUG conference this week are here: http://www.tanelpoder.com/files/Advanced_Oracle_Troubleshooting.pdf. Both Advanced Oracle troubleshooting and SQL execution plan session slides are inside that file.

Tanel Poder Oracle, Performance, Tools, Training, Troubleshooting

I frequently get a question about how to find out when was a table last modified. I’m talking about table data, not table structure, the latter would be detectable from dba_objects.last_ddl_time.

Unless you have some table level DML auditing already turned on, then as one option you could use LogMiner and “just” work through the redo/archivelogs in the range of interest with it. This could be very time consuming (especially if the last change was done a while back), so here’s another option for getting last table modification info very easily, however it comes with some restrictions.

http://www.tanelpoder.com/files/scripts/lastchanged.sql

(read instructions and limitations from the script header).

The idea is following:

1. Oracle has an ORA_ROWSCN pseudocolumn which reports the last known change time for a row in a table. The “time” shows a commit SCN number of last transaction modifying the row, not a real timestamp though. It is important to note that unless the ROWDEPENDECIES are enabled, then the last SCN is known only at data block level, not row level, rowscn’s for all rows in a block would report whatever SCN is in the last change SCN in block header.
2. SCN is ever-increasing internal “time” used by Oracle recovery and transaction layers and it is possible to map this to real time with reasonable accuracy using few Oracle’s tables which store SCN to wallclock time mappings. My script reports the time range in which the last change to datablock/row occurred so you’ll know how accurate it is.
   I use sys.smon_scn_time and v$log_history views for SCN to real time mapping. So my script reports two times, first one may be more accurate, second one has longer history on the other hand.You can use whatever other datasource for doing this mapping, as long as it has SCNs and corresponding timestamps in it. For example, if you have log_checkpoints_to_alert parameter set to true, you can grep the SCN/timestamp pairs out with command like this:

   cat alert_win10g.log | egrep -e "^Beginning.*checkpoint|[[:alpha:]]{3} [[:alpha:]]{3} [[:digit:]]{2} "
   
   

Here are few usage examples.

First I’ll check some data which was probably last changed a long time ago:

SQL> @lastchanged sys.obj$ name='DBMS_STANDARD'

-- LastChanged.sql v1.0 by Tanel Poder ( http://www.tanelpoder.com )

Running this query:

.   select MAX(ora_rowscn)
.   from sys.obj$
.   where name='DBMS_STANDARD';

DATA_SOURCE       LAST_CHANGED
----------------- -------------------------------------------------------
sys.smon_scn_time Before  2008-12-31 16:05:25 (earlier than 21 days ago)
v$log_history     Before  2008-10-27 03:58:16 (earlier than 86 days ago)

2 rows analyzed.

As both sys.smon_scn_time and v$log_history don’t have records dating back to that old time when the database was created (when DBMS_STANDARD and other object records in that datablock were created), they just show that the change happened before the oldest SCN to time mapping they have.

Here’s a check on a regular table, but we are only interested in rows/datablocks where the “sal” column is bigger than 1000:

Read more…

Tanel Poder Administration, Oracle, Tools, Troubleshooting