Commit 73ed74bb authored by Paal Kvamme's avatar Paal Kvamme
Browse files

Make the Timer classes aware of OpenMP. Unfortunately making them slightly less general.

parent a5c72e15
......@@ -33,6 +33,7 @@
#endif
#include <atomic>
#include <omp.h>
namespace {
int sprintf_s(char *buffer, int size, const char *format, ...)
......@@ -112,7 +113,7 @@ namespace InternalZGY {
*/
Timer::Timer(bool enabled, const char* name, int skip, bool startrunning)
: enabled_(enabled), skip_(skip), frequency_(1), overhead_(0),
laps_(0), last_(0), total_(0), begin_(0), end_(0), running_(false), verbose_(enabled ? 1 : 0)
laps_(0), last_(0), total_(0), adjusted_(0), begin_(0), end_(0), running_(false), verbose_(enabled ? 1 : 0)
{
name_[0] = '\0';
buff_[0] = '\0';
......@@ -200,8 +201,10 @@ Timer::doStop()
end_ = getNativeTime();
if (running_) {
last_ = end_ - begin_ - overhead_;
if (laps_ >= skip_)
if (laps_ >= skip_) {
total_ += last_;
adjusted_ += last_ / omp_get_num_threads();
}
++laps_;
running_ = false;
}
......@@ -218,6 +221,7 @@ Timer::doReset()
{
last_ = 0;
total_ = 0;
adjusted_= 0;
laps_ = 0;
running_ = false;
}
......@@ -248,7 +252,7 @@ Timer::getValue(bool details, bool msonly)
if (!enabled_)
return "";
getValue_s(buff_, sizeof(buff_),
getName(), getCount(), getTotal(), getRunning(),
getName(), getCount(), getTotal(), getAdjusted(), getRunning(),
details, msonly);
return buff_;
}
......@@ -258,7 +262,7 @@ Timer::getValue(bool details, bool msonly)
* \copydoc Timer::getValue
*/
void
Timer::getValue_s(char *result, int buffer_size, const char *name, int count, double total, bool running, bool details, bool msonly)
Timer::getValue_s(char *result, int buffer_size, const char *name, int count, double total, double adjusted, bool running, bool details, bool msonly)
{
result[0] = '\0';
......@@ -284,6 +288,17 @@ Timer::getValue_s(char *result, int buffer_size, const char *name, int count, do
if (count > 1)
sprintf_s(result+strlen(result), buffer_size-strlen(result), " in %d calls", count);
if (adjusted != total && adjusted != 0) {
if (msonly)
sprintf_s(result+strlen(result), buffer_size-strlen(result), " adjusted %9.1lf ms", adjusted * 1000.0);
else if (total < 0.00999)
sprintf_s(result+strlen(result), buffer_size-strlen(result), " adjusted %6.1lf us", adjusted * 1000000.0);
else if (total < 9.99)
sprintf_s(result+strlen(result), buffer_size-strlen(result), " adjusted %6.1lf ms", adjusted * 1000.0);
else
sprintf_s(result+strlen(result), buffer_size-strlen(result), " adjusted %6.1lf s ", adjusted * 1.0);
}
//if (getSkip() != 0)
// sprintf_s(result+strlen(result), buffer_size-strlen(result), " (first %d not counted)", getSkip());
......@@ -376,11 +391,12 @@ public:
long long frequency_;
std::atomic<int> count_;
std::atomic<long long> total_;
std::atomic<long long> adjusted_;
std::atomic<long long> last_;
char name_[256]; // Optional name of this timer
char buff_[256]; // Returned from getValue().
explicit Impl(const char *name)
: frequency_(1000*1000), count_(0), total_(0), last_(0)
: frequency_(1000*1000), count_(0), total_(0), adjusted_(0), last_(0)
{
name_[0] = '\0';
buff_[0] = '\0';
......@@ -426,6 +442,12 @@ SummaryTimer::getTotal() const
return static_cast<double>(pimpl_->total_.load()) / pimpl_->frequency_;
}
double
SummaryTimer::getAdjusted() const
{
return static_cast<double>(pimpl_->adjusted_.load()) / pimpl_->frequency_;
}
double
SummaryTimer::getLast() const
{
......@@ -442,11 +464,20 @@ const char*
SummaryTimer::getValue(bool details, bool msonly) const
{
Timer::getValue_s(pimpl_->buff_, sizeof(pimpl_->buff_),
getName(), getCount(), getTotal(), false,
getName(), getCount(), getTotal(), getAdjusted(), false,
details, msonly);
return pimpl_->buff_;
}
const char*
SummaryTimer::getCSV() const
{
sprintf_s(pimpl_->buff_, sizeof(pimpl_->buff_),
"TIMER,\"%s\",%d,%.3lf,%.3lf\n",
getName(), getCount(), getTotal(), getAdjusted());
return pimpl_->buff_;
}
/**
* \brief Clear all counters.
* \details The timer name is unchanged.
......@@ -456,6 +487,7 @@ SummaryTimer::reset()
{
pimpl_->count_ = 0;
pimpl_->total_ = 0;
pimpl_->adjusted_ = 0;
pimpl_->last_ = 0;
}
......@@ -465,10 +497,11 @@ SummaryTimer::reset()
* so it is possible to e.g. add an managed timer to an umanaged one.
*/
void
SummaryTimer::add(int count, double total, double last)
SummaryTimer::add(int count, double total, double adjusted, double last)
{
pimpl_->count_.fetch_add(count);
pimpl_->total_.fetch_add((long long)(total * pimpl_->frequency_));
pimpl_->adjusted_.fetch_add((long long)(adjusted * pimpl_->frequency_));
pimpl_->last_.store((long long)(last * pimpl_->frequency_));
}
......@@ -480,7 +513,7 @@ void
SummaryTimer::add(const Timer& t)
{
if (t.getEnabled()) {
add(t.getCount(), t.getTotal(), t.getLast());
add(t.getCount(), t.getTotal(), t.getAdjusted(), t.getLast());
}
}
......@@ -503,6 +536,7 @@ SummaryPrintingTimer::print()
{
if (getCount() != 0) {
const char *msg = getValue(true, true);
//const char *msg = getCSV();
fwrite(msg, 1, strlen(msg), stderr);
}
reset();
......
......@@ -66,6 +66,7 @@ private: // mutable
int laps_; // Number of accumulated results
long long last_; // Time for last lap
long long total_; // Accumulated total time
long long adjusted_; // Accumulated total time adjusted for thread count
long long begin_; // Time of last call to Start();
long long end_; // Time of last call to Stop();
bool running_; // Guard against two Stop() in a row.
......@@ -86,13 +87,14 @@ public:
double getFrequency() const { return static_cast<double>(frequency_); }
double getLast() const { return static_cast<double>(last_) / static_cast<double>(frequency_); }
double getTotal() const { return static_cast<double>(total_) / static_cast<double>(frequency_); }
double getAdjusted() const { return static_cast<double>(adjusted_) / static_cast<double>(frequency_); }
double getOverhead() const { return static_cast<double>(overhead_) / static_cast<double>(frequency_); }
int getCount() const { return laps_ < skip_ ? 0 : laps_ - skip_; }
const char* getName() const { return name_; }
int getSkip() const { return skip_ < laps_ ? skip_ : laps_; }
bool getRunning() const { return running_; }
int getVerbose() const { return verbose_; }
static void getValue_s(char *buf, int len, const char *name, int count, double total, bool running, bool details, bool msonly);
static void getValue_s(char *buf, int len, const char *name, int count, double total, double adjusted, bool running, bool details, bool msonly);
const char* getValue(bool details = false, bool msonly = false);
// Shouldn't be public but might come in handy if extending Timer.
double getLastStop() const { return end_; }
......@@ -174,13 +176,15 @@ public:
double getFrequency() const;
int getCount() const;
double getTotal() const;
double getAdjusted() const;
double getLast() const;
const char* getName() const;
const char* getValue(bool details, bool msonly) const;
const char* getCSV() const;
// OPERATIONS
void reset();
void add(int count, double total, double last);
void add(int count, double total, double adjusted, double last);
void add(const Timer& t);
};
......@@ -223,6 +227,12 @@ public:
* // timing the following code...
*}
* \endcode
*
* A more obscure feature: If you want to output the results of a
* SummaryPrintngTimer at a specific point then you can call done()
* on any SimpleTimer that is linked to this timer and is still
* in scope, and then call print() on the PrintingTimer to pretend
* that it went out of scope.
*/
class OPENZGY_TEST_API SimpleTimer : public Timer
{
......@@ -235,9 +245,13 @@ public:
}
~SimpleTimer()
{
done();
}
void done() {
if (getEnabled()) {
stop();
owner_.add(*this);
reset();
}
}
};
......
Supports Markdown
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment