cleaned up time use

This commit is contained in:
kjell@kjell-win7.hsd1.co.comcast.net. 2013-12-28 20:39:12 +01:00
parent 2e5d323b52
commit a522c219ce
9 changed files with 20 additions and 23 deletions

View File

@ -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)) {

View File

@ -11,7 +11,6 @@
#include <memory>
#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<std::ofstream> _outptr;
g2::steady_time_point _steady_start_time;
void addLogFileHeader();
std::ofstream & filestream() {return *(_outptr.get()); }

View File

@ -27,6 +27,7 @@
#include <future>
#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<typename std::result_of<Func()>::type> spawn_task(Func func, BgWorke
task_type task(std::move(func));
std::future<result_type> result = task.get_future();
worker->send(MoveOnCopy<task_type>(std::move(task)));
worker->send(MoveOnCopy<task_type>(std::move(task)));
return std::move(result);
}
} // end namespace g2

View File

@ -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<std::chrono::microseconds>(now - g_start_time).count();
}

View File

@ -53,7 +53,7 @@ namespace g2 {
protected:
std::time_t _timestamp;
long _microseconds;
int64_t _microseconds;
std::string _file;
int _line;
std::string _function;

View File

@ -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); }
};

View File

@ -40,7 +40,7 @@ namespace g2 {
std::shared_ptr<internal::Sink<T>> 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<PromiseType> promise;
promise.set_exception(std::make_exception_ptr(e));

View File

@ -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<std::chrono::system_clock> system_time_point;
typedef std::chrono::milliseconds milliseconds;
typedef std::chrono::microseconds microseconds;

View File

@ -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<microsecond>(application_end_time - start_time).count();
auto total_time_us = std::chrono::duration_cast<microsecond>(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<long long>& 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
}