PostgreSQL DBA(153) - pgAdmin（log_XXX parameter：what）

husthxd發表於2019-12-30

本節介紹了與日誌相關的配置引數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;
               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這幾個維度來解析這些引數，本節是第三部分，介紹what to log。

### What to log
**debug_print_parse**
是否列印分析階段的查詢樹，預設為off-不列印

**debug_print_rewritten**
是否列印查詢重寫階段的查詢樹，預設為off-不列印

**debug_print_plan**
是否列印計劃階段的計劃樹，預設為off-不列印

**debug_pretty_print**
是否以優雅的方式列印？預設為on

**log_checkpoints**
是否記錄checkpoint資訊，預設為off。
在checkpoint發生時，PG會記錄相關的資訊
```
checkpoint_timeout = 1min   # range 30s-1d
checkpoint_completion_target = 0.5  # checkpoint target duration, 0.0 - 1.0
#checkpoint_flush_after = 256kB   # measured in pages, 0 disables
#checkpoint_warning = 30s   # 0 disables
log_checkpoints = on
```
插入資料，在檢查點發生時，可以看到檢查點的相關資訊輸出
```
2019-12-30 14:27:03.618 CST [2224] LOG:  duration: 106.374 ms  statement: insert into tbl select x,'c1'||x from generate_series(1,10000) x;
2019-12-30 14:28:00.428 CST [2166] LOG:  checkpoint starting: time
2019-12-30 14:28:06.387 CST [2166] LOG:  checkpoint complete: wrote 59 buffers (0.4%); 0 WAL file(s) added, 0 removed, 0 recycled; write=5.949 s, sync=0.001 s, total=5.958 s; sync files=3, longest=0.001 s, average=0.000 s; distance=764 kB, estimate=764 kB

```

**log_connections**
記錄登入資訊，包括什麼時候有連線請求，哪個使用者連線的是哪個資料庫；如連線失敗，也會記錄相關資訊。
```
###修改配置資訊
[test@localhost ~]$ grep 'log_connections' $PGDATA/postgresql.conf
# "postgres -c log_connections=on".  Some parameters can be changed at run time
log_connections = on
[test@localhost ~]$ pg_ctl reload
server signaled
[test@localhost ~]$

###日誌輸出
2019-12-30 14:33:02.527 CST [2634] LOG:  connection received: host=[local]
2019-12-30 14:33:02.531 CST [2634] LOG:  connection authorized: user=test database=testdb application_name=psql

```

**log_disconnections**
記錄連線斷開登入資訊
```
###
[test@localhost ~]$ grep 'log_disconnections' $PGDATA/postgresql.conf
log_disconnections = on
[test@localhost ~]$

###日誌輸出
2019-12-30 14:34:57.646 CST [2734] LOG:  disconnection: session time: 0:00:04.885 user=test database=testdb host=[local]

```

**log_duration**
記錄執行時間，僅記錄執行時間，沒有其他多餘的資訊。預設為on。
```
2019-12-30 14:36:49.149 CST [2224] LOG:  duration: 12.178 ms

```

**log_error_verbosity**
出現錯誤時的日誌診斷資訊級別，可選項包括：terse, default, or verbose，預設值為default
使用verbose，可以看到哪個原始檔的哪一行，方便診斷
```
###建立測試物件
[local:/data/run/test]:5000 test@testdb=# create view vw_tbl as select * from tbl;
CREATE VIEW
[local:/data/run/test]:5000 test@testdb=#

###terse
2019-12-30 14:41:30.395 CST [2163] LOG:  parameter "log_error_verbosity" changed to "terse"
2019-12-30 14:41:39.689 CST [2224] ERROR:  cannot drop table tbl because other objects depend on it

###default
2019-12-30 14:42:27.106 CST [2163] LOG:  parameter "log_error_verbosity" changed to "default"
2019-12-30 14:42:33.287 CST [2224] ERROR:  cannot drop table tbl because other objects depend on it
2019-12-30 14:42:33.287 CST [2224] DETAIL:  view vw_tbl depends on table tbl
2019-12-30 14:42:33.287 CST [2224] HINT:  Use DROP ... CASCADE to drop the dependent objects too.

###verbose
2019-12-30 14:43:29.654 CST [2163] LOG:  00000: parameter "log_error_verbosity" changed to "verbose"
2019-12-30 14:43:29.654 CST [2163] LOCATION:  ProcessConfigFileInternal, guc-file.l:456
2019-12-30 14:43:32.790 CST [2224] ERROR:  2BP01: cannot drop table tbl because other objects depend on it
2019-12-30 14:43:32.790 CST [2224] DETAIL:  view vw_tbl depends on table tbl
2019-12-30 14:43:32.790 CST [2224] HINT:  Use DROP ... CASCADE to drop the dependent objects too.
2019-12-30 14:43:32.790 CST [2224] LOCATION:  reportDependentObjects, dependency.c:1196

```

