From ac90ff21027ffb87dc8352d7f353da1c2f92d536 Mon Sep 17 00:00:00 2001 From: Ryan Curtin Date: Thu, 12 Oct 2017 17:16:38 -0400 Subject: [PATCH] Refactor timers: use mutexes and hold only one value. --- src/mlpack/bindings/cli/end_program.hpp | 10 +-- .../bindings/python/mlpack/cli_util.hpp | 4 +- src/mlpack/core/util/cli.cpp | 13 --- src/mlpack/core/util/cli.hpp | 5 -- src/mlpack/core/util/timers.cpp | 89 ++++++++++--------- src/mlpack/core/util/timers.hpp | 27 +++--- src/mlpack/tests/timer_test.cpp | 6 +- 7 files changed, 74 insertions(+), 80 deletions(-) diff --git a/src/mlpack/bindings/cli/end_program.hpp b/src/mlpack/bindings/cli/end_program.hpp index e07b9a1d4d..4eed33438c 100644 --- a/src/mlpack/bindings/cli/end_program.hpp +++ b/src/mlpack/bindings/cli/end_program.hpp @@ -21,7 +21,7 @@ namespace cli { inline void EndProgram() { // Stop the CLI timers. - CLI::StopTimers(); + CLI::GetSingleton().timer.StopAllTimers(); // Print any output. const std::map& parameters = CLI::Parameters(); @@ -61,12 +61,10 @@ inline void EndProgram() } Log::Info << "Program timers:" << std::endl; - std::list timerNames = - CLI::GetSingleton().timer.GetAllTimerNames(); - for (auto it2 : timerNames) + for (auto it2 : CLI::GetSingleton().timer.GetAllTimers()) { - Log::Info << " " << it2 << ": "; - CLI::GetSingleton().timer.PrintTimer(it2); + Log::Info << " " << it2.first << ": "; + CLI::GetSingleton().timer.PrintTimer(it2.first); } } } diff --git a/src/mlpack/bindings/python/mlpack/cli_util.hpp b/src/mlpack/bindings/python/mlpack/cli_util.hpp index bce15212f9..185a876f1d 100644 --- a/src/mlpack/bindings/python/mlpack/cli_util.hpp +++ b/src/mlpack/bindings/python/mlpack/cli_util.hpp @@ -114,7 +114,7 @@ inline void DisableBacktrace() inline void ResetTimers() { // Just get a new object---removes all old timers. - CLI::GetSingleton().timer = Timers(); + CLI::GetSingleton().timer.Reset(); } /** @@ -122,7 +122,7 @@ inline void ResetTimers() */ inline void EnableTimers() { - Timer::Enabled() = true; + Timer::EnableTiming(); } } // namespace util diff --git a/src/mlpack/core/util/cli.cpp b/src/mlpack/core/util/cli.cpp index 0c6a5e0126..f2793323e7 100644 --- a/src/mlpack/core/util/cli.cpp +++ b/src/mlpack/core/util/cli.cpp @@ -43,19 +43,6 @@ CLI::CLI(const CLI& /* other */) : didParse(false), doc(&emptyProgramDoc) return; } -void CLI::StopTimers() -{ - // Terminate the program timers. - for (auto it : CLI::GetSingleton().timer.GetAllTimers()) - { - for (auto it2 : it.second) - { - if (CLI::GetSingleton().timer.GetState(it2.first, it.first) == 1) - CLI::GetSingleton().timer.StopTimer(it2.first, it.first); - } - } -} - /** * Destroy the CLI object. This resets the pointer to the singleton, so in case * someone tries to access it after destruction, a new one will be made (the diff --git a/src/mlpack/core/util/cli.hpp b/src/mlpack/core/util/cli.hpp index b3f405c63d..48c54da466 100644 --- a/src/mlpack/core/util/cli.hpp +++ b/src/mlpack/core/util/cli.hpp @@ -202,11 +202,6 @@ class CLI template static std::string GetPrintableParam(const std::string& identifier); - /** - * Stop all of the timers. - */ - static void StopTimers(); - /** * Destroy the CLI object. This resets the pointer to the singleton, so in * case someone tries to access it after destruction, a new one will be made diff --git a/src/mlpack/core/util/timers.cpp b/src/mlpack/core/util/timers.cpp index 740f1186f5..146a5ff14a 100644 --- a/src/mlpack/core/util/timers.cpp +++ b/src/mlpack/core/util/timers.cpp @@ -42,12 +42,7 @@ void Timer::Stop(const string& name) */ microseconds Timer::Get(const string& name) { - microseconds result(0); - for (auto it : CLI::GetSingleton().timer.GetAllTimers()) - if (it.second.count(name) > 0) - result += it.second[name]; - - return result; + return CLI::GetSingleton().timer.GetTimer(name); } // Enable timing. @@ -65,34 +60,25 @@ void Timer::DisableTiming() // Reset all timers. Save state of enabled. void Timer::ResetAll() { - bool wasEnabled = CLI::GetSingleton().timer.Enabled(); - CLI::GetSingleton().timer = Timers(); - CLI::GetSingleton().timer.Enabled() = wasEnabled; + CLI::GetSingleton().timer.Reset(); } -map>& -Timers::GetAllTimers() +// Reset a Timers object. +void Timers::Reset() +{ + timers.clear(); + timerStartTime.clear(); + timerState.clear(); +} + +map& Timers::GetAllTimers() { return timers; } -list Timers::GetAllTimerNames() +microseconds Timers::GetTimer(const string& timerName) { - list l; - for (auto it : CLI::GetSingleton().timer.GetAllTimers()) - for (auto it2 : it.second) - l.push_back(it2.first); - - // Filter duplicates. - l.unique(); - - return l; -} - -microseconds Timers::GetTimer(const string& timerName, - const thread::id& threadId) -{ - return timers[threadId][timerName]; + return timers[timerName]; } bool Timers::GetState(const string& timerName, @@ -103,12 +89,8 @@ bool Timers::GetState(const string& timerName, void Timers::PrintTimer(const string& timerName) { - microseconds totalDuration(0); - for (auto it : timers) - if (it.second.count(timerName) > 0) - totalDuration += it.second[timerName]; - // Convert microseconds to seconds. + microseconds totalDuration = GetTimer(timerName); seconds totalDurationSec = duration_cast(totalDuration); microseconds totalDurationMicroSec = duration_cast(totalDuration % seconds(1)); @@ -166,6 +148,19 @@ void Timers::PrintTimer(const string& timerName) Log::Info << endl; } +void Timers::StopAllTimers() +{ + // Terminate the program timers. + for (auto it : timerState) + { + for (auto it2 : it.second) + { + if (timerState[it.first][it2.first] == 1) + StopTimer(it2.first, it.first); + } + } +} + high_resolution_clock::time_point Timers::GetTime() { return high_resolution_clock::now(); @@ -174,7 +169,8 @@ high_resolution_clock::time_point Timers::GetTime() void Timers::StartTimer(const string& timerName, const thread::id& threadId) { - if ((timerState[threadId][timerName] == 1) && (timerName != "total_time")) + timersMutex.lock(); + if ((timerState[threadId][timerName]) && (timerName != "total_time")) { ostringstream error; error << "Timer::Start(): timer '" << timerName @@ -182,23 +178,24 @@ void Timers::StartTimer(const string& timerName, throw runtime_error(error.str()); } - timerState[threadId][timerName] = true; - high_resolution_clock::time_point currTime = GetTime(); - // If the timer is added first time. - if (timers[threadId].count(timerName) == 0) + // If the timer is added for the first time. + if (timers.count(timerName) == 0) { - timers[threadId][timerName] = (microseconds) 0; + timers[timerName] = (microseconds) 0; } + timerState[threadId][timerName] = true; timerStartTime[threadId][timerName] = currTime; + timersMutex.unlock(); } void Timers::StopTimer(const string& timerName, const thread::id& threadId) { - if ((timerState[threadId][timerName] == 0) && (timerName != "total_time")) + timersMutex.lock(); + if ((!timerState[threadId][timerName]) && (timerName != "total_time")) { ostringstream error; error << "Timer::Stop(): timer '" << timerName @@ -206,11 +203,19 @@ void Timers::StopTimer(const string& timerName, throw runtime_error(error.str()); } - timerState[threadId][timerName] = false; - high_resolution_clock::time_point currTime = GetTime(); // Calculate the delta time. - timers[threadId][timerName] += duration_cast(currTime - + timerState[threadId][timerName] = false; + timers[timerName] += duration_cast(currTime - timerStartTime[threadId][timerName]); + + // Remove the entries. + timerState[threadId].erase(timerName); + timerStartTime[threadId].erase(timerName); + if (timerState[threadId].empty()) + timerState.erase(threadId); + if (timerStartTime[threadId].empty()) + timerStartTime.erase(threadId); + timersMutex.unlock(); } diff --git a/src/mlpack/core/util/timers.hpp b/src/mlpack/core/util/timers.hpp index dc7f3b45a5..af2655f208 100644 --- a/src/mlpack/core/util/timers.hpp +++ b/src/mlpack/core/util/timers.hpp @@ -17,6 +17,7 @@ #include #include // chrono library for cross platform timer calculation. #include // std::thread is used for thread safety. +#include #include #if defined(_WIN32) @@ -100,23 +101,21 @@ class Timers /** * Returns a copy of all the timers used via this interface. */ - std::map>& - GetAllTimers(); + std::map& GetAllTimers(); /** - * Returns a list of all timer names. + * Reset the timers. This stops all running timers and removes them. Whether + * or not timing is enabled will not be changed. */ - std::list GetAllTimerNames(); + void Reset(); /** - * Returns a copy of the timer specified. + * Returns a copy of the timer specified. This contains the sum of the timing + * results for timers that have been stopped with this name. * * @param timerName The name of the timer in question. - * @param threadId Id of the thread accessing the timer. */ - std::chrono::microseconds GetTimer( - const std::string& timerName, - const std::thread::id& threadId = std::thread::id()); + std::chrono::microseconds GetTimer(const std::string& timerName); /** * Prints the specified timer. If it took longer than a minute to complete @@ -156,6 +155,11 @@ class Timers bool GetState(const std::string& timerName, const std::thread::id& threadId = std::thread::id()); + /** + * Stop all timers. + */ + void StopAllTimers(); + //! Modify whether or not timing is enabled. bool& Enabled() { return enabled; } //! Get whether or not timing is enabled. @@ -163,8 +167,9 @@ class Timers private: //! A map of all the timers that are being tracked. - std::map> - timers; + std::map timers; + //! A mutex for modifying the timers. + std::mutex timersMutex; //! A map that contains whether or not each timer is currently running. std::map> timerState; //! A map for the starting values of the timers. diff --git a/src/mlpack/tests/timer_test.cpp b/src/mlpack/tests/timer_test.cpp index b0a3b3042b..f24c8d7c4e 100644 --- a/src/mlpack/tests/timer_test.cpp +++ b/src/mlpack/tests/timer_test.cpp @@ -98,6 +98,7 @@ BOOST_AUTO_TEST_CASE(TwiceStartTimerTest) Timer::DisableTiming(); } +#include BOOST_AUTO_TEST_CASE(MultithreadTimerTest) { Timer::EnableTiming(); @@ -112,7 +113,10 @@ BOOST_AUTO_TEST_CASE(MultithreadTimerTest) #ifdef _WIN32 Sleep(20); #else - usleep(20000); + int restarts = 0; + // Catch occasional EINTR failures. + while (usleep(20000) != 0 && restarts < 3) + ++restarts; #endif Timer::Stop("thread_timer");