libMesh::PerfLog Class Reference

Responsible for timing and summarizing events. More...

#include <perf_log.h>

Public Member Functions

 PerfLog (const std::string &label_name="", const bool log_events=true)
 
 ~PerfLog ()
 
void clear ()
 
void disable_logging ()
 
void enable_logging ()
 
bool logging_enabled () const
 
void push (const char *label, const char *header="")
 
void push (const std::string &label, const std::string &header="")
 
void pop (const char *label, const char *header="")
 
void pop (const std::string &label, const std::string &header="")
 
void start_event (const std::string &label, const std::string &header="")
 
void stop_event (const std::string &label, const std::string &header="")
 
void pause_event (const std::string &label, const std::string &header="")
 
void restart_event (const std::string &label, const std::string &header="")
 
std::string get_log () const
 
std::string get_info_header () const
 
std::string get_perf_info () const
 
void print_log () const
 
double get_elapsed_time () const
 
double get_active_time () const
 
PerfData get_perf_data (const std::string &label, const std::string &header="")
 
const std::map< std::pair< std::string, std::string >, PerfData > & get_log_raw () const
 

Private Member Functions

void split_on_whitespace (const std::string &input, std::vector< std::string > &output) const
 

Private Attributes

const std::string label_name
 
bool log_events
 
double total_time
 
struct timeval tstart
 
std::map< std::pair< std::string, std::string >, PerfDatalog
 
std::stack< PerfData * > log_stack
 

Static Private Attributes

static bool called = false
 

Detailed Description

Responsible for timing and summarizing events.

The PerfLog class allows monitoring of specific events. An event is defined by a unique string that functions as a label. Each time the event is executed data are recorded. This class is particulary useful for finding performance bottlenecks.

Author
Benjamin Kirk
Date
2003

Definition at line 124 of file perf_log.h.

Constructor & Destructor Documentation

libMesh::PerfLog::PerfLog ( const std::string &  label_name = "",
const bool  log_events = true 
)

Constructor. label_name is the name of the object, which will bw print in the log to distinguish it from other objects. log_events is a flag to optionally disable logging. You can use this flag to turn off logging without touching any other code.

Definition at line 45 of file perf_log.C.

References clear(), libmesh_nullptr, log_events, and tstart.

46  :
47  label_name(ln),
48  log_events(le),
49  total_time(0.)
50 {
51  gettimeofday (&tstart, libmesh_nullptr);
52 
53  if (log_events)
54  this->clear();
55 }
double total_time
Definition: perf_log.h:273
const class libmesh_nullptr_t libmesh_nullptr
const std::string label_name
Definition: perf_log.h:263
void clear()
Definition: perf_log.C:67
struct timeval tstart
Definition: perf_log.h:278
libMesh::PerfLog::~PerfLog ( )

Destructor. Calls clear() and print_log().

Definition at line 59 of file perf_log.C.

References log_events, and print_log().

60 {
61  if (log_events)
62  this->print_log();
63 }
void print_log() const
Definition: perf_log.C:582

Member Function Documentation

void libMesh::PerfLog::clear ( )

Clears all the internal data and restores the data structures to a pristine state. This function checks to see if it is currently monitoring any events, and if so errors. Be sure you are not logging any events when you call this function.

Definition at line 67 of file perf_log.C.

References label_name, libmesh_nullptr, log, log_events, log_stack, and tstart.

Referenced by libMesh::libmesh_terminate_handler(), libMesh::LibMeshInit::LibMeshInit(), and PerfLog().

