redis 性能问题查找

ddsdjn

　　使用redis出现性能问题，可以使用redis的slowlog命令 来查看哪些命令阻塞了redis。
　　使用redis作为数据库时，系统出现少量超时，通过日志信息发现，超时发生在bgsave时。bgsave命令会fork一个子进程，子进程会将redis数据库信息dump到rdb文件中。因此不能确定使用bgsave命令时，是fork一个子进程引起超时，还是dump文件时与主进程的sync同步同时写磁盘引起的超时。
　　这时就可以使用redis自带的slowlog命令了，但是需要在redis 配置文件中加入slowlog使用的参数。

################################## SLOW LOG ###################################
# The Redis Slow Log is a system to log queries that exceeded a specified
# execution time. The execution time does not include the I/O operations
# like talking with the client, sending the reply and so forth,
# but just the time needed to actually execute the command (this is the only
# stage of command execution where the thread is blocked and can not serve
# other requests in the meantime).
#
# You can configure the slow log with two parameters: one tells Redis
# what is the execution time, in microseconds, to exceed in order for the
# command to get logged, and the other parameter is the length of the
# slow log. When a new command is logged the oldest one is removed from the
# queue of logged commands.
# The following time is expressed in microseconds, so 1000000 is equivalent
# to one second. Note that a negative number disables the slow log, while
# a value of zero forces the logging of every command.
#如果一个命令执行操作10ms，需要记录下这个命令和执行时间
slowlog-log-slower-than 10000
# There is no limit to this length. Just be aware that it will consume memory.
# You can reclaim memory used by the slow log with SLOWLOG RESET.
#保留最近的1024个超时的命令
slowlog-max-len 1024
　　下面开始使用slowlog查看超时的命令有哪些，先使用redis-cli连接服务器，在使用slowlog命令查看超时的命令有哪些。

redis 127.0.0.1:7771> SLOWLOG GET 3
1) 1) (integer) 174            //编号
2) (integer) 1413914462     //发生日期，UnixTime类型，需要使用工具转换成日期
3) (integer) 724446         //命令次持续时间，单位是微妙
4) 1) "bgSave"              //执行的命令和参数
2) 1) (integer) 173
2) (integer) 1413828062
3) (integer) 740908
4) 1) "bgSave"
3) 1) (integer) 172
2) (integer) 1413741662
3) (integer) 737333
4) 1) "bgSave"
　　问题发现了，bgsave命令执行时间用了700多ms，原来是fork时使用了太长时间，从而阻塞了主进程。
　　-------------------------------------------------showlog命令实现细节------------------------------------------------------
　　执行时间的记录。所有redis命令都会调用call函数来执行，而call函数就在执行前后记录下时间，并放在slowlog时间队列中，队列的最大长度就是配置文件定义的长度。

/* Call() is the core of Redis execution of a command */
void call(redisClient *c, int flags) {
long long dirty, start, duration;
int client_old_flags = c->flags;
。。。
/* Call the command. */
c->flags &= ~(REDIS_FORCE_AOF|REDIS_FORCE_REPL);
redisOpArrayInit(&server.also_propagate);
dirty = server.dirty;
start = ustime();   //记录命令执行开始时间
c->cmd->proc(c);    //执行命令
duration = ustime()-start;   //记录命令执行时间
dirty = server.dirty-dirty;
/* When EVAL is called loading the AOF we don't want commands called
* from Lua to go into the slowlog or to populate statistics. */
if (server.loading && c->flags & REDIS_LUA_CLIENT)
flags &= ~(REDIS_CALL_SLOWLOG | REDIS_CALL_STATS);
/* If the caller is Lua, we want to force the EVAL caller to propagate
* the script if the command flag or client flag are forcing the
* propagation. */
if (c->flags & REDIS_LUA_CLIENT && server.lua_caller) {
if (c->flags & REDIS_FORCE_REPL)
server.lua_caller->flags |= REDIS_FORCE_REPL;
if (c->flags & REDIS_FORCE_AOF)
server.lua_caller->flags |= REDIS_FORCE_AOF;
}
/* Log the command into the Slow log if needed, and populate the
* per-command statistics that we show in INFO commandstats. */
if (flags & REDIS_CALL_SLOWLOG && c->cmd->proc != execCommand)
slowlogPushEntryIfNeeded(c->argv,c->argc,duration);   //保存命令执行时间
。。。
}

　　执行时间的查看。slowlogCommand 函数对应slowlog命令。
　　

/* The SLOWLOG command. Implements all the subcommands needed to handle the
* Redis slow log. */
void slowlogCommand(redisClient *c) {
if (c->argc == 2 && !strcasecmp(c->argv[1]->ptr,"reset")) {
slowlogReset();
addReply(c,shared.ok);
} else if (c->argc == 2 && !strcasecmp(c->argv[1]->ptr,"len")) {
addReplyLongLong(c,listLength(server.slowlog));
} else if ((c->argc == 2 || c->argc == 3) &&
!strcasecmp(c->argv[1]->ptr,"get"))
{
long count = 10, sent = 0;
listIter li;
void *totentries;
listNode *ln;
slowlogEntry *se;
if (c->argc == 3 &&
getLongFromObjectOrReply(c,c->argv[2],&count,NULL) != REDIS_OK)
return;
listRewind(server.slowlog,&li);
totentries = addDeferredMultiBulkLength(c);
//打印count数量的超时命令
while(count-- && (ln = listNext(&li))) {
int j;
se = ln->value;
addReplyMultiBulkLen(c,4);
addReplyLongLong(c,se->id);
addReplyLongLong(c,se->time);
addReplyLongLong(c,se->duration);
addReplyMultiBulkLen(c,se->argc);
for (j = 0; j < se->argc; j++)
addReplyBulk(c,se->argv[j]);
sent++;
}
setDeferredMultiBulkLength(c,totentries,sent);
} else {
addReplyError(c,
"Unknown SLOWLOG subcommand or wrong # of args. Try GET, RESET, LEN.");
}
}