zubkov-andrei / pg_profile

Postgres historic workload reports
Other
228 stars 33 forks source link

Вопрос по настройке таймаутов take_sample() в новой версии pg_profile 4.0 #48

Closed xinferum closed 2 years ago

xinferum commented 2 years ago

Добрый день.

Мы обновили у себя pg_profile с версии 0.3.6 до версии 4.0 сразу после его выхода. По итогам чуть более недели использования у нас возникла такая ситуация, что каждый день довольно много раз pg_profile не может собрать данные во время запуска take_sample(). У нас используется выделенный сервер для сбора данных с разных баз, собираем данные каждый час.

Ошибок в выполнении take_sample() с точки зрения кода, нет в логе PostgreSQL мы видим только сообщения:

2022-09-02 00:00:00.074 MSK [1196()-3160] app=[],client=[] [LOG:  cron job 46 connection failed
2022-09-02 00:00:00.075 MSK [1196()-3161] app=[],client=[] [LOG:  cron job 47 connection failed
2022-09-02 00:00:00.075 MSK [1196()-3162] app=[],client=[] [LOG:  cron job 45 connection failed

В моменты когда для части серверов не удается получить семплы.

Я пробовал увеличить в функции take_sample(int4, bool) в 117 строке таймаут подключения dblink с 3 секунд до 30:

PERFORM dblink('server_connection','SET lock_timeout=30000');

Но это не улучшило ситуацию.

Подскажите, могу ли я где-то еще подкрутить таймауты, мы хотели бы получать семплы в большинстве случаев. Ранее на версии 0.3.6 у нас неудачные сборки были только когда базы были недоступны, а сейчас регулярно. Проблема наблюдается независимо от того, когда выполняется take_sample() - вне окна сборки размеров отношений или в окне сборки размеров, у нас сборка отношений разрешена с 0 до 3 часов ночи по Москве, а проблемы со сборкой семплов возникают в течение всех суток.

zubkov-andrei commented 2 years ago

Добрый день! Большое спасибо за сообщение, надо разбираться. К сожалению, по тексту ошибки понять что-либо трудно. Функция take_sample() должна возвращать текст ошибки, хорошо бы его получить. Самый просто вариант - выполнить вручную из psql и получить текст ошибки. Но если ошибка стабильно не воспроизводится, это может сразу не получиться. Тогда хорошо бы в задании, выполняемом по крону предусмотреть возможность сохранения результатов выполнения функции take_sample в какой-нибудь исторической таблице.

xinferum commented 2 years ago

Хорошо, обсудим с коллегой, что-нибудь придумаем для логирования. Или возможно просто попробуем погонять какую-нибудь реплику вызовами take_sample() раз в минуту на тестовом контуре, возможно поймаем момент воспроизведения проблемы. Как будет новая информация - предоставлю логи.

zubkov-andrei commented 2 years ago

Проще всего наверное перенаправить вывод psql в файл с аппендом в задании крона.

xinferum commented 2 years ago

Добрый день.

С репликами стало чуть более понятно:

2022-09-05 09:00:34.016 MSK [19612()-8] app=[pg_cron],client=[::1(44426)] [profile_mon@profile_mon], [vxid:8/3139 txid:2291307] [SELECT] ERROR:  FATAL:  terminating connection due to conflict with recovery
    DETAIL:  User query might have needed to see row versions that must be removed.
    HINT:  In a moment you should be able to reconnect to the database and repeat your command.
    server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.

Сбор данных иногда сталкивается с тем, что его прерывает postgresql для наката изменений с мастера. Ранее такого не наблюдали, возможно сбор статистик стал дольше, хотя на нагруженном кластере take_sample() занимает порядка 6 секунд.

Может быть были добавлены какие-то данные статистики сервера, которые прилетают с мастера и теперь встречается такое поведение?

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

zubkov-andrei commented 2 years ago

Спасибо за информацию. Это интересно. В 4-й версии сбор статистик происходит (наконец) в режиме изоляции REPEATABLE READ READ ONLY, что, безусловно, увеличивает вероятность получения такой ошибки на реплике. Что тут можно попробовать...

xinferum commented 2 years ago

К сожалению, вариант с изменением конфигурации PostgreSQL нам не подойдет, да и отсутствие семпла на реплике не столь критично. Да, мы понимаем, что на репликах могут быть проблемы со сбором статистики в любом случае.

Мы пока подозреваем, что у нас возможно возникают блокировки именно при работе с базой самого pg_profile, т.к. мы используем выделенный сервер с бд чисто под pg_profile, который собирает данные с удаленных серверов PostgreSQL. И у нас получилось так что сбор семплов take_sample() для нескольких десятков серверов в pg_cron запускался в одно и то же время. Сейчас попробовали разнести по времени, чтобы стартовало пачками серверов, будем наблюдать.

В логе на сервере pg_profile обнаружили подобные сообщения:

2022-09-05 14:01:26.813 MSK [26051()-5] app=[pg_cron],client=[::1(48148)] [profile_mon@profile_mon], [vxid:31/244 txid:2293823] [SELECT waiting] LOG:  process 26051 still waiting for ShareUpdateExclusiveLock on relation 18222 of database 16384 after 85538.406 ms
2022-09-05 14:01:26.813 MSK [26051()-6] app=[pg_cron],client=[::1(48148)] [profile_mon@profile_mon], [vxid:31/244 txid:2293823] [SELECT waiting] DETAIL:  Process holding the lock: 26049. Wait queue: 26042, 26048, 26047, 26052, 26056, 26057, 26054, 26055, 26051, 26053, 26059, 26060, 26065, 26058, 26062, 26066.
2022-09-05 14:01:26.813 MSK [26051()-7] app=[pg_cron],client=[::1(48148)] [profile_mon@profile_mon], [vxid:31/244 txid:2293823] [SELECT waiting] CONTEXT:  SQL statement "ANALYZE last_stat_tablespaces"
    PL/pgSQL function take_sample(integer,boolean) line 660 at SQL statement
    PL/pgSQL function take_sample(name,boolean) line 9 at RETURN
2022-09-05 14:01:26.813 MSK [26051()-8] app=[pg_cron],client=[::1(48148)] [profile_mon@profile_mon], [vxid:31/244 txid:2293823] [SELECT waiting] STATEMENT:  SELECT profile.take_sample('server_name')

Пока относительно ошибок при сборке с мастеров сказать ничего не могу. Не отловил. Не поможет разнесение во времени запуска take_sample() - буду отлавливать.

zubkov-andrei commented 2 years ago

Да, похоже на это. Похоже ANALYZE будет конкурировать с параллельными снимками. Я подумаю что с этим можно сделать.

xinferum commented 2 years ago

После разнесения заданий take_sample() во времени по пачкам серверов, проблема ушла. Ошибок сборки семплов даже на репликах не было со вчерашнего вечера. Мы сделали пачки серверов еще меньше (с 10 до 5 серверов за раз уменьшили) сейчас, разнесены пачки с шагом в 2 минуты.

В логе PostgreSQL сообщения о блокировках ShareUpdateExclusiveLock так и остались, но сейчас очередь меньше получается и в таймауты укладываемся. Может в коде pg_profile попробовать использовать рекомендательные блокировки pg_advisory_lock() ?

zubkov-andrei commented 2 years ago

Спасибо за информацию. Это должно помочь в размышлениях. advisory_lock там уже был, но тут он не очень нужен. Сейчас профайл блокирует возможность запуска двух параллельных снимков по одному серверу используя блокировку уровня записи каждом сервере. Но, похоже, не очень получается. Я подумаю что с этим можно сделать, тут нужно несколько методов попробовать.

zubkov-andrei commented 2 years ago

Сергей, а будет у вас возможность проверить тестовую версию? С ней будет сложность - на нее нельзя будет обновиться и с нее потом не вернешься обновлением на релизную версию - только удалять и заново ставить. Учитывая необходимость сброса статистик stat_statements, информацию о нагрузке, собранную за время тестирования вы потеряете если только не сохраните на некоторое время тестовую версию после окончания тестирования, но тогда отчеты за это время можно будет собрать только в ней.

xinferum commented 2 years ago

Мы можем потерять определенный период данных на время тестов, для нас это не критично. Текущее состояние кластера забекапим (может даже просто на холодную, остановив postgresql), а потом вернемся на него, вернув файлы расширения обратно версии 4.0.

Я только не понял момента с тем что на тестовую версию нельзя обновиться. То есть все настраивать с нуля придется для тестов на бд профайла? Лучше бы конечно чтобы с 4.0 я мог обновится на тестовую версию, пусть это и будет путь в один конец и ничего потом с ней нельзя будет сделать.

Если будет версия для тестов - без проблем, потестируем.

zubkov-andrei commented 2 years ago

Обновление на тестовую версию может получиться, а может и нет - зависеть будет от трудоёмкости составления скрипта обновления. Но в самом крайнем случае настройки серверов в профайле хранятся в одной таблице - можно и перегрузить. И не думаю что вам понадобится бэкап - можно просто создать копию базы данных и опыты вести в ней, а потом просто дропнуть.

zubkov-andrei commented 2 years ago

Сегрей, я отправил новую версию в ветку develop. В числе прочего, в ней должна быть поправлена и обнаруженная вами проблема. Если вас не затруднит, посмотрите работает ли она как ожидается. Если всё будет хорошо, я выпущу из этой ветки релиз.

xinferum commented 2 years ago

Спасибо, Андрей.

Постараюсь сегодня обновиться и протестировать наш кейс.

xinferum commented 2 years ago

Андрей, я обновил pg_profile, перевел обратно запуск сбора данных со всех серверов одновременно в 00 минут каждого часа. Уже дважды был сбор данных, серверов по которым не было семплов наш мониторинг пока не обнаружил. Из лога сервера пропали сообщения о блокировках ShareUpdateExclusiveLock.

Похоже проблема исправлена.

Я предлагаю пока несколько дней пусть покрутится новая версия, например до среды (чтобы и нагрузка выходных была на базах и пары будних дней), а в среду я напишу по итогу все ли было нормально. Если время терпит.

zubkov-andrei commented 2 years ago

Большое спасибо, Сергей. Да, конечно, в этом деле торопиться не надо. С 4.0 нехорошо получилось именно из-за невозможности полноценно протестировать в такой развесистой конфигурации и на протяжении продолжительного времени. Хорошо бы еще убедиться и в том что отчёты нормально строятся, но тут я особых проблем не ожидаю. Буду ждать от вас сообщения о результатах наблюдений.

xinferum commented 2 years ago

Андрей, добрый день.

Все эти дни pg_profile работал корректно. Все семплы собирались, в логах сообщений ShareUpdateExclusiveLock не было. Отчеты запрашивал - ничего необычного в них не увидел. Полет нормальный на данной devel версии.

У меня вопрос, после выхода релиза, мне необходимо будет откатить бд и файлы расширения до 4.0 и обновиться? Или я могу оставить все как есть, и, когда выйдет новая версия, например, 4.2, обновиться как обычно?

zubkov-andrei commented 2 years ago

Сергей, добрый день. Большое спасибо за обнаруженную проблему и тщательное тестирование. Думаю, сегодня-завтра я опубликую релизную версию 4.1. Я планирую ее публикацию из версии, которую вы тестировали, так что никаких проблем с дальнейшим обновлением у вас не должно быть.

xinferum commented 2 years ago

Отлично! Спасибо большое за разработку решения! Issue закрываю.