Автор: Крючков Вячеслав
Тема: Подсчитаем consistent gets
Источник: Russian Oracle User Group
Номер документа: 1.1
Дата публикации: 24.04.2009
Последнее изменение: 24.04.2009


Общеизвестный факт, что полный доступ к таблице (или к значительной ее части) по индексу не эффективен. Тем не менее повторюсь и приведу пример (Оговорю сразу - предполагается, что речь идет о часто используемой таблице и она вся закеширована. В противном случае добавятся физические чтения как N процентов от логических чтений). Создадим табличку для тестов:

SQL> conn rtest/rtest
SQL> create table READS_TEST as select * from all_objects;

Table created.

SQL> create unique index indx_1 on READS_TEST (object_id);

Index created.

SQL> EXEC Dbms_Stats.gather_table_stats('RTEST', 'READS_TEST');

SQL> set autotrace traceonly;

И выполним два запроса: используя доступ по индексу и фулскан.

SQL> select /*+ INDEX (READS_TEST indx_1) */ * from READS_TEST;

5299 rows selected.

------------------------------------------------------------------------------------------
| Id  | Operation                   | Name       | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |            |  5299 |   429K|    80   (2)| 00:00:01 |
|   1 |  TABLE ACCESS BY INDEX ROWID| READS_TEST |  5299 |   429K|    80   (2)| 00:00:01 |
|   2 |   INDEX FULL SCAN           | INDX_1     |  5299 |       |    12   (0)| 00:00:01 |
------------------------------------------------------------------------------------------

Statistics
----------------------------------------------------------
...
       784  consistent gets
...

SQL> select * from READS_TEST;

5299 rows selected.

--------------------------------------------------------------------------------
| Id  | Operation         | Name       | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |            |  5299 |   429K|     7  (15)| 00:00:01 |
|   1 |  TABLE ACCESS FULL| READS_TEST |  5299 |   429K|     7  (15)| 00:00:01 |
--------------------------------------------------------------------------------

Statistics
----------------------------------------------------------
...
        425  consistent gets
...
	  
SQL> set autotrace off

Что и требовалось доказать, доступ по индексу - 784 логический чтений, полный доступ к таблице - 425. Однако если посмотреть на размер таблицы, можно уведеть одну неувязку:

SQL> SELECT BLOCKS FROM user_tables WHERE table_name = 'READS_TEST';

    BLOCKS
----------
        80

Размер таблицы-то всего 80 блоков, откуда 425 чтений? Включим трассировку и посмотрим, откуда они берутся.

	   
SQL> alter session set events '10046 trace name context forever, level 12';
SQL> select * from READS_TEST;

В трейсе, обработаном утилитой tkprof видим те же 425 чтений (query=425):

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.01       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch      355      0.03       0.02          0        425          0        5299
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total      357      0.04       0.02          0        425          0        5299

В необработанном трейсе:

PARSING IN CURSOR #1 len=24 dep=0 uid=55 oct=3 lid=55 tim=1194712239 hv=919921535 ad='1f03c07c'
select * from READS_TEST
END OF STMT
PARSE #1:c=0,e=869,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=1194712233
BINDS #1:
EXEC #1:c=0,e=364,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1194714381
WAIT #1: nam='SQL*Net message to client' ela= 8 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1194714734
FETCH #1:c=0,e=72,p=0,cr=4,cu=0,mis=0,r=1,dep=0,og=1,tim=1194715167
WAIT #1: nam='SQL*Net message from client' ela= 889 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1194716460
WAIT #1: nam='SQL*Net message to client' ela= 5 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1194717027
FETCH #1:c=0,e=388,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=1,tim=1194717382
WAIT #1: nam='SQL*Net message from client' ela= 857 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1194718607
WAIT #1: nam='SQL*Net message to client' ela= 5 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1194719433
FETCH #1:c=0,e=585,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=1,tim=1194719982
...

