Library cache - latch contention

[gnagesh]

Hi Oracle Guru's,

My database is encountering latch contention, since I am new to this tuning business, can any one help me in this regard. Here are the details.

Oracle Version: 8.1.6
Os : SunOs 5.7
Memory 1GB
No.Of.Cpu's 2

Here are init.ora parameters :

open_cursors = 200
max_enabled_roles = 30
db_block_lru_latches=4

db_block_buffers = 75776
db_file_multiblock_read_count = 8

shared_pool_size = 518328320
shared_pool_reserved_size=51832832


large_pool_size = 614400
java_pool_size = 20971520

log_checkpoint_interval = 5242880
log_checkpoint_timeout = 0

processes = 100

log_buffer = 1048576

db_block_size = 4096

sort_area_size = 165536
sort_area_retained_size = 165536
session_cached_cursors=100
sessions=150
cursor_sharing=force

My Hit Ratios are :

SQL> select (req.value*5000)/entries.value "Ratio (<1 on OK)"
2 from v$sysstat req, v$sysstat entries
3 where req.name = 'redo log space requests'
4 and entries.name = 'redo entries';

Ratio (<1 on OK)
----------------
.099594008
SQL> select (sum(pins)-sum(reloads))/sum(pins) as "LIBRARY CACHE HIT RATIO"
2 from v$librarycache;

LIBRARY CACHE HIT RATIO
-----------------------
.999993491

SQL> select (sum(gets)-sum(getmisses))/sum(gets) as "ROW CACHE HIT RATIO"
2 from v$rowcache;

ROW CACHE HIT RATIO
-------------------
.915638424
SQL> select gethitratio "GETHITRATIO >= .95 on OK" from v$librarycache where namespace = 'SQL AREA';


GETHITRATIO >= .95 on OK
------------------------
.991263985

SQL> select (sum(gets)-sum(misses))*100/sum(gets) as "Latch Hit Ration (> 99 OK)" from v$latch;

Latch Hit Ration (> 99 OK)
--------------------------
99.6805838

select 1 - (phy.value / (cur.value + con.value)) "BUFFER HIT RATIO (> 0.90 OK)"
from v$sysstat cur, v$sysstat con, v$sysstat phy
where cur.name = 'db block gets'
and con.name = 'consistent gets'
and phy.name = 'physical reads';
BUFFER HIT RATIO (> 0.90 OK)
----------------------------
.999752085

SQL> select sum(waits)* 100 / sum(gets) "RATIO < 5 on OK", sum(waits) "WAITS", sum(gets) "GETS "
2 from v$rollstat;

RATIO < 5 on OK WAITS GETS
--------------- ---------- ----------
.000558414 2 358157

SQL> select class, count from v$WAITSTAT where class in
2 ('undo header','undo block','system undo header',
3 'system undo block');

CLASS COUNT
------------------ ----------
system undo header 0
system undo block 0
undo header 325
undo block 406

SQL> select sum(count) as "All waits" from v$WAITSTAT where class in
2 ('undo header','undo block','system undo header',
3 'system undo block');

All waits
----------
731

SQL> select sum(value) "Data Requests" from v$SYSSTAT
2 where name in ('db block gets', 'consistent gets');

Data Requests
-------------
12927845

SQL> select name, value from v$sysstat where name like '%sort%';

NAME VALUE
---------------------------------------------------------------- ----------
sorts (memory) 39281
sorts (disk) 5
sorts (rows) 131558

SQL> select (sum(gets)-sum(misses))*100/sum(gets) as "Latch Hit Ration (> 99 OK)" from v$latch;

Latch Hit Ration (> 99 OK)
--------------------------
99.6806015

So, Is my hitratio's are sounding fine? Even my latch hitratio is >99, i found there is latch contention. I found this latch contention using following query, please correct me if i am wrong.

SQL> select name,gets,misses,sleeps
2 from v$latch
3 where name like 'library%';

NAME GETS
---------------------------------------------------------------- ----------
MISSES SLEEPS
---------- ----------
library cache 12427916
112413 9127

library cache load lock 1764
0 0

where as my following query is giving the result as

SQL> select gethitratio from v$librarycache where namespace = 'SQL AREA';

GETHITRATIO
-----------
.991253332

Is It Okay?

Here is my another observation from v$sqlarea

SQL> select sql_text, parse_calls, executions from v$sqlarea
2 where parse_calls > 100 and executions < 2*parse_calls;


