数据库性能优化, 没有日志可不行.
这篇文章介绍了很多常用以及不常用的日志参数, 算是性能优化相关的日志参数入门科普大荟萃吧.
以下内容翻译自:
https://www.crunchydata.com/blog/postgres-logging-for-performance-optimization
Postgres 日志不仅是查找和调试关键错误的首选工具,也是应用程序性能监控的关键工具。
今天,让我们开始设置 Postgres 的日志记录 —— 从记录哪些内容、如何记录所需内容的基础知识开始,以及作为您辛勤工作的回报 —— 如何使用这些内容来监控和提升性能。Postgres的日志文档( https://www.postgresql.org/docs/current/runtime-config-logging.html )非常出色,因此请查阅这些文档以获取最新、最全面的配置。这篇博客会提供一些实用的建议和设置。
让我们深入讨论一下:
WAL 注意事项:本文仅讨论服务器的消息和错误日志(logging),而非事务预写日志 (WAL)。虽然预写日志也是一种日志,但 WAL 的目的是记录所有数据和模式变更,以便用于备份、灾难恢复和流复制。
首先,Postgres 默认只会将日志发送到终端。要启用将日志发送到日志文件,请打开日志收集器。
logging_collector = on
日志消息格式由log_destination参数决定,可设置为以下一个或多个:stderr、csvlog、jsonlog 和 syslog。stderr为默认值。使用多个日志记录目标时,请使用逗号分隔值:
-- setting multiple log destinations
log_destination = 'stderr,json'
如果logging_collector = 'on',则stderr,csvlog和jsonlog日志记录将转到 log_directory 指定的目录中的文件,设置为csv、json时需要启用日志收集器。
服务器生成的所有日志消息都具有以下严重性级别之一:
日志消息将如下所示:
-- background worker crash
ERROR: background worker "logical replication launcher" crashed
--disk i/o
ERROR: could not fsync file "pg_wal/0000000100000000000000A3": Input/output error
--out of disk space for temp files
ERROR: could not create temporary file: No space left on device
--vacuum warning
WARNING: relation "public.large_table" contains more than "autovacuum_vacuum_threshold" dead tuples
服务器log_min_messages设置用于确定哪些日志消息实际记录到配置的日志目标。所有严重级别达到或高于配置级别的消息都将被发送。默认值为“error”,这通常是一个不错的设置。“warning”在调试时也可能有用。
log_min_messages='warning'
因此,WARNING包含所有严重级别为warning, error, log, fatal, and panic的消息。通常,调试级别仅用于开发或特定用途。
除了上面介绍的日志严重性选择之外,还可以根据 log_statement 参数选择要记录的 SQL 查询。您可以选择的值包括:
log_min_message 配置显示。DDL 对于生产来说是一个不错的选择。
log_statement = 'ddl';
语法错误或在解析或规划阶段失败的语句不包含在log_statement内。这些语句包含在log_min_error_statement内,应将其设置为 ERROR 或更低的值以记录它们。
log_min_error_statement=ERROR
SQL 错误代码如下所示,相关时会显示 HINT 行。如果您使用 log_min_error_statement = 'error' 记录实际语句,则 HINT 行会显示在最后。
2025-05-09 14:02:37 UTC [28561] ERROR: operator does not exist: integer == integer at character 33
2025-05-09 14:02:37 UTC [28561] HINT: Perhaps you meant to use the standard operator "=".
2025-05-09 14:02:37 UTC [28561] STATEMENT: SELECT * FROM users WHERE id == 42;
许多人的共同点是确保敏感数据(例如信用卡号 或 PII)不包含在记录的查询数据中。log_parameter_max_length和log_parameter_max_length_on_error参数允许您将分别记录在查询和错误日志消息中的预处理语句绑定参数值的长度限制为指定的字节数。这适用于使用PREPARE/EXECUTE的显式命名预处理语句的绑定参数,以及由使用扩展查询协议( https://www.postgresql.org/docs/current/protocol-flow.html#PROTOCOL-FLOW-EXT-QUERY ) 的应用程序数据库驱动程序运行的“unnamed”预处理语句的绑定参数。
默认值为 -1,表示将完整记录所有绑定参数。设置为 0 则完全禁用绑定参数记录。
log_parameter_max_length = 0
log_parameter_max_length_on_error = 0
如果您只需要针对某些查询或事务完成此操作,也可以使用SET SESSION和SET LOCAL即时设置这些查询,或者可以使用ALTER USER 为给定用户在给定数据库上的所有查询设置这些查询,甚至为给定用户在特定数据库ALTER DATABASE上的所有查询设置这些查询。
# set for an entire session
SET SESSION log_parameter_max_length = 0;
SET SESSION log_parameter_max_length_on_error = 0
# set for a transaction
BEGIN;
SET LOCAL log_parameter_max_length = 0;
SET LOCAL log_parameter_max_length_on_error = 0;
...
COMMIT;
# set for all queries run by user bob
ALTER ROLE bob SET log_parameter_max_length = 0;
ALTER ROLE bob SET log_parameter_max_length_on_error = 0;
# set for all traffic on database pii_db
ALTER DATABASE pii_db SET log_parameter_max_length = 0;
ALTER DATABASE pii_db SET flog_parameter_max_length_on_error = 0;
# set for all queries run by bob on the pii_db
ALTER ROLE bob IN DATABASE SET og_parameter_max_length = 0;
ALTER ROLE bob IN DATABASE SET log_parameter_max_length_on_error = 0;
开箱即用的 Postgres 日志条目如下所示:
2025-05-19 13:49:04.908 EDT [3108283] ERROR: column "asdfklasdf" does not exist at character 8
时间戳和进程 ID 部分来自默认值log_line_prefix:
log_line_prefix = '%m [%p] '
我们经常建议人们使用更好的前缀来为生成日志消息的内容提供更多上下文。
log_line_prefix = '%m [%p]%q %u@%d '
如果您设置了前缀,请确保保留进程ID(%p),因为这在排除特定进程故障以查找/停止时有很大帮助。将添加%u用户和%d数据库,如果您在单个实例中使用多个 postgres db,这将很有帮助。
请参阅log_line_prefix 文档%以获取有效的 printf 样式转义序列的完整列表。
https://www.postgresql.org/docs/current/runtime-config-logging.html#GUC-LOG-LINE-PREFIX
该log_error_verbosity设置用于确定日志消息本身的详细程度。
log_error_verbosity = 'default'
除了服务器和查询日志之外,您还可以使用PGAudit扩展审核用户行为。PGAudit它不是 Postgres 本身附带的核心扩展,但在所有主要操作系统发行版的存储库中都有它的软件包。
使用PGAudit扩展需要设置 shared_preload_libraries 包含 pgaudit, 在每个需要审计的数据库中创建pgaudit插件,pgaudit.log参数要设置为 none 以外的值。
-- add to preloaded libraries
shared_preload_libraries = 'pgaudit'
-- add extension
CREATE EXTENSION pgaudit
-- enable the pgaudit.log
pgaudit.log = ddl
审计日志记录更精细的数据,例如执行操作的人员、操作发生的时间以及具体更改的内容。这允许跟踪特定的用户操作,包括插入、更新、删除和管理命令。pgaudit.log的可能值包括:read、write、role、ddl、misc。
ALTER ROLE audited_user SET pgaudit.log = 'read, write, ddl';
审计日志如下所示,以逗号分隔(CSV)
2025-05-09 12:34:56.789 UTC [12345] myuser@mydb LOG: AUDIT: SESSION,1,SELECT,pg_catalog.pg_stat_activity,SELECT * FROM pg_stat_activity;
如果您注意到常规日志和审计日志相互重叠,那么您是对的。pgAudit除了 Postgres 的内置日志记录外,还提供详细的审计日志记录(包括会话级信息、角色和更改)。如果您只需要记录 DDL 语句,并且对pgAudit 提供的附加审计功能不感兴趣,那么log_statement = 'ddl'可能就足够了。
该log_filename设置用于指定使用strftime转义模式的日志文件名格式( https://pubs.opengroup.org/onlinepubs/009695399/functions/strftime.html )。默认情况下,日志文件名包含带有时间戳的 postgresql 格式。
log_filename = 'postgresql-%Y-%m-%d_%H%M%S.log'
默认为小时、分钟、秒可能是不必要的,所以这是一个很好的简单方法:
log_filename = 'postgresql-%Y-%m-%d'
stderr日志文件会有.log后缀,csvlog文件会有.csv后缀,jsonlog文件会有.json后缀。
Postgres 为stderr、csvlog和jsonlog 写入的日志文件位于 指定的目录中log_directory。该目录可以是绝对路径,也可以是相对于data_directory路径的相对路径。日志文件syslog的写入位置取决于操作系统的 syslog 配置。
-- where on the host is the data directory
SHOW data_directory;
-- where on the host is the log directory
SHOW log_directory;
-- what do the log file names look like
SHOW log_filename;
-- exact location of the current log file
SELECT pg_current_logfile();
现在我们已经设置了一些日志...但是如果您不设置轮换(覆盖),您的磁盘就会被日志填满。
以下将轮换设置为 1 天。
log_rotation_age = '1d'
这会设置要轮换的文件大小,以防在 1 天结束之前文件大小大于 10MB。
log_rotation_size = '10MB'
如果log_filename格式规范导致日志文件名的重复使用(postgresql-%w.log Replaced by the weekday as a decimal number [0,6], with 0 representing Sunday. ),并且未启用log_truncation_on_rotation , 新的日志内容将被append到现有日志文件的后面, 而不是截断。
log_truncate_on_rotation = 'on'
如果log_filename使用的格式不会导致自动重复使用文件名,例如postgresql-%Y-%m-%d.log,建议使用外部日志轮换工具(如 Linux 的日志轮换工具)logrotate 来根据需要删除旧日志(可能在将它们存档到单独的长期存储位置之后),以避免过多的磁盘空间使用。
现在你已经设置好了日志记录,可以用它来定位具体的系统问题了。通常情况下,通过 Postgres 日志进行问题排查的流程如下:
我们已经掌握了一些日志,知道它们是什么样子的,用途是什么,并且可以用来排查关键错误。接下来, 我们希望日志能发现运行速度异常的SQL。
如果您想捕获运行时间超过某个时间段的查询信息,可以使用该 log_min_duration_statement 参数进行配置。这是 PostgreSQL 的慢查询日志阈值,因此它对于调试长时间运行的查询尤其有用。
当您开始处理查询性能时,记录最慢的查询是查看哪些查询效率低下的好方法。
log_min_duration_statement = '1s'
-- example log for a query that took 1000+ seconds
LOG: duration: 2001.342 ms statement: SELECT count(*) from orders;
您可以通过启用 log_lock_waits 来记录查询锁等待 。日志中的锁等待情况可以很好地表明进程正在发生锁争用。启用此功能几乎没有任何开销(此处描述可能有误, 如果deadlock_timeout设置值很小, 就必须小心),而且对于生产数据库来说非常安全。
log_lock_waits = 'on'
启用锁等待日志记录后,该deadlock_timeout设置将用作记录锁等待的阈值,例如,deadlock_timeout = '1s' 任何等待锁 1 秒或更长时间的查询都将记录该等待。
记录的锁等待将如下所示:
2024-05-16 14:45:12.345 UTC [45678] user@database LOG: process 45678 still waiting for ShareLock on transaction 123456 after 1000.001 ms
2024-05-16 14:45:12.345 UTC [45678] user@database DETAIL: Process holding the lock: 12345. Wait queue: 45678, 45670.
2024-05-16 14:45:12.345 UTC [45678] user@database STATEMENT: UPDATE orders SET status = 'shipped' WHERE id = 42;
我们可以看到:
Postgres 内存的效率是数据库操作快速流畅的关键因素。如果您的查询必须在磁盘上而不是内存缓冲区中执行读取或排序,则可能意味着您需要加大 work_mem, 以某种方式扩展内存容量。添加索引或重写sql也可以减少查询返回结果所需的数据量。
排查内存是否不足 或 work_mem等相关配置太小的一个非常常见的方法, 在 Postgres 创建临时文件时进行记录。默认情况下,此功能处于-1关闭状态。设置为 0 时,每当创建临时文件时都会记录在 Postgres 日志中 —— 这通常不是一个好主意。
理想情况下,将 log_temp_files 设置为与工作内存work_mem相同的大小。这是 Postgres 需要将数据溢出到磁盘之前每个操作的内存限制。如果操作在 work_mem 以内,系统将不会创建临时文件,因此无需记录日志。如果操作溢出到磁盘,它会创建一个至少与work_mem 一样大的临时文件。因此,每当临时文件超过允许单个操作使用的内存大小时,就会记录日志。
-- log temp files >4mb in kb, set to current work_mem setting
log_temp_files = '4096'
临时文件的实际日志将如下所示
2024-05-16 14:23:05.123 UTC [12345] user@database LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp1234.0", size 245760
2024-05-16 14:23:05.123 UTC [12345] user@database DETAIL: Sort operation used temporary file because work_mem was exceeded
auto_explain 是 Postgres 的一个扩展,它会自动记录 query 的 EXPLAIN 计划,这对于调试和性能调优非常有用。Auto_explain 功能随 Postgres 提供,但必须明确启用。
-- add to preloaded libraries
-- create the extension
CREATE EXTENSION IF NOT EXISTS auto_explain;
-- restart Postgres after this
您可以设置 auto_explain 来记录不同持续时间的查询
-- Log plans for queries that run longer than 1000ms
auto_explain.log_min_duration = '1000ms';
auto_explain 还有其他设置,用于显示buffers和其他一些功能,请参阅auto_explain 文档( https://www.postgresql.org/docs/current/auto-explain.html )。Auto_explain 会生成大量日志,因此请谨慎操作。
对于非常大的查询或分区表上的查询,这些计划可能会非常长。另一种方法是始终为单个会话设置 auto_explain。
更多auto_explain的使用参考:
Auto_explain 日志看起来是这样的:
LOG: duration: 1008.035 ms plan:
May 17 02:42:06 z7j4asvir5dufokh5hpzoy postgres[43712]: [29-2]
Query Text: select count(*) from page_hits limit 1000;
是否记录给定的Autovacuum作业由参数log_autovacuum_min_duration控制,该参数自 PG15 起默认为 10 分钟,在之前的版本中默认禁用,值为 -1。由于自动清理的日志条目包含手动VACUUM VERBOSE命令输出中显示的所有相同信息,许多人会将其降低到一两秒来详细记录自动清理守护进程所完成的工作,或者通常会将其降低到 0 秒来记录其所有工作。
log_autovacuum_min_duration = '1s'
以下是自 PostgreSQL 主版本 15 以来auto VACUUM操作的日志示例:
[3506673][autovacuum worker][501/2614][0] LOG: automatic vacuum of table "testdb.public.pgbench_accounts": index scans: 1
pages: 0 removed, 327869 remain, 81969 scanned (25.00% of total)
tuples: 0 removed, 14769015 remain, 2000000 are dead but not yet removable
removable cutoff: 929, which was 3 XIDs old when operation ended
new relfrozenxid: 929, which is 11 XIDs ahead of previous value
frozen: 0 pages from table (0.00% of total) had 0 tuples frozen
index scan needed: 49181 pages from table (15.00% of total) had 2999999 dead item identifiers removed
index "pgbench_accounts_pkey": pages: 54840 in total, 8224 newly deleted, 8224 currently deleted, 0 reusable
I/O timings: read: 174.219 ms, write: 0.000 ms
avg read rate: 26.491 MB/s, avg write rate: 22.489 MB/s
buffer usage: 276192 hits, 41175 misses, 34955 dirtied
WAL usage: 123002 records, 57432 full page images, 75538789 bytes
system usage: CPU: user: 0.64 s, system: 0.27 s, elapsed: 12.14 s
以下是它们在之前主要版本中的样子:
[17656][autovacuum worker][5/463][0] LOG: automatic vacuum of table "testdb.public.pgbench_accounts": index scans: 1
pages: 0 removed, 327869 remain, 0 skipped due to pins, 0 skipped frozen
tuples: 0 removed, 14740860 remain, 2000000 are dead but not yet removable, oldest xmin: 760
index scan needed: 49181 pages from table (15.00% of total) had 2999999 dead item identifiers removed
index "pgbench_accounts_pkey": pages: 54840 in total, 8224 newly deleted, 8224 currently deleted, 0 reusable
I/O timings: read: 488.030 ms, write: 238.542 ms
avg read rate: 55.609 MB/s, avg write rate: 21.009 MB/s
buffer usage: 192958 hits, 124428 misses, 47008 dirtied
WAL usage: 122981 records, 0 full page images, 19019531 bytes
system usage: CPU: user: 1.14 s, system: 0.80 s, elapsed: 17.48 s
对于大多数拥有大型应用程序的用户来说,建议妥善处理日志,而不是将其丢弃。保持日志的可访问性和可搜索性对于修复错误至关重要,并且正如您上面所见,它对性能也非常有帮助。日志有点像保险。您可能不需要每天都使用它们,但当遇到问题时,您会很高兴它们在那里。
有一个开源项目用于分析 Postgres 日志,叫做 pgBadger。如果你曾经手动查看过日志,那么这个项目看起来就像变魔术一样。它会将 Postgres 日志输出转换成一个带有可缩放图表的 HTML 页面。
大多数人会定期或按需运行来分析 PostgreSQL 日志并生成 HTML 报告。
如果您使用的是托管云 Postgres 服务,并且能够将日志导出到文件中,那么可以使用 pgBadger。在 Crunchy Bridge 上,您可以像这样将日志拖尾到 pgBadger:
--send the CLI logs to a local text file
cb logs qzyqhjdg3focnta3zvleomq > pglogs.txt
-- pgBadger reads the text file and provides html output
pgbadger -f syslog pglogs.txt -o out.html
有很多公司乐于托管、解析并供您搜索日志。我们与一些客户合作,他们对 pgAnalyze、Datadog、Honeybadger 等服务非常满意。这些服务可以作为代理、小型 Pod 容器或其他服务运行,用于导出日志。对于使用云主机的用户来说,这确实是一个好主意。
--set up syslog drain
log_destination = 'syslog';
如今,大型应用程序的日志需要自行管理,这或许并不令人意外。一些团队选择自行托管和查询日志。Snowflake、Clickhouse、Crunchy Data Warehouse等系统以及许多其他系统都可以提供基于 SQL 的存储和查询引擎,以实现高吞吐量日志。当这些日志系统以平面文件的形式存储在对象存储中时,其成本效益非常高。
这是我今天讲到的所有内容的详细设置总结。不过各位……具体情况要根据实际情况而定,所以请仔细阅读文档并根据你的具体应用需求进行调整。不要直接复制粘贴。
-- Set up logging collector
ALTER SYSTEM SET logging_collector = 'on';
-- log system error messages
ALTER SYSTEM SET log_min_messages='error'
-- log all data definition changes
ALTER SYSTEM SET log_statement = 'ddl';
-- log the full statement for sql errors
ALTER SYSTEM SET log_min_error_statement= 'ERROR';
-- setlog file name
ALTER SYSTEM SET log_filename = 'postgres-%Y-%m-%d';
-- add database name and process id to log prefix
ALTER SYSTEM SET log_line_prefix = '%m [%p] %q%u@%d ';
-- rotate logs every day
ALTER SYSTEM SET log_rotation_age = '1d'
-- enable the pgaudit.log
ALTER SYSTEM SET pgaudit.log = 'ddl';
-- log queries longer than 1000ms
ALTER SYSTEM SET log_min_duration_statement = '1000';
-- Log lock waits
ALTER SYSTEM SET log_lock_waits = 'on';
-- log temp files, when postgres needs disk instead of cache, set to your work_mem
ALTER SYSTEM SET log_temp_files = '4096';
-- Log plans for queries that run longer than 1000ms
ALTER SYSTEM SET auto_explain.log_min_duration = '1000ms';
-- Set up some kind of log destination to a place to search logs
ALTER SYSTEM set log_destination = 'syslog';