lms,lmon 繁忙

guoq.lee

原帖由 lijiebin 于 2010-9-26 17:32 发表
出问题时,IO 是正常的
每个节点4个4核cpu
cpu 主要是lmon 和lms比较繁忙
我们每个节点4个lms

lmon 很容易占满1个cpu.4个lms进程也在 cpu排行榜前几名

可以说cpu 都被lms和lmon占满了。

3个节点，有时候一个节点这样，有时候2个节点这样，有时候3个节点都这样。

排除BUG的可能来说。
LMS主要是用来GC traffic，它会使用大量的CPU，但是我觉得不见得能占用100%.
先从GC traffic入手，减少资源的争用（比如热点块）。

lijiebin

出问题时lmon 占用100%
lms  98，99 这样子

现在业务太复杂了，要从业务的角度优化，就要找出他们的bad sql，这个一直在努力。

有没有什么方法，可以跟踪一下lms或者lmon ,看看繁忙时到底是哪里的问题。
10046，来跟踪，看不出问题。
只看到lms很多cache buffer chain 类似的等待。
一个chain 上，对象非常多，等待事件也非常多

lijiebin

正常时某节点部分awr

Load Profile Per SecondPer TransactionRedo size:218,047.582,551.29Logical reads:22,338.99261.38Block changes:1,091.6912.77Physical reads:42.620.50Physical writes:198.732.33User calls:3,071.7535.94Parses:450.855.28Hard parses:0.130.00Sorts:17.470.20Logons:0.610.01Executes:1,747.3320.44Transactions:85.47

% Blocks changed per Read:	4.89	Recursive Call %:	15.89
Rollback per transaction %:	2.13	Rows per Sort:	14.56

Instance Efficiency Percentages (Target 100%)

Buffer Nowait %:	99.96	Redo NoWait %:	100.00
Buffer Hit %:	99.90	In-memory Sort %:	100.00
Library Hit %:	99.98	Soft Parse %:	99.97
Execute to Parse %:	74.20	Latch Hit %:	99.99
Parse CPU to Parse Elapsd %:	86.14	% Non-Parse CPU:	98.55

Shared Pool Statistics BeginEndMemory Usage %:82.7582.75% SQL with executions>1:85.1886.03% Memory for SQL w/exec>1:81.3782.23Top 5 Timed Events EventWaitsTime(s)Avg Wait(ms)% Total Call TimeWait ClassCPU time2,13258.0enq: TX - row lock contention2,2501,04846628.5ApplicationARCH wait on SENDREQ1299227,14925.1Networkdb file sequential read116,192672618.3User I/Olog file sync305,268398110.8CommitRAC StatisticsBeginEndNumber of Instances:33Global Cache Load Profile Per SecondPer TransactionGlobal Cache blocks received:77.360.91Global Cache blocks served:297.023.48GCS/GES messages received:1,211.2614.17GCS/GES messages sent:544.886.38DBWR Fusion writes:4.910.06Estd Interconnect traffic (KB)3,338.08Global Cache Efficiency Percentages (Target local+remote 100%)

Buffer access - local cache %:	99.55
Buffer access - remote cache %:	0.35
Buffer access - disk %:	0.10

Global Cache and Enqueue Services - Workload Characteristics

Avg global enqueue get time (ms):	0.1
Avg global cache cr block receive time (ms):	0.5
Avg global cache current block receive time (ms):	0.6
Avg global cache cr block build time (ms):	0.0
Avg global cache cr block send time (ms):	0.0
Global cache log flushes for cr blocks served %:	3.1
Avg global cache cr block flush time (ms):	0.5
Avg global cache current block pin time (ms):	0.0
Avg global cache current block send time (ms):	0.0
Global cache log flushes for current blocks served %:	0.1
Avg global cache current block flush time (ms):	1.4

Global Cache and Enqueue Services - Messaging Statistics

