#oracle #query-optimization #database-administration #sql-execution-plan #sqlperformance
#Oracle #оптимизация запросов #администрирование базы данных #sql-execution-plan #производительность sqlperformance
Вопрос:
Я пытаюсь изучить влияние на производительность операции массового сбора. Я выполнил пару запросов и получил результат 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.
Ответ №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
Комментарии:
1. Привет, Р. Ду. Спасибо за ваш ответ. Если я запускаю свои блоки один за другим и получаю вывод tkprof, я вижу это так, как вы показали здесь. Но если я выполняю все свои запросы за один шаг, а затем получаю вывод tkprof для всех, я могу видеть SQL-запрос с выборками для первого блока, но для остальных он не показывает SQL-запросы, которые я использовал в них. Итак, в чем может быть причина?
2. это потому, что у вас точно такой же запрос во всех блоках, поэтому все время для этого запроса суммируется. например, если вы запустите 4 разных блока с одним и тем же запросом, вы увидите Execute = 4 для этого запроса. Слегка измените свой запрос, чтобы увидеть 4 разных запроса в вашем tkprof, например, добавьте предложение типа «И 1> = 1», «И 2> = 1». Это не должно изменять время синтаксического анализа и выполнения, но это заставит Oracle рассматривать его как новый запрос.
3. Да. Это правильно. Большое вам спасибо R.Du Bests
4. Пожалуйста. Другой вариант — запустить 1 сеанс sqlplus для каждого измерения. Каждый раз, когда вам нужно будет подключаться к sqlplus, выполните команду «alter session set sql_trace= true», запустите 1 блок PL / SQL, затем выйдите из sql * plus, чтобы у вас было 4 разных файла трассировки.