Redis use case

This use case considers the diagnosis of an issue identified in the Redis in-memory data store (see pull request #10531).
The instructions to reproduce the use case are available at how to reproduce, while an extendend set of visualizations provided by DIO are available at portfolio.

Problem

The server log file is repeatedly opened and closed for every written line, which adds extra latency for log operations and can potentially slowdown Redis performance.

Diagnosis

Using DIO to observe I/O access patterns for the log file, we can see the same set of system calls being done repeatedly, with a sequential access pattern (i.e., the offset increases for each set of operations). Further analysing this pattern, we can see the exact order of requests for one of these sets: openat→lseek→fstat→write→close.

Figure 1. Log file access pattern, depicting system calls issued over time per minute (V1)

Figure 2. Sample of first 350 microseconds within a millisecong of the log file access pattern(V1)

Solution

As suggested in the Pull Request for the issue, this inefficient I/O pattern can be fixed by:

• keeping the log's file descriptor opened while the file is being used, and
• using writev to write log lines more efficiently.

Validation

Using DIO, we are also able to validate the proposed solution by observing the new access pattern for the log file. With the suggested fix, redundant open and close operations are avoided, along with the need for using lseek before every write operation. Also, writev is now used to write log lines, instead of write.

Figure 1. Log file access pattern, depicting system calls issued over time per minute (V2)

Figure 2. Sample of first 350 microseconds within a millisecong of the log file access pattern(V2)