Search

Top 60 Oracle Blogs

Recent comments

February 2011

Most Expensive SQL Statement Ever

You know the cost calculation that the cost based optimizer (CBO) uses to determine which execution plan to choose for a SQL statement, right? If you don’t, you should immediately stop reading this and pick up a good novel instead. Ah, you’re still here? Well I got an interesting email today from one of my co-workers saying he had to kill a query yesterday. Actually that’s a big part of his current job. Killing runaway queries – apparently that job takes most of his time between 8 and 5. Anyway, he sent me this execution plan today, no comments, “just have a look at this”, he said.

---------------------------------------------------------------------------------------------------
| Id  | Operation              | Name             | Rows  | Bytes|TempSpc| Cost (%CPU)| Time     |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT       |                  |       |       |      |    65P(100)|          |
|   1 |  SORT ORDER BY         |                  |    18E|    15E|   15E|    65P (78)|999:59:59 |
|   2 |   COUNT                |                  |       |       |      |            |          |
|*  3 |    FILTER              |                  |       |       |      |            |          |
|   4 |     NESTED LOOPS       |                  |    18E|    15E|      |    14P  (3)|999:59:59 |
|   5 |      NESTED LOOPS      |                  |   984G|   216T|      |    14G  (3)|999:59:59 |
|   6 |       TABLE ACCESS FULL| CAT_6000_6001TBL |  7270K|  1074M|      |   176K  (3)| 00:15:46 |
|   7 |       TABLE ACCESS FULL| CAT_6000TBL      |   135K|    11M|      |  1950   (3)| 00:00:11 |
|   8 |      INDEX FULL SCAN   | PK_OBJECTS       |    32M|   306M|      | 15207   (3)| 00:01:22 |
---------------------------------------------------------------------------------------------------

So I had a look. Yes – that’s a 65P in the cost column. I’ve seen worse (but not in a production system). Cost is not always a good indication of run time, by the way. It’s just a sort of normalized estimation after all. But the estimate for the number of rows and bytes (18E and 15E) are very impressive as well. This query ran for several hours before my buddy finally killed it. As you might expect, the query was missing a join condition between a couple of large tables (7M and 32M).

Here’s a test I worked up to see how big a number I could get.

SYS@LAB1024> !cat dplan.sql
set lines 150
select * from table(dbms_xplan.display_cursor('&sql_id','&child_no','typical'))
/
 
SYS@LAB1024> @dplan
Enter value for sql_id: gf5nnx0pyfqq2
Enter value for child_no: 
 
PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  gf5nnx0pyfqq2, child number 0
-------------------------------------
select a.col2, sum(a.col1) from kso.skew a, kso.skew b group by a.col2
 
Plan hash value: 321450672
 
-----------------------------------------------------------------------------------
| Id  | Operation               | Name    | Rows  | Bytes | Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------
|   0 | SELECT STATEMENT        |         |       |       |   689G(100)|          |
|   1 |  HASH GROUP BY          |         |     1 |    16 |   689G (84)|999:59:59 |
|   2 |   MERGE JOIN CARTESIAN  |         |  1024T|    14P|   145G (22)|999:59:59 |
|   3 |    TABLE ACCESS FULL    | SKEW    |    32M|   488M| 10032  (18)| 00:01:21 |
|   4 |    BUFFER SORT          |         |    32M|       |   689G (84)|999:59:59 |
|   5 |     INDEX FAST FULL SCAN| SKEW_PK |    32M|       |  4558  (22)| 00:00:37 |
-----------------------------------------------------------------------------------
 
 
17 rows selected.
 
SYS@LAB1024> @dplan
Enter value for sql_id: 12p7fuydx3dd5
Enter value for child_no: 
 
PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  12p7fuydx3dd5, child number 0
-------------------------------------
select a.col2, sum(a.col1) from kso.skew a, kso.skew b, kso.skew c group by
a.col2
 
Plan hash value: 175710540
 
