struct latencySample {
    int32_t time;  // Sampling time of the event
    uint32_t latency;  // Execution duration of the event (in milliseconds)
};

struct latencyTimeSeries {
    int idx;  // Writing position of the sampling event array
    uint32_t max;  // Maximum latency of the current event
    struct latencySample samples[LATENCY_TS_LEN];  // Array of sampling events, recording LATENCY_TS_LEN sampling results. LATENCY_TS_LEN defaults to 160.
};

struct redisServer {
   …
   dict *latency_events;
   …
}

void initServer(void) {
    …
    latencyMonitorInit();
}

void latencyMonitorInit(void) {
    server.latency_events = dictCreate(&latencyTimeSeriesDictType, NULL);
}

void latencyAddSample(char *event, mstime_t latency)

// Search for the hash entry for the event
struct latencyTimeSeries *ts = dictFetchValue(server.latency_events, event);
…
if (ts == NULL) {  // If the hash entry is empty, create a new one
    ts = zmalloc(sizeof(*ts));
    ts->idx = 0;
    ts->max = 0;
    memset(ts->samples, 0, sizeof(ts->samples));
    dictAdd(server.latency_events, zstrdup(event), ts);  // Insert the hash entry into the hash table
}

if (latency > ts->max) ts->max = latency;

// Get the previous sampling result of the same event type
prev = (ts->idx + LATENCY_TS_LEN - 1) % LATENCY_TS_LEN;
if (ts->samples[prev].time == now) {  // If the current and previous sampling results are obtained in the same second
    if (latency > ts->samples[prev].latency)  // If the execution duration of the current sampling result is greater than that of the previous sampling result

void latencyAddSample(char *event, mstime_t latency) {
    // Search for the hash entry for the event
    struct latencyTimeSeries *ts = dictFetchValue(server.latency_events, event);
    …
    if (ts == NULL) {  // If the hash entry is empty, create a new one
        ts = zmalloc(sizeof(*ts));
        ts->idx = 0;
        ts->max = 0;
        memset(ts->samples, 0, sizeof(ts->samples));
        dictAdd(server.latency_events, zstrdup(event), ts);  // Insert the hash entry into the hash table
    }

    if (latency > ts->max) ts->max = latency;

    // Get the previous sampling result of the same event type
    prev = (ts->idx + LATENCY_TS_LEN - 1) % LATENCY_TS_LEN;
    if (ts->samples[prev].time == now) {  // If the current and previous sampling results are obtained in the same second
        if (latency > ts->samples[prev].latency)  // If the execution duration of the current sampling result is greater than that of the previous sampling result
            ts->samples[prev].latency = latency;  // Update the execution duration in the previous sampling result
    } else {
        // Insert a new sampling result
        ts->samples[ts->idx].time = now;
        ts->samples[ts->idx].latency = latency;
        ts->idx = (ts->idx + 1) % LATENCY_TS_LEN;
    }
}

ts->samples[prev].latency = latency; // Directly update the execution duration of the previous sample result
return;
}
// Otherwise, insert the current sample result
ts->samples[ts->idx].time = time(NULL);
ts->samples[ts->idx].latency = latency;


Here, you should also note that the latencyAddSample function reuses the latencyTimeSeries array when recording sample results. Therefore, if the number of sample results exceeds the default size of the array, the old sample results will be overwritten. If you want to record more sample results, you need to increase the length of the latencyTimeSeries array.

So when is the latencyAddSample function called for sampling?

Actually, the latencyAddSample function is encapsulated in the latencyAddSampleIfNeeded function. In the latencyAddSampleIfNeeded function, it is only called to record sample results when the event execution duration exceeds the value of the latency-monitor-threshold configuration item. You can see the definition of the latencyAddSampleIfNeeded function below.


#define latencyAddSampleIfNeeded(event,var) \
    if (server.latency_monitor_threshold && \
        (var) >= server.latency_monitor_threshold) \
          latencyAddSample((event),(var));


The latencyAddSampleIfNeeded function is actually called when the latency event occurs. Here are two examples.

For example, when a Redis command is executed through the call function (in the server.c file), the call function calls the latencyAddSampleIfNeeded function to sample, as shown below.


if (flags & CMD_CALL_SLOWLOG && c->cmd->proc != execCommand) {
        // Depending on the CMD_FAST flag in the command data structure, determine whether the current event is a fast-command event or a command event
        char *latency_event = (c->cmd->flags & CMD_FAST) ?
                              "fast-command" : "command";
        latencyAddSampleIfNeeded(latency_event,duration/1000);
        …
}


Another example is when Redis calls the flushAppendOnlyFile function to write to the AOF file, if the configuration item for AOF file synchronization is AOF_FSYNC_ALWAYS, the flushAppendOnlyFile function will call the latencyAddSampleIfNeeded function to record the sampling result of the aof-fsync-always latency event, as shown below.


void flushAppendOnlyFile(int force) {
…
if (server.aof_fsync == AOF_FSYNC_ALWAYS) {
latencyStartMonitor(latency); // Call the latencyStartMonitor function to start the timer
redis_fsync(server.aof_fd); // Actually write data to disk
        latencyEndMonitor(latency); // Call the latencyEndMonitor to end the timer and calculate the duration
        latencyAddSampleIfNeeded("aof-fsync-always",latency);
…}
}


In this case, what you need to note is that when Redis source code calls the latencyAddSampleIfNeeded function to record sample results, it often calls the latencyStartMonitor function to start the timer before the latency event occurs, and calls the latencyEndMonitor function to end the timer and calculate the event execution duration after the event execution is completed.

In addition, you can also use tools for reading Redis source code, such as Sublime and Source Insight, to find other places where the latencyAddSampleIfNeeded function is called by searching for function relationships.

