Chinaunix首页 | 论坛 | 博客
  • 博客访问: 6404206
  • 博文数量: 567
  • 博客积分: 13065
  • 博客等级: 上将
  • 技术积分: 10046
  • 用 户 组: 普通用户
  • 注册时间: 2008-03-26 16:44
个人简介

推荐: blog.csdn.net/aquester https://github.com/eyjian https://www.cnblogs.com/aquester http://blog.chinaunix.net/uid/20682147.html

文章分类

全部博文(567)

分类: C/C++

2019-03-21 16:26:22


REdis版本:4.0.9

运行环境:Linux 3.10.107 x86_64 gcc_version:4.8.5

结论:是一个BUG,在4.0.11版本中被作者antirez所修复

 

现象:

1) top显示

 

2) 执行REdis info命令直接卡住不动

3) 集群通讯端口大量的“CLOSE_WAIT

4) 日志文件大量的“Bad message length or signature received from Cluster bus

5) 物理内存和虚拟内存均占用不高(配置最大内存为5G,实际占用物理内存才4M多)

6) 通过其它正常节点查看,该故障节点处于“fail”状态

 

推测:发生了死循环。

 

GDB分析:

(gdb) bt

#0  je_malloc (size=size@entry=47) at src/jemalloc.c:1425

#1  0x00000000004329ee in zmalloc (size=size@entry=47) at zmalloc.c:98

#2  0x000000000043cea9 in createEmbeddedStringObject (ptr=0x7f5da721b101 "dog:cgi:proj_trans_query_hb", len=27) at object.c:85

#3  0x000000000043cf65 in createStringObject (ptr=ptr@entry=0x7f5da721b101 "dog:cgi:proj_trans_query_hb", len=) at object.c:119

#4  0x000000000044141b in dbRandomKey (db=0x7f5da72d5000) at db.c:236

#5  0x00000000004414c2 in randomkeyCommand (c=0x7f5da6dd9e00) at db.c:498

#6  0x000000000042c03e in call (c=c@entry=0x7f5da6dd9e00, flags=flags@entry=15) at server.c:2229

#7  0x000000000042c6e7 in processCommand (c=0x7f5da6dd9e00) at server.c:2510

#8  0x000000000043b745 in processInputBuffer (c=0x7f5da6dd9e00) at networking.c:1354

#9  0x00000000004267f0 in aeProcessEvents (eventLoop=eventLoop@entry=0x7f5da723a050, flags=flags@entry=11) at ae.c:440

#10 0x0000000000426adb in aeMain (eventLoop=0x7f5da723a050) at ae.c:498

#11 0x00000000004238ef in main (argc=, argv=0x7ffc0451ab58) at server.c:3894

(gdb) f 5

#5  0x00000000004414c2 in randomkeyCommand (c=0x7f5da6dd9e00) at db.c:498

498     db.c: No such file or directory.

(gdb) p *c

$7 = {id = 144, fd = 78, db = 0x7f5da72d5000, name = 0x0, querybuf = 0x7f5da70ae285 "", pending_querybuf = 0x7f5da7216743 "", querybuf_peak = 0, argc = 1, argv = 0x7f5da72167f0, 

  cmd = 0x741820 , lastcmd = 0x741820 , reqtype = 2, multibulklen = 0, bulklen = -1, reply = 0x7f5da6d20ea0, reply_bytes = 0, 

  sentlen = 0, ctime = 1542039740, lastinteraction = 1542039740, obuf_soft_limit_reached_time = 0, flags = 0, authenticated = 0, replstate = 0, repl_put_online_on_ack = 0, 

  repldbfd = -1496183376, repldboff = 0, repldbsize = 0, replpreamble = 0x5bdb29d9 , read_reploff = 0, reploff = 0, repl_ack_off = 0, 

  repl_ack_time = 0, psync_initial_offset = 1090943882, 

  replid = "\000\000\000\000]\177\000\000\000\000\000\000\000\000\000\000\216\000\000\000\000\000\000\000\377\377\377\377\000\000\000\000\000P-\247]\177\000\000", 

  slave_listening_port = 0, slave_ip = "\000\000\000\000\000\000\000\000\243k!\247]\177", '\000' , "]\177\000\000@g!\247]\177\000\000\000\000\000\000\000", 

  slave_capa = 0, mstate = {commands = 0x0, count = 0, minreplicas = -1, minreplicas_timeout = 140040207470240}, btype = 0, bpop = {timeout = 0, keys = 0x7f5da72b2aa0, target = 0x0, 

    numreplicas = 0, reploffset = 0, module_blocked_handle = 0x0}, woff = 0, watched_keys = 0x7f5da6d20e70, pubsub_channels = 0x7f5da72b2b00, pubsub_patterns = 0x7f5da6d20ed0, 

  peerid = 0x0, bufpos = 0, 

  buf = '\000' , "\023.Kp\000\000\000\000\240\016\322\246]\177\000\000\000++\247]\177\000\000\320\016\322\246]\177", '\000' , "$-1\r\n", '\000' , "\240*+\247]\177", '\000' , "\242;\223<\000\000\000\000\000\000\000\000]\177\000\000\000\000\000\000\000\000\000\000\240*+\247]\177", '\000' , "$-1\r", '\000' ...}

