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.

As you can read in the documentation, the columns MAX_TEMPSEG_SIZE and LAST_TEMPSEG_SIZE in the dynamic performance view V$SQL_WORKAREA provide information about the size of the temporary segment used for a specific workarea. The values are given in bytes. Let’s perform a test to check this information…

• Create a test table that contains about 1MB of data:

SQL> CREATE TABLE t AS
  2  SELECT rownum AS id, dbms_random.string('p',1000) AS pad
  3  FROM dual
  4  CONNECT BY level <= 1000;

SQL> execute dbms_stats.gather_table_stats(user, 't')

• Setup the session to force the user process to spill into a temporary segment:

SQL> ALTER SESSION SET workarea_size_policy = manual;
SQL> ALTER SESSION SET sort_area_size = 524288;

• Run test query including a sort operation (that spills to the temporary tablespace):

SQL> SELECT id FROM t ORDER BY pad;

• Check the amount of used temporary space by querying V$SQL_WORKAREA:

SQL> SELECT max_tempseg_size, last_tempseg_size
  2  FROM v$sql_workarea
  3  WHERE (sql_id, child_number) IN (SELECT prev_sql_id, prev_child_number
  4                                   FROM v$session
  5                                   WHERE sid = sys_context('userenv','sid'));

MAX_TEMPSEG_SIZE LAST_TEMPSEG_SIZE
---------------- -----------------
         2097152           2097152

According to this information the size of the temporary space used to execute the query was 2MB. So far, so good.

Always according to the documentation another dynamic performance view, V$SQL_PLAN_STATISTICS_ALL, should provide the same information (remember, V$SQL_PLAN_STATISTICS_ALL shows in a single view all the information provided by the views V$SQL_PLAN, V$SQL_PLAN_STATISTICS, and V$SQL_WORKAREA). Let’s check it…

• Run the same test query as before:

SQL> SELECT id FROM t ORDER BY pad;

• Check the amount of used memory by querying V$SQL_PLAN_STATISTICS_ALL:

SQL> SELECT max_tempseg_size, last_tempseg_size
  2  FROM v$sql_plan_statistics_all
  3  WHERE (sql_id, child_number) IN (SELECT prev_sql_id, prev_child_number
  4                                   FROM v$session
  5                                   WHERE sid = sys_context('userenv','sid'))
  6  AND max_tempseg_size IS NOT NULL;

MAX_TEMPSEG_SIZE LAST_TEMPSEG_SIZE
---------------- -----------------
            2048              2048

Ups! According to this information the size of the temporary space used to execute the query was 2KB. Mhmm, something is not good… For this reason, at the end of 2007 I opened a service request about this issue. The support guy recognized the problem and opened a bug. Fine. For some unknown reasons (?) yesterday I was checking the status of few bugs. While doing so I noticed that this specific bug was closed few months ago with the status “Could Not Reproduce”! I don’t know you, but on my 64-bit Linux server I can reproduce it with at least 11.1.0.7.0, 11.1.0.6.0, 10.2.0.4.0, 10.2.0.3.0, 10.2.0.2.0, 10.2.0.1.0, 10.1.0.5.0, 10.1.0.4.0 and 10.1.0.3.0. Geez!

It is essential to note that also the package DBMS_XPLAN shows wrong information (here an example for the same query as before):

SQL> SELECT * FROM table(dbms_xplan.display_cursor(null,null,'memstats last'));

PLAN_TABLE_OUTPUT
---------------------------------------------------------------------------------
SQL_ID  ftb71b6926dtn, child number 0
-------------------------------------
SELECT id FROM t ORDER BY pad

Plan hash value: 961378228

---------------------------------------------------------------------------------
| Id  | Operation          | Name | E-Rows |  OMem |  1Mem | Used-Mem | Used-Tmp|
---------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      |        |       |       |          |         |
|   1 |  SORT ORDER BY     |      |   1000 |  1152K|   562K|  529K (1)|    2048 |
|   2 |   TABLE ACCESS FULL| T    |   1000 |       |       |          |         |
---------------------------------------------------------------------------------

