分享到

引言

在处理数据库支持的应用程序时,管理性能是一项持续的任务。运行缓慢的查询可能导致超时,降低用户体验,消耗更多资源,甚至可能根据你支付数据库费用的方式影响你的预算。这些问题使得理解数据库的性能特性变得很重要,以便你能识别并修复有问题的查询。

在本指南中,我们将讨论在 PostgreSQL 数据库中识别低效查询的不同方法。随后,我们将讨论可用于修复慢查询以维护 PostgreSQL 性能的不同技术。

检查活动查询和进程

在尝试追踪低性能查询时,首先要检查的是当前活动查询和进程的列表。PostgreSQL 通过 pg_stat_activity 视图提供此数据。

The pg_stat_activity 视图是 PostgreSQL 累积统计系统中的一个可用视图。它包含每个服务器进程的一行,帮助你查看每个进程当前正在处理什么。

要显示视图中的所有信息,请键入

SELECT * FROM pg_stat_activity \gx
-[ RECORD 1 ]----+-------------------------------
datid |
datname |
pid | 1963
leader_pid |
usesysid |
usename |
application_name |
client_addr |
client_hostname |
client_port |
backend_start | 2022-11-01 11:03:44.083043+01
xact_start |
query_start |
state_change |
wait_event_type | Activity
wait_event | AutoVacuumMain
state |
backend_xid |
backend_xmin |
query_id |
query |
backend_type | autovacuum launcher
-[ RECORD 2 ]----+-------------------------------
datid |
datname |
pid | 1965
leader_pid |
usesysid | 10
usename | postgres
application_name |
client_addr |
client_hostname |
client_port |
backend_start | 2022-11-01 11:03:44.083926+01
xact_start |
query_start |
state_change |
wait_event_type | Activity
wait_event | LogicalLauncherMain
state |
backend_xid |
backend_xmin |
query_id |
query |
backend_type | logical replication launcher
-[ RECORD 3 ]----+-------------------------------
datid | 13921
datname | postgres
pid | 836027
leader_pid |
usesysid | 10
usename | postgres
application_name | psql
client_addr |
client_hostname |
client_port | -1
backend_start | 2022-11-06 20:20:18.273218+01
xact_start | 2022-11-06 20:39:01.207078+01
query_start | 2022-11-06 20:39:01.207078+01
state_change | 2022-11-06 20:39:01.207088+01
wait_event_type |
wait_event |
state | active
backend_xid |
backend_xmin | 762
query_id |
query | select * from pg_stat_activity
backend_type | client backend
-[ RECORD 4 ]----+-------------------------------
datid |
datname |
pid | 1961
leader_pid |
usesysid |
usename |
application_name |
client_addr |
client_hostname |
client_port |
backend_start | 2022-11-01 11:03:44.082354+01
xact_start |
query_start |
state_change |
wait_event_type | Activity
wait_event | BgWriterHibernate
state |
backend_xid |
backend_xmin |
query_id |
query |
backend_type | background writer
-[ RECORD 5 ]----+-------------------------------
datid |
datname |
pid | 1960
leader_pid |
usesysid |
usename |
application_name |
client_addr |
client_hostname |
client_port |
backend_start | 2022-11-01 11:03:44.082065+01
xact_start |
query_start |
state_change |
wait_event_type | Activity
wait_event | CheckpointerMain
state |
backend_xid |
backend_xmin |
query_id |
query |
backend_type | checkpointer
-[ RECORD 6 ]----+-------------------------------
datid |
datname |
pid | 1962
leader_pid |
usesysid |
usename |
application_name |
client_addr |
client_hostname |
client_port |
backend_start | 2022-11-01 11:03:44.082653+01
xact_start |
query_start |
state_change |
wait_event_type | Activity
wait_event | WalWriterMain
state |
backend_xid |
backend_xmin |
query_id |
query |
backend_type | walwriter

注意: 使用 \gx 行终止符序列而不是传统的 `;` 分号告诉 PostgreSQL 为当前查询使用扩展输出模式。这会将每个记录的列和相关值垂直而不是水平显示,这在某些情况下可以提高可读性。

