Merge branch 'master' into fixed-injections

post-process.py

 #!/usr/bin/env python
 """
 Usage:
-    post-process.py [options] output-log
+    post-process.py [options] output-log matched-log
 
-Match the sends and recvs across the ranks and output a unified log.
+Match the sends and recvs across the ranks so that the timings for message
+completion can be checked. This is written to the file matched_log.  Also
+produces simple report of some interesting values and produces plots comparing
+various timings.
 
 This file is part of SWIFT.
 
@@ -24,6 +27,11 @@ You should have received a copy of the GNU Lesser General Public License
 along with this program.  If not, see <http://www.gnu.org/licenses/>.
 """
 
+import matplotlib
+#matplotlib.use("Agg")
+import matplotlib.pyplot as plt
+import numpy
+import pylab as pl
 import sys
 import argparse
 
@@ -33,6 +41,9 @@ parser = argparse.ArgumentParser(description="Match MPI reports")
 parser.add_argument(
     "input",
     help="Output log from simulator")
+parser.add_argument(
+    "output",
+    help="Matched entries from the input data")
 parser.add_argument(
     "-v",
     "--verbose",
@@ -43,6 +54,7 @@ parser.add_argument(
 )
 args = parser.parse_args()
 infile = args.input
+outfile = args.output
 
 #  Indices for words in a line.
 logticcol=0
@@ -63,8 +75,14 @@ mincol=14
 maxcol=15
 
 #  Keyed lines.
-sends = {}
-recvs = {}
+keysends = {}
+keyrecvs = {}
+
+#  Indexed lines.
+sends = []
+recvs = []
+nsends = 0
+nrecvs = 0
 
 #  Gather keys from the input log. We created dicts with matchable keys
 #  for when sends start and recvs end. Other pairings are possible...
@@ -80,10 +98,12 @@ with open(infile, "r") as fp:
                   words[isubtypecol] + "/" + \
                   words[tagcol] + "/" + \
                   words[sizecol]
-            if not key in sends:
-                sends[key] = [line[:-1]]
+            if not key in keysends:
+                keysends[key] = [nsends]
             else:
-                sends[key].append(line[:-1])
+                keysends[key].append(nsends)
+            sends.append(words)
+            nsends = nsends + 1
 
         elif words[itypecol] == "23":
             key = words[rankcol] + "/" + \
@@ -91,21 +111,68 @@ with open(infile, "r") as fp:
                   words[isubtypecol] + "/" + \
                   words[tagcol] + "/" + \
                   words[sizecol]
-            if not key in recvs:
-                recvs[key] = [line[:-1]]
+            if not key in keyrecvs:
+                keyrecvs[key] = [nrecvs]
             else:
-                recvs[key].append(line[:-1])
+                keyrecvs[key].append(nrecvs)
+            recvs.append(words)
+            nrecvs = nrecvs + 1
 
 #  Now output. Note we could have unmatched recv keys, we don't check for that.
-print "# send_logticin send_logtic send_injtic send_endtic send_dtic send_step send_rank send_otherrank send_itype send_isubtype send_tag send_size send_nr_tests send_tsum send_tmin send_tmax recv_logticin recv_logtic recv_injtic recv_endtic recv_dtic recv_step recv_rank recv_otherrank recv_itype recv_isubtype recv_tag recv_size recv_nr_tests recv_tsum recv_tmin recv_tmax"
-for key in sends:
-    if key in recvs:
-        if len(sends[key]) == 1 and len(recvs[key]) == 1:
-            print sends[key][0], recvs[key][0]
+msends = [None] * nsends
+with open(outfile, "w") as fp:
+    fp.write("# send_logticin send_logtic send_injtic send_endtic send_dtic send_step send_rank send_otherrank send_itype send_isubtype send_tag send_size send_nr_tests send_tsum send_tmin send_tmax recv_logticin recv_logtic recv_injtic recv_endtic recv_dtic recv_step recv_rank recv_otherrank recv_itype recv_isubtype recv_tag recv_size recv_nr_tests recv_tsum recv_tmin recv_tmax\n")
+    for key in keysends:
+        if key in keyrecvs:
+            if len(keysends[key]) == 1 and len(keyrecvs[key]) == 1:
+                isend = keysends[key][0]
+                irecv = keyrecvs[key][0]
+                msends[isend] = irecv
+                fp.write(" ".join(sends[isend]) + " " + " ".join(recvs[irecv]) + "\n")
+            else:
+                print "# ERROR: found ", len(keysends[key]), "/", len(keyrecvs[key]), " matches for key: ", key, " should be 1/1"
         else:
-            print "# ERROR: found ", len(sends[key]), "/", len(recvs[key]), " matches for key: ", key, " should be 1/1"
-    else:
-        print "# ERROR: missing recv key: ", key
-
+            print "# ERROR: missing recv key: ", key
+
+print "# Matched sends and recvs written to file: ", outfile
+
+# Reorder recvs to same order as sends.
+recvs = [recvs[i] for i in msends]
+
+# Do a plot. Display and saves the graphic, uncomment the "Agg" line above to just save.
+def doplot(x, y, xlabel, ylabel, title, outpng):
+    axmax1 = max(x)
+    axmax2 = max(y)
+    axmax = max([axmax1, axmax2])
+    fig,ax = plt.subplots()
+    ax.set_xlim(0,axmax)
+    ax.set_ylim(0,axmax)
+    ax.plot(x, y, ',')
+    ax.set_xlabel(xlabel)
+    ax.set_ylabel(ylabel)
+    ax.set_title("SWIFTmpistepsim plot: " + title)
+    fig.tight_layout()
+    plt.savefig(outpng,  bbox_inches="tight")
+    print "# Saved plot to: ", outpng
+    plt.show()
+
+#  Plot no. 1: sends injection time against time of local handoff.
+send_injects = [float(send[injcol]) for send in [line for line in sends]]
+send_ends = [float(send[endcol]) for send in [line for line in sends]]
+doplot(send_injects, send_ends, "Message start time",
+       "Message local completion time", "local send completions",
+       "local_sends.png")
+
+#  Plot no. 2: recv injection time against time of local handoff.
+recv_injects = [float(recv[injcol]) for recv in [line for line in recvs]]
+recv_ends = [float(recv[endcol]) for recv in [line for line in recvs]]
+doplot(recv_injects, recv_ends, "Message start time",
+       "Message local completion time", "local recv completions",
+       "local_recvs.png")
+
+#  Plot no. 3: send injection time against time of remote completion.
+doplot(send_injects, recv_ends, "Message start time",
+       "Global message completion time", "message completion times",
+       "completions.png")
 
 sys.exit(0)

swiftmpistepsim.c

@@ -110,6 +110,7 @@ static void *inject_thread(void *arg) {
     /* Differences to SWIFT: MPI_BYTE not the MPI_Type. */
     int err = 0;
     if (log->type == task_type_send) {
+      log->data = calloc(log->size, 1);
       err = MPI_Isend(log->data, log->size, MPI_BYTE, log->otherrank, log->tag,
                       subtypeMPI_comms[log->subtype], &log->req);
 
@@ -119,6 +120,7 @@ static void *inject_thread(void *arg) {
       atomic_inc(&todo_send);
 
     } else {
+      log->data = calloc(log->size, 1);
       err = MPI_Irecv(log->data, log->size, MPI_BYTE, log->otherrank, log->tag,
                       subtypeMPI_comms[log->subtype], &log->req);
 
@@ -307,7 +309,7 @@ static void pick_logs(void) {
       nlogs, sizeof(struct mpiuse_log_entry *));
   nr_reqs = 0;
   sends_queue = (struct mpiuse_log_entry **)calloc(
-      nlogs, sizeof(struct mpiuse_log_entry *) * nlogs);
+      nlogs, sizeof(struct mpiuse_log_entry *));
   nr_sends = 0;
   recvs_queue = (struct mpiuse_log_entry **)calloc(
       nlogs, sizeof(struct mpiuse_log_entry *));
@@ -318,10 +320,8 @@ static void pick_logs(void) {
     if (log->rank == myrank && log->activation) {
       if (log->type == task_type_send || log->type == task_type_recv) {
 
-        /* Allocate space for data. */
-        log->data = calloc(log->size, 1);
-
         /* And keep this log. */
+        log->data = NULL;
         reqs_queue[nr_reqs] = log;
         nr_reqs++;