Remove SCOPED_TIMER, use PROF_COUNTER

SCOPED_TIMER is a QA-only simpler version of PROF_COUNTER.

Extend PROF_COUNTER to allow access to the std::chrono::duration
for more flexibility.

Wrap PROF_COUNTER in SCOPED_PROF_COUNTER for RAII duration
output (for the same effect as SCOPED_TIMER).
This commit is contained in:
John Beard 2019-06-11 22:16:54 +01:00
parent cbe8c5a934
commit 781c5f7e1d
5 changed files with 78 additions and 91 deletions

View File

@ -72,7 +72,7 @@ public:
void Start() void Start()
{ {
m_running = true; m_running = true;
m_starttime = std::chrono::high_resolution_clock::now(); m_starttime = CLOCK::now();
m_lasttime = m_starttime; m_lasttime = m_starttime;
} }
@ -85,7 +85,8 @@ public:
if( !m_running ) if( !m_running )
return; return;
m_stoptime = std::chrono::high_resolution_clock::now(); m_stoptime = CLOCK::now();
m_running = false;
} }
/** /**
@ -93,13 +94,7 @@ public:
*/ */
void Show() void Show()
{ {
TIME_POINT display_stoptime = m_running ? std::cerr << m_name << " took " << msecs() << "ms." << std::endl;
std::chrono::high_resolution_clock::now() :
m_stoptime;
std::chrono::duration<double, std::milli> elapsed = display_stoptime - m_starttime;
m_lasttime = display_stoptime;
std::cerr << m_name << " took " << elapsed.count() << " ms." << std::endl;
} }
/** /**
@ -109,9 +104,7 @@ public:
*/ */
void Show( const std::string& aMessage ) void Show( const std::string& aMessage )
{ {
TIME_POINT display_stoptime = m_running ? TIME_POINT display_stoptime = m_running ? CLOCK::now() : m_stoptime;
std::chrono::high_resolution_clock::now() :
m_stoptime;
std::chrono::duration<double, std::milli> elapsed = display_stoptime - m_starttime; std::chrono::duration<double, std::milli> elapsed = display_stoptime - m_starttime;
std::chrono::duration<double, std::milli> delta_time = display_stoptime - m_lasttime; std::chrono::duration<double, std::milli> delta_time = display_stoptime - m_lasttime;
@ -125,43 +118,94 @@ public:
*/ */
void ShowDlg() void ShowDlg()
{ {
TIME_POINT display_stoptime = m_running ? const double ms = msecs();
std::chrono::high_resolution_clock::now() :
m_stoptime;
std::chrono::duration<double, std::milli> elapsed = display_stoptime - m_starttime;
wxString msg; wxString msg;
if( elapsed.count() < 1000.0 ) if( ms < 1000.0 )
msg << m_name << " took " << elapsed.count() << " ms."; msg << m_name << " took " << ms << " ms.";
else else
msg << m_name << " took " << elapsed.count()/1000.0 << " sec."; msg << m_name << " took " << ms / 1000.0 << " sec.";
wxLogMessage( msg ); wxLogMessage( msg );
} }
/** /**
* @return the elapsed time in ms * @return the time since the timer was started. If the timer is stopped,
* the duration is from the start time to the time it was stopped, else it
* is to the current time.
*/ */
double msecs() const template <typename DURATION>
DURATION SinceStart( bool aSinceLast = false )
{ {
TIME_POINT stoptime = m_running ? const TIME_POINT stoptime = m_running ? CLOCK::now() : m_stoptime;
std::chrono::high_resolution_clock::now() : const TIME_POINT starttime = aSinceLast ? m_lasttime : m_starttime;
m_stoptime;
std::chrono::duration<double, std::milli> elapsed = stoptime - m_starttime; m_lasttime = stoptime;
return elapsed.count(); return std::chrono::duration_cast<DURATION>( stoptime - starttime );
}
/**
* @param aSinceLast: only get the time since the last time the time was read
* @return the elapsed time in ms since the timer was started.
*/
double msecs( bool aSinceLast = false )
{
using DUR_MS = std::chrono::duration<double, std::milli>;
return SinceStart<DUR_MS>( aSinceLast ).count();
} }
private: private:
std::string m_name; // a string printed in message std::string m_name; // a string printed in message
bool m_running; bool m_running;
typedef std::chrono::time_point<std::chrono::high_resolution_clock> TIME_POINT; using CLOCK = std::chrono::high_resolution_clock;
using TIME_POINT = std::chrono::time_point<CLOCK>;
TIME_POINT m_starttime, m_lasttime, m_stoptime; TIME_POINT m_starttime, m_lasttime, m_stoptime;
}; };
/**
* A simple RAII class to measure the time of an operation.
*
* On construction, a timer is started, and on destruction, the timer is
* ended, and the time difference is written into the given duration.
*
* For example:
*
* DURATION duration; // select a duration type as needed
* {
* SCOPED_PROF_COUNTER<DURATION> timer( duration );
* timed_activity();
* }
* // duration is now the time timed activity took
*
* From C++17, with class template argument deduction, you should be able to
* omit the <DURATION>.
*/
template <typename DURATION>
class SCOPED_PROF_COUNTER
{
public:
SCOPED_PROF_COUNTER( DURATION& aDuration ) : m_counter(), m_duration( aDuration )
{
}
~SCOPED_PROF_COUNTER()
{
// update the output
m_duration = m_counter.SinceStart<DURATION>();
}
private:
///< The counter to use to do the profiling
PROF_COUNTER m_counter;
///< The duration to update at the end of the scope
DURATION& m_duration;
};
/** /**
* Function GetRunningMicroSecs * Function GetRunningMicroSecs
* An alternate way to calculate an elapset time (in microsecondes) to class PROF_COUNTER * An alternate way to calculate an elapset time (in microsecondes) to class PROF_COUNTER

View File

@ -59,7 +59,7 @@ public:
std::unique_ptr<SEXPR::SEXPR> sexpr( m_parser.Parse( sexpr_str ) ); std::unique_ptr<SEXPR::SEXPR> sexpr( m_parser.Parse( sexpr_str ) );
if( m_verbose ) if( m_verbose )
timer.Show( "S-Expression Parsing" ); std::cout << "S-Expression Parsing took " << timer.msecs() << "ms" << std::endl;
return sexpr != nullptr; return sexpr != nullptr;
} }

View File

@ -27,6 +27,7 @@
#include <string> #include <string>
#include <common.h> #include <common.h>
#include <profile.h>
#include <wx/cmdline.h> #include <wx/cmdline.h>
@ -36,7 +37,6 @@
#include <drc/courtyard_overlap.h> #include <drc/courtyard_overlap.h>
#include <drc/drc_marker_factory.h> #include <drc/drc_marker_factory.h>
#include <qa_utils/scoped_timer.h>
#include <qa_utils/stdstream_line_reader.h> #include <qa_utils/stdstream_line_reader.h>
@ -84,7 +84,7 @@ public:
DRC_DURATION duration; DRC_DURATION duration;
{ {
SCOPED_TIMER<DRC_DURATION> timer( duration ); SCOPED_PROF_COUNTER<DRC_DURATION> timer( duration );
drc_prov->RunDRC( aBoard ); drc_prov->RunDRC( aBoard );
} }

View File

@ -27,6 +27,7 @@
#include <string> #include <string>
#include <common.h> #include <common.h>
#include <profile.h>
#include <wx/cmdline.h> #include <wx/cmdline.h>
@ -37,7 +38,6 @@
#include <wx/cmdline.h> #include <wx/cmdline.h>
#include <qa_utils/scoped_timer.h>
#include <qa_utils/stdstream_line_reader.h> #include <qa_utils/stdstream_line_reader.h>
using PARSE_DURATION = std::chrono::microseconds; using PARSE_DURATION = std::chrono::microseconds;
@ -65,8 +65,10 @@ bool parse( std::istream& aStream, bool aVerbose )
try try
{ {
SCOPED_TIMER<PARSE_DURATION> timer( duration ); PROF_COUNTER timer;
board = parser.Parse(); board = parser.Parse();
duration = timer.SinceStart<PARSE_DURATION>();
} }
catch( const IO_ERROR& parse_error ) catch( const IO_ERROR& parse_error )
{ {

View File

@ -1,59 +0,0 @@
/*
* This program source code file is part of KiCad, a free EDA CAD application.
*
* Copyright (C) 2018 KiCad Developers, see AUTHORS.txt for contributors.
*
* This program is free software; you can redistribute it and/or
* modify it under the terms of the GNU General Public License
* as published by the Free Software Foundation; either version 2
* of the License, or (at your option) any later version.
*
* This program 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 General Public License for more details.
*
* You should have received a copy of the GNU General Public License
* along with this program; if not, you may find one here:
* http://www.gnu.org/licenses/old-licenses/gpl-2.0.html
* or you may search the http://www.gnu.org website for the version 2 license,
* or you may write to the Free Software Foundation, Inc.,
* 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA
*/
#ifndef SCOPED_TIMER_H
#define SCOPED_TIMER_H
#include <chrono>
/**
* A simple RAII class to measure the time of an operation.
*
* ON construction, a timer is started, and on destruction, the timer is
* ended, and the time difference is written into the given duration
*/
template <typename DURATION> class SCOPED_TIMER
{
using CLOCK = std::chrono::steady_clock;
using TIME_PT = std::chrono::time_point<CLOCK>;
public:
SCOPED_TIMER( DURATION& aDuration ) : m_duration( aDuration )
{
m_start = CLOCK::now();
}
~SCOPED_TIMER()
{
const auto end = CLOCK::now();
// update the output
m_duration = std::chrono::duration_cast<DURATION>( end - m_start );
}
private:
DURATION& m_duration;
TIME_PT m_start;
};
#endif // SCOPED_TIMER_h