Tendis icon indicating copy to clipboard operation
Tendis copied to clipboard

tendis failover use too much time

Open piaoairy219 opened this issue 4 years ago • 33 comments

2 machine 192.168.149.15/192.168.149.27 centos7.7 3 instances in every machine use latest release version: tendis-2.1.2-rocksdb-v5.13.4 192.168.149.15:51001 (master) -> 192.168.149.27:51001 (slave) 192.168.149.15:51002 (master) -> 192.168.149.27:51002 (slave) 192.168.149.15:51003 (master) -> 192.168.149.27:51003 (slave) follow the instruction in http://tendis.cn/#/Tendisplus/%E8%BF%90%E7%BB%B4/new_cluster redis-cli -c can set and get many keys successfully(moved related slots) QQ截图20210225200845

but when I kill 192.168.149.15:51001, it can't failover and improved 192.168.149.27:51001 into master automatically, and I can't get any key, even which isn't in slots of down master. doesn't tendis failover automatically?

QQ图片20210225200350 QQ图片20210225200536 QQ截图20210225200624

piaoairy219 avatar Feb 25 '21 12:02 piaoairy219

below is one configuration, other is just different in bind&port: # tendisplus configuration for testing bind 192.168.149.15 port 51001 loglevel notice logdir ./home/log dumpdir ./home/dump dir ./home/db pidfile ./home/tendisplus.pid slowlog ./home/log/slowlog rocks.blockcachemb 640 executorThreadNum 4 netiothreadnum 2 requirepass titan cluster-enabled yes

rocks.blockcache_strict_capacity_limit 0 rocks.cache_index_and_filter_blocks 1 rocks.max_open_files -1 rocks.compress_type snappy #rocks.level0_compress_enabled no #rocks.level1_compress_enabled no rocks.level_compaction_dynamic_level_bytes 1 # [n >= 4, n <= 64, n ~= cpu_cores] rocks.max_background_compactions 64 #rocks.max_write_buffer_number 16 #rocks.min_write_buffer_number_to_merge 14 rocks.write_buffer_size 67108864 rocks.target_file_size_base 67108864 rocks.max_bytes_for_level_base 536870912

piaoairy219 avatar Feb 25 '21 12:02 piaoairy219

If a slave improve to be a master, there are conditions:

  1. slave is online
  2. slave is not behind master too much

More details in https://github.com/Tencent/Tendis/blob/dev-2.2/src/tendisplus/cluster/cluster_manager.cpp#L2601

You can see the log in ./home/log/INFO, what happened at that moment.

TendisDev avatar Feb 26 '21 06:02 TendisDev

现在能failover了。 原来master上配置了requirepass,但是slave上没有配masterauth,我还以为这两个选项是独立的。 我刚刚添加了masterauth,配的跟requirepass一样,可以failover了。但是还有一些问题

我杀掉192.168.149.15:51001,然后立即多次重试对27:51001的访问 [root()@vm-bjdhj-149-27 tendis1]# /home/work/zzkv_test/redis-cli -c -h 192.168.149.27 -p 51001 -a titan get key2 Error: Connection reset by peer [root()@vm-bjdhj-149-27 tendis1]# /home/work/zzkv_test/redis-cli -c -h 192.168.149.27 -p 51001 -a titan get key2 Could not connect to Redis at 192.168.149.15:51001: Connection refused Could not connect to Redis at 192.168.149.15:51001: Connection refused [root()@vm-bjdhj-149-27 tendis1]# /home/work/zzkv_test/redis-cli -c -h 192.168.149.27 -p 51001 -a titan get key2 Could not connect to Redis at 192.168.149.15:51001: Connection refused Could not connect to Redis at 192.168.149.15:51001: Connection refused

约一二十秒后终于能够读取了: [root()@vm-bjdhj-149-27 tendis1]# /home/work/zzkv_test/redis-cli -c -h 192.168.149.27 -p 51001 -a titan get key2 "val2" 我检查27:51001--老slave(新master),它在老master连不上约20秒后,才开始报告老master不可用,开始选主。

所以我有如下几个问题: 1 为什么老master不可用期间,老slave不能读取?是否要改什么配置 2 切主时间怎么缩短? 3 切主之前老master不可用这段时间,是否有办法让它相关槽位上的写请求也成功?

