云计算之路-阿里云上:读取缓存时的“黑色0.1秒”

看到标题中的“0.1秒”,你也许会呲之以鼻:不会吧,0.1秒也要计较,不是吃饱撑着,是没吃饱也撑着。

依然没撑着!在memcached应用场景中,响应速度是处于1ms级别的,0.1s可是比1ms慢了100倍啊。

如果你不相信1ms级别,请看这篇文章(微博CacheService架构浅析)中的一段话:

目前微博平台部分业务子系统的Cache服务已经迁移到了CacheService之上,它在实际的运行过程中也取得了良好的性能表现,目前整个集群在线上每天支撑着超过300W的QPS,平均响应耗时低于1ms。

进入正题。。。

自从使用阿里云以来,我们一直被一个问题困扰——日志中时不时会记录读取缓存超过100ms的情况。

一开始我们用的是云服务器跑memcached作为缓存服务,当时以为是虚拟机跑memcached性能跟不上,于是就期待阿里云的缓存服务能解决这个问题。

可是等到阿里云推出OCS(开放缓存服务),换上去之后,读取缓存超过100ms的情况还是会出现。

难道是memcached客户端EnyimMemcached的问题,看了EnyimMemcached的源代码,也没看出问题,EnyimMemcached只是Socket读取数据然后二进制反序列化,这地方再慢也不至于超过100ms吧。

百思不得其解,这个问题就一直放着。。。

今天早上发现日志中记录了00:00-8:00之间竟然发生了近1200次的读取缓存超过100ms的情况,几乎每分钟都出现。昨天刚刚给“黑色n秒”问题找到了最合理的猜想,正处在劲头上。于是趁热打铁,给“黑色n秒”家族添加了一位新成员——“黑色0.1秒”,好好分析一下。

那分析从何处开始呢?我们把怀疑对象锁定在了网络TCP层,所以从抓包开始。

对于Windows系统,最强大的抓包工具非Wireshark莫属。

在云服务器上启动Wireshark,选择与OCS进行通信的内网接口,配置Capture Filter只抓取与OCS进行通信的TCP包。

Wireshark Capture运行没多久,就出现了一次“黑色0.1秒”。

成功抓到了包,根据日志中时间点及缓存Key找到了对应的TCP包:

然后在Wireshark的右击菜单中选择“Follow TCP Strem”,只显示这个TCP流的包:

结果有了一个惊人的发现:云服务器收到OCS响应包的时间是11:23:22.780498,而云服务器发出ACK确认包的时间却是11:23:793597,竟然相差了130.99ms;而日志中缓存读取时间是132.8142ms,0.1秒都耗在了云服务器TCP层在收到包与发ACK包之间。

这个问题应该是TCP层的问题,与上层没问题,与EnyimMemcached就更没关系了。

为了验证这一点,我们修改了一下EnyimMemcached的源代码,在Enyim.Caching.Memcached.Protocol.Binary.BinaryResponse的Read方法中添加了一行代码System.Threading.Thread.Sleep(2000);,让EnyimMemcached在读取缓存数据时暂停2s:


public unsafe bool Read(PooledSocket socket)
{
this.StatusCode = -1;

if (!socket.IsAlive)
return false;

System.Threading.Thread.Sleep(2000);

var header = new byte[HeaderLength];
socket.Read(header, 0, header.Length);

int dataLength, extraLength;

DeserializeHeader(header, out dataLength, out extraLength);

if (dataLength > 0)
{
var data = new byte[dataLength];
socket.Read(data, 0, dataLength);

this.Extra = new ArraySegment<byte>(data, 0, extraLength);
this.Data = new ArraySegment<byte>(data, extraLength, data.Length - extraLength);
}

return this.StatusCode == 0;
}

然后在正常情况下抓包(没有出现黑色0.1秒)

云服务器收到OCS响应包与发ACK包之间只相差了0.00002秒(0.02ms)。

抓包数据证明了“黑色0.1秒”与EnyimMemcached没有关系,属于TCP层的问题。

于是又引发了一个问了无数次的问题?是微软Windows的问题还是阿里云虚拟机的问题?

云计算之路-阿里云上:读取缓存时的“黑色0.1秒”,布布扣,bubuko.com

时间: 2024-08-05 11:12:14

云计算之路-阿里云上:读取缓存时的“黑色0.1秒”的相关文章

云计算之路-阿里云上:原来“黑色0.1秒”发生在socket读取数据时

