一 问题现象
接开发同事反馈，某个日志表原来有100多万条记录，删除到只剩下200多条记录，在删除大量数据之后，执行查询，还是非常缓慢。
postgres=# \c superp2b_test superp2b_test You are now connected to database "superp2b_test" as user "superp2b_test". superp2b_test=> select count(*) from t_sys_exception_log; count ------- 267 (1 row) Time: 101702.768 ms superp2b_test=> create table t_sys_exception_log_bak as select * from t_sys_exception_log; SELECT 267 Time: 160531.138 ms superp2b_test=> select count(*) from t_sys_exception_log_bak ; count ------- 267 (1 row) Time: 87.180 ms superp2b_test=>
通过执行CTAS复制该表为t_sys_exception_log_bak之后，查询该复制表却不慢。
二查看表结构和表及相关索引统计信息
superp2b_test=> \d t_sys_exception_log
Table "public.t_sys_exception_log"
Column | Type | Modifiers
------------------+--------------------------------+-----------
id | character(32) | not null
class_name | character varying(512) |
create_time | timestamp(6) without time zone |
remark | character varying(1024) |
type | character varying(4) |
exception_type | character varying(1024) |
exception_detail | text |
method_name | character varying(255) |
source | character varying(1024) |
target | character varying(1024) |
operator_id | character(32) |
operator_name | character varying(255) |
Indexes:
"t_sys_exception_log_pkey" PRIMARY KEY, btree (id)
"t_sys_exception_log_class_name_idx" btree (class_name)
"t_sys_exception_log_create_time_idx" btree (create_time)
"t_sys_exception_log_exception_type_idx" btree (exception_type)
"t_sys_exception_log_method_name_idx" btree (method_name)
"t_sys_exception_log_operator_id_idx" btree (operator_id)
"t_sys_exception_log_operator_name_idx" btree (operator_name)
superp2b_test=> select relname,relpages,to_char(reltuples,'999999999') from pg_class where relname like 't_sys_exception_log%';
relname | relpages | to_char
----------------------------------------+----------+------------
t_sys_exception_log | 293660 | 1515498
t_sys_exception_log_class_name_idx | 14813 | 1515502
t_sys_exception_log_pkey | 20655 | 1515502
t_sys_exception_log_create_time_idx | 4162 | 1515502
t_sys_exception_log_exception_type_idx | 12626 | 1515502
t_sys_exception_log_method_name_idx | 8555 | 1515502
t_sys_exception_log_operator_id_idx | 5302 | 1515502
t_sys_exception_log_operator_name_idx | 5267 | 1515502
t_sys_exception_log_bak | 38 | 267
(9 rows)
Time: 12.494 ms
superp2b_test=>
从上，看到，虽然表里当前只有267条记录，但是由于删除大量数据之后，数据库没有及时更新该表的统计信息，导致数据库依然认为该表有1515498条记录，占用了293660个磁盘页。
三 分析其执行计划
superp2b_test=> explain analyze select count(*) from t_sys_exception_log; QUERY PLAN ------------------------------------------------------------------------------------------------------------------------------------- Aggregate (cost=312603.72..312603.73 rows=1 width=0) (actual time=25771.014..25771.014 rows=1 loops=1) -> Seq Scan on t_sys_exception_log (cost=0.00..308814.98 rows=1515498 width=0) (actual time=14.402..25770.915 rows=267 loops=1) Total runtime: 25771.087 ms (3 rows) Time: 25779.274 ms superp2b_test=>
的确，发现优化器对于该select count(*) from t_sys_exception_log语句，执行的全表扫描，且，优化器认为该表仍然有rows=1515498。实际上，该表只有267条记录。
四 收集统计信息
superp2b_test=> analyze verbose t_sys_exception_log;
信息: 正在分析 "public.t_sys_exception_log"
信息: "t_sys_exception_log": 已经扫描了293660页的30000, 包含28可用的记录和154878不能用的记录; 在示例中有28条记录,估算所有记录为1360704 .
ANALYZE
Time: 14294.586 ms
superp2b_test=> select relname,relpages,to_char(reltuples,'999999999') from pg_class where relname like 't_sys_exception_log%';
relname | relpages | to_char
----------------------------------------+----------+------------
t_sys_exception_log | 293660 | 1360704
t_sys_exception_log_class_name_idx | 14818 | 1360704
t_sys_exception_log_pkey | 20659 | 1360704
t_sys_exception_log_create_time_idx | 4163 | 1360704
t_sys_exception_log_exception_type_idx | 12629 | 1360704
t_sys_exception_log_method_name_idx | 8559 | 1360704
t_sys_exception_log_operator_id_idx | 5304 | 1360704
t_sys_exception_log_operator_name_idx | 5268 | 1360704
t_sys_exception_log_bak | 38 | 267
(9 rows)
Time: 18.558 ms
superp2b_test=> explain analyze select count(*) from t_sys_exception_log;
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=310668.80..310668.81 rows=1 width=0) (actual time=24315.485..24315.485 rows=1 loops=1)
-> Seq Scan on t_sys_exception_log (cost=0.00..307267.04 rows=1360704 width=0) (actual time=19.217..24315.358 rows=267 loops=1)
Total runtime: 24315.574 ms
(3 rows)
Time: 24346.502 ms
superp2b_test=>
通过analyze来收集统计信息时，数据库扫描了该表所占有的磁盘页的293660页中的30000页。同时，数据库认为该表仍然有1360704条记录。此时，数据库收集的统计信息依然是不准确的，或者说是错误的。且，数据库还把这个错误的统计信息更新到字典表pg_statistic中。
接下来，再执行一次统计信息收集，并查看其select count(*) from t_sys_exception_log语句的执行计划：
superp2b_test=> analyze verbose t_sys_exception_log;
信息: 正在分析 "public.t_sys_exception_log"
信息: "t_sys_exception_log": 已经扫描了293660页的30000, 包含26可用的记录和105480不能用的记录; 在示例中有26条记录,估算所有记录为1221722 .
ANALYZE
Time: 15645.520 ms
superp2b_test=> select relname,relpages,to_char(reltuples,'999999999') from pg_class where relname like 't_sys_exception_log%';
relname | relpages | to_char
----------------------------------------+----------+------------
t_sys_exception_log | 293660 | 1221722
t_sys_exception_log_class_name_idx | 14818 | 1221722
t_sys_exception_log_pkey | 20659 | 1221722
t_sys_exception_log_create_time_idx | 4163 | 1221722
t_sys_exception_log_exception_type_idx | 12629 | 1221722
t_sys_exception_log_method_name_idx | 8559 | 1221722
t_sys_exception_log_operator_id_idx | 5304 | 1221722
t_sys_exception_log_operator_name_idx | 5268 | 1221722
t_sys_exception_log_bak | 38 | 267
(9 rows)
Time: 11.437 ms
superp2b_test=> explain analyze select count(*) from t_sys_exception_log;
QUERY PLAN
------------------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=308931.52..308931.53 rows=1 width=0) (actual time=21058.435..21058.435 rows=1 loops=1)
-> Seq Scan on t_sys_exception_log (cost=0.00..305877.22 rows=1221722 width=0) (actual time=0.146..21058.327 rows=268 loops=1)
Total runtime: 21058.525 ms
(3 rows)
Time: 21161.205 ms
superp2b_test=>
数据库依然认为，t_sys_exception_log占用293660个磁盘页，有1221722条记录。同时，这个统计信息也是错误的。
五 数据库自动收集统计信息
由于手头上有事儿，暂时停止了上述手工收集该表统计信息的工作。忙完其它事情之后，再回过头来继续的时候，发现了“惊喜”。
superp2b_test=> explain analyze select count(*) from t_sys_exception_log;
QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=21547.18..21547.19 rows=1 width=0) (actual time=27.386..27.386 rows=1 loops=1)
-> Index Only Scan using t_sys_exception_log_create_time_idx on t_sys_exception_log (cost=0.30..20562.24 rows=393976 width=0) (actual time=9.056..27.337 rows=268 loops=1)
Heap Fetches: 23
Total runtime: 27.450 ms
(4 rows)
Time: 127.384 ms
superp2b_test=> select relname,relpages,to_char(reltuples,'999999999') from pg_class where relname like 't_sys_exception_log%';
relname | relpages | to_char
----------------------------------------+----------+------------
t_sys_exception_log | 293660 | 393976
t_sys_exception_log_class_name_idx | 14818 | 268
t_sys_exception_log_pkey | 20659 | 268
t_sys_exception_log_create_time_idx | 4163 | 268
t_sys_exception_log_exception_type_idx | 12629 | 268
t_sys_exception_log_method_name_idx | 8559 | 268
t_sys_exception_log_operator_id_idx | 5304 | 268
t_sys_exception_log_operator_name_idx | 5268 | 268
t_sys_exception_log_bak | 38 | 267
(9 rows)
Time: 18.922 ms
superp2b_test=> analyze verbose t_sys_exception_log;
信息: 正在分析 "public.t_sys_exception_log"
信息: "t_sys_exception_log": 已经扫描了293660页的30000, 包含32可用的记录和20不能用的记录; 在示例中有32条记录,估算所有记录为353760 .
ANALYZE
Time: 22083.290 ms
superp2b_test=> select relname,relpages,to_char(reltuples,'999999999') from pg_class where relname like 't_sys_exception_log%';
relname | relpages | to_char
----------------------------------------+----------+------------
t_sys_exception_log | 293660 | 353760
t_sys_exception_log_class_name_idx | 14818 | 353760
t_sys_exception_log_pkey | 20659 | 353760
t_sys_exception_log_create_time_idx | 4163 | 353760
t_sys_exception_log_exception_type_idx | 12629 | 353760
t_sys_exception_log_method_name_idx | 8559 | 353760
t_sys_exception_log_operator_id_idx | 5304 | 353760
t_sys_exception_log_operator_name_idx | 5268 | 353760
t_sys_exception_log_bak | 38 | 267
(9 rows)
Time: 13.805 ms
superp2b_test=> explain analyze select count(*) from t_sys_exception_log;
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=20885.77..20885.78 rows=1 width=0) (actual time=0.193..0.194 rows=1 loops=1)
-> Index Only Scan using t_sys_exception_log_create_time_idx on t_sys_exception_log (cost=0.30..20001.37 rows=353760 width=0) (actual time=0.052..0.159 rows=268 loops=1)
Heap Fetches: 23
Total runtime: 0.230 ms
(4 rows)
Time: 1.753 ms
superp2b_test=> select relname,relpages,to_char(reltuples,'999999999') from pg_class where relname like 't_sys_exception_log%';
relname | relpages | to_char
----------------------------------------+----------+------------
t_sys_exception_log | 293660 | 353760
t_sys_exception_log_class_name_idx | 14818 | 353760
t_sys_exception_log_pkey | 20659 | 353760
t_sys_exception_log_create_time_idx | 4163 | 353760
t_sys_exception_log_exception_type_idx | 12629 | 353760
t_sys_exception_log_method_name_idx | 8559 | 353760
t_sys_exception_log_operator_id_idx | 5304 | 353760
t_sys_exception_log_operator_name_idx | 5268 | 353760
t_sys_exception_log_bak | 38 | 267
(9 rows)
Time: 1.458 ms
superp2b_test=> vacuum(verbose,full,freeze,analyze) t_sys_exception_log;
信息: 正在清理 (vacuum) "public.t_sys_exception_log"
信息: "t_sys_exception_log": 在293660个页中找到0个可删除行版本，268不可删除的行版本.
DETAIL: 0 死行版本号仍不能移除.
CPU 3.04s/1.11u sec elapsed 29.73 sec.
信息: 正在分析 "public.t_sys_exception_log"
信息: "t_sys_exception_log": 已经扫描了38页的38, 包含268可用的记录和0不能用的记录; 在示例中有268条记录,估算所有记录为268 .
VACUUM
Time: 32353.681 ms
superp2b_test=> select relname,relpages,to_char(reltuples,'999999999') from pg_class where relname like 't_sys_exception_log%';
relname | relpages | to_char
----------------------------------------+----------+------------
t_sys_exception_log | 38 | 268
t_sys_exception_log_class_name_idx | 5 | 268
t_sys_exception_log_bak | 38 | 267
t_sys_exception_log_pkey | 4 | 268
t_sys_exception_log_create_time_idx | 2 | 268
t_sys_exception_log_exception_type_idx | 5 | 268
t_sys_exception_log_method_name_idx | 4 | 268
t_sys_exception_log_operator_id_idx | 4 | 268
t_sys_exception_log_operator_name_idx | 2 | 268
(9 rows)
Time: 6.762 ms
superp2b_test=> explain analyze select count(*) from t_sys_exception_log;
QUERY PLAN
------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=41.35..41.36 rows=1 width=0) (actual time=0.103..0.103 rows=1 loops=1)
-> Seq Scan on t_sys_exception_log (cost=0.00..40.68 rows=268 width=0) (actual time=0.005..0.074 rows=268 loops=1)
Total runtime: 0.133 ms
(3 rows)
Time: 0.535 ms
superp2b_test=> select count(*) from t_sys_exception_log;
count
-------
268
(1 row)
Time: 1.007 ms
superp2b_test=>
说明：
1 第一次执行查看执行计划时，发现执行计划有所改变，变的“更快更好”了，从之前的全表扫描变为索引扫描，执行效率变好了。但是，这个离真实情况下的执行计划，应该还是有误差，因为表里才268条记录，此时不应该走index的；
2 接下来，查看统计信息，发现t_sys_exception_log表上的统计信息依然显示有393976条记录，而该表上的index却显示的有268条记录，与真实情况向吻合；
3 再手工收集一次统计信息看看，再次发生偏差，结果显示有353760条记录，连之前索引上的统计信息也从正确的268条记录，变为了353760条记录；
4 干脆执行vacuum(verbose,full,freeze,analyze) t_sys_exception_log来回收空间+更新统计信息。这里，不论是从vacuum的verbose信息来看，还是从pg_class里的信息查询来看，统计信息终于正确了；
5 最后，再次查看执行计划，发现回归正常了。统计一个只有268条记录的表数据量，其选择的全表扫描的执行计划，比较合理。且，该条语句本身，执行起来，也回归正常了，不再像前面那么慢，让人费解了。
六 小结与疑问
1 对于PostgreSQL数据库而言，如果有频繁的DML操作，或者批量DML操作的情形，要及时更新统计信息；
2 为什么手工执行analyze收集统计信息时，得到的统计信息结果，与实际情况偏差那么大？
3 多次执行analyze之后，依然得不到准确的统计信息？
4 间隔一段时间之后，发现统计信息比较接近真实情况（此时，猜测应该是数据库autovacuum自动更新了统计信息）？
5 如果是autovacuum更新统计信息之后，为什么优化器选择的执行计划不够好，只有268条记录的表执行count操作，还是选择index scan?
6 为什么，最后通过执行vacuum来回收空间+更新统计信息之后，统计信息保持正确且不再变动？