**log_hostname**
是否記錄主機名稱，預設為off。

**log_line_prefix**
每一行日誌前的字首。預設為'%m [%p] '，可使用的萬用字元包括：
>%a – application name
%u – user name
%d – database name
%r – remote host and port
%h – remote host
%p – process ID
%t – timestamp without milliseconds
%m – timestamp with milliseconds
%i – command tag
%e – SQL state
%c – session ID
%l – session line number
%s – session start timestamp
%v – virtual transaction ID
%x – transaction ID (0 if none)
%q – stop here in non-session processes
%% – ‘%'

把該引數修改為'%m %u@%d %p %r'，reload後的日誌輸出：
```
2019-12-30 15:20:31.707 CST @ [2163]  LOG:  00000: parameter "log_line_prefix" changed to "%m %u@%d [%p] %r "
2019-12-30 15:20:31.707 CST @ [2163]  LOCATION:  ProcessConfigFileInternal, guc-file.l:456
2019-12-30 15:20:40.148 CST test@testdb [2224] [local] ERROR:  2BP01: cannot drop table tbl because other objects depend on it
2019-12-30 15:20:40.148 CST test@testdb [2224] [local] DETAIL:  view vw_tbl depends on table tbl
2019-12-30 15:20:40.148 CST test@testdb [2224] [local] HINT:  Use DROP ... CASCADE to drop the dependent objects too.
2019-12-30 15:20:40.148 CST test@testdb [2224] [local] LOCATION:  reportDependentObjects, dependency.c:1196

```

**log_lock_waits**
記錄等待時間超過deadlock_timeout（預設為1s）的lock。
```
2019-12-30 15:27:06.637 CST @ [2163]  LOG:  00000: parameter "log_lock_waits" changed to "on"
2019-12-30 15:27:06.637 CST @ [2163]  LOCATION:  ProcessConfigFileInternal, guc-file.l:456
2019-12-30 15:27:18.462 CST test@testdb [2224] [local] LOG:  00000: duration: 0.542 ms
2019-12-30 15:27:18.462 CST test@testdb [2224] [local] LOCATION:  exec_simple_query, postgres.c:1289
2019-12-30 15:27:36.559 CST test@testdb [5749] [local] LOG:  00000: duration: 0.639 ms
2019-12-30 15:27:36.559 CST test@testdb [5749] [local] LOCATION:  exec_simple_query, postgres.c:1289
2019-12-30 15:27:44.470 CST test@testdb [2224] [local] LOG:  00000: duration: 3.592 ms
2019-12-30 15:27:44.470 CST test@testdb [2224] [local] LOCATION:  exec_simple_query, postgres.c:1289
2019-12-30 15:27:58.024 CST test@testdb [5749] [local] LOG:  00000: process 5749 still waiting for AccessShareLock on relation 16385 of database 16384 after 1000.615 ms at character 22
2019-12-30 15:27:58.024 CST test@testdb [5749] [local] DETAIL:  Process holding the lock: 2224. Wait queue: 5749.
2019-12-30 15:27:58.024 CST test@testdb [5749] [local] LOCATION:  ProcSleep, proc.c:1493
...

```

