Teuchos Package Browser (Single Doxygen Collection)  Version of the Day
TimeMonitor_UnitTests.cpp
Go to the documentation of this file.
1 /*
2 // @HEADER
3 // ***********************************************************************
4 //
5 // Teuchos: Common Tools Package
6 // Copyright (2004) Sandia Corporation
7 //
8 // Under terms of Contract DE-AC04-94AL85000, there is a non-exclusive
9 // license for use of this work by or on behalf of the U.S. Government.
10 //
11 // Redistribution and use in source and binary forms, with or without
12 // modification, are permitted provided that the following conditions are
13 // met:
14 //
15 // 1. Redistributions of source code must retain the above copyright
16 // notice, this list of conditions and the following disclaimer.
17 //
18 // 2. Redistributions in binary form must reproduce the above copyright
19 // notice, this list of conditions and the following disclaimer in the
20 // documentation and/or other materials provided with the distribution.
21 //
22 // 3. Neither the name of the Corporation nor the names of the
23 // contributors may be used to endorse or promote products derived from
24 // this software without specific prior written permission.
25 //
26 // THIS SOFTWARE IS PROVIDED BY SANDIA CORPORATION "AS IS" AND ANY
27 // EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
28 // IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR
29 // PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL SANDIA CORPORATION OR THE
30 // CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL,
31 // EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO,
32 // PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR
33 // PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF
34 // LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING
35 // NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS
36 // SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
37 //
38 // Questions? Contact Michael A. Heroux (maherou@sandia.gov)
39 //
40 // ***********************************************************************
41 // @HEADER
42 */
43 
44 #include "Teuchos_TimeMonitor.hpp"
45 #include "Teuchos_DefaultComm.hpp"
47 
48 // slowLoop does not reliably make a timer nonzero (RHEL6, gcc 4.4.7, OpenMPI 1.5.4).
49 // Thus, I'm introducing headers to make sleep() available.
50 #ifndef ICL
51 #include <unistd.h>
52 #else
53 void sleep(int sec)
54 {
55  Sleep(sec);
56 }
57 #endif
58 
59 #ifdef _MSC_VER
60 #pragma comment(lib, "Ws2_32.lib")
61 # include <Winsock2.h>
62 # include <process.h>
63 void sleep(int sec)
64 {
65  Sleep(sec * 1000);
66 }
67 #endif
68 
69 namespace {
70 
71  void func_time_monitor1()
72  {
73  TEUCHOS_FUNC_TIME_MONITOR("FUNC_TIME_MONITOR1");
74  }
75 
76 
77  void func_time_monitor2()
78  {
79  TEUCHOS_FUNC_TIME_MONITOR("FUNC_TIME_MONITOR2");
80  {
81  TEUCHOS_FUNC_TIME_MONITOR_DIFF("FUNC_TIME_MONITOR2_inner", inner);
82  }
83  }
84 
85  // This function is commented out because no code in this file
86  // actually uses it. Commenting it out avoids compiler warnings
87  // ("unused function").
88 #if 0
89  // Slowly compute the n-th Fibonacci number. This gives timers
90  // something to time. Be careful not to make n too large, or you'll
91  // run out of stack space.
92  int
93  fib (const int n)
94  {
95  if (n <= 0) {
96  return 0;
97  } else if (n == 1) {
98  return 1;
99  }
100  else {
101  // You should never compute the n-th Fibonacci number like this.
102  // This is exponentially slow in n. The point of using a slow
103  // algorithm like this is to exercise timers.
104  return fib (n-1) + fib (n-2);
105  }
106  }
107 #endif // 0
108 
109  // Do a number of arithmetic operations proportional to n^3, in
110  // order to have something to time. Unlike the recursive function
111  // fib() commented out above, this function shouldn't take up a lot
112  // of stack space.
113  double
114  slowLoop (const size_t n)
115  {
116  const double inc = 1 / static_cast<double> (n);
117  double x = 1.0;
118 
119  for (size_t i = 0; i < n; ++i) {
120  for (size_t j = 0; j < n; ++j) {
121  for (size_t k = 0; k < n; ++k) {
122  x = x + inc;
123  }
124  }
125  }
126  return x;
127  }
128 
129 } // namespace (anonymous)
130 
131 
132 namespace Teuchos {
133  //
134  // Basic TimeMonitor test: create and exercise a timer on all (MPI)
135  // processes, and make sure that TimeMonitor::summarize() reports it.
136  //
137  TEUCHOS_UNIT_TEST( TimeMonitor, FUNC_TIME_MONITOR )
138  {
140  using Teuchos::parameterList;
141  using Teuchos::RCP;
142 
143  func_time_monitor1 (); // Function to time.
144 
145  { // Repeat test for default output format.
146  std::ostringstream oss;
148 
149  // Echo summarize() output to the FancyOStream out (which is a
150  // standard unit test argument). Output should only appear in
151  // show-all-test-details mode.
152  out << oss.str () << std::endl;
153 
154  // Make sure that the timer's name shows up in the output.
155  const size_t substr_i = oss.str ().find ("FUNC_TIME_MONITOR1");
156  TEST_INEQUALITY(substr_i, std::string::npos);
157  }
158 
159  { // Repeat test for YAML output, compact style.
160  std::ostringstream oss;
161  RCP<ParameterList> reportParams =
162  parameterList (* (TimeMonitor::getValidReportParameters ()));
163  reportParams->set ("Report format", "YAML");
164  reportParams->set ("YAML style", "compact");
165  TimeMonitor::report (oss, reportParams);
166 
167  // Echo output to the FancyOStream out (which is a standard unit
168  // test argument). Output should only appear in "show all test
169  // details" mode.
170  out << oss.str () << std::endl;
171 
172  // Make sure that the timer's name shows up in the output.
173  const size_t substr_i = oss.str ().find ("FUNC_TIME_MONITOR1");
174  TEST_INEQUALITY(substr_i, std::string::npos);
175  }
176 
177  { // Repeat test for YAML output, spacious style.
178  std::ostringstream oss;
179  RCP<ParameterList> reportParams =
180  parameterList (* (TimeMonitor::getValidReportParameters ()));
181  reportParams->set ("Report format", "YAML");
182  reportParams->set ("YAML style", "spacious");
183  TimeMonitor::report (oss, reportParams);
184 
185  // Echo output to the FancyOStream out (which is a standard unit
186  // test argument). Output should only appear in "show all test
187  // details" mode.
188  out << oss.str () << std::endl;
189 
190  // Make sure that the timer's name shows up in the output.
191  const size_t substr_i = oss.str ().find ("FUNC_TIME_MONITOR1");
192  TEST_INEQUALITY(substr_i, std::string::npos);
193  }
194 
195  // This sets up for the next unit test.
197  }
198 
199  //
200  // Test for TimeMonitor's enableTimer and disableTimer methods.
201  //
203  {
204  using Teuchos::Array;
205  using Teuchos::OSTab;
207  using Teuchos::parameterList;
208  using Teuchos::RCP;
209  using Teuchos::rcpFromRef;
210  using Teuchos::Time;
211  using Teuchos::TimeMonitor;
212  using std::endl;
213  typedef Teuchos::Array<RCP<Time> >::size_type size_type;
214 
215  out << "Testing TimeMonitor's disableTimer() and enableTimer() methods"
216  << endl;
217  OSTab (rcpFromRef (out));
218 
219  out << "Creating timers" << endl;
220  const int numTrials = 5;
221  const int numTimers = 3;
222  Array<RCP<Time> > timers (numTimers);
223  for (size_type i = 0; i < numTimers; ++i) {
224  std::ostringstream os; // construct timer name
225  os << "Timer " << i;
226  timers[i] = TimeMonitor::getNewTimer (os.str ());
227  }
228 
229  out << "Running all timers without disabling any" << endl;
230  // The actual number of operations in slowloop is proportional to
231  // the cube of the loop length. Adjust loopLength as necessary to
232  // ensure the timer reports a nonzero elapsed time for each of the
233  // invocations.
234  const size_t loopLength = 25;
235  for (int k = 0; k < numTrials; ++k) {
236  for (size_type i = 0; i < numTimers; ++i) {
237  TimeMonitor timeMon (* timers[i]);
238  slowLoop (loopLength);
239  }
240  }
241  for (size_type i = 0; i < numTimers; ++i) {
242  TEST_EQUALITY( timers[i]->numCalls(), numTrials );
243  }
244 
245  out << "Disabling one timer and trying again" << endl;
246  // Disable timers[0] only, and repeat the above loops.
248  for (int k = 0; k < numTrials; ++k) {
249  for (size_type i = 0; i < numTimers; ++i) {
250  TimeMonitor timeMon (* timers[i]);
251  slowLoop (loopLength);
252  }
253  }
254  TEST_EQUALITY( timers[0]->numCalls(), numTrials );
255  for (size_type i = 1; i < numTimers; ++i) {
256  TEST_EQUALITY( timers[i]->numCalls(), 2*numTrials );
257  }
258 
259  out << "Reenabling the timer and trying again" << endl;
260  // Enable timers[0] and repeat the above loops.
261  TEST_NOTHROW( TimeMonitor::enableTimer ("Timer 0") );
262  for (int k = 0; k < numTrials; ++k) {
263  for (size_type i = 0; i < numTimers; ++i) {
264  TimeMonitor timeMon (* timers[i]);
265  slowLoop (loopLength);
266  }
267  }
268  TEST_EQUALITY( timers[0]->numCalls(), 2*numTrials );
269  for (size_type i = 1; i < numTimers; ++i) {
270  TEST_EQUALITY( timers[i]->numCalls(), 3*numTrials );
271  }
272 
273  out << "Test that summarize() reports enabled and disabled timers" << endl;
274  // Make sure that summarize() reports all timers. Disabling a
275  // timer must _not_ exclude it from the list of timers printed by
276  // summarize(). Disable a different timer this time just for fun.
278  {
279  std::ostringstream oss;
281 
282  // Echo summarize() output to the FancyOStream out (which is a
283  // standard unit test argument). Output should only appear in
284  // show-all-test-details mode.
285  out << oss.str () << std::endl;
286 
287  // Make sure that each timer's name shows up in the output.
288  for (size_type i = 0; i < numTimers; ++i) {
289  const std::string name = timers[i]->name ();
290  const size_t substr_i = oss.str ().find (name);
291  TEST_INEQUALITY(substr_i, std::string::npos);
292  }
293  }
294 
295  // This sets up for the next unit test.
297  }
298 
299 
300  //
301  // Test correct quoting of labels for TimeMonitor's YAML output.
302  //
303  TEUCHOS_UNIT_TEST( TimeMonitor, YamlLabelQuoting )
304  {
305  using Teuchos::Array;
307  using Teuchos::parameterList;
308  using Teuchos::RCP;
309  using Teuchos::Time;
310  typedef Array<std::string>::size_type size_type;
311 
312  Array<std::string> inputLabels, outputLabels;
313 
314  // Make sure to exercise things that don't need quoting, like
315  // spaces and certain punctuation, as well as things that do need
316  // quoting, like colons, inner double quotes, and backslashes.
317  inputLabels.push_back ("NoQuotingNeeded");
318  inputLabels.push_back ("No quoting needed");
319  inputLabels.push_back ("\"AlreadyQuotedNoQuotingNeeded\"");
320  inputLabels.push_back ("\"Already quoted, no quoting needed\"");
321  inputLabels.push_back ("\"Already quoted: quoting needed\"");
322  inputLabels.push_back ("NotQuoted:QuotingNeeded");
323  inputLabels.push_back ("Not quoted: quoting needed");
324  // Test both individual double quotes, and pairs of double quotes.
325  inputLabels.push_back ("Not quoted \" quoting needed");
326  inputLabels.push_back ("Not quoted \" \" quoting needed");
327  inputLabels.push_back ("\"Already quoted \" quoting needed\"");
328  inputLabels.push_back ("\"Already quoted \" \" quoting needed\"");
329  // Remember that in C strings, a double backslash turns into a
330  // single backslash. Our YAML output routine should turn each
331  // single backslash back into a double backslash.
332  inputLabels.push_back ("Not quoted \\ quoting needed");
333  inputLabels.push_back ("Not quoted \\\\ quoting needed");
334  inputLabels.push_back ("Not quoted \\ \\ quoting needed");
335  inputLabels.push_back ("\"Already quoted \\ quoting needed\"");
336  inputLabels.push_back ("\"Already quoted \\\\ quoting needed\"");
337  inputLabels.push_back ("\"Already quoted \\ \\ quoting needed\"");
338 
339  outputLabels.push_back ("NoQuotingNeeded");
340  outputLabels.push_back ("No quoting needed");
341  outputLabels.push_back ("\"AlreadyQuotedNoQuotingNeeded\"");
342  outputLabels.push_back ("\"Already quoted, no quoting needed\"");
343  outputLabels.push_back ("\"Already quoted: quoting needed\"");
344  outputLabels.push_back ("\"NotQuoted:QuotingNeeded\"");
345  outputLabels.push_back ("\"Not quoted: quoting needed\"");
346  outputLabels.push_back ("\"Not quoted \\\" quoting needed\"");
347  outputLabels.push_back ("\"Not quoted \\\" \\\" quoting needed\"");
348  outputLabels.push_back ("\"Already quoted \\\" quoting needed\"");
349  outputLabels.push_back ("\"Already quoted \\\" \\\" quoting needed\"");
350  outputLabels.push_back ("\"Not quoted \\\\ quoting needed\"");
351  outputLabels.push_back ("\"Not quoted \\\\\\\\ quoting needed\"");
352  outputLabels.push_back ("\"Not quoted \\\\ \\\\ quoting needed\"");
353  outputLabels.push_back ("\"Already quoted \\\\ quoting needed\"");
354  outputLabels.push_back ("\"Already quoted \\\\\\\\ quoting needed\"");
355  outputLabels.push_back ("\"Already quoted \\\\ \\\\ quoting needed\"");
356 
357  // Sanity check.
359  inputLabels.size () != outputLabels.size (),
360  std::logic_error,
361  "The number of input labels is different than the number of output labels."
362  " Please ask a Teuchos developer to make sure that every test input "
363  "label has a corresponding output label.");
364 
365  Array<RCP<Time> > timers;
366  for (size_type i = 0; i < inputLabels.size (); ++i) {
367  timers.push_back (TimeMonitor::getNewCounter (inputLabels[i]));
368  }
369 
370  // The actual number of operations in the loop is proportional to
371  // the cube of the loop length. Adjust the quantities below as
372  // necessary to ensure the timer reports a nonzero elapsed time
373  // for each of the invocations.
374  const size_t loopLength = 25;
375  for (int k = 0; k < 3; ++k) {
376  for (size_type i = 0; i < timers.size (); ++i) {
377  TimeMonitor timeMon (* timers[i]);
378  slowLoop (loopLength);
379  }
380  }
381 
382  { // YAML output, compact style.
383  std::ostringstream oss;
384  RCP<ParameterList> reportParams =
385  parameterList (* (TimeMonitor::getValidReportParameters ()));
386  reportParams->set ("Report format", "YAML");
387  reportParams->set ("YAML style", "compact");
388  TimeMonitor::report (oss, reportParams);
389 
390  // Echo output to the FancyOStream out (which is a standard unit
391  // test argument). Output should only appear in "show all test
392  // details" mode.
393  out << oss.str () << std::endl;
394 
395  // Make sure that all timer labels appear correctly in the output.
396  for (size_type i = 0; i < inputLabels.size(); ++i) {
397  const size_t pos = oss.str ().find (outputLabels[i]);
398  TEST_INEQUALITY(pos, std::string::npos);
399  }
400  }
401 
402  { // YAML output, spacious style.
403  std::ostringstream oss;
404  RCP<ParameterList> reportParams =
405  parameterList (* (TimeMonitor::getValidReportParameters ()));
406  reportParams->set ("Report format", "YAML");
407  reportParams->set ("YAML style", "spacious");
408  TimeMonitor::report (oss, reportParams);
409 
410  // Echo output to the FancyOStream out (which is a standard unit
411  // test argument). Output should only appear in "show all test
412  // details" mode.
413  out << oss.str () << std::endl;
414 
415  // Make sure that all timer labels appear correctly in the output.
416  for (size_type i = 0; i < inputLabels.size(); ++i) {
417  const size_t pos = oss.str ().find (outputLabels[i]);
418  TEST_INEQUALITY(pos, std::string::npos);
419  }
420  }
421 
422  // This sets up for the next unit test.
424  }
425 
426 
427  //
428  // Test filtering of timer labels.
429  //
430  TEUCHOS_UNIT_TEST( TimeMonitor, TimerLabelFiltering )
431  {
432  using Teuchos::Array;
434  using Teuchos::parameterList;
435  using Teuchos::RCP;
436  using Teuchos::Time;
437  typedef Array<std::string>::size_type size_type;
438 
439  // Filters to use in the test.
440  Array<std::string> filters;
441  filters.push_back ("Foo:");
442  filters.push_back ("Bar:");
443  filters.push_back ("Baz:");
444 
445  // All the timer labels.
446  Array<std::string> labels;
447  labels.push_back ("Foo: timer 1");
448  labels.push_back ("Foo: timer 2");
449  labels.push_back ("Foo: timer 3");
450  labels.push_back ("Bar: timer 1");
451  labels.push_back ("Bar: timer 2");
452  labels.push_back ("Baz: timer 1");
453  labels.push_back ("Xyzzy");
454  labels.push_back ("This is not a pipe");
455  labels.push_back ("You should not see this");
456 
457  Array<Array<std::string> > outLabels (3);
458  // Label(s) that should be printed for filters[0]
459  outLabels[0].push_back ("Foo: timer 1");
460  outLabels[0].push_back ("Foo: timer 2");
461  outLabels[0].push_back ("Foo: timer 3");
462  // Label(s) that should be printed for filters[1]
463  outLabels[1].push_back ("Bar: timer 1");
464  outLabels[1].push_back ("Bar: timer 2");
465  // Label(s) that should be printed for filters[2]
466  outLabels[2].push_back ("Baz: timer 1");
467 
468  // Labels that should not be printed for any of the filters below.
469  Array<std::string> otherLabels;
470  otherLabels.push_back ("Xyzzy");
471  otherLabels.push_back ("This is not a pipe");
472  otherLabels.push_back ("You should not see this");
473 
474  Array<RCP<Time> > timers;
475  for (size_type i = 0; i < labels.size (); ++i) {
476  timers.push_back (TimeMonitor::getNewCounter (labels[i]));
477  }
478 
479  // The actual number of operations in the loop is proportional to
480  // the cube of the loop length. Adjust the quantities below as
481  // necessary to ensure the timer reports a nonzero elapsed time
482  // for each of the invocations.
483  const size_t loopLength = 25;
484  for (int k = 0; k < 3; ++k) {
485  for (size_type i = 0; i < timers.size (); ++i) {
486  TimeMonitor timeMon (* timers[i]);
487  slowLoop (loopLength);
488  }
489  }
490 
491  try {
492  // FIXME (mfh 21 Aug 2012) We don't yet have a test ensuring that
493  // the filter only selects at the beginning of the timer label.
494 
495  // Test for each filter.
496  for (size_type i = 0; i < filters.size (); ++i) {
497  { // Default (tabular) output format.
498  std::ostringstream oss;
499  RCP<ParameterList> reportParams =
500  parameterList (* (TimeMonitor::getValidReportParameters ()));
501  TimeMonitor::report (oss, filters[i], reportParams);
502 
503  // Echo output to the FancyOStream out (which is a standard unit
504  // test argument). Output should only appear in "show all test
505  // details" mode.
506  out << oss.str () << std::endl;
507 
508  // Check whether the labels that were supposed to be printed
509  // were actually printed.
510  for (size_type j = 0; j < outLabels[i].size(); ++j) {
511  const size_t pos = oss.str ().find (outLabels[i][j]);
512  TEST_INEQUALITY(pos, std::string::npos);
513  }
514 
515  // Check whether the labels that were _not_ supposed to be
516  // printed were actually printed.
517  //
518  // First, check the labels that should only be printed with
519  // the other filters.
520  for (size_type ii = 0; ii < outLabels.size(); ++ii) {
521  if (ii != i) {
522  for (size_type j = 0; j < outLabels[ii].size(); ++j) {
523  const size_t pos = oss.str ().find (outLabels[ii][j]);
524  TEST_EQUALITY(pos, std::string::npos);
525  }
526  }
527  }
528  // Next, check the labels that should not be printed for any
529  // filters.
530  for (size_type j = 0; j < otherLabels.size(); ++j) {
531  const size_t pos = oss.str ().find (otherLabels[j]);
532  TEST_EQUALITY(pos, std::string::npos);
533  }
534  }
535 
536  { // YAML output, compact style.
537  std::ostringstream oss;
538  RCP<ParameterList> reportParams =
539  parameterList (* (TimeMonitor::getValidReportParameters ()));
540  reportParams->set ("Report format", "YAML");
541  reportParams->set ("YAML style", "compact");
542  TimeMonitor::report (oss, filters[i], reportParams);
543 
544  // Echo output to the FancyOStream out (which is a standard unit
545  // test argument). Output should only appear in "show all test
546  // details" mode.
547  out << oss.str () << std::endl;
548 
549  // Check whether the labels that were supposed to be printed
550  // were actually printed.
551  for (size_type j = 0; j < outLabels[i].size(); ++j) {
552  const size_t pos = oss.str ().find (outLabels[i][j]);
553  TEST_INEQUALITY(pos, std::string::npos);
554  }
555 
556  // Check whether the labels that were _not_ supposed to be
557  // printed were actually printed.
558  //
559  // First, check the labels that should only be printed with
560  // the other filters.
561  for (size_type ii = 0; ii < outLabels.size(); ++ii) {
562  if (ii != i) {
563  for (size_type j = 0; j < outLabels[ii].size(); ++j) {
564  const size_t pos = oss.str ().find (outLabels[ii][j]);
565  TEST_EQUALITY(pos, std::string::npos);
566  }
567  }
568  }
569  // Next, check the labels that should not be printed for any
570  // filters.
571  for (size_type j = 0; j < otherLabels.size(); ++j) {
572  const size_t pos = oss.str ().find (otherLabels[j]);
573  TEST_EQUALITY(pos, std::string::npos);
574  }
575  }
576 
577  { // YAML output, spacious style.
578  std::ostringstream oss;
579  RCP<ParameterList> reportParams =
580  parameterList (* (TimeMonitor::getValidReportParameters ()));
581  reportParams->set ("Report format", "YAML");
582  reportParams->set ("YAML style", "spacious");
583  TimeMonitor::report (oss, filters[i], reportParams);
584 
585  // Echo output to the FancyOStream out (which is a standard unit
586  // test argument). Output should only appear in "show all test
587  // details" mode.
588  out << oss.str () << std::endl;
589 
590  // Check whether the labels that were supposed to be printed
591  // were actually printed.
592  for (size_type j = 0; j < outLabels[i].size(); ++j) {
593  const size_t pos = oss.str ().find (outLabels[i][j]);
594  TEST_INEQUALITY(pos, std::string::npos);
595  }
596 
597  // Check whether the labels that were _not_ supposed to be
598  // printed were actually printed.
599  //
600  // First, check the labels that should only be printed with
601  // the other filters.
602  for (size_type ii = 0; ii < outLabels.size(); ++ii) {
603  if (ii != i) {
604  for (size_type j = 0; j < outLabels[ii].size(); ++j) {
605  const size_t pos = oss.str ().find (outLabels[ii][j]);
606  TEST_EQUALITY(pos, std::string::npos);
607  }
608  }
609  }
610  // Next, check the labels that should not be printed for any
611  // filters.
612  for (size_type j = 0; j < otherLabels.size(); ++j) {
613  const size_t pos = oss.str ().find (otherLabels[j]);
614  TEST_EQUALITY(pos, std::string::npos);
615  }
616  }
617  }
618  }
619  catch (...) {
620  // Make sure to clear the counters, so that they don't pollute
621  // the remaining tests. (The Teuchos unit test framework may
622  // catch any exceptions that the above code throws, but allow
623  // the remaining tests to continue.)
625  throw;
626  }
627 
628  // This sets up for the next unit test.
630  }
631 
632 
633 
634  //
635  // TimeMonitor nested timers test: create two timers on all (MPI)
636  // processes, use the second inside the scope of the first, and make
637  // sure that TimeMonitor::summarize() reports both timers.
638  //
639  TEUCHOS_UNIT_TEST( TimeMonitor, FUNC_TIME_MONITOR_tested )
640  {
642  using Teuchos::parameterList;
643  using Teuchos::RCP;
644 
645  func_time_monitor2 ();
646 
647  {
648  std::ostringstream oss;
650 
651  // Echo summarize() output to the FancyOStream out (which is a
652  // standard unit test argument). Output should only appear in
653  // show-all-test-details mode.
654  out << oss.str() << std::endl;
655 
656  const size_t substr_i = oss.str().find ("FUNC_TIME_MONITOR2");
657  TEST_INEQUALITY(substr_i, std::string::npos);
658  const size_t substr_inner_i = oss.str().find ("FUNC_TIME_MONITOR2_inner");
659  TEST_INEQUALITY(substr_inner_i, std::string::npos);
660  }
661 
662  { // Repeat test for YAML output, compact style.
663  std::ostringstream oss;
664  RCP<ParameterList> reportParams =
665  parameterList (* (TimeMonitor::getValidReportParameters ()));
666  reportParams->set ("Report format", "YAML");
667  reportParams->set ("YAML style", "compact");
668  TimeMonitor::report (oss, reportParams);
669 
670  // Echo output to the FancyOStream out (which is a standard unit
671  // test argument). Output should only appear in "show all test
672  // details" mode.
673  out << oss.str () << std::endl;
674 
675  const size_t substr_i = oss.str().find ("FUNC_TIME_MONITOR2");
676  TEST_INEQUALITY(substr_i, std::string::npos);
677  const size_t substr_inner_i = oss.str().find ("FUNC_TIME_MONITOR2_inner");
678  TEST_INEQUALITY(substr_inner_i, std::string::npos);
679  }
680 
681  { // Repeat test for YAML output, spacious style.
682  std::ostringstream oss;
683  RCP<ParameterList> reportParams =
684  parameterList (* (TimeMonitor::getValidReportParameters ()));
685  reportParams->set ("Report format", "YAML");
686  reportParams->set ("YAML style", "spacious");
687  TimeMonitor::report (oss, reportParams);
688 
689  // Echo output to the FancyOStream out (which is a standard unit
690  // test argument). Output should only appear in "show all test
691  // details" mode.
692  out << oss.str () << std::endl;
693 
694  const size_t substr_i = oss.str().find ("FUNC_TIME_MONITOR2");
695  TEST_INEQUALITY(substr_i, std::string::npos);
696  const size_t substr_inner_i = oss.str().find ("FUNC_TIME_MONITOR2_inner");
697  TEST_INEQUALITY(substr_inner_i, std::string::npos);
698  }
699 
700  // This sets up for the next unit test.
702  }
703 
704  //
705  // Test whether TimeMonitor::summarize() does the right thing when
706  // different MPI processes create different sets of timers. This
707  // test is only meaningful if running with more than one MPI
708  // process, but it should also pass if running in a non-MPI build or
709  // with only one MPI process.
710  //
711  TEUCHOS_UNIT_TEST( TimeMonitor, SUMMARIZE_diffTimerSets )
712  {
714  const int numProcs = comm->getSize ();
715  const int myRank = comm->getRank ();
716 
717  // If MPI has not been initialized, turn the MPI communicator into
718  // a "serial" communicator. This may not be necessary when using
719  // the Teuchos Unit Test Framework.
720 #ifdef HAVE_MPI
721  {
722  int mpiHasBeenInitialized = 0;
723  MPI_Initialized (&mpiHasBeenInitialized);
724  if (! mpiHasBeenInitialized) {
726  }
727  }
728 #endif // HAVE_MPI
729 
730  // Store the output of TimeMonitor::summarize() here.
731  std::ostringstream oss;
732 
733  // Timer A gets created on all MPI processes.
734  // Timer B only gets created on Proc 0.
735  RCP<Time> timerA = TimeMonitor::getNewCounter ("Timer A");
736  RCP<Time> timerB;
737  if (myRank == 0) {
738  timerB = TimeMonitor::getNewCounter ("Timer B");
739  }
740  else {
741  timerB = null; // True anyway, but I want to make this explicit.
742  }
743 
744  // The actual number of operations in the loop is proportional to
745  // the cube of the loop length. Adjust the quantities below as
746  // necessary to ensure the timer reports a nonzero elapsed time
747  // for each of the invocations.
748  const size_t timerA_loopLength = 150;
749  const size_t timerB_loopLength = 200;
750 
751  // Timer A gets a call count of 3.
752  for (size_t k = 0; k < 3; ++k) {
753  TimeMonitor monitorA (*timerA);
754  slowLoop (timerA_loopLength);
755  }
756  if (myRank == 0) { // Timer B gets a call count of 1 on Proc 0.
757  TimeMonitor monitorB (*timerB);
758  slowLoop (timerB_loopLength);
759  }
760 
761  const bool alwaysWriteLocal = false; // the default
762  const bool writeGlobalStats = true; // the default
763  const bool writeZeroTimers = true; // the default
764  TimeMonitor::summarize (oss, alwaysWriteLocal, writeGlobalStats,
765  writeZeroTimers, Intersection);
766 
767  // Echo summarize() output to the FancyOStream out (which is a
768  // standard unit test argument). Output should only appear in
769  // show-all-test-details mode.
770  out << std::endl << "Testing intersection of timers:" << std::endl
771  << oss.str() << std::endl;
772 
773  // Since setOp == Intersection, only Timer A should be reported,
774  // unless there is only one (MPI) process.
775  size_t substr_i = oss.str().find ("Timer A");
776  TEST_INEQUALITY(substr_i, std::string::npos);
777  if (numProcs > 1) {
778  substr_i = oss.str().find ("Timer B");
779  TEST_EQUALITY(substr_i, std::string::npos);
780  }
781 
782  // Now call summarize(), but ask for a union of timers.
783  std::ostringstream ossUnion;
784  TimeMonitor::summarize (ossUnion, alwaysWriteLocal, writeGlobalStats,
785  writeZeroTimers, Union);
786 
787  // Echo summarize() output to the FancyOStream out (which is a
788  // standard unit test argument). Output should only appear in
789  // show-all-test-details mode.
790  out << std::endl << "Testing union of timers:" << std::endl
791  << ossUnion.str() << std::endl;
792 
793  // Since setOp == Union, both Timer A and Timer B should be
794  // reported.
795  substr_i = ossUnion.str().find ("Timer A");
796  TEST_INEQUALITY(substr_i, std::string::npos);
797  substr_i = ossUnion.str().find ("Timer B");
798  TEST_INEQUALITY(substr_i, std::string::npos);
799 
800  // This sets up for the next unit test.
802  }
803 
804  //
805  // Test whether the option to filter out zero timers works, for the
806  // case that all (MPI) processes have the same call counts.
807  //
808  TEUCHOS_UNIT_TEST( TimeMonitor, FILTER_ZERO_TIMERS_sameParallelCallCounts )
809  {
810  // Store the output of TimeMonitor::summarize() here.
811  std::ostringstream oss;
812 
813  RCP<Time> timerA = TimeMonitor::getNewCounter ("Timer A");
814  RCP<Time> timerB = TimeMonitor::getNewCounter ("Timer B");
815  RCP<Time> timerC = TimeMonitor::getNewCounter ("Timer C");
816 
817  // Timers A and B get nonzero elapsed times and call counts on all
818  // (MPI) processes. Timer C never gets started, so it should have
819  // a zero elapsed time and zero call count on all processes.
820 
821  // The actual number of operations in the loop is proportional to
822  // the cube of the loop length. Adjust the quantities below as
823  // necessary to ensure the timer reports a nonzero elapsed time
824  // for each of the invocations.
825  const size_t timerA_loopLength = 200;
826  const size_t timerB_loopLength = 250;
827 
828  // Timer A gets a call count of 3.
829  for (size_t k = 0; k < 3; ++k) {
830  TimeMonitor monitorA (*timerA);
831  slowLoop (size_t (timerA_loopLength));
832  }
833  // Timer B gets a call count of 1.
834  {
835  TimeMonitor monitorB (*timerB);
836  slowLoop (size_t (timerB_loopLength));
837  }
838 
839  const bool alwaysWriteLocal = false; // the default
840  const bool writeGlobalStats = true; // the default
841  const bool writeZeroTimers = false; // NOT the default
842  TimeMonitor::summarize (oss, alwaysWriteLocal, writeGlobalStats,
843  writeZeroTimers);
844 
845  // Echo summarize() output to the FancyOStream out (which is a
846  // standard unit test argument). Output should only appear in
847  // show-all-test-details mode.
848  out << oss.str() << std::endl;
849 
850  // Timers A and B should be reported.
851  size_t substr_i = oss.str().find ("Timer A");
852  TEST_INEQUALITY(substr_i, std::string::npos);
853  substr_i = oss.str().find ("Timer B");
854  TEST_INEQUALITY(substr_i, std::string::npos);
855 
856  // Timer C should NOT be reported.
857  substr_i = oss.str().find ("Timer C");
858  TEST_EQUALITY(substr_i, std::string::npos);
859 
860  // This sets up for the next unit test.
862  }
863 
864 
865  //
866  // Test whether the option to filter out zero timers works, for the
867  // case that different (MPI) processes have different call counts.
868  //
869  TEUCHOS_UNIT_TEST( TimeMonitor, FILTER_ZERO_TIMERS_differentParallelCallCounts )
870  {
872  const int myRank = comm->getRank ();
873 
874  // If MPI has not been initialized, turn the MPI communicator into
875  // a "serial" communicator. This may not be necessary when using
876  // the Teuchos Unit Test Framework.
877 #ifdef HAVE_MPI
878  {
879  int mpiHasBeenInitialized = 0;
880  MPI_Initialized (&mpiHasBeenInitialized);
881  if (! mpiHasBeenInitialized) {
883  }
884  }
885 #endif // HAVE_MPI
886 
887  // Store the output of TimeMonitor::summarize() here.
888  std::ostringstream oss;
889 
890  RCP<Time> timerA = TimeMonitor::getNewCounter ("Timer A");
891  RCP<Time> timerB = TimeMonitor::getNewCounter ("Timer B");
892  RCP<Time> timerC = TimeMonitor::getNewCounter ("Timer C");
893 
894  // Timer A gets a nonzero elapsed time and call count on Proc 0,
895  // but a zero elapsed time and call count elsewhere.
896  //
897  // Timer B gets the same nonzero elapsed time and call count on
898  // all MPI procs.
899  //
900  // Timer C gets a zero elapsed time and call count on all procs.
901  //
902  // The actual number of operations in the loop is proportional to
903  // the cube of the loop length. Adjust the quantities below as
904  // necessary to ensure the timer reports a nonzero elapsed time
905  // for each of the invocations.
906  const size_t timerA_loopLength = 200;
907  const size_t timerB_loopLength = 500;
908 
909  if (myRank == 0) {
910  // Timer A gets a call count of 3 on Proc 0.
911  for (int k = 0; k < 3; ++k) {
912  TimeMonitor monitorA (*timerA);
913  slowLoop (size_t (timerA_loopLength));
914  }
915  }
916 
917  // Timer B gets a call count of 1 on all procs.
918  {
919  TimeMonitor monitorB (*timerB);
920  slowLoop (size_t (timerB_loopLength));
921  }
922 
923  const bool alwaysWriteLocal = false; // the default
924  const bool writeGlobalStats = true; // the default
925  const bool writeZeroTimers = false; // NOT the default
926  TimeMonitor::summarize (oss, alwaysWriteLocal, writeGlobalStats,
927  writeZeroTimers, Union);
928 
929  // Echo summarize() output to the FancyOStream out (which is a
930  // standard unit test argument). Output should only appear in
931  // show-all-test-details mode.
932  out << oss.str() << std::endl;
933 
934  // Timers A and B should both be reported.
935  size_t substr_i = oss.str().find ("Timer A");
936  TEST_INEQUALITY(substr_i, std::string::npos);
937  substr_i = oss.str().find ("Timer B");
938  TEST_INEQUALITY(substr_i, std::string::npos);
939 
940  // Timer C should NOT be reported.
941  substr_i = oss.str().find ("Timer C");
942  TEST_EQUALITY(substr_i, std::string::npos);
943 
944  // This sets up for the next unit test (if there is one).
946  }
947 
948  //
949  // Test option to disregard missing timers from processes in TimeMonitor::summarize().
950  //
951  TEUCHOS_UNIT_TEST( TimeMonitor, IgnoreMissingTimers )
952  {
954  const int myRank = comm->getRank ();
955 
956 #ifdef HAVE_MPI
957  {
958  int mpiHasBeenInitialized = 0;
959  MPI_Initialized (&mpiHasBeenInitialized);
960  if (! mpiHasBeenInitialized) {
962  }
963  }
964 #endif // HAVE_MPI
965 
966  // Store the output of TimeMonitor::summarize() here.
967  std::ostringstream oss;
968 
969  std::string timerName="Timer Z";
970  // Timer Z appears on all PIDs except 0.
971  {
972  switch (myRank) {
973  case 1 :
974  break;
975  case 0 :
976  {
977  RCP<Time> timer = TimeMonitor::getNewCounter (timerName);
978  TimeMonitor monitor (*timer);
979  sleep(1);
980  }
981  break;
982  case 2 :
983  {
984  RCP<Time> timer = TimeMonitor::getNewCounter (timerName);
985  TimeMonitor monitor (*timer);
986  sleep(1);
987  }
988  break;
989  default :
990  {
991  RCP<Time> timer = TimeMonitor::getNewCounter (timerName);
992  TimeMonitor monitor (*timer);
993  sleep(1);
994  }
995  }
996  }
997 
999  // test two versions of summarize with default behavior
1001 
1002  //version 1, comm provided
1003  const bool alwaysWriteLocal = false;
1004  const bool writeGlobalStats = true;
1005  const bool writeZeroTimers = false;
1006  bool ignoreMissingTimers = false; // the default
1007  std::string filter = "";
1008  TimeMonitor::summarize (comm.ptr(), oss, alwaysWriteLocal, writeGlobalStats,
1009  writeZeroTimers, Union, filter, ignoreMissingTimers);
1010 
1011  // Echo summarize() output to the FancyOStream out (which is a
1012  // standard unit test argument). Output should only appear in
1013  // show-all-test-details mode.
1014  out << oss.str() << std::endl;
1015 
1016  if (comm->getSize() > 1) {
1017  // The min should be 0
1018  size_t substr_i = oss.str().find ("0 (0)");
1019  TEST_INEQUALITY(substr_i, std::string::npos);
1020  }
1021 
1022  //version 2, no comm provided
1023  std::ostringstream oss2;
1024  TimeMonitor::summarize (oss2, alwaysWriteLocal, writeGlobalStats,
1025  writeZeroTimers, Union, filter, ignoreMissingTimers);
1026  out << oss2.str() << std::endl;
1027  if (comm->getSize() > 1) {
1028  // The min should be 0
1029  size_t substr_i = oss2.str().find ("0 (0)");
1030  TEST_INEQUALITY(substr_i, std::string::npos);
1031  }
1032 
1034  // test two versions of summarize with *non* default behavior
1036  //version 1, comm provided
1037  ignoreMissingTimers = true; // NOT the default
1038  std::ostringstream oss3;
1039  TimeMonitor::summarize (comm.ptr(), oss3, alwaysWriteLocal, writeGlobalStats,
1040  writeZeroTimers, Union, filter, ignoreMissingTimers);
1041  out << oss3.str() << std::endl;
1042 
1043  // The min should be different from 0
1044  size_t substr_i = oss3.str().find ("0 (0)");
1045  TEST_EQUALITY(substr_i, std::string::npos);
1046 
1047  //version 2, no comm provided
1048  std::ostringstream oss4;
1049  TimeMonitor::summarize (oss4, alwaysWriteLocal, writeGlobalStats,
1050  writeZeroTimers, Union, filter, ignoreMissingTimers);
1051  out << oss4.str() << std::endl;
1052  // The min should be different from 0
1053  substr_i = oss4.str().find ("0 (0)");
1054  TEST_EQUALITY(substr_i, std::string::npos);
1055 
1056  // This sets up for the next unit test (if there is one).
1058  }
1059 
1060 } // namespace Teuchos
#define TEUCHOS_FUNC_TIME_MONITOR(FUNCNAME)
Defines a timer for a specific function.
#define TEST_INEQUALITY(v1, v2)
Assert the inequality of v1 and v2.
static Teuchos::RCP< const Comm< OrdinalType > > getDefaultSerialComm(const Teuchos::RCP< const Comm< OrdinalType > > &comm)
Return a serial Comm if the input Comm is null.
static void clearCounters()
"Forget" about all counters created with getNewCounter().
#define TEST_NOTHROW(code)
Asserr that the statement &#39;code&#39; does not thrown any excpetions.
ParameterList & set(std::string const &name, T const &value, std::string const &docString="", RCP< const ParameterEntryValidator > const &validator=null)
Set a parameter whose value has type T.
static RCP< Time > getNewCounter(const std::string &name)
Create a new counter with the specified name and add it to a global set of counters of this type...
#define TEUCHOS_TEST_FOR_EXCEPTION(throw_exception_test, Exception, msg)
Macro for throwing an exception with breakpointing to ease debugging.
static void disableTimer(const std::string &name)
Disable the timer with the given name.
static Teuchos::RCP< const Comm< OrdinalType > > getComm()
Return the default global communicator.
static RCP< const ParameterList > getValidReportParameters()
Default parameters (with validators) for report().
basic_OSTab< char > OSTab
static RCP< Time > getNewTimer(const std::string &name)
Return a new timer with the given name (class method).
TEUCHOS_UNIT_TEST(ConstNonconstObjectContainer, create)
static void summarize(Ptr< const Comm< int > > comm, std::ostream &out=std::cout, const bool alwaysWriteLocal=false, const bool writeGlobalStats=true, const bool writeZeroTimers=true, const ECounterSetOp setOp=Intersection, const std::string &filter="", const bool ignoreZeroTimers=false)
Print summary statistics for all timers on the given communicator.
Wall-clock timer.
size_type size() const
Unit testing support.
A list of parameters of arbitrary type.
void push_back(const value_type &x)
Scope protection wrapper for Teuchos::Time, with timer reporting functionality.
Smart reference counting pointer class for automatic garbage collection.
TEST_EQUALITY(rcp_dynamic_cast< const EnhancedNumberValidator< double > >(castedDep1->getValuesAndValidators().find("val1") ->second, true) ->getMax(), double1Vali->getMax())
Ptr< T > ptr() const
Get a safer wrapper raw C++ pointer to the underlying object.
static void enableTimer(const std::string &name)
Enable the timer with the given name.
A scope-safe timer wrapper class, that can compute global timer statistics.
static void report(Ptr< const Comm< int > > comm, std::ostream &out, const std::string &filter, const RCP< ParameterList > &params=null)
Report timer statistics to the given output stream.
#define TEUCHOS_FUNC_TIME_MONITOR_DIFF(FUNCNAME, DIFF)
Defines a timer for a specific function (with differentiator).
Replacement for std::vector that is compatible with the Teuchos Memory Management classes...