Server

Redis SLOWLOG subcommand

Redis Server Course	Redis Technical Support	Redis Enterprise Server

Redis SLOWLOG

Slowlog는 모든 명령의 수행시간이 설정 시간 이상이면 기록을 남깁니다. Latency Monitor와 함께 서버 성능을 분석 또는 문제(trouble) 발생시 추적할 수 있는 유용한 도구입니다.
수행시간은 서버에서 처리하는 시간만 포함합니다. 명령이 클라이언트에서 서버로 도착하는 시간, 결과를 클라이언트에 보내는 시간은 포함하지 않습니다. Slowlog 기록으로 인한 성능 저하를 최소화하기 위해서 파일에 기록하지 않고 메모리에만 합니다.

이 문서는 버전 4.0.4를 기준으로 만들었습니다.

활성화 방법

활성화하는 데는 redis.conf에 있는 두 가지 파라미터가 사용됩니다.
이는 서버 운영 중 config set 명령으로 설정 가능합니다. 서버 설치 후 디폴트 값으로 활성화됩니다.

slowlog-log-slower-than: 여기 설정한 시간(microseconds) 이상인 명령을 기록합니다. 단위는 마이크로초(microseconds)입니다. Default는 10000(10ms)입니다. 0(영)으로 설정하면 모든 명령을 기록합니다.
비활성화하려면 음수(마이너스)로 설정합니다.
slowlog-max-len: 여기 설정한 것만큼 보관합니다. Default는 128입니다. 제한은 없습니다. 꽉 차면 오래된 것부터 지우고 새것이 기록됩니다.

SLOWLOG Subcommand

Slowlog 명령에는 총 3개의 subcommand가 있다.

GET: 사용법 slowlog get
Slowlog에 기록된 시각(Linux timestamp), 수행시간, 명령, 클라이언트 정보를 조회해 볼 수 있다.
GETH: 사용법 slowlog geth
위 내용을 보기 쉬운 형태로 보여줍니다.
LOG: 사용법 slowlog log
Slowlog를 로그 파일에 기록합니다.
LEN: 사용법 slowlog len
몇 개가 기록되었는지 조회해 볼 수 있다.
RESET: 사용법 slowlog reset
Slowlog 기록을 삭제한다. 복구할 수 없다.

SLOWLOG GET [숫자]

Slowlog 기록을 보여준다. 숫자는 몇 개를 보여줄지 정한다. 숫자를 입력하지 않으면 디폴트 10개이다.
다음 네 항목을 보여준다.

ID: 증가하는 일련번호
실행시각(Linux timestamp)
수행시간(microseconds)
명령: value의 길이가 128바이트보다 크면 128바이트와 (more bytes)가 표시됩니다. Subcommand(option)는 32개까지만 표시됩니다.
client ip:port : 버전 4.0에서 추가
client name : 버전 4.0에서 추가, client name은 "client setname" 명령으로 지정할 수 있습니다.

실행 예

127.0.0.1:6020> slowlog get 3
1) 1) (integer) 1045
     2) (integer) 1512179163
     3) (integer) 5
     4) 1) "set"
         2) "key"
     3) "ABCDEFGHIJKLMNOPQRSTUVWXYZ1234567890ABCDEFGHIJKLMNOPQRSTUVWXYZ1234567890ABCDEFGHIJKLMNOPQRSTUVWXYZ1234567890ABCDEFGHIJKLMNOPQRST... (160 more bytes)"
     5) "127.0.0.1:49622"
     6) "redisGate-Octo"
2) 1) (integer) 1044
     2) (integer) 1512178766
     3) (integer) 27
     4) 1) "slowlog"
         2) "get"
         3) "5"
     5) "127.0.0.1:49622"
     6) "redisGate-Octo"
3) 1) (integer) 1043
     2) (integer) 1512178761
     3) (integer) 18
     4) 1) "set"
         2) "key"
         3) "value"
     5) "127.0.0.1:49622"
     6) "redisGate-Octo"

SLOWLOG GETH [숫자]

일시, 소요시간 등을 보기 쉽게 보여줍니다. H는 human의 약자입니다.
Slowlog가 명령 실행시간을 볼 수 있는 유일하고 유용한 방법임에도 불구하고 잘 사용되지 않는 것은 '실행 시각'이 숫자로만 나오고 다른 항목도 설명이 없어서 일것입니다. 파악하기 쉽도록 했으니 유용하게 사용하시기 바랍니다.

127.0.0.1:6000> slowlog geth
1) 1) "Id: 19"
     2) "Time: 2019-09-12 21:19:02"  <- 실행 시각
     3) "Duration(us): 15927"    <- 소요시간(microseconds)
     4) 1) "keys"
          2) "*"
     5) "Client-ip:port: 127.0.0.1:40920"
     6) "Client-name: redisGate"

