perf_log.h

Go to the documentation of this file.

// The libMesh Finite Element Library.
// Copyright (C) 2002-2019 Benjamin S. Kirk, John W. Peterson, Roy H. Stogner
 
// This library is free software; you can redistribute it and/or
// modify it under the terms of the GNU Lesser General Public
// License as published by the Free Software Foundation; either
// version 2.1 of the License, or (at your option) any later version.
 
// This library is distributed in the hope that it will be useful,
// but WITHOUT ANY WARRANTY; without even the implied warranty of
// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
// Lesser General Public License for more details.
 
// You should have received a copy of the GNU Lesser General Public
// License along with this library; if not, write to the Free Software
// Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
 
 
 
#ifndef LIBMESH_PERFLOG_H
#define LIBMESH_PERFLOG_H
 
 
// Local includes
#include "libmesh/libmesh_common.h"
 
// C++ includes
#include <cstddef>
#include <map>
#include <stack>
#include <string>
#include <vector>
#include <sys/time.h>
 
namespace libMesh
{
 
class PerfData
{
public:
 
  PerfData () :
    tot_time(0.),
    tot_time_incl_sub(0.),
    tstart(),
    tstart_incl_sub(),
    count(0),
    open(false),
    called_recursively(0)
  {}
 
 
  double tot_time;
 
  double tot_time_incl_sub;
 
  struct timeval tstart;
 
  struct timeval tstart_incl_sub;
 
  unsigned int count;
 
  bool open;
 
  void   start ();
  void   restart ();
  double pause ();
  double pause_for(PerfData & other);
  double stopit ();
 
  int called_recursively;
 
protected:
  double stop_or_pause(const bool do_stop);
};
 
 
 
 
class PerfLog
{
public:
 
  PerfLog(const std::string & label_name="",
          const bool log_events=true);
 
  ~PerfLog();
 
  void clear();
 
  void disable_logging() { log_events = false; }
 
  void enable_logging() { log_events = true; }
 
  bool logging_enabled() const { return log_events; }
 
  void fast_push (const char * label,
                  const char * header="");
 
  void push (const char * label,
             const char * header="");
 
  void push (const std::string & label,
             const std::string & header="");
 
  void fast_pop (const char * label,
                 const char * 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="");
 
  typedef std::map<std::pair<const char *,
                             const char *>,
                   PerfData> log_type;
#ifdef LIBMESH_ENABLE_DEPRECATED
  const log_type & get_log_raw() const
  {
    libmesh_deprecated();
    return log;
  }
#endif
 
private:
 
 
  const std::string label_name;
 
  bool log_events;
 
  double total_time;
 
  struct timeval tstart;
 
  log_type log;
 
  std::stack<PerfData*> log_stack;
 
  static bool called;
 
  void split_on_whitespace(const std::string & input,
                           std::vector<std::string> & output) const;
 
  std::map<std::string, const char *> non_temporary_strings;
};
 
 
 
// ------------------------------------------------------------
// PerfData class member functions
inline
void PerfData::start ()
{
  this->count++;
  this->called_recursively++;
  gettimeofday (&(this->tstart), nullptr);
  this->tstart_incl_sub = this->tstart;
}
 
 
 
inline
void PerfData::restart ()
{
  gettimeofday (&(this->tstart), nullptr);
}
 
 
 
inline
double PerfData::pause ()
{
  return this->stop_or_pause(false);
}
 
 
inline
double PerfData::stop_or_pause(const bool do_stop)
{
  // save the start times, reuse the structure we have rather than create
  // a new one.
  const time_t
    tstart_tv_sec  = this->tstart.tv_sec,
    tstart_tv_usec = this->tstart.tv_usec;
 
  gettimeofday (&(this->tstart), nullptr);
 
  const double elapsed_time = (static_cast<double>(this->tstart.tv_sec  - tstart_tv_sec) +
                               static_cast<double>(this->tstart.tv_usec - tstart_tv_usec)*1.e-6);
 
  this->tot_time += elapsed_time;
 
  if (do_stop)
    {
      const double elapsed_time_incl_sub = (static_cast<double>(this->tstart.tv_sec  - this->tstart_incl_sub.tv_sec) +
                                            static_cast<double>(this->tstart.tv_usec - this->tstart_incl_sub.tv_usec)*1.e-6);
 
      this->tot_time_incl_sub += elapsed_time_incl_sub;
    }
 
  return elapsed_time;
}
 
 
 
inline
double PerfData::pause_for(PerfData & other)
{
  gettimeofday (&(other.tstart), nullptr);
 
  const double elapsed_time = (static_cast<double>(other.tstart.tv_sec  - this->tstart.tv_sec) +
                               static_cast<double>(other.tstart.tv_usec - this->tstart.tv_usec)*1.e-6);
  this->tot_time += elapsed_time;
 
  other.count++;
  other.called_recursively++;
  other.tstart_incl_sub = other.tstart;
 
  return elapsed_time;
}
 
 
 
inline
double PerfData::stopit ()
{
  // stopit is just similar to pause except that it decrements the
  // recursive call counter
 
  this->called_recursively--;
  return this->stop_or_pause(true);
}
 
 
 
// ------------------------------------------------------------
// PerfLog class inline member functions
inline
void PerfLog::fast_push (const char * label,
                         const char * header)
{
  if (this->log_events)
    {
      // Get a reference to the event data to avoid
      // repeated map lookups
      PerfData * perf_data = &(log[std::make_pair(header,label)]);
 
      if (!log_stack.empty())
        total_time += log_stack.top()->pause_for(*perf_data);
      else
        perf_data->start();
      log_stack.push(perf_data);
    }
}
 
 
 
inline
void PerfLog::fast_pop(const char * libmesh_dbg_var(label),
                       const char * libmesh_dbg_var(header))
{
  if (this->log_events)
    {
      libmesh_assert (!log_stack.empty());
 
#ifndef NDEBUG
      PerfData * perf_data = &(log[std::make_pair(header,label)]);
      if (perf_data != log_stack.top())
        {
          libMesh::err << "PerfLog can't pop (" << header << ',' << label << ')' << std::endl;
          libMesh::err << "From top of stack of running logs:" << std::endl;
          for (auto i : log)
            if (&(i.second) == log_stack.top())
              libMesh::err << '(' << i.first.first << ',' << i.first.second << ')' << std::endl;
 
          libmesh_assert_equal_to (perf_data, log_stack.top());
        }
#endif
 
      total_time += log_stack.top()->stopit();
 
      log_stack.pop();
 
      if (!log_stack.empty())
        log_stack.top()->restart();
    }
}
 
 
 
inline
double PerfLog::get_elapsed_time () const
{
  struct timeval tnow;
 
  gettimeofday (&tnow, nullptr);
 
  const double elapsed_time = (static_cast<double>(tnow.tv_sec  - tstart.tv_sec) +
                               static_cast<double>(tnow.tv_usec - tstart.tv_usec)*1.e-6);
  return elapsed_time;
}
 
inline
double PerfLog::get_active_time() const
{
  return total_time;
}
 
} // namespace libMesh
 
 
 
#endif // LIBMESH_PERFLOG_H