From a522c219ce28c83515812b006111d8de70d80bcd Mon Sep 17 00:00:00 2001 From: "kjell@kjell-win7.hsd1.co.comcast.net." Date: Sat, 28 Dec 2013 20:39:12 +0100 Subject: [PATCH] cleaned up time use --- g2log/src/g2filesink.cpp | 1 - g2log/src/g2filesink.hpp | 2 -- g2log/src/g2future.hpp | 3 ++- g2log/src/g2logmessage.cpp | 8 +++---- g2log/src/g2logmessage.hpp | 2 +- g2log/src/g2moveoncopy.hpp | 2 +- g2log/src/g2sinkhandle.hpp | 2 +- g2log/src/g2time.hpp | 1 - .../test_performance/main_threaded_worst.cpp | 22 +++++++++---------- 9 files changed, 20 insertions(+), 23 deletions(-) diff --git a/g2log/src/g2filesink.cpp b/g2log/src/g2filesink.cpp index b9f1f13..9db4613 100644 --- a/g2log/src/g2filesink.cpp +++ b/g2log/src/g2filesink.cpp @@ -14,7 +14,6 @@ FileSink::FileSink(const std::string& log_prefix, const std::string& log_directo : _log_file_with_path(log_directory) , _log_prefix_backup(log_prefix) , _outptr(new std::ofstream) -, _steady_start_time(std::chrono::steady_clock::now()) { _log_prefix_backup = prefixSanityFix(log_prefix); if (!isValidFilename(_log_prefix_backup)) { diff --git a/g2log/src/g2filesink.hpp b/g2log/src/g2filesink.hpp index ad8c2f8..c5c06bb 100644 --- a/g2log/src/g2filesink.hpp +++ b/g2log/src/g2filesink.hpp @@ -11,7 +11,6 @@ #include #include "g2logmessage.hpp" // TODO refactoring, should include message instead -#include "g2time.hpp" namespace g2 { @@ -29,7 +28,6 @@ private: std::string _log_file_with_path; std::string _log_prefix_backup; // needed in case of future log file changes of directory std::unique_ptr _outptr; - g2::steady_time_point _steady_start_time; void addLogFileHeader(); std::ofstream & filestream() {return *(_outptr.get()); } diff --git a/g2log/src/g2future.hpp b/g2log/src/g2future.hpp index de04385..ba0f740 100644 --- a/g2log/src/g2future.hpp +++ b/g2log/src/g2future.hpp @@ -27,6 +27,7 @@ #include #include "active.hpp" #include "g2moveoncopy.hpp" +#include "stlpatch_future.hpp" namespace g2 { // Generic helper function to avoid repeating the steps for managing @@ -47,7 +48,7 @@ std::future::type> spawn_task(Func func, BgWorke task_type task(std::move(func)); std::future result = task.get_future(); - worker->send(MoveOnCopy(std::move(task))); + worker->send(MoveOnCopy(std::move(task))); return std::move(result); } } // end namespace g2 diff --git a/g2log/src/g2logmessage.cpp b/g2log/src/g2logmessage.cpp index 4791c0f..fb4a30c 100644 --- a/g2log/src/g2logmessage.cpp +++ b/g2log/src/g2logmessage.cpp @@ -17,11 +17,11 @@ namespace { std::once_flag g_start_time_flag; - g2::steady_time_point g_start_time; + std::chrono::steady_clock::time_point g_start_time; - long microsecondsCounter() { - std::call_once(g_start_time_flag, []() { g_start_time = std::chrono::steady_clock::now(); }); - g2::steady_time_point now = std::chrono::steady_clock::now(); + int64_t microsecondsCounter() { + std::call_once(g_start_time_flag, []() { g_start_time = std::chrono::steady_clock::now(); }); + auto now = std::chrono::steady_clock::now(); return std::chrono::duration_cast(now - g_start_time).count(); } diff --git a/g2log/src/g2logmessage.hpp b/g2log/src/g2logmessage.hpp index af7dcd4..6cf4941 100644 --- a/g2log/src/g2logmessage.hpp +++ b/g2log/src/g2logmessage.hpp @@ -53,7 +53,7 @@ namespace g2 { protected: std::time_t _timestamp; - long _microseconds; + int64_t _microseconds; std::string _file; int _line; std::string _function; diff --git a/g2log/src/g2moveoncopy.hpp b/g2log/src/g2moveoncopy.hpp index aa72cc9..e724e15 100644 --- a/g2log/src/g2moveoncopy.hpp +++ b/g2log/src/g2moveoncopy.hpp @@ -30,7 +30,7 @@ namespace g2 { return *this; } - void operator()() { _move_only(); } + void operator()() { _move_only(); } Moveable& get() { return _move_only; } Moveable release() { return std::move(_move_only); } }; diff --git a/g2log/src/g2sinkhandle.hpp b/g2log/src/g2sinkhandle.hpp index acf809c..0bda393 100644 --- a/g2log/src/g2sinkhandle.hpp +++ b/g2log/src/g2sinkhandle.hpp @@ -40,7 +40,7 @@ namespace g2 { std::shared_ptr> sink(_sink); return sink->send(call, args...); } catch (const std::bad_weak_ptr& e) { - T* t; + T* t = nullptr; typedef decltype(std::bind(call, t, args...)()) PromiseType; std::promise promise; promise.set_exception(std::make_exception_ptr(e)); diff --git a/g2log/src/g2time.hpp b/g2log/src/g2time.hpp index 842a219..814f476 100644 --- a/g2log/src/g2time.hpp +++ b/g2log/src/g2time.hpp @@ -28,7 +28,6 @@ namespace g2 static const std::string time_formatted = "%H:%M:%S"; } - typedef std::chrono::steady_clock::time_point steady_time_point; typedef std::chrono::time_point system_time_point; typedef std::chrono::milliseconds milliseconds; typedef std::chrono::microseconds microseconds; diff --git a/g2log/test_performance/main_threaded_worst.cpp b/g2log/test_performance/main_threaded_worst.cpp index 2a82ff1..814b381 100644 --- a/g2log/test_performance/main_threaded_worst.cpp +++ b/g2log/test_performance/main_threaded_worst.cpp @@ -55,15 +55,15 @@ int main(int argc, char** argv) const std::string g_prefix_log_name = title + "-performance-" + thread_count_oss.str() + "threads-WORST_LOG"; const std::string g_measurement_dump= g_path + g_prefix_log_name + "_RESULT.txt"; const std::string g_measurement_bucket_dump= g_path + g_prefix_log_name + "_RESULT_buckets.txt"; - - + const int64_t us_to_ms = 1000; + const int64_t us_to_s = 1000000; std::ostringstream oss; oss << "\n\n" << title << " performance " << number_of_threads << " threads WORST (PEAK) times\n"; oss << "Each thread running #: " << g_loop << " * " << g_iterations << " iterations of log entries" << std::endl; // worst mean case is about 10us per log entry const size_t xtra_margin = 2; - oss << "*** It can take som time. Please wait: Approximate wait time on MY PC was: " << number_of_threads * (long long) (g_iterations * 10 * xtra_margin / 1000000 ) << " seconds" << std::endl; + oss << "*** It can take som time. Please wait: Approximate wait time on MY PC was: " << number_of_threads * (int64_t)(g_iterations * 10 * xtra_margin / us_to_s) << " seconds" << std::endl; writeTextToFile(g_measurement_dump, oss.str(), kAppend); oss.str(""); // clear the stream @@ -85,7 +85,7 @@ int main(int argc, char** argv) threads_result[idx].reserve(g_iterations); } - auto start_time = std::chrono::steady_clock::now(); + auto start_time = std::chrono::high_resolution_clock::now(); for(size_t idx = 0; idx < number_of_threads; ++idx) { std::ostringstream count; @@ -99,7 +99,7 @@ int main(int argc, char** argv) { threads[idx].join(); } - auto application_end_time = std::chrono::steady_clock::now(); + auto application_end_time = std::chrono::high_resolution_clock::now(); delete [] threads; @@ -109,13 +109,13 @@ int main(int argc, char** argv) google::ShutdownGoogleLogging(); #endif - auto worker_end_time = std::chrono::steady_clock::now(); + auto worker_end_time = std::chrono::high_resolution_clock::now(); auto application_time_us = std::chrono::duration_cast(application_end_time - start_time).count(); auto total_time_us = std::chrono::duration_cast(worker_end_time - start_time).count(); - oss << "\n" << number_of_threads << "*" << g_iterations << " log entries took: [" << total_time_us / 1000000 << " s] to write to disk"<< std::endl; - oss << "[Application(" << number_of_threads << "_threads+overhead time for measurement):\t" << application_time_us/1000 << " ms]" << std::endl; - oss << "[Background thread to finish:\t\t\t\t" << total_time_us/1000 << " ms]" << std::endl; + oss << "\n" << number_of_threads << "*" << g_iterations << " log entries took: [" << total_time_us / us_to_s << " s] to write to disk" << std::endl; + oss << "[Application(" << number_of_threads << "_threads+overhead time for measurement):\t" << application_time_us/us_to_ms << " ms]" << std::endl; + oss << "[Background thread to finish:\t\t\t\t" << total_time_us/us_to_ms << " ms]" << std::endl; oss << "\nAverage time per log entry:" << std::endl; oss << "[Application: " << application_time_us/(number_of_threads*g_iterations) << " us]" << std::endl; @@ -123,7 +123,7 @@ int main(int argc, char** argv) { std::vector& t_result = threads_result[idx]; auto worstUs = (*std::max_element(t_result.begin(), t_result.end())); - oss << "[Application t" << idx+1 << " worst took: " << worstUs / 1000 << " ms (" << worstUs << " us)] " << std::endl; + oss << "[Application t" << idx+1 << " worst took: " << worstUs / int64_t(1000) << " ms (" << worstUs << " us)] " << std::endl; } writeTextToFile(g_measurement_dump,oss.str(), kAppend); std::cout << "Result can be found at:" << g_measurement_dump << std::endl; @@ -143,7 +143,7 @@ int main(int argc, char** argv) // for(long long& idx : all_measurements) --- didn't work?! for(auto iter = all_measurements.begin(); iter != all_measurements.end(); ++iter) { - auto value = (*iter)/1000; // convert to ms + auto value = (*iter)/us_to_ms; // convert to ms //auto bucket=floor(value*10+0.5)/10; ++value_amounts[value]; // asuming size_t is default 0 when initialized }