我们的文章会在微信公众号IT民工的龙马人生和博客网站( www.htz.pw )同步更新 ，欢迎关注收藏，也欢迎大家转载，但是请在文章开始地方标注文章出处，谢谢！ 由于博客中有大量代码，通过页面浏览效果更佳。
故障分析：分析TRACE文件中报错SQL语句、访问的块、绑定变量信息
下面是一个测试环境，简单介绍在当前trace文件中怎么找到报错sql访问的块与sql的绑定变量。
本案例以ORA-00604/ORA-01555来分析。
1，测试版本
www.htz.pw > select * from v$version where rownum<3;BANNER—————————————————————-Oracle Database 10g Enterprise Edition Release 10.2.0.5.0 – 64biPL/SQL Release 10.2.0.5.0 – Productionwww.htz.pw > !lsb_release -aLSB Version: :core-4.0-amd64:core-4.0-ia32:core-4.0-noarch:graphics-4.0-amd64:graphics-4.0-ia32:graphics-4.0-noarch:printing-4.0-amd64:printing-4.0-ia32:printing-4.0-noarchDistributor ID: RedHatEnterpriseServerDescription: Red Hat Enterprise Linux Server release 4.8 (Tikanga)Release: 4.8Codename: Tikanga2，故障现象
Errors in file /oracle/app/oracle/admin/asm10g/udump/asm10g_ora_4251.trc:ORA-00704: bootstrap process failureORA-00604: error occurred at recursive SQL level 1ORA-01555: snapshot too old: rollback segment number 8 with name "_SYSSMU8$" too small这里看到已经出现了ORA-01555的报错，默认trace文件不包括详细的trace信息
3，配置10046与errorstack
www.htz.pw > oradebug setmypidStatement processed.www.htz.pw > oradebug event 10046 trace name context forever,level 12;Statement processed.www.htz.pw > oradebug event 1555 trace name errorstack forever,level 12;Statement processed.www.htz.pw > alter database open resetlogs;在alert文件中可以发现下面的详细信息
ORA-01555 caused by SQL statement below (SQL ID: 2ajy4zgqrakrx, SCN: 0x0001.4000007b):Sun Jul 20 22:16:45 CST 2014select ts#,file#,block#,nvl(bobj#,0),nvl(tab#,0),intcols,nvl(clucols,0),audit$,flags,pctfree$,pctused$,initrans,maxtrans,rowcnt,blkcnt,empcnt,avgspc,chncnt,avgrln,analyzetime, samplesize,cols,property,nvl(degree,1),nvl(instances,1),avgspc_flb,flbcnt,kernelcols,nvl(trigflag, 0),nvl(spare1,0),nvl(spare2,0),spare4,spare6 from tab$ where obj#=:1Sun Jul 20 22:16:45 CST 2014Errors in file /oracle/app/oracle/admin/asm10g/udump/asm10g_ora_4251.trc:ORA-01555: snapshot too old: rollback segment number 8 with name "???" too smallSun Jul 20 22:16:47 CST 2014Errors in file /oracle/app/oracle/admin/asm10g/udump/asm10g_ora_4251.trc:ORA-01555: snapshot too old: rollback segment number 8 with name "_SYSSMU8$" too smallSun Jul 20 22:16:48 CST 2014Errors in file /oracle/app/oracle/admin/asm10g/udump/asm10g_ora_4251.trc:ORA-00604: error occurred at recursive SQL level 1ORA-01555: snapshot too old: rollback segment number 8 with name "_SYSSMU8$" too smallSun Jul 20 22:16:48 CST 2014Errors in file /oracle/app/oracle/admin/asm10g/udump/asm10g_ora_4251.trc:ORA-00704: bootstrap process failureORA-00604: error occurred at recursive SQL level 1ORA-01555: snapshot too old: rollback segment number 8 with name "_SYSSMU8$" too small这里看到了报错的trace文件。
4，在trace文件中查询详细信息
4.1 查找块与每个块的ITL信息
[root@www.htz.pw ~]#grep -E "^Block he|^0x0" /oracle/app/oracle/admin/asm10g/udump/asm10g_ora_4251.trcBlock header dump: 0x004000260x01 0x0000.007.00000011 0x00400017.0019.43 C— 0 scn 0x0000.000008f60x02 0x0008.012.000000fe 0x008009f2.00dd.02 —- 2 fsc 0x0000.00000000Block header dump: 0x0040007c0x01 0x0007.017.000000b3 0x008062d3.0093.2a –U- 1 fsc 0x0000.00034536Block header dump: 0x004000320x01 0x0004.029.000000ef 0x0080cfb0.00b9.02 C— 0 scn 0x0000.0005661eBlock header dump: 0x004000330x01 0x0005.00e.00000024 0x00800f39.0012.01 CB– 0 scn 0x0000.000109ca0x02 0x0008.02d.000000d2 0x0080007e.00b9.05 –U- 1 fsc 0x0000.0005ed04Block header dump: 0x004000260x01 0x0000.007.00000011 0x00400017.0019.43 C— 0 scn 0x0000.000008f60x02 0x0008.012.000000fe 0x008009f2.00dd.02 —- 2 fsc 0x0000.00000000Block header dump: 0x004000ca0x01 0x0000.000.00000000 0x00000000.0000.00 —- 0 fsc 0x0000.000000000x02 0x0000.044.00000027 0x0040019f.0035.3b –U- 1 fsc 0x0000.0005e5ccBlock header dump: 0x0040006a0x01 0x0000.02e.0000002a 0x00400016.0037.19 –U- 1 fsc 0x0000.00075d1aBlock header dump: 0x004000260x01 0x0000.007.00000011 0x00400017.0019.43 C— 0 scn 0x0000.000008f60x02 0x0008.012.000000fe 0x008009f2.00dd.02 —- 2 fsc 0x0000.00000000Block header dump: 0x0040007c0x01 0x0007.017.000000b3 0x008062d3.0093.2a –U- 1 fsc 0x0000.00034536Block header dump: 0x004000320x01 0x0004.029.000000ef 0x0080cfb0.00b9.02 C— 0 scn 0x0000.0005661eBlock header dump: 0x004000330x01 0x0005.00e.00000024 0x00800f39.0012.01 CB– 0 scn 0x0000.000109ca0x02 0x0008.02d.000000d2 0x0080007e.00b9.05 –U- 1 fsc 0x0000.0005ed04Block header dump: 0x004000260x01 0x0000.007.00000011 0x00400017.0019.43 C— 0 scn 0x0000.000008f60x02 0x0008.012.000000fe 0x008009f2.00dd.02 —- 2 fsc 0x0000.00000000Block header dump: 0x004000ca0x01 0x0000.000.00000000 0x00000000.0000.00 —- 0 fsc 0x0000.000000000x02 0x0000.044.00000027 0x0040019f.0035.3b –U- 1 fsc 0x0000.0005e5ccBlock header dump: 0x0040006a0x01 0x0000.02e.0000002a 0x00400016.0037.19 –U- 1 fsc 0x0000.00075d1aBlock header dump: 0x0040007c0x01 0x0007.017.000000b3 0x008062d3.0093.2a –U- 1 fsc 0x0000.00034536Block header dump: 0x004000320x01 0x0004.029.000000ef 0x0080cfb0.00b9.02 C— 0 scn 0x0000.0005661eBlock header dump: 0x004000330x01 0x0005.00e.00000024 0x00800f39.0012.01 CB– 0 scn 0x0000.000109ca0x02 0x0008.02d.000000d2 0x0080007e.00b9.05 –U- 1 fsc 0x0000.0005ed04Block header dump: 0x004000260x01 0x0000.007.00000011 0x00400017.0019.43 C— 0 scn 0x0000.000008f60x02 0x0008.012.000000fe 0x008009f2.00dd.02 —- 2 fsc 0x0000.00000000Block header dump: 0x004000ca0x01 0x0000.000.00000000 0x00000000.0000.00 —- 0 fsc 0x0000.000000000x02 0x0000.044.00000027 0x0040019f.0035.3b –U- 1 fsc 0x0000.0005e5ccBlock header dump: 0x0040006a0x01 0x0000.02e.0000002a 0x00400016.0037.19 –U- 1 fsc 0x0000.00075d1a4.2 查看报错SQL的等待事件
=====================PARSING IN CURSOR #2 len=343 dep=1 uid=0 oct=3 lid=0 tim=1372915825389474 hv=3983887101 ad=’83688078′select ts#,file#,block#,nvl(bobj#,0),nvl(tab#,0),intcols,nvl(clucols,0),audit$,flags,pctfree$,pctused$,initrans,maxtrans,rowcnt,blkcnt,empcnt,avgspc,chncnt,avgrln,analyzetime, samplesize,cols,property,nvl(degree,1),nvl(instances,1),avgspc_flb,flbcnt,kernelcols,nvl(trigflag, 0),nvl(spare1,0),nvl(spare2,0),spare4,spare6 from tab$ where obj#=:1END OF STMTEXEC #2:c=0,e=37,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=1372915825389473WAIT #2: nam=’db file sequential read’ ela= 254 file#=1 block#=38 blocks=1 obj#=4 tim=1372915825389837这里可能会存在多条此SQL语句
4.3 查看SQL的绑定变量信息
Cursor#2(0x2ba396ac1a88) state=FETCH curiob=0x2ba396adafc8curflg=8007 fl2=200000 par=0x2ba396ac1a20 ses=0x83b8f158sqltxt(0x83688078)=select ts#,file#,block#,nvl(bobj#,0),nvl(tab#,0),intcols,nvl(clucols,0),audit$,flags,pctfree$,pctused$,initrans,maxtrans,rowcnt,blkcnt,empcnt,avgspc,chncnt,avgrln,analyzetime, samplesize,cols,property,nvl(degree,1),nvl(instances,1),avgspc_flb,flbcnt,kernelcols,nvl(trigflag, 0),nvl(spare1,0),nvl(spare2,0),spare4,spare6 from tab$ where obj#=:1hash=3a1c00e80fafeffb2547c4fbed754afdparent=0x8038f1d0 maxchild=01 plk=0x80b3f668 ppn=ncursor instantiation=0x2ba396adafc8 used=1405865804child#0(0x83687e48) pcs=0x8038e7f0clk=0x80b259b0 ci=0x8038e4c8 pn=0x836ead50 ctx=0x7ff93148kgsccflg=1 llk[0x2ba396adafd0,0x2ba396adafd0] idx=fexscflg=e01414f6 fl2=45000401 fl3=4022210c fl4=100Bind bytecodesOpcode = 1 UnoptimizedOffsi = 48, Offsi = 0kkscoacdBind#0oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0kxsbbbfp=2ba3971a9ba0 bln=22 avl=03 flg=05value=2554.4 查看SQL语句访问的块
这里是查看报错时的正在访问的块，在上2步中，我们看到了Cursor#2，在10046中可以找到PARSING IN CURSOR #2，可以看到SQL的WAIT中WAIT #2: nam=’db file sequential read’ ela= 254 file#=1 block#=38 blocks=1 obj#=4 tim=1372915825389837，这就代表最后访问的一个块是1,38
另外我们也可以在相同的版本的数据库中去查询
在trace中以1/38去查看，能找到下面的信息
BH (0x79ff8f58) file#: 1 rdba: 0x00400026 (1/38) class: 1 ba: 0x79f68000set: 3 blksize: 8192 bsi: 0 set-flg: 2 pwbcnt: 0dbwrid: 0 obj: 2 objn: 4 tsn: 0 afn: 1hash: [833bebb8,833bebb8] lru: [79ff90e8,79ff8ec8]obj-flags: object_ckpt_listckptq: [829a5d30,829a5d30] fileq: [829a5d50,829a5d50] objq: [80b4d860,80b4d860]use: [829956a0,829956a0] wait: [NULL]st: XCURRENT md: SHR tch: 0flags: buffer_dirty redo_since_readLRBA: [0x1.3.0] HSCN: [0x1.4000007b] HSUB: [1]buffer tsn: 0 rdba: 0x00400026 (1/38)scn: 0x0001.4000007b seq: 0x01 flg: 0x00 tail: 0x007b0601frmt: 0x02 chkval: 0x0000 type: 0x06=trans dataHex dump of block: st=0, typ_found=1在以0x00400026能查找到下面信息
Block header dump: 0x00400026Object id on Block? Yseg/obj: 0x2 csc: 0x01.4000007b itc: 2 flg: – typ: 1 – DATAfsl: 0 fnx: 0x0 ver: 0x01Itl Xid Uba Flag Lck Scn/Fsc0x01 0x0000.007.00000011 0x00400017.0019.43 C— 0 scn 0x0000.000008f60x02 0x0008.012.000000fe 0x008009f2.00dd.02 —- 2 fsc 0x0000.00000000到此块的信息已经找到了。
------------------作者介绍-----------------------
姓名：黄廷忠 现就职：Oracle中国高级服务团队 曾就职：OceanBase、云和恩墨、东方龙马等 电话、微信、QQ：18081072613
CSDN地址: (https://blog.csdn.net/wwwhtzpw)
博客园地址: (https://www.cnblogs.com/www-htz-pw)