Avg message sent queue time (ms):	0.1
Avg message sent queue time on ksxp (ms):	0.2
Avg message received queue time (ms):	0.1
Avg GCS message process time (ms):	0.0
Avg GES message process time (ms):	0.0
% of direct sent messages:	30.30
% of indirect sent messages:	25.34
% of flow controlled messages:	44.36

Wait Events Statistics
Time Model Statistics

Total time in database user-calls (DB Time): 3679s Statistics including the word "background" measure background process time, and so do not contribute to the DB time statistic
• Ordered by % or DB time desc, Statistic name

Statistic NameTime (s)% of DB Timesql execute elapsed time2,982.6781.07DB CPU2,132.0457.95parse time elapsed40.941.11PL/SQL execution elapsed time12.640.34repeated bind elapsed time10.040.27hard parse elapsed time3.180.09connection management call elapsed time1.280.03sequence load elapsed time0.800.02hard parse (sharing criteria) elapsed time0.290.01hard parse (bind mismatch) elapsed time0.020.00PL/SQL compilation elapsed time0.000.00DB time3,679.00background elapsed time2,030.35background cpu time394.14Wait Class

s - second cs - centisecond - 100th of a second ms - millisecond - 1000th of a second us - microsecond - 1000000th of a second
• ordered by wait time desc, waits desc

Wait ClassWaits%Time -outsTotal Wait Time (s)Avg wait (ms)Waits /txnNetwork9,769,6650.001,067031.89Application3,13268.141,0493350.01User I/O159,1340.0067740.52System I/O366,2880.0346611.20Commit305,2680.0039811.00Cluster443,7570.0123911.45Other158,53165.9214310.52Concurrency6,5490.75810.02Configuration2860.00120.00Administrative70.000330.00Wait Events

s - second cs - centisecond - 100th of a second ms - millisecond - 1000th of a second us - microsecond - 1000000th of a second
• ordered by wait time desc, waits desc (idle events last)

