Langsamer Sidekiq + Postmaster mit 95%+ CPU (32 Kerne) nach Postgresql-Version-Upgrade

Unterstützung Installation
1

Also, ich habe heute ein Upgrade durchgeführt, und dabei scheint die PostgreSQL-Version aktualisiert worden zu sein. Seitdem ist dieses Problem (oder ein ähnliches) wieder aufgetreten (der alte Beitrag ist jetzt geschlossen):

Ich habe versucht, was dieses Problem zuvor gelöst hat:

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

und auch:

REINDEX DATABASE discourse;

Leider ohne Erfolg :upside_down_face:

Postmaster nutzt 95–100 % der 32 CPU-Kerne. Sidekiq arbeitet mit etwa 1 Job pro Sekunde.

Ich habe auch versucht, Redis zu leeren und das System erneut neu aufzubauen. Ich habe zwischen 12, 8 und 4 Unicorn Sidekiqs sowie Unicorn-Workern getestet.

Vor dem PostgreSQL-Upgrade lief alles mit 12 Unicorn-Workern und Sidekiqs wirklich stabil und reibungslos. Derzeit läuft Version 2.5.0.beta5, und ich glaube, vor dem Update war es 2.5.0.beta2.

:firstworldproblem:

2

Sie müssen prüfen, welche genauen Abfragen PostgreSQL ausführt, damit wir Vorschläge unterbreiten können.

Die Aktivierung von pg_stat_statements ist dafür sehr nützlich.

3

Danke @Falco – hier sind einige Statistiken. Lass mich wissen, wenn du mehr der Abfragen sehen möchtest, da sie am Ende abgeschnitten werden.

                                                                                                                                                     query                                                                                                                                                     | total_time | calls |   min   |  mean   |    max    | 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
4

Kurzer Hinweis: Ich habe das gleiche Problem – und leider keine Erfahrung mit PostgreSQL. Wenn ich etwas nachschauen soll, bräuchte ich etwas detailliertere Anweisungen. Entschuldigung.

5

Könntest du bitte einen vacuum verbose analyze versuchen? Das gilt auch für dich, @eboehnisch. Die folgende sehr einfache Abfrage, die durchschnittlich 2 Sekunden dauert, ist wirklich seltsam:

Wie im PostgreSQL 12-Update-Thema erwähnt, ist es nach dem Update ratsam, Statistiken zu generieren.

6

Ich habe VACUUM VERBOSE ANALYZE; ausgeführt. Worauf sollte ich in den Ergebnissen achten?

7

Super, danke! Ich denke, das hat das Problem gelöst, bei dem Postmaster-Prozesse durch den hohen CPU-Verbrauch außer Kontrolle gerieten. Das ist also eine deutliche Verbesserung.

Sidekiq ist leider immer noch langsam, aber besser als zuvor, bevor VACUUM VERBOSE ANALYZE; ausgeführt wurde.

8

Nichts Besonderes, es sei denn, es handelt sich um eine große Fehlermeldung.

Die Leistung sollte sich jetzt wieder erholen.

JUHUU!

Es sollte jetzt in der Lage sein, das Rennen zu gewinnen und die Warteschlange schließlich zu verarbeiten.

9

Dies hat die Situation zwar definitiv verbessert, aber nach einer Weile nutzten erneut drei postmaster-Prozesse jeweils über eine Minute lang 100 % der CPU.

10

Ich würde sagen, warte noch etwas, denn du hast wahrscheinlich eine Warteschlange, die du aus der ruhigen Phase heraus abarbeiten musst. Überprüfe /sidekiq für Statistiken.

11

:smiley: Die Geschwindigkeit hat sich wirklich deutlich erhöht, sieht so aus, als wäre es behoben. Vielen Dank für die Hilfe @Falco! Ich lasse es noch eine Weile laufen und poste später hier ein Update~

12

Versuchen Sie vielleicht Folgendes:

VACUUM FULL VERBOSE;

