Хронометраж: EXPLAIN ANALYZE

Чертежи запросов уже не кажутся тебе тайнописью: cost, rows, width — ты читаешь их, как штурманскую прокладку. Но по дороге вниз, к машинному отделению, тебя догоняет неприятная мысль: всё это — прогнозы. Штурман ОБЕЩАЕТ маршрут за столько-то попугаев. А как рейс пройдёт на самом деле?

КВЕРИ ждёт тебя у испытательного стенда — плиты с зажимами, над которой на цепочке висит древний секундомер с механической стрелкой.

КВЕРИ: Чертёж говорит, как штурман собирался ехать. Хронометраж — как съездилось. Инженер, который верит одним чертежам, рано или поздно строит мост из бумаги. Заводи секундомер.

Вторая скобка: факт рядом с прогнозом

К знакомому EXPLAIN добавляется одно слово:

EXPLAIN ANALYZE <твой запрос>;

С ANALYZE машина не ограничивается прогнозом — она ВЫПОЛНЯЕТ запрос по-настоящему, с секундомером на каждом узле, и печатает тот же чертёж с дописанными показаниями. Эту команду ты уже встречал в Хранилище; теперь разберём её вывод по цифрам. У каждого узла появляется вторая скобка:

(cost=… rows=… width=…)                ← прогноз штурмана, попугаи
(actual time=старт..итог rows=… loops=…) ← показания секундомера, факт

• actual time=старт..итог — устроено как у cost (прошлый урок), только единицы честные: МИЛЛИСЕКУНДЫ. Первая цифра — через сколько узел отдал первую строку, вторая — когда закончил.
• rows — сколько строк узел вернул НА САМОМ ДЕЛЕ. Рядом с прогнозным rows из первой скобки это главная пара чисел плана — ей мы посвятим отдельный урок.
• loops — сколько раз узел запускался за рейс. Пока держи в голове «обычно 1»; чуть ниже увидишь, как это число взрывается.

Внизу плана добавляются две служебные строки: Planning Time — сколько думал штурман, и Execution Time — сколько ехал исполнитель.

Оценка встречает факт

Испытуемый — термодатчик №388: он висит прямо над люком машинного отделения, на палубе J. Запрос собирает всю его ленту показаний по времени: полный проход по журналу с фильтром, над ним сортировка.

Сначала — чертёж без рейса, как ты уже умеешь:

Читаем показания секундомера

Три наблюдения по свежему хронометражу:

1. Штурман почти угадал. Прогноз обещал около 360 строк — факт дал ровно 361. Когда оценка и факт сходятся, штурман ведёт по свежим картам; расхождение на порядок — сигнал тревоги, и ему посвящён отдельный урок этой главы.
2. actual time показывает характер узла. У Seq Scan старт около нуля, а итог — почти всё время рейса: первую строку он отдаёт сразу и дальше струится ровно — узел-ручей из прошлого урока. У Sort старт и итог почти совпадают: сортировка не может отдать НИ ОДНОЙ строки, пока не увидит все, — та самая плотина: копит и отдаёт залпом. Две цифры — и ты уже знаешь, кто перед тобой.
3. Миллисекунды плавают. Запусти ячейку ещё раз — времена чуть изменятся: кеши, соседние процессы, настроение станции. А вот rows=361 и Rows Removed by Filter: 179639 не сдвинутся ни на строку. Факт рейса детерминирован — дрожат лишь стрелка секундомера да, как ты помнишь с прошлого урока, прогноз штурмана. Поэтому инженер цитирует в отчётах строки и узлы, а времена — только порядками.

Узел, который запускался сорок раз

В планах выше у каждого узла стояло loops=1: узел отработал за рейс один раз. Так бывает не всегда. Вспомни отчёт, который завис: подзапрос-счётчик машина запускала заново для КАЖДОГО датчика. Сейчас ты увидишь, как это выглядит на секундомере.

Берём сорок датчиков палубы J — той самой, через чей люк ты сюда спустился, — и для каждого спрашиваем: когда он в последний раз выходил на связь?

Главное правило скобки: умножай на loops

Числа в actual-скобке — это СРЕДНЕЕ НА ОДИН запуск узла (округлённое), а не сумма. Полный вклад узла считается умножением:

• Aggregate: rows=1 × loops=40 → сорок строк за весь рейс, по одному «последнему сеансу связи» на датчик.
• Seq Scan on ls_readings: rows=361 × loops=40 ≈ 14 440 возвращённых строк. А ПРОЛИСТАНО куда больше: каждый запуск перебирает журнал целиком, 40 × 180 000 = 7 200 000 строк — семь миллионов ради сорока ответов.
• actual time — тоже среднее на запуск: полное время узла ≈ итоговая цифра × loops.

Вот почему, прежде чем судить узел по его миллисекундам, инженер смотрит на loops: скромный узел на несколько миллисекунд, запущенный тысячи раз, съедает минуты — сорок секунд утреннего отчёта сделаны ровно из этого теста, только датчиков там было больше.

КВЕРИ: Секундомер не обвиняет — он свидетельствует. Узел на считаные миллисекунды невиновен. Присмотрись к тому, кто запустил его сорок раз.

Секундомер сказал, СКОЛЬКО времени ушло. Следующий вопрос инженера — КУДА: что именно машина листала все эти миллисекунды? Ответ измеряется не строками, а страницами — в следующем уроке откроем BUFFERS и посчитаем ввод-вывод.