Analysis: added matplotlib figure generation with several desirable performance metrics.

setup.cfg

@@ -45,6 +45,7 @@ install_requires =
     psutil ~= 5.8
     pyyaml ~= 5.4
     texttable ~= 1.6
+    matplotlib ~= 3.4.2
 
 [options.packages.find]
 where=src

src/plotman/analyzer.py

@@ -2,14 +2,132 @@
 import re
 import statistics
 import sys
+import time, datetime
 
 import texttable as tt
+import numpy as np
+
+import matplotlib
+import matplotlib.pyplot as plt
 
 from plotman import plot_util
 
 
-def analyze(logfilenames, clipterminals, bytmp, bybitfield):
+def create_ax_dumbbell(ax, data, max_stacked=50):
+    '''
+        Create a dumbbell plot of concurrent plot instances over time.
+        Parameters:
+            ax: a matplotlib axis.
+            data: numpy arrary with [start times, end times].
+    '''
+
+    def newline(p1, p2, color='r'):
+        l = matplotlib.lines.Line2D([p1[0],p2[0]], [p1[1],p2[1]], color=color)
+        ax.add_line(l)
+        return l
+
+    # Prevent the stack from growing to tall
+    num_rows = data.shape[0]
+    stacker = []
+    for _ in range(int(np.ceil(num_rows / float(max_stacked)))):
+        stacker.extend(list(range(max_stacked)))
+    stacker = np.array(stacker)
+    stacker = stacker[:-(max_stacked-int(num_rows % float(max_stacked)))]
+
+    for (p1, p2), i in zip(data[:,:2], stacker):
+        newline([p1, i], [p2, i])
+    ax.scatter(data[:,0], stacker, color='b')
+    ax.scatter(data[:,1], stacker, color='b')
+
+    ax.set_ylabel('Plots')
+    ax.set_xlim(np.min(data[:,0])-2, np.max(data[:,1])+2)
+
+
+def create_ax_plotrate(ax, data, end=True, window=3):
+    '''
+        Create a plot showing the rate of plotting over time. Can be computed
+            with respect to the plot start (this is rate of plot creation) or 
+            with respect to the plot end (this is rate of plot completion).
+        Parameters:
+            ax: a matplotlib axis.
+            data: numpy arrary with [start times, end times].
+            end: T/F, compute plot creation or plot completion rate.
+            window: Window to compute rate over. 
+    '''
+
+    def estimate_rate(data, window):
+        rate_list = []
+        window_list = []
+        # This takes care of when we dont have a full window
+        for i in range(window):
+            rate_list.append(data[i] - data[0])
+            window_list.append(i)
+        # This takes care of when we do
+        for i in range(len(data) - window):
+            rate_list.append(data[i+window] - data[i])
+            window_list.append(window)
+        rate_list, window_list = np.array(rate_list), np.array(window_list)
+        rate_list[rate_list == 0] = np.nan # This prevents div by zero error
+        return np.where(np.logical_not(np.isnan(rate_list)), (window_list-1) / rate_list, 0)
+
+    # Estimate the rate of ending or the rate of starting
+    if end:
+        rate = estimate_rate(data[:,1], window)
+        ax.plot(data[:,1], rate)
+    else:
+        rate = estimate_rate(data[:,0], window)
+        ax.plot(data[:,0], rate)
+
+    ax.set_ylabel('Avg Plot Rate (plots/hour)')
+    ax.set_xlim(np.min(data[:,0])-2, np.max(data[:,1])+2)
+
+
+def create_ax_plottime(ax, data, window=3):
+    '''
+        Create a plot showing the average time to create a single plot. This is 
+            computed using a moving average. Note that the plot may not be 
+            very accurate for the beginning and ending windows.
+        Parameters:
+            ax: a matplotlib axis.
+            data: numpy arrary with [start times, end times].
+            window: Window to compute rate over. 
+    '''
+
+    # Compute moving avg
+    kernel = np.ones(window) / window
+    data_tiled = np.vstack((
+        np.expand_dims(data[:,1] - data[:,0], axis=1),
+        np.tile(data[-1,1] - data[-1,0], (window-1, 1))
+    ))
+    rolling_avg = np.convolve(data_tiled.squeeze(), kernel, mode='valid')
+
+    ax.plot(data[:,1], rolling_avg)
+
+    ax.set_ylabel('Avg Plot Time (hours)')
+    ax.set_xlim(np.min(data[:,0])-2, np.max(data[:,1])+2)
+
+
+def create_ax_plotcumulative(ax, data):
+    '''
+        Create a plot showing the cumulative number of plots over time.
+        Parameters:
+            ax: a matplotlib axis.
+            data: numpy arrary with [start times, end times].
+    '''
+    ax.plot(data[:,1], range(data.shape[0]))
+
+    ax.set_ylabel('Total plots (plots)')
+    ax.set_xlim(np.min(data[:,0])-2, np.max(data[:,1])+2)
+
+
+def analyze(logfilenames, clipterminals, bytmp, bybitfield, figfile):
     data = {}
