Медленный Sidekiq + Postmaster потребляют 95%+ CPU (32 ядра) после обновления версии Postgresql

Итак, я сегодня выполнил обновление, и в процессе, похоже, была обновлена версия PostgreSQL. После этого проблема (или аналогичная) вернулась (старая тема теперь закрыта):

Я попробовал то, что ранее решало эту проблему:

cd /var/discourse/
./launcher enter app
sudo -u postgres psql
\c discourse
VACUUM FULL VERBOSE;

а также:

REINDEX DATABASE discourse;

Но безрезультатно :upside_down_face:

Postmaster использует 95–100 % из 32 ядер CPU. Sidekiq обрабатывает примерно 1 задачу в секунду.

Я также пробовал очистить Redis и пересобрать систему заново. Я тестировал с 12, 8 и 4 воркерами Unicorn и процессами Sidekiq.

До обновления PostgreSQL всё работало очень стабильно и плавно с 12 воркерами Unicorn и процессами Sidekiq. Сейчас запущена версия 2.5.0.beta5, а до обновления, насколько я помню, была 2.5.0.beta2.

:firstworldproblem:

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

Включение pg_stat_statements для этого очень полезно.

Спасибо, @Falco. Вот некоторые статистические данные. Дайте знать, если нужно увидеть больше запросов, так как они обрезаются в конце.

                                                                                                                                                     запрос                                                                                                                                                     | общее_время | вызовы |   мин   |  средн   |    макс    | pct_cpu
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+------------+-------+---------+---------+-----------+---------
SELECT "posts"."id", "posts"."user_id", "posts"."topic_id", "posts"."post_number", "posts"."raw", "posts"."cooked", "posts"."created_at", "posts"."updated_at", "posts"."reply_to_post_number", "posts"."reply_count", "posts"."quote_count", "posts"."deleted_at", "posts"."off_topic_count", "posts"."like | 4018799.92 |  2031 | 1458.34 | 1978.73 |   2690.51 |   38.90
SELECT COUNT(*) FROM "posts" WHERE ("posts"."deleted_at" IS NULL) AND (posts.post_type IN ($1,$2,$3)) AND (post_number > COALESCE(( SELECT last_read_post_number FROM topic_users tu WHERE tu.user_id = $4 AND tu.topic_id = $5 ),$6)) AND (reply_to_user_id = $7 OR exists( SELECT $8 from topic_users tu W | 3959915.35 |  2021 | 1467.53 | 1959.38 |   2753.25 |   38.33
SELECT COUNT(*) FROM "posts" INNER JOIN "topics" ON "topics"."id" = "posts"."topic_id" AND ("topics"."deleted_at" IS NULL) WHERE ("posts"."deleted_at" IS NULL) AND (topics.category_id = $1) AND (topics.visible = $2) AND (posts.deleted_at IS NULL) AND (posts.user_deleted = $3) AND (topics.id <> $4) A |  349840.54 |   148 |   55.14 | 2363.79 | 111182.89 |    3.39
SELECT "posts"."id" FROM "posts" WHERE ("posts"."deleted_at" IS NULL) AND "posts"."topic_id" = $1 AND (posts.user_id = $2 OR post_type IN ($3,$4,$5)) AND "posts"."post_number" = $6 LIMIT $7                                                                                                                |  237109.72 |   123 | 1488.37 | 1927.72 |   2387.02 |    2.30
SELECT "posts"."id", "posts"."user_id", "posts"."topic_id", "posts"."post_number", "posts"."raw", "posts"."cooked", "posts"."created_at", "posts"."updated_at", "posts"."reply_to_post_number", "posts"."reply_count", "posts"."quote_count", "posts"."deleted_at", "posts"."off_topic_count", "posts"."like |  223843.91 |   560 |  269.46 |  399.72 |    522.30 |    2.17
SELECT "posts"."id", "posts"."user_id", "posts"."topic_id", "posts"."post_number", "posts"."raw", "posts"."cooked", "posts"."created_at", "posts"."updated_at", "posts"."reply_to_post_number", "posts"."reply_count", "posts"."quote_count", "posts"."deleted_at", "posts"."off_topic_count", "posts"."like |  222330.42 |   113 | 1516.53 | 1967.53 |   2620.96 |    2.15
SELECT l.post_id, l.url, l.clicks, COALESCE(t.title, l.title) AS title, l.internal, l.reflection, l.domain FROM topic_links l LEFT JOIN topics t ON t.id = l.link_topic_id LEFT JOIN categories AS c ON c.id = t.category_id WHERE (t.deleted_at IS NULL) AND (COALESCE(t.archetype, $1) <> $2) AND (l.post_ |   77597.13 |   134 |  479.18 |  579.08 |    662.30 |    0.75
SELECT "posts"."id", EXTRACT($1 FROM CURRENT_TIMESTAMP - created_at)::INT AS days_ago FROM "posts" WHERE ("posts"."deleted_at" IS NULL) AND "posts"."topic_id" = $2 AND (posts.user_id = $3 OR post_type IN ($4,$5,$6)) ORDER BY "posts"."sort_order" ASC                                                    |   57100.18 |   131 |  285.36 |  435.88 |    545.55 |    0.55
SELECT MAX("posts"."post_number") FROM "posts" WHERE ("posts"."deleted_at" IS NULL) AND "posts"."topic_id" = $1 AND (posts.user_id = $2 OR post_type IN ($3,$4,$5))                                                                                                                                          |   56887.08 |   131 |  285.22 |  434.25 |    534.65 |    0.55
SELECT COALESCE(SUM(rs.score), $1) AS total_spam_score, COUNT(DISTINCT rs.user_id) AS spam_user_count FROM reviewables AS r INNER JOIN reviewable_scores AS rs ON rs.reviewable_id = r.id WHERE r.target_created_by_id = $2 AND rs.reviewable_score_type = $3 AND rs.status IN ($4, $5)                      |   16211.73 |   119 |   86.25 |  136.23 |    163.52 |    0.16
SELECT COUNT(*) FROM "topics" WHERE ("topics"."deleted_at" IS NULL) AND "topics"."category_id" = $1 AND "topics"."visible" = $2 AND (topics.id <> $3) AND (topics.created_at > $4)                                                                                                                           |   14922.91 |   152 |   61.68 |   98.18 |    154.13 |    0.14
SELECT COUNT(*) FROM "users" INNER JOIN "topic_allowed_users" ON "users"."id" = "topic_allowed_users"."user_id" WHERE "topic_allowed_users"."topic_id" = $1                                                                                                                                                  |   14358.68 |   186 |    9.17 |   77.20 |    109.96 |    0.14
SELECT ftl.url, COALESCE(ft.title, ftl.title) AS title, ftl.link_topic_id, ftl.reflection, ftl.internal, ftl.domain, MIN(ftl.user_id) AS user_id, SUM(clicks) AS clicks FROM topic_links AS ftl LEFT JOIN topics AS ft ON ftl.link_topic_id = ft.id LEFT JOIN categories AS c ON c.id = ft.category_id WHERE |   14029.70 |   186 |   12.82 |   75.43 |     94.01 |    0.14
SELECT COUNT(*) FROM ( SELECT $1 FROM notifications n LEFT JOIN topics t ON t.id = n.topic_id WHERE t.deleted_at IS NULL AND n.high_priority = $2 AND n.user_id = $3 AND n.id > $4 AND NOT read LIMIT $5 ) AS X                                                                                              |    3364.46 |  3790 |    0.02 |    0.89 |      3.21 |    0.03
SELECT * FROM ( SELECT n.id, n.read FROM notifications n LEFT JOIN topics t ON n.topic_id = t.id WHERE t.deleted_at IS NULL AND n.high_priority AND n.user_id = $1 AND NOT read ORDER BY n.id DESC LIMIT $2 ) AS x UNION ALL SELECT * FROM ( SELECT n.id, n.read FROM notifications n LEFT JOIN topics t ON  |     968.26 |  3654 |    0.06 |    0.26 |      1.04 |    0.01
SELECT tags.name as tag_name, SUM(stats.topic_count) AS sum_topic_count FROM category_tag_stats stats JOIN tags ON stats.tag_id = tags.id AND stats.topic_count > $1 WHERE stats.category_id in ($2,$3,$4,$5,$6,$7,$8,$9,$10,$11,$12,$13,$14,$15,$16,$17,$18,$19,$20,$21,$22,$23,$24,$25,$26,$27,$28,$29,$30 |     953.21 |   173 |    3.57 |    5.51 |      7.52 |    0.01
SELECT a.attname FROM ( SELECT indrelid, indkey, generate_subscripts(indkey, $1) idx FROM pg_index WHERE indrelid = $2::regclass AND indisprimary ) i JOIN pg_attribute a ON a.attrelid = i.indrelid AND a.attnum = i.indkey[i.idx] ORDER BY i.idx                                                           |     657.76 |   163 |    0.01 |    4.04 |      8.66 |    0.01
SELECT $1 AS one FROM "push_subscriptions" WHERE "push_subscriptions"."user_id" = $2 LIMIT $3                                                                                                                                                                                                                |     381.25 |  2029 |    0.10 |    0.19 |      0.41 |    0.00
INSERT INTO "notifications" ("notification_type", "user_id", "data", "created_at", "updated_at", "topic_id", "post_number") VALUES ($1, $2, $3, $4, $5, $6, $7) RETURNING "id"                                                                                                                               |     339.56 |  2028 |    0.08 |    0.17 |      0.94 |    0.00
SELECT "users".* FROM "users" WHERE "users"."id" = $1 LIMIT $2                                                                                                                                                                                                                                               |     313.51 |  7521 |    0.02 |    0.04 |      0.16 |    0.00

Просто хочу кратко отметить, что у меня та же проблема, и, боюсь, я не разбираюсь в PostgreSQL. Если мне нужно будет что-то искать, мне понадобятся более подробные инструкции. Извините.

Попробуйте выполнить VACUUM VERBOSE ANALYZE. Это также относится к вам, @eboehnisch. Следующий очень простой запрос, выполняющийся в среднем за 2 секунды, выглядит крайне странно:

Как было сказано в теме Обновление PostgreSQL 12, после обновления рекомендуется обновить статистику.

Попробовал VACUUM VERBOSE ANALYZE;. На что стоит обращать внимание в результатах?

Отлично, спасибо! Похоже, это решило проблему с почтальонами, которые бесконтрольно нагружали процессор. Это значительное улучшение.

Sidekiq всё ещё работает медленно, к сожалению, но лучше, чем до выполнения VACUUM VERBOSE ANALYZE;

Ничего особенного, если только это не сообщение об ошибке.

Производительность должна восстановиться сейчас.

УРА!

Теперь он должен успевать справляться с очередью в итоге.

Это, безусловно, улучшило ситуацию, но через некоторое время снова три процесса postmaster начали использовать 100% процессорного времени более минуты каждый.

Я бы сказал, подождите немного, потому что у вас, вероятно, есть очередь задач, накопленная за медленный период. Проверьте /sidekiq для статистики.

:smiley: Скорость действительно значительно выросла, похоже, проблема решена. Большое спасибо за помощь, @Falco! Я оставлю его работать ещё некоторое время и позже опубликую здесь обновление~

Попробуйте выполнить:

VACUUM FULL VERBOSE;

и (предполагая, что имя вашей базы данных — ‘discourse’, что является значением по умолчанию):

REINDEX DATABASE discourse;

Это может быть лучше, чем обычная переиндексация, но я не проверял это: PostgreSQL 12 update

Обе операции, перечисленные выше, создают блокировки, которые могут стать серьёзной проблемой на работающем сайте. Я рекомендую выполнить те, что указаны в разделе пост-апдейт-опциональные-задачи, поскольку, помимо высокой нагрузки на процессор, они не блокируют нормальные операции базы данных.

Запустите оба. Однако второй выдаст ошибку:

discourse=# REINDEX SCHEMA CONCURRENTLY public;
ERROR:  could not create unique index "index_users_on_username_lower_ccnew"
DETAIL:  Key (username_lower)=(marks) is duplicated.

Похоже, пора углубиться в PostgreSQL, найти и удалить эту запись.

Vacuuming в целом сработало, но я всё ещё наблюдаю пики каждые несколько минут, когда один-три процесса postmaster потребляют процессор в течение одной-двух минут каждый. Так что, видимо, есть ещё что-то.

Возможно ли откатиться до PostgreSQL 10?

Конечно, если у вас есть резервная копия, созданная до обновления. Однако вы потеряете все данные, созданные после этой резервной копии.

Гораздо лучше разобраться в этих проблемах, так как PostgreSQL 12 теперь является стандартом для любых новых установок.

Нет, это невозможно… мы навсегда переходим на PG-12.

см.:

Хорошо, чтобы подытожить: всё выглядит отлично, Postmaster значительно успокоился, а Sidekiq снова работает очень быстро.

Кратко о том, что сработало в моём случае (при имени базы данных по умолчанию ‘discourse’):

cd /var/discourse/
./launcher enter app
sudo -u postgres psql
\c discourse

Затем из консоли PostgreSQL были выполнены следующие команды. Каждая из них занимает некоторое время в зависимости от размера БД; первые две также вызывают высокую нагрузку на процессор:

VACUUM FULL VERBOSE;

REINDEX DATABASE discourse;

VACUUM VERBOSE ANALYZE;

Примечание: Я не заметил разницы, пока не выполнил команду VACUUM VERBOSE ANALYZE; по рекомендации @Falco, поэтому первые две команды могли оказаться излишними. Однако первые две, похоже, были ключевыми для решения этой проблемы в прошлом в предыдущей версии PostgreSQL.

Если во время выполнения REINDEX DATABASE discourse; вы получите ошибку типа ‘ERROR: deadlock detected’ — просто попробуйте запустить её снова, пока не сработает. Это случилось со мной в прошлый раз (в предыдущей версии PostgreSQL).

Существуют рекомендации по выполнению параллельной перестройки индексов вместо указанной выше: PostgreSQL 12 update

Однако обратите внимание, что @eboehnisch выше получил ошибку при выполнении параллельной перестройки индексов, см. выше.

Мы неоднократно сталкивались с этим при различных миграциях, поэтому, по-моему, стоит добавить это в скрипт миграции, @Falco

Я знаю, что это немного замедляет процесс, но оно того стоит — это сократит количество обращений в поддержку.

Примечание: слово VERBOSE здесь означает лишь то, что команда выводит информацию о ходе выполнения. Главное, чего не хватало, — это VACUUM ANALYZE. Перестроение индексов в основном служит для освобождения места.