近期看到一个awr的报告,里面有较多log buffer space,算是一份比较特殊的awr报告,对它进行了一次分析,因为blog排版问题,使用pdf格式展示

阅读PDF版:记录一次log buffer space等待分析
近期看到一个awr的报告,里面有较多log buffer space,算是一份比较特殊的awr报告,对它进行了一次分析,因为blog排版问题,使用pdf格式展示

阅读PDF版:记录一次log buffer space等待分析
今天在分析一份awr中发现了较为明显的enq: TX – allocate ITL entry等待,这里通过试验详细重现了enq: TX – allocate ITL entry等待
创建测试对象
SQL> create table t_xifenfei (name char(2000)) pctfree 0 initrans 1;
Table created.
SQL> insert into t_xifenfei select object_name from all_objects where rownum < 5;
4 rows created.
SQL> commit;
Commit complete.
SQL> alter system flush buffer_cache;
System altered.
SQL> select distinct dbms_rowid.rowid_relative_fno(rowid) file#,
2 dbms_rowid.rowid_block_number(rowid) block# from t_xifenfei;
FILE# BLOCK#
---------- ----------
4 32
bbed查看block
BBED> set block 32
BLOCK# 32
BBED> map
File: /u01/oracle/oradata/XFF/users01.dbf (0)
Block: 32 Dba:0x00000000
------------------------------------------------------------
KTB Data Block (Table/Cluster)
struct kcbh, 20 bytes @0
struct ktbbh, 72 bytes @20
struct kdbh, 14 bytes @100
struct kdbt[1], 4 bytes @114
sb2 kdbr[4] @118
ub1 freespace[38] @126 --该block空闲空间为38byte
ub1 rowdata[8024] @164
ub4 tailchk @8188
BBED> p ktbbh
struct ktbbh, 72 bytes @20
ub1 ktbbhtyp @20 0x01 (KDDBTDATA)
union ktbbhsid, 4 bytes @24
ub4 ktbbhsg1 @24 0x0000d318
ub4 ktbbhod1 @24 0x0000d318
struct ktbbhcsc, 8 bytes @28
ub4 kscnbas @28 0xc0320e3b
ub2 kscnwrp @32 0x0b2c
b2 ktbbhict @36 2
ub1 ktbbhflg @38 0x32 (NONE)
ub1 ktbbhfsl @39 0x00
ub4 ktbbhfnx @40 0x01000019
struct ktbbhitl[0], 24 bytes @44 --1个itl slot为24byte
struct ktbitxid, 8 bytes @44
ub2 kxidusn @44 0x0015
ub2 kxidslt @46 0x0019
ub4 kxidsqn @48 0x00000005
struct ktbituba, 8 bytes @52
ub4 kubadba @52 0x0080009d
ub2 kubaseq @56 0x0002
ub1 kubarec @58 0x28
ub2 ktbitflg @60 0x2004 (KTBFUPB)
union _ktbitun, 2 bytes @62
b2 _ktbitfsc @62 0
ub2 _ktbitwrp @62 0x0000
ub4 ktbitbas @64 0xc0320e4e
struct ktbbhitl[1], 24 bytes @68 --有两个itl slot
struct ktbitxid, 8 bytes @68
ub2 kxidusn @68 0x0000
ub2 kxidslt @70 0x0000
ub4 kxidsqn @72 0x00000000
struct ktbituba, 8 bytes @76
ub4 kubadba @76 0x00000000
ub2 kubaseq @80 0x0000
ub1 kubarec @82 0x00
ub2 ktbitflg @84 0x0000 (NONE)
union _ktbitun, 2 bytes @86
b2 _ktbitfsc @86 0
ub2 _ktbitwrp @86 0x0000
ub4 ktbitbas @88 0x00000000
通过bbed我们可以得出如下结论:
1.该block剩余38 byte 空闲空间可以用来存放数据
2.该block 初始化 itl 为2(和我们设置的1不相符)
3.一个itl slot为24byte
更新表记录
--session 1 SQL> select trim(name) from t_xifenfei; TRIM(NAME) -------------------------------------------------------------------------------- ICOL$ I_USER1 CON$ UNDO$ SQL> update t_xifenfei set name='WWW.XIFENFEI.COM' WHERE name='ICOL$'; 1 row updated. --session 2 SQL> update t_xifenfei set name='www.orasos.com' where name='UNDO$'; 1 row updated. --session 3 SQL> update t_xifenfei set name='www.orasos.com' where name='CON$'; 1 row updated. --session 4 SQL> update t_xifenfei set name='www.orasos.com' where name='I_USER1'; --hang住 --session 5 SQL> select event from v$session where event like 'enq%'; EVENT ---------------------------------------------------------------- enq: TX - allocate ITL entry
通过这里可以看到我们模拟了4个update 该block操作(均未提交),前面三个可以正常的update操作,第四个出现了enq: TX – allocate ITL entry等待,根据我们知识分析(未提交事务的itl不能覆盖,一个dml操作需要一个itl),这里使用了3个itl slot,而我们已经知道一个itl 需要24byte,该block初始化有2个itl,现在这里有3个dml操作成功,即占用了3个itl,所以该block的剩余空间只有38-24=14 byte<24byte,因此无法分配第四个itl slot从而出现了enq: TX - allocate ITL entry等待
bbed验证上述分析
BBED> map
File: /u01/oracle/oradata/XFF/users01.dbf (0)
Block: 32 Dba:0x00000000
------------------------------------------------------------
KTB Data Block (Table/Cluster)
struct kcbh, 20 bytes @0
struct ktbbh, 96 bytes @20
struct kdbh, 14 bytes @124
struct kdbt[1], 4 bytes @138
sb2 kdbr[4] @142
ub1 freespace[14] @150
ub1 rowdata[8024] @164
ub4 tailchk @8188
BBED> p ktbbh
struct ktbbh, 96 bytes @20
ub1 ktbbhtyp @20 0x01 (KDDBTDATA)
union ktbbhsid, 4 bytes @24
ub4 ktbbhsg1 @24 0x0000d318
ub4 ktbbhod1 @24 0x0000d318
struct ktbbhcsc, 8 bytes @28
ub4 kscnbas @28 0xc0320eb0
ub2 kscnwrp @32 0x0b2c
b2 ktbbhict @36 3
ub1 ktbbhflg @38 0x32 (NONE)
ub1 ktbbhfsl @39 0x00
ub4 ktbbhfnx @40 0x01000019
struct ktbbhitl[0], 24 bytes @44
struct ktbitxid, 8 bytes @44
ub2 kxidusn @44 0x0003
ub2 kxidslt @46 0x001f
ub4 kxidsqn @48 0x00000208
struct ktbituba, 8 bytes @52
ub4 kubadba @52 0x00800027
ub2 kubaseq @56 0x0414
ub1 kubarec @58 0x01
ub2 ktbitflg @60 0x0001 (NONE)
union _ktbitun, 2 bytes @62
b2 _ktbitfsc @62 0
ub2 _ktbitwrp @62 0x0000
ub4 ktbitbas @64 0x00000000
struct ktbbhitl[1], 24 bytes @68
struct ktbitxid, 8 bytes @68
ub2 kxidusn @68 0x000a
ub2 kxidslt @70 0x000f
ub4 kxidsqn @72 0x00000185
struct ktbituba, 8 bytes @76
ub4 kubadba @76 0x0080008a
ub2 kubaseq @80 0x01a6
ub1 kubarec @82 0x0c
ub2 ktbitflg @84 0x0001 (NONE)
union _ktbitun, 2 bytes @86
b2 _ktbitfsc @86 0
ub2 _ktbitwrp @86 0x0000
ub4 ktbitbas @88 0x00000000
struct ktbbhitl[2], 24 bytes @92
struct ktbitxid, 8 bytes @92
ub2 kxidusn @92 0x0008
ub2 kxidslt @94 0x002a
ub4 kxidsqn @96 0x00000217
struct ktbituba, 8 bytes @100
ub4 kubadba @100 0x008000cc
ub2 kubaseq @104 0x0291
ub1 kubarec @106 0x12
ub2 ktbitflg @108 0x0001 (NONE)
union _ktbitun, 2 bytes @110
b2 _ktbitfsc @110 0
ub2 _ktbitwrp @110 0x0000
ub4 ktbitbas @112 0x00000000
可以看到剩余空间为14byte,事务槽为3个,因此上述分析为正确。
提交会话测试
--session 1 SQL> commit; Commit complete. --session 4 SQL> update t_xifenfei set name='www.orasos.com' where name='I_USER1'; 1 row updated.
证明commit掉事务后,itl slot可以重利用
总结说明
enq: TX – allocate ITL entry为分配ITL条目的等待,因为PCTFREE不足,BLOCK中没有足够空间分配ITL,ORACLE只能重用ITL,但是这个时候由于没有COMMIT,无法重用ITL,所以会出现allocate ITL等待事件。要解决此类问题,我们可以考虑增加PCTFREE和initrans大小,需要注意该修改只能对于新block生效,已经存放数据的block不会发生改变.另外可以考虑修改业务逻辑,减少频繁访问
某客户有一服务器,shared pool 相关latch出现异常等待,影响系统性能.分析结果:因为系统空闲内存太少,使用太多Paging Space导致该异常;解决办法:1.增加内存,2.在业务接受范围内减小sga等其他和内存消耗相关参数
nmon查看剩余内存
x Physical PageSpace | pages/sec In Out | FileSystemCache x% Used 99.8% 34.9% | to Paging Space 0.0 0.0 | (numperm) 14.8% x% Free 0.2% 65.1% | to File System 0.0 33.0 | Process 63.9% xMB Used 21452.8MB 11446.1MB | Page Scans 0.0 | System 21.1% xMB Free (少)-->51.2MB 21321.9MB | Page Cycles 0.0 | Free 0.2% xTotal(MB) 21504.0MB 32768.0MB | Page Steals 0.0 | ------
topas查看内存配置
Disk Busy% KBPS TPS KB-Read KB-Writ MEMORY
Topas Monitor for host: p570b03 EVENTS/QUEUES FILE/TTY
Wed Jan 9 13:30:30 2013 Interval: 2 Cswitch 785 Readch 173.1K
Syscall 54407 Writech 213.1K
CPU User% Kern% Wait% Idle% Reads 118 Rawin 0
ALL 43.6 1.7 0.0 54.8 Writes 110 Ttyout 352
Forks 0 Igets 0
Network KBPS I-Pack O-Pack KB-In KB-Out Execs 0 Namei 5
Total 84.5 146.0 200.6 26.4 58.1 Runqueue 0.5 Dirblk 0
Waitqueue 0.0
Disk Busy% KBPS TPS KB-Read KB-Writ MEMORY
Total 0.0 164.6 17.0 0.0 164.6 PAGING Real,MB 21504
Faults 12408 % Comp 86 <---大部分计算内存
FileSystem KBPS TPS KB-Read KB-Writ Steals 0 % Noncomp 13 <---fs cache较少
Total 316.3 17.9 151.5 164.9 PgspIn 0 % Client 13
PgspOut 0
Name PID CPU% PgSp Owner PageIn 0 PAGING SPACE
oracle 6357252 16.7 8.4 oracle PageOut 42 Size,MB 32768
oracle 15401474 8.3 70.8 oracle Sios 42 % Used 35 <---使用比较多
oracle 12714542 8.3 8.3 oracle % Free 65
oracle 5767556 8.3 8.3 oracle NFS (calls/sec)
oracle 5898996 8.3 134.9 oracle SerV2 0 WPAR Activ 0
oracle 17629634 8.3 134.9 oracle CliV2 0 WPAR Total 0
oracle 13959694 0.0 8.4 oracle SerV3 0 Press: "h"-help
oracle 5439860 0.0 134.3 oracle CliV3 0 "q"-quit
内存参数配置
vmo -F -a --数据库相关参数 minperm% = 3 v_pinshm = 0 lru_file_repage = 0 maxclient% = 90 maxperm% = 90 strict_maxclient = 1 strict_maxperm = 0 page_steal_method = 1
因为是AIX 6.1,这里的vmo配置基本上是oracle 推荐值(大页没有配置,非必须选项)
会话进程占用内存
procmap 15466998
15466998 : oraclewasudb (LOCAL=NO)
100000000 97466K read/exec oracle
11000088d 2430K read/write oracle
9fffffff0000000 51K read/exec /usr/ccs/bin/usla64
9fffffff000cfe2 0K read/write /usr/ccs/bin/usla64
900000000b14930 2K read/exec /usr/lib/libC.a[shr3_64.o]
9001000a0122930 0K read/write /usr/lib/libC.a[shr3_64.o]
900000000af5b00 118K read/exec /usr/lib/libC.a[shrcore_64.o]
9001000a0319100 12K read/write /usr/lib/libC.a[shrcore_64.o]
900000000ad7000 118K read/exec /usr/lib/libC.a[ansicore_64.o]
9001000a030fe00 36K read/write /usr/lib/libC.a[ansicore_64.o]
900000000411468 0K read/exec /usr/lib/libicudata.a[shr_64.o]
9001000a0121468 0K read/write /usr/lib/libicudata.a[shr_64.o]
90000000040f738 2K read/exec /usr/lib/libC.a[shr2_64.o]
9001000a0323738 0K read/write /usr/lib/libC.a[shr2_64.o]
9000000008ec800 1699K read/exec /usr/lib/libC.a[ansi_64.o]
9001000a0324a00 277K read/write /usr/lib/libC.a[ansi_64.o]
9000000008c9b00 135K read/exec /usr/lib/libC.a[shr_64.o]
9001000a031db00 19K read/write /usr/lib/libC.a[shr_64.o]
900000000708180 1732K read/exec /usr/lib/libicuuc.a[shr_64.o]
9001000a036bdac 180K read/write /usr/lib/libicuuc.a[shr_64.o]
900000000493d80 2510K read/exec /usr/lib/libicui18n.a[shr_64.o]
9001000a0399148 270K read/write /usr/lib/libicui18n.a[shr_64.o]
900000000473200 91K read/exec /usr/lib/libsrc.a[shr_64.o]
9001000a01127a8 55K read/write /usr/lib/libsrc.a[shr_64.o]
90000000045a300 98K read/exec /usr/lib/libcorcfg.a[shr_64.o]
9001000a04147c8 18K read/write /usr/lib/libcorcfg.a[shr_64.o]
900000000b16200 750K read/exec /usr/lib/liblvm.a[shr_64.o]
9001000a03dd028 219K read/write /usr/lib/liblvm.a[shr_64.o]
900000000444f00 82K read/exec /usr/lib/libcfg.a[shr_64.o]
9001000a027b8f0 26K read/write /usr/lib/libcfg.a[shr_64.o]
90000000040e3a0 2K read/exec /usr/lib/libcrypt.a[shr_64.o]
9001000a0106948 0K read/write /usr/lib/libcrypt.a[shr_64.o]
90000000233c860 5K read/exec /usr/lib/libc.a[aio_64.o]
9001000a0437568 0K read/write /usr/lib/libc.a[aio_64.o]
9000000003efc00 120K read/exec /usr/lib/libodm.a[shr_64.o]
9001000a0107cc8 40K read/write /usr/lib/libodm.a[shr_64.o]
900000000bd2c80 147K read/exec /usr/lib/libperfstat.a[shr_64.o]
9001000a041a960 14K read/write /usr/lib/libperfstat.a[shr_64.o]
900000000bf8000 0K read/exec /usr/lib/libdl.a[shr_64.o]
9001000a041f000 0K read/write /usr/lib/libdl.a[shr_64.o]
9000000024ac100 8680K read/exec /oracle/product/10g/lib/libjox10.a[shr.o]
8001000a0000ca0 588K read/write /oracle/product/10g/lib/libjox10.a[shr.o]
900000000a96000 257K read/exec /usr/lib/libpthreads.a[shr_xpg5_64.o]
9001000a0283000 559K read/write /usr/lib/libpthreads.a[shr_xpg5_64.o]
900000000000800 4025K read/exec /usr/lib/libc.a[shr_64.o]
9001000a0000020 1047K read/write /usr/lib/libc.a[shr_64.o]
Total 123902K
在上表中,标记为read/write的内存即是进程的私有内存,每个会话大概占用内存近6M,数据库大概有80多个会话,占用内存大概,占用内存大概500M左右.
数据库参数配置
SQL> select sum(PGA_ALLOC_MEM)/1024/1024/1024,count(*) from v$process;
SUM(PGA_ALLOC_MEM)/1024/1024/1024 COUNT(*)
--------------------------------- ----------
2.46758329 84
SQL> show parameter pga;
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
_pga_max_size big integer 500M
pga_aggregate_target big integer 2000M
SQL> show parameter sga
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
lock_sga boolean FALSE
pre_page_sga boolean FALSE
sga_max_size big integer 12000M
sga_target big integer 10000M
SQL> show sga;
Total System Global Area 1.2583E+10 bytes
Fixed Size 2117744 bytes
Variable Size 7600082832 bytes
Database Buffers 4966055936 bytes
Redo Buffers 14655488 bytes
当前系统整体ORACLE使用内存汇总:sga 12G+pga 2.5G+process 0.5G,大概占用内存15G,留给系统内存6G左右,系统使用大量交换分区,导致系统性能下降,最明显的为:shared pool相关latch等待异常,具体awr为:


因为系统因为个别session需要大量内存设置_pga_max_size参数,导致部分会话系统占用2.5g内存,建议设置该参数为默认值,并对个别会话独立设置,设置pga_aggregate_target=1.5G,sga_target=sga_max_size=8.5G,awr结果为:


在不少时候我们需要对一个值是否是null的查询,根据Oracle的特点,我们单纯在在这个列上创建一个index不能满足这个需求,因为b-tree index中就是不包含null列.通过创建含常数列的复合index可以满足该需求
数据库版本
SQL> select * from v$version; BANNER ---------------------------------------------------------------- Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - Prod PL/SQL Release 10.2.0.4.0 - Production CORE 10.2.0.4.0 Production TNS for Linux: Version 10.2.0.4.0 - Production NLSRTL Version 10.2.0.4.0 - Production
创建测试表
SQL> create table t_xifenfei 2 as 3 select * from dba_objects; Table created. SQL> desc t_xifenfei; Name Null? Type ----------------------------------------- -------- ---------------------------- OWNER VARCHAR2(30) OBJECT_NAME VARCHAR2(128) SUBOBJECT_NAME VARCHAR2(30) OBJECT_ID NUMBER DATA_OBJECT_ID NUMBER OBJECT_TYPE VARCHAR2(19) CREATED DATE LAST_DDL_TIME DATE TIMESTAMP VARCHAR2(19) STATUS VARCHAR2(7) TEMPORARY VARCHAR2(1) GENERATED VARCHAR2(1) SECONDARY VARCHAR2(1)
创建可能含null列index
SQL> create index ind_object_id on t_xifenfei(object_id); Index created. SQL> exec dbms_stats.gather_table_stats(user,'T_XIFENFEI',cascade => true); PL/SQL procedure successfully completed.
查看执行计划
SQL> SET AUTOT TRACE EXP stat
SQL> SELECT * FROM T_XIFENFEI WHERE OBJECT_ID IS NULL;
no rows selected
Execution Plan
----------------------------------------------------------
Plan hash value: 548923532
--------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 95 | 159 (2)| 00:00:02 |
|* 1 | TABLE ACCESS FULL| T_XIFENFEI | 1 | 95 | 159 (2)| 00:00:02 |
--------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("OBJECT_ID" IS NULL)
Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
695 consistent gets
0 physical reads
0 redo size
995 bytes sent via SQL*Net to client
389 bytes received via SQL*Net from client
1 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
0 rows processed
可以看到我们创建的一个普通的index,查询判断是否为null的时候,没有被应用该index,而是直接使用全表扫描.
创建支持null index
SQL> drop index ind_object_id ; Index dropped. SQL> create index ind_object_id on t_xifenfei(object_id,0); Index created. SQL> exec dbms_stats.gather_table_stats(user,'T_XIFENFEI',cascade => true); PL/SQL procedure successfully completed.
查看执行计划
SQL> SELECT * FROM T_XIFENFEI WHERE OBJECT_ID IS NULL;
Execution Plan
----------------------------------------------------------
Plan hash value: 804765899
---------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
---------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 95 | 1 (0)| 00:00:01 |
| 1 | TABLE ACCESS BY INDEX ROWID| T_XIFENFEI | 1 | 95 | 1 (0)| 00:00:01 |
|* 2 | INDEX RANGE SCAN | IND_OBJECT_ID | 1 | | 1 (0)| 00:00:01 |
---------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("OBJECT_ID" IS NULL)
Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
2 consistent gets
0 physical reads
0 redo size
995 bytes sent via SQL*Net to client
389 bytes received via SQL*Net from client
1 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
0 rows processed
这里使用了index,并且执行中逻辑读大幅度下降,很大程度提高了程序的执行效率,逻辑读从695降低为2.
原因分析
建立一个包含列和常数的复合index,可以实现该需求,根据b-tree index的特点,只有当index中包含的列都为null的时候,才不会别在index中记录,因为设置了index中包含的常数列,所以就是列为null,也会被包含在该index中,从而查询null值的时候依然可以使用到该index
分析一份awr,发现不太熟悉的等待事件”inactive transaction branch”,awr相关信息如下



分析top 1 sql中的对象
SQL> select * from v$version;
BANNER
-----------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - 64bit Production
PL/SQL Release 11.2.0.2.0 - Production
CORE 11.2.0.2.0 Production
TNS for IBM/AIX RISC System/6000: Version 11.2.0.2.0 - Production
NLSRTL Version 11.2.0.2.0 - Production
SQL> select owner,object_type from dba_objects where object_name =upper('wCommonShortMsg');
OWNER OBJECT_TYPE
------------------------------ -------------------
PUBLIC SYNONYM
OFFONQUERY SYNONYM
SQL> COL DB_LINK FOR A12
SQL> select TABLE_OWNER,TABLE_NAME,DB_LINK from dba_SYNONYMS WHERE
2 SYNONYM_NAME=upper('wCommonShortMsg');
TABLE_OWNER TABLE_NAME DB_LINK
------------------------------ ------------------------------ ------------
WCOMMONSHORTMSG CRMDB_LINK
WCOMMONSHORTMSG DB_LINK_CRM
通过这里查询,可以确定引起dblink相关等待严重的是关于wCommonShortMsg同义词查询导致(使用dblink连接到其他库),结合数据库版本,大致可以确定inactive transaction branch等待和MOS中的bug 10413418相符

![]() |
|