[20170515]数据库启动的一个疑问.txt
--//别人问的问题我自己以前也没有注意,做一个记录.
1.环境:
SYS@book> startup mount
ORACLE instance started.
Total System Global Area 634732544 bytes
Fixed Size 2255792 bytes
Variable Size 197133392 bytes
Database Buffers 427819008 bytes
Redo Buffers 7524352 bytes
Database mounted.
SYS@book> @ &r/10046on 12
Session altered.
SYS@book> alter database open ;
Database altered.
SYS@book> @ &r/10046off
Session altered.
2.问题:
$ grep -i "^update" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_34905.trc
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
--//仅仅看到3行update.
$ tkprof /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_34905.trc
output = aa
TKPROF: Release 11.2.0.4.0 - Development on Mon May 15 11:15:30 2017
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
--//检查aa.prf文件:
********************************************************************************
SQL ID: 8vyjutx6hg3wh Plan Hash: 3078630091
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,
undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13
where
us#=:1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 20 0.00 0.00 0 0 0 0
Execute 20 0.00 0.00 1 20 42 20
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 40 0.00 0.00 1 20 42 20
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: RULE
Parsing user id: SYS (recursive depth: 1)
Number of plan statistics captured: 3
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
0 0 0 UPDATE UNDO$ (cr=1 pr=0 pw=0 time=111 us)
1 1 1 INDEX UNIQUE SCAN I_UNDO1 (cr=1 pr=0 pw=0 time=3 us)(object id 34)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 1 0.00 0.00
********************************************************************************
--//很明显执行20次.而不是前面显示的3次.
3.分析:
=====================
PARSING IN CURSOR #140657324151688 len=160 dep=1 uid=0 oct=6 lid=0 tim=1494818056965769 hv=1292341136 ad='7da43060' sqlid='8vyjutx6hg3wh'
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
END OF STMT
PARSE #140657324151688:c=1000,e=1711,p=3,cr=39,cu=0,mis=1,r=0,dep=1,og=3,plh=0,tim=1494818056965769
BINDS #140657324151688:
...
value=1
WAIT #140657324151688: nam='db file sequential read' ela= 7 file#=1 block#=135 blocks=1 obj#=0 tim=1494818056966806
EXEC #140657324151688:c=1000,e=1085,p=1,cr=1,cu=3,mis=1,r=1,dep=1,og=3,plh=3078630091,tim=1494818056966917
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
STAT #140657324151688 id=1 cnt=0 pid=0 pos=1 obj=0 op='UPDATE UNDO$ (cr=1 pr=1 pw=0 time=241 us)'
STAT #140657324151688 id=2 cnt=1 pid=1 pos=1 obj=34 op='INDEX UNIQUE SCAN I_UNDO1 (cr=1 pr=0 pw=0 time=4 us)'
CLOSE #140657324151688:c=0,e=3,dep=1,type=0,tim=1494818056966968
WAIT #140657327122216: nam='db file sequential read' ela= 7 file#=3 block#=128 blocks=1 obj#=0 tim=1494818056967067
--//如果你这样查看:
$ grep "plh=3078630091" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_34905.trc | grep EXEC|wc
20 40 2082
--//很明显这个session_cached_cursors有关.
SYS@book> show parameter session_cached_cursors
NAME TYPE VALUE
------------------------------------ -------- ------
session_cached_cursors integer 50
SYS@book> alter system set session_cached_cursors=0 scope=spfile ;
System altered.
--//重复测试:
$ grep "^update" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_35075.trc
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
$ grep "^update" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_35075.trc|wc
20 180 3220
--//正好20行.
SYS@book> column name format a40
SYS@book> select US#,NAME from sys.undo$;
US# NAME
---------- ----------------------------------------
0 SYSTEM
1 _SYSSMU1_3724004606$
2 _SYSSMU2_2996391332$
3 _SYSSMU3_1723003836$
4 _SYSSMU4_1254879796$
5 _SYSSMU5_898567397$
6 _SYSSMU6_1263032392$
7 _SYSSMU7_2070203016$
8 _SYSSMU8_517538920$
9 _SYSSMU9_1650507775$
10 _SYSSMU10_1197734989$
11 _SYSSMU11_894599432$
12 _SYSSMU12_1573055333$
13 _SYSSMU13_3860906822$
14 _SYSSMU14_3319140121$
15 _SYSSMU15_1436577151$
16 _SYSSMU16_1689093467$
17 _SYSSMU17_1049158485$
18 _SYSSMU18_1557221903$
19 _SYSSMU19_2284825117$
20 _SYSSMU20_2312497597$
21 rows selected.
--//这个提示在分析跟踪文件时应该注意!!前几天看 [20170511]sed awk抽取段落技巧.txt,链接
http://blog.itpub.net/267265/viewspace-2138877/
$ cat extractsql.sh
#! /bin/bash
awk '/PARSING IN CURSOR/,/END OF STMT/' $1 | egrep -v '^PARSING|^END OF STMT'
--//这样抽取的脚本会漏掉一些语句,至少执行测试次数不对.
4.其他问题:
SYS@book> @ &r/sharepool/shp4 8vyjutx6hg3wh 0
old 18: WHERE kglobt03 = '&1' or kglhdpar='&1' or kglhdadr='&1' or KGLNAHSH= &2
new 18: WHERE kglobt03 = '8vyjutx6hg3wh' or kglhdpar='8vyjutx6hg3wh' or kglhdadr='8vyjutx6hg3wh' or KGLNAHSH= 0
TEXT KGLHDADR KGLHDPAR C40 KGLHDIVC KGLOBHD0 KGLOBHD6 KGLOBHS0 KGLOBHS6 KGLOBT16 N0_6_16 N20 KGLNAHSH KGLOBT03 KGLOBT09
-------------- ---------------- ---------------- ---------------------------------------- ---------- ---------------- ---------------- ---------- ---------- ---------- --------- ---------- ---------- ------------- ----------
子游标句柄地址 000000007DA44448 000000007DA458C8 update /*+ rule */ undo$ set name=:2,fil 1 00 00 0 0 3457 3457 3457 1292341136 8vyjutx6hg3wh 0
父游标句柄地址 000000007DA458C8 000000007DA458C8 update /*+ rule */ undo$ set name=:2,fil 1 000000007DA45810 00 4848 0 0 4848 4848 1292341136 8vyjutx6hg3wh 65535
--//很奇怪这个启动完成,子光标就清除了,仅仅保留父游标信息,查询v$sql视图无法查询到结果,不知道oracle为什么这样设计.
SYS@book> select * from v$sql where sql_id='8vyjutx6hg3wh';
no rows selected
--//那位知道为什么???
