Огромное несоответствие между сообщаемым размером индекса и количеством буферов в плане выполнения

10

Проблема

У нас есть запрос как

SELECT COUNT(1) 
  FROM article
  JOIN reservation ON a_id = r_article_id 
 WHERE r_last_modified < now() - '8 weeks'::interval 
   AND r_group_id = 1 
   AND r_status = 'OPEN';

Поскольку время ожидания истекает (через 10 минут) чаще всего, я решил исследовать проблему.

EXPLAIN (ANALYZE, BUFFERS)Результат выглядит следующим образом :

 Aggregate  (cost=264775.48..264775.49 rows=1 width=0) (actual time=238960.290..238960.291 rows=1 loops=1)
   Buffers: shared hit=200483 read=64361 dirtied=666 written=8, temp read=3631 written=3617
   I/O Timings: read=169806.955 write=0.154
   ->  Hash Join  (cost=52413.67..264647.65 rows=51130 width=0) (actual time=1845.483..238957.588 rows=21644 loops=1)
         Hash Cond: (reservation.r_article_id = article.a_id)
         Buffers: shared hit=200483 read=64361 dirtied=666 written=8, temp read=3631 written=3617
         I/O Timings: read=169806.955 write=0.154
         ->  Index Scan using reservation_r_article_id_idx1 on reservation  (cost=0.42..205458.72 rows=51130 width=4) (actual time=34.035..237000.197 rows=21644 loops=1)
               Filter: ((r_group_id = 1) AND (r_status = 'OPEN') AND (r_last_modified < (now() - '56 days'::interval)))
               Rows Removed by Filter: 151549
               Buffers: shared hit=200193 read=48853 dirtied=450 written=8
               I/O Timings: read=168614.105 write=0.154
         ->  Hash  (cost=29662.22..29662.22 rows=1386722 width=4) (actual time=1749.392..1749.392 rows=1386814 loops=1)
               Buckets: 32768  Batches: 8  Memory Usage: 6109kB
               Buffers: shared hit=287 read=15508 dirtied=216, temp written=3551
               I/O Timings: read=1192.850
               ->  Seq Scan on article  (cost=0.00..29662.22 rows=1386722 width=4) (actual time=23.822..1439.310 rows=1386814 loops=1)
                     Buffers: shared hit=287 read=15508 dirtied=216
                     I/O Timings: read=1192.850
 Total runtime: 238961.812 ms

Узким местом узкого места, очевидно, является сканирование индекса. Итак, давайте посмотрим определение индекса:

CREATE INDEX reservation_r_article_id_idx1 
    ON reservation USING btree (r_article_id)
 WHERE (r_status <> ALL (ARRAY['FULFILLED', 'CLOSED', 'CANCELED']));

Размеры и номера строк

Его размер (сообщаемый \di+физическим файлом или при посещении) составляет 36 МБ. Поскольку резервирование обычно тратит только относительно короткое время во всех статусах, не перечисленных выше, происходит много обновлений, поэтому индекс довольно раздутый (здесь тратится около 24 МБ) - тем не менее, размер относительно невелик.

reservationТаблица составляет около 3,8 ГБ, содержащей около 40 миллионов строк. Количество резервирований, которые еще не закрыты, составляет около 170 000 (точное число указано в узле сканирования индекса выше).

Теперь сюрприз: сканирование индекса сообщает об извлечении огромного количества буферов (то есть страниц по 8 КБ):

Buffers: shared hit=200193 read=48853 dirtied=450 written=8

Числа, считанные из кэша и диска (или из кэша ОС), составляют в целом 1,9 ГБ!

Худший вариант развития событий

С другой стороны, в наихудшем сценарии, когда каждый кортеж находится на отдельной странице таблицы, будет учитываться посещение (21644 + 151549) + 4608 страниц (общее количество строк, извлеченных из таблицы, плюс номер страницы индекса из физического размер). Это все еще только ниже 180 000 - намного ниже наблюдаемых почти 250 000.

Интересно (и, возможно, важно), что скорость чтения с диска составляет около 2,2 МБ / с, что вполне нормально, я думаю.

Ну и что?

Кто-нибудь имеет представление о том, откуда может появиться это несоответствие?

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

Обновление: проверка эффекта кэширования или микровакуумирования

