PostgreSQL DBA(151) - pgAdmin（log_XXX parameter：where）

本节介绍了与日志相关的配置参数log_XXX。

概览

在新initdb的数据库上查询pg_settings，可查询PostgreSQL中与log的参数包括：

[test@localhost ~]$ psql
Expanded display is used automatically.
psql (12.1)
Type "help" for help.
[local:/var/run/test]:5000 test@testdb=# select category,name,setting from pg_settings where name like 'log%' order by category;
After canonicalize_qual()
   {OPEXPR 
   :opno 1209 
   :opfuncid 850 
   :opresulttype 16 
   :opretset false 
   :opcollid 0 
   :inputcollid 100 
   :args (
      {VAR 
      :varno 4 
      :varattno 1 
      :vartype 25 
      :vartypmod -1 
      :varcollid 100 
      :varlevelsup 0 
      :varnoold 4 
      :varoattno 1 
      :location -1
      }
      {CONST 
      :consttype 25 
      :consttypmod -1 
      :constcollid 100 
      :constlen -1 
      :constbyval false 
      :constisnull false 
      :location 62 
      :constvalue 8 [ 32 0 0 0 108 111 103 37 ]
      }
   )
   :location 57
   }
RELOPTINFO (a): rows=5 width=96
  baserestrictinfo: a.name ~~ log%
  path list:
  FunctionScan(a) rows=5 cost=0.00..12.50
  cheapest parameterized paths:
  FunctionScan(a) rows=5 cost=0.00..12.50
  cheapest startup path:
  FunctionScan(a) rows=5 cost=0.00..12.50
  cheapest total path:
  FunctionScan(a) rows=5 cost=0.00..12.50
               category               |            name             |            setting             
--------------------------------------+-----------------------------+--------------------------------
 Reporting and Logging / What to Log  | log_lock_waits              | off
 Reporting and Logging / What to Log  | log_checkpoints             | off
 Reporting and Logging / What to Log  | log_connections             | off
 Reporting and Logging / What to Log  | log_timezone                | PRC
 Reporting and Logging / What to Log  | log_temp_files              | -1
 Reporting and Logging / What to Log  | log_disconnections          | off
 Reporting and Logging / What to Log  | log_duration                | off
 Reporting and Logging / What to Log  | log_error_verbosity         | default
 Reporting and Logging / What to Log  | log_statement               | none
 Reporting and Logging / What to Log  | log_replication_commands    | off
 Reporting and Logging / What to Log  | log_autovacuum_min_duration | -1
 Reporting and Logging / What to Log  | log_hostname                | off
 Reporting and Logging / What to Log  | log_line_prefix             | %m [%p] 
 Reporting and Logging / When to Log  | log_min_duration_statement  | -1
 Reporting and Logging / When to Log  | log_min_error_statement     | error
 Reporting and Logging / When to Log  | log_min_messages            | warning
 Reporting and Logging / When to Log  | log_transaction_sample_rate | 0
 Reporting and Logging / Where to Log | log_destination             | stderr
 Reporting and Logging / Where to Log | log_filename                | postgresql-%Y-%m-%d_%H%M%S.log
 Reporting and Logging / Where to Log | logging_collector           | off
 Reporting and Logging / Where to Log | log_truncate_on_rotation    | off
 Reporting and Logging / Where to Log | log_rotation_size           | 10240
 Reporting and Logging / Where to Log | log_file_mode               | 0600
 Reporting and Logging / Where to Log | log_rotation_age            | 1440
 Reporting and Logging / Where to Log | log_directory               | log
 Statistics / Monitoring              | log_statement_stats         | off
 Statistics / Monitoring              | log_planner_stats           | off
 Statistics / Monitoring              | log_executor_stats          | off
 Statistics / Monitoring              | log_parser_stats            | off
(29 rows)
[local:/var/run/test]:5000 test@testdb=#

可以看到，日志直接输出在控制台上，而log_打头的参数有29个，下面从where、when、what这几个维度来解析这些参数，本节是第一部分，介绍where。

log：where

与”where”这个维度有所相关的日志参数包括log_directory、log_destination、log_filename、log_file_mode。
log_directory
默认值为log，是一个相对路径，实际的绝对路径是$PGDATA/log，当然也可以使用/打头指定日志存储的绝对路径。