EventWaits%Time -outsTotal Wait Time (s)Avg wait (ms)Waits /txnenq: TX - row lock contention2,25094.841,0484660.01ARCH wait on SENDREQ1290.0092271490.00db file sequential read116,1920.0067260.38log file sync305,2680.0039811.00log file parallel write306,6250.0028111.00LNS wait on SENDREQ6570.001281950.00LNS ASYNC control file txn128100.001259770.00enq: CF - contention34432.85571650.00gc buffer busy26,4480.135520.09gc cr block 2-way99,8070.003300.33gc current grant busy36,6010.003110.12gc cr block 3-way65,1830.003000.21reliable message6383.4528440.00db file parallel write27,9370.002410.09gc current block 2-way67,1440.002300.22gc current grant 2-way86,5340.002200.28log file sequential read12,8060.002020.04gc current block 3-way35,2810.001700.12KJC: Wait for msg sends to complete5794.74162790.00gc current block busy1,5340.001490.01control file sequential read16,3910.001110.05gc cr block busy8,8010.001010.03gcs log flush sync17,16225.46910.06ARCH wait on c/f tx acquire 29100.0099770.00SQL*Net message to client9,523,7270.008031.09wait for scn ack1,4220.00750.00SQL*Net more data from client47,9310.00700.16enq: TX - index contention3171.266180.00direct path read37,1640.00400.12enq: WF - contention2814.2941320.00enq: US - contention12,8680.00300.04kjbdrmcvtq lmon drm quiesce: ping completion4643.483600.00SQL*Net more data to client197,2210.00300.64control file parallel write1,7530.00320.01gc cr grant 2-way11,1260.00300.04Log archive I/O6320.00240.00IPC send completion sync5,58499.28200.02cr request retry2100.0014890.00read by other session2,0330.00100.01row cache lock4,2500.00100.01os thread startup140.001640.00gc current multi block request4,6580.00100.02gc current grant congested20.0013080.00enq: PS - contention2,0220.00100.01log file switch completion150.001360.00ges global resource directory to be frozen46100.000110.00cursor: pin S wait on X4697.830110.00PX Deq: reap credit57,68685.99000.19latch free6140.00010.00DFS lock handle1,6380.00000.01PX Deq Credit: send blkd5,19442.88000.02name-service call wait60.000590.00ges LMON for send queues1822.220180.00enq: FB - contention7180.00000.00enq: TM - contention7140.00000.00switch logfile command70.000330.00CGS wait for IPC msg32,76099.40000.11buffer busy waits4700.00000.00latch: cache buffers chains1,3500.00000.00latch: library cache700.00010.00gc cr multi block request6280.00000.00LGWR wait for redo copy1,6760.00000.01ksxr poll remote instances14,58960.51000.05enq: HW - contention2280.00000.00direct path write3,7450.00000.01PX Deq: Signal ACK47931.94000.00SQL*Net break/reset to client1680.00000.00global enqueue expand wait475.00080.00rdbms ipc reply2330.00000.00latch: session allocation1430.00000.00latch: KCL gc element parent latch2030.00000.00enq: TX - contention60.00020.00cursor: pin S8320.00000.00latch: cache buffers lru chain1140.00000.00wait list latch free10.000110.00latch: enqueue hash chains490.00000.00latch: ges resource hash list900.00000.00latch: gcs resource hash1640.00000.00library cache lock210.00000.00log file single write160.00000.00enq: SQ - contention80.00010.00gc current split80.00010.00buffer deadlock3393.94000.00latch: object queue header operation250.00000.00enq: TD - KTF dump entries120.00000.00latch: redo allocation400.00000.00enq: TX - allocate ITL entry140.00000.00PX qref latch91599.89000.00latch: messages170.00000.00enq: TA - contention80.00000.00enq: WR - contention60.00000.00latch: redo writing210.00000.00latch: checkpoint queue latch120.00000.00enq: AF - task serialization20.00010.00latch: library cache lock20.00010.00library cache pin40.00000.00latch: row cache objects40.00000.00enq: DR - contention20.00000.00enq: WL - contention20.00000.00enq: JQ - contention10.00010.00enq: TT - contention20.00000.00ges2 LMON to wake up LMD - mrcvr80.00000.00gc cr failure20.00000.00latch: undo global data10.00000.00latch: shared pool10.00000.00SQL*Net message from client9,523,6430.002,236,77323531.09jobq slave wait14,41349.4635,00824290.05gcs remote message3,750,63388.1113,776412.24LNS ASYNC end of log10,47699.6610,2239760.03PX Idle Wait5,36162.538,82216460.02class slave wait17014.124,091240630.00Streams AQ: qmn slave idle wait1270.003,514276650.00Streams AQ: qmn coordinator idle wait25450.003,513138320.00ASM background timer9840.003,50035570.00DIAG idle wait17,7460.003,5001970.06ges remote message158,45396.923,494220.52Streams AQ: waiting for time management or cleanup tasks2100.002,02310112920.00PX Deq: Execution Msg12,10534.691,4381190.04KSV master wait1380.723230.00PX Deq: Msg Fragment4,48744.86100.01PX Deq: Execute Reply84939.46000.00PX Deq: Join ACK51234.57000.00PX Deq: Parse Reply46032.83000.00PX Deq Credit: need buffer32121.50000.00Streams AQ: RAC qmn coordinator idle wait254100.00000.00
Background Wait Events

• ordered by wait time desc, waits desc (idle events last)