Основываясь на ответе jjanes , я проверил, что происходит, когда я сразу же запускаю тот же самый запрос. Количество затронутых буферов на самом деле не меняется. (Для этого я упростил запрос до минимума, который все еще показывает проблему.) Это то, что я вижу при первом запуске:

 Aggregate  (cost=240541.52..240541.53 rows=1 width=0) (actual time=97703.589..97703.590 rows=1 loops=1)
   Buffers: shared hit=413981 read=46977 dirtied=56
   I/O Timings: read=96807.444
   ->  Index Scan using reservation_r_article_id_idx1 on reservation  (cost=0.42..240380.54 rows=64392 width=0) (actual time=13.757..97698.461 rows=19236 loops=1)
         Filter: ((r_group_id = 1) AND (r_status = 'OPEN') AND (r_last_modified < (now() - '56 days'::interval)))
         Rows Removed by Filter: 232481
         Buffers: shared hit=413981 read=46977 dirtied=56
         I/O Timings: read=96807.444
 Total runtime: 97703.694 ms

и после второго:

 Aggregate  (cost=240543.26..240543.27 rows=1 width=0) (actual time=388.123..388.124 rows=1 loops=1)
   Buffers: shared hit=460990
   ->  Index Scan using reservation_r_article_id_idx1 on reservation  (cost=0.42..240382.28 rows=64392 width=0) (actual time=0.032..385.900 rows=19236 loops=1)
         Filter: ((r_group_id = 1) AND (r_status = 'OPEN') AND (r_last_modified < (now() - '56 days'::interval)))
         Rows Removed by Filter: 232584
         Buffers: shared hit=460990
 Total runtime: 388.187 ms
Dezso
источник
1
Вероятно, не имеет значения, но вам нужно присоединиться к article? Похоже, что все задействованные столбцы взяты из reservationтаблицы и (при условии, что есть FK, результат должен быть одинаковым).
ypercubeᵀᴹ
Это очень хороший вопрос. И вы правы, это не нужно - это запрос, используемый при мониторинге другой командой. Тем не менее, по крайней мере, глядя на план запроса, все остальное - всего лишь украшение для этого мерзкого сканирования индекса :)
dezso
1
Позвольте мне добавить, что удаление объединения не имеет большого значения - преувеличенное сканирование индекса остается там.
Dezso
Доступ к тосту? Хотя я сомневаюсь, что любая из колонок, которые вы показываете, будет поджарена Если у вас есть свободный клон базы данных для тестирования, вы можете запустить pg_stat_reset()его, а затем выполнить запрос, а затем посмотреть, pg_statio_user_tablesгде он атрибутирует блоки.
Джейн

Ответы:

4

Я думаю, что ключом здесь является множество обновлений и раздувание в индексе.

Индекс содержит указатели на строки в таблице, которые больше не являются «живыми». Это старые версии обновленных строк. Старые версии строк хранятся некоторое время, чтобы удовлетворить запросы со старым снимком, а затем - еще некоторое время, потому что никто не хочет выполнять их удаление чаще, чем необходимо.

При сканировании индекса он должен посетить эти строки и затем заметить, что они больше не видны, поэтому игнорирует их. Оператор explain (analyze,buffers)не сообщает об этой активности в явном виде, за исключением подсчета буферов, считываемых / удаляемых в процессе проверки этих строк.

Существует некоторый «микровакуумный» код для деревьев, такой, что когда сканирование снова возвращается к индексу, он вспоминает, что преследуемый указатель больше не был активным, и помечает его как мертвый в индексе. Таким образом, следующий подобный запрос, который запускается, не должен преследовать его снова. Таким образом, если вы снова выполните тот же самый запрос, вы, вероятно, увидите, что доступ к буферу упадет ближе к тому, что вы прогнозировали.

Вы также можете VACUUMчаще использовать таблицу, которая будет очищать мертвые кортежи из самой таблицы, а не только из частичного индекса. В целом, таблицы с высоким частичным индексом оборота могут выиграть от более агрессивного вакуума, чем уровень по умолчанию.

jjanes
источник
Пожалуйста, посмотрите мои изменения - для меня это похоже на кеширование, а не микровакуумирование.
Dezso
Ваши новые числа сильно отличаются от старых (примерно вдвое), поэтому трудно понять, что они означают, не видя новых чисел для фактических строк и строк, отфильтрованных для сканирования индекса.
Джанес
Добавлены полные планы, как они выглядят сегодня. Число затронутых буферов сильно выросло с пятницы, как и число строк.
Дезсо
У вас есть долговременные транзакции? Если это так, возможно, что при сканировании индекса все еще отслеживаются строки, которые ему не видны (что приводит к дополнительным ударам буфера), но он пока не может их убрать, поскольку они могут быть видны кому-то еще со старшей снимок.
Джанес
У меня их нет - типичная транзакция занимает меньше секунды. Изредка несколько секунд, но не дольше.
Дезсо