Delete vs. Truncate - graphically

This is too funny to not share. Of course, everyone knows that a truncate is much more efficient than a full table delete. On my system, still suffering from a slow log writer, but absolutely quiet at the moment, I ran an insert of a million rows (ctas from tbl1 to tbl2), a delete of those million rows (from tbl2) , and then a truncate of them (from tbl1). I looked over at Enterprise Manager and this is what I saw: (I added the tags for benefit of blog readers)















I had not been expecting such a graphical re-enforcement of the rule. I had found the full table delete in some executing code and was curious how much redo it was generating. I ran René Nyffenegger's script 'how_much_redo' .
Assuming that it is giving accurate results, here is what I got for the 3 operations.

SQL> INSERT INTO T1_DEL (SELECT * FROM T1);

1161874 rows created.

SQL> exec how_much_redo;
New Redo Bytes Written: 408985600 (390 MB of redo TO INSERT)


SQL> delete from T1_DEL;

1161874 rows deleted.

Elapsed: 00:06:30.90 (6 MINUTES TO DELETE)
New Redo Bytes Written: 661496320 (630 MB of redo TO DELETE)



SQL> truncate table T1;

Table truncated.

Elapsed: 00:00:06.80 (6 SECONDS TO TRUNCATE)
New Redo Bytes Written: 815616 (less than 1Mb of redo to TRUNCATE)

Lazy Log Writer - The non Resolution

OK, after the huge emergency, "You can't attend the last day of open world because our problems are too big." After my debugging efforts, how did the problem of the slow writes to the redo log files resolve?

1. Management asked that the entire database be moved to the NAS disks because they initially seemed faster. I had to let them know, that, no, the writes there are not faster.

2. The efforts to cross the great divide and get the storage manager in the other company to actually look at his configuration resulted in, "Since the writes are slow on two different pieces of our machinery, it can't be our fault - it must be oracle. I'm debugging nothing."

3. The other company informed us, "By the way, we will be installing new hardware in a couple of weeks at the same time that you are making a major application upgrade." How does that sound for a prospect of a smooth transition? This was followed by an email, "Claudia, are you working with the other company on this?" Not only am I not working with them, I never heard of it!

4. Management informed me, "Since there will be a hardware change soon, don't bother to follow up on this problem."

So they will install the hardware, we will deploy the new application version, and there will be storm and drama about the excessive waits for redo log writes. I think that I should change my name to Cassandra.

A lazy log writer

I've been laughing because I live 1 block from Moscone Center. It was closer for me to walk between the conference and my house than it was to walk between some of the sessions. Today, I saw the other side of that coin. I got ordered back to work and missed the last day of the conference, (and Chen Shapira's presentation!!!)

What was going on at work? Not much - as in not what should have been. I like looking at the performance monitor on Enterprise Manager for a quick glance at what is going on. It wasn't a pretty picture.



Clicking on the 'Blocking Sessions' tab I saw that that the log writer session was blocking various other sessions.

I went into the alert log and was pointed to a log writer trace file. Inside the trace file I found

*** 2008-09-25 15:28:24.239
Warning: log write time 15460ms, size 6999KB

*** 2008-09-25 15:28:24.836
Warning: log write time 590ms, size 6898KB

*** 2008-09-25 15:28:29.852
Warning: log write time 5020ms, size 6999KB

I looked at metalink and got

" The above warning messages has been introduced in 10.2.0.4 patchset. This warning message will be generated only if the log write time is more than 500 ms and it will be written to the lgwr trace file .

"These messages are very much expected in 10.2.0.4 database in case the log write is more than 500 ms. This is a warning which means that the write process is not as fast as it intented to be . So probably you need to check if the disk is slow or not or for any potential OS causes. "

We just upgraded to 10.2.0.4. Our storage is across the great divide at another company. We are often short of answers other than, "Everything is configured correctly". With quite a bit of work we have gotten a pair of LUNS allocated for redo logs.

As a test, I moved the redo logs from the SAN to a NSF drive - NOT one that should be allocated to redo. Here was the immediate result:



The log writer waits stopped. Compliments from management. A request from management to storage management to move the entire database to this kind of storage, everyone is happy

almost.

Tonight I looked at the trace file:

*** 2008-09-25 22:53:34.154
Warning: log write time 750ms, size 0KB
*** 2008-09-25 22:53:35.943
Warning: log write time 1770ms, size 28KB
*** 2008-09-25 22:53:39.889
Warning: log write time 940ms, size 0KB

Log writer is taking forever, and it isn't even doing anything!

To be continued..... and detective suggestions welcome!

OOW - Day 2 - Simple things

I spent most of the day in hands on classes. I learned to use the Configuration Management Pack of Grid Control to install patches. It looked really interesting. Now I have to go back to work and figure out how to install Grid Control so I can use it. I assume there will be a fair amount of kicking, screaming, and tearing out my hair in that little task which the Oracle demonstrator waved his hand at, as if to say, "It's nothing". Oh those little nothings.

I then went to a hands on on Oracle Advanced Compression in 11g. The class really was just working through a couple of OBE examples with the comfort of people who actually know the a LOT about Oracle Compression there to help with the silly little problems that people have working through examples. I wish I had had some sort of deep questions to ask about compression. All I learned was, it works. There is some time, and some space savings. It will be useful when we move up to 11g.

When I say that the Advanced Compression was 'Hands On', I mean it literally. Braille would have been more accurate. For some reason, the whole demo was available in a box slightly larger than a youtube video. I get annoyed with myself when I have difficulties with the parts that I think should be the simple parts.. Here were a whole group of Oracle employee experts who couldn't make the VM window expand to the whole screen. There was more compression in the demo than anyone intended!

OOW - Day 1 - Blogger's perks.

OOW'08 - Day 1. I spent the day in the 11g New Features Exam Cram. A couple of people encouraged me to try the exam. I have never touched 11g. I took the course as an intro to 11g, not as a refresher before the exam. If I passed the certification after just this, then the OCP really is meaningless. I prefer to actually know what I'm being tested on when taking an exam.

I happened to be seated next to Fuad Arshad, who apparently does work with Oracle 11g and is ready for the exam. I wish him all the best on the exam.

Fuad's conference badge had a large 'Blogger' written in bright orange on the case. I know that I signed up for one. I asked at the registration desk, and they gave me a 'Blogger' badge too. I lined up for the Keynote Address. Immediately, the ushers pushed me out of the main line and into a smaller line for press & bloggers. I was led to a special area of the auditiorium saved for bloggers - a long table set up so that we could record every golden world of Mary Matalin & James Carville. For Pete's sake! I think this 'Blogger' badge is going to have some strange side effects.

Then this evening I was able to get together with all of the other Oracle Bloggers who I have been following for a year. That was really special. What a nice bunch of people!