SQL_TEXT
--------------------------------------------------------------------------------
PARSE_CALLS EXECUTIONS
----------- ----------

SELECT 0 STATUS FROM DUAL
76282 76282

SELECT :b1 STATUS,:b2 DESTINATIONNO,:b3 OUTBOUNDRES,:b4 CBGRP,:b5 DURATION,:b6 P
REFIX FROM DUAL
19091 19092


SQL_TEXT
--------------------------------------------------------------------------------
PARSE_CALLS EXECUTIONS
----------- ----------
SELECT :b1 STATUS,:b2 SERVICE_TYPE,:b3 PLAY_MSG,:b4 GREETING_MSG,:b5 LANG_SELECT
ION,:b6 ANI_AUTHORIZATION,:b7 PIN_AUTHORIZATION,:b8 ACC_AUTHORIZATION,:b9 LANGUA
GE_CODE,:b10 ANI_TYPE,:b11 WARNING_THRESHOLD,:b12 USERNO FROM DUAL
19112 19112

SELECT :b1 STATUS,:b2 USERNO,:b3 CREDITVALUE,:b4 CHECKLIMIT,:b5 SERVICETYPE,:b6
LANGUAGE_CODE,:b7 CARDTYPE FROM DUAL
19104 19104


SQL_TEXT
--------------------------------------------------------------------------------
PARSE_CALLS EXECUTIONS
----------- ----------
SELECT NVL(:b1,0) STATUS FROM DUAL
38141 38141

begin ppms5_ssp1.callflow_ssp_excel.reset_user_no(:1,:2,:3); end;
19075 19075

begin callflow_fsp_excel.SP_INSERT_CALLLOG(:V00001,:V00002,:V00003,:V00004,:V000
05,:V00006,:V00007,:V00008,:V00009,:V00010,:V00011,:V00012,:V00013,:V00014,:V000

SQL_TEXT
--------------------------------------------------------------------------------
PARSE_CALLS EXECUTIONS
----------- ----------
15,:V00016,:V00017,:V00018,:V00019,:V00020,:V00021,Cp_STATUS=>:R000C001); end;
19080 0

begin callflow_fsp_excel.SP_INSERT_CALLLOG(P_DUMMY=>:V00001,P_DNIS1=>:V00002,P_U
SER_NO_2=>:V00003,P_START_TIME_3=>:V00004,P_CALL_DURATION_4=>119,P_SYS_NAME_5=>:
V00006,P_SERVER_NAME_6=>:V00007,P_LANGUAGE_CODE_7=>:V00008,P_LINE_NO_8=>1,P_DIRE
CTION_9=>:V00010,P_REASON_ID_10=>:V00011,P_ANI_11=>:V00012,P_DNIS_12=>:V00013,P_
CATEGORY_ID_13=>:V00014,P_SERVICE_TYPE_14=>3,P_SESSION_ID_16=>:V00016,P_TRUNK_ID
_17=>0,P_INFO_DIGIT_18=>:V00018,P_USER_ACCESS_NO=>:V00019,P_HOME_CODE=>:V00020,P

SQL_TEXT
--------------------------------------------------------------------------------
PARSE_CALLS EXECUTIONS
----------- ----------
_CARD_TYPE=>1,Cp_STATUS=>:R000C001); end;
19076 19075

begin callflow_fsp_excel.SP_INSERT_CALLLOG(P_DUMMY=>:V00001,P_DNIS1=>:V00002,P_U
SER_NO_2=>:V00003,P_START_TIME_3=>:V00004,P_CALL_DURATION_4=>119,P_SYS_NAME_5=>:
V00006,P_SERVER_NAME_6=>:V00007,P_LANGUAGE_CODE_7=>:V00008,P_LINE_NO_8=>1,P_DIRE
CTION_9=>:V00010,P_REASON_ID_10=>:V00011,P_ANI_11=>:V00012,P_DNIS_12=>:V00013,P_
CATEGORY_ID_13=>:V00014,P_SERVICE_TYPE_14=>3,P_SESSION_ID_16=>:V00016,P_TRUNK_ID
_17=>:V00017,P_INFO_DIGIT_18=>:V00018,P_USER_ACCESS_NO=>:V00019,P_HOME_CODE=>:V0

SQL_TEXT
--------------------------------------------------------------------------------
PARSE_CALLS EXECUTIONS
----------- ----------
0020,P_CARD_TYPE=>1,Cp_STATUS=>:R000C001); end;
19069 19066

