Glenn Fawcett's Weblog

« Oracle's vision of... | Main | Threshold login... »

Decoding 'latch:cache buffers chains' object from Oracle trace file

Tuesday Mar 14, 2006

If you have been using Method-R for response time based profiling, then you will appreciate this note. The "Cache Buffers Chains" latch pops up from time-to-time when trying to scale applications on high-end systems. It is usually a sign of an application issue so locating the source of contention is critical. There are several notes in metalink (42152.1 and 163424.1) which describe how to find hot blocks, but nothing that uses the the Oracle "10046 event" trace files.
Below is output from a trace file (10gR1) which shows the application waiting on a CBC latch:

   WAIT #3: nam='latch: cache buffers chains' ela= 18996 p1=15245584968 p2=116 p3=1

The ADDR in "p1=" is a decimal value which can be converted into hex and used to query the x$bh, v$latch_children, and sys.dba_extents tables to find the objects that are contending CBCs.

I created a script "CBC_p1_to_obj.sql" which hides the nasty sql and takes the ADDR as input. Below is an example from a recent experiment:

SQL> @CBC_p1_to_obj

Function created.

Enter value for cbc_addr_p1: 15245584968
old  12:   x.hladdr  = to_hex('&&CBC_ADDR_P1') and
new  12:   x.hladdr  = to_hex('15245584968') and

SEGMENT_NAME                           EXTENT#     BLOCK#        TCH     CHILD#     SLEEPS
----------------------------------- ---------- ---------- ---------- ---------- ----------
SYSMAN.MGMT_METRICS                          6          8          2        944          0
SYSMAN.MGMT_METRICS_RAW_PK                  32        113          2        944          0
SYSMAN.MGMT_METRICS_RAW_PK                  33         90          2        944          0
SYSMAN.MGMT_METRICS_1HOUR_PK                18         21          2        944          0
SYSMAN.MGMT_METRICS_1HOUR_PK                17         44          2        944          0
SYS.I_DEPENDENCY1                           18         14          1        944          0
SYS.WRI$_ADV_TASKS_IDX_01                    0          1          1        944          0
XDB.SYS_LOB0000043477C00008$$                0          3          1        944          0
OLAPSYS.MRAC_OLAP2_AW_PHYS_OBJ_T             0          3          1        944          0
OLAPSYS.MRAC_OLAP2_AW_PHYS_OBJ_T             0          3          1        944          0
XDB.SYS_LOB0000043477C00008$$                0          3          1        944          0

SEGMENT_NAME                           EXTENT#     BLOCK#        TCH     CHILD#     SLEEPS
----------------------------------- ---------- ---------- ---------- ---------- ----------
SYS.C_OBJ#                                  16        118          0        944          0
DG.T1PK                                     19        115          0        944          0

13 rows selected.

I hope you will find this script useful. Let me know if you experience any issues.

[2] Comments

Like this post?

Posted at 05:09PM Mar 14, 2006 by glennf in Oracle
Tags:

Comments:

hi My tracefile has output below; *** 2007-07-18 17:51:35.030 WAIT #9: nam='latch: cache buffers chains' ela= 6 p1=-4611686000843200856 p2=116 p3=0 as you see p1 value is negative when I put negative your script gives error when I put positive value then script says there are no rows returned so do you have any idea about where my hot block is? SQL> @hot_blocks.sql Function created. Enter value for cbc_addr_p1: -4611686000843200856 old 12: x.hladdr = coskan.to_hex('&&CBC_ADDR_P1') and new 12: x.hladdr = coskan.to_hex('-4611686000843200856') and x.hladdr = coskan.to_hex('-4611686000843200856') and * ERROR at line 12: ORA-06501: PL/SQL: program error ORA-06512: at "COSKAN.TO_HEX", line 9 SQL> @hot_blocks.sql Function created. Enter value for cbc_addr_p1: 4611686000843200856 old 12: x.hladdr = coskan.to_hex('&&CBC_ADDR_P1') and new 12: x.hladdr = coskan.to_hex('4611686000843200856') and no rows selected

Posted by Coskan Gundogar on July 18, 2007 at 08:00 AM PDT #

The issue is with the negative value for the latch address. Not sure why Oracle is reporting this as a negative.