BigdataLyn's TECH Blog! 刀不磨要生锈,人不学习要落后 - Thinking ahead

Oracle 10046 event Tips

2020-05-14

Oracle 10046 event Tips

10046 event

  • 1.开启10046跟踪事件
alter session set events '10046 trace name context forever, level 12';

如果想更容易标识trace文件,在开启事件之前,可以先设置trace的标识

alter session set tracefile_identifier='INSERT_SQL';

这样完成后,trace文件名称就会加上INSERT_SQL

  • 2.执行要跟踪的sql语句(对应的trace文件中有SQL的执行情况)
select * from dba_users where username='SCOTT';
  • 3.停止10046事件跟踪
alter session set events '10046 trace name context off';
  • 4.定位此次生成的trace文件
select distinct(m.sid),p.pid,p.tracefile from v$mystat m,v$session s,v$process p where m.sid=s.sid and s.paddr=p.addr;
  • 5.用tkprof工具格式化文件输出
tkprof xxxx xxxx.out

Shell Scripts for events


STARTTIME=`date +%s`

sqlplus sys/oracle@PDB1 as sysdba <<! >/dev/null

spool sql_trace_${STARTTIME}.log
set echo on
set pagesize 0
set sqlprompt "&_CONNECT_IDENTIFIER SQL> "
set linesize 500
set time on

--- <SQL TRACE Start>
alter session set tracefile_identifier='10046_Events_${TAG}';
alter session set timed_statistics = true;
alter session set statistics_level=all;
alter session set max_dump_file_size = unlimited;
alter session set events '10046 trace name context forever,level 12';


--- exec sql


--- <SQL TRACE End>

select distinct(m.sid), 'sqltrace:'||p.tracefile from v\$mystat m,v\$session s,v\$process p where m.sid=s.sid and s.paddr=p.addr;

alter session set events '10046 trace name context off';

spool off
exit;

!

Sample Scripts

  • Test scripts
[oracle@ora7 test_scirpts]$ cat exec_main_sql.sh
#!/bin/sh

STARTTIME=`date +%Y%m%d%H%M%S`

sqlplus sys/oracle@PDB1 as sysdba <<! >/dev/null

spool sql_trace_${STARTTIME}.log
set echo on
set pagesize 0
set sqlprompt "&_CONNECT_IDENTIFIER SQL> "
set linesize 500
set time on

--- <SQL TRACE Start>
alter session set tracefile_identifier='10046_Events_${TAG}';
alter session set timed_statistics = true;
alter session set statistics_level=all;
alter session set max_dump_file_size = unlimited;
alter session set events '10046 trace name context forever,level 12';


--- exec sql

@sql/s1.sql

--- <SQL TRACE End>

select distinct(m.sid), 'sqltrace:'||p.tracefile from v\$mystat m,v\$session s,v\$process p where m.sid=s.sid and s.paddr=p.addr;

alter session set events '10046 trace name context off';

spool off
exit;

!

[oracle@ora7 test_scirpts]$ cat sql/s1.sql
select owner,count(*) from lyn.t1 group by owner;
[oracle@ora7 test_scirpts]$
  • Execution sample:
[oracle@ora7 test_scirpts]$ sh -x exec_main_sql.sh
++ date +%Y%m%d%H%M%S
+ STARTTIME=20200518141228
+ sqlplus sys/oracle@PDB1 as sysdba
[oracle@ora7 test_scirpts]$ ls -tlr
total 28
-rw-r--r--. 1 oracle oinstall   674 May 18 13:41 ex.sql
drwxr-xr-x. 2 oracle oinstall    20 May 18 14:09 sql
-rw-r--r--. 1 oracle oinstall   772 May 18 14:11 exec_main_sql.sh
-rw-r--r--. 1 oracle oinstall 19798 May 18 14:12 sql_trace_20200518141228.log
[oracle@ora7 test_scirpts]$ cat sql_trace_20200518141228.log
SYS@PDB1> set echo on
SYS@PDB1> set pagesize 0
SYS@PDB1> set sqlprompt "&_CONNECT_IDENTIFIER SQL> "
PDB1 SQL> set linesize 500
PDB1 SQL> set time on
14:12:28 PDB1 SQL>
14:12:28 PDB1 SQL> --- <SQL TRACE Start>
14:12:28 PDB1 SQL> alter session set tracefile_identifier='10046_Events_';