log_destination
可选项包括stderr, csvlog, syslog, eventlog
stderr
默认值STDERR,标准输出（standard error）,上面我们执行查询配置参数的语句实际结果输出前的那一串其实是输出到STDERR的结果.在logging_collector=off的情况下，使用此选项会把日志信息输出到terminal中。

syslog
操作系统日志daemon.与syslog相关的参数还有以下几个:
syslog_facility = ‘LOCAL0’,表示 “category of source”
syslog_ident = ‘postgres’,日志的识别符
syslog_sequence_numbers = on,是否开启序列编号
syslog_split_messages = on,是否拆分消息

下面是修改为syslog后，执行select 1/0后的日志输出。

[root@localhost log]# uname -a
Linux localhost.localdomain 3.10.0-693.el7.x86_64 #1 SMP Tue Aug 22 21:09:27 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
[root@localhost log]# pwd
/var/log
[root@localhost log]# tail -n 20 messages
...
Dec 26 11:28:03 localhost postgres[5035]: [7-1] 2019-12-26 11:28:03.737 CST [5035] ERROR:  division by zero
Dec 26 11:28:03 localhost postgres[5035]: [7-2] 2019-12-26 11:28:03.737 CST [5035] STATEMENT:  select 1/0;
...
[root@localhost log]#

postgres是syslog_ident定义的字符串，可以由用户自行定义，[5035]中的5035是pid。
比如把该参数修改为12.1：

###修改参数
[test@localhost tmpdb]$ pg_ctl reload
server signaled
[test@localhost tmpdb]$ grep 'syslog_ident' postgresql.conf 
syslog_ident = 'pg12.1'
[test@localhost tmpdb]$ 
###日志输出
Dec 26 11:34:32 localhost postgres[4800]: [7-1] 2019-12-26 11:34:32.906 CST [4800] LOG:  received SIGHUP, reloading configuration files
Dec 26 11:34:32 localhost pg12.1[4800]: [8-1] 2019-12-26 11:34:32.907 CST [4800] LOG:  parameter "syslog_ident" changed to "pg12.1"
Dec 26 11:34:37 localhost pg12.1[5035]: [8-1] 2019-12-26 11:34:37.163 CST [5035] ERROR:  division by zero
Dec 26 11:34:37 localhost pg12.1[5035]: [8-2] 2019-12-26 11:34:37.163 CST [5035] STATEMENT:  select 1/0;
[root@localhost log]#

其中4800是postmaster进程，5035是backend进程
通过ps -ef查看进程信息

[test@localhost tmpdb]$ ps -ef|grep postgres|grep 4800
test      4800     1  0 11:24 ?        00:00:00 /appdb/pg12/pg12.1/bin/postgres
test      4802  4800  0 11:24 ?        00:00:00 postgres: checkpointer   
test      4803  4800  0 11:24 ?        00:00:00 postgres: background writer   
test      4804  4800  0 11:24 ?        00:00:00 postgres: walwriter   
test      4805  4800  0 11:24 ?        00:00:00 postgres: autovacuum launcher  
test      4806  4800  0 11:24 ?        00:00:00 postgres: stats collector   
test      4807  4800  0 11:24 ?        00:00:00 postgres: logical replication launcher  
test      5035  4800  0 11:27 ?        00:00:00 postgres: test testdb [local] idle
[test@localhost tmpdb]$

修改rsyslog的配置，设定local0日志的输出并重启rsyslog服务

[root@localhost ~]# grep 'local0' /etc/rsyslog.conf 
local0.*                                                /var/log/postgres.log
[root@localhost ~]#

修改PG日志输出为syslog，查看日志输出

