9 Minuten Lesezeit (1776 Worte)

Zahlen, Daten, Fakten? Die PostgreSQL Erweiterung „pg_stat_monitor“ im Überblick

Dienstag, 19. Juli 2022

In den vorangegangenen PostgreSQL-Beiträgen haben wir über die Erweiterung „pg_profile“ und das Tool „pgBadger“ gesprochen. Beides sind ausgesprochen „wertvolle“ Tools, um der Performance einer Datenbank auf den Grund zu gehen, bzw. um Probleme zu analysieren. Heute schauen wir uns die von Percona entwickelte Extension „pg_stat_monitor“ an. Der Ansatz, dieser von Percona entwickelten und gepflegten Erweiterung ist es, einen ganzheitlichen Überblick bei der Bewertung von SQL-Queries zu geben. Dies geschieht mittels einer einzigen View („pg_stat_monitor“). Die Funktionalität ist auf den ersten Blick ähnlich der vielfach bekannten Extension „pg_stat_statements“. Im Detail gibt es jedoch einige Unterschiede und / oder Verbesserungen. Wir wollen die Erweiterung an dieser Stelle kurz mit ihren wesentlichen Eigenschaften vorstellen.

Die Installation, das kleine 1 x 1

Die Installation der Extension ist nicht kompliziert. Zunächst binden wir das Percona Software Repository auf unserem Testserver ein, um das entsprechende Paket mit der Erweiterung installieren zu können:

bash> wget https://repo.percona.com/apt/percona-release_latest.generic_all.deb
bash> dpkg -i percona-release_latest.generic_all.deb
bash> apt update
bash>percona-release setup ppg14

Jetzt können wir gezielt die benötigte Extension installieren und in den Cluster (Postgres-Server) einbinden.

apt install percona-pg-stat-monitor14

Die Extension wird, wie bei PostgreSQL üblich, installiert. Die Konfiguration des Servers muss zusätzlich für die Verwendung dieses Tools angepasst werden, damit die entsprechende Library der Extension mit dem Start des Clusters geladen wird (Parameter "shared_preload_libraries"):

postgres=# create extension pg_stat_monitor;
CREATE EXTENSION

postgres=# ALTER SYSTEM SET shared_preload_libraries = 'pg_stat_monitor,pg_stat_statements';
ALTER SYSTEM

Nach dem Reboot des PostgreSQL-Clusters steht uns nun die Erweiterung zur Verfügung:

postgres=# select * from pg_extension;
  oid  |      extname       | extowner | extnamespace | extrelocatable | extversion | extconfig | extcondition
-------+--------------------+----------+--------------+----------------+------------+-----------+--------------
 13743 | plpgsql            |       10 |           11 | f              | 1.0        |           |
 16384 | pg_stat_monitor    |       10 |         2200 | t              | 1.0        |           |
 16404 | pg_stat_statements |       10 |         2200 | t              | 1.9        |           |
(3 rows)

Der Zahlenraum

Nach der Installation stehen uns zwei Tabellen (Views) zur Verfügung. In der Tabelle „pg_stat_monitor“ werden die Ergebnisse der Query-Aktivität des Clusters festgehalten. Die Tabelle „pg_stat_monitor_settings“ definiert, wie und welche Daten protokolliert werden. Wichtig ist zu verstehen, dass die Ergebnisse, bzw. Metriken der einzelnen Queries, nicht permanent fortgeschrieben werden (die entsprechenden Metriken steigen nicht permanent monoton an). Dies ist beispielsweise bei der Erweiterung „pg_stat_statements“ der Fall und unterscheidet damit beide Lösungen signifikant. Vielmehr stellt uns „pg_stat_monitor“ per Default 10 sogenannte „Buckets“ (Eimer) zur Verfügung, die „ab Werk“ jeweils 60 Sekunden aufnehmen. Der Beobachtungszeitraum besteht somit aus 10 x 60 Sekunden (10 Minuten).

Im Folgenden sehen wir uns die Daten für ein immer wiederkehrendes SELECT mit der ID 'BB08F6556B678B54' an, um diese Struktur von „Buckets“ zu verstehen. Die Query wurde von der bekannten Benchmark-Suite „pgbench“ erzeugt, welche in einer Schleife wieder und wieder über einen längeren Zeitraum gegen unseren Testserver-Cluster gelaufen ist.

postgres=# select bucket, bucket_start_time, calls, queryid, query, total_exec_time, mean_exec_time from pg_stat_monitor where queryid = 'BB08F6556B678B54';
 bucket |  bucket_start_time  | calls |     queryid      |                 query                 | total_exec_time | mean_exec_time
