zoukankan      html  css  js  c++  java
  • REdis CPU百分百问题分析

     

    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=<optimized out>) 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=<optimized out>, 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 <redisCommandTable+7520>, lastcmd = 0x741820 <redisCommandTable+7520>, 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 <Address 0x5bdb29d9 out of bounds>, read_reploff = 0, reploff = 0, repl_ack_off = 0, 

      repl_ack_time = 0, psync_initial_offset = 1090943882, 

      replid = "00000000]17700000000000000000000216000000000000003773773773770000000000P-247]1770000", 

      slave_listening_port = 0, slave_ip = "0000000000000000243k!247]177", '00' <repeats 14 times>, "]1770000@g!247]17700000000000000", 

      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 = '00' <repeats 20 times>, "23.Kp0000000024016322246]177000000++247]177000032016322246]177", '00' <repeats 14 times>, "$-1 ", '00' <repeats 39 times>, "240*+247]177", '00' <repeats 34 times>, "242;223<0000000000000000]17700000000000000000000240*+247]177", '00' <repeats 14 times>, "$-1 ", '00' <repeats 16 times>...}

    (gdb) p *c->cmd

    $8 = {name = 0x4f3026 "randomkey", proc = 0x4414b0 <randomkeyCommand>, 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=<optimized out>, 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 <redisCommandTable+7520>, lastcmd = 0x741820 <redisCommandTable+7520>, 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 <Address 0x5bdb29d9 out of bounds>, read_reploff = 0, reploff = 0, repl_ack_off = 0, 

      repl_ack_time = 0, psync_initial_offset = 1090943882, 

      replid = "00000000]17700000000000000000000216000000000000003773773773770000000000P-247]1770000", 

      slave_listening_port = 0, slave_ip = "0000000000000000243k!247]177", '00' <repeats 14 times>, "]1770000@g!247]17700000000000000", 

      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 = '00' <repeats 20 times>, "23.Kp0000000024016322246]177000000++247]177000032016322246]177", '00' <repeats 14 times>, "$-1 ", '00' <repeats 39 times>, "240*+247]177", '00' <repeats 34 times>, "242;223<0000000000000000]17700000000000000000000240*+247]177", '00' <repeats 14 times>, "$-1 ", '00' <repeats 16 times>...}

    (gdb) p *c->cmd

    $10 = {name = 0x4f3026 "randomkey", proc = 0x4414b0 <randomkeyCommand>, 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(+)

     

     

  • 相关阅读:
    tar命令,vi编辑器
    Linux命令、权限
    Color Transfer between Images code实现
    利用Eclipse使用Java OpenCV(Using OpenCV Java with Eclipse)
    Matrix Factorization SVD 矩阵分解
    ZOJ Problem Set
    Machine Learning
    ZOJ Problem Set
    ZOJ Problem Set
    ZOJ Problem Set
  • 原文地址:https://www.cnblogs.com/aquester/p/10572517.html
Copyright © 2011-2022 走看看