输出中有许多字段在查找较慢的查询时会很有帮助。其中一些最相关的包括

  • state:进程的当前状态。列为 active 的行正在执行。其他状态包括 idle(等待新客户端命令的进程)、idle in transaction(在事务上下文中等待命令的进程)和 idle in transaction (aborted)(语句导致错误的事务)。
  • query:最近执行的查询。对于活动进程,这将是当前正在执行的查询。
  • usename:与进程关联的用户名。
  • application_name:连接到进程的应用程序名称。
  • datname:用户连接到的数据库名称。
  • wait_event:进程正在等待的事件名称(如果有)。如果进程处于 active 状态并且存在 wait_event,则表示查询当前被系统中的其他部分阻塞。
  • wait_event_type:进程正在等待的事件类别。
  • pid:进程的进程 ID。
  • query_start:对于活动查询,表示当前查询开始的时间戳。
  • xact_start:如果进程正在执行事务,表示当前事务开始的时间戳。

我们可以根据当前上下文的相关列来过滤查询。一个有用的模式是使用 age() 函数来计算查询已运行的时间。例如

SELECT
age(clock_timestamp(), query_start),
usename,
datname,
query
FROM pg_stat_activity
WHERE
state != 'idle'
AND query NOT ILIKE '%pg_stat_activity%'
ORDER BY age desc;

这将显示非空闲查询的执行时间、用户名、数据库和查询文本。我们将结果按查询运行时间从长到短排序,并从结果中排除此特定查询。

同样,你可以看到所有非空闲但有等待事件的进程

SELECT
usename,
datname,
query,
wait_event_type,
wait_event
FROM pg_stat_activity
WHERE
state != 'idle'
AND query wait_event != ''

这可以帮助你查看因系统其他部分(例如,锁竞争)而未当前进展的查询。

检查其他系统统计信息

尽管 pg_stat_activity 视图可能会提供你识别慢查询所需的大部分信息,但查看其他系统统计信息也很有用,以帮助识别额外的优化目标。

查看数据库统计信息

The pg_stat_database 表包含每个数据库的统计信息

SELECT * FROM pg_stat_database \gx
. . .
-[ RECORD 2 ]------------+------------------------------
datid | 13921
datname | postgres
numbackends | 1
xact_commit | 266
xact_rollback | 9
blks_read | 229
blks_hit | 11263
tup_returned | 118708
tup_fetched | 3563
tup_inserted | 0
tup_updated | 0
tup_deleted | 0
conflicts | 0
temp_files | 0
temp_bytes | 0
deadlocks | 0
checksum_failures |
checksum_last_failure |
blk_read_time | 0
blk_write_time | 0
session_time | 5303626.534
active_time | 200.906
idle_in_transaction_time | 0
sessions | 2
sessions_abandoned | 0
sessions_fatal | 0
sessions_killed | 0
stats_reset | 2022-11-06 20:20:18.279798+01
. . .

对于我们的目的,一些有趣的列包括

  • blks_read:数据库中读取的磁盘块数。
  • blks_hit:磁盘块在缓冲区缓存中被找到的次数(避免了从磁盘进行慢速读取)。
  • xact_commit:已提交的事务数。
  • xact_rollback:已回滚的事务数。

正如 Data Egret 团队在其博客上所示,你可以使用这些原始值来计算有趣的统计数据,例如你的缓存命中率

SELECT
datname,
100 * blks_hit / (blks_hit + blks_read) as cache_hit_ratio
FROM
pg_stat_database
WHERE
(blks_hit + blks_read) > 0;
datname | cache_hit_ratio
-----------+-----------------
| 99
postgres | 98
template1 | 99
(3 rows)

这可能是很有价值的信息,可以帮助你评估是否可以通过增加数据库集群的 RAM 来获益,以便最常见的查询可以有效地缓存。

查看表统计信息

另一组有用的视图是 pg_stat_all_tablespg_stat_user_tablespg_stat_sys_tablespg_stat_all_tables 视图显示所有数据库的访问统计信息,而另外两个视图则根据表是用户表还是系统表进行过滤。