------------------------------------------------------------------------------------
| Id  | Operation                | Name    | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT         |         |       |       |    18E(100)|          |
|   1 |  HASH GROUP BY           |         |     1 |    16 |    18E (81)|999:59:59 |
|   2 |   MERGE JOIN CARTESIAN   |         |    18E|    15E|  4670P (22)|999:59:59 |
|   3 |    MERGE JOIN CARTESIAN  |         |  1024T|    14P|   145G (22)|999:59:59 |
|   4 |     TABLE ACCESS FULL    | SKEW    |    32M|   488M| 10032  (18)| 00:01:21 |
|   5 |     BUFFER SORT          |         |    32M|       |   145G (22)|999:59:59 |
|   6 |      INDEX FAST FULL SCAN| SKEW_PK |    32M|       |  4558  (22)| 00:00:37 |
|   7 |    BUFFER SORT           |         |    32M|       |    18E (81)|999:59:59 |
|   8 |     INDEX FAST FULL SCAN | SKEW_PK |    32M|       |  4558  (22)| 00:00:37 |
------------------------------------------------------------------------------------
 
 
21 rows selected.
 
SYS@LAB1024> @dplan
Enter value for sql_id: 7b53dxh6w6mpj
Enter value for child_no: 
 
PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  7b53dxh6w6mpj, child number 0
-------------------------------------
select a.col2, sum(a.col1) from kso.skew a, kso.skew b, kso.skew c, kso.skew
d group by a.col2
 
Plan hash value: 3965951819
 
-------------------------------------------------------------------------------------
| Id  | Operation                 | Name    | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT          |         |       |       |    18E(100)|          |
|   1 |  HASH GROUP BY            |         |     1 |    16 |    18E  (0)|999:59:59 |
|   2 |   MERGE JOIN CARTESIAN    |         |    18E|    15E|    18E  (0)|999:59:59 |
|   3 |    MERGE JOIN CARTESIAN   |         |    18E|    15E|  4670P (22)|999:59:59 |
|   4 |     MERGE JOIN CARTESIAN  |         |  1024T|    14P|   145G (22)|999:59:59 |
|   5 |      TABLE ACCESS FULL    | SKEW    |    32M|   488M| 10032  (18)| 00:01:21 |
|   6 |      BUFFER SORT          |         |    32M|       |   145G (22)|999:59:59 |
|   7 |       INDEX FAST FULL SCAN| SKEW_PK |    32M|       |  4558  (22)| 00:00:37 |
|   8 |     BUFFER SORT           |         |    32M|       |  4670P (22)|999:59:59 |
|   9 |      INDEX FAST FULL SCAN | SKEW_PK |    32M|       |  4558  (22)| 00:00:37 |
|  10 |    BUFFER SORT            |         |    32M|       |    18E  (0)|999:59:59 |
|  11 |     INDEX FAST FULL SCAN  | SKEW_PK |    32M|       |  4558  (22)| 00:00:37 |
-------------------------------------------------------------------------------------
 
 
24 rows selected.

So it looks like the cost tops out at 18E as does the estimated number of rows. Oddly the number of bytes appears to top out at 15E. So the production query had maxed out the rows and bytes estimate although the cost was significantly under the max. Still 65P is the biggest cost I’ve seen in a production system. Anyone seen a bigger one?

P.S. I have two categories for SQL related posts. “Developer Tricks” and “Wall of Shame”. This one gets both tags.

Hereafter…

I went to see Hereafter this evening. On the surface the subject matter sounded pretty grim, what with it being about death and the afterlife, but Clint Eastwood directed it, so I thought I’d give it a go.

The overriding thing I can say about the film is it was very gentle. If this were standard Hollywood crap there would have been X-Files type revelations or flash ghostly effects. As it was, there was none of that. It was just the characters and how death and the afterlife had affected their lives. Very understated and told at a gentle pace and in no way challenging. I want to say words like “nice” and “pleasant”, but they sound a bit insulting, but I don’t mean them to be.

If you like spooky psychic stuff this definitely is *n0t* the film for you.

Matt Damon and Bryce Dallas Howard worked really well together. She had quite a small part in the film, but her character was definitely the highlight for me. The other actors were a bit out of their league in comparison, except for the cameo of Derek Jacobi playing himself. If he had got that wrong it would have been a bit sad. :)

