Teuchos Package Browser (Single Doxygen Collection) Version of the Day
TimeMonitor_UnitTests.cpp
Go to the documentation of this file.
00001 /*
00002 // @HEADER
00003 // ***********************************************************************
00004 //
00005 //                    Teuchos: Common Tools Package
00006 //                 Copyright (2004) Sandia Corporation
00007 //
00008 // Under terms of Contract DE-AC04-94AL85000, there is a non-exclusive
00009 // license for use of this work by or on behalf of the U.S. Government.
00010 //
00011 // Redistribution and use in source and binary forms, with or without
00012 // modification, are permitted provided that the following conditions are
00013 // met:
00014 //
00015 // 1. Redistributions of source code must retain the above copyright
00016 // notice, this list of conditions and the following disclaimer.
00017 //
00018 // 2. Redistributions in binary form must reproduce the above copyright
00019 // notice, this list of conditions and the following disclaimer in the
00020 // documentation and/or other materials provided with the distribution.
00021 //
00022 // 3. Neither the name of the Corporation nor the names of the
00023 // contributors may be used to endorse or promote products derived from
00024 // this software without specific prior written permission.
00025 //
00026 // THIS SOFTWARE IS PROVIDED BY SANDIA CORPORATION "AS IS" AND ANY
00027 // EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
00028 // IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR
00029 // PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL SANDIA CORPORATION OR THE
00030 // CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL,
00031 // EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO,
00032 // PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR
00033 // PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF
00034 // LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING
00035 // NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS
00036 // SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
00037 //
00038 // Questions? Contact Michael A. Heroux (maherou@sandia.gov)
00039 //
00040 // ***********************************************************************
00041 // @HEADER
00042 */
00043 
00044 #include "Teuchos_TimeMonitor.hpp"
00045 #include "Teuchos_DefaultComm.hpp"
00046 #include "Teuchos_UnitTestHarness.hpp"
00047 
00048 namespace {
00049 
00050   void func_time_monitor1()
00051   {
00052     TEUCHOS_FUNC_TIME_MONITOR("FUNC_TIME_MONITOR1");
00053   }
00054 
00055 
00056   void func_time_monitor2()
00057   {
00058     TEUCHOS_FUNC_TIME_MONITOR("FUNC_TIME_MONITOR2");
00059     {
00060       TEUCHOS_FUNC_TIME_MONITOR_DIFF("FUNC_TIME_MONITOR2_inner", inner);
00061     }
00062   }
00063 
00064 
00065   // Slowly compute the n-th Fibonacci number.  This gives timers
00066   // something to time.  Be careful not to make n too large, or
00067   // you'll run out of stack space.
00068   int 
00069   fib (const int n) 
00070   {
00071     if (n <= 0)
00072       return 0;
00073     else if (n == 1)
00074       return 1;
00075     else
00076       // You should never compute the n-th Fibonacci number like
00077       // this.  This is exponentially slow in n.  The point of using
00078       // a slow algorithm like this is to exercise timers.
00079       return fib(n-1) + fib(n-2);
00080   }
00081 
00082   // Do a number of arithmetic operations proportional to n^3, in
00083   // order to have something to time.  Unlike fib() above, this
00084   // function shouldn't take up a lot of stack space.
00085   double
00086   slowLoop (const size_t n)
00087   {
00088     const double inc = 1 / static_cast<double> (n);
00089     double x = 1.0;
00090 
00091     for (size_t i = 0; i < n; ++i)
00092       for (size_t j = 0; j < n; ++j)
00093   for (size_t k = 0; k < n; ++k)
00094     x = x + inc;
00095 
00096     return x;
00097   }
00098 
00099 } // namespace (anonymous)
00100 
00101 
00102 namespace Teuchos {
00103 
00104 
00105   //
00106   // Basic TimeMonitor test: create and exercise a timer on all (MPI)
00107   // processes, and make sure that TimeMonitor::summarize() reports it.
00108   //
00109   TEUCHOS_UNIT_TEST( TimeMonitor, FUNC_TIME_MONITOR  )
00110   {
00111     func_time_monitor1 ();
00112     std::ostringstream oss;
00113     TimeMonitor::summarize (oss);
00114 
00115     // Echo summarize() output to the FancyOStream out (which is a
00116     // standard unit test argument).  Output should only appear in
00117     // show-all-test-details mode.
00118     out << oss.str() << std::endl;
00119 
00120     const size_t substr_i = oss.str().find ("FUNC_TIME_MONITOR1");
00121     TEST_INEQUALITY(substr_i, std::string::npos);
00122 
00123     // This sets up for the next unit test.
00124     TimeMonitor::clearTimers ();
00125   }
00126 
00127   //
00128   // TimeMonitor nested timers test: create two timers on all (MPI)
00129   // processes, use the second inside the scope of the first, and make
00130   // sure that TimeMonitor::summarize() reports both timers.
00131   //
00132   TEUCHOS_UNIT_TEST( TimeMonitor, FUNC_TIME_MONITOR_tested  )
00133   {
00134     func_time_monitor2 ();
00135     std::ostringstream oss;
00136     TimeMonitor::summarize (oss);
00137 
00138     // Echo summarize() output to the FancyOStream out (which is a
00139     // standard unit test argument).  Output should only appear in
00140     // show-all-test-details mode.
00141     out << oss.str() << std::endl;
00142 
00143     const size_t substr_i = oss.str().find ("FUNC_TIME_MONITOR2");
00144     TEST_INEQUALITY(substr_i, std::string::npos);
00145     const size_t substr_inner_i = oss.str().find ("FUNC_TIME_MONITOR2_inner");
00146     TEST_INEQUALITY(substr_inner_i, std::string::npos);
00147 
00148     // This sets up for the next unit test.
00149     TimeMonitor::clearTimers ();
00150   }
00151 
00152   //
00153   // Test whether TimeMonitor::summarize() does the right thing when
00154   // different MPI processes create different sets of timers.  This
00155   // test is only meaningful if running with more than one MPI
00156   // process, but it should also pass if running in a non-MPI build or
00157   // with only one MPI process.
00158   //
00159   TEUCHOS_UNIT_TEST( TimeMonitor, SUMMARIZE_diffTimerSets )
00160   {
00161     RCP<const Comm<int> > comm = Teuchos::DefaultComm<int>::getComm ();
00162     const int numProcs = comm->getSize ();
00163     const int myRank = comm->getRank ();
00164 
00165     // If MPI has not been initialized, turn the MPI communicator into
00166     // a "serial" communicator.  This may not be necessary when using
00167     // the Teuchos Unit Test Framework.
00168 #ifdef HAVE_MPI
00169     {
00170       int mpiHasBeenInitialized = 0;
00171       MPI_Initialized (&mpiHasBeenInitialized);
00172       if (! mpiHasBeenInitialized)
00173   comm = Teuchos::DefaultComm<int>::getDefaultSerialComm (null);
00174     }
00175 #endif // HAVE_MPI
00176 
00177     // Store the output of TimeMonitor::summarize() here.
00178     std::ostringstream oss;
00179 
00180     // Timer A gets created on all MPI processes.
00181     // Timer B only gets created on Proc 0.
00182     RCP<Time> timerA = TimeMonitor::getNewCounter ("Timer A");
00183     RCP<Time> timerB;
00184     if (myRank == 0)
00185       timerB = TimeMonitor::getNewCounter ("Timer B");
00186     else
00187       timerB = null; // True anyway, but I want to make this explicit.
00188 
00189     // The actual number of operations in the loop is proportional to
00190     // the cube of the loop length.  Adjust the quantities below as
00191     // necessary to ensure the timer reports a nonzero elapsed time
00192     // for each of the invocations.
00193     const size_t timerA_loopLength = 150;
00194     const size_t timerB_loopLength = 200;
00195 
00196     // Timer A gets a call count of 3.
00197     for (size_t k = 0; k < 3; ++k)
00198       {
00199   TimeMonitor monitorA (*timerA);
00200   slowLoop (size_t (timerA_loopLength));
00201       }
00202     if (myRank == 0)
00203       { // Timer B gets a call count of 1.
00204   TimeMonitor monitorB (*timerB);
00205   slowLoop (size_t (timerB_loopLength));
00206       }
00207 
00208     const bool alwaysWriteLocal = false; // the default
00209     const bool writeGlobalStats = true;  // the default
00210     const bool writeZeroTimers = true;  // the default
00211     TimeMonitor::summarize (oss, alwaysWriteLocal, writeGlobalStats, 
00212           writeZeroTimers, Intersection);
00213 
00214     // Echo summarize() output to the FancyOStream out (which is a
00215     // standard unit test argument).  Output should only appear in
00216     // show-all-test-details mode.
00217     out << std::endl << "Testing intersection of timers:" << std::endl
00218   << oss.str() << std::endl;
00219 
00220     // Since setOp == Intersection, only Timer A should be reported,
00221     // unless there is only one (MPI) process.
00222     size_t substr_i = oss.str().find ("Timer A");
00223     TEST_INEQUALITY(substr_i, std::string::npos);
00224     if (numProcs > 1)
00225       {
00226   substr_i = oss.str().find ("Timer B");
00227   TEST_EQUALITY(substr_i, std::string::npos);
00228       }
00229 
00230     // Now call summarize(), but ask for a union of timers.
00231     std::ostringstream ossUnion;
00232     TimeMonitor::summarize (ossUnion, alwaysWriteLocal, writeGlobalStats, 
00233           writeZeroTimers, Union);
00234 
00235     // Echo summarize() output to the FancyOStream out (which is a
00236     // standard unit test argument).  Output should only appear in
00237     // show-all-test-details mode.
00238     out << std::endl << "Testing union of timers:" << std::endl
00239   << ossUnion.str() << std::endl;
00240 
00241     // Since setOp == Union, both Timer A and Timer B should be
00242     // reported.
00243     substr_i = ossUnion.str().find ("Timer A");
00244     TEST_INEQUALITY(substr_i, std::string::npos);
00245     substr_i = ossUnion.str().find ("Timer B");
00246     TEST_INEQUALITY(substr_i, std::string::npos);
00247 
00248     // This sets up for the next unit test.
00249     TimeMonitor::clearTimers ();
00250   }  
00251 
00252   //
00253   // Test whether the option to filter out zero timers works, for the
00254   // case that all (MPI) processes have the same call counts.
00255   //
00256   TEUCHOS_UNIT_TEST( TimeMonitor, FILTER_ZERO_TIMERS_sameParallelCallCounts )
00257   {
00258     // Store the output of TimeMonitor::summarize() here.
00259     std::ostringstream oss;
00260 
00261     RCP<Time> timerA = TimeMonitor::getNewCounter ("Timer A");
00262     RCP<Time> timerB = TimeMonitor::getNewCounter ("Timer B");
00263     RCP<Time> timerC = TimeMonitor::getNewCounter ("Timer C");
00264 
00265     // Timers A and B get nonzero elapsed times and call counts on all
00266     // (MPI) processes.  Timer C never gets started, so it should have
00267     // a zero elapsed time and zero call count on all processes.
00268 
00269     // The actual number of operations in the loop is proportional to
00270     // the cube of the loop length.  Adjust the quantities below as
00271     // necessary to ensure the timer reports a nonzero elapsed time
00272     // for each of the invocations.
00273     const size_t timerA_loopLength = 200;
00274     const size_t timerB_loopLength = 250;
00275 
00276     // Timer A gets a call count of 3.
00277     for (size_t k = 0; k < 3; ++k)
00278       {
00279   TimeMonitor monitorA (*timerA);
00280   slowLoop (size_t (timerA_loopLength));
00281       }
00282     // Timer B gets a call count of 1.
00283     {
00284       TimeMonitor monitorB (*timerB);
00285       slowLoop (size_t (timerB_loopLength));
00286     }
00287 
00288     const bool alwaysWriteLocal = false; // the default
00289     const bool writeGlobalStats = true;  // the default
00290     const bool writeZeroTimers = false;  // NOT the default
00291     TimeMonitor::summarize (oss, alwaysWriteLocal, writeGlobalStats, 
00292           writeZeroTimers);
00293 
00294     // Echo summarize() output to the FancyOStream out (which is a
00295     // standard unit test argument).  Output should only appear in
00296     // show-all-test-details mode.
00297     out << oss.str() << std::endl;
00298 
00299     // Timers A and B should be reported.
00300     size_t substr_i = oss.str().find ("Timer A");
00301     TEST_INEQUALITY(substr_i, std::string::npos);
00302     substr_i = oss.str().find ("Timer B");
00303     TEST_INEQUALITY(substr_i, std::string::npos);
00304 
00305     // Timer C should NOT be reported.
00306     substr_i = oss.str().find ("Timer C");
00307     TEST_EQUALITY(substr_i, std::string::npos);
00308 
00309     // This sets up for the next unit test.
00310     TimeMonitor::clearTimers ();
00311   }
00312 
00313 
00314   //
00315   // Test whether the option to filter out zero timers works, for the
00316   // case that different (MPI) processes have different call counts.
00317   //
00318   TEUCHOS_UNIT_TEST( TimeMonitor, FILTER_ZERO_TIMERS_differentParallelCallCounts )
00319   {
00320     RCP<const Comm<int> > comm = Teuchos::DefaultComm<int>::getComm ();
00321     const int myRank = comm->getRank ();
00322 
00323     // If MPI has not been initialized, turn the MPI communicator into
00324     // a "serial" communicator.  This may not be necessary when using
00325     // the Teuchos Unit Test Framework.
00326 #ifdef HAVE_MPI
00327     {
00328       int mpiHasBeenInitialized = 0;
00329       MPI_Initialized (&mpiHasBeenInitialized);
00330       if (! mpiHasBeenInitialized)
00331   comm = Teuchos::DefaultComm<int>::getDefaultSerialComm (null);
00332     }
00333 #endif // HAVE_MPI
00334 
00335     // Store the output of TimeMonitor::summarize() here.
00336     std::ostringstream oss;
00337 
00338     RCP<Time> timerA = TimeMonitor::getNewCounter ("Timer A");
00339     RCP<Time> timerB = TimeMonitor::getNewCounter ("Timer B");
00340     RCP<Time> timerC = TimeMonitor::getNewCounter ("Timer C");
00341 
00342     // Timer A gets a nonzero elapsed time and call count on Proc 0,
00343     // but a zero elapsed time and call count elsewhere.
00344     //
00345     // Timer B gets the same nonzero elapsed time and call count on
00346     // all MPI procs.
00347     //
00348     // Timer C gets a zero elapsed time and call count on all procs.
00349     //
00350     // The actual number of operations in the loop is proportional to
00351     // the cube of the loop length.  Adjust the quantities below as
00352     // necessary to ensure the timer reports a nonzero elapsed time
00353     // for each of the invocations.
00354     const size_t timerA_loopLength = 200;
00355     const size_t timerB_loopLength = 500;
00356 
00357     if (myRank == 0)
00358       {
00359   // Timer A gets a call count of 3 on Proc 0.
00360   for (int k = 0; k < 3; ++k)
00361     {
00362       TimeMonitor monitorA (*timerA);
00363       slowLoop (size_t (timerA_loopLength));
00364     }
00365       }
00366 
00367     // Timer B gets a call count of 1 on all procs.
00368     {
00369       TimeMonitor monitorB (*timerB);
00370       slowLoop (size_t (timerB_loopLength));
00371     }
00372 
00373     const bool alwaysWriteLocal = false; // the default
00374     const bool writeGlobalStats = true;  // the default
00375     const bool writeZeroTimers = false;  // NOT the default
00376     TimeMonitor::summarize (oss, alwaysWriteLocal, writeGlobalStats, 
00377           writeZeroTimers, Union);
00378 
00379     // Echo summarize() output to the FancyOStream out (which is a
00380     // standard unit test argument).  Output should only appear in
00381     // show-all-test-details mode.
00382     out << oss.str() << std::endl;
00383 
00384     // Timers A and B should both be reported.
00385     size_t substr_i = oss.str().find ("Timer A");
00386     TEST_INEQUALITY(substr_i, std::string::npos);
00387     substr_i = oss.str().find ("Timer B");
00388     TEST_INEQUALITY(substr_i, std::string::npos);
00389 
00390     // Timer C should NOT be reported.
00391     substr_i = oss.str().find ("Timer C");
00392     TEST_EQUALITY(substr_i, std::string::npos);
00393 
00394     // This sets up for the next unit test (if there is one).
00395     TimeMonitor::clearTimers ();
00396   }
00397 
00398 
00399 } // namespace Teuchos
 All Classes Namespaces Files Functions Variables Typedefs Enumerations Enumerator Friends Defines