Глава 10

14 5, Share Row-Excl,

15 6, Exclusive )

16 into l str

17 from dual; 18

19 return l str;

20 end;

21 / Function created. tkyte@TKYTE816>

tkyte@TKYTE816> select enqueue decode(1415053318) from dual; ENQUEUE DECODE(1415053318)

TX Exclusive

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

select ename from emp where empno = :bv for update NOWAIT; update emp set ename = lower(ename) where empno = :bv;

Это решает проблему блокирования. По крайней мере теперь точно известно, почему изменение выполнялось так долго. Мы можем постфактум это определить. Больше не нужно заниматься диагностикой на месте - достаточно получить соответствующую трассировочную информацию.

Ближе к концу трассировочного файла мы видим:

PARSING IN CURSOR #5 len=52 dep=0 uid=54 oct=47 lid=54 tim=6190451

hv=1697159799 ad=3532750 BEGIN DBMS OUTPUT.GET LINES(:LINES, :NUMLINES) ; END;

END OF STMT

PARSE #5:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0, dep=0,og=4,tim=6190451

BINDS #5:

bind 0: dty=l mxl=2000(255) mal=25 scl=00 pre=00 oacflg=43 oacf12=10

size*2000 offset=0

bfp=07448dd4 Ып=2 55 avl-00 flg=05

bind 1: dty=2 mxl=22(02) mal=00 scl=00 pre=00 oacflg=01 oacf12=0 size=24 offset=0

bfp=0741c7e8 bln=22 avl=02 flg=05

value=25

WAIT #5: nam=SQL*Net message to client ela= 0 pl=1111838976 p2=l p3=0 EXEC #5:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=l,dep=0,og=4,tim=6190451

WAIT #5: nam=SQL*Net message from client ela= 273 pl=1111838976 p2=l p3=0

Стратегии и средства настройки 5 6 9

А вот этот оператор - неожиданность. Мы сами его не выполняли, и это не рекурсивный SQL-оператор (dep=O). Он поступил от клиентского приложения. Все это показывает детали работы утилиты SQL*Plus и пакета DBMS OUTPUT. В файле начального запуска login.sql я задал команду set serveroutput on, чтобы при запуске утилиты SQL*Plus в]дача результатов с помощью пакета DBMS OUTPUT б1ла включена. После каждого выполненного оператора, который мог сгенерировать данные для пакета DBMS OUTPUT, утилита SQL*Plus должна вызвать процедуру GET LINES для получения данных и их выдачи на экран (подробнее о пакете DBMS OUTPUT см. в Приложении А). Мы видим, как утилита SQL*Plus делает этот вызов. Более того, мы видим, что первый параметр, :LINES, фактически является массивом из 25 элементов (mal=25). Теперь понятно, что утилита SQL*Plus извлекает из буфера DBMS OUTPUT по 25 строк за раз и выдает их на экран. Тот факт, что можно трассировать действия утилиты SQL*Plus, показателен: значит, мы можем трассировать действия любого программного обеспечения, работающего с СУБД Oracle, и понять, что оно делает.

Наконец, вот последние записи трассировочного файла:

XCTEND rlbk=0, rd only=0

WAIT #0: nam=log file sync ela= 0 pl=968 p2=0 p3=0 STAT #4 id=l cnt=l pid=0 pos=0 obj=0 op=UPDATE ЕМР

STAT #4 id=2 cnt=2 pid=l pos=l obj=24767 op=TABLE ACCESS FULL EMP

Запись XCTEND (граница транзакции) связана с фиксацией изменений, но мы явно ничего не фиксировали. Утилита SQL*Plus без предупреждений зафиксировала изменения при выходе. В записи XCTEND имеются следующие значения:

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

rlbk Флаг отката. Если указано значение 0, значит, транзакция

зафиксирована. Значение 1 обозначает откат транзакции.

rdOnly Флаг только для чтения. Если указано значение 1, транзакция

выполнялась в режиме только для чтения. Значение 0 показывает, что изменения были и они зафиксированы (или отменены).

Сразу после записи XCTEND зафиксированы еще какие-то ожидания событий, в данном случае - синхронизации журнального файла. Если обратиться к руководству Oracle Server Reference и найти это событие, можно узнать, что значение 988 для параметра pi означает, что необходимо записать буфер 988 журнала повторного выполнения, и именно сброса этого буфера на диск мы ждали. Ждать пришлось менее сотой доли секунды, о чем свидетельствует значение ela=0.

Последние записи в трассировочном файле - записи STAT. Это фактический план выполнения SQL-оператора. Этому плану можно доверять. Более того, для каждого шага плана указано точное количество обработанных строк. Эти записи создаются после закрытия соответствующего курсора. В общем случае это означает, что клиентское приложение должно завершить работу, чтобы эти записи появились в файле - выполнения оператора ALTER SESSION SET SQL TRACE=FALSE может оказаться недостаточно. Поля этой записи имеют следующие значения:

5 7 0 Глава 10

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

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

id Номер строки плана, от 1 до общего количества строк плана.

cnt Количество строк, прошедших через эту стадию плана.

pid Идентификатор родительской стадии для данной стадии плана.

Используется для корректного отражения иерархии плана с помощью отступов.

pos Позиция в плане.

obj Идентификатор соответствующего объекта, при необходимости.

ор Текстовое описание выполняемой операции.

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

ошибки разбора (PARSE) - выполнялся недопустимый SQL-оператор;

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

Решая различные проблемы, я постоянно обращаюсь к трассировочным файлам, в которых записываются ошибки. Если при использовании готового приложения, средства сторонних производителей и даже команд Oracle выдается невразумительное сообщение об ошибке, имеет смысл выполнить команду с включенной трассировкой SQL TRACE и посмотреть в трассировочном файле, что на самом деле происходит. Во многих случаях причина проблемы может быть установлена по трассировочному файлу, поскольку все выполненные от имени сеанса SQL-операторы в нем записаны.

Чтобы продемонстрировать эти записи, я выполнил следующий SQL-оператор:

tkyte@TKYTE816> create table t (x int primary key) ;

Table created.

tkyte@TKYTE816> alter session set sql trace=true;

Session altered.

tkyte@TKYTE816> select * from; select * from

ERROR at line 1:

ORA-00903: invalid table name

tkyte@TKYTE816> insert into t values (1);

1 row created.

tkyte@TKYTE816> insert into t values (1);

insert into t values (1) *

ERROR at line 1: