开发者学堂课程【PostgreSQL快速入门： PostgreSQL 执行计划，成本公式解说，代价因子校准，自动跟踪SQL执行计划（三）】学习笔记与课程紧密联系，让用户快速学习知识
课程地址：https://developer.aliyun.com/learning/course/16/detail/91
PostgreSQL 执行计划，成本公式解说，代价因子校准，自动跟踪SQL执行计划（三）
内容介绍：
七、explain代价因子的校准
八、auto_explain 插件的使用
七、explain 代价因子校准
1、不同的硬件环境 CPU 性能，IO 性能各不相同，所以默认的代价因子可能不适合实际的硬件环境，如图代价需要实际的案例校准。
举个例子，第一步要校准的是连续扫描页面的成本（seq_page_cost）以及 cpu_tuple_cost，通过全表扫描校准 cpu_tuple_cost，连续扫描成本通过第三方的软件计算出来，或者从硬盘给的参数中推出来。这里用了 system temp 脚本计算每一个连续扫描的块带来的开销。
2、创建测试表
digoal=# create table tbl_cost align (id int, info text, crt_time timesteap)
CREATE TABLE
然后往里面插入一些记录，记录最好是随机的。这样的话可以使得我们后面要做的离散 IO请求测试更准确一些
digoal=# insert into tbl_cost_align select (random ()*2000000000)::int,md5(random0::text), clock_tinestanp （）from
generate_series(1,100000):
INSERT O 100000
digoal=# insert into (tbl_cost_align select Grandom （）*2000000000)::int,md5（random（）::text), clock_tinestamp （）from
generate_series(1,10000000);
INSERT O 10000000
总共插入了一千零十万行。插入以后要分析表，获得统计信息。
digoal=# analyze tbl_cost_align:
ANALYZE
3、可以查看到占用的数据块个数
digoal=# select relpages from pc_alass where relname
=’tbl_cost_align’
relpages
94393
(1 row)
得到 relpages 和总共的行数，行数是一千零十万行。
执行 checkpoint 后关闭数据库的了得到一个纯粹的物理磁盘的连续 io请求的 cost 常量，不能有 shared buffer 的干扰.
digoal# checkpoint;
CHECKPOINT
pc93@db-172-16-3-150-> pgctl stop -m fast
waiting for server to shut down.... done
server stopped
同时还不能有 OSCache的干扰，所以要清理操作系统 cache。
[root@db-172-16-3-150ssd1]# sync;echo3>/proc/sys/vm/drop_caches
前面我们说了，有些指标可以通过硬件厂商得到或者自行测试得到。那么这里我们就要自己测试得到。测试方法比较多，本文将通过systemtap 来得到每次 IO请求的时间。为了降低 systentap 带来的额外开销，
请参考:
http://blog.163.com/digoal@126/blog/static/1638770402013102610150692/ http://blog.163.com/digoal@126/blog/static/168770402013102621826954/
指定亲和1，启动数据库:
pg93@db-172-16-3-150->taskset-c1 /home/pg93/pgsq19.3.1/bin/postgres >/dev/null 2>@1
4、开启psql
pg93@db-172-16-3-150-> psq1
psql (9.3.1)
Type “help“ for help
digoal=# select pg_backend_pid():
pg_backend_pid
-----------------------
5727
（1 rows）
指定亲和7,开启stap，收集postgres进程相关的io信息
[root@db-172-16-3-150 ~]# taskset -c 7 stap -e ‘
global a
probe process("/hone/pg93/pgsq19.3.1/bin/postgres”).
mark("query_start")
delete a
println("query_start“,user_string($argl),“pid:",pid（）)
}
probe vfs. read return {
t=gettimeofday_ns() - @entry(gettimeofday_ns())
# if (execnme() ==“postarez" && devname != “N/A")
a[pid()] <<< t
}
probe process("/home/pg93/pgsql9.3.1/bin/postges").mark("
query_done") {
if (@count(a[pid()]))
printdln(“**", pid(), @count(a[pid()]), @avg(a[pid()])) println("query_done“,user_string($argl),“pid:",pid())
if (@count(a[pid()])) {
println (@hist_log(a[pid()]))
#println(@hist_linear(alpid()],1024,4096,100))
}
delete a
｝＇ -x 5727
这个 postgre 里面内置了一个探针，叫 query_start，探针一旦触发，会把a的全局变量数据删掉，然后打印一条记录，打印的是当前的 pid，还有查询的 SQL 语句。
每遇到一次 vfs.read 就会把它的时间记录下来。最后当查询结束的时候，统计总共开销的时间是多少，平均每一次 IO 的时间是多少，然后再输出它的柱状图。如果不是从真正的物理设备读，不要这条记录 # if (execnme() ==“postarez" && devname != “N/A") ，但是实际的操作过程中有域图的功能，实际场景当中可以不写这条语句。
5、接下来在 psql 中执行 explain analyze，在 explain 的结果中可以得到一个值，实际的执行时间(3260.695-0.839）。并且可以得到原始的cost(195393.00)，这个原始的cost有助于验证公式是否正确。
digoal=# explain (analyze,verbose, costs,buffers, liming) select * from tbl_cost_align:
QUERY PLAN
Seq Scan on postgres.tbl_cost_align (cost=0.00..195393.00 rows=10100000 width=45) (actual tine=0.839..3260.695
rows=10100000 loops
=1)
Output: id,info,crt_tine
Buffers: shared read=94393--注意这个read指的是未命中shared buffer，如果是命中的话会有hit=?
Total runtime: 4325.885 ms
(4 rows)
实际执行explain (analyze,verbose, costs,buffers, liming) select * from tbl_cost_align: 这条 SQL 语句的时候，stap 脚本已经开始监听了，有 query_start 的输出，之后对每一个 vfs.read 系统调用做一个运算，把时间加到 aipad 数组里。
执行完 explain 之后，在 stap 输出中得到了我们想要的平均 IO 响应时间信息(14329)
5727是postgre 进程的 pid，94417是调用多少次，@avg(a[pid()]) 是每一次 vfs.read 系统调用的时间开销，用到的秒是纳秒，每次io调用14329纳秒。下面是输出 IO 的柱状图，每一次 IO 请求统计出来的柱状图。
65536到131072纳秒之间有五千多次调用，实际上，真正的物理读只有五千多次。
实际上调用了九万多次，其中有八万多次在 oscache 里面调用，因为有预读，读的时候有 read had。物理设备每一次预读是 getra，block --getra /dev/sdb1，
sdb1 每次会预读256个数据块，每次会多读一些。最终得到的结果是读了将近六千次，已经预读了很多个数据块。
6、现在1000万条数据已经插完了，
analyze tbl_cost_align 看它占了多少数据块，总共是94393，pg_ct1 stop -m fast，把 oscache 清掉，pg_ct1 start 把数据库起来，起来之后要查看当前连接的 pid，要指定 cpu 亲和7，因为这里是一个八核的CPU。启用数据库，尽量不要用零号 ID 启动，重新启动。这样做是因为零号 CPU 会带来额外的开销，具体的原因和超系统有关。重新用一号 CPU 启动，一号数据库启动完成。
7、然后启动脚本，给它指定一个 pid，这个 pid 指的是进程的 pid，
脚本已经启动完成。stap 已经起来，模块已经加载好了。
现在要给一个查询语句，一定要用 analyze，因为要校准它，把它校准成 cost 跟实际的执行时间一样，这个时候就能看到输出。
30404**94419**8230 和原来的差别有点大，os cache 已经清掉了，说明数据是对的。真正的 io 响应时间在65539纳秒以上，因为有预读的功能，大部分 IO 在 os cache 里面响应。已经得到了平均 IO 响应时间，我们得到的是8230，跟预想不一样。
8、下面做一个公式，
shared hit 没有，read 是94393个数据块，这里真正在发生一些物理的读，下面从公式里面得到 cpu_tuple_cost，真正的时间是3554.348，这个值等于页面乘以真正的时间开销。这个时间是得到的8230，0.00823是毫秒，94393*0.00823 是每个数据会消耗的毫秒数，再加上 cpu_tuple_cost，cpu 是一千零十万行，再乘以一个x，还要减去启动0.839，要从这个公式里得到x。select （（3554.348-0.839）-94393*0.00823）/10100000，算出来x等于0.0002749162980198。
现在的两个值已经算好了，把它修改一下，seq_page_cost 修改成0.00823，cpu_tuple_cost 改成0.0002749162980198，现在两个因子已经校准完成。
可以重启数据库，pg_ctl restart -m fast，现在在 os cache 有如下内容，
所以要先把 os cache 清掉。然后再 explain analyze，得到的实际时间低一些，因为没有 cache stap，cache stap 会额外带来一些开销，现在校准的时间跟2369已经很接近了，刨去 skype 做探针 hander 带来的额外开销，探测94419次，这带来的额外开销有1.2秒左右，把这个时间去掉。现在出来的时间是连续扫描的时间，校准完这个之后，另外还要校准随机扫描的因子。
9、随机扫描页面的成本以及 CPU 的 index tuple cost，就是索引扫描带来的额外开销是多少，cpu_operate_cost 的校准。
这里有两个未知数，random_page_cosr 从stap跟踪获得，cpu_index_tuple_cost 和 cpu_operate_cost 两个未知数需要两个等式求得，一个等式不能求出两个未知数，要利用 cpu_index_tuple_cost 和 cpu_operate_cost 的比例得到第二个等式，这个比例来自 postgre 参数，它们的比例是2:1。现在要计算这个成本，先把所有的成本都归一，这样方便后面计算。
digoal=# set random_page_cost=1;
SET
digoal=# set cpu_tuple_cost=1；
SET
digoal=# set cpu_index_tuple_cost=1
SET
digoal=# set cpu_operator_cost=1;
SET
这次要走索引扫描，
digoal=# set enable_scqscan=off; set enable_bitmapscan=off; explain(analyze,verbose,costs,buffers,timing) select * from tbl_cost_align where id>1998999963;
QUERY PLAN
Index Scan using idx_tbl_cost_align_id on postgres.tbl_cost_align(cost=174.00..20181.67 rows=5031 width=45)（actual time=0.029.17.73 rows=5037 loops=1)
Output: id, info, crt_time
Index Cond:(tbl_cost_align.id>1998999963)
Buffers: shared hit=5054
Total runtime: 18.477 ms
(5 rows)
执行计划表明这是个索引扫描，至于扫了多少个数据块是未知的，索引的tuples也是未知的,已知的是cost和rows。
20181.67=blocks*random_page_cost +cpu_tuple_cost*5031 + cpu_index_tuple_cost*5031 + cpu_operator_cost*? 公式 ，一个是随机的 page cost，blocks 不知道，随机扫描多少块是不知道的，最终要在五千多行上做处理，cpu_tuple_cost*5031 是行数，cpu_operator_cost 在索引上面有多少 tuple 是不知道的，所以 cpu_operator_cost 乘以多少行是不知道的，这是一个过滤条件。过滤条件是从一万行里过滤出5031行还是六千行里过滤是不知道的，所以打了一个问号。这可以通过调整 cpu_operator_cost 来得到，
如果把它变成2，cost 就变成了25386，25386-20181得到5205，相当于是从5205行里过滤出5031行，相当于做了一个短式变换，这样就求出了从多少个索引的 tuple 上做条件扫描，扫描出5031行。
10、现在还要得到random_page_cost 的 blocks，这个 blocks 也是未知的。
现在把 random_page_cost 该成2，改成2之后在再做一个减法，就得到了 blocks，成本变小。现在等式更新成
0181.67=4914.66*random_page_cost+cpu_tuple_cost*5031 +cpu_index_tuple_cost*5031+ cpu_operator_cost*5205，接下来要做的是通过 stap 统计出 random_page_cost 的成本。通过以下方式写数据库，把 cache 清掉。
pg93@db-172-16-3-150->taskset-c 1/home/pg93/ pgsq9.3.1/
bin/postgres>/dev/null2>&1
[root@db-172-16-3-150~]# sync;echo3>/proc/sys
/vm/drop_caches
digoal=# select pg_backend_pid);
pg_backend_pid
10009
(1 row)
stap也是这样。
复制 taskset-c/home/pg93/pgsql9.3.1/bin/postgres>/dev/
null2>&1，把数据库清掉，重启。然后查看 pid，
是30653。执行digoal=# set enable_seqscan=off; set enable_
bitmapscan=off;explain (analyz e,verbose,costs, buffers,
timing)select*from tbl_cost_align where id>1998999963
这条 sql 语句，这个 SQL 语句的实际执行时间是1673毫秒，
随机扫描的成本也已经出来了，是326822。
比连续扫描大了40倍左右。因为是随机扫描，下图预读功能起到的功能很小，
只有10个块左右预读出来是有效的，大部分都不是预读出来的。替换等式，
select 1673.138-0.661=4914.66*0.326822+
0.00027491629801980198*4777+ *4777+ *5205，从两个等式里面就能得到 cpu_index_tuple_cost 和 cpu_operator_cost 。
11、把这两个放进去之后在执行 analyze，
结合例子1得到的两个常量，所有的5个常量值就调整好了
digoal=# set cpu_tuple_cost=0.00018884145574257426
SET
digoal=#set cpu_index_tuple cost=0.00433497085216479990 SET
digoal=#set cpu_operator_cost=0.00216748542608239995;
SET
digoal=# set seq_page_cost=0.014329
SET
digoal=# set random_page_cost=0.368362
SET
vi postgre.conf，进入到下图所示地方，
修改成如图，
接下来重启数据库，然后把 os cache 清掉，执行 analyze，where id＞1998999963，现在真实执行时间更跟 cost 很相近，cost 是1561，真正的执行时间是1141，相差的是随机扫描的时候 stap 带来的一些额外开销，可以忽略不计。
八、auto_explain 插件的使用
1、auto_explain 插件可以帮助我们发现一些执行计划不正常的SQL语句。
先把插件安装进来，cd /opt/soft_bak/postgresql1-9.3.2，编译的时候如果用 genetic world，就会编译好；如果没有，可以到 contribute 目录下 auto_explain 里面去 genetic。create extension auto_explain，auto_explain 直接load 就可以用，一个是线程用法，一个是非线程用法。
2、线程的用法是指直接 load ，
设置 SQL 语句大于指定的时间的时候，就会把它执行计划记下来。设定时间是10毫秒，只要超过10毫秒执行时间，都会把 SQL 语句记下来。select count （*） from tbl_cost_align，执行时间肯定是超过十毫秒的，这个时候就会把日志记到配置的日志目录中。默认配置目录是在 pg log 目录里，看一下当前日志是否已经记下了 explain？
刚才执行 select count（*） 的时候已经把执行计划记下来了，显然超过十毫秒。如果把它改成十秒钟，select count（*）就不会被记下来，因为执行时间没有超出，这个时候就没有记下来。
3、用这个还可以配在参数文件中，配置两个参数。
auto_explain 时间是100毫秒，超出100毫秒就会把这个 SQL 语句记下来。
它的好处是当一条 SQL 语句不正常的时候，把他的执行计划记下来，检查是否是因为没加索引导致执行时间变长。执行计划这个章节到此结束，可以练习使用 auto_explain 跟踪慢 sql 执行计划，explain 代价因此的校准。