piaoairy219 avatar Feb 26 '21 08:02 piaoairy219

@TendisDev 请问上面这个failover时间过长的问题,如何解

piaoairy219 avatar Mar 02 '21 02:03 piaoairy219

image 可以把这个参数变小

TendisDev avatar Mar 02 '21 03:03 TendisDev

@vinchen 这个不能生效,我昨天把cluster-node-timeout改成5000,发现主退出要7-14秒,然后它的从才发现主连接断开,然后不断尝试重连主持续7秒后,才开始选主。 刚才我把cluster-node-timeout改成100,并重启从使其生效,然后再kill主,结果主退出和从尝试重连仍各要7秒,并且之后从一直报错,没有再选主。 主收到kill 主完成退出 从发现连接断开开始重连 从报告主不可达但不能选主

piaoairy219 avatar Mar 02 '21 03:03 piaoairy219

这个情况应该是执行了正常shutdown的行为,资源回收,并刷盘等操作还在执行,并且gossip通讯相关线程仍在工作,所以其他节点没有及时对这个节点判死

可以尝试使用kill -9终止进程

收到shutdown指令,gossip 相关线程尽快退出应该可以加快这种情况的HA,我们评估下

TendisDev avatar Mar 02 '21 03:03 TendisDev

退出慢可以用kill -9解,但是从之后又重连7秒的过程如何缩短?且报data age to large不能选主的问题如何解呢?

piaoairy219 avatar Mar 02 '21 03:03 piaoairy219

可以看下shutdown逻辑,将cluster相关的线程退出提前,编译一个版本看看效果

TendisDev avatar Mar 02 '21 03:03 TendisDev

我是指主已经退出了从又重连7秒的问题,这个把主的cluster线程退出提前,也影响不了前者啊,毕竟前者是在主完全退出才开始的

piaoairy219 avatar Mar 02 '21 04:03 piaoairy219

  1. 是否所有节点的nodetimeout都调整一致了,调整为多少
  2. 使用kill -9杀master是否仍存在上述问题

如果仍然存在,提供一下完整的配置的操作流程,我们先重现一下

TendisDev avatar Mar 02 '21 04:03 TendisDev

(1)开始选主之前的延迟是因为 需要一半以上的master 对fail节点进行标记,标记完成后统计达到一半以上发广播,和从一种重连7秒应该没有关系 (2)data age to large这里触发是因为你的time out时间太小,因此主从之间上次通信的时间有个最大值的限制,他是根据timeout时间计算的,这里看日志通信时间超过了2秒限制。

flywukong avatar Mar 02 '21 07:03 flywukong

@flywukong data age to large这里触发是因为你的time out时间太小,因此主从之间上次通信的时间有个最大值的限制,他是根据timeout时间计算的,这里看日志通信时间超过了2秒限制。 你意思是根据配置的cluster-node-timeout计算了上次通信时间吗? 我配的是100 前面选主前的延迟7秒,的确是没有统一所有节点的配置值,我原以为改下宕机主的从就行了。现在改完后,标记宕机主变快了,但是仍然报错data age to large

piaoairy219 avatar Mar 02 '21 08:03 piaoairy219

发现把旧的从也重启,就可以变主了,没有data age to large错误了。 但是再kill新的主,发现它的从又报data age to large不能切主了。

piaoairy219 avatar Mar 02 '21 09:03 piaoairy219

@TendisDev 请问上面这个data age to large:不能选主的问题怎么解呢 另外,前面说的将cluster相关的线程退出提前,是否会造成有一部分数据没同步到从,从升主后,客户端读的数据,与当初写到老主的数据不一致?

piaoairy219 avatar Mar 03 '21 02:03 piaoairy219

上次主从通信的时间psynctime是由主从同步模块来记录的,从节点选举需要满足下面这个条件 now() - psynctime > 10*cluster-node-timeout + 1 不满足的话就不能选举为主

flywukong avatar Mar 03 '21 03:03 flywukong

我看到过https://github.com/Tencent/Tendis/blob/dev-2.2/src/tendisplus/cluster/cluster_manager.cpp#L2601 里的相关代码,但是找不到决定psynctime的相关配置 多久主从通信一次呢,可配置吗

