Oracle Scratchpad

July 2, 2013

12c I/O debug

Filed under: 12c,Oracle,Troubleshooting — Jonathan Lewis @ 6:05 pm BST Jul 2,2013

By my count there are 109 new v$ and gv$ dynamic performance views in 12c (so far) – and Glen Fawcett has posted a short note on a group that may be of particular benefit to anyone who finds they really have to delve into esoteric I/O problems from time to time. For the less exotic, there’s v$io_outliers and v$lgwrio_outliers which give details about any very slow I/Os – for the more exotic there’s v$kernel_io_outliers – which is the really fascinating one.

Here’s a short session capture focused on v$io_outliers:


SQL> select function_name, wait_event, count(*) from v$io_outlier group by function_name, wait_event;

FUNCTION_NAME      WAIT_EVENT                                                         COUNT(*)
------------------ ---------------------------------------------------------------- ----------
Direct Writes                                                                                1
DBWR                                                                                        11
Buffer Cache Reads db file parallel read                                                     1
Others             control file parallel write                                              32
Others                                                                                      34
Buffer Cache Reads                                                                          10

6 rows selected.

SQL> select io_size, io_latency from v$io_outlier
  2  where wait_event = 'control file parallel write'
  3  order by io_latency;

   IO_SIZE IO_LATENCY
---------- ----------
        16        514
        16        533
        16        545
        16        552
        16        557
        16        588
        16        629
        16        632
        16        639
        16        654
        16        717
        16        739
        16        793
        16        851
        16        859
        16        872
        16        965
        16       1074
        16       1261
        16       1513
        16       2020
        16       2699
        16       3756
        16       3986
        16       4379
        16       4518
        16       4757
        16       4908
        16       9817
        16      10279
        16      13883
        16    2924040

32 rows selected.

SQL> select * from v$event_histogram where event = 'control file parallel write';

WAIT_TIME_MILLI WAIT_COUNT LAST_UPDATE_TIME                        CON_ID
--------------- ---------- ----------------------------------- ----------
              1       6903 02-JUL-13 08.34.51.556059 AM +01:00          0
              2      67990 02-JUL-13 08.36.06.643280 AM +01:00          0
              4       5839 02-JUL-13 08.36.00.635787 AM +01:00          0
              8        909 02-JUL-13 08.32.17.999903 AM +01:00          0
             16        404 02-JUL-13 08.26.17.019774 AM +01:00          0
             32        375 02-JUL-13 08.20.16.049842 AM +01:00          0
             64        316 02-JUL-13 08.25.35.997658 AM +01:00          0
            128        154 02-JUL-13 07.50.17.522235 AM +01:00          0
            256         43 02-JUL-13 07.50.17.268394 AM +01:00          0
            512         37 02-JUL-13 07.50.21.405903 AM +01:00          0
           1024         31 01-JUL-13 01.46.43.419938 PM +01:00          0
           2048          3 02-JUL-13 07.50.14.716905 AM +01:00          0
           4096          2 01-JUL-13 06.47.38.055541 AM +01:00          0
           8192          5 02-JUL-13 06.12.18.501807 AM +01:00          0
          16384          2 01-JUL-13 01.09.21.839019 PM +01:00          0
          32768          1 30-JUN-13 02.39.07.008164 AM +01:00          0
          65536          0                                              0
         131072          0                                              0
         262144          0                                              0
         524288          0                                              0
        1048576          0                                              0
        2097152          0                                              0
        4194304          1 01-JUL-13 11.17.20.600514 AM +01:00          0

23 rows selected.

Unfortunately, although the figures are close, a quick check on the v$event_histogram ranges ending 4096, 8192, 16384 and 32767 don’t quite match the precision figures given in v$io_outlier – there’s a little slippage across the boundaries.

Footnote: looking at the gv$ definitions – v$lgwrio_outlier and v$io_outlier differ only in whether they include or exclude “io_component_id” number 2 (the lgwr component).

July 1, 2013

12c Determinism

Filed under: 12c,Oracle,Troubleshooting — Jonathan Lewis @ 4:55 pm BST Jul 1,2013

Following a comment from Marcin Przepiorowski on my last post, it crossed my mind to check whether “with” functions can be deterministic – the answer seems to be “not yet”. Here’s a simple script that you can run from end to end to check current and future releases – it compares inline (with) and standalone functions when the “deterministic” keyword has been used.


create table t1
as
select
	1	n1