Cheers

Tim…

WordPress 3.0.5…

WordPress 3.0.5 has been released. Happy upgrading.

Cheers

Tim…

GTTs

That’s Global Temporary Table, of course.

A request appeared on the OTN database forum recently asking if it was possible to allocate a global temporary table to a particular temporary tablespace because the programmer didn’t want typical users to be at risk of running out of temporary space when a particular global temporary table suddenly got loaded with millions of rows.

If you’re running 11.1 or above, go straight to the footnote, otherwise read on.

At first sight the answer seems to be no – but an important point in the question was the comment: “I have a procedure which …”. This may make it possible to isolate this table in the required way.

When someone inserts data into a global temporary table the tablespace used to instantiate their version of the table is the temporary tablespace of the schema that is inserting the data. But remember, if you call a procedure to insert the data it’s (usually) the schema that owns the procedure that is doing the insert. (I say “usually” because you could, of course, have a procedure defined as “authid current_user”)

Consider the following (running on 11.1.0.6):

select
	username, temporary_tablespace
from
	dba_users
where
	username in ('U1','TEST_USER')
;

USERNAME        TEMPORARY_TABLESPACE
--------------- --------------------
U1              TEMP
TEST_USER       TEMP2

I have two users with different temporary tablespaces. In schema test_user we do the following:

create global temporary table t
as
select	*
from	all_objects
where	rownum = 0;

grant all on t to u1;

create or replace procedure pt
as
begin
	insert into t select * from all_objects where rownum <= 1000;
end;
/

grant execute on pt to u1;

Now we connect as user u1 and run the following:


SQL> insert into test_user.t select * from all_objects where rownum < = 10;

10 rows created.

SQL> commit;

Commit complete.

SQL> execute test_user.pt

PL/SQL procedure successfully completed.

SQL> commit;

Commit complete.

The first commit it very important, by the way. In another session logged in through a suitably privileged account, execute the following before each commit:

select username, tablespace from v$sort_usage;

The results after the direct call to insert into the GTT will be:

USERNAME TABLESPACE
-------- ----------------
U1       TEMP

The results from the call to the procedure will be:

USERNAME TABLESPACE
-------- ----------------
U1       TEMP2

The direct insert has used the temporary tablespace of schema U1, but the insert from the procedure call has used the temporary tablespace of schema test_user. So there are ways to allocate a global temporary table to a particularly temporary tablespace if you always use a procedure to populate it. I did point out, though, that the first commit in the demonstration was important. If you don’t do this commit the global temporary table will have been instantiated in the “wrong” temporary tablespace at the point you call the procedure, so the data from the procedure call would be added to the existing data – i.e. where you didn’t want it to go.

Footnote: Everything changes – you’ll see in a response to the thread from Uwe Hesse that from 11g onwards you can specify a tablespace for a global temporary tablespace, and that’s where the data will go. (But I’d drafted this note before I got back to the thread – and it’s still valid for earlier versions of Oracle.)

Footnote 2: I had to create a spare temporary tablespace for this demo. It’s funny little detail that although you: “create TEMPORARY tablespace … TEMPfile…”, when it comes to dropping it’s: “drop tablespace … including … datafiles”.

SQL Performance Problem, AWR Reports Query is #1 in Elapsed Time, #2 in CPU Time – How Would You Help?

February 6, 2011 (Updated February 25, 2011) I occasionally read various forums on the Internet including a couple of Usenet groups (comp.databases.oracle.server, comp.databases.oracle.misc), OTN forums (Database – General, SQL and PL/SQL), Oracle-L, AskTom, and a handful of other forums.  I don’t participate on all of the forums, but I try to help when possible on [...]

Things worth to mention and remember (I) - Parallel Execution Control

Continue to Part II

Motivated by Arup Nanda's great "100 Things You Probably Didn't Know About Oracle Database" and inspired by Jonathan Lewis' "Philosophy" series I'll start a new series about things worth to mention and remember, but in contrast to my usual posts I'll furthermore set a new challenge for myself - trying to write as short and concise as Jonathan does in his series. It is probably no coincidence that Charles Hooper and myself contributed by far the longest chapter to "Expert Oracle Practices" :-)