(gdb) p *c->cmd

$8 = {name = 0x4f3026 "randomkey", proc = 0x4414b0 , arity = 1, sflags = 0x4f2e87 "rR", flags = 130, getkeys_proc = 0x0, firstkey = 0, lastkey = 0, keystep = 0, 

  microseconds = 139, calls = 67}

(gdb) c

Continuing.

^C

Program received signal SIGINT, Interrupt.

0x00007f5da782339b in random () from /lib64/libc.so.6

(gdb) bt

#0  0x00007f5da782339b in random () from /lib64/libc.so.6

#1  0x0000000000428bf5 in dictGetRandomKey (d=0x7f5da7218360) at dict.c:630

#2  0x00000000004413e0 in dbRandomKey (db=0x7f5da72d5000) at db.c:232

#3  0x00000000004414c2 in randomkeyCommand (c=0x7f5da6dd9e00) at db.c:498

#4  0x000000000042c03e in call (c=c@entry=0x7f5da6dd9e00, flags=flags@entry=15) at server.c:2229

#5  0x000000000042c6e7 in processCommand (c=0x7f5da6dd9e00) at server.c:2510

#6  0x000000000043b745 in processInputBuffer (c=0x7f5da6dd9e00) at networking.c:1354

#7  0x00000000004267f0 in aeProcessEvents (eventLoop=eventLoop@entry=0x7f5da723a050, flags=flags@entry=11) at ae.c:440

#8  0x0000000000426adb in aeMain (eventLoop=0x7f5da723a050) at ae.c:498

#9  0x00000000004238ef in main (argc=, argv=0x7ffc0451ab58) at server.c:3894

(gdb) f 3

#3  0x00000000004414c2 in randomkeyCommand (c=0x7f5da6dd9e00) at db.c:498

498     in db.c

(gdb) p *c

$9 = {id = 144, fd = 78, db = 0x7f5da72d5000, name = 0x0, querybuf = 0x7f5da70ae285 "", pending_querybuf = 0x7f5da7216743 "", querybuf_peak = 0, argc = 1, argv = 0x7f5da72167f0, 

  cmd = 0x741820 , lastcmd = 0x741820 , reqtype = 2, multibulklen = 0, bulklen = -1, reply = 0x7f5da6d20ea0, reply_bytes = 0, 

  sentlen = 0, ctime = 1542039740, lastinteraction = 1542039740, obuf_soft_limit_reached_time = 0, flags = 0, authenticated = 0, replstate = 0, repl_put_online_on_ack = 0, 

  repldbfd = -1496183376, repldboff = 0, repldbsize = 0, replpreamble = 0x5bdb29d9 , read_reploff = 0, reploff = 0, repl_ack_off = 0, 

  repl_ack_time = 0, psync_initial_offset = 1090943882, 

  replid = "\000\000\000\000]\177\000\000\000\000\000\000\000\000\000\000\216\000\000\000\000\000\000\000\377\377\377\377\000\000\000\000\000P-\247]\177\000\000", 

  slave_listening_port = 0, slave_ip = "\000\000\000\000\000\000\000\000\243k!\247]\177", '\000' , "]\177\000\000@g!\247]\177\000\000\000\000\000\000\000", 

  slave_capa = 0, mstate = {commands = 0x0, count = 0, minreplicas = -1, minreplicas_timeout = 140040207470240}, btype = 0, bpop = {timeout = 0, keys = 0x7f5da72b2aa0, target = 0x0, 

    numreplicas = 0, reploffset = 0, module_blocked_handle = 0x0}, woff = 0, watched_keys = 0x7f5da6d20e70, pubsub_channels = 0x7f5da72b2b00, pubsub_patterns = 0x7f5da6d20ed0, 

  peerid = 0x0, bufpos = 0, 

  buf = '\000' , "\023.Kp\000\000\000\000\240\016\322\246]\177\000\000\000++\247]\177\000\000\320\016\322\246]\177", '\000' , "$-1\r\n", '\000' , "\240*+\247]\177", '\000' , "\242;\223<\000\000\000\000\000\000\000\000]\177\000\000\000\000\000\000\000\000\000\000\240*+\247]\177", '\000' , "$-1\r", '\000' ...}

(gdb) p *c->cmd

$10 = {name = 0x4f3026 "randomkey", proc = 0x4414b0 , arity = 1, sflags = 0x4f2e87 "rR", flags = 130, getkeys_proc = 0x0, firstkey = 0, lastkey = 0, keystep = 0, 

  microseconds = 139, calls = 67}

 

从两次不同时间点的数据看,c的地址未发生变化,是同一对象。对照相应版本的源代码,找有循环的地方缩小范围,确定死循环发生的具体函数。

/* Return a random key, in form of a Redis object.

 * If there are no keys, NULL is returned.

 *

 * The function makes sure to return keys not already expired. */