--------+---------------------+-------+------------------+---------------------------------------+-----------------+----------------
      7 | 2022-05-12 10:07:00 |    12 | BB08F6556B678B54 | select count(*) from pgbench_branches |          0.6685 |         0.0557
      8 | 2022-05-12 10:08:00 |    12 | BB08F6556B678B54 | select count(*) from pgbench_branches |          0.7346 |         0.0612
      9 | 2022-05-12 10:09:00 |    12 | BB08F6556B678B54 | select count(*) from pgbench_branches |          0.5955 |         0.0496
      0 | 2022-05-12 10:10:00 |    12 | BB08F6556B678B54 | select count(*) from pgbench_branches |          0.5876 |          0.049
      1 | 2022-05-12 10:11:00 |    12 | BB08F6556B678B54 | select count(*) from pgbench_branches |           0.692 |         0.0577
      2 | 2022-05-12 10:12:00 |    12 | BB08F6556B678B54 | select count(*) from pgbench_branches |          1.0027 |         0.0836
      3 | 2022-05-12 10:13:00 |    12 | BB08F6556B678B54 | select count(*) from pgbench_branches |          0.7638 |         0.0637
      4 | 2022-05-12 10:14:00 |    12 | BB08F6556B678B54 | select count(*) from pgbench_branches |          0.7361 |         0.0613
      5 | 2022-05-12 10:15:00 |    12 | BB08F6556B678B54 | select count(*) from pgbench_branches |           0.848 |         0.0707
      6 | 2022-05-12 10:16:00 |     1 | BB08F6556B678B54 | select count(*) from pgbench_branches |          0.0346 |         0.0346

Wir sehen die zyklische Beschreibung unserer „Buckets“ (0 - 9) und erkennen auch das oben beschriebene zeitliche Intervall von 10 Minuten (10:07:00 - 10:16:59; Achtung: Die Spalte „bucket_start_time“ beschreibt den Startzeitpunkt, ab dem begonnen (!) wurde das „Bucket“ zu beschreiben).

Zusätzlich haben wir der Auswertung einige wenige, exemplarische Metriken hinzugefügt („total_exec_time“ 🠖 summierte Gesamtlaufzeit der Statements; „mean_exec_time“ 🠖 durchschnittliche Laufzeit eines Statements).

Natürlich sind viele weitere interessante Metriken über diese „View“ verfügbar.

Welche Metriken zur Verfügung stehen (es sind übrigens deutlich mehr als bei der Extension „pg_stat_statements“), kann der untenstehenden Tabellenstruktur entnommen werden:

postgres=# \d pg_stat_monitor
                      View "public.pg_stat_monitor"
       Column        |       Type       | Collation | Nullable | Default
---------------------+------------------+-----------+----------+---------
 bucket              | bigint           |           |          |
 bucket_start_time   | text             |           |          |
 userid              | regrole          |           |          |
 datname             | name             |           |          |
 client_ip           | inet             |           |          |
 queryid             | text             |           |          |
 toplevel            | boolean          |           |          |
 top_queryid         | text             |           |          |
 query               | text             |           |          |
 comments            | text             |           |          |
 planid              | text             |           |          |
 query_plan          | text             |           |          |
 top_query           | text             |           |          |
 application_name    | text             |           |          |
 relations           | text[]           |           |          |
 cmd_type            | integer          |           |          |
 cmd_type_text       | text             |           |          |
 elevel              | integer          |           |          |
 sqlcode             | text             |           |          |
 message             | text             |           |          |
 calls               | bigint           |           |          |
 total_exec_time     | double precision |           |          |
 min_exec_time       | double precision |           |          |
 max_exec_time       | double precision |           |          |
 mean_exec_time      | double precision |           |          |
 stddev_exec_time    | double precision |           |          |
 rows_retrieved      | bigint           |           |          |
 plans_calls         | bigint           |           |          |
 total_plan_time     | double precision |           |          |
 min_plan_time       | double precision |           |          |
 max_plan_time       | double precision |           |          |
 mean_plan_time      | double precision |           |          |
 stddev_plan_time    | double precision |           |          |
 shared_blks_hit     | bigint           |           |          |
 shared_blks_read    | bigint           |           |          |
 shared_blks_dirtied | bigint           |           |          |
 shared_blks_written | bigint           |           |          |
 local_blks_hit      | bigint           |           |          |
 local_blks_read     | bigint           |           |          |
 local_blks_dirtied  | bigint           |           |          |
 local_blks_written  | bigint           |           |          |
 temp_blks_read      | bigint           |           |          |
 temp_blks_written   | bigint           |           |          |
 blk_read_time       | double precision |           |          |
 blk_write_time      | double precision |           |          |
 resp_calls          | text[]           |           |          |
 cpu_user_time       | double precision |           |          |
 cpu_sys_time        | double precision |           |          |
 wal_records         | bigint           |           |          |
 wal_fpi             | bigint           |           |          |
 wal_bytes           | numeric          |           |          |
 state_code          | bigint           |           |          |
 state               | text             |           |          |

