{"id":2183,"date":"2020-07-26T22:12:04","date_gmt":"2020-07-27T01:12:04","guid":{"rendered":"http:\/\/dbtimewizard.com.br\/blog\/?p=2183"},"modified":"2020-07-26T22:12:04","modified_gmt":"2020-07-27T01:12:04","slug":"voce-sabe-identificar-consultas-demoradas-no-codigo-plsql","status":"publish","type":"post","link":"http:\/\/dbtimewizard.com.br\/blog\/voce-sabe-identificar-consultas-demoradas-no-codigo-plsql\/","title":{"rendered":"Voc\u00ea sabe identificar consultas demoradas no c\u00f3digo PL\/SQL?"},"content":{"rendered":"

Durante o desenvolvimento ou altera\u00e7\u00e3o de um c\u00f3digo PL\/SQL eventualmente o desempenho ou tempo de execu\u00e7\u00e3o deste c\u00f3digo pode ser insatisfat\u00f3rio, <\/span>dependendo do tamanho c\u00f3digo e de quantas instru\u00e7\u00f5es SQL existem nele pode haver certa dificuldade para identificar qual ou quais instru\u00e7\u00f5es SQL est\u00e3o causando a perda de desempenho, para ajudar a identificar as instru\u00e7\u00f5es do c\u00f3digo que est\u00e3o com baixo desempenho voc\u00ea pode utilizar o pacote DBMS_TRACE.<\/span><\/p>\n

A proposta deste artigo \u00e9 mostrar um exemplo pr\u00e1tico de como podemos utilizar o pacote DBMS_TRACE para identificar num c\u00f3digo PL\/SQL qual \u00e9 a consulta que est\u00e1 com baixo desempenho, fazer a melhoria necess\u00e1ria e validar a solu\u00e7\u00e3o apresentada.<\/span><\/p>\n

 
\n <\/p>\n

Para realizar esta demonstra\u00e7\u00e3o pr\u00e1tica vamos executar as seguintes etapas:<\/span><\/p>\n

1) Configurar o banco para usar o pacote DBMS_TRACE<\/span><\/strong>
\n2) Criar os objetos para a demonstra\u00e7\u00e3o <\/span><\/strong>
\n3) Executar a procedure habilitando o trace<\/span><\/strong>
\n4) Analisar as informa\u00e7\u00f5es geradas no trace<\/span><\/strong>
\n5) Aplicar melhoria no banco<\/span><\/strong>
\n6) Executar a procedure novamente habilitando o trace<\/span><\/strong>
\n7) Analisar as informa\u00e7\u00f5es geradas no trace ap\u00f3s melhoria<\/span><\/strong><\/p>\n

1) Configurar o banco para usar o pacote DBMS_TRACE<\/span><\/h2>\n

