Почему мой файл TKPROF не показывает число выборок моего блока PL / SQL?

Question

Я пытаюсь изучить влияние на производительность операции массового сбора.Я выполнил пару запросов и взял вывод TKPROF.Однако для любого из этих блоков PL / SQL нет счетчика выборок, чтобы увидеть счетчик переключения контекста.Все они равны 0. И я не мог ясно понять эффекты массового сбора, также по временам выполнения.

Ниже я поделился выводом TKPROF выполненных запросов.И я использовал стандартную схему SH базы данных.Не могли бы вы помочь мне в этом?

TKPROF: Release 12.2.0.1.0 - Development on Thu Apr 11 08:51:44 2019

Copyright (c) 1982, 2017, Oracle and/or its affiliates.  All rights reserved.

Trace file: orcl_ora_15104_TUNY.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: 3bza4q71t1k45 Plan Hash: 0

BEGIN dbms_session.session_trace_enable(waits=>true, binds => true); END;


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        0      0.00       0.00          0          0          0           0
Execute      1      0.03       0.03          2        377          0           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        1      0.03       0.03          2        377          0           1

Misses in library cache during parse: 0
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 230  

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        4.06          4.06
********************************************************************************

declare
 cursor c1 is select cust_id, cust_email FROM customers order by cust_id;
 type r_type is table of c1%rowtype;
 r1 r_type := r_type();
 idx pls_integer := 0;
BEGIN
    OPEN c1;
    LOOP
        idx:=idx+1;
        r1.extend;
        FETCH c1 INTO r1(idx);
        EXIT WHEN c1%notfound;
    END LOOP;
    CLOSE c1;
    dbms_output.put_line(r1(idx-1).cust_id);
END;

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      2.06       2.05          0          0          0           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      2.06       2.05          0          0          0           1

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 230  

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  PGA memory operation                          171        0.00          0.00
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.02          0.02
********************************************************************************

declare
 cursor c1 is select cust_id, cust_email FROM customers order by cust_id;
 type r_type is table of c1%rowtype;
 r1 r_type := r_type();
BEGIN
    OPEN c1;
        FETCH c1 BULK COLLECT INTO r1;
    CLOSE c1;
    dbms_output.put_line(r1(r1.last).cust_id);
END;

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           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.00       0.00          0          0          0           1

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 230  

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  PGA memory operation                            1        0.00          0.00
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.07          0.07
********************************************************************************

declare
 cursor c1 is select cust_id, cust_email FROM customers order by cust_id;
 type r_type is table of c1%rowtype;
 r1 r_type := r_type();
BEGIN
    OPEN c1;
        FETCH c1 BULK COLLECT INTO r1 LIMIT 100;
    CLOSE c1;
    dbms_output.put_line(r1(r1.last).cust_id);
END;

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           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.00       0.00          0          0          0           1

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 230  

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  PGA memory operation                            1        0.00          0.00
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.07          0.07
********************************************************************************

declare
 cursor c1 is select cust_id, cust_email FROM customers order by cust_id;
 type r_type is table of c1%rowtype;
 r1 r_type := r_type();
BEGIN
    OPEN c1;
        FETCH c1 BULK COLLECT INTO r1 LIMIT 1000;
    CLOSE c1;
    dbms_output.put_line(r1(r1.last).cust_id);
END;

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.01       0.00          0          0          0           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.01       0.00          0          0          0           1

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 230  

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  PGA memory operation                            1        0.00          0.00
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1       14.66         14.66
********************************************************************************

declare
 cursor c1 is select cust_id, cust_email FROM customers order by cust_id;
 type r_type is table of c1%rowtype;
 r1 r_type := r_type();
BEGIN
    OPEN c1;
        FETCH c1 BULK COLLECT INTO r1 LIMIT 100000;
    CLOSE c1;
    dbms_output.put_line(r1(r1.last).cust_id);
END;

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.03          0          0          0           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.00       0.03          0          0          0           1

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 230  

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  PGA memory operation                            1        0.00          0.00
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1       11.04         11.04
********************************************************************************

SQL ID: bz2z37aj1gkkw Plan Hash: 0

BEGIN dbms_session.session_trace_disable; END;


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           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.00       0.00          0          0          0           1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 230  



********************************************************************************

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        6      0.00       0.00          0          0          0           0
Execute      7      2.10       2.13          2        377          0           7
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       13      2.10       2.13          2        377          0           7

Misses in library cache during parse: 1
Misses in library cache during execute: 1

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       6        0.00          0.00
  SQL*Net message from client                     6       14.66         29.95
  PGA memory operation                          175        0.00          0.01


OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        0      0.00       0.00          0          0          0           0
Execute      0      0.00       0.00          0          0          0           0
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        0      0.00       0.00          0          0          0           0

Misses in library cache during parse: 0

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  PGA memory operation                          478        0.00          0.00

    7  user  SQL statements in session.
    0  internal SQL statements in session.
    7  SQL statements in session.
********************************************************************************
Trace file: orcl_ora_15104_TUNY.trc
Trace file compatibility: 12.2.0.0
Sort options: default

       1  session in tracefile.
       7  user  SQL statements in trace file.
       0  internal SQL statements in trace file.
       7  SQL statements in trace file.
       7  unique SQL statements in trace file.
   56323  lines in trace file.
      32  elapsed seconds in trace file.

Answer 1

По умолчанию в вашем файле tkprof должен быть записан запрос SELECT.

Сначала переведите сеанс в режим трассировки:

ALTER SESSION SET SQL_TRACE=TRUE

Затем запустите следующий блок PL / SQL, например:

declare
  cursor c1 is select username 
    FROM all_users order by username;
  type r_type is table of c1%rowtype;  r1 r_type := r_type();
  idx pls_integer := 0;
BEGIN
    OPEN c1;
    LOOP
        idx:=idx+1;
        r1.extend;
        FETCH c1 INTO r1(idx);
        EXIT WHEN c1%notfound;
    END LOOP;
    CLOSE c1;
    dbms_output.put_line(r1(idx-1).username);
END;
/

Затем вы можете сгенерировать файл tkprof из файла трассировки:

tkprof xe_ora_16120.trc sys=no

и в сгенерированном файле tkprof вы должны увидеть время для запросов SQL, которые были в блоке PL / SQL:

SQL ID: cccjz73g9uyba Plan Hash: 1902255816

SELECT USERNAME 
FROM
 ALL_USERS ORDER BY USERNAME


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.03       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch       31      0.00       0.00          0         55          0          30
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       33      0.03       0.01          0         55          0          30