Production Call-out

On Saturday morning, we ran into a problem on one of our 9.2.0.7 Production databases during an Extract, Transform and Load (ETL) batch process.

I was called at 5:15am to look at a job that normally runs in a few minutes but had failed after 30 or 40 minutes when trying to allocate an extent in a TEMP tablespace. Application Support and the Operators were keen for me to add space to the TEMP tablespace so that the job could run through to completion because there were hundreds of dependant jobs still to run. When you're providing on-call Production support there's a balance between getting things moving again and analysing the problem properly. In this case it looked like a simple space problem.

So I added 10Gb to the existing 10Gb TEMP tablespace, we re-ran the job and it fell over again after another 40 minutes (maybe longer). At this point I wanted to analyse the problem properly because it was clear that the job was doing something completely different to previous runs but I was (slightly) over-ruled. We came to an agreement that we would add 20Gb, run it one more time, but that I would check what the job was doing while it was running.

Looking at the execution plan (extracted from V$SQL_PLAN), there was a MERGE JOIN CARTESIAN step in there. Nothing wrong with that per se, but it looked like it was choosing it for a table with an extremely small number of rows - 1. I investigated the stats in DBA_TABLES and it turned out that NUM_ROWS for one of the tables was zero, but a quick count showed that there were over a quarter of a million rows in the table. What had happened was that the ETL process truncates tables before populating them with data. Normally it should run long before the statistics are gathered but it's been running later and later each night and eventually the two jobs were running at the same time. When dbms_stats looked at that table, it happened to be empty. The stats were an accurate reflection of an unusual mid-process state and the optimiser was picking a sensible plan for a tiny table

Looking back, I think this is the most common major problem I've seen with stats at site after site - the optimiser thinking a table has zero rows because the stats have not been generated since the table was populated. It leads to some bizarre execution plans.

I regenerated the stats on that table and the job ran in 3 or 4 minutes without using any temp space to speak of. Of course, the Operations report still described it as a space problem, but I had that modified later.

The proper solution will include

1) Configuring the correct dependencies between the ETL process and the stats collection.

2) Dropping the tempfiles I added (done)

3) Keeping a history of CBO statistics. This wouldn't have prevented the problem happening but would have made it a little easier to diagnose and much easier to fix, by importing yesterday's statistics. I'm in the process of implementing this at work, so will probably blog about that later.