redis analyst (9)- redis cluster issues/puzzles on producation

上篇文章枚举了诸多互联网公司分享的应用redis cluster中遇到的问题,本文罗列所在公司上线后出现的一些问题,也包括一些小的困惑。

问题1:出现auto failover

现象:监控redis半个多月的时候,偶然发现其中1台master自动触发failover。
原因:

1.1 查看出现的时间点的日志:

Node 912a1efa1f4085b4b7333706e546f64d16580761 reported node 3892d1dfa68d9976ce44b19e532d9c0e80a0357d as not reachable.

从日志看到node not reachable,首先想到2个因素:
(1)redis是单进程和单线程,所以有任何一个耗时操作都会导致阻塞时间过长,最终导致failover.
(2)网络因素;
首先排除了可能原因(1),因为从系统应用分析,并无任何特殊操作。都是最普通的操作且请求量很小,可能原因(2)不能排除。

1.2 查看出现问题时间点的系统资源应用情况:

查看了所有的常见指标,除了最近1分钟的load异常外,均正常,锁定原因为:系统load过高,达到7,导致系统僵死。其他节点认为这个节点挂了。

解决:考虑到所有其他指标:cpu/memory/disk等都正常,以及其他2台master一直也正常,业务量非常小,这种情况偶发,所以归结问题原因是这台虚拟机有问题,所以反馈问题并迁移虚拟机,迁移后system load一直平稳无问题。也没有出现failover.

困惑2:slave的ops远小于master的ops

现象:已知所有操作都是删除操作,并无查询操作。所以很好奇,为什么master和slave的ops差别这么大:前3台为master,达到100ops,相反slave不到10.

解惑:CRUD中,不见得只要是CUD就肯定会“传播”命令到slave,还有一个条件是必须“库”发生了改变。例如当前的业务中,处于测试阶段,所有主流操作都是删除操作,而且这些删除操作都是删除一个没有key的操作。所以并没有发生改变(即下文中dirty为0)。
计算dirty值:

    /* Call the command. */
    c->flags &= ~(REDIS_FORCE_AOF|REDIS_FORCE_REPL);
    // 保留旧 dirty 计数器值
    dirty = server.dirty;
    // 计算命令开始执行的时间
    start = ustime();
    // 执行实现函数
    c->cmd->proc(c);
    // 计算命令执行耗费的时间
    duration = ustime()-start;
    // 计算命令执行之后的 dirty 值
    dirty = server.dirty-dirty;

只有dirty值发生改变:

  
        // 如果数据库有被修改,即判断dirty,那么启用 REPL 和 AOF 传播
        if (dirty)
            flags |= (REDIS_PROPAGATE_REPL | REDIS_PROPAGATE_AOF);

        if (flags != REDIS_PROPAGATE_NONE)
            propagate(c->cmd,c->db->id,c->argv,c->argc,flags);

所有的操作,不见得都会改变dirty值:

void delCommand(redisClient *c) {
    int deleted = 0, j;

    for (j = 1; j < c->argc; j++) {

        // 尝试删除键
        if (dbDelete(c->db,c->argv[j])) {
            //改变server.dirty
            server.dirty++;
        }
    }

 }

问题3:socket timeout

现象:查看最近1周数据访问量,有4个socket timeout错误:


redis.clients.jedis.exceptions.JedisConnectionException: java.net.SocketTimeoutException: Read timed out
at redis.clients.util.RedisInputStream.ensureFill(RedisInputStream.java:202)
at redis.clients.util.RedisInputStream.readByte(RedisInputStream.java:40)
at redis.clients.jedis.Protocol.process(Protocol.java:151)
at redis.clients.jedis.Protocol.read(Protocol.java:215)
at redis.clients.jedis.Connection.readProtocolWithCheckingBroken(Connection.java:340)
at redis.clients.jedis.Connection.getIntegerReply(Connection.java:265)
at redis.clients.jedis.Jedis.del(Jedis.java:197)
at redis.clients.jedis.JedisCluster$110.execute(JedisCluster.java:1205)
at redis.clients.jedis.JedisCluster$110.execute(JedisCluster.java:1202)
at redis.clients.jedis.JedisClusterCommand.runWithRetries(JedisClusterCommand.java:120)
at redis.clients.jedis.JedisClusterCommand.run(JedisClusterCommand.java:31)
at redis.clients.jedis.JedisCluster.del(JedisCluster.java:1207)
at com.webex.dsagent.client.redis.RedisClientImpl.deleteSelectedTelephonyPoolsInfo(RedisClientImpl.java:77)
at sun.reflect.GeneratedMethodAccessor75.invoke(Unknown Source)

