RDS PostgreSQL DB 在每日 2 小时 CPU 峰值期间缓慢和超时



2个多星期以来,我观察到我的 RDS 实例(db.t3.small上的 PostgreSQL 10.6(在工作时间每天有 2 小时的 CPU 峰值,以及读取和写入延迟增加,导致我的应用程序响应能力差或超时。

我确实进行了调查(见下文(,在这一点上,我非常确信这些影响我的用户的峰值不是由我的使用引起的,并且倾向于认为它们是由 RDS 的流氓管理任务或某些 PostgreSQL 问题引起的。

有人忍受并解决了PostgreSQL的类似问题吗? 有人可以帮我调查 RDS 管理任务方面吗? 或者指出我其他途径来深入了解这些?

我观察到的:

  • 在 RDS 仪表板中,清除大约 2 小时的 CPU 峰值,使用率约为 20%,而在正常使用率下,CPU 保持在远低于 5%
  • 读取和写入延迟在这些 CPU 峰值附近增加
  • 来自我的生产应用程序数据库的查询变得缓慢甚至超时,使我的用户无法使用

我调查过什么:

  • 数据库连接在高峰期不高,最大 0 到 10
  • 我的数据库很小,pg_size告诉我它是 18MB!我最高的表目前有 1169 行,没有一列超过 10 列。
  • 可用存储空间还好,还在19000MB以上
  • 我知道我的用户不是很忙,因为谢天谢地,这是他们使用我的应用程序的一种假期。再说一次,在我知道我的应用程序的使用率很高的日期和时间范围内,CPU 使用率从未超过 5%。
  • 我在此数据库上没有计划任务或进程。
  • 记录所有语句和超过 200 毫秒的语句证实了这一点,除了 PgAdmin 查询花费少于 200 毫秒的统计信息之外,没有发生很多语句,当我停止它们时,这对 CPU 使用率没有影响
  • 备份不是罪魁祸首,它们在夜间进行,大约需要 3 分钟。
  • 据我所知,与不良查询或挂起交易无关。我在高峰期检查了pg_stat_activity,检查了"事务中空闲"和"活动"的持续时间。那里最多有10-11个活动。我的 4-5 中没有任何可疑之处。其余的是"rdsadmin"活动,我没有权限查看详细信息。我看到的唯一让我有点怀疑的活动是来自 PgAdmin 收集统计数据,但我用pg_cancel_backend杀死了它,杀死了我的 PgAdmin 服务器,它消失了,峰值持续了 30 多分钟。
  • 性能详情似乎并没有指出我在这些高峰期的可疑活动。
  • 基本的PostgreSQL日志中,我看到检查点确实变得更长(10到100倍(,但相当接近峰值而不是在开始时。

以下是峰值开始(激活语句日志之前(的基本日志:

2019-12-09 15:04:05 UTC::@:[4221]:LOG:  checkpoint starting: time
2019-12-09 15:04:05 UTC::@:[4221]:LOG:  checkpoint complete: wrote 2 buffers (0.0%); 0 WAL file(s) added, 0 removed, 1 recycled; write=0.202 s, sync=0.001 s, total=0.213 s; sync files=2, longest=0.001 s, average=0.000 s; distance=16369 kB, estimate=16395 kB
2019-12-09 15:09:05 UTC::@:[4221]:LOG:  checkpoint starting: time
2019-12-09 15:09:05 UTC::@:[4221]:LOG:  checkpoint complete: wrote 1 buffers (0.0%); 0 WAL file(s) added, 0 removed, 1 recycled; write=0.101 s, sync=0.001 s, total=0.112 s; sync files=1, longest=0.001 s, average=0.001 s; distance=16384 kB, estimate=16394 kB
2019-12-09 15:14:05 UTC::@:[4221]:LOG:  checkpoint starting: time
2019-12-09 15:14:05 UTC::@:[4221]:LOG:  checkpoint complete: wrote 1 buffers (0.0%); 0 WAL file(s) added, 0 removed, 1 recycled; write=0.101 s, sync=0.002 s, total=0.113 s; sync files=1, longest=0.002 s, average=0.002 s; distance=16384 kB, estimate=16393 kB
2019-12-09 15:19:06 UTC::@:[4221]:LOG:  checkpoint starting: time
2019-12-09 15:19:06 UTC::@:[4221]:LOG:  checkpoint complete: wrote 1 buffers (0.0%); 0 WAL file(s) added, 0 removed, 1 recycled; write=0.101 s, sync=0.001 s, total=0.113 s; sync files=1, longest=0.001 s, average=0.001 s; distance=16384 kB, estimate=16392 kB
[CPU PEAK STARTS here that day, at 16:20 UPC+1]
2019-12-09 15:24:06 UTC::@:[4221]:LOG:  checkpoint starting: time
2019-12-09 15:24:06 UTC::@:[4221]:LOG:  checkpoint complete: wrote 1 buffers (0.0%); 0 WAL file(s) added, 0 removed, 1 recycled; write=0.101 s, sync=0.002 s, total=0.114 s; sync files=1, longest=0.002 s, average=0.002 s; distance=16384 kB, estimate=16391 kB
2019-12-09 15:29:06 UTC::@:[4221]:LOG:  checkpoint starting: time
2019-12-09 15:29:06 UTC::@:[4221]:LOG:  checkpoint complete: wrote 1 buffers (0.0%); 0 WAL file(s) added, 0 removed, 1 recycled; write=0.101 s, sync=0.002 s, total=0.113 s; sync files=1, longest=0.001 s, average=0.001 s; distance=16384 kB, estimate=16390 kB
2019-12-09 15:34:06 UTC::@:[4221]:LOG:  checkpoint starting: time
2019-12-09 15:34:06 UTC::@:[4221]:LOG:  checkpoint complete: wrote 1 buffers (0.0%); 0 WAL file(s) added, 0 removed, 1 recycled; write=0.103 s, sync=0.002 s, total=0.118 s; sync files=1, longest=0.002 s, average=0.002 s; distance=16384 kB, estimate=16390 kB
2019-12-09 15:39:06 UTC::@:[4221]:LOG:  checkpoint starting: time
2019-12-09 15:39:06 UTC::@:[4221]:LOG:  checkpoint complete: wrote 1 buffers (0.0%); 0 WAL file(s) added, 0 removed, 1 recycled; write=0.104 s, sync=0.003 s, total=0.127 s; sync files=1, longest=0.002 s, average=0.002 s; distance=16384 kB, estimate=16389 kB
2019-12-09 15:44:06 UTC::@:[4221]:LOG:  checkpoint starting: time
2019-12-09 15:44:06 UTC::@:[4221]:LOG:  checkpoint complete: wrote 2 buffers (0.0%); 0 WAL file(s) added, 0 removed, 1 recycled; write=0.219 s, sync=0.010 s, total=0.303 s; sync files=2, longest=0.010 s, average=0.005 s; distance=16392 kB, estimate=16392 kB
2019-12-09 15:49:07 UTC::@:[4221]:LOG:  checkpoint starting: time
2019-12-09 15:49:09 UTC::@:[4221]:LOG:  checkpoint complete: wrote 1 buffers (0.0%); 0 WAL file(s) added, 0 removed, 1 recycled; write=0.318 s, sync=0.516 s, total=2.426 s; sync files=1, longest=0.516 s, average=0.516 s; distance=16375 kB, estimate=16390 kB
2019-12-09 15:54:07 UTC::@:[4221]:LOG:  checkpoint starting: time
2019-12-09 15:54:09 UTC::@:[4221]:LOG:  checkpoint complete: wrote 1 buffers (0.0%); 0 WAL file(s) added, 0 removed, 1 recycled; write=0.367 s, sync=1.230 s, total=2.043 s; sync files=1, longest=1.230 s, average=1.230 s; distance=16384 kB, estimate=16389 kB
2019-12-09 15:59:07 UTC::@:[4221]:LOG:  checkpoint starting: time
2019-12-09 15:59:08 UTC::@:[4221]:LOG:  checkpoint complete: wrote 1 buffers (0.0%); 0 WAL file(s) added, 0 removed, 1 recycled; write=0.139 s, sync=0.195 s, total=1.124 s; sync files=1, longest=0.195 s, average=0.195 s; distance=16383 kB, estimate=16389 kB

CPU 大约 1 个峰值,CPU 超过一周,读取延迟在峰值附近,写入延迟在峰值附近,性能见解在 12 月 10 日峰值附近,性能见解在 12 月 9 日峰值附近

可能是由于PostgreSQL的后台进程,您的磁盘上的突增积分即将用完。 如果我没记错的话,Rds 上的所有磁盘都是 gp2 类型。这意味着您有一定的基本 iops 和积分,您可以在短时间内花费超过该值。您应该能够在监视页面上的队列深度指标中看到此效果。如果这是幸福的,你应该看到这个数字的峰值。最简单的解决方案是增加磁盘大小。

最新更新