EventWaits%Time -outsTotal Wait Time (s)Avg wait (ms)Waits /txnARCH wait on SENDREQ1290.0092271490.00log file parallel write306,6280.0028111.00LNS wait on SENDREQ6570.001281950.00LNS ASYNC control file txn128100.001259770.00events in waitclass Other84,08155.1410210.27db file parallel write27,9370.002410.09log file sequential read12,8060.002020.04control file sequential read13,3660.001010.04control file parallel write1,7530.00320.01Log archive I/O6320.00240.00os thread startup140.001640.00gc cr block 3-way7980.00000.00row cache lock6890.00000.00enq: TM - contention7100.00000.00gc current block 2-way3430.00000.00gc current block 3-way860.00010.00direct path read1,7750.00000.01gc cr block 2-way2290.00000.00direct path write5630.00000.00enq: HW - contention960.00000.00gc current grant busy290.00000.00log file single write160.00000.00latch: cache buffers chains610.00000.00latch: redo writing210.00000.00gc current block busy10.00010.00latch: row cache objects30.00000.00library cache lock10.00010.00buffer busy waits70.00000.00rdbms ipc message393,37415.6165,1171661.28gcs remote message3,750,54388.1113,776412.24LNS ASYNC end of log10,47699.6610,2239760.03Streams AQ: qmn slave idle wait1270.003,514276650.00Streams AQ: qmn coordinator idle wait25450.003,513138320.00ASM background timer9840.003,50035570.00DIAG idle wait17,7470.003,5001970.06pmon timer1,24499.843,49928130.00smon timer7300.003,49647890.00ges remote message158,42196.923,494220.52Streams AQ: waiting for time management or cleanup tasks2100.002,02310112920.00KSV master wait1380.723230.00PX Deq: Parse Reply4332.56010.00PX Deq: Join ACK4839.58000.00PX Deq: Execute Reply3023.33000.00Streams AQ: RAC qmn coordinator idle wait254100.00000.00
Operating System StatisticsStatisticTotalBUSY_TIME263,193IDLE_TIME5,467,543IOWAIT_TIME80,919NICE_TIME93SYS_TIME51,558USER_TIME176,621LOAD2RSRC_MGR_CPU_WAIT_TIME0PHYSICAL_MEMORY_BYTES1,113,040NUM_CPUS16NUM_CPU_SOCKETS4
Service Statistics

• ordered by DB Time

Service NameDB Time (s)DB CPU (s)Physical ReadsLogical Readsbilldb.99bill.com3,599.102,067.90150,62879,481,406SYS$USERS66.7063.5004,699SYS$BACKGROUND0.000.002,151520,485rac.source0.000.0000
Back to Wait Events Statistics

Service Wait Class Stats

Wait Class info for services in the Service Statistics section. Total Waits and Time Waited displayed for the following wait classes: User I/O, Concurrency, Administrative, Network
• Time Waited (Wt Time) in centisecond (100th of a second)

Service NameUser I/O Total WtsUser I/O Wt TimeConcurcy Total WtsConcurcy Wt TimeAdmin Total WtsAdmin Wt TimeNetwork Total WtsNetwork Wt Timebilldb.99bill.com1558426731556197130097682791734SYS$USERS00280723240SYS$BACKGROUND329137990212800786105011

[ 本帖最后由 lijiebin 于 2010-9-27 09:28 编辑 ]

lijiebin

Load Profile Per SecondPer TransactionRedo size:183,507.302,619.72Logical reads:20,441.07291.81Block changes:895.0012.78Physical reads:28.660.41Physical writes:194.252.77User calls:2,731.4138.99Parses:439.026.27Hard parses:0.300.00Sorts:15.950.23Logons:1.150.02Executes:1,462.1520.87Transactions:70.05

% Blocks changed per Read:	4.38	Recursive Call %:	16.81
Rollback per transaction %:	3.34	Rows per Sort:	30.74

Instance Efficiency Percentages (Target 100%)

Buffer Nowait %:	99.90	Redo NoWait %:	100.00
Buffer Hit %:	99.87	In-memory Sort %:	100.00
Library Hit %:	99.94	Soft Parse %:	99.93
Execute to Parse %:	69.97	Latch Hit %:	99.97
Parse CPU to Parse Elapsd %:	49.99	% Non-Parse CPU:	98.10