Session altered.

14:12:28 PDB1 SQL> alter session set timed_statistics = true;

Session altered.

14:12:28 PDB1 SQL> alter session set statistics_level=all;

Session altered.

14:12:28 PDB1 SQL> alter session set max_dump_file_size = unlimited;

Session altered.

14:12:28 PDB1 SQL> alter session set events '10046 trace name context forever,level 12';

Session altered.

14:12:28 PDB1 SQL>
14:12:28 PDB1 SQL>
14:12:28 PDB1 SQL> --- exec sql
14:12:28 PDB1 SQL>
14:12:28 PDB1 SQL> @sql/s1.sql
14:12:28 PDB1 SQL> select owner,count(*) from lyn.t1 group by owner;
SYS
52330
~~
34 rows selected.

14:12:28 PDB1 SQL>
14:12:28 PDB1 SQL> --- <SQL TRACE End>
14:12:28 PDB1 SQL>
14:12:28 PDB1 SQL> select distinct(m.sid), 'sqltrace:'||p.tracefile from v$mystat m,v$session s,v$process p where m.sid=s.sid and s.paddr=p.addr;
        74
sqltrace:/u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_30037_10046_Events_.trc
14:12:28 PDB1 SQL>
14:12:28 PDB1 SQL> alter session set events '10046 trace name context off';

Session altered.

14:12:28 PDB1 SQL>
14:12:28 PDB1 SQL> spool off
[oracle@ora7 test_scirpts]$
  • tkprof trace log:
[oracle@ora7 test_scirpts]$ tkprof /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_30037_10046_Events_.trc ./10046_Events.tkprof.out

TKPROF: Release 19.0.0.0.0 - Development on Mon May 18 14:16:10 2020

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


[oracle@ora7 test_scirpts]$ cat ./10046_Events.tkprof.out

TKPROF: Release 19.0.0.0.0 - Development on Mon May 18 14:16:10 2020

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

Trace file: /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_30037_10046_Events_.trc
Sort options: default

********************************************************************************
count    = number of times OCI procedure was executed
cpu      = cpu time in seconds executing
elapsed  = elapsed time in seconds executing
disk     = number of physical reads of buffers from disk
query    = number of buffers gotten for consistent read
current  = number of buffers gotten in current mode (usually for update)
rows     = number of rows processed by the fetch or execute call
********************************************************************************

SQL ID: 7z2ypwassqs1m Plan Hash: 136660032

select owner,count(*)
from
 lyn.t1 group by owner


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        4      0.01       0.01          0        589          0          34
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        6      0.01       0.01          0        589          0          34

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
        34         34         34  HASH GROUP BY (cr=589 pr=0 pw=0 time=11320 us starts=1 cost=168 size=170 card=34)
     74243      74243      74243   TABLE ACCESS FULL T1 (cr=589 pr=0 pw=0 time=5083 us starts=1 cost=166 size=371215 card=74243)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  PGA memory operation                           12        0.00          0.00
  Disk file operations I/O                        1        0.00          0.00
  SQL*Net message to client                       4        0.00          0.00
  SQL*Net message from client                     4        0.00          0.00
********************************************************************************

Reference

tracefile_identifier Tips:

1.342 TRACEFILE_IDENTIFIER

SYS@PDB1> alter session set tracefile_identifier='1234567890123456789012345678901234567';

Session altered.

SYS@PDB1> alter session set tracefile_identifier='12345678901234567890123456789012345678';
ERROR:
ORA-02097: parameter cannot be modified because specified value is invalid
ORA-48912: The specified trace filename is too long

SYS@PDB1>

To be continue…

Have a good work&life! 2020/05 via LinHong


Similar Posts

Comments