begin callflow_fsp_excel.TWOSTAGE_FIRSTAUTHORIZE(:V00001,:V00002,:V00003,:V00004
,cp=>:R000C001); end;
19182 0

begin callflow_fsp_excel.TWOSTAGE_FIRSTAUTHORIZE(P_DUMMY=>:V00001,P_ANI=>:V00002
,P_DNIS=>:V00003,P_MAXPORT=>1000,cp=>:R000C001); end;

SQL_TEXT
--------------------------------------------------------------------------------
PARSE_CALLS EXECUTIONS
----------- ----------
19115 19112

begin callflow_fsp_excel.TWOSTAGE_THIRDAUTHORIZE(:V00001,:V00002,:V00003,:V00004
,:V00005,:V00006,:V00007,:V00008,cp=>:R000C001); end;
19092 0

begin callflow_fsp_excel.TWOSTAGE_THIRDAUTHORIZE(P_DUMMY=>:V00001,P_USERNO=>:V00
002,P_DEST=>:V00003,P_DNIS=>:V00004,P_DNISSERVER=>:V00005,P_INFORMATION_DIGIT=>:
V00006,P_HOME_CODE=>:V00007,P_CARD_TYPE=>1,cp=>:R000C001); end;

SQL_TEXT
--------------------------------------------------------------------------------
PARSE_CALLS EXECUTIONS
----------- ----------
19092 19092

begin callflow_fsp_excel.twoStage_secondAuthorize(:V00001,:V00002,:V00003,:V0000
4,:V00005,:V00006,:V00007,:V00008,:V00009,cp=>:R000C001); end;
19106 0

begin callflow_fsp_excel.twoStage_secondAuthorize(P_DUMMY=>:V00001,P_ANI=>:V0000
2,P_DNIS=>:V00003,P_PWD=>:V00004,P_ACC=>:V00005,P_ANITYPE=>1,P_LINESESSION=>:V00
007,P_NEWCALL_FLAG=>0,P_MAXPORT=>1000,cp=>:R000C001); end;

SQL_TEXT
--------------------------------------------------------------------------------
PARSE_CALLS EXECUTIONS
----------- ----------
19104 19104

begin ppms5_ssp1.callflow.sp_insert_calllog( :1, :2, :3, :4, :5, :6, :7,
:8, :9, :10, :11, :12, :13, :14, :15, :16, :17, :18, :19, :20, :21, :22, :23, :
24); end;
38141 38141

begin ppms5_ssp1.callflow_ssp_excel.twoStage_firstAuthorize(:1,:2,:3,:4,:5,:6,:7
,:8,:9,:10,:11,:12,:13,:14,:15,:16,:17); end;

SQL_TEXT
--------------------------------------------------------------------------------
PARSE_CALLS EXECUTIONS
----------- ----------
19112 19112

begin ppms5_ssp1.callflow_ssp_excel.twoStage_secondAuthorize(:1,:2,:3,:4,:5,:6,:
7,:8,:9,:10,:11,:12,:13,:14,:15,:16,:17,:18,:19,:20); end;
19104 19104

begin ppms5_ssp1.callflow_ssp_excel.twoStage_thirdAuthorize(:1,:2,:3,:4,:5,:6,:7
,:8,:9,:10,:11,:12,:13); end;
19092 19092


Since I had already pinned above displayed packages, why so many parse calls are occuring?

Please consider this as a urgent. Now I am totally in confusion state, what I have to consider, Hit Ratios?/ any thing else?

My worry is, even my hitratio's sounding fine, my user still not statisfied with the results? What else I have to tune?

Looking forward your suggestions.

Thanks In Advance.

[julian]

I noticed that db_block_lru_latches=4. How many CPUs do you have? If 1, then drop db_block_lru_latches, if > 1, say you have n, set db_block_lru_latches=6*n and let the keep and recycle pool use these latches (in case you use those pools).

P.S. It could be that your shared_pool is a bit too big, ½G. Do you have heavy use of stored packages and functions?

[pando]

from the stats I wouldnt say you are facing latch contention because the ratio between gets, misses and sleeps are low

12427916, 112413, 9127

This is good so why you are saying you are having library latch contentions? How do you determin or what is *bad* in your criteria? How about looking the explain plan of those heavy SQL statements? I noticed you are using cursor_sharing=force, any particular reason? Or the application is not using bind variables?

Also your SGA is too high, you have 1GB memory and you are allocating around 750MB SGA this may cause paging/swapping if you have too many concurrent sessions and there are other applications running in the same box