[root@localhost ~]# ls -l /var/log/postg*
-rw------- 1 root root 1656 Dec 26 16:29 /var/log/postgres.log
[root@localhost ~]# cat /var/log/postgres.log
Dec 26 16:29:04 localhost pg12.1[23642]: [1-1] 2019-12-26 16:29:04.668 CST [23642] LOG:  starting PostgreSQL 12.1 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 4.8.5 20150623 (Red Hat 4.8.5-16), 64-bit
Dec 26 16:29:04 localhost pg12.1[23642]: [2-1] 2019-12-26 16:29:04.668 CST [23642] LOG:  listening on IPv6 address "::1", port 5000
Dec 26 16:29:04 localhost pg12.1[23642]: [3-1] 2019-12-26 16:29:04.668 CST [23642] LOG:  listening on IPv4 address "127.0.0.1", port 5000
Dec 26 16:29:04 localhost pg12.1[23642]: [4-1] 2019-12-26 16:29:04.669 CST [23642] LOG:  listening on Unix socket "/var/run/test/.s.PGSQL.5000"
Dec 26 16:29:04 localhost pg12.1[23642]: [5-1] 2019-12-26 16:29:04.683 CST [23642] LOG:  redirecting log output to logging collector process
Dec 26 16:29:04 localhost pg12.1[23642]: [5-2] 2019-12-26 16:29:04.683 CST [23642] HINT:  Future log output will appear in directory "log".
Dec 26 16:29:04 localhost pg12.1[23642]: [6-1] 2019-12-26 16:29:04.684 CST [23642] LOG:  ending log output to stderr
Dec 26 16:29:04 localhost pg12.1[23642]: [6-2] 2019-12-26 16:29:04.684 CST [23642] HINT:  Future log output will go to log destination "syslog".
Dec 26 16:29:04 localhost pg12.1[23644]: [7-1] 2019-12-26 16:29:04.688 CST [23644] LOG:  database system was shut down at 2019-12-26 16:29:04 CST
Dec 26 16:29:04 localhost pg12.1[23642]: [7-1] 2019-12-26 16:29:04.693 CST [23642] LOG:  database system is ready to accept connections
Dec 26 16:29:38 localhost pg12.1[23683]: [8-1] 2019-12-26 16:29:38.824 CST [23683] ERROR:  division by zero
Dec 26 16:29:38 localhost pg12.1[23683]: [8-2] 2019-12-26 16:29:38.824 CST [23683] STATEMENT:  select 1/0;
[root@localhost ~]#

syslog需要依赖平台的实现，更深入的内容后续再行介绍。

csvlog
csv格式文件。如使用该选项，则需要设置logging_collector参数为on。
设置该参数为on，log_destination设置为stderr

###logging_collector=off
[root@localhost 5035]# ps -ef|grep 4800
test      4800     1  0 11:24 ?        00:00:00 /appdb/pg12/pg12.1/bin/postgres
test      4802  4800  0 11:24 ?        00:00:00 postgres: checkpointer   
test      4803  4800  0 11:24 ?        00:00:00 postgres: background writer   
test      4804  4800  0 11:24 ?        00:00:00 postgres: walwriter   
test      4805  4800  0 11:24 ?        00:00:00 postgres: autovacuum launcher  
test      4806  4800  0 11:24 ?        00:00:00 postgres: stats collector   
test      4807  4800  0 11:24 ?        00:00:00 postgres: logical replication launcher  
test      5035  4800  0 11:27 ?        00:00:00 postgres: test testdb [local] idle
root     15986  5275  0 14:36 pts/5    00:00:00 grep --color=auto 4800
###logging_collector=on
[root@localhost 5035]# ps -ef|grep 16024
test     16024     1  0 14:37 ?        00:00:00 /appdb/pg12/pg12.1/bin/postgres
test     16025 16024  0 14:37 ?        00:00:00 postgres: logger   
test     16027 16024  0 14:37 ?        00:00:00 postgres: checkpointer   
test     16028 16024  0 14:37 ?        00:00:00 postgres: background writer   
test     16029 16024  0 14:37 ?        00:00:00 postgres: walwriter   
test     16030 16024  0 14:37 ?        00:00:00 postgres: autovacuum launcher  
test     16031 16024  0 14:37 ?        00:00:00 postgres: stats collector   
test     16032 16024  0 14:37 ?        00:00:00 postgres: logical replication launcher  
root     16090  5275  0 14:38 pts/5    00:00:00 grep --color=auto 16024

新出现了一个进程logger（后续会逐步解读这部分的源码），日志输出到$PGDATA/log目录下