SELECT * FROM pg_stat_all_tables \gx
. . .
-[ RECORD 104 ]-----+------------------------
relid | 1262
schemaname | pg_catalog
relname | pg_database
seq_scan | 5168
seq_tup_read | 20655
idx_scan | 20539
idx_tup_fetch | 20539
n_tup_ins | 0
n_tup_upd | 0
n_tup_del | 0
n_tup_hot_upd | 0
n_live_tup | 0
n_dead_tup | 0
n_mod_since_analyze | 0
n_ins_since_vacuum | 0
last_vacuum |
last_autovacuum |
last_analyze |
last_autoanalyze |
vacuum_count | 0
autovacuum_count | 0
analyze_count | 0
autoanalyze_count | 0

这些视图中一些有趣的列包括

  • seq_scan:在表上运行的顺序扫描次数。
  • seq_tup_read:顺序扫描返回的行数。
  • idx_scan:针对表运行的索引扫描次数。
  • idx_tup_fetch:通过索引检索的行数。

这些列中的数字可以帮助你评估索引的性能以及你的查询是否有效地使用了它们。如果你发现你的表有许多顺序扫描,你可能会受益于创建可供你最常见查询使用的额外索引。

查看索引命中情况

如果你需要更多关于当前索引的信息,可以查看 pg_stat_all_indexespg_stat_user_indexespg_stat_sys_indexes 视图

SELECT * FROM pg_stat_all_indexes \gx
. . .
-[ RECORD 6 ]-+----------------------------------------------
relid | 1249
indexrelid | 2659
schemaname | pg_catalog
relname | pg_attribute
indexrelname | pg_attribute_relid_attnum_index
idx_scan | 822
idx_tup_read | 1670
idx_tup_fetch | 1670
. . .

这些视图提供了关于你的每个索引被使用频率的信息。idx_scan 列显示索引被扫描的次数。idx_tup_read 列显示扫描返回的条目数,而 idx_tup_fetch 显示索引扫描返回的总行数。

这些信息有助于你了解何时存在未被查询使用的索引。一旦识别出这些索引,你可以重写查询以利用它们,或者删除未使用的索引以提高写入性能。

查看锁信息

你收集的一些关于慢查询的信息可能指向了锁定问题。你可以通过查询 pg_locks 视图来获取当前所有持有锁的更多信息

SELECT * FROM pg_locks \gx
-[ RECORD 1 ]------+----------------
locktype | relation
database | 13921
relation | 12290
page |
tuple |
virtualxid |
transactionid |
classid |
objid |
objsubid |
virtualtransaction | 3/3920
pid | 967262
mode | AccessShareLock
granted | t
fastpath | t
waitstart |
-[ RECORD 2 ]------+----------------
locktype | virtualxid
database |
relation |
page |
tuple |
virtualxid | 3/3920
transactionid |
classid |
objid |
objsubid |
virtualtransaction | 3/3920
pid | 967262
mode | ExclusiveLock
granted | t
fastpath | t
waitstart |

输出将提供 PostgreSQL 中所有锁的信息。这有助于你诊断当不同进程请求控制相同对象时可能发生的争用问题。

一些可能帮助你调查问题锁的列包括

  • locktype可锁定对象的类型
  • database/relation/page/tuple:被锁定项的对象 ID。对于数据库和关系,这些可以在 pg_databasepg_class 中交叉引用。
  • mode:已实现或请求的锁模式
  • granted:表示锁是否已被授予的布尔值。

启用慢查询日志记录

更轻松地查找长时间运行查询信息的一种方法是启用慢查询日志记录。启用慢查询日志记录允许 PostgreSQL 自动记录任何执行时间超过给定时间的查询。这使你能够收集有关在调查时未执行的慢查询的信息。

检查 PostgreSQL 是否已启用慢查询日志记录

你首先应该做的是验证慢查询日志记录的当前状态。如果慢查询日志记录已启用,你无需进行任何操作。

你可以通过键入以下内容来检查是否启用了慢查询日志记录