db_block_lru_latches=4 seems fine since you have 2 CPUs

[Edited by pando on 12-26-2001 at 05:17 PM]

[gnagesh]

Hi

Thanks for your reply. Since My applications depends on more packages and stored procedures, I kept shared pool high.

When I upload my stats pack report to http://www.oraperf.com, it was reported library cache contention.

as per as cursor_sharing=force concerned, Yes!, some of the programs are not using bind variables. And most of the packaged stored procedures are difined with TYPE CURSOR, for output variables, hence, while returning the values to the caller,

OPEN CURSOR ... FOR SELECT ... FROM DUAL.

is heavely used. Is this causing more parsing?

What you would suggest for my SGA, How much percent of memory I should keep?

presently I am not using keep and recycle pool, Do you suggest these pools?

Thanks in Advance

[julian]

db_block_lru_latches=4 seems fine since you have 2 CPUs

[Edited by pando on 12-26-2001 at 05:17 PM]

I would set db_block_lru_latches=12 if there are 2 CPUs on the system.

[julian]

What you would suggest for my SGA, How much percent of memory I should keep?

That's hard to tell. But most people would suggest 50-70% for the SGA.

presently I am not using keep and recycle pool, Do you suggest these pools?

I do if you know what to do with them. If you have for example some small tables which are often accsessed, you may want to keep them in memory.

[gnagesh]

Hi

Thanks for your reply. Now I had reduced my sga size to 50% of my 1G memory. Here are the details and ratios.

SGA details :
SVRMGR> connect internal
Connected.
SVRMGR> show sga
Total System Global Area 529362852 bytes
Fixed Size 94116 bytes
Variable Size 118603776 bytes
Database Buffers 409600000 bytes
Redo Buffers 1064960 bytes

Init.ora parameters :

open_cursors = 200
max_enabled_roles = 30
db_block_lru_latches=4

db_block_buffers = 100000
db_file_multiblock_read_count = 32

shared_pool_size = 70000000
shared_pool_reserved_size=7000000


large_pool_size = 614400
java_pool_size = 20971520

#log_checkpoint_interval = 10000
log_checkpoint_interval = 5242880
#log_checkpoint_timeout = 1800
log_checkpoint_timeout = 0

processes = 100

#log_buffer = 163840
log_buffer = 1048576
#log_buffer = 662496

Hit Ratios :

SYSTEM@MASSBEJ2> select (req.value*5000)/entries.value "Ratio (<1 on OK)"
2 from v$sysstat req, v$sysstat entries
3 where req.name = 'redo log space requests'
4 and entries.name = 'redo entries';

Ratio (<1 on OK)
----------------
.118308193

SYSTEM@MASSBEJ2>
SYSTEM@MASSBEJ2> select (sum(pins)-sum(reloads))/sum(pins) as "LIBRARY CACHE HIT RATIO"
2 from v$librarycache;

LIBRARY CACHE HIT RATIO
-----------------------
.9999952

SYSTEM@MASSBEJ2>
SYSTEM@MASSBEJ2> select (sum(gets)-sum(getmisses))/sum(gets) as "ROW CACHE HIT RATIO"
2 from v$rowcache;

ROW CACHE HIT RATIO
-------------------
.876130025

SYSTEM@MASSBEJ2>
SYSTEM@MASSBEJ2> select gethitratio "GETHITRATIO >= .95 on OK" from v$librarycache where namespace = 'SQL AREA';

GETHITRATIO >= .95 on OK
------------------------
.983274365

SYSTEM@MASSBEJ2>
SYSTEM@MASSBEJ2> select (sum(gets)-sum(misses))*100/sum(gets) as "Latch Hit Ratio (> 99 OK)" from v$latch;

Latch Hit Ratio (> 99 OK)
-------------------------
96.2612677

SYSTEM@MASSBEJ2>
SYSTEM@MASSBEJ2> select 1 - (phy.value / (cur.value + con.value)) "BUFFER HIT RATIO (> 0.90 OK)"
2 from v$sysstat cur, v$sysstat con, v$sysstat phy
3 where cur.name = 'db block gets'
4 and con.name = 'consistent gets'
5 and phy.name = 'physical reads';

BUFFER HIT RATIO (> 0.90 OK)
----------------------------
.999962913

SYSTEM@MASSBEJ2>
SYSTEM@MASSBEJ2> select sum(waits)* 100 / sum(gets) "RATIO < 5 on OK", sum(waits) "WAITS", sum(gets) "GETS "
2 from v$rollstat;