Und (unter der Annahme, dass Ihr Datenbankname ‘discourse’ ist, was der Standard ist):

REINDEX DATABASE discourse;

Dies könnte besser sein als eine normale Neuindizierung, aber ich habe es nicht getestet: PostgreSQL 12 update

13

Beide oben aufgeführten Operationen erzeugen Sperren, die auf einer Live-Seite wirklich problematisch sein können. Ich empfehle die unter post-update-optional-tasks aufgeführten Aufgaben, da diese – abgesehen von einer hohen CPU-Auslastung – den normalen Datenbankbetrieb nicht blockieren.

14

Führe beide aus. Letzteres meldet jedoch einen Fehler:

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

Ich vermute, es ist an der Zeit, mich mit PostgreSQL zu befassen, den Datensatz zu finden und zu löschen.

Das Vacuumieren hat mehr oder weniger geholfen, aber ich bekomme immer noch alle paar Minuten Spitzen, bei denen ein bis drei postmaster-Prozesse jeweils ein bis zwei Minuten lang CPU verbrauchen. Also gibt es wohl noch mehr.

15

Ist es möglich, auf PostgreSQL 10 zurückzukehren?

16

Klar, wenn du ein Backup vor dem Upgrade hast. Allerdings gehen alle seit dem Backup erstellten Daten verloren.

Es ist fast sicher besser, die Ursache dieser Probleme zu finden. Postgres12 ist mittlerweile der Standard für jede neue Installation.

17

Nein, das ist nicht möglich … wir wechseln dauerhaft zu PG12.

18

siehe:

19

Okay, um darauf zurückzukommen: Alles sieht weiterhin gut aus, Postmaster hat sich drastisch beruhigt und Sidekiq läuft wieder sehr schnell.

Zusammenfassung dessen, was in meinem Szenario funktioniert hat (mit dem Standard-Datenbanknamen ‘discourse’):

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

Anschließend wurden von der Postgres-Konsole aus jeweils die folgenden Befehle ausgeführt. Jeder Befehl benötigt je nach Datenbankgröße etwas Zeit; die ersten beiden verursachen zudem eine hohe CPU-Auslastung:

VACUUM FULL VERBOSE;

REINDEX DATABASE discourse;

VACUUM VERBOSE ANALYZE;

Hinweis: Ich habe erst einen Unterschied bemerkt, nachdem VACUUM VERBOSE ANALYZE; gemäß der Empfehlung von @Falco ausgeführt wurde. Daher waren die ersten beiden Befehle möglicherweise nicht notwendig. Allerdings scheinen die ersten beiden Schlüsselfaktoren gewesen zu sein, um dieses Problem in der Vergangenheit in der vorherigen Version von PostgreSQL zu beheben.

Falls Sie während REINDEX DATABASE discourse; einen Fehler wie ‘ERROR: deadlock detected’ erhalten, versuchen Sie einfach, den Befehl erneut auszuführen, bis er erfolgreich ist. Das ist mir beim letzten Mal (in der vorherigen PostgreSQL-Version) ebenfalls passiert.

Es gibt Empfehlungen, stattdessen eine gleichzeitige Neuindizierung (concurrent reindex) durchzuführen: PostgreSQL 12 update

Beachten Sie jedoch, dass @eboehnisch oben einen Fehler bei der gleichzeitigen Neuindizierung erhielt, siehe oben.

20

Wir haben dies bei verschiedenen Migrationen oft genug gesehen, daher sollten wir es meiner Meinung nach in das Migrations-Skript aufnehmen, @Falco …

Ich weiß, dass es die Abläufe erheblich verlangsamt, aber es lohnt sich und wird den Supportaufwand reduzieren.

Hinweis… Das Wort VERBOSE bedeutet hier lediglich, dass während der Ausführung Ausgaben erfolgen. Das Wichtigste, das fehlte, war VACUUM ANALYZE. Die Neuindizierung dient hauptsächlich der Wiederherstellung von Speicherplatz.