munin/nominatim_query_speed_querylog

   1 #!/usr/bin/python3
   2 #
   3 # Plugin to monitor the types of requsts made to the API
   4 #
   5 # Uses the query log.
   6 #
   7 # Parameters:
   8 #
   9 #       config   (required)
  10 #       autoconf (optional - used by munin-config)
  11 #
  12
  13 import re
  14 import os
  15 import sys
  16 from datetime import datetime, timedelta
  17
  18 CONFIG="""graph_title Total Nominatim response time
  19 graph_vlabel Time to response
  20 graph_category Nominatim
  21 graph_period minute
  22 graph_args --base 1000
  23
  24 avgs.label Average search time
  25 avgs.draw LINE
  26 avgs.type GAUGE
  27 avgs.min 0
  28 avgs.info Moving 5 minute average time to perform search
  29 avgs.label Average time to response
  30
  31 avgr.label Average reverse time
  32 avgr.draw LINE
  33 avgr.type GAUGE
  34 avgr.min 0
  35 avgr.info Moving 5 minute average time to perform search
  36 avgr.label Average time to response
  37
  38 max.label Slowest time to response
  39 max.draw LINE
  40 max.type GAUGE
  41 max.min 0
  42 max.info Slowest query in last 5 minutes"""
  43
  44 ENTRY_REGEX = re.compile(r'\[[^]]+\] (?P<dur>[0-9.]+) (?P<numres>\d+) (?P<type>[a-z]+) ')
  45 TIME_REGEX = re.compile(r'\[(?P<t_year>\d\d\d\d)-(?P<t_month>\d\d)-(?P<t_day>\d\d) (?P<t_hour>\d\d):(?P<t_min>\d\d):(?P<t_sec>\d\d)[0-9.]*\] ')
  46
  47
  48 class LogFile:
  49     """ A query log file, unpacked. """
  50
  51     def __init__(self, filename):
  52         self.fd = open(filename, encoding='utf-8')
  53         self.len = os.path.getsize(filename)
  54
  55     def __del__(self):
  56         self.fd.close()
  57
  58     def seek_next(self, abstime):
  59         self.fd.seek(abstime)
  60         self.fd.readline()
  61         l = self.fd.readline()
  62         e = TIME_REGEX.match(l)
  63         if e is None:
  64             return None
  65         e = e.groupdict()
  66         return datetime(int(e['t_year']), int(e['t_month']), int(e['t_day']),
  67                              int(e['t_hour']), int(e['t_min']), int(e['t_sec']))
  68
  69     def seek_to_date(self, target):
  70         # start position for binary search
  71         fromseek = 0
  72         fromdate = self.seek_next(0)
  73         if fromdate > target:
  74             return True
  75         # end position for binary search
  76         toseek = -100
  77         while -toseek < self.len:
  78             todate = self.seek_next(self.len + toseek)
  79             if todate is not None:
  80                 break
  81             toseek -= 100
  82         if todate is None or todate < target:
  83             return False
  84         toseek = self.len + toseek
  85
  86
  87         while True:
  88             bps = (toseek - fromseek) / (todate - fromdate).total_seconds()
  89             newseek = fromseek + int((target - fromdate).total_seconds() * bps)
  90             newdate = self.seek_next(newseek)
  91             if newdate is None:
  92                 return False;
  93             error = abs((target - newdate).total_seconds())
  94             if error < 1:
  95                 return True
  96             if newdate > target:
  97                 toseek = newseek
  98                 todate = newdate
  99                 oldfromseek = fromseek
 100                 fromseek = toseek - error * bps
 101                 while True:
 102                     if fromseek <= oldfromseek:
 103                         fromseek = oldfromseek
 104                         fromdate = self.seek_next(fromseek)
 105                         break
 106                     fromdate = self.seek_next(fromseek)
 107                     if fromdate < target:
 108                         break;
 109                     bps *=2
 110                     fromseek -= error * bps
 111             else:
 112                 fromseek = newseek
 113                 fromdate = newdate
 114                 oldtoseek = toseek
 115                 toseek = fromseek + error * bps
 116                 while True:
 117                     if toseek > oldtoseek:
 118                         toseek = oldtoseek
 119                         todate = self.seek_next(toseek)
 120                         break
 121                     todate = self.seek_next(toseek)
 122                     if todate > target:
 123                         break
 124                     bps *=2
 125                     toseek += error * bps
 126             if toseek - fromseek < 500:
 127                 return True
 128
 129
 130     def loglines(self):
 131         for l in self.fd:
 132             e = ENTRY_REGEX.match(l)
 133             if e is None:
 134                 raise ValueError("Invalid log line:", l)
 135             yield e.groupdict()
 136
 137
 138 if __name__ == '__main__':
 139
 140     if len(sys.argv) > 1 and sys.argv[1] == 'config':
 141         print(CONFIG)
 142         sys.exit(0)
 143
 144     sumrev = 0
 145     numrev = 0
 146     sumsearch = 0
 147     numsearch = 0
 148     maxres = 0
 149     if 'NOMINATIM_QUERYLOG' in os.environ:
 150         lf = LogFile(os.environ['NOMINATIM_QUERYLOG'])
 151         if lf.seek_to_date(datetime.now() - timedelta(minutes=5)):
 152             for l in lf.loglines():
 153                 dur = float(l['dur'])
 154                 if l['type'] == 'reverse':
 155                     numrev += 1
 156                     sumrev += dur
 157                 elif  l['type'] == 'search':
 158                     numsearch += 1
 159                     sumsearch += dur
 160                 if dur > maxres:
 161                     maxres = dur
 162
 163
 164     print('avgs.value', 0 if numsearch == 0 else sumsearch/numsearch)
 165     print('avgr.value', 0 if numrev == 0 else sumrev/numrev)
 166     print('max.value', maxres)