[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.有机会认真学习防水墙的工作机制，另外一点也说明我们上线缺乏严谨的测试，不能商家这样吹嘘。