METHOD_OPT of NULL

This is the start of a series of MEEK (maybe everyone else knows) posts as I seem to keep running into things about Oracle that I feel I should have known.

Until very recently I did not know what using METHOD_OPT => NULL in a DBMS_STATS call does. If you do then stop reading here :-)

Creation of a test table…

MNASH@orcl> create table t as select * from dba_objects;

Table created.

MNASH@orcl> select count(*) from t;

  COUNT(*)
----------
     72563

MNASH@orcl> select table_name, num_rows from user_tables where table_name = 'T';

TABLE_NAME   NUM_ROWS
---------- ----------
T

MNASH@orcl> select table_name, column_name, num_distinct from user_tab_columns where table_name = 'T';

TABLE_NAME COLUMN_NAME                    NUM_DISTINCT
---------- ------------------------------ ------------
T          OWNER
T          OBJECT_NAME
T          SUBOBJECT_NAME
T          OBJECT_ID
T          DATA_OBJECT_ID
T          OBJECT_TYPE
T          CREATED
T          LAST_DDL_TIME
T          TIMESTAMP
T          STATUS
T          TEMPORARY
T          GENERATED
T          SECONDARY
T          NAMESPACE
T          EDITION_NAME

15 rows selected.

MNASH@orcl>

Gathering statistics using DBMS_STATS.GATHER_TABLE_STATS with METHOD_OPT => NULL

MNASH@orcl> exec dbms_stats.gather_table_stats(null,'T',method_opt=>null)

PL/SQL procedure successfully completed.

MNASH@orcl> select table_name, num_rows from user_tables where table_name = 'T';

TABLE_NAME   NUM_ROWS
---------- ----------
T               72563

MNASH@orcl> select table_name, column_name, num_distinct from user_tab_columns where table_name = 'T';

TABLE_NAME COLUMN_NAME                    NUM_DISTINCT
---------- ------------------------------ ------------
T          OWNER
T          OBJECT_NAME
T          SUBOBJECT_NAME
T          OBJECT_ID
T          DATA_OBJECT_ID
T          OBJECT_TYPE
T          CREATED
T          LAST_DDL_TIME
T          TIMESTAMP
T          STATUS
T          TEMPORARY
T          GENERATED
T          SECONDARY
T          NAMESPACE
T          EDITION_NAME

15 rows selected.

MNASH@orcl>

Statistics are gathered for the table, but not for the columns of the table.

I found out about this through a friend after puzzling over how some of the tables in a database had statistics at a table level, but none for the columns.

Just for completeness, the following shows what happens when METHOD_OPT is allowed to default:

MNASH@orcl> exec dbms_stats.gather_table_stats(null,'T')

PL/SQL procedure successfully completed.

MNASH@orcl> select table_name, num_rows from user_tables where table_name = 'T';

TABLE_NAME   NUM_ROWS
---------- ----------
T               72563

MNASH@orcl> select table_name, column_name, num_distinct from user_tab_columns where table_name = 'T';

TABLE_NAME COLUMN_NAME                    NUM_DISTINCT
---------- ------------------------------ ------------
T          OWNER                                    32
T          OBJECT_NAME                           43784
T          SUBOBJECT_NAME                          108
T          OBJECT_ID                             72563
T          DATA_OBJECT_ID                         7705
T          OBJECT_TYPE                              44
T          CREATED                                1174
T          LAST_DDL_TIME                          1272
T          TIMESTAMP                              1318
T          STATUS                                    1
T          TEMPORARY                                 2
T          GENERATED                                 2
T          SECONDARY                                 2
T          NAMESPACE                                21
T          EDITION_NAME                              0

15 rows selected.

MNASH@orcl>

Whether or not you want to use the default, which is to allow Oracle to create histograms as it sees appropriate, is a separate point which has received plenty of attention elsewhere.

In the case I was looking into there was actually a bug in the code used as a wrapper to DBMS_STATS and it was not intended that no column statistics were gathered, but I started to wonder if there would be a situation where using this undocumented option would be attractive. I did some fairly simple testing to establish the overhead of collecting column statistics…

The test was:

1 – Increase the number of rows in table T to around 1 million
2 – Delete table statistics for table T
3 – Flush the buffer cache
4 – Gather table statistics using compute with method_opt => null
5 – Repeat (2) to (4) 5 times
6 – Delete table statistics for table T
7 – Flush the buffer cache
8 – Gather table statistics using compute with method_opt => ‘for all columns size 1′
9 – Repeat (6) to (8) 5 times

Looking at the elapsed time for the statistics gathering I got averages of:

