Глава 10

*** 2001-03-17 12:16:38.407

*** SESSION ID:(7.74) 2001-03-17 12:16:38.407

APPNAME mod=SQL*PLUS mh=3669949024 act= ah=4029777240

Запись APPNAME была сделана при вызове подпрограммы пакета DBMS APPLICATION INFO (подробнее об этом пакете см. в Приложении А). Этот пакет используется для регистрации действий приложений в базе данных, чтобы по результатам запросов к представлению V$SESSION можно было понять, какое именно приложение открыло сеанс. Утилита SQL*Plus, в частности, этот пакет использует. В вашем трассировочном файле записи APPNAME может и не быть: все зависит от среды. Б]ло бы замечательно, если бы все приложения регистрировались с помощью этого пакета, так что, надеюсь, вы обнаружили эту запись, в которой указано имя работающего модуля. Эта запись имеет следующий формат:

APPNAME mod=%s mh=%lu act=%s ah=%lu Поле Значение

mod Имя модуля, переданное DBMS APPLICATION INFO

mh Хэш-значение для модуля

act Действие модуля, переданное DBMS APPLICATION INFO

ah Хэш-значение для действия

Если вы программируете на языке С, то узнаете строку формата для функции printf стандартной библиотеки С. По ней можно определить, какого типа данные будут в записи APPNAME; %s - это строка, %lu - длинное целое без знака (число). Далее в моем трассировочном файле идут строки:

PARSING IN CURSOR #3 len=70 dep=0 uid=54 oct=42 lid=54 tim=6184206 hv=347037164 ad=31883a4

alter session set events 10046 trace name context forever, level 12 END OF STMT

EXEC #3:c=0,e=0,p=0,cr=0,cu=0,mis=l,r=0,dep=0,og=4,tim=6184206

WAIT #3: nam=SQL*Net message to client ela= 0 pl=1111838976 p2=l p3=0

WAIT #3: nam=SQL*Net message from client ela= 818 pl-1111838976 p2=l p3=0

Здесь можно увидеть, каким именно оператором включена трассировка. Перед этим идет запись CURSOR, которая будет в трассировочном файле всегда (все SQL-операто-ры в трассировочном файле предваряются записью CURSOR). Эта запись имеет следующий формат:

Parsing in Cursor #%d len=%d dep=%d uid=%ld oct=%d lid=%ld tim=%ld hv=%ld ad=%s

Стратегии и средства настройки 563

Поле Значение

Cursor # Номер курсора. Его можно использовать, в частности, для определения максимального количества открытых курсоров в приложении, поскольку это значение увеличивается и уменьшается на единицу при каждом открытии нового и закрытии существующего курсора, соответственно.

len Длина соответствующего SQL-оператора.

dep Рекурсивная глубина SQL-оператора. Рекурсивный SQL-оператор - это SQL-оператор, инициированный другим SQL-оператором. Обычно рекурсивные SQL-операторы выполняются сервером Oracle для разбора запроса или управления пространством. Это могут быть также SQL-операторы, вызванные в программных единицах PL/SQL (программная единица или блок PL/SQL - это тоже SQL). Так что операторы приложения тоже могут оказаться рекурсивными .

uid Идентификатор пользователя - владельца текущей схемы. Обратите

внимание, что значение может отличаться от представленного ниже идентификатора lid, в частности, если использовался оператор alter session set current schema для изменения схемы, в которой выполняется разбор.

oct Oracle Command Type. Числовой код, показывающий тип выполняемого оператора SQL.

lid Идентификатор пользователя, от имени которого выполнялась проверка

привилегий доступа.

tim Таймер с точностью до сотых долей секунды. Сравнивая время

регистрации событий, можно определить, насколько отдалены они друг от друга по времени.

hv Хэш-идентификатор SQL-оператора.

ad Значение в столбце ADDR строки представления VSSQLAREA, описывающей SQL-оператор.

Затем в трассировочном файле можно увидеть, что оператор выполнялся сразу же после разбора. Запись EXEC имеет следующий формат:

EC Cursor#: c=%d, e=%d,p=%d, cr=%d, cu=%d,mi.s=%d, r=%d, dep=%d, og=%d, tim=%d

Поле Значение

Cursor # Номер курсора,

с Процессорное время выполнения в сотых долях секунды,

е Реальное время выполнения в сотых долях секунды,

р Количество выполненных физических чтений.

cr Количество чтений блоков в согласованном режиме (логический

ввод/вывод).

сu Количество непосредственных чтений блоков (логический ввод/вывод).

Глава 10

Поле Значение

mis Количество непопаданий в библиотечный кэш, по которому можно

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

r Количество обработанных строк.

Рекурсивная глубина SQL-оператора.

og Цель оптимизации, 1 =

на основе правил, 4 =

все строки, 2 = первые строки, выбор режима оптимизации

оптимизация

Таймер.

Есть и другие разновидности записи EXEC, с другими ключевыми словами вместо EXEC:

Записи PARSE, FETCH, UNMAP и SORT UNMAP содержат ту же информацию, что и запись EXEC, причем, в том же порядке.

Последняя часть этого раздела содержит первые упоминания об ожидании событий. В данном случае это:

WAIT #3: nam=SQL*Net message to client ela= 0 pl=1111838976 p2=l p3=0 WAIT #3: nam=SQL*Net message from client ela= 818 pl=1111838976 p2=l p3=0

Это типичные ожидания данных при пересылке с клиента на сервер, которые уже описывались ранее в этой главе. Строка, содержащая message to client, означает, что сервер послал клиенту сообщение и ждет ответа. Строка, содержащая message from client, означает, что сервер ждет запроса от клиента. В данном случае реальное время ожидания (ela) этого события составило 8,18 секунды. Это означает, что я подождал 8,18 секунды после выполнения оператора ALTER SESSION, прежде чем послать следующую команду данного примера. Если только не обрабатывается постоянный и непрерывный поток обращений к серверу, ожидание message from client неизбежно и вполне нормально. Запись WAIT имеет следующий формат:

WAIT Cursor#: nam=%s ela=%d pl=%ul p2=%ul p3=%ul

Поле

Значение

Cursor # Номер курсора.

nam Имя ожидаемого соб]тия. В руководстве Oracle Server Reference

содержится полный список событий, которые может ожидать сервер, подробным описанием каждого события.