SELECT * FROM pg_settings WHERE name = 'log_min_duration_statement'\gx
-[ RECORD 1 ]---+---------------------------------------------------------------------------
name | log_min_duration_statement
setting | -1
unit | ms
category | Reporting and Logging / When to Log
short_desc | Sets the minimum execution time above which all statements will be logged.
extra_desc | Zero prints all queries. -1 turns this feature off.
context | superuser
vartype | integer
source | default
min_val | -1
max_val | 2147483647
enumvals |
boot_val | -1
reset_val | -1
sourcefile |
sourceline |
pending_restart | f

如果你检查 short_descextra_desc 列的值,你将找到允许我们评估日志记录是否当前启用的信息。我们可以看到慢查询日志记录当前*未*启用,因为 setting 列当前设置为 -1

现在你了解了当前状态,可以根据需要进行更改。

配置 PostgreSQL 以记录慢查询

在继续之前,需要注意的是,虽然慢查询日志记录非常有用,但它可能会产生额外的性能影响。PostgreSQL 必须执行额外的操作来计时每个查询并将其结果记录到日志中。这可能会影响性能并意外地占用硬盘空间。

始终记录慢查询可能不是一个好主意。相反,在你积极调查问题时启用该功能,并在完成后禁用它。

全局记录慢查询

考虑到这一点,你可以通过修改 PostgreSQL 服务器的配置文件来全局配置慢查询日志记录。你也可以交互式地修改这些值,但在配置文件中设置良好的默认值将使以后交互式调整变得更容易。

打开 PostgreSQL 的配置文件。你可以通过键入以下内容找到当前配置文件的位置

SHOW config_file;
config_file
-----------------------------------------
/etc/postgresql/14/main/postgresql.conf
(1 row)

在文件中,搜索 log_min_duration_statement 设置。如果我们的示例输出值是从配置文件中读取的,它将被设置为 -1 以指示该功能当前已禁用。还有许多其他相关设置可以根据你的需要进行调整

. . .
# Query logging configuration
#log_min_duration_statement = -1 # -1 is disabled, 0 logs all statements
# and their durations, > 0 logs only
# statements running at least this number
# of milliseconds
#log_min_duration_sample = -1 # -1 is disabled, 0 logs a sample of statements
# and their durations, > 0 logs only a sample of
# statements running at least this number
# of milliseconds;
# sample fraction is determined by log_statement_sample_rate
#log_statement_sample_rate = 1.0 # fraction of logged statements exceeding
# log_min_duration_sample to be logged;
# 1.0 logs all such statements, 0.0 never logs
#log_transaction_sample_rate = 0.0 # fraction of transactions whose statements
# are logged regardless of their duration; 1.0 logs all
# statements from all transactions, 0.0 never logs
. . .

目前,log_min_duration_statement 设置被注释掉,其当前值设置为 -1 以表示默认值。文件中的其他设置都有很好的注释,允许你对超过最小值的语句进行采样,而不是记录所有语句。最后一个设置还允许你对事务中发生的语句进行采样。

你可以通过取消注释 log_min_duration_statement 并将其设置为另一个值来开启长查询日志记录。例如,我们可以将其设置为 5 秒,以记录任何执行时间超过此值的语句

log_min_duration_statement = 5s

保存文件后,你可以通过在 PostgreSQL 中键入以下内容来重新加载 PostgreSQL 服务器

SELECT pg_reload_conf();

你可以通过再次检查当前值来验证服务器是否正在使用你的新设置

SELECT * FROM pg_settings WHERE name = 'log_min_duration_statement'\gx
-[ RECORD 1 ]---+---------------------------------------------------------------------------
name | log_min_duration_statement
setting | 5000
unit | ms
category | Reporting and Logging / When to Log
short_desc | Sets the minimum execution time above which all statements will be logged.
extra_desc | Zero prints all queries. -1 turns this feature off.
context | superuser
vartype | integer
source | configuration file
min_val | -1
max_val | 2147483647
enumvals |
boot_val | -1
reset_val | 5000
sourcefile | /etc/postgresql/14/main/postgresql.conf
sourceline | 506
pending_restart | f

