我喜欢我的工作的重要一点是,我是软件开发团队的一员,该团队不仅为人们构建软件,而且还积极管理高流量 Web 基础设施。这意味着,作为开发人员,我们背负着我们建立的技术债务,并且我们会在合理的时候使用我们最好的判断来帮助偿还这些债务。最近,我们正在审查我们的监控图,并花了一些时间查看我们的 memcached 实例。这个特定的客户端使用 Circonus 并为 memcache 设置了指标,包括总内存、获取/放置速率(请求和字节)和命中/未命中率。
这些未命中的数量并不是特别多,但是缓存未命中通常表明系统中的某些内容可以更快。在流量扩大和小的效率低下开始累积之前,它们可能值得研究。
诊断
我们知道发生了未命中,但我们在整个代码中都有缓存调用。为了追踪这一点,我们需要查看系统上真正发生了什么,以便观察遗漏了什么。不幸的是,memcached 没有提供执行此操作的内部机制,这使得这项任务非常困难,以至于一些人编写了专门用于执行此操作的第 3 方应用程序,例如 mctop。对我来说幸运的是,这些系统在 Illumos 上运行,因此我们可以受益于 dtrace 实用程序。 Dtrace 允许我在几乎没有风险的情况下详细检查生产系统,因此我们可以直接查看其中一个内存缓存实例并实时查看发生了什么。我们没有自己编写,而是使用了 Matt Ingenthron 提供的很棒的 memcached dtrace 脚本,他在 https://gist.github.com/ingenthr/6116473 提供了该脚本
在其中一台生产机器上运行密钥流脚本,我们在获取或设置密钥时看到密钥。
$ sudo ~/memcache_scripts/keyflow.d
get OGefRqwX:45220, FOUND KEY
get H02pZPjq:2087rulessml::en, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get WETtYDA0:__special_reg_map, FOUND KEY
get WETtYDA0:__special_reg_map, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get suB5w6XF:683112, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get WETtYDA0:1:default, FOUND KEY
get WETtYDA0:1:default, FOUND KEY
get H02pZPjq:2087rulessml::en, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
...
显示的是 memcache 命令和密钥; 'get' 说,'从 memcached 获取这个',它试图获取的密钥,以及结果。此客户端的内部缓存代码使用包装器模块根据模块(前 9 个字符)命名键,然后使用开发人员提供的键。
我们真的只关心未命中,所以让我们只过滤那些:
$ sudo ~/memcache_scripts/keyflow.d
get OGefRqwX:45220, FOUND KEY
get H02pZPjq:2087rulessml::en, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get WETtYDA0:__special_reg_map, FOUND KEY
get WETtYDA0:__special_reg_map, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get suB5w6XF:683112, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get WETtYDA0:1:default, FOUND KEY
get WETtYDA0:1:default, FOUND KEY
get H02pZPjq:2087rulessml::en, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
...
稍微观察一下,我们注意到缓存未命中的一些共性。我们选择了一个似乎出现频率很高的密钥(“rest_api:gmail.com”)并从那里开始。
错误并不总是你的错
这个键有一个命名空间,所以我们可以通过 grep 查找那个命名空间来查看发生的键流。
$ sudo ~/memcache_scripts/keyflow.d
get OGefRqwX:45220, FOUND KEY
get H02pZPjq:2087rulessml::en, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get WETtYDA0:__special_reg_map, FOUND KEY
get WETtYDA0:__special_reg_map, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get suB5w6XF:683112, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get WETtYDA0:1:default, FOUND KEY
get WETtYDA0:1:default, FOUND KEY
get H02pZPjq:2087rulessml::en, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
...
客户的 Node.js REST API 重复使用同一域进行内存缓存提取调用。缓存未命中后的常见模式是向权威来源发出请求,然后在缓存中设置该值以供下次使用。在这种情况下,我们看不到任何集合,只是重复获取相同的项目。是时候深入挖掘了。
我们能够快速确定缓存调用的位置。该客户拒绝通过 API 注册属于其黑名单成员的域。该列表非常大,所以我们只想缓存当前的“热”域,然后回退到数据库检查其余部分。代码非常简单。
$ sudo ~/memcache_scripts/keyflow.d
get OGefRqwX:45220, FOUND KEY
get H02pZPjq:2087rulessml::en, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get WETtYDA0:__special_reg_map, FOUND KEY
get WETtYDA0:__special_reg_map, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get suB5w6XF:683112, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get WETtYDA0:1:default, FOUND KEY
get WETtYDA0:1:default, FOUND KEY
get H02pZPjq:2087rulessml::en, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
...
如果键不在缓存中,查询它,设置它,然后继续。该代码忽略了 set() 的返回值,因为如果出现错误,我们实际上不会对此做任何事情。为了调试问题,我们添加一个回调来设置以查看响应是什么。奇怪的是,就在此时,它开始起作用了!我们可以看到“set”命令从 dtrace 脚本转到 memcached。深入研究 set() 函数调用,我们发现这实际上是我们用来处理 memcached 的 npm 模块的问题。如果未向 set() 函数提供回调,则模块的验证模块不会将其视为函数,并认为存在类型不匹配。然后它尝试使用提供的回调返回一个错误,该回调不存在,所以它什么都不做;无声地失败。这是一个可怕的失败案例。如果需要回调函数,它应该立即大声失败。如果不需要,那么它应该继续按预期工作;前提是请求没有错。如果没有提供回调,整个包代码的其余部分将被编写为正常工作,因此只需要更改 npm 模块源代码中的验证函数以允许未定义的回调。
我们在模块的 github 存储库中创建了一个问题,并向该项目提交了带有测试用例的拉取请求。我们会看看他们是否同意。
缓存否定响应
缓存未命中的第二大原因是常见错误。在检查缓存时,我们经常会说,“X的值是多少?”如果找不到,我们将检查权威来源。但是,如果权威来源也没有呢?很多时候,我们只是继续前进。以发送到购买页面的跟踪代码为例。某些代码会自动给某人 10% 的折扣,因此我们需要检查它是否是特殊代码。如果不是,那么我们什么都不做。这是其中一个案例。然而,绝大多数情况下,这些查找中的大多数都没有返回任何内容,因为它们仅用于跟踪。 'Nothing' 也是一个值,可以缓存。通过缓存否定响应或缺少值,页面可以继续避免缓慢的数据库查找。这会缩短常见情况下的页面加载时间。重要的是要牢记您的业务规则以使此数据失效。如果添加折扣,您的缓存值需要多长时间才能过期以反映新值?
不要重新获取你已经知道的东西
下一个项目有点难以诊断。在观察一些访问模式时,我们注意到同一个键经常会被连续多次提取。好奇为什么这是一个如此受欢迎的密钥,我们也对其进行了调查。
人们对面向对象编程有很多讨厌的地方,但特别讨厌的是“黑匣子”方法通常会隐藏特定调用的代价。该客户有几种不同的视图,可以根据上下文为页面显示,并且通常会根据该特定视图打开/关闭不同的行为。这些标志将通过创建 Page 对象并检查它来提供。例如:
$ sudo ~/memcache_scripts/keyflow.d
get OGefRqwX:45220, FOUND KEY
get H02pZPjq:2087rulessml::en, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get WETtYDA0:__special_reg_map, FOUND KEY
get WETtYDA0:__special_reg_map, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get suB5w6XF:683112, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get WETtYDA0:1:default, FOUND KEY
get WETtYDA0:1:default, FOUND KEY
get H02pZPjq:2087rulessml::en, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
...
随着功能的添加/删除,这些调用最终会散布在代码中需要检查标志的地方。程序员并不知道,这个构造函数正在从内存缓存中获取这些标志。在几个月的新功能请求之后,代码现在可以在单个页面加载时从内存缓存中获取相同的数据 7-10 次。通过一些重构,可以很容易地避免这种情况,方法是在开始时获取一次数据,然后将对象传递给随后的各种逻辑路径。我们网络中的 Memcache 调用只有几毫秒,但这些毫秒加起来。
结果
该图由修复前后的两天组成。未命中率几乎降为零:
正如欢迎(下图)一样,由于不再在同一页面加载中多次获取相同的值,缓存命中量现在也有所下降。在下图中,左侧是与前一周重叠的新流量模式。推送之后,我们看到 memcached 提取总数大约下降了 10% - 20%。所有这些都节省了时间,可以更快地将页面发送给客户。
消除噪音使事件更加突出
在清理我们的数据之后,没有噪音使得偏离规范的事件在视觉上更加明显。在实施上述修复后不久,我们突然想到:
确保你自己的图书馆是正确的
虽然我们能够查看上一期的实时流量,但必须事后调查这些峰值,但我们仍然需要找出发生了什么。从那时起抓取一些流量日志,我们能够重放一些流量并找到罪魁祸首。这非常令人担忧。
$ sudo ~/memcache_scripts/keyflow.d
get OGefRqwX:45220, FOUND KEY
get H02pZPjq:2087rulessml::en, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get WETtYDA0:__special_reg_map, FOUND KEY
get WETtYDA0:__special_reg_map, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get suB5w6XF:683112, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get WETtYDA0:1:default, FOUND KEY
get WETtYDA0:1:default, FOUND KEY
get H02pZPjq:2087rulessml::en, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
...
看起来我们正试图从内存缓存中提取 SQL 查询片段。果然,日志调查显示该站点当时正在被扫描。 SQL 注入尝试导致额外的缓存键提取。
我们可以通过使用以下命令攻击我们的一台开发机器来重现该错误:
$ sudo ~/memcache_scripts/keyflow.d
get OGefRqwX:45220, FOUND KEY
get H02pZPjq:2087rulessml::en, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get WETtYDA0:__special_reg_map, FOUND KEY
get WETtYDA0:__special_reg_map, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get suB5w6XF:683112, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get WETtYDA0:1:default, FOUND KEY
get WETtYDA0:1:default, FOUND KEY
get H02pZPjq:2087rulessml::en, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
...
这转换为类型值:
$ sudo ~/memcache_scripts/keyflow.d
get OGefRqwX:45220, FOUND KEY
get H02pZPjq:2087rulessml::en, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get WETtYDA0:__special_reg_map, FOUND KEY
get WETtYDA0:__special_reg_map, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get suB5w6XF:683112, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get WETtYDA0:1:default, FOUND KEY
get WETtYDA0:1:default, FOUND KEY
get H02pZPjq:2087rulessml::en, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
...
我们试图获取相同的三个密钥。
结果证明这是内部包装器模块的错误。该模块将只接受给定的任何密钥并尝试获取它。这不能很好地与 memcache 协议一起使用。内存缓存键不能包含任何空格或控制字符,并且必须 <= 250 个字符。 get 请求中的空格用于允许某人使用单个获取命令获取多个密钥,这就是我们所做的,也是 dtrace 将其显示为三个单独获取的原因。由于我们的模块只会接受第一个响应而忽略其余响应,因此这里没有漏洞(耶!),只是效率低下。一次执行多个获取是组合请求的一种很好的技术,但此模块的上下文假设是单个键获取请求。
为了修复它,修改了模块以去除无效值。该示例现在将尝试获取:
$ sudo ~/memcache_scripts/keyflow.d
get OGefRqwX:45220, FOUND KEY
get H02pZPjq:2087rulessml::en, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get WETtYDA0:__special_reg_map, FOUND KEY
get WETtYDA0:__special_reg_map, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get suB5w6XF:683112, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
get WETtYDA0:1:default, FOUND KEY
get WETtYDA0:1:default, FOUND KEY
get H02pZPjq:2087rulessml::en, FOUND KEY
get 3P4iT8M/:4, FOUND KEY
...
这将是一次获取尝试,缓存未命中,并且生活将继续。
结论
1. 缓存是一个很棒的工具,但就像系统的所有部分一样,值得时不时地重新检查一下,以确保一切都按应有的方式工作。可能会找到一些廉价的性能提升和一些反模式的好例子。
2. 除了查找错误之外,监控还有很多好处。这些错误都不是特别糟糕,事实上,它们中的大多数仍然产生了正确的结果。监控并不总是显示错误所在,而是可以改进的地方,同样重要的是显示它们是否成功。