Striving for Optimal Performance

Today’s post is dedicated to the Metalink SR identified by the number 6468252.994. I know, this number says nothing to you. For me, however, it’s a very well known number. The reason is quite simple… Even if I open this SR almost two years ago (to be precise, September 5, 2007), it was closed few days ago. By far the most long-lasting SR I even experienced.

Let me explain why I opened it.

When assessing execution plans I like to use DBMS_XPLAN or, when necessary, to directly look at views like V$SQL_PLAN_STATISTICS and V$SQL_PLAN_STATISTICS_ALL. I like them because they provide a lot of information about what’s going on. In other words, they help me avoiding guesswork as much as possible. One of the most interesting information they provide is the number of rows returned by a given operation. DBMS_XPLAN provides this information in the column “A-Rows”. Be careful to not confuse it with the columns “Rows” and “E-Rows”. While “A-Rows” shows the actual number of rows, the other two shows the estimated number of rows. So far, so good.

What I don’t like about the column “A-Rows” (or the underlying columns LAST_OUTPUT_ROWS in the V$ views), is that for the operations modifying a table 0 is shown. By the way, according to the documentation it is not a bug. In my book I point out this behavior at page 233. For example, as the following SQL statements show, even if 14 rows are modified the value of “A-Rows” for the operation UPDATE (Id=1) is 0:

SQL> UPDATE /*+ gather_plan_statistics */ scott.emp SET sal = sal * 1.15;

14 rows updated.

SQL> SELECT * FROM table(dbms_xplan.display_cursor(format=>'iostats last'));

SQL_ID  4cs72g2hp6j67, child number 0
-------------------------------------
UPDATE /*+ gather_plan_statistics */ scott.emp SET sal = sal * 1.15

Plan hash value: 1494045816

-------------------------------------------------------------------------------------
| Id  | Operation          | Name | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
-------------------------------------------------------------------------------------
|   0 | UPDATE STATEMENT   |      |      1 |        |      0 |00:00:00.01 |      25 |
|   1 |  UPDATE            | EMP  |      1 |        |      0 |00:00:00.01 |      25 |
|   2 |   TABLE ACCESS FULL| EMP  |      1 |     14 |     14 |00:00:00.01 |       7 |
-------------------------------------------------------------------------------------

Back to the SR. What I tried to do with the SR is to convince Oracle that it would be much better to have the information about the number of modified rows. Unfortunately, they confirmed that the current behavior is the best one. My guess is that doing such a modification is not trivial and, therefore, they decided not doing it. In fact, also the SQL trace files have a similar behavior. For example, via SQL trace, the execution plan for the UPDATE statement shown before is the following:

Rows     Row Source Operation
-------  ---------------------------------------------------
      0  UPDATE  EMP (cr=7 pr=0 pw=0 time=0 us)
     14   TABLE ACCESS FULL EMP (cr=7 pr=0 pw=0 time=0 us cost=3 size=56 card=14)

It is also interesting to note that while analyzing the code (probably for checking whether the change I proposed was doable) a developer discovered a bug. Based on the information I received (see bug number 6410147) it seems that in some situation the value of “A-Rows” is different than 0. But, since it is a bug, they fixed it.

Update 2009-08-03: part 2 of this post is available here.

This is a partial screenshot of an application without a decent error handling.

Do you recognize it?

It goes without saying that no further comments are needed…

As of Oracle Database 11g, serial full table scans can use direct reads (see Metalink note 793845.1). This is basically done for improving the performance of large full table scans. In my opinion, the most important pros and cons of this feature are the following…

Pros (which are related to the fact that the buffer cache is not used):

• Reduced latch utilization
• The size of the physical I/Os does not depend on the blocks that are in the buffer cache

Cons:

• A segment checkpoint must precede the first direct read
• Repeated delayed block cleanouts

In this post, as the title suggests, I would like to focus on the last one. The reason is simple. I cannot remember having already read something about that topic.

Let’s start by showing you an example where delayed block cleanouts are performed…

• Create a test table and insert some data into it (note that the table uses 10000 database blocks):

