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     for s in statsdata:
  32         if s[0] > timestamp: return (s[0], s[1:])
  33     return (statsdata[-1][0], statsdata[-1][1:])
  34
  35 def parse_run(lines, timestamp, outfp=sys.stdout, statsdata=[]):
  36     global stat_sum, op_sum
  37
  38     #print timestamp
  39     requested_load = extract_re(lines, r"\s*Requested Load.*= (\d+)")
  40     load = int(requested_load.group(1))
  41     results = extract_re(lines, r"SFS NFS THROUGHPUT:\s*([\d.]+).*RESPONSE TIME:\s*([\d.]+) Msec/Op")
  42     timestamp = extract_re(lines, r"SFS Aggregate Results.*, (.*)")
  43     if timestamp is not None:
  44         try:
  45             timestamp = parse_date(timestamp.group(1))
  46         except:
  47             timestamp = None
  48
  49     # Extract the stable of per-operation counts, response times, etc.
  50     regexp = re.compile(r"^(\w+)" + r"\s*([\d.]+)%?" * 9)
  51     table = {}
  52     for l in lines:
  53         m = regexp.match(l)
  54         if m:
  55             try:
  56                 table[m.group(1)] = [float(m.group(i)) for i in range(2, 11)]
  57             except:
  58                 #sys.stderr.write("Error parsing line: " + l.strip() + "\n")
  59                 pass
  60
  61     # Search for statistics on uploads/downloads in the time interval when the
  62     # benchmark is running.  We have the ending time.  SPECsfs runs for the 10
  63     # minutes prior, and uses the last 5 minuts of data.  Let's use the time
  64     # from 6 minutes prior to 1 minute prior, to give another 5-minute period
  65     # with a bit of a buffer after in case timing is slightly off.
  66     (t1, s1) = find_stats(statsdata, timestamp - 6*60)
  67     (t2, s2) = find_stats(statsdata, timestamp - 1*60)
  68     stat_delta = map(lambda x, y: y - x, s1, s2)
  69
  70     outfp.write("# finish_timestamp: " + str(timestamp) + "\n")
  71     outfp.write("# in %s seconds: stats are %s\n" % (t2 - t1, stat_delta))
  72     outfp.write("%d\t%s\t%s" % (load, results.group(1), results.group(2)))
  73     for o in OPERATIONS:
  74         val = '-'
  75         try: val = table[o][5]
  76         except: pass
  77         outfp.write("\t%s" % (val,))
  78     outfp.write("\n")
  79
  80     op_sum += int(results.group(1))
  81     stat_sum = map(lambda x, y: x + y, stat_sum, stat_delta)
  82
  83 def parse_sfsres(fp, statsdata):
  84     sys.stdout.write("# target_ops actual_ops latency_avg")
  85     for o in OPERATIONS:
  86         sys.stdout.write(" " + o)
  87     sys.stdout.write("\n")
  88     timestamp = None
  89     run_data = []
  90     for line in fp:
  91         m = re.match(r"^([^*]+) \*{32,}$", line)
  92         if m:
  93             if len(run_data) > 0:
  94                 parse_run(run_data, timestamp, statsdata=statsdata)
  95             run_data = []
  96             timestamp = m.group(1)
  97         else:
  98             run_data.append(line)
  99     if len(run_data) > 0:
 100         parse_run(run_data, timestamp, statsdata=statsdata)
 101
 102     print
 103     print "Total SFS operations:", op_sum * 300
 104     print "Statistics:"
 105     cost = 0.0
 106     for i in range(len(STATSDATA)):
 107         cost += stat_sum[i] * COSTS[i]
 108         print "%s: %s (%s)" % (STATSDATA[i], stat_sum[i], stat_sum[i] / (op_sum * 300.0))
 109     print "Total cost: %s (%s per op)" % (cost, cost / (op_sum * 300.0))
 110
 111 def parse_stats(statsfile):
 112     datapoints = []
 113     for line in statsfile:
 114         if re.match(r"^#", line): continue
 115         datapoints.append([float(x) for x in line.split()])
 116     return datapoints
 117
 118 if __name__ == '__main__':
 119     input_sfsres = open(sys.argv[1])
 120     try:
 121         input_stats = open(sys.argv[2])
 122         statsdata = parse_stats(input_stats)
 123     except:
 124         statsdata = []
 125
 126     parse_sfsres(input_sfsres, statsdata)