La traccia è una parte importante per l'ottimizzazione del database Oracle. Ciò consentirà di acquisire tutta la dichiarazione del problema , l'evento di attesa che è responsabile del rallentamento dell'esecuzione della sessione.
Il database Oracle ha fornito molti modi più rapidi per tracciare la sessione locale, la sessione di altri utenti e formattare la traccia per renderla leggibile
Diamo un'occhiata a come attivare la traccia SQL, l'evento 10046 nel database Oracle e l'utilità trcsess, tkprof
Sommario
Traccia SQL ,100046 evento
Se vuoi tracciare in una sessione locale, ecco i passaggi per attivare la traccia SQL
Normal trace alter session set sql_trace = true; -- To put trace on alter session set sql_trace = false; -- To put trace off Full level with wait event And bind trace alter session set events = ‘10046 trace name context forever, level 12’; To put tracing off alter session set events = ‘10046 trace name context off’; Same as Normal trace exec DBMS_SESSION.set_sql_trace(sql_trace => TRUE); exec DBMS_SESSION.set_sql_trace(sql_trace => FALSE);
Se vuoi tracciare in un'altra sessione in esecuzione, ecco i passaggi
Normal trace execute dbms_system.set_sql_trace_in_session (‘sid’,’serial’,true); -- To put tracing on execute dbms_system.set_sql_trace_in_session (‘sid’,’serial’,true); -- To put tracing off Full level with wait event And bind trace execute dbms_system.set_ev(‘sid’,’serial’,10046,12,’’); To put trace off execute dbms_system.set_ev(‘sid’,’serial’,10046,0,’’);
Devi aver visto l'utilizzo di 12,0 in varie affermazioni sopra. Sono livelli di traccia. Oracle Tracing ha livelli di traccia. Ecco i valori validi
| 0 | Nessuna traccia. Come disattivare sql_trace. |
| 2 | L'equivalente di sql_trace regolare Fornisce percorso di esecuzione, conteggi di righe, file flat più piccolo Vantaggi Fornisce il percorso di esecuzione Fornisce il conteggio delle righe Produce il file flat più piccolo Svantaggi Impossibile dire quali valori sono stati forniti in fase di esecuzione a SQL Se le statistiche per la query sono basse ma il tempo di esecuzione è lungo non è possibile determinare quali eventi hanno causato la lunga attesa |
| 4 | Lo stesso di 2, ma con l'aggiunta di valori delle variabili vincolanti Vantaggi Fornisce il percorso di esecuzione Fornisce il conteggio delle righe Può indicare per quali valori è stata eseguita l'istruzione Svantaggi Ancora una volta, se il tempo di esecuzione è lungo e le statistiche sono basse, sarà difficile dire perché in questo tipo di traccia. Produce un file flat più grande che la traccia regolare perché le informazioni sulla variabile di binding devono essere archiviate. |
| 8 | Lo stesso di 2, ma con l'aggiunta di eventi di attesa Traccia regolare più i tempi delle operazioni del database che l'SQL ha atteso per essere completato. Ad esempio:tempi di accesso al disco. Vantaggi Fornisce il percorso di esecuzione Fornisce il conteggio delle righe Può indicare i tempi per tutti gli eventi associati a SQL. Svantaggi Il file di traccia può facilmente raggiungere il limite massimo a causa di tutte le informazioni che Oracle deve scrivere nel file di traccia e quindi sono disponibili solo informazioni parziali nel file di traccia. Le informazioni sulla variabile di associazione non sono disponibili |
| 12 | Lo stesso di 2, ma con entrambi i valori della variabile bind e gli eventi wait Traccia regolare con le informazioni sia sull'attesa che sul collegamento. Contiene le informazioni più complete e produrrà il file di traccia più grande. Fornisce il percorso di esecuzione Fornisce i conteggi delle righe Può indicare i tempi per tutti gli eventi associati a SQL. Può indicare quali valori il SQL è stato eseguito con Vantaggi Fornisce il percorso di esecuzione Fornisce il conteggio delle righe Può indicare i tempi di tutti gli eventi associati a SQL. Può indicare con quali valori è stato eseguito l'SQL Svantaggi Il file di traccia può facilmente raggiungere il limite massimo a causa di tutte le informazioni che Oracle deve scrivere nel file di traccia e quindi sono disponibili solo informazioni parziali nel file di traccia. |
Esistono anche altri modi per eseguire il tracciamento. Eccone alcuni
(1) ORADEBUG
Ciò richiede l'accesso come sysdba
oradebug setospid 1111 -- Debug session with the specified Oracle process id oradebug setorapid 1111 --- Debug session with the specified OS process oradebug event 10046 trace name context forever, level 4; oradebug event 10046 trace name context off; --- This disable the trace oradebug close_trace --- This closes the trace file Oradebug TRACEFILE_NAME;
(2) Con Oracle 10g le opzioni di traccia SQL sono state estese utilizzando il pacchetto DBMS_MONITOR
EXECUTE dbms_monitor.session_trace_enable
Which is similar
ALTER SESSION SET EVENTS '10046 trace name context forever, level 2';
EXECUTE dbms_monitor.session_trace_enable (binds=>true);
Which is similar
ALTER SESSION SET EVENTS '10046 trace name context forever, level 4';
EXECUTE dbms_monitor.session_trace_enable (waits=>true);
Which is similar
ALTER SESSION SET EVENTS '10046 trace name context forever, level 8';
EXECUTE dbms_monitor.session_trace_enable('sid','serial#')
Which is similar
execute dbms_system.set_ev(‘sid’,’serial’,10046,2,’’);
EXECUTE dbms_monitor.session_trace_enable ('sid','serial#',binds=>true);
Which is similar
execute dbms_system.set_ev(‘sid’,’serial’,10046,4,’’);
EXECUTE dbms_monitor.session_trace_enable ('sid','serial#',waits=>true);
Which is similar
execute dbms_system.set_ev(‘sid’,’serial’,10046,8,’’); Ci sono molte altre funzionalità disponibili in dbms_monitor. Possiamo abilitare la traccia in base all'identificatore del cliente e in più modi
Come identificare i file di traccia
Possiamo identificare i file di traccia utilizzando lo spid della sessione. Inoltre il file di traccia conterrà la coppia sid,serial# all'inizio del file di traccia.
La query sottostante può essere utilizzata per trovare il file di traccia della sessione locale
select c.value || '/' || d.instance_name ||'_ora_' || a.spid || '.trc' trace
from v$process a, v$session b, v$parameter c, v$instance d
where a.addr = b.paddr
and b.audsid = userenv('sessionid')
and c.name = 'user_dump_dest'
/
C'è un altro modo semplice per identificare il file di traccia che è chiamato identificatore di traccia
alter session set tracefile_identifer=’ORAC’; This is identifier
Esempio di file di traccia
Trace file /app/oracle/TEST/diag/rdbms/test/TEST/trace/TEST_ora_13025_IDEN.trc Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production With the Partitioning, Real Application Clusters, OLAP, Data Mining and Real Application Testing options ORACLE_HOME = /app/oracle/TEST/11.2.0/db System name: SunOS12 Node name: sun12Release: 5.10Version: Generic_144488-11 Machine: sun4u Instance name: TEST Redo thread mounted by this instance: 1 Oracle process number: 202 Unix process pid: 13025, image: [email protected] SunOS12 *** 2013-10-21 12:28:56.461 *** SESSION ID:(3875.17341) 2013-10-21 12:28:56.461*** CLIENT ID:() 2013-10-21 12:28:56.461 *** SERVICE NAME:(TEST) 2013-10-21 12:28:56.461 *** MODULE NAME:([email protected](TNS V1-V3)) 2013-10-21 12:28:56.461 *** ACTION NAME:() 2013-10-21 12:28:56.461 CLOSE #4:c=0,e=11,dep=1,type=1,tim=8866891135825 ===================== PARSING IN CURSOR #5 len=356 dep=1 uid=173 oct=3 lid=173 tim=8866891136821 hv=2468783182 ad='4c70e4398' sqlid='0wmwsjy9kd92f'SELECT PROFILE_OPTION_ID, APPLICATION_ID, SITE_ENABLED_FLAG , APP_ENABLED_FLAG , RESP_ENABLED_FLAG , USER_ENABLED_FLAG, ORG_ENABLED_FLAG , SERVER_ENABLED_FLAG, SERVERRESP_ENABLED_FLAG, HIERARCHY_TYPE, USER_CHANGEABLE_FLAG FROM FND_PROFILE_OPTIONS WHERE PROFILE_OPTION_NAME = :B1 AND START_DATE_ACTIVE <= SYSDATE AND NVL(END_DATE_ACTIVE, SYSDATE) >= SYSDATEEND OF STMT BINDS #5: Bind#0 oacdty=01 mxl=128(80) mxlc=00 mal=00 scl=00 pre=00 oacflg=03 fl2=1206001 frm=01 csi=871 siz=128 off=0 kxsbbbfp=ffffffff7d677b48 bln=128 avl=21 flg=0 value="PER_BUSINESS_GROUP_ID" EXEC #5:c=0,e=1474,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=1374985481,tim=8866891138224 FETCH #5:c=0,e=61,p=0,cr=3,cu=0,mis=0,r=1,dep=1,og=1,plh=1374985481,tim=8866891138429 CLOSE #5:c=0,e=5,dep=1,type=3,tim=8866891138503 ===================== PARSING IN CURSOR #4 len=230 dep=1 uid=173 oct=3 lid=173 tim=8866891138634 hv=3575592451 ad='3aeea3da0' sqlid='55dc767ajydh3' SELECT PROFILE_OPTION_VALUE FROM FND_PROFILE_OPTION_VALUES WHERE PROFILE_OPTION_ID = :B4 AND APPLICATION_ID = :B3 AND LEVEL_ID = 10003 AND LEVEL_VALUE = :B2 AND LEVEL_VALUE_APPLICATION_ID = :B1 AND PROFILE_OPTION_VALUE IS NOT NULL END OF STMT BINDS #4: Bind#0 oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00 oacflg=03 fl2=1206001 frm=00 csi=00 siz=96 off=0 kxsbbbfp=ffffffff7d677b68 bln=22 avl=03 flg=05 value=1204 Bind#1 oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00 oacflg=03 fl2=1206001 frm=00 csi=00 siz=0 off=24 kxsbbbfp=ffffffff7d677b80 bln=22 avl=02 flg=01 value=800 Bind#2 oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00 oacflg=03 fl2=1206001 frm=00 csi=00 siz=0 off=48 kxsbbbfp=ffffffff7d677b98 bln=22 avl=04 flg=01 value=50334 Bind#3 oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00 oacflg=03 fl2=1206001 frm=00 csi=00 siz=0 off=72 kxsbbbfp=ffffffff7d677bb0 bln=22 avl=01 flg=01 value=0 EXEC #4:c=0,e=377,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=2802907561,tim=8866891138978 FETCH #4:c=0,e=26,p=0,cr=3,cu=0,mis=0,r=0,dep=1,og=1,plh=2802907561,tim=8866891139050 CLOSE #4:c=0,e=2,dep=1,type=3,tim=8866891139116 ===================== PARSING IN CURSOR #5 len=191 dep=1 uid=173 oct=3 lid=173 tim=8866891139308 hv=303338305 ad='3bedf0e48' sqlid='7qs7fx89194u1' SELECT PROFILE_OPTION_VALUE FROM FND_PROFILE_OPTION_VALUES WHERE PROFILE_OPTION_ID = :B4 AND APPLICATION_ID = :B3 AND LEVEL_ID = :B2 AND LEVEL_VALUE = :B1 AND PROFILE_OPTION_VALUE IS NOT NULL END OF STMT BINDS #5: Bind#0 oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00 oacflg=03 fl2=1206001 frm=00 csi=00 siz=96 off=0 kxsbbbfp=ffffffff7d673b78 bln=22 avl=03 flg=05 value=1204 Bind#1 oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00 oacflg=03 fl2=1206001 frm=00 csi=00 siz=0 off=24 kxsbbbfp=ffffffff7d673b90 bln=22 avl=02 flg=01 value=800 Bind#2 oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00 oacflg=03 fl2=1206001 frm=00 csi=00 siz=0 off=48 kxsbbbfp=ffffffff7d673ba8 bln=22 avl=04 flg=01 value=10001
come verificare se la traccia è abilitata in Oracle
Se hai abilitato la traccia utilizzando il pacchetto DBMS_MONITOR, possiamo verificare se la traccia è abilitata utilizzando la query sottostante
set lines 180 col module for a45 col sql_trace_waits for a20 col sql_trace_binds for a20 col sql_trace for a20 select username,module,sid,sql_trace,sql_trace_waits,sql_trace_binds from v$session where sql_trace='ENABLED' /
Se è abilitato attraverso altri metodi, l'unico modo per controllare è guardare la posizione della traccia e scoprire i file di traccia che sono recenti e quindi trovare sid e serial# in esso e quindi puoi interrogare v$session per trovare il sessione e puoi disabilitare la traccia se vuoi
Utilità Oracle tkprof
I file di traccia ottenuti dal metodo sopra sono in forma grezza che può essere convertita in un formato più leggibile utilizzando l'utilità tkprof (utilità Transient Kernel PROFile)
tkprof Usage: tkprof tracefile outputfile [explain= ] [table= ] [print= ] [insert= ] [sys= ] [sort= ] table=schema.tablename Use 'schema.tablename' with 'explain=' option. explain=user/password Connect to ORACLE and issue EXPLAIN PLAN. print=integer List only the first 'integer' SQL statements. aggregate=yes|no insert=filename List SQL statements and data inside INSERT statements. sys=no TKPROF does not list SQL statements run as user SYS. record=filename Record non-recursive statements found in the trace file. waits=yes|no Record summary for any wait events found in the trace file. sort=option Set of zero or more of the following sort options: prscnt number of times parse was called prscpu CPU time parsing prsela elapsed time parsing prsdsk number of disk reads during parse prsqry number of buffers for consistent read during parseprscu number of buffers for current read during parseprsmis number of misses in library cache during parseexecnt number of execute was called execpu CPU time spent executing exeela elapsed time executing exedsk number of disk reads during execute exeqry number of buffers for consistent read during execute execu number of buffers for current read during execute exerow number of rows processed during execute exemis number of library cache misses during execute fchcnt number of times fetch was called fchcpu cpu time spent fetching fchela elapsed time fetching fchdsk number of disk reads during fetch fchqry number of buffers for consistent read during fetch fchcu number of buffers for current read during fetch fchrow number of rows fetched userid userid of user that parsed the cursor
Alcuni esempi
tkprof file.trc file.txt sys=no explain=userid/password sort=prsela,exeela,fchela tkprof file.trc file.txt sys=no explain=userid/password sort=prsela,exeela,fchela tkprof file.trc file.txt sys=no tkprof file.trc file.txt sys=no explain=userid/password sort=prsela,exeela,fchela This print 10 sql only tkprof .trc elaps.prf sys=no explain=apps/ sort=(prsela,exeela,fchela) print=10 This print all the sql tkprof .trc elaps.prf sys=no explain=apps/apps sort=prsela,exeela,fchela
Esempio di contenuto del file tkprof
TKPROF: Release 11.2.0.4.0 - Production on Tue Jan 17 14:12:41 2013 Copyright (c) 1982, 2007, Oracle. All rights reserved. Trace file: TEST_ora_15941.trc Sort options: execpu fchcpu ******************************************************************************** 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: 6w82ggrtysx Plan Hash: 2325776775 SELECT FUNCTION_NAME FROM FND_USER_DESKTOP_OBJECTS WHERE USER_ID = :b1 AND APPLICATION_ID = :b2 AND RESPONSIBILITY_ID = :b3 AND TYPE = 'FUNCTION' AND ROWNUM <= 10 ORDER BY SEQUENCE 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 4 0 1 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 4 0.00 0.00 0 4 0 1 Misses in library cache during parse: 0 Optimizer mode: ALL_ROWS Parsing user id: 173 (APPS) Number of plan statistics captured: 1 Rows (1st) Rows (avg) Rows (max) Row Source Operation ---------- ---------- ---------- --------------------------------------------------- 1 1 1 SORT ORDER BY (cr=4 pr=0 pw=0 time=0 us cost=6 size=41 card=1) 1 1 1 COUNT STOPKEY (cr=4 pr=0 pw=0 time=0 us) 1 1 1 TABLE ACCESS BY INDEX ROWID FND_USER_DESKTOP_OBJECTS (cr=4 pr=0 pw=0 time=0 us cost=5 size=41 card=1) 1 1 1 INDEX RANGE SCAN FND_USER_DESKTOP_OBJECTS_N1 (cr=3 pr=0 pw=0 time=0 us cost=3 size=0 card=3)(object id 33596) Rows Execution Plan ------- --------------------------------------------------- 0 SELECT STATEMENT MODE: ALL_ROWS 1 SORT (ORDER BY) 1 COUNT (STOPKEY) 1 TABLE ACCESS MODE: ANALYZED (BY INDEX ROWID) OF 'FND_USER_DESKTOP_OBJECTS' (TABLE) 1 INDEX MODE: ANALYZED (RANGE SCAN) OF 'FND_USER_DESKTOP_OBJECTS_N1' (INDEX) Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ SQL*Net message to client 5 0.00 0.00 SQL*Net message from client 5 0.00 0.00******************************************************************************** SQL ID: 276ut2ywqux Plan Hash: 3856112528 select object_name, icon_name from fnd_desktop_objects 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 3 0.00 0.00 0 6 0 47 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 5 0.00 0.00 0 6 0 47 Misses in library cache during parse: 0 Optimizer mode: ALL_ROWS Parsing user id: 173 (APPS) Number of plan statistics captured: 1 Rows (1st) Rows (avg) Rows (max) Row Source Operation ---------- ---------- ---------- --------------------------------------------------- 47 47 47 TABLE ACCESS FULL FND_DESKTOP_OBJECTS (cr=6 pr=0 pw=0 time=0 us cost=2 size=1175 card=47) Rows Execution Plan ------- --------------------------------------------------- 0 SELECT STATEMENT MODE: ALL_ROWS 47 TABLE ACCESS MODE: ANALYZED (FULL) OF 'FND_DESKTOP_OBJECTS' (TABLE)
Tracce di Oracle utilità
Quando si utilizzano sessioni del server condiviso, sono coinvolti molti processi. La traccia relativa alla sessione dell'utente è distribuita su diversi file di traccia appartenenti a processi diversi. Ciò rende difficile ottenere un quadro completo del ciclo di vita di una sessione.
L'utilità trcsess consolida l'output di traccia dai file di traccia selezionati in base a diversi criteri
trcsess [output=output_file_name] [session=session_id] [clientid=client_id] [service=service_name] [action=action_name] [module=module_name] [trace_files] trcsess output=main.trc service=TEST *trc
Dopo che il file di traccia consolidato è stato generato, puoi eseguire tkprof su di esso.
Maggiori informazioni
In 11g e versioni successive, sql_trace è anche un evento e può essere impostato con la sintassi dell'evento:
SQL> oradebug doc event name sql_trace sql_trace: event for sql trace Usage ------- sql_trace wait < false | true >, bind < false | true >, plan_stat < never | first_execution | all_executions | adaptive >, level <ub4>
Quindi potresti usarlo come segue per abilitare SQL_TRACE che richiede informazioni di collegamento:
alter session set events 'sql_trace bind=true';
o vincolare e attendere le informazioni (avviso separate da virgole):
alter session set events 'sql_trace bind=true, wait=true';
Un'ulteriore traccia può essere limitata a una serie di SQL_ID se si include un filtro per essa. Es.
alter session set events 'sql_trace [sql: sql_id=g3yc1js3g2689 | sql_id=7ujay4u33g337]bind=true, wait=true';
10046 livelli di EVENTO:(i nuovi valori di sql_trace sono inclusi in [..])
Questi sono valori di bit, quindi possono essere messi insieme per ottenere diversi mix
1 – Abilita la funzionalità SQL_TRACE standard (predefinita)
4 – Come valori di binding della traccia di livello 1 PLUS [ bind=true ]
8 – Poiché la traccia di livello 1 PLUS attende [ wait=true ]
Questo è particolarmente utile per individuare latch wait ecc.
ma può anche essere utilizzato per individuare scansioni di tabelle complete e scansioni di indici.
A partire dall'11g sono disponibili questi livelli di bit aggiuntivi:
16 – Genera dump di riga STAT per ogni esecuzione [ plan_stat=all_executions ]
32 – Non eseguire mai il dump delle statistiche di esecuzione [ plan_stat=never ]
A partire dall'11.2.0.2 è disponibile questo livello di bit aggiuntivo:
64 – Dump adattivo delle righe STAT. [ plan_stat=adaptive ]
Questo scarica le informazioni STAT se un SQL impiega più di 1 minuto circa
in tal modo
Fornendo informazioni per gli SQL più costosi e per diverse esecuzioni di tali
SQL.
es:un livello di evento comune è 12 che include output SQL_TRACE standard, binding, attese e
tracciamento della linea STAT predefinita.
Note:
Il dumping STAT è stato modificato in 11g in modo che non vengano aggregati in tutte le esecuzioni ma vengano scaricati dopo l'esecuzione. Ciò è stato fatto per risolvere i casi in cui il cursore non è chiuso e quindi le informazioni STAT non vengono scaricate.
Ora garantiamo di acquisire le informazioni STAT dopo l'esecuzione. Vedere i livelli di bit sopra per avere un controllo più preciso sulle linee STAT.
Legge anche
v$active_session_history
spiega il piano in Oracle
sql tuning Advisor
