4 # Parse the sfsres log file generated by SPECsfs to generate more detailed
5 # latency statistics than in the sfssum summary file.
7 import re, subprocess, sys
9 def extract_re(lines, regexp):
10 if isinstance(regexp, str):
11 regexp = re.compile(regexp)
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)
21 stat_sum = [0 for _ in STATSDATA]
23 def parse_date(datestr):
24 p = subprocess.Popen(['/bin/date', '-d', datestr, '+%s'],
25 stdout=subprocess.PIPE)
30 def find_stats(statsdata, timestamp):
32 if s[0] > timestamp: return (s[0], s[1:])
33 return (statsdata[-1][0], statsdata[-1][1:])
35 def parse_run(lines, timestamp, outfp=sys.stdout, statsdata=[]):
36 global stat_sum, op_sum
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:
45 timestamp = parse_date(timestamp.group(1))
49 # Extract the stable of per-operation counts, response times, etc.
50 regexp = re.compile(r"^(\w+)" + r"\s*([\d.]+)%?" * 9)
56 table[m.group(1)] = [float(m.group(i)) for i in range(2, 11)]
58 #sys.stderr.write("Error parsing line: " + l.strip() + "\n")
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)
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)))
75 try: val = table[o][5]
77 outfp.write("\t%s" % (val,))
80 op_sum += int(results.group(1))
81 stat_sum = map(lambda x, y: x + y, stat_sum, stat_delta)
83 def parse_sfsres(fp, statsdata):
84 sys.stdout.write("# target_ops actual_ops latency_avg")
86 sys.stdout.write(" " + o)
87 sys.stdout.write("\n")
91 m = re.match(r"^([^*]+) \*{32,}$", line)
94 parse_run(run_data, timestamp, statsdata=statsdata)
96 timestamp = m.group(1)
100 parse_run(run_data, timestamp, statsdata=statsdata)
103 print "Total SFS operations:", op_sum * 300
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))
111 def parse_stats(statsfile):
113 for line in statsfile:
114 if re.match(r"^#", line): continue
115 datapoints.append([float(x) for x in line.split()])
118 if __name__ == '__main__':
119 input_sfsres = open(sys.argv[1])
121 input_stats = open(sys.argv[2])
122 statsdata = parse_stats(input_stats)
126 parse_sfsres(input_sfsres, statsdata)