关于PostgreSQL的IO

如果数据库的IO出现瓶颈，通常可以通过PG的参数进行调优。为了更好的优化IO应该了解PG的IO。

哪些地方会产生IO?

PG产生的IO可以归结到下面这几个地方。

WAL写入
每个事务执行都会产生IO，同步提交下提交时还会刷新磁盘。Checkpoint后脏页的首次刷出是全页写，最糟的情况每个小事务产生8K WAL写入，后面的WAL写入量可以粗略的认为和数据更新量相当。有个后台WAL写入进程专门把WAL Buffer写到磁盘，后台WAL刷的速度赶不上WAL Buffer写入速度时，postgres进程会直接把WAL Buffer写入磁盘。
后台写入器
后台写入器的目标为postgres进程预留足够的缓冲区，默认是最近所需的平均值的2倍(bgwriter_lru_multiplier)，但默认每 200 毫秒(bgwriter_delay)不超过100 个缓冲区(bgwriter_lru_maxpages)。
Checkpoint
每次Checkpoint会刷出缓冲区中的所有脏页。触发Checkpoint的时点有两个，一个默认5 分钟(checkpoint_timeout)的定期检查点，另一个是产生的WAL文件数超过checkpoint_segments时。9.5以后checkpoint_segments参数被去掉了，改成了是max_wal_size，WAL写入量超过max_wal_size的1/3~1/2时触发Checkpoint。
自动清理
自动清理可能会从磁盘读取数据块。每次自动清理的量可以通过相关参数控制。
postgres进程
- 读入缓冲区中缺失的页时会产生磁盘读。
- WAL后台写入器忙不过来时，postgres进程也会直接写和刷WAL。
- 后台写入器未能预留足够缓冲区时，刷出脏的缓冲区。
- work_mem不足时生成临时文件也会产生IO。

TPCC产生的IO的例子

通过BenchmarkSQL跑TPCC测试，看一看IO情况。

测试环境

4 core虚机，2GB内存。
PostgreSQL 9.5

BenchmarkSQL设置

30个仓库，3GB的样子。

[root@node2 run]#cat props.pg
driver=org.postgresql.Driver
conn=jdbc:postgresql://localhost:5432/benchmarksql2
user=postgres
password=password

warehouses=30
terminals=4
//To run specified transactions per terminal- runMins must equal zero
runTxnsPerTerminal=0
//To run for specified minutes- runTxnsPerTerminal must equal zero
runMins=2
//Number of total transactions per minute
limitTxnsPerMin=0


//The following five values must add up to 100
//The default percentages of 45, 43, 4, 4 & 4 match the TPC-C spec
newOrderWeight=45
paymentWeight=43
orderStatusWeight=4
deliveryWeight=4
stockLevelWeight=4

PostgreSQL参数

shared_buffers是512MB，不能覆盖所有数据。

logging_collector = on 
log_directory = 'pg_log'
log_line_prefix = '%m %c '
log_checkpoints = on
shared_buffers = 512MB
maintenance_work_mem = 150MB
max_wal_size = 2GB
wal_level=hot_standby
full_page_writes = on
synchronous_commit = on

测试前

postgres=# select pg_stat_reset();
 pg_stat_reset 
---------------

(1 row)

postgres=# select pg_stat_reset_shared('bgwriter');
 pg_stat_reset_shared 
----------------------

(1 row)
postgres=# select pg_current_xlog_location();
 pg_current_xlog_location 
--------------------------
 4/7027C648
(1 row)

测试

[root@node2 run]# sh runBenchmark.sh props.pg

BenchmarkSQL的安装和测试前的数据导入略。

测试结果

[root@node2 run]# sh runBenchmark.sh props.pg 
Term-00, Running Average tpmTOTAL: 12861.34    Current tpmTOTAL: 425544    Memory Usage: 9MB / 35MB

系统产生WAL的速度大概是9MB/s。

benchmarksql2=# select pg_current_xlog_location();
 pg_current_xlog_location 
--------------------------
 4/E9B61648
(1 row)

benchmarksql2=# select pg_xlog_location_diff('4/E9B61648','4/7027C648')/(60*5);
-[ RECORD 1 ]------------------
?column? | 6797899.093333333333

IO读都发生在postgres进程。写入则发生在多个进程，后台WAL写入进程产生的写很少，WAL写入主要是postgres进程在做。

