PostgreSQL Errorlogging in die Stderr

Welche Log Optionen gibt es?

Postgres hat mehrere Möglichkeiten Logging zu betreiben: 

• Das Eventlog von Windows
• Als CSV in eine Datenbank
• Zu einem Syslog Server
• Und in die Stderr (bzw. in ein Logfile via Logging Collector)

Wie man sieht, gibt es einige Optionen mit unterschiedlichen Vor- und Nachteilen.

Ein Beispiel: Das Logging in die Stderr ist lückenlos und dafür designend keine Nachrichten zu verwerfen ,im Gegensatz zur Syslog-Variante. Jedoch hat man dadurch das Risiko, dass aufgrund extrem hoher Serverlast der entsprechende Prozess blockiert werden kann. Syslog würde in diesem Fall einfach Nachrichten verwerfen. (Mehr dazu in der Dokumentation am Ende des Artikels)
In diesem Artikel konzentrieren wir uns auf das Logging via Stderr und dem Logging Collector.

Aktivieren des Logging Collector

Zuerst muss das Logging aktiviert werden. Dies ist per Default aktiv, sofern man PostgreSQL mittels yum installiert hat. Das Aktivieren des Logging Collectors startet einen neuen Background Process der sich darum kümmert die Stderr in die entsprechenden Logfiles zu lenken und somit das Logging aktiviert.

Ausschlaggebend hierfür ist hier der „logging_collector“ Parameter.

postgres=# alter system set logging_collector=on;

postgres=# show logging_collector;
logging_collector
-------------------
 On

Hinweis: Nach Änderungen am Logging_collector Parameter muss das Cluster neu gestartet werden!

Wenn der Collector aktiv ist, sieht man im Parameter „log_directory“ den entsprechenden Pfad zum Logfile.

postgres=# show log_directory;
 log_directory
---------------
 log
(1 row)

Dieser Ordner ist im DATA-Directory (PGDATA) zu finden. Dieses könnt ihr entweder dem ps Prozessen entnehmen oder ebenfalls in Postgres abfragen:

Linux

postgres@TestHost [Test_Cluster]:~> ps -ef | grep postgres
postgres   933     1  0 Aug01 ?        00:00:08 /u01/posgresql_111/bin/postgres -D /u01/pgdata/pg4ora

Postgres

postgres=# SHOW data_directory;
   data_directory
--------------------
 /u01/pgdata/pg4ora

Eine Beispielkonfiguration

Nachfolgend werden einige Parameter vorgestellt und konfiguriert damit wir eine stabile Ausgangsposition haben. Danach muss system- und applikationsspezifisches Finetuning erfolgen.

Für unseren Fall haben wir einige Kriterien:

• Ein Logfile pro Tag
• Der Filename der Datei ist „alert_log_[Cluster_name]_%Y-%m-%d.log“
• Aufbewahrungszeitraum 31 Tage 
• Automatisches löschen nach Rotation
• Überwachung von DDLs (Bitte bei Ihnen vorher den Bedarf prüfen)
• Zeilen-Prefix beinhaltet: Timestamp, Datenbankname, Username und Remotehost/Port
• Es werden connects / Disconnetcs geloggt. (Bitte vorher den Bedarf prüfen)
• Zusätzlich sollen alle Statements geloggt werden, welche länger als 2 Sekunden laufen (Bitte vorher den Bedarf prüfen)

Zusätzlich unterscheidet sich das Einrichten des Parameters anhand eines Reload oder Restarts.
Reloads benötigen keine Downtime, Restarts hingegen schon.

Der Reload wird mit folgendem Befehl in Linux oder innerhalb der DB durchgeführt:

Linux

postgres@TestHost [Test_Cluster]: pg_ctl reload 

DB:
postgres=# select pg_reload_conf();
pg_reload_conf
----------------
 t
(1 row)

Parameterliste

Hier die Erklärung zu den Parametern mit Beispiel Outputs:

log_line_prefix
Formatierung des Formates jedes Log-Eintrags
 

Diese Liste ist unvollständig. Natürlich können noch deutlich mehr Präfixe genutzt werden. Hierzu hilft die weiter unten genannte Dokumentation weiter.

log_line_prefix = '%t <%e> <%d %u %r> %%'
 

Output:

2020-04-20 11:55:21 CEST <22003> < test_db postgres [local]> %ERROR:  smallint out of range

2020-04-20 11:55:21 CEST <22003> < test_db postgres [local]>% STATEMENT:  insert into scott.t1 VALUES (1111);
 

log_truncate_on_rotation
Wenn eine Rotation eintritt, wird das „alte Logfile“ gelöscht. (Nach „log_rotation_age“ Tagen)

log_rotation_age
Der Aufbewahrungszeitraum der Logs, bevor eine Logfilerotation eintritt. In unserem Fall geben wir 
dies als „[Integer]d“ an. Es funktionieren aber auch nur integer, die dann als Minuten gehandhabt 
werden

log_connections/disconnections
Überwachung über aufbauende bzw. abbauende Verbindungen:

Output

LOG:  received SIGHUP, reloading configuration files
LOG:  parameter "log_connections" changed to "on"
LOG:  parameter "log_disconnections" changed to "on"
[…]
LOG:  connection authorized: user=postgres database=TestDB
LOG:  disconnection: session time: 0:01:10.407 user=postgres database=TestDB host=[local]

log_statement
Welche Änderungen wurden vorgenommen? 

log_statement=’ddl’             #none,ddl,mod,all

• None = Es werden keine Informationen gesammelt
• Ddl = Alle DDLs wie create, alter und drop Statements werden protokolliert
• Mod = Alles, was DDL macht + datenmodifizierende Statements. beispielsweise insert, updates, deletes etc.. 
• All = loggt jedes Statement ausnahmslos. Mit Ausnahme von Statements, welche aufgrund von simplen Syntaxfehler nicht durchgehen. Der Grund hierfür ist, dass das logging erst nach dem ersten Parse stattfindet
   

Output

LOG:  parameter "log_statement" changed to "ddl"
[…]
LOG:  statement: drop table scott.t1;

Log_min_duration_statement 
Gibt das zeitliche Limit an, ab wann Statements geloggt werden

Output

[…]
2020-04-20 11:42:08 CEST <Test_DB postgres [local]> %LOG:  duration: 2451.407 ms  statement: select count(*) from scott.t1;
[…]

Mit dieser Grundkonfiguration deckt man bereits einiges ab und kann eine gewisse Zurückverfolgbarkeit gewährleisten, da die Files 31 Tage aufbewahrt werden.
Die Anzahl an konfigurierbaren Parametern ist hoch, sie lassen sich aus folgender Dokumentation entnehmen:
https://www.postgresql.org/docs/current/runtime-config-logging.html


Sie brauchen Unterstützung beim Finden der passenden Konfiguration, damit kein Fehler im Verborgenen bleibt,, wir helfen gerne weiter.