|
Teuchos Package Browser (Single Doxygen Collection)
Version of the Day
|
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 // slowLoop does not reliably make a timer nonzero (RHEL6, gcc 4.4.7, OpenMPI 1.5.4). 00049 // Thus, I'm introducing headers to make sleep() available. 00050 #ifndef ICL 00051 #include <unistd.h> 00052 #else 00053 void sleep(int sec) 00054 { 00055 Sleep(sec); 00056 } 00057 #endif 00058 00059 #ifdef _MSC_VER 00060 #pragma comment(lib, "Ws2_32.lib") 00061 # include <Winsock2.h> 00062 # include <process.h> 00063 void sleep(int sec) 00064 { 00065 Sleep(sec * 1000); 00066 } 00067 #endif 00068 00069 namespace { 00070 00071 void func_time_monitor1() 00072 { 00073 TEUCHOS_FUNC_TIME_MONITOR("FUNC_TIME_MONITOR1"); 00074 } 00075 00076 00077 void func_time_monitor2() 00078 { 00079 TEUCHOS_FUNC_TIME_MONITOR("FUNC_TIME_MONITOR2"); 00080 { 00081 TEUCHOS_FUNC_TIME_MONITOR_DIFF("FUNC_TIME_MONITOR2_inner", inner); 00082 } 00083 } 00084 00085 // This function is commented out because no code in this file 00086 // actually uses it. Commenting it out avoids compiler warnings 00087 // ("unused function"). 00088 #if 0 00089 // Slowly compute the n-th Fibonacci number. This gives timers 00090 // something to time. Be careful not to make n too large, or you'll 00091 // run out of stack space. 00092 int 00093 fib (const int n) 00094 { 00095 if (n <= 0) { 00096 return 0; 00097 } else if (n == 1) { 00098 return 1; 00099 } 00100 else { 00101 // You should never compute the n-th Fibonacci number like this. 00102 // This is exponentially slow in n. The point of using a slow 00103 // algorithm like this is to exercise timers. 00104 return fib (n-1) + fib (n-2); 00105 } 00106 } 00107 #endif // 0 00108 00109 // Do a number of arithmetic operations proportional to n^3, in 00110 // order to have something to time. Unlike the recursive function 00111 // fib() commented out above, this function shouldn't take up a lot 00112 // of stack space. 00113 double 00114 slowLoop (const size_t n) 00115 { 00116 const double inc = 1 / static_cast<double> (n); 00117 double x = 1.0; 00118 00119 for (size_t i = 0; i < n; ++i) { 00120 for (size_t j = 0; j < n; ++j) { 00121 for (size_t k = 0; k < n; ++k) { 00122 x = x + inc; 00123 } 00124 } 00125 } 00126 return x; 00127 } 00128 00129 } // namespace (anonymous) 00130 00131 00132 namespace Teuchos { 00133 // 00134 // Basic TimeMonitor test: create and exercise a timer on all (MPI) 00135 // processes, and make sure that TimeMonitor::summarize() reports it. 00136 // 00137 TEUCHOS_UNIT_TEST( TimeMonitor, FUNC_TIME_MONITOR ) 00138 { 00139 using Teuchos::ParameterList; 00140 using Teuchos::parameterList; 00141 using Teuchos::RCP; 00142 00143 func_time_monitor1 (); // Function to time. 00144 00145 { // Repeat test for default output format. 00146 std::ostringstream oss; 00147 TimeMonitor::summarize (oss); 00148 00149 // Echo summarize() output to the FancyOStream out (which is a 00150 // standard unit test argument). Output should only appear in 00151 // show-all-test-details mode. 00152 out << oss.str () << std::endl; 00153 00154 // Make sure that the timer's name shows up in the output. 00155 const size_t substr_i = oss.str ().find ("FUNC_TIME_MONITOR1"); 00156 TEST_INEQUALITY(substr_i, std::string::npos); 00157 } 00158 00159 { // Repeat test for YAML output, compact style. 00160 std::ostringstream oss; 00161 RCP<ParameterList> reportParams = 00162 parameterList (* (TimeMonitor::getValidReportParameters ())); 00163 reportParams->set ("Report format", "YAML"); 00164 reportParams->set ("YAML style", "compact"); 00165 TimeMonitor::report (oss, reportParams); 00166 00167 // Echo output to the FancyOStream out (which is a standard unit 00168 // test argument). Output should only appear in "show all test 00169 // details" mode. 00170 out << oss.str () << std::endl; 00171 00172 // Make sure that the timer's name shows up in the output. 00173 const size_t substr_i = oss.str ().find ("FUNC_TIME_MONITOR1"); 00174 TEST_INEQUALITY(substr_i, std::string::npos); 00175 } 00176 00177 { // Repeat test for YAML output, spacious style. 00178 std::ostringstream oss; 00179 RCP<ParameterList> reportParams = 00180 parameterList (* (TimeMonitor::getValidReportParameters ())); 00181 reportParams->set ("Report format", "YAML"); 00182 reportParams->set ("YAML style", "spacious"); 00183 TimeMonitor::report (oss, reportParams); 00184 00185 // Echo output to the FancyOStream out (which is a standard unit 00186 // test argument). Output should only appear in "show all test 00187 // details" mode. 00188 out << oss.str () << std::endl; 00189 00190 // Make sure that the timer's name shows up in the output. 00191 const size_t substr_i = oss.str ().find ("FUNC_TIME_MONITOR1"); 00192 TEST_INEQUALITY(substr_i, std::string::npos); 00193 } 00194 00195 // This sets up for the next unit test. 00196 TimeMonitor::clearCounters (); 00197 } 00198 00199 // 00200 // Test for TimeMonitor's enableTimer and disableTimer methods. 00201 // 00202 TEUCHOS_UNIT_TEST( TimeMonitor, enableTimer ) 00203 { 00204 using Teuchos::Array; 00205 using Teuchos::OSTab; 00206 using Teuchos::ParameterList; 00207 using Teuchos::parameterList; 00208 using Teuchos::RCP; 00209 using Teuchos::rcpFromRef; 00210 using Teuchos::Time; 00211 using Teuchos::TimeMonitor; 00212 using std::endl; 00213 typedef Teuchos::Array<RCP<Time> >::size_type size_type; 00214 00215 out << "Testing TimeMonitor's disableTimer() and enableTimer() methods" 00216 << endl; 00217 OSTab (rcpFromRef (out)); 00218 00219 out << "Creating timers" << endl; 00220 const int numTrials = 5; 00221 const int numTimers = 3; 00222 Array<RCP<Time> > timers (numTimers); 00223 for (size_type i = 0; i < numTimers; ++i) { 00224 std::ostringstream os; // construct timer name 00225 os << "Timer " << i; 00226 timers[i] = TimeMonitor::getNewTimer (os.str ()); 00227 } 00228 00229 out << "Running all timers without disabling any" << endl; 00230 // The actual number of operations in slowloop is proportional to 00231 // the cube of the loop length. Adjust loopLength as necessary to 00232 // ensure the timer reports a nonzero elapsed time for each of the 00233 // invocations. 00234 const size_t loopLength = 25; 00235 for (int k = 0; k < numTrials; ++k) { 00236 for (size_type i = 0; i < numTimers; ++i) { 00237 TimeMonitor timeMon (* timers[i]); 00238 slowLoop (loopLength); 00239 } 00240 } 00241 for (size_type i = 0; i < numTimers; ++i) { 00242 TEST_EQUALITY( timers[i]->numCalls(), numTrials ); 00243 } 00244 00245 out << "Disabling one timer and trying again" << endl; 00246 // Disable timers[0] only, and repeat the above loops. 00247 TEST_NOTHROW( TimeMonitor::disableTimer ("Timer 0") ); 00248 for (int k = 0; k < numTrials; ++k) { 00249 for (size_type i = 0; i < numTimers; ++i) { 00250 TimeMonitor timeMon (* timers[i]); 00251 slowLoop (loopLength); 00252 } 00253 } 00254 TEST_EQUALITY( timers[0]->numCalls(), numTrials ); 00255 for (size_type i = 1; i < numTimers; ++i) { 00256 TEST_EQUALITY( timers[i]->numCalls(), 2*numTrials ); 00257 } 00258 00259 out << "Reenabling the timer and trying again" << endl; 00260 // Enable timers[0] and repeat the above loops. 00261 TEST_NOTHROW( TimeMonitor::enableTimer ("Timer 0") ); 00262 for (int k = 0; k < numTrials; ++k) { 00263 for (size_type i = 0; i < numTimers; ++i) { 00264 TimeMonitor timeMon (* timers[i]); 00265 slowLoop (loopLength); 00266 } 00267 } 00268 TEST_EQUALITY( timers[0]->numCalls(), 2*numTrials ); 00269 for (size_type i = 1; i < numTimers; ++i) { 00270 TEST_EQUALITY( timers[i]->numCalls(), 3*numTrials ); 00271 } 00272 00273 out << "Test that summarize() reports enabled and disabled timers" << endl; 00274 // Make sure that summarize() reports all timers. Disabling a 00275 // timer must _not_ exclude it from the list of timers printed by 00276 // summarize(). Disable a different timer this time just for fun. 00277 TEST_NOTHROW( TimeMonitor::disableTimer ("Timer 1") ); 00278 { 00279 std::ostringstream oss; 00280 TimeMonitor::summarize (oss); 00281 00282 // Echo summarize() output to the FancyOStream out (which is a 00283 // standard unit test argument). Output should only appear in 00284 // show-all-test-details mode. 00285 out << oss.str () << std::endl; 00286 00287 // Make sure that each timer's name shows up in the output. 00288 for (size_type i = 0; i < numTimers; ++i) { 00289 const std::string name = timers[i]->name (); 00290 const size_t substr_i = oss.str ().find (name); 00291 TEST_INEQUALITY(substr_i, std::string::npos); 00292 } 00293 } 00294 00295 // This sets up for the next unit test. 00296 TimeMonitor::clearCounters (); 00297 } 00298 00299 00300 // 00301 // Test correct quoting of labels for TimeMonitor's YAML output. 00302 // 00303 TEUCHOS_UNIT_TEST( TimeMonitor, YamlLabelQuoting ) 00304 { 00305 using Teuchos::Array; 00306 using Teuchos::ParameterList; 00307 using Teuchos::parameterList; 00308 using Teuchos::RCP; 00309 using Teuchos::Time; 00310 typedef Array<std::string>::size_type size_type; 00311 00312 Array<std::string> inputLabels, outputLabels; 00313 00314 // Make sure to exercise things that don't need quoting, like 00315 // spaces and certain punctuation, as well as things that do need 00316 // quoting, like colons, inner double quotes, and backslashes. 00317 inputLabels.push_back ("NoQuotingNeeded"); 00318 inputLabels.push_back ("No quoting needed"); 00319 inputLabels.push_back ("\"AlreadyQuotedNoQuotingNeeded\""); 00320 inputLabels.push_back ("\"Already quoted, no quoting needed\""); 00321 inputLabels.push_back ("\"Already quoted: quoting needed\""); 00322 inputLabels.push_back ("NotQuoted:QuotingNeeded"); 00323 inputLabels.push_back ("Not quoted: quoting needed"); 00324 // Test both individual double quotes, and pairs of double quotes. 00325 inputLabels.push_back ("Not quoted \" quoting needed"); 00326 inputLabels.push_back ("Not quoted \" \" quoting needed"); 00327 inputLabels.push_back ("\"Already quoted \" quoting needed\""); 00328 inputLabels.push_back ("\"Already quoted \" \" quoting needed\""); 00329 // Remember that in C strings, a double backslash turns into a 00330 // single backslash. Our YAML output routine should turn each 00331 // single backslash back into a double backslash. 00332 inputLabels.push_back ("Not quoted \\ quoting needed"); 00333 inputLabels.push_back ("Not quoted \\\\ quoting needed"); 00334 inputLabels.push_back ("Not quoted \\ \\ quoting needed"); 00335 inputLabels.push_back ("\"Already quoted \\ quoting needed\""); 00336 inputLabels.push_back ("\"Already quoted \\\\ quoting needed\""); 00337 inputLabels.push_back ("\"Already quoted \\ \\ quoting needed\""); 00338 00339 outputLabels.push_back ("NoQuotingNeeded"); 00340 outputLabels.push_back ("No quoting needed"); 00341 outputLabels.push_back ("\"AlreadyQuotedNoQuotingNeeded\""); 00342 outputLabels.push_back ("\"Already quoted, no quoting needed\""); 00343 outputLabels.push_back ("\"Already quoted: quoting needed\""); 00344 outputLabels.push_back ("\"NotQuoted:QuotingNeeded\""); 00345 outputLabels.push_back ("\"Not quoted: quoting needed\""); 00346 outputLabels.push_back ("\"Not quoted \\\" quoting needed\""); 00347 outputLabels.push_back ("\"Not quoted \\\" \\\" quoting needed\""); 00348 outputLabels.push_back ("\"Already quoted \\\" quoting needed\""); 00349 outputLabels.push_back ("\"Already quoted \\\" \\\" quoting needed\""); 00350 outputLabels.push_back ("\"Not quoted \\\\ quoting needed\""); 00351 outputLabels.push_back ("\"Not quoted \\\\\\\\ quoting needed\""); 00352 outputLabels.push_back ("\"Not quoted \\\\ \\\\ quoting needed\""); 00353 outputLabels.push_back ("\"Already quoted \\\\ quoting needed\""); 00354 outputLabels.push_back ("\"Already quoted \\\\\\\\ quoting needed\""); 00355 outputLabels.push_back ("\"Already quoted \\\\ \\\\ quoting needed\""); 00356 00357 // Sanity check. 00358 TEUCHOS_TEST_FOR_EXCEPTION( 00359 inputLabels.size () != outputLabels.size (), 00360 std::logic_error, 00361 "The number of input labels is different than the number of output labels." 00362 " Please ask a Teuchos developer to make sure that every test input " 00363 "label has a corresponding output label."); 00364 00365 Array<RCP<Time> > timers; 00366 for (size_type i = 0; i < inputLabels.size (); ++i) { 00367 timers.push_back (TimeMonitor::getNewCounter (inputLabels[i])); 00368 } 00369 00370 // The actual number of operations in the loop is proportional to 00371 // the cube of the loop length. Adjust the quantities below as 00372 // necessary to ensure the timer reports a nonzero elapsed time 00373 // for each of the invocations. 00374 const size_t loopLength = 25; 00375 for (int k = 0; k < 3; ++k) { 00376 for (size_type i = 0; i < timers.size (); ++i) { 00377 TimeMonitor timeMon (* timers[i]); 00378 slowLoop (loopLength); 00379 } 00380 } 00381 00382 { // YAML output, compact style. 00383 std::ostringstream oss; 00384 RCP<ParameterList> reportParams = 00385 parameterList (* (TimeMonitor::getValidReportParameters ())); 00386 reportParams->set ("Report format", "YAML"); 00387 reportParams->set ("YAML style", "compact"); 00388 TimeMonitor::report (oss, reportParams); 00389 00390 // Echo output to the FancyOStream out (which is a standard unit 00391 // test argument). Output should only appear in "show all test 00392 // details" mode. 00393 out << oss.str () << std::endl; 00394 00395 // Make sure that all timer labels appear correctly in the output. 00396 for (size_type i = 0; i < inputLabels.size(); ++i) { 00397 const size_t pos = oss.str ().find (outputLabels[i]); 00398 TEST_INEQUALITY(pos, std::string::npos); 00399 } 00400 } 00401 00402 { // YAML output, spacious style. 00403 std::ostringstream oss; 00404 RCP<ParameterList> reportParams = 00405 parameterList (* (TimeMonitor::getValidReportParameters ())); 00406 reportParams->set ("Report format", "YAML"); 00407 reportParams->set ("YAML style", "spacious"); 00408 TimeMonitor::report (oss, reportParams); 00409 00410 // Echo output to the FancyOStream out (which is a standard unit 00411 // test argument). Output should only appear in "show all test 00412 // details" mode. 00413 out << oss.str () << std::endl; 00414 00415 // Make sure that all timer labels appear correctly in the output. 00416 for (size_type i = 0; i < inputLabels.size(); ++i) { 00417 const size_t pos = oss.str ().find (outputLabels[i]); 00418 TEST_INEQUALITY(pos, std::string::npos); 00419 } 00420 } 00421 00422 // This sets up for the next unit test. 00423 TimeMonitor::clearCounters (); 00424 } 00425 00426 00427 // 00428 // Test filtering of timer labels. 00429 // 00430 TEUCHOS_UNIT_TEST( TimeMonitor, TimerLabelFiltering ) 00431 { 00432 using Teuchos::Array; 00433 using Teuchos::ParameterList; 00434 using Teuchos::parameterList; 00435 using Teuchos::RCP; 00436 using Teuchos::Time; 00437 typedef Array<std::string>::size_type size_type; 00438 00439 // Filters to use in the test. 00440 Array<std::string> filters; 00441 filters.push_back ("Foo:"); 00442 filters.push_back ("Bar:"); 00443 filters.push_back ("Baz:"); 00444 00445 // All the timer labels. 00446 Array<std::string> labels; 00447 labels.push_back ("Foo: timer 1"); 00448 labels.push_back ("Foo: timer 2"); 00449 labels.push_back ("Foo: timer 3"); 00450 labels.push_back ("Bar: timer 1"); 00451 labels.push_back ("Bar: timer 2"); 00452 labels.push_back ("Baz: timer 1"); 00453 labels.push_back ("Xyzzy"); 00454 labels.push_back ("This is not a pipe"); 00455 labels.push_back ("You should not see this"); 00456 00457 Array<Array<std::string> > outLabels (3); 00458 // Label(s) that should be printed for filters[0] 00459 outLabels[0].push_back ("Foo: timer 1"); 00460 outLabels[0].push_back ("Foo: timer 2"); 00461 outLabels[0].push_back ("Foo: timer 3"); 00462 // Label(s) that should be printed for filters[1] 00463 outLabels[1].push_back ("Bar: timer 1"); 00464 outLabels[1].push_back ("Bar: timer 2"); 00465 // Label(s) that should be printed for filters[2] 00466 outLabels[2].push_back ("Baz: timer 1"); 00467 00468 // Labels that should not be printed for any of the filters below. 00469 Array<std::string> otherLabels; 00470 otherLabels.push_back ("Xyzzy"); 00471 otherLabels.push_back ("This is not a pipe"); 00472 otherLabels.push_back ("You should not see this"); 00473 00474 Array<RCP<Time> > timers; 00475 for (size_type i = 0; i < labels.size (); ++i) { 00476 timers.push_back (TimeMonitor::getNewCounter (labels[i])); 00477 } 00478 00479 // The actual number of operations in the loop is proportional to 00480 // the cube of the loop length. Adjust the quantities below as 00481 // necessary to ensure the timer reports a nonzero elapsed time 00482 // for each of the invocations. 00483 const size_t loopLength = 25; 00484 for (int k = 0; k < 3; ++k) { 00485 for (size_type i = 0; i < timers.size (); ++i) { 00486 TimeMonitor timeMon (* timers[i]); 00487 slowLoop (loopLength); 00488 } 00489 } 00490 00491 try { 00492 // FIXME (mfh 21 Aug 2012) We don't yet have a test ensuring that 00493 // the filter only selects at the beginning of the timer label. 00494 00495 // Test for each filter. 00496 for (size_type i = 0; i < filters.size (); ++i) { 00497 { // Default (tabular) output format. 00498 std::ostringstream oss; 00499 RCP<ParameterList> reportParams = 00500 parameterList (* (TimeMonitor::getValidReportParameters ())); 00501 TimeMonitor::report (oss, filters[i], reportParams); 00502 00503 // Echo output to the FancyOStream out (which is a standard unit 00504 // test argument). Output should only appear in "show all test 00505 // details" mode. 00506 out << oss.str () << std::endl; 00507 00508 // Check whether the labels that were supposed to be printed 00509 // were actually printed. 00510 for (size_type j = 0; j < outLabels[i].size(); ++j) { 00511 const size_t pos = oss.str ().find (outLabels[i][j]); 00512 TEST_INEQUALITY(pos, std::string::npos); 00513 } 00514 00515 // Check whether the labels that were _not_ supposed to be 00516 // printed were actually printed. 00517 // 00518 // First, check the labels that should only be printed with 00519 // the other filters. 00520 for (size_type ii = 0; ii < outLabels.size(); ++ii) { 00521 if (ii != i) { 00522 for (size_type j = 0; j < outLabels[ii].size(); ++j) { 00523 const size_t pos = oss.str ().find (outLabels[ii][j]); 00524 TEST_EQUALITY(pos, std::string::npos); 00525 } 00526 } 00527 } 00528 // Next, check the labels that should not be printed for any 00529 // filters. 00530 for (size_type j = 0; j < otherLabels.size(); ++j) { 00531 const size_t pos = oss.str ().find (otherLabels[j]); 00532 TEST_EQUALITY(pos, std::string::npos); 00533 } 00534 } 00535 00536 { // YAML output, compact style. 00537 std::ostringstream oss; 00538 RCP<ParameterList> reportParams = 00539 parameterList (* (TimeMonitor::getValidReportParameters ())); 00540 reportParams->set ("Report format", "YAML"); 00541 reportParams->set ("YAML style", "compact"); 00542 TimeMonitor::report (oss, filters[i], reportParams); 00543 00544 // Echo output to the FancyOStream out (which is a standard unit 00545 // test argument). Output should only appear in "show all test 00546 // details" mode. 00547 out << oss.str () << std::endl; 00548 00549 // Check whether the labels that were supposed to be printed 00550 // were actually printed. 00551 for (size_type j = 0; j < outLabels[i].size(); ++j) { 00552 const size_t pos = oss.str ().find (outLabels[i][j]); 00553 TEST_INEQUALITY(pos, std::string::npos); 00554 } 00555 00556 // Check whether the labels that were _not_ supposed to be 00557 // printed were actually printed. 00558 // 00559 // First, check the labels that should only be printed with 00560 // the other filters. 00561 for (size_type ii = 0; ii < outLabels.size(); ++ii) { 00562 if (ii != i) { 00563 for (size_type j = 0; j < outLabels[ii].size(); ++j) { 00564 const size_t pos = oss.str ().find (outLabels[ii][j]); 00565 TEST_EQUALITY(pos, std::string::npos); 00566 } 00567 } 00568 } 00569 // Next, check the labels that should not be printed for any 00570 // filters. 00571 for (size_type j = 0; j < otherLabels.size(); ++j) { 00572 const size_t pos = oss.str ().find (otherLabels[j]); 00573 TEST_EQUALITY(pos, std::string::npos); 00574 } 00575 } 00576 00577 { // YAML output, spacious style. 00578 std::ostringstream oss; 00579 RCP<ParameterList> reportParams = 00580 parameterList (* (TimeMonitor::getValidReportParameters ())); 00581 reportParams->set ("Report format", "YAML"); 00582 reportParams->set ("YAML style", "spacious"); 00583 TimeMonitor::report (oss, filters[i], reportParams); 00584 00585 // Echo output to the FancyOStream out (which is a standard unit 00586 // test argument). Output should only appear in "show all test 00587 // details" mode. 00588 out << oss.str () << std::endl; 00589 00590 // Check whether the labels that were supposed to be printed 00591 // were actually printed. 00592 for (size_type j = 0; j < outLabels[i].size(); ++j) { 00593 const size_t pos = oss.str ().find (outLabels[i][j]); 00594 TEST_INEQUALITY(pos, std::string::npos); 00595 } 00596 00597 // Check whether the labels that were _not_ supposed to be 00598 // printed were actually printed. 00599 // 00600 // First, check the labels that should only be printed with 00601 // the other filters. 00602 for (size_type ii = 0; ii < outLabels.size(); ++ii) { 00603 if (ii != i) { 00604 for (size_type j = 0; j < outLabels[ii].size(); ++j) { 00605 const size_t pos = oss.str ().find (outLabels[ii][j]); 00606 TEST_EQUALITY(pos, std::string::npos); 00607 } 00608 } 00609 } 00610 // Next, check the labels that should not be printed for any 00611 // filters. 00612 for (size_type j = 0; j < otherLabels.size(); ++j) { 00613 const size_t pos = oss.str ().find (otherLabels[j]); 00614 TEST_EQUALITY(pos, std::string::npos); 00615 } 00616 } 00617 } 00618 } 00619 catch (...) { 00620 // Make sure to clear the counters, so that they don't pollute 00621 // the remaining tests. (The Teuchos unit test framework may 00622 // catch any exceptions that the above code throws, but allow 00623 // the remaining tests to continue.) 00624 TimeMonitor::clearCounters (); 00625 throw; 00626 } 00627 00628 // This sets up for the next unit test. 00629 TimeMonitor::clearCounters (); 00630 } 00631 00632 00633 00634 // 00635 // TimeMonitor nested timers test: create two timers on all (MPI) 00636 // processes, use the second inside the scope of the first, and make 00637 // sure that TimeMonitor::summarize() reports both timers. 00638 // 00639 TEUCHOS_UNIT_TEST( TimeMonitor, FUNC_TIME_MONITOR_tested ) 00640 { 00641 using Teuchos::ParameterList; 00642 using Teuchos::parameterList; 00643 using Teuchos::RCP; 00644 00645 func_time_monitor2 (); 00646 00647 { 00648 std::ostringstream oss; 00649 TimeMonitor::summarize (oss); 00650 00651 // Echo summarize() output to the FancyOStream out (which is a 00652 // standard unit test argument). Output should only appear in 00653 // show-all-test-details mode. 00654 out << oss.str() << std::endl; 00655 00656 const size_t substr_i = oss.str().find ("FUNC_TIME_MONITOR2"); 00657 TEST_INEQUALITY(substr_i, std::string::npos); 00658 const size_t substr_inner_i = oss.str().find ("FUNC_TIME_MONITOR2_inner"); 00659 TEST_INEQUALITY(substr_inner_i, std::string::npos); 00660 } 00661 00662 { // Repeat test for YAML output, compact style. 00663 std::ostringstream oss; 00664 RCP<ParameterList> reportParams = 00665 parameterList (* (TimeMonitor::getValidReportParameters ())); 00666 reportParams->set ("Report format", "YAML"); 00667 reportParams->set ("YAML style", "compact"); 00668 TimeMonitor::report (oss, reportParams); 00669 00670 // Echo output to the FancyOStream out (which is a standard unit 00671 // test argument). Output should only appear in "show all test 00672 // details" mode. 00673 out << oss.str () << std::endl; 00674 00675 const size_t substr_i = oss.str().find ("FUNC_TIME_MONITOR2"); 00676 TEST_INEQUALITY(substr_i, std::string::npos); 00677 const size_t substr_inner_i = oss.str().find ("FUNC_TIME_MONITOR2_inner"); 00678 TEST_INEQUALITY(substr_inner_i, std::string::npos); 00679 } 00680 00681 { // Repeat test for YAML output, spacious style. 00682 std::ostringstream oss; 00683 RCP<ParameterList> reportParams = 00684 parameterList (* (TimeMonitor::getValidReportParameters ())); 00685 reportParams->set ("Report format", "YAML"); 00686 reportParams->set ("YAML style", "spacious"); 00687 TimeMonitor::report (oss, reportParams); 00688 00689 // Echo output to the FancyOStream out (which is a standard unit 00690 // test argument). Output should only appear in "show all test 00691 // details" mode. 00692 out << oss.str () << std::endl; 00693 00694 const size_t substr_i = oss.str().find ("FUNC_TIME_MONITOR2"); 00695 TEST_INEQUALITY(substr_i, std::string::npos); 00696 const size_t substr_inner_i = oss.str().find ("FUNC_TIME_MONITOR2_inner"); 00697 TEST_INEQUALITY(substr_inner_i, std::string::npos); 00698 } 00699 00700 // This sets up for the next unit test. 00701 TimeMonitor::clearCounters (); 00702 } 00703 00704 // 00705 // Test whether TimeMonitor::summarize() does the right thing when 00706 // different MPI processes create different sets of timers. This 00707 // test is only meaningful if running with more than one MPI 00708 // process, but it should also pass if running in a non-MPI build or 00709 // with only one MPI process. 00710 // 00711 TEUCHOS_UNIT_TEST( TimeMonitor, SUMMARIZE_diffTimerSets ) 00712 { 00713 RCP<const Comm<int> > comm = Teuchos::DefaultComm<int>::getComm (); 00714 const int numProcs = comm->getSize (); 00715 const int myRank = comm->getRank (); 00716 00717 // If MPI has not been initialized, turn the MPI communicator into 00718 // a "serial" communicator. This may not be necessary when using 00719 // the Teuchos Unit Test Framework. 00720 #ifdef HAVE_MPI 00721 { 00722 int mpiHasBeenInitialized = 0; 00723 MPI_Initialized (&mpiHasBeenInitialized); 00724 if (! mpiHasBeenInitialized) { 00725 comm = Teuchos::DefaultComm<int>::getDefaultSerialComm (null); 00726 } 00727 } 00728 #endif // HAVE_MPI 00729 00730 // Store the output of TimeMonitor::summarize() here. 00731 std::ostringstream oss; 00732 00733 // Timer A gets created on all MPI processes. 00734 // Timer B only gets created on Proc 0. 00735 RCP<Time> timerA = TimeMonitor::getNewCounter ("Timer A"); 00736 RCP<Time> timerB; 00737 if (myRank == 0) { 00738 timerB = TimeMonitor::getNewCounter ("Timer B"); 00739 } 00740 else { 00741 timerB = null; // True anyway, but I want to make this explicit. 00742 } 00743 00744 // The actual number of operations in the loop is proportional to 00745 // the cube of the loop length. Adjust the quantities below as 00746 // necessary to ensure the timer reports a nonzero elapsed time 00747 // for each of the invocations. 00748 const size_t timerA_loopLength = 150; 00749 const size_t timerB_loopLength = 200; 00750 00751 // Timer A gets a call count of 3. 00752 for (size_t k = 0; k < 3; ++k) { 00753 TimeMonitor monitorA (*timerA); 00754 slowLoop (timerA_loopLength); 00755 } 00756 if (myRank == 0) { // Timer B gets a call count of 1 on Proc 0. 00757 TimeMonitor monitorB (*timerB); 00758 slowLoop (timerB_loopLength); 00759 } 00760 00761 const bool alwaysWriteLocal = false; // the default 00762 const bool writeGlobalStats = true; // the default 00763 const bool writeZeroTimers = true; // the default 00764 TimeMonitor::summarize (oss, alwaysWriteLocal, writeGlobalStats, 00765 writeZeroTimers, Intersection); 00766 00767 // Echo summarize() output to the FancyOStream out (which is a 00768 // standard unit test argument). Output should only appear in 00769 // show-all-test-details mode. 00770 out << std::endl << "Testing intersection of timers:" << std::endl 00771 << oss.str() << std::endl; 00772 00773 // Since setOp == Intersection, only Timer A should be reported, 00774 // unless there is only one (MPI) process. 00775 size_t substr_i = oss.str().find ("Timer A"); 00776 TEST_INEQUALITY(substr_i, std::string::npos); 00777 if (numProcs > 1) { 00778 substr_i = oss.str().find ("Timer B"); 00779 TEST_EQUALITY(substr_i, std::string::npos); 00780 } 00781 00782 // Now call summarize(), but ask for a union of timers. 00783 std::ostringstream ossUnion; 00784 TimeMonitor::summarize (ossUnion, alwaysWriteLocal, writeGlobalStats, 00785 writeZeroTimers, Union); 00786 00787 // Echo summarize() output to the FancyOStream out (which is a 00788 // standard unit test argument). Output should only appear in 00789 // show-all-test-details mode. 00790 out << std::endl << "Testing union of timers:" << std::endl 00791 << ossUnion.str() << std::endl; 00792 00793 // Since setOp == Union, both Timer A and Timer B should be 00794 // reported. 00795 substr_i = ossUnion.str().find ("Timer A"); 00796 TEST_INEQUALITY(substr_i, std::string::npos); 00797 substr_i = ossUnion.str().find ("Timer B"); 00798 TEST_INEQUALITY(substr_i, std::string::npos); 00799 00800 // This sets up for the next unit test. 00801 TimeMonitor::clearCounters (); 00802 } 00803 00804 // 00805 // Test whether the option to filter out zero timers works, for the 00806 // case that all (MPI) processes have the same call counts. 00807 // 00808 TEUCHOS_UNIT_TEST( TimeMonitor, FILTER_ZERO_TIMERS_sameParallelCallCounts ) 00809 { 00810 // Store the output of TimeMonitor::summarize() here. 00811 std::ostringstream oss; 00812 00813 RCP<Time> timerA = TimeMonitor::getNewCounter ("Timer A"); 00814 RCP<Time> timerB = TimeMonitor::getNewCounter ("Timer B"); 00815 RCP<Time> timerC = TimeMonitor::getNewCounter ("Timer C"); 00816 00817 // Timers A and B get nonzero elapsed times and call counts on all 00818 // (MPI) processes. Timer C never gets started, so it should have 00819 // a zero elapsed time and zero call count on all processes. 00820 00821 // The actual number of operations in the loop is proportional to 00822 // the cube of the loop length. Adjust the quantities below as 00823 // necessary to ensure the timer reports a nonzero elapsed time 00824 // for each of the invocations. 00825 const size_t timerA_loopLength = 200; 00826 const size_t timerB_loopLength = 250; 00827 00828 // Timer A gets a call count of 3. 00829 for (size_t k = 0; k < 3; ++k) { 00830 TimeMonitor monitorA (*timerA); 00831 slowLoop (size_t (timerA_loopLength)); 00832 } 00833 // Timer B gets a call count of 1. 00834 { 00835 TimeMonitor monitorB (*timerB); 00836 slowLoop (size_t (timerB_loopLength)); 00837 } 00838 00839 const bool alwaysWriteLocal = false; // the default 00840 const bool writeGlobalStats = true; // the default 00841 const bool writeZeroTimers = false; // NOT the default 00842 TimeMonitor::summarize (oss, alwaysWriteLocal, writeGlobalStats, 00843 writeZeroTimers); 00844 00845 // Echo summarize() output to the FancyOStream out (which is a 00846 // standard unit test argument). Output should only appear in 00847 // show-all-test-details mode. 00848 out << oss.str() << std::endl; 00849 00850 // Timers A and B should be reported. 00851 size_t substr_i = oss.str().find ("Timer A"); 00852 TEST_INEQUALITY(substr_i, std::string::npos); 00853 substr_i = oss.str().find ("Timer B"); 00854 TEST_INEQUALITY(substr_i, std::string::npos); 00855 00856 // Timer C should NOT be reported. 00857 substr_i = oss.str().find ("Timer C"); 00858 TEST_EQUALITY(substr_i, std::string::npos); 00859 00860 // This sets up for the next unit test. 00861 TimeMonitor::clearCounters (); 00862 } 00863 00864 00865 // 00866 // Test whether the option to filter out zero timers works, for the 00867 // case that different (MPI) processes have different call counts. 00868 // 00869 TEUCHOS_UNIT_TEST( TimeMonitor, FILTER_ZERO_TIMERS_differentParallelCallCounts ) 00870 { 00871 RCP<const Comm<int> > comm = Teuchos::DefaultComm<int>::getComm (); 00872 const int myRank = comm->getRank (); 00873 00874 // If MPI has not been initialized, turn the MPI communicator into 00875 // a "serial" communicator. This may not be necessary when using 00876 // the Teuchos Unit Test Framework. 00877 #ifdef HAVE_MPI 00878 { 00879 int mpiHasBeenInitialized = 0; 00880 MPI_Initialized (&mpiHasBeenInitialized); 00881 if (! mpiHasBeenInitialized) { 00882 comm = Teuchos::DefaultComm<int>::getDefaultSerialComm (null); 00883 } 00884 } 00885 #endif // HAVE_MPI 00886 00887 // Store the output of TimeMonitor::summarize() here. 00888 std::ostringstream oss; 00889 00890 RCP<Time> timerA = TimeMonitor::getNewCounter ("Timer A"); 00891 RCP<Time> timerB = TimeMonitor::getNewCounter ("Timer B"); 00892 RCP<Time> timerC = TimeMonitor::getNewCounter ("Timer C"); 00893 00894 // Timer A gets a nonzero elapsed time and call count on Proc 0, 00895 // but a zero elapsed time and call count elsewhere. 00896 // 00897 // Timer B gets the same nonzero elapsed time and call count on 00898 // all MPI procs. 00899 // 00900 // Timer C gets a zero elapsed time and call count on all procs. 00901 // 00902 // The actual number of operations in the loop is proportional to 00903 // the cube of the loop length. Adjust the quantities below as 00904 // necessary to ensure the timer reports a nonzero elapsed time 00905 // for each of the invocations. 00906 const size_t timerA_loopLength = 200; 00907 const size_t timerB_loopLength = 500; 00908 00909 if (myRank == 0) { 00910 // Timer A gets a call count of 3 on Proc 0. 00911 for (int k = 0; k < 3; ++k) { 00912 TimeMonitor monitorA (*timerA); 00913 slowLoop (size_t (timerA_loopLength)); 00914 } 00915 } 00916 00917 // Timer B gets a call count of 1 on all procs. 00918 { 00919 TimeMonitor monitorB (*timerB); 00920 slowLoop (size_t (timerB_loopLength)); 00921 } 00922 00923 const bool alwaysWriteLocal = false; // the default 00924 const bool writeGlobalStats = true; // the default 00925 const bool writeZeroTimers = false; // NOT the default 00926 TimeMonitor::summarize (oss, alwaysWriteLocal, writeGlobalStats, 00927 writeZeroTimers, Union); 00928 00929 // Echo summarize() output to the FancyOStream out (which is a 00930 // standard unit test argument). Output should only appear in 00931 // show-all-test-details mode. 00932 out << oss.str() << std::endl; 00933 00934 // Timers A and B should both be reported. 00935 size_t substr_i = oss.str().find ("Timer A"); 00936 TEST_INEQUALITY(substr_i, std::string::npos); 00937 substr_i = oss.str().find ("Timer B"); 00938 TEST_INEQUALITY(substr_i, std::string::npos); 00939 00940 // Timer C should NOT be reported. 00941 substr_i = oss.str().find ("Timer C"); 00942 TEST_EQUALITY(substr_i, std::string::npos); 00943 00944 // This sets up for the next unit test (if there is one). 00945 TimeMonitor::clearCounters (); 00946 } 00947 00948 // 00949 // Test option to disregard missing timers from processes in TimeMonitor::summarize(). 00950 // 00951 TEUCHOS_UNIT_TEST( TimeMonitor, IgnoreMissingTimers ) 00952 { 00953 RCP<const Comm<int> > comm = Teuchos::DefaultComm<int>::getComm (); 00954 const int myRank = comm->getRank (); 00955 00956 #ifdef HAVE_MPI 00957 { 00958 int mpiHasBeenInitialized = 0; 00959 MPI_Initialized (&mpiHasBeenInitialized); 00960 if (! mpiHasBeenInitialized) { 00961 comm = Teuchos::DefaultComm<int>::getDefaultSerialComm (null); 00962 } 00963 } 00964 #endif // HAVE_MPI 00965 00966 // Store the output of TimeMonitor::summarize() here. 00967 std::ostringstream oss; 00968 00969 std::string timerName="Timer Z"; 00970 // Timer Z appears on all PIDs except 0. 00971 { 00972 switch (myRank) { 00973 case 1 : 00974 break; 00975 case 0 : 00976 { 00977 RCP<Time> timer = TimeMonitor::getNewCounter (timerName); 00978 TimeMonitor monitor (*timer); 00979 sleep(1); 00980 } 00981 break; 00982 case 2 : 00983 { 00984 RCP<Time> timer = TimeMonitor::getNewCounter (timerName); 00985 TimeMonitor monitor (*timer); 00986 sleep(1); 00987 } 00988 break; 00989 default : 00990 { 00991 RCP<Time> timer = TimeMonitor::getNewCounter (timerName); 00992 TimeMonitor monitor (*timer); 00993 sleep(1); 00994 } 00995 } 00996 } 00997 00999 // test two versions of summarize with default behavior 01001 01002 //version 1, comm provided 01003 const bool alwaysWriteLocal = false; 01004 const bool writeGlobalStats = true; 01005 const bool writeZeroTimers = false; 01006 bool ignoreMissingTimers = false; // the default 01007 std::string filter = ""; 01008 TimeMonitor::summarize (comm.ptr(), oss, alwaysWriteLocal, writeGlobalStats, 01009 writeZeroTimers, Union, filter, ignoreMissingTimers); 01010 01011 // Echo summarize() output to the FancyOStream out (which is a 01012 // standard unit test argument). Output should only appear in 01013 // show-all-test-details mode. 01014 out << oss.str() << std::endl; 01015 01016 if (comm->getSize() > 1) { 01017 // The min should be 0 01018 size_t substr_i = oss.str().find ("0 (0)"); 01019 TEST_INEQUALITY(substr_i, std::string::npos); 01020 } 01021 01022 //version 2, no comm provided 01023 std::ostringstream oss2; 01024 TimeMonitor::summarize (oss2, alwaysWriteLocal, writeGlobalStats, 01025 writeZeroTimers, Union, filter, ignoreMissingTimers); 01026 out << oss2.str() << std::endl; 01027 if (comm->getSize() > 1) { 01028 // The min should be 0 01029 size_t substr_i = oss2.str().find ("0 (0)"); 01030 TEST_INEQUALITY(substr_i, std::string::npos); 01031 } 01032 01034 // test two versions of summarize with *non* default behavior 01036 //version 1, comm provided 01037 ignoreMissingTimers = true; // NOT the default 01038 std::ostringstream oss3; 01039 TimeMonitor::summarize (comm.ptr(), oss3, alwaysWriteLocal, writeGlobalStats, 01040 writeZeroTimers, Union, filter, ignoreMissingTimers); 01041 out << oss3.str() << std::endl; 01042 01043 // The min should be different from 0 01044 size_t substr_i = oss3.str().find ("0 (0)"); 01045 TEST_EQUALITY(substr_i, std::string::npos); 01046 01047 //version 2, no comm provided 01048 std::ostringstream oss4; 01049 TimeMonitor::summarize (oss4, alwaysWriteLocal, writeGlobalStats, 01050 writeZeroTimers, Union, filter, ignoreMissingTimers); 01051 out << oss4.str() << std::endl; 01052 // The min should be different from 0 01053 substr_i = oss4.str().find ("0 (0)"); 01054 TEST_EQUALITY(substr_i, std::string::npos); 01055 01056 // This sets up for the next unit test (if there is one). 01057 TimeMonitor::clearCounters (); 01058 } 01059 01060 } // namespace Teuchos
1.7.6.1