The only good thing about the fact that Oracle is not willing to fix the bug is that my book, Troubleshooting Oracle Performance, does not need to be updated. In fact, at page 210, while describing the output of the package DBMS_XPLAN I wrote the following information:

• Used-Tmp: The amount of temporary space used by the operation during the last execution. This value must be multiplied by 1,024 to be consistent with the other memory utilization columns (for example, 32K means 32MB).
• Max-Tmp: The maximum amount of temporary space used by the operation. This value has to be multiplied by 1,024 to be consistent with the other memory utilization columns (for example, 32K means 32MB).

ADDENDA (Mai 6, 2009): This post was noticed by an Oracle employee and, as a result, the bug was reopened. Thank you Greg!

As of Oracle Database 11g it is possible to use a virtual column as partition key. In this post I do not want to discuss how it works and whether this is good or not… Instead, I would like to show you that the feature might lead to wrong results.

First of all, I would like to show you a test where everything works fine. For that purpose, let’s create a table (notice the virtual column n2), insert one row into it, and gather the object statistics:

SQL> CREATE TABLE t (
  2    n1 NUMBER,
  3    n2 AS (CASE n1 WHEN 1 THEN 1 WHEN 2 THEN 2 ELSE 0 END) VIRTUAL
  4  )
  5  PARTITION BY LIST (n2) (
  6    PARTITION zero VALUES (0),
  7    PARTITION one VALUES (1),
  8    PARTITION two VALUES (2)
  9  )
 10  ENABLE ROW MOVEMENT;

SQL> INSERT INTO t (n1) VALUES (1);

SQL> COMMIT;

SQL> execute dbms_stats.gather_table_stats(user,'t')

The aim of the following test is to check whether row movement works correctly. Hence, I update the column n1 to cause such a movement. To check whether row movement is performed or not, I display the content of the two involved partitions before and after the update statement. In addition, I also display the rowids (because of the movement the row should get a new rowid).

SQL> SELECT rowid, n1, n2 FROM t PARTITION (zero);

no rows selected

SQL> SELECT rowid, n1, n2 FROM t PARTITION (one);

ROWID                      N1         N2
------------------ ---------- ----------
AAAE89AAEAAAAGNAAA          1          1

SQL> UPDATE t SET n1 = 3;

SQL> COMMIT;

SQL> SELECT rowid, n1, n2 FROM t PARTITION (zero);

ROWID                      N1         N2
------------------ ---------- ----------
AAAE88AAEAAAAF9AAA          3          0

SQL> SELECT rowid, n1, n2 FROM t PARTITION (one);

no rows selected

The previous test was successful. Now, let me show you a situation that leads to wrong results :-(

To reproduce the bug I basically execute the same operations as before. The only difference is that seven columns are added before the columns n1 and n2 in the table. Hence, the test table is recreated with the following statements:

SQL> DROP TABLE t PURGE;

SQL> CREATE TABLE t (
  2    d1 NUMBER,
  3    d2 NUMBER,
  4    d3 NUMBER,
  5    d4 NUMBER,
  6    d5 NUMBER,
  7    d6 NUMBER,
  8    d7 NUMBER,
  9    n1 NUMBER,
 10    n2 AS (CASE n1 WHEN 1 THEN 1 WHEN 2 THEN 2 ELSE 0 END) VIRTUAL
 11  )
 12  PARTITION BY LIST (n2) (
 13    PARTITION zero VALUES (0),
 14    PARTITION one VALUES (1),
 15    PARTITION two VALUES (2)
 16  )
 17  ENABLE ROW MOVEMENT;

SQL> INSERT INTO t (n1) VALUES (1);

SQL> COMMIT;

SQL> execute dbms_stats.gather_table_stats(user,'t')

As before, I update the row to cause the movement and display the content of the two involved partitions before and after doing it.

SQL> SELECT rowid, n1, n2 FROM t PARTITION (zero);

no rows selected

SQL> SELECT rowid, n1, n2 FROM t PARTITION (one);

ROWID                      N1         N2
------------------ ---------- ----------
AAAE9BAAEAAAAGNAAA          1          1

SQL> UPDATE t SET n1 = 3;

SQL> COMMIT;

SQL> SELECT rowid, n1, n2 FROM t PARTITION (zero);

no rows selected

SQL> SELECT rowid, n1, n2 FROM t PARTITION (one);

ROWID                      N1         N2
------------------ ---------- ----------
AAAE9BAAEAAAAGNAAA          3          0

As you can see, the two queries after the update statement return wrong results. Also the rowid is the same. Hence, row movement was not performed. It goes without saying that also other queries might return wrong results. An example is the following:

SQL> SELECT rowid, n1, n2 FROM t WHERE n2 = 1;

ROWID                      N1         N2
------------------ ---------- ----------
AAAE9BAAEAAAAGNAAA          3          0

By playing around with the number of columns and position of the columns n1 and n2, I found out that depending on the situation you might have correct results or wrong results.

Since I was able to reproduce the problem with several databases (both 11.1.0.6 and 11.1.0.7), last Friday I opened a service request. Now the issue is tracked as bug# 8258501.

Today I tried to install Oracle AD4J on a Linux server that I have at home. The installation procedure is really simple and fully described here. Unfortunately, when I tried to access the console for the first time (that access is one of the installation steps), the HTTP server returned an internal server error (500). In the mod_jserv.log logfile I found the following error messages:

[13/02/2009 10:06:38:079] (EMERGENCY) ajp12: can not connect to host 127.0.0.1:3501
[13/02/2009 10:06:38:181] (EMERGENCY) ajp12: connection fail
[13/02/2009 10:06:38:181] (ERROR) an error returned handling request via protocol "ajpv12"

Mhmm… a listener should be available on port 3501. But, no such listener was available on my system (note that port 3500 is used for the HTTP listener):

oracle@helicon:/u00/app/oracle/product/ad4j/ [rdbms11107] netstat -l --numeric-ports | grep 350[01]
tcp        0      0 *:3500                      *:*                         LISTEN

A quick search in Metalink revealed that at least another person has hit the same issue few days ago (see bug# 8235076). Since OSS is still working on it, I’ll wait to see what the findings are. In the mean time, I was able to successfully install it on my Windows laptop.

Anyway, if somebody of you managed to successfully install AD4J on Linux, please, let me know!

ADDENDA (February 16th, 2009): Because of the comments of Charles and Michael I spent a bit more time looking at the problem. In fact, the first time I stopped immediately after seeing the bug in Metalink… I was lazy ;-). Hey, I try to optimize my worktime as well. Anyway, both suggested to manually start jserv. When I tried to do so, I received an error (at last). Based on it the problem was self explanatory! The java environment was causing the problem… In fact, with the default installation of CentOS 4.4 only the package java-1.4.2-gcj-compat was installed. After downloading and installing the most recent version of HotSpot (build 1.6.0_12-b04) the problem was solved.

In this post I would like to remove some misinformation about the utilization of hints with invisible indexes.

Let’s start by providing you what two sources say about that topic:

• Oracle Database 11g: New Features for DBAs and Developers (by Sam R. Alapati and Charles Kim, page 132)
  “If you want the optimizer to take the invisible index into account, you must use the index hint, as shown in the following example:“

• Oracle Database 11g: The Top New Features for DBAs and Developers – Schema Management (by Arup Nanda)
  “To make the optimizer use the index again, you have to explicitly name the index in a hint:”

Both sources point out that a hint can be used to compel the query optimizer to use an invisible index. Both also provide an example (not shown here). But, what is more important, both are wrong! In other words, a hint cannot be used to compel the query optimizer to use an invisible index.

What’s going on?!?

The problem is that this specific information used to be correct for the beta release of Oracle Database 11g. But that behavior was a bug, not a feature! Therefore, once the bug was fixed, this piece of information was no longer valid.

This is what happens when authors use beta releases for doing their tests…