Luxoft Training предлагает познакомиться с переводом статьи Рандольфа Гайста «Advanced Oracle Troubleshooting Session — PGA/UGA memory fragmentation».
Рандольф Гайст специализируется на исправлении ошибок, связанных с производительностью баз данных Oracle. Входит в число лучших специалистов в мире в области анализа исполнения SQL-кода и технологий Oracle по оптимизации. Является сертифицированным администратором Oracle базы данных (OCP DBA) версий 8i, 9i и 10g.
Сессия устранения неполадок в Oracle для продвинутых пользователей – фрагментация памяти PGA/UGA
Сессия диагностики и устранения неисправностей базы данных одного из моих клиентов началась со следующего описания проблемы: в некоторых конкретных средах иногда отдельный процесс пакетной обработки занимает значительно больше времени, чем ожидается (вместо нескольких минут несколько часов). Кроме того, при мониторинге можно обнаружить SQL-запросы, которые ведут себя нестандартно.
Итак, в первую очередь необходимо было научиться воспроизводить проблему.
Достаточно быстро удалось обнаружить конкретный вызов сложной хранимой процедуры PL/SQL из некоторого пакета, которая обращалась к множеству других хранимых процедур / пакетов и которая служила для обработки LOB (больших объектов), содержащих данные XML.
Оказалось, что проблему можно воспроизвести вызовом данной хранимой процедуры несколько раз в цикле, причем в различных средах баз данных, как и сообщалось в начале.
Уникальное свойство данной хранимой процедуры – она выполнялась в «эксклюзивном» режиме. Это значит, что она выполнялась на достаточно большом сервере IBMpSeries (AIX 5.3, 11.1.0.7, 240 Гб RAM, многочисленные многоядерные процессоры P6, дорогостоящее хранилище) без каких-либо других активных бизнес-процессов одновременно. В основном это было последовательное выполнение. Мониторинг показал, что данная процедура тратила большую часть времени на два простых и понятных SQL-запроса. Это были статические SQL-запросы, вызываемые из PL/SQL, которые обращались к одной и той же маленькой таблице по уникальному индексу и по ROWID. Таким образом, у нас было два SQL-запроса, которые при нормальных условиях в худшем случае могли потребовать два логических чтения, поскольку индекс и таблица полностью помещались в буферный кэш.
В ходе мониторинга выполнения этих SQL-запросов при запуске вышеупомянутого цикла стало ясно, что они вызывались тысячи раз (в зависимости от содержания LOBXML) при каждом запуске.
Поскольку это были статические SQL, кэш курсоров PL/SQL (а также кэш блоков данных) очень хорошо работал – то есть разбор запроса выполнялся только один раз, а затем при каждом следующем выполнении происходили только логические, но не физические чтения.
Кроме того, в большинстве случаев эти SQL-запросы не обнаруживали искомое значение в небольшой таблице. Значит, что в среднем для одного выполнения запроса требовалось единственное логическое чтение – сканирование уникального индекса, поскольку искомое значение в нем отсутствовало.
При проверке статистики выполнений SQL-запросов в различных средах (Linux вместо AIX) было установлено, что эти же SQL-запросы выполнялись аналогичное количество раз, но в этих средах на выполнение пакетного задания времени требовалось меньше. В связи с этим огромное количество выполнений SQL выглядело странно, но не являлось основной причиной проблемы.
Итак:
• Мы определили хранимую процедуру, которая работает с LOB, представляющим XML как причину проблемы.
• Большая часть времени процедуры тратилась на два статических SQL-запроса, которые выполнялись тысячи раз при каждом запуске хранимой процедуры.
• Однако эти SQL использовали «оптимальный» план выполнения и в действительности генерировали только один логический I/O за один запуск.
• Из-за «эксклюзивного» поведения пакетного задания соперничество с другими процессами было невозможно.
• Иными словами, речь не идет об обычных подозрениях типа «неэффективный план запроса», «конкуренция за ресурсы», «сериализация» и т.д.
• Поэтому обычные методы мониторинга производительности: события ожидания, расширенная трассировка SQL, история активных сессий, статистика сессий / статистика системы, отчеты ASH / AWR / ADDM, не выявили очевидную причину проблемы.
• Запуск SQL-запросов, определенных в отдельном процессе, показал, что они занимают в среднем 10 микросекунд (!) за один запуск, что довольно быстро. В связи с чем возникает вопрос: как стало возможным, что эти запросы отображаются как проблемные – при запуске в простом цикле десять тысяч запусков возможны за одну секунду.
Мы столкнулись с классической ситуацией «События ожидания ничего не объясняют (иногда)». Все, что мы видим – большая часть времени тратилась на запуск этих SQL. Все, что мы выяснили – все это происходило на единственном процессоре, выполняющем эти запросы.
Но подождите, в ходе мониторинга статистической дельты сессии (например, с помощью утилиты «snapper» Тэнела Подера) обнаружился интересный момент: при выполнении процесс требовал все больше и больше памяти PGA/UGA.
Таким образом, пора было применять продвинутые методы решения проблем – например, участник Oak Table Тэнел Подер выполнил множество исследований в этой области и предоставил большое количество полезных инструментов.
В ходе дальнейших проверок обнаружилось несколько аномалий, которые сориентировали, в каком направлении искать дальше.
Потребление PGA/UGA-процесса увеличивалось при каждой итерации цикла, запускающего хранимую процедуру PL/SQL, т.е. где-то скрывалась проблема с памятью. В связи с этим хорошей идеей было проверить дамп памяти PGA/UGA-процесса.
Осторожно: получение дампа памяти может вывести из строя вашу систему или процесс, поэтому будьте очень осторожны в ходе выполнения этой операции в рабочей среде. Получение дампа памяти PGA обычно влияет только на один процесс, поэтому не является слишком критичным (если это не фоновый процесс, конечно).
Можно получить дамп памяти с помощью EVENTS:
ALTER SESSION SET EVENTS 'immediate trace name heapdumplevel <lvl>'; А также можно запросить дамп памяти с помощью ORADEBUG ASSYSDBA после определения процесса с помощью SETOSPID, SETORAPID или SETMYPID:
ORADEBUG DUMP HEAPDUMP <LVL>'; Также см. сайт Джулиана Дайка, где представлен обзор доступных уровней дампов памяти.
В данном случае дампа пятого уровня (5= 4+1, т.е. PGA иUGA), по-видимому, достаточно (если интересуют текущие/пользовательские вызовы, необходим уровень 29= 8 + 16 + 4 + 1).
В главе 8 нашей книги Рекомендации экспертов по Oracle от Oak Table мы с Чарльзом описываем наиболее важные варианты дампов памяти и другие методы мониторинга производительности, применяемые в данном случае.
Полученный файл трассировки может быть первично проанализирован, например, с помощью скрипта heapdump_analyzer Тэнела… Поскольку в нашем случае объем файла трассировки был довольно большим, мы использовали немного измененную версию программы awk, из heapdump_analyzer для создания файла, который затем подключили как внешнюю таблицу Oracle, чтобы можно было выполнять более сложные запросы к этим данным.
Вот команда, преобразующая файл трассировки в файл, пригодный для использования в качестве внешней таблицы Oracle:
cat $TRACE_FILE | awk '
/^HEAP DUMP heap name=/ { split($0,ht,"""); HTYPE=ht[2]; doPrintOut = 1; }
/Chunk/{ if ( doPrintOut == 1 ) {
split($0,sf,""");
printf "%10d , %16s, %16s, %16sn", $4, HTYPE, $5, sf[2];
}
}
/Total heap size/ {
doPrintOut=0;
}
' > $EXT_TAB_DIR/heapdump.txt
Ниже приведен пример DDL для такой внешней таблицы:
create table heapdump
(
chunk_size integer
, heap_type varchar2(16)
, chunk_type varchar2(16)
, alloc_reason varchar2(16)
)
organization external
(
type oracle_loader
default directory ext_tab_dir
access parameters
(
records delimited by newline
fields terminated by ','
lrtrim
)
location ('heapdump.txt')
);
Этот процесс вызывает «утечку» временных LOB – в V$TEMPORARY_LOBS наблюдается постоянное увеличение количества LOB, однако оно идет медленно (один объект при каждом запуске хранимой процедуры), а потребление памяти во временном табличном пространстве остается низким.
При расчете среднего времени выполнения двух SQL-запросов, повторяющихся множество раз, стало ясно, что они на самом деле сначала выполнялись так же быстро, как и при раздельном выполнении, но их выполнение постепенно замедлялось.
Спустя несколько минут на выполнение этих запросов, на которое изначально уходило несколько микросекунд, потребовалось уже несколько миллисекунд (!). Не удивительно, что пакетное задание заняло часы, учитывая, что выполнить эти запросы требовалось множество раз. Но теперь каждое выполнение занимало в тысячу раз больше времени, чем в самом начале процесса.
При более внимательном рассмотрении стало ясно, что такое замедление сказалось на каждом SQL-запросе, который был выполнен. Но так как выполнение многих из этих запросов в любом случае заняло несколько миллисекунд и они были выполнены небольшое количество раз, увеличение времени выполнения на несколько миллисекунд в действительности было не так существенно. Это были те запросы, которые выполнялись так часто, что получили наибольший «прирост» времени выполнения.
В результате, после завершения цикла, который запускал хранимую процедуру PL/SQL, стало понятно, что были затронуты все процессы в рамках этой сессии. Например, на выполнение простой операции SELECT * FROMDUAL или нулевого блока PL/SQL (BEGINNULL; END) потребовалось около 30 сотых долей секунды (0,3 секунды!). Та же самая операция в новой сессии (в то время как другая сессия все еще была открыта) была выполнена мгновенно (менее чем за 0,01 секунды, данные получены с помощью средства подсчета времени SQL*Plus) – это было характерно только для этой сессии, а не для случая в целом.
Таким образом, появилось что-то, что очевидно занимало все больше и больше времени ЦП. Это повлекло за собой увеличение времени выполнения «каждой» операции, вне зависимости от того, какой именно она была.
Пришло время обратиться к более глубокому уровню и исследовать трассировку на уровне операционной системы для того, чтобы понять, на что же уходит большая часть времени при выполнении процесса. К сожалению, мы имели дело с AIX 5.3, поэтому набор средств, при помощи которых можно было бы произвести необходимые измерения, был сильно ограничен. AIX не поддерживает DTrace, а новый инструмент ProbeVue доступен только для версий AIX 6 и выше. Поэтому нам оставался только встроенный oradebugshort_stack от Oracle и procstack для AIX, которые мы использовали для получения образцов из стека вызовов процессов переднего плана.
Но вновь на помощь приходит Тэнел. Используя его набор инструментов «OStackProf», мы смогли получить элементы из стека вызовов, но только для выяснения того, что процесс большую часть времени потратил на управление памятью. Это было только предположением, поскольку никто не мог сказать, что же на самом деле означали имена функций из стека вызовов. На основании документации MOS 175982.1 это все имело отношение к управлению памятью ADT (объекты Oracle).
Так выглядела трассировка стека:
Belowisthestackprefixcommontoallsamples:
------------------------------------------------------------------------
Frame->function()
------------------------------------------------------------------------
# 36 ->main()
# 35 ->opimai_real()b0
# 34 ->sou2o()
# 33 ->opidrv()
# 32 ->opiodr()b98
# 31 ->opiino()f0
# 30 ->opitsk()
# 29 ->ttcpip()c
# 28 ->opiodr()b98
# 27 ->kpoal8()c
# 26 ->opiexe()
# 25 ->kkxexe()c
# 24 ->peicnt()
# 23 ->plsql_run()
# 22 ->pfrrun()
# 21 ->pfrrun_no_tool()c
# 20 ->pfrinstr_EXECC()c
# 19 ->pevm_EXECC()e4
# 18 ->psdnal()c
# 17 ->psddr0()
# 16 ->rpidrv()
# ...(seecallprofilebelow)
#
# -#--------------------------------------------------------------------
# - Num.Samples ->incallstack()
# ----------------------------------------------------------------------
76 ->rpiswu2()c0->rpidru()->skgmstack()c4->rpidrus()c8->opiodr()b98->opipls()->opiexe()e4->auddft()b8->audbeg()->ktcxbr0()a0->kocbeg()->koctxbg()->kohalc()->kohalmc()->kghfru()c->44c0->->
20 ->rpiswu2()c0->rpidru()->skgmstack()c4->rpidrus()c8->opiodr()b98->opipls()->opiexe()->44c0->->
1 ->rpiswu2()c0->rpidru()->skgmstack()c4->rpidrus()c8->opiodr()b98->opipls()->opiexe()b8c->kksfbc()ec->ktcsna()c->ktucloGetGlobalMinScn()->44c0->->
1 ->rpiswu2()c0->rpidru()->skgmstack()c4->rpidrus()c8->opiodr()b98->opipls()->opiexe()->ksuvrl()c->44c0->->
1 ->rpiswu2()c0->rpidru()->skgmstack()c4->rpidrus()c8->opiodr()b98->opipls()->opiexe()->44c0->->
1 ->rpiswu2()c0->rpidru()->skgmstack()c4->rpidrus()c8->opiodr()->ksuprc()c->44c0->->
Имена функций «auddft»/«audbeg» могут указывать на нечто, имеющее отношение к аудиту, но в базе данных опция аудита никак не задействована, за исключением параметра «audit_trail = DB». Алекс Фэткулин недавно опубликовал описание проблемы, при которой включенная опция аудита приводила к замедлению 11.2.0.1, и, безусловно, при установке параметра «audit_trail = NONE» в 11.1.07 или 11.2.0.1 замедление наблюдалось не столь явно. Это означает, что в действительности есть части кода, имеющие отношение к аудиту. Однако же это не решило проблему – все еще наблюдалось значительное замедление работы.
Важное наблюдение было получено при анализе дампа памятиPGA/UGA:
Дамп PGA/UGA включал сотни тысяч очень малых кусочков данных, которые имели отношение к работе с XML («qmxdpls_subhea»). Таким образом, очевидным стало предположение, что ошибка связана с чем-то, имеющим отношение к управлению памятью для XML.
Поэтому мы сконцентрировали внимание на тех частях кода, которые отвечали за обработку XML. Очень быстро баг был найден: в коде отсутствовало обращение к DBMS_XMLDOM.FREEDOCUMENT.
Видимо, данный баг присутствовал в коде с самого начала, но приложение было разработано для 10.2, где такого снижения скорости работы не наблюдалось Однако были похожие признаки проблемы, например, увеличенное потребление памяти PGA/UGA и утечка для временных LOB, но идентичного замедления работы не было. После того, как некоторое время назад база данных была переведена на версию 11.1.0.7, проблема замедления проявилась.
Итак, проблема может быть решена или обнаружена после простого добавления или удаления из кода обращения freedocument.
Это привело нас к разработке типового тестового сценария, который позволяет воспроизвести проблему по требованию в большинстве случаев использования баз данных 11.1.0.7 или выше.
Обратите внимание: проблема, по-видимому, имеет отношение к варианту Oracle для конкретной операционной системы. Oracle 11.1.0.7 под Linux x64 вел себя несколько иначе – только некоторые SQL-запросы подвергались замедлению, что происходило при использовании AIX-версии.
drop table t_testloop;
purge table t_testloop;
create table t_testloop (
id integer not null
, vc varchar2(255)
, constraint t_testloop_pk primary key (id)
)
;
insert into
t_testloop
(
id
, vc
)
select
level as id
, rpad('x', 100, 'x') as vc
from
dual
connect by
level <= 100;
commit;
exec dbms_stats.gather_table_stats(null, 'T_TESTLOOP')
-- This is supposed to be a INDEX UNIQUE SCAN + TABLE ACCESS BY ROWID
explain plan for
select
id
, vc
from
t_testloop
where
id = to_number(:x);
set linesize 160
set pagesize 999
select * from table(dbms_xplan.display);
set timing on echo on serveroutput on
-- This is the normal (reference) execution time for running
-- the simple statement a thousand times
declare
procedure check_key
as
x integer;
n_id integer;
s_vc varchar2(255);
begin
x := 42 * 3;
select
id
, vc
into
n_id
, s_vc
from
t_testloop
where
id = x;
exception
when NO_DATA_FOUND then
null;
end;
begin
for i in 1..1000 loop
check_key;
end loop;
end;
/
-- "Deterministic" randomness :-))
exec dbms_random.seed(0)
declare
start_time number;
end_time number;
-- Generate some CLOB containing XML
-- Note that it looks like the CLOB needs
-- to be different for every iteration
-- otherwise the issue couldn't be reproduced
function return_clob return clob
as
the_lobclob;
s_name varchar2(20);
n_sal integer;
s_job varchar2(20);
begin
the_lob := '<root>
';
for i in 1..20 loop
s_name := dbms_random.string('U', trunc(dbms_random.value(1, 21)));
n_sal := trunc(dbms_random.value(1, 1001));
s_job := dbms_random.string('U', trunc(dbms_random.value(1, 21)));
the_lob := the_lob || '<emp attr1="val1" attr2="val2" attr3="val3">
<empno attr1="val1" attr2="val2" attr3="val3">' || to_char(i, 'TM') || '</empno>
<name attr1="val1" attr2="val2" attr3="val3">' || s_name || '</name>
<sal attr1="val1" attr2="val2" attr3="val3">' || to_char(n_sal, 'TM') || '</sal>
<job attr1="val1" attr2="val2" attr3="val3">' || s_job || '</job>
</emp>
';
end loop;
the_lob := the_lob || '</root>';
return the_lob;
end return_clob;
-- Some usage of the PL/SQL XML DOM API
-- Some dummy processing of the attributes of the given node
procedure process_attributes
(
in_nodedbms_xmldom.DOMNode
)
is
len number;
n dbms_xmldom.DOMNode;
nnmdbms_xmldom.DOMNamedNodeMap;
key varchar2(1000);
val varchar2(32767);
BEGIN
nnm := dbms_xmldom.getAttributes(in_node);
if (dbms_xmldom.isNull(nnm) = FALSE) then
len := dbms_xmldom.getLength(nnm);
-- loop through attributes
for i in 0..len-1 loop
n := dbms_xmldom.item(nnm, i);
key := dbms_xmldom.getNodeName(n);
val := dbms_xmldom.getNodeValue(n);
end loop;
end if;
end process_attributes;
-- Some usage of the PL/SQL XML DOM API
-- Recursively walk the nodes of the DOM
-- and call the attribute processing per node
procedure walk_node
(
in_nodedbms_xmldom.DOMNode
)
is
nldbms_xmldom.DOMNodeList;
len number;
n dbms_xmldom.DOMNode;
node_name varchar2(100);
begin
-- loop through elements
node_name:=dbms_xmldom.getNodeName(in_node);
process_attributes(in_node);
nl := dbms_xmldom.getChildNodes(in_node);
len := dbms_xmldom.getLength(nl);
for i in 0..len-1 loop
n := dbms_xmldom.item(nl, i);
node_name := dbms_xmldom.getNodeName(n);
walk_node(n);
end loop;
end walk_node;
-- The main procedure
procedureprocess_xml_clob
as
the_lobclob;
varXMLType;
doc dbms_xmldom.DOMDocument;
root dbms_xmldom.DOMNode;
root_tag varchar2(100);
begin
-- Get the CLOB with the XML
the_lob := return_clob;
-- Instantiate an XMLTYPE
var := xmltype(the_lob);
-- Generate a new DOM document from the XMLType
-- This seems to allocate a temporary LOB under the covers
doc := dbms_xmldom.newDOMDocument(var);
-- Some rudimentary XML DOM processing
root := dbms_xmldom.makeNode(dbms_xmldom.getDocumentElement(doc));
root_tag := dbms_xmldom.getNodeName(root);
-- If you want to burn more CPU to exaggerate the effect
-- uncomment this
-- walk_node(root);
-- This omission here causes a significant PGA/UGA memory leak
-- and causes version 11.1 and 11.2 to slow down everything
-- in this session
-- Version 10.2 suffers from the same symptoms but doesn't slow down
--DBMS_XMLDOM.freeDocument(doc);
end;
begin
-- Run this a thousand times and measure / output the runtime per execution
for i in 1..1000 loop
start_time := dbms_utility.get_time;
process_xml_clob;
end_time := dbms_utility.get_time;
dbms_output.put_line('Run ' || to_char(i, 'TM') || ': Time (in seconds)= ' || ((end_time - start_time)/100));
end loop;
end;
/
-- Do the simple statement again a thousand times
-- Notice the difference in runtime when using 11.1.0.7 or 11.2.0.1
declare
procedure check_key
as
x integer;
n_id integer;
s_vc varchar2(255);
begin
x := 42 * 3;
select
id
, vc
into
n_id
, s_vc
from
t_testloop
where
id = x;
exception
when NO_DATA_FOUND then
null;
end;
begin
for i in 1..1000 loop
check_key;
end loop;
end;
/
Важная строка, приведенная выше: «DBMS_XMLDOM.FREEDOCUMENT». Если вы запускаете скрипт без вызова FREEDOCUMENT под версией базы данных, подверженной замедлению (11.1.0.7 или 11.2.0.1), то обычно результат выглядит следующим образом:
SQL> declare
2 procedure check_key
3 as
4 x integer;
5 n_id integer;
6 s_vc varchar2(255);
7 begin
8 x := 42 * 3;
9 select
10 id
11 , vc
12 into
13 n_id
14 , s_vc
15 from
16 t_testloop
17 where
18 id = x;
19 exception
20 when NO_DATA_FOUND then
21 null;
22 end;
23 begin
24 for i in 1..1000 loop
25 check_key;
26 end loop;
27 end;
28 /
PL/SQL procedure successfully completed.
Elapsed: 00:00:00.94
.
.
.
Run 1: Time (in seconds)= .49
Run 2: Time (in seconds)= .08
Run 3: Time (in seconds)= .08
Run 4: Time (in seconds)= .08
Run 5: Time (in seconds)= .05
Run 6: Time (in seconds)= .03
Run 7: Time (in seconds)= .03
Run 8: Time (in seconds)= .03
Run 9: Time (in seconds)= .03
Run 10: Time (in seconds)= .02
Run 11: Time (in seconds)= .03
Run 12: Time (in seconds)= .03
Run 13: Time (in seconds)= .03
Run 14: Time (in seconds)= .03
Run 15: Time (in seconds)= .03
Run 16: Time (in seconds)= .03
Run 17: Time (in seconds)= .02
Run 18: Time (in seconds)= .03
Run 19: Time (in seconds)= .03
Run 20: Time (in seconds)= .03
Run 21: Time (in seconds)= .03
Run 22: Time (in seconds)= .03
Run 23: Time (in seconds)= .03
Run 24: Time (in seconds)= .03
Run 25: Time (in seconds)= .03
.
.
.
Run 287: Time (in seconds)= .03
Run 288: Time (in seconds)= .03
Run 289: Time (in seconds)= .03
Run 290: Time (in seconds)= .03
Run 291: Time (in seconds)= .02
Run 292: Time (in seconds)= .03
Run 293: Time (in seconds)= .03
Run 294: Time (in seconds)= .03
Run 295: Time (in seconds)= .03
Run 296: Time (in seconds)= .03
Run 297: Time (in seconds)= .03
Run 298: Time (in seconds)= .02
Run 299: Time (in seconds)= .03
Run 300: Time (in seconds)= .03
Run 301: Time (in seconds)= .03
Run 302: Time (in seconds)= .03
Run 303: Time (in seconds)= .17
Run 304: Time (in seconds)= .17
Run 305: Time (in seconds)= .17
Run 306: Time (in seconds)= .17
Run 307: Time (in seconds)= .17
Run 308: Time (in seconds)= .17
Run 309: Time (in seconds)= .17
Run 310: Time (in seconds)= .17
Run 311: Time (in seconds)= .18
Run 312: Time (in seconds)= .17
Run 313: Time (in seconds)= .18
Run 314: Time (in seconds)= .18
Run 315: Time (in seconds)= .18
Run 316: Time (in seconds)= .17
Run 317: Time (in seconds)= .19
Run 318: Time (in seconds)= .18
Run 319: Time (in seconds)= .18
Run 320: Time (in seconds)= .19
Run 321: Time (in seconds)= .18
Run 322: Time (in seconds)= .19
.
.
.
Run 973: Time (in seconds)= .82
Run 974: Time (in seconds)= .83
Run 975: Time (in seconds)= .83
Run 976: Time (in seconds)= .82
Run 977: Time (in seconds)= .83
Run 978: Time (in seconds)= .83
Run 979: Time (in seconds)= .82
Run 980: Time (in seconds)= .82
Run 981: Time (in seconds)= .83
Run 982: Time (in seconds)= .82
Run 983: Time (in seconds)= .83
Run 984: Time (in seconds)= .83
Run 985: Time (in seconds)= .82
Run 986: Time (in seconds)= .84
Run 987: Time (in seconds)= .83
Run 988: Time (in seconds)= .86
Run 989: Time (in seconds)= .84
Run 990: Time (in seconds)= .83
Run 991: Time (in seconds)= .85
Run 992: Time (in seconds)= .84
Run 993: Time (in seconds)= .84
Run 994: Time (in seconds)= .85
Run 995: Time (in seconds)= .84
Run 996: Time (in seconds)= .85
Run 997: Time (in seconds)= .84
Run 998: Time (in seconds)= .87
Run 999: Time (in seconds)= .84
Run 1000: Time (in seconds)= .85
PL/SQL procedure successfully completed.
Elapsed: 00:06:00.49
SQL>
SQL> declare
2 procedure check_key
3 as
4 x integer;
5 n_id integer;
6 s_vc varchar2(255);
7 begin
8 x := 42 * 3;
9 select
10 id
11 , vc
12 into
13 n_id
14 , s_vc
15 from
16 t_testloop
17 where
18 id = x;
19 exception
20 when NO_DATA_FOUND then
21 null;
22 end;
23 begin
24 for i in 1..1000 loop
25 check_key;
26 end loop;
27 end;
28 /
PL/SQL procedure successfully completed.
Elapsed: 00:00:03.02
SQL>
Обратите внимание; после определенного количества итераций выполнение команд замедляется все больше и больше. Что еще более интересно – простой цикл из 1 000 SQL-запросов затем требует значительно большего времени для выполнения, чем до того, как началось выполнение данного блока кода.
Возможно, вам захочется понаблюдать за потреблением PGA/UGA во время сбора статистики или при выполнении V$PROCESS и V$TEMPORARY_LOBS во время выполнения данного блока кода.
Если вы запустите те же операции в версии 10.2.0.4, вы увидите те же признаки проблемы, но время выполнения останется стабильным, по крайней мере, на протяжении 1 000 итераций. Ясно, что наступит момент, когда система станет испытывать трудности с постоянно растущим объемом потребляемой памяти, но это не имеет отношения к нашей проблеме.
Если обращение к DBMS_XMLDOM.FREEDOCUMENT осуществляется корректно, то та же часть кода в 11.1.0.7 и 11.2.0.1 обеспечит стабильное время выполнения процесса (не будет повышенного потребления памяти PGA/UGA или временных LOB).
Найджел Нобл также недавно опубликовал заметку в блоге о проблемах с памятью PL/SQL, которые проявляются только в версии 11.1.0.7, но не обнаруживаются в версии 10.2.0.4.
Несмотря на то, что проблемы, на которые указывают Алекс Фэткулин и Найджел Нобл, не обязательно имеют отношение к описанной здесь проблеме, все-таки это указывает на то, что выпуск Oracle версии 11 вводит некие изменения в управление памятью (возможно, из-за внедрения функции автоматического управления памятью AMM или параметра memory_target), которые ведут себя иначе, чем в предыдущих версиях при наличии определенных условий.
24 марта в Москве пройдет мастер-класс Рандольфа Гайста, посвященный решению проблем производительности базы данных Oracle.
Автор: Luxoft
