You Asked

Hi Tom,

I am loading tables in a database. I can't figure out why the
control file parallel write event is always so high.
The DB is only used as a staging area for loading/converting data. No users. I tried to minimize checkpoints.
We don't care about recovery for this DB.

log_archive_start boolean FALSE
log_checkpoint_interval integer 0
log_checkpoint_timeout integer 0
log_buffer integer 512000

GROUP# BYTES ARC STATUS
------------ ------------ --- ----------------
1 2147483648 NO ACTIVE
4 2147483648 NO CURRENT

Top 5 Wait Events
~~~~~~~~~~~~~~~~~ Wait % Total
Event Waits Time (cs) Wt Time
-------------------------------------------- ------------ ------------ -------
control file parallel write 2,350 33,154 67.13
log file parallel write 2,499 12,044 24.39
single-task message 2 4,002 8.10
db file parallel write 221 63 .13
db file sequential read 31 41 .08

and Tom said...

we write to the control files even more then we write to logs.

While you say "recovery isn't important" -- we would beg mightly to differ. Checkpoints are NOT something you want to minimize - in fact, you want them to happen continously (they happen in the background -- the only time your foreground process has to wait for them is when they didn't have time to FINISH in the background!!! if you make them "not happen" -- you'll just create a large backlog and have to wait for it)

You tune the control file writes in the same way you do logs

o dedicated devices to remove contention
o never on raid 5
o if you are just using UFS, mount with forcedirectio for logs and control files
if you can (or check out your logical volume vendors docs for how to mount
and bypass buffer cache). use raw if push comes to shove -- slice up a small
partition.

It looks like you need to tune your control/log devices here. A bigger log buffer and FAR FAR FAR fewer commits (you are probably committing way way too much -- that is causing extra control file writes and log waits - the only time you want for logs; when you commit or the redo log buffer is totally full).

Stop committing so much (I'm guessing on that -- people "love to commit" for some reason).

Make a much much larger redo log buffer.

Tune the control and log devices.

Rating

(6 ratings)

Is this answer out of date? If it is, please let us know via a Comment

Comments

A reader, August 21, 2003 - 2:43 pm UTC

meant to select 5 stars

A reader, August 21, 2003 - 2:44 pm UTC

tuning control file parallel write wait event

Wayne, June 12, 2004 - 11:26 am UTC

Tom,

AS always, great job.

I am getting waits on a box that is not in production, yet (sun v880). control file wait can easily be over 50% of my wait (statspack - 8.1.7 db) (but, it is "faster" than the box it is replacing.)

Question - before I "tune" - how do I convince the sysadmin to force direct i/o for my log and controlfile writes?

He requested raid 5 ( he has gone to solaris 1+0 for this box 4 disks for everything ... )

Next, will be the analyzing the stats to see if we need to budget for better laid out drive arrays ...

Wayne

June 12, 2004 - 12:00 pm UTC

but you don't wait for it? (background wait event, might be "noise"

50% of what exactly? something is going to be waited on no matter what -- the question is "50% of what amount of wait during what period of time under what kind of load"

A dba that requested raid 5? I've never met one of those before. That is usually the manager doing that because they see it is cheaper and therefore must be "better" :) (tongue in cheek heavily there)

What writes/reads the control file?

Sandy Becker, September 16, 2004 - 2:18 pm UTC

Tom,

You stated that we write to the control files even more than we write to logs. We recently put a 9i RAC database into production and we're seeing the following in statspack:

Top 5 Timed Events
~~~~~~~~~~~~~~~~~~ % Total
Event Waits Time (s) Ela Time
-------------------------------------------- ------------ ----------- --------
control file sequential read 7,702 7 47.32
CPU time * 4 25.01
control file parallel write 1,370 1 8.27
control file single write 56 1 6.04
global cache cr request 1,454 0 2.50
-------------------------------------------------------------

This is a Rel. 9.2.0.4 batch billing database with three instances. Control file read/write are consistently in the top 5 events. I have a few questions.

1) Is it possible the high numbers of control file reads/writes related to RAC and the intercommunication between instances? We don't see this behavior in any of our non-RAC 9i databases.

2) What processes read and/or write to the control file? Is there a view I can query to get this information?

Thank you.

Sandy

September 16, 2004 - 3:07 pm UTC

well, first of all -- the wait times here are teeny tiny -- i would use an application level trace in order to see if this is even affecting my *end user applications*