piaoairy219 avatar Mar 03 '21 03:03 piaoairy219

旧的从这里重启 可以变主是一个bug (刚拉起psynctime有个初始化值), 这里应该不可用变主,因为它数据是不对的,我们正在修复

flywukong avatar Mar 03 '21 03:03 flywukong

1秒通信一次,不需要你配置,cluster-node-timeou时间太小不合适,导致data_age这里满足不了条件,或者你可以修改一下这个cluster-slave-validity-factor 改成小于10的值(比如5), 这样data_age就不容易触发

flywukong avatar Mar 03 '21 03:03 flywukong

明白了,原来是bug绕过了规则限制啊:) 不过从代码看应该是now() - psynctime > 10*cluster-node-timeout + 1满足才不能选主吧 企业微信截图_20210303112439 所以我如果我想维持cluster-node-timeout较小(为了减少服务不可用时间),要把cluster-slave-validity-factor改大吧,就是不知道有无其它负面影响

piaoairy219 avatar Mar 03 '21 03:03 piaoairy219

是这个条件,意思是psynctime必须要最近时间点的,fator是改大 , 后面这块逻辑会优化下, 只要不是timeout时间太小导致误判 其它负面影响应该不大

flywukong avatar Mar 03 '21 03:03 flywukong

我把各个节点timeout都改为200,factor都改为50 发现标记failing后,又等了700ms左右才选主,这个时间是怎么回事,可优化吗。之前测试发现有1秒左右整个集群状态为down,所有槽位都读不了数据,应该就是这个时间。 企业微信截图_20210303121345

piaoairy219 avatar Mar 03 '21 04:03 piaoairy219

@flywukong @TendisDev

piaoairy219 avatar Mar 03 '21 06:03 piaoairy219

探测到master  fail后, slave 会延迟下面一段时间发起选举: 500 + random()%500 + rank*1000  单位是毫秒, 目的是为了在多个slave的情况下能够保证rank最低的当选为 master 这里我们默认还没提供参数配置来调整延迟时间,在一主一从的情况下 这个延迟其实是可以去掉的

flywukong avatar Mar 03 '21 10:03 flywukong

我是三主三从,模拟线上情况。 对于线上来说,老主挂掉后,肯定希望新主越快上线越好。因为在此期间,请求都不能响应了。线上业务访问都中断了

piaoairy219 avatar Mar 03 '21 10:03 piaoairy219

如果一个master 只有一个slave , cluster_manager.cpp 里面这行代码你可以按照自己的需求改下,改小一点 ,改成0应该也没问题 auto delayTime = msSinceEpoch() + 500 + /* Fixed delay of 500 milliseconds, let FAIL msg propagate. */ redis_port::random() % 500;

flywukong avatar Mar 03 '21 11:03 flywukong

好的,我试试。redis_port::random() % 500是让多个从错开,避免竞争选主吧?

我昨天试了把_clusterMgr->stop()提前,的确能把其它节点感知主down掉提前了6-7秒,这样应该没问题吧

--- a/src/tendisplus/server/server_entry.cpp
+++ b/src/tendisplus/server/server_entry.cpp
@@ -1465,15 +1465,15 @@ void ServerEntry::stop() {
   _replMgr->stop();
   if (_migrateMgr)
     _migrateMgr->stop();
+  if (_clusterMgr) {
+    _clusterMgr->stop();
+  }
   if (_indexMgr)
     _indexMgr->stop();
   {
     std::lock_guard<std::mutex> lk(_mutex);
     _sessions.clear();
   }
-  if (_clusterMgr) {
-    _clusterMgr->stop();
-  }
   if (_gcMgr) {
     _gcMgr->stop();
   }

另外,我发现主在收到kill信号后,仍然过了0.5-1秒,采取执行stop操作 I0303 18:53:55.990830 32318 main.cpp:22] signal:15 caught, begin shutdown server I0303 18:53:56.850428 32318 server_entry.cpp:1433] _isShutdowned is true I0303 18:53:56.850437 32318 server_entry.cpp:1455] server begins to stop...