[test@localhost tmpdb]$ cd log
[test@localhost log]$ ls
postgresql-2019-12-26_143730.log
[test@localhost log]$ tail -n 20 postgresql-2019-12-26_143730.log 
2019-12-26 14:37:30.317 CST [16026] LOG:  database system was shut down at 2019-12-26 14:37:30 CST
2019-12-26 14:37:30.354 CST [16024] LOG:  database system is ready to accept connections
2019-12-26 14:41:27.684 CST [16293] ERROR:  division by zero
2019-12-26 14:41:27.684 CST [16293] STATEMENT:  select 1/0;
[test@localhost log]$

接着，我们修改该参数为csvlog，执行select 1/0

[test@localhost tmpdb]$ ls -l ./log/
total 12
-rw------- 1 test test 807 Dec 26 14:45 postgresql-2019-12-26_143730.log
-rw------- 1 test test 676 Dec 26 14:45 postgresql-2019-12-26_144540.csv
-rw------- 1 test test 168 Dec 26 14:45 postgresql-2019-12-26_144540.log
[test@localhost tmpdb]$ tail -n 20 ./log/postgresql-2019-12-26_144540.csv
2019-12-26 14:45:40.781 CST,,,16534,,5e045714.4096,1,,2019-12-26 14:45:40 CST,,0,LOG,00000,"ending log output to stderr",,"Future log output will go to log destination ""csvlog"".",,,,,,,""
2019-12-26 14:45:40.802 CST,,,16536,,5e045714.4098,1,,2019-12-26 14:45:40 CST,,0,LOG,00000,"database system was shut down at 2019-12-26 14:45:40 CST",,,,,,,,,""
2019-12-26 14:45:40.808 CST,,,16534,,5e045714.4096,2,,2019-12-26 14:45:40 CST,,0,LOG,00000,"database system is ready to accept connections",,,,,,,,,""
2019-12-26 14:45:44.258 CST,"test","testdb",16546,"[local]",5e045717.40a2,1,"SELECT",2019-12-26 14:45:43 CST,3/2,0,ERROR,22012,"division by zero",,,,,,"select 1/0;",,,"psql"
[test@localhost tmpdb]$ tail -n 20 ./log/postgresql-2019-12-26_144540.log
2019-12-26 14:45:40.781 CST [16534] LOG:  ending log output to stderr
2019-12-26 14:45:40.781 CST [16534] HINT:  Future log output will go to log destination "csvlog".
[test@localhost tmpdb]$ tail -n 100 ./log/postgresql-2019-12-26_144540.log
2019-12-26 14:45:40.781 CST [16534] LOG:  ending log output to stderr
2019-12-26 14:45:40.781 CST [16534] HINT:  Future log output will go to log destination "csvlog".
[test@localhost tmpdb]$

可以看到，修改为csvlog后，输出的日志格式为以逗号分隔的csv文件格式，这种格式的文件可以很方便的导入到数据库（Oracle、PG、MySQL等）中。

eventlog
Windows平台的事件日志。

logging_collector
参见上述解释，简单来说，设置为on，则PG会启动logger进程，同时日志会发送给pg的syslogger进程，否则不会。

log_filename
默认值为’postgresql-%Y-%m-%d_%H%M%S.log’，其中%Y代表年，%m代表月，%d代表日，%H代表小时，%M代表分钟，%S代表秒。
可用的匹配符可参见 strftime，如使用默认值，则每隔一秒就会产生一个日志文件（如有的话）。

