Top 60 Oracle Blogs

Recent comments

July 2011

LGWR redo write times (log file parallel write)

General ***rule of thumb*** I’ve heard and buy into is that decent log file syncs times should be 3ms or under. Well “log file sync” depends on “log file parallel write” times, and “log file parallel write” times depend on the size of the write, thus I looked at some different log write sizes on a Solaris system with redo files on a SAN with plenty of write back cache and 4Gb FC and there are the distributions I saw on this single system

In the following charts

  • X axis is # of blocks written per write
  • Y axis
    1. milliseconds per write on top two graphs
    2. MB per Second on the bottom two graphs

This data was from the 10046 trace files from the lgwr process.Block size is 512bytes.

Sort of stange that the throughput goes to 90MB/s at 4-5 blocks and then drops off precipitously to 10-20MB/s above, when I’d expect I/O to speed up with larger write sizes.

One nagging question for me is why aren’t the log writes faster over 4G FB with write back cache. The fastest log write above 10 blocks (5K) is just under 25MB/s. I’d expect over 100MB/s. Definitely can dd write with oflag=sync  at over 100MB/s.

Nice old page from the formidable Steve Adams with query to get block size:

select max(lebsz) from sys.x$kccle;

UPDATE: the above data was from a customer system. I just ran a similar test  on my lab machine and got results of more along the lines I was expecting. On the my lab machine I have the redo on file system mounted over 1GbE NFS  which maxes out around 115MB/s. On a good day I get 108ish MB/s and on a bad day around 50MB/s – it’s a public network (ie company wide). Today was a bad day, but the results are pretty good:




Query to get  average  log write write times

       round((time_ms_end-time_ms_beg)/nullif(count_end-count_beg,0),1) avg_ms
from (
       to_char(s.BEGIN_INTERVAL_TIME,'DD-MON-YY HH24:MI')  btime,
       total_waits count_end,
       time_waited_micro/1000 time_ms_end,
       Lag (e.time_waited_micro/1000)
              OVER( PARTITION BY e.event_name ORDER BY s.snap_id) time_ms_beg,
       Lag (e.total_waits)
              OVER( PARTITION BY e.event_name ORDER BY s.snap_id) count_beg
   and e.event_name in (
                  'log file sync',
                  'log file parallel write'
   and  s.dbid=e.dbid
order by btime

Redo Sizes

select   dbid, to_char( begin_time ,'YYYY/MM/DD HH24'),
         round(sum(decode(metric_name,'Redo Generated Per Sec',average,0)) /
         nullif(sum(decode(metric_name,'Redo Writes Per Sec',average,0)),0)/1024,0)  avg_log_write_kb
from     dba_hist_sysmetric_summary
where    metric_name in  (
                           'Redo Writes Per Sec',
                           'Redo Generated Per Sec'
         ) /* and DBID=[dbid if share repository] */
group  by dbid, to_char( begin_time ,'YYYY/MM/DD HH24')


Bug update

We received notice of a patch to correct the bug I discussed with gathering stats on tables with virtual columns/function-based indexes in parallel in my previous post. The patch is number 10013177 and can be found at

After applying the patch, all stats collections worked without error. Whew!

Explain plan nodes sized by time


Thought I had blogged about this before but couldn’t find the reference. Tanel Poder put together a nifty tool that takes an explain plan with execution stats and maps it out such that he steps that take more time are bigger and those that take less smaller. Some small steps might be so small they aren’t even visible which is fine. Why should we see them if they are so fast?!

I’m also wondering if DB Optimizer could harness this type of functionality. Currently the graphic execution plan nodes are all the same size like on the left, but maybe the nodes could be sized by time as well:

Not sure my mockup is the prettiest example but I think it at least shows the idea.

How Many Ways to Solve this Problem? Add the Sequential Numbers x Through y

July 13, 2011 I am not entirely sure why, however a couple of days ago the following search keywords were used to access one or more articles on this blog: the sum of 1+2+3+4...+98+99+100 The above request I found to be a bit interesting, and there is a 50/50 chance that the person found the right answer [...]

Another World XI

In celebration of Test Match 2000 (where surely Sachin Tendulkar is due to complete his century of centuries – albeit in a losing cause ) The ICC have a new poll looking for an all time XI. You have til midnight tonight to complete it Mine is the same as the World XI I put [...]

VMware price changes could be perfect for Oracle VM uptake…

It’s not very often you see Oracle looking like the cheap option, but Oracle VM has always been pretty attractive on that score. :)

The latest information about VMware vSphere 5.0 pricing sounds like the perfect cue for Oracle to start another big push on the virtualization front, as I’m sure a lot of VMware customers will be swallowing hard as they read the new pricing model. It certainly makes Oracle VM sound even more attractive than it did before.

If Oracle could just get Oracle VM 3.0 out of the door, it might be able to make some serious inroads into the to VMware user base.






WordPress 3.2.1 Released…

As is often the way, new major releases from WordPress are quickly followed by maintenance releases. The recent release of WordPress 3.2 is now quickly followed by WordPress 3.2.1. Happy upgrading. :)



An update and a day in Dayton...

I wrote previously about a neat Chrome add-in for AWR viewing - and it has recently been updated. You can read about that here...

Additionally - I've been a little tardy in updating asktom with a list of events I'll be doing (I'll get that filled in next week - it includes San Francisco USA, Sydney Australia, Edinburgh Scotland, Frankfurt Germany, Milwaukee WI, Chicago IL and Toronto in the next month and a half..). But more immediately is Dayton Ohio this thursday. You can read about that here...


Many questions I see on the internet could be resolved by the simple expedient of looking at the information that’s in front of you; and many of the questions that clutter up forums and newsgroup would simply cease to appear if more people adopted this approach. Here’s an example of what I mean:

According to Metalink note 34559.1 the p1 value is the absolute file number. According to dba_data_files all my file numbers are one, two or three digits, but when I “select distinct p1 from v$session_wait” I am seeing a file number (p1) of 1413697536. Why is this appearing ?

No doubt someone reading this post will look at that number and immediately recognise it as coming from an SQL*Net message wait on a tcp connection (1413697536 = 0×54435000 -> 0×54 0×43 0×50 -> T C P) and may wonder why the Metalink note didn’t explain that p1 was the absolute file number only when the wait was related to some sort of file I/O. This was the thought that crossed my mind, so I logged on to MOS to see what the note said (because sometimes I fill in the feedback form to correct the errors or ask for a note to be withdrawn) and this is what I found:

Title of note: “db file sequential read” Reference Note
First line of note: This is a reference note for the wait event “db file sequential read” which …

I find that I can’t conjure up any circumstances where a person could know enough to query v$session_wait and dba_data_files, and yet not notice the significance of the title and first line of the metalink note.

Footnote: According to a story I heard recently, there is at least one site where the management has blocked access to any internet sites that cause too much traffic on the company network. Unfortunately the IT department seemed to spend a lot of time reading the Oracle online documentation. So whenever I see the expression RTFM I now interpret it as “read the firewalled manuals”.