68 {
69  if (log_events)
70  {
71  // check that all events are closed
72  for (std::map<std::pair<std::string,std::string>, PerfData>::iterator
73  pos = log.begin(); pos != log.end(); ++pos)
74  if (pos->second.open)
75  libmesh_error_msg("ERROR clearning performance log for class " \
76  << label_name \
77  << "\nevent " \
78  << pos->first.second \
79  << " is still being monitored!");
80 
81  gettimeofday (&tstart, libmesh_nullptr);
82 
83  log.clear();
84 
85  while (!log_stack.empty())
86  log_stack.pop();
87  }
88 }
const class libmesh_nullptr_t libmesh_nullptr
std::map< std::pair< std::string, std::string >, PerfData > log
Definition: perf_log.h:285
std::stack< PerfData * > log_stack
Definition: perf_log.h:290
const std::string label_name
Definition: perf_log.h:263
struct timeval tstart
Definition: perf_log.h:278
void libMesh::PerfLog::disable_logging ( )
inline

Disables performance logging for an active object.

Definition at line 155 of file perf_log.h.

Referenced by libMesh::LibMeshInit::LibMeshInit(), and libMesh::Threads::task_scheduler_init::terminate().

155 { log_events = false; }
void libMesh::PerfLog::enable_logging ( )
inline

Enables performance logging for an active object.

Definition at line 160 of file perf_log.h.

Referenced by libMesh::Threads::task_scheduler_init::terminate().

160 { log_events = true; }
double libMesh::PerfLog::get_active_time ( ) const
inline
Returns
The active time

Definition at line 469 of file perf_log.h.

470 {
471  return total_time;
472 }
double total_time
Definition: perf_log.h:273
double libMesh::PerfLog::get_elapsed_time ( ) const
inline
Returns
The total time spent on this event.

Definition at line 457 of file perf_log.h.

References libmesh_nullptr, and libMesh::PerfData::tstart.

458 {
459  struct timeval tnow;
460 
461  gettimeofday (&tnow, libmesh_nullptr);
462 
463  const double elapsed_time = (static_cast<double>(tnow.tv_sec - tstart.tv_sec) +
464  static_cast<double>(tnow.tv_usec - tstart.tv_usec)*1.e-6);
465  return elapsed_time;
466 }
const class libmesh_nullptr_t libmesh_nullptr
struct timeval tstart
Definition: perf_log.h:278
std::string libMesh::PerfLog::get_info_header ( ) const
Returns
A string containing ONLY the information header.

Definition at line 91 of file perf_log.C.

References libMesh::Utility::get_timestamp(), libMesh::global_n_processors(), libMesh::global_processor_id(), log_events, and split_on_whitespace().

Referenced by get_log().