%a
The abbreviated name of the day of the week according to the current locale. (Calculated from tm_wday.)
%A
The full name of the day of the week according to the current locale. (Calculated from tm_wday.)
%b
The abbreviated month name according to the current locale. (Calculated from tm_mon.)
%B
The full month name according to the current locale. (Calculated from tm_mon.)
%c
The preferred date and time representation for the current locale.
%C
The century number (year/100) as a 2-digit integer. (SU) (Calculated from tm_year.)
%d
The day of the month as a decimal number (range 01 to 31). (Calculated from tm_mday.)
%D
Equivalent to %m/%d/%y. (Yecch—for Americans only. Americans should note that in other countries %d/%m/%y is rather common. This means that in international context this format is ambiguous and should not be used.) (SU)
%e
Like %d, the day of the month as a decimal number, but a leading zero is replaced by a space. (SU) (Calculated from tm_mday.)
%E
Modifier: use alternative format, see below. (SU)
%F
Equivalent to %Y-%m-%d (the ISO 8601 date format). (C99)
%G
The ISO 8601 week-based year (see NOTES) with century as a decimal number. The 4-digit year corresponding to the ISO week number (see %V). This has the same format and value as %Y, except that if the ISO week number belongs to the previous or next year, that year is used instead. (TZ) (Calculated from tm_year, tm_yday, and tm_wday.)
%g
Like %G, but without century, that is, with a 2-digit year (00–99). (TZ) (Calculated from tm_year, tm_yday, and tm_wday.)
%h
Equivalent to %b. (SU)
%H
The hour as a decimal number using a 24-hour clock (range 00 to 23). (Calculated from tm_hour.)
%I
The hour as a decimal number using a 12-hour clock (range 01 to 12). (Calculated from tm_hour.)
%j
The day of the year as a decimal number (range 001 to 366). (Calculated from tm_yday.)
%k
The hour (24-hour clock) as a decimal number (range 0 to 23); single digits are preceded by a blank. (See also %H.) (Calculated from tm_hour.) (TZ)
%l
The hour (12-hour clock) as a decimal number (range 1 to 12); single digits are preceded by a blank. (See also %I.) (Calculated from tm_hour.) (TZ)
%m
The month as a decimal number (range 01 to 12). (Calculated from tm_mon.)
%M
The minute as a decimal number (range 00 to 59). (Calculated from tm_min.)
%n
A newline character. (SU)
%O
Modifier: use alternative format, see below. (SU)
%p
Either “AM” or “PM” according to the given time value, or the corresponding strings for the current locale. Noon is treated as “PM” and midnight as “AM”. (Calculated from tm_hour.)
%P
Like %p but in lowercase: “am” or “pm” or a corresponding string for the current locale. (Calculated from tm_hour.) (GNU)
%r
The time in a.m. or p.m. notation. In the POSIX locale this is equivalent to %I:%M:%S %p. (SU)
%R
The time in 24-hour notation (%H:%M). (SU) For a version including the seconds, see %T below.
%s
The number of seconds since the Epoch, 1970-01-01 00:00:00 +0000 (UTC). (TZ) (Calculated from mktime(tm).)
%S
The second as a decimal number (range 00 to 60). (The range is up to 60 to allow for occasional leap seconds.) (Calculated from tm_sec.)
%t
A tab character. (SU)
%T
The time in 24-hour notation (%H:%M:%S). (SU)
%u
The day of the week as a decimal, range 1 to 7, Monday being 1. See also %w. (Calculated from tm_wday.) (SU)
%U
The week number of the current year as a decimal number, range 00 to 53, starting with the first Sunday as the first day of week 01. See also %V and %W. (Calculated from tm_yday and tm_wday.)
%V
The ISO 8601 week number (see NOTES) of the current year as a decimal number, range 01 to 53, where week 1 is the first week that has at least 4 days in the new year. See also %U and %W. (Calculated from tm_year, tm_yday, and tm_wday.) (SU)
%w
The day of the week as a decimal, range 0 to 6, Sunday being 0. See also %u. (Calculated from tm_wday.)
%W
The week number of the current year as a decimal number, range 00 to 53, starting with the first Monday as the first day of week 01. (Calculated from tm_yday and tm_wday.)
%x
The preferred date representation for the current locale without the time.
%X
The preferred time representation for the current locale without the date.
%y
The year as a decimal number without a century (range 00 to 99). (Calculated from tm_year)
%Y
The year as a decimal number including the century. (Calculated from tm_year)
%z
The +hhmm or -hhmm numeric timezone (that is, the hour and minute offset from UTC). (SU)
%Z
The timezone name or abbreviation.
%+
The date and time in date(1) format. (TZ) (Not supported in glibc2.)
%%
A literal ‘%’ character.

log_file_mode
日志文件的mode，用于控制日志文件的访问权限，默认为0600

[test@localhost tmpdb]$ cd log
[test@localhost log]$ ll
total 16
-rw------- 1 test test  807 Dec 26 14:45 postgresql-2019-12-26_143730.log
-rw------- 1 test test 1584 Dec 26 14:52 postgresql-2019-12-26_144540.csv
-rw------- 1 test test  168 Dec 26 14:45 postgresql-2019-12-26_144540.log
-rw------- 1 test test  309 Dec 26 14:52 postgresql-2019-12-26_145238.log