null: 2.3 seconds
for all columns size 1: 14.5 seconds

That’s a pretty big overhead, but a lot of information you are robbing the CBO of if you don’t gather them!

I then ran the same test, but with AUTO_SAMPLE_SIZE as this is a more realistic case and got averages of:

null: 1.5 seconds
for all columns size 1: 3.4 seconds

Note: The tests were performed on a 11.2.0.1 database.


TO_CHAR or NOT TO_CHAR

Another post where I probably show trivial things. This issue is very easy to diagnose and fix but quite complicate to prevent.
I’ll start from my personal statistics of performance analyses during development. From my point of view there are 5 levels of SQL tuning that are using in code development. I try to present percent of queries that tuned by each of them.

N Method % of statement tested
1 No test. Rely on optimizer and experience. 50
2 Execute on developer database. 25
3 Execute on a database with real size data. 15
4 Execute on database with real size data and analyse the execution plan. 10
5 Execute on database with real size data and analyse the execution plan and predicates. 0.0000001

It shows that usually we usually start intensively tune queries only when it does not work on a real production or preproduction stage. It have sense but some hidden rocks can and should be diagnosed during using the first level of tuning. Based on my own experience the own expertise can be easily overestimated. Before I start this post I query some my friends and no one was aware this oracle trick, thus I believe that it would be useful for general audience too.
Will you check the predicates if the access method is expected and use the correct index. Probably not but oracle loves to make surprises. In our case it was surprise with concatenated indexes and implicit conversion.
I’ll try to show the case using the example

--Create sample table
CREATE TABLE eterpani.TESTTABLE
   (    COL1 NUMBER(10,0) DEFAULT (0) NOT NULL ENABLE,
        ID NUMBER(10,0) NOT NULL ENABLE,
        PARTITIONKEY CHAR(1) NOT NULL ENABLE,
        COL2 NUMBER(10,0),
        COL3 VARCHAR2(6 CHAR) NOT NULL ENABLE,
        COL4 DATE NOT NULL ENABLE,
        COL5 VARCHAR2(3 CHAR) NOT NULL ENABLE,
        AMOUNT NUMBER(16,3) DEFAULT (0) NOT NULL ENABLE,
         CONSTRAINT TESTTABLE_PK PRIMARY KEY (ID,PARTITIONKEY) USING INDEX )
/
--Put concatenated index on it where col2 column is in the middle
CREATE INDEX eterpani.TESTTABLE_IDX1 ON eterpani.TESTTABLE
   (PARTITIONKEY,  COL4, COL5, COL2, COL3)
/
--Populate table by some data
INSERT INTO eterpani.TESTTABLE
SELECT COL1, ID, PARTITIONKEY, COL2, COL3, COL4,COL5,AMOUNT FROM dual
   MODEL DIMENSION by (65 i)
   MEASURES (0 COL1,
             0 ID,
             CAST(' ' as CHAR(1)) PARTITIONKEY,
             0 COL2,
             CAST(' ' as CHAR(25)) COL3,
             sysdate COL4,
             CAST(' ' as CHAR(3)) COL5,
             0 AMOUNT)
     (col1[for i from 1 to 100000 increment 1] = ROUND(DBMS_RANDOM.VALUE(100,150)),
      ID[for i from 1 to 100000 increment 1] = cv(i),
      PARTITIONKEY[for i from 1 to 100000 increment 1] = CHR(65+MOD(cv(i),26)),
      col2[for i from 1 to 100000 increment 1] = ROUND(DBMS_RANDOM.VALUE(10,12)),
      col3[for i from 1 to 100000 increment 1] = PARTITIONKEY[cv(i)]||DBMS_RANDOM.STRING('U',5),
      col4[for i from 1 to 100000 increment 1] = TRUNC(SYSDATE)+ROUND(DBMS_RANDOM.VALUE(-5,5)),
      col5[for i from 1 to 100000 increment 1] = TO_CHAR(ROUND(DBMS_RANDOM.VALUE(10,999))),
      AMOUNT[for i from 1 to 100000 increment 1] = ROUND(DBMS_RANDOM.VALUE(100,1000)))
/
COMMIT
/

The preparation steps are over. Lets run the query.

Set autotrace on
SELECT PARTITIONKEY, COL4, COL3, COL2, COL5, SUM(AMOUNT) SUMAMOUNT
FROM eterpani.TESTTABLE
WHERE PARTITIONKEY = 'C' AND COL3='COWRTE'
     AND COL4 = TRUNC(SYSDATE) AND COL2 = 11
     AND COL5 = 901 AND COL1=131
