• 10046事件跟踪会话sql


    背景知识:

    10046 事件按照收集信息内容,可以分成4个级别:

    Level 1: 等同于SQL_TRACE 的功能
    Level 4: 在Level 1的基础上增加收集绑定变量的信息
    Level 8: 在Level 1 的基础上增加等待事件的信息
    Level 12:等同于Level 4+Level 8, 即同时收集绑定变量信息和等待事件信息。

    一: 跟踪当前会话sql

    1. sys用户给执行跟踪dblink用户授权
    SQL> grant alter session to dblink;
    Grant succeeded.

    2. 返回dblink用户操作
    SQL> show user;
    USER is "DBLINK"

    3. 查询sid,serial#
    SQL> select sid,serial# from v$session where username='DBLINK';
    SID SERIAL#
    ---------- ----------
    45 14

    4. 查询当前用户的trace文件
    SQL> select * from v$diag_info where name like 'Default%';

    INST_ID NAME
    ---------- ----------------------------------------------------------------
    VALUE
    --------------------------------------------------------------------------------
    1 Default Trace File
    /home/oracle/app/diag/rdbms/orcl/orcl/trace/orcl_ora_2823.trc

    5. 启动10046事件
    SQL> alter session set events '10046 trace name context forever, level 12';

    Session altered.

    6. 执行测试sql(即将被跟踪的sql)
    SQL> variable a number; #含有绷定变量的sql
    SQL> exec :a:=2;
    PL/SQL procedure successfully completed.

    SQL> select count(*) from dba_objects where object_id=:a;

    COUNT(*)
    ----------

    7. 关闭10046事件
    SQL> alter session set events '10046 trace name context off';
    Session altered.

    8.1 查看原始10046后的trace文件 注意:10046事件的trace文件内容是sql按时间顺序执行的结果

    [oracle@11g ~]$ vi /home/oracle/app/diag/rdbms/orcl/orcl/trace/orcl_ora_2823.trc

    Trace file /home/oracle/app/diag/rdbms/orcl/orcl/trace/orcl_ora_2823.trc
    Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
    With the Partitioning, OLAP, Data Mining and Real Application Testing options
    ORACLE_HOME = /home/oracle/app/oracle/product/11.2.0/dbhome_1
    System name: Linux
    Node name: 11g
    Release: 2.6.32-573.el6.x86_64
    Version: #1 SMP Thu Jul 23 15:44:03 UTC 2015
    Machine: x86_64
    Instance name: orcl
    Redo thread mounted by this instance: 1
    Oracle process number: 32
    Unix process pid: 2823, image: oracle@11g (TNS V1-V3)

    *** 2014-11-19 04:42:30.941
    *** SESSION ID:(45.14) 2014-11-19 04:42:30.941
    *** CLIENT ID:() 2014-11-19 04:42:30.941
    *** SERVICE NAME:(SYS$USERS) 2014-11-19 04:42:30.941
    *** MODULE NAME:(SQL*Plus) 2014-11-19 04:42:30.941
    *** ACTION NAME:() 2014-11-19 04:42:30.941

    WAIT #2: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416390150940558

    *** 2014-11-19 04:44:47.004
    WAIT #2: nam='SQL*Net message from client' ela= 136063164 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416390287004294
    CLOSE #2:c=0,e=3,dep=0,type=3,tim=1416390287004441
    =====================
    PARSING IN CURSOR #5 len=19 dep=0 uid=90 oct=47 lid=90 tim=1416390287005001 hv=3805855218 ad='87972f88' sqlid='1w9223jdjggk'
    BEGIN :a:=2; END;
    END OF STMT
    PARSE #5:c=0,e=467,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1416390287005001
    BINDS #5:
    Bind#0
    oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
    oacflg=03 fl2=1000000 frm=00 csi=00 siz=24 off=0
    kxsbbbfp=7fd108695a28 bln=22 avl=00 flg=05
    WAIT #5: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416390287006240
    EXEC #5:c=1999,e=1191,p=0,cr=0,cu=0,mis=1,r=1,dep=0,og=1,plh=0,tim=1416390287006261


    *** 2014-11-19 04:56:00.212
    WAIT #5: nam='SQL*Net message from client' ela= 673206425 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416390960212735
    CLOSE #5:c=0,e=49,dep=0,type=0,tim=1416390960212948
    =====================
    PARSING IN CURSOR #1 len=51 dep=0 uid=90 oct=3 lid=90 tim=1416390960213839 hv=3085049059 ad='87973410' sqlid='214vxnyvy4773'
    select count(*) from dba_objects where object_id=:a
    END OF STMT
    PARSE #1:c=1000,e=844,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1416390960213838
    =====================
    PARSING IN CURSOR #6 len=37 dep=1 uid=0 oct=3 lid=0 tim=1416390960214450 hv=1398610540 ad='9a8c2c00' sqlid='grwydz59pu6mc'
    select text from view$ where rowid=:1
    END OF STMT
    PARSE #6:c=1000,e=408,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1416390960214449
    =====================
    PARSING IN CURSOR #2 len=210 dep=2 uid=0 oct=3 lid=0 tim=1416390960215089 hv=864012087 ad='8a7b0300' sqlid='96g93hntrzjtr'
    select /*+ rule */ bucket_cnt, row_cnt, cache_cnt, null_cnt, timestamp#, sample_size, minimum, maximum, distcnt, lowval, hival, density, col#, spare1, spare2, avgcln from hist_head$ where obj#=:1 and intcol#=:2
    END OF STMT
    PARSE #2:c=0,e=292,p=0,cr=0,cu=0,mis=1,r=0,dep=2,og=3,plh=0,tim=1416390960215089
    BINDS #2:
    Bind#0
    oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
    oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
    kxsbbbfp=7fd108751d48 bln=22 avl=02 flg=05
    value=69
    Bind#1
    oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
    oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
    kxsbbbfp=7fd108751d18 bln=24 avl=03 flg=05
    value=1001
    EXEC #2:c=1000,e=9315,p=0,cr=0,cu=0,mis=1,r=0,dep=2,og=3,plh=2239883476,tim=1416390960224458
    FETCH #2:c=0,e=28,p=0,cr=2,cu=0,mis=0,r=0,dep=2,og=3,plh=2239883476,tim=1416390960224573
    STAT #2 id=1 cnt=0 pid=0 pos=1 obj=424 op='TABLE ACCESS BY INDEX ROWID HIST_HEAD$ (cr=2 pr=0 pw=0 time=0 us)'
    STAT #2 id=2 cnt=0 pid=1 pos=1 obj=426 op='INDEX RANGE SCAN I_HH_OBJ#_INTCOL# (cr=2 pr=0 pw=0 time=0 us)'
    CLOSE #2:c=0,e=2,dep=2,type=3,tim=1416390960224765
    =====================
    PARSING IN CURSOR #5 len=210 dep=2 uid=0 oct=3 lid=0 tim=1416390960224900 hv=864012087 ad='8a7b0300' sqlid='96g93hntrzjtr'
    select /*+ rule */ bucket_cnt, row_cnt, cache_cnt, null_cnt, timestamp#, sample_size, minimum, maximum, distcnt, lowval, hival, density, col#, spare1, spare2, avgcln from hist_head$ where obj#=:1 and intcol#=:2
    END OF STMT
    BINDS #5:
    Bind#0
    oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
    oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
    kxsbbbfp=7fd108751d48 bln=22 avl=02 flg=05
    value=69
    Bind#1
    oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
    oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
    kxsbbbfp=7fd108751d18 bln=24 avl=02 flg=05
    value=8
    EXEC #5:c=0,e=132,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=3,plh=2239883476,tim=1416390960225016
    FETCH #5:c=0,e=12,p=0,cr=2,cu=0,mis=0,r=0,dep=2,og=3,plh=2239883476,tim=1416390960225045
    CLOSE #5:c=0,e=1,dep=2,type=3,tim=1416390960225068
    BINDS #6:
    Bind#0
    oacdty=11 mxl=16(16) mxlc=00 mal=00 scl=00 pre=00
    oacflg=18 fl2=0001 frm=00 csi=00 siz=16 off=0
    kxsbbbfp=7fd1086aa078 bln=16 avl=16 flg=05

    。。。。。 省略大量输出

    "~/app/diag/rdbms/orcl/orcl/trace/orcl_ora_2823.trc" 148L, 8943C

    8.2 使用tkprof工具查看10046时间的trace文件
    [oracle@11g ~]$ tkprof /home/oracle/app/diag/rdbms/orcl/orcl/trace/orcl_ora_2823.trc andy.txt sys=no

    TKPROF: Release 11.2.0.1.0 - Development on Wed Nov 19 05:00:35 2014

    Copyright (c) 1982, 2009, Oracle and/or its affiliates. All rights reserved.

    [oracle@11g ~]$ vi andy.txt

    from
    dba_objects where object_id=:a

    call count cpu elapsed disk query current rows
    ------- ------ -------- ---------- ---------- ---------- ---------- ----------
    Parse 1 0.00 0.00 0 0 0 0
    Execute 1 0.00 0.00 0 0 0 0
    Fetch 2 0.00 0.00 0 5 0 1
    ------- ------ -------- ---------- ---------- ---------- ---------- ----------
    total 4 0.01 0.00 0 5 0 1

    Misses in library cache during parse: 1
    Misses in library cache during execute: 1
    Optimizer mode: ALL_ROWS
    Parsing user id: 90

    Rows Row Source Operation # 执行计划
    ------- ---------------------------------------------------
    1 SORT AGGREGATE (cr=5 pr=0 pw=0 time=0 us)
    1 VIEW DBA_OBJECTS (cr=5 pr=0 pw=0 time=0 us cost=5 size=26 card=2)
    1 UNION-ALL (cr=5 pr=0 pw=0 time=0 us)
    1 FILTER (cr=5 pr=0 pw=0 time=0 us)
    1 NESTED LOOPS (cr=5 pr=0 pw=0 time=0 us cost=5 size=71 card=1)
    1 NESTED LOOPS (cr=4 pr=0 pw=0 time=0 us cost=4 size=67 card=1)
    1 TABLE ACCESS BY INDEX ROWID OBJ$ (cr=3 pr=0 pw=0 time=0 us cost=3 size=45 card=1)
    1 INDEX RANGE SCAN I_OBJ1 (cr=2 pr=0 pw=0 time=0 us cost=2 size=0 card=1)(object id 36)
    1 INDEX RANGE SCAN I_USER2 (cr=1 pr=0 pw=0 time=0 us cost=1 size=22 card=1)(object id 47)
    1 INDEX RANGE SCAN I_USER2 (cr=1 pr=0 pw=0 time=0 us cost=1 size=4 card=1)(object id 47)
    0 TABLE ACCESS BY INDEX ROWID IND$ (cr=0 pr=0 pw=0 time=0 us cost=2 size=8 card=1)
    0 INDEX UNIQUE SCAN I_IND1 (cr=0 pr=0 pw=0 time=0 us cost=1 size=0 card=1)(object id 41)
    0 NESTED LOOPS (cr=0 pr=0 pw=0 time=0 us cost=2 size=29 card=1)
    0 INDEX FULL SCAN I_USER2 (cr=0 pr=0 pw=0 time=0 us cost=1 size=20 card=1)(object id 47)
    0 INDEX RANGE SCAN I_OBJ4 (cr=0 pr=0 pw=0 time=0 us cost=1 size=9 card=1)(object id 39)

    ————————————————————————————————————————————————————

    二:跟踪指定会话 (具体步骤参上面部分,这里简写)

    使用10046 事件跟踪启动trace
    SQL> exec dbms_monitor.session_trace_enable(45,14,waits=>true,binds=>true)
    PL/SQL procedure successfully completed.

    关闭trace
    SQL> exec dbms_monitor.session_trace_disable(45,14);
    PL/SQL procedure successfully completed.

    OK,结束。 转载请标明出处。

    10046 事件按照收集信息内容,可以分成4个级别:

    Level 1: 等同于SQL_TRACE 的功能
    Level 4: 在Level 1的基础上增加收集绑定变量的信息
    Level 8: 在Level 1 的基础上增加等待事件的信息
    Level 12:等同于Level 4+Level 8, 即同时收集绑定变量信息和等待事件信息。

  • 相关阅读:
    ubuntu查看系统负载和程序运行状况
    ubuntu 离线装包
    python如何离线装包 离线如何部署python环境
    开发板上如何配置apahe2+mysql+php7
    c++指针实例
    nginx反向代理nginx,RealServer日志打印真实ip
    lvs+keep搭建高可用web服务
    linux一键安装vncserver脚本
    ansible 学习与实践
    centos7编译安装MySQL5.7.9
  • 原文地址:https://www.cnblogs.com/andy6/p/6202002.html
Copyright © 2020-2023  润新知