diff --git a/Makefile b/Makefile index a80360021e3e500d7559aa85ca0433765545e4c1..0e9fb5aabe26faf197833696d39c503a649721ce 100644 --- a/Makefile +++ b/Makefile @@ -1,10 +1,10 @@ all: mpistalls mpistalls-timed -mpistalls: mpistalls.c mpiuse.c mpiuse.h atomic.h cycle.h - $(CC) -g -O0 -o mpistalls mpistalls.c mpiuse.c -I/usr/include/mpi -lmpi -lpthread +mpistalls: mpistalls.c mpiuse.c mpiuse.h atomic.h cycle.h clocks.h clocks.c + $(CC) -g -O0 -Wall -o mpistalls mpistalls.c mpiuse.c clocks.c -I/usr/include/mpi -lmpi -lpthread mpistalls-timed: mpistalls-timed.c mpiuse.c mpiuse.h atomic.h cycle.h clocks.h clocks.c - $(CC) -g -O0 -o mpistalls-timed mpistalls-timed.c mpiuse.c clocks.c -I/usr/include/mpi -lmpi -lpthread + $(CC) -g -O0 -Wall -o mpistalls-timed mpistalls-timed.c mpiuse.c clocks.c -I/usr/include/mpi -lmpi -lpthread clean: rm mpistalls mpistalls-timed diff --git a/clocks.c b/clocks.c index ca592650815e0edf88e279c9025a62bab9ac3f31..9e88ec31f749c3001318cf64272c985d67dc1714 100644 --- a/clocks.c +++ b/clocks.c @@ -210,7 +210,7 @@ const char *clocks_getunit(void) { return clocks_units[clocks_units_index]; } * * Need to call clocks_set_cpufreq() to mark the start of execution. * - * The time is return in the format [sssss.s]. + * The time is return in the format [ssss.sss]. * * @result the time since the start of the execution */ @@ -218,7 +218,7 @@ const char *clocks_get_timesincestart(void) { static char buffer[40]; - sprintf(buffer, "[%07.1f]", + sprintf(buffer, "[%07.3f]", clocks_diff_ticks(getticks(), clocks_start_ticks) / 1000.0); return buffer; diff --git a/error.h b/error.h index 05bc9fa80b6bc74acf571b6054fc84f0013091e3..c3b9a11b5d970816a9423361977ba83ece367adb 100644 --- a/error.h +++ b/error.h @@ -1,18 +1,21 @@ #include <mpi.h> +#include "clocks.h" extern int myrank; /* Exit in error macro. */ -#define error(s, ...) \ +#define error(s, ...) \ ({ \ fflush(stdout); \ - fprintf(stderr, "%d/ %s:%s():%i: " s "\n", myrank, __FILE__, __FUNCTION__, \ - __LINE__, ##__VA_ARGS__); \ + fprintf(stderr, "[%03i] %s %s:%s():%i: " s "\n", myrank, \ + clocks_get_timesincestart(), \ + __FILE__, __FUNCTION__, __LINE__, ##__VA_ARGS__); \ MPI_Abort(MPI_COMM_WORLD, -1); \ }) /* Print a message */ -#define message(s, ...) \ +#define message(s, ...) \ ({ \ - printf("%d/ %s: " s "\n", myrank, __FUNCTION__, ##__VA_ARGS__); \ + printf("[%04i] %s %s: " s "\n", myrank, \ + clocks_get_timesincestart(),__FUNCTION__, ##__VA_ARGS__); \ }) diff --git a/mpistalls-timed.c b/mpistalls-timed.c index 9146c14a32fea6bd96217e7491f6f0c8ff252771..25888e134891f84d6b6d37afb509964e3e29222d 100644 --- a/mpistalls-timed.c +++ b/mpistalls-timed.c @@ -21,6 +21,9 @@ /* Global: Our rank for all to see. */ int myrank = -1; +/* Are we verbose. */ +static int verbose = 0; + /* Integer types of send and recv tasks, must match log. */ static const int task_type_send = 22; static const int task_type_recv = 23; @@ -43,29 +46,34 @@ static int volatile nr_sends = 0; static int volatile ind_send = 0; static int volatile todo_send = 0; -/* Delta tics that we do not wait for. XXX measure this. */ -const ticks looptics = 10000; - /* CPU frequency of the machine that created the MPI log. */ // XXX need to store this in the data file. static double clocks_cpufreq = 2194844448.0; -/* Injection thread, initiates MPI_Isend and MPI_Irecv requests at various - * times. */ +/** + * @brief Injection thread, initiates MPI_Isend and MPI_Irecv requests. + * + * The requests are initiated in the time order of the original log and an + * attempt to start these with the same interval gap is made. + */ static void *inject_thread(void *arg) { - message("%d: injection thread starts", *((int *)arg)); + + if (verbose) + message("%d: injection thread starts", *((int *)arg)); ticks starttics = getticks(); /* Ticks of our last attempt. */ ticks basetic = reqs_queue[0]->tic; + /* The time that once around this loop takes. We do not wait for injections + * that are closer in time than this value. */ + ticks looptics = 0; + while (ind_req < nr_reqs) { struct mpiuse_log_entry *log = reqs_queue[ind_req]; /* Expect time between this request and the previous one. */ ticks dt = log->tic - basetic; - double ddt = (double)log->tic - (double)basetic; - ticks oldbasetic = basetic; basetic = log->tic; /* Guess some time below which we should not attempt to wait, otherwise @@ -113,26 +121,41 @@ static void *inject_thread(void *arg) { if (err != MPI_SUCCESS) error("Failed to activate send or recv"); ind_req++; + + /* Set looptics on the first pass. Assumes MPI_Isend and MPI_Irecv are + * equally timed. */ + if (looptics == 0) { + looptics = starttics - getticks(); + if (verbose) + message("injection loop took %.3f %s.", clocks_from_ticks(looptics), + clocks_getunit()); + } + } + + /* All done, thread exiting. */ + if (verbose) { + message("%d injections completed, sends = %d, recvs = %d", ind_req, + nr_sends, nr_recvs); + message("remaining sends = %d, recvs = %d", todo_send, todo_recv); } - message("%d injections completed, sends = %d, recvs = %d", ind_req, - nr_sends, nr_recvs); - message("remaining sends = %d, recvs = %d", todo_send, todo_recv); message("took %.3f %s.", clocks_from_ticks(getticks() - starttics), clocks_getunit()); atomic_dec(&injecting); return NULL; } -/* Send thread, checks if MPI_Isend requests have completed. */ +/** + * @brief Send thread, checks if MPI_Isend requests have completed. + */ static void *send_thread(void *arg) { - message("%d: send thread starts (%d)", *((int *)arg), injecting); + + if (verbose) + message("%d: send thread starts (%d)", *((int *)arg), injecting); ticks starttics = getticks(); - int res; - MPI_Status stat; - // Need a test that only exits when requests are all inserted and we have - // emptied our queue. */ + /* We loop while new requests are being injected and then when we still have + * sends to complete. */ size_t attempts = 0; while (injecting || (!injecting && todo_send > 0)) { int nsends = nr_sends; @@ -140,13 +163,15 @@ static void *send_thread(void *arg) { struct mpiuse_log_entry *log = sends_queue[k]; if (log != NULL) { attempts++; + int res; + MPI_Status stat; int err = MPI_Test(&log->req, &res, &stat); if (err != MPI_SUCCESS) { error("MPI_Test call failed"); } if (res) { + /* Done, clean up. */ - //message("MPI_Test successful"); free(log->data); sends_queue[k] = NULL; atomic_dec(&todo_send); @@ -154,21 +179,27 @@ static void *send_thread(void *arg) { } } } - message("sends completed, required %zd attempts (left: %d)", attempts, - todo_send); + + /* All done, thread exiting. */ + if (verbose) + message("sends completed, required %zd attempts (left: %d)", attempts, + todo_send); message("took %.3f %s.", clocks_from_ticks(getticks() - starttics), clocks_getunit()); return NULL; } -/* Recv thread, checks if MPI_Irecv requests have completed. */ +/** + * @brief Recv thread, checks if MPI_Irecv requests have completed. + */ static void *recv_thread(void *arg) { - message("%d: recv thread starts", *((int *)arg)); - ticks starttics = getticks(); - int res; - MPI_Status stat; + if (verbose) + message("%d: recv thread starts", *((int *)arg)); + ticks starttics = getticks(); + /* We loop while new requests are being injected and then when we still have + * recvs to complete. */ size_t attempts = 0; while (injecting || (!injecting && todo_recv > 0)) { int nrecvs = nr_recvs; @@ -176,13 +207,15 @@ static void *recv_thread(void *arg) { struct mpiuse_log_entry *log = recvs_queue[k]; if (log != NULL) { attempts++; + int res; + MPI_Status stat; int err = MPI_Test(&log->req, &res, &stat); if (err != MPI_SUCCESS) { error("MPI_Test call failed"); } if (res) { + /* Done, clean up. */ - //message("MPI_Test successful"); free(log->data); recvs_queue[k] = NULL; atomic_dec(&todo_recv); @@ -191,14 +224,18 @@ static void *recv_thread(void *arg) { } } - message("recvs completed, required %zd attempts (left: %d)", attempts, - todo_recv); + /* All done, thread exiting. */ + if (verbose) + message("recvs completed, required %zd attempts (left: %d)", attempts, + todo_recv); message("took %.3f %s.", clocks_from_ticks(getticks() - starttics), clocks_getunit()); return NULL; } -/* Comparison function for logged times. */ +/** + * @brief Comparison function for logged times. + */ static int cmp_logs(const void *p1, const void *p2) { struct mpiuse_log_entry *l1 = *(struct mpiuse_log_entry **)p1; struct mpiuse_log_entry *l2 = *(struct mpiuse_log_entry **)p2; @@ -211,13 +248,15 @@ static int cmp_logs(const void *p1, const void *p2) { return 0; } -/* Pick out the relevant logging data for our rank, i.e. all activations of - * sends and recvs. */ +/** + * @brief Pick out the relevant logging data for our rank, i.e. all + * activations of sends and recvs. We ignore the original completions. + * The final list is sorted into increasing time of activation. + */ static void pick_logs(void) { size_t nlogs = mpiuse_nr_logs(); - int nranks = mpiuse_nr_ranks(); - /* Duplicate of logs. XXX could loop twice to reduce memory use if needed. */ + /* Duplicate of logs. */ reqs_queue = (struct mpiuse_log_entry **) malloc(sizeof(struct mpiuse_log_entry *) * nlogs); nr_reqs= 0; @@ -250,12 +289,16 @@ static void pick_logs(void) { qsort(reqs_queue, nr_reqs, sizeof(struct mpiuse_log_entry *), cmp_logs); } + +/** + * @brief main function. + */ int main(int argc, char *argv[]) { /* First we read the SWIFT MPI logger output that defines the communcations * we will undertake and the time differences between injections into the * queues. */ - mpiuse_log_restore("testdata/mpiuse_report-step1.dat"); + mpiuse_log_restore("testdata/mpiuse_report-step1062.dat"); int nranks = mpiuse_nr_ranks(); /* Initiate MPI. */ @@ -286,9 +329,12 @@ int main(int argc, char *argv[]) { /* Each rank requires its own queue, so extract them. */ pick_logs(); - /* Start time. */ - message("Start of MPI tests"); + /* Time to start time. */ clocks_set_cpufreq(0); + if (myrank == 0) { + message("Start of MPI tests"); + message("=================="); + } /* Make three threads, one for injecting tasks and two to check for * completions of the sends and recv independently. */ @@ -311,6 +357,7 @@ int main(int argc, char *argv[]) { res = MPI_Finalize(); if (res != MPI_SUCCESS) error("call to MPI_Finalize failed with error %i.", res); + if (myrank == 0) message("Bye"); return 0; }