92 {
93  std::ostringstream oss;
94 
95  if (log_events)
96  {
97  std::string date = Utility::get_timestamp();
98 
99  // Get system information
100  struct utsname sysInfo;
101  uname(&sysInfo);
102 
103  // Get user information
104  //
105  // Some systems, for example Crays, actually have getpwuid on the head-node
106  // but (if I understand correctly) a dynamically-linked glibc is not available
107  // on the backend, which is running a reduced operating system like Compute
108  // Node Linux. Thus functions like getpwuid cannot be called. This makes
109  // automatically testing for the existence of getpwuid on the login node
110  // difficult. The configure test would work on the login node but will fail
111  // on the backend. Hence we have added a configure flag, --disable-getpwuid,
112  // to manually turn this off.
113 #ifdef LIBMESH_HAVE_GETPWUID
114  struct passwd * p = getpwuid(getuid());
115 #endif
116  oss << "\n";
117 
118  // Construct string stream objects for each of the outputs
119  std::ostringstream
120  pid_stream,
121  nprocs_stream,
122  time_stream,
123  os_stream,
124  host_stream,
125  osrel_stream,
126  osver_stream,
127  machine_stream,
128  user_stream;
129 
130 
131  // Put pointers to these streams in a vector
132  std::vector<std::ostringstream*> v;
133  v.push_back(&pid_stream);
134  v.push_back(&nprocs_stream);
135  v.push_back(&time_stream);
136  v.push_back(&os_stream);
137  v.push_back(&host_stream);
138  v.push_back(&osrel_stream);
139  v.push_back(&osver_stream);
140  v.push_back(&machine_stream);
141  v.push_back(&user_stream);
142 
143  // Fill string stream objects
145  {
146  pid_stream << "| Processor id: " << libMesh::global_processor_id();
147  nprocs_stream << "| Num Processors: " << libMesh::global_n_processors();
148  }
149 
150  time_stream << "| Time: " << date ;
151  os_stream << "| OS: " << sysInfo.sysname ;
152  host_stream << "| HostName: " << sysInfo.nodename ;
153  osrel_stream << "| OS Release: " << sysInfo.release ;
154  osver_stream << "| OS Version: " << sysInfo.version ;
155  machine_stream << "| Machine: " << sysInfo.machine ;
156  user_stream << "| Username: ";
157 #ifdef LIBMESH_HAVE_GETPWUID
158  if (p && p->pw_name)
159  user_stream << p->pw_name;
160  else
161 #endif
162  user_stream << "Unknown";
163 
164  // Parse the LIBMESH_CONFIGURE_INFO string literal before using it in PerfLog output
165  std::string libmesh_configure_info(LIBMESH_CONFIGURE_INFO);
166  std::vector<std::string> parsed_libmesh_configure_info;
167  this->split_on_whitespace(libmesh_configure_info,
168  parsed_libmesh_configure_info);
169 
170  // There should always be at at least one entry in
171  // parsed_libmesh_configure_info, even if the user just ran
172  // ../configure.
173  libmesh_assert_greater (parsed_libmesh_configure_info.size(), 0);
174 
175  // Find the longest string in all the streams
176  unsigned int max_length = 0;
177  for (std::size_t i=0; i<v.size(); ++i)
178  if (v[i]->str().size() > max_length)
179  max_length = cast_int<unsigned int>
180  (v[i]->str().size());
181 
182  // Find the longest string in the parsed_libmesh_configure_info
183  for (std::size_t i=0; i<parsed_libmesh_configure_info.size(); ++i)
184  if (parsed_libmesh_configure_info[i].size() > max_length)
185  max_length = cast_int<unsigned int>
186  (parsed_libmesh_configure_info[i].size());
187 
188  // Print dashed line for the header
189  oss << ' '
190  << std::string(max_length+1, '-')
191  << '\n';
192 
193  // Loop over all the strings and add end formatting
194  for (std::size_t i=0; i<v.size(); ++i)
195  {
196  if (v[i]->str().size())
197  oss << v[i]->str()
198  << std::setw (cast_int<int>
199  (max_length + 4 - v[i]->str().size()))
200  << std::right
201  << "|\n";
202  }
203 
204  // Print out configuration header plus first parsed string. The
205  // magic number 18 below accounts for the length of the word
206  // 'Configuration'.
207  oss << "| Configuration: "
208  << parsed_libmesh_configure_info[0]
209  << std::setw (cast_int<int>
210  (max_length + 4 -
211  parsed_libmesh_configure_info[0].size() - 18))
212  << std::right
213  << "|\n";
214 
215  // Loop over the parsed_libmesh_configure_info and add end formatting. The magic
216  // number 3 below accounts for the leading 'pipe' character and indentation
217  for (std::size_t i=1; i<parsed_libmesh_configure_info.size(); ++i)
218  {
219  oss << "| "
220  << parsed_libmesh_configure_info[i]
221  << std::setw (cast_int<int>
222  (max_length + 4 -
223  parsed_libmesh_configure_info[i].size() - 3))
224  << std::right
225  << "|\n";
226  }
227 
228 
229  // Print dashed line
230  oss << ' '
231  << std::string(max_length+1, '-')
232  << '\n';
233  }
234 
235  return oss.str();
236 }
processor_id_type global_n_processors()
Definition: libmesh_base.h:104
std::string get_timestamp()
Definition: timestamp.C:37
processor_id_type global_processor_id()
Definition: libmesh_base.h:114
void split_on_whitespace(const std::string &input, std::vector< std::string > &output) const
Definition: perf_log.C:631
std::string libMesh::PerfLog::get_log ( ) const
Returns
A string containing: (1) Basic machine information (if first call) (2) The performance log