设置为0777，重启，文件为666

[test@localhost tmpdb]$ ll ./log
total 20
-rw------- 1 test test  807 Dec 26 14:45 postgresql-2019-12-26_143730.log
-rw------- 1 test test 1584 Dec 26 14:52 postgresql-2019-12-26_144540.csv
-rw------- 1 test test  168 Dec 26 14:45 postgresql-2019-12-26_144540.log
-rw------- 1 test test  807 Dec 26 14:57 postgresql-2019-12-26_145238.log
-rw-rw-rw- 1 test test  309 Dec 26 14:58 postgresql-2019-12-26_145757.log
[test@localhost tmpdb]$

log_truncate_on_rotation
可选项为on和off，默认为off。
如设置为on，在rotate时，如果文件存在，则截断文件内容，否则在已存在的文件中追加信息。
关于rotation，PG提供了两种模式：一种基于大小，另外一种基于时间，对应的参数分别是log_rotation_size和log_rotation_age。

log_rotation_size
单位为KB，默认值为10MB。该参数意思是在大小超过该设定后，生成新的日志文件。

log_rotation_age
单位为分钟，默认为1d，即1440分钟。该参数意思是经过这个时长之后，产生新的日志文件。如配置为5分钟，则5分钟后产生新的日志文件，文件名称由log_filename控制。

由于文件名称由log_filename控制，那么在大小或者时间超过设定，但文件名称设定为不变（如设定为postgresql-%Y-%m-%d.log），结果会如何呢？

[test@localhost tmpdb]$ grep 'log_filename' postgresql.conf 
log_filename = 'postgresql-%Y-%m-%d.log'  # log file name pattern,
[test@localhost tmpdb]$ grep 'rotation' postgresql.conf 
log_truncate_on_rotation = on   # If on, an existing log file with the
                                # time-driven rotation, not on restarts
                                # or size-driven rotation.  Default is
log_rotation_age = 5            # Automatic rotation of logfiles will
log_rotation_size = 10MB        # Automatic rotation of logfiles will
[test@localhost tmpdb]$ 
[test@localhost tmpdb]$ rm -rf ./log
[test@localhost tmpdb]$ pg_ctl restart
waiting for server to shut down.... done
server stopped
waiting for server to start....2019-12-26 15:10:26.812 CST [18042] LOG:  starting PostgreSQL 12.1 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 4.8.5 20150623 (Red Hat 4.8.5-16), 64-bit
2019-12-26 15:10:26.812 CST [18042] LOG:  listening on IPv6 address "::1", port 5000
2019-12-26 15:10:26.812 CST [18042] LOG:  listening on IPv4 address "127.0.0.1", port 5000
2019-12-26 15:10:26.814 CST [18042] LOG:  listening on Unix socket "/var/run/test/.s.PGSQL.5000"
2019-12-26 15:10:26.823 CST [18042] LOG:  redirecting log output to logging collector process
2019-12-26 15:10:26.823 CST [18042] HINT:  Future log output will appear in directory "log".
 done
server started
[test@localhost tmpdb]$ ll ./log/
total 4
-rw------- 1 test test 188 Dec 26 15:11 postgresql-2019-12-26.log
[test@localhost tmpdb]$ 
[test@localhost tmpdb]$ ll ./log/
total 4
-rw------- 1 test test 188 Dec 26 15:11 postgresql-2019-12-26.log
[test@localhost tmpdb]$ watch -n1 ls -l ./log
[test@localhost tmpdb]$ ll ./log/
total 4
-rw------- 1 test test 551 Dec 26 15:12 postgresql-2019-12-26.log
[test@localhost tmpdb]$

由于文件已存在，因此不会截断该文件。同理，如文件已存在，就算时间到了也不会截断。

在工程实践上，可通过设置log_filename为按周天或者按月天，这样可以保证周一到周日每天只有一个文件或者从一号到三十一号号一天只有一个文件，避免出现过多的文件。

参考资料
Understanding postgresql.conf : log
Error Reporting and Logging