Commit 7b977fbd authored by David Frank's avatar David Frank Committed by Tobias Lasser
Browse files

Refactor and adapt output format of Timer

This patch adds 3 changes:
- Rely on spdlog::stopwatch instead of the 'raw' standard library clock
- Change the output format a touch to improve readability
- Rename of variables to express intent better

As of version 1.8.0 of spdlog a stopwatch is provided. I thought it
would be nice to justs rely on that one instead of rolling our own (even
if it's not that hard).

The other change is the output format. Instead of printing in the format
'[Timing] [debug] Execution of <caller>: <fn> took <time>ms', I changed
it to '[<caller>] [debug] <fn> took <time>s'. So instead of having a
separate Timing logger, the logger for the class is used. IMO, this
cleans up the log a touch, as my eyes don't have to search in different
columns, but it's minor. Also I use the default output format of the
spdlog::stopwatch, which is in decimal and seconds.

Also I used the change to rename the variables, as it was just a little
off.
parent 921ede92
Pipeline #651737 passed with stages
in 22 minutes and 16 seconds
...@@ -2,24 +2,10 @@ ...@@ -2,24 +2,10 @@
namespace elsa namespace elsa
{ {
template <class Duration, class Clock> Timer::Timer(std::string caller, std::string method)
Timer<Duration, Clock>::Timer(std::string name, std::string message) : _caller{std::move(caller)}, _method{std::move(method)}
: _start{Clock::now()}, _name{std::move(name)}, _message{std::move(message)}
{ {
} }
template <class Duration, class Clock> Timer::~Timer() { Logger::get(_caller)->debug("{} took {:.3}s", _method, _watch); }
Timer<Duration, Clock>::~Timer()
{
typename Clock::time_point stop = Clock::now();
auto timeElapsed =
std::to_string(std::chrono::duration_cast<Duration>(stop - _start).count());
Logger::get("Timing")->debug("Execution of {}: {} took {} ms", _name, _message,
timeElapsed);
}
// ------------------------------------------
// explicit template instantiation
template class Timer<std::chrono::milliseconds, std::chrono::steady_clock>;
} // namespace elsa } // namespace elsa
...@@ -3,6 +3,8 @@ ...@@ -3,6 +3,8 @@
#include <chrono> #include <chrono>
#include <string> #include <string>
#include "spdlog/stopwatch.h"
#include "Logger.h" #include "Logger.h"
namespace elsa namespace elsa
...@@ -10,27 +12,29 @@ namespace elsa ...@@ -10,27 +12,29 @@ namespace elsa
/** /**
* @brief Timer class to provide easy logging of timing. * @brief Timer class to provide easy logging of timing.
* *
* This class provides logging of timing using the guard pattern. It measures the current time
* from creation, until destruction and outputs a log message with time elapsed on destruction.
*
* @author Matthias Wieczorek - initial code * @author Matthias Wieczorek - initial code
* @author Maximilian Hornung - modularization * @author Maximilian Hornung - modularization
* @author Tobias Lasser - minor changes * @author Tobias Lasser - minor changes
* @author David Frank - use spdlog::stopwatch, renaming of variables for expressing intent
* better
* *
* This class provides logging of timing using the guard pattern. It stores the current time
* upon creation, and outputs a log message with time elapsed on destruction.
*/ */
template <class Duration = std::chrono::milliseconds, class Clock = std::chrono::steady_clock>
class Timer class Timer
{ {
public: public:
/// start the timer, using loggerName as logger, outputting message at end /// start the timer, using loggerName as logger, outputting message at end
Timer(std::string name, std::string message); Timer(std::string caller, std::string method);
/// stop the timer and actually output the log message /// stop the timer and actually output the log message
~Timer(); ~Timer();
private: private:
typename Clock::time_point _start; /// the start time on creation spdlog::stopwatch _watch{}; /// stopwatch measuring the time
std::string _name; /// the name of what is running std::string _caller; /// the name of what is running
std::string _message; /// the message to output (in addition to timing) std::string _method; /// the message to output (in addition to timing)
}; };
} // namespace elsa } // namespace elsa
...@@ -61,7 +61,7 @@ namespace elsa ...@@ -61,7 +61,7 @@ namespace elsa
void FiniteDifferences<data_t>::applyImpl(const DataContainer<data_t>& x, void FiniteDifferences<data_t>::applyImpl(const DataContainer<data_t>& x,
DataContainer<data_t>& Ax) const DataContainer<data_t>& Ax) const
{ {
Timer<> timeguard("FiniteDifferences", "apply"); Timer timeguard("FiniteDifferences", "apply");
Ax = 0; Ax = 0;
...@@ -84,7 +84,7 @@ namespace elsa ...@@ -84,7 +84,7 @@ namespace elsa
void FiniteDifferences<data_t>::applyAdjointImpl(const DataContainer<data_t>& y, void FiniteDifferences<data_t>::applyAdjointImpl(const DataContainer<data_t>& y,
DataContainer<data_t>& Aty) const DataContainer<data_t>& Aty) const
{ {
Timer<> timeguard("FiniteDifferences", "applyAdjoint"); Timer timeguard("FiniteDifferences", "applyAdjoint");
Aty = 0; Aty = 0;
......
...@@ -36,7 +36,7 @@ namespace elsa ...@@ -36,7 +36,7 @@ namespace elsa
void JosephsMethod<data_t>::applyImpl(const DataContainer<data_t>& x, void JosephsMethod<data_t>::applyImpl(const DataContainer<data_t>& x,
DataContainer<data_t>& Ax) const DataContainer<data_t>& Ax) const
{ {
Timer<> timeguard("JosephsMethod", "apply"); Timer timeguard("JosephsMethod", "apply");
traverseVolume<false>(x, Ax); traverseVolume<false>(x, Ax);
} }
...@@ -44,7 +44,7 @@ namespace elsa ...@@ -44,7 +44,7 @@ namespace elsa
void JosephsMethod<data_t>::applyAdjointImpl(const DataContainer<data_t>& y, void JosephsMethod<data_t>::applyAdjointImpl(const DataContainer<data_t>& y,
DataContainer<data_t>& Aty) const DataContainer<data_t>& Aty) const
{ {
Timer<> timeguard("JosephsMethod", "applyAdjoint"); Timer timeguard("JosephsMethod", "applyAdjoint");
traverseVolume<true>(y, Aty); traverseVolume<true>(y, Aty);
} }
......
...@@ -134,7 +134,7 @@ namespace elsa ...@@ -134,7 +134,7 @@ namespace elsa
void JosephsMethodCUDA<data_t>::applyImpl(const DataContainer<data_t>& x, void JosephsMethodCUDA<data_t>::applyImpl(const DataContainer<data_t>& x,
DataContainer<data_t>& Ax) const DataContainer<data_t>& Ax) const
{ {
Timer<> timeGuard("JosephsMethodCUDA", "apply"); Timer timeGuard("JosephsMethodCUDA", "apply");
// transfer volume as texture // transfer volume as texture
auto [volumeTex, volume] = copyTextureToGPU(x); auto [volumeTex, volume] = copyTextureToGPU(x);
...@@ -218,7 +218,7 @@ namespace elsa ...@@ -218,7 +218,7 @@ namespace elsa
void JosephsMethodCUDA<data_t>::applyAdjointImpl(const DataContainer<data_t>& y, void JosephsMethodCUDA<data_t>::applyAdjointImpl(const DataContainer<data_t>& y,
DataContainer<data_t>& Aty) const DataContainer<data_t>& Aty) const
{ {
Timer<> timeguard("JosephsMethodCUDA", "applyAdjoint"); Timer timeguard("JosephsMethodCUDA", "applyAdjoint");
// allocate memory for volume // allocate memory for volume
auto domainDims = _domainDescriptor->getNumberOfCoefficientsPerDimension(); auto domainDims = _domainDescriptor->getNumberOfCoefficientsPerDimension();
......
...@@ -96,7 +96,7 @@ namespace elsa ...@@ -96,7 +96,7 @@ namespace elsa
void SiddonsMethodCUDA<data_t>::applyImpl(const DataContainer<data_t>& x, void SiddonsMethodCUDA<data_t>::applyImpl(const DataContainer<data_t>& x,
DataContainer<data_t>& Ax) const DataContainer<data_t>& Ax) const
{ {
Timer<> timeGuard("SiddonsMethodCUDA", "apply"); Timer timeGuard("SiddonsMethodCUDA", "apply");
traverseVolume<false>((void*) &(x[0]), (void*) &(Ax[0])); traverseVolume<false>((void*) &(x[0]), (void*) &(Ax[0]));
} }
...@@ -105,7 +105,7 @@ namespace elsa ...@@ -105,7 +105,7 @@ namespace elsa
void SiddonsMethodCUDA<data_t>::applyAdjointImpl(const DataContainer<data_t>& y, void SiddonsMethodCUDA<data_t>::applyAdjointImpl(const DataContainer<data_t>& y,
DataContainer<data_t>& Aty) const DataContainer<data_t>& Aty) const
{ {
Timer<> timeguard("SiddonsMethodCUDA", "applyAdjoint"); Timer timeguard("SiddonsMethodCUDA", "applyAdjoint");
traverseVolume<true>((void*) &(Aty[0]), (void*) &(y[0])); traverseVolume<true>((void*) &(Aty[0]), (void*) &(y[0]));
} }
......
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