我分析了下代码,感觉下图第一个红框里,两个等待条件是导致它不立即stop的,_mutex加锁的地方很多,但我现在没读写,应该不至于等这么久,怀疑_eventCV.wait_for这里等待导致的,是否能优化呢? 企业微信截图_16148263138794

piaoairy219 avatar Mar 04 '21 03:03 piaoairy219

是为了避免同时竞争选主, _clusterMgr->stop()可以提前

flywukong avatar Mar 04 '21 03:03 flywukong

上面说的stop前的约1秒等待,能定位什么原因吗?是否可优化 @flywukong @TendisDev

piaoairy219 avatar Mar 05 '21 10:03 piaoairy219

@flywukong @TendisDev 上面能failover缩短并成功,是因为当时没有读写请求。 我发现一些新问题: 1 我在failover期间,加上读写请求,发现failover又明显边长,甚至不能选主! 加上读写请求后,大多数failover的结果是:_replMgr->stop()这一步显著加长,需要10秒左右。不过有一次达到了30秒,结果从又不能满足now() - psynctime > cluster-slave-validity-factor * cluster-node-timeout + 1 ,无法选主。 _replMgr->stop()且从不能选主的那一次见如下三幅图,后续没有复现 企业微信截图_16151963032664 企业微信截图_16151961229878 企业微信截图_16151963032664 大多数时候_replMgr->stop()要10秒,从能选主的见下图,也是有报错的 企业微信截图_16152053649100 2 failover期有丢数据的情况 我开两个脚本,一个写,先执行,一个读,晚于写脚本几分钟执行。两者访问的key都是相同起点,且不断递增。 中间进行failover,failover需几秒钟。failover时第一个写出错key之前的那一段key区间,都是前端写入成功的。按理说failover完成后,集群恢复正常,读进程晚了几分钟再来读这段key区间,应该是可以读到的。结果读到的很多都是空,即failover前的一段key,有不少丢失了。我后续手动访问这些key,仍然是读不到值的。 这样,即使最终一致性也没有满足了。 想问问,是否是正常现象?一般分布式要么强一致+牺牲切主期可用性,要么可用性基本无损+最终一致性,看起来tendisCP/AP都牺牲了,也没有最终一致性。不知道是不是我的环境或配置有不对的. 如下是测试脚本

if [ $# -lt 2 ]; then
    echo "usage: $0 <logfile> <type> "
    echo "1 means set, other means get"
    exit 1
fi

file=$1
type=$2
key=69999999920000000
date '+%T'
while [ 1 ] 
do
    echo "key=$key" >> $file
    if [ $type -eq 1 ]; then
        /home/work/zzkv_test/redis-cli -h 10.136.219.145 -p 51000 set $key $key >> $file
    else
        /home/work/zzkv_test/redis-cli -h 10.136.219.145 -p 51000 get $key >> $file
    fi
    let key++
done

这是两个脚本输出的对比。69999999920153478是因为failover,写进程第一个访问出错的key。读写qps大概是700/s,通过predixy代理来进行访问 企业微信截图_16151988869468

以上两种测试,各tendis节点都是如下配置(仅bind和port不同),三主三从

bind 10.136.219.145
port 51001
loglevel notice
logdir ./home/log
dumpdir ./home/dump
dir ./home/db
pidfile ./home/tendisplus.pid
slowlog ./home/log/slowlog
rocks.blockcachemb 65536 
executorThreadNum 48
netiothreadnum 8
requirepass titan
masterauth titan
cluster-enabled yes

cluster-node-timeout 200
cluster-slave-validity-factor 50

rocks.blockcache_strict_capacity_limit 0
rocks.cache_index_and_filter_blocks 1
rocks.max_open_files -1
rocks.compress_type snappy
#rocks.level0_compress_enabled no
#rocks.level1_compress_enabled no
rocks.level_compaction_dynamic_level_bytes 1
# [n >= 4, n <= 64, n ~= cpu_cores]
rocks.max_background_compactions 64
#rocks.max_write_buffer_number 16
#rocks.min_write_buffer_number_to_merge 14
rocks.write_buffer_size 67108864
rocks.target_file_size_base 67108864
rocks.max_bytes_for_level_base 536870912```

piaoairy219 avatar Mar 08 '21 12:03 piaoairy219