**log_statement**
記錄哪些語句，可選項包括none, ddl, mod, all。
設定該引數為all，而log_min_duration_statement設定為600
執行SQL
```
[local:/data/run/test]:5000 test@testdb=# select 1;
 ?column? 
----------
        1
(1 row)

[local:/data/run/test]:5000 test@testdb=# select pg_sleep(1);
 pg_sleep 
----------
 
(1 row)

```
雖然select 1;執行得很快，沒有超過600ms，但由於設定了該引數為all，因此也會在日誌中出現
```
2019-12-30 15:32:41.934 CST @ [2163]  LOG:  00000: received SIGHUP, reloading configuration files
2019-12-30 15:32:41.934 CST @ [2163]  LOCATION:  SIGHUP_handler, postmaster.c:2635
2019-12-30 15:32:41.939 CST @ [2163]  LOG:  00000: parameter "log_min_duration_statement" changed to "600"
2019-12-30 15:32:41.939 CST @ [2163]  LOCATION:  ProcessConfigFileInternal, guc-file.l:456
2019-12-30 15:32:41.939 CST @ [2163]  LOG:  00000: parameter "log_statement" changed to "all"
2019-12-30 15:32:41.939 CST @ [2163]  LOCATION:  ProcessConfigFileInternal, guc-file.l:456
2019-12-30 15:32:51.932 CST test@testdb [2224] [local] LOG:  00000: statement: select 1;
2019-12-30 15:32:51.932 CST test@testdb [2224] [local] LOCATION:  exec_simple_query, postgres.c:1045
2019-12-30 15:32:51.932 CST test@testdb [2224] [local] LOG:  00000: duration: 0.375 ms
2019-12-30 15:32:51.932 CST test@testdb [2224] [local] LOCATION:  exec_simple_query, postgres.c:1289
2019-12-30 15:33:02.686 CST test@testdb [2224] [local] LOG:  00000: statement: select pg_sleep(1);
2019-12-30 15:33:02.686 CST test@testdb [2224] [local] LOCATION:  exec_simple_query, postgres.c:1045
2019-12-30 15:33:03.691 CST test@testdb [2224] [local] LOG:  00000: duration: 1005.297 ms
2019-12-30 15:33:03.691 CST test@testdb [2224] [local] LOCATION:  exec_simple_query, postgres.c:1289

```
把該引數設定為none，執行同樣的SQL，日誌輸出中只有select pg_sleep(1);
```
2019-12-30 15:35:06.740 CST @ [2163]  LOG:  00000: received SIGHUP, reloading configuration files
2019-12-30 15:35:06.740 CST @ [2163]  LOCATION:  SIGHUP_handler, postmaster.c:2635
2019-12-30 15:35:06.743 CST @ [2163]  LOG:  00000: parameter "log_statement" changed to "none"
2019-12-30 15:35:06.743 CST @ [2163]  LOCATION:  ProcessConfigFileInternal, guc-file.l:456
2019-12-30 15:35:09.995 CST test@testdb [2224] [local] LOG:  00000: duration: 0.325 ms
2019-12-30 15:35:09.995 CST test@testdb [2224] [local] LOCATION:  exec_simple_query, postgres.c:1289
2019-12-30 15:35:12.441 CST test@testdb [2224] [local] LOG:  00000: duration: 1001.645 ms  statement: select pg_sleep(1);
2019-12-30 15:35:12.441 CST test@testdb [2224] [local] LOCATION:  exec_simple_query, postgres.c:1296

```

**log_replication_commands**
是否記錄複製命令。

**log_temp_files**
是否記錄大小超過該引數配置大小的臨時檔案。在執行大批次資料排序或者使用臨時表時可以用於診斷。
```
2019-12-30 15:40:37.992 CST @ [2163]  LOG:  00000: received SIGHUP, reloading configuration files
2019-12-30 15:40:37.992 CST @ [2163]  LOCATION:  SIGHUP_handler, postmaster.c:2635
2019-12-30 15:40:37.993 CST @ [2163]  LOG:  00000: parameter "log_replication_commands" changed to "on"
2019-12-30 15:40:37.993 CST @ [2163]  LOCATION:  ProcessConfigFileInternal, guc-file.l:456
2019-12-30 15:40:37.993 CST @ [2163]  LOG:  00000: parameter "log_temp_files" changed to "1024"
2019-12-30 15:40:37.993 CST @ [2163]  LOCATION:  ProcessConfigFileInternal, guc-file.l:456
###日誌輸出
2019-12-30 15:42:07.897 CST test@testdb [2224] [local] LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp2224.4", size 29507584
2019-12-30 15:42:07.897 CST test@testdb [2224] [local] LOCATION:  ReportTemporaryFileUsage, fd.c:1285

```

**log_timezone**
是否記錄時區資訊。