Nesta etapa vamos executar o script TRACETAB.sql que esta dispon\u00edvel no diret\u00f3rio HOME do banco, para criar os objetos necess\u00e1rios na utiliza\u00e7\u00e3o do pacote DBMS_TRACE.<\/span><\/p>\n

 <\/p>\n

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
<\/div><\/td>
[<\/span>oracle@<\/span>odbsrv11 ~]<\/span>$ sqlplus \/<\/span> as<\/span> sysdba
\n
\nSQL*<\/span>Plus:<\/span> Release 11.<\/span>2.<\/span>0.<\/span>4.<\/span>0 Production on Mon Jul 15<\/span> 10<\/span>:<\/span>05<\/span>:<\/span>19<\/span> 2020<\/span>
\n
\nCopyright (<\/span>c)<\/span> 1982<\/span>,<\/span> 2013<\/span>,<\/span> Oracle.<\/span>  All rights reserved.<\/span>
\n
\n
\nConnected to:<\/span>
\nOracle Database 11g Enterprise Edition Release 11.<\/span>2.<\/span>0.<\/span>4.<\/span>0 -<\/span> 64bit Production
\nWith the Partitioning,<\/span> Real Application Clusters,<\/span> Automatic Storage Management,<\/span> OLAP,<\/span>
\nData Mining and Real Application Testing options
\n
\nSQL><\/span> @<\/span>?\/<\/span>rdbms\/<\/span>admin\/<\/span>tracetab.<\/span>sql
\n
\nTable dropped.<\/span>
\n
\n
\nTable dropped.<\/span>
\n
\n
\nSequence dropped.<\/span>
\n
\n
\nTable created.<\/span>
\n
\n
\nComment created.<\/span>
\n
\n
\nTable created.<\/span>
\n
\n
\nComment created.<\/span>
\n
\n
\nSequence created.<\/span>
\n
\nSQL><\/span> grant select on PLSQL_TRACE_EVENTS to public<\/span>;<\/span>
\n
\nGrant succeeded.<\/span>
\n
\nSQL><\/span> grant select on PLSQL_TRACE_RUNS to public<\/span>;<\/span>
\n
\nGrant succeeded.<\/span>
\n
\nSQL><\/span> grant execute on DBMS_TRACE to SH;<\/span>
\n
\nGrant succeeded.<\/span>
\n
\nSQL><\/span> create public<\/span> synonym PLSQL_TRACE_RUNS for<\/span> SYS.<\/span>PLSQL_TRACE_RUNS;<\/span>
\n
\nSynonym created.<\/span>
\n
\nSQL><\/span> create public<\/span> synonym PLSQL_TRACE_EVENTS for<\/span> SYS.<\/span>PLSQL_TRACE_EVENTS;<\/span>
\n
\nSynonym created.<\/span>
\n
\nSQL><\/span> set lines 300<\/span> pages 100<\/span>
\ncol OWNER for<\/span> a16;<\/span>
\ncol OBJECT_NAME for<\/span> a30;<\/span>
\ncol OBJECT_TYPE for<\/span> a30;<\/span>
\nSELECT owner,<\/span> object_name,<\/span> object_type
\n  FROM dba_objects
\n WHERE object_name like 'PLSQL_TRACE%'<\/span>
\n ORDER by 2<\/span>,<\/span> 1<\/span>;<\/span>
\nSQL><\/span> SQL><\/span> SQL><\/span> SQL><\/span>   2<\/span>    3<\/span>    4<\/span>
\nOWNER            OBJECT_NAME                    OBJECT_TYPE
\n----------------<\/span> ------------------------------<\/span> ------------------------------<\/span>
\nPUBLIC<\/span>           PLSQL_TRACE_EVENTS             SYNONYM
\nSYS              PLSQL_TRACE_EVENTS             TABLE
\nSYS              PLSQL_TRACE_RUNNUMBER          SEQUENCE
\nPUBLIC<\/span>           PLSQL_TRACE_RUNS               SYNONYM
\nSYS              PLSQL_TRACE_RUNS               TABLE
\n
\nSQL><\/span><\/div><\/td><\/tr><\/tbody><\/table><\/div>\n

 <\/p>\n

Obs: Foi atribu\u00eddo o grant de EXECUTE no pacote DBMS_TRACE para o owner SH, pois vamos utilizar este usu\u00e1rio em nossa simula\u00e7\u00e3o.<\/span><\/p>\n

2) Criar os objetos para a demonstra\u00e7\u00e3o<\/span><\/h2>\n

