一个重量级HTTP api的304优化分析与突发失效问题解决

前言

最近查看nginx log排查问题时，意外中发现重量级的主页 list api 304比例已暴跌至不到1%，之前该比例长期维持在30%以上，近期也未改动过相关逻辑，跟进后最终发现是服务端本地cache混用导致的问题。

304优化原因

app每次冷启初始化时都会请求重量级的HTTP主页list api，其会拉取全量1000个item(游戏关卡)组成的list数据一次性返回，返回的响应数据经gzip压缩之后依然有将近300KB大小(解压后近3MB)，单api如此大的数据传输对于网络带宽和传输速度都有明显的影响。
该api返回包括静态数据和动态数据部分，静态数据变动一般由运营在后台配置修改导致，一周变动次数有限，动态数据则和用户自身游玩行为有关，整体而言对于该api相当一部分用户多次请求得到的数据应该都是相同的，所以去年和客户端一起对该api进行了HTTP 304优化。

304对客户端请求耗时与带宽影响分析

之前测试了日本与美国东海岸之间主页list api返回304与完整300KB大小的耗时对比，两者耗时相差超过600ms--作为对比服务端处理耗时upstream_response_time一直稳定在100ms左右。
从网络协议与数据传输的角度解释这一现象，C/S 首先建立TCP连接，而后基于TCP建立HTTPS连接，服务端收到客户端完整请求并通过一系列业务逻辑生成最终返回数据-无论是否启用304到这一步为止流程都是一样的。
接下来返回数据这一步就差别大了，如果返回数据很少--如1KB，一个TCP包即可将完整响应数据发挥给客户端，日本到美国东海岸ping耗时(RTT)约为160~200ms(以下取160ms为例)，网络良好的情况下客户端将在服务端发送数据包后80ms收到该响应，而如果300KB数据，则需要至少200个TCP包（根据RFC6928定义TCP滑动窗口初始值为10MSS，后续根据网络情况会动态调整），最终体现为客户端完全收到300KB响应数据需要4个乃至更多个RTT(>=640ms)的时间，也就是300KB数据传输上比1KB数据传输要多耗时至少560ms，而实际上包越多，在TCP通信过程中发生丢包、重传、拥塞控制等意外情况的概率也就越大，其受网络不稳定因素影响而耗时更长的可能也要大得多。
至于所需带宽对比则很明显接近1:300。
去年对该接口做完304支持优化后，当时的效果是超过30%的请求都可以通过304直接返回，一个简单的304优化就能使该接口使用带宽资源降低近30%，对于美国地区用户而言超过30%请求耗时减少600+ms，平均耗时降低200+ms，应该说还是相当划算的。

304比例异常暴跌

测试环境尝试复现
偶然发现线上304比例暴跌后，首先尝试在测试环境复现问题，结果测试环境居然没法复现出来，无论是浏览器、curl命令还是app直接请求，结果都显示同一用户多次请求会正常返回304，陷入沉思==！

线上环境复现

测试环境无法复现，直接尝试线上环境验证，结果发现问题必现--对于同一个用户的连续两次请求，简单粗暴将两次api请求返回的数据copy到本地比对其变化，发现1000个item中有个别item有会多余的字段，看到字段名立刻明白了问题所在：本地cache被混用了。

本地cache的引入

对于该api返回的1000个item，每个item都需要单独调用normalize函数进行一系列的处理--如配置资源地址到完整资源包格式转换、动态文案组装等，即便单个item normalize调用只需要0.1ms，*1000之后也会变成100ms，所以服务端对于每个item的normalize结果都做了一个短期的本地cache，命中缓存的情况下1000个normalize所花费的时间由100ms减少成了数ms，这个优化已经上线很长时间，直到最近才发现它可能会导致304机制的失效。
对normalize函数启用本地cache的Python代码实现大概类似如下：

class ItemModel:
    local_item_cache = LocalCache(10000)
    @local_item_cache.cache(60)
    def normalize(self, phone_type,  item_id):
      # 资源包格式转换、动态文案组装等
      ...
      return self

cache混用问题的引入

近期app新增加了一个游戏模式，服务端对于该模式下的用户每次均会从一个100+item的池子中按一定策略随机选定一个返回，该item在返回前一样会调用normalize函数，如果命中本地cache直接返回，否则执行normalize函数并将结果存入本地cache后再返回。

问题出在这里：主页list item normalize与新游戏模式下item normalize使用的是同一个本地cache，出于节约拷贝开销的考虑，本地cache命中返回的其实是一个对象引用，而新模式在normalize之后，还会针对该游戏模式新增数个额外字段、并修改部分已有字段的内容-会有部分随机数值策略，这会直接修改掉底层本地cache缓存的实际对象内容，这样主页list api执行item的normalize时也会读到这些被额外修改过的缓存对象，同一个用户两次主页 list api请求如果读取到的1000 item中存在任意一个item受到新游戏模式修改影响就可能导致最终数据不一致--另外线上Python服务为多主机、多进程部署，每个进程都会维护自己独立的本地cache，此种情况下不同进程本地cache缓存的对象数据基本都是不一致的，用户请求可能落在任意进程上更加重了这种可能性--其返回的数据etag也会变化，也就不可能触发304机制了。

测试环境为什么无法复现呢？

因为测试环境就几个内部人员，同时存在请求主页list和新游戏模式游玩用户的时候很少--简单来说就是并发度不够，所以绝大部分情况下该问题很难触发。