干货 | 记一个真实的排障案例：携程Redis偶发连接失败案例分析

Thu May 31 11:29:18 CST 2018
Thread 1 (Thread 0x7ff2db6de720 (LWP 8378)):
#0  0x000000000048cec4 in ?? ()
#1  0x00000000004914a4 in je_arena_ralloc ()
#2  0x00000000004836a1 in je_realloc ()
#3  0x0000000000422cc5 in zrealloc ()
#4  0x00000000004213d7 in sdsRemoveFreeSpace ()
#5  0x000000000041ef3c inclientsCronResizeQueryBuffer () 
#6  0x00000000004205de in clientsCron ()

#7  0x0000000000420784 in serverCron ()
#8  0x0000000000418542 in aeProcessEvents ()
#9  0x000000000041873b in aeMain ()
#100x0000000000420fce in main ()
Thu May 31 11:29:19 CST 2018
Thread 1 (Thread 0x7ff2db6de720 (LWP8378)):
#0  0x0000003729ee5407 in madvise () from/lib64/libc.so.6
#1  0x0000000000493a4e in je_pages_purge ()
#2  0x000000000048cf70 in ?? ()
#3  0x00000000004914a4 in je_arena_ralloc ()
#4  0x00000000004836a1 in je_realloc ()
#5  0x0000000000422cc5 in zrealloc ()
#6  0x00000000004213d7 in sdsRemoveFreeSpace ()
#7  0x000000000041ef3c inclientsCronResizeQueryBuffer ()
#8  0x00000000004205de in clientsCron ()

#9  0x0000000000420784 in serverCron ()
#100x0000000000418542 in aeProcessEvents ()
#110x000000000041873b in aeMain ()
#12 0x0000000000420fcein main ()
Thu May 31 11:29:19 CST 2018
Thread 1 (Thread 0x7ff2db6de720 (LWP8378)):
#0  0x000000000048108c in je_malloc_usable_size()
#1  0x0000000000422be6 in zmalloc ()
#2  0x00000000004220bc in sdsnewlen ()
#3  0x000000000042c409 in createStringObject ()
#4  0x000000000042918e in processMultibulkBuffer()
#5  0x0000000000429662 in processInputBuffer ()
#6  0x0000000000429762 in readQueryFromClient ()
#7  0x000000000041847c in aeProcessEvents ()
#8  0x000000000041873b in aeMain ()
#9  0x0000000000420fce in main ()
Thu May 31 11:29:20 CST 2018
Thread 1 (Thread 0x7ff2db6de720 (LWP8378)):
#0  0x000000372a60e7cd in write () from/lib64/libpthread.so.0
#1  0x0000000000428833 in sendReplyToClient ()
#2  0x0000000000418435 in aeProcessEvents ()
#3  0x000000000041873b in aeMain ()
#4  0x0000000000420fce in main ()

clientsCron(server.h):
#define CLIENTS_CRON_MIN_ITERATIONS 5
voidclientsCron(void){
 /*Makesuretoprocessatleastnumclients/server.hzofclients
 *percall.Sincethisfunctioniscalledserver.hztimespersecond
 *wearesurethatintheworstcaseweprocessalltheclientsin1
 *second.*/
 intnumclients=listLength(server.clients);
 intiterations=numclients/server.hz;
 mstime_tnow=mstime();
 /*Processatleastafewclientswhileweareatit,evenifweneed
 *toprocesslessthanCLIENTS_CRON_MIN_ITERATIONStomeetourcontract
 *ofprocessingeachclientoncepersecond.*/
 if(iterations<CLIENTS_CRON_MIN_ITERATIONS)
 iterations=(numclients<CLIENTS_CRON_MIN_ITERATIONS)?
 numclients:CLIENTS_CRON_MIN_ITERATIONS;
 while(listLength(server.clients)&&iterations--){
 client*c;
 listNode*head;
 /*Rotatethelist,takethecurrenthead,process.
 *Thiswayiftheclientmustberemovedfromthelistit'sthe
 *firstelementandwedon'tincurintoO(N)computation.*/
 listRotate(server.clients);
 head=listFirst(server.clients);
 c=listNodeValue(head);
 /*Thefollowingfunctionsdodifferentservicechecksontheclient.
 *Theprotocolisthattheyreturnnon-zeroiftheclientwas
 *terminated.*/
 if(clientsCronHandleTimeout(c,now))continue;
 if(clientsCronResizeQueryBuffer(c))continue;
 }
}