Definition at line 556 of file perf_log.C.

References called, get_info_header(), get_perf_info(), log, and log_events.

Referenced by print_log().

557 {
558  std::ostringstream oss;
559 
560  if (log_events)
561  {
562  // Only print the log
563  // if it isn't empty
564  if (!log.empty())
565  {
566  // Possibly print machine info,
567  // but only do this once
568  if (!called)
569  {
570  called = true;
571  oss << get_info_header();
572  }
573  oss << get_perf_info();
574  }
575  }
576 
577  return oss.str();
578 }
std::map< std::pair< std::string, std::string >, PerfData > log
Definition: perf_log.h:285
std::string get_perf_info() const
Definition: perf_log.C:241
std::string get_info_header() const
Definition: perf_log.C:91
static bool called
Definition: perf_log.h:297
const std::map< std::pair<std::string, std::string>, PerfData >& libMesh::PerfLog::get_log_raw ( ) const
inline
Returns
the raw underlying data structure for the entire performance log.

Definition at line 255 of file perf_log.h.

255 { return log; }
std::map< std::pair< std::string, std::string >, PerfData > log
Definition: perf_log.h:285
PerfData libMesh::PerfLog::get_perf_data ( const std::string &  label,
const std::string &  header = "" 
)

Return the PerfData object associated with a label and header.

Definition at line 594 of file perf_log.C.

References log.

595 {
596  return log[std::make_pair(header, label)];
597 }
std::map< std::pair< std::string, std::string >, PerfData > log
Definition: perf_log.h:285
std::string libMesh::PerfLog::get_perf_info ( ) const
Returns
A string containing ONLY the log information

Definition at line 241 of file perf_log.C.

References libMesh::PerfData::count, label_name, libmesh_nullptr, log, log_events, libMesh::Real, libMesh::PerfData::tot_time, libMesh::PerfData::tot_time_incl_sub, total_time, and tstart.

Referenced by get_log().

