Starting with Pg – where are logs?

Just so that it will be perfectly clear: the logs I have in mind are the ones for DBAs to read – with slow queries, errors, and other interesting information.

So, how does one find them?

If you can connect to PostgreSQL, you can get settings from there, and usually, you will not even need to be superuser.

If you can't connect to PostgreSQL, you'll have to dig in config files to find out the values. I described how to do it in previous posts:

First thing that we need to check is log_destination.

It can have four different values: eventlog, syslog, stderr, and csvlog.

What do they mean?

log_destination value: eventlog

This is setting that is only for Windows hosts. There is more information about it in documentation.

log_destination value: syslog

In Unix-ish systems there is a thing called syslog. You send text there, and syslog daemon does something with them. Depending on configuration it can write these messages to one or more files, ignore, or even send to remote syslog server (centralized log storage).

Aside from logged line, syslog also uses two additional parameters:

  • facility – basically a broad bucket – what kind of message is it. PostgreSQL, by default, uses local0, but you can change it with syslog_facility config variable.
  • ident – a string that should generally be name of program that caused this line. Default is postgres, and you can change it with syslog_ident config variable.

Going through configuration of all possible syslog daemons is a no-go, but let's look at some common scenarios.

For now, let's assume that you're using local0 facility.

On Linux, one of the popular syslog daemons is rsyslog. You can check if you're running it by:

=$ ps -C rsyslogd
    PID TTY          TIME CMD
    897 ?        00:00:06 rsyslogd

If that's the case, it's configuration is in /etc/rsyslog.conf file, and, optionally, in any files with .conf extension in /etc/rsyslog.d/ directory.

In there, you're looking for lines that look like:

  • local0.* /path/to/logfile
  • *.* /path/to/logfile

The first thing is facilities, dot, and priority (basically log level). * means everything.

For example in my rsyslog configuration I have:

=# cat rsyslog.conf rsyslog.d/*.conf | grep -E '^(local0|\*)'
*.*;auth,authpriv.none          -/var/log/syslog
*.emerg                         :omusrmsg:*

Which means that all messages are logged to /var/log/syslog, and messages with emerg priority will also get delivered via “messages" to all users.

Given lack of specialized entry for local0, I can guess that logs go to /var/log/syslog.

To test it, let's run:

$ select 'test syslog', 1/0;
ERROR:  division by zero

and now, I can:

=$ sudo grep 'test syslog' /var/log/syslog
2021-03-03T22:31:45.383057+01:00 korsarz postgres[3419182]: [4-1] 2021-03-03 22:31:45.382 CET depesz@depesz 3419182 [local] LOG:  statement: select 'test syslog', 1/0;
2021-03-03T22:31:45.383225+01:00 korsarz postgres[3419182]: [5-2] 2021-03-03 22:31:45.382 CET depesz@depesz 3419182 [local] STATEMENT:  select 'test syslog', 1/0;

In case of Mac, it seems that syslog is handled by asl daemon, with configuration in /etc/asl.conf. Sample line looks like:

? [= Facility local0] file pg.log

This redirects all local0 messages to /var/log/pg.log.

Great, log found 🙂

log_destination value: stderr

Now, this is more interesting.

First thing we need to check now is logging_collector config variable.

This is boolean option, can be only on or off:

log_destination value: stderr, logging_collector value: on

This means that PostgreSQL handles writes to logs. To see where the logs really go we need to consult two options:

  • log_directory – this is the directory that will store logs, it defaults to log, which means that it will log directory within data_directory. You can set it to value starting with / to use absolute paths.
  • log_filename – this is template how the log files should be named. Default value is postgresql-%Y-%m-%d_%H%M%S.log. All those %* parts are simply strftime conversions.

With these settings, I can:

=$ psql -X -c "select name, setting from pg_settings where name in ( 'log_directory', 'data_directory', 'log_filename' )"
      name      |            setting             
----------------+--------------------------------
 data_directory | /home/pgdba/data
 log_directory  | log
 log_filename   | postgresql-%Y-%m-%d_%H%M%S.log
(3 rows)
 
=$ sudo ls -l /home/pgdba/data/log/
total 51296
-rw------- 1 pgdba pgdba   930378 Mar  1 19:39 postgresql-2021-03-01_110951.log
-rw------- 1 pgdba pgdba    51869 Mar  2 18:34 postgresql-2021-03-02_000000.log
-rw------- 1 pgdba pgdba 51530178 Mar  3 22:43 postgresql-2021-03-03_000000.log

New log is created on PostgreSQL start, or when logging_collector will decide that it needs to rotate to new logfile. This rotation process can be configured using log_rotation_age, log_rotation_size, and log_truncate_on_rotation options.

For example, if I'd set:

log_rotation_age = '1d'
log_rotation_size = '100M'
log_truncate_on_rotation = off

