diff --git a/.gitlab-ci.yml b/.gitlab-ci.yml index e7629f991cd9ba131d1cfac26c5a5f3a48bbd877..675725ee75695e475e751a717bc2520f02d10522 100644 --- a/.gitlab-ci.yml +++ b/.gitlab-ci.yml @@ -109,6 +109,10 @@ variables: variables: EMPER_WORKER_WAKEUP_STRATEGY: "all" +.do-not-log-timestamp: + variables: + EMPER_LOG_TIMESTAMP: "false" + test-gcc: extends: - .test @@ -184,3 +188,8 @@ test-worker-wakeup-strategy-all: extends: - .test - .worker-wakeup-strategy-all + +test-do-not-log-timestamp: + extends: + - .test + - .do-not-log-timestamp diff --git a/emper/Debug.cpp b/emper/Debug.cpp index ffc6012f4108e1383ed70321fded214d21d529a5..6c3248280e995fad47616a06a59d66404dc0a4f4 100644 --- a/emper/Debug.cpp +++ b/emper/Debug.cpp @@ -2,36 +2,60 @@ // Copyright © 2020 Florian Schmaus #include "Debug.hpp" +#include <chrono> +#include <ctime> // for localtime #include <iomanip> // for operator<<, setfill, setw #include <iostream> // for operator<<, cerr, ostream, basic_ostream #include <mutex> // for mutex, unique_lock #include "Common.hpp" +#include "Emper.hpp" #include "Worker.hpp" // for Runtime #include "emper-common.h" // for workerid_t #include "emper-config.h" // for EMPER_LOG_LEVEL static std::mutex emper_log_mutex; +void emper_add_timestamp_to(std::ostringstream& logMessage) { + auto now = std::chrono::high_resolution_clock::now(); + + auto now_time_t = std::chrono::high_resolution_clock::to_time_t(now); + auto* now_localtime = std::localtime(&now_time_t); + logMessage << std::put_time(now_localtime, "%H%M."); + + auto now_nanos = std::chrono::time_point_cast<std::chrono::nanoseconds>(now); + auto time_since_epoch = now_nanos.time_since_epoch(); + long time_since_epoch_long = time_since_epoch.count(); + + long remaining_nanos = time_since_epoch_long % 1000000000; + logMessage << remaining_nanos; +} + void emper_log(const std::string& prefix, const std::string& message) { Worker* worker = Worker::getCurrentWorker(); - std::ostringstream workerPrefix; + std::ostringstream logMessage; if (likely(worker)) { workerid_t workerId = worker->getWorkerId(); std::string workerIdAsString = std::to_string(workerId); - workerPrefix << std::setfill('0') << std::setw(3) << workerIdAsString << " "; + logMessage << std::setfill('0') << std::setw(3) << workerIdAsString << " "; } else { - workerPrefix << " "; + logMessage << " "; + } + + if constexpr (emper::LOG_TIMESTAMP) { + emper_add_timestamp_to(logMessage); } - std::unique_lock<std::mutex> lock(emper_log_mutex); - std::cerr << workerPrefix.str(); if (!prefix.empty()) { - std::cerr << " " << prefix << " "; + logMessage << " " << prefix << " "; } else { - std::cerr << " "; + logMessage << " "; } - std::cerr << message << std::endl; + + logMessage << message; + + std::unique_lock<std::mutex> lock(emper_log_mutex); + std::cerr << logMessage.str() << std::endl; } // global log_level which can be changed to control the log output diff --git a/emper/Debug.hpp b/emper/Debug.hpp index a2de8be4832ac9d0f336a3e7cee8a704e7c3c910..71b9cea518484703e2824f0277a006cba1933076 100644 --- a/emper/Debug.hpp +++ b/emper/Debug.hpp @@ -82,6 +82,8 @@ namespace emper { extern enum LogLevel log_level; } +void emper_add_timestamp_to(std::ostringstream& logMessage); + void emper_log(const std::string& prefix, const std::string& message); template <LogSubsystem logSubsystem> diff --git a/emper/Emper.hpp b/emper/Emper.hpp index b321dc1b99da50cd564cfc13a3bd25c14b12a44c..ef2ee4e1b916c0f9d988c20ef7614a5829505e07 100644 --- a/emper/Emper.hpp +++ b/emper/Emper.hpp @@ -48,5 +48,13 @@ static const bool DEBUG = #endif ; +static const bool LOG_TIMESTAMP = +#ifdef EMPER_LOG_TIMESTAMP + true +#else + false +#endif + ; + auto getFullVersion() -> std::string; } // namespace emper diff --git a/iwyu-mappings.imp b/iwyu-mappings.imp index 3b0d99bef9cad915b5f885595e236530608d3c27..d488f92979391bc3e5f498df5d942ec204ca8625 100644 --- a/iwyu-mappings.imp +++ b/iwyu-mappings.imp @@ -2,4 +2,5 @@ { include: ["<bits/getopt_core.h>", "private", "<unistd.h>", "public"] }, { include: ["@<gtest/.*>", "private", "<gtest/gtest.h>", "public"] }, { include: ["<urcu/map/urcu-memb.h>", "private", "<urcu.h>", "public"] }, + { include: ["<bits/cxxabi_forced.h>", "private", "<ctime>", "public" ] }, ] diff --git a/meson.build b/meson.build index 6d8f5d40bf6366096784dc0a5074b763a00566ce..d0ae395fb545d0697f7fb27281060fa040ecf05f 100644 --- a/meson.build +++ b/meson.build @@ -44,6 +44,7 @@ elif log_level == 'OFF' conf_data.set('EMPER_LOG_OFF', true) endif conf_data.set('EMPER_LOG_LEVEL', log_level) +conf_data.set('EMPER_LOG_TIMESTAMP', get_option('log_timestamp')) subdir('emper') subdir('tests') diff --git a/meson_options.txt b/meson_options.txt index 99943e52a1e8e19ca2afab6f121a9b2825aa778f..2fcd1b2cb70931ac4fa42012470262c936537c1d 100644 --- a/meson_options.txt +++ b/meson_options.txt @@ -10,6 +10,12 @@ option( choices: ['automatic', 'OFF', 'Error', 'Warning', 'Info', 'Debug', 'FineDebug', 'FinerDebug', 'FinestDebug', 'ALL'], value: 'automatic', ) +option( + 'log_timestamp', + type: 'boolean', + value: true, + description: 'Add a timestamp to the EMPER log messages', +) option( 'worker_sleep', type: 'boolean',