**參考資料**
[Understanding postgresql.conf : log](https://www.depesz.com/2011/05/06/understanding-postgresql-conf-log/)

來自 “ ITPUB部落格 ” ，連結：http://blog.itpub.net/6906/viewspace-2671314/，如需轉載，請註明出處，否則將追究法律責任。

相關文章

PostgreSQL DBA(152) - pgAdmin（log_XXX parameter：when）
2019-12-27
SQL
PostgreSQL DBA(151) - pgAdmin（log_XXX parameter：where）
2019-12-26
SQL
PostgreSQL DBA(166) - pgAdmin(Parallelism, what next？)
2020-02-27
SQLParallel
PostgreSQL DBA(120) - pgAdmin(HA with Patroni)
2019-11-04
SQL
PostgreSQL DBA(168) - pgAdmin(config：checkpoint)
2020-03-05
SQL
PostgreSQL DBA(164) - pgAdmin(Drop column)
2020-02-13
SQL
PostgreSQL DBA(156) - pgAdmin（Rollback setting）
2020-01-09
SQL
PostgreSQL DBA(101) - pgAdmin(statement timeout)
2019-10-08
SQL
PostgreSQL DBA(160) - pgAdmin(prepare transaction)
2020-02-10
SQL
PostgreSQL DBA(147) - pgAdmin（Scripts for freeze）
2019-12-17
SQL
PostgreSQL DBA(173) - pgAdmin(Network latency)
2020-05-18
SQL
PostgreSQL DBA(86) - Table Parameter(fillfactor)
2019-08-27
SQL
PostgreSQL DBA(180) - What is locktype=transactionid
2021-04-28
SQL
PostgreSQL DBA(161) - pgAdmin(synchronous_commit)
2020-02-11
SQLMIT
PostgreSQL DBA(128) - pgAdmin(Load balance with HAProxy)
2019-11-14
SQL
PostgreSQL DBA(106) - pgAdmin(Don't do this：NOT IN)
2019-10-14
SQL
PostgreSQL DBA(102) - pgAdmin(Row Level Security)
2019-10-09
SQL
PostgreSQL DBA(170) - pgAdmin(Queries For Index Maintenance)
2020-04-07
SQLIndexAINaN
PostgreSQL DBA(143) - pgAdmin（Monitoring PostgreSQL VACUUM processes#2）
2019-12-11
SQL
PostgreSQL DBA(167) - pgAdmin(config：work_mem)
2020-03-02
SQL
PostgreSQL DBA(132) - pgAdmin(unix_socket_directories)
2019-11-18
SQL
PostgreSQL DBA(104) - pgAdmin(Don't do this：Rule)
2019-10-11
SQL
PostgreSQL DBA(103) - pgAdmin(Don't do this：Encoding)
2019-10-10
SQLEncoding
PostgreSQL DBA(165) - pgAdmin(Create Function選項)
2020-02-25
SQLFunction
PostgreSQL DBA(148) - pgAdmin（Show script for psql command）
2019-12-17
SQL
PostgreSQL DBA(107) - pgAdmin(Don't do this：NOT IN vs NOT EXISTS)
2019-10-15
SQL
PostgreSQL DBA(144) - pgAdmin（AUTOVACUUM：引數解析#2）
2019-12-12
SQL
PostgreSQL DBA(145) - pgAdmin（AUTOVACUUM：引數解析#3）
2019-12-12
SQL
PostgreSQL DBA(154) - pgAdmin（bool轉換為smallint）
2019-12-31
SQL
PostgreSQL DBA(121) - pgAdmin(HA：PAF vs repmgr vs Patroni)
2019-11-05
SQL
PostgreSQL DBA(159) - pgAdmin(Allow vacuum command to process indexes in paralle
2020-01-20
SQLIndex
PostgreSQL DBA(157) - pgAdmin（OOM & max_locks_per_transaction ）
2020-01-10
SQLOOM
PostgreSQL DBA(105) - pgAdmin(Don't do this：psql&inheritance)
2019-10-12
SQL
PostgreSQL DBA(109) - pgAdmin(Don't do this：Don't use BETWEEN)
2019-10-17
SQL
PostgreSQL DBA(119) - pgAdmin(LIMIT：Index Scan vs Bitmap Index Scan)
2019-11-01
SQLMITIndex
PostgreSQL DBA(117) - pgAdmin(Don't do this： Don't use serial)
2019-10-29
SQL
PostgreSQL DBA(146) - pgAdmin（pg_dumpall vs pg_dump）
2019-12-16
SQL
PostgreSQL DBA(75) - Locks(locktype：transactionid)：What You Should Know
2019-08-13
SQL