配置:
connectionTimeout=800
soTimeout=1000

BTW: 确实消耗了&gt;1000ms
componentType":"Redis","totalDurationInMS":1163

原因: 查看4个错误发生的时间,都发生在某天的一个时间点,且用key计算分段,也处于同一个机器上,所以归结到网络原因或虚拟机问题,无法重现。

linux commands note

1 查看文件大小,倒序按数字:

du -sh *|sort -n -r

-r 倒序 -n 按数字排

2 查看磁盘按G为单位:

df -h 

3 永久修改主机名:

vi /etc/sysconfig/network 

区别临时修改 hostname

4 设置自动启动:

修改/etc/rc.d/rc.local

5 sed替换

sed  -i 's/properties/property/g'  file.xml

-i为直接替换源文件,否则不直接替换源文件。

6 iptable转port:

iptables -t nat -A PREROUTING -p tcp --dport 80 -j REDIRECT --to-port 5601
iptables -t nat -L
iptables -t nat -F

7 根据ip反查dns:

# host 10.224.2.138

8 查DNS Server:

more /etc/resolv.conf 
nameserver 10.224.91.8

9 根据ip查信息:

nbtstat -A 10.154.144.205

metric driven (1) – aware spike erosion

现象

查看某个host的最近2周的load(last 1 minute)情况,可观察到尖峰时刻发生在5月3号,数值为0.167.

当试图查看具体什么时间点达到尖峰时(缩小时间范围),发现这个尖峰时刻的数据值不再是0.167,而是2:

从现象上表明:时间范围越大,数据的可信度越低,继续查看图1中的其他低点的尖峰,缩小时间范围后,竟然超过了第一尖峰,验证了这个设想。

原因

按常理,绘制图像的时候,直接将所有的数据展示出来即可,简单明了,但是实际操作中,对于一个时间范围较小的数据量较小时,并不存在问题,但是考虑到假设需要展示1年或者一个数据量超级大的数据时,存在两个问题:

  • 性能问题:显而易见,“点”越多,绘制的时间越长,性能也越差,可能等几分钟才能等到一幅图渲染完成。例如下图:如此稠密的图,展示就已经耗费很多时间,而实际上稠密的部分并无太多意义:

  • 显示问题:假设所用的电脑屏幕分辨率是1920 x 1080,同时X轴以时间为单位,当展示大范围的时间范围(例如1年)的时候,则每个肉眼有价值的点是“1年*365天*24小时/1920=4.56天”,而56天的数据范围,要不全部展示(则出现问题1),要不采取一定的策略,仅展示一部分。

所以结合现实(电脑分辨率)和性能问题(数据量太大),很多metric绘制采取了一定的策略。例如上文提及中观察到奇怪现象原因在于:

当展示一段时间范围内的数据时,采用的是平均值。所以当时间范围越大,尖峰越不准确,因为这个尖峰实际上所显示时间范围的平均值。

解决:

了解现象的原因,自然可以注意到并接纳这个现象,同时也大体能思考出如何解决, 既然展示的是平均值,那真正需要“尖峰”,展示最大值即可。

(1)对于没有提供辅助方案或者懒于处理数据的用户:

接纳这个现象,真正需要尖峰数据时,多选择尖峰时刻,多缩小范围。

(2)很多metric系统提供了辅助方案:

例如Cassandra自带的opscenter中的一些图: 显示平均值之外,显示最大值和最小值:

例如circonus提供了Aggregation Overlays,在原有默认展示图的基础之上,展示各种定制的“图层”

增加图层后:最大值变成了6.1,而不是最开始的0.167,时间点也不是图1所展示的尖峰时刻。

小结

注意metric图形中是否有spike erosion现象,如果存在,则接受之并适当处理,才能获取到真正想要的数据。而不是诧异于数据的诡异。

再如一类似例子:

下图为redis监控的一个指标,表示当前连接的客户端的数目,但是奇怪的是,偶尔会出现小数结果:例如图中的37.5.

实际上,虽然是gauge的值类型,也是整型值,但是显示时间范围不同时,怎么展示值是个问题?是最后一个数据,还是第一个数据,还是平均数还是最大值,而在这里可以注意到value type是average value即平均值。例如时间范围选择2天时,会以10分钟为频度计算平均值,所以会出现小数点值。

