RDS性能降低 - 复盘 - Honeycomb

RDS性能降低 - 复盘 - Honeycomb

原文： https://www.honeycomb.io/blog...

译：祝坤荣

概要

注：除非特别说明，所有时间都是UTC。

5月3号周四， 从00:39:08 UTC（周三 17:39 PDT）我们经历了一次Honeycomb服务的大约24分钟的彻底停机。大部分服务恢复时间是2018-05-03 01:02:49，所有面向客户的服务恢复是在01:07:00。

影响

• 在停机期间，客户不能登录或查看Honeycomb服务的图表。
• 停机期间发送给Honeycomb API的事件被大量拒绝；大约86%的API不能服务，而且大约81%的应该已经提交的事件在停机期间没有被记录。(百分比的差距是由于一个单独的API可以处理不同的事件并且停机没有平均影响到所有数据集)
• 由于Honeycomb API没有报告成功，一些仍存储在客户服务上的事件在Honeycomb API恢复正常后又被重新提交。
• 停机期间大约有15%的事件成功保存

我们对这次停机影响的每一个客户都十分抱歉。我们对于数据的管理十分认真，并通过对系统的多项改进措施来确保未来这类的停机事件不会造成数据丢失，并确保我们在类似的失败中可以更快的恢复。

发生了什么？

事后看，故障链只有4点连通：

1. 我们产品使用的RDS MySQL数据库实例经历了一次突然的和大规模的性能减低； P95(query_time)从11毫秒变成>1000毫秒，同时写操作吞吐在20秒内从 780/秒降到 5/秒。
2. RDS没有识别到故障，所以 Mutil-AZ feature没有激活故障转移。
3. 由于增加的query_time导致的延迟， Go的 MySQL 客户端连接池被等待慢查询结果的连接填满了并且作为补偿又打开了更多的连接。
4. MySQL服务器的max_connections设置达到了上限，导致定时任务和新启动的后台进程不能连接到数据库并导致“Error 1040：Too many connections”的日志信息。

恢复部分很快：

1. RDS数据库的延迟和吞吐突然出现改善；在20秒内P95(query_time)写从>600ms 掉到 <200ms， 同时总吞吐从<500OPS 变成>2500OPS。
2. 排队的事件快速完成，数据库在70秒内的OPS大于3000， 并在回到正常状态时变成： 300-500OPS，<10ms 写。

我们如何得到答案的故事是一个如何使用Honeycomb来debug生产系统的有趣的例子。

根因分析

在之后第二天早上我们的复盘会议上，两个理论摆在桌上：

1. 大量的连接数导致停机，并引起了数据库运行缓慢，或
2. 数据库由于一些原因运行缓慢，导致大量的连接数。

我们担心一些bug隐藏在我们的应用里(或我们使用的其中一个 Go 库)导致我们的应用在不能连接数据库时关机，这样在同样情况再发生时又会导致一样的停机故障。

每个人都同意这很像是下层数据库的问题（存储，CPU或连接）是根因，但我们也同意如果我们以抱怨网络的方式忽略一个潜在应用级的bug会更有危险。

作为开发者的责任：这可能不是数据库，而可能是你的代码问题。

为了降低风险，我们决定在受控环境来重现Error 1040场景并观察系统表现。在我们的实验集群上重现连接池溢出清楚的表明了连接满确实会影响应用并导致定时任务失败，它不会导致失控的CPU或延迟升高。

我们现在有两个数据集：生产的停机和实验用的。由于我们使用Honeycomb来观察Honeycomb，所以在这个例子对比A和B很容易

实验生产停机

左边，实验集群从12:30到13:23（除了一些失败的定时任务很难看出证据）运行，而在右边，生产的停机很清楚地显示着。实验有个空结果：我们没有发现 Error 1040导致了停机。看起来像是系统的一些底层问题导致的。

有了这个信息，我们需要在生产数据上挖掘的更深入了。由于Honeycomb数据集是高保真的（我们不做任何聚合或预先的计算），可以将数据调整到每秒级别并调整数据来抽取模式。这里是从rdslogs里记录的性能数据。

有15秒没有活动，然后有一批query_time值达到了15秒的完成动作，看起来很明显。在结束时的性能异常也有一个有意思的热力图模式：

概括下，数据展示了高于23分钟的低吞吐，高延迟行为，并持续了少于30秒切换区域，之前是正常的高吞吐，低延迟，尖峰应用驱动的行为，接着是大量的追赶事件，最后切换到正常的高吞吐模式。

由于这不是一个全面的根因分析，但对于我们明确问题在数据库系统而不是我们的应用代码已经够了；我们的应用看起来运行正常。我们之后再 SQL 的normalized_query字符串上验证了我们的代码在恢复过程中工作符合预期。

得到这些信息后我们重新调查了我们的RDS配置并确认

• Multi-AZ是打开的。
• 实例监视面板没有显示任何健康事件。
• AWS文档指出Multi-AZ不会考虑性能作为健康检查的内容

经验

• 受管理的数据库很好，除非他们没托管。
• 我们会优先考虑在“game day”运行我们的实验RDS做故障转移来重新验证在硬件故障时我们对于我们系统运行的理解。虽然我们不认为RDS会有很多硬件故障，但当我们需要处理RDS AZ故障转移时我们需要一个准备好的手册来执行。
• 我们在改进我们的管道来保证在基础设施不能连接到数据库时接受的用户事件我们可以缓存它们而不是失败。硬件问题发生，这就是生活；丢失数据不需要发生。

时间线 (2018-05-03 UTC)

00:39 – outage starts

00:40 – first alert

00:42 – engineers start investigation

00:50 – escalation, multiple investigators looking at several potential avenues

00:55 – status.honeycomb.io updated to keep our customers informed

00:58 – first engineering interventions to attempt to heal system, minimal impact

01:03 – outage resolution starts

01:04:23 – resolution completes, system stabilized

01:15 – engineers conclude that outage is resolved, update status.honeycomb.io

本文来自微信公众号「麦芽面包，id「darkjune_think」转载请注明。

交流Email: zhukunrong@yeah.net