Fala pessoal, espero que estejam todos bem!
O artigo de hoje será algo bem rápido, porém bem interessante. A ideia aqui é mostrar de uma forma prática como utilizar trace files para monitorar sessões de usuários do banco de dados. Algo muito importante para DBAs e que pode ajudar muito no acompanhamento de performance das queries que forem executadas no ambiente.
set pages 80set lines 300col machine format a30Col osuser format a10alter session set nls_date_format='dd/mm/yyyyhh24:mi';select S.sid, S.serial#, s.program, S.osuser, p.spid,S.machine, S.logon_timefrom v$session s, v$process pwhere s.paddr = p.addrand S.username='nome_usuario';
Com esse comando eu consigo validar a sessão do meu usuário igual no exemplo abaixo:
SQL> select s.sid, s.serial#, s.program, s.osuser, p.spid,s.machine, s.logon_timefrom v$session s, v$process pwhere s.paddr = p.addrand s.username='TESTETRACE'; : 2 3 4 5 SID SERIAL# PROGRAM OSUSER SPID MACHINE LOGON_TIME---------- -------- ------------------------------------ --------- ------ -------------------------- ----------- 136 53893 sqlplus@oragrid.localdomain (TNS V1-V3) oracle 6494 oragrid.localdomain 17/11/2024 13:46
Agora para habilitar o trace em um client com uma session id específica basta eu executar a procedure EXEC DBMS_MONITOR.session_trace_enable e passar o SID e o SERIAL# da sessão.
EXEC DBMS_MONITOR.session_trace_enable(session_id=>&SID, serial_num=>&SERIAL, waits=>TRUE,binds=>FALSE);
É importante dizer que o trace só permanece ativo enquanto a sessão estiver aberta, caso a sessão seja finalizada. É necessário realizar o procedimento novamente.
Após isso, o usuário pode iniciar as atividades dentro do banco e essas atividades serão monitoradas pelo trace.
E para visualizar o trace de uma forma mais humanizada, uma boa opção que temos é utilizando o tkprof da seguinte forma:
$ cd $ORACLE_BASE/diag/rdbms/oragrid/oragrid/trace$ tkprof arquivo.trc nometrace.txt sys=no
O ‘arquivo.trc’ irá se encontrar no diretório de trace do seu $ORACLE_BASE e terá a nomenclatura de ‘ora.trc’ igual no exemplo abaixo
[oracle@oragrid trace]$ tkprof oragrid_ora_6494.trc trace_teste.txt sys=no[oracle@oragrid trace]$ vi trace_teste.txt
E após visualizar o arquivo ‘trace_teste’ igual o gerado no meu caso. Já é possível verificar algumas informações do trace sobre as consultas realizadas pelo usuário.
TKPROF: Release 19.0.0.0.0 - Development on Sun Nov 17 14:22:23 2024Copyright (c) 1982, 2019, Oracle and/or its affiliates. All rights reserved.Trace file: oragrid_ora_6494.trcSort options: default***************************************************************************count = number of times OCI procedure was executedcpu = cpu time in seconds executingelapsed = elapsed time in seconds executingdisk = number of physical reads of buffers from diskquery = number of buffers gotten for consistent readcurrent = number of buffers gotten in current mode (usually for update)rows = number of rows processed by the fetch or execute call***************************************************************************SELECT e.employee_id, e.first_name, e.last_name,d.department_nameFROM hr.employees eJOIN hr.departments d ON e.department_id =d.department_idcall count cpu elapsed disk query current rows------- ------ ------ ------- ------- ------- ------- -------Parse 1 0.00 0.00 0 0 0 0Execute 1 0.00 0.00 0 0 0 0Fetch 9 0.00 0.00 0 18 0 106------- ------ ------ ------- ------- ------- ------- -------total 11 0.00 0.00 0 18 0 106Misses in library cache during parse: 1Optimizer mode: ALL_ROWSParsing user id: 106Number of plan statistics captured: 1Rows (1st) Rows (avg) Rows (max) Row Source Operation---------- ---------- ---------- ------------------------------------------ 106 106 106 MERGE JOIN (cr=18 pr=0 pw=0 time=156 us starts=1 cost=6 size=4028 card=106) 27 27 27 TABLE ACCESS BY INDEX ROWID DEPARTMENTS (cr=12 pr=0 pw=0 time=167 us starts=1 cost=2 size=432 card=27) 27 27 27 INDEX FULL SCAN DEPT_ID_PK (cr=6 pr=0 pw=0 time=82 us starts=1 cost=1 size=0 card=27)(object id 73017) 106 106 106 SORT JOIN (cr=6 pr=0 pw=0 time=150 us starts=27 cost=4 size=2354 card=107) 107 107 107 TABLE ACCESS FULL EMPLOYEES (cr=6 pr=0 pw=0 time=32 us starts=1 cost=3 size=2354 card=107)Elapsed times include waiting on following events:Event waited on Times Max. Wait Total Waited---------------------------------------- ------- ------------ ---------------SQL*Net message to client 9 0.00 0.00SQL*Net message from client 9 13.86 13.86***************************************************************************SELECT AVG(salary) AS average_salaryFROM hr.employeescall count cpu elapsed disk query current rows------- ------ ------ ------- ------- ------- ------- -------Parse 1 0.00 0.00 0 0 1 0Execute 1 0.00 0.00 0 0 0 1Fetch 2 0.00 0.00 0 6 0 1------- ------ ------ ------- ------- ------- ------- -------total 4 0.00 0.00 0 6 1 1Misses in library cache during parse: 1Optimizer mode: ALL_ROWSParsing user id: 106Number of plan statistics captured: 1Rows (1st) Rows (avg) Rows (max) Row Source Operation---------- ---------- ---------- ------------------------------------------ 1 1 1 SORT AGGREGATE (cr=6 pr=0 pw=0 time=71 us starts=1) 107 107 107 TABLE ACCESS FULL EMPLOYEES (cr=6 pr=0 pw=0 time=38 us starts=1 cost=3 size=428 card=107)Elapsed times include waiting on following events:Event waited on Times Max. Wait Total Waited---------------------------------------- ------- ------------ ---------------SQL*Net message to client 2 0.00 0.00log file sync 1 0.00 0.00"trace_teste.txt" 238L, 12516C
Fetch 2 0.00 0.00 0 9 0 11------- ------ ------ ------- ------- ------- ------- -------total 4 0.00 0.00 0 9 1 11Misses in library cache during parse: 1Optimizer mode: ALL_ROWSParsing user id: 106Number of plan statistics captured: 1Rows (1st) Rows (avg) Rows (max) Row Source Operation---------- ---------- ---------- ------------------------------------------ 11 11 11 HASH GROUP BY (cr=9 pr=0 pw=0 time=399 us starts=1 cost=4 size=513 card=27) 106 106 106 NESTED LOOPS (cr=9 pr=0 pw=0 time=77 us starts=1 cost=3 size=2014 card=106) 27 27 27 TABLE ACCESS FULL DEPARTMENTS (cr=6 pr=0 pw=0 time=56 us starts=1 cost=3 size=432 card=27) 106 106 106 INDEX RANGE SCAN EMP_DEPARTMENT_IX (cr=3 pr=0 pw=0 time=63 us starts=27 cost=0 size=12 card=4)(object id 73028)Elapsed times include waiting on following events:Event waited on Times Max. Wait Total Waited---------------------------------------- ------- ------------ ---------------SQL*Net message to client 2 0.00 0.00PGA memory operation 8 0.00 0.00log file sync 1 0.00 0.00SQL*Net message from client 1 0.00 0.00***************************************************************************OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTScall count cpu elapsed disk query current rows------- ------ ------ ------- ------- ------- ------- -------Parse 5 0.00 0.01 0 0 3 0Execute 5 0.00 0.00 0 0 0 0Fetch 27 0.00 0.00 0 55 0 276------- ------ ------ ------- ------- ------- ------- -------total 37 0.00 0.01 0 55 3 276Misses in library cache during parse: 5Elapsed times include waiting on following events:Event waited on Times Max. Wait Total Waited---------------------------------------- ------- ------------ ---------------SQL*Net message to client 27 0.00 0.00SQL*Net message from client 26 13.86 14.19log file sync 3 0.00 0.00PGA memory operation 11 0.00 0.00OVERALL TOTALS FOR ALL RECURSIVE STATEMENTScall count cpu elapsed disk query current rows------- ------ ------ ------- ------- ------- ------- -------Parse 3 0.00 0.00 0 0 0 0Execute 7 0.00 0.00 0 1 14 3Fetch 4 0.00 0.00 0 5 0 1------- ------ ------ ------- ------- ------- ------- -------total 14 0.00 0.00 0 6 14 4Misses in library cache during parse: 3Misses in library cache during execute: 35 user SQL statements in session.3 internal SQL statements in session.8 SQL statements in session.***************************************************************************Trace file: oragrid_ora_6494.trcTrace file compatibility: 12.2.0.0.0Sort options: default1 session in tracefile.5 user SQL statements in trace file.3 internal SQL statements in trace file.8 SQL statements in trace file.226 lines in trace file.14 elapsed seconds in trace file.