GROUP BY PARTITIONKEY,  COL4, COL5, COL2, COL3;

Let’s look on execution plan

Execution Plan
----------------------------------------------------------
Plan hash value: 3717891987

-------------------------------------------------------------------------------------------
|Id| Operation                   | Name           | Rows  | Bytes | Cost (%CPU)|  Time    |
-------------------------------------------------------------------------------------------
| 0|SELECT STATEMENT             |                |   1   |  59   |  4   (0)   | 00:00:01 |
| 1| SORT GROUP BY NOSORT        |                |   1   |  59   |  4   (0)   | 00:00:01 |
|*2|  TABLE ACCESS BY INDEX ROWID| TESTTABLE      |   1   |  59   |  4   (0)   | 00:00:01 |
|*3|   INDEX RANGE SCAN          | TESTTABLE_IDX1 |   1   |       |  4   (0)   | 00:00:01 |

If someone had showed me this execution plan few months ago I would have said that it is the good one without any doubts. But let me make a small changes in a query – put explicit conversion to COL5 predicate.

Set autotrace on
SELECT PARTITIONKEY, MAX(COL1), COL4, COL3, COL2, COL5, SUM(AMOUNT) SUMAMOUNT
FROM eterpani.TESTTABLE
WHERE PARTITIONKEY = 'C' AND COL3='COWRTE'
     AND COL4 = TRUNC(SYSDATE)  AND COL2 = 11
     AND COL5 = TO_CHAR(901) AND COL1=131
GROUP BY PARTITIONKEY,  COL4, COL5, COL2, COL3;

As result we have the same execution plan. Even the “Plan hash value” is the same. At this stage you can say no difference no reasons to bother. But difference exists. Firstly pay attention to the bottom part of the autotrace output

Without TO_CHAR Statistics
———————————————————-
0 recursive calls
0 db block gets
9 consistent gets
0 physical reads
0 redo size
675 bytes sent via SQL*Net to client
513 bytes received via SQL*Net from client
1 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
0 rows processed
With TO_CHAR Statistics
———————————————————-
0 recursive calls
0 db block gets
3 consistent gets
0 physical reads
0 redo size
746 bytes sent via SQL*Net to client
513 bytes received via SQL*Net from client
1 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
0 rows processed

Does the triple number of read blocks confuse you? The answer on this confusion is in the middle part of autotrace output

Without TO_CHAR Predicate Information (identified by operation id):
—————————————————

2 – filter(“COL1″=131)
3 – access(“PARTITIONKEY”=’C’ AND “COL4″=TRUNC(SYSDATE@!) AND “COL2″=11 AND “COL3″=’COWRTE’)
filter(“COL3″=’COWRTE’ AND “COL2″=11 AND TO_NUMBER(“COL5″)=901)

With TO_CHAR Predicate Information (identified by operation id):
—————————————————

2 – filter(“COL1″=131)
3 – access(“PARTITIONKEY”=’C’ AND “COL4″=TRUNC(SYSDATE@!) AND “COL5″=’901′ AND “COL2″=11 AND “COL3″=’COWRTE’)

As you understand the most selective predicate in this query is “COL3=’COW131’”. This predicate use indexed column and mentioned in corresponding section thus everything should be easy and strait forward. But there is one small difference. Oracle implicitly convert all values in COL5 to number. Why Oracle is doing it gods know. But it prevent usage of COL5 in access path. Even without explicit conversion we still use the index but read more blocks.
I have tried to describe this difference in reading on a picture
index block reading schema
All index blocks with the same PARTITIONKEY and COL4 values would be reviewed in a process of searching the relevant records. It is just index blocks reading but it is additional read operation that can dramatically increase the time query depending on cardinality of COL5. Moreover we have extra CPU waste. Instead of one conversion operation from constant to char we convert each single COL5 value to number. Believe me it is not we all expected on our databases.
There are two conclusions on above information:
firstly – be careful when looking on execution plan, check not only plan but predicates and other bits and pieces
Secondly – implicit thing have tendency to work unpredictably. Convert explicitly where you can.
Usefull doc: ORA-01722: Invalid Number; Implicit Conversion Not Working Correctly [ID 743595.1]


America’s Cup World Series kick-off in Cascais

At portrix, we share a passion for sports and being from Hamburg, sailing of course has a top spot on our list. I have been following the America’s Cup roughly from 2007 when Team Oracle and Larry Ellison showed great spirit and commitment to winning this cup but were defeated early in the qualifying races.
In 2010, we set the race broadcast up in our meeting room and were blown away by the power, speed and precision of the winged trimaran USA-17. But the races itself were rather boring and could not live up to our expectations. The starts were postponed again and again due to changes in wind conditions and once the boats were underway, there were only few maneuvers and certainly no close racing. The trimaran was much faster and sailed much smoother than Alinghi’s catamaran, so spectators were left with beautiful pictures of a race that was dominated by Team Oracle.

