[20200424]跟蹤特定sql語句以及v$open_cursor檢視(再補充).txt

[20200424]跟蹤特定sql語句以及v$open_cursor檢視(再補充).txt

--//前幾天寫的http://blog.itpub.net/267265/viewspace-2687519/ => [20200422]跟蹤特定sql語句以及v$open_cursor檢視(補充).txt
--//昨天才知道防水牆可能導致軟軟解析失效.連結 :http://blog.itpub.net/267265/viewspace-2687922/.
--//也就是前面測試想當然認為oracle exadata環境與我的測試環境補丁不同.實際上可能在exadata問題依舊.
--//在exadata重複測試看看.

1.環境:
PPPPP_HHH@xxxx> @ ver1
PORT_STRING                    VERSION        BANNER
------------------------------ -------------- --------------------------------------------------------------------------------
x86_64/Linux 2.4.xx            11.2.0.4.0     Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production

--//session 2:
SYS@xxxx> alter system set events 'sql_trace off';
System altered.
--//初始化這步不要忘記!!避免影響下面的測試。我在這裡犯了幾次錯誤，無法重演我遇到的問題。

$ cat voc.sql
column SID format 9999
column USER_NAME format a10
column CURSOR_TYPE format a32
column SQL_TEXT format a34
select * from v$open_cursor where sql_id='&&1' and sid=&&2;

$ cat vocx.sql
column KGLLKCTP format A32
column KGLNAOBJ format a34
SELECT inst_id
      ,kgllkuse
      ,kgllksnm
      ,user_name
      ,kglhdpar
      ,kglnahsh
      ,kgllksqlid
      ,kglnaobj
      ,kgllkest
      ,DECODE (kgllkexc, 0, TO_NUMBER (NULL), kgllkexc)
      ,kgllkctp
      ,kgllkhdl
  FROM x$kgllk
 WHERE     kglhdnsp = 0
       AND kglhdpar != kgllkhdl
       AND kgllksqlid = '&&1'
       AND kgllksnm = &&2;

--//session 1:
PPPPP_HHH@xxxx> select 8 from dual;

         8
----------
         8

PPPPP_HHH@xxxx> @ hash
HASH_VALUE SQL_ID        CHILD_NUMBER HASH_HEX
---------- ------------- ------------ ---------
 925730553 43jhwwsvkv1rt            0  372d86f9
--//執行多次,避免被踢出共享池.

PPPPP_HHH@xxxx> @ hash
HASH_VALUE SQL_ID        CHILD_NUMBER HASH_HEX
---------- ------------- ------------ ---------
 925730553 43jhwwsvkv1rt            0  372d86f9
--//記下sql_id=43jhwwsvkv1rt。:

2.測試:
--//session 2:
SYS@xxxx>  alter system set events 'sql_trace [sql:sql_id=43jhwwsvkv1rt] bind=true, wait=true';
System altered.

--//session 1:
--//重新登入:
PPPPP_HHH@xxxx> @ spid

       SID    SERIAL# PROCESS                  SERVER    SPID       PID  P_SERIAL# C50
---------- ---------- ------------------------ --------- ------ ------- ---------- --------------------------------------------------
       656      43525 13050                    DEDICATED 45169     2090        139 alter system kill session '656,43525' immediate;
--//記下sid=656.

select 8 from dual;
select 8 from dual;
select 8 from dual;
select 8 from dual;
select 8 from dual;

--//每次執行select 8 from dual;前在session 2 都執行@vcs 43jhwwsvkv1rt &session1_sid(這裡656).

SYS@xxxx> set verify off
SYS@xxxx> @ voc 43jhwwsvkv1rt 656
no rows selected

SYS@xxxx> @ voc 43jhwwsvkv1rt 656
SADDR              SID USER_NAME  ADDRESS          HASH_VALUE SQL_ID        SQL_TEXT           LAST_SQL_ACTIVE_TIM SQL_EXEC_ID CURSOR_TYPE
---------------- ----- ---------- ---------------- ---------- ------------- ------------------ ------------------- ----------- --------------------------------
00000012D2230988   656 PPPPP_HHH 00000000BF7AFEC8  925730553 43jhwwsvkv1rt select 8 from dual                                 OPEN

