diff --git a/src/plotman/analyzer.py b/src/plotman/analyzer.py index 67073805..e2320c6d 100644 --- a/src/plotman/analyzer.py +++ b/src/plotman/analyzer.py @@ -1,7 +1,6 @@ import os import re import statistics -import sys import texttable as tt @@ -18,6 +17,8 @@ def analyze(logfilenames, clipterminals, bytmp, bybitfield): n_sorts = 0 n_uniform = 0 is_first_last = False + total_time = 0 + copy_time = 0 # Read the logfile, triggering various behaviors on various # regex matches. @@ -89,14 +90,27 @@ def analyze(logfilenames, clipterminals, bytmp, bybitfield): if clipterminals and is_first_last: pass # Drop this data; omit from statistics. else: - data.setdefault(sl, {}).setdefault('total time', []).append(float(m.group(1))) - for phase in ['1', '2', '3', '4']: - data.setdefault(sl, {}).setdefault('phase ' + phase, []).append(phase_time[phase]) - data.setdefault(sl, {}).setdefault('%usort', []).append(100 * n_uniform // n_sorts) + total_time = float(m.group(1)) + + # Copy Time. Sample log line: + # Copy time = 958.194 seconds. CPU (6.290%) Sat May 22 17:39:57 2021 + m = re.search(r'^Copy time = (\d+.\d+) seconds.*', line) + if m: + copy_time = float(m.group(1)) + + # Rename plot. Sample log line: + # Renamed final file from "/mnt/d1/a4.plot.2.tmp" to "/mnt/d2/a4.plot" + m = re.search(r'^Renamed final file.*', line) + if m: + data.setdefault(sl, {}).setdefault('copy time', []).append(copy_time) + data.setdefault(sl, {}).setdefault('total time', []).append(total_time + copy_time) + for phase in ['1', '2', '3', '4']: + data.setdefault(sl, {}).setdefault('phase ' + phase, []).append(phase_time[phase]) + data.setdefault(sl, {}).setdefault('%usort', []).append(100 * n_uniform // n_sorts) # Prepare report tab = tt.Texttable() - all_measures = ['%usort', 'phase 1', 'phase 2', 'phase 3', 'phase 4', 'total time'] + all_measures = ['%usort', 'phase 1', 'phase 2', 'phase 3', 'phase 4', 'copy time', 'total time'] headings = ['Slice', 'n'] + all_measures tab.header(headings)