Oracle Racing SpithillAfter winning the old mug, it was up to the Golden Gate Yacht Club and Larry Ellison to come up with new rules and a new concept for America’s Cup sailing to bring the excitement back. The next cup will take place in 2013 in San Francisco on 72-foot wing-sailed catamarans and the challenger will be determined in the Louis Vuitton Cup. Until then nine teams are touring around the world in what is called the America’s Cup World Series, racing with winged 45-feet catamarans to get accustomed to a new style of racing

Fortunately, Knud and I had the chance to visit the first stop of the brand new America’s Cup World Series so we could see and experience all of these changes ourselves. First of all, the boats may look like small versions of the trimaran but they are still huge and the wings make them look very unique. I was already able to spot the race course from the plane on the approach to Lisbon. One of the main goals that Larry had in mind was to make the sport more appealing to spectators. They moved the race course very close to shore so that all events could easily be followed from the beaches, piers and streets of Cascais. We set up at our hotel’s pool with a laptop so we could also follow the excellent live stream online. While GPS maps have been standard in sailing races for a while now, there were cameras everywhere. On the boats, on other boats and on three helicopters. The sailors were equipped with microphones to provide live audio of on-board communications including swearing.

I was very impressed by the professionalism and dedication of Team Oracle and the organizers of the cup. It became clear in every detail of the event that these guys are serious about changing the style of Cup Racing to make it more exciting, televisable, accessible to a wider audience and bring together the fastest boats and best sailors. Experiencing this drive for excellence is fascinating and provides an insight into the mentality that led to not only domination in sailing but the database world aswell. Rest assured: If Larry has a vision, he will commit to get it right.

And in my opinion, it all paid out. The whole event is packed with fun and excitement and so were the races. There were lots of lead changes and close calls, tight maneuvers and passionate sailors that pushed their boats to the edge.

The official website has a ton of information and breathtaking video coverage. Check it out! Go to any of the upcoming venues, follow the races from the beach, boats or bars. It will be worth your time and there is also a lot going on on shore. You can get really close to the team bases and admire the technology and watch the teams prepare. The race is broadcast to a huge stage and screen which hosts DJs and live music at night.

Fake lack of TimeZones in DBMS_JOBs

Reading about others mistakes is great fun, but everyone believes that he will not make such stupid mistakes. My personal attitude is a bit different – If someone has done such mistake, it can be repeated by another man. We are living in the world without unique things either good or bad.
Today I’ll speak about DBMS_JOBs and TIMEZONEs. The issue that I got was looking very odd thus I want to present it hear.
I have discovered it when I run the dbms_jobs. The job successfully posted into DBA_JOBS but launch postponed for one hour in comparison to the time form NEXT_DATE. Moreover this problem appeared to be only on one node.
To reproduce the case I have chosen the very simple job:

declare
    job_id pls_integer;
  begin
    sys.dbms_job.submit(job =>  job_id,
                         what => 'begin null; end;', -- fake job pl/sql block
                         next_date => sysdate, -- start immediately
                         interval => 'sysdate+1', -- next start next day
                         instance => 1); -- RAC instance that I am going to use
    commit;
end;
/

I have run the same queries for the first and for the second nodes. As result of these scripts I got the following output (the query can be launched on any RAC node). To make it more clear I have add “SYSDATE” column to the DBMS_JOBS view.

> select JOB, WHAT, BROKEN, LAST_DATE, NEXT_DATE, INSTANCE, SYSDATE from DBA_JOBS;
JOB  WHAT                 B LAST_DATE            NEXT_DATE              INSTANCE SYSDATE
---- -------------------- - -------------------- ---------------------- -------- --------------------
   1 begin null; end;     N                      26 Jul 10:13:18               1 26 Jul 10:21:36
   2 begin null; end;     N 26 Jul 10:18:14      27 Jul 10:18:14               2 26 Jul 10:21:36

The job on the first node does not run even when sysdate is after next_date. All general checks like job_queue_processes and broken jobs do not explain the situation.
After one hour when I starring on the screen the content of DBA_JOBS changed to

