服务端性能优化：Troubleshooting 两则

这篇文章的内容是两年前的两个多IDC高延迟的Troubleshooting，经过仔细的分析和定位，最终解决，并对线上业务起到了很好的优化效果。分享给大家，共同交流学习。

最近在梳理某项目上各服务接口的性能情况，遇到两个问题。以下是定位和解决问题的一个思路，分享给大家。

业务之前并没有详细的性能日志记录，仅在电信机房(T机房)进行了性能测试，结果是各接口满足预期，服务上线。

在进一步对接口进行性能分析时，对各业务接口的关键路径添加了日志统计，通过日志进行分析，将接口的延迟进行统计，接入Grafana，观察数据后，发现两类问题。

1. 连接MongoDB的服务，网通机房(C机房)延迟比电信机房(T机房)要高。

2. 连接Mysql的服务，网通机房(C机房)延迟比电信机房(T机房)高。

   NOTE: 这些服务接口，都是只读，没有写操作。

   对两类问题分别进行排查:

MongoDB

简单的排查后发现，MongoDB实例有过一次迁移，并且迁移后只保留了电信机房(T机房)的实例，网通机房(C机房)没有从库，所以网通机房(C机房)延迟比电信机房(T机房)高。对网通机房(C机房)部署了从库实例后，却意外发现电信机房(T机房)的延迟比网通机房(C机房)高了。再次排查后发现，代码中配置的MongoDB的读策略是secondary（从库优先），所以网通机房(C机房)有从库后，电信机房(T机房)也去网通机房(C机房)读取，导致了电信机房(T机房)的延迟变高。更改读策略为nearest（就近优先），有所好转，但并没有预想的效果那么好。仔细看下官方文档

The driver reads from a random member of the set that has a ping time that is less than 15ms slower than the member with the lowest ping time. Reads in the MongoClient::RP_NEAREST mode do not consider the member’s type and may read from both primaries and secondaries.

就会发现， nearest是在客户端维护一个到各个实例延迟小于15ms的集合 ，而我们电信机房(T机房)到网通机房(C机房)是光纤直连，延迟在12ms左右，所以，每次客户端可能会连接到电信机房(T机房)，也可能到网通机房(C机房)。

这点在以后的应用中，大家可以注意下。

Mysql

在所有的服务中，只有一个服务接口是读mysql实现的，而这个接口的表现更是奇怪，网通机房(C机房)的延迟比电信机房(T机房)多100 ms+。

开始时猜测有可能业务内做了某些写主库的操作，比如写mysql，或写redis之类的，跨机房写导致的延迟高。

实际分析后发现，业务内并没有写操作，多出的时间就是读mysql的时间。

mysql是有网通机房(C机房)的从库的，为什么读取从库的数据，延迟还会这么高呢。在我们服务端ping 网通机房(C机房)的mysql ip，发现延迟正常，只有零点几毫秒，不存在网络问题。

下一步就是通过抓包，分析下我们服务端跟mysql间到底有哪些交互，到底是哪个环节慢了。

根据抓包结果发现，正常的select查表请求很快能得到响应，但当从我们服务端发送一个 “Describe tableName”的请求到mysql 服务端时，服务端等待了较长时间(30ms+)才返回结果，而且一次接口服务请求中，有多次Describe的请求，这样，导致网通机房(C机房)最终延迟很高。

问题定位后，开始尝试解决。

解决问题前需要先理清思路：

1. DescribeTableName 这个命令是干什么用的，业务里并没有显式调用。这个请求能不能去掉。

2. 如果不能去掉，那它的延迟为什么这么高，能不能优化？

第一个问题比较简单，Describe 命令是现在ORM中比较通用的做法，通过获取数据库的表结构，来动态的创建Model。如果不调用Describe命令，当然也可以做到，那样就需要自己业务端对每个model进行声明，这样开发成本会大大增加，这个方式不可取。所以需要保留Describe命令。

第二个问题，延迟为什么高，这个命令是很简单的一个命令，没有任何复杂的操作，而且主库上都没有这个问题。结合DBA同学在Mysql上使用了Atlas中间件，可以大胆猜想下，应该是这个中间件搞的鬼，把select请求分配到从库执行，但是把Describe分配到了主库执行，有可能是因为Atlas中间件只考虑了一些读的SQL，把这类请求分配到从库，而其它各种请求，可能由于过于复杂，就默认分配到主库去执行。当然这只是猜测，没有查看过Atlas的源码，所以不能妄下结论。结合已经整理到的线索，跟DBA同学进行了确认，确定 Describe命令确实被Atlas中间件发送到主库去执行了，至于这么做的原因， 是为了避免主从结构不一致时，从库拿到的表结构错误 。这种情况下，我们也不能评价说中间件做的到底合理不合理，所以我们需要从自己的角度再思考下能不能优化。如果说希望避免每次请求都执行Describe命令，除了说刚才提到的自己声明，另外一个方式就是cache了，因为表结构变化的频次太低了，我们完全可以设置一个较长时间的cache，来避免频繁的这种请求。业务使用的是  Phalcon 框架，这个框架中已经提供了这种meta-Data cache的方案,Yii中也有类似的实现: schemaCaching。

当启用这种cache后，效果就很明显，可以看到：

网通机房(C机房)延迟从原来的120ms降到7ms, 电信机房(T机房)延迟从原来的10ms降低到5ms.

后续需要考虑的就是，如果表结构发生变化，如何在不影响业务的情况下进行更新。这个也可以有多种实现的方案，大家可以自己想下。

总结

解决问题的思路就在于，遵循最小化原则，先对可能产生这种问题原因进行大胆猜测，然后快速验证，逐步缩小范围，将问题定位到一个最小可复现的范围内，再深入分析具体原因。当然这一切都要有数据说话，如果平时开发中，能提供足够丰富的日志数据，就可以很快的定位问题，甚至提前发现问题。

最后插个广告，猜猜我画的是啥？

 

来自：https://mp.weixin.qq.com/s/4Fq7gLoV1my7UT-h9VI0ig