[root@node2 run]# iotop
Total DISK READ :      23.72 M/s | Total DISK WRITE :      16.29 M/s
Actual DISK READ:      23.72 M/s | Actual DISK WRITE:       7.17 M/s
  TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN     IO>    COMMAND                                                                                
 2635 be/4 postgres    4.07 M/s 1097.99 K/s  0.00 % 31.34 % postgres: postgres benchmarksql2 127.0.0.1(35112) COMMIT
 2634 be/4 postgres    9.16 M/s 1405.13 K/s  0.00 % 24.42 % postgres: postgres benchmarksql2 127.0.0.1(35111) idle in transaction
 2637 be/4 postgres    5.38 M/s    2.86 M/s  0.00 % 20.23 % postgres: postgres benchmarksql2 127.0.0.1(35114) COMMIT
 2636 be/4 postgres    5.11 M/s 1888.86 K/s  0.00 % 16.84 % postgres: postgres benchmarksql2 127.0.0.1(35113) COMMIT
 2603 be/4 postgres    0.00 B/s   69.10 K/s  0.00 %  1.54 % postgres: wal writer process
 2601 be/4 postgres    0.00 B/s    4.99 M/s  0.00 %  0.00 % postgres: checkpointer process
 2602 be/4 postgres    0.00 B/s    4.08 M/s  0.00 %  0.00 % postgres: writer process
    1 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % systemd --switched-root --system --deserialize 24
    2 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [kthreadd]
    3 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [ksoftirqd/0]

    [root@node2 run]# iostat -x 60 5
    avg-cpu:  %user   %nice %system %iowait  %steal   %idle
              28.11    0.00   28.36   17.27    0.00   26.26

    Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
    sda               0.55     1.18 1019.82  820.18 26093.60 16734.47    46.55    13.22    7.21    3.43   11.92   0.47  86.78
    scd0              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00    0.00    0.00   0.00   0.00
    dm-0              0.00     0.00 1019.75  821.33 26082.73 16734.38    46.51    13.36    7.25    3.44   11.98   0.47  86.90
    dm-1              0.00     0.00    0.62    0.02     2.47     0.07     8.00     0.00    1.13    1.16    0.00   0.16   0.01

这期间发生了2次checkpoint(另2次checkpoint是测试后发生的)。

[root@node2 run]# vi /data/postgresql/data/pg_log/postgresql-2016-06-05_222924.log
2016-06-05 22:32:13.330 CST 57543744.a29 LOG:  checkpoint starting: xlog
2016-06-05 22:33:19.221 CST 57543744.a29 LOG:  checkpoint complete: wrote 40523 buffers (61.8%); 0 transaction log file(s) added, 0 removed, 25 recycled; write=64.058 s, sync=1.593 s, total=65.893 s; sync files=38, longest=1.354 s, average=0.041 s; distance=718446 kB, estimate=718446 kB
2016-06-05 22:34:12.246 CST 57543744.a29 LOG:  checkpoint starting: xlog
2016-06-05 22:35:03.426 CST 57543744.a29 LOG:  checkpoint complete: wrote 39749 buffers (60.7%); 0 transaction log file(s) added, 0 removed, 44 recycled; write=49.579 s, sync=1.567 s, total=51.180 s; sync files=39, longest=1.374 s, average=0.040 s; distance=720820 kB, estimate=720820 kB
2016-06-05 22:39:12.529 CST 57543744.a29 LOG:  checkpoint starting: time
2016-06-05 22:43:42.526 CST 57543744.a29 LOG:  checkpoint complete: wrote 43209 buffers (65.9%); 0 transaction log file(s) added, 0 removed, 44 recycled; write=269.537 s, sync=0.451 s, total=269.997 s; sync files=37, longest=0.358 s, average=0.012 s; distance=552320 kB, estimate=703970 kB
2016-06-05 22:44:12.557 CST 57543744.a29 LOG:  checkpoint starting: time
2016-06-05 22:44:12.568 CST 57543744.a29 LOG:  checkpoint complete: wrote 0 buffers (0.0%); 0 transaction log file(s) added, 0 removed, 33 recycled; write=0.001 s, sync=0.000 s, total=0.010 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=633573 kB

这期间发生的数据页IO

benchmarksql2=# select * from pg_stat_bgwriter;
-[ RECORD 1 ]---------+------------------------------
checkpoints_timed     | 2
checkpoints_req       | 2
checkpoint_write_time | 383175
checkpoint_sync_time  | 3611
buffers_checkpoint    | 123481  #在检查点期间被写的缓冲区数目
buffers_clean         | 135864  #被后台写进程写的缓冲区数目
maxwritten_clean      | 16
buffers_backend       | 9530    #被一个后端直接写的缓冲区数量
buffers_backend_fsync | 0
buffers_alloc         | 250455  #从磁盘读入的缓冲区数量
stats_reset           | 2016-06-05 22:30:04.645808+08


benchmarksql2=# select * from pg_stat_database where datname='benchmarksql2';
-[ RECORD 1 ]--+------------------------------
datid          | 25184
datname        | benchmarksql2
numbackends    | 1
xact_commit    | 58865
xact_rollback  | 306
blks_read      | 251857
blks_hit       | 13293967
tup_returned   | 39973845
tup_fetched    | 26979898
tup_inserted   | 372559
tup_updated    | 696305
tup_deleted    | 24773
conflicts      | 0
temp_files     | 0
temp_bytes     | 0
deadlocks      | 0
blk_read_time  | 0
blk_write_time | 0
stats_reset    | 2016-06-05 22:30:01.652567+08

备注

试图减小wal_writer_delay和bgwriter_delay的值优化性能，但结果并不稳定。默认值200ms时多次测试结果在9000~13500之间；都设成100ms结果在11000~14000之间；2个值组合设置为200ms,100ms,10ms,结果在11000~12500之间。