242 {
243  std::ostringstream oss;
244 
245  if (log_events && !log.empty())
246  {
247  // Stop timing for this event.
248  struct timeval tstop;
249 
250  gettimeofday (&tstop, libmesh_nullptr);
251 
252  const double elapsed_time = (static_cast<double>(tstop.tv_sec - tstart.tv_sec) +
253  static_cast<double>(tstop.tv_usec - tstart.tv_usec)*1.e-6);
254 
255  // Figure out the formatting required based on the event names
256  // Unsigned ints for each of the column widths
257  unsigned int event_col_width = 30;
258  const unsigned int ncalls_col_width = 11;
259  const unsigned int tot_time_col_width = 12;
260  const unsigned int avg_time_col_width = 12;
261  const unsigned int tot_time_incl_sub_col_width = 12;
262  const unsigned int avg_time_incl_sub_col_width = 12;
263  const unsigned int pct_active_col_width = 9;
264  const unsigned int pct_active_incl_sub_col_width = 9;
265 
266  // Iterator to be used to loop over the map of timed events
267  std::map<std::pair<std::string,std::string>, PerfData>::const_iterator pos;
268 
269  // Reset the event column width based on the longest event name plus
270  // a possible 2-character indentation, plus a space.
271  for (pos = log.begin(); pos != log.end(); ++pos)
272  if (pos->first.second.size()+3 > event_col_width)
273  event_col_width = cast_int<unsigned int>
274  (pos->first.second.size()+3);
275 
276  // Set the total width of the column
277  const unsigned int total_col_width =
278  event_col_width +
279  ncalls_col_width +
280  tot_time_col_width +
281  avg_time_col_width +
282  tot_time_incl_sub_col_width +
283  avg_time_incl_sub_col_width +
284  pct_active_col_width+
285  pct_active_incl_sub_col_width+1;
286 
287  // Print dashed line
288  oss << ' '
289  << std::string(total_col_width, '-')
290  << '\n';
291 
292  {
293  // Construct temporary message string
294  std::ostringstream temp;
295  temp << "| " << label_name << " Performance: Alive time=" << elapsed_time
296  << ", Active time=" << total_time;
297 
298  // Get the size of the temporary string
299  const unsigned int temp_size = cast_int<unsigned int>
300  (temp.str().size());
301 
302  // Send the temporary message to the output
303  oss << temp.str();
304 
305  // If this string is longer than the previously computed total
306  // column width, skip the additional formatting... this shouldn't
307  // happen often, hopefully. Add two additional characters for a
308  // space and a "|" character at the end.
309  if (temp_size < total_col_width+2)
310  oss << std::setw(total_col_width - temp_size + 2)
311  << std::right
312  << "|";
313 
314  oss << '\n';
315  }
316 
317  // Print dashed line
318  oss << ' '
319  << std::string(total_col_width, '-')
320  << '\n';
321 
322 
323  // Write out the header for the events listing
324  oss << "| "
325  << std::setw(event_col_width)
326  << std::left
327  << "Event"
328  << std::setw(ncalls_col_width)
329  << std::left
330  << "nCalls"
331  << std::setw(tot_time_col_width)
332  << std::left
333  << "Total Time"
334  << std::setw(avg_time_col_width)
335  << std::left
336  << "Avg Time"
337  << std::setw(tot_time_incl_sub_col_width)
338  << std::left
339  << "Total Time"
340  << std::setw(avg_time_incl_sub_col_width)
341  << std::left
342  << "Avg Time"
343  << std::setw(pct_active_col_width+pct_active_incl_sub_col_width)
344  << std::left
345  << "% of Active Time"
346  << "|\n"
347  << "| "
348  << std::setw(event_col_width)
349  << std::left
350  << ""
351  << std::setw(ncalls_col_width)
352  << std::left
353  << ""
354  << std::setw(tot_time_col_width)
355  << std::left
356  << "w/o Sub"
357  << std::setw(avg_time_col_width)
358  << std::left
359  << "w/o Sub"
360  << std::setw(tot_time_incl_sub_col_width)
361  << std::left
362  << "With Sub"
363  << std::setw(avg_time_incl_sub_col_width)
364  << std::left
365  << "With Sub"
366  << std::setw(pct_active_col_width)
367  << std::left
368  << "w/o S"
369  << std::setw(pct_active_incl_sub_col_width)
370  << std::left
371  << "With S"
372  << "|\n|"
373  << std::string(total_col_width, '-')
374  << "|\n|"
375  << std::string(total_col_width, ' ')
376  << "|\n";
377 
378  unsigned int summed_function_calls = 0;
379  double summed_total_time = 0;
380  double summed_percentage = 0;
381 
382  std::string last_header("");
383 
384  for (pos = log.begin(); pos != log.end(); ++pos)
385  {
386  const PerfData & perf_data = pos->second;
387 
388  // Only print the event if the count is non-zero.
389  if (perf_data.count != 0)
390  {
391  const unsigned int perf_count = perf_data.count;
392  const double perf_time = perf_data.tot_time;
393  const double perf_avg_time = perf_time / static_cast<double>(perf_count);
394  const double perf_time_incl_sub = perf_data.tot_time_incl_sub;
395  const double perf_avg_time_incl_sub = perf_time_incl_sub / static_cast<double>(perf_count);
396  const double perf_percent = (total_time != 0.) ? perf_time / total_time * 100. : 0.;
397  const double perf_percent_incl_sub = (total_time != 0.) ? perf_time_incl_sub / total_time * 100. : 0.;
398 
399  summed_function_calls += perf_count;
400  summed_total_time += perf_time;
401  summed_percentage += perf_percent;
402 
403  // Print the event name
404  if (pos->first.first == "")
405  oss << "| "
406  << std::setw(event_col_width)
407  << std::left
408  << pos->first.second;
409 
410  else
411  {
412  if (last_header != pos->first.first)
413  {
414  last_header = pos->first.first;
415 
416  // print blank line followed by header name
417  // (account for additional space before the
418  // header)
419  oss << "|"
420  << std::string(total_col_width, ' ')
421  << "|\n| "
422  << std::setw(total_col_width-1)
423  << std::left
424  << pos->first.first
425  << "|\n";
426  }
427 
428  oss << "| "
429  << std::setw(event_col_width-2)
430  << std::left
431  << pos->first.second;
432  }
433 
434 
435  // Print the number of calls to the event.
436  oss << std::setw(ncalls_col_width)
437  << perf_count;
438 
439  // Save the original stream flags
440  std::ios_base::fmtflags out_flags = oss.flags();
441 
442  // Print the total time spent in the event
443  oss << std::fixed
444  << std::setprecision(4)
445  << std::setw(tot_time_col_width)
446  << std::left
447  << perf_time;
448 
449 
450  // Print the average time per function call
451  oss << std::fixed
452  << std::setprecision(6)
453  << std::setw(avg_time_col_width)
454  << std::left
455  << perf_avg_time;
456 
457  // Print the total time spent in the event incl. sub-events
458  oss << std::fixed
459  << std::setprecision(4)
460  << std::setw(tot_time_incl_sub_col_width)
461  << std::left
462  << perf_time_incl_sub;
463 
464  // Print the average time per function call incl. sub-events
465  oss << std::fixed
466  << std::setprecision(6)
467  << std::setw(avg_time_incl_sub_col_width)
468  << std::left
469  << perf_avg_time_incl_sub;
470 
471  // Print the percentage of the time spent in the event
472  oss << std::fixed
473  << std::setprecision(2)
474  << std::setw(pct_active_col_width)
475  << std::left
476  << perf_percent;
477 
478  // Print the percentage of the time spent in the event incl. sub-events
479  oss << std::fixed
480  << std::setprecision(2)
481  << std::setw(pct_active_incl_sub_col_width)
482  << std::left
483  << perf_percent_incl_sub;
484 
485  // Reset the stream flags
486  oss.flags(out_flags);
487 
488  oss << "|\n";
489  }
490  }
491 
492  oss << ' '
493  << std::string(total_col_width, '-')
494  << "\n| "
495  << std::setw(event_col_width)
496  << std::left
497  << "Totals:";
498 
499  // Print the total number of logged function calls
500  // For routines which are called many times, summed_function_calls may
501  // exceed 7 digits. If this happens use, scientific notation.
502  if (summed_function_calls < 9999999)
503  oss << std::setw(ncalls_col_width)
504  << summed_function_calls;
505 
506  else
507  {
508  // Save the original stream flags
509  std::ios_base::fmtflags out_flags = oss.flags();
510 
511  oss << std::scientific
512  << std::setprecision(3)
513  << std::setw(ncalls_col_width)
514  << std::left
515  << static_cast<Real>(summed_function_calls);
516 
517  // Reset the stream flags
518  oss.flags(out_flags);
519  }
520 
521  // Print the total time spent in logged function calls. Don't bother saving/restoring
522  // the flags here since we are almost done with this stream anyway...
523  oss << std::fixed
524  << std::setprecision(4)
525  << std::setw(tot_time_col_width)
526  << std::left
527  << summed_total_time;
528 
529  // Null, the average time doesn't make sense as a total
530  oss << std::setw(avg_time_col_width) << "";
531 
532  // Same for times that include sub-events
533  oss << std::setw(tot_time_incl_sub_col_width)
534  << ""
535  << std::setw(avg_time_incl_sub_col_width)
536  << "";
537 
538  // Print the total percentage followed by dashed line
539  oss << std::fixed
540  << std::setprecision(2)
541  << std::setw(pct_active_col_width)
542  << std::left
543  << summed_percentage
544  << std::setw(pct_active_incl_sub_col_width)
545  << ""
546  << "|\n "
547  << std::string(total_col_width, '-')
548  << '\n';
549  }
550 
551  return oss.str();
552 }
double total_time
Definition: perf_log.h:273
const class libmesh_nullptr_t libmesh_nullptr
std::map< std::pair< std::string, std::string >, PerfData > log
Definition: perf_log.h:285
const std::string label_name
Definition: perf_log.h:263
DIE A HORRIBLE DEATH HERE typedef LIBMESH_DEFAULT_SCALAR_TYPE Real
struct timeval tstart
Definition: perf_log.h:278
bool libMesh::PerfLog::logging_enabled ( ) const
inline
Returns
true iff performance logging is enabled

