--- permalink: 2019/08/20/tools/499-error-solve/ title: 499问题查询解决 tags: - Http date: 2019-08-20 18:38:45 categories: - 系统 --- > 本文记录了我从遇到 499 问题，到解决的全过程。 > > 如果有小伙伴比较急，需要知道问题可能出现在哪里，请直接看 **解决思路** 一栏 随着公司的发展，系统也越来越健全。近期使用了阿里云的 `sls` 服务来分析 `nginx` 系统日志，并设立了告警功能。 各种平时注意不到的异常情况发生了。 ### 系统环境 经典的 `LNMP` ### 什么是 499 解释是：`client has closed connection` 这很有可能是因为服务器端处理的时间过长，客户端“不耐烦”了。 ### 解决思路 先考虑程序是否有问题，定位某个接口，做详细分析。 再考虑服务是否有问题，是不是 `MySQL` 的连接数量太少、是不是 `PHP-FPM` 的进程数量不够。 最后考虑用户行为。 ### 第一次499处理 当我看到运维同事报过来的第一个 `499` 数据的时候，我感觉有点莫名。 之前没有处理过相应的问题，第一次拿到这个问题，还有点棘手。 大致分析了一下，大部分的请求响应都还算可以，在 `0.5s` 以内，部分情况会超过 `1s`。 由于占比不大，所以最终也没有得出什么结论。 也就不了了之了。 ### 解决日志上报失败得来的惊喜 **一些信息** 我们部分接口会放在响应之前上报相关日志，因为是同步的，所以上报的时间会算在接口响应中。 **问题** 领导找到，说商品列表的响应速度太慢了，让查一下原因。 **定位问题** 既然是响应慢，那我得知道慢在什么地方，才好解决问题。 于是用了很暴力的解决方式，就是在我认为可能出现问题的节点放入调试时间，最终通过相减得到每个环节需要的时间。 最终发现，除了上报，其他所有的相应都很快。 然后查了一下上报日志，最近果断没有相关的日志。 再看到有其他接口的日志，略微比较一下之后，发现了问题。 为了好分析线上报的一些问题，我将响应数据一起上报了，不知道是怎么回事，现在上报数据一大就会出现问题。 所以就去除了上报数据，上报成功，接口响应也提升了。 **499变少了** 由于接口响应变快了，相关的 `499` 也减少了。 ### 收到了告警邮件 运维同事偷偷的配置了告警邮件，并写上了我，然后，被轰炸了。 ### 再上征途 **一些信息** 我们会在一些平台投放广告，前人用了 `talking data` 的服务(简称 `TD`)，`TD` 对接第三方平台，`TD` 再通知我们。 **奇怪的现象** 我分析了一下日志。 从分布上，激活的接口(`TD` 通知的接口)报 `499` 的概率非常之高。 从响应时长上，激活的接口最高达到了 *60秒*。 然后，又针对激活的接口做仔细分析，最终发现，在报 `499` 的时候，激活接口的响应时间会有个 *增长* 的趋势。 **猜测** 现在问题出现了，那是什么原因造成的呢？ 1、猜测一 猜测：因为激活数量一直在递增，目前已经达到千万级，可能是没用到索引。 实际：有用到索引 2、猜测二 猜测：因为激活数据会产生插入更新，索引排序时间过长，导致阻塞。 实际：最终发现不是，这个没有验证。 3、猜测三 猜测：MySQL连接数量不足 实际：远远没达到(有监控可以直接看出，没有监控的话，只能根据数据分析了) 4、猜测四 猜测：PHP-FPM 进程不足，导致阻塞 实际：巅峰情况下只使用了 1/3 **分析PHP慢日志** 在所有猜测都不是的情况下，最终看了一下线上的 `PHP` 慢日志(这个一般不会开启)。 有了不一样的的发现。 在激活接口出现 `499` 的时间段内，经常出现 `session_start` 的慢日志(配置的是超过 3s 会出现慢日志)。 那么是为什么呢？ *我将其归为 `session_start` 的时候，需要文件写权限(默认的，没有更改)，而当出现并发的时候，这个时候争夺文件锁的时候，发生了阻塞，导致后续请求阻塞了，最终超时。* 想起之前本地环境也在 `session_start` 时出现过问题，就有了大致的解决方案。 1、不启动 `session`。事实上是可以的，因为是单纯的接口，不需要使用 `session`。 2、设置 `session_save_handler` 为 `redis` 和 `memcached`，他们在高并发下的能力更强。 最终，我关闭了 `session`，观察了一段时间，没有告警了。 **一些思考** 或许有些小伙伴已经想到了，既然是接口，理论上 `session` 是不会重复的。 这里有一个信息，`talking data` 使用的是 ` Apache-HttpClient/4.5.2`。查了一下，它本身会处理 `set-cookie` 的操作，下一次请求就会带上 `cookie`。所以就尴尬了，由于同一个 `PHPSESSID` 的高并发，所以文件锁阻塞了。 ### 最后 感觉自己解决问题的时候，先想的是不是别人的问题造成的，这个想法和处理方式是有问题的。 应该是先从本身分析，当本身没问题了，再去找外围的问题，会更好的解决问题。