Monitoring Redis Commands

 

In this post we will review a method of monitoring Redis commands usage, using a small GO based utility.

When you have a complex micro-services system that is heavily using a Redis cluster, you will need, sooner or later, to monitor the Redis usage. Each micro-service uses a subset of the many Redis APIs: GET, SET, HINCR, SMEMBER, and many more. You might find yourself lost.

Which keys are the cause for the top of the CPU stress on the Redis? 

Which commands are used to access each key?

Redis does not leave you empty handed, as it provides a great tool: The Redis MONITOR command.

Running the Redis MONITOR command prints out every command that is processed by the Redis server, for example:

1597239055.206779 [0 192.168.100.9:58908] "hexists" "book-0001-2020-08-12T13:30:54" "AddAccount"
1597239055.213690 [0 192.168.100.9:58908] "set" "author-0001" "1597239054"
1597239056.202888 [0 192.168.100.9:58908] "hexists" "book-0001-2020-08-12T13:30:55" "AddAccount"
1597239056.206297 [0 192.168.100.9:58908] "set" "customer-0001" "1597239055"
...

That's a good start, but the real value is only when you aggregate this output to create a summary report of the APIs and keys.

The common usage of Redis is to have a prefix for all types of the keys used for the same purpose, for example, if we keep books information in the Redis, we will probably use keys in the format of:

BOOK-<id>

So, let's groups all Redis APIs based on the prefix. First, let configure the keys prefixes:

var prefixes = []string{
   "store-",
   "book-",
   "customer-",
   "author-",
}

Next, we read the output from the Redis MONITOR command, and analyze it:

type Stats struct {
   access   int
   commands map[string]int
}

type Scanner struct {
   keys      map[string]Stats
   lines     int
   lastPrint time.Time
}


func main() {
   s := Scanner{
      keys:      make(map[string]Stats),
      lastPrint: time.Now(),
   }
   s.Scan()
}

func (s *Scanner) Scan() {
   reader := bufio.NewReader(os.Stdin)
   for {
      line, err := reader.ReadString('\n')
      if err != nil {
         if err == io.EOF {
            break
         }
         panic(err)
      }
      err = s.parseLine(line)
      if err != nil {
         panic(err)
      }
   }

   s.summary()
}

func (s *Scanner) parseLine(line string) error {
   if s.lines%10000 == 0 {
      fmt.Printf("%v commands processed\r\n", s.lines)
   }
   if time.Since(s.lastPrint) > time.Minute {
      s.lastPrint = time.Now()
      s.summary()
   }
   s.lines++
   if strings.HasPrefix(line, "OK") || strings.TrimSpace(line) == "" {
      return nil
   }
   r := regexp.MustCompile("\\S+ \\[.*] \"([a-z]*)\" ?\"?(.*)?\"?")
   located := r.FindStringSubmatch(line)
   if located == nil {
      return fmt.Errorf("unable to parse line: %v", line)
   }
   command := located[1]
   key := located[2]

   prefix := getPrefix(key)

   stats := s.keys[prefix]
   stats.access++
   if stats.commands == nil {
      stats.commands = make(map[string]int)
   }
   stats.commands[command]++
   s.keys[prefix] = stats
   return nil
}

func getPrefix(key string) string {
   for _, prefix := range prefixes {
      if strings.HasPrefix(key, prefix) {
         return prefix
      }
   }
   panic(fmt.Errorf("missing prefix for key %v", key))
}

func (s *Scanner) summary() {
   output := "\n\nSummary\n\r\n"

   total := 0
   for _, stats := range s.keys {
      total += stats.access
   }

   sortedKeys := make([]string, 0)
   for key := range s.keys {
      sortedKeys = append(sortedKeys, key)
   }

   sort.Slice(sortedKeys, func(i, j int) bool {
      return s.keys[sortedKeys[i]].access > s.keys[sortedKeys[j]].access
   })

   for _, key := range sortedKeys {
      stats := s.keys[key]
      percent := 100 * stats.access / total
      output += fmt.Sprintf("%v %v%% %v\r\n", key, percent, stats.commands)
   }
   fmt.Printf(output)
}

To run the utility, we redirect the output if the Redis MONITOR command to the utility STDIN:

kubectl exec -it redis-statefulset-0 -- redis-cli monitor | ./redismonitor

And we get a report of each key access by its prefix, and the list of APIs used:

book- 31% map[exists:14548 hgetall:84258 hincrby:41242 hset:43647]
store- 10% map[hgetall:29097 hincrby:29096]
customer- 9% map[hdel:14548 hgetall:26694 hset:14548]
...

Final Notes

Using the report, we can conclude what are the keys who are mostly used, and which Redis APIs are used to access each key. Next we can jump into the related code that accesses the keys, and review it.

A small change in the code that accesses the top keys, would result in a high impact on the product footprint both in the Redis performance, and both in the application itself.