Definition at line 165 of file perf_log.h.

Referenced by libMesh::Threads::task_scheduler_init::terminate().

165 { return log_events; }
void libMesh::PerfLog::pause_event ( const std::string &  label,
const std::string &  header = "" 
)

Suspend monitoring of the event.

Definition at line 615 of file perf_log.C.

617 {
618  // nothing to do. pushing the next object on the stack will handle it
619 }
void libMesh::PerfLog::pop ( const char *  label,
const char *  header = "" 
)
inline

Pop the event label off the stack, resuming any lower event.

Definition at line 447 of file perf_log.h.

Referenced by push(), stop_event(), and libMesh::PerfItem::~PerfItem().

449 {
450  if (this->log_events)
451  this->pop(std::string(label), std::string(header));
452 }
void pop(const char *label, const char *header="")
Definition: perf_log.h:447
void libMesh::PerfLog::pop ( const std::string &  label,
const std::string &  header = "" 
)

Pop the event label off the stack, resuming any lower event.

void libMesh::PerfLog::print_log ( ) const

Print the log.

Definition at line 582 of file perf_log.C.

References get_log(), log_events, and libMesh::out.

Referenced by libMesh::libmesh_terminate_handler(), libMesh::LibMeshInit::LibMeshInit(), and ~PerfLog().

