amazon-web-services - 提交持续时间长，postgres 9.1 中的高 I/O 等待

Question

我们在 postgres 日志中观察到很长的 COMMIT 时间和很高的 I/O 等待时间。
Postgres 版本 PostgreSQL 9.1.14 on x86_64-unknown-linux-gnu，由 gcc (Ubuntu/Linaro 4.6.3-1ubuntu5) 4.6.3 编译，64 位

iotop 显示以下输出

          TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN      IO    COMMAND
04:01:25 15676 be/4 postgres    0.00 B/s    0.00 B/s  0.00 % 99.99 % postgres: masked masked 10.2.21.22(37713) idle
04:01:16 15676 be/4 postgres    0.00 B/s    0.00 B/s  0.00 % 99.99 % postgres: masked masked 10.2.21.22(37713) idle
04:01:15 15675 be/4 postgres    0.00 B/s    0.00 B/s  0.00 % 99.99 % postgres: masked masked 10.2.21.22(37712) idle in transaction
04:00:51 15407 be/4 postgres  173.52 K/s    0.00 B/s  0.00 % 99.99 % postgres: masked masked 10.2.21.22(37670) idle
04:02:12 16054 be/4 postgres    0.00 B/s    0.00 B/s  0.00 % 96.63 % postgres: masked masked 10.2.21.22(37740) idle
04:04:11 16578 be/4 postgres    0.00 B/s   23.66 K/s  0.00 % 95.39 % postgres: masked masked 10.2.21.22(37793) idle
04:00:59 15570 be/4 postgres    0.00 B/s    0.00 B/s  0.00 % 85.27 % postgres: masked masked 10.2.21.22(37681) COMMIT
04:02:11 16051 be/4 postgres    0.00 B/s    0.00 B/s  0.00 % 80.07 % postgres: masked masked 10.2.21.22(37737) idle
04:01:23 15660 be/4 postgres    0.00 B/s   15.75 K/s  0.00 % 52.99 % postgres: masked masked 10.2.21.22(37693) idle
04:01:35 15658 be/4 postgres    0.00 B/s   39.42 K/s  0.00 % 39.18 % postgres: masked masked 10.2.21.22(37691) idle in transaction
04:01:59 15734 be/4 postgres 1288.75 K/s    0.00 B/s  0.00 % 30.35 % postgres: masked masked 10.2.21.22(37725) idle
04:01:02 15656 be/4 postgres    7.89 K/s    0.00 B/s  0.00 % 30.06 % postgres: masked masked 10.2.21.22(37689) idle
04:02:28 16064 be/4 postgres 1438.18 K/s   15.72 K/s  0.00 % 23.72 % postgres: masked masked 10.2.21.22(37752) SELECT
04:03:30 16338 be/4 postgres  433.52 K/s   15.76 K/s  0.00 % 22.59 % postgres: masked masked 10.2.21.22(37775) idle in transaction
04:01:43 15726 be/4 postgres    0.00 B/s    7.88 K/s  0.00 % 20.77 % postgres: masked masked 10.2.21.22(37717) idle
04:01:23 15570 be/4 postgres    0.00 B/s   15.75 K/s  0.00 % 19.81 % postgres: masked masked 10.2.21.22(37681) idle
04:02:51 16284 be/4 postgres  441.56 K/s    7.88 K/s  0.00 % 17.11 % postgres: masked masked 10.2.21.22(37761) idle
04:03:39 16343 be/4 postgres  497.22 K/s   63.14 K/s  0.00 % 13.77 % postgres: masked masked 10.2.21.22(37780) idle
04:02:40 16053 be/4 postgres  204.88 K/s   31.52 K/s  0.00 % 11.31 % postgres: masked masked 10.2.21.22(37739) BIND
04:01:13 15646 be/4 postgres    0.00 B/s   47.24 K/s  0.00 % 11.17 % postgres: masked masked 10.2.21.22(37682) BIND
04:01:13 15660 be/4 postgres   94.49 K/s    0.00 B/s  0.00 % 10.80 % postgres: masked masked 10.2.21.22(37693) COMMIT

