tfb_res.py

import os
import sys
import zipfile
import json
import re
import datetime
import optparse

parser = optparse.OptionParser("usage: %prog [options]", add_help_option=False)
parser.add_option("-f", "--file", dest="filename", default='', type="string")
parser.add_option("-m", "--maxnum", dest="maxnum", default=50, type="int")
parser.add_option("-@", "--fw", dest="fw", action="store_true", default=False)
parser.add_option("-t", "--tn", dest="tn", default='', type="string")
(opt, args) = parser.parse_args()


re_time = re.compile(r'(\d+)(\D+)')

def decode_time(text):
    ts = re_time.findall(text)
    dt = datetime.timedelta(seconds = 0)
    for i, t in enumerate(reversed(ts)):
        if i == 0:
            dt += datetime.timedelta(seconds = int(t[0]))
        if i == 1:
            dt += datetime.timedelta(minutes = int(t[0]))
        if i == 2:
            dt += datetime.timedelta(hours = int(t[0]))
    return dt    

tfbstat = { }

def add_stat_time(substr, item, fname, add_time = True):
    global tfbstat
    x = s.find(substr)
    if x < 0:
        return False
    tm = s[x + len(substr) + 1:]
    tm = tm.strip()
    tm = decode_time(tm)
    if add_time:
        item[fname] += tm
    else:
        item[fname] = tm
    return tm

def add_stat_str(substr, item, fname):
    global tfbstat
    x = s.find(substr)
    if x < 0:
        return False
    string = s[x + len(substr) + 1:]
    item[fname] = string
    return string

def add_stat_counter(substr, item, fname):
    global tfbstat
    x = s.find(substr)
    if x < 0:
        return False
    item[fname] += 1
    return item[fname]
    
base_dict = {
    'test_count': 0,
    'total_test_time': datetime.timedelta(seconds = 0),
    'build_time': datetime.timedelta(seconds = 0),
    'verif_time': datetime.timedelta(seconds = 0),
    'sleep_time': datetime.timedelta(seconds = 0),
    'error': ''
}


zip = zipfile.ZipFile(opt.filename, 'r')

ftstat = { }  # full test stat
ftstat['tests'] = { }

for fn in zip.namelist():
    if fn.endswith('/benchmark.log'):
        tfblog = zip.read(fn)
    if fn.endswith('/results.json'):
        tfbres = zip.read(fn)
    if opt.tn:
        vn = fn.split('/')
        if len(vn) > 3 and vn[-3] == opt.tn:
            tname = vn[-2]
            fname = vn[-1]
            finfo = zip.getinfo(fn)
            ft = finfo.date_time
            fdt = datetime.datetime(year=ft[0], month=ft[1], day=ft[2], hour=ft[3], minute=ft[4], second=ft[5])
            epoch = int((fdt - datetime.datetime(1970,1,1)).total_seconds())
            if fname == '':
                pass #print(f'Dir name: {tname} \t: {fdt}')
            else:
                pass #print(f'  {tname}/{fname} \t: {fdt}')
            if tname == 'build' or tname == 'run':
                if fname == '':
                    ftstat[tname+'_start'] = fdt
                else:
                    ftstat[tname+'_finish'] = fdt
                continue
            if fname == '':
                ftstat['tests'][tname] = { }
                continue
            ftstat['tests'][tname][fname] = fdt
            

tfbres = json.loads(tfbres.decode('utf8'))
testMetadata = tfbres['testMetadata']
fwdict = { }
for fw in sorted(testMetadata, key=lambda item: item['framework']):
    fw_name = fw['framework']
    fwdict[fw_name] = base_dict.copy()
     
print(f"Number of frameworks: {len(fwdict)}")

