Merge branch 'fio-histo-log-pctiles' of https://github.com/parallel-fs-utils/fio
[fio.git] / tools / hist / fio-histo-log-pctiles.py
1 #!/usr/bin/env python
2
3 # module to parse fio histogram log files, not using pandas
4 # runs in python v2 or v3
5 # to get help with the CLI: $ python fio-histo-log-pctiles.py -h
6 # this can be run standalone as a script but is callable
7 # assumes all threads run for same time duration
8 # assumes all threads are doing the same thing for the entire run
9
10 # percentiles:
11 #  0 - min latency
12 #  50 - median
13 #  100 - max latency
14
15 # TO-DO: 
16 #   separate read and write stats for randrw mixed workload
17 #   report average latency if needed
18 #   prove that it works (partially done with unit tests)
19
20 # to run unit tests, set UNITTEST environment variable to anything
21 # if you do this, don't pass normal CLI parameters to it
22 # otherwise it runs the CLI
23
24 import sys, os, math, copy
25 from copy import deepcopy
26 import argparse
27 import unittest2
28
29 msec_per_sec = 1000
30 nsec_per_usec = 1000
31
32 class FioHistoLogExc(Exception):
33     pass
34
35 # if there is an error, print message, and exit with error status
36
37 def myabort(msg):
38     print('ERROR: ' + msg)
39     sys.exit(1)
40
41 # convert histogram log file into a list of
42 # (time_ms, direction, bsz, buckets) tuples where
43 # - time_ms is the time in msec at which the log record was written
44 # - direction is 0 (read) or 1 (write)
45 # - bsz is block size (not used)
46 # - buckets is a CSV list of counters that make up the histogram
47 # caller decides if the expected number of counters are present
48
49
50 def exception_suffix( record_num, pathname ):
51     return 'in histogram record %d file %s' % (record_num+1, pathname)
52
53 # log file parser raises FioHistoLogExc exceptions
54 # it returns histogram buckets in whatever unit fio uses
55
56 def parse_hist_file(logfn, buckets_per_interval):
57     max_timestamp_ms = 0.0
58     
59     with open(logfn, 'r') as f:
60         records = [ l.strip() for l in f.readlines() ]
61     intervals = []
62     for k, r in enumerate(records):
63         if r == '':
64             continue
65         tokens = r.split(',')
66         try:
67             int_tokens = [ int(t) for t in tokens ]
68         except ValueError as e:
69             raise FioHistoLogExc('non-integer value %s' % exception_suffix(k+1, logfn))
70
71         neg_ints = list(filter( lambda tk : tk < 0, int_tokens ))
72         if len(neg_ints) > 0:
73             raise FioHistoLogExc('negative integer value %s' % exception_suffix(k+1, logfn))
74
75         if len(int_tokens) < 3:
76             raise FioHistoLogExc('too few numbers %s' % exception_suffix(k+1, logfn))
77
78         time_ms = int_tokens[0]
79         if time_ms > max_timestamp_ms:
80             max_timestamp_ms = time_ms
81
82         direction = int_tokens[1]
83         if direction != 0 and direction != 1:
84             raise FioHistoLogExc('invalid I/O direction %s' % exception_suffix(k+1, logfn))
85
86         bsz = int_tokens[2]
87         if bsz > (1 << 24):
88             raise FioHistoLogExc('block size too large %s' % exception_suffix(k+1, logfn))
89
90         buckets = int_tokens[3:]
91         if len(buckets) != buckets_per_interval:
92             raise FioHistoLogExc('%d buckets per interval but %d expected in %s' % 
93                     (len(buckets), buckets_per_interval, exception_suffix(k+1, logfn)))
94         intervals.append((time_ms, direction, bsz, buckets))
95     if len(intervals) == 0:
96         raise FioHistoLogExc('no records in %s' % logfn)
97     return (intervals, max_timestamp_ms)
98
99
100 # compute time range for each bucket index in histogram record
101 # see comments in https://github.com/axboe/fio/blob/master/stat.h
102 # for description of bucket groups and buckets
103 # fio v3 bucket ranges are in nanosec (since response times are measured in nanosec)
104 # but we convert fio v3 nanosecs to floating-point microseconds
105
106 def time_ranges(groups, counters_per_group, fio_version=3):
107     bucket_width = 1
108     bucket_base = 0
109     bucket_intervals = []
110     for g in range(0, groups):
111         for b in range(0, counters_per_group):
112             rmin = float(bucket_base)
113             rmax = rmin + bucket_width
114             if fio_version == 3:
115                 rmin /= nsec_per_usec
116                 rmax /= nsec_per_usec
117             bucket_intervals.append( [rmin, rmax] )
118             bucket_base += bucket_width
119         if g != 0:
120             bucket_width *= 2
121     return bucket_intervals
122
123
124 # compute number of time quantum intervals in the test
125
126 def get_time_intervals(time_quantum, max_timestamp_ms):
127     # round down to nearest second
128     max_timestamp = max_timestamp_ms // msec_per_sec
129     # round up to nearest whole multiple of time_quantum
130     time_interval_count = (max_timestamp + time_quantum) // time_quantum
131     end_time = time_interval_count * time_quantum
132     return (end_time, time_interval_count)
133
134 # align raw histogram log data to time quantum so 
135 # we can then combine histograms from different threads with addition
136 # for randrw workload we count both reads and writes in same output bucket
137 # but we separate reads and writes for purposes of calculating
138 # end time for histogram record.
139 # this requires us to weight a raw histogram bucket by the 
140 # fraction of time quantum that the bucket overlaps the current
141 # time quantum interval
142 # for example, if we have a bucket with 515 samples for time interval
143 # [ 1010, 2014 ] msec since start of test, and time quantum is 1 sec, then
144 # for time quantum interval [ 1000, 2000 ] msec, the overlap is
145 # (2000 - 1010) / (2000 - 1000) = 0.99
146 # so the contribution of this bucket to this time quantum is
147 # 515 x 0.99 = 509.85
148
149 def align_histo_log(raw_histogram_log, time_quantum, bucket_count, max_timestamp_ms):
150
151     # slice up test time int intervals of time_quantum seconds
152
153     (end_time, time_interval_count) = get_time_intervals(time_quantum, max_timestamp_ms)
154     time_qtm_ms = time_quantum * msec_per_sec
155     end_time_ms = end_time * msec_per_sec
156     aligned_intervals = []
157     for j in range(0, time_interval_count):
158         aligned_intervals.append((
159             j * time_qtm_ms,
160             [ 0.0 for j in range(0, bucket_count) ] ))
161
162     log_record_count = len(raw_histogram_log)
163     for k, record in enumerate(raw_histogram_log):
164
165         # find next record with same direction to get end-time
166         # have to avoid going past end of array
167         # for fio randrw workload, 
168         # we have read and write records on same time interval
169         # sometimes read and write records are in opposite order
170         # assertion checks that next read/write record 
171         # can be separated by at most 2 other records
172
173         (time_msec, direction, sz, interval_buckets) = record
174         if k+1 < log_record_count:
175             (time_msec_end, direction2, _, _) = raw_histogram_log[k+1]
176             if direction2 != direction:
177                 if k+2 < log_record_count:
178                     (time_msec_end, direction2, _, _) = raw_histogram_log[k+2]
179                     if direction2 != direction:
180                         if k+3 < log_record_count:
181                             (time_msec_end, direction2, _, _) = raw_histogram_log[k+3]
182                             assert direction2 == direction
183                         else:
184                             time_msec_end = end_time_ms
185                 else:
186                     time_msec_end = end_time_ms
187         else:
188             time_msec_end = end_time_ms
189
190         # calculate first quantum that overlaps this histogram record 
191
192         qtm_start_ms = (time_msec // time_qtm_ms) * time_qtm_ms
193         qtm_end_ms = ((time_msec + time_qtm_ms) // time_qtm_ms) * time_qtm_ms
194         qtm_index = qtm_start_ms // time_qtm_ms
195
196         # for each quantum that overlaps this histogram record's time interval
197
198         while qtm_start_ms < time_msec_end:  # while quantum overlaps record
199
200             # calculate fraction of time that this quantum 
201             # overlaps histogram record's time interval
202             
203             overlap_start = max(qtm_start_ms, time_msec)
204             overlap_end = min(qtm_end_ms, time_msec_end)
205             weight = float(overlap_end - overlap_start)
206             weight /= (time_msec_end - time_msec)
207             (_,aligned_histogram) = aligned_intervals[qtm_index]
208             for bx, b in enumerate(interval_buckets):
209                 weighted_bucket = weight * b
210                 aligned_histogram[bx] += weighted_bucket
211
212             # advance to the next time quantum
213
214             qtm_start_ms += time_qtm_ms
215             qtm_end_ms += time_qtm_ms
216             qtm_index += 1
217
218     return aligned_intervals
219
220 # add histogram in "source" to histogram in "target"
221 # it is assumed that the 2 histograms are precisely time-aligned
222
223 def add_to_histo_from( target, source ):
224     for b in range(0, len(source)):
225         target[b] += source[b]
226
227 # compute percentiles
228 # inputs:
229 #   buckets: histogram bucket array 
230 #   wanted: list of floating-pt percentiles to calculate
231 #   time_ranges: [tmin,tmax) time interval for each bucket
232 # returns None if no I/O reported.
233 # otherwise we would be dividing by zero
234 # think of buckets as probability distribution function
235 # and this loop is integrating to get cumulative distribution function
236
237 def get_pctiles(buckets, wanted, time_ranges):
238
239     # get total of IO requests done
240     total_ios = 0
241     for io_count in buckets:
242         total_ios += io_count
243
244     # don't return percentiles if no I/O was done during interval
245     if total_ios == 0.0:
246         return None
247
248     pctile_count = len(wanted)
249
250     # results returned as dictionary keyed by percentile
251     pctile_result = {}
252
253     # index of next percentile in list
254     pctile_index = 0
255
256     # next percentile
257     next_pctile = wanted[pctile_index]
258
259     # no one is interested in percentiles bigger than this but not 100.0
260     # this prevents floating-point error from preventing loop exit
261     almost_100 = 99.9999
262
263     # pct is the percentile corresponding to 
264     # all I/O requests up through bucket b
265     pct = 0.0
266     total_so_far = 0
267     for b, io_count in enumerate(buckets):
268         if io_count == 0:
269             continue
270         total_so_far += io_count
271         # last_pct_lt is the percentile corresponding to 
272         # all I/O requests up to, but not including, bucket b
273         last_pct = pct
274         pct = 100.0 * float(total_so_far) / total_ios
275         # a single bucket could satisfy multiple pctiles
276         # so this must be a while loop
277         # for 100-percentile (max latency) case, no bucket exceeds it 
278         # so we must stop there.
279         while ((next_pctile == 100.0 and pct >= almost_100) or
280                (next_pctile < 100.0  and pct > next_pctile)):
281             # interpolate between min and max time for bucket time interval
282             # we keep the time_ranges access inside this loop, 
283             # even though it could be above the loop,
284             # because in many cases we will not be even entering 
285             # the loop so we optimize out these accesses
286             range_max_time = time_ranges[b][1]
287             range_min_time = time_ranges[b][0]
288             offset_frac = (next_pctile - last_pct)/(pct - last_pct)
289             interpolation = range_min_time + (offset_frac*(range_max_time - range_min_time))
290             pctile_result[next_pctile] = interpolation
291             pctile_index += 1
292             if pctile_index == pctile_count:
293                 break
294             next_pctile = wanted[pctile_index]
295         if pctile_index == pctile_count:
296             break
297     assert pctile_index == pctile_count
298     return pctile_result
299
300
301 # this is really the main program
302
303 def compute_percentiles_from_logs():
304     parser = argparse.ArgumentParser()
305     parser.add_argument("--fio-version", dest="fio_version", 
306         default="3", choices=[2,3], type=int, 
307         help="fio version (default=3)")
308     parser.add_argument("--bucket-groups", dest="bucket_groups", default="29", type=int, 
309         help="fio histogram bucket groups (default=29)")
310     parser.add_argument("--bucket-bits", dest="bucket_bits", 
311         default="6", type=int, 
312         help="fio histogram buckets-per-group bits (default=6 means 64 buckets/group)")
313     parser.add_argument("--percentiles", dest="pctiles_wanted", 
314         default="0 50 95 99 100", type=float, nargs='+',
315         help="fio histogram buckets-per-group bits (default=6 means 64 buckets/group)")
316     parser.add_argument("--time-quantum", dest="time_quantum", 
317         default="1", type=int,
318         help="time quantum in seconds (default=1)")
319     parser.add_argument("--output-unit", dest="output_unit", 
320         default="usec", type=str,
321         help="Latency percentile output unit: msec|usec|nsec (default usec)")
322     parser.add_argument("file_list", nargs='+')
323     args = parser.parse_args()
324     print(args)
325
326     if not args.bucket_groups:
327         # default changes based on fio version
328         if fio_version == 2:
329             args.bucket_groups = 19
330         else:
331             # default in fio 3.x
332             args.bucket_groups = 29
333
334     # print parameters
335
336     print('bucket groups = %d' % args.bucket_groups)
337     print('bucket bits = %d' % args.bucket_bits)
338     print('time quantum = %d sec' % args.time_quantum)
339     print('percentiles = %s' % ','.join([ str(p) for p in args.pctiles_wanted ]))
340     buckets_per_group = 1 << args.bucket_bits
341     print('buckets per group = %d' % buckets_per_group)
342     buckets_per_interval = buckets_per_group * args.bucket_groups
343     print('buckets per interval = %d ' % buckets_per_interval)
344     bucket_index_range = range(0, buckets_per_interval)
345     if args.time_quantum == 0:
346         print('ERROR: time-quantum must be a positive number of seconds')
347     print('output unit = ' + args.output_unit)
348     if args.output_unit == 'msec':
349         time_divisor = 1000.0
350     elif args.output_unit == 'usec':
351         time_divisor = 1.0
352
353     # calculate response time interval associated with each histogram bucket
354
355     bucket_times = time_ranges(args.bucket_groups, buckets_per_group, fio_version=args.fio_version)
356
357     # construct template for each histogram bucket array with buckets all zeroes
358     # we just copy this for each new histogram
359
360     zeroed_buckets = [ 0.0 for r in bucket_index_range ]
361
362     # print CSV header just like fiologparser_hist does
363
364     header = 'msec, '
365     for p in args.pctiles_wanted:
366         header += '%3.1f, ' % p
367     print('time (millisec), percentiles in increasing order with values in ' + args.output_unit)
368     print(header)
369
370     # parse the histogram logs
371     # assumption: each bucket has a monotonically increasing time
372     # assumption: time ranges do not overlap for a single thread's records
373     # (exception: if randrw workload, then there is a read and a write 
374     # record for the same time interval)
375
376     max_timestamp_all_logs = 0
377     hist_files = {}
378     for fn in args.file_list:
379         try:
380             (hist_files[fn], max_timestamp_ms)  = parse_hist_file(fn, buckets_per_interval)
381         except FioHistoLogExc as e:
382             myabort(str(e))
383         max_timestamp_all_logs = max(max_timestamp_all_logs, max_timestamp_ms)
384
385     (end_time, time_interval_count) = get_time_intervals(args.time_quantum, max_timestamp_all_logs)
386     all_threads_histograms = [ ((j*args.time_quantum*msec_per_sec), deepcopy(zeroed_buckets))
387                                 for j in range(0, time_interval_count) ]
388
389     for logfn in hist_files.keys():
390         aligned_per_thread = align_histo_log(hist_files[logfn], 
391                                              args.time_quantum, 
392                                              buckets_per_interval, 
393                                              max_timestamp_all_logs)
394         for t in range(0, time_interval_count):
395             (_, all_threads_histo_t) = all_threads_histograms[t]
396             (_, log_histo_t) = aligned_per_thread[t]
397             add_to_histo_from( all_threads_histo_t, log_histo_t )
398
399     # calculate percentiles across aggregate histogram for all threads
400
401     for (t_msec, all_threads_histo_t) in all_threads_histograms:
402         record = '%d, ' % t_msec
403         pct = get_pctiles(all_threads_histo_t, args.pctiles_wanted, bucket_times)
404         if not pct:
405             for w in args.pctiles_wanted:
406                 record += ', '
407         else:
408             pct_keys = [ k for k in pct.keys() ]
409             pct_values = [ str(pct[wanted]/time_divisor) for wanted in sorted(pct_keys) ]
410             record += ', '.join(pct_values)
411         print(record)
412
413
414
415 #end of MAIN PROGRAM
416
417
418
419 ##### below are unit tests ##############
420
421 import tempfile, shutil
422 from os.path import join
423 should_not_get_here = False
424
425 class Test(unittest2.TestCase):
426     tempdir = None
427
428     # a little less typing please
429     def A(self, boolean_val):
430         self.assertTrue(boolean_val)
431
432     # initialize unit test environment
433
434     @classmethod
435     def setUpClass(cls):
436         d = tempfile.mkdtemp()
437         Test.tempdir = d
438
439     # remove anything left by unit test environment
440     # unless user sets UNITTEST_LEAVE_FILES environment variable
441
442     @classmethod
443     def tearDownClass(cls):
444         if not os.getenv("UNITTEST_LEAVE_FILES"):
445             shutil.rmtree(cls.tempdir)
446
447     def setUp(self):
448         self.fn = join(Test.tempdir, self.id())
449
450     def test_a_add_histos(self):
451         a = [ 1.0, 2.0 ]
452         b = [ 1.5, 2.5 ]
453         add_to_histo_from( a, b )
454         self.A(a == [2.5, 4.5])
455         self.A(b == [1.5, 2.5])
456
457     def test_b1_parse_log(self):
458         with open(self.fn, 'w') as f:
459             f.write('1234, 0, 4096, 1, 2, 3, 4\n')
460             f.write('5678,1,16384,5,6,7,8 \n')
461         (raw_histo_log, max_timestamp) = parse_hist_file(self.fn, 4) # 4 buckets per interval
462         self.A(len(raw_histo_log) == 2 and max_timestamp == 5678)
463         (time_ms, direction, bsz, histo) = raw_histo_log[0]
464         self.A(time_ms == 1234 and direction == 0 and bsz == 4096 and histo == [ 1, 2, 3, 4 ])
465         (time_ms, direction, bsz, histo) = raw_histo_log[1]
466         self.A(time_ms == 5678 and direction == 1 and bsz == 16384 and histo == [ 5, 6, 7, 8 ])
467
468     def test_b2_parse_empty_log(self):
469         with open(self.fn, 'w') as f:
470             pass
471         try:
472             (raw_histo_log, max_timestamp_ms) = parse_hist_file(self.fn, 4)
473             self.A(should_not_get_here)
474         except FioHistoLogExc as e:
475             self.A(str(e).startswith('no records'))
476
477     def test_b3_parse_empty_records(self):
478         with open(self.fn, 'w') as f:
479             f.write('\n')
480             f.write('1234, 0, 4096, 1, 2, 3, 4\n')
481             f.write('5678,1,16384,5,6,7,8 \n')
482             f.write('\n')
483         (raw_histo_log, max_timestamp_ms) = parse_hist_file(self.fn, 4)
484         self.A(len(raw_histo_log) == 2 and max_timestamp_ms == 5678)
485         (time_ms, direction, bsz, histo) = raw_histo_log[0]
486         self.A(time_ms == 1234 and direction == 0 and bsz == 4096 and histo == [ 1, 2, 3, 4 ])
487         (time_ms, direction, bsz, histo) = raw_histo_log[1]
488         self.A(time_ms == 5678 and direction == 1 and bsz == 16384 and histo == [ 5, 6, 7, 8 ])
489
490     def test_b4_parse_non_int(self):
491         with open(self.fn, 'w') as f:
492             f.write('12, 0, 4096, 1a, 2, 3, 4\n')
493         try:
494             (raw_histo_log, _) = parse_hist_file(self.fn, 4)
495             self.A(False)
496         except FioHistoLogExc as e:
497             self.A(str(e).startswith('non-integer'))
498
499     def test_b5_parse_neg_int(self):
500         with open(self.fn, 'w') as f:
501             f.write('-12, 0, 4096, 1, 2, 3, 4\n')
502         try:
503             (raw_histo_log, _) = parse_hist_file(self.fn, 4)
504             self.A(False)
505         except FioHistoLogExc as e:
506             self.A(str(e).startswith('negative integer'))
507
508     def test_b6_parse_too_few_int(self):
509         with open(self.fn, 'w') as f:
510             f.write('0, 0\n')
511         try:
512             (raw_histo_log, _) = parse_hist_file(self.fn, 4)
513             self.A(False)
514         except FioHistoLogExc as e:
515             self.A(str(e).startswith('too few numbers'))
516
517     def test_b7_parse_invalid_direction(self):
518         with open(self.fn, 'w') as f:
519             f.write('100, 2, 4096, 1, 2, 3, 4\n')
520         try:
521             (raw_histo_log, _) = parse_hist_file(self.fn, 4)
522             self.A(False)
523         except FioHistoLogExc as e:
524             self.A(str(e).startswith('invalid I/O direction'))
525
526     def test_b8_parse_bsz_too_big(self):
527         with open(self.fn+'_good', 'w') as f:
528             f.write('100, 1, %d, 1, 2, 3, 4\n' % (1<<24))
529         (raw_histo_log, max_timestamp_ms) = parse_hist_file(self.fn+'_good', 4)
530         with open(self.fn+'_bad', 'w') as f:
531             f.write('100, 1, 20000000, 1, 2, 3, 4\n')
532         try:
533             (raw_histo_log, _) = parse_hist_file(self.fn+'_bad', 4)
534             self.A(False)
535         except FioHistoLogExc as e:
536             self.A(str(e).startswith('block size too large'))
537
538     def test_b9_parse_wrong_bucket_count(self):
539         with open(self.fn, 'w') as f:
540             f.write('100, 1, %d, 1, 2, 3, 4, 5\n' % (1<<24))
541         try:
542             (raw_histo_log, _) = parse_hist_file(self.fn, 4)
543             self.A(False)
544         except FioHistoLogExc as e:
545             self.A(str(e).__contains__('buckets per interval'))
546
547     def test_c1_time_ranges(self):
548         ranges = time_ranges(3, 2)  # fio_version defaults to 3
549         expected_ranges = [ # fio_version 3 is in nanoseconds
550                 [0.000, 0.001], [0.001, 0.002],   # first group
551                 [0.002, 0.003], [0.003, 0.004],   # second group same width
552                 [0.004, 0.006], [0.006, 0.008]]   # subsequent groups double width
553         self.A(ranges == expected_ranges)
554         ranges = time_ranges(3, 2, fio_version=3)
555         self.A(ranges == expected_ranges)
556         ranges = time_ranges(3, 2, fio_version=2)
557         expected_ranges_v2 = [ [ 1000.0 * min_or_max for min_or_max in time_range ] 
558                                for time_range in expected_ranges ]
559         self.A(ranges == expected_ranges_v2)
560         # see fio V3 stat.h for why 29 groups and 2^6 buckets/group
561         normal_ranges_v3 = time_ranges(29, 64)
562         # for v3, bucket time intervals are measured in nanoseconds
563         self.A(len(normal_ranges_v3) == 29 * 64 and normal_ranges_v3[-1][1] == 64*(1<<(29-1))/1000.0)
564         normal_ranges_v2 = time_ranges(19, 64, fio_version=2)
565         # for v2, bucket time intervals are measured in microseconds so we have fewer buckets
566         self.A(len(normal_ranges_v2) == 19 * 64 and normal_ranges_v2[-1][1] == 64*(1<<(19-1)))
567
568     def test_d1_align_histo_log_1_quantum(self):
569         with open(self.fn, 'w') as f:
570             f.write('100, 1, 4096, 1, 2, 3, 4')
571         (raw_histo_log, max_timestamp_ms) = parse_hist_file(self.fn, 4)
572         self.A(max_timestamp_ms == 100)
573         aligned_log = align_histo_log(raw_histo_log, 5, 4, max_timestamp_ms)
574         self.A(len(aligned_log) == 1)
575         (time_ms0, h) = aligned_log[0]
576         self.A(time_ms0 == 0 and h == [1.0, 2.0, 3.0, 4.0])
577
578     # we need this to compare 2 lists of floating point numbers for equality
579     # because of floating-point imprecision
580
581     def compare_2_floats(self, x, y):
582         if x == 0.0 or y == 0.0:
583             return (x+y) < 0.0000001
584         else:
585             return (math.fabs(x-y)/x) < 0.00001
586                 
587     def is_close(self, buckets, buckets_expected):
588         if len(buckets) != len(buckets_expected):
589             return False
590         compare_buckets = lambda k: self.compare_2_floats(buckets[k], buckets_expected[k])
591         indices_close = list(filter(compare_buckets, range(0, len(buckets))))
592         return len(indices_close) == len(buckets)
593
594     def test_d2_align_histo_log_2_quantum(self):
595         with open(self.fn, 'w') as f:
596             f.write('2000, 1, 4096, 1, 2, 3, 4\n')
597             f.write('7000, 1, 4096, 1, 2, 3, 4\n')
598         (raw_histo_log, max_timestamp_ms) = parse_hist_file(self.fn, 4)
599         self.A(max_timestamp_ms == 7000)
600         (_, _, _, raw_buckets1) = raw_histo_log[0]
601         (_, _, _, raw_buckets2) = raw_histo_log[1]
602         aligned_log = align_histo_log(raw_histo_log, 5, 4, max_timestamp_ms)
603         self.A(len(aligned_log) == 2)
604         (time_ms1, h1) = aligned_log[0]
605         (time_ms2, h2) = aligned_log[1]
606         # because first record is from time interval [2000, 7000]
607         # we weight it according
608         expect1 = [float(b) * 0.6 for b in raw_buckets1]
609         expect2 = [float(b) * 0.4 for b in raw_buckets1]
610         for e in range(0, len(expect2)):
611             expect2[e] += raw_buckets2[e]
612         self.A(time_ms1 == 0    and self.is_close(h1, expect1))
613         self.A(time_ms2 == 5000 and self.is_close(h2, expect2))
614
615     # what to expect if histogram buckets are all equal
616     def test_e1_get_pctiles_flat_histo(self):
617         with open(self.fn, 'w') as f:
618             buckets = [ 100 for j in range(0, 128) ]
619             f.write('9000, 1, 4096, %s\n' % ', '.join([str(b) for b in buckets]))
620         (raw_histo_log, max_timestamp_ms) = parse_hist_file(self.fn, 128)
621         self.A(max_timestamp_ms == 9000)
622         aligned_log = align_histo_log(raw_histo_log, 5, 128, max_timestamp_ms)
623         time_intervals = time_ranges(4, 32)
624         # since buckets are all equal, then median is halfway through time_intervals
625         # and max latency interval is at end of time_intervals
626         self.A(time_intervals[64][1] == 0.066 and time_intervals[127][1] == 0.256)
627         pctiles_wanted = [ 0, 50, 100 ]
628         pct_vs_time = []
629         for (time_ms, histo) in aligned_log:
630             pct_vs_time.append(get_pctiles(histo, pctiles_wanted, time_intervals))
631         self.A(pct_vs_time[0] == None)  # no I/O in this time interval
632         expected_pctiles = { 0:0.000, 50:0.064, 100:0.256 }
633         self.A(pct_vs_time[1] == expected_pctiles)
634
635     # what to expect if just the highest histogram bucket is used
636     def test_e2_get_pctiles_highest_pct(self):
637         fio_v3_bucket_count = 29 * 64
638         with open(self.fn, 'w') as f:
639             # make a empty fio v3 histogram
640             buckets = [ 0 for j in range(0, fio_v3_bucket_count) ]
641             # add one I/O request to last bucket
642             buckets[-1] = 1
643             f.write('9000, 1, 4096, %s\n' % ', '.join([str(b) for b in buckets]))
644         (raw_histo_log, max_timestamp_ms) = parse_hist_file(self.fn, fio_v3_bucket_count)
645         self.A(max_timestamp_ms == 9000)
646         aligned_log = align_histo_log(raw_histo_log, 5, fio_v3_bucket_count, max_timestamp_ms)
647         (time_ms, histo) = aligned_log[1]
648         time_intervals = time_ranges(29, 64)
649         expected_pctiles = { 100.0:(64*(1<<28))/1000.0 }
650         pct = get_pctiles( histo, [ 100.0 ], time_intervals )
651         self.A(pct == expected_pctiles)
652
653 # we are using this module as a standalone program
654
655 if __name__ == '__main__':
656     if os.getenv('UNITTEST'):
657         sys.exit(unittest2.main())
658     else:
659         compute_percentiles_from_logs()
660