이 기능은 Enterprise 버전에서 사용 가능합니다.

SLOWLOG LOG

Slowlog를 로그 파일에 기록합니다. 기록 후 Reset해서 메모리에 있던 내용을 지웁니다.
Slowlog의 문제점 중 하나는 메모리에 기록하기 때문에 기록 개수에 제한을 두고 있다는 것입니다. 디폴트로 128개입니다. 128개가 초과되면 기존 내용이 지워지고 다시 기록됩니다. 그래서 로그 파일에 기록할 수 있도록 했습니다.
Slowlog.log파일이 있으면 slowlog 파일에 기록되고 없으면 redis.log 파일에 기록됩니다.

Timestamp              Duration(us) Client-ip:port        Client-name  Command [options]
2019-09-12 21:19:02        15927 127.0.0.1:40920                    keys * 
2019-09-12 21:20:00          100 127.0.0.1:49334                    set key10092 value10092 
2019-09-12 21:20:01          102 127.0.0.1:49590                    set key10220 value10220 
2019-09-12 21:20:02          101 127.0.0.1:49948                    set key10399 value10399

이 기능은 Enterprise 버전에서 사용 가능합니다.

SLOWLOG LEN

Slowlog에 기록된 개수를 보여준다.
실행 예

127.0.0.1:6200> slowlog len
(integer) 33

SLOWLOG RESET

기록을 지운다.
실행 예

127.0.0.1:6200> slowlog reset
OK
127.0.0.1:6200> slowlog len
(integer) 1

Slowlog 명령 자체도 기록으로 남기기 때문에 slowlog len에서 1이 나온것이다.

SLOWLOG Internal Data Structure

Slowlog는 리스트(list) 자료구조에 저장된다.

SLOWLOG 소스코드

slowlog-log-slower-than와 slowlog-max-len의 default 값이 server.h에 정의되어 있다.

#define CONFIG_DEFAULT_SLOWLOG_LOG_SLOWER_THAN 10000
#define CONFIG_DEFAULT_SLOWLOG_MAX_LEN 128

server.c : 모든 명령을 실행하는 call()에서 마이크로초로 수행시간(duration)을 측정하고, 설정에 따라 Latency 나 Slowlog에 기록을 남긴다.
Call()에서 실행하지 않는 특별한 경우는 기록에 남지 않는다. 예를 들어, debug populate 명령은 dbAdd()를 직접 실행하기 때문에 Slowlog 기록되지 않는다.

void call(client *c, int flags) {
	... 중간 생략 ...
    start = ustime();
    c->cmd->proc(c);
    duration = ustime()-start;
	... 중간 생략 ...
    /* Log the command into the Slow log if needed, and populate the
     * per-command statistics that we show in INFO commandstats. */
    if (flags & CMD_CALL_SLOWLOG && c->cmd->proc != execCommand) {
        char *latency_event = (c->cmd->flags & CMD_FAST) ?
                              "fast-command" : "command";
        latencyAddSampleIfNeeded(latency_event,duration/1000);
        slowlogPushEntryIfNeeded(c->argv,c->argc,duration);
    }
	... 중간 생략 ...
}

slowlog.h : slowlogEntry struct

/* This structure defines an entry inside the slow log list */
typedef struct slowlogEntry {
    robj **argv;
    int argc;
    long long id;       /* Unique entry identifier. */
    long long duration; /* Time spent by the query, in nanoseconds. */
    time_t time;        /* Unix time at which the query was executed. */
} slowlogEntry;

slowlog.c: function 설명
slowlog functions relation

그림 1-1 Slowlog functions relation

각 function에 대한 간단한 설명입니다.

slowlogCommand: slowlog 명령을 수행한다.
slowlogReset: slowlog reset을 수행한다. slowlogCommand()에서 호출된다.
slowlogPushEntryIfNeeded: Slowlog를 기록하는 메인 function이다.
slowlogCreateEntry: slowlogEntry 구조체를 할당하고 기록한다. slowlogPushEntryIfNeeded()에서 호출된다.
slowlogInit: server.c의 initServer()에서 서버 시작 시 한번 호출되며, 리스트 구조체를 만들고 초기화한다.
slowlogFreeEntry: SlowlogEntry 메모리를 해제(free)한다. slowlogInit()에서 호출된다.

SLOWLOG 관련 참고 자료

redis.io에 있는 Slowlog
redislabs.com에 있는 Enhancing Redis Slow Log

명령문

SLOWLOG subcommand [argument]

이 명령은 version 2.2.12 부터 사용할 수 있다.

Clients for C

Hiredis

<< DEBUG	SLOWLOG	LATENCY >>

조회수 :

Email 답글이 올라오면 이메일로 알려드리겠습니다.