После нескольких месяцев попыток договориться с клиентом из Дал­ласа о визите, в понедельник в отделе продаж hotsos.com раздался те­лефонный звонок. Люди, с которыми мы пытались договориться о встрече, зашли в тупик, пытаясь найти причину ухудшения произ­водительности, и собирались дать нам шанс все исправить. В среду мы этим шансом воспользовались.

Что-то похожее мы уже видели. Компания несколько месяцев боро­лась с ухудшением производительности, связанным со слишком боль­шим временем отклика одной программы. Все эти месяцы штатные специалисты компании старались найти решение, но ни одна из их по­пыток не была успешной. В конце концов они опустили руки, и руко­водство решило выделить серьезную сумму на решение проблемы. По­этому в выходные, предшествующие полученному нами телефонному звонку, компания заменила в системе процессоры на более производи­тельные. Модернизация прошла успешно, и, конечно же, все надея­лись (хоть и нервничали немного), что в понедельник все будет рабо­тать гораздо лучше.

К их ужасу производительность медленной программы после чрезвы­чайно дорогостоящего обновления оборудования стала еще хуже. При­чем значительно хуже. Поэтому в понедельник они нам позвонили: «Приходите и покажите нам, что можно сделать». Через два дня мы сели в машину и поехали. Вот что мы обнаружили:

Компания работала с продуктом Oracle Payroll. Он был сконфигу­рирован традиционным способом: пакетные задания выполнялись на сервере базы данных, а десятки пользователей, работавших че­рез броузеры, были распределены по зданию и связаны локальной сетью (LAN).

Производительность программы PYUGEN мешала нормальной работе компании уже несколько месяцев. Когда мы появились, программа PYUGEN могла обрабатывать около 27 заданий в минуту. Производи­тельность надо было увеличить вдвое.

Мониторинг производительности выполнялся при помощи хорошо известного полнофункционального средства, которое запрашивало данные фиксированных представлений V$SYSTEM_EVENT и V$LATCH. Это средство показывало, что источником неприятностей в системе бы­ли события ожидания освобождения защелок latch free. Подавляю­щее большинство ожиданий latch free относилось к защелкам цепо­чек буферов кэша.

Специалисты компании правильно поняли, что конкуренция за за­щелки цепочек буферов кэша является вероятным признаком не­эффективного SQL (т. е. содержащего большое количество LIO). Од­нако разработчики приложений заказчика проанализировали про­грамму PYUGEN и не смогли уменьшить количество LIO в SQL.

Только что произведенное повышение частоты всех двенадцати процессоров системы с 700 МГц до 1 ГГц значительно ухудшило производительность программы PYUGEN. Отсутствие повышения про­изводительности при замене процессоров стало последней каплей, заставившей клиента пригласить к себе команду hotsos.com.

Определение цели

