Der Blog-Post Postgres log_statement='all' should be your default von Greg Sabino Mullane hat mich ermutigt unsere Logging-Strategie für die von uns genutzten und betreuten Datenbanken zu überdenken.
Es ist besser damit zu starten alles zu loggen und dann je nach Bedarf anzupassen als umgekehrt.
In Kombination mit der Postgres-Dokumentation Abschnitt 18.8.4 kann ich folgende Einstellungen empfehlen:
log_statement = 'all'
log_destination = 'csvlog'
logging_collector = on
log_directory = '/var/www/logs/pgsql'
log_filename = 'pgsql-%Y-%m-%d.log'
log_file_mode = 0644
log_truncate_on_rotation = on
log_rotation_age = 1d
log_rotation_size = 0
log_connections = on
log_disconnections = on
log_duration = on
log_hostname = on
log_timezone = 'UTC'
Wie man an log_destination = 'csvlog' sehen kann, haben wir uns für die Ausgabe in CSV-Dateien entschieden, weil man diese leicht für eine Auswertung in die Datenbank einlesen kann. Wenn csvlog eingestellt ist, muss auch der logging_collector auf on stehen. Dies erfordert auch einen Neustart des Servers. reload mit pg_ctl reicht nicht. Das Statement zum Erzeugen der Tabelle, in die die CSV-Dateien eingelesen werden, sieht laut Doku wie folgt aus:
CREATE TABLE postgres_log (
  log_time timestamp(3) with time zone,
  user_name text,
  database_name text,
  process_id integer,
  connection_from text,
  session_id text,
  session_line_num bigint,
  command_tag text,
  session_start_time timestamp with time zone,
  virtual_transaction_id text,
  transaction_id bigint,
  error_severity text,
  sql_state_code text,
  message text,
  detail text,
  hint text,
  internal_query text,
  internal_query_pos integer,
  context text,
  query text,
  query_pos integer,
  location text,
  application_name text,
  PRIMARY KEY (session_id, session_line_num)
);

Zum Einlesen der Datein bietet sich ein Script an, welches ein mal am Tag durch einen Cronjob ausgeführt wird und ein COPY-Statement beinhaltet.
PGSQL_SERVER=$(docker inspect --format '{{ .NetworkSettings.IPAddress }}' pgsql-server)
PGSQL_USER=kvwmap
PGSQL_PASSWORD=secret
PGSQL_LOGFILE=/var/www/logs/pgsql/pgsql-$(date -d "yesterday" '+%Y-%m-%d').csv

if [ -f $PGSQL_LOGFILE ]; then
  result=$(PGPASSWORD=$PGSQL_PASSWORD psql -h $PGSQL_SERVER -U $PGSQL_USER -c "COPY postgres_log FROM '${PGSQL_LOGFILE}' WITH csv" postgres)
  if [[ "$result" == *"COPY "* ]] ; then
    gzip $PGSQL_LOGFILE
  fi
fi

Im ersten Abschnitt werden Konstanten gesetzt. Server, User und Passwort muss jeder selber setzen. Bei uns läuft die Datenbank in einem Docker-Container und daher wird die aktuelle IP-Adresse des Servers von dem Docker-Container über einen vorgegebenen Namen abgefragt. Das Logfile hat ein Namensschema mit einem täglich wechselnden Datum, weil wir ja täglich einlesen wollen und die Einstellung log_rotation_age = 1d muss deshalb auch genau auf 1 Tag stehn. Damit wirklich alles von einem Tag in dieser Datei mit dem Datum steht, muss auch log_rotation_size = 0 sein. Sonst würden evtl. mehrere Dateien pro Tag angelegt und auch eingelesen werden müssen. Wenn man in CSV-Dateien ausgibt ist log_line_prefix irrelevant, weil sowieso immer alles ausgegeben wird. Im Einlesescript werden die Dateien komprimiert, wenn die Rückgabe vom COPY-Statement den Text 'COPY ' beinhaltet. Aus pgsql-2018-01-12.csv wird dann z.B. pgsql-2018-01-12.gz
Der log_file_mode wurde auf 644 gesetzt, damit der postgres lesend auf die CSV-Datei zugreifen kann. Wichtig ist auch, dass postgres auf das in log_directory eingestellte Verzeichnis schreibend und lesend zugreifen können muss.
log_truncate_on_rotation = on bedeutet nur, dass die Datei überschrieben wird, wenn sie vorhanden ist. Das kann ohne manuellen Eingriff nur nach einem Jahr passieren, aber da wir die Dateien sowieso gzippen, sollte das nicht vorkommen. Die Parameter log_connections, log_disconnections, log_duration, und log_hostname sorgen dafür, dass auch diese Informationen gelogged werden.
log_timezone = 'UTC' sorgt dafür, dass die Zeitstempel in UTC sind. Jenachdem wann der Cron-Job triggert, kann es also sein, dass z.B. in der Datei von einem Tag die erste Stunde vom Folgetag mit enthalten ist. Das ist aber irrelevant solange man das zwischendurch nicht ändert.
Hat man nun alle logs in einer Tabelle kann man einfach Filtern bzw. Abfragen was einen interessiert. Zunächst wird sicher interessant sein was man überhaupt gebrauchen kann. Man wird schnell erkennen, dass einige Ausgaben weniger andere mehr nutztlich sind. Welche Sichten man sich baut und was man ggf. auslagert oder löscht wird die Zeit dann mit sich bringen. Wie aber oben schon erwähnt. Wenn ein Problem aufgetreten ist, kann man genau nachvollziehen was passiert ist.