583 {
584  if (log_events)
585  {
586  // Check to see if the log_string is empty, and if so,
587  // avoid printing an unnecessary newline.
588  std::string log_string = this->get_log();
589  if (log_string.size() > 0)
590  libMesh::out << log_string << std::endl;
591  }
592 }
std::string get_log() const
Definition: perf_log.C:556
OStreamProxy out(std::cout)
void libMesh::PerfLog::push ( const char *  label,
const char *  header = "" 
)
inline

Push the event label onto the stack, pausing any active event.

Definition at line 402 of file perf_log.h.

References libMesh::err, libMesh::libmesh_assert(), libMesh::libmesh_dbg_var(), and pop().

Referenced by libMesh::PerfItem::PerfItem(), and start_event().

404 {
405  if (this->log_events)
406  this->push(std::string(label), std::string(header));
407 }
void push(const char *label, const char *header="")
Definition: perf_log.h:402
void libMesh::PerfLog::push ( const std::string &  label,
const std::string &  header = "" 
)
inline

Push the event label onto the stack, pausing any active event.

Definition at line 381 of file perf_log.h.

References libMesh::PerfData::pause(), and libMesh::PerfData::start().

383 {
384  if (this->log_events)
385  {
386  // Get a reference to the event data to avoid
387  // repeated map lookups
388  PerfData * perf_data = &(log[std::make_pair(header,label)]);
389 
390  if (!log_stack.empty())
391  total_time +=
392  log_stack.top()->pause();
393 
394  perf_data->start();
395  log_stack.push(perf_data);
396  }
397 }
double total_time
Definition: perf_log.h:273
std::map< std::pair< std::string, std::string >, PerfData > log
Definition: perf_log.h:285
std::stack< PerfData * > log_stack
Definition: perf_log.h:290
void libMesh::PerfLog::restart_event ( const std::string &  label,
const std::string &  header = "" 
)