clientsCronResizeQueryBuffer(server.h):
/*Theclientquerybufferisansds.cstringthatcanendwithalotof
 *freespacenotused,thisfunctionreclaimsspaceifneeded.
 *
 *Thefunctionalwaysreturns0asitneverterminatestheclient.*/
intclientsCronResizeQueryBuffer(client*c){
 size_tquerybuf_size=sdsAllocSize(c->querybuf);
 time_tidletime=server.unixtime-c->lastinteraction;
 /*只在以下两种情况下会Resize querybuffer:
 *1)Querybuffer>BIG_ARG(在server.h 中定义#definePROTO_MBULK_BIG_ARG     (1024*32))且这个Buffer的小于一段时间的客户端使用的峰值.
 *2)客户端空闲超过2s且Buffer size大于1k.*/
 if(((querybuf_size>PROTO_MBULK_BIG_ARG)&&
 (querybuf_size/(c->querybuf_peak+1))>2)||
 (querybuf_size>1024&&idletime>2))
 {
 /*Onlyresizethequerybufferifitisactuallywastingspace.*/
 if(sdsavail(c->querybuf)>1024){
 c->querybuf=sdsRemoveFreeSpace(c->querybuf);
 }
 }
 /*Resetthepeakagaintocapturethepeakmemoryusageinthenext
 *cycle.*/
 c->querybuf_peak=0;
 return0;
}