SYS@xxxx> @ voc 43jhwwsvkv1rt 656
SADDR              SID USER_NAME  ADDRESS          HASH_VALUE SQL_ID        SQL_TEXT           LAST_SQL_ACTIVE_TIM SQL_EXEC_ID CURSOR_TYPE
---------------- ----- ---------- ---------------- ---------- ------------- ------------------ ------------------- ----------- --------------------------------
00000012D2230988   656 PPPPP_HHH 00000000BF7AFEC8  925730553 43jhwwsvkv1rt select 8 from dual                                 OPEN

SYS@xxxx> @ voc 43jhwwsvkv1rt 656
SADDR              SID USER_NAME  ADDRESS          HASH_VALUE SQL_ID        SQL_TEXT           LAST_SQL_ACTIVE_TIM SQL_EXEC_ID CURSOR_TYPE
---------------- ----- ---------- ---------------- ---------- ------------- ------------------ ------------------- ----------- --------------------------------
00000012D2230988   656 PPPPP_HHH 00000000BF7AFEC8  925730553 43jhwwsvkv1rt select 8 from dual                                 OPEN

SYS@xxxx> @ voc 43jhwwsvkv1rt 656
SADDR              SID USER_NAME  ADDRESS          HASH_VALUE SQL_ID        SQL_TEXT           LAST_SQL_ACTIVE_TIM SQL_EXEC_ID CURSOR_TYPE
---------------- ----- ---------- ---------------- ---------- ------------- ------------------ ------------------- ----------- --------------------------------
00000012D2230988   656 PPPPP_HHH 00000000BF7AFEC8  925730553 43jhwwsvkv1rt select 8 from dual                                 OPEN
00000012D2230988   656 PPPPP_HHH 00000000BF7AFEC8  925730553 43jhwwsvkv1rt select 8 from dual                                 DICTIONARY LOOKUP CURSOR CACHED

SYS@xxxx> @ voc 43jhwwsvkv1rt 656
SADDR              SID USER_NAME  ADDRESS          HASH_VALUE SQL_ID        SQL_TEXT           LAST_SQL_ACTIVE_TIM SQL_EXEC_ID CURSOR_TYPE
---------------- ----- ---------- ---------------- ---------- ------------- ------------------ ------------------- ----------- --------------------------------
00000012D2230988   656 PPPPP_HHH 00000000BF7AFEC8  925730553 43jhwwsvkv1rt select 8 from dual                                 OPEN
00000012D2230988   656 PPPPP_HHH 00000000BF7AFEC8  925730553 43jhwwsvkv1rt select 8 from dual                                 DICTIONARY LOOKUP CURSOR CACHED
00000012D2230988   656 PPPPP_HHH 00000000BF7AFEC8  925730553 43jhwwsvkv1rt select 8 from dual                                 DICTIONARY LOOKUP CURSOR CACHED
--//問題再現，我前面遇到消失情況實際上防水牆導致自動關閉游標，不會出現軟軟解析。

--//session 1:
PPPPP_HHH@xxxx> @ ver
BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production

--//session 2:
SYS@xxxx> @ voc 43jhwwsvkv1rt 656
SADDR              SID USER_NAME  ADDRESS          HASH_VALUE SQL_ID        SQL_TEXT           LAST_SQL_ACTIVE_TIM SQL_EXEC_ID CURSOR_TYPE
---------------- ----- ---------- ---------------- ---------- ------------- ------------------ ------------------- ----------- --------------------------------
00000012D2230988   656 PPPPP_HHH 00000000BF7AFEC8  925730553 43jhwwsvkv1rt select 8 from dual                                 DICTIONARY LOOKUP CURSOR CACHED
00000012D2230988   656 PPPPP_HHH 00000000BF7AFEC8  925730553 43jhwwsvkv1rt select 8 from dual                                 DICTIONARY LOOKUP CURSOR CACHED
00000012D2230988   656 PPPPP_HHH 00000000BF7AFEC8  925730553 43jhwwsvkv1rt select 8 from dual                                 DICTIONARY LOOKUP CURSOR CACHED