robj *dbRandomKey(redisDb *db) { // db.c:225

    dictEntry *de;

 

    while(1) {

        sds key;

        robj *keyobj;

 

        de = dictGetRandomKey(db->dict); // db.c:232

        if (de == NULL) return NULL;

 

        key = dictGetKey(de);

        keyobj = createStringObject(key,sdslen(key));

        if (dictFind(db->expires,key)) {

            if (expireIfNeeded(db,keyobj)) {

                decrRefCount(keyobj);

                continue; /* search for another key. This expired. */

            }

        }

        return keyobj;

    }

}

 

void randomkeyCommand(client *c) { // db.c:495

    robj *key;

 

    if ((key = dbRandomKey(c->db)) == NULL) { // db.c:498

        addReply(c,shared.nullbulk);

        return;

    }

 

    // 在这里打一断点,如果没执行到这,

    // 即可确定函数dbRandomKey发生死循环

    addReplyBulk(c,key); // db.c:503

    decrRefCount(key);

}

 

/* Return a random entry from the hash table. Useful to

 * implement randomized algorithms */

dictEntry *dictGetRandomKey(dict *d) // dict.c:610

{

    dictEntry *he, *orighe;

    unsigned long h;

    int listlen, listele;

 

    if (dictSize(d) == 0) return NULL;

    if (dictIsRehashing(d)) _dictRehashStep(d);

    if (dictIsRehashing(d)) {

        do {

            /* We are sure there are no elements in indexes from 0

             * to rehashidx-1 */

            h = d->rehashidx + (random() % (d->ht[0].size +

                                            d->ht[1].size -

                                            d->rehashidx));

            he = (h >= d->ht[0].size) ? d->ht[1].table[h - d->ht[0].size] :

                                      d->ht[0].table[h];

        } while(he == NULL);

    } else {

        do {

            h = random() & d->ht[0].sizemask; // dict.c:630

            he = d->ht[0].table[h];

        } while(he == NULL);

    }

 

    /* Now we found a non empty bucket, but it is a linked

     * list and we need to get a random element from the list.

     * The only sane way to do so is counting the elements and

     * select a random index. */

    listlen = 0;

    orighe = he;

    while(he) {

        he = he->next;

        listlen++;

    }

    listele = random() % listlen;

    he = orighe;

    while(listele--) he = he->next;

    return he;

}

 

经过GDB分析,死循环发生在函数dbRandomKey中,其中的“while(1)”退不出来。亦即走不到退出循环语句“if (de == NULL) return NULL;”。

 

估计是个BUG,查看新版本(5.0.4)的实现(dictSize4.0.95.0.4两个版本源文件中的位置不变):

#define dictSize(d) ((d)->ht[0].used+(d)->ht[1].used) // dict.h:147

 

/* Return a random key, in form of a Redis object.

 * If there are no keys, NULL is returned.

 *

 * The function makes sure to return keys not already expired. */

robj *dbRandomKey(redisDb *db) { // db.c:235

    dictEntry *de;

    int maxtries = 100; // 最多重试次数,可消除死循环,但是否起作用,还有两个前置条件

    int allvolatile = dictSize(db->dict) == dictSize(db->expires);

 

    while(1) {

        sds key;

        robj *keyobj;

 

        de = dictGetRandomKey(db->dict);

        if (de == NULL) return NULL;

 

        key = dictGetKey(de);

        keyobj = createStringObject(key,sdslen(key));

        if (dictFind(db->expires,key)) {

            if (allvolatile && server.masterhost && --maxtries == 0) {

                /* If the DB is composed only of keys with an expire set,

                 * it could happen that all the keys are already logically

                 * expired in the slave, so the function cannot stop because

                 * expireIfNeeded() is false, nor it can stop because

                 * dictGetRandomKey() returns NULL (there are keys to return).

                 * To prevent the infinite loop we do some tries, but if there

                 * are the conditions for an infinite loop, eventually we

                 * return a key name that may be already expired. */

                return keyobj;

            }

            if (expireIfNeeded(db,keyobj)) {

                decrRefCount(keyobj);

                continue; /* search for another key. This expired. */

            }

        }

        return keyobj;

    }

}

 

确定4.0.9版本的“if (allvolatile && server.masterhost && --maxtries == 0) {”是否成立:

(gdb) p db->dict->ht[0].used

$11 = 1

(gdb) p db->dict->ht[1].used 

$12 = 0

(gdb) p server.masterhost

$13 = 0x7f5da7221f41 "10.11.34.35"

 

显然是可以进入if语句退出循环的,因此可以确定这是一个BUG,并且5.0.4版本已经修复了该问题,往前查4.0.11版本的实现已和5.0.4版本相同,也许更早的版本就已经修复了该问题。

通过查看RELEASENOTES,确定这个BUG是在4.0.11中修复的:

antirez in commit ab145a9f:

 Fix infinite loop in dbRandomKey().

 1 file changed, 13 insertions(+)

 

 

阅读(100595) | 评论(0) | 转发(0) |
给主人留下些什么吧!~~
评论热议
请登录后评论。

登录 注册