the controlfile sequential read would happen due to admin stuff (v$ views, alter backup to trace, things that make you read the controlfile) as well as sharing some information between instances (eg: RAC)

the background processes are thing that would write to the control file (the parallel write). the single file write is writing out that shared information.

Thanks

Sandy, September 16, 2004 - 3:30 pm UTC

Tom,

Thank you for your quick response. They spent almost 8 months tuning the application so I wasn't worried about the performance, just curious why we saw the control file events in our RAC timed events and not in non-RAC. This has been very helpful to us.

Thank you again.

who write controlfile when create a tablespace

Steven Zhang, September 17, 2004 - 2:32 am UTC

hello
I have a question to ask.which process take charge of write record into controlfile when one session create a tablespace.
i trace a session ,part of trace output like this:

create tablespace zbt datafile 'zbt.ora' size 10M
=====================
PARSING IN CURSOR #2 len=357 dep=1 uid=0 oct=2 lid=0 tim=1013114133 hv=21142229 ad='16a354c8'
insert into ts$ (ts#,name,online$,contents$,undofile#,undoblock#,blocksize, dflmaxext,dflinit,dflincr,dflextpct,dflminext,dflminlen,inc#,owner#,scnwrp,scnbas,pitrscnwrp,pitrscnbas,dflogging, affstrength,bitmapped,plugged,directallowed,flags,spare1,spare2) values (:1,:2,:3,:4,:5,:6,:7,:8,:9,:10,:11,:12,:13,1,:14,:15,:16,:17,:18,:19,0,:20,:21,1,:22,:23,:24)
END OF STMT
PARSE #2:c=15625,e=1076,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=0,tim=1013114120
EXEC #2:c=0,e=1103,p=0,cr=3,cu=11,mis=0,r=1,dep=1,og=4,tim=1013141798
=====================
PARSING IN CURSOR #2 len=322 dep=1 uid=0 oct=6 lid=0 tim=1013773959 hv=3069360096 ad='16a25124'
update ts$ set name=:2,online$=:3,contents$=:4,undofile#=:5,undoblock#=:6, blocksize=:7,dflmaxext=:8,dflinit=:9,dflincr=:10,dflextpct=:11,dflminext=:12,dflminlen=:13,owner#=:14,scnwrp=:15,scnbas=:16,pitrscnwrp=:17,pitrscnbas=:18,dflogging=:19,bitmapped=:20,inc#=:21,flags=:22,plugged=:23,spare1=:24,spare2=:25 where ts#=:1
END OF STMT
PARSE #2:c=0,e=94,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=1013773948
EXEC #2:c=0,e=383,p=0,cr=4,cu=2,mis=0,r=1,dep=1,og=4,tim=1013802632
STAT #2 id=1 cnt=0 pid=0 pos=1 obj=0 op='UPDATE '
STAT #2 id=2 cnt=1 pid=1 pos=1 obj=16 op='TABLE ACCESS CLUSTER TS$ '
STAT #2 id=3 cnt=1 pid=2 pos=1 obj=7 op='INDEX UNIQUE SCAN I_TS# '
=====================
PARSING IN CURSOR #2 len=122 dep=1 uid=0 oct=3 lid=0 tim=1013850387 hv=3129366963 ad='1762425c'
select blocks,NVL(ts#,-1),status$,NVL(relfile#,0),maxextend,inc, crscnwrp,crscnbas,NVL(spare1,0) from file$ where file#=:1
END OF STMT
PARSE #2:c=0,e=719,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=0,tim=1013850376
EXEC #2:c=15625,e=571,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=1013879403
FETCH #2:c=0,e=24,p=0,cr=1,cu=0,mis=0,r=0,dep=1,og=4,tim=1013885576
STAT #2 id=1 cnt=0 pid=0 pos=1 obj=17 op='TABLE ACCESS BY INDEX ROWID FILE$ '
STAT #2 id=2 cnt=0 pid=1 pos=1 obj=41 op='INDEX UNIQUE SCAN I_FILE1 '
=====================
PARSING IN CURSOR #2 len=189 dep=1 uid=0 oct=2 lid=0 tim=1013905310 hv=898408886 ad='16a20920'
insert into file$ (file#,blocks,ts#,status$,relfile#,maxextend,inc,crscnwrp,crscnbas,spare1) values (:1,:2,DECODE(:3,-1,NULL,:3),:4, DECODE(:5,0,NULL,:5),:6,:7,:8,:9,DECODE(:10,0,NULL,:10))
END OF STMT
PARSE #2:c=0,e=775,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=0,tim=1013905299
EXEC #2:c=0,e=615,p=0,cr=1,cu=5,mis=0,r=1,dep=1,og=4,tim=1013936351
=====================
PARSING IN CURSOR #2 len=102 dep=1 uid=0 oct=3 lid=0 tim=1013942726 hv=299084576 ad='16a1e094'
select /*+ INDEX_ASC(file$ i_file2) */ relfile# from file$ where ts#=:1 and relfile# between :2 and :3
END OF STMT
PARSE #2:c=0,e=109,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=1013942708
EXEC #2:c=0,e=68,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=1013975213
FETCH #2:c=0,e=35,p=0,cr=1,cu=0,mis=0,r=0,dep=1,og=4,tim=1013981540
STAT #2 id=1 cnt=0 pid=0 pos=1 obj=0 op='FILTER '
STAT #2 id=2 cnt=0 pid=1 pos=1 obj=42 op='INDEX RANGE SCAN I_FILE2 '
=====================
PARSING IN CURSOR #2 len=182 dep=1 uid=0 oct=6 lid=0 tim=1014000937 hv=910208921 ad='16a1a3ac'
update file$ set blocks=:2,ts#=DECODE(:3,-1,NULL,:3),status$=:4, relfile#=DECODE(:5,0,NULL,:5),maxextend=:6,inc=:7,crscnwrp=:8,crscnbas=:9,spare1=DECODE(:10,0,NULL,:10)where file#=:1
END OF STMT
PARSE #2:c=0,e=75,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=1014000927
EXEC #2:c=0,e=613,p=0,cr=1,cu=3,mis=0,r=1,dep=1,og=4,tim=1014038211
STAT #2 id=1 cnt=1 pid=0 pos=1 obj=0 op='UPDATE '
STAT #2 id=2 cnt=1 pid=1 pos=1 obj=41 op='INDEX UNIQUE SCAN I_FILE1 '
=====================
PARSING IN CURSOR #2 len=182 dep=1 uid=0 oct=6 lid=0 tim=1014215321 hv=910208921 ad='16a1a3ac'
update file$ set blocks=:2,ts#=DECODE(:3,-1,NULL,:3),status$=:4, relfile#=DECODE(:5,0,NULL,:5),maxextend=:6,inc=:7,crscnwrp=:8,crscnbas=:9,spare1=DECODE(:10,0,NULL,:10)where file#=:1
END OF STMT
PARSE #2:c=0,e=85,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=1014215310
EXEC #2:c=0,e=223,p=0,cr=1,cu=1,mis=0,r=1,dep=1,og=4,tim=1014248880
STAT #2 id=1 cnt=1 pid=0 pos=1 obj=0 op='UPDATE '
STAT #2 id=2 cnt=1 pid=1 pos=1 obj=41 op='INDEX UNIQUE SCAN I_FILE1 '

there are insert update on ts$ file$,it seem session who create tablespace write records into controlfile.Am I right?

eager to wait your response.
thanks

September 17, 2004 - 8:44 am UTC

ok, i'm not going to *show* the entire test -- but i'll describe it.

i erased my control files. So, any new process that wanted to read or write them would not find them (but the backgrounds would still have them open -- the backgrounds would be able to read and write them -- this is linux, might not work on windows).

I then logged in (created my dedicated server) and created a tablespace.

Alert log shows:

Fri Sep 17 08:24:28 2004
create tablespace t
Fri Sep 17 08:24:49 2004
Errors in file /home/ora9ir2/admin/ora9ir2/udump/ora9ir2_ora_11552.trc:
ORA-00603: ORACLE server session terminated by fatal error
ORA-00210: cannot open the specified controlfile
ORA-00202: controlfile: '/home/ora9ir2/oradata/ora9ir2/control01.ctl'
ORA-27041: unable to open file
Linux Error: 2: No such file or directory
Additional information: 3
ORA-00210: cannot open the specified controlfile
ORA-00202: controlfile: '/home/ora9ir2/oradata/ora9ir2/control01.ctl'
ORA-27041: unable to open file
Linux Error: 2: No such file or directory
Additional information: 3
Fri Sep 17 08:25:01 2004

it was my sessions dedicated server trying to write to it. The oracle process associated with my session.

Now, off to fix my database...

More to Explore

Performance

Get all the information about database performance in the Database Performance guide.

Breadcrumb

Question and Answer