SYS@xxxx> @vocx 43jhwwsvkv1rt 656
   INST_ID KGLLKUSE           KGLLKSNM USER_NAME  KGLHDPAR           KGLNAHSH KGLLKSQLID    KGLNAOBJ           KGLLKEST            DECODE(KGLLKEXC,0,TO_NUMBER(NULL),KGLLKEXC) KGLLKCTP                         KGLLKHDL
---------- ---------------- ---------- ---------- ---------------- ---------- ------------- ------------------ ------------------- ------------------------------------------- -------------------------------- ----------------
         1 00000012D2230988        656 PPPPP_HHH 00000000BF7AFEC8  925730553 43jhwwsvkv1rt select 8 from dual                                                                 DICTIONARY LOOKUP CURSOR CACHED  00000000BC239B40
         1 00000012D2230988        656 PPPPP_HHH 00000000BF7AFEC8  925730553 43jhwwsvkv1rt select 8 from dual                                                                 DICTIONARY LOOKUP CURSOR CACHED  00000000BC239B40
         1 00000012D2230988        656 PPPPP_HHH 00000000BF7AFEC8  925730553 43jhwwsvkv1rt select 8 from dual                                                                 DICTIONARY LOOKUP CURSOR CACHED  00000000BC239B40

SYS@xxxx> @ tpt/sqlid 43jhwwsvkv1rt ''
Show SQL text, child cursors and execution stats for SQLID 43jhwwsvkv1rt child nvl('','%')
HASH_VALUE PLAN_HASH_VALUE  CH# SQL_TEXT
---------- --------------- ---- ------------------
 925730553      1388734953    0 select 8 from dual

 CH# PARENT_HANDLE    OBJECT_HANDLE     PLAN_HASH     PARSES   H_PARSES EXECUTIONS    FETCHES ROWS_PROCESSED ROWS_PER_FETCH    CPU_SEC CPU_SEC_EXEC    ELA_SEC ELA_SEC_EXEC       LIOS  LIOS_EXEC       PIOS      SORTS USERS_EXECUTING
---- ---------------- ---------------- ---------- ---------- ---------- ---------- ---------- -------------- -------------- ---------- ------------ ---------- ------------ ---------- ---------- ---------- ---------- ---------------
   0 00000000BF7AFEC8 00000000BF7AFD58 1388734953         24          1         24         24             24              1       .002   .000083333    .002218   .000092417          0          0          0          0               0
   1 00000000BF7AFEC8 00000000BC239B40 1388734953          5          1          5          5              5              1       .003        .0006    .002805      .000561          0          0          0          0               0

--//跟蹤時選擇是child_number=1的子游標。KGLLKHDL=00000000BC239B40.

3.檢查跟蹤檔案：
$  grep 43jhwwsvkv1rt dbcn1_ora_45169.trc
PARSING IN CURSOR #140662105231976 len=18 dep=0 uid=103 oct=3 lid=103 tim=1587689561363057 hv=925730553 ad='bf7afec8' sqlid='43jhwwsvkv1rt'
PARSING IN CURSOR #140662105231976 len=18 dep=0 uid=103 oct=3 lid=103 tim=1587689566752744 hv=925730553 ad='bf7afec8' sqlid='43jhwwsvkv1rt'
PARSING IN CURSOR #140662105231976 len=18 dep=0 uid=103 oct=3 lid=103 tim=1587689569936774 hv=925730553 ad='bf7afec8' sqlid='43jhwwsvkv1rt'
PARSING IN CURSOR #140662105230728 len=18 dep=0 uid=103 oct=3 lid=103 tim=1587689572416776 hv=925730553 ad='bf7afec8' sqlid='43jhwwsvkv1rt'
PARSING IN CURSOR #140662105299672 len=18 dep=0 uid=103 oct=3 lid=103 tim=1587689575408820 hv=925730553 ad='bf7afec8' sqlid='43jhwwsvkv1rt'
--//可以發現再現我測試環境遇到的測試環境一樣的問題。
--//PARSING IN CURSOR #NNNNNNNNNNNNNNN的後面數字會變我不知道什麼回事。

4.總結：
1.思考問題不能想當然。
2.有機會認真學習防水牆的工作機制，另外一點也說明我們上線缺乏嚴謹的測試，不能商家這樣吹噓。