SQL> CREATE TABLE t (id NUMBER, pad VARCHAR2(500)) TABLESPACE test_8k;

SQL> INSERT INTO t
  2  SELECT rownum, rpad('*',500,'*')
  3  FROM dual
  4  CONNECT BY level <= 140000;

SQL> COMMIT;

• Generate some blocks that require delayed block cleanout:

SQL> UPDATE t SET id=id*10;

SQL> COMMIT;

• Flush the buffer cache (this is necessary because many blocks are in the buffer cache and, therefore, direct reads would not be used for reading the test table):

SQL> ALTER SYSTEM FLUSH BUFFER_CACHE;

• Execute two queries on the test table and store the session statistics in a helper table:

SQL> CREATE TABLE s AS
  2  SELECT 0 AS run, name, value
  3  FROM v$statname NATURAL JOIN v$mystat;

SQL> SELECT count(*) FROM t;

  COUNT(*)
----------
    140000

SQL> INSERT INTO s
  2  SELECT 1, name, value
  3  FROM v$statname NATURAL JOIN v$mystat;

SQL> SELECT count(*) FROM t;

  COUNT(*)
----------
    140000

SQL> INSERT INTO s
  2  SELECT 2, name, value
  3  FROM v$statname NATURAL JOIN v$mystat;

• Show some statistics for the two executions:

SQL> SELECT *
  2  FROM (
  3    SELECT run, name, value-lag(value) OVER (ORDER BY name, run) AS value
  4    FROM s
  5    WHERE name IN ('cleanouts only - consistent read gets',
  6                   'session logical reads',
  7                   'physical reads',
  8                   'physical reads direct')
  9  )
 10  PIVOT (sum(value) FOR run IN (1 AS RUN_1, 2 AS RUN2_2))
 11  ORDER BY name;

NAME                                          RUN_1     RUN2_2
---------------------------------------- ---------- ----------
cleanouts only - consistent read gets          9466       9399
physical reads                                10112      10004
physical reads direct                         10003      10003
session logical reads                         19850      19538

As you can see from the execution statistics, both runs did almost the same amount of (direct) reads, logical reads and cleanouts. Especially the last is strange. In fact, usually, the cleanouts are performed only once for each block. In this case, however, the same cleanouts are performed for every execution of the query.

This is clearly due to the direct reads.

To confirm that, let’s rerun the test without using serial direct reads. For that purpose, event 10949 is enabled.

SQL> TRUNCATE TABLE s;

SQL> ALTER SESSION SET EVENTS '10949 TRACE NAME CONTEXT FOREVER';

SQL> INSERT INTO s
  2  SELECT 0 AS run, name, value
  3  FROM v$statname NATURAL JOIN v$mystat;

SQL> SELECT count(*) FROM t;

  COUNT(*)
----------
    140000

SQL> INSERT INTO s
  2  SELECT 1, name, value
  3  FROM v$statname NATURAL JOIN v$mystat;

SQL> SELECT count(*) FROM t;

  COUNT(*)
----------
    140000

SQL> INSERT INTO s
  2  SELECT 2, name, value
  3  FROM v$statname NATURAL JOIN v$mystat;

SQL> SELECT *
  2  FROM (
  3    SELECT run, name, value-lag(value) OVER (ORDER BY name, run) AS value
  4    FROM s
  5    WHERE name IN ('cleanouts only - consistent read gets',
  6                   'session logical reads',
  7                   'physical reads',
  8                   'physical reads direct')
  9  )
 10  PIVOT (sum(value) FOR run IN (1 AS RUN_3, 2 AS RUN2_4))
 11  ORDER BY name;

NAME                                          RUN_3     RUN2_4
---------------------------------------- ---------- ----------
cleanouts only - consistent read gets          9399          0
physical reads                                 9919          0
physical reads direct                             0          0
session logical reads                         19592      10228

As you can see from the statistics, the major difference between the second and the third run is the number of direct reads. The interesting thing is to notice how the third run finally did a “regular” cleanout and, therefore, the subsequent run, the fourth one, was able to directly read the (cleaned) blocks. Because of that the number of logical reads of the fourth run was much lower.