И дальше много-много строчек подобных FETCH #1:c=0,e=585,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=1,tim=1194719982 (если есть сложности с интерпретацией сырого трейса, см. ноту 39817.1). Операция FETCH - возврат строк клиенту, cr=1 означает, что для данного фетча было сделано одно согласованное чтение. Вот и наши 417 чтений - 355 фетчей (см. Fetch=355 в обработанном трейсе) преимущественно по 1, иногда по 2 блока на фетч (в случае если возвращаемые строки находяться в конце одного и начале следующего блоков). Почему же так много фетчей? Смотрим на r=15, клиент забирает результат запроса по 15 строк. И действительно, в sqlplus по умолчанию размер фетча - 15 строк. Что же будет, если ученьшить его по самое немогу?

SQL> set array 1
SQL> select * from READS_TEST;

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     2651      0.10       0.08          0       2697          0        5299
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total     2653      0.10       0.08          0       2697          0        5299

PARSING IN CURSOR #1 len=24 dep=0 uid=55 oct=3 lid=55 tim=1198393061 hv=919921535 ad='1f03c07c'
select * from READS_TEST
END OF STMT
PARSE #1:c=0,e=72,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1198393056
BINDS #1:
EXEC #1:c=0,e=375,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1198395070
WAIT #1: nam='SQL*Net message to client' ela= 6 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1198395456
FETCH #1:c=0,e=72,p=0,cr=4,cu=0,mis=0,r=1,dep=0,og=1,tim=1198395878
WAIT #1: nam='SQL*Net message from client' ela= 941 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1198397204
WAIT #1: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1198397751
FETCH #1:c=0,e=390,p=0,cr=1,cu=0,mis=0,r=2,dep=0,og=1,tim=1198398109
WAIT #1: nam='SQL*Net message from client' ela= 607 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1198399108
WAIT #1: nam='SQL*Net message to client' ela= 4 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1198399629
FETCH #1:c=0,e=367,p=0,cr=1,cu=0,mis=0,r=2,dep=0,og=1,tim=1198399963
...

Запрос тот же, план тот же, данные те же, статистика та же, изменился только размер фетча. Результат - количество прочитанных блоков увеличилось в 2697/425=6.4 раза! Тут еще sqlplus жульничет, читает по 2 строки (r=2 в необработанном трейсе). Например в pl/sql используя курсор или из программы на java например можно добиться чтения действительно по одной строке, в таком случае будет прочитано 5308 блоков! Немного больше, чем количество строк, и это при фулскане таблицы. Для каждого фетча серверу необходимо прочитать блок, в котором содержится строка. И не важно, что до этого был прочитан тот же блок, и не важно, что только одна строка нужна. Делаем фетч -> читаем блок. В случае с chained rows ситуация будет гм.. несколько хуже. В поисках негативного влияния большого размера фетча я запустил две сессии с тем же запросом "SELECT * FROM READS_TEST;": одну с размером фетча 100, вторую с 2 и сравнил статистику. Основные отличия:

Stats (fetchsize=100)                   Value
------------------------------------ -----------
user calls                                    81
session logical reads                        160
CPU used by this session                       0
bytes sent via SQL*Net to client          207412

Stats (fetchsize=2)                     Value
------------------------------------ -----------
user calls                                  2678
session logical reads                       2722
CPU used by this session                      17
bytes sent via SQL*Net to client          537200

Ничего плохого в статистике первой сессии замечено не было, даже наоборот. У первой сессии намного меньше 'user calls' 81 против 2678 (каждый фетч дает допольниткльный вызов), большая разница в 'session logical reads' - 160 против 2722, как следствие 'CPU used by this session' - 0 против 17. Кроме этого заметна значительная разница в объеме передаваемой информации по сети - 'bytes sent via SQL*Net to client' у первой сесии 207412 против 537200 у второй. В остальном статистика не отличается.

