Add statistics to Cache

issue10100
review335611003

CHANGELOG

@@ -1,3 +1,4 @@
+* Add statistics to Cache
 * Add support for avatars
 * Add status command
 * Add document widget on form view

bin/trytond-stat

@@ -3,8 +3,11 @@
 # this repository contains the full copyright notices and license terms.
 import curses
 import datetime as dt
-import sys
+import math
 import os
+import sys
+
+from collections import defaultdict
 
 DIR = os.path.abspath(os.path.normpath(os.path.join(__file__,
     '..', '..', 'trytond')))
@@ -27,6 +30,7 @@ def main(stdscr):
     reverse = True
     processes = {}
     status_pad = curses.newpad(1, 1)
+    cache_pad = curses.newpad(1, 1)
 
     def refresh_status():
         now = dt.datetime.now()
@@ -35,29 +39,72 @@ def main(stdscr):
         def expired(process):
             return process['expire'] > now
 
-        def format(since, pid, request):
+        def format_status(since, pid, request):
             since = str(dt.timedelta(seconds=int(since)))
             return f"{pid:>5} {since:>18} {request}"
         status_pad.clear()
-        status = [format(*i) for i in sorted(
+        status = [format_status(*i) for i in sorted(
                 ((msg['since'], p['id'], msg['request'])
                     for p in filter(expired, processes.values())
                     for msg in p['status']),
                 reverse=reverse)]
-        prow = max(len(status), height - 2)
-        pcol = width - 2
-        status_pad.resize(prow + 2, pcol)
+        prow = min(len(status) + 1, height // 2)
+        pcol = max(max(map(len, status), default=0), width)
+        status_pad.resize(len(status) + 1, pcol + 1)
         for i, line in enumerate(status, 1):
-            status_pad.addnstr(i, 1, line.ljust(pcol), pcol - 2)
-        status_pad.border(0)
+            status_pad.addnstr(i, 0, line.ljust(pcol), pcol)
         status_pad.addnstr(
-            0, 0, ' {pid:>5} {since:>18} {request}'.format(
+            0, 0, "{pid:>5} {since:>18} {request} ({n})".format(
                 pid="pid",
                 since="TIME" + ('↑' if reverse else '↓'),
-                request="request"
-                ).upper().ljust(pcol),
-            pcol, curses.A_REVERSE)
-        status_pad.refresh(0, 0, 0, 0, height - 1, width)
+                request="request",
+                n=len(status),
+                ).upper().ljust(pcol), pcol, curses.A_REVERSE)
+        status_pad.noutrefresh(0, 0, 0, 0, prow, width - 1)
+
+        def ratio(cache):
+            if cache['hit'] or cache['miss']:
+                return cache['hit'] / (cache['hit'] + cache['miss'])
+            return 0
+
+        def format_cache(name, hit, miss, ratio, size):
+            return f"{hit:{size}d} {miss:{size}d} {ratio * 100:6.2f} {name}"
+
+        cache_pad.clear()
+        cache_stats = defaultdict(lambda: defaultdict(lambda: 0))
+        for p in filter(expired, processes.values()):
+            for cache in p['caches']:
+                stats = cache_stats[cache['name']]
+                stats['name'] = cache['name']
+                stats['hit'] += cache['hit']
+                stats['miss'] += cache['miss']
+        for cache in cache_stats.values():
+            cache['ratio'] = ratio(cache)
+        try:
+            size = math.ceil(math.log10(
+                    max(s['hit'] + s['miss'] for s in cache_stats.values())))
+        except ValueError:
+            size = 1
+        size = max(size, 4)
+        caches = [format_cache(size=size, **cache) for cache in sorted(
+                cache_stats.values(), key=lambda c: (c['ratio'], c['miss']),
+                reverse=reverse)]
+        crow = max(len(caches) + 1, (height - prow))
+        ccol = max(max(map(len, caches), default=0), width)
+        cache_pad.resize(crow + 1, ccol + 1)
+        for i, line in enumerate(caches, 1):
+            cache_pad.addnstr(i, 0, line.ljust(ccol), ccol)
+        cache_pad.addstr(
+            0, 0,
+            "{hit:>{size}} {miss:>{size}} {ratio:>6} {name} ({n})".format(
+                size=size,
+                hit="hit",
+                miss="miss",
+                ratio="% " + ('↑' if reverse else '↓'),
+                name="name",
+                n=len(caches),
+                ).upper().ljust(ccol), curses.A_REVERSE)
+        cache_pad.noutrefresh(0, 0, prow, 0, height - 1, width - 1)
 
     def refresh():
         global reverse

doc/ref/cache.rst

@@ -22,6 +22,18 @@ starts and resets on :class:`Transaction` commit or rollback.
     after being set in or retrieved from the cache.
 ..
 
+.. attribute:: hit
+
+Count the number of times the cache returned a cached value.
+
+.. attribute:: miss
+
+Count the number of times the cache did not contain the key.
+
+.. classmethod:: stats()
+
+Yield statistics for each instance.
+
 .. method:: get(key[, default])
 
 Retrieve the value of the key in the cache. If a ``default`` is specified it

trytond/cache.py

@@ -60,6 +60,7 @@ class BaseCache(object):
         self._name = name
         self.size_limit = size_limit
         self.context = context
+        self.hit = self.miss = 0
         if isinstance(duration, dt.timedelta):
             self.duration = duration
         elif isinstance(duration, (int, float)):
@@ -71,6 +72,15 @@ class BaseCache(object):
         assert self._name not in self._instances
         self._instances[self._name] = self
 
+    @classmethod
+    def stats(cls):
+        for name, inst in cls._instances.items():
+            yield {
+                'name': name,
+                'hit': inst.hit,
+                'miss': inst.miss,
+                }
+
     def _key(self, key):
         if self.context:
             context = Transaction().context
@@ -152,10 +162,13 @@ class MemoryCache(BaseCache):
         try:
             (expire, result) = cache.pop(key)
             if expire and expire < dt.datetime.now():
+                self.miss += 1
                 return default
             cache[key] = (expire, result)
+            self.hit += 1
             return result
         except (KeyError, TypeError):
+            self.miss += 1
             return default
 
     def set(self, key, value):

trytond/status.py

@@ -27,6 +27,7 @@ def processing(request):
 
 
 def log():
+    from trytond.cache import Cache
     msg = []
     now = time.perf_counter()
     for process in sorted(status.copy().values(), key=lambda p: p.start_time):
@@ -37,6 +38,7 @@ def log():
     return {
         'id': os.getpid(),
         'status': msg,
+        'caches': list(Cache.stats()),
         }