现在,setting 字段设置为 5000,unit 字段设置为 ms,表明我们设置的 5 秒已转换为 5000 毫秒并已应用。sourcefile 行也确认此值是从我们修改的配置文件中读取的。

按数据库记录慢查询

在尝试检测慢查询时,另一个选项是将慢查询日志记录限制到特定数据库。虽然 log_min_duration_statement 可以全局设置,如上一节所示,但它也可以在数据库级别进行配置。

要为单个数据库开启慢查询日志记录,请使用 ALTER DATABASE 命令

ALTER DATABASE helloprisma SET 'log_min_duration_statement' = 2000;
ALTER DATABASE

请注意,与全局设置不同,当使用 ALTER DATABASE 命令时,该值必须是一个不带单位的整数,表示毫秒时间。

我们可以通过查询每个数据库的角色设置来验证该设置是否已应用

\drds
List of settings
Role | Database | Settings
------+-------------+-------------------------------
| helloprisma | log_min_duration_statement=2000
(1 row)

我们可以验证这没有干扰我们之前设置为 5 秒阈值的全局设置

SELECT * FROM pg_settings WHERE name = 'log_min_duration_statement'\gx
-[ RECORD 1 ]---+---------------------------------------------------------------------------
name | log_min_duration_statement
setting | 5000
unit | ms
category | Reporting and Logging / When to Log
short_desc | Sets the minimum execution time above which all statements will be logged.
extra_desc | Zero prints all queries. -1 turns this feature off.
context | superuser
vartype | integer
source | configuration file
min_val | -1
max_val | 2147483647
enumvals |
boot_val | -1
reset_val | 5000
sourcefile | /etc/postgresql/14/main/postgresql.conf
sourceline | 506
pending_restart | f

测试慢查询日志记录

通过发出一个超过最小日志记录持续时间的语句来测试该设置

SELECT pg_sleep(10);
pg_sleep
----------
(1 row)

检查日志,你应该会找到指示发生了长时间运行查询的语句

2022-11-11 17:58:04.719 CET [1121088] postgres@postgres STATEMENT: select sleep(10);
2022-11-11 17:58:42.635 CET [1121088] postgres@postgres LOG: duration: 10017.171 ms statement: select pg_sleep(10);

由于我们为全局限制和特定表设置了不同的阈值,因此我们可以通过使用应触发其中一个而非另一个的查询时间来测试每个阈值是否正确应用。

例如,我们可以连接到具有较低阈值的数据库并休眠 4 秒,这应该会触发一条日志行

\c helloprisma
SELECT pg_sleep(4);

我们的日志显示

2022-11-13 14:46:07.361 CET [1252789] postgres@helloprisma STATEMENT: alter database helloprisma set log_min_duration_statement=2s;
2022-11-13 14:53:05.027 CET [1309069] postgres@helloprisma LOG: duration: 4022.546 ms statement: select pg_sleep(4);

现在,我们可以切换到只受全局设置影响的另一个数据库。相同的休眠语句不应触发日志行

\c postgres
SELECT pg_sleep(4);

不应记录新的日志行。

总结

在本文中,我们介绍了如何查看和理解 PostgreSQL 提供的一些性能信息。查看这些信息可以让你深入了解系统资源、查询模式和配置设置中的不同瓶颈。当你遇到性能问题时,可以检查 PostgreSQL 提供的信息,开始调查问题行为。

我们还讨论了如何使用慢查询日志记录来精确找出哪些查询正在占用系统资源并执行时间超出预期。记录这些数据并评估生成的日志可以帮助你确定可能需要额外索引、不同查询结构或更高效查询设计的地方。了解如何识别这些耗费资源的操作是运行更具功能性的数据库支持应用程序的第一步。

关于作者
Justin Ellingwood

Justin Ellingwood

Justin 自 2013 年以来一直撰写有关数据库、Linux、基础设施和开发者工具的文章。他目前与妻子和两只兔子居住在柏林。他通常不需要用第三人称写作,这让所有相关方都松了一口气。
© . All rights reserved.