Негативное влияние может проявиться в том, что при маленьком размере фетча первая строка результата попадет к клиенту немного (или много?) быстрее, чем при большом. Насколько быстрее - зависит от запроса. Так что надо пробовать и смотреть. Еще плохо может быть на стороне клиента - нужно больше памяти для храния большего массива данных (зато всегда можно потыкать пальцем в java, мол памяти ест мама не горюй :).

Эффект многократного чтения блоков при фулскане исчезает, если добавить сортировку (в этом случае серверу необходимо прочесть всю таблицу перед тем, как вернуть первую строку). Статистика по двум сессиям с разным размером фетча для запроса "select * from READS_TEST order by owner":

Stat (fetchsize=100)                    Value
------------------------------------ -----------
user calls                                    81
session logical reads                        101
CPU used by this session                       4
bytes sent via SQL*Net to client          210019

Stat (fetchsize=2)                      Value
------------------------------------ -----------
user calls                                  2678
session logical reads                        101
CPU used by this session                      14
bytes sent via SQL*Net to client          539823

В обоих случаях - 101 consistent gets. Однако разница в 'bytes sent via SQL*Net to client' никуда не делась 210019 против 539823. 'CPU used by this session' также отличается в пользу большего фетча - 4 против 14, осталавсь разница и в 'user calls' - 81 против 2678.

Все предыдущие примеры были показаны на полном доступе к таблице и большому результирующему набору. Однако болячка эта есть и у доступа по индексу к маленькому количеству строк, только с индексом все еще веселее. В данном примере выбирается только 5 строк и я хотел бы сделать тест при размере фетча равном 1, поэтому перейдем к pl/sql. Запрос "select * from READS_TEST where object_name = 'RTEST'" использует неуникальный индекс для доступа к таблице, возвращает 5 строк. Опция LIMIT управляет размером фетча.

declare
cursor c is select owner from READS_TEST where object_name = 'RTEST';
type array is table of c%rowtype index by binary_integer;