readQueryFromClient（networking.c）:
redisClient*createClient(intfd){
 redisClient*c=zmalloc(sizeof(redisClient));
 /*passing-1asfditispossibletocreateanonconnectedclient.
 *ThisisusefulsincealltheRediscommandsneedstobeexecuted
 *inthecontextofaclient.Whencommandsareexecutedinother
 *contexts(forinstanceaLuascript)weneedanonconnectedclient.*/
 if(fd!=-1){
 anetNonBlock(NULL,fd);
 anetEnableTcpNoDelay(NULL,fd);
 if(server.tcpkeepalive)
 anetKeepAlive(NULL,fd,server.tcpkeepalive);
 if(aeCreateFileEvent(server.el,fd,AE_READABLE,
 readQueryFromClient,c)==AE_ERR)
 {
 close(fd);
 zfree(c);
 returnNULL;
 }
 }
 selectDb(c,0);
 c->id=server.next_client_id++;
 c->fd=fd;
 c->name=NULL;
 c->bufpos=0;
c->querybuf=sdsempty();初始化是0
readQueryFromClient(networking.c):
voidreadQueryFromClient(aeEventLoop*el,intfd,void*privdata,intmask){
 redisClient*c=(redisClient*)privdata;
 intnread,readlen;
 size_tqblen;
 REDIS_NOTUSED(el);
 REDIS_NOTUSED(mask);
 server.current_client=c;
 readlen=REDIS_IOBUF_LEN;
 /*Ifthisisamultibulkrequest,andweareprocessingabulkreply
 *thatislargeenough,trytomaximizetheprobabilitythatthequery
 *buffercontainsexactlytheSDSstringrepresentingtheobject,even
 *attheriskofrequiringmoreread(2)calls.Thiswaythefunction
 *processMultiBulkBuffer()canavoidcopyingbufferstocreatethe
 *RedisObjectrepresentingtheargument.*/
 if(c->reqtype==REDIS_REQ_MULTIBULK&&c->multibulklen&&c->bulklen!=-1
 &&c->bulklen>=REDIS_MBULK_BIG_ARG)
 {
 intremaining=(unsigned)(c->bulklen+2)-sdslen(c->querybuf);
 if(remaining<readlen)readlen=remaining;
 }
 qblen=sdslen(c->querybuf);
 if(c->querybuf_peak<qblen)c->querybuf_peak=qblen;
 c->querybuf=sdsMakeRoomFor(c->querybuf,readlen);

if (((querybuf_size >REDIS_MBULK_BIG_ARG) &&
        (querybuf_size/(c->querybuf_peak+1)) > 2) ||
 (querybuf_size >1024*32 && idletime > 2))
    {
       /* Only resize the query buffer if it is actually wasting space. */
       if (sdsavail(c->querybuf) > 1024*32) {
           c->querybuf = sdsRemoveFreeSpace(c->querybuf);
       }
    }

Thu Jun 14 21:56:54 CST 2018
#3 0x0000003729ee893d in clone () from /lib64/libc.so.6
Thread 1 (Thread 0x7f2dc108d720 (LWP27851)):
#0 0x0000003729ee5400 in madvise () from /lib64/libc.so.6
#1 0x0000000000493a1e in je_pages_purge ()
#2  0x000000000048cf40 in arena_purge ()
#3 0x00000000004a7dad in je_tcache_bin_flush_large ()
#4 0x00000000004a85e9 in je_tcache_event_hard ()
#5 0x000000000042c0b5 in decrRefCount ()
#6 0x000000000042744d in resetClient ()
#7  0x000000000042963bin processInputBuffer ()
#8 0x0000000000429762 in readQueryFromClient ()
#9 0x000000000041847c in aeProcessEvents ()
#10 0x000000000041873b in aeMain ()
#11 0x0000000000420fce in main ()
Thu Jun 14 21:56:54 CST 2018
Thread 1 (Thread 0x7f2dc108d720 (LWP27851)):
#0 0x0000003729ee5400 in madvise () from /lib64/libc.so.6
#1 0x0000000000493a1e in je_pages_purge ()
#2  0x000000000048cf40 in arena_purge ()
#3 0x00000000004a7dad in je_tcache_bin_flush_large ()
#4 0x00000000004a85e9 in je_tcache_event_hard ()
#5 0x000000000042c0b5 in decrRefCount ()
#6 0x000000000042744d in resetClient ()
#7 0x000000000042963b in processInputBuffer ()
#8 0x0000000000429762 in readQueryFromClient ()
#9 0x000000000041847c in aeProcessEvents ()
#10 0x000000000041873b in aeMain ()
#11 0x0000000000420fce in main ()

arena_purge(arena.c)
staticvoid
arena_purge(arena_t*arena,boolall)
{
 arena_chunk_t*chunk;
 size_tnpurgatory;
 if(config_debug){
 size_tndirty=0;
 arena_chunk_dirty_iter(&arena->chunks_dirty,NULL,
 chunks_dirty_iter_cb,(void*)&ndirty);
 assert(ndirty==arena->ndirty);
 }
 assert(arena->ndirty>arena->npurgatory||all);
 assert((arena->nactive>>opt_lg_dirty_mult)<(arena->ndirty-
 arena->npurgatory)||all);
 if(config_stats)
 arena->stats.npurge++;
 npurgatory=arena_compute_npurgatory(arena,all);
 arena->npurgatory+=npurgatory;
 while(npurgatory>0){
 size_tnpurgeable,npurged,nunpurged;
 /*Getnextchunkwithdirtypages.*/
 chunk=arena_chunk_dirty_first(&arena->chunks_dirty);
 if(chunk==NULL){
 arena->npurgatory-=npurgatory;
 return;
 }
 npurgeable=chunk->ndirty;
 assert(npurgeable!=0);
 if(npurgeable>npurgatory&&chunk->nruns_adjac==0){
 arena->npurgatory+=npurgeable-npurgatory;
 npurgatory=npurgeable;
 }
 arena->npurgatory-=npurgeable;
 npurgatory-=npurgeable;
 npurged=arena_chunk_purge(arena,chunk,all);
 nunpurged=npurgeable-npurged;
 arena->npurgatory+=nunpurged;
 npurgatory+=nunpurged;
 }
}

arena_purge(arena.c)
staticvoid
arena_purge(arena_t*arena,boolall)
{
 chunk_hooks_tchunk_hooks=chunk_hooks_get(arena);
 size_tnpurge,npurgeable,npurged;
 arena_runs_dirty_link_tpurge_runs_sentinel;
 extent_node_tpurge_chunks_sentinel;
 arena->purging=true;
 /*
 *Callstoarena_dirty_count()aredisabledevenfordebugbuilds
 *becauseoverheadgrowsnonlinearlyasmemoryusageincreases.
 */
 if(false&&config_debug){
 size_tndirty=arena_dirty_count(arena);
 assert(ndirty==arena->ndirty);
 }
 assert((arena->nactive>>arena->lg_dirty_mult)<arena->ndirty||all);
 if(config_stats)
 arena->stats.npurge++;
 npurge=arena_compute_npurge(arena,all);
 qr_new(&purge_runs_sentinel,rd_link);
 extent_node_dirty_linkage_init(&purge_chunks_sentinel);
 npurgeable=arena_stash_dirty(arena,&chunk_hooks,all,npurge,
 &purge_runs_sentinel,&purge_chunks_sentinel);
 assert(npurgeable>=npurge);
 npurged=arena_purge_stashed(arena,&chunk_hooks,&purge_runs_sentinel,
 &purge_chunks_sentinel);
 assert(npurged==npurgeable);
 arena_unstash_purged(arena,&chunk_hooks,&purge_runs_sentinel,
 &purge_chunks_sentinel);
 arena->purging=false;
}