results/parse-sfsres.py

   1 #!/usr/bin/python
   2 # coding=utf-8
   3 #
   4 # Parse the sfsres log file generated by SPECsfs to generate more detailed
   5 # latency statistics than in the sfssum summary file.
   6
   7 import re, subprocess, sys
   8
   9 def extract_re(lines, regexp):
  10     if isinstance(regexp, str):
  11         regexp = re.compile(regexp)
  12     for l in lines:
  13         m = regexp.match(l)
  14         if m: return m
  15
  16 OPERATIONS = ('read', 'write', 'create', 'setattr', 'lookup', 'getattr')
  17 STATSDATA = ('getop', 'getbyte', 'putop', 'putbyte', 'nfsincount', 'nfsinbyte', 'nfsoutcount', 'nfsoutbyte')
  18 COSTS = (0.01e-4, 0.15/1024**3, 0.01e-3, 0.10/1024**3, 0, 0, 0, 0)
  19
  20 op_sum = 0
  21 stat_sum = [0 for _ in STATSDATA]
  22
  23 def parse_date(datestr):
  24     p = subprocess.Popen(['/bin/date', '-d', datestr, '+%s'],
  25                          stdout=subprocess.PIPE)
  26     d = p.stdout.read()
  27     p.wait()
  28     return int(d.strip())
  29
  30 def find_stats(statsdata, timestamp):
  31     if statsdata is None: return (0, [0] * len(STATSDATA))
  32     for s in statsdata:
  33         if s[0] > timestamp: return (s[0], s[1:])
  34     return (statsdata[-1][0], statsdata[-1][1:])
  35
  36 def parse_run(lines, timestamp, outfp=sys.stdout, statsdata=[]):
  37     global stat_sum, op_sum
  38
  39     #print timestamp
  40     requested_load = extract_re(lines, r"\s*Requested Load.*= (\d+)")
  41     load = int(requested_load.group(1))
  42     results = extract_re(lines, r"SFS NFS THROUGHPUT:\s*([\d.]+).*RESPONSE TIME:\s*([\d.]+) Msec/Op")
  43     timestamp = extract_re(lines, r"SFS Aggregate Results.*, (.*)")
  44     if timestamp is not None:
  45         try:
  46             timestamp = parse_date(timestamp.group(1))
  47         except:
  48             timestamp = None
  49
  50     # Extract the stable of per-operation counts, response times, etc.
  51     regexp = re.compile(r"^(\w+)" + r"\s*([\d.]+)%?" * 9)
  52     table = {}
  53     for l in lines:
  54         m = regexp.match(l)
  55         if m:
  56             try:
  57                 table[m.group(1)] = [float(m.group(i)) for i in range(2, 11)]
  58             except:
  59                 #sys.stderr.write("Error parsing line: " + l.strip() + "\n")
  60                 pass
  61
  62     # Search for statistics on uploads/downloads in the time interval when the
  63     # benchmark is running.  We have the ending time.  SPECsfs runs for the 10
  64     # minutes prior, and uses the last 5 minuts of data.  Let's use the time
  65     # from 6 minutes prior to 1 minute prior, to give another 5-minute period
  66     # with a bit of a buffer after in case timing is slightly off.
  67     (t1, s1) = find_stats(statsdata, timestamp - 6*60)
  68     (t2, s2) = find_stats(statsdata, timestamp - 1*60)
  69     stat_delta = map(lambda x, y: y - x, s1, s2)
  70
  71     outfp.write("# finish_timestamp: " + str(timestamp) + "\n")
  72     outfp.write("# in %s seconds: stats are %s\n" % (t2 - t1, stat_delta))
  73     outfp.write("%d\t%s\t%s" % (load, results.group(1), results.group(2)))
  74     for o in OPERATIONS:
  75         val = '-'
  76         try: val = table[o][5]
  77         except: pass
  78         outfp.write("\t%s" % (val,))
  79     outfp.write("\n")
  80
  81     op_sum += int(results.group(1))
  82     stat_sum = map(lambda x, y: x + y, stat_sum, stat_delta)
  83
  84 def parse_sfsres(fp, statsdata):
  85     sys.stdout.write("# target_ops actual_ops latency_avg")
  86     for o in OPERATIONS:
  87         sys.stdout.write(" " + o)
  88     sys.stdout.write("\n")
  89     timestamp = None
  90     run_data = []
  91     for line in fp:
  92         m = re.match(r"^([^*]+) \*{32,}$", line)
  93         if m:
  94             if len(run_data) > 0:
  95                 parse_run(run_data, timestamp, statsdata=statsdata)
  96             run_data = []
  97             timestamp = m.group(1)
  98         else:
  99             run_data.append(line)
 100     if len(run_data) > 0:
 101         parse_run(run_data, timestamp, statsdata=statsdata)
 102
 103     print
 104     print "Total SFS operations:", op_sum * 300
 105     print "Statistics:"
 106     cost = 0.0
 107     for i in range(len(STATSDATA)):
 108         cost += stat_sum[i] * COSTS[i]
 109         print "%s: %s (%s)" % (STATSDATA[i], stat_sum[i], stat_sum[i] / (op_sum * 300.0))
 110     print "Total cost: %s (%s per op)" % (cost, cost / (op_sum * 300.0))
 111
 112 def parse_stats(statsfile):
 113     datapoints = []
 114     for line in statsfile:
 115         if re.match(r"^#", line): continue
 116         datapoints.append([float(x) for x in line.split()])
 117     return datapoints
 118
 119 if __name__ == '__main__':
 120     input_sfsres = open(sys.argv[1])
 121     try:
 122         input_stats = open(sys.argv[2])
 123         statsdata = parse_stats(input_stats)
 124     except:
 125         statsdata = None
 126
 127     parse_sfsres(input_sfsres, statsdata)