PostgreSQL will switch to new log every 24 hours, and additionally, once current log will contain 100MB of data. If newly generated filename would already exist (because, for example, it didn't change from previous), I want to keep it's data, instead of truncating file.

This can be used to keep only small subset of logs, for example:

log_rotation_age = '1h'
log_rotation_size = '0'
log_truncate_on_rotation = on
log_filename = 'postgresql-%a-%H.log'

Will rotate logfile every hour, but filenames will be based on day of week, and hour, so there will be only 7 * 24 of them, like:

  • postgresql-Wed-22.log
  • postgresql-Wed-11.log
  • postgresql-Wed-00.log
  • postgresql-Tue-13.log
  • postgresql-Tue-02.log
  • postgresql-Mon-15.log
  • postgresql-Mon-04.log
  • postgresql-Sun-17.log
  • postgresql-Sun-06.log
  • postgresql-Sat-19.log
  • postgresql-Sat-08.log

and, whenever after rotation Pg will find that the logfile exists, it will truncate it (after all, it's week old data).

log_destination value: stderr, logging_collector value: off

With this setting, and log_destination set to stderr, Pg will simply write the logs to STDERR for something else to handle it.

This is pretty common, for example, with Debian/Ubuntu packaged PostgreSQL's.

So, what's going on with logs then? Well, if you're on such system, with prepackaged Pg, you can try:

=$ sudo pg_lsclusters 
Ver Cluster Port Status Owner    Data directory              Log file
13  main    5432 online postgres /var/lib/postgresql/13/main /var/log/postgresql/postgresql-13-main.log

This clearly shows where the log goes.

But what if it's not that?

Well, let's find pid of main Pg process. It's inside data_directory, in file named postmaster.pid, so:

=$ psql -qAtX -c 'show data_directory'
/home/pgdba/data
 
=$ sudo head -n 1 /home/pgdba/data/postmaster.pid
3500043

With this information we can check where stderr goes:

=$ sudo lsof -a -p 3500043 -d 2
COMMAND      PID  USER   FD   TYPE DEVICE SIZE/OFF     NODE NAME
postgres 3500043 pgdba    2w   REG  253,0      622 63833987 /home/pgdba/logfile

The thing is that it is also possible that you'll see something like this:

COMMAND      PID  USER   FD   TYPE DEVICE SIZE/OFF NODE NAME
postgres 3504632 pgdba    2u   CHR 136,20      0t0   23 /dev/pts/20

In this case logs go directly to some terminal. You can find who is using this terminal, and how:

=$ ps uw t pts/20
USER         PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
pgdba    3436554  0.0  0.0  13964  5784 pts/20   Ss+  22:39   0:00 -bash

In any way – you know where the log is, though if it's logging to terminal, you might have last X lines, depending on size of scrollback in the terminal.

log_destination value: csvlog

This is pretty interesting option.

It depends on logging_collector to be enabled, and is also using log_directory, log_filename, and other options listed for log_destination = ‘stderr' with logging_collector = on.

With these settings:

  • log_destination = ‘csvlog'
  • log_directory = ‘log'
  • log_filename = ‘postgresql-%Y-%m-%d_%H%M%S.log'
  • logging_collector = ‘on'

When I restarted PostgreSQL, in my log directory I saw two files:

=$ ls -l data/log/
total 8
-rw------- 1 pgdba pgdba 1711 Mar  3 23:18 postgresql-2021-03-03_231732.csv
-rw------- 1 pgdba pgdba  174 Mar  3 23:17 postgresql-2021-03-03_231732.log

The .log one, is not really interesing – it contains information that got logged before switching to csvlog:

=$ cat data/log/postgresql-2021-03-03_231732.log 
2021-03-03 23:17:32.044 CET @ 3519029  LOG:  ending log output to stderr
2021-03-03 23:17:32.044 CET @ 3519029  HINT:  Future log output will go to log destination "csvlog".

but the .csv file is much more interesting. It contains normal logs, but in a format that you can parse automatically – as it's normal csv:

=$ head -n 1 data/log/postgresql-2021-03-03_231732.csv 
2021-03-03 23:17:32.044 CET,,,3519029,,60400afc.35b235,1,,2021-03-03 23:17:32 CET,,0,LOG,00000,"ending log output to stderr",,"Future log output will go to log destination ""csvlog"".",,,,,,,"","postmaster",

With this in place, I can:

=$ 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,
  backend_type text,
  leader_pid integer,
  PRIMARY KEY (session_id, session_line_num)
);
 
=$ copy postgres_log from 'log/postgresql-2021-03-03_231732.csv' WITH csv;
 
=$ select * from postgres_log order by random() limit 1 \gx
─[ RECORD 1 ]──────────┬───────────────────────────────────────────────
log_time               │ 2021-03-03 23:17:32.045+01
user_name              │ [null]
database_name          │ [null]
process_id             │ 3519029
connection_from        │ [null]
session_id             │ 60400afc.35b235
session_line_num       │ 3
command_tag            │ [null]
session_start_time     │ 2021-03-03 23:17:32+01
virtual_transaction_id │ [null]
transaction_id         │ 0
error_severity         │ LOG
sql_state_code         │ 00000
message                │ listening on IPv4 address "0.0.0.0", port 5140
detail                 │ [null]
hint                   │ [null]
internal_query         │ [null]
internal_query_pos     │ [null]
context                │ [null]
query                  │ [null]
query_pos              │ [null]
location               │ [null]
application_name       │ 
backend_type           │ postmaster
leader_pid             │ [null]

Please just note that format of csvlog changes from version to version, and if you want to load it to database, use appropriate create table from your version of documentation

And that wraps it. Hope you'll find it useful.

One thought on “Starting with Pg – where are logs?”

  1. Thank you, very useful article. Little additition.
    Since v10, in a case of rotation of logs, when logging_collector is on, we can use pg_current_logfile() to determine current log file name.

Leave a Reply

Your email address will not be published.

This site uses Akismet to reduce spam. Learn how your comment data is processed.