Shared Pool Statistics BeginEndMemory Usage %:82.6682.87% SQL with executions>1:85.2785.12% Memory for SQL w/exec>1:81.3680.58Top 5 Timed Events EventWaitsTime(s)Avg Wait(ms)% Total Call TimeWait Classenq: TX - index contention87,62239,81045427.4Concurrencygc buffer busy51,38922,48243715.4Clusterenq: TX - row lock contention47,24122,36447315.4Applicationbuffer busy waits30,02817,94759812.3Concurrencylog file sync261,9129,369366.4CommitRAC StatisticsBeginEndNumber of Instances:33Global Cache Load Profile Per SecondPer TransactionGlobal Cache blocks received:66.670.95Global Cache blocks served:175.742.51GCS/GES messages received:804.3011.48GCS/GES messages sent:428.566.12DBWR Fusion writes:3.430.05Estd Interconnect traffic (KB)2,180.08 Global Cache Efficiency Percentages (Target local+remote 100%)

Buffer access - local cache %:	99.55
Buffer access - remote cache %:	0.33
Buffer access - disk %:	0.13

Global Cache and Enqueue Services - Workload Characteristics

Avg global enqueue get time (ms):	77.4
Avg global cache cr block receive time (ms):	4.4
Avg global cache current block receive time (ms):	18.5
Avg global cache cr block build time (ms):	0.0
Avg global cache cr block send time (ms):	0.0
Global cache log flushes for cr blocks served %:	5.7
Avg global cache cr block flush time (ms):	14.4
Avg global cache current block pin time (ms):	0.5
Avg global cache current block send time (ms):	0.0
Global cache log flushes for current blocks served %:	0.2
Avg global cache current block flush time (ms):	11.4

Global Cache and Enqueue Services - Messaging Statistics

Avg message sent queue time (ms):	59.4
Avg message sent queue time on ksxp (ms):	4.2
Avg message received queue time (ms):	0.7
Avg GCS message process time (ms):	0.0
Avg GES message process time (ms):	0.0
% of direct sent messages:	31.82
% of indirect sent messages:	25.38
% of flow controlled messages:	42.80

Wait Events Statistics Time Model Statistics

Total time in database user-calls (DB Time): 145539.2s Statistics including the word "background" measure background process time, and so do not contribute to the DB time statistic
• Ordered by % or DB time desc, Statistic name

Statistic NameTime (s)% of DB Timesql execute elapsed time135,980.6093.43DB CPU1,799.181.24sequence load elapsed time756.870.52connection management call elapsed time476.640.33parse time elapsed132.780.09hard parse elapsed time90.510.06PL/SQL execution elapsed time17.560.01repeated bind elapsed time7.670.01PL/SQL compilation elapsed time2.440.00hard parse (sharing criteria) elapsed time1.210.00hard parse (bind mismatch) elapsed time0.640.00failed parse elapsed time0.000.00DB time145,539.18 background elapsed time7,426.15 background cpu time3,198.34
Wait Class

s - second cs - centisecond - 100th of a second ms - millisecond - 1000th of a second us - microsecond - 1000000th of a second
• ordered by wait time desc, waits desc

Wait ClassWaits%Time -outsTotal Wait Time (s)Avg wait (ms)Waits /txnConcurrency160,68060.5260,6383770.64Cluster421,3439.4035,140831.67Application48,50893.3722,3664610.19Other439,42653.0213,984321.75Commit261,9121.509,369361.04Configuration10,35579.114,7564590.04Network8,508,0910.001,022033.81User I/O107,5950.0057050.43System I/O304,0870.0231811.21Administrative50.000370.00
Wait Events

s - second cs - centisecond - 100th of a second ms - millisecond - 1000th of a second us - microsecond - 1000000th of a second
• ordered by wait time desc, waits desc (idle events last)