К моменту нашего прибытия клиент уже завершил этап выбора поль­зовательской операции, определив, что основную проблему для произ­водительности системы представляет собой PYUGEN. Поэтому нашим первым шагом по прибытии был сбор корректно выбранных диагно­стических данных. Для этого клиента сбор данных расширенной трас­сировки SQL был прост, т. к. время отклика пользовательской опера­ции формировалось исключительно выполнением программы PYUGEN. Для включения и отключения расширенной трассировки SQL мы при­менили собственную свободно распространяемую программу Sparky (http://www.hotsos.com).

Программа, которую мы собирались исследовать, выполнялась более получаса, в результате чего было сформировано около 70 Мбайт дан­ных расширенной трассировки. Данные трассировки обрабатывались программой Hotsos Profiler, которая сформировала профиль ресурсов, приведенный в примере 12.1.

Response Time Component	Duration		# Calls	Dur/Call
SQL*Net message from client	984.0s	49.6%	95,161	0.010340s
SQL*Net more data from client	418.8s	21.1%	3,345	0.125208s
db file sequential read	279.3s	14.1%	45,084	0.006196s
CPU service	248.7s	12.5%	222,760	0.001116s
unaccounted-for	27.9s	1.4%
latch free	23.7s	1.2%	34,695	0.000683s
log file sync	1.1s	0.1%	506	0.002154s
SQL*Net more data to client	0.8s	0.0%	15,982	0.000052s
log file switch completion	0.3s	0.0%	3	0.093333s
enqueue	0.3s	0.0%	106	0.002358s
buffer busy waits	0.2s	0.0%	67	0.003284s
SQL*Net message to client	0.2s	0.0%	95,161	0.000003s
db file scattered read	0.0s	0.0%	2	0.005000s
SQL*Net break/reset to client	0.0s	0.0%	2	0.000000s
Total	1,985.3s	100.0%

Данные профиля ресурсов удивили всех, кто работал над проектом по­следние несколько месяцев. Уже по одному только профилю ресурсов с абсолютной уверенностью можно утверждать, что вклад ожидания осво­бождения защелок в общее время отклика PYUGEN был чрезвычайно мал. Если бы компании удалось вообще исключить событие ожидания latch free из системы, время выполнения программы изменилось бы на 1%.

Такое в нашей работе бывает часто: многие проблемы произво­дительности пользовательских операций невозможно опреде­лить на основе исследования данных в масштабе всей системы. Данные из представления V$SYSTEM_EVENT верны; просто они не имеют отношения к решаемой проблеме. Помните - по агреги­рованным данным нельзя восстановить составляющие.

На самом деле представление V$SYSTEM_EVENT ясно указывало на то, что основным событием ожидания является SQL*Net message from client, но ведь каждый уважающий себя аналитик производительности Oracle знает, что надо исключить из рассмотрения все события SQL*Net, т. к. они являются событиями «простоя».

Около 50% общего времени отклика PYUGEN было занято выполнением системных вызовов чтения SQL*Net. Расположение событий SQL*Net message from client во главе профиля ресурсов заставило нас быстро пе­репроверить собранные данные с тем, чтобы убедиться, что такое гла­венствующее положение событий, происходящих между вызовами ба­зы данных, не является результатом ошибки сбора данных. Ошибки не было. События SQL*Net message from client и их продолжительности были равномерно распределены по файлу трассировки и являлись результатом тысяч вызовов базы данных. Если принять в рассмотрение еще одно событие SQL*Net, SQL*Net more data from client, то окажется, что мы выявили более 70% общего времени отклика PYUGEN.

Диагностика и лечение

Естественно, нельзя игнорировать 70% времени отклика программы, даже если соответствующие события называют событиями «простоя». Будь то событие простоя или нет, в любом случае это время вошло в пользовательское время отклика, значит, с ним нужно разобраться. Если бы статистика собиралась не так аккуратно (у нас корректно вы­брана программа и временная область), то события SQL*Net message from client, вероятно, занимали бы гораздо больше времени в полученных данных. При такой ошибке сбора необходимо исключить из рассмотре­ния так называемые события простоя.

Все правильно, имя хоста, выведенное справа от символа @ в V$SESSION, точно совпадает с именем узла (Node name) из преамбулы файла трасси­ровки SQL. PYUGEN точно работает на том же самом хосте, что и сервер

Мы начали исследование с первой строки профиля ресурсов. Посколь­ку речь шла о поставляемом приложении, мы считали, что вряд ли удастся манипулировать количеством вызовов базы данных, и поэтому сконцентрировались на столбце продолжительности вызова. И значе­ние данного столбца показалось нам подозрительным - его порядок от­ражал скорее работу в локальной сети (сотые доли секунды, о чем мы говорили в главе 10), чем межпроцессное взаимодействие (IPC) (тысяч­ные доли секунды или меньше). Поэтому мы перепроверили, действи­тельно ли пакетная программа PYUGEN выполняется на сервере базы дан­ных (там же, где и соответствующий PYUGEN серверный процесс Oracle), для чего обратились к данным V$SESSION, автоматически собранным программой Sparky при включении сбора (см. пример 12.2).

базы данных. Почему же тогда при работе программы PYUGEN наблюда­ются такие задержки SQL*Net message from client? В поисках ответа мы обратились к файлу tnsnames.ora системы. Оказалось, что системный инженер, стремясь облегчить жизнь системных администраторов, установил для всей системы единый псевдоним TNS. Пакетные задания направлялись на тот же адаптер протокола TCP/IP, что и броузеры клиентов системы.

Разработать стратегию, отлично вписавшуюся в рамки благоприятст­вования системному администрированию, было несложно. Можно бы­ло добавить второй псевдоним в файл tnsnames.ora. Второй псевдоним был бы идентичен первому, только имя у него было бы другое, а син­таксис (PROTOCOL=BEQ) занял бы место (PROTOCOL=TCP). Заказчику надо было бы остановить и заново запустить Oracle Applications Concurrent Manager, указав новый псевдоним, использующий адаптер протокола bequeath. Новый файл tnsnames.ora можно было бы без побочных эф­фектов распространить по всей системе. Все, кроме запустивших Con­current Manager, продолжали бы использовать тот же TNS-псевдоним, что и ранее.

Прежде чем претворять это изменение в жизнь, заказчик провел про­стой эксперимент. Была выполнена команда SELECT, которая потребо­вала бы нескольких тысяч вызовов базы данных из сеанса SQL*Plus, работающего на сервере базы данных, и для нее были сняты времен­ные характеристики. Сначала команду выполнили в сеансе, установ­ленном при помощи старого псевдонима, использующего адаптер про­токола TCP/IP, а затем в сеансе, установленном при помощи нового псевдонима, использующего адаптер протокола bequeath. Тест пока­зал, что использование адаптера протокола bequeath снизило задерж­ки SQL*Net message from client до менее чем 0,001 секунды. Выполнив лишь одно это изменение, мы могли ожидать сокращения общего вре­мени отклика программы как минимум на 40% (рис. 12.1).

На самом деле у нас есть причины ожидать улучшения более чем на 40%. Второй по значимости вклад во время отклика PYUGEN вносит еще одно событие SQL*Net - SQL*Net more data from client. Это событие вы­звано последовательностью вызовов разбора, передававших слишком длинные текстовые строки SQL по SQL*Net от клиента к серверу (вме­сто того чтобы достигать той же цели посредством вызовов хранимых процедур). Длинные текстовые строки SQL не помещались в один па­кет SQL*Net, поэтому ядро Oracle довольно долго ожидало второго и, возможно, последующих пакетов SQL*Net в ходе вызовов разбора. Ко­нечно, учитывая, что Oracle Payroll поставляется без исходных тек­стов, наши надежды на быстрое уменьшение количества выполнений данного события были достаточно призрачны. Однако можно было на­деяться, что задержка SQL*Net more data from client частично связана с передачей по сети, и что смена адаптера протокола ускорит исполне­ние этого события.

Результаты

Результаты оказались просто замечательными. Производительность программы Payroll возросла с 27 заданий в минуту до 61. Проверка предложенного изменения tnsnames.ora заняла 15 минут и еще около недели ушло на процедуру контроля за изменениями. В целом мы про­вели у заказчика менее четырех часов. Из них два заняла инсталляция Sparky (потребовалось обновить Perl на хосте сервера базы данных), и чуть менее получаса потребовалось для прогона программы PYUGEN с включенной трассировкой SQL уровня 8. Оставшиеся полтора часа были посвящены встречам, приветствиям, анализу, тестированию и подведению итогов.

Да, кстати... почему программа Payroll стала работать медленнее после модернизации процессоров? Ей требовалось немного процессорного времени, поэтому такая модернизация имела чрезвычайно малый по­ложительный эффект на PYUGEN. Большая часть времени уходила на простаивание в очереди для сетевого обслуживания. При этом наряду с заданием Payroll исполнялись и другие программы. Обновление про­цессора сделало их более быстрыми, в результате чего они стали ин­тенсивнее генерировать сетевые вызовы (число которых осталось неиз­менным после модернизации процессоров) в течение более короткого промежутка времени. В результате конкуренция за сетевое обслужи­вание в процессе работы Payroll усилилась. Следовательно, каждый сетевой вызов ввода/вывода, совершаемый программой Payroll, стал чуть более медленным, чем до модернизации. Ухудшение сетевого вре­мени отклика перечеркнуло небольшое улучшение времени обслужи­вания процессором, что привело к итоговому снижению производи­тельности Payroll. А это было нехорошо... ведь программа Payroll име­ла самый высокий бизнес-приоритет в системе.

Мораль

Рассмотренный пример иллюстрирует несколько важных моментов:

Нельзя опираться на данные V$, определяя причину низкой произ­водительности системы. Главную роль в постановке задачи должен играть бизнес. Реальная проблема производительности системы -это то, что вызывает недопустимо большое время отклика для са­мой важной, с точки зрения бизнеса, пользовательской операции.

По агрегированным данным нельзя восстановить составляющие. Анализ общесистемных статистик для экземпляра не позволяет га­рантированно определить, в чем причина плохой производительно­сти одной конкретной программы.

Модернизация оборудования - более сомнительная, в смысле повы­шения производительности, операция, чем можно себе предста­вить. Можно не только зря потратить много денег, но и снизить производительность «усовершенствуемой» программы.

Выявить и устранить причину плохой производительности посред­ством старого метода проб и ошибок практически невозможно. Плохая производительность может быть вызвана огромным коли­чеством разнообразных факторов. Не надо проверять все, что могло бы ее вызвать, достаточно исследовать пользовательскую операцию и найти причину.