Поиск длинных запросов

Где взять скрипт для поиска

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

Набор состоит из трех скриптов, указанных во вложении. Все три скрипта должны располагаться в каталоге $HOME/bin. Каталог $HOME/bin должен быть включен в переменную окружения PATH (при создании пользователя обычно так и делают).

Головной скрипт имеет имя actsql (можете его переименовать, если хотите). Скачав этот скрипт, следует дать пользователю право на его исполнение - например, так:

	cd ~/bin
	chmod u+x actsql

Как это устроено

Скрипт actsql выполняет стандартную команду Informix

	onstat -u

, которая выдает полный список всех служебных и пользовательских сессий, и построчно анализирует полученный листинг. Листинг выглядит примерно так:

	IBM Informix Dynamic Server Version ??.???? -- On-Line -- Up 7 days 01:07:42 -- 1643548 Kbytes

	Userthreads
	address          flags   sessid   user     tty      wait             tout locks nreads   nwrites
	486b1028         ---P--D 1        informix -        0                0    0     552      27798
	486b1908         ---P--F 0        informix -        0                0    0     0        195973
		. . . . . . .
	486b8c68         ---P--D 16       informix -        0                0    0     0        0
	486b9548         Y--P--- 176      webuser  -        0                0    1     2        13
	486b9e28         ---P--D 17       informix -        0                0    0     2        0
		. . . . . . .
	486bdc48         ---P--- 33       informix -        0                0    1     1050     82973
	486bee08         Y--P--- 174      webuser  -        59a81e98         0    1     0        0
	 24 active, 128 total, 26 maximum concurrent

В этом листинге, помимо заголовков и подвала, данные о каждой сессии занимают одну строку и указаны в листинге жирным шрифтом. Состояние сессии занимает 10 полей строки:

address - адрес дескриптора сессии в разделяемой памяти сервера
flags - флаги состояния сессии
sessid - номер (идентификатор) сессии
user - имя пользователя, открывшего сессию
tty - имя терминала, с которого открыта сессия, или знак минус
wait - адрес структуры в разделяемой памяти, описывающей, чего именно ожидает эта сессия. Если указан ноль - сессия выполняется или готова к выполнению
tout - число секунд, оставшихся в текущем цикле ожидания. Если указан ноль - сессия не находится в состоянии блокировки
locks - текущее число блокировок, инициированных и не закрытых этой сессией. Обычно существует минимум одна блокировка, указывающая на подключение к базе данных
nreads - общее число операций чтения страниц данной сессией - от начала сессии
nwrites - общее число операций записи страниц данной сессией - от начала сессии

Для поиска активных пользовательских сессий предназначен awk-скрипт onstat_u__actives.awk. Активной пользовательской сессией считается сессия, для которой одновременно

нет ожидания (ноль в шестом поле листинга)
имя пользователя - не root и не informix (четвертое поле листинга)

Если сессия активна и принадлежит обычному пользователю, скрипт onstat_u__actives.awk возвращает номер сессии (третье поле листинга). Если сессия чего-то ждет или же сессия является системной - скрипт ничего не возвращает.

Если в цикле получен очередной номер сессии, то с помощью другой стандартной команды Informix - onstat -g ses номер-сессии мы получаем полный листинг состояния этой сессии. Далее в дело вступает третий скрипт - onstat_g_ses.awk, который разбирает полученный листинг на блоки. В данном случае нас интересуют три блока:

блок, начинающийся с текста "Stored procedure stack" - здесь указывается текущий стек вызовов пользовательских хранимых процедур
блок, начинающийся с текста "Current SQL statement" - здесь указывается текущий выполняемый запрос SQL (прямой запрос или запрос внутри исполняемой процедуры - безразлично)
блок, начинающийся с текста "Last parsed SQL statement" - здесь указывается последний транслированный пользователем запрос (прямой запрос либо вызов процедуры) - то есть тот запрос, который выдал пользователь (клиент)

Эти три блока записываются в текстовый файл в текущем каталоге. Имя полученного файла состоит из идентификатора сессии, текущих даты и времени - например, "S_21568730.D_20220802_113016".

Как искать длинные запросы

