diff options
author | Erik Schnetter <schnetter@cct.lsu.edu> | 2006-07-31 15:26:00 +0000 |
---|---|---|
committer | Erik Schnetter <schnetter@cct.lsu.edu> | 2006-07-31 15:26:00 +0000 |
commit | 2f54810c8c9450e7c4d7e00f6beb97759f20c179 (patch) | |
tree | c9855ec140091c8f239f0438b0c0a6daa6912c80 /Carpet/CarpetLib | |
parent | 3c9fceb2947be6d35e1178bdca8c2d73d31b5862 (diff) |
CarpetLib: Extend timing statistics
Add timers for the new communication infrastructure.
Enhance the timers to also track the minimum and maximum time spent.
Add a parameter to output timing information to files.
darcs-hash:20060731152618-dae7b-1d049b2b37397610c14648078fd0ee92f252ca2a.gz
Diffstat (limited to 'Carpet/CarpetLib')
-rw-r--r-- | Carpet/CarpetLib/param.ccl | 6 | ||||
-rw-r--r-- | Carpet/CarpetLib/src/commstate.cc | 14 | ||||
-rw-r--r-- | Carpet/CarpetLib/src/gdata.cc | 11 | ||||
-rw-r--r-- | Carpet/CarpetLib/src/timestat.cc | 93 | ||||
-rw-r--r-- | Carpet/CarpetLib/src/timestat.hh | 12 |
5 files changed, 101 insertions, 35 deletions
diff --git a/Carpet/CarpetLib/param.ccl b/Carpet/CarpetLib/param.ccl index c21fa38f1..54501823e 100644 --- a/Carpet/CarpetLib/param.ccl +++ b/Carpet/CarpetLib/param.ccl @@ -35,6 +35,12 @@ BOOLEAN print_timestats "Print timing statistics at every iteration" STEERABLE=a { } "no" +INT print_timestats_every "Print timing statistics periodically" STEERABLE=always +{ + 0 :: "don't report" + 1:* :: "report every so many iterations" +} 0 + BOOLEAN save_memory_during_regridding "Save some memory during regridding at the expense of speed" STEERABLE=always { } "yes" diff --git a/Carpet/CarpetLib/src/commstate.cc b/Carpet/CarpetLib/src/commstate.cc index fa0e833c9..ec4bbf667 100644 --- a/Carpet/CarpetLib/src/commstate.cc +++ b/Carpet/CarpetLib/src/commstate.cc @@ -7,6 +7,12 @@ #include "vect.hh" #include "commstate.hh" +#include "timestat.hh" + + + +using namespace std; + // Communication state control @@ -89,9 +95,11 @@ void comm_state::step () procbuf.recvbuf = procbuf.recvbufbase; if (procbuf.recvbufsize > 0) { + wtime_commstate_sizes_irecv.start(); MPI_Irecv (procbuf.recvbufbase, procbuf.recvbufsize, typebufs[type].mpi_datatype, proc, type, dist::comm(), &rrequests[dist::size()*type + proc]); + wtime_commstate_sizes_irecv.stop(); num_posted_recvs++; } } @@ -163,7 +171,9 @@ bool comm_state::AllPostedCommunicationsFinished () // check if all outstanding receives have been completed already if (num_posted_recvs == num_completed_recvs) { // finalize the outstanding sends in one go + wtime_commstate_waitall_final.start(); MPI_Waitall (srequests.size(), &srequests.front(), MPI_STATUSES_IGNORE); + wtime_commstate_waitall_final.stop(); return true; } @@ -178,15 +188,19 @@ bool comm_state::AllPostedCommunicationsFinished () } // wait for completion of all posted receive operations + wtime_commstate_waitall.start(); MPI_Waitall (rrequests.size(), &rrequests.front(), MPI_STATUSES_IGNORE); + wtime_commstate_waitall.stop(); num_completed_recvs = num_posted_recvs; } else { int num_completed_recvs_ = 0; vector<int> completed_recvs(rrequests.size(), -1); // wait for completion of at least one posted receive operation + wtime_commstate_waitsome.start(); MPI_Waitsome (rrequests.size(), &rrequests.front(), &num_completed_recvs_, &completed_recvs.front(), MPI_STATUSES_IGNORE); + wtime_commstate_waitsome.stop(); assert (0 < num_completed_recvs_); num_completed_recvs += num_completed_recvs_; diff --git a/Carpet/CarpetLib/src/gdata.cc b/Carpet/CarpetLib/src/gdata.cc index 97896639d..428eb6871 100644 --- a/Carpet/CarpetLib/src/gdata.cc +++ b/Carpet/CarpetLib/src/gdata.cc @@ -316,6 +316,7 @@ void gdata::copy_into_sendbuffer (comm_state& state, state.typebufs.at(c_datatype()).mpi_datatype, proc(), c_datatype(), dist::comm(), &state.srequests.at(dist::size()*c_datatype() + proc())); + wtime_commstate_isend.stop(); } } } @@ -338,6 +339,7 @@ void gdata::copy_from_recvbuffer (comm_state& state, ivect items = (box.upper() - box.lower()) / box.stride() + 1; ivect offs = (box.lower() - ext.lower()) / ext.stride(); + wtime_commstate_memcpy.start(); assert (dim == 3); for (int k = 0; k < items[2]; k++) { for (int j = 0; j < items[1]; j++) { @@ -347,6 +349,7 @@ void gdata::copy_from_recvbuffer (comm_state& state, procbuf.recvbuf += datatypesize * items[0]; } } + wtime_commstate_memcpy.stop(); } @@ -453,8 +456,10 @@ void gdata comm_state::gcommbuf * b = make_typed_commbuf (box); + wtime_commstate_interpolate_irecv.start(); MPI_Irecv (b->pointer(), b->size(), b->datatype(), src->proc(), tag, dist::comm(), &b->request); + wtime_commstate_interpolate_irecv.stop(); state.requests.push_back (b->request); state.recvbufs.push (b); } else { @@ -468,8 +473,10 @@ void gdata order_space, order_time); delete tmp; + wtime_commstate_interpolate_from_isend.start(); MPI_Isend (b->pointer(), b->size(), b->datatype(), proc(), tag, dist::comm(), &b->request); + wtime_commstate_interpolate_from_isend.stop(); state.requests.push_back (b->request); state.sendbufs.push (b); } @@ -516,11 +523,13 @@ void gdata procbuf.sendbuf += datatypesize * box.size(); // post the send if the buffer is full - if (fillstate == procbuf.sendbufsize*datatypesize) { + if (fillstate == (int)procbuf.sendbufsize*datatypesize) { + wtime_commstate_interpolate_to_isend.start(); MPI_Isend (procbuf.sendbufbase, procbuf.sendbufsize, state.typebufs.at(c_datatype()).mpi_datatype, proc(), c_datatype(), dist::comm(), &state.srequests.at(dist::size()*c_datatype() + proc())); + wtime_commstate_interpolate_to_isend.stop(); } } } diff --git a/Carpet/CarpetLib/src/timestat.cc b/Carpet/CarpetLib/src/timestat.cc index 86767cff4..f5116481f 100644 --- a/Carpet/CarpetLib/src/timestat.cc +++ b/Carpet/CarpetLib/src/timestat.cc @@ -18,7 +18,7 @@ using namespace std; timestat::timestat () - : wtime(0.0), wtime2(0.0), count(0.0), + : wtime(0.0), wtime2(0.0), wmin(0.0), wmax(0.0), count(0.0), running(false) { } @@ -27,6 +27,8 @@ void timestat::addstat (double const t) { wtime += t; wtime2 += t*t; + wmin = min (wmin, t); + wmax = max (wmax, t); ++count; } @@ -50,12 +52,14 @@ void timestat::stop () ostream& operator<< (ostream& os, const timestat& wt) { double const avg = wt.wtime / wt.count; - double const stddev = sqrt(max(0.0, wt.wtime2 / wt.count - avg * avg)); + double const stddev = sqrt (max (0.0, wt.wtime2 / wt.count - pow (avg, 2))); os << "timestat[seconds]:" << " cnt: " << wt.count << " sum: " << wt.wtime << " avg: " << avg - << " stddev: " << stddev; + << " stddev: " << stddev + << " min: " << wt.wmin + << " max: " << wt.wmax; return os; } @@ -95,6 +99,16 @@ timestat wtime_isend; timestat wtime_isendwait; timestat wtime_irecvwait; +timestat wtime_commstate_sizes_irecv; +timestat wtime_commstate_waitall_final; +timestat wtime_commstate_waitall; +timestat wtime_commstate_waitsome; +timestat wtime_commstate_isend; +timestat wtime_commstate_memcpy; +timestat wtime_commstate_interpolate_irecv; +timestat wtime_commstate_interpolate_from_isend; +timestat wtime_commstate_interpolate_to_isend; + extern "C" void CarpetLib_printtimestats (CCTK_ARGUMENTS); @@ -103,41 +117,54 @@ void CarpetLib_printtimestats (CCTK_ARGUMENTS) { DECLARE_CCTK_ARGUMENTS; DECLARE_CCTK_PARAMETERS; - if (print_timestats) { + if (print_timestats or + (print_timestats_every and + cctk_iteration % print_timestats_every == 0)) + { cout << "Timing statistics from CarpetLib:" << endl - << " wtime_copyfrom_recv: " << wtime_copyfrom_recv << endl - << " wtime_copyfrom_send: " << wtime_copyfrom_send << endl - << " wtime_copyfrom_wait: " << wtime_copyfrom_wait << endl + << " wtime_copyfrom_recv: " << wtime_copyfrom_recv << endl + << " wtime_copyfrom_send: " << wtime_copyfrom_send << endl + << " wtime_copyfrom_wait: " << wtime_copyfrom_wait << endl + << endl + << " wtime_copyfrom_recv_maketyped: " << wtime_copyfrom_recv_maketyped << endl + << " wtime_copyfrom_recv_allocate: " << wtime_copyfrom_recv_allocate << endl + << " wtime_copyfrom_recv_changeproc_recv: " << wtime_copyfrom_recv_changeproc_recv << endl + << " wtime_copyfrom_send_copyfrom_nocomm1: " << wtime_copyfrom_send_copyfrom_nocomm1 << endl + << " wtime_copyfrom_send_copyfrom_nocomm2: " << wtime_copyfrom_send_copyfrom_nocomm2 << endl + << " wtime_copyfrom_send_changeproc_send: " << wtime_copyfrom_send_changeproc_send << endl + << " wtime_copyfrom_wait_changeproc_wait: " << wtime_copyfrom_wait_changeproc_wait << endl + << " wtime_copyfrom_wait_copyfrom_nocomm2: " << wtime_copyfrom_wait_copyfrom_nocomm << endl + << " wtime_copyfrom_wait_delete: " << wtime_copyfrom_wait_delete << endl << endl - << " wtime_copyfrom_recv_maketyped: " << wtime_copyfrom_recv_maketyped << endl - << " wtime_copyfrom_recv_allocate: " << wtime_copyfrom_recv_allocate << endl - << " wtime_copyfrom_recv_changeproc_recv: " << wtime_copyfrom_recv_changeproc_recv << endl - << " wtime_copyfrom_send_copyfrom_nocomm1: " << wtime_copyfrom_send_copyfrom_nocomm1 << endl - << " wtime_copyfrom_send_copyfrom_nocomm2: " << wtime_copyfrom_send_copyfrom_nocomm2 << endl - << " wtime_copyfrom_send_changeproc_send: " << wtime_copyfrom_send_changeproc_send << endl - << " wtime_copyfrom_wait_changeproc_wait: " << wtime_copyfrom_wait_changeproc_wait << endl - << " wtime_copyfrom_wait_copyfrom_nocomm2: " << wtime_copyfrom_wait_copyfrom_nocomm << endl - << " wtime_copyfrom_wait_delete: " << wtime_copyfrom_wait_delete << endl + << " wtime_copyfrom_recvinner_allocate: " << wtime_copyfrom_recvinner_allocate << endl + << " wtime_copyfrom_recvinner_recv: " << wtime_copyfrom_recvinner_recv << endl + << " wtime_copyfrom_sendinner_allocate: " << wtime_copyfrom_sendinner_allocate << endl + << " wtime_copyfrom_sendinner_copy: " << wtime_copyfrom_sendinner_copy << endl + << " wtime_copyfrom_sendinner_send: " << wtime_copyfrom_sendinner_send << endl + << " wtime_copyfrom_recvwaitinner_wait: " << wtime_copyfrom_recvwaitinner_wait << endl + << " wtime_copyfrom_recvwaitinner_copy: " << wtime_copyfrom_recvwaitinner_copy << endl + << " wtime_copyfrom_recvwaitinner_delete: " << wtime_copyfrom_recvwaitinner_delete << endl + << " wtime_copyfrom_sendwaitinner_wait: " << wtime_copyfrom_sendwaitinner_wait << endl + << " wtime_copyfrom_sendwaitinner_delete: " << wtime_copyfrom_sendwaitinner_delete << endl << endl - << " wtime_copyfrom_recvinner_allocate: " << wtime_copyfrom_recvinner_allocate << endl - << " wtime_copyfrom_recvinner_recv: " << wtime_copyfrom_recvinner_recv << endl - << " wtime_copyfrom_sendinner_allocate: " << wtime_copyfrom_sendinner_allocate << endl - << " wtime_copyfrom_sendinner_copy: " << wtime_copyfrom_sendinner_copy << endl - << " wtime_copyfrom_sendinner_send: " << wtime_copyfrom_sendinner_send << endl - << " wtime_copyfrom_recvwaitinner_wait: " << wtime_copyfrom_recvwaitinner_wait << endl - << " wtime_copyfrom_recvwaitinner_copy: " << wtime_copyfrom_recvwaitinner_copy << endl - << " wtime_copyfrom_recvwaitinner_delete: " << wtime_copyfrom_recvwaitinner_delete << endl - << " wtime_copyfrom_sendwaitinner_wait: " << wtime_copyfrom_sendwaitinner_wait << endl - << " wtime_copyfrom_sendwaitinner_delete: " << wtime_copyfrom_sendwaitinner_delete << endl + << " wtime_changeproc_recv: " << wtime_changeproc_recv << endl + << " wtime_changeproc_send: " << wtime_changeproc_send << endl + << " wtime_changeproc_wait: " << wtime_changeproc_wait << endl << endl - << " wtime_changeproc_recv: " << wtime_changeproc_recv << endl - << " wtime_changeproc_send: " << wtime_changeproc_send << endl - << " wtime_changeproc_wait: " << wtime_changeproc_wait << endl + << " wtime_irecv: " << wtime_irecv << endl + << " wtime_isend: " << wtime_isend << endl + << " wtime_isendwait: " << wtime_isendwait << endl + << " wtime_irecvwait: " << wtime_irecvwait << endl << endl - << " wtime_irecv: " << wtime_irecv << endl - << " wtime_isend: " << wtime_isend << endl - << " wtime_isendwait: " << wtime_isendwait << endl - << " wtime_irecvwait: " << wtime_irecvwait << endl + << " wtime_commstate_sizes_irecv: " << wtime_commstate_sizes_irecv << endl + << " wtime_commstate_waitall_final: " << wtime_commstate_waitall_final << endl + << " wtime_commstate_waitall: " << wtime_commstate_waitall << endl + << " wtime_commstate_waitsome: " << wtime_commstate_waitsome << endl + << " wtime_commstate_isend: " << wtime_commstate_isend << endl + << " wtime_commstate_memcpy: " << wtime_commstate_memcpy << endl + << " wtime_commstate_interpolate_irecv: " << wtime_commstate_interpolate_irecv << endl + << " wtime_commstate_interpolate_from_isend: " << wtime_commstate_interpolate_from_isend << endl + << " wtime_commstate_interpolate_to_isend: " << wtime_commstate_interpolate_to_isend << endl << endl; } } diff --git a/Carpet/CarpetLib/src/timestat.hh b/Carpet/CarpetLib/src/timestat.hh index 11a7a00aa..896b94236 100644 --- a/Carpet/CarpetLib/src/timestat.hh +++ b/Carpet/CarpetLib/src/timestat.hh @@ -13,6 +13,8 @@ class timestat { public: double wtime; double wtime2; + double wmin; + double wmax; double count; public: @@ -68,6 +70,14 @@ extern timestat wtime_isend; extern timestat wtime_irecvwait; extern timestat wtime_isendwait; - +extern timestat wtime_commstate_sizes_irecv; +extern timestat wtime_commstate_waitall_final; +extern timestat wtime_commstate_waitall; +extern timestat wtime_commstate_waitsome; +extern timestat wtime_commstate_isend; +extern timestat wtime_commstate_memcpy; +extern timestat wtime_commstate_interpolate_irecv; +extern timestat wtime_commstate_interpolate_from_isend; +extern timestat wtime_commstate_interpolate_to_isend; #endif // TIMESTAT_HH |