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