tfblog = tfblog.decode('utf8')
tfblog = tfblog.splitlines()
curr_fw_name = '_unknown_'
curr_test_name = '_unknown_'
state = 3
for s in tfblog:
    if state >= 3 and s.startswith('------------------'):
        state = 1
        curr_fw_name = ''
        curr_test_name = ''
        continue
    if state == 1 and s.startswith('Benchmarking'):
        #print(s)
        curr_test_name = s.split(' ')[1]
        tfbstat[curr_test_name] = base_dict.copy()
        for fw in fwdict.keys():
            if curr_test_name.startswith(fw):
                curr_fw_name = fw
        state = 2
        continue
    if state == 2 and s.startswith('------------------'):
        state = 3
        continue
    if state == 3:
        item = tfbstat[curr_test_name]
        add_stat_counter('BENCHMARKING DB ...', item, 'test_count')
        add_stat_counter('BENCHMARKING JSON ...', item, 'test_count')
        add_stat_counter('BENCHMARKING QUERY ...', item, 'test_count')
        add_stat_counter('BENCHMARKING UPDATE ...', item, 'test_count')
        add_stat_counter('BENCHMARKING FORTUNE ...', item, 'test_count')
        add_stat_counter('BENCHMARKING PLAINTEXT ...', item, 'test_count')
        add_stat_counter('BENCHMARKING CACHED-QUERY ...', item, 'test_count')
        add_stat_time(f'{curr_test_name}: Build time:', item, 'build_time')
        add_stat_time(f'{curr_test_name}: Verify time:', item, 'verif_time')
        add_stat_time('Total test time:', item, 'total_test_time')
        add_stat_time('Clean up: Sleep', item, 'sleep_time')
        add_stat_str(f'{curr_test_name}: ERROR:', item, 'error')
        if curr_fw_name:
            item = fwdict[curr_fw_name]
            add_stat_time(f'{curr_test_name}: Build time:', item, 'build_time')
            add_stat_time(f'{curr_test_name}: Verify time:', item, 'verif_time')
            add_stat_time('Total test time:', item, 'total_test_time')
            add_stat_time('Clean up: Sleep', item, 'sleep_time')
            add_stat_str(f'{curr_test_name}: ERROR:', item, 'error')
            
zip.close() 


print(f"Number of tests: {len(tfbstat)}")

total_time = datetime.timedelta(seconds = 0)
build_time = datetime.timedelta(seconds = 0)
verif_time = datetime.timedelta(seconds = 0)
f_ver_time = datetime.timedelta(seconds = 0)
f_ver_num = 0
sleep_time = datetime.timedelta(seconds = 0)
for test in tfbstat:
    total_time += tfbstat[test]['total_test_time']
    total_time += tfbstat[test]['sleep_time']
    sleep_time += tfbstat[test]['sleep_time']
    build_time += tfbstat[test]['build_time']
    verif_time += tfbstat[test]['verif_time']
    if tfbstat[test]['test_count'] >= 6:
        f_ver_num += 1
        f_ver_time += tfbstat[test]['verif_time']

tt = (total_time - sleep_time).total_seconds() / 3600
vt = verif_time.total_seconds() / 3600
st = sleep_time.total_seconds() / 3600
print(f'Total time: {total_time} (included %.2f hours of sleep)' % st)
print(f'Total time: %.2f + %.2f = %.2f hours' % (tt, st, total_time.total_seconds() / 3600))
print(f'Total build  time: %.2f hours' % (build_time.total_seconds() / 3600))
print(f'Total verify time: %.2f hours' % (vt))
vt_avg = (vt * 60) / len(tfbstat)
print(f'Verify time avg: (%.2f * 60) / %d = %.2f min' % (vt, len(tfbstat), vt_avg))
print(f'Number of full tests: {f_ver_num}')
fvt = f_ver_time.total_seconds() / 3600
fvt_avg = (fvt * 60) / f_ver_num
print(f'Full tests verify time avg: (%.2f * 60) / %d = %.2f min' % (fvt, f_ver_num, fvt_avg))

if opt.fw:
    kdict = fwdict
else:
    kdict = tfbstat
    
klst = [ k for k, v in sorted(kdict.items(), key=lambda item: item[1]['total_test_time'], reverse=True) ]

print('')
k = 0
for elem_name in klst:
    if opt.tn and elem_name != opt.tn:
        continue
    item = kdict[elem_name]
    tt = item["total_test_time"]
    bt = item["build_time"]
    vt = item["verif_time"]
    error = f'ERROR: "{item["error"]}"' if item["error"] else ''
    print(f'{tt} ({bt} + {vt})  {elem_name}   {error}')
    k += 1
    if k >= opt.maxnum:
        break

if opt.tn:
    print('')
    #print(ftstat)
    full_tlist = [ 'db', 'json', 'query', 'update', 'fortune', 'plaintext', 'cached-query' ]
    tlist = [ ]
    for tname in full_tlist:
        if tname in ftstat['tests']:
            tlist.append(tname)
    print('%15s' % (' '), ' ', 'verify    test')
    ver_time_start = ftstat['run_start'] # min(ftstat.items(), key=lambda x: x[''])
    vt_prev = ver_time_start
    vt_last = None
    tt_first = None
    tt_last = None
    for i, tname in enumerate(tlist):
        item = ftstat['tests'][tname]
        vt = item['verification.txt'] - vt_prev
        vt_prev = item['verification.txt']
        if not tt_first:
            tt_first = item['stats.txt']
        tt = item['raw.txt'] - item['stats.txt']
        print('%15s' % (tname), ':', vt, ' ', tt)
        tt_last = item['raw.txt'] 
    print('')
    print('%15s' % ('TOTAL'), ':', vt_prev - ver_time_start, ' ', tt_last - tt_first)
    print('')
    print('Total verify and test time:', tt_last - ver_time_start)

print('')
print('======= FINISH =========')