Inhaltliche Erklärungen der Attribute können der aktuellen Dokumentation entnommen werden:

https://github.com/percona/pg_stat_monitor/blob/main/docs/REFERENCE.md

Beschreibende Statistik

Eine besondere Bedeutung hat die Spalte „resp_calls“, welche ein Histogramm der Query, für den Zeitraum eines „Buckets“ enthält. Wir schauen uns das Laufzeitverhalten des oben bereits genutzten SELECTs nun detaillierter an.

postgres=# select bucket, bucket_start_time, calls, total_exec_time, mean_exec_time, resp_calls  from pg_stat_monitor where queryid = 'BB08F6556B678B54' and bucket = 7;
 bucket |  bucket_start_time  | calls | total_exec_time | mean_exec_time |       resp_calls
--------+---------------------+-------+-----------------+----------------+------------------------
      7 | 2022-05-12 10:27:00 |    12 |          0.5604 |         0.0467 | {12,0,0,0,0,0,0,0,0,0}

Um die Darstellung der Histogramme etwas ansprechender zu gestalten, wird die Funktion „histogram“ mitgeliefert. Diese stellt die Ausführungszeiten als Balkendiagramm dar. Die einzelnen Balken repräsentieren dabei die unterschiedlichen Zeiten in Millisekunden-Klassen („range“). In unserem Beispiel wurde die Query in diesem Zeitfenster meistens (10x) innerhalb der Klasse von 0 bis 3 Millisekunden ausgeführt. Nur in wenigen Fällen (2x) hat die Ausführung etwas länger gedauert (3 – 10 Millisekunden).

select * from histogram(7, 'BB08F6556B678B54') AS a(range TEXT, freq INT, bar TEXT);
postgres=# select * from histogram(7, 'BB08F6556B678B54') AS a(range TEXT, freq INT, bar TEXT);
       range        | freq |                                            bar
--------------------+------+--------------------------------------------------------------------------------------------
  (0 - 3)}          |   12 | ■■■■■■■■■■■■■■■■■■■■■■■■
  (3 - 10)}         |    2 | ■■■■■■
  (10 - 31)}        |    0 |
  (31 - 100)}       |    0 |
  (100 - 316)}      |    0 |
  (316 - 1000)}     |    0 |
  (1000 - 3162)}    |    0 |
  (3162 - 10000)}   |    0 |
  (10000 - 31622)}  |    0 |
  (31622 - 100000)} |    0 |
(10 rows)

Immer schön dem Plan folgen?

Für den Fall, dass schwankende Ausführungszeiten beobachtet werden (Verteilung des Statements auf unterschiedliche Histogramm-Klassen), kann dies verschiedene Ursachen haben. Beispielsweise könnte dieses Verhalten an unterschiedlichen Ausführungsplänen liegen, die zur Ausführung der Query genutzt wurden. Auch diese Pläne können im Bedarfsfall zusätzlich durch die „Extension“ protokolliert werden.

Dazu muss die Konfiguration angepasst und der Cluster neu gestartet werden:

postgres=# alter system set pg_stat_monitor.pgsm_enable_query_plan=on;
ALTER SYSTEM

Ab diesem Moment werden pro Ausführung einer Query, die Pläne ebenfalls gespeichert, können abgerufen und im Bedarfsfall auch über die „Buckets“ (und damit das Zeitfenster unseres Beobachtungszeitraumes) verglichen werden.

Im unten stehenden Beispiel haben wir, aus Gründen der Übersichtlichkeit, den Ausführungsplan aus lediglich einem Bucket dargestellt.

postgres=# select bucket, bucket_start_time, query_plan from pg_stat_monitor where queryid = '8F863D27E005EBE2' and bucket = 0 limit 1;
 bucket |  bucket_start_time  |                         query_plan
--------+---------------------+------------------------------------------------------------
      0 | 2022-05-12 10:40:00 | Index Scan using pgbench_accounts_pkey on pgbench_accounts+
        |                     |   Index Cond: (aid = 203561)

Fazit

„pg_stat_monitor“ ist eine weitere sinnvolle Extension, um Performance-Problemen auf den Grund zu gehen. Wer sich bereits mit „pg_stat_statements“ beschäftigt hat, sollte auf jeden Fall einen „Blick riskieren“ und die beiden Erweiterungen gegenüberstellen und vergleichen. Gerade das „Werkzeug“ der Histogramme ist eine nützliche Ergänzung und kann im Bedarfsfall extrem nützlich sein.