Agora vamos criar os objetos para nossa demonstra\u00e7\u00e3o, uma tabela e uma procedure no schema SH.<\/span><\/p>\n

 <\/p>\n

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
<\/div><\/td>
NOT CONNECTED ><\/span> conn sh\/<\/span>sh@<\/span>lab11
\nConnected.<\/span>
\n
\nSQL ><\/span>
\nSQL ><\/span> alter session set workarea_size_policy=<\/span>MANUAL;<\/span>
\n
\nSession altered.<\/span>
\n
\nElapsed:<\/span> 00<\/span>:<\/span>00<\/span>:<\/span>00.00<\/span>
\nSQL ><\/span>
\nSQL ><\/span> alter session set sort_area_size=<\/span>2000000000<\/span>;<\/span>
\n
\nSession altered.<\/span>
\n
\nElapsed:<\/span> 00<\/span>:<\/span>00<\/span>:<\/span>00.00<\/span>
\nSQL ><\/span>
\nSQL ><\/span> create table dbtw065 as<\/span>
\n  2<\/span>     select 'DBTimeWizard - Performance and Tuning'<\/span> as<\/span> produto,<\/span>
\n  3<\/span>            mod(<\/span>rownum,<\/span>5<\/span>)<\/span>    as<\/span> codigo,<\/span>
\n  4<\/span>            mod(<\/span>rownum,<\/span>1000<\/span>)<\/span> as<\/span> cliente_id ,<\/span>
\n  5<\/span>            round<\/span><\/a>(<\/span>dbms_random.<\/span>value(<\/span>10000<\/span>,<\/span>0<\/span>)<\/span>)<\/span>as<\/span> postal_id,<\/span>
\n  6<\/span>            5000<\/span> as<\/span> total_vendas,<\/span>
\n  7<\/span>            trunc(<\/span>sysdate -<\/span> 9999<\/span> +<\/span> mod(<\/span>rownum,<\/span>10000<\/span>)<\/span>)<\/span> as<\/span> data_venda
\n  8<\/span>       from dual connect by level<=<\/span>2e7<\/span>;<\/span>
\n
\nTable created.<\/span>
\n
\nElapsed:<\/span> 00<\/span>:<\/span>03<\/span>:<\/span>48.77<\/span>
\nSQL ><\/span>
\nSQL ><\/span>
\nSQL ><\/span> alter table dbtw065 nologging;<\/span>
\n
\nTable altered.<\/span>
\n
\nElapsed:<\/span> 00<\/span>:<\/span>00<\/span>:<\/span>00.15<\/span>
\nSQL ><\/span>
\nSQL ><\/span> insert \/*+ append *\/<\/span> into dbtw065 select *<\/span> from dbtw065;<\/span>
\n
\n20000000<\/span> rows created.<\/span>
\n
\nElapsed:<\/span> 00<\/span>:<\/span>02<\/span>:<\/span>11.83<\/span>
\nSQL ><\/span>
\nSQL ><\/span> commit;<\/span>
\n
\nCommit complete.<\/span>
\n
\nElapsed:<\/span> 00<\/span>:<\/span>00<\/span>:<\/span>00.01<\/span>
\nSQL ><\/span>
\nSQL ><\/span> exec<\/span><\/a> dbms_stats.<\/span>gather_table_stats(<\/span>ownname=><\/span> USER,<\/span> tabname=><\/span> 'DBTW065'<\/span>,<\/span> cascade=><\/span> true<\/span>,<\/span> method_opt=><\/span> 'FOR ALL COLUMNS SIZE SKEWONLY'<\/span>)<\/span>;<\/span>
\n
\nPL\/<\/span>SQL procedure successfully completed.<\/span>
\n
\nElapsed:<\/span> 00<\/span>:<\/span>04<\/span>:<\/span>44.33<\/span>
\nSQL ><\/span>
\nSQL ><\/span> alter table dbtw065 logging;<\/span>
\n
\nTable altered.<\/span>
\n
\nElapsed:<\/span> 00<\/span>:<\/span>00<\/span>:<\/span>00.03<\/span>
\nSQL ><\/span>
\nSQL ><\/span> CREATE OR REPLACE PROCEDURE dbtw065_prc
\n  2<\/span>  IS
\n  3<\/span>     contador number;<\/span>
\n  4<\/span>     CURSOR c_dbtw IS
\n  5<\/span>     select \/* dbtw-065.2 *\/<\/span> *<\/span>
\n  6<\/span>       from dbtw065
\n  7<\/span>      where cliente_id =<\/span> 711<\/span>
\n  8<\/span>        and postal_id =<\/span> 7348<\/span>;<\/span>
\n  9<\/span>     r_dbtw c_dbtw%<\/span>ROWTYPE;<\/span>
\n 10<\/span>
\n 11<\/span>
\n 12<\/span>  BEGIN
\n 13<\/span>
\n 14<\/span>     --<\/span> Consulta 1<\/span>
\n 15<\/span>     select \/* dbtw-065.1 *\/<\/span> count<\/span><\/a>(<\/span>1<\/span>)<\/span> into contador  from (<\/span>
\n 16<\/span>     select c.<\/span>CUST_ID,<\/span>
\n 17<\/span>            sum(<\/span>amount_sold)<\/span> total_sold
\n 18<\/span>      from sh.<\/span>sales s,<\/span>
\n 19<\/span>           sh.<\/span>customers c
\n 20<\/span>     where c.<\/span>cust_id=<\/span>s.<\/span>cust_id
\n 21<\/span>       and cust_state_province =<\/span> 'Barcelona'<\/span>
\n 22<\/span>     group by c.<\/span>cust_id)<\/span>
\n 23<\/span>     where total_sold ><\/span> 50000<\/span>;<\/span>
\n 24<\/span>
\n 25<\/span>     --<\/span> Consulta 2<\/span>
\n 26<\/span>     OPEN c_dbtw;<\/span>
\n 27<\/span>     LOOP
\n 28<\/span>        FETCH  c_dbtw  INTO r_dbtw;<\/span>
\n 29<\/span>        EXIT<\/span><\/a> WHEN c_dbtw%<\/span>NOTFOUND;<\/span>
\n 30<\/span>        dbms_output.<\/span>put_line(<\/span>'cliente_id: '<\/span>||<\/span>r_dbtw.<\/span>cliente_id||<\/span>'  postal_id: '<\/span>||<\/span>r_dbtw.<\/span>postal_id)<\/span>;<\/span>
\n 31<\/span>     END<\/span><\/a> LOOP;<\/span>
\n 32<\/span>     CLOSE c_dbtw;<\/span>
\n 33<\/span>
\n 34<\/span>     --<\/span> Consulta 3<\/span>
\n 35<\/span>     SELECT \/* dbtw-065.3 *\/<\/span> count<\/span><\/a>(<\/span>1<\/span>)<\/span> into contador
\n 36<\/span>       FROM sh.<\/span>customers c,<\/span>
\n 37<\/span>            sh.<\/span>sales s
\n 38<\/span>      WHERE c.<\/span>cust_id =<\/span> s.<\/span>cust_id
\n 39<\/span>        AND c.<\/span>country_id =<\/span> 52776<\/span>
\n 40<\/span>        AND s.<\/span>channel_id =<\/span> 2<\/span>
\n 41<\/span>        AND (<\/span>c.<\/span>cust_last_name like 'Ly%'<\/span>
\n 42<\/span>         OR c.<\/span>cust_last_name like 'Ry%'<\/span>)<\/span>;<\/span>
\n 43<\/span>
\n 44<\/span>  END<\/span><\/a>;<\/span>
\n 45<\/span>  \/<\/span>
\n
\nProcedure created.<\/span>
\n
\nElapsed:<\/span> 00<\/span>:<\/span>00<\/span>:<\/span>00.40<\/span>
\nSQL ><\/span><\/div><\/td><\/tr><\/tbody><\/table><\/div>\n

 
\n3) Executar a procedure habilitando o trace<\/span><\/strong><\/p>\n

Para realizar o trace da procedure precisamos habilita-lo antes da execu\u00e7\u00e3o e desativa-lo ap\u00f3s a execu\u00e7\u00e3o, a seguir vamos executar um bloco PL\/SQL anonimo com esta sequ\u00eancia.<\/span><\/p>\n

 <\/p>\n

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
<\/div><\/td>
SQL ><\/span> set  serveroutput on size 9999<\/span>
\nSQL ><\/span> alter session set current_schema =<\/span> sh;<\/span>
\n
\nSession altered.<\/span>
\n
\nElapsed:<\/span> 00<\/span>:<\/span>00<\/span>:<\/span>00.00<\/span>
\nSQL ><\/span>
\nSQL ><\/span> begin
\n  2<\/span>
\n  3<\/span>     dbms_trace.<\/span>set_plsql_trace(<\/span>dbms_trace.<\/span>trace_all_lines)<\/span>;<\/span>
\n  4<\/span>     dbtw065_prc;<\/span>
\n  5<\/span>     dbms_trace.<\/span>clear_plsql_trace;<\/span>
\n  6<\/span>
\n  7<\/span>  end<\/span><\/a>;<\/span>
\n  8<\/span>  \/<\/span>
\ncliente_id:<\/span> 711<\/span>  postal_id:<\/span> 7348<\/span>
\ncliente_id:<\/span> 711<\/span>  postal_id:<\/span> 7348<\/span>
\ncliente_id:<\/span> 711<\/span>  postal_id:<\/span> 7348<\/span>
\ncliente_id:<\/span> 711<\/span>  postal_id:<\/span> 7348<\/span>
\n
\nPL\/<\/span>SQL procedure successfully completed.<\/span>
\n
\nElapsed:<\/span> 00<\/span>:<\/span>00<\/span>:<\/span>59.89<\/span>
\nSQL ><\/span><\/div><\/td><\/tr><\/tbody><\/table><\/div>\n

 <\/p>\n

4) Analisar as informa\u00e7\u00f5es geradas no trace<\/span><\/h2>\n

Consultando a tabela PLSQL_TRACE_EVENTS podemos obter um relat\u00f3rio da execu\u00e7\u00e3o da nossa procedure mostrando os tempos consumidos em cada passo.<\/span><\/p>\n

 <\/p>\n

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
<\/div><\/td>
SQL ><\/span> set lines 300<\/span> pages 100<\/span>
\nSQL ><\/span> col EVENT_TIME  for<\/span> a24;<\/span>
\nSQL ><\/span> col PROC_OWNER for<\/span> a16;<\/span>
\nSQL ><\/span> col EVENT_COMMENT for<\/span> a40;<\/span>
\nSQL ><\/span> col CMD-<\/span>PROC for<\/span> a60;<\/span>
\nSQL ><\/span>
\nSQL ><\/span> select te.<\/span>EVENT_SEQ
\n  2<\/span>         ,<\/span>to_char(<\/span>te.<\/span>EVENT_TIME,<\/span>'dd-mm-yyyy hh24:mi:ss'<\/span>)<\/span> EVENT_TIME
\n  3<\/span>         ,<\/span>SUBSTR<\/span><\/a>(<\/span>src.<\/span>text,<\/span>1<\/span>,<\/span>60<\/span>)<\/span> "CMD-PROC"<\/span>
\n  4<\/span>    from plsql_trace_events te
\n  5<\/span>    left JOIN<\/span><\/a> (<\/span>select *<\/span>
\n  6<\/span>                 from all_source
\n  7<\/span>                where name =<\/span> 'DBTW065_PRC'<\/span>
\n  8<\/span>                  AND owner =<\/span> 'SH'<\/span>)<\/span> src
\n  9<\/span>           ON (<\/span>te.<\/span>event_unit_owner=<\/span>src.<\/span>owner and te.<\/span>event_unit=<\/span>src.<\/span>name and te.<\/span>event_line=<\/span>src.<\/span>line)<\/span>
\n 10<\/span>    where te.<\/span>runid =<\/span> (<\/span>select max<\/span><\/a>(<\/span>runid)<\/span> from plsql_trace_runs)<\/span>
\n 11<\/span>      and te.<\/span>event_unit_owner <><\/span> 'SYS'<\/span>
\n 12<\/span>    order by 1<\/span>;<\/span>
\n
\n EVENT_SEQ EVENT_TIME               CMD-<\/span>PROC
\n----------<\/span> ------------------------<\/span> ------------------------------------------------------------<\/span>
\n         8<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>53<\/span>:<\/span>40<\/span>      PROCEDURE dbtw065_prc
\n         9<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>53<\/span>:<\/span>40<\/span>         select \/* dbtw-065.1 *\/<\/span> count<\/span><\/a>(<\/span>1<\/span>)<\/span> into contador  from (<\/span>
\n        10<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>53<\/span>:<\/span>42<\/span>         OPEN c_dbtw;<\/span>
\n        11<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>53<\/span>:<\/span>42<\/span>         select \/* dbtw-065.2 *\/<\/span> *<\/span>
\n        12<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>53<\/span>:<\/span>42<\/span>         OPEN c_dbtw;<\/span>
\n        13<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>53<\/span>:<\/span>42<\/span>         LOOP
\n        14<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>53<\/span>:<\/span>42<\/span>            FETCH  c_dbtw  INTO r_dbtw;<\/span>
\n        15<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>01<\/span>            EXIT<\/span><\/a> WHEN c_dbtw%<\/span>NOTFOUND;<\/span>
\n        16<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>01<\/span>            dbms_output.<\/span>put_line(<\/span>'cliente_id: '<\/span>||<\/span>r_dbtw.<\/span>cliente_id
\n        45<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>01<\/span>            dbms_output.<\/span>put_line(<\/span>'cliente_id: '<\/span>||<\/span>r_dbtw.<\/span>cliente_id
\n        46<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>01<\/span>         LOOP
\n        47<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>01<\/span>            FETCH  c_dbtw  INTO r_dbtw;<\/span>
\n        48<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>04<\/span>            EXIT<\/span><\/a> WHEN c_dbtw%<\/span>NOTFOUND;<\/span>
\n        49<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>04<\/span>            dbms_output.<\/span>put_line(<\/span>'cliente_id: '<\/span>||<\/span>r_dbtw.<\/span>cliente_id
\n        70<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>04<\/span>            dbms_output.<\/span>put_line(<\/span>'cliente_id: '<\/span>||<\/span>r_dbtw.<\/span>cliente_id
\n        71<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>04<\/span>         LOOP
\n        72<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>04<\/span>            FETCH  c_dbtw  INTO r_dbtw;<\/span>
\n        73<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>30<\/span>            EXIT<\/span><\/a> WHEN c_dbtw%<\/span>NOTFOUND;<\/span>
\n        74<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>30<\/span>            dbms_output.<\/span>put_line(<\/span>'cliente_id: '<\/span>||<\/span>r_dbtw.<\/span>cliente_id
\n        95<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>30<\/span>            dbms_output.<\/span>put_line(<\/span>'cliente_id: '<\/span>||<\/span>r_dbtw.<\/span>cliente_id
\n        96<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>30<\/span>         LOOP
\n        97<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>30<\/span>            FETCH  c_dbtw  INTO r_dbtw;<\/span>
\n        98<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>31<\/span>            EXIT<\/span><\/a> WHEN c_dbtw%<\/span>NOTFOUND;<\/span>
\n        99<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>31<\/span>            dbms_output.<\/span>put_line(<\/span>'cliente_id: '<\/span>||<\/span>r_dbtw.<\/span>cliente_id
\n       120<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>31<\/span>            dbms_output.<\/span>put_line(<\/span>'cliente_id: '<\/span>||<\/span>r_dbtw.<\/span>cliente_id
\n       121<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>31<\/span>         LOOP
\n       122<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>31<\/span>            FETCH  c_dbtw  INTO r_dbtw;<\/span>
\n       123<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>38<\/span>            EXIT<\/span><\/a> WHEN c_dbtw%<\/span>NOTFOUND;<\/span>
\n       124<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>38<\/span>         CLOSE c_dbtw;<\/span>
\n       125<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>38<\/span>         SELECT \/* dbtw-065.3 *\/<\/span> count<\/span><\/a>(<\/span>1<\/span>)<\/span> into contador
\n       126<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>54<\/span>:<\/span>40<\/span>      END<\/span><\/a>;<\/span>
\n
\n31<\/span> rows selected.<\/span>
\n
\nSQL ><\/span><\/div><\/td><\/tr><\/tbody><\/table><\/div>\n

 <\/p>\n

Observe que\u00a0a subtra\u00e7\u00e3o do tempo final da execu\u00e7\u00e3o pelo tempo inicial\u00a0corresponde a 60 segundos que \u00e9 o tempo de execu\u00e7\u00e3o procedure.<\/span>
\nO ponto da procedure que consumiu mais tempo foi entre os EVENT_SEQ 72 e 73, neste ponto foram gastos 26 segundos para realizar o comando FETCH no cursor C_DBTW, este cursor executa a consulta DBTW-065.2.<\/span>
\nOs outros pontos onde os tempos de dura\u00e7\u00e3o foram elevados na procedure s\u00e3o todos relacionados ao comando FETCH no cursor C_DBTW, portanto\u00a0conclu\u00edmos que\u00a0precisamos otimizar a consulta DBTW-065.2 para baixar o tempo de execu\u00e7\u00e3o da procedure.<\/span><\/p>\n

5) Aplicar melhoria no banco<\/span><\/h2>\n

A consulta DBTW-065.2 possui dois filtros na clausula WHERE para as colunas POSTAL_ID e CLIENTE_ID, vamos criar um \u00edndice composto na tabela DBTW065 incluindo estas duas colunas. Se voc\u00ea quiser saber mais sobre \u00edndice composto leia o artigo:\u00a0Quando devemos criar um \u00edndice composto?<\/a><\/strong><\/span><\/p>\n

 <\/p>\n

1
2
3
4
5
6
7
8
9
10
11
12
<\/div><\/td>
SQL ><\/span> create index idx_dbtw065 on dbtw065(<\/span>postal_id,<\/span>cliente_id)<\/span> parallel 16<\/span>;<\/span>
\n
\nIndex created.<\/span>
\n
\nElapsed:<\/span> 00<\/span>:<\/span>00<\/span>:<\/span>24.94<\/span>
\nSQL ><\/span>
\nSQL ><\/span> alter index idx_dbtw065 noparallel;<\/span>
\n
\nIndex altered.<\/span>
\n
\nElapsed:<\/span> 00<\/span>:<\/span>00<\/span>:<\/span>00.01<\/span>
\nSQL ><\/span><\/div><\/td><\/tr><\/tbody><\/table><\/div>\n

 <\/p>\n

6) Executar a procedure novamente habilitando o trace<\/span><\/h2>\n

 <\/p>\n

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
<\/div><\/td>
SQL ><\/span> set  serveroutput on size 9999<\/span>
\nSQL ><\/span> alter session set current_schema =<\/span> sh;<\/span>
\n
\nSession altered.<\/span>
\n
\nElapsed:<\/span> 00<\/span>:<\/span>00<\/span>:<\/span>00.00<\/span>
\nSQL ><\/span>
\nSQL ><\/span> begin
\n  2<\/span>
\n  3<\/span>     dbms_trace.<\/span>set_plsql_trace(<\/span>dbms_trace.<\/span>trace_all_lines)<\/span>;<\/span>
\n  4<\/span>     dbtw065_prc;<\/span>
\n  5<\/span>     dbms_trace.<\/span>clear_plsql_trace;<\/span>
\n  6<\/span>
\n  7<\/span>  end<\/span><\/a>;<\/span>
\n  8<\/span>  \/<\/span>
\ncliente_id:<\/span> 711<\/span>  postal_id:<\/span> 7348<\/span>
\ncliente_id:<\/span> 711<\/span>  postal_id:<\/span> 7348<\/span>
\ncliente_id:<\/span> 711<\/span>  postal_id:<\/span> 7348<\/span>
\ncliente_id:<\/span> 711<\/span>  postal_id:<\/span> 7348<\/span>
\n
\nPL\/<\/span>SQL procedure successfully completed.<\/span>
\n
\nElapsed:<\/span> 00<\/span>:<\/span>00<\/span>:<\/span>04.46<\/span>
\nSQL ><\/span><\/div><\/td><\/tr><\/tbody><\/table><\/div>\n

 <\/p>\n

Observando o tempo de execu\u00e7\u00e3o da procedure podemos verificar que houve uma melhora significativa, o tempo de execu\u00e7\u00e3o da procedure caiu de 60 segundos para 4 segundos e 46 cent\u00e9simos de segundo. Houve uma redu\u00e7\u00e3o de 92,5% no tempo de execu\u00e7\u00e3o da procedure. <\/span><\/p>\n

 <\/p>\n

7) Analisar as informa\u00e7\u00f5es geradas no trace ap\u00f3s melhoria<\/span><\/h2>\n

 <\/p>\n

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
<\/div><\/td>
SQL ><\/span> set lines 300<\/span> pages 100<\/span>
\nSQL ><\/span> col EVENT_TIME  for<\/span> a24;<\/span>
\nSQL ><\/span> col PROC_OWNER for<\/span> a16;<\/span>
\nSQL ><\/span> col EVENT_COMMENT for<\/span> a40;<\/span>
\nSQL ><\/span> col CMD-<\/span>PROC for<\/span> a60;<\/span>
\nSQL ><\/span>
\nSQL ><\/span> select te.<\/span>EVENT_SEQ
\n  2<\/span>         ,<\/span>to_char(<\/span>te.<\/span>EVENT_TIME,<\/span>'dd-mm-yyyy hh24:mi:ss'<\/span>)<\/span> EVENT_TIME
\n  3<\/span>         ,<\/span>SUBSTR<\/span><\/a>(<\/span>src.<\/span>text,<\/span>1<\/span>,<\/span>60<\/span>)<\/span> "CMD-PROC"<\/span>
\n  4<\/span>    from plsql_trace_events te
\n  5<\/span>    left JOIN<\/span><\/a> (<\/span>select *<\/span>
\n  6<\/span>                 from all_source
\n  7<\/span>                where name =<\/span> 'DBTW065_PRC'<\/span>
\n  8<\/span>                  AND owner =<\/span> 'SH'<\/span>)<\/span> src
\n  9<\/span>           ON (<\/span>te.<\/span>event_unit_owner=<\/span>src.<\/span>owner and te.<\/span>event_unit=<\/span>src.<\/span>name and te.<\/span>event_line=<\/span>src.<\/span>line)<\/span>
\n 10<\/span>    where te.<\/span>runid =<\/span> (<\/span>select max<\/span><\/a>(<\/span>runid)<\/span> from plsql_trace_runs)<\/span>
\n 11<\/span>      and te.<\/span>event_unit_owner <><\/span> 'SYS'<\/span>
\n 12<\/span>    order by 1<\/span>;<\/span>
\n
\n EVENT_SEQ EVENT_TIME               CMD-<\/span>PROC
\n----------<\/span> ------------------------<\/span> ------------------------------------------------------------<\/span>
\n         7<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>11<\/span>      PROCEDURE dbtw065_prc
\n         8<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>11<\/span>         select \/* dbtw-065.1 *\/<\/span> count<\/span><\/a>(<\/span>1<\/span>)<\/span> into contador  from (<\/span>
\n         9<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>         OPEN c_dbtw;<\/span>
\n        10<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>         select \/* dbtw-065.2 *\/<\/span> *<\/span>
\n        11<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>         OPEN c_dbtw;<\/span>
\n        12<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>         LOOP
\n        13<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>            FETCH  c_dbtw  INTO r_dbtw;<\/span>
\n        14<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>            EXIT<\/span><\/a> WHEN c_dbtw%<\/span>NOTFOUND;<\/span>
\n        15<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>            dbms_output.<\/span>put_line(<\/span>'cliente_id: '<\/span>||<\/span>r_dbtw.<\/span>cliente_id
\n        44<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>            dbms_output.<\/span>put_line(<\/span>'cliente_id: '<\/span>||<\/span>r_dbtw.<\/span>cliente_id
\n        45<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>         LOOP
\n        46<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>            FETCH  c_dbtw  INTO r_dbtw;<\/span>
\n        47<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>            EXIT<\/span><\/a> WHEN c_dbtw%<\/span>NOTFOUND;<\/span>
\n        48<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>            dbms_output.<\/span>put_line(<\/span>'cliente_id: '<\/span>||<\/span>r_dbtw.<\/span>cliente_id
\n        69<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>            dbms_output.<\/span>put_line(<\/span>'cliente_id: '<\/span>||<\/span>r_dbtw.<\/span>cliente_id
\n        70<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>         LOOP
\n        71<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>            FETCH  c_dbtw  INTO r_dbtw;<\/span>
\n        72<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>            EXIT<\/span><\/a> WHEN c_dbtw%<\/span>NOTFOUND;<\/span>
\n        73<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>            dbms_output.<\/span>put_line(<\/span>'cliente_id: '<\/span>||<\/span>r_dbtw.<\/span>cliente_id
\n        94<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>            dbms_output.<\/span>put_line(<\/span>'cliente_id: '<\/span>||<\/span>r_dbtw.<\/span>cliente_id
\n        95<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>         LOOP
\n        96<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>            FETCH  c_dbtw  INTO r_dbtw;<\/span>
\n        97<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>            EXIT<\/span><\/a> WHEN c_dbtw%<\/span>NOTFOUND;<\/span>
\n        98<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>            dbms_output.<\/span>put_line(<\/span>'cliente_id: '<\/span>||<\/span>r_dbtw.<\/span>cliente_id
\n       119<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>            dbms_output.<\/span>put_line(<\/span>'cliente_id: '<\/span>||<\/span>r_dbtw.<\/span>cliente_id
\n       120<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>         LOOP
\n       121<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>            FETCH  c_dbtw  INTO r_dbtw;<\/span>
\n       122<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>            EXIT<\/span><\/a> WHEN c_dbtw%<\/span>NOTFOUND;<\/span>
\n       123<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>         CLOSE c_dbtw;<\/span>
\n       124<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>13<\/span>         SELECT \/* dbtw-065.3 *\/<\/span> count<\/span><\/a>(<\/span>1<\/span>)<\/span> into contador
\n       125<\/span> 15<\/span>-<\/span>07<\/span>-<\/span>2020<\/span> 10<\/span>:<\/span>59<\/span>:<\/span>15<\/span>      END<\/span><\/a>;<\/span>
\n
\n31<\/span> rows selected.<\/span>
\n
\nSQL ><\/span><\/div><\/td><\/tr><\/tbody><\/table><\/div>\n

 <\/p>\n

Verificando o relat\u00f3rio gerado pela consulta na tabela PLSQL_TRACE_EVENTS, constatamos que todas as chamadas do comando FETCH foram executadas em menos de 1 segundo e os quatro segundos gastos na execu\u00e7\u00e3o da procedure foram consumidos pelas outras duas consultas que faziam parte da procedure.<\/span><\/p>\n

Refer\u00eancias<\/span><\/h2>\n

https:\/\/docs.oracle.com\/cd\/E18283_01\/appdev.112\/<\/a><\/span><\/strong><\/p>\n

 
\n 
\n 
\n\"Promo-D75L\"<\/a><\/p>\n

\"video-02\"<\/a>
\n 
\n 
\n 
\n 
\n 
\n 
\n 
\n 
\n 
\n 
\n 
\n <\/p>\n","protected":false},"excerpt":{"rendered":"

Durante o desenvolvimento ou altera\u00e7\u00e3o de um c\u00f3digo PL\/SQL eventualmente o desempenho ou tempo de execu\u00e7\u00e3o deste c\u00f3digo pode ser insatisfat\u00f3rio, dependendo do tamanho c\u00f3digo e de quantas instru\u00e7\u00f5es SQL existem nele pode haver certa dificuldade para identificar qual ou quais instru\u00e7\u00f5es SQL est\u00e3o causando a perda de desempenho, para ajudar a identificar as instru\u00e7\u00f5es do c\u00f3digo que est\u00e3o com<\/p>\n","protected":false},"author":2,"featured_media":2184,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[211],"tags":[236,82,10,239,209,237,238],"class_list":["post-2183","post","type-post","status-publish","format-standard","has-post-thumbnail","hentry","category-plsql","tag-dbms_trace","tag-optimizer","tag-otimizador","tag-otimizar-plsql","tag-plsql-tuning","tag-plsql_trace_events","tag-plsql_trace_runs"],"aioseo_notices":[],"_links":{"self":[{"href":"http:\/\/dbtimewizard.com.br\/blog\/wp-json\/wp\/v2\/posts\/2183","targetHints":{"allow":["GET"]}}],"collection":[{"href":"http:\/\/dbtimewizard.com.br\/blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"http:\/\/dbtimewizard.com.br\/blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"http:\/\/dbtimewizard.com.br\/blog\/wp-json\/wp\/v2\/users\/2"}],"replies":[{"embeddable":true,"href":"http:\/\/dbtimewizard.com.br\/blog\/wp-json\/wp\/v2\/comments?post=2183"}],"version-history":[{"count":20,"href":"http:\/\/dbtimewizard.com.br\/blog\/wp-json\/wp\/v2\/posts\/2183\/revisions"}],"predecessor-version":[{"id":2208,"href":"http:\/\/dbtimewizard.com.br\/blog\/wp-json\/wp\/v2\/posts\/2183\/revisions\/2208"}],"wp:featuredmedia":[{"embeddable":true,"href":"http:\/\/dbtimewizard.com.br\/blog\/wp-json\/wp\/v2\/media\/2184"}],"wp:attachment":[{"href":"http:\/\/dbtimewizard.com.br\/blog\/wp-json\/wp\/v2\/media?parent=2183"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"http:\/\/dbtimewizard.com.br\/blog\/wp-json\/wp\/v2\/categories?post=2183"},{"taxonomy":"post_tag","embeddable":true,"href":"http:\/\/dbtimewizard.com.br\/blog\/wp-json\/wp\/v2\/tags?post=2183"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}