[20170515]資料庫啟動的一個疑問.txt

[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

--//那位知道為什麼???