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