from
	all_objects
where
	rownum <= 10
;

execute dbms_stats.gather_table_stats(user,'t1')

create or replace function standalone_function(i_in number) return number
deterministic
is
begin
	dbms_output.put_line('Standalone function');
	return i_in;
end;
/

spool 12c_deterministic

prompt	============
prompt	arraysize 20
prompt	============

set arraysize 20

with
	function inline_function(i_in number) return number
	deterministic
	as
	begin
		dbms_output.put_line('Inline function');	
		return(i_in);
	end;
select
	standalone_function(n1),
	inline_function(n1)
from
	t1
/

The code is very simple – create a table with 10 rows of one column, every row holding the same value; create a standalone function declared as deterministic that simple outputs a message and returns the input value. If determinism is actually in play then, within a single database call, Oracle will call the function just once per input value rather than once per reference. The query then defines an inline (with) function, and selects using the standalone and inline functions from the table. Here’s the output:

============
arraysize 20
============

STANDALONE_FUNCTION(N1) INLINE_FUNCTION(N1)
----------------------- -------------------
                      1                   1
                      1                   1
                      1                   1
                      1                   1
                      1                   1
                      1                   1
                      1                   1
                      1                   1
                      1                   1
                      1                   1

10 rows selected.

Standalone function
Inline function
Standalone function
Inline function
Inline function
Inline function
Inline function
Inline function
Inline function
Inline function
Inline function
Inline function

As you can see, the inline function has been called 10 times while the standalone function has been called twice. (The two calls to the standalone function is a feature of the way that SQL*Plus fetches the first row from a query and then starts using the arraysize for subsequent fetches – each fetch call is a new database call which requires a new call to the deterministic function … try running the code with the arraysize set to 2 (or 1 – which SQL*Plus will silently change to 2).

The intent of inline (with) functions is to make PL/SQL function calls within SQL more efficient – but before you change your code to take advantage of the feature, make sure that you are going to lose the benefit of determinism.

June 30, 2013

12c Funny

Filed under: 12c,Oracle,Troubleshooting — Jonathan Lewis @ 7:10 pm BST Jun 30,2013

Here’s a quirky little thing I discovered about 5 minutes after installing 12c Beta 1 (cut-n-pasted from SQL*Plus):

create or replace view v$my_stats
as
select
        ms.sid,
        sn.statistic#,
        sn.name,
        sn.class,
        ms.value
from
        v$mystat        ms,
        v$statname      sn
where
        sn.statistic# = ms.statistic#
 14  ;
create or replace view v$my_stats
                       *
ERROR at line 1:
ORA-00999: invalid view name

You can’t create views with names that start with V$ or GV$ in the sys schema. Presumably to eliminate the risk of someone’s clever view definition from overwriting and disabling one of the distributed dynamic performance views by accident.

(more…)

June 9, 2013

10053

Filed under: CBO,Oracle,Troubleshooting — Jonathan Lewis @ 9:24 am BST Jun 9,2013

I thought I’d try to spend some of today catching up on old comments – first the easier ones, then the outstanding questions on Oracle Core.
The very first one I looked at was about pushing predicates, and the specific comment prompted me to jot down this little note about the 10053 trace file (the CBO trace).

In “real-life” I don’t often look at 10053 trace files because they tend to be very long and messy and usually you can see all you need from an execution plan – perhaps through SQL Monitoring, or possible with the rowsource execution stats enabled. However there are questions that can sometimes be resolved very quickly by a simple text search of a trace file; questions of the form: “why isn’t the optimizer using feature X”, for example: “why didn’t the optimizer use predicate push for this view?” If you have a question of this type, then search the trace file for the word “bypass” – you may find comments like the following:

        JPPD:     JPPD bypassed: Outer query references right side of outer join
        JPPD:     JPPD bypassed: View has a single or group set function.
        JPPD:     JPPD bypassed: OLD_PUSH_PRED hint specified
        JPPD:     JPPD bypassed: User-defined operator
        JPPD:     JPPD bypassed: Push-down not enabled
        JPPD:     JPPD bypassed: View not on right-side of outer join
        JPPD:     JPPD bypassed: View contains a group by.
        JPPD:     JPPD bypassed: View contains a window function.
        JPPD:     JPPD bypassed: View contains a MODEL clause.
        JPPD:     JPPD bypassed: View contains a DISTINCT.
        JPPD:     JPPD bypassed: View contains a rownum reference.
        JPPD:     JPPD bypassed: START WITH query block.
        JPPD:     JPPD bypassed: View is a set query block.
        JPPD:     JPPD bypassed: Negative hint found
        JPPD:     JPPD bypassed: Outline does not contain hint
        JPPD:     JPPD bypassed: Base table missing statistics
        JPPD:     JPPD bypassed: Remote table
        JPPD:     JPPD bypassed: Security violation
        JPPD:     JPPD bypassed: Possible security violation.
        JPPD bypassed: Table level NO_PUSH_PRED hint.
        JPPD bypassed: Table-level hint.
        JPPD bypassed: Query block NO_PUSH_PRED hint.
        JPPD bypassed: View semijoined to table
        JPPD bypassed: Contained view has no table in fro list.
        JPPD bypassed: View contains a START WITH query block.
        JPPD bypassed: Does not contain a view.
        JPPD bypassed: Found branches of different types

According to a note that I’ve got with this list, by the way, I used “strings -a” on the Oracle executable for 10.2.0.1 to generate it. It’s probably about time I did the same for newer versions of Oracle.

Footnote:

My plans for addressing comments have been disrupted somewhat. Just as I published this note, an email holding two 10053 trace files arrived. (The author had asked before sending them, and I was sufficiently curious that I had agreed to take a quick look). So I’ve spent most of the last hour doing what I’ve just said I hardly ever to – looking at 10053 trace files.

The question was “why does this query run serially if I have a particular scalar subquery in the select list, but run parallel if I replace it with a function”.  The immediate answer, after I’d seen the query and thought about it for a bit, was: “because the manuals (10.2 – the relevant version) say that you don’t parallelize if you have scalar subqueries in the select list”; but this changed the question to: “why is it just this one scalar subquery that causes serialization when the other two scalar subqueries don’t”. Of the three scalar subqueries, only one of them cause the query to serialize.

The answer to that question is a little more subtle – and I’ll blog about it when I can find time to model the scenario.

May 27, 2013

CUR Gets

Filed under: Oracle,Troubleshooting — Jonathan Lewis @ 6:16 pm BST May 27,2013

Here’s an interesting anomaly from the OTN database forum – PL/SQL track. It’s a single row delete from a table that does a huge number of db block gets and (in the first example shown) physical reads. Here’s the supplied output with autotrace enabled:

(more…)

May 23, 2013

Dynamic Sampling – 2

Filed under: CBO,Hints,Oracle,Troubleshooting — Jonathan Lewis @ 12:46 pm BST May 23,2013

I’ve written about dynamic sampling in the past, but here’s a little wrinkle that’s easy to miss. How do you get the optimizer to work out the correct cardinality for a query like (the table creation statement follows the query):

(more…)

May 22, 2013

gather_plan_statistics – 2

Filed under: Oracle,Performance,Troubleshooting — Jonathan Lewis @ 12:40 pm BST May 22,2013

Some time ago – actually a few years ago – I wrote a note about the hint /*+ gather_plan_statistics */ making some informal comments about the implementation and relevant hidden parameters. I’ve recently discovered a couple of notes from Alexander Anokhin describing the feature in far more detail and describing some of the misleading side effects of the implementaiton. There are two parts (so far): part 1 and part 2.

 

May 13, 2013

Parse Time

Filed under: Execution plans,Oracle,Performance,Troubleshooting — Jonathan Lewis @ 6:59 pm BST May 13,2013

Dominic Brooks published a note recently about some very nasty SQL – originally thinking that it was displaying a run-time problem due to the extreme number of copies of the lnnvl() function the optimizer had produced. In fact it turned out to be a parse-time problem rather than a run-time problem, but when I first read Dominic’s note I was sufficiently surprised that I decided to try modelling the query.

(more…)

May 10, 2013

Hakan Factor

Filed under: Infrastructure,Oracle,Troubleshooting — Jonathan Lewis @ 3:52 pm BST May 10,2013

Here’s a quick and dirty script to create a procedure (in the SYS schema – so be careful) to check the Hakan Factor for an object. If you’re not familiar with the Hakan Factor, it’s the value that gets set when you use the command “alter table minimize records_per_block;”.

(more…)

May 2, 2013

v$lock

Filed under: Locks,Oracle,Statistics,Troubleshooting — Jonathan Lewis @ 7:03 pm BST May 2,2013

The problem of slow queries on v$lock just came up again on the OTN database forum, so I thought I’d better push out a post that’s been hanging around on my blog for the last few months. This is actually mentioned in MOS in note 1328789.1: “Query Against v$lock Run from OEM Performs Slowly” which points out that it is basically a problem of bad statistics and all you have to do is collect the stats.

(more…)

April 16, 2013

systimestamp

Filed under: Bugs,Oracle,Troubleshooting — Jonathan Lewis @ 12:46 am BST Apr 16,2013

For your entertainment – there’s nothing up my sleeves, this was a simple cut-n-paste after real-time typing with no tricks:

20:39:51 SQL> create table t1 (t1 timestamp);

Table created.

20:39:55 SQL> insert into t1 values(systimestamp);

1 row created.

20:39:59 SQL> select t1 - systimestamp  from t1;

T1-SYSTIMESTAMP
---------------------------------------------------------------------------
+000000000 04:59:50.680620

1 row selected.

20:40:08 SQL>

(more…)

April 13, 2013

Deadlocks

Filed under: deadlocks,Locks,Oracle,Troubleshooting — Jonathan Lewis @ 11:36 am BST Apr 13,2013

Here’s a deadlock graph that might cause a little confusion:

Deadlock graph:
                       ---------Blocker(s)--------  ---------Waiter(s)---------
 Resource Name          process session holds waits  process session holds waits
 TX-001a0015-00014787        34      90     X             32       3           S
 TX-00190008-0000601b        32       3     X             34      90           S

 session 90: DID 0001-0022-00000327      session 3: DID 0001-0020-000009E9
 session 3: DID 0001-0020-000009E9       session 90: DID 0001-0022-00000327

 Rows waited on:
  Session 90: obj - rowid = 00030CE5 - AAAwzlAAGAABDiuAAA
  (dictionary objn - 199909, file - 6, block - 276654, slot - 0)
  Session 3: obj - rowid = 00030CE5 - AAAwzlAAGAABp8gAAA
  (dictionary objn - 199909, file - 6, block - 433952, slot - 0)

(more…)

April 7, 2013

DML Tracking

Filed under: Oracle,Troubleshooting — Jonathan Lewis @ 10:04 pm BST Apr 7,2013

You’ve probably seen questions on the internet occasionally about finding out how frequently an object has been modified. The question is a little ambiguous – does it mean how much change has occurred, or how many DML statements have been executed; either may be an interesting measure. Of course, Oracle gave us a method of answering the first question a long time ago: v$segstat (or v$segment_statistics if you don’t mind suffering the join) and the resulting content in the AWR or Statspack reports:
(more…)

March 31, 2013

Index Selectivity

Filed under: CBO,Oracle,Troubleshooting — Jonathan Lewis @ 6:42 pm BST Mar 31,2013

Here’s a summary of a recent posting on OTN:

I have two indexes (REFNO, REFTYPESEQNO) and (REFNO,TMSTAMP,REFTYPESEQNO). When I run the following query the optimizer uses the second index rather than the first index – which is an exact match for the predicates, unless I hint it otherwise:

(more…)

March 29, 2013

Missing SQL

Filed under: Bugs,Oracle,Statspack,Troubleshooting — Jonathan Lewis @ 9:35 am BST Mar 29,2013

From time to time I’ve looked at an AWR report and pointed out to the owner the difference in work load visible in the “SQL ordered by” sections of the report when they compare the summary figure with the sum of the work done by the individual statements. Often the summary will state that the captured SQL in the interval represents some percentage of the total workload  in the high 80s to mid 90s – sometimes you might see a statement that the capture represents a really low percentage, perhaps in the 30s or 40s.

You have to be a little sensible about interpreting these figures, of course – at one extreme it’s easy to double-count the cost of SQL inside PL/SQL, at the other you may notice that every single statement reported does about the same amount of work so you can’t extrapolate from a pattern to decide how significant a low percentage might be. Nevertheless I have seen examples of AWR reports where I’ve felt justified in suggesting that at some point in the interval some SQL has appeared, worked very hard, and disappeared from the library cache before the AWR managed to capture it.

Now, from Nigel Noble, comes another explanation for why the AWR report might be hiding expensive SQL – a bug, which doesn’t get fixed until 12.2 (although there are backports in hand).

« Previous PageNext Page »

The Rubric Theme Blog at WordPress.com.

Follow

Get every new post delivered to your Inbox.

Join 3,505 other followers