Okay, so far the Redis latency monitoring framework can record sampling results of latency events through the latencyAddSampleIfNeeded function. In fact, the Redis latency monitoring framework also implements latency analysis and provides suggestions for dealing with slow latency. Let's take a look.

### Latency Analysis and Suggestions

First, Redis provides a latency doctor command to give a latency analysis report and suggestions for dealing with latency. When we execute this command, Redis uses the latencyCommand function to process it. In the process of handling this command, the latencyCommand function calls the createLatencyReport function to generate a latency analysis report and suggestions.

Specifically, the createLatencyReport function first calls the analyzeLatencyForEvent function to calculate the mean, maximum, and minimum durations of the sampled latency event execution. You can read the source code of the analyzeLatencyForEvent function to understand the specific statistical calculation process.

Then, the createLatencyReport function provides suggestions based on this type of event, combined with Redis configuration and other knowledge.

In fact, in the createLatencyReport function, it defines several int variables. When the values of these variables are 1, it means that it is recommended for Redis users to adopt a measure to deal with high latency. I have shown some variables corresponding to countermeasures in the code below. You can have a look. In addition, you can also read the source code of the createLatencyReport function to understand all the countermeasures.


sds createLatencyReport(void) {
…
int advise_slowlog_enabled = 0;  // Suggest enabling slowlog
int advise_slowlog_tuning = 0;   // Suggest adjusting slowlog threshold
int advise_slowlog_inspect = 0;  // Suggest checking slowlog results
int advise_disk_contention = 0;  // Suggest reducing disk contention
…
}


Let's take a simple example. For the command event, the createLatencyReport function will give suggestions such as enabling slowlog, adjusting slowlog threshold, checking slowlog log results, and avoiding the use of bigkey based on the slowlog settings. The code for this part is as follows:


if (!strcasecmp(event,"command")) {
   // Suggest enabling slowlog if it is not enabled
   if (server.slowlog_log_slower_than < 0) {
       advise_slowlog_enabled = 1;
       advices++;
  }  // Suggest adjusting the slowlog threshold if the command duration threshold used by slowlog is too large
  else if (server.slowlog_log_slower_than/1000 >
            server.latency_monitor_threshold)
            {
                advise_slowlog_tuning = 1;
                advices++;
            }
            advise_slowlog_inspect = 1;  // Suggest checking the slowlog log results
            advise_large_objects = 1;  // Suggest avoiding the use of bigkey
            advices += 2;
        }
}


Therefore, it is great that the createLatencyReport function provides targeted suggestions while calculating latency statistics. This is also a suggestion from the perspective of Redis developers and is more targeted.

Okay, so far we have learned about the implementation of the latency monitoring framework. Next, let's learn about the implementation of slow command logging in Redis.
## Implementation of Slow Command Log

Redis uses a simple method to record slow command logs, which is by using a list to store the commands that exceed the slow command log execution time threshold.

In the data structure `redisServer` of the global variable `server` in Redis, there is a member variable of list type called `slowlog`, which is used to store the slow command log list, as shown below:

```c
struct redisServer {
…
list *slowlog;
…}

void slowlogPushEntryIfNeeded(client *c, robj **argv, int argc, long long duration)

// Check if the duration of the current command execution exceeds the configured threshold
if (duration >= server.slowlog_log_slower_than)
   listAddNodeHead(server.slowlog, slowlogCreateEntry(c,argv,argc,duration));

// If the log list exceeds the threshold length, delete the log entry at the end of the list
while (listLength(server.slowlog) > server.slowlog_max_len)
    listDelNode(server.slowlog,listLast(server.slowlog));

typedef struct slowlogEntry {
    robj **argv;     // Command and arguments of the log entry
    int argc;        // Number of command and arguments for the log entry
    long long id;       // Unique ID of the log entry
    long long duration;  // Execution duration of the command for this log entry (in microseconds)
    time_t time;        // Execution timestamp of the command for this log entry
    sds cname;          // Name of the client that sent the command for this log entry
    sds peerid;         // Network address of the client that sent the command for this log entry
} slowlogEntry;

slowlogEntry *slowlogCreateEntry(client *c, robj **argv, int argc, long long duration) {
    slowlogEntry *se = zmalloc(sizeof(*se)); // Allocate space for the log entry
    int j, slargc = argc;  // Number of parameters to be recorded, default is the number of parameters for the current command
     
    // If the number of parameters for the current command exceeds the threshold, only record the threshold number of parameters
    if (slargc > SLOWLOG_ENTRY_MAX_ARGC) slargc = SLOWLOG_ENTRY_MAX_ARGC;
    se->argc = slargc;
    ...
    for (j = 0; j < slargc; j++) {  // Record the command and parameters one by one
       if (slargc != argc && j == slargc-1) {  // If the number of command parameters exceeds the threshold, use the last parameter to record the actual number of remaining parameters
          se->argv[j] = createObject(OBJ_STRING,
                    sdscatprintf(sdsempty(),"... (%d more arguments)",
                    argc-slargc+1));
        } else {
            ...  // Fill the command parameters in the log entry
        }
    }
    ... // Fill in information such as command execution duration and client address in the log entry
}

void call(client *c, int flags) {
...
start = server.ustime; // Start timing before command execution
c->cmd->proc(c);  // Actual command execution
duration = ustime()-start; // Calculate the execution time of the command
...
if (flags & CMD_CALL_SLOWLOG && c->cmd->proc != execCommand) {
    ...
    // Call the slowlogPushEntryIfNeeded function to record slow command
    slowlogPushEntryIfNeeded(c,c->argv,c->argc,duration);
}
...}