perf_log.h

Go to the documentation of this file.

// The libMesh Finite Element Library.
// Copyright (C) 2002-2014 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
{

// ------------------------------------------------------------
// PerfData class definition
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 stopit ();

  int called_recursively;

protected:
  double stop_or_pause(const bool do_stop);
};




// ------------------------------------------------------------
// PerfLog class definition
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 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="");

private:


  const std::string label_name;

  bool log_events;

  double total_time;

  struct timeval tstart;

  std::map<std::pair<std::string,
                     std::string>,
           PerfData> log;

  std::stack<PerfData*> log_stack;

  static bool called;

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



// ------------------------------------------------------------
// PerfData class member funcions
inline
void PerfData::start ()
{
  this->count++;
  this->called_recursively++;
  gettimeofday (&(this->tstart), NULL);
  this->tstart_incl_sub = this->tstart;
}



inline
void PerfData::restart ()
{
  gettimeofday (&(this->tstart), NULL);
}



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), NULL);

  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::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 funcions
inline
void PerfLog::push (const std::string &label,
                    const std::string &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();

      perf_data->start();
      log_stack.push(perf_data);
    }
}



inline
void PerfLog::push (const char *label,
                    const char *header)
{
  if (this->log_events)
    this->push(std::string(label), std::string(header));
}



inline
void PerfLog::pop (const std::string &libmesh_dbg_var(label),
                   const std::string &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;
          std::map<std::pair<std::string, std::string>, PerfData>::iterator
            i = log.begin(), endi = log.end();
          for (; i != endi; ++i)
            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
void PerfLog::pop(const char *label,
                  const char *header)
{
  if (this->log_events)
    this->pop(std::string(label), std::string(header));
}



inline
double PerfLog::get_elapsed_time () const
{
  struct timeval tnow;

  gettimeofday (&tnow, NULL);

  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