EventWaits%Time -outsTotal Wait Time (s)Avg wait (ms)Waits /txnenq: TX - index contention87,62290.5139,8104540.35gc buffer busy51,38952.3022,4824370.20enq: TX - row lock contention47,24195.8722,3644730.19buffer busy waits30,02857.4517,9475980.12log file sync261,9121.509,369361.04gc current grant busy30,11526.625,5301840.12enq: US - contention35,78324.134,5281270.14enq: HW - contention9,99580.094,0244030.04gcs drm freeze in enter server mode1,82177.053,05816790.01gc current grant 2-way78,9491.923,055390.31enq: FB - contention6,46385.612,7714290.03row cache lock17,0783.612,6121530.07enq: TX - contention3,39083.811,4164180.01ARCH wait on SENDREQ1290.0091570940.00gc current multi block request6,05524.118901470.02enq: SQ - contention32058.4473122850.00gc current block busy2,67419.457092650.01latch: object queue header operation62,4640.00707110.25gc current block 2-way62,4680.53687110.25gc remaster1,04826.535735470.00db file sequential read97,4720.0056460.39kjbdrmcvtq lmon drm quiesce: ping completion2,75390.854981810.01wait for scn ack11,5793.39456390.05gc current block 3-way20,7940.76301140.08gc cr block 2-way82,0110.1527030.33gc cr block 3-way47,2900.2323350.19latch: cache buffers chains24,7870.0022890.10log file parallel write240,3360.0019910.95gc cr grant 2-way14,1650.64184130.06gc cr multi block request13,7840.529770.05latch: cache buffers lru chain5,1710.0078150.02LGWR wait for redo copy11,38242.767260.05enq: JD - contention2864.296924720.00LNS ASYNC control file txn65100.00649780.00gc cr block busy10,5020.256260.04LNS wait on SENDREQ6710.0053780.00enq: CF - contention38725.58501290.00SQL*Net more data from client46,9770.004410.19PX Deq Credit: send blkd14,63344.454230.06latch: ges resource hash list7,7220.003850.03ges global resource directory to be frozen2,753100.0030110.01gc current grant congested3821.05266860.00name-service call wait6163.93223640.00KJC: Wait for msg sends to complete7894.87222790.00rdbms ipc reply1,9650.0521110.01db file parallel write28,1820.002010.11ges2 LMON to wake up LMD - mrcvr1,51171.0819130.01reliable message8851.3619220.00log file sequential read12,4640.001920.05os thread startup3743.24184960.00latch free1,1430.1717150.00latch: library cache lock1020.00171680.00gcs log flush sync27,39530.721710.11gc current split2646.15166210.00gc current retry1471.43117940.00control file sequential read17,0300.001010.07gc cr block congested812.5078740.00DFS lock handle6,7940.09710.03SQL*Net message to client8,396,1230.007033.36latch: session allocation2600.006250.00read by other session1,2970.15540.01gc current block congested1010.0054620.00enq: TD - KTF dump entries2040.0042000.00latch: row cache objects4990.00470.00enq: WF - contention3112.9031090.00Log archive I/O7840.00340.00control file parallel write1,8680.00320.01buffer deadlock27,44395.09300.11TCP Socket (KGAS)3,5400.00310.01IPC send completion sync6,94599.48200.03gc cr grant congested20.0028420.00SQL*Net break/reset to client4660.00230.00direct path read5,9260.00100.02PX Deq: reap credit127,97384.11100.51SQL*Net more data to client60,0510.00100.24cr request retry1100.0019780.00ARCH wait on c/f tx acquire 21100.0019770.00ges LMON for send queues3073.331300.00enq: PS - contention2,6860.00100.01latch: enqueue hash chains4680.00120.00global enqueue expand wait6298.391110.00latch: library cache1260.00150.00wait list latch free520.001110.00cursor: pin S wait on X45100.000110.00latch: KCL gc element parent latch5,4510.06000.02enq: TM - contention8010.00000.00PX Deq: Signal ACK77031.82000.00switch logfile command50.000370.00CGS wait for IPC msg23,43998.17000.09log file switch completion90.000180.00lms flush message acks30.000490.00ksxr poll remote instances25,16952.51000.10latch: shared pool130.000110.00enq: TX - allocate ITL entry90.000120.00db file parallel read190.00050.00db file scattered read270.00030.00library cache lock1840.00000.00latch: gcs resource hash4860.00000.00direct path write2,8540.00000.01enq: JQ - contention750.00010.00kksfbc child completion1100.000500.00library cache pin1500.00000.00PX qref latch10,59699.95000.04latch: redo allocation500.00000.00library cache load lock50.00040.00cursor: pin S1,1760.00000.00enq: TA - contention150.00000.00log file single write160.00000.00kst: async disk IO3,3420.00000.01latch: redo writing220.00000.00enq: PI - contention40.00010.00enq: WR - contention60.00000.00latch: checkpoint queue latch230.00000.00enq: TT - contention60.00000.00latch: undo global data50.00000.00latch: messages110.00000.00enq: AF - task serialization10.00010.00enq: DR - contention20.00000.00enq: WL - contention20.00000.00gc cr failure10.00010.00SQL*Net message to dblink6000.00000.00latch: library cache pin20.00000.00lock escalate retry2100.00000.00cursor: mutex S20.00000.00SQL*Net message from client8,395,9940.002,613,34031133.36jobq slave wait14,17348.5034,09024050.06PX Idle Wait7,30064.5612,48017100.03gcs remote message2,504,29086.6111,64059.95LNS ASYNC end of log10,65099.6610,3899760.04class slave wait20910.053,697176870.00ASM background timer1,0710.003,51132790.00Streams AQ: qmn slave idle wait1270.003,502275710.00Streams AQ: qmn coordinator idle wait25450.003,501137850.00ges remote message209,16490.913,500170.83DIAG idle wait17,7220.023,4931970.07Streams AQ: waiting for time management or cleanup tasks2100.001,6248119580.00PX Deq: Execution Msg14,85231.58498340.06PX Deq: Execute Reply16,21436.10166100.06PX Deq: Parse Reply80333.0035430.00PX Deq Credit: need buffer66319.00350.00KSV master wait1800.563180.00single-task message500.001230.00PX Deq: Msg Fragment5,55443.18100.02SQL*Net message from dblink6000.00010.00PX Deq: Join ACK88736.08000.00Streams AQ: RAC qmn coordinator idle wait254100.00000.00
Background Wait Events

