Line data    Source code

       1             : // Author(s): Jeroen Keiren
       2             : // Copyright: see the accompanying file COPYING or copy at
       3             : // https://github.com/mCRL2org/mCRL2/blob/master/COPYING
       4             : //
       5             : // Distributed under the Boost Software License, Version 1.0.
       6             : // (See accompanying file LICENSE_1_0.txt or copy at
       7             : // http://www.boost.org/LICENSE_1_0.txt)
       8             : //
       9             : /// \file mcrl2/utilities/execution_timer.h
      10             : /// \brief Class to obtain running times of code.
      11             : 
      12             : #ifndef MCRL2_UTILITIES_EXECUTION_TIMER_H
      13             : #define MCRL2_UTILITIES_EXECUTION_TIMER_H
      14             : 
      15             : #include "mcrl2/utilities/exception.h"
      16             : 
      17             : #include <chrono>
      18             : #include <fstream>
      19             : #include <map>
      20             : #include <string>
      21             : 
      22             : namespace mcrl2
      23             : {
      24             : 
      25             : namespace utilities
      26             : {
      27             : 
      28             : /// \brief Simple timer to time the CPU time used by a piece of code.
      29             : ///
      30             : /// Example usage:
      31             : /// execution_timer timer("test_tool", "/path/to/file")
      32             : /// timer.start("hint")
      33             : /// ... (execute some code here) ...
      34             : /// timer.finish("hint")
      35             : /// timer.report()
      36             : ///
      37             : /// This will output the following to the file "/path/to/file", or
      38             : /// standard error if filename is empty, assuming that the time between
      39             : /// start and finish is n seconds (with precision of 2 decimal places).
      40             : /// - tool: test_tool
      41             : ///   timing:
      42             : ///     hint: n
      43             : ///
      44             : /// Note that this is an output format that can immediately be parsed using
      45             : /// YAML (http://www.yaml.org/)
      46             : class execution_timer
      47             : {
      48             :   protected:
      49             : 
      50             :     /// \brief Pair of start and finish times
      51             :     struct timing
      52             :     {
      53             :       std::chrono::steady_clock::time_point start;      
      54             :       std::chrono::steady_clock::time_point finish;
      55             : 
      56             :       clock_t start_user;      
      57             :       clock_t finish_user;
      58             : 
      59          20 :       timing() :
      60          20 :         start(),
      61          20 :         finish()
      62          20 :       {}
      63             :     };
      64             : 
      65             :     std::string m_tool_name; //!< name of the tool we are timing
      66             :     std::string m_filename; //!< name of the file to write timings to
      67             :     std::map<std::string, timing> m_timings; //!< collection of timings
      68             : 
      69             :     /// \brief Write the report to an output stream.
      70             :     /// \param[in] s The output stream to which the report is written.
      71           0 :     void write_report(std::ostream& s)
      72             :     {
      73           0 :       std::ios::fmtflags oldflags = s.setf(std::ios::fixed, std::ios::floatfield);
      74           0 :       s.precision(3);
      75             : 
      76           0 :       s << "- tool: " << m_tool_name << std::endl
      77           0 :         << "  timing:" << std::endl;
      78             : 
      79           0 :       for (std::map<std::string, timing>::const_iterator i = m_timings.begin(); i != m_timings.end(); ++i)
      80             :       {
      81           0 :         if (i->second.finish == std::chrono::steady_clock::time_point())
      82             :         {
      83           0 :           s << "    " << i->first << ": did not finish. " << std::endl;
      84             :         }
      85           0 :         else if (i->second.start > i->second.finish)
      86             :         {
      87           0 :           throw mcrl2::runtime_error("Start of " + i->first + " occurred after finish.");
      88             :         }
      89             :         else
      90             :         {
      91           0 :           s << "    " << i->first << ": "
      92           0 :             << std::chrono::duration_cast<std::chrono::milliseconds>(i->second.finish - i->second.start).count() / 1000.0
      93           0 :             << "s (user: " << static_cast<double>(i->second.finish_user - i->second.start_user) / CLOCKS_PER_SEC << "s)"
      94           0 :             << std::endl;
      95             :         }
      96             :       }
      97           0 :       s.flags(oldflags);
      98           0 :     }
      99             : 
     100             :   public:
     101             : 
     102             :     /// \brief Constructor of a simple execution timer
     103             :     /// \param[in] tool_name Name of the tool that does the measurements
     104             :     /// \param[in] filename Name of the file to which the measurements are written
     105          13 :     execution_timer(const std::string& tool_name = "", std::string const& filename = "") :
     106          13 :       m_tool_name(tool_name),
     107          13 :       m_filename(filename)
     108          13 :     {}
     109             : 
     110             :     /// \brief Destructor
     111          13 :     ~execution_timer()
     112          13 :     {}
     113             : 
     114             :     /// \brief Start measurement with a hint
     115             :     /// \param[in] timing_name Name of the measurement being started
     116             :     /// \pre No start(timing_name) has occurred before
     117             :     /// \post The current time has been recorded as starting time of timing_name
     118          20 :     void start(const std::string& timing_name)
     119             :     {
     120          20 :       std::map<std::string, timing>::iterator t = m_timings.lower_bound(timing_name);
     121          20 :       if (t != m_timings.end() && t->first == timing_name)
     122             :       {
     123           0 :         throw mcrl2::runtime_error("Starting already known timing '" + timing_name + "'. This causes unreliable results.");
     124             :       }
     125          20 :       t = m_timings.insert(t, make_pair(timing_name, timing()));
     126             : 
     127          20 :       t->second.start = std::chrono::steady_clock::now();
     128          20 :       t->second.start_user = clock();
     129          20 :     }
     130             : 
     131             :     /// \brief Finish a measurement with a hint
     132             :     /// \param[in] timing_name Name of the measurment being finished
     133             :     /// \pre A start(timing_name) was executed before
     134             :     /// \post The current time has been recorded as end time of timing_name
     135          20 :     void finish(const std::string& timing_name)
     136             :     {
     137          20 :       std::chrono::steady_clock::time_point finish = std::chrono::steady_clock::now();
     138          20 :       const std::map<std::string, timing>::iterator t = m_timings.find(timing_name);
     139          20 :       if (t == m_timings.end())
     140             :       {
     141           0 :         throw mcrl2::runtime_error("Finishing timing '" + timing_name + "' that was not started.");
     142             :       }
     143          20 :       if (std::chrono::steady_clock::time_point() != t->second.finish)
     144             :       {
     145           0 :         throw mcrl2::runtime_error("Finishing timing '" + timing_name + "' for the second time.");
     146             :       }
     147             : 
     148          20 :       t->second.finish = finish;
     149          20 :       t->second.finish_user = clock();
     150          20 :     }
     151             : 
     152             :     /// \brief Write all timing information that has been recorded.
     153             :     ///
     154             :     /// Timing information is written to the filename that was provided in
     155             :     /// the constructor. If no filename was provided (i.e. the filename is
     156             :     /// empty) the information is written to standard error.
     157             :     /// The output is in YAML compatible format.
     158           0 :     void report()
     159             :     {
     160           0 :       if (m_filename.empty())
     161             :       {
     162           0 :         write_report(std::cerr);
     163             :       }
     164             :       else
     165             :       {
     166           0 :         std::ofstream out;
     167           0 :         out.open(m_filename.c_str(), std::ios::app);
     168           0 :         write_report(out);
     169           0 :         out.close();
     170           0 :       }
     171           0 :     }
     172             : 
     173             : };
     174             : 
     175             : } // namespace utilities
     176             : 
     177             : } // namespace mcrl2
     178             : 
     179             : #endif // MCRL2_UTILITIES_EXECUTION_TIMER_H