Oracloid Blog

I’m trying to make this blog from my Blackberry. I’m a little slow and I’d rather focus on the excellent presentations of the subject conference so I’ll try to make it short.

Yesterday was the opening and I should say it was great — nice tour on the Whiskey Heritage Center and couple interesting and humorous sessions delivered by Jonathan Lewis and Graham Wood combined with whiskey tasting. The evening obviously continued after that but you can assume that anyway if you know what I’m talking about.

Finally, today… The day started badly - I had to wake up at 2am Ottawa time just to figure out that I’m sleeping on the floor of smoking room and that I forgot my hygienic stuff at Doug’s house yesterday. Why on the floor you ask? No worries, I wasn’t so drunk yesterday to collapse somewhere. The problem is that my hotel reservations was canceled — apparently it was booked one day earlier than I expected — stupid me didn’t check the reservation. But the funny thing is that it was canceled due to “no show”. So I should be quite happy to be able to sleep at least somewhere.

Obviously, I was late for the first presentation which, by the way, was a masterpiece from Doug Burns about DTrace. The next presentation was from Carel-Jan, Mr. Standby, about, well, standby. Unfortunately, I’ve been a little busy with some conference logistics and instead had to enjoy a walk through the Castle in “beautiful” Scotish weather.

The third presentation was mine. The first 5 minutes were probably the best because Doug stole them from my time to present yet another award to Mr. CBO, Jonathan Lewis. Since Doug started talking, I had to remind him about the boys and couple of them did make it out of the box — my favorite one and one Canadian. ;-)

That’s all folks. For now… Stay tuned — more to come!

You are following the blog than you might recall that I’m going to make a presentation on the Miracle Scotland Database Forum 2007. My presentation is called RAC load testing adventures and it’s based on a project I’ve been through with one of our clients.

Courtesy of my good mate, Doug Burns, I arrived a little earlier - yesterday. Instead of getting Doug to pick me up we agreed that I just take a bus to the city center instead of splitting his day into two small parts.
When I was boarding the bus a bagpiper was playing next to it I really felt like I was in Scotland:

(more…)

With this post, I’m starting a series about Oracle Block Change Tracking internals. The feature was introduced in Oracle 10 Release 1. I have already published my past presentations and the white paper about that, so what pushed me to get back to this topic again? A few things:

• During my presentations, the audience wasn’t always able to absorb all the information. Reading the white paper later requires quite a bit of dedication and focus to go through many pages of in-depth details. Reading small blog posts is easier and it allows the reader go through the material slowly.
• I would like to share how I came up with the details and what research methods I used.
• The research is not over, so I would like to continue it here and, perhaps, someone will be interested enough to join the club.

When I first started, I tried to dig at least something from Metalink, but the public notes contained no implementation details. What I extracted is some pieces of bug texts, and from there I concluded that fixed tables starting with X$KRC are most probably related to the BCT feature. I quickly extracted all X$KRC tables:

SQL> select name from V$FIXED_TABLE where name like 'X$KRC%';

NAME
------------------------------
X$KRCFH
X$KRCEXT
X$KRCCDE
X$KRCCDS
X$KRCCDR
X$KRCGFE
X$KRCFDE
X$KRCFBH
X$KRCBIT
X$KRCSTAT                      

10 rows selected

I tried to watch them closely and see how they evolve, but it was too difficult to see the trend. So, I decided to create a kind of Statspack for X$KRC tables, a.k.a. X$KRC “Snappack”.

(more…)

One of our clients had an ORA-1555 “snapshot too old” error two nights in a row. The quick and dirty fix would be to increase the retention_period and the potential size of the UNDO tablespace.

I was looking at it together with Dave, my new team mate, and a small detail popped up right away — Query Duration=76584 — 21+ hours? I checked the retention period, and it was 2 hours, so the dirty fix would probably fail unless it’s very dirty — dumping undo retention to something like a day and blowing the UNDO tablespace, and still without guarantee that the query finish within a day. (In fact, I rather think that it would run for 42 hours. But I digress.)

The query was simple (names obscured):

SELECT *
FROM   TABLE1
WHERE
       (COL_DATE >=
                (SELECT MAX(COL_DATE)
                   FROM TABLE2
                  WHERE FILTER_COL = :"SYS_B_0")
                );

Table1 has millions of rows, so my first reaction was to check if there are histograms on this column, whether it has an index on it, and when statistics were last collected. There were no index and no histograms, so the execution plan couldn’t be any different than a full table scan. In this case, the query shouldn’t really be running for longer than 21 hours.

We couldn’t easily get the client’s developer’s advice on which batch this statement belongs to, but it definitely was a batch and seems to be regular. So, assuming that the duration is correct, the query was supposed to be running right at that moment. I checked the V$SESSION with STATUS='ACTIVE' OR LAST_ET_CALL > 3600 — nothing back. Dave recalled that there was a bug related to the reported duration of queries reported within ORA-1555 error and in view V$UNDOSTAT. Fair enough — we located the Metalink Note and used another query with a workaround giving the same result.

Next step was to look at V$SQL and see if the query was still there and running. And, bingo! there it was! V$SQL provided the hash value and V$SESSION.SQL_HASH_VALUE showed the guilty session with status ‘INACTIVE’ and LAST_CALL_ET in the range of a few minutes. A quick peek into V$SESSION_WAIT showed that the session was waiting on SQL*Net message from client for several minutes. I was already 99% sure what was going on, and I just needed a few minutes to prove it with a 10046 trace, so we enabled 10046 event with level 8. The content of the trace file speaks for itself:

*** 2007-05-15 09:33:12.418
WAIT #1: nam='SQL*Net message from client' ela= 256877226 p1=1413697536 p2=1 p3=0
WAIT #1: nam='db file scattered read' ela= 8144 p1=12 p2=39721 p3=12
WAIT #1: nam='SQL*Net message to client' ela= 4 p1=1413697536 p2=1 p3=0
WAIT #1: nam='SQL*Net more data to client' ela= 175 p1=1413697536 p2=2001 p3=0
FETCH #1:c=0,e=10805,p=12,cr=4,cu=0,mis=0,r=100,dep=0,og=4,tim=6190387721660
*** 2007-05-15 09:37:34.942
WAIT #1: nam='SQL*Net message from client' ela= 256356355 p1=1413697536 p2=1 p3=0
WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1413697536 p2=1 p3=0
WAIT #1: nam='SQL*Net more data to client' ela= 156 p1=1413697536 p2=2001 p3=0
FETCH #1:c=0,e=1462,p=0,cr=2,cu=0,mis=0,r=100,dep=0,og=4,tim=6190644080126

So the query was not actively kicking and this is why we didn’t catch it in the beginning. I should also mention that the program (as indicated in V$SESSION) was DTSRun.exe, so it seems that the culprit is some kind of data-extraction job that fetches 100 rows and processes them for 256 seconds before going for another fetch. Well, what would you expect from a Microsoft tool? ;-)

Anyway, since DTS is not our responsibility, we had to hand this issue to the relevant group with the definitive diagnosis, “It’s not a database problem.”