• ordered by wait time desc, waits desc (idle events last)

EventWaits%Time -outsTotal Wait Time (s)Avg wait (ms)Waits /txnevents in waitclass Other175,21832.642,566150.70ARCH wait on SENDREQ1290.0091570940.00log file parallel write240,3340.0019910.95latch: cache buffers chains16,4240.00170100.07row cache lock1,1651.80109940.00LNS ASYNC control file txn65100.00649780.00LNS wait on SENDREQ6710.0053780.00buffer busy waits6547.69375640.00db file parallel write28,1820.002010.11gc cr block 2-way3143.5020640.00log file sequential read12,4650.001920.05os thread startup3447.06175080.00gc cr block busy1118.11171530.00gc current block 2-way4711.2714300.00gc cr block 3-way6230.9612200.00control file sequential read13,9860.00910.06gc current grant busy336.0641130.00Log archive I/O7840.00340.00control file parallel write1,8680.00320.01db file sequential read1,2670.00210.01gc current block 3-way1440.692110.00gc current block busy120.000260.00enq: TM - contention7990.00000.00gc cr grant 2-way8080.00000.00direct path read2,0050.00000.01enq: HW - contention1030.00010.00direct path write6000.00000.00log file sync10.000310.00latch: row cache objects160.00020.00gc current grant 2-way450.00000.00log file single write160.00000.00kst: async disk IO3,3420.00000.01latch: redo writing220.00000.00library cache lock90.00000.00library cache pin160.00000.00gc buffer busy20.00000.00rdbms ipc message322,30913.6861,1851901.28gcs remote message2,504,33786.6111,64059.95LNS ASYNC end of log10,65199.6610,3909760.04ASM background timer1,0710.003,51132790.00Streams AQ: qmn slave idle wait1270.003,502275710.00Streams AQ: qmn coordinator idle wait25450.003,501137850.00ges remote message209,19590.913,500170.83pmon timer1,26698.103,49927640.01DIAG idle wait17,7200.003,4901970.07smon timer7130.003,33646790.00Streams AQ: waiting for time management or cleanup tasks2100.001,6248119580.00KSV master wait1800.563180.00PX Deq: Parse Reply3930.77000.00PX Deq: Join ACK4544.44000.00PX Deq: Execute Reply2931.03000.00Streams AQ: RAC qmn coordinator idle wait254100.00000.00
Operating System StatisticsStatisticTotalBUSY_TIME544,306IDLE_TIME5,200,085IOWAIT_TIME65,319NICE_TIME128SYS_TIME60,947USER_TIME453,303LOAD1RSRC_MGR_CPU_WAIT_TIME0PHYSICAL_MEMORY_BYTES2,593,084NUM_CPUS16NUM_CPU_SOCKETS4
Service Statistics