在昨天的博文(云计算之路-阿里云上:读取缓存时的"黑色0.1秒")中我们犯了一个很低级的错误--把13ms算成了130ms(感谢陈硕发现这个错误!),从而对问题的原因作出了错误的推断,望大家谅解! 从中我们吸取到了一个教训:趁热打铁要小心,容易失去冷静,作出错误的判断. 今天我们痛定思痛,用了一个下午的时间重新分析了"黑色0.1秒"问题,这次从EnyimMemcached的源代码下手(https://github.com/enyim/EnyimMemcached).

云计算之路-阿里云上:什么是“黑色1秒”?

为了更好地分享我们解决"黑色1秒"问题的过程,在这篇博文中我们将专门描述一下"黑色1秒"问题的表现. "黑色1秒"是我们使用阿里云以来继"黑色10秒"之后遭遇的最奇特.最诡异.最难以捉摸.最富有戏剧性的问题. 它有2个最显著的特征: 第一个是最直观的表现,在Windows性能监视器(Performace Monitor)中会出现1秒的ASP.NET Applications -> Requests/Sec(简称QPS)为

云计算之路-阿里云上:消灭“黑色n秒”第三招——禁用网卡的TCP/IP Offload

程咬金有三板斧,我们有三招.在这篇博文中我们要出第三招,同时也意味着昨天在"希望的田野"上的第二招失败了. 前两招打头(CPU)不凑效,这一招要换一个部位,但依然要坚持攻击敌人最弱(最忙最累)部位的原则.那除了CPU,最忙最累的部位是哪里呢?对于Web服务器来说,毫无悬念,当然是网卡.而且阿里云的云服务器,所有的网络负载都集中在一块内网网卡上,SLB(负载均衡)用它,OCS(缓存服务)用它,RDS(数据库服务)也用它.所以,就对它出招! 招式受这篇博文(XenServer – Wind

云计算之路-阿里云上:Wireshark抓包分析一个耗时20秒的请求

这篇博文分享的是我们针对一个耗时20秒的请求,用Wireshark进行抓包分析的过程. 请求的流程是这样的:客户端浏览器 -> SLB(负载均衡) -> ECS(云服务器) -> SLB -> 客户端浏览器. 下面是分析的过程: 1. 启动Wireshark,针对内网网卡进行抓包. 2. 在IIS日志中找出要分析的请求(借助Log Parser Studio) 通过c-ip(Client IP Address)可以获知SLB的内网IP,在分析Wireshar抓包时需要依据这个IP进

云计算之路-阿里云上:超过70秒的请求抓包分析

超过70秒的请求是通过分析IIS日志发现的: 10.159.63.104是SLB的内网IP. 通过Wireshark抓包分析请求是9:22:21收到的(tcp.stream eq 23080): 09:22:21.299838000 10.159.63.104 10.161.241.208 HTTP 291 GET /eastsea/p/3764040.html HTTP/1.0 这个请求响应内容的长度是:Content-Length 1154110(1.1MB) 云服务器(ECS)在收到请求后

云计算之路-阿里云上:对“黑色n秒”问题的最终猜想——CPU C-states引起的

如果说2013年云计算之路的主题是"踩坑",那么2014年我们希望云计算之路的主题变成"填坑"--当然填坑是阿里云来完成的,我们只是见证曾经的坑坑洼洼变成平坦大道. 15号(周四)晚上我们发现了SLB会话保持的坑,16号晚上阿里云成功定位并进行修复,这两天正式发布后会填平这个坑.这次从踩坑到填坑的过程是最痛快的一次. 接下来我们的目标锁定在"黑色n秒"(刚发现一个英文说法:stuck for x seconds)这个坑我们最多.最神秘.最诡异的坑

云计算之路-阿里云上:CPU 100%引发的状况

今天下午17:00-17:05之间,在请求量没有明显变化的情况下,SLB中的1台云服务器的CPU突然串到100%(当时SLB中一共有3台云服务器),见下图: 造成的直接后果是请求执行时间变得超长,最长竟然达到了53秒(下图中的紫色线条). 另外伴随的表现是大量请求排队. 再看看这个时间段其它2台服务器的表现: 从这些现象分析,我们猜测CPU 100%这台云服务器出现了CPU资源争抢问题,将之从SLB中摘除后恢复正常. 云计算之路-阿里云上:CPU 100%引发的状况,布布扣,bubuko.com

云计算之路-阿里云上:消灭“黑色n秒”第一招——不让CPU空闲

昨天对"黑色n秒"问题的最终猜想以失败而告终,从而让我们结束了被动猜想阶段,进入了主动进攻阶段--出招. 今天出第一招--用C#写个小程序,让其在每个CPU核上运行一个线程,不让任何一个CPU核进入空闲(idle)状态,以进一步排除CPU idle引起的"黑色n秒". 在这一招中,借助的最重要的武器是System.Diagnostics.ProcessThread.ProcessorAffinity.通过给ProcessorAffinity设置一个掩码,就可以指定当

云计算之路-阿里云上:消灭“黑色n秒”第二招——给w3wp进程指定CPU核

虽然昨天的第一招失败了,但是从失败中我们学到了与多核CPU相关的Processor Affinity(处理器关联)的知识. 既然我们可以让.NET程序的不同线程运行于指定的CPU核,那是不是也可以让IIS应用程序池的进程w3wp运行于指定的CPU核? 虽然看起来"黑色n秒"似乎与w3wp运行于哪些CPU核没有什么关系,但是我们既然把怀疑对象锁定在CPU,那么任何与CPU相关的线索都不能放过.即使失败,也会满载而归,因为如果没有"黑色n秒"这个问题的驱动,我们根本不会