在高峰时段，提交时间长达 60 秒。
该问题始于一周前，似乎在每小时的第一分钟发生。
申请没有变化。
当时没有正在运行的批处理作业会导致此问题。
我们通过停止所有作业/爬行过程消除了这种情况。

我们已经使用 pg_repack 从 99% 的表中删除了膨胀。
缓慢的 COMMIT 操作位于不再有膨胀的表上。

使用 RAID10 配置。
存储是磁性 EBS。
同步提交已开启。
Postgres 正在使用 fdatasync()。
AWS 支持关于存储健康的说法。

strace 显示了一堆 semop 调用花费了很多时间，并且只有一个缓慢的 fdatasync 调用。

$ egrep "<[0-9][0-9]\." t.*
t.31944:1479632446.159939 semop(6029370, {{11, -1, 0}}, 1) = 0 <15.760687>
t.32000:1479632447.872642 semop(6127677, {{0, -1, 0}}, 1) = 0 <14.095245>
t.32001:1479632444.780242 semop(6094908, {{15, -1, 0}}, 1) = 0 <17.113239>
t.32151:1479632493.655164 select(8, [3 6 7], NULL, NULL, {60, 0}) = 1 (in [3], left {46, 614240}) <14.339090>
t.32198:1479632451.200194 semop(5963832, {{7, -1, 0}}, 1) = 0 <11.095583>
t.32200:1479632445.740529 semop(6094908, {{13, -1, 0}}, 1) = 0 <16.153911>
t.32207:1479632451.329028 semop(6062139, {{7, -1, 0}}, 1) = 0 <10.970497>
t.32226:1479632446.384585 semop(6029370, {{8, -1, 0}}, 1) = 0 <15.565608>
t.32289:1479632451.044155 fdatasync(106)        = 0 <10.849081>
t.32289:1479632470.284825 semop(5996601, {{14, -1, 0}}, 1) = 0 <10.686889>
t.32290:1479632444.608746 semop(5963832, {{8, -1, 0}}, 1) = 0 <17.284606>
t.32301:1479632445.757671 semop(6127677, {{8, -1, 0}}, 1) = 0 <16.137046>
t.32302:1479632445.504563 semop(6094908, {{4, -1, 0}}, 1) = 0 <16.389120>
t.32303:1479632445.889161 semop(6029370, {{6, -1, 0}}, 1) = 0 <16.005659>
t.32304:1479632446.377368 semop(6062139, {{12, -1, 0}}, 1) = 0 <15.554953>
t.32305:1479632448.269680 semop(6062139, {{14, -1, 0}}, 1) = 0 <13.717228>
t.32306:1479632450.465661 semop(5963832, {{3, -1, 0}}, 1) = 0 <11.783744>
t.32307:1479632448.959793 semop(6062139, {{8, -1, 0}}, 1) = 0 <13.289375>
t.32308:1479632446.948341 semop(6062139, {{10, -1, 0}}, 1) = 0 <15.001958>
t.32315:1479632451.534348 semop(6127677, {{12, -1, 0}}, 1) = 0 <10.765300>
t.32316:1479632450.209942 semop(6094908, {{3, -1, 0}}, 1) = 0 <12.039340>
t.32317:1479632451.032158 semop(6094908, {{7, -1, 0}}, 1) = 0 <11.217471>
t.32318:1479632451.088017 semop(5996601, {{12, -1, 0}}, 1) = 0 <11.161855>
t.32320:1479632452.161327 semop(5963832, {{14, -1, 0}}, 1) = 0 <10.138437>
t.32321:1479632451.070412 semop(5963832, {{13, -1, 0}}, 1) = 0 <11.179321>

pg_test_fsync 输出可用。

非常感谢任何其他指针。
谢谢!

Answer 1

通过进行以下更改解决了该问题。

将主数据库移至 EBS optimized instance

由 SSD 提供支持

使用预配置的 IOPS

使用 pg_repack 去除膨胀