+
+    # Get valid logfiles if we were passed a directory
+    if not isinstance(logfilenames, list) and os.path.isdir(logfilenames):
+        logfilenames = [os.path.join(os.path.dirname(logfilenames), l) for l in os.listdir(logfilenames) if
+            os.path.splitext(l)[-1] == '.log']
+
     for logfilename in logfilenames:
         with open(logfilename, 'r') as f:
             # Record of slicing and data associated with the slice
@@ -94,6 +212,48 @@ def analyze(logfilenames, clipterminals, bytmp, bybitfield):
                             data.setdefault(sl, {}).setdefault('phase ' + phase, []).append(phase_time[phase])
                         data.setdefault(sl, {}).setdefault('%usort', []).append(100 * n_uniform // n_sorts)
 
+                        # Grab the time ended, compute the time started
+                        time_ended = time.mktime(datetime.datetime.strptime(line.split(')')[-1][1:-1], '%a %b %d %H:%M:%S %Y').timetuple())
+                        data.setdefault(sl, {}).setdefault('time ended', []).append(time_ended)
+                        data.setdefault(sl, {}).setdefault('time started', []).append(time_ended - float(m.group(1)))
+
+    if figfile is not None:
+        # Prepare report
+        for sl in data.keys():
+
+            # This array will hold start and end data (in hours)
+            data_started_ended = np.array([[ts, te, te-ts] for 
+                ts, te in zip(data[sl]['time started'], data[sl]['time ended'])
+            ]) / (60 * 60)
+            assert data_started_ended.shape[0] >= 3, 'Cannot generate figure with less than 3 datapoints ({} datapoints passed)'.format(data_started_ended.shape[0])
+
+            # Sift the data so that it starts at zero
+            data_started_ended -= np.min(data_started_ended[:, 0])
+
+            # Sort the rows by start time 
+            data_started_ended = data_started_ended[np.argsort(data_started_ended[:, 0])]
+
+            # Create figure
+            num_plots = 4
+            f, _ = plt.subplots(2,1, figsize=(8, 12))
+            ax = plt.subplot(num_plots,1,1)
+            ax.set_title('Plot performance summary')
+
+            create_ax_dumbbell(ax, data_started_ended)
+
+            ax = plt.subplot(num_plots,1,2)
+            create_ax_plotrate(ax, data_started_ended, end=True, window=3)
+
+            ax = plt.subplot(num_plots,1,3)
+            create_ax_plottime(ax, data_started_ended, window=3)
+
+            ax = plt.subplot(num_plots,1,4)
+            create_ax_plotcumulative(ax, data_started_ended)
+
+            print('Saving analysis figure to {}'.format(figfile))
+            ax.set_xlabel('Time (hours)')
+            f.savefig(figfile)
+
     # Prepare report
     tab = tt.Texttable()
     all_measures = ['%usort', 'phase 1', 'phase 2', 'phase 3', 'phase 4', 'total time']

src/plotman/plotman.py

@@ -72,8 +72,12 @@ def parse_args(self):
         p_analyze.add_argument('--bybitfield',
                 action='store_true',
                 help='slice by bitfield/non-bitfield sorting')
-        p_analyze.add_argument('logfile', type=str, nargs='+',
+        p_analyze.add_argument('--logfile', type=str, nargs='+', default=None,
                 help='logfile(s) to analyze')
+        p_analyze.add_argument('--logdir', type=str, default=None,
+                help='directory containing multiple logfiles to analyze')
+        p_analyze.add_argument('--figfile', type=str, default=None,
+                help='figure to be created if logdir is passed')
 
         args = parser.parse_args()
         return args
@@ -155,9 +159,14 @@ def main():
     # Analysis of completed jobs
     #
     elif args.cmd == 'analyze':
-
-        analyzer.analyze(args.logfile, args.clipterminals,
-                args.bytmp, args.bybitfield)
+        if args.logfile is not None:
+            analyzer.analyze(args.logfile, args.clipterminals,
+                    args.bytmp, args.bybitfield, args.figfile)
+        elif args.logdir is not None:
+            analyzer.analyze(args.logdir, args.clipterminals,
+                    args.bytmp, args.bybitfield, args.figfile)
+        else:
+            raise RuntimeError('Must pass a log file (--logfile) or a directory containing multiple log files (--logdir)')
 
     else:
         jobs = Job.get_running_jobs(cfg.directories.log)