• ordered by DB Time

Service NameDB Time (s)DB CPU (s)Physical ReadsLogical Readsbilldb.99bill.com143,745.001,688.9093,14470,415,770SYS$USERS1,794.20110.305,8592,331,259SYS$BACKGROUND0.000.003,961698,887rac.source0.000.0000
Service Wait Class Stats

Wait Class info for services in the Service Statistics section. Total Waits and Time Waited displayed for the following wait classes: User I/O, Concurrency, Administrative, Network
• Time Waited (Wt Time) in centisecond (100th of a second)

Service NameUser I/O Total WtsUser I/O Wt TimeConcurcy Total WtsConcurcy Wt TimeAdmin Total WtsAdmin Wt TimeNetwork Total WtsNetwork Wt Timebilldb.99bill.com966075356313793859727010084942695199SYS$USERS580229943192327315194380263SYS$BACKGROUND515645718779332890080096776

guoq.lee

Avg global enqueue get time (ms):        77.4
这个就能反应出LMON的情况，oracle说Avg global enqueue get time (ms)应该在20-30，不过我看见一般都在1以下。
gc buffer busy        51,389        22,482        437        15.4        Cluster
能反应出lms的情况

你的系统是不是一个事务型的系统，并且在出问题的时候负载能比较大些？

我的建议是在出问题的时候，看看session都在等什么。同时尽可能的减少资源争用。

一个3节点的RAC还是不是太适合事务性的系统。

[ 本帖最后由 guoq.lee 于 2010-9-27 11:24 编辑 ]

lijiebin

是啊，系统有很多复杂的事物。
出问题时，系统的负载没有明显的变化。
出问题时，很多session 的等待
但是分不出来，这些等待是因为rac 的节点之间的争用引起的。

还是因为这些等待造成的rac ,lmon 的繁忙

因为平时的session 的这些等待和出现问题时，差别不大。

[ 本帖最后由 lijiebin 于 2010-9-27 16:36 编辑 ]

tiger_lw

根据个人经验，出现你这样的问题的根本原因是你应用里面的sql语句。

要解决以下问题：
1，对DML，要用分段提交及时提交（同时还要解决dml的性能问题），比如5000条就提交一次。你的GES等待很严重，多半就是这个原因导致的，同时繁忙时，你的top都是DML语句。
2，优化你的select语句，尽量使查询访问的consitent read降到最低，因为select也可能导致大量cache fusion出现。

lijiebin

原帖由 tiger_lw 于 2010-10-6 22:19 发表
根据个人经验，出现你这样的问题的根本原因是你应用里面的sql语句。

要解决以下问题：
1，对DML，要用分段提交及时提交（同时还要解决dml的性能问题），比如5000条就提交一次。你的GES等待很严重，多半就是这个原因导致的，同时繁忙时，你的top都是DML语句。
2，优化你的select语句，尽量使查询访问的consitent read降到最低，因为select也可能导致大量cache fusion出现。

sql语句，应该不是这个问题
你看看系统出问题时候的负载，和正常时，几乎完全一样。

最后我建议更改一些索引的pctfree 和itl 的初始化数量。
看看效果把。