总结:metric的阅读中,可能存在很多无法理解的现象,要考虑到实际绘制的原理和数据如何产生等问题,才能有效理解metric.

common performance tool and solution

之前一直想把经常搞的性能测试的公共部分(压力控制部分)抽取出来作为一个公共的部分(jar),这样一方面能让开发测试者都集中在”测试性能的case”编写上,另外一个方面使用同一标准和同一实现有利于”团队”内部标准化。

实际上,现在大多直接使用jmeter来控制压力,也能达到效果,但是jmeter本身到底如何控制的,不去熟读代码很难理解,实际使用中,假设case需要调用java代码等时,还需要学习bean shell等,所以总结起来就是自由度不够大,不够透明,所以试用一段时间后,觉得不如自己实现一套,自由度大的,更广泛通用可控的,于是有了:

https://github.com/jiafu1115/performance-test-tool

直接看如何使用(基本使用方式):

compile exec:java -Dexec.mainClass="com.test.performance.PerfTool" -Dexec.args="-t com.test.performance.demo.DemoTestCaseImpl -duration 20 -thread 5 -tps 30"

(1)控制3个参数:1 持续多久 -duration 20 2 使用多少线程 -thread 5 3 TPS期待多少 -tps 30 实际使用,可以只指定线程数,让每个线程loop去发,也可以单独设置tps不设置线程数来尽量达到预期TPS.
(2)提供2种方式:1 测试Case实现类:-t com.test.performance.demo.DemoTestCaseImpl 2 收集测试结果类: -r com.test.performance.result.impl.InfluxdbCollectMethodImpl或自己提供
(3)提供3种运行信息:1 -program MyProgramName 2 -testname TestWebService 3 -runid ThisRunId
(4)提供4种case辅助: 1 before test 2 after test 3 prepare environment 4 destroy environment.

这样基本完成单机压力控制和实现,然后默认提供了influxdb的收集结果的方式和日志输出的方式可供选择,从而使用者只需要专注用例实现和结果收集即可。

结合这个单机的压力控制,还要完成三件事情:

(1) 并发控制: 可以采用jenkins的multi config项目来控制多个机器并发。

效果图:

(2) 结果收集: 可以采用influxdb等来收集,同时需要收集被测试机器的性能,可以在机器上部署collectd,然后发到influxdb,这样数据结果包含2个部分:性能测试数据和系统性能。
(3) 结果分析: 可以直接使用grafana来展示即可,而对于server的数据收集可采用collectd + grafana.

效果图:

结果应该至少提供3个维度:
(1)测试的性能数据, TPS, 响应时间(分布), 成功率
(2)被测机器的系统性能: cpu, memory, io, etc
(3)被测应用的性能数据: TPS, 响应时间(分布),成功率

总结: 经过剥离变化,就解决了共同的问题,然后使得性能测试者只关注自身测试用例和测试结果的收集和展示,这样就轻松了许多。

附:

1 使用的组件的安装:

1.1 influxdb 安装:

wget https://dl.influxdata.com/influxdb/releases/influxdb-1.5.0.x86_64.rpm
sudo yum localinstall influxdb-1.5.0.x86_64.rpm
service influxdb start

1.1版本后无web界面了,别找了。

1.2 grafana 安装

wget https://s3-us-west-2.amazonaws.com/grafana-releases/release/grafana-5.0.3-1.x86_64.rpm
sudo yum localinstall grafana-5.0.3-1.x86_64.rpm
service grafana-server start

1.3 collectd 安装

wget http://mirrors.163.com/.help/CentOS6-Base-163.repo
yum install epel-release
yum install collectd
service collectd start

2. 使用的组件的配置:

2.1 influxdb + collectd收集系统信息需要的配置:

influxdb配置:

开启collectd数据收集:

[[collectd]]
    enabled = true
    bind-address = ":25826"
    database = "collectd"

启动会报错: /usr/share/collectd/types.db
所以influx上也要装上collectd可以解决这个问题。

2.2 collectd配置: server指向influxdb

Hostname "10.224.82.92"
 
Interval 2
ReadThreads 5

LoadPlugin cpu
LoadPlugin load
LoadPlugin memory
LoadPlugin swap
LoadPlugin battery

LoadPlugin network
<Plugin "network">
Server "10.224.2.147" "25826"
</Plugin>