l_data array;
v_name Varchar2(100);
begin
	execute immediate 'alter session set events ''10046 trace name context forever, level 12''';
     open c;
      loop
          fetch c bulk collect into l_data LIMIT 15; -- здесь менять размер фетча, пробуем 15 и 1
          for i in 1 .. l_data.count
          loop
              v_name := l_data(i).owner;
          end loop;
          exit when c%notfound;
      end loop;
      close c;
	execute immediate 'alter session set events ''10046 trace name context off''';
	SELECT Value||(CASE WHEN InStr(Value,'\')>0 THEN '\' ELSE '/' END)||INSTANCE_NAME||'_ora_'||SPID||'.trc' into v_name FROM v$session s, v$process  p ,v$instance, v$parameter WHERE sid = (SELECT sid FROM v$mystat WHERE ROWNUM < 2) AND s.paddr = p.addr AND name = 'user_dump_dest';
	dbms_output.put_line(v_name);
end;
/

Результат обработанной трассировки для размера фетча 15:

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        1      0.00       0.00          0          3          0           5
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      0.00       0.00          0          3          0           5

Для размера фетча 1:

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        6      0.00       0.00          0         12          0           5
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        8      0.00       0.00          0         12          0           5

Разница 3 чтения против 12. С тремя все понятно: 1 - прочитали корневой блок индекса + 1 - прочитали листовой блок индекса + 1 - прочитали блок таблицы, отдали клиенту пять строчек, при этом знаем, что больше строчек нет. Во втором случае начало то же: 3 чтения на первый фетч + 2 на второй фетч (1 блок индекса + 1 блок таблицы) + 2*3 (еще три фетча 1 блок индекса + 1 блок таблицы) + 1 блок индекса чтоб проверить, что больше читать нечего. Разница количества блоков в 4 раза! Фактически получаем, что для каждого фетча нужно прочитать два блока - индекс и таблицу, количество чтений будет всегда примерно равно количеству строк умноженному на 2. Даже если в результате получаем только 1 строку, при размере фетча равном 1 будет дополнительное чтение блока индекса чтоб проверить, нет ли там еще одной подходящей записи. Уникальный индекс тут поможет, но создать индекс уникальным мы можем далеко не всегда.

Как я уже говорил, негативный эффект от большого размера фетча может сказываться на времени возврата первой строки. Для демонстрации тоже используем pl/sql и курсор. В кратце смысл теста - с разным размером фетча выполняем относительно сложный запрос с использованием индексов и nested_loop-ов (что обеспечивает несколько логических чтений для возврата одной строки), фетчим только первую строку результата, повторяем выполнение запроса и фетч 1000 раз.

declare
cursor c is SELECT /*+ USE_NL (t1 t2 t3) */ t1.owner FROM reads_test t1, reads_test t2, reads_test t3 WHERE t1.OBJECT_NAME = t2.OBJECT_NAME AND t3.OBJECT_NAME = t2.OBJECT_NAME;
type array is table of c%rowtype index by binary_integer;
cursor c1 is SELECT sn.name, ms.Value FROM v$statname sn, v$mystat ms WHERE sn.STATISTIC# = ms.STATISTIC#  AND ms.STATISTIC# IN (6,9,12,335);
type array1 is table of c1%rowtype index by binary_integer;

l_data array;
v_name Varchar2(100);
l_data1 array1;
vl number;
begin
	for i in 1..1000 loop
	    open c;
		fetch c bulk collect into l_data LIMIT 100;
		v_name := l_data(1).owner;
	    close c;
	end loop;
	open c1;
	fetch c1 bulk collect into l_data1 LIMIT 4;
	  for i1 in 1 .. l_data1.count
	  loop
		  dbms_output.put(rpad(l_data1(i1).name,40));
		  dbms_output.put_line(l_data1(i1).value);
	  end loop;
	close c1;
end;
/

Результат для размера фетча = 100:

user calls                              30
session logical reads                   126040
CPU used by this session                61
bytes sent via SQL*Net to client        4537
Elapsed: 00:00:00.64

Результат для размера фетча = 1:

user calls                              30
session logical reads                   11036
CPU used by this session                9
bytes sent via SQL*Net to client        4537
Elapsed: 00:00:00.07

Видим значительную разцицу во времени выполнения, разницу в 'session logical reads' и 'CPU used by this session' все показатели в пользу маленького размера фетча. Полькольку тест сделан на pl/sql, в статистике нет разницы по 'bytes sent via SQL*Net to client', если сделать подобный тест на java, разница в переданных данных будет значительной, тоже в пользу маленького размера фетча. Фактически первая сессия выбрала 1000 раз по 100 строк, вторая сессия - 1000 раз по одной строке. Я считаю, что ситуация при которой клиент забирает только небольшое количество строк из результирующего набора - плохой дизайн приложения и нужно переделывать в корне, но как временное решение может помочь уменьшение размера фетча до количества забираемых строк (в принципе ситуация маловероятна, если размер фетча не был неоправданно завышен ранее, например по-умолчанию в java он равен 10).

Влияние размера фетча на количество чтений наблюдается на всех доступных мне версиях, проверено на 8.1.7.4, 9.2.0.8, 10.2.0.3, 11.1.0.6.0. Когда я впервые с этим столкнулся, был некоторое время озадачен. Проблема хитрая, планы запросов не отличаются, заметить можно только при трассировке или проанализировав FETCHES, EXECUTIONS, ROWS_PROCESSED, BUFFER_GETS из V$SQL (FETCHES появилось в 9i). Улучшение производительности при увеличении размера фетча напрямую зависят от количества возвращаемых строк, чем больше строк тем лучше будет с большим фетчем. Но обязательно пробовать и сравнивать!


Дополнительные материалы: Демонстрационные скрипты