Прежде всего нужно создать новый пустой каталог и перейти в этот каталог. Затем нужно несколько раз выполнить команду actsql с интервалом в 20-30 секунд. В новом каталоге образуется некоторое количество файлов. Список этих файлов может выглядеть примерно так:

	$ ls -l
	-rw-r--r--   1 white    sci         2054 Aug  2 11:29 S_20448128.D_20220802_112944
	-rw-r--r--   1 white    sci          123 Aug  2 11:31 S_20488844.D_20220802_113151
	-rw-r--r--   1 white    sci         2124 Aug  2 11:30 S_21568730.D_20220802_113002
	-rw-r--r--   1 white    sci         2124 Aug  2 11:30 S_21568730.D_20220802_113016
	-rw-r--r--   1 white    sci         2124 Aug  2 11:30 S_21568730.D_20220802_113032
	-rw-r--r--   1 white    sci          428 Aug  2 11:30 S_21568730.D_20220802_113057
	-rw-r--r--   1 white    sci         2124 Aug  2 11:31 S_21568730.D_20220802_113114
	-rw-r--r--   1 white    sci         2124 Aug  2 11:31 S_21568730.D_20220802_113151
	-rw-r--r--   1 white    sci         1360 Aug  2 11:29 S_21607176.D_20220802_112944
	-rw-r--r--   1 white    sci         1360 Aug  2 11:30 S_21607176.D_20220802_113016
	-rw-r--r--   1 white    sci         1360 Aug  2 11:31 S_21607176.D_20220802_113114
	-rw-r--r--   1 white    sci          302 Aug  2 11:30 S_21657671.D_20220802_113032
	-rw-r--r--   1 white    sci          968 Aug  2 11:31 S_21657793.D_20220802_113131
	-rw-r--r--   1 white    sci         6484 Aug  2 11:29 S_21664556.D_20220802_112944
	-rw-r--r--   1 white    sci         6484 Aug  2 11:30 S_21664556.D_20220802_113002
	-rw-r--r--   1 white    sci         6484 Aug  2 11:30 S_21664556.D_20220802_113016
	-rw-r--r--   1 white    sci         6484 Aug  2 11:30 S_21664556.D_20220802_113032
	-rw-r--r--   1 white    sci        39144 Aug  2 11:31 S_21730885.D_20220802_113131

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

Следует прежде всего обратить внимание на строки листинга, относящиеся к одной и той же сессии и размер файла которых совпадает - скорее всего, тексты выполняемых запросов одинаковы. Например, здесь имеются три строки, относящиеся к сессии 21607176 (выше выделено жирным):

	-rw-r--r--   1 white    sci         1360 Aug  2 11:29 S_21607176.D_20220802_112944
	-rw-r--r--   1 white    sci         1360 Aug  2 11:30 S_21607176.D_20220802_113016
	-rw-r--r--   1 white    sci         1360 Aug  2 11:31 S_21607176.D_20220802_113114

Осталось посмотреть, что именно выполнялось в это время:

	$ cat S_21607176.D_20220802_112944
	STACK


	LAST SQL

	   SELECT b.bol_id,b.usl_id,b.source_id,b.kol,      
		b.date_n,b.date_k,b.mkb_id,m.kod_usl,m.n_usl,mk.name,b.mkb_id_dop,mk2.name     
		NAME_dop,mk.caption  ,pol.fio_ter, b.uch_id  
		FROM bol_usl b, med_usl m     ,mkb mk,outer mkb mk2, pol_spec pol  
		WHERE  b.source_id=?    AND b.pr='P'     AND m.pr='P'  AND b.usl_id=m.usl_id  
		---AND b.DATE_n >(extend(current,year     to day ) - INTERVAL (3) MONTH TO MONTH )  
		--AND b.DATE_n     >(extend(mdy(month(current),01,year(current)), year to day) - INTERVAL (3)     MONTH TO MONTH )  
		AND mk.mkb_id=b.mkb_id  AND mk2.mkb_id=b.mkb_id_dop  and     pol.ter_id = b.uch_id and  pol.cod_k = 9  
		order by b.date_n DESC,     m.kod_usl  

	CURRENT SQL

	   SELECT b.bol_id,b.usl_id,b.source_id,b.kol,      
		b.date_n,b.date_k,b.mkb_id,m.kod_usl,m.n_usl,mk.name,b.mkb_id_dop,mk2.name     
		NAME_dop,mk.caption  ,pol.fio_ter, b.uch_id  
		FROM bol_usl b, med_usl m     ,mkb mk,outer mkb mk2, pol_spec pol  
		WHERE  b.source_id=?    AND b.pr='P'     AND m.pr='P'  AND b.usl_id=m.usl_id  
		---AND b.DATE_n >(extend(current,year     to day ) - INTERVAL (3) MONTH TO MONTH )  
		--AND b.DATE_n     >(extend(mdy(month(current),01,year(current)), year to day) - INTERVAL (3)     MONTH TO MONTH )  
		AND mk.mkb_id=b.mkb_id  AND mk2.mkb_id=b.mkb_id_dop  and     pol.ter_id = b.uch_id and  pol.cod_k = 9  
		order by b.date_n DESC,     m.kod_usl

Исходный текст запроса представлен в неформатированном виде (в том виде, в каком он получен командой onstat). Тем не менее несложно понять, какой именно запрос выполняется так долго.

Прикрепленные файлы

1. Поиск длинных сессий
actsql ; 202 байт

2. Определение состояние (активность или ожидание) отдельной сессии
onstat_u__actives.awk ; 344 байт

3. Получение состояние текущего выполняемого запроса отдельной сессии
onstat_g_ses.awk ; 3499 байт