El seguimiento es una parte importante para el ajuste de la base de datos de Oracle. Esto ayudará a capturar toda la declaración del problema, el evento de espera que es responsable del funcionamiento lento de la sesión.
La base de datos de Oracle ha proporcionado muchas formas más rápidas de rastrear la sesión local, otra sesión de usuario y formatear el seguimiento para que sea legible
Echemos un vistazo a cómo activar el seguimiento SQL, el evento 10046 en la base de datos Oracle y la utilidad trcsess, tkprof
Índice
- Seguimiento de SQL, evento 100046
- Cómo identificar los archivos de rastreo
- cómo verificar si el seguimiento está habilitado en Oracle
- Utilidad Oracle tkprof
- Utilidad Oracle trcsess
Seguimiento de SQL, evento 100046
Si desea realizar un seguimiento en una sesión local, estos son los pasos para activar el seguimiento de 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);
Si desea rastrear en otra sesión en ejecución, estos son los pasos
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,’’);
Debe haber visto el uso de 12,0 en varias declaraciones anteriores. Son niveles de seguimiento. Oracle Tracing tiene niveles de seguimiento. Estos son los valores válidos
| 0 | Sin rastro. Como desactivar sql_trace. |
| 2 | El equivalente de sql_trace normal Proporciona la ruta de ejecución, el recuento de filas, el archivo plano más pequeño Ventajas Proporciona una ruta de ejecución Proporciona recuentos de filas Produce el archivo plano más pequeño Desventajas No se puede saber qué valores se proporcionaron en tiempo de ejecución a SQL Si las estadísticas de la consulta son bajas pero el tiempo de ejecución es largo, no se puede saber qué eventos causaron la larga espera |
| 4 | Igual que 2, pero con la adición de valores de variables de vinculación Ventajas Proporciona una ruta de ejecución Proporciona recuentos de filas Puede decir para qué valores se ejecutó la declaración Desventajas Nuevamente, si el tiempo de ejecución es largo y las estadísticas son bajas, será difícil saber por qué en este tipo de rastreo. Produce un archivo plano más grande que el rastreo regular porque la información de la variable de vinculación debe almacenarse. |
| 8 | Igual que 2, pero con la adición de eventos de espera Rastreo regular más los tiempos de operación de la base de datos que el SQL esperó para completarse. Por ejemplo:tiempos de acceso al disco. Ventajas Proporciona una ruta de ejecución Proporciona recuentos de filas Puede indicar los tiempos de todos los eventos asociados con SQL. Desventajas El archivo de seguimiento puede alcanzar su máximo fácilmente debido a toda la información que Oracle debe escribir en el archivo de seguimiento y, por lo tanto, solo hay información parcial disponible en el archivo de seguimiento. La información de la variable de vinculación no está disponible |
| 12 | Igual que 2, pero con valores de variables de enlace y eventos de espera Rastreo normal con información de espera y de enlace. Contiene la información más completa y producirá el archivo de seguimiento más grande. Proporciona la ruta de ejecución Proporciona recuentos de filas Puede indicar los tiempos de todos los eventos asociados con SQL. Puede indicar qué valores SQL se ejecutó con Ventajas Proporciona una ruta de ejecución Proporciona recuentos de filas Puede indicar los tiempos de todos los eventos asociados con SQL. Puede indicar con qué valores se ejecutó SQL Desventajas El archivo de rastreo puede alcanzar su límite fácilmente debido a toda la información que Oracle debe escribir en el archivo de rastreo y, luego, solo hay información parcial disponible en el archivo de rastreo. |
Hay otras formas de hacer el rastreo también. Estos son algunos de estos
(1) ORADEBUG
Esto requiere iniciar sesión como 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, las opciones de seguimiento de SQL se han ampliado mediante el paquete 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,’’); Hay muchas otras funciones disponibles en dbms_monitor. Podemos habilitar el seguimiento en función del identificador del cliente y de varias formas
Cómo identificar los archivos de seguimiento
Podemos identificar los archivos de rastreo usando el spid de la sesión. Además, el archivo de rastreo contendrá el par sid,serial# al comienzo del archivo de rastreo.
La siguiente consulta se puede usar para encontrar el archivo de rastreo de la sesión local
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'
/
Hay otra manera fácil de identificar el archivo de seguimiento que se llama identificador de seguimiento
alter session set tracefile_identifer=’ORAC’; This is identifier
Archivo de seguimiento de ejemplo
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
cómo verificar si el rastreo está habilitado en Oracle
Si ha habilitado el rastreo usando el paquete DBMS_MONITOR, podemos verificar si el rastreo está habilitado usando la siguiente consulta
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' /
Si está habilitado a través de otros métodos, entonces la única forma de verificar es mirar la ubicación del seguimiento y encontrar los archivos de seguimiento que son recientes y luego encontrar el sid y el número de serie en él y luego puede consultar v$session para encontrar el sesión y puede deshabilitar el seguimiento si lo desea
Utilidad Oracle tkprof
Los archivos de seguimiento obtenidos con el método anterior están en formato sin procesar, que se puede convertir a un formato más legible mediante la utilidad tkprof (utilidad Transitoria 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
Algunos ejemplos
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
Contenido de ejemplo del archivo 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)
Oráculo trcsess utilidad
Cuando se utilizan sesiones de servidor compartido, se involucran muchos procesos. El seguimiento correspondiente a la sesión del usuario se encuentra disperso en diferentes archivos de seguimiento que pertenecen a diferentes procesos. Esto hace que sea difícil obtener una imagen completa del ciclo de vida de una sesión.
La utilidad trcsess consolida la salida de seguimiento de los archivos de seguimiento seleccionados en función de varios criterios
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
Después de generar el archivo de seguimiento consolidado, puede ejecutar tkprof en él.
Más información
En 11g y superior, sql_trace también es un evento y se puede configurar con la sintaxis de eventos:
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>
Entonces podría usarlo de la siguiente manera para habilitar SQL_TRACE solicitando información de vinculación:
alter session set events 'sql_trace bind=true';
o enlazar y esperar información (aviso separado por comas):
alter session set events 'sql_trace bind=true, wait=true';
El seguimiento adicional se puede limitar a un conjunto de SQL_ID si incluye un filtro para ello. Por ejemplo
alter session set events 'sql_trace [sql: sql_id=g3yc1js3g2689 | sql_id=7ujay4u33g337]bind=true, wait=true';
10046 niveles de EVENTO:(los nuevos valores de sql_trace se incluyen en [..])
Estos son valores de bits, por lo que se pueden juntar para obtener diferentes combinaciones
1:habilite la funcionalidad estándar de SQL_TRACE (predeterminado)
4:como nivel 1 MÁS valores de enlace de seguimiento [bind=true]
8:como nivel 1 PLUS, el seguimiento espera [esperar =verdadero]
Esto es especialmente útil para detectar la espera de bloqueo, etc.
pero también se puede usar para detectar escaneos de tabla completa y escaneos de índice.
A partir de 11g, estos niveles de bits adicionales están disponibles:
16:generar volcados de línea STAT para cada ejecución [plan_stat=all_executions]
32:nunca volcar estadísticas de ejecución [plan_stat=never]
A partir de 11.2.0.2, este nivel de bit adicional está disponible:
64:volcado adaptativo de líneas STAT. [ plan_stat=adaptive ]
Esto descarga la información STAT si un SQL tardó más de 1 minuto,
dando así información para los SQL más caros y para diferentes ejecuciones de tales
SQLs.
por ejemplo:un nivel de evento común es 12 que incluye salida SQL_TRACE estándar, enlaces, esperas y
rastreo de línea STAT predeterminado.
Notas:
El volcado STAT se modificó en 11g para que no se agreguen en todas las ejecuciones, sino que se descarguen después de la ejecución. Esto se ha hecho para abordar los casos en los que el cursor no está cerrado y, por lo tanto, la información STAT no se descarga.
Ahora garantizamos capturar la información STAT después de la ejecución. Consulte los niveles de bits anteriores para tener un control más preciso sobre las líneas STAT.
También lee
v$active_session_history
explicar el plan en Oracle
Asesor de ajuste de SQL