Restart monitoring the event.

Definition at line 623 of file perf_log.C.

625 {
626  // nothing to do. popping the top off the stack will handle it.
627 }
void libMesh::PerfLog::split_on_whitespace ( const std::string &  input,
std::vector< std::string > &  output 
) const
private

Splits a string on whitespace into a vector of separate strings. This is used to make the LIBMESH_CONFIGURE_INFO a little more manageable.

Definition at line 631 of file perf_log.C.

Referenced by get_info_header().

632 {
633  // Check for easy return
634  if (input.size()==0)
635  return;
636 
637  // Here we hard-code the string to split on, since the algorithm below
638  // is somewhat specific to it...
639  const std::string split_on("' '");
640 
641  size_t current_pos = 0;
642  while (true)
643  {
644  // Find next end location
645  size_t end_pos = input.find(split_on, current_pos);
646 
647  if (end_pos != std::string::npos)
648  {
649  // Create substring. Note: the second argument to substr is
650  // the *length* of string to create, not the ending position!
651  output.push_back( input.substr(current_pos, end_pos - current_pos + 1) );
652 
653  // Update search starting position, make sure to go past the end of the split_on string, but
654  // include the previous single quote (hence the -1).
655  current_pos = end_pos + split_on.size() - 1;
656  }
657  else
658  {
659  // Push back whatever remains of the string onto the output.
660  // Note that substr with only 1 argument pushes back
661  // whatever remains of the string. This also handles the
662  // case where the string does not contain any matches.
663  output.push_back( input.substr(current_pos) );
664 
665  // We are done searching the string, so break out of the while loop
666  break;
667  }
668  }
669 }
void libMesh::PerfLog::start_event ( const std::string &  label,
const std::string &  header = "" 
)

Start monitoring the event named label.

Definition at line 599 of file perf_log.C.

References push().

601 {
602  this->push(label,header);
603 }
void push(const char *label, const char *header="")
Definition: perf_log.h:402
void libMesh::PerfLog::stop_event ( const std::string &  label,
const std::string &  header = "" 
)

Stop monitoring the event named label.

Definition at line 607 of file perf_log.C.

References pop().

609 {
610  this->pop(label,header);
611 }
void pop(const char *label, const char *header="")
Definition: perf_log.h:447

Member Data Documentation

bool libMesh::PerfLog::called = false
staticprivate

Flag indicating if print_log() has been called. This is used to print a header with machine-specific data the first time that print_log() is called.

Definition at line 297 of file perf_log.h.

Referenced by get_log().

const std::string libMesh::PerfLog::label_name
private

The label for this object.

Definition at line 263 of file perf_log.h.

Referenced by clear(), and get_perf_info().

std::map<std::pair<std::string, std::string>, PerfData> libMesh::PerfLog::log
private

The actual log.

Definition at line 285 of file perf_log.h.

Referenced by clear(), get_log(), get_perf_data(), and get_perf_info().

bool libMesh::PerfLog::log_events
private

Flag to optionally disable all logging.

Definition at line 268 of file perf_log.h.

Referenced by clear(), get_info_header(), get_log(), get_perf_info(), PerfLog(), print_log(), and ~PerfLog().

std::stack<PerfData*> libMesh::PerfLog::log_stack
private

A stack to hold the current performance log trace.

Definition at line 290 of file perf_log.h.

Referenced by clear().

double libMesh::PerfLog::total_time
private

The total running time for recorded events.

Definition at line 273 of file perf_log.h.

Referenced by get_perf_info().

struct timeval libMesh::PerfLog::tstart
private

The time we were constructed or last cleared.

Definition at line 278 of file perf_log.h.

Referenced by clear(), get_perf_info(), and PerfLog().


The documentation for this class was generated from the following files: