通过ERRORSTACK找出正在运行的SQL中的绑定变量值

July 11th, 2009

oradebg中的ERRORSTACK可以帮我们找到被open中的SQL的绑定变量值。

举例如下:

session A:

SQL> select spid from v$process where addr in (
2 select paddr from v$session where sid in (
3 select sid from v$mystat where rownum=1));

SPID
————————————
29397

SQL> var cnt number
SQL> exec :cnt :=1000000

PL/SQL procedure successfully completed.

SQL> select * from dba_objects where rownum<:cnt;

这个session正在运行时,我们对他做一个level 3的ERRORSTACK

SQL> oradebug setospid 29397
Oracle pid: 58, Unix process pid: 29397, image: oracle@qadb17 (TNS V1-V3)
SQL> oradebug dump errorstack 3
Statement processed.

从trace file中我们可以看到这一段信息:

Cursor#2(ffffffff7b831758) state=ROW curiob=ffffffff7b849e10
curflg=46 fl2=400 par=0 ses=419176ae8
sqltxt(3b421a118)=select * from dba_objects where rownum<:cnt
hash=939f4a697bb3b0f40484e0e412dc34b1
parent=3b3b69db0 maxchild=01 plk=3b8156b20 ppn=n
cursor instantiation=ffffffff7b849e10 used=1247324332
child#0(3b4219f98) pcs=3b3b699c0
clk=3b8157478 ci=3b3b690a8 pn=3b44355f0 ctx=3b3b687f8
kgsccflg=0 llk[ffffffff7b849e18,ffffffff7b849e18] idx=0
xscflg=c0110476 fl2=5200009 fl3=42222008 fl4=100
Bind bytecodes
Opcode = 2 Bind Twotask Scalar Sql In (may be out) Copy
oacdef = 3b3b65378 Offsi = 48, Offsi = 0
kkscoacd
Bind#0
oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
oacflg=03 fl2=1000000 frm=00 csi=00 siz=24 off=0
kxsbbbfp=ffffffff7b8499c8 bln=22 avl=02 flg=05
value=1000000 — 绑定变量值
Frames pfr ffffffff7b849d78 siz=20096 efr ffffffff7b849c48 siz=20024
Cursor frame dump
enxt: 8.0×00000010 enxt: 7.0x00000cc8 enxt: 6.0x00000b58 enxt: 5.0×00001000
enxt: 4.0x00000f88 enxt: 3.0×00000720 enxt: 2.0×00000020 enxt: 1.0x00000f50
pnxt: 2.0×00000038 pnxt: 1.0×00000010
kxscphp ffffffff7b840690 siz=2152 inu=1672 nps=1624
kxscdfhp ffffffff7b840490 siz=984 inu=88 nps=0
kxscbhp ffffffff7b8402b0 siz=984 inu=168 nps=48
kxscwhp ffffffff7b8405a0 siz=1287808 inu=1283808 nps=1283624
Session cached cursors

从这段trace file中可以看到绑定变量为1000000。

Eagle Fan oracle

无题

July 5th, 2009

不知不觉这个blog已经写了有三年半了,其中关于oracle的技术文章占了大多数。

我是从04年开始写blog的,换了三个地方

04~05 ITPUB 无休无止
05~06 MSN Space
06~ www.dbafan.com

这个blog是写的时间最长的,并且打算一直写下去。

今天发现itpub上的blog已经出现了访问的问题,所以打算陆陆续续的把前面两个blog上写过的一些还没有过时的技术文章迁移到这个blog中来。

现在这个blog是在dreamhost上自己申请的空间,可以很方便的备份并且搜索起来也容易多了。

Eagle Fan Life

Tips: PL/SQL中监控执行进度两种方法

July 5th, 2009

这是我常用的两种PL/SQL监控运行状况的方法:

1. 使用dbms_application_info.SET_CLIENT_INFO

举例如下:

declare
cursor cr is select rowid from test;
delete_count number;
total_count number;
begin
delete_count :=0;
total_count :=0;
for i in cr loop
delete from test where rowid=i.rowid;
delete_count :=delete_count+1;
total_count :=total_count+1;
if (delete_count>100) then
dbms_application_info.SET_CLIENT_INFO(‘ So far ‘||total_count||’ rows has been deleted’);
delete_count :=0;
commit;
end if;
end loop;
end;
/

另开一session, select client_info from v$session where client_info like ‘So far%’;

注意info的长度有限制,超过64字符会被截断

2. 使用dbms_system.ksdwrt, 这个可以写到300个字符

KSDWRT Procedure

This procedure prints the message to the target file (alert log and/or trace file).

Syntax

DBMS_SYSTEM.KSDWRT (
dest IN BINARY_INTEGER,
tst IN VARCHAR2);

Parameters:

dest Destination is indicated by the following values:
1 – Write to trace file.
2 – Write to alertlog.
3 – Write to both.

tst Message (not tested for max length, but output with 300 chars was successful)

举例如下:

declare
cursor cr is select rowid from test;
delete_count number;
total_count number;
begin
delete_count :=0;
total_count :=0;
for i in cr loop
delete from test where rowid=i.rowid;
delete_count :=delete_count+1;
total_count :=total_count+1;
if (delete_count>100) then
dbms_system.ksdwrt (1,’ So far ‘||total_count||’ rows has been deleted’);
delete_count :=0;
commit;
end if;
end loop;
end;
/

然后开一session, tail -30f xxx.trc

Eagle Fan oracle

尽量缩短oracle upgrade时间

July 1st, 2009

在做oracle upgrade的时候,因为需要down机,所以节约每一分钟时间都很重要,特别是当需要升级很多台数据库的时候。

我们过去两年的时间内升级了两三百台primary数据库。从节约时间上来说,大致有以下三个tips:

1. 将新的binary copy到服务器上,在维护前先relink all。
2. 在中间startup upgarde的时候采用比较小的SGA参数,这样可以节约allocate和deallocate SGA的时间,特别是对于SGA较大的情况(>20GB)
3. set echo off
这里不仅仅指运行catupgrd.sql前的set echo off,而且要修改两个脚本,将其中的set echo on改为set echo off或者去掉。

\mv $ORACLE_HOME/rdbms/admin/prvthlrt.plb $ORACLE_HOME/rdbms/admin/prvthlrt.plb.bak
sed ‘s/SET ECHO ON/SET ECHO OFF/’ $ORACLE_HOME/rdbms/admin/prvthlrt.plb.bak > $ORACLE_HOME/rdbms/admin/prvthlrt.plb

\mv $ORACLE_HOME/rdbms/admin/catocm.sql $ORACLE_HOME/rdbms/admin/catocm.sql.bak
sed ‘s/set echo on/set echo off/’ $ORACLE_HOME/rdbms/admin/catocm.sql.bak > $ORACLE_HOME/rdbms/admin/catocm.sql

改动这两个脚本可以节约好几分钟的时间。在不同的机器上时间差别可能不同。

我在Sun V440上做过9i到10g的实验,如果不修改文件,需要耗时27分钟,修改后耗时22分钟,相差5分钟。

Eagle Fan oracle 10g

LOB segment上的HW enqueue问题 (9205 version)

June 29th, 2009

第一次遇到这个问题是在2006年,后来陆陆续续的遇到过好几次,都是在9205的版本上。

可是一直没有在自己的blog上好好总结一下。我以为自己写过了,今天想找给别人时才发现没有写过。

数据库版本当时为9205。问题表现为大量的active session等待在mod为6的HW enqueue上。

当前获得enqueue的session执行非常慢,平时小于一秒钟的DML操作现在大约需要几十秒钟才能完成。

查询v$lock得到下面的信息:

SID TY ID1 ID2 LMODE REQUEST CTIME BLOCK
———- — ———- ———- ———- ———- ———- ———-
3575 HW 16 159461642 6 0 18 1
3546 HW 16 159461642 0 6 257 0
3542 HW 16 159461642 0 6 348 0
3468 HW 16 159461642 0 6 31 0
3329 HW 16 159461642 0 6 46 0
2634 HW 16 159461642 0 6 171 0
2565 HW 16 159461642 0 6 94 0
2532 HW 16 159461642 0 6 77 0
2497 HW 16 159461642 0 6 304 0
2179 HW 16 159461642 0 6 386 0
1972 HW 16 159461642 0 6 116 0
1927 HW 16 159461642 0 6 183 0
1777 HW 16 159461642 0 6 209 0
1690 HW 16 159461642 0 6 249 0
1637 HW 16 159461642 0 6 164 0
1616 HW 16 159461642 0 6 17 0
1601 HW 16 159461642 0 6 109 0
1353 HW 16 159461642 0 6 134 0
1236 HW 16 159461642 0 6 320 0
1218 HW 16 159461642 0 6 64 0
1163 HW 16 159461642 0 6 234 0
1150 HW 16 159461642 0 6 291 0
1082 HW 16 159461642 0 6 150 0
1074 HW 16 159461642 0 6 219 0
987 HW 16 159461642 0 6 195 0
713 HW 16 159461642 0 6 374 0
683 HW 16 159461642 0 6 331 0
672 HW 16 159461642 0 6 275 0
535 HW 16 159461642 0 6 361 0
404 HW 16 159461642 0 6 400 0

ID2是DBA,我们可以用“oracle DBA convertor”工具得到相应的File#和Block#

SQL> !dba 159461642

Oracle DBA convertor

by Stephan Haisley, Center Of Expertise, Oracle Corporation
RDBA: 0x981310a (159461642) File#: 38 Block#: 78090

SQL> select segment_name,partition_name,header_file,header_block from
SQL> dba_segments where segment_name=’SYS_LOB0000009458C00013$$’;

SEGMENT_NAME PARTITION_NAME HEADER_FILE HEADER_BLOCK

—————————————- —————————— ———– ————
SYS_LOB0000009458C00013$$ SYS_LOB_P19 38 65289
SYS_LOB0000009458C00013$$ SYS_LOB_P20 46 52489
SYS_LOB0000009458C00013$$ SYS_LOB_P21 38 78089 — 78090 = 78089+1

然后你会发现这个Block并不是Lob segment header,而是Lob segment header后面一个block。注意这一点非常重要,这是这一类问题的标准特征。

如果等待的block是segment header,那么你遇到的不是本文所描述的问题。

一般的HW enqueue发生在segment header上,而后面这个block是什么呢?

说到这个block,要从Lob segment的undo方式说起。Lob segment将old image存放在自己的segment中,而不是undo segment中。
这块存放old image的空间的大小有两种方式来定义,pctversion或者是retention。
对此不熟悉的同学可以参考我以前的两篇文章当ORA-01555遇到了LOBPCTVERSION or RETENTION?

而这个block就是用来记录这些可以被回收的old image blocks,采用bitmap方式存储。

当可回收的old image space超过PCTVERSION定义的百分比时,新增加的数据可以从这些old image space中回收。

但是oracle在回收时有两个bug:

Bug 4867884(Note:4867884.8) – Lob HW lock contention with space reclaimation — fixed in 10.1.0.6, 10.2.0.3, 11g (Future version)
Bug 4113930(Note:4113930.8) – Space reclaimation shows HW enqueue contention with concurrent insert of LOBs — fixed in 9.2.0.8 , 10.1.0.5 , 10.2.0.1

触发这个bug有两个条件
1. 可回收的old image space超过PCTVERSION定义的百分比
2. concurrent transaction超过一定的数值,具体的值不清楚,我遇到问题时的concurrent transaction数目大约为30

所以解决这个问题就从上面两点来入手。

1.

最快解决问题的方法就是调大pctversion。

dump segment header后的那个block(38,78090)
alter system dump datafile 38 block 78090;

找到一行free blocks:10109615,根据这个可以算出free blocks所占的百分比,然后调整pctversion使其大于该百分比,这样就不会有回收空间的动作。
这一方法可以很快的解决问题,就是比较浪费空间。如果有维护的时间,可以通过move的方式来回收空间。

2.

从segment上的并发数入手,例如减少并发量,或者hash partition table使每个segment上面的并发数减少

Eagle Fan oracle