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:
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