RATIO < 5 on OK WAITS GETS
--------------- ---------- ----------
0 0 144266

SYSTEM@MASSBEJ2>
SYSTEM@MASSBEJ2> select class, count from v$WAITSTAT where class in
2 ('undo header','undo block','system undo header',
3 'system undo block');

CLASS COUNT
------------------ ----------
system undo header 0
system undo block 0
undo header 231
undo block 112

SYSTEM@MASSBEJ2>
SYSTEM@MASSBEJ2> select sum(count) as "All waits" from v$WAITSTAT where class in
2 ('undo header','undo block','system undo header',
3 'system undo block');

All waits
----------
343

SYSTEM@MASSBEJ2>
SYSTEM@MASSBEJ2> select sum(value) "Data Requests" from v$SYSSTAT
2 where name in ('db block gets', 'consistent gets');

Data Requests
-------------
67408803

SYSTEM@MASSBEJ2>
SYSTEM@MASSBEJ2> select name, value from v$sysstat where name like '%sort%';

NAME VALUE
---------------------------------------------------------------- ----------
sorts (memory) 39179
sorts (disk) 2
sorts (rows) 60639

SYSTEM@MASSBEJ2>
SYSTEM@MASSBEJ2> spool off

Now. My queries are

1. Is My hitratios are Okay?
2. Why my packages are more times parsing? even after piining them into shared pool. What could be the reason?
3. What other areas I should look for other bottlenecks?

Thanks In Advance.

[julian]

1. Is My hitratios are Okay?

You should let the instance run for a while after bouncing in order to have an accurate say on the ratios.

2. Why my packages are more times parsing? even after piining them into shared pool. What could be the reason?

What exactly dod you mean?

3. What other areas I should look for other bottlenecks?

Your db_file_multiblock_read_count is 32. I would suggest 8. Would should try to have your block size (8K?) * db_file_multiblock_read_count equal the maximum I/O for the system. On most platforms it is 64K.

Also, high db_file_multiblock_read_count will cause the optimzer overlook the indexes and go for FTSs.

[gnagesh]

Hi

Thanks.

1. I had run my instance with full load for one hour, and collected the hitraios.

2. My block size is 4k, so do you mean to set db_file_multiblock_read_count = 8

3. What I mean is :

SYSTEM@MASSBEJ2> set termout off
old: termout ON
new: termout OFF
SYSTEM@MASSBEJ2> select
2 sql_text,
3 sharable_mem + persistent_mem + runtime_mem memory,
4 sorts,
5 executions,
6 first_load_time,
7 invalidations,
8 parse_calls,
9 disk_reads,
10 buffer_gets,
11 rows_processed,
12 round(rows_processed/greatest(executions,1)) row_ratio,
13 round(disk_reads/greatest(executions,1)) disk_ratio,
14 round(buffer_gets/greatest(executions,1)) buffer_ratio
15 from v$sqlarea
16 where
17 executions > 100
18 or disk_reads > 1000
19 or buffer_gets > 1000
20 or rows_processed > 1000
21 order by
22 executions * 250 + disk_reads * 25 + buffer_gets desc
23 ;

begin
callflow_fsp_excel.SP_INSERT_CALLLOG(P_DUMMY=>:V00001,P_DNIS1=>:V00002,P_USER_
NO_2=>:V00003,P_START_TIME_3=>:V00004,P_CALL_DURATION_4=>119,P_SYS_NAME_5=>:V0
0006,P_SERVER_NAME_6=>:V00007,P_LANGUAGE_CODE_7=>:V00008,P_LINE_NO_8=>1,P_DIRE
CTION_9=>:V00010,P_REASON_ID_10=>:V00011,P_ANI_11=>:V00012,P_DNIS_12=>:V00013,
P_CATEGORY_ID_13=>:V00014,P_SERVICE_TYPE_14=>3,P_SESSION_ID_16=>:V00016,P_TRUN
K_ID_17=>:V00017,P_INFO_DIGIT_18=>:V00018,P_USER_ACCESS_NO=>:V00019,P_HOME_COD
E=>:V00020,P_CARD_TYPE=>1,Cp_STATUS=>:R000C001); end;


First load time: 2001-12-27/12:06:44
Buffer gets: 1098831 ratio 139
Disk reads: 1 ratio 0
Rows delivered 7887 ratio 1
Executions 7887
Parses 7887
Memory 17001
Sorts 0
Invalidations 0

Thanks in Advance.