В ходе расследования проблем возникает необходимость получить информацию о текущих исполняемых запросах в СУБД. Примером когда необходима подобная информация может служить разбор превышения времени ожидания на блокировке СУБД. В этой статье я создам подобную ситуацию и покажу какую информацию можно получить.
Подготовка
Суть примера заключается в том чтобы получить ожидание на блокировке СУБД. Для этого нам потребуется тестовая база данных, а также информация об имени таблицы в базе для составления SQL-запроса. С помощью обработки выполним запись в регистр и встанем на ожидании, не завершив транзакцию. В Management Studio выполним запрос чтения данных из регистра. Поскольку в предлагаемом примере уровень изоляции Read Committed, запрос на чтение будет ожидать освобождения ресурса, который заблокирован транзакцией записи.
Создание базы данных
Создадим базу данных, в которой установим режим управления блокировкой «Управляемый», основной режим запуска «Обычное приложение», режим использования модальных окон в «Использовать», режим совместимости «8.2.13». Добавим в базу регистр сведений «ТекущиеИсполняемыеЗапросы» (непериодический, независимый). В регистре добавим измерение: «Измерение1» (тип Число) и ресурс: «Ресурс1» (тип Число). Также создадим обработку «ЗаписьВРегистрВТранзакции» со следующим кодом:
|
1 2 3 4 5 6 7 8 9 |
НачатьТранзакцию(); НаборЗаписей = РегистрыСведений.ТекущиеИсполняемыеЗапросы.СоздатьНаборЗаписей(); НаборЗаписей.Отбор.Измерение1.Установить(1); НоваяЗапись = НаборЗаписей.Добавить(); НоваяЗапись.Измерение1 = 1; НоваяЗапись.Ресурс1 = 1; НаборЗаписей.Записать(Истина); Предупреждение("Ожидание"); ЗафиксироватьТранзакцию(); |
SQL-запрос
Для составления SQL-запроса нам потребуется имя таблицы базы данных, соответствующее регистру сведений. Для этого воспользуемся обработкой из статьи «Получение информации о структуре хранения базы данных в терминах 1С:Предприятие и СУБД». В моей базе данных имя этой таблицы: «_InfoRg243», напишем следующий запрос выборки всех данных из таблицы:
|
1 2 3 4 |
SELECT * FROM dbo._InfoRg243 |
Эксперимент
Эксперимент довольно прост:
- Открываем в 1С обработку «ЗаписьВРегистрВТранзакции» и встаем на модальном окне предупреждения
- В Management Studio выполняем SQL-запрос, он должен начать выполняться и «повиснуть» на выполнении
В результате этих действий в нашей базе данных выполняется запрос, который ожидает освобождения ресурса. Если бы было установлено время таймаута (а по умолчанию его нет), возникла бы ошибка превышения времени ожидания на блокировке.
Получение информации о текущих запросах
Текущее состояние нашей системы дает нам возможность выполнить запрос, который вернет информацию об исполняемых в данный момент запросах. В моем запросе будут использованы следующие динамические административные представления:
| Представление | Описание |
|---|---|
| dm_exec_requests | Возвращает сведения о каждом из запросов, выполняющихся в SQL Server |
| dm_exec_sql_text | Возвращает текст пакета SQL, который определен указанным параметром |
| dm_exec_query_plan | Возвращает события инструкции Showplan в XML-формате для пакета, указанного в дескрипторе плана |
Текст запроса приведен ниже, а также доступен во вложении к статье:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 |
SELECT DB_NAME(er.database_id) AS DB_Name, er.start_time, er.session_id, er.status, er.command, -- performance: er.reads+er.writes AS IO, er.logical_reads, er.cpu_time, er.total_elapsed_time, -- waits: er.blocking_session_id, er.wait_type, er.wait_time, er.wait_resource, -- query: qt.text, qp.query_plan FROM sys.dm_exec_requests as er CROSS APPLY sys.dm_exec_sql_text(er.sql_handle) qt CROSS APPLY sys.dm_exec_query_plan(er.plan_handle) qp WHERE er.database_id = DB_ID('MyBase') |
В условии отбора «MyBase» — имя моей базы данных в СУБД. Результат запроса представлен на картинке ниже:
У меня на картинке выведено 2 строки: первая (обведена красным цветом) — запрос, ожидающий освобождения ресурса; вторая — сам запрос получения информации об исполняемых запросах, поэтому ее разбирать не будем.
Ниже приведу описания колонок результата запроса:
| Имя колонки | Описание |
|---|---|
| DB_Name | Имя базы данных к которой выполняется запрос |
| start_time | Отметка времени поступления запроса |
| session_id | Идентификатор сеанса, к которому относится данный запрос |
| status | Состояние запроса |
| command | Тип выполняемой команды |
| IO | Число операций чтения и записи, выполненных данным запросом |
| logical_reads | Число логических операций чтения, выполненных данным запросом |
| cpu_time | Время ЦП (в миллисекундах), затраченное на выполнение запроса |
| total_elapsed_time | Общее время, истекшее с момента поступления запроса (в миллисекундах) |
| blocking_session_id | Идентификатор сеанса, блокирующего запрос |
| wait_type | Если запрос в настоящий момент блокирован, в столбце содержится тип ожидания |
| wait_time | Если запрос в настоящий момент блокирован, в столбце содержится продолжительность текущего ожидания (в миллисекундах) |
| wait_resource | Если запрос в настоящий момент блокирован, в столбце указан ресурс, освобождения которого ожидает запрос |
| text | Текст поступившего запроса |
| query_plan | Предполагаемый план выполнения поступившего запроса |
Анализ результата запроса
Интерпретируем результат запроса:
02.08.2016 в 12:50:18 сеансом с идентификатором «70» к базе данных «MyBase» был отправлен запрос типа SELECT. Текст запроса, а так же предполагаемый план выполнения запроса указаны в полях text и query_plan соответственно. Запрос был приостановлен (suspend) по причине ожидания получения разделяемой (S) блокировки на ресурсе «KEY: …». Данный ресурс захвачен блокирующим сеансом с идентификатором 69. Время ожидания, а так же общее время истекшее с момента получения запроса указаны в полях wait_time и total_elapsed_time соответственно.