类此9430ms (rw) file: kct.c line: 7800 count: 13 total: 26874ms time: 1296124原因分析

ckpt进程的trace文件中出现类似：9430ms (rw) file: kct.c line: 7800 count: 13 total: 26874ms time: 1296124
ckpt进程的trace文件中报如下错误

Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - 64bit Production
With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
Data Mining and Real Application Testing options
ORACLE_HOME = /oradb/11.2.0/db
System name:	AIX
Node name:	offondb2
Release:	1
Version:	6
Machine:	00CC83664C00
Instance name: offon2
Redo thread mounted by this instance: 2
Oracle process number: 20
Unix process pid: 19660878, image: oracle@offondb2 (CKPT)


*** 2012-10-26 13:25:00.971
  1: 9430ms (rw) file: kct.c line: 7800 count: 13 total: 26874ms time: 1296124
  2: 1777ms (rw) file: krse.c line: 1800 count: 164 total: 122140ms time: 364176
  3: 1450ms (rw) file: kct.c line: 1011 count: 1 total: 1450ms time: 1594117
  4: 1230ms (rw) file: kcrf.c line: 10012 count: 135 total: 90995ms time: 2630737
  5: 1173ms (ro) file: kcrr.c line: 3525 count: 13 total: 8842ms time: 3645916
  6: 890ms (rw) file: kcrf.c line: 9959 count: 8 total: 4812ms time: 3578222
  7: 830ms (ro) file: kcf.c line: 5306 count: 1 total: 830ms time: 1594116
  8: 677ms (rw) file: kcv.c line: 11783 count: 8 total: 4499ms time: 416869
Control file enqueue hold time tracking dump at time: 2092019

*** 2012-10-26 15:25:14.789
  1: 9430ms (rw) file: kct.c line: 7800 count: 13 total: 26874ms time: 1296124
  2: 1777ms (rw) file: krse.c line: 1800 count: 165 total: 122832ms time: 364176
  3: 1450ms (rw) file: kct.c line: 1011 count: 1 total: 1450ms time: 1594117
  4: 1230ms (rw) file: kcrf.c line: 10012 count: 135 total: 90995ms time: 2630737
  5: 1173ms (ro) file: kcrr.c line: 3525 count: 13 total: 8842ms time: 3645916
  6: 890ms (rw) file: kcrf.c line: 9959 count: 8 total: 4812ms time: 3578222
  7: 830ms (ro) file: kcf.c line: 5306 count: 1 total: 830ms time: 1594116
  8: 677ms (rw) file: kcv.c line: 11783 count: 8 total: 4499ms time: 416869

原因分析并解决

New controlfile enqueue hold time tracking statistics have been added in 11.2 to 
aid diagnosis of controlfile transaction related performance related issues.

To disable the trace set _controlfile_enqueue_holding_time_tracking_size to 0:

- spfile
alter system set "_controlfile_enqueue_holding_time_tracking_size"=0 scope=spfile;

- pfile
_controlfile_enqueue_holding_time_tracking_size=0

A database restart is required.

查询_controlfile_enqueue_holding_time_tracking_size

SQL> col name for a32
SQL> col value for a24
SQL> col description for a70
SQL> set linesize 150
SQL> select a.ksppinm name,b.ksppstvl value,a.ksppdesc description
  2    from x$ksppi a,x$ksppcv b
  3   where a.inst_id = USERENV ('Instance')
  4     and b.inst_id = USERENV ('Instance')
  5     and a.indx = b.indx
  6     and upper(a.ksppinm) LIKE upper('%&param%')
  7  order by name
  8  /
Enter value for param: _controlfile_enqueue_holding_time_tracking_size
old   6:    and upper(a.ksppinm) LIKE upper('%&param%')
new   6:    and upper(a.ksppinm) LIKE upper('%_controlfile_enqueue_holding_time_tracking_size%')
</strong>
NAME                             VALUE      DESCRIPTION
-------------------------------- ---------- ------------------------------------------------
_controlfile_enqueue_holding_tim 10         control file enqueue holding time tracking size
e_tracking_size

补充MOS说明[791417.1]

New controlfile enqueue hold time tracking statistics have been added in 11.2 to aid 
diagnosis of controlfile transaction related performance related issues:

Control File Enqueue AWR Statistics:
max cf enq hold time - The maximum amount of time in milliseconds a client has held the control file enqueue.
total cf enq hold time - The total amount of time in milliseconds all clients have held the control file enqueue.
total number of cf enq holders - The total number of times clients have held the control file enqueue.

Periodically, the CKPT process dumps statistics for the top N control file enqueue holders. 
N defaults to 10, but can be modified with the static hidden 
parameter: _controlfile_enqueue_holding_time_tracking_size.The dump looks like the following:

Preface: "Control file enqueue hold time tracking dump at time: [relative time]".
a. Time the client has held the control file enqueue.
b. Type of client's control file enqueue transaction - rw or ro.
c. File name where the client obtained control file enqueue.
d. Line number where the client obtained control file enqueue.
e. Number of times the client has held the control file enqueue since it became a member of the top N.
f. Total time the client has held the control file in all those times from [e].
g. Relative time the client obtained the control file enqueue from [a].