За какво EXPLAIN мълчи и как да го накараме да говори

Класическият въпрос, който програмист задава на своя DBA или собственик на бизнес на консултант на PostgreSQL, почти винаги звучи по същия начин: „Защо изпълнението на заявките в базата данни отнема толкова време?“

Традиционен набор от причини:

• неефективен алгоритъм
  когато решите да се ПРИСЪЕДИНЕТЕ към няколко CTE над няколко десетки хиляди записа
• остаряла статистика
  ако действителното разпределение на данните в таблицата вече е много различно от това, събрано от ANALYZE последния път
• „включване“ на ресурси
  и вече няма достатъчно специална изчислителна мощност на процесора, гигабайти памет се изпомпват постоянно или дискът не може да се справи с всички „желания“ на базата данни
• блокиране от конкуриращи се процеси

И ако блокировките са доста трудни за улавяне и анализиране, то за всичко останало ни трябва план за запитване, които могат да бъдат получени с помощта на Оператор EXPLAIN (По-добре е, разбира се, незабавно да ОБЯСНИТЕ (АНАЛИЗИРАТЕ, БУФЕРИ) ...) или модул auto_explain.

Но, както е посочено в същата документация,

„Разбирането на план е изкуство и за да го овладеете изисква определен опит...“

Но можете и без него, ако използвате правилния инструмент!

Как обикновено изглежда планът за заявка? Нещо такова:

Index Scan using pg_class_relname_nsp_index on pg_class (actual time=0.049..0.050 rows=1 loops=1)
  Index Cond: (relname = $1)
  Filter: (oid = $0)
  Buffers: shared hit=4
  InitPlan 1 (returns $0,$1)
    ->  Limit (actual time=0.019..0.020 rows=1 loops=1)
          Buffers: shared hit=1
          ->  Seq Scan on pg_class pg_class_1 (actual time=0.015..0.015 rows=1 loops=1)
                Filter: (relkind = 'r'::"char")
                Rows Removed by Filter: 5
                Buffers: shared hit=1

или така:

"Append  (cost=868.60..878.95 rows=2 width=233) (actual time=0.024..0.144 rows=2 loops=1)"
"  Buffers: shared hit=3"
"  CTE cl"
"    ->  Seq Scan on pg_class  (cost=0.00..868.60 rows=9972 width=537) (actual time=0.016..0.042 rows=101 loops=1)"
"          Buffers: shared hit=3"
"  ->  Limit  (cost=0.00..0.10 rows=1 width=233) (actual time=0.023..0.024 rows=1 loops=1)"
"        Buffers: shared hit=1"
"        ->  CTE Scan on cl  (cost=0.00..997.20 rows=9972 width=233) (actual time=0.021..0.021 rows=1 loops=1)"
"              Buffers: shared hit=1"
"  ->  Limit  (cost=10.00..10.10 rows=1 width=233) (actual time=0.117..0.118 rows=1 loops=1)"
"        Buffers: shared hit=2"
"        ->  CTE Scan on cl cl_1  (cost=0.00..997.20 rows=9972 width=233) (actual time=0.001..0.104 rows=101 loops=1)"
"              Buffers: shared hit=2"
"Planning Time: 0.634 ms"
"Execution Time: 0.248 ms"

Но четенето на плана в текст „от листа“ е много трудно и неясно:

• се показва във възела сума по поддърво ресурси
  тоест, за да разберете колко време е отнело изпълнението на конкретен възел или колко точно това четене от таблицата е извело данни от диска, трябва по някакъв начин да извадите едното от другото
• необходимо е време за възел умножете по цикли
  да, изваждането не е най-сложната операция, която трябва да се направи "в главата" - в крайна сметка времето за изпълнение е посочено като средно за едно изпълнение на възел и може да има стотици от тях
• добре, и всичко това заедно ни пречи да отговорим на основния въпрос - така че кой "най-слабото звено"?

Когато се опитахме да обясним всичко това на няколкостотин наши разработчици, разбрахме, че отстрани изглеждаше така:

А това означава, че имаме нужда от...

Инструмент

В него се опитахме да съберем всички ключови механики, които помагат да се разбере „кой е виновен и какво да прави“ според плана и заявката. Е, и споделете част от опита си с общността.
Запознайте се и използвайте - обяснение.tensor.ru

Видимост на плановете

Лесно ли е да се разбере планът, когато изглежда така?

Seq Scan on pg_class (actual time=0.009..1.304 rows=6609 loops=1)
  Buffers: shared hit=263
Planning Time: 0.108 ms
Execution Time: 1.800 ms

Не очень.

Но като това, в съкратен видкогато ключовите индикатори са разделени, е много по-ясно:

Но ако планът е по-сложен, той ще се притече на помощ разпределение на времеви графики по възли:

Е, за най-трудните варианти той бърза да помогне диаграма на напредъка:

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

Структурни улики

Е, ако цялата структура на плана и неговите възпалени места вече са изложени и видими, защо не ги подчертаете на разработчика и не ги обясните на „руски език“?

Вече сме събрали няколко дузини такива шаблони за препоръки.

Профайлър на заявки ред по ред

Сега, ако наложите оригиналната заявка върху анализирания план, можете да видите колко време е изразходвано за всяко отделно изявление - нещо подобно:

...или дори така:

Подмяна на параметри в заявка

Ако сте „прикачили“ не само заявка към плана, но и нейните параметри от реда DETAIL на дневника, можете допълнително да го копирате в една от опциите:

• със заместване на стойността в заявката
  за директно изпълнение на вашата база и допълнително профилиране

  SELECT 'const', 'param'::text;

• със заместване на стойност чрез PREPARE/EXECUTE
  да емулира работата на планировчика, когато параметричната част може да бъде игнорирана - например при работа върху разделени таблици

  DEALLOCATE ALL;
  PREPARE q(text) AS SELECT 'const', $1::text;
  EXECUTE q('param'::text);
  

Архив на планове

Залепете, анализирайте, споделете с колеги! Плановете ще останат архивирани и можете да се върнете към тях по-късно: обяснение.tensor.ru/архив

Но ако не искате другите да виждат вашия план, не забравяйте да поставите отметка в квадратчето „не публикувайте в архив“.

В следващите статии ще говоря за трудностите и решенията, които възникват при анализирането на план.

Източник: www.habr.com