> select JOB, WHAT, BROKEN, LAST_DATE, NEXT_DATE, INSTANCE, SYSDATE from DBA_JOBS;
JOB  WHAT                 B LAST_DATE            NEXT_DATE              INSTANCE SYSDATE
---- -------------------- - -------------------- ---------------------- -------- --------------------
   1 begin null; end;     N 26 Jul 10:13:20      27 Jul 10:13:18               1 26 Jul 11:15:23
   2 begin null; end;     N 26 Jul 10:18:14      27 Jul 10:18:14               2 26 Jul 11:15:23

Aha! The CJQ process run as expected but just believes that the time is different from what I see. According to documentation DBMS_JOB uses the “date” data type to store the start date/time and does not store/use time zone related information. JOBS who are scheduled are always executed when sysdate => next execution time. But this information contradicts with data that I see.
I struggle with this puzzle until find out that in UNIX each process have separate time zone. And can be easily managed by environment variable TZ.

> export TZ=Europe/London
>  echo $TZ
Europe/London
> date
Tue Jul 26 12:12:25 GMT+01:00 2011
> export TZ=GMT-1:30
>  echo $TZ
GMT-1:30
> date
Tue Jul 26 12:42:04 GMT 2011

Back to oracle side of the process. What is sysdate – sysdate is oracle function that simply queries the OS time of the day. The result looks like independent of any oracle time zone information but
the OS TZ environment variable influences the time that the OS will pass on to Oracle. The process time zone is defined at process start time.
Thus my first attempt to sort it out was to restart coordinator CJQ process.

>alter system job_queue_processes=0 scope=memory sid='db1';
System altered.
-- wait for a minute
>alter system job_queue_processes=100 scope=memory sid='db1';
System altered.
> host ps -ef | grep cjq
  oracle 31653974        1   0 12:46:59      -  0:00 ora_cjq0_db1

The CJQ process was restarted without any gains. It looks like the oracle core respawns it with the same TZ as the PMON. But after restarting the instance from UNIX session with the right TZ environment variable the issue has been fixed. The conclusion is common – be careful and life would be easier.

Useful Note: DBMS_SCHEDULER or DBMS_JOB And DST / Timezones Explained. [ID 467722.1]
Troubleshooting DBMS_SCHEDULER and DBMS_JOB [ID 783357.1]


Diagnosing “random” connection resets in 11g

This was a pretty weird problem I have dealt with in the past few days. We migrated a database system from 10g to 11g a while back and almost everything worked just fine. Of course, we also rolled out new clients to the app servers and things pretty much worked. But occasionally, servers would get a “Connection reset” error/exception when trying to connect. All information we had on this issue was the stacktrace from the driver which really does not tell you a whole lot.

Caused by: java.net.SocketException: Connection reset
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:96)
at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
at oracle.net.ns.DataPacket.send(DataPacket.java:219)
at oracle.net.ns.NetOutputStream.flush(NetOutputStream.java:208)
at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:224)
at oracle.net.ns.NetInputStream.read(NetInputStream.java:172)
at oracle.net.ns.NetInputStream.read(NetInputStream.java:97)
at oracle.net.ns.NetInputStream.read(NetInputStream.java:82)

So eventually, this landed on my desk and we checked the sqlnet logfiles and settings but things looked good there. We also checked network settings and statistics in the OS but things looked good there aswell. I would have liked to blame this on the networking guys but all systems are on the same subnet so this could not be an issue with a firewall or router.

So in all my desperation I asked the mighty google machine which came up with this OTN forum thread which suggested that this could be related to the implementation of random number generation on linux systems.

At some point during the connection establishment, the driver requires some random numbers which by default are generated by /dev/random on linux systems. But this pseudo-device blocks when there is not enough entropy in the system to ensure “real randomness”. Entropy is generated by mouse and keyboard input aswell as some network drivers. It looks like our machines in trouble were not generating entropy fast enough as they needed to at some points and this caused the jdbc driver to fail connecting. Anyway, the suggested workaround of setting the default source of randomness to the non-blocking /dev/urandom helped.

There is also a quite well hidden metalink note on this which also links to this really good blog article.

I remember that this has bitten me in the ass before about 10 years ago where an SSL-enabled apache webserver refused to start under certain conditions. Our first workaround was to send someone to go to the box and move the mouse or type stuff on the keyboard…

Speaking at UKOUG in Birmingham

This year’s event calender is quickly filling up with my presentation “Setting up RAC for planned downtime” being accepted at the UK’s user group conference in December. I have not been to this conference before and am thrilled to finally check out Europe’s largest english speaking Oracle event. I have heard only good things about this event and I am sure that there will be lots of smart, nice and interesting people to meet and exchange ideas with.

This might also be a good chance to get together with other RAC SIG members from the UK and Europe. Let me know if you are interested in setting something up.