So don't expect any lengthy descriptions and testcases in this series - also I don't intend to provide here ground-breaking material. All this has probably been published several times in the past, nevertheless I believe it's worth to mention these things again (and again...).

Here we go, the first one worth to mention and remember is important for those that have an Enterprise Edition license and make use of the Parallel Execution feature:

If you haven't enabled Parallel DML on session level (ALTER SESSION ENABLE/FORCE PARALLEL DML) you are not able to force parallel DML execution on statement level using explicit PARALLEL hints for the DML operation. (This one is probably known)

If you disable Parallel Query on session level (ALTER SESSION DISABLE PARALLEL QUERY) explicit PARALLEL hints on statement level for a query operation will overrule this and therefore still use Parallel Query. The session setting only overrules the object level parallel settings, not the PARALLEL hint (This is probably less known)

Although there is probably a rationale behind this it is still obvious I think that there is a major inconsistency here.

In particular the latter is unfortunate if you have existing code with embedded PARALLEL hints and want to ensure that the execution is done serially without any code changes in order to not waste any parallel slaves processes meant to be used by other concurrent executions.

To me it would be much more intuitive and sensible if the setting on session level overruled anything else and therefore allowed to control the code using that general setting, as it does with parallel DML.

By the way, a parallel DML degree forced via ALTER SESSION FORCE PARALLEL DML PARALLEL N will then still be overruled by explicit PARALLEL hints applied to the DML operation, it's just that PARALLEL DML is simply not possible if not at least enabled at session level.

Actually I'm not aware of any officially supported way (which means without fiddling with any undocumented parameters) of preventing the Parallel Query execution of statements with embedded PARALLEL hints on session level besides using the Resource Manager and limiting the Parallel Degree to 1.

Note that this approach has again its own quirks and drawbacks, since obviously the execution plan generated based on the optimizer assumption of Parallel Execution will be effectively downgraded to serial execution at runtime rather than being re-optimized for serial execution. In many cases not a good idea - an execution plan generated for serial execution might look quite different and might be much more efficient when being executed serially.

As a final note, if you think you can work around this by using the undocumented "_optimizer_ignore_hints" parameter, you will be in for a surprise that apparently the APPEND, PARALLEL and NO_PARALLEL hints do not get ignored and still apply and therefore parallelize query execution.

Addendum March 2011: One further oddity should not be left unmentioned: In above mentioned scenario of parallel query being disabled on SESSION level via ALTER SESSION DISABLE PARALLEL QUERY and the usage of PARALLEL hints the following applies:

- Potentially a plan based on parallel execution is generated by the optimizer (as outlined)
- But the costing of the operations is based on serial execution, so the costs of parallel full table scans or index scans are not scaled down based on the degree of parallelism as usually

This means that the resulting execution plans are possibly different to a session where parallel query is enabled - it is more likely to get a serial execution plan favoured by the optimizer in the scenario with parallel query disabled due to the costing based on serial costs.

Nevertheless at runtime parallel execution (with the computed parallel degree) will be used if a parallel plan has been generated by the optimizer.

Dynamic Views

People forget from time to time that when you query the dynamic performance views (v$ views) you shouldn’t expect to get a read-consistent result set – and this can lead to some very strange results, especially when you start writing joins between views (for example you may be able to find a session is both “not waiting” and “waiting” if you still join v$session and v$session_wait).

Here’s a visual analogy to help you remember what’s going on: “Australian Propellors ?”

And a graphic to help explain the phenomenon: “Rolling Shutter Effect.”

And here, for stunning effect only, is another clip that appeared in the “related topics”.

Cunning way to thwart spammers…

I wrote the other day about the level of spam I was having on my forum. I did a little playing about and all seemed to calm down. In fact the forum got very quiet indeed. It was quite pleasant not having to worry about it.

Anyway, today I got a little suspicious as I had no posts at all. I tried to write a post myself and got a server error. It seems the last switch I flicked on the control panel tried to do something my hosting provider doesn’t allow and blocked all posts.

