最近在实现一个列表查询的功能时遇到了【性能】问题,由于对后端性能方面没有太深入的了解和实践,所以在发现问题后卡了较长时间,通过查阅文档,借助分析工具,最终找到并解决问题。
这篇文章记录我解决问题的过程和学习到的新知识,如果有理解错误的地方,请帮我指出。
执行环境:Postgres 9.6.0
,Sequelize 4.44.0
问题背景
我要实现的功能是提供一个后端列表查询接口,这个接口涉及到数据库的三个表,分别是 UserSurveys
, Surveys
, Questionnaires
。实体关系是 1:1:1
。
查询接口从 User_Surveys
开始,通过外键 survey_id
关联 Surveys
表,外键 quesitonnaire_id
关联 Questionnaires
表。
这个接口需要支持根据 Questionnaire.name 过滤最终返回的 UserSurveys 条目。很简单的需求,之前已经做过很多次,我不加思索地写下以下代码并迅速提交代码(隐去了不相关的代码逻辑),项目中使用 Sequelize (一个 Node.js ORM 库)。
await UserSurvey.findAndCountAll({
offset,
limit,
where: {
status,
},
include: [
{
model: Survey,
required: true,
include: [
{
model: Questionnaire,
required: true,
where: {
name: {
[Op.like]: `%${questoinnaire_name}%`
}
}
}
}
]
}
],
order: [
['created_at', 'DESC'],
]
});
发完测试环境,开发自测的过程中发现,当我传入 querstionnaire_name 的时候请求特别慢!
慢到什么程度?搜索【问卷】请求完成时间是 【14.89s】!!!简单刷新重试几次,确认问题来自后端接口。
顺着请求路由,回溯到后端代码,确认我编写的代码没有问题。那就是 SQL
执行的问题?在日志文件中找到最终执行的 SQL
语句。
EXPLAIN ANALYZE SELECT "survey->questionnaire"."id"
AS "survey.questionnaire.id", "survey->questionnaire"."name" AS "survey.questionnaire.name" FROM ("user_surveys" AS "user_survey"
INNER JOIN "surveys" AS "survey" ON "user_survey"."survey_id" = "survey"."id"
INNER JOIN "questionnaires" AS "survey->questionnaire" ON "survey"."questionnaire_id" = "survey->questionnaire"."id"
AND "survey->questionnaire"."name" like '%问卷%') where "user_survey".status = 'PUBLISH' ORDER BY"user_survey"."created_at" DESC LIMIT 10 OFFSET 0;
三个表通过条件 Inner Join
,Sequelize
生成的 SQL
没什么问题,怎么确认是 SQL
执行语句的问题呢?
EXPLAIN 命令
在 Postgres
执行 SQL
语句之前,会对查询条件,数据属性,表结构等进行分析,选出一种最优的 Query Plan
。在 Query Plan
中描述了 Postgres
将会使用何种方式扫描数据库,如何连接表,运行成本等等信息。
通过阅读理解这些信息,开发者就能更好地理解查询语句的运行过程。
使用 EXPLAIN
命令很简单,只需要在原有语句前添加 EXPLAIN
。例如官方文档中的例子。
EXPLAIN SELECT * FROM tenk1;
QUERY PLAN
-------------------------------------------------------------
Seq Scan on tenk1 (cost=0.00..458.00 rows=10000 width=244)
执行 EXPLAIN SELECT * FROM tenk1;
得到的运行结果 Postgres
给出的 QUERY PLAN
,结果中可以看到将会使用 Seq Scan
的方式,遍历 tenk1 表,cost=0.00..458.0
表示预计的启动开销 0.00
, 和返回所有记录的总开销458.00
,总共会返回 10000
行(rows),每行占用内存 244 bytes
。
EXPLAIN
命令给出的是预估的执行计划数据,并不会真正地运行语句,想得到更真实的运行数据,需要使用加上 ANALYZE
参数。
EXPLAIN ANALYZE SELECT * FROM tenk1;
QUERY PLAN
--------------------------------------------------------------------------------------------------------
Seq Scan on tenk1 (cost=0.00..458.00 rows=10000 width=244) (actual time=0.128..0.377 rows=10000 loops=1)
Planning time: 0.181 ms
Execution time: 0.501 ms
加上 ANALYZE
参数之后,可以看到操作被执行的总次数(loops
),而 actual time
和 rows
是每次执行的平均值,以及整个语句最终执行时长(Execution time)。
"cost" 使用的是任意单位,通常是关心其相对值。而"actual time"数值是以真实时间的毫秒计的。
使用ANALYZE
如果需要执行 UPDATE
,INSERT
,DELETE
等操作要留心,最好是在事务中执行。
BEGIN;
EXPLAIN ANALYZE UPDATE ...;
ROLLBACK; or COMMIT;
阅读 Query Plan
Query Plan 返回的是一个树结构,执行顺序是子节点优先,一个上层节点的开销包括它的所有子节点的开销。
举个例子:
EXPLAIN ANALYZE SELECT *
FROM tenk1 t1, tenk2 t2
WHERE t1.unique1 < 100 AND t1.unique2 = t2.unique2
ORDER BY t1.fivethous;
返回的 Query Plan
--------------------------------------------------------------------------------------------------------------------------------------------
Sort (cost=717.34..717.59 rows=101 width=488) (actual time=7.761..7.774 rows=100 loops=1)
Sort Key: t1.fivethous
Sort Method: quicksort Memory: 77kB
-> Hash Join (cost=230.47..713.98 rows=101 width=488) (actual time=0.711..7.427 rows=100 loops=1)
Hash Cond: (t2.unique2 = t1.unique2)
-> Seq Scan on tenk2 t2 (cost=0.00..445.00 rows=10000 width=244) (actual time=0.007..2.583 rows=10000 loops=1)
-> Hash (cost=229.20..229.20 rows=101 width=244) (actual time=0.659..0.659 rows=100 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 28kB
-> Bitmap Heap Scan on tenk1 t1 (cost=5.07..229.20 rows=101 width=244) (actual time=0.080..0.526 rows=100 loops=1)
Recheck Cond: (unique1 < 100)
-> Bitmap Index Scan on tenk1_unique1 (cost=0.00..5.04 rows=101 width=0) (actual time=0.049..0.049 rows=100 loops=1)
Index Cond: (unique1 < 100)
Planning time: 0.194 ms
Execution time: 8.008 ms
->
标记着树节点,暂时移除开销的信息,抽离出来树干结构如下。
Sort
Sort Key: t1.fivethous
Sort Method: quicksort Memory: 77kB
└── Hash Join
Hash Cond: (t2.unique2 = t1.unique2)
├── Seq Scan
└── Hash
└── Bitmap Heap Scan
└── Bitmap Index Scan
Index Cond: (unique1 < 100)
从这个结构中可以看出,Postgres 使用 Seq Scan
的方式读取 tenk2 表,再使用 Bitmap Heap Scan
和 Bitmap Index Scan
的方式扫描 tenk1 表,将符合条件(unique1 < 100)
的条目读入内存 Hash。
接着使用 Hash Join
的连接方式,根据连接条件Hash Cond: (t2.unique2 = t1.unique2)
连接子节点的扫描结果。
最后使用 quicksort
的方式,基于 t1.fivethous
字段进行排序,得到最终查询结果。
什么是索引(Index)?
数据库中索引就像书籍中的关键字检索,按字符顺序排列,当我们想看某个关键字在书本中出现的位置的时候,可以通过这份 Index
快速定位到具体页面,直接翻到对应的页面,而不是从第一页开始一页一页地查找关键字。
数据库中分为 ClusterIndex 和 NonClusterIndex,ClusterIndex 一个表只有一个,由数据库根据 Table 唯一主键创建,NonClusterIndex 一个表可以出现很多个,可以由用户自由维护。
当我们在 DB 中运行 Create Index
时,就是创建了一个 NonClusterIndex,数据库会维护一个结构来记录 ClusterIndex 和 NonClusterIndex 的关系。
按照 NonClusterIndex 进行排序,之后使用索引就能快速定位到想要查找的条目。
不过需要注意:
- 维护索引本身需要成本的,在数据库内容发生变更时,通常都需要对应地调整索引。
- 使用索引也需要开销,使用索引的顺序会导致数据库读取头在行间跳跃,这比顺序读取的开销要大得多。
Seq Scan、Index Scan、Bitmap Heap Scan
在执行不同的 Query 时,规划器可能会使用不同的扫描节点方式。
EXPLAIN SELECT * FROM tenk1 WHERE unique1 < 7000;
QUERY PLAN
------------------------------------------------------------
Seq Scan on tenk1 (cost=0.00..483.00 rows=7001 width=244)
Filter: (unique1 < 7000)
上面的例子中,规划器将使用 Seq Scan
的方式扫描 tenk1 表的每一行,根据 Filter 条件过滤符合条件的条目。
有的时候,规划器则会选择使用 Index Scan
,通过索引条件直接查找。
EXPLAIN SELECT * FROM tenk1 WHERE unique1 = 42;
QUERY PLAN
-----------------------------------------------------------------------------
Index Scan using tenk1_unique1 on tenk1 (cost=0.29..8.30 rows=1 width=244)
Index Cond: (unique1 = 42)
在这种规划类型中,表的数据行是以索引顺序抓取的,意味着数据库读取头需要在数据行之前来回跳动,数据量很大的情况下,开销非常大。
还有另一种类型 Bitmap Heap Scan
EXPLAIN SELECT * FROM tenk1 WHERE unique1 < 100 AND stringu1 = 'xxx';
QUERY PLAN
------------------------------------------------------------------------------
Bitmap Heap Scan on tenk1 (cost=5.04..229.43 rows=1 width=244)
Recheck Cond: (unique1 < 100)
Filter: (stringu1 = 'xxx'::name)
-> Bitmap Index Scan on tenk1_unique1 (cost=0.00..5.04 rows=101 width=0)
Index Cond: (unique1 < 100)
Bitmap Heap Scan 分为两步,首先通过 Bitmap Index Scan 从表中抓取出匹配的行,再由上层规划节点在读取他们之前按照物理位置排序,这样可以最小化开销。
接着看表连接相关的知识。
Nested loops, Hash Join, Merge Join
Nested loops 工作方式是循环从一张表中读取数据,然后访问另一张表(通常有索引)。驱动表中的每一行与 inner 表中的相应记录JOIN,类似一个嵌套的循环。
EXPLAIN SELECT *
FROM tenk1 t1, tenk2 t2
WHERE t1.unique1 < 10 AND t1.unique2 = t2.unique2;
QUERY PLAN
--------------------------------------------------------------------------------------
Nested Loop (cost=4.65..118.62 rows=10 width=488)
-> Bitmap Heap Scan on tenk1 t1 (cost=4.36..39.47 rows=10 width=244)
Recheck Cond: (unique1 < 10)
-> Bitmap Index Scan on tenk1_unique1 (cost=0.00..4.36 rows=10 width=0)
Index Cond: (unique1 < 10)
-> Index Scan using tenk2_unique2 on tenk2 t2 (cost=0.29..7.91 rows=1 width=244)
Index Cond: (unique2 = t1.unique2)
在这个例子中,规划器使用了 Nested Loop
的表连接方式,使用 Bitmap Heap Scan 扫描 tenk1 表,获得 10 行数据。接着 Nested Loop 将对获得的每行数据进行执行一次内部扫描,将匹配条件的 (unique2 = t1.unique2)
数据连接。运行成本约为 【外层扫描开销 39.27】 + 【内层扫描开销 10 * 7.91】+ 一点 CPU 的计算时间。
使用 JS 代码描述,过程大概如下,对于 tenk1 中的每一行数据,都会在 tenk2 中执行一次查找,如果没有索引的情况下,时间复杂度是 O(MN)。
for (const t1 of tenk1) {
for (const t2 of tenk2) {
if (t1.unique2 === t2.unique2) {
t1.tenk2 = t2;
break;
}
}
}
稍加修改查询条件,可能会得到另一种连接方式
EXPLAIN SELECT *
FROM tenk1 t1, tenk2 t2
WHERE t1.unique1 < 100 AND t1.unique2 = t2.unique2;
QUERY PLAN
------------------------------------------------------------------------------------------
Hash Join (cost=230.47..713.98 rows=101 width=488)
Hash Cond: (t2.unique2 = t1.unique2)
-> Seq Scan on tenk2 t2 (cost=0.00..445.00 rows=10000 width=244)
-> Hash (cost=229.20..229.20 rows=101 width=244)
-> Bitmap Heap Scan on tenk1 t1 (cost=5.07..229.20 rows=101 width=244)
Recheck Cond: (unique1 < 100)
-> Bitmap Index Scan on tenk1_unique1 (cost=0.00..5.04 rows=101 width=0)
Index Cond: (unique1 < 100)
在这个例子中,规划器选择了哈希连接,tenk1 (通常是选择较小的表) 通过 Bitmap Heap Scan 扫入到内存中的哈希表,结合 tenk2 的扫描结果对每一行进行哈希表探测。
用 JS 代码描述代码执行过程大致如下,这种方式的时间复杂度为 O(N + M)
const dict = {};
for (const t1 of tenk1) {
dict[t1.unique2] = t1;
}
for (const t2 of tenk2) {
t2['tenk2'] = dict[t2.unique2]
}
还有一种连接方式 Merge Join
,这种连接方式要求输入中的连接键都是有序的。
EXPLAIN SELECT *
FROM tenk1 t1, onek t2
WHERE t1.unique1 < 100 AND t1.unique2 = t2.unique2;
QUERY PLAN
------------------------------------------------------------------------------------------
Merge Join (cost=198.11..268.19 rows=10 width=488)
Merge Cond: (t1.unique2 = t2.unique2)
-> Index Scan using tenk1_unique2 on tenk1 t1 (cost=0.29..656.28 rows=101 width=244)
Filter: (unique1 < 100)
-> Sort (cost=197.83..200.33 rows=1000 width=244)
Sort Key: t2.unique2
-> Seq Scan on onek t2 (cost=0.00..148.00 rows=1000 width=244)
对于大量行的排序,顺序扫描加排序通常比索引扫描更高效,因为索引扫描需要非连续的磁盘访问。
定位问题
掌握了如何使用 EXPLAIN 命令,回到最初的问题,查看为什么我的查询语句问题出在哪里?
QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------------------
Limit (cost=256.52..256.52 rows=1 width=540) (actual time=7257.566..7257.568 rows=10 loops=1)
-> Sort (cost=256.52..256.52 rows=1 width=540) (actual time=7257.564..7257.566 rows=10 loops=1)
Sort Key: user_survey.created_at DESC
Sort Method: top-N heapsort Memory: 26kB
-> Nested Loop (cost=26.88..256.51 rows=1 width=540) (actual time=156.527..7257.419 rows=196 loops=1)
-> Nested Loop (cost=0.00..221.74 rows=1 width=548) (actual time=0.957..7057.564 rows=1647 loops=1)
Join Filter: (survey.questionnaire_id = "survey->questionnaire".id)
Rows Removed by Join Filter: 6539694
-> Seq Scan on questionnaires "survey->questionnaire" (cost=0.00..130.07 rows=1 width=532) (actual time=0.009..1.591 rows=3441 loops=1)
Filter: ((name)::text ~~ '%问卷%'::text)
Rows Removed by Filter: 176
-> Seq Scan on surveys survey (cost=0.00..67.96 rows=1896 width=32) (actual time=0.001..1.247 rows=1901 loops=3441)
-> Bitmap Heap Scan on user_surveys user_survey (cost=26.88..34.75 rows=2 width=24) (actual time=0.121..0.121 rows=0 loops=1647)
Recheck Cond: (((status)::text = 'PUBLISH'::text) AND (survey_id = survey.id))
Heap Blocks: exact=134
-> BitmapAnd (cost=26.88..26.88 rows=2 width=0) (actual time=0.120..0.120 rows=0 loops=1647)
-> Bitmap Index Scan on user_surveys_status_index (cost=0.00..10.23 rows=242 width=0) (actual time=0.064..0.064 rows=310 loops=1647)
Index Cond: ((status)::text = 'PUBLISH'::text)
-> Bitmap Index Scan on user_surveys_survey_id_index (cost=0.00..16.33 rows=1753 width=0) (actual time=0.055..0.055 rows=72 loops=1647)
Index Cond: (survey_id = survey.id)
Planning time: 1.434 ms
Execution time: 7257.672 ms
(22 rows)
从 Query Plan 上可以看到,这个查询需要 7.2s 的执行时间!哪里有问题?
Nested Loop (cost=0.00..221.74 rows=1 width=548) (actual time=0.957..7057.564 rows=1647 loops=1)
Join Filter: (survey.questionnaire_id = "survey->questionnaire".id)
Rows Removed by Join Filter: 6539694
-> Seq Scan on questionnaires "survey->questionnaire" (cost=0.00..130.07 rows=1 width=532) (actual time=0.009..1.591 rows=3441 loops=1)
Filter: ((name)::text ~~ '%问卷%'::text)
Rows Removed by Filter: 176
-> Seq Scan on surveys survey (cost=0.00..67.96 rows=1896 width=32) (actual time=0.001..1.247 rows=1901 loops=3441)
从报告中可以看出,规划器在连接 Surveys 和 Questionnaires 表时,使用的连接方式是 Nested Loop,外层遍历 Questionnaires 表得到 3441 行数据,内层继续顺序遍历 Surveys 表,执行 3441 次,前面提到了,这种方式最差的时间复杂度是 O(MN)。
对症下药,优化的方案就是让规划器有更优的执行方案可选,改善表连接的糟糕表现,具体操作是给 surveys.questionnaire_id 添加索引。
CREATE INDEX surveys_questionnaire_id_index ON surveys (questionnaire_id);
再次执行 EXPLAIN ANYLYZE
,可以看到规划器使用上了我们增加的索引,基于索引检索之后再进行表连接明显快了很多,查询总时长从 7.2s 减小到 160ms。
...
Nested Loop (cost=4.34..156.90 rows=1 width=548) (actual time=0.030..7.091 rows=1647 loops=1)
-> Seq Scan on questionnaires "survey->questionnaire" (cost=0.00..130.07 rows=1 width=532) (actual time=0.008..0.839 rows=3441 loops=1)
Filter: ((name)::text ~~ '%问卷%'::text)
Rows Removed by Filter: 176
-> Bitmap Heap Scan on surveys survey (cost=4.34..26.74 rows=8 width=32) (actual time=0.001..0.001 rows=0 loops=3441)
Recheck Cond: (questionnaire_id = "survey->questionnaire".id)
Heap Blocks: exact=281
-> Bitmap Index Scan on surveys_questionnaire_id_index (cost=0.00..4.34 rows=8 width=0) (actual time=0.001..0.001 rows=0 loops=3441)
Index Cond: (questionnaire_id = "survey->questionnaire".id)
...
Planning time: 0.692 ms
Execution time: 160.381 ms
继续查看报告,发现在做第外层 Nested Loop
表连接的时候,Bitmap Heap Scan on user_surveys 执行时间为 1647 * 0.085ms。
Nested Loop (cost=31.20..191.79 rows=1 width=540) (actual time=0.971..148.585 rows=196 loops=1)
-> Nested Loop (cost=4.34..157.03 rows=1 width=548) (actual time=0.024..6.963 rows=1647 loops=1)
...
-> Bitmap Heap Scan on user_surveys user_survey (cost=26.86..34.74 rows=2 width=24) (actual time=0.085..0.085 rows=0 loops=1647)
Recheck Cond: (((status)::text = 'PUBLISH'::text) AND (survey_id = survey.id))
Heap Blocks: exact=134
-> BitmapAnd (cost=26.86..26.86 rows=2 width=0) (actual time=0.085..0.085 rows=0 loops=1647)
-> Bitmap Index Scan on user_surveys_status_index (actual time=0.015..0.015 rows=310 loops=1647)
Index Cond: ((status)::text = 'PUBLISH'::text)
-> Bitmap Index Scan on user_surveys_survey_id_index (actual time=0.069..0.069 rows=72 loops=1647)
Index Cond: (survey_id = survey.id)
主要时间是花在了扫描两个索引上,单次耗时 0.085ms
BitmapAnd (cost=26.86..26.86 rows=2 width=0) (actual time=0.085..0.085 rows=0 loops=1647)
-> Bitmap Index Scan on user_surveys_status_index (actual time=0.015..0.015 rows=310 loops=1647)
Index Cond: ((status)::text = 'PUBLISH'::text)
-> Bitmap Index Scan on user_surveys_survey_id_index (actual time=0.069..0.069 rows=72 loops=1647)
Index Cond: (survey_id = survey.id)
再次对症下药,添加一个多列索引
CREATE INDEX user_surveys_status_survey_id_index ON user_surveys (status, survey_id);
多列索引列的顺序是有讲究的,按照常用频率从左到右,这样能更好地利用索引。
再次执行 EXPLAIN
Limit (cost=163.81..163.82 rows=1 width=540) (actual time=10.097..10.099 rows=10 loops=1)
-> Sort (cost=163.81..163.82 rows=1 width=540) (actual time=10.096..10.096 rows=10 loops=1)
Sort Key: user_survey.created_at DESC
Sort Method: top-N heapsort Memory: 26kB
-> Nested Loop (cost=4.76..163.80 rows=1 width=540) (actual time=0.258..10.023 rows=196 loops=1)
-> Nested Loop (cost=4.34..157.03 rows=1 width=548) (actual time=0.027..6.812 rows=1647 loops=1)
-> Seq Scan on questionnaires "survey->questionnaire" (cost=0.00..130.21 rows=1 width=532) (actual time=0.008..0.810 rows=3441 loops=1)
Filter: ((name)::text ~~ '%问卷%'::text)
Rows Removed by Filter: 176
-> Bitmap Heap Scan on surveys survey (cost=4.34..26.74 rows=8 width=32) (actual time=0.001..0.001 rows=0 loops=3441)
Recheck Cond: (questionnaire_id = "survey->questionnaire".id)
Heap Blocks: exact=281
-> Bitmap Index Scan on surveys_questionnaire_id_index (cost=0.00..4.34 rows=8 width=0) (actual time=0.001..0.001 rows=0 loops=3441)
Index Cond: (questionnaire_id = "survey->questionnaire".id)
-> Index Scan using user_surveys_status_survey_id_index on user_surveys user_survey (cost=0.42..6.75 rows=2 width=24) (actual time=0.002..0.002 rows=0 loops=1647)
Index Cond: (((status)::text = 'PUBLISH'::text) AND (survey_id = survey.id))
Planning time: 0.622 ms
Execution time: 10.163 ms
现在执行时长已经降到了 10ms 了,10ms
是规划器执行的时间,加上数据传递给客户端,ORM 包的处理,网络传输等时间才更接近用户在前端最终感知到的时间。
最终,Chrome Network Panel 上看,从前端发起查询时长终于降到合理的范围(前端 Input 组件本身会做 500ms
Debounce)。
总结
通过一次完整的学习,掌握了科学有效的方法,以后就不用盲目去猜测是否需要添加索引。遇到性能问题也能更快更有效地解决。
再次说明,这篇文章是我在学习过程中的笔记,由于水平有限,可能存在不准确的信息,仅供参考。深入的学习,还请以官方文档为准。