So my cunning plan turned out to be not so cunning afterall… :(

Let’s see if the deluge starts again…

Cheers

Tim…

Getting up and running with Universal Connection Pool – Take 2

In yesterday’s post (which is actually didn’t want to post that day) I wrote about the Universal Connection Pool feature. You should be able to get started with the information I gave you, but it didn’t include any hints on how to have a look under the covers of UCP. This can be changed …Oracle includes very fine-grained logging information with UCP, but experiment show that you have to either use log level FINE or FINEST to get to the real information of what’s going on.

LOGGING

Tomcat uses the log4j framework to define its own logging, as shown in the catalina.{bat,sh} file:

set LOGGING_CONFIG=-Djava.util.logging.config.file=”%CATALINA_BASE%\conf\logging.properties”

One thing you possibly don’t want to do is to include your own log4j configuration there-any change to your application’s file requires a restart of tomcat. Think of a production environment and then it becomes clear why such an approach is neither desirable nor practical.

Instead, you can put a file called logging.properties into the src directory within your application. In it you define logging to your heart’s delight. I have taken the following from the documentation and Pas Apicella’s blog. It really opens the floodgates for very detailed logging, so don’t use this in any other than a development environment…

handlers = org.apache.juli.FileHandler, java.util.logging.ConsoleHandler

org.apache.juli.FileHandler.level = ALL
org.apache.juli.FileHandler.directory = ${catalina.base}/logs
org.apache.juli.FileHandler.prefix = ucp.
org.apache.juli.FileHandler.formatter = oracle.ucp.util.logging.UCPFormatter

java.util.logging.FileHandler.level = WARNING

.level = FINEST

# FCF classes
oracle.ucp.common.FailoverEventHandlerThreadBase.level = ALL

oracle.ucp.jdbc.oracle.ONSDatabaseFailoverEvent.level = ALL
oracle.ucp.jdbc.oracle.ONSRuntimeLBEventHandlerThread.level = ALL
oracle.ucp.jdbc.oracle.ONSOracleRuntimeLBEventSubscriber.level = ALL
oracle.ucp.jdbc.oracle.ONSRuntimeLoadBalancingEvent.level = ALL
oracle.ucp.jdbc.oracle.ONSOracleFailoverEventSubscriber.level = ALL
oracle.ucp.jdbc.oracle.ONSDatabaseEventHandlerThread.level = ALL
oracle.ucp.jdbc.oracle.OracleFailoverEvent.level = ALL
oracle.ucp.jdbc.oracle.OracleFailoverEventSubscriber.level = ALL
oracle.ucp.jdbc.oracle.OracleFailoverEventImpl.level = ALL
oracle.ucp.jdbc.oracle.OracleFailoverEventNotification.level = ALL
oracle.ucp.jdbc.oracle.OracleFailoverHandler.level = ALL
oracle.ucp.jdbc.oracle.OracleFailoverablePooledConnection.level = ALL

oracle.ucp.jdbc.oracle.OraclePooledConnectionConnectionPool.level = ALL
oracle.ucp.jdbc.oracle.OracleConnectionConnectionPool.level = ALL
oracle.ucp.jdbc.oracle.OracleXAConnectionConnectionPool.level = ALL
oracle.ucp.jdbc.oracle.OracleJDBCConnectionPool.level = ALL

oracle.ucp.jdbc.oracle.OracleDatabaseInstanceInfo.level = ALL
oracle.ucp.jdbc.oracle.OracleDatabaseInstanceInfoList.level = ALL

# RCLB classes
oracle.ucp.jdbc.oracle.ONSRuntimeLBEventHandlerThread.level = ALL
oracle.ucp.jdbc.oracle.ONSOracleRuntimeLBEventSubscriber.level = ALL
oracle.ucp.jdbc.oracle.OracleRuntimeLoadBalancingHandler.level = ALL
oracle.ucp.jdbc.oracle.ONSRuntimeLoadBalancingEvent.level = ALL

Now when you redeploy your application, a new file ucp.timestamp will be created in %CATALINA_HOME%\logs and list all the beauty of what’s going on. The log file is now very verbose though.

FAST CONNECTION FAILOVER

The previous source code didn’t take full potential of the fact that the fastConnectionFailover functionality was enabled. For the following to work you might want to disable the validateConnectionOnBorrow setting in META-INF/context.xml. In fact, we’d like to validate the connection when we get it from the pool ourselves. The code of the Hello.java servlet has changed as follows:

// time to get UCP to start
writer.println("

UCP

"); Connection conn = null; oracle.ucp.jdbc.PoolDataSource ds = null; try { Context ctx = new InitialContext(); Context envContext = (Context) ctx.lookup("java:/comp/env"); ds = (oracle.ucp.jdbc.PoolDataSource) envContext.lookup ("jdbc/UCPPool"); writer.println("Got the datasource - "); writer.println("FCF enabled? " + ds.getFastConnectionFailoverEnabled()); conn = ds.getConnection(); } catch (Exception e) { try { // here's where the FCF comes in if (conn == null || !((ValidConnection) conn).isValid()) { writer.println("

Have to retry connection (" + e.getMessage() + ")

"); OracleJDBCConnectionPoolStatistics stats = (OracleJDBCConnectionPoolStatistics) ds.getStatistics(); writer.println("Pool stats: " + stats.getFCFProcessingInfo()); conn.close(); } else { writer.println("Unknown exception: " + e); } } catch (SQLException sqle) { e.printStackTrace(); return; } } try { writer.println("

Connected to Oracle intance

"); Statement stmt = conn.createStatement(); ResultSet rs = stmt.executeQuery("select 'Hello World from '||sys_context('userenv','instance_name') from dual"); while (rs.next()) { writer.println("

" + rs.getString(1) + "

");
}

rs.close();
stmt.close();
conn.close();

} catch (Exception e) {
writer.println("

" + e + "

");
}

writer.println("");
writer.println("");

}

I will probably attach the code to the post as the layout is pretty broken.

IS THE POOL INTELLIGENT?

To see if the runtime load balancing feature works at all I shut down the second of my two database instances before restarting the application. I expect all sessions to be on the first instance (to be expected as there is not a second one). Is that so?

SQL> ed
Wrote file afiedt.buf

 1  select count(inst_id),inst_id,
 2  status from gv$session where username='SCOTT'
 3* group by inst_id, status
SQL> /
COUNT(INST_ID)    INST_ID STATUS
-------------- ---------- --------
58          1 INACTIVE

Now what happens when I start the second instance?

SQL> !srvctl start instance -d lnrut1d -i LNRUT1D_2
/

SQL>
COUNT(INST_ID)    INST_ID STATUS
-------------- ---------- --------
 69          1 INACTIVE

SQL> /

COUNT(INST_ID)    INST_ID STATUS
-------------- ---------- --------
 57          1 INACTIVE
 19          2 INACTIVE

SQL> /

COUNT(INST_ID)    INST_ID STATUS
-------------- ---------- --------
 25          1 INACTIVE
 45          2 INACTIVE

That’s neat-the second instance catches up. I eventually ended up near-equilibrium. The inverse is also true. Consider two instances up as shown here:

SQL> select count(inst_id),inst_id,
 2  status from gv$session where username='SCOTT'
 3  group by inst_id, status
 4  /

COUNT(INST_ID)    INST_ID STATUS
-------------- ---------- --------
 21          1 INACTIVE
 26          2 INACTIVE
 1          2 ACTIVE
 2          1 ACTIVE

SQL> !srvctl stop instance -d lnrut1d -i LNRUT1D_2 -o abort

SQL> /

COUNT(INST_ID)    INST_ID STATUS
-------------- ---------- --------
 36          1 INACTIVE

Now when I shut the second instance down, the number of sessions on the first node goes up:


SQL> /

COUNT(INST_ID)    INST_ID STATUS
-------------- ---------- --------
 65          1 INACTIVE

I like this!

A short podcast...

We've just posted a short podcast with more information about the Real World Performance days I'm participating in. We are starting on the west coast of the US and will be presenting across the country over the next few months - eventually ending up in the UK.

For more information or to sign up - goto http://www.ioug.org/ and select Events -> A day of Real World Performance from the menu.
Hope to see you there!