From dbba2b2b1dd6fe71a6b10b29fb41aa9ab6ef5b0f Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Tue, 22 Dec 2020 17:00:46 +0100 Subject: [PATCH 01/27] Added log levels. Ensured that C++17 is needed to compile. --- CMakeLists.txt | 2 +- README.md | 32 +++++++++++-- src/Log.h | 84 ++++++++++++++++++++++------------ test/test-stdthreadostream.cpp | 14 +++++- 4 files changed, 96 insertions(+), 36 deletions(-) diff --git a/CMakeLists.txt b/CMakeLists.txt index f9fc715..4a974c4 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -1,7 +1,7 @@ cmake_minimum_required(VERSION 3.17) project(cpp_logger) -set(CMAKE_CXX_STANDARD 20) +set(CMAKE_CXX_STANDARD 17) include_directories(cpp-memory-manager) include_directories(src) diff --git a/README.md b/README.md index 42f88d3..f7c74ea 100644 --- a/README.md +++ b/README.md @@ -12,14 +12,14 @@ Log::registerCurrentTask("main"); Log::i(nowtech::LogTopics::system) << "bulk data size:" << someCollection.size() << Log::end; // one group of 2 items -auto logger = Log::n() << "bulk data follows:"; // one group of many items starts +auto logger = Log::n() << "bulk data follows:"; // one group of many items starts for(auto item : someCollection) { logger << LC::X4 << item; // format: hexadecimal, fill to 4 digits } logger << Log::end; // the group of many items ends ``` -This is a complete rework of my [old logger](https://github.com/balazs-bamer/cpp-logger/tree/old/) after identifying the design flaws and performance problems. I used C++20 -capable compilers during development, but the code is probably C++17 compatible. +This is a complete rework of my [old logger](https://github.com/balazs-bamer/cpp-logger/tree/old/) after identifying the design flaws and performance problems. The library requires C++17. The code was written to possibly conform MISRA C++ and High-Integrity C++. @@ -36,7 +36,7 @@ Copyright 2020 Balázs Bámer. - String literals or string constants can be transferred using their pointers to save MCU cycles. - More transient strings will be copied instantly. - Operate in a _strictly typed_ way as opposed to the printf-based loggers some companies still use today. -- We needed a much finer granularity than the usual log levels, so I've introduced independently selectable topics. However, these allow easy simulation of traditional log levels, see in the API section. +- We needed a much finer granularity than the usual log levels, so I've introduced independently selectable topics. Recently I've also added traditional log levels. - Important aim was to let the user log a _group of related items_ without other tasks interleaving the output of converting these items. - Possibly minimal relying on external libraries. It does not depend on numeric to string conversion functions. - In contrast with the original solution, the new one extensively uses templated classes to @@ -263,6 +263,7 @@ Explanation of configuration parameters: |`TaskRepresentation tTaskRepresentation` |`Log` |One of `cNone` (for omitting it), `cId` (for numeric task ID), `cName` (for task name).| |`size_t tDirectBufferSize` |`Log` |When 0, the given _Queue_ will be used. Otherwise, it is the size of a buffer on stack to hold a converted item before sending it.| |`typename tSender::tAppInterface_::LogTime tRefreshPeriod`|`Log` |Timeout in implementation-defined unit (usually ms) for waiting on the queue before sending what already present.| +|`ErrorLevel tErrorLevel` |`Log` |The application log level with the default value `ErrorLevel::All`.| |`bool allowRegistrationLog` |`LogConfig` |True if task (un)registering should be logged.| |`LogFormat taskIdFormat` |`LogConfig` |Format of task ID to use when `tTaskRepresentation == TaskRepresentation::cId`.| |`LogFormat tickFormat` |`LogConfig` |Format for displaying the timestamp in the header, if any. Should be `LogConfig::cInvalid` to disable tick output.| @@ -282,7 +283,26 @@ nowtech::log::TopicInstance someOtherTopic; } ``` -To enable some of them, the interesting ones must be registered in the log system. Although log levels are not supported natively, here is a workaround to define them. +To enable some of them, the interesting ones must be registered in the log system. When the log system receives `LogTopic` parameter, it will be logged regardless of the actual applicaiton log level. + +There are three possibilities to use log levels. + +#### Native log levels + +The `Log` class takes an optional template argument, the application log level. The `Log::n(...)` and `Log::i(...)` functions' overloads without operands and taking a `TaskId` (see below) are templated methods with a default value of `ErrorLevel::All`. By providing template values these for methods, the given instantiation chooses between a functional and an empty return value. As the empty one will be fully optimized out for unused log levels, this is more performant than the next one. The log system has these predefined log levels in `Log`: + +```C++ +static constexpr ErrorLevel fatal = ErrorLevel::Fatal; +static constexpr ErrorLevel error = ErrorLevel::Error; +static constexpr ErrorLevel warn = ErrorLevel::Warning; +static constexpr ErrorLevel info = ErrorLevel::Info; +static constexpr ErrorLevel debug = ErrorLevel::Debug; +static constexpr ErrorLevel all = ErrorLevel::All; +``` + +#### Emulated log levels + +For topic declarations, please refer above. This method suits better architectures with limited flash space, since it requires no internal method instantiation for each log level used. However, checking topics is a runtime process and total elimination of unused log statements won't happen for optimizing compilation. ```C++ #ifdef LEVEL1 @@ -297,6 +317,10 @@ Log::registerTopic(nowtech::LogTopics::level3, "level3"); #endif ``` +#### Variadic macros + +C++20 has suitable variadic macros in the preprocessor, which would enable one to use the folding expression API to define preprocessor-implemented loglevels. I didn't implement it. This would mean a perfect solution from performance and space point of view. + ### Logging All the logging API is implemented as static functions in the `Log` template class. Logging happens using a `std::ostream` -like API, like in the example in the beginning. There are two overloaded functions to start the chain: diff --git a/src/Log.h b/src/Log.h index cdc79f7..cd43c82 100644 --- a/src/Log.h +++ b/src/Log.h @@ -26,11 +26,21 @@ enum class TaskRepresentation : uint8_t { using LogTopic = int8_t; // this needs to be signed to let the overload resolution work -template +enum class ErrorLevel : uint8_t { + Off = 0u, + Fatal = 1u, + Error = 2u, + Warning = 3u, + Info = 4u, + Debug = 5u, + All = 6u +}; + +template class Log; class TopicInstance final { - template + template friend class Log; public: @@ -109,7 +119,7 @@ enum class LogShiftChainEndMarker : uint8_t { cEnd = 0u }; -template +template class Log final { private: static constexpr bool csShutdownLog = tSender::csVoid; @@ -366,13 +376,21 @@ class Log final { } }; // class LogShiftChainHelperEmpty - using LogShiftChainHelper = std::conditional_t>; + using LogShiftChainHelperRaw = std::conditional_t; + using LogShiftChainHelper = std::conditional_t; + template + using LogShiftChainHelperErrorLevel = std::conditional_t<(csShutdownLog || tErrorLevel < tRequestedErrorLevel), LogShiftChainHelperEmpty, LogShiftChainHelperRaw>; public: /// Will be used as Log << something << to << log << Log::end; - static constexpr LogShiftChainEndMarker end = LogShiftChainEndMarker::cEnd; + static constexpr LogShiftChainEndMarker end = LogShiftChainEndMarker::cEnd; + static constexpr ErrorLevel fatal = ErrorLevel::Fatal; + static constexpr ErrorLevel error = ErrorLevel::Error; + static constexpr ErrorLevel warn = ErrorLevel::Warning; + static constexpr ErrorLevel info = ErrorLevel::Info; + static constexpr ErrorLevel debug = ErrorLevel::Debug; + static constexpr ErrorLevel all = ErrorLevel::All; - // TODO remark in docs: must come before registering topics template static void init(LogConfig const &aConfig, tTypes... aArgs) { if constexpr(!csShutdownLog) { @@ -510,22 +528,24 @@ class Log final { } } - static LogShiftChainHelper i() noexcept { - if constexpr(!csShutdownLog) { + template + static LogShiftChainHelperErrorLevel i() noexcept { + if constexpr(!csShutdownLog && tErrorLevel >= tRequestedErrorLevel) { TaskId const taskId = tAppInterface::getCurrentTaskId(); - return sendHeader(taskId); + return sendHeader>(taskId); } else { - return LogShiftChainHelper{csInvalidTaskId}; + return LogShiftChainHelperErrorLevel{csInvalidTaskId}; } } - static LogShiftChainHelper i(TaskId const aTaskId) noexcept { - if constexpr(!csShutdownLog) { - return sendHeader(aTaskId); + template + static LogShiftChainHelperErrorLevel i(TaskId const aTaskId) noexcept { + if constexpr(!csShutdownLog && tErrorLevel >= tRequestedErrorLevel) { + return sendHeader>(aTaskId); } else { - return LogShiftChainHelper{csInvalidTaskId}; + return LogShiftChainHelperErrorLevel{csInvalidTaskId}; } } @@ -533,10 +553,10 @@ class Log final { if constexpr(!csShutdownLog) { if(sRegisteredTopics[aTopic] != nullptr) { TaskId const taskId = tAppInterface::getCurrentTaskId(); - return sendHeader(taskId, sRegisteredTopics[aTopic]); + return sendHeader(taskId, sRegisteredTopics[aTopic]); } else { - return sendHeader(csInvalidTaskId); + return sendHeader(csInvalidTaskId); } } else { @@ -547,10 +567,10 @@ class Log final { static LogShiftChainHelper i(LogTopic const aTopic, TaskId const aTaskId) noexcept { if constexpr(!csShutdownLog) { if(sRegisteredTopics[aTopic] != nullptr) { - return sendHeader(aTaskId, sRegisteredTopics[aTopic]); + return sendHeader(aTaskId, sRegisteredTopics[aTopic]); } else { - return sendHeader(csInvalidTaskId); + return sendHeader(csInvalidTaskId); } } else { @@ -558,21 +578,23 @@ class Log final { } } - static LogShiftChainHelper n() noexcept { - if constexpr(!csShutdownLog) { - return LogShiftChainHelper{tAppInterface::getCurrentTaskId()}; + template + static LogShiftChainHelperErrorLevel n() noexcept { + if constexpr(!csShutdownLog && tErrorLevel >= tRequestedErrorLevel) { + return LogShiftChainHelperErrorLevel{tAppInterface::getCurrentTaskId()}; } else { - return LogShiftChainHelper{csInvalidTaskId}; + return LogShiftChainHelperErrorLevel{csInvalidTaskId}; } } - static LogShiftChainHelper n(TaskId const aTaskId) noexcept { - if constexpr(!csShutdownLog) { - return LogShiftChainHelper{aTaskId}; + template + static LogShiftChainHelperErrorLevel n(TaskId const aTaskId) noexcept { + if constexpr(!csShutdownLog && tErrorLevel >= tRequestedErrorLevel) { + return LogShiftChainHelperErrorLevel{aTaskId}; } else { - return LogShiftChainHelper{csInvalidTaskId}; + return LogShiftChainHelperErrorLevel{csInvalidTaskId}; } } @@ -610,8 +632,9 @@ class Log final { } private: - static LogShiftChainHelper sendHeader(TaskId const aTaskId) noexcept { - LogShiftChainHelper result{aTaskId}; + template + static tLogShiftChainHelper sendHeader(TaskId const aTaskId) noexcept { + tLogShiftChainHelper result{aTaskId}; if(result.isValid()) { if constexpr(tTaskRepresentation == TaskRepresentation::cId) { result << sConfig->taskIdFormat << aTaskId; @@ -637,8 +660,9 @@ class Log final { return result; } - static LogShiftChainHelper sendHeader(TaskId const aTaskId, char const * aTopicName) noexcept { - LogShiftChainHelper result = sendHeader(aTaskId); + template + static tLogShiftChainHelper sendHeader(TaskId const aTaskId, char const * aTopicName) noexcept { + tLogShiftChainHelper result = sendHeader(aTaskId); if(result.isValid() && aTopicName != nullptr) { result << aTopicName; } diff --git a/test/test-stdthreadostream.cpp b/test/test-stdthreadostream.cpp index 99527f0..a242c46 100644 --- a/test/test-stdthreadostream.cpp +++ b/test/test-stdthreadostream.cpp @@ -69,6 +69,7 @@ constexpr size_t cgQueueSize = 444u; constexpr nowtech::log::LogTopic cgMaxTopicCount = 2; constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cName; constexpr size_t cgDirectBufferSize = 0u; +constexpr nowtech::log::ErrorLevel cgErrorLevel = nowtech::log::ErrorLevel::Error; using LogAppInterfaceStd = nowtech::log::AppInterfaceStd; constexpr typename LogAppInterfaceStd::LogTime cgTimeout = 123u; @@ -77,7 +78,7 @@ using LogMessage = nowtech::log::MessageCompact; using LogSenderStdOstream = nowtech::log::SenderStdOstream; using LogQueueStdBoost = nowtech::log::QueueStdBoost; -using Log = nowtech::log::Log; +using Log = nowtech::log::Log; void delayedLog(size_t n) { Log::registerCurrentTask(cgThreadNames[n]); @@ -148,6 +149,17 @@ int main() { Log::i() << "bool:" << true << Log::end; Log::i() << "bool:" << false << Log::end; + Log::i() << "fatal" << Log::end; + Log::i() << "error" << Log::end; + Log::i() << "warning" << Log::end; + Log::i() << "info" << Log::end; + Log::i() << "debug" << Log::end; + Log::n() << "fatal" << Log::end; + Log::n() << "error" << Log::end; + Log::n() << "warning" << Log::end; + Log::n() << "info" << Log::end; + Log::n() << "debug" << Log::end; + for(size_t i = 0; i < cgThreadCount; ++i) { threads[i] = std::thread(delayedLog, i); } From 3f28181e5fab15a2e8716f3889a14d8a9748cd0f Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Tue, 22 Dec 2020 17:17:51 +0100 Subject: [PATCH 02/27] More docs. --- README.md | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/README.md b/README.md index f7c74ea..607ec4a 100644 --- a/README.md +++ b/README.md @@ -300,6 +300,12 @@ static constexpr ErrorLevel debug = ErrorLevel::Debug; static constexpr ErrorLevel all = ErrorLevel::All; ``` +So logging happens like + +```C++ +Log::i() << "x:" << LC::D4 << posX << "y:" << LC::D4 << posY; +``` + #### Emulated log levels For topic declarations, please refer above. This method suits better architectures with limited flash space, since it requires no internal method instantiation for each log level used. However, checking topics is a runtime process and total elimination of unused log statements won't happen for optimizing compilation. From 0955d5d7fd7dde1317553f74e49bae682a061019 Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Tue, 22 Dec 2020 17:20:24 +0100 Subject: [PATCH 03/27] More docs. --- README.md | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/README.md b/README.md index 607ec4a..39a8c49 100644 --- a/README.md +++ b/README.md @@ -12,7 +12,7 @@ Log::registerCurrentTask("main"); Log::i(nowtech::LogTopics::system) << "bulk data size:" << someCollection.size() << Log::end; // one group of 2 items -auto logger = Log::n() << "bulk data follows:"; // one group of many items starts +auto logger = Log::n() << "bulk data follows:"; // one group of many items starts for(auto item : someCollection) { logger << LC::X4 << item; // format: hexadecimal, fill to 4 digits } @@ -303,7 +303,7 @@ static constexpr ErrorLevel all = ErrorLevel::All; So logging happens like ```C++ -Log::i() << "x:" << LC::D4 << posX << "y:" << LC::D4 << posY; +Log::i() << "x:" << LC::D4 << posX << "y:" << LC::D4 << posY; ``` #### Emulated log levels From 2ddb05fb450c3386a528382ad94c3ddec9041a43 Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Tue, 22 Dec 2020 17:58:04 +0100 Subject: [PATCH 04/27] Bugfix in decs. --- README.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/README.md b/README.md index 39a8c49..05fa8b8 100644 --- a/README.md +++ b/README.md @@ -303,7 +303,7 @@ static constexpr ErrorLevel all = ErrorLevel::All; So logging happens like ```C++ -Log::i() << "x:" << LC::D4 << posX << "y:" << LC::D4 << posY; +Log::i() << "x:" << LC::D4 << posX << "y:" << LC::D4 << posY << Log::end; ``` #### Emulated log levels From 5ead4cd596526b4256a6f9548e44ffd2348cb82d Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Thu, 24 Dec 2020 19:53:13 +0100 Subject: [PATCH 05/27] Added benchmarks using picobench. --- benchmark/picobench-direct.cpp | 65 ++++++++++++++++++++++++++ benchmark/picobench-msg-compact.cpp | 72 +++++++++++++++++++++++++++++ benchmark/picobench-msg-variant.cpp | 72 +++++++++++++++++++++++++++++ 3 files changed, 209 insertions(+) create mode 100644 benchmark/picobench-direct.cpp create mode 100644 benchmark/picobench-msg-compact.cpp create mode 100644 benchmark/picobench-msg-variant.cpp diff --git a/benchmark/picobench-direct.cpp b/benchmark/picobench-direct.cpp new file mode 100644 index 0000000..2c8799c --- /dev/null +++ b/benchmark/picobench-direct.cpp @@ -0,0 +1,65 @@ +#define PICOBENCH_IMPLEMENT +#define PICOBENCH_DEFAULT_SAMPLES 10 +#include "picobench/picobench.hpp" + +//#include "lwlog/lwlog.h" + +#include "LogAppInterfaceStd.h" +#include "LogConverterCustomText.h" +#include "LogSenderStdOstream.h" +#include "LogSenderVoid.h" +#include "LogQueueStdBoost.h" +#include "LogQueueVoid.h" +#include "LogMessageCompact.h" +#include "LogMessageVariant.h" +#include "Log.h" +#include + + +constexpr nowtech::log::TaskId cgMaxTaskCount = 1; +constexpr bool cgLogFromIsr = false; +constexpr size_t cgTaskShutdownSleepPeriod = 100u; +constexpr bool cgArchitecture64 = true; +constexpr uint8_t cgAppendStackBufferSize = 100u; +constexpr bool cgAppendBasePrefix = true; +constexpr bool cgAlignSigned = false; +constexpr size_t cgTransmitBufferSize = 123u; +constexpr size_t cgPayloadSize = 8u; +constexpr bool cgSupportFloatingPoint = true; +constexpr size_t cgQueueSize = 444u; +constexpr nowtech::log::LogTopic cgMaxTopicCount = 2; +constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cName; +constexpr nowtech::log::ErrorLevel cgRequiredLevel = nowtech::log::ErrorLevel::Info; + +constexpr size_t cgDirectBufferSize = 1024u; +using LogAppInterfaceStd = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterfaceStd::LogTime cgTimeout = 123u; +constexpr typename LogAppInterfaceStd::LogTime cgRefreshPeriod = 444; +using LogMessage = nowtech::log::MessageVariant; +using LogConverterCustomText = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStdOstream; +using LogQueue = nowtech::log::QueueVoid; +using Log = nowtech::log::Log; + +void nowtechLogRef(picobench::state& s) { + for (auto _ : s) { + Log::i() << "Info message" << Log::end; + } +} +PICOBENCH(nowtechLogRef); + +int main(int argc, char* argv[]) +{ + nowtech::log::LogConfig logConfig; + logConfig.allowRegistrationLog = false; + std::ofstream out("tmp"); + LogSender::init(&out); + Log::init(logConfig); + Log::registerCurrentTask("main"); + + picobench::runner r; + r.parse_cmd_line(argc, argv); + return r.run(); + Log::unregisterCurrentTask(); + Log::done(); +} diff --git a/benchmark/picobench-msg-compact.cpp b/benchmark/picobench-msg-compact.cpp new file mode 100644 index 0000000..51964af --- /dev/null +++ b/benchmark/picobench-msg-compact.cpp @@ -0,0 +1,72 @@ +#define PICOBENCH_IMPLEMENT +#define PICOBENCH_DEFAULT_SAMPLES 10 +#include "picobench/picobench.hpp" + +#include "LogAppInterfaceStd.h" +#include "LogConverterCustomText.h" +#include "LogSenderStdOstream.h" +#include "LogSenderVoid.h" +#include "LogQueueStdBoost.h" +#include "LogQueueVoid.h" +#include "LogMessageCompact.h" +#include "LogMessageVariant.h" +#include "Log.h" +#include +#include + + +constexpr nowtech::log::TaskId cgMaxTaskCount = 1; +constexpr bool cgLogFromIsr = false; +constexpr size_t cgTaskShutdownSleepPeriod = 100u; +constexpr bool cgArchitecture64 = true; +constexpr uint8_t cgAppendStackBufferSize = 100u; +constexpr bool cgAppendBasePrefix = true; +constexpr bool cgAlignSigned = false; +constexpr size_t cgTransmitBufferSize = 444444u; +constexpr size_t cgPayloadSize = 8u; +constexpr bool cgSupportFloatingPoint = true; +constexpr size_t cgQueueSize = 444444u; +constexpr nowtech::log::LogTopic cgMaxTopicCount = 2; +constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cName; +constexpr nowtech::log::ErrorLevel cgRequiredLevel = nowtech::log::ErrorLevel::Info; + +constexpr size_t cgDirectBufferSize = 0u; +using LogAppInterfaceStd = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterfaceStd::LogTime cgTimeout = 123u; +constexpr typename LogAppInterfaceStd::LogTime cgRefreshPeriod = 444; +using LogMessage = nowtech::log::MessageCompact; +using LogConverterCustomText = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStdOstream; +using LogQueue = nowtech::log::QueueStdBoost; +using Log = nowtech::log::Log; + +void nowtechLogRef(picobench::state& s) { + for (auto _ : s) { + Log::i() << "Info message" << Log::end; + } +} +PICOBENCH(nowtechLogRef); + +void nowtechLogCopy(picobench::state& s) { + for (auto _ : s) { + Log::i() << LC::St << "Info message" << Log::end; + } +} +PICOBENCH(nowtechLogCopy); + +int main(int argc, char* argv[]) +{ + nowtech::log::LogConfig logConfig; + logConfig.allowRegistrationLog = false; + std::ofstream out("tmp"); + LogSender::init(&out); + Log::init(logConfig); + Log::registerCurrentTask("main"); + + picobench::runner r; + r.parse_cmd_line(argc, argv); + auto ret = r.run(); + Log::unregisterCurrentTask(); + Log::done(); + return ret; +} diff --git a/benchmark/picobench-msg-variant.cpp b/benchmark/picobench-msg-variant.cpp new file mode 100644 index 0000000..7cfdc0f --- /dev/null +++ b/benchmark/picobench-msg-variant.cpp @@ -0,0 +1,72 @@ +#define PICOBENCH_IMPLEMENT +#define PICOBENCH_DEFAULT_SAMPLES 10 +#include "picobench/picobench.hpp" + +#include "LogAppInterfaceStd.h" +#include "LogConverterCustomText.h" +#include "LogSenderStdOstream.h" +#include "LogSenderVoid.h" +#include "LogQueueStdBoost.h" +#include "LogQueueVoid.h" +#include "LogMessageCompact.h" +#include "LogMessageVariant.h" +#include "Log.h" +#include +#include + + +constexpr nowtech::log::TaskId cgMaxTaskCount = 1; +constexpr bool cgLogFromIsr = false; +constexpr size_t cgTaskShutdownSleepPeriod = 100u; +constexpr bool cgArchitecture64 = true; +constexpr uint8_t cgAppendStackBufferSize = 100u; +constexpr bool cgAppendBasePrefix = true; +constexpr bool cgAlignSigned = false; +constexpr size_t cgTransmitBufferSize = 444444u; +constexpr size_t cgPayloadSize = 8u; +constexpr bool cgSupportFloatingPoint = true; +constexpr size_t cgQueueSize = 444444u; +constexpr nowtech::log::LogTopic cgMaxTopicCount = 2; +constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cName; +constexpr nowtech::log::ErrorLevel cgRequiredLevel = nowtech::log::ErrorLevel::Info; + +constexpr size_t cgDirectBufferSize = 0u; +using LogAppInterfaceStd = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterfaceStd::LogTime cgTimeout = 123u; +constexpr typename LogAppInterfaceStd::LogTime cgRefreshPeriod = 444; +using LogMessage = nowtech::log::MessageVariant; +using LogConverterCustomText = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStdOstream; +using LogQueue = nowtech::log::QueueStdBoost; +using Log = nowtech::log::Log; + +void nowtechLogRef(picobench::state& s) { + for (auto _ : s) { + Log::i() << "Info message" << Log::end; + } +} +PICOBENCH(nowtechLogRef); + +void nowtechLogCopy(picobench::state& s) { + for (auto _ : s) { + Log::i() << LC::St << "Info message" << Log::end; + } +} +PICOBENCH(nowtechLogCopy); + +int main(int argc, char* argv[]) +{ + nowtech::log::LogConfig logConfig; + logConfig.allowRegistrationLog = false; + std::ofstream out("tmp"); + LogSender::init(&out); + Log::init(logConfig); + Log::registerCurrentTask("main"); + + picobench::runner r; + r.parse_cmd_line(argc, argv); + auto ret = r.run(); + Log::unregisterCurrentTask(); + Log::done(); + return ret; +} From e08f9ad21486849171877c6aae42f4359aacd007 Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Thu, 24 Dec 2020 20:16:46 +0100 Subject: [PATCH 06/27] Bugfix. Added benchmark docs. --- README.md | 19 +++++++++++++++++++ benchmark/picobench-direct.cpp | 3 ++- 2 files changed, 21 insertions(+), 1 deletion(-) diff --git a/README.md b/README.md index 05fa8b8..d20132a 100644 --- a/README.md +++ b/README.md @@ -17,6 +17,11 @@ for(auto item : someCollection) { logger << LC::X4 << item; // format: hexadecimal, fill to 4 digits } logger << Log::end; // the group of many items ends + +//... + +Log::unregisterCurrentTask(); +Log::done(); ``` This is a complete rework of my [old logger](https://github.com/balazs-bamer/cpp-logger/tree/old/) after identifying the design flaws and performance problems. The library requires C++17. @@ -125,6 +130,20 @@ This is a minimal implementation for STM32 UART using blocking HAL transmission. It is a simple std::ostream wrapper. +## Benchmarks + +I used [picobench](https://github.com/iboB/picobench) for benchmarks using the supplied bechmark apps. Here are some averaged results for 8192 iterations on my _Intel(R) Xeon(R) CPU E31220L @ 2.20GHz_. Compiled using `clang++ -O2`. There were no significant differences for `MessageVariant` or `MessageCompact`. Log activity was +- print header + - print task name + - print timestamp +- print the logged string + +|Scenario |Average ns / log call| +|-------------------------|--------------------:| +|direct |250| +|Constant string (no copy)|450| +|Transient string (copy) |580| + ## Space requirements I have investigated several scenarios using simple applications which contain practically nothing but a task creation apart of the logging. This way I could measure the net space required by the log library and its necessary supplementary functions like std::unordered_set or floating-point emulation for log10. diff --git a/benchmark/picobench-direct.cpp b/benchmark/picobench-direct.cpp index 2c8799c..fa118e1 100644 --- a/benchmark/picobench-direct.cpp +++ b/benchmark/picobench-direct.cpp @@ -59,7 +59,8 @@ int main(int argc, char* argv[]) picobench::runner r; r.parse_cmd_line(argc, argv); - return r.run(); + auto ret = r.run(); Log::unregisterCurrentTask(); Log::done(); + return ret; } From d60d7bac6aeaba38dfea993142e495c69f2ff484 Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Sat, 26 Dec 2020 11:59:04 +0100 Subject: [PATCH 07/27] More benchmarks. --- .gitignore | 1 + README.md | 14 ++++++++------ benchmark/picobench-direct.cpp | 5 ++++- benchmark/picobench-msg-compact.cpp | 7 +++++-- benchmark/picobench-msg-variant.cpp | 7 +++++-- 5 files changed, 23 insertions(+), 11 deletions(-) diff --git a/.gitignore b/.gitignore index 0c68bbd..d84f33d 100644 --- a/.gitignore +++ b/.gitignore @@ -31,6 +31,7 @@ test-stdthreadostream *.exe *.out *.app +picobench test-stdthreadostream test-stdostream test-sizes diff --git a/README.md b/README.md index d20132a..2a4f56c 100644 --- a/README.md +++ b/README.md @@ -132,17 +132,19 @@ It is a simple std::ostream wrapper. ## Benchmarks -I used [picobench](https://github.com/iboB/picobench) for benchmarks using the supplied bechmark apps. Here are some averaged results for 8192 iterations on my _Intel(R) Xeon(R) CPU E31220L @ 2.20GHz_. Compiled using `clang++ -O2`. There were no significant differences for `MessageVariant` or `MessageCompact`. Log activity was +I used [picobench](https://github.com/iboB/picobench) for benchmarks using the supplied bechmark apps. Here are some averaged results measured on 8192 iterations on my _Intel(R) Xeon(R) CPU E31220L @ 2.20GHz_. Compiled using `clang++ -O2`. There were no significant differences for `MessageVariant` or `MessageCompact`. Log activity was - print header - print task name - print timestamp - print the logged string -|Scenario |Average ns / log call| -|-------------------------|--------------------:| -|direct |250| -|Constant string (no copy)|450| -|Transient string (copy) |580| +Each value is the average time required for _one_ log call in nanoseconds. + +|Scenario |Unknown `TaskId` (ns)|Provided `TaskId` (ns)| +|-------------------------|--------------------:|---------------------:| +|direct |250 |160 | +|Constant string (no copy)|450 |430 | +|Transient string (copy) |580 |500 | ## Space requirements diff --git a/benchmark/picobench-direct.cpp b/benchmark/picobench-direct.cpp index fa118e1..58c37c2 100644 --- a/benchmark/picobench-direct.cpp +++ b/benchmark/picobench-direct.cpp @@ -41,9 +41,11 @@ using LogSender = nowtech::log::SenderStdOstream; using Log = nowtech::log::Log; +nowtech::log::TaskId gTaskId; + void nowtechLogRef(picobench::state& s) { for (auto _ : s) { - Log::i() << "Info message" << Log::end; + Log::i(gTaskId) << "Info message" << Log::end; } } PICOBENCH(nowtechLogRef); @@ -56,6 +58,7 @@ int main(int argc, char* argv[]) LogSender::init(&out); Log::init(logConfig); Log::registerCurrentTask("main"); + gTaskId = Log::getCurrentTaskId(); picobench::runner r; r.parse_cmd_line(argc, argv); diff --git a/benchmark/picobench-msg-compact.cpp b/benchmark/picobench-msg-compact.cpp index 51964af..2b6102f 100644 --- a/benchmark/picobench-msg-compact.cpp +++ b/benchmark/picobench-msg-compact.cpp @@ -40,16 +40,18 @@ using LogSender = nowtech::log::SenderStdOstream; using Log = nowtech::log::Log; +nowtech::log::TaskId gTaskId; + void nowtechLogRef(picobench::state& s) { for (auto _ : s) { - Log::i() << "Info message" << Log::end; + Log::i(gTaskId) << "Info message" << Log::end; } } PICOBENCH(nowtechLogRef); void nowtechLogCopy(picobench::state& s) { for (auto _ : s) { - Log::i() << LC::St << "Info message" << Log::end; + Log::i(gTaskId) << LC::St << "Info message" << Log::end; } } PICOBENCH(nowtechLogCopy); @@ -62,6 +64,7 @@ int main(int argc, char* argv[]) LogSender::init(&out); Log::init(logConfig); Log::registerCurrentTask("main"); + gTaskId = Log::getCurrentTaskId(); picobench::runner r; r.parse_cmd_line(argc, argv); diff --git a/benchmark/picobench-msg-variant.cpp b/benchmark/picobench-msg-variant.cpp index 7cfdc0f..f497058 100644 --- a/benchmark/picobench-msg-variant.cpp +++ b/benchmark/picobench-msg-variant.cpp @@ -40,16 +40,18 @@ using LogSender = nowtech::log::SenderStdOstream; using Log = nowtech::log::Log; +nowtech::log::TaskId gTaskId; + void nowtechLogRef(picobench::state& s) { for (auto _ : s) { - Log::i() << "Info message" << Log::end; + Log::i(gTaskId) << "Info message" << Log::end; } } PICOBENCH(nowtechLogRef); void nowtechLogCopy(picobench::state& s) { for (auto _ : s) { - Log::i() << LC::St << "Info message" << Log::end; + Log::i(gTaskId) << LC::St << "Info message" << Log::end; } } PICOBENCH(nowtechLogCopy); @@ -62,6 +64,7 @@ int main(int argc, char* argv[]) LogSender::init(&out); Log::init(logConfig); Log::registerCurrentTask("main"); + gTaskId = Log::getCurrentTaskId(); picobench::runner r; r.parse_cmd_line(argc, argv); From 8a0ecd0d38f2e7b6e6d602bcb8d28464457bb0f7 Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Sat, 26 Dec 2020 12:07:41 +0100 Subject: [PATCH 08/27] New measurement. --- README.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/README.md b/README.md index 2a4f56c..49d1926 100644 --- a/README.md +++ b/README.md @@ -143,7 +143,7 @@ Each value is the average time required for _one_ log call in nanoseconds. |Scenario |Unknown `TaskId` (ns)|Provided `TaskId` (ns)| |-------------------------|--------------------:|---------------------:| |direct |250 |160 | -|Constant string (no copy)|450 |430 | +|Constant string (no copy)|500 |430 | |Transient string (copy) |580 |500 | ## Space requirements From 7437389da3445c21554148e82f6e0e11a9e4c050 Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Tue, 29 Dec 2020 20:23:26 +0100 Subject: [PATCH 09/27] Added atomic buffer. Refactor for better template API. Bugfixes. Needs more bugfixes. --- .vscode/launch.json | 2 +- .vscode/tasks.json | 1 + CMakeLists.txt | 5 +- src/Log.h | 189 +++++++++++++++++++++++---------- src/LogAppInterfaceStd.h | 22 +++- src/LogAtomicBuffers.h | 96 +++++++++++++++++ src/LogConverterCustomText.h | 6 +- src/LogQueueStdBoost.h | 13 ++- test/test-stdthreadostream.cpp | 47 ++++++-- 9 files changed, 301 insertions(+), 80 deletions(-) create mode 100644 src/LogAtomicBuffers.h diff --git a/.vscode/launch.json b/.vscode/launch.json index 452b759..e058277 100644 --- a/.vscode/launch.json +++ b/.vscode/launch.json @@ -8,7 +8,7 @@ "name": "(gdb) Launch", "type": "cppdbg", "request": "launch", - "program": "${workspaceFolder}/test-stdostream", + "program": "${workspaceFolder}/test-stdthreadostream", "args": [], "stopAtEntry": false, "cwd": "${workspaceFolder}", diff --git a/.vscode/tasks.json b/.vscode/tasks.json index d930591..91679f7 100644 --- a/.vscode/tasks.json +++ b/.vscode/tasks.json @@ -7,6 +7,7 @@ "command": "/usr/bin/clang++", "args": [ "-ggdb", + "-Og", "test/test-stdthreadostream.cpp", "-Wall", "-Wpedantic", diff --git a/CMakeLists.txt b/CMakeLists.txt index 4a974c4..bb77b94 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -6,12 +6,13 @@ set(CMAKE_CXX_STANDARD 17) include_directories(cpp-memory-manager) include_directories(src) -add_compile_options(-Os -Wall -Wextra -Wpedantic) +add_compile_options(-Og -ggdb -Wall -Wextra -Wpedantic) add_link_options(-lpthread) add_executable(cpp_logger cpp-memory-manager/PoolAllocator.h src/Log.h + src/LogAtomicBuffers.h src/LogAppInterfaceStd.h src/LogConverterCustomText.h src/LogMessageBase.h @@ -22,4 +23,4 @@ add_executable(cpp_logger src/LogQueueVoid.h src/LogSenderStdOstream.h src/LogSenderVoid.h - test/test-sizes-stdthreadostream.cpp) + test/test-stdthreadostream.cpp) diff --git a/src/Log.h b/src/Log.h index cd43c82..88f226a 100644 --- a/src/Log.h +++ b/src/Log.h @@ -2,6 +2,7 @@ #define NOWTECH_LOG #include "LogMessageBase.h" +#include "LogAtomicBuffers.h" #include "PoolAllocator.h" #include #include @@ -36,11 +37,11 @@ enum class ErrorLevel : uint8_t { All = 6u }; -template +template class Log; class TopicInstance final { - template + template friend class Log; public: @@ -55,16 +56,27 @@ class TopicInstance final { } public: - LogTopic operator*() { + LogTopic operator*() const { return mValue; } - operator LogTopic() { + operator LogTopic() const { return mValue; } }; -struct LogConfig final { +template +struct Config final { +public: + static constexpr bool csAllowRegistrationLog = tAllowRegistrationLog; + static constexpr LogTopic csMaxTopicCount = tMaxTopicCount; + static constexpr TaskRepresentation csTaskRepresentation = tTaskRepresentation; + static constexpr size_t csDirectBufferSize = tDirectBufferSize; + static constexpr int32_t csRefreshPeriod = tRefreshPeriod; // Can represent 1s even if the unit is ns. + static constexpr ErrorLevel csErrorLevel = tErrorLevel; +}; + +struct LogFormatConfig final { public: /// This is the default logging format and the only one I will document /// here. For the others, the letter represents the base of the number @@ -99,10 +111,6 @@ struct LogConfig final { // Indicates the next char* value should be stored in messages instead of taking only its address inline static constexpr LogFormat St {13u, LogFormat::csFillValueStoreString }; - /// If true, task registration will be sent to the output in the form - /// in the form -=- Registered task: taskname (1) -=- - bool allowRegistrationLog = true; - /// Format for displaying the task ID in the message header. LogFormat taskIdFormat = X2; @@ -110,8 +118,9 @@ struct LogConfig final { /// cInvalid to disable tick output. LogFormat tickFormat = D5; LogFormat defaultFormat = Fm; + LogFormat atomicFormat = Fm; - LogConfig() noexcept = default; + LogFormatConfig() noexcept = default; }; /// Dummy type to use in << chain as end marker. @@ -119,28 +128,41 @@ enum class LogShiftChainEndMarker : uint8_t { cEnd = 0u }; -template +template class Log final { private: - static constexpr bool csShutdownLog = tSender::csVoid; - static constexpr bool csSendInBackground = (tDirectBufferSize == 0u); // will omit tQueue using tMessage = typename tQueue::tMessage_; using tAppInterface = typename tSender::tAppInterface_; using tConverter = typename tSender::tConverter_; using ConversionResult = typename tConverter::ConversionResult; using LogTime = typename tAppInterface::LogTime; using TopicName = char const *; - - static constexpr size_t csPayloadSizeBr = tMessage::csPayloadSize; - static constexpr size_t csPayloadSizeNet = tMessage::csPayloadSize - 1u; // we leave space for terminal 0 to avoid counting bytes - static constexpr size_t csQueueSize = tQueue::csQueueSize; - static constexpr TaskId csInvalidTaskId = tAppInterface::csInvalidTaskId; - static constexpr TaskId csIsrTaskId = tAppInterface::csIsrTaskId; - static constexpr TaskId csMaxTaskCount = tAppInterface::csMaxTaskCount; - static constexpr TaskId csMaxTotalTaskCount = tAppInterface::csMaxTaskCount + 1u; - static constexpr size_t csListItemOverhead = sizeof(void*) * 8u; - static constexpr bool csConstantTaskNames = tAppInterface::csConstantTaskNames; - + using tAtomicBufferType = typename tAtomicBuffer::tAtomicBufferType_; + + static constexpr size_t csDirectBufferSize = tLogConfig::csDirectBufferSize; + static constexpr bool csShutdownLog = tSender::csVoid; + static constexpr bool csSendInBackground = (csDirectBufferSize == 0u); // will omit tQueue + static constexpr size_t csAtomicBufferSizeExponent = tAtomicBuffer::csAtomicBufferSizeExponent; + static constexpr size_t csAtomicBufferSize = tAtomicBuffer::csAtomicBufferSize; + static constexpr bool csAtomicBufferOperational = tAtomicBuffer::csAtomicBufferSizeExponent > 0u; + static constexpr tAtomicBufferType csAtomicBufferInvalidValue = tAtomicBuffer::csInvalidValue; + static constexpr size_t csMaxAtomicBufferSizeExp = std::max(32u, sizeof(void*) * 8u - 1u); + static constexpr size_t csPayloadSizeBr = tMessage::csPayloadSize; + static constexpr size_t csPayloadSizeNet = tMessage::csPayloadSize - 1u; // we leave space for terminal 0 to avoid counting bytes + static constexpr int32_t csRefreshPeriod = tLogConfig::csRefreshPeriod; + static constexpr size_t csQueueSize = tQueue::csQueueSize; + static constexpr TaskId csInvalidTaskId = tAppInterface::csInvalidTaskId; + static constexpr TaskId csIsrTaskId = tAppInterface::csIsrTaskId; + static constexpr TaskId csMaxTaskCount = tAppInterface::csMaxTaskCount; + static constexpr TaskId csMaxTotalTaskCount = tAppInterface::csMaxTaskCount + 1u; + static constexpr size_t csListItemOverhead = sizeof(void*) * 8u; + static constexpr bool csConstantTaskNames = tAppInterface::csConstantTaskNames; + static constexpr bool csAllowRegistrationLog = tLogConfig::csAllowRegistrationLog; + + static constexpr ErrorLevel csErrorLevel = tLogConfig::csErrorLevel; + static constexpr TaskRepresentation csTaskRepresentation = tLogConfig::csTaskRepresentation; + + static constexpr LogTopic csMaxTopicCount = tLogConfig::csMaxTopicCount; static constexpr LogTopic csFirstFreeTopic = 0; static constexpr MessageSequence csSequence0 = 0u; static constexpr MessageSequence csSequence1 = 1u; @@ -159,14 +181,16 @@ class Log final { static_assert(csMaxTaskCount < std::numeric_limits::max()); static_assert(std::is_same_v); static_assert(std::is_same_v); + static_assert(std::is_integral_v); + static_assert(csAtomicBufferSizeExponent <= csMaxAtomicBufferSizeExp); inline static constexpr char csRegisteredTask[] = "-=- Registered task:"; inline static constexpr char csUnregisteredTask[] = "-=- Unregistered task:"; - inline static LogConfig const *sConfig; + inline static LogFormatConfig const *sConfig; inline static std::atomic sNextFreeTopic; inline static std::atomic sKeepAliveTask; - inline static std::array sRegisteredTopics; + inline static std::array sRegisteredTopics; inline static TaskShutdownArray *sTaskShutdowns; inline static Occupier sOccupier; @@ -319,8 +343,8 @@ class Log final { else { format = sConfig->defaultFormat; } - ConversionResult buffer[tDirectBufferSize]; - tConverter converter(buffer, buffer + tDirectBufferSize); + ConversionResult buffer[csDirectBufferSize]; + tConverter converter(buffer, buffer + csDirectBufferSize); converter.convert(aValue, format.mBase, format.mFill); tAppInterface::lock(); tSender::send(buffer, converter.end()); @@ -338,8 +362,8 @@ class Log final { void operator<<(LogShiftChainEndMarker const) noexcept { if(mTaskId != csInvalidTaskId) { - ConversionResult buffer[tDirectBufferSize]; - tConverter converter(buffer, buffer + tDirectBufferSize); + ConversionResult buffer[csDirectBufferSize]; + tConverter converter(buffer, buffer + csDirectBufferSize); converter.terminateSequence(); tAppInterface::lock(); tSender::send(buffer, converter.end()); @@ -379,7 +403,7 @@ class Log final { using LogShiftChainHelperRaw = std::conditional_t; using LogShiftChainHelper = std::conditional_t; template - using LogShiftChainHelperErrorLevel = std::conditional_t<(csShutdownLog || tErrorLevel < tRequestedErrorLevel), LogShiftChainHelperEmpty, LogShiftChainHelperRaw>; + using LogShiftChainHelperErrorLevel = std::conditional_t<(csShutdownLog || csErrorLevel < tRequestedErrorLevel), LogShiftChainHelperEmpty, LogShiftChainHelperRaw>; public: /// Will be used as Log << something << to << log << Log::end; @@ -392,7 +416,7 @@ class Log final { static constexpr ErrorLevel all = ErrorLevel::All; template - static void init(LogConfig const &aConfig, tTypes... aArgs) { + static void init(LogFormatConfig const &aConfig, tTypes... aArgs) { if constexpr(!csShutdownLog) { sConfig = &aConfig; if constexpr(csSendInBackground) { @@ -412,8 +436,9 @@ class Log final { tAppInterface::init(); } tQueue::init(); + tAtomicBuffer::init(); sNextFreeTopic = csFirstFreeTopic; - std::fill_n(sRegisteredTopics.begin(), tMaxTopicCount, nullptr); + std::fill_n(sRegisteredTopics.begin(), csMaxTopicCount, nullptr); } else { // nothing to do } @@ -436,6 +461,7 @@ class Log final { else { // nothing to do } tQueue::done(); + tAtomicBuffer::done(); tSender::done(); tAppInterface::done(); } @@ -466,7 +492,7 @@ class Log final { } else { // nothing to do } - if(sConfig->allowRegistrationLog) { + if constexpr(csAllowRegistrationLog) { n(taskId) << csRegisteredTask << aTaskName << taskId << end; } else { // nothing to do @@ -484,8 +510,12 @@ class Log final { static void unregisterCurrentTask() noexcept { if constexpr(!csShutdownLog) { TaskId taskId = tAppInterface::getCurrentTaskId(); - if(taskId != csInvalidTaskId && sConfig->allowRegistrationLog) { - n(taskId) << csUnregisteredTask << taskId << end; + if constexpr(csAllowRegistrationLog) { + if(taskId != csInvalidTaskId) { + n(taskId) << csUnregisteredTask << taskId << end; + } + else { // nothing to do + } } else { // nothing to do } @@ -508,7 +538,7 @@ class Log final { static void registerTopic(TopicInstance &aTopic, char const * const aPrefix) { if constexpr(!csShutdownLog) { aTopic = sNextFreeTopic++; - if(aTopic >= tMaxTopicCount) { + if(aTopic >= csMaxTopicCount) { tAppInterface::fatalError(Exception::cOutOfTopics); } else { @@ -528,9 +558,30 @@ class Log final { } } + static void pushAtomic(tAtomicBufferType const &aValue) noexcept { + if constexpr(!csShutdownLog && csAtomicBufferOperational) { + tAtomicBuffer::push(aValue); + } + else { // nothing to do + } + } + + static void sendAtomicBuffer() noexcept { + if constexpr(!csShutdownLog && csAtomicBufferOperational) { + if constexpr(csSendInBackground) { + tAtomicBuffer::scheduleForSend(); + tAppInterface::atomicBufferSendWait(); + } else { + doSendAtomicBuffer(); + } + } + else { // nothing to do + } + } + template static LogShiftChainHelperErrorLevel i() noexcept { - if constexpr(!csShutdownLog && tErrorLevel >= tRequestedErrorLevel) { + if constexpr(!csShutdownLog && csErrorLevel >= tRequestedErrorLevel) { TaskId const taskId = tAppInterface::getCurrentTaskId(); return sendHeader>(taskId); } @@ -541,7 +592,7 @@ class Log final { template static LogShiftChainHelperErrorLevel i(TaskId const aTaskId) noexcept { - if constexpr(!csShutdownLog && tErrorLevel >= tRequestedErrorLevel) { + if constexpr(!csShutdownLog && csErrorLevel >= tRequestedErrorLevel) { return sendHeader>(aTaskId); } else { @@ -580,7 +631,7 @@ class Log final { template static LogShiftChainHelperErrorLevel n() noexcept { - if constexpr(!csShutdownLog && tErrorLevel >= tRequestedErrorLevel) { + if constexpr(!csShutdownLog && csErrorLevel >= tRequestedErrorLevel) { return LogShiftChainHelperErrorLevel{tAppInterface::getCurrentTaskId()}; } else { @@ -590,7 +641,7 @@ class Log final { template static LogShiftChainHelperErrorLevel n(TaskId const aTaskId) noexcept { - if constexpr(!csShutdownLog && tErrorLevel >= tRequestedErrorLevel) { + if constexpr(!csShutdownLog && csErrorLevel >= tRequestedErrorLevel) { return LogShiftChainHelperErrorLevel{aTaskId}; } else { @@ -636,15 +687,15 @@ class Log final { static tLogShiftChainHelper sendHeader(TaskId const aTaskId) noexcept { tLogShiftChainHelper result{aTaskId}; if(result.isValid()) { - if constexpr(tTaskRepresentation == TaskRepresentation::cId) { + if constexpr(csTaskRepresentation == TaskRepresentation::cId) { result << sConfig->taskIdFormat << aTaskId; } - else if constexpr (tTaskRepresentation == TaskRepresentation::cName) { + else if constexpr (csTaskRepresentation == TaskRepresentation::cName) { if constexpr (csConstantTaskNames) { result << tAppInterface::getTaskName(aTaskId); } else { - result << LogConfig::St << tAppInterface::getTaskName(aTaskId); + result << LogFormatConfig::St << tAppInterface::getTaskName(aTaskId); } } else { // nothing to do @@ -674,21 +725,27 @@ class Log final { static void transmitterTaskFunction() noexcept { while(sKeepAliveTask || !tQueue::empty()) { tMessage message; - if(tQueue::pop(message, tRefreshPeriod)) { + if(tQueue::pop(message, csRefreshPeriod)) { TaskId taskId = message.getTaskId(); - if constexpr(csSendInBackground) { - if (message.isShutdown()) { - (*sTaskShutdowns)[taskId] = true; - } - else { - checkAndInsertAndTransmit(taskId, message); - } + if (message.isShutdown()) { + (*sTaskShutdowns)[taskId] = true; } else { checkAndInsertAndTransmit(taskId, message); } } - else { // nothing to do + else { + if constexpr(csAtomicBufferOperational) { + if(tAtomicBuffer::isScheduledForSent()) { + doSendAtomicBuffer(); + tAppInterface::atomicBufferSendFinished(); + tAtomicBuffer::sendFinished(); + } + else { // nothing to do + } + } + else { // nothing to do + } } } tAppInterface::finish(); @@ -744,10 +801,34 @@ class Log final { converter.terminateSequence(); tSender::send(begin, converter.end()); } + + static void doSendAtomicBuffer() noexcept { + auto [inBuffer, inIndex] = tAtomicBuffer::getBuffer(); + auto [outBegin, outEnd] = tSender::getBuffer(); + size_t processed = 0u; + while(processed < csAtomicBufferSize) { + tConverter converter(outBegin, outEnd); + auto validOutEnd = converter.end(); + while((converter.end() != outEnd) && (processed < csAtomicBufferSize)) { + if(inBuffer[inIndex] != csAtomicBufferInvalidValue) { + converter.convert(inBuffer[inIndex], sConfig->atomicFormat.mBase, sConfig->atomicFormat.mFill); + if (converter.end() != outEnd) { + validOutEnd = converter.end(); + } else { // nothing to do + } + } + else { // nothing to do + } + inIndex = (inIndex + 1u) % csAtomicBufferSize; + ++processed; + } + tSender::send(outBegin, validOutEnd); + } + } }; } -using LC = nowtech::log::LogConfig; +using LC = nowtech::log::LogFormatConfig; #endif diff --git a/src/LogAppInterfaceStd.h b/src/LogAppInterfaceStd.h index 231f86f..622cafe 100644 --- a/src/LogAppInterfaceStd.h +++ b/src/LogAppInterfaceStd.h @@ -41,21 +41,25 @@ class AppInterfaceStd final { private: class Semaphore final { private: - std::atomic mNotified = false; - std::mutex mMutex; - std::unique_lock mLock; - std::condition_variable mConditionVariable; + std::atomic mNotified = false; + std::mutex mMutex; + std::unique_lock mLock; + std::condition_variable mConditionVariable; public: Semaphore() noexcept : mLock(mMutex) { } void wait() noexcept { + mNotified = false; mConditionVariable.wait(mLock, [this] { return mNotified == true; }); } void notify() noexcept { - mNotified = true; + { + std::lock_guard lock(mMutex); + mNotified = true; + } mConditionVariable.notify_one(); } }; @@ -156,6 +160,14 @@ class AppInterfaceStd final { static void unlock() noexcept { // Now don't care. } + static void atomicBufferSendWait() noexcept { + sSemaphore.wait(); + } + + static void atomicBufferSendFinished() noexcept { + sSemaphore.notify(); + } + static void error(Exception const aError) { throw std::ios_base::failure(csErrorMessages[static_cast(aError)]); } diff --git a/src/LogAtomicBuffers.h b/src/LogAtomicBuffers.h new file mode 100644 index 0000000..db0f124 --- /dev/null +++ b/src/LogAtomicBuffers.h @@ -0,0 +1,96 @@ +#ifndef NOWTECH_LOG_ATOMIC_BUFFERS +#define NOWTECH_LOG_ATOMIC_BUFFERS + +#include +#include +#include + +namespace nowtech::log { + +template +class AtomicBufferOperational final { +public: + using tAtomicBufferType_ = tAtomicBufferType; + static constexpr std::size_t csAtomicBufferSizeExponent = tAtomicBufferSizeExponent; + static constexpr std::size_t csAtomicBufferSize = 1u << tAtomicBufferSizeExponent; + static constexpr tAtomicBufferType csInvalidValue = tInvalidValue; + +private: + inline static tAtomicBufferType *sBuffer; // We spare one instruction per access by having C-style array instead of std::array + inline static std::atomic sNextWrite; + inline static std::atomic sShouldSend; + +public: + static void init() { + sNextWrite = 0u; + sShouldSend = false; + sBuffer = tAppInterface::template _newArray(csAtomicBufferSize); + invalidate(); + } + + static void done() { + tAppInterface::template _deleteArray(sBuffer); + } + + static void push(tAtomicBufferType const aValue) noexcept { + std::size_t nextIndex = sNextWrite++ % csAtomicBufferSize; + sBuffer[nextIndex] = aValue; + } + + static void scheduleForSend() noexcept { + sShouldSend = true; + } + + static bool isScheduledForSent() noexcept { + return sShouldSend.load(); + } + + static void sendFinished() noexcept { + sShouldSend = false; + } + + static auto getBuffer() noexcept { + return std::pair{sBuffer, sNextWrite % csAtomicBufferSize}; + } + + static void invalidate() noexcept { + std::fill_n(sBuffer, csAtomicBufferSize, tInvalidValue); + } +}; + +class AtomicBufferVoid final { +public: + using tAtomicBufferType_ = char; + static constexpr std::size_t csAtomicBufferSizeExponent = 0u; + static constexpr std::size_t csAtomicBufferSize = 1u; + + static void init() { // nothing to do + } + + static void done() { // nothing to do + } + + static void push(tAtomicBufferType_ const) noexcept { // nothing to do + } + + static void scheduleForSend() noexcept { // nothing to do + } + + static bool isScheduledForSent() noexcept { // nothing to do + return false; + } + + static void sendFinished() noexcept { // nothing to do + } + + static std::pair getBuffer() noexcept { // nothing to do + return std::pair(nullptr, 0u); + } + + static void invalidate() noexcept { // nothing to do + } +}; + +} + +#endif diff --git a/src/LogConverterCustomText.h b/src/LogConverterCustomText.h index 7912876..07b0506 100644 --- a/src/LogConverterCustomText.h +++ b/src/LogConverterCustomText.h @@ -10,9 +10,9 @@ namespace nowtech::log { template class ConverterCustomText final { public: - using tMessage_ = tMessage; - using ConversionResult = char; - using Iterator = char*; + using tMessage_ = tMessage; + using ConversionResult = char; + using Iterator = char*; static constexpr Iterator csNullIterator = nullptr; // Used in SenderVoid to return void begin-end pair. static constexpr bool csSupportFloatingPoint = tMessage::csSupportFloatingPoint; diff --git a/src/LogQueueStdBoost.h b/src/LogQueueStdBoost.h index 0480bc8..7dbec29 100644 --- a/src/LogQueueStdBoost.h +++ b/src/LogQueueStdBoost.h @@ -20,10 +20,10 @@ class QueueStdBoost final { private: class FreeRtosQueue final { boost::lockfree::queue mQueue; - std::atomic mNotified; - std::mutex mMutex; - std::unique_lock mLock; - std::condition_variable mConditionVariable; + std::atomic mNotified; + std::mutex mMutex; + std::unique_lock mLock; + std::condition_variable mConditionVariable; public: /// First implementation, we assume we have plenty of memory. @@ -42,7 +42,10 @@ class QueueStdBoost final { void push(tMessage const &aMessage) noexcept { bool success = mQueue.bounded_push(aMessage); if(success) { - mNotified = true; + { + std::lock_guard lock(mMutex); + mNotified = true; + } mConditionVariable.notify_one(); } else { // nothing to do diff --git a/test/test-stdthreadostream.cpp b/test/test-stdthreadostream.cpp index a242c46..193ef5d 100644 --- a/test/test-stdthreadostream.cpp +++ b/test/test-stdthreadostream.cpp @@ -56,12 +56,16 @@ namespace nowtech::LogTopics { } constexpr nowtech::log::TaskId cgMaxTaskCount = cgThreadCount + 1; +constexpr bool cgAllowRegistrationLog = true; constexpr bool cgLogFromIsr = false; constexpr size_t cgTaskShutdownSleepPeriod = 100u; constexpr bool cgArchitecture64 = true; constexpr uint8_t cgAppendStackBufferSize = 100u; constexpr bool cgAppendBasePrefix = true; constexpr bool cgAlignSigned = false; +using AtomicBufferType = int32_t; +constexpr size_t cgAtomicBufferExponent = 14u; +constexpr AtomicBufferType cgAtomicBufferInvalidValue = 1234546789; constexpr size_t cgTransmitBufferSize = 123u; constexpr size_t cgPayloadSize = 14u; constexpr bool cgSupportFloatingPoint = true; @@ -71,32 +75,44 @@ constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log:: constexpr size_t cgDirectBufferSize = 0u; constexpr nowtech::log::ErrorLevel cgErrorLevel = nowtech::log::ErrorLevel::Error; -using LogAppInterfaceStd = nowtech::log::AppInterfaceStd; -constexpr typename LogAppInterfaceStd::LogTime cgTimeout = 123u; -constexpr typename LogAppInterfaceStd::LogTime cgRefreshPeriod = 444; +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; using LogMessage = nowtech::log::MessageCompact; using LogConverterCustomText = nowtech::log::ConverterCustomText; -using LogSenderStdOstream = nowtech::log::SenderStdOstream; -using LogQueueStdBoost = nowtech::log::QueueStdBoost; -using Log = nowtech::log::Log; - +using LogSenderStdOstream = nowtech::log::SenderStdOstream; +using LogQueueStdBoost = nowtech::log::QueueStdBoost; +using LogAtomicBuffer = nowtech::log::AtomicBufferOperational; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; + void delayedLog(size_t n) { Log::registerCurrentTask(cgThreadNames[n]); Log::i(nowtech::LogTopics::system) << static_cast(n) << ": " << static_cast(0) << Log::end; - for(int64_t i = 1; i < 13; ++i) { + for(int64_t i = 1; i < 4; ++i) { std::this_thread::sleep_for(std::chrono::milliseconds(1 << i)); Log::i(nowtech::LogTopics::system) << static_cast(n) << "thread delay logarithm: " << LC::X1 << i << Log::end; } Log::unregisterCurrentTask(); } +std::atomic gCounter; +constexpr int32_t cgAtomicCount = 100; + +void atomicLog(size_t n) { + Log::registerCurrentTask(cgThreadNames[n]); + for(int32_t i = 0; i < cgAtomicCount; ++i) { + Log::pushAtomic(gCounter++); + } + Log::unregisterCurrentTask(); +} + char gTextToCopy[] = "This_text_will_be_copied_in_messages."; int main() { std::thread threads[cgThreadCount + 1u]; // let there be zero threads - nowtech::log::LogConfig logConfig; - logConfig.allowRegistrationLog = true; + nowtech::log::LogFormatConfig logConfig; LogSenderStdOstream::init(&std::cout); Log::init(logConfig); @@ -167,6 +183,17 @@ int main() { threads[i].join(); } + gCounter = 0; + + for(size_t i = 0; i < cgThreadCount; ++i) { + threads[i] = std::thread(atomicLog, i); + } + for(size_t i = 0; i < cgThreadCount; ++i) { + threads[i].join(); + } + Log::sendAtomicBuffer(); + Log::n() << Log::end; + Log::unregisterCurrentTask(); Log::done(); return 0; From 06cc58e48281fcbeaa904ea289f4e65602236c11 Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Wed, 30 Dec 2020 18:46:07 +0100 Subject: [PATCH 10/27] Bugfix. --- src/Log.h | 14 +++++++++----- test/test-stdthreadostream.cpp | 1 + 2 files changed, 10 insertions(+), 5 deletions(-) diff --git a/src/Log.h b/src/Log.h index 88f226a..706f47b 100644 --- a/src/Log.h +++ b/src/Log.h @@ -201,6 +201,9 @@ class Log final { /// This will be used to send via queue. It stores the first message, and sends it only with the terminal marker. class LogShiftChainHelperBackgroundSend final { + private: + inline static constexpr char csEmptyString[] = ""; + inline static constexpr LogFormat csEmptyFormat {2u, 0u}; TaskId mTaskId; LogFormat mNextFormat; MessageSequence mNextSequence; @@ -214,7 +217,8 @@ class Log final { LogShiftChainHelperBackgroundSend(TaskId const aTaskId) noexcept : mTaskId(aTaskId) , mNextSequence(0u) { - mNextFormat.invalidate(); + mNextFormat.invalidate(); + mFirstMessage.set(csEmptyString, csEmptyFormat, mTaskId, mNextSequence); // This will be overwritten if any message arrives. } /// Can be used in application code to eliminate further operator<< calls when the topic is disabled. @@ -579,7 +583,7 @@ class Log final { } } - template + template static LogShiftChainHelperErrorLevel i() noexcept { if constexpr(!csShutdownLog && csErrorLevel >= tRequestedErrorLevel) { TaskId const taskId = tAppInterface::getCurrentTaskId(); @@ -590,7 +594,7 @@ class Log final { } } - template + template static LogShiftChainHelperErrorLevel i(TaskId const aTaskId) noexcept { if constexpr(!csShutdownLog && csErrorLevel >= tRequestedErrorLevel) { return sendHeader>(aTaskId); @@ -629,7 +633,7 @@ class Log final { } } - template + template static LogShiftChainHelperErrorLevel n() noexcept { if constexpr(!csShutdownLog && csErrorLevel >= tRequestedErrorLevel) { return LogShiftChainHelperErrorLevel{tAppInterface::getCurrentTaskId()}; @@ -639,7 +643,7 @@ class Log final { } } - template + template static LogShiftChainHelperErrorLevel n(TaskId const aTaskId) noexcept { if constexpr(!csShutdownLog && csErrorLevel >= tRequestedErrorLevel) { return LogShiftChainHelperErrorLevel{aTaskId}; diff --git a/test/test-stdthreadostream.cpp b/test/test-stdthreadostream.cpp index 193ef5d..6daefbe 100644 --- a/test/test-stdthreadostream.cpp +++ b/test/test-stdthreadostream.cpp @@ -193,6 +193,7 @@ int main() { } Log::sendAtomicBuffer(); Log::n() << Log::end; + std::this_thread::sleep_for(std::chrono::seconds(2)); Log::unregisterCurrentTask(); Log::done(); From 203df41be571c5a77fd939136b2b1f0e43018505 Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Wed, 30 Dec 2020 20:15:16 +0100 Subject: [PATCH 11/27] Bugfix. Documented AtomicBuffers. --- README.md | 74 +++++++++++++++++++++++++++++++++++++++++++++++-------- src/Log.h | 15 +++++++++-- 2 files changed, 77 insertions(+), 12 deletions(-) diff --git a/README.md b/README.md index 49d1926..2478a1c 100644 --- a/README.md +++ b/README.md @@ -42,6 +42,7 @@ Copyright 2020 Balázs Bámer. - More transient strings will be copied instantly. - Operate in a _strictly typed_ way as opposed to the printf-based loggers some companies still use today. - We needed a much finer granularity than the usual log levels, so I've introduced independently selectable topics. Recently I've also added traditional log levels. +- Provide blazing-fast atomic logging of one integral type into a buffer. Its contents can later be converted and sent. - Important aim was to let the user log a _group of related items_ without other tasks interleaving the output of converting these items. - Possibly minimal relying on external libraries. It does not depend on numeric to string conversion functions. - In contrast with the original solution, the new one extensively uses templated classes to @@ -69,6 +70,8 @@ The logger consists of six classes: - _Message_ - used as a transfer medium in the Queue. For numeric types and strings transferred by pointers, one message is needed per item. For stored strings several messages may be necessary. There are two general-purpose implementations: - a variant based message. - a more space-efficient handcrafted message. +- _AtomicBuffer_ - provides buffer and instrumentation for the atomic logging. This bypasses all the queues and logic used to log groups of various types. +- _Config_ - provides some configuration parameters. The logger can operate in two modes: - Direct without queue, when the conversion and sending happens without message instantiation and queue usage. This can be useful for single-threaded applications. @@ -126,10 +129,35 @@ Emply implementation for the case when all the log calls have to be eliminated f This is a minimal implementation for STM32 UART using blocking HAL transmission. A more sophisticated one would use double buffering with DMA to use the MCU more efficiently and allow buffering new data during the potentially slow transmission of the old buffer. This mechanism is implemented in the old version. -### LogSenderStdOstream +### SenderStdOstream It is a simple std::ostream wrapper. +### AtomicBufferOperational + +Normal cross-platform implementaiton. + +### AtomicBufferVoid + +Used instead the normal one to strip its static variables when not in use. + +### Config + +Converts the template arguments into public static variables. One can use it or write a template-less direct class instead using this example: + +```C++ +template +struct Config final { +public: + static constexpr bool csAllowRegistrationLog = tAllowRegistrationLog; + static constexpr LogTopic csMaxTopicCount = tMaxTopicCount; + static constexpr TaskRepresentation csTaskRepresentation = tTaskRepresentation; + static constexpr size_t csDirectBufferSize = tDirectBufferSize; + static constexpr int32_t csRefreshPeriod = tRefreshPeriod; // Can represent 1s even if the unit is ns. + static constexpr ErrorLevel csErrorLevel = tErrorLevel; +}; +``` + ## Benchmarks I used [picobench](https://github.com/iboB/picobench) for benchmarks using the supplied bechmark apps. Here are some averaged results measured on 8192 iterations on my _Intel(R) Xeon(R) CPU E31220L @ 2.20GHz_. Compiled using `clang++ -O2`. There were no significant differences for `MessageVariant` or `MessageCompact`. Log activity was @@ -278,17 +306,24 @@ Explanation of configuration parameters: |`typename tMessage` |_Queue_ |The _Message_ type to use.| |`typename tAppInterface` |_Queue_ |The _app interface_ type to use.| |`size_t tQueueSize` |_Queue_ |Number of items the queue should hold. This applies to the master queue and to the aggregated capacity of the per-task queues.| +|`typename tAppInterface` |`AtomicBufferOperational`|The _app interface_ to use.| +|`typename tAtomicBufferType` |`AtomicBufferOperational`|The integral type to log as atomic.| +|`tAtomicBufferSizeExponent` |`AtomicBufferOperational`|Exponent of the buffer size (base of the power is 2). For numeric reasons, the buffer size is always a power of 2.| +|`tAtomicBufferType tInvalidValue` |`AtomicBufferOperational`|Invalid value, which won't be sent when all the buffer contents are being sent.| |`typename tQueue` |`Log` |The _Queue_ type to use.| |`typename tSender` |`Log` |The _Sender_ type to use.| -|`LogTopic tMaxTopicCount` |`Log` |LogTopic is `int8_t`. Maximum is 127.| -|`TaskRepresentation tTaskRepresentation` |`Log` |One of `cNone` (for omitting it), `cId` (for numeric task ID), `cName` (for task name).| -|`size_t tDirectBufferSize` |`Log` |When 0, the given _Queue_ will be used. Otherwise, it is the size of a buffer on stack to hold a converted item before sending it.| -|`typename tSender::tAppInterface_::LogTime tRefreshPeriod`|`Log` |Timeout in implementation-defined unit (usually ms) for waiting on the queue before sending what already present.| -|`ErrorLevel tErrorLevel` |`Log` |The application log level with the default value `ErrorLevel::All`.| -|`bool allowRegistrationLog` |`LogConfig` |True if task (un)registering should be logged.| -|`LogFormat taskIdFormat` |`LogConfig` |Format of task ID to use when `tTaskRepresentation == TaskRepresentation::cId`.| -|`LogFormat tickFormat` |`LogConfig` |Format for displaying the timestamp in the header, if any. Should be `LogConfig::cInvalid` to disable tick output.| -|`LogFormat defaultFormat` |`LogConfig` |Default formatting, initially `LogConfig::Fm` to obtain maximum possible precision for floating point types.| +|`typename tAtomicBuffer` |`Log` |The _AtomicBuffer_ type to use.| +|`typename tLogConfig` |`Log` |The _LogConfig_ type to use.| +|`bool allowRegistrationLog` |`Config` |True if task (un)registering should be logged.| +|`LogTopic tMaxTopicCount` |`Config` |LogTopic is `int8_t`. Maximum is 127.| +|`TaskRepresentation tTaskRepresentation` |`Config` |One of `cNone` (for omitting it), `cId` (for numeric task ID), `cName` (for task name).| +|`size_t tDirectBufferSize` |`Config` |When 0, the given _Queue_ will be used. Otherwise, it is the size of a buffer on stack to hold a converted item before sending it.| +|`int32_t tRefreshPeriod` |`Config` |Timeout in implementation-defined unit (usually ms) for waiting on the queue before sending what already present.| +|`ErrorLevel tErrorLevel` |`Config` |The application log level with the default value `ErrorLevel::All`.| +|`LogFormat atomicFormat` |`LogFormatConfig` |Format used for converting the bulk data in the _AtomicBuffer_. +|`LogFormat taskIdFormat` |`LogFormatConfig` |Format of task ID to use when `tTaskRepresentation == TaskRepresentation::cId`.| +|`LogFormat tickFormat` |`LogFormatConfig` |Format for displaying the timestamp in the header, if any. Should be `LogConfig::cInvalid` to disable tick output.| +|`LogFormat defaultFormat` |`LogFormatConfig` |Default formatting, initially `LogConfig::Fm` to obtain maximum possible precision for floating point types.| ### Topics and log levels @@ -350,6 +385,8 @@ C++20 has suitable variadic macros in the preprocessor, which would enable one t ### Logging +#### Group logging + All the logging API is implemented as static functions in the `Log` template class. Logging happens using a `std::ostream` -like API, like in the example in the beginning. There are two overloaded functions to start the chain: - `static LogShiftChainHelper i(...) noexcept` writes any header configured for the application. - `static LogShiftChainHelper n(...) noexcept` omits this header, just writes the actual stuff it receives using `<<`. @@ -380,3 +417,20 @@ Log::f(Log::i(nowtech::LogTopics::someTopic), some, variables, follow); ``` and apart of being clumsy, it is even takes more binary space than the `std::ostream` -like API it uses under the hood. It appends `Log::end` automatically. + +#### Atomic logging + +Atomic logging can happen any time in this way (now the buffer is of type `int16_t`): + +```C++ +int16_t value = 13; +Log::pushAtomic(value); +``` + +Of course this is only effective if the logging is on and the `AtomicBufferOperational` class is being used. These values are accepted from any task and land in a circular buffer, which is continuously overwritten. To extract the contents, first the application should stop calling `Log::pushAtomic` because the slower readout would produce undefined behaviour when still being written into. (There is no locking for maximum performance.) Then, a task with valid log registry should call + +```C++ +Log::sendAtomicBuffer(); +``` + +which is a blocking call for direct sending, but happens in the background in multithreaded mode. Note, in this later case sending from all other tasks is blocked, only the queues will hold the messages from concurrent logging as long as they can. diff --git a/src/Log.h b/src/Log.h index 706f47b..30129aa 100644 --- a/src/Log.h +++ b/src/Log.h @@ -204,10 +204,12 @@ class Log final { private: inline static constexpr char csEmptyString[] = ""; inline static constexpr LogFormat csEmptyFormat {2u, 0u}; + TaskId mTaskId; LogFormat mNextFormat; MessageSequence mNextSequence; tMessage mFirstMessage; + bool mWasMessage; public: static constexpr LogShiftChainEndMarker end = LogShiftChainEndMarker::cEnd; @@ -216,9 +218,9 @@ class Log final { LogShiftChainHelperBackgroundSend(TaskId const aTaskId) noexcept : mTaskId(aTaskId) - , mNextSequence(0u) { + , mNextSequence(0u) + , mWasMessage(false) { mNextFormat.invalidate(); - mFirstMessage.set(csEmptyString, csEmptyFormat, mTaskId, mNextSequence); // This will be overwritten if any message arrives. } /// Can be used in application code to eliminate further operator<< calls when the topic is disabled. @@ -254,6 +256,11 @@ class Log final { void operator<<(LogShiftChainEndMarker const) noexcept { if(mTaskId != csInvalidTaskId) { + if(!mWasMessage) { + mFirstMessage.set(csEmptyString, csEmptyFormat, mTaskId, csSequence0); + } + else { // nothing to do + } tQueue::push(mFirstMessage); } else { // nothing to do @@ -309,6 +316,7 @@ class Log final { void sendOrStore(tMessage const & aMessage) noexcept { if(mNextSequence == csSequence0) { + mWasMessage = true; mFirstMessage = aMessage; } else { @@ -828,6 +836,9 @@ class Log final { } tSender::send(outBegin, validOutEnd); } + tConverter converter(outBegin, outEnd); + converter.terminateSequence(); + tSender::send(outBegin, converter.end()); } }; From 73b532c7deae3eb6e4e743e1ac4c1f9303b4f1a3 Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Thu, 31 Dec 2020 18:28:56 +0100 Subject: [PATCH 12/27] Bugfix. --- src/Log.h | 2 +- src/LogConverterCustomText.h | 8 ++------ src/LogQueueVoid.h | 2 +- 3 files changed, 4 insertions(+), 8 deletions(-) diff --git a/src/Log.h b/src/Log.h index 30129aa..2710f6c 100644 --- a/src/Log.h +++ b/src/Log.h @@ -703,7 +703,7 @@ class Log final { result << sConfig->taskIdFormat << aTaskId; } else if constexpr (csTaskRepresentation == TaskRepresentation::cName) { - if constexpr (csConstantTaskNames) { + if constexpr (csConstantTaskNames || !csSendInBackground) { result << tAppInterface::getTaskName(aTaskId); } else { diff --git a/src/LogConverterCustomText.h b/src/LogConverterCustomText.h index 07b0506..8636939 100644 --- a/src/LogConverterCustomText.h +++ b/src/LogConverterCustomText.h @@ -125,13 +125,9 @@ class ConverterCustomText final { appendSpace(); } - void convert(char const * const aValue, uint8_t const, uint8_t const aFill) noexcept { + void convert(char const * const aValue, uint8_t const, uint8_t const) noexcept { append(aValue); - if(aFill < LogFormat::csFillValueStoreString) { // Antipattern to use the fill for other purposes, but we go for space saving. - appendSpace(); - } - else { // nothing to do - } + appendSpace(); } void convert(bool const aValue, uint8_t const, uint8_t const) noexcept { diff --git a/src/LogQueueVoid.h b/src/LogQueueVoid.h index 0883b93..d408fd4 100644 --- a/src/LogQueueVoid.h +++ b/src/LogQueueVoid.h @@ -5,7 +5,7 @@ namespace nowtech::log { -template +template class QueueVoid final { public: using tMessage_ = tMessage; From 9cc558b84ff5660006a4945f5d021e0cdebf925a Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Thu, 31 Dec 2020 20:16:53 +0100 Subject: [PATCH 13/27] Bugfix. --- src/LogQueueVoid.h | 2 ++ 1 file changed, 2 insertions(+) diff --git a/src/LogQueueVoid.h b/src/LogQueueVoid.h index d408fd4..776581f 100644 --- a/src/LogQueueVoid.h +++ b/src/LogQueueVoid.h @@ -12,6 +12,8 @@ class QueueVoid final { using tAppInterface_ = tAppInterface; using LogTime = typename tAppInterface::LogTime; + static constexpr size_t csQueueSize = 0u; + private: QueueVoid() = delete; From 0538a2486d6831bd35d7ce78d6210e97962e68ba Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Thu, 31 Dec 2020 20:18:38 +0100 Subject: [PATCH 14/27] More testing, docs. --- .idea/cpp_logger.iml | 2 + .idea/modules.xml | 8 ++ CMakeLists.txt | 2 +- README.md | 63 ++++++++------ benchmark/picobench-direct.cpp | 2 - sizecalc.ods | Bin 9601 -> 10289 bytes test/test-sizes-atomic-stdostream.cpp | 118 ++++++++++++++++++++++++++ test/test-sizes-stdthreadostream.cpp | 85 +++++++++++-------- test/test-stdostream.cpp | 51 ++++++++--- test/test-stdthreadostream.cpp | 2 - 10 files changed, 254 insertions(+), 79 deletions(-) create mode 100644 .idea/cpp_logger.iml create mode 100644 .idea/modules.xml create mode 100644 test/test-sizes-atomic-stdostream.cpp diff --git a/.idea/cpp_logger.iml b/.idea/cpp_logger.iml new file mode 100644 index 0000000..f08604b --- /dev/null +++ b/.idea/cpp_logger.iml @@ -0,0 +1,2 @@ + + \ No newline at end of file diff --git a/.idea/modules.xml b/.idea/modules.xml new file mode 100644 index 0000000..bbaa508 --- /dev/null +++ b/.idea/modules.xml @@ -0,0 +1,8 @@ + + + + + + + + \ No newline at end of file diff --git a/CMakeLists.txt b/CMakeLists.txt index bb77b94..5b86a9f 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -23,4 +23,4 @@ add_executable(cpp_logger src/LogQueueVoid.h src/LogSenderStdOstream.h src/LogSenderVoid.h - test/test-stdthreadostream.cpp) + test/test-sizes-atomic-stdostream.cpp) diff --git a/README.md b/README.md index 2478a1c..1204aae 100644 --- a/README.md +++ b/README.md @@ -184,7 +184,7 @@ For desktop, I used clang version 10.0.0 on x64. For embedded, I used arm-none-e - logging with queue using MessageVariant (for multithreaded applications) - logging with queue using MessageCompact (for multithreaded applications) -### FreeRTOS with floating point +### FreeRTOS with floating point STALE To obtain net results, I put some floating-point operations in the application *test-sizes-freertosminimal-float.cpp* because a real application would use them apart of logging. @@ -195,7 +195,7 @@ To obtain net results, I put some floating-point operations in the application * |MessageVariant|15304 |112 | 76 | |MessageCompact|15024 |112 | 76 | -### FreeRTOS without floating point +### FreeRTOS without floating point STALE No floating point arithmetics in the application and the support is turned off in the logger. Source is *test-sizes-freertosminimal-nofloat.cpp* @@ -206,16 +206,26 @@ No floating point arithmetics in the application and the support is turned off i |MessageVariant|6440 |12 | 80 | |MessageCompact|6192 |12 | 80 | -### x86 STL with floating point +### x86 STL with floating point, only chained log Not much point to calculate size growth here, but why not? Source is *test-sizes-stdthreadostream.cpp* |Scenario | Text| Data| BSS| |--------------|------:|-----:|------:| -|direct |11899 | 273 |492 | +|direct |11835 | 273 |492 | |off |0 |0 |0 | -|MessageVariant|22483 | 457 |892 | -|MessageCompact|20851 |457 | 892 | +|MessageVariant|22803 | 457 |892 | +|MessageCompact|21175 |457 | 892 | + +### x86 STL with floating point, only atomic log + +Not much point to calculate size growth here, but why not? Source is *test-sizes-stdthreadostream.cpp* + +|Scenario | Text| Data| BSS| +|--------------|------:|-----:|------:| +|direct |9536 | 233 |516 | +|off |0 |0 |0 | +|multithreaded |20467 |457 | 916 | ## API @@ -259,31 +269,36 @@ Log system initialiation consists of the following steps: Refer the beginning for an example for STL without the first step. Here is a FreeRTOS template declaration without floating point support but for multithreaded mode: ```C++ -constexpr nowtech::log::TaskId cgMaxTaskCount = 1u; +constexpr nowtech::log::TaskId cgMaxTaskCount = cgThreadCount + 1; +constexpr bool cgAllowRegistrationLog = true; constexpr bool cgLogFromIsr = false; -constexpr size_t cgTaskShutdownPollPeriod = 100u; -constexpr bool cgArchitecture64 = false; +constexpr size_t cgTaskShutdownSleepPeriod = 100u; +constexpr bool cgArchitecture64 = true; constexpr uint8_t cgAppendStackBufferSize = 100u; constexpr bool cgAppendBasePrefix = true; constexpr bool cgAlignSigned = false; +using AtomicBufferType = int32_t; +constexpr size_t cgAtomicBufferExponent = 14u; +constexpr AtomicBufferType cgAtomicBufferInvalidValue = 1234546789; constexpr size_t cgTransmitBufferSize = 123u; -constexpr size_t cgPayloadSize = 6u; // This disables 64-bit integer arithmetic. -constexpr bool cgSupportFloatingPoint = false; -constexpr size_t cgQueueSize = 111u; +constexpr size_t cgPayloadSize = 14u; +constexpr bool cgSupportFloatingPoint = true; +constexpr size_t cgQueueSize = 444u; constexpr nowtech::log::LogTopic cgMaxTopicCount = 2; constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cName; -constexpr uint32_t cgLogTaskStackSize = 256u; -constexpr uint32_t cgLogTaskPriority = tskIDLE_PRIORITY + 1u; - constexpr size_t cgDirectBufferSize = 0u; -using LogAppInterfaceFreeRtosMinimal = nowtech::log::AppInterfaceFreeRtosMinimal; -constexpr typename LogAppInterfaceFreeRtosMinimal::LogTime cgTimeout = 123u; -constexpr typename LogAppInterfaceFreeRtosMinimal::LogTime cgRefreshPeriod = 444; +constexpr nowtech::log::ErrorLevel cgErrorLevel = nowtech::log::ErrorLevel::Error; + +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; using LogMessage = nowtech::log::MessageCompact; -using LogConverterCustomText = nowtech::log::ConverterCustomText; -using LogSender = nowtech::log::SenderStmHalMinimal; -using LogQueue = nowtech::log::QueueFreeRtos; -using Log = nowtech::log::Log; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStdOstream; +using LogQueue = nowtech::log::QueueStdBoost; +using LogAtomicBuffer = nowtech::log::AtomicBufferOperational; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; ``` Explanation of configuration parameters: @@ -427,10 +442,10 @@ int16_t value = 13; Log::pushAtomic(value); ``` -Of course this is only effective if the logging is on and the `AtomicBufferOperational` class is being used. These values are accepted from any task and land in a circular buffer, which is continuously overwritten. To extract the contents, first the application should stop calling `Log::pushAtomic` because the slower readout would produce undefined behaviour when still being written into. (There is no locking for maximum performance.) Then, a task with valid log registry should call +Of course this is only effective if the logging is on and the `AtomicBufferOperational` class is being used. These values are accepted from any task or ISR and land in a circular buffer, which is continuously overwritten. To extract the contents, first the application should stop calling `Log::pushAtomic` because the slower readout would produce undefined behaviour when still being written into. (There is no locking for maximum performance.) Then, a task with valid log registry should call ```C++ Log::sendAtomicBuffer(); ``` -which is a blocking call for direct sending, but happens in the background in multithreaded mode. Note, in this later case sending from all other tasks is blocked, only the queues will hold the messages from concurrent logging as long as they can. +which is a blocking call. Note, in multithreaded mode sending from all other tasks won't happen, only the queues will hold the messages from concurrent logging as long as they can. diff --git a/benchmark/picobench-direct.cpp b/benchmark/picobench-direct.cpp index 58c37c2..b828348 100644 --- a/benchmark/picobench-direct.cpp +++ b/benchmark/picobench-direct.cpp @@ -2,8 +2,6 @@ #define PICOBENCH_DEFAULT_SAMPLES 10 #include "picobench/picobench.hpp" -//#include "lwlog/lwlog.h" - #include "LogAppInterfaceStd.h" #include "LogConverterCustomText.h" #include "LogSenderStdOstream.h" diff --git a/sizecalc.ods b/sizecalc.ods index d39f419c1408be337f7f484172f1e2b93c57094e..3d87e19aed01b4b60425b775b3394edf4e21e305 100644 GIT binary patch delta 8473 zcmcI}bxb3355v;2K#n=&x}J-f_y7LP2gmp6LNS^IXLX! z*X)0l=inUwZttXkNBGaKhFpKUki|V<{;9?pl7TeIkwJoggPgyCT7mzoDV6gbEG+Dw zA!~IY_`v__nF>h&$i>XCV76V;lh>*bkjTySOV^^mlaCO}kz6gA^(8>8(B&R4`0aJI zcaH5TG)!j4cfCL6q%5E(|K0<9!_wR>EFY7~Api3+C-05TE1KPu@ok0k#DrFWqP#10 z6?i7;>=0>v`Ik0jvryk4d+eYapUk_`*@qB&Y4tp^5@ZfvU}~~cBEkssr{Y1my-TUK z;R!|^x#ZTkL2j`7-dBsV<_=sNV9m)`Tq*YGgK}cq)p$A=hKv*hO#cg`AuUDRNm^_C z0PTJo>!(lqkHZ-yuTfQ}w(!+$othsdR9DZF>*)&nrbUThV2B&uVHKts^|OxLJ5$Wd zDkj+?B$ad30UFZrt7*`=NX?>!`@) zKYarbDRWUscx*7E-&a2Gzbr7eG}(EL35yAvzj1rs5X z#R0!0niLu;cuE`U=M%R);-oSOOlsFaT4D6KPTuwB^XST7r`zuf`thBFH5_fDC88}h z`^>?ma-6PL7VhU~+mc@$`+H)4Eg~d$esv&cB(tN%hJmH-k>SRk49lCZ-VPs#CGC+> zj0~psiOK&+D+aU|L>7jQE&GtYzgpFiPVsDLU$Xv`Iuv#}`0}`<=9ARNHO(|7)3-NC z#?i!+q#+?{3U2wpAm6-sTp~4F3llr6{Oh&zNqPKW*gSD-w3DS%8XFTroulue z0lfCLTCjChC%jH#bhVghFjfPdm#EZLJ7dAllC{~%Iy%sjz$kmPVL!#;ymxIEa^$ofNCY;k9*Np>deop7l->UKDiqa?YN+{M181(q?t zg@cj#&lSQns9q;~^jUahB_LImkIstEq?B^-n0+SHPI)x^SVSelg9E8meCniUu^Ou& zlB&DzA`1v=Kthl%*U+GhORk+Qm0U0`*$o{~jZusH_Jy@gOYY2ux7R0^R7M&Q!!Q-`+nUx}$@Dedxe67}$Vyb+sj%&ihY)6p%^Ul>w!=eXY zf>Lm~oVNh=(WV8v=t6wT52AYB25`fzdOG)+L4Kfup`e1BS#3PFy9AG%L>v6BI62dl zl{q!)R9Dm0*0=A9LxK{mpGqd#qU-oGsj-ON#F)O)aNkcCjd?SCjvw&0;vfB+ghKil zy7*YnUZyr05f@97YH`E#Gl<(N~j+%%al93FIx{JLFvdVwzcu zm)rpu^>U%aNoQDtPmKWx^w*uW8WFrdoSaq=j<3{?8ElFB ziPq&jU{_D35tI~SjSM7whvpL}6erA=p%2C*a*{I8PjLaqudAAc4~wNyV&|EiEhe#} z{hXRski}U?aVD~_lpscrDg4thpTIkLi1HoqB;d{NrmDeWoR!Cch_69IZ!ef6u24~b z=ZzK;|jN=YEmD8Q+KN*-^wI zNQ&k8u^jqqIb%CmAYX9S4xEm|wrc-^{B$hlc*e7^aDL-S#nS0&z7Whd7?Y5rT?zwm zX3#H2WPnGpL5@&Fsd6>Yk2#Mk!bJRLmk{KMa@K)<0Eb@%si-a2l)FJ7VC1aqBfXzO z$1Z@*6{d1@L)F|eT2<(BXWnRST2GC*ydl=vJ$tI!x~tt1K;vA6thvN0^HA)$pCy&` zb7x*#E{d;IHVUnWzUq|Fv7s#w=t2dEH#Rdf59R3gowUoH3E1TcvTEepYf|a+#`~Av`|g=cr@W6%+WgdC5vvaT$*FBJ zbp}&DDl@G%@-@`C5b`@N-|>0?e0~jHr*;6H4M=bK{XhZZq{0lE*Fgq7p!(E-E48gH zE@7w=#CQ=>ZZh_ByX z_go`f5E72+s*D}}ECr^aC8gLn!E#YxaBO8Qj1SWw~q#h)@h@cBH3--tc5 z@Rpv9H`DzLi=$CZVAohL`f$6prFN2K`gLS9GxG?AJnzA-y6>at1Tz!U_~}}I8`T<_ zA@vnqes#_x~fZDS`cmA-vU%?QES*ZJn9iZLHU{wCz?nF?}~GQB@4=fEw#1X&YvF|M!QY z3#W!>e&C`cU&3p`m2-rYJ5CpV#EYto>KhT%!gJL!14XTvO4nJ;~^DBQ5eVr2ug3~Z{s z$p+%fy0s@#IRJ4IZ6;dUij7}X4L*KAYSdf|)&_{-t;^Y1~` zr7Uyhum#ym<;fTkcZmtkGkenOt7ngO-`m8ju5TtcTb$#6SdB&zAtqi)g>-Y=n?qVo zz-eT`pp5q)j&R}uC zsf!(oN2j6;%pB}^mAOOQN{CgU<%yU*q4>Bq1YBA!9^}ongBh)M0?aoOYlY=Cn&w2H z*aI-K!Fb7#i<(-;dP}t$uFOq?5}(mV?g@pN>xngctP#FzheyKkSDa?PMNeiqjSe$y zq#y9-fVDjY8CW-NE$Vfj>qO>D_D)x=C3nPBt(G9#pdeB5ym>;{x=g)2Oe4A%xfo;| zI-U^aPgH6i(~R8y1~DxZ_fYgY@DyKL#w@tz+}Mx4NUa;mCd-)f&jb496Zh?>%Uu!G zPESTn8WJf%u(6c(bs2O`x8^%c;HfI1SgS5dKp?HZnS;@{_*-%6;DUf=N(~J(?F#Ns z8)+ON3DCjEhsws_8z99*R=eGYYts4OR?d&jmjbqFXWD%R`QvmO$`RVKoZ3Z}J5!_g zn-|wX?EXYa(&!Y&v-wmLRor&rEgs(@Se@BM(=lzTKr(!ru%;>vOscJl>-?hR%3q_Q zflQIqV+R&8-jake>tUj1&O-c6fqP@=k#tOlTjhL`M_ADv%V6k_nZjNGJ4q>!&xB-> z5(I}mD;5U7x~O~-z3P}`(;&|ZP&05t#t+m5Piao+Hu`^C$J(`9Opp9ryg(z(iPw}n zn|ov)zB{li&7`5cjY{FE$&Rj#S)#cMz^NWSCtGzyjU*i3iTfo!@=!TVl(=cdn=oL= zX`jm~B1PPi(YJC>z9>yk-O96=cA+PwvTiUiYM##_DJR!iotUi5*shUt7^j1OIX}J) z+3vkQr8l5{wQM|rNl&fkoxOXqor0WN?{R1m_Xrc<_A{2YpGC7!CA~3~gQj5vK9|l2 zq7>t--!s&q)y`=2<9imoNb|RuU5Mm0exq{7bzB2Y-opb&qKW3!P z^~`dDN-FV4K-$k^Czm=@tm{`%G36O3A|ASg`C$J}&-5d<`~95%#F4tw zI0E2lET#pnZ#0Je!%Obc7gpTPa^J2?*KafM{V$fFEJ0RwvQ6LE$L2G9$+`VdW}gNo06p}f_L()=iRagp!)4upn)NYv+oUjjkFm?DO0UO)v6)Wg z8|G0&s3v-sqNPpbJ&)_5p3!o6k8olRg4J9zF0%^gRVvR}Yx|h*%zUB~UV@S_@D(cJ z1$KpI99k5W9A7#)tPt2s8R&gD&5S4=YkIkWXUo7FC&Kp#SAyS0sU+>d6YtW^ z3HTLAKiFeGtc#f8ctXDit@0)0)(*<5v(VZbL6d2J<8zY2S?5~o)4M;h54CJfy8bQp z{igmOu@6*&MgnL%kZM&Zh9j1`#p_xZ7qa=_yn0UQu~gO;lmN+j{URm)ySS~=Ek z=22*xYdAXN&sxQp;!}l1SK%-t%9=_E%2zj}(zHGpk=1TVR6RA6Ye}vPcGE+1%^_#z zDYy-iY#fw8-@~wT~RAa0)0NQAe`fA-6OBqOo;Pt=!th8UkT4M0+@iLlB>B3-LRx{sTtFU%Fc;k zX3s8W^6f4T=V;aL!y9rcV<^LbF>aXN!zu2X_)8&{EX9}y#TQx`<4Fo$7gEA2{SaT? zJd${Ryk8TmV;-iJ(*8HY4al zDMA|NzGZ{rq`h_akEhKwR)pNVz;*eClqcf@mc)WwDJWK{2P@!eF$*{8u-icM12t9z zNPkDxX77Zm{SkwQN9P(xNt1yk%F`b1RPK8PbQgp8Qh4gm+Rw{7lu>D|F(4>VeD^xr z&|LO7GEF}=>~v{}<-_%BT1V1MbwEf_hFULJ|K0#}8m~kY9OU=KiJA=|))&94wyf)= zTUJYu5q?@;gid)_PW|`pn*GfLCWD?UV3Gnqss;694&Jc%&|+|GgaHWhk-`hE`3vcm z`;I1NEi0e=WeSZH?gkb#RCEL^8mTsAbb7IKixG&wh84U+o}=p{-+NVTc-Jl?`POK9 zE+l-D0G;CY;IKTLPp!tkKuG=d7dw-Vlk`T#`{q!-%fDobYXj96!lJlx@Zo5LffeVZ zm-YPdjz&SoE>gkQ8#6ZwM4{1wOzwUQ4{XftjcZn&2%dKjZH$%~ggrVrlBTe+zvpg( z2n2-25V}+00>@EYOmKtPqR~m>-5sN_xv`l@lr?rW827bn5yeBXnCW-7E{FV~am&^@ zQNgi0i>#^JeyY%j%n(B$>$$0pG=KEEIm3o-QB>a?x7vl zHSV9r-8aT4b*i4rc6^mrt*;ExH=k5ibt43Lwl@|($Ie^GTvxZ)#`nX>zQ#jEvz_4* zl-BHmqED7N{iK7cj)crayHLQFw)bOSM!PN?H>KVAw6xDAsB3C0Frawwp3_AI0&X0z|CX zyJLHlGCwpX>DB`j_-8F4jCv6uR4twKAI}Hy^XoFJXJ4WJ?Axpnx*Ac?Z`>`#f9>0U zGr3BdgvFPTaA07NAbe~Q0HRn?Rz;kdf|y5CR!~w|gp)<&BdfF^mzE^Atc<*t>;2WMph;YHea+V_{-!Yhh;a#mU0T(Zb%{4X`qDv~zZ}xAu0h zbaHZXcJpy{_jGr6)pHCnv<GcK4 ztp)LIMG1L1IXQVH1;ypXdD$gJ`K6_0`K2{k70o5(HN}-pWmR>hwXJn!1vTX*%@ujI zRpo89r8PA*)eWt6%^fZEHEqrHEiElMjU#0Z-NhXU+>mDEM9UUF%9hvPNTO1vq?4Dd7o1Pt>S)Cp2 zn;sut1jc%2r^Z(%``2bire|iR=a*&|SC{6d*Oum1R#v-a_eSTpMwj-cS9WLCk5<;V z=C)2&w{})`Pp9`TR}U`M4==YD$4*xI&sK(ZmZ!GXR}a@`4mKC|wpNa}=8tz)ZjRS? z-faJ9|7d6T@c4Lt>-=cvKh^7In8J-vQ7|Mh%zvU7EQbbqmbb9wr3wfAsy z{PK8qb8~Zb_i*#@`{C~D>GAgE<>l=c`}OtJgDc${3=9TKN=#VAefezh)eggy@SXi{ zbXHRK(QH@<_@NI@blaFYo9dY2q1IW#`vp4c6&Ca3^-l%P{@g-=^Jw&6$m%v*z^!-y zy2z!kfykfmDjI8+@(C7Jd|og!PdIY&)qZ*3s5v75 zDJbXj8sTdq8Uks{G??Xd_u<5C6>B{2i5X#jqq4n`uhHP8<7if2D^cmb{z-ylIO_>= zdV+aP=`oHQuZ(}DGDH5ke#xA@#i<4XaAZ5oxRt+a=B3{sJq?32#@!XcpK-8+AQ1|g8)_!Sv76+Byw3q;j3!Kc2q|?s{IYKp49~~g zg9a}5QA$i0PpZQE&GkBgVGr-d$`}uMXCyB^YMLXIDmzB^E`A-dLa`<4?K82a#KmPZc%lwPe3Zfu&Ii_V1${ z8Ra3(_|GqX%2IhVUa1oWjfiQUuOmn%QH4dV)$LNoeQBfG_vg|lI1lS|(?i6pbPg-n zOr=GoW*hh%vlOOnwERKhKISkSg=w!t72(z{4*9lL6Z1c_z720%j|f>31cwuvBY;Lq zO&TEa4)xjFl|E#Y!*nj?0Vw?3EQ{u;IZmByIj9>? zp{1rI=Is)kJuQJEl+U_8Hih2S3TZiHa$Yl!VB9B5G7>((ClHZ9=-cvnt%&hh+-Eqt z1eJMzbgIkj=VN65v@w6M%4>Fbk~8c#vSNeQBrJfd5&;tzOfqE-jMTO(;P4S=rrwWk z9M44VS9mFF#5KN;OKntL;H5rpDo~Li)P4G@8ZzJc0czAnhI1wtIMrYe)mtw-tGe61 zuDjTzxH`>L+wf*B2duwT6QemLD-hMhGS&r~h?ezFG}@7Uvs}wcdq=6Jqj6^)9Xny3 zzEE`+kuhR3QQTq<=qb6$YrQ`7tF~;uqn#ESA6Hh}=cpZ?w95t!a2&Qe?R-<4F4PvS zJCnJ!=-3dmx_2YgeH>n}j>$TdFncZt^li-^rdD4bQ}*JUON@@!PX1iY zscC1h$fN%~j$cwr=O9M+%WW=mnP$Rk$&RCXkwp(r&toMo;H&L052(_14*1oLtz0i(m*n04Pz4< zB~|7Xg^>sf|IMW6|Mm&^UmHXav@Ga093}z_Nj&n0rIiww7po942>6FIsZ^Uq;`lF- z8H?;+N_H#-0mzID^G)UcOOOV=U4wrGRg+W7 zV1oTyJpT*h*I#X&6sYh1PQ*YmWCRdQ;Boe(bpP=Ff8c)s2gQM7$34S>h{)mplE(jF zWPyW7z)5NUe?gW(vE;O*|8pWF|DMF33OYnw3B})&_%9WAo`MVMPp^OLydZo^TJ=A7 z{*xbv{|AoYTL$Xn>|t%{^oJ5xl=;^){*9>gpWMP9_WZw11@xT~U+WL{f9A1>|LyQr z6Tx`HHg$Hkur>b&`u~;ZzU8{O|L6&a2O`172hmU={`DG?*Vh$U--K%hC@?Ure>jSe UgDOaHKvq62U%ROEE+lx0C)%h1n|ei;wqv2zQN!q z)G%EXl0W8@s63eeRS!_ZqChyvdok>MYCxE{dtzPy!(lE0?cG7^A{Q#{+0;w zaELL9QR3caP=168$@&A?AGmBk;-I=p@yb6Hf21KoMp#+nAh30DvLw^I0TmHuVO_z* z^i(f3VfW56z8hr3xy!Xa=oSmtwo|C=iO0JBbMQ_u30#9F*};JFm7$TqN-%f`2W!Zy zbD6j@SeWV>OGPYk5clcR@rsf<4NOeoFH+JZ^hP8Syl1^G8#g8ydk8v@cYKqd)1F<$ z2F}mA%E(f%?KJ;l>8Zb>p1A$EO$nC8e7F>2!|(|O0FXul0RHnE{rMGPb`MyfJ4=<} zjUBDyB|B9-XqPQQ7?ol@VoXX@Oafa5&9tXw^Ga!axL?ra#c%gL&guo4b`jw_$z(eH z4~%+hw+1OjT0+00#))mLCw;evs~j7jwv%GNTV641xn}JOtqg3)(tJvl7Gl<0?k7Qq zjEZ284MKn1hu*2ln%8W~q#!d4HPbLJ2p*X6pgWl^dLV05K$+}%`P|rkDa$R_5+jt`})P>gMHI7;% z=#{C;UM~mD<$VqFFQoa?-7VD|oibvR`~C1Aua-rIc8CK#>;fp_ zx~B;nyw$ZjC#AI0CNHjpFgIFHDAF(^{ojo)SP(}SlHqG5qI>$RU;cCr<5$uPu`V}z z_pY8%LeJruj!~f|p`0u}Gt_dSEORvMqc~wGziblsmbqNQ^-0b4u=NokJU=N6V80SYV;9d)o1Y$mC~NFa=V7DM%*h#NO@3%zIHZOZ3q z%1o8JIn;1`>fPas>ElS1Epfkh@x#UfYSu4s#z2-A$;ybp{E(cG92b*3 z_A8?ok9J#+Uc3z;Nz_JpObD|66>#mn_079?G$@nhEABI?`WQAQnQR>Kq52+|0DQHV z{F7(<;Zy2HBCc7vyf|c<%q)%zJZ6en$XySgsWEt>eORftN*T1EQPfUK2Re4Tkr$<| z_*C8E0$smzZ(uT68h$17@>AxZjDQ*LDUG@#>czw$Q+S36*8#rJRnd? zHDEcql8roD4>9kf{S)cUlFNAYE;OXQtGVzyaWa1;!l%&h3eQft8p1~X`6d(@LIxiP zoF{Um2;xk&`w|1?4#Qib;BWpS~BS`&rr83>F z8DZ}M9HygLK;Jki^JPuqTTGKykvePyUV-Dn1h-Hg@Y%*#QO3nda-K&hSI-&Kk!CKC zXaT595)PGQSmQm})XLsWmI^sIE2;ZNw`$NqG)XJ?kV&z(e1YHM`p^P>ZzEna__Fp1 z$bH89Zu@F+>x^HSVh$clB#y`T^Q}^ho74-SoS^cHS)|~vN?eLJSkrg{p0fc}0=xFj zEVjo=)9calI+>qKXx(-)iagY=nx0B8>zGMesRlyXeg>IUES&|vavOLKKD(8f3vBl{ z?qmh<_p;T_V>+WT{P^W6J518ngL3=onc5j|DvhcGj`D;>9qHjiFGf5yZ$#{qP4k^k z(gh`v>DzdN&#S(&uN}hUS@$@~t)k{aTLULO?{X%`qPymIP0NMJCdM;>4=yCv2m2ir zWeYN(4`!5vi3PaPLq8NKWVi_WT!x;AUDUlP+H0*X+zg5Rs;bJRIsEliQg>dP&qb?7Q-O4}xNUk?rtC=H*pi#w`B-s0mDaEI}l zx%=8QI`yI0*ghkd(Zd~=v@H`5oA28Dwk-RY7CP$n%=(x&ini@&wuxoNGoaBc<4%!K zdS~eRMm#vCDJ80?-cYtia7=;{z|2KBWgpl#Gu;*=0SlHE3P_6?@fIQbwY_`F8L2r8xW+?S6A2 zrJ4!HgJJ*xs-S=GPDVHs&^;~L=oub@rZbJF%tPezI#q~@`gy>dIKFLFupJhV(J52B zmtHg!ReEY3xZ)GKxx_QkJr>R_xaF+MG0O^mnL zG5a}jWuOFXXuMidr+*YZ<=_Pt}M^6oBcY~}WXGZN@{edOpW1;?5Ux2DI0dA^2WNt<_J4$sdMEOG&~%npStJ`AYdEFv1M3gxbT_lvBuTkC$xvjRodE zS+q9XAQ!7#dT|bkt0t><^?&Y~KuIU($UaFK(0a3hX}sfThzz(nQEJPi&1Z-Du|X8l zWG3{<#KRtf6ujR=WG-aZztlj4<9h-xlX?QH8l`h(&JrA;CSQNF{Nh)c#Uet9e+!WQ z)FQ$m*8_0`5AmOgbp*>O?|hk{tLV0zqF4A@Z5$pIv=Z>sTCR)sJx8QQ+N14_1hE1k zw;maH6}z>Yk^N%iDz4TAB|fH|tc7@;aj!t@5R*X~yMyzYwa6YY_+jPZVUa^>c9e7J zlU)h{FdOwM)B-3)JeC-wfK6>aGV*}t`eEw+;dzPPucpUuN*tcCWO!Hi63#K1r~Hbd z_3oM+{}u41RqMD;lB#3vm(h=5Ma4QpaA$?9-ot?UOFJ;(c#W3SVw4{tA(xmI>&cw0 zmj1v|CZt+K6XSqyv`}_=G1T-e&KDhA`C1Qs4B=SaZRqD{hc#pN&97A+mFA>Cl=z%^ zN4P*pTI$n^CQw-YQQPNCdfr)_=aY%1rnsCpvr&FRs~Je6t)#N6cVt_l95r`)XRRYX zFY8SfJ13W#AR0Tl?1Y1)(Xk^VK!0yHNa$J(hq|LXE`Yv}@dxWy&`daEFh+m;k{mu^ zttOL%5Hy=O;0WX6xC^}8|9}rEDMS&3U{rW^N0RPqR~VfdS5IqP_QPDwZmJV^We3;A zZ`k2AcI)|0Aof5^KdxfvTU)Cfto83RF(VB-oxnOF6-EY|Aem6i#2C?J+I(%i1Xz$$ zI`)z7VL|1TC!kt7UIyz^ps4w29P>U~gtZB13woSY+Vb*&=xGp#v%AixDwAA-5^So0 z2&5+B^`@MML@X5xeI_=&m?f2#@q0sJodArFhUzW&k7ouIvfOlsk{Ju}m0t4BAy5;Q zyjd%v#bO}3eFC3{s2@EWF7!}*J4gBzSdXGF!VMlI<-mFEs!D5_!VKi12J6VCx4$sb zk$^JDP5%%w#=QL5muC(jP+~XDa3&a+5IGMJ@ws|kjv2PA;A>&$c-pK3DZV-y--KG* zx+WqIS{n@=4wXWoz5{o6O45OJ^qadaZ)|v?+D33>An#hJOT~-@$*vp$i>{1v8}umNl zRP<(c#CX!?8V+q*@jUZHfD&BIL0By;2{jv3VI@2vUo7ym+0(qLFoGL8s6J)9frflR zkTk5I zEY`$(3DYPuG?rJ+>N|b!H;A+wHGNHs7NYJdpl2`db8l$R&mzSK000@)zf!Lf;Licm zBqD(>I8XBt_%=7wthl#D=jyIVZxT#X)cy!+rQ17|pTxGLv3V00kp;bx<}oFl*ne!o zvDg0wRF!8xQKY!A->ciC6TEBsKva2EL*c4&Ee&wSkqL2Jn^m+Yvrl(#6n^0-lrL0+ za_RU`mz$0;FSwiNO}gxaq)@(>C~Hl)nDQ3XiO}CA;lLOj!aLw2G%X)#<~|;A^o_-$ zKy{TTRXQ$>-XfooWZ+k4r#P2S9eG%YA{wsSy4LHO5$kkb#7_S3)>u=N?EQ*| zkW1S93%vS?13kM1(A7vLmMBpwY|qwYw|DqOJquQk%4k})=gSR2u(SovC2BX2*5V8b zwxzj=aaudkP8y&T(SIQ5Ut1Ay{Sm`j3w_RaX4?%fh!Rzg6aW#x-brz!V{8nZQud#*!U6XNLU=&y)hOO%(&^k8pi(8SkFn2gMJ(I zRDoLt9>J4|AK2+R%1T~Y*yYFC(!HZNTuN`uyxofe zgrFbzSer`NAtyc0<+UMfP9_>=8Ae1yyeh30`~gR^S!LW&3&D<3(4#i3V+n$Pb@M!L z!&m`(yv%suB5qc2#r@%lfI-4*QV3K&uX=badQ>8kMin7L z0Xo!F!w&!0r-X$aK9)WA$*fp_6;YhIeBIL;A+?!dprX*xWpzuFGHzaASf95ksl?2+ z{6=Z@A$jGX_L9dIB#;i8yy+9B4P#?<5?1G<>W?N>%A$|q#U6r+GlmlS$24$EU1MH4{eLyurRtF1-C1Q>^F!fYe{f z<nO{qsHm!_>!@q$>8h)0X=v+e zYb&T4%IdsV(J)ljHU;ay*VZ%DF|yXOa5t0}HCLB0(oi#=qXql zX}g$eS(=-h+PK;{dAnE{IoZ3oJHB^uc6M>|a`W)=a&`9baP#(t=sN`&+WDI~`4n*;$gIeUoVbd-Pqkm-8ot8niqmqkvvcwaz7)U<^K(mz z@{5b%ImL*alA40Tvb^%fB1Ap1I2VB^YC_~SAc~O4s>Gs}^op*pHQx%FMk*V-YTJ5| zonz&lQ}xiUAC0{uO~Z4I!z*p@ ztz@*LVyLTrth;KYr*W#Qe72`*roVn=sIj}Jr>$?KWni**aOm66MElTm&+us9=*(z; z`|x1T)L`52P~XDHx4F^YiHY%!v98_obo|Wn0#kr}&x$cd{iIv6K-Q|hh)tTe9;gjvT)z#(Y_09FImDR1i z&9&vd?UkLK?Tx*|rQ_S(!_%FUi~aMP8Nd)!STK{i@n~Vt;V+ypijyd7*X#(F|?867W{Q_ev~%j`zK+PsHZ4*qvc)Itu>W zo~B?&>!odD$rPfY+xE8TT0=+QM4UfrbmGAb5;7R;rXi4s&;A+P=hF#4{^d;hS=4yy zr5^HNAVpv_YHhIiOign8b2Sms<=v>eVBh7+BY(j{U+R?A+s`9SZ*mPXi(iP#x9HpTcD5HyOf84FQP4?CJj6Eu3~sxLzs)&-&n zBDtOQSEt=HOwJQbH?A72Z#G-}7u64wKF`hCkKk`dJT^a&7JE?IExLI|#q4mZ4g+PU zv1DKA2-p3()^T|io7->_3nIc2WkrLE6PYU_w)8fW-+Gl#U1F1++UOB{RC|SIpYV*v z_j1}$<|gs;ZL(>o${3+rO9-vHd-Z%Rom?`ngTN41rDZdCJH%eLcM|Vc#vGeY3vy z!7{ENXz2{{rc2A`Bdzi(#q$c+VP9lrFRUbb7wp84{vG2q&zUf{?dbRcq#^}+dRPw#%d2HDl#l~7117mbkA;l&X>(7_SJ=3FA&Hr zsIl7hq>hpnyhwYCI}G{d+uvz&P&uH^>-kDjcj+_3>o;BlIo4);b-Ik#J;ZP{E(UiO zsXqH!PIsO|&l1Gax3}xY8tEN^8-P2p{2y)euiSTbrV`jhx7d1arjb?!Dn3)6N!XU-SCHGxy8EmlK#N_x12TxGu?XVkgffOI8MA4Ub{S6SUy znd3DZ+1dg^6=YczEZ$K@R;SpYI~9-_LzR3NRc8E5o+3IY~STh zlN|%@j%L<$TXRBxK0i=dPn@zCD!g3c@v(-Kv7djP%jJzZ@!A#nq&3Vl`O!DImDq{q zgY`9z>xW9F@~}9M_;sQ___O8`kJaLUXn}UjHzg1Kh0pvUyNbr1&`cyE&j5pqyy`Nf zX8x*iuyLY!lS9a-QdD=1&3!{@RxXEF4pIGnij4!&R&EjXfPwzx`v;-$H*%`U@?_j8 ziOjg8&%cvaXvkhZaO{G(;fu3qa+T6u!QGkm%vfwMh1c`3{Yz5|4<@XRAoZ-wAw2r5 z4>LFCbtwjl(Zg63p-Af- zvHAwwgpYTGr!h)N^1N=-yVpm+^IGL6*-L(o0Kv|tiq2?(cOObPo3~%m)8liw?Fe9X zDv-X^Tg<8!gWEgteisZvmM zb>WUIFP?*YxN)am&+*yoIS&kZFOfE>DL+?3FoK1bMRikj?7Bhtsrq+TRa80#rK-$2 z-MNjqswFlH4bxH`{8s#Vs)fAF2~$Z)<|8S2!55~(klZ|#LyX?b4nHCyug$FB=YP9E z|F!=Ay;S>0H2?3XUs`NlV$vro@jYAT-n#G7q{S7)N<u!VL|k~xcAZh#dpDa>6tX{C4WC-#QH1N`-%SV_Sf0P^Szn#3lH1( zVA=n?kU#k`rN1}G*#Gb&hRHCHY2Rc2z0Sq?hfVt9-`Hj@E>?CH|3LqrI{0@j{PZ85 qXe6*E270P{_~iL{FvoB5?!J^J{)bTiUh{wUMTX@7 diff --git a/test/test-sizes-atomic-stdostream.cpp b/test/test-sizes-atomic-stdostream.cpp new file mode 100644 index 0000000..e1886ba --- /dev/null +++ b/test/test-sizes-atomic-stdostream.cpp @@ -0,0 +1,118 @@ +// +// Created by balazs on 2020. 12. 03.. +// + +#include "LogAppInterfaceStd.h" +#include "LogConverterCustomText.h" +#include "LogSenderStdOstream.h" +#include "LogSenderVoid.h" +#include "LogQueueVoid.h" +#include "LogQueueStdBoost.h" +#include "LogMessageCompact.h" +#include "Log.h" +#include +#include + +#include + +// clang++ -std=c++20 -Isrc -Icpp-memory-manager -Os -Wl,-Map,test-sizes.map -demangle test/test-sizes-stdthreadostream.cpp -lpthread -o test-sizes +// clang++ -std=c++20 -Isrc -Icpp-memory-manager -Os -S -fno-asynchronous-unwind-tables -fno-dwarf2-cfi-asm -masm=intel test/test-sizes.cpp -o test-sizes.s +// llvm-size-10 test-sizes + +constexpr size_t cgThreadCount = 0; + +constexpr nowtech::log::TaskId cgMaxTaskCount = cgThreadCount + 1; +constexpr bool cgAllowRegistrationLog = true; +constexpr bool cgLogFromIsr = false; +constexpr size_t cgTaskShutdownSleepPeriod = 100u; +constexpr bool cgArchitecture64 = true; +constexpr uint8_t cgAppendStackBufferSize = 100u; +constexpr bool cgAppendBasePrefix = true; +constexpr bool cgAlignSigned = false; +using AtomicBufferType = int32_t; +constexpr size_t cgAtomicBufferExponent = 14u; +constexpr AtomicBufferType cgAtomicBufferInvalidValue = 1234546789; +constexpr size_t cgTransmitBufferSize = 123u; +constexpr size_t cgPayloadSize = 8u; +constexpr bool cgSupportFloatingPoint = true; +constexpr size_t cgQueueSize = 444u; +constexpr nowtech::log::LogTopic cgMaxTopicCount = 2; +constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cName; +constexpr nowtech::log::ErrorLevel cgErrorLevel = nowtech::log::ErrorLevel::Error; + +constexpr size_t cgDirectBufferSize = 43u; +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; +using LogMessage = nowtech::log::MessageCompact; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStdOstream; +using LogQueue = nowtech::log::QueueVoid; +using LogAtomicBuffer = nowtech::log::AtomicBufferOperational; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; +/* + text data bss dec hex filename + 12803 1053 520 14376 3828 test-sizes +*/ + +/* No log call present at all, not even cout.write, only thread creation: + text data bss dec hex filename + 3267 820 4 4091 ffb test-sizes +*/ + +/*constexpr size_t cgDirectBufferSize = 43u; +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; +using LogMessage = nowtech::log::MessageCompact; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderVoid; +using LogQueue = nowtech::log::QueueVoid; +using LogAtomicBuffer = nowtech::log::AtomicBufferOperational; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; +text data bss dec hex filename + 3267 820 4 4091 ffb test-sizes + */ + +/*constexpr size_t cgDirectBufferSize = 0u; +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; +using LogMessage = nowtech::log::MessageCompact; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStdOstream; +using LogQueue = nowtech::log::QueueStdBoost; +using LogAtomicBuffer = nowtech::log::AtomicBufferOperational; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; + text data bss dec hex filename + 23734 1277 920 25931 654b test-sizes + */ + +int32_t gInt32 = 4; + +void todo() noexcept { + gInt32 = getpid(); +} + +int main() { + std::thread thread(todo); + thread.join(); + + nowtech::log::LogFormatConfig logConfig; + LogSender::init(&std::cout); +// LogSender::init(); + Log::init(logConfig); + Log::registerCurrentTask("main"); + + Log::pushAtomic(gInt32); + Log::sendAtomicBuffer(); + + Log::unregisterCurrentTask(); + Log::done(); + + return gInt32; +} + diff --git a/test/test-sizes-stdthreadostream.cpp b/test/test-sizes-stdthreadostream.cpp index f3cbab8..454e555 100644 --- a/test/test-sizes-stdthreadostream.cpp +++ b/test/test-sizes-stdthreadostream.cpp @@ -16,7 +16,7 @@ #include -// clang++ -std=c++20 -Isrc -Icpp-memory-manager -Os -Wl,-Map,test-sizes.map -demangle test/test-sizes.cpp -lpthread -o test-sizes +// clang++ -std=c++20 -Isrc -Icpp-memory-manager -Os -Wl,-Map,test-sizes.map -demangle test/test-sizes-stdthreadostream.cpp -lpthread -o test-sizes // clang++ -std=c++20 -Isrc -Icpp-memory-manager -Os -S -fno-asynchronous-unwind-tables -fno-dwarf2-cfi-asm -masm=intel test/test-sizes.cpp -o test-sizes.s // llvm-size-10 test-sizes @@ -28,31 +28,37 @@ nowtech::log::TopicInstance surplus; } constexpr nowtech::log::TaskId cgMaxTaskCount = cgThreadCount + 1; +constexpr bool cgAllowRegistrationLog = true; constexpr bool cgLogFromIsr = false; constexpr size_t cgTaskShutdownSleepPeriod = 100u; constexpr bool cgArchitecture64 = true; constexpr uint8_t cgAppendStackBufferSize = 100u; constexpr bool cgAppendBasePrefix = true; constexpr bool cgAlignSigned = false; +using AtomicBufferType = int32_t; +constexpr size_t cgAtomicBufferExponent = 14u; +constexpr AtomicBufferType cgAtomicBufferInvalidValue = 1234546789; constexpr size_t cgTransmitBufferSize = 123u; constexpr size_t cgPayloadSize = 8u; constexpr bool cgSupportFloatingPoint = true; constexpr size_t cgQueueSize = 444u; constexpr nowtech::log::LogTopic cgMaxTopicCount = 2; constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cName; - +constexpr nowtech::log::ErrorLevel cgErrorLevel = nowtech::log::ErrorLevel::Error; /*constexpr size_t cgDirectBufferSize = 43u; -using LogAppInterfaceStd = nowtech::log::AppInterfaceStd; -constexpr typename LogAppInterfaceStd::LogTime cgTimeout = 123u; -constexpr typename LogAppInterfaceStd::LogTime cgRefreshPeriod = 444; +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; using LogMessage = nowtech::log::MessageVariant; -using LogConverterCustomText = nowtech::log::ConverterCustomText; -using LogSender = nowtech::log::SenderStdOstream; -using LogQueue = nowtech::log::QueueVoid; -using Log = nowtech::log::Log; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStdOstream; +using LogQueue = nowtech::log::QueueVoid; +using LogAtomicBuffer = nowtech::log::AtomicBufferVoid; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; text data bss dec hex filename - 15182 1101 496 16779 418b test-sizes + 15118 1101 496 16715 414b test-sizes */ /* No log call present at all, not even cout.write, only thread creation: @@ -60,45 +66,51 @@ using Log = nowtech::log::Log; -constexpr typename LogAppInterfaceStd::LogTime cgTimeout = 123u; -constexpr typename LogAppInterfaceStd::LogTime cgRefreshPeriod = 444; +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; using LogMessage = nowtech::log::MessageVariant; -using LogConverterCustomText = nowtech::log::ConverterCustomText; -using LogSender = nowtech::log::SenderVoid; -using LogQueue = nowtech::log::QueueVoid; -using Log = nowtech::log::Log; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderVoid; +using LogQueue = nowtech::log::QueueVoid; +using LogAtomicBuffer = nowtech::log::AtomicBufferVoid; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; text data bss dec hex filename 3283 828 4 4115 1013 test-sizes */ -/*constexpr size_t cgDirectBufferSize = 0u; -using LogAppInterfaceStd = nowtech::log::AppInterfaceStd; -constexpr typename LogAppInterfaceStd::LogTime cgTimeout = 123u; -constexpr typename LogAppInterfaceStd::LogTime cgRefreshPeriod = 444; +/* +constexpr size_t cgDirectBufferSize = 0u; +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; using LogMessage = nowtech::log::MessageVariant; -using LogConverterCustomText = nowtech::log::ConverterCustomText; -using LogSender = nowtech::log::SenderStdOstream; -using LogQueue = nowtech::log::QueueStdBoost; -using Log = nowtech::log::Log; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStdOstream; +using LogQueue = nowtech::log::QueueStdBoost; +using LogAtomicBuffer = nowtech::log::AtomicBufferVoid; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; text data bss dec hex filename - 25766 1285 896 27947 6d2b test-sizes + 26086 1285 896 28267 6e6b test-sizes */ constexpr size_t cgDirectBufferSize = 0u; -using LogAppInterfaceStd = nowtech::log::AppInterfaceStd; -constexpr typename LogAppInterfaceStd::LogTime cgTimeout = 123u; -constexpr typename LogAppInterfaceStd::LogTime cgRefreshPeriod = 444; +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; using LogMessage = nowtech::log::MessageCompact; -using LogConverterCustomText = nowtech::log::ConverterCustomText; -using LogSender = nowtech::log::SenderStdOstream; -using LogQueue = nowtech::log::QueueStdBoost; -using Log = nowtech::log::Log; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStdOstream; +using LogQueue = nowtech::log::QueueStdBoost; +using LogAtomicBuffer = nowtech::log::AtomicBufferVoid; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; /* text data bss dec hex filename - 24134 1285 896 26315 66cb test-sizes + 24458 1285 896 26639 680f test-sizes */ uint32_t cgUint32 = 3; @@ -115,8 +127,7 @@ int main() { std::thread thread(todo); thread.join(); - nowtech::log::LogConfig logConfig; - logConfig.allowRegistrationLog = true; + nowtech::log::LogFormatConfig logConfig; LogSender::init(&std::cout); // LogSender::init(); Log::init(logConfig); diff --git a/test/test-stdostream.cpp b/test/test-stdostream.cpp index 55cd613..4050a3f 100644 --- a/test/test-stdostream.cpp +++ b/test/test-stdostream.cpp @@ -54,44 +54,61 @@ namespace nowtech::LogTopics { } constexpr nowtech::log::TaskId cgMaxTaskCount = cgThreadCount + 1; +constexpr bool cgAllowRegistrationLog = true; constexpr bool cgLogFromIsr = false; constexpr size_t cgTaskShutdownSleepPeriod = 100u; constexpr bool cgArchitecture64 = true; constexpr uint8_t cgAppendStackBufferSize = 100u; constexpr bool cgAppendBasePrefix = true; constexpr bool cgAlignSigned = false; +using AtomicBufferType = int32_t; +constexpr size_t cgAtomicBufferExponent = 14u; +constexpr AtomicBufferType cgAtomicBufferInvalidValue = 1234546789; constexpr size_t cgTransmitBufferSize = 123u; -constexpr size_t cgPayloadSize = 8u; +constexpr size_t cgPayloadSize = 14u; constexpr bool cgSupportFloatingPoint = true; constexpr size_t cgQueueSize = 444u; constexpr nowtech::log::LogTopic cgMaxTopicCount = 2; constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cName; constexpr size_t cgDirectBufferSize = 43u; +constexpr nowtech::log::ErrorLevel cgErrorLevel = nowtech::log::ErrorLevel::Error; -using LogAppInterfaceStd = nowtech::log::AppInterfaceStd; -constexpr typename LogAppInterfaceStd::LogTime cgTimeout = 123u; -constexpr typename LogAppInterfaceStd::LogTime cgRefreshPeriod = 444; +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; using LogMessage = nowtech::log::MessageVariant; using LogConverterCustomText = nowtech::log::ConverterCustomText; -using LogSenderStdOstream = nowtech::log::SenderStdOstream; -using LogQueueVoid = nowtech::log::QueueVoid; -using Log = nowtech::log::Log; - +using LogSenderStdOstream = nowtech::log::SenderStdOstream; +using LogQueueVoid = nowtech::log::QueueVoid; +using LogAtomicBuffer = nowtech::log::AtomicBufferOperational; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; + void delayedLog(size_t n) { Log::registerCurrentTask(cgThreadNames[n]); Log::i(nowtech::LogTopics::system) << n << ": " << 0 << Log::end; - for(int64_t i = 1; i < 13; ++i) { + for(int64_t i = 1; i < 3; ++i) { std::this_thread::sleep_for(std::chrono::milliseconds(1 << i)); Log::i(nowtech::LogTopics::system) << n << ". thread delay logarithm: " << LC::X1 << i << Log::end; } Log::unregisterCurrentTask(); } +std::atomic gCounter; +constexpr int32_t cgAtomicCount = 100; + +void atomicLog(size_t n) { + Log::registerCurrentTask(cgThreadNames[n]); + for(int32_t i = 0; i < cgAtomicCount; ++i) { + Log::pushAtomic(gCounter++); + } + Log::unregisterCurrentTask(); +} + int main() { std::thread threads[cgThreadCount]; - nowtech::log::LogConfig logConfig; - logConfig.allowRegistrationLog = true; + nowtech::log::LogFormatConfig logConfig; LogSenderStdOstream::init(&std::cout); Log::init(logConfig); @@ -146,10 +163,18 @@ int main() { for(size_t i = 0; i < cgThreadCount; ++i) { threads[i].join(); } - Log::unregisterCurrentTask(); - Log::done(); + gCounter = 0; + for(size_t i = 0; i < cgThreadCount; ++i) { + threads[i] = std::thread(atomicLog, i); + } + for(size_t i = 0; i < cgThreadCount; ++i) { + threads[i].join(); + } + Log::sendAtomicBuffer(); + Log::unregisterCurrentTask(); + Log::done(); return 0; } diff --git a/test/test-stdthreadostream.cpp b/test/test-stdthreadostream.cpp index 6daefbe..77242c2 100644 --- a/test/test-stdthreadostream.cpp +++ b/test/test-stdthreadostream.cpp @@ -184,7 +184,6 @@ int main() { } gCounter = 0; - for(size_t i = 0; i < cgThreadCount; ++i) { threads[i] = std::thread(atomicLog, i); } @@ -193,7 +192,6 @@ int main() { } Log::sendAtomicBuffer(); Log::n() << Log::end; - std::this_thread::sleep_for(std::chrono::seconds(2)); Log::unregisterCurrentTask(); Log::done(); From a848405521568f02524d616997567c406c135556 Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Fri, 1 Jan 2021 10:22:18 +0100 Subject: [PATCH 15/27] Updated benchmarks. --- README.md | 30 ++++++--------------- benchmark/picobench-direct.cpp | 41 +++++++++++++++++++---------- benchmark/picobench-msg-compact.cpp | 28 +++++++++++--------- benchmark/picobench-msg-variant.cpp | 28 +++++++++++--------- test/test-stdostream.cpp | 2 +- 5 files changed, 68 insertions(+), 61 deletions(-) diff --git a/README.md b/README.md index 1204aae..5af0dd2 100644 --- a/README.md +++ b/README.md @@ -170,10 +170,17 @@ Each value is the average time required for _one_ log call in nanoseconds. |Scenario |Unknown `TaskId` (ns)|Provided `TaskId` (ns)| |-------------------------|--------------------:|---------------------:| -|direct |250 |160 | +|direct |250 |190 | |Constant string (no copy)|500 |430 | |Transient string (copy) |580 |500 | +Here are benchmark results of atomic logging `int32_t` values, measured on 2097152 iterations. Note that this does not include offline buffer sending, so it is the same for any logger mode: + +|Scenario |Atomic (ns)| +|-------------------------|----------:| +|any |7 | + + ## Space requirements I have investigated several scenarios using simple applications which contain practically nothing but a task creation apart of the logging. This way I could measure the net space required by the log library and its necessary supplementary functions like std::unordered_set or floating-point emulation for log10. @@ -206,27 +213,6 @@ No floating point arithmetics in the application and the support is turned off i |MessageVariant|6440 |12 | 80 | |MessageCompact|6192 |12 | 80 | -### x86 STL with floating point, only chained log - -Not much point to calculate size growth here, but why not? Source is *test-sizes-stdthreadostream.cpp* - -|Scenario | Text| Data| BSS| -|--------------|------:|-----:|------:| -|direct |11835 | 273 |492 | -|off |0 |0 |0 | -|MessageVariant|22803 | 457 |892 | -|MessageCompact|21175 |457 | 892 | - -### x86 STL with floating point, only atomic log - -Not much point to calculate size growth here, but why not? Source is *test-sizes-stdthreadostream.cpp* - -|Scenario | Text| Data| BSS| -|--------------|------:|-----:|------:| -|direct |9536 | 233 |516 | -|off |0 |0 |0 | -|multithreaded |20467 |457 | 916 | - ## API ### Supported types diff --git a/benchmark/picobench-direct.cpp b/benchmark/picobench-direct.cpp index b828348..983a5f5 100644 --- a/benchmark/picobench-direct.cpp +++ b/benchmark/picobench-direct.cpp @@ -1,5 +1,6 @@ #define PICOBENCH_IMPLEMENT #define PICOBENCH_DEFAULT_SAMPLES 10 +#define PICOBENCH_DEFAULT_ITERATIONS { 64, 512, 4096, 32768, 262144, 2097152 } #include "picobench/picobench.hpp" #include "LogAppInterfaceStd.h" @@ -13,31 +14,36 @@ #include "Log.h" #include - constexpr nowtech::log::TaskId cgMaxTaskCount = 1; +constexpr bool cgAllowRegistrationLog = true; constexpr bool cgLogFromIsr = false; constexpr size_t cgTaskShutdownSleepPeriod = 100u; constexpr bool cgArchitecture64 = true; constexpr uint8_t cgAppendStackBufferSize = 100u; constexpr bool cgAppendBasePrefix = true; constexpr bool cgAlignSigned = false; +using AtomicBufferType = int32_t; +constexpr size_t cgAtomicBufferExponent = 14u; +constexpr AtomicBufferType cgAtomicBufferInvalidValue = 1234546789; constexpr size_t cgTransmitBufferSize = 123u; -constexpr size_t cgPayloadSize = 8u; +constexpr size_t cgPayloadSize = 14u; constexpr bool cgSupportFloatingPoint = true; constexpr size_t cgQueueSize = 444u; constexpr nowtech::log::LogTopic cgMaxTopicCount = 2; constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cName; -constexpr nowtech::log::ErrorLevel cgRequiredLevel = nowtech::log::ErrorLevel::Info; +constexpr size_t cgDirectBufferSize = 1234u; +constexpr nowtech::log::ErrorLevel cgErrorLevel = nowtech::log::ErrorLevel::Info; -constexpr size_t cgDirectBufferSize = 1024u; -using LogAppInterfaceStd = nowtech::log::AppInterfaceStd; -constexpr typename LogAppInterfaceStd::LogTime cgTimeout = 123u; -constexpr typename LogAppInterfaceStd::LogTime cgRefreshPeriod = 444; +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; using LogMessage = nowtech::log::MessageVariant; -using LogConverterCustomText = nowtech::log::ConverterCustomText; -using LogSender = nowtech::log::SenderStdOstream; -using LogQueue = nowtech::log::QueueVoid; -using Log = nowtech::log::Log; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStdOstream; +using LogQueue = nowtech::log::QueueVoid; +using LogAtomicBuffer = nowtech::log::AtomicBufferOperational; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; nowtech::log::TaskId gTaskId; @@ -48,11 +54,17 @@ void nowtechLogRef(picobench::state& s) { } PICOBENCH(nowtechLogRef); +void nowtechLogAtomic(picobench::state& s) { + for (auto _ : s) { + Log::pushAtomic(gTaskId); + } +} +PICOBENCH(nowtechLogAtomic); + int main(int argc, char* argv[]) { - nowtech::log::LogConfig logConfig; - logConfig.allowRegistrationLog = false; - std::ofstream out("tmp"); + nowtech::log::LogFormatConfig logConfig; + std::ofstream out("/tmp/x"); LogSender::init(&out); Log::init(logConfig); Log::registerCurrentTask("main"); @@ -61,6 +73,7 @@ int main(int argc, char* argv[]) picobench::runner r; r.parse_cmd_line(argc, argv); auto ret = r.run(); + Log::sendAtomicBuffer(); Log::unregisterCurrentTask(); Log::done(); return ret; diff --git a/benchmark/picobench-msg-compact.cpp b/benchmark/picobench-msg-compact.cpp index 2b6102f..e4c98a6 100644 --- a/benchmark/picobench-msg-compact.cpp +++ b/benchmark/picobench-msg-compact.cpp @@ -14,31 +14,36 @@ #include #include - constexpr nowtech::log::TaskId cgMaxTaskCount = 1; +constexpr bool cgAllowRegistrationLog = true; constexpr bool cgLogFromIsr = false; constexpr size_t cgTaskShutdownSleepPeriod = 100u; constexpr bool cgArchitecture64 = true; constexpr uint8_t cgAppendStackBufferSize = 100u; constexpr bool cgAppendBasePrefix = true; constexpr bool cgAlignSigned = false; +using AtomicBufferType = int32_t; +constexpr size_t cgAtomicBufferExponent = 14u; +constexpr AtomicBufferType cgAtomicBufferInvalidValue = 1234546789; constexpr size_t cgTransmitBufferSize = 444444u; constexpr size_t cgPayloadSize = 8u; constexpr bool cgSupportFloatingPoint = true; constexpr size_t cgQueueSize = 444444u; constexpr nowtech::log::LogTopic cgMaxTopicCount = 2; constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cName; -constexpr nowtech::log::ErrorLevel cgRequiredLevel = nowtech::log::ErrorLevel::Info; - constexpr size_t cgDirectBufferSize = 0u; -using LogAppInterfaceStd = nowtech::log::AppInterfaceStd; -constexpr typename LogAppInterfaceStd::LogTime cgTimeout = 123u; -constexpr typename LogAppInterfaceStd::LogTime cgRefreshPeriod = 444; +constexpr nowtech::log::ErrorLevel cgErrorLevel = nowtech::log::ErrorLevel::Info; + +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; using LogMessage = nowtech::log::MessageCompact; -using LogConverterCustomText = nowtech::log::ConverterCustomText; -using LogSender = nowtech::log::SenderStdOstream; -using LogQueue = nowtech::log::QueueStdBoost; -using Log = nowtech::log::Log; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStdOstream; +using LogQueue = nowtech::log::QueueStdBoost; +using LogAtomicBuffer = nowtech::log::AtomicBufferOperational; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; nowtech::log::TaskId gTaskId; @@ -58,8 +63,7 @@ PICOBENCH(nowtechLogCopy); int main(int argc, char* argv[]) { - nowtech::log::LogConfig logConfig; - logConfig.allowRegistrationLog = false; + nowtech::log::LogFormatConfig logConfig; std::ofstream out("tmp"); LogSender::init(&out); Log::init(logConfig); diff --git a/benchmark/picobench-msg-variant.cpp b/benchmark/picobench-msg-variant.cpp index f497058..dac5180 100644 --- a/benchmark/picobench-msg-variant.cpp +++ b/benchmark/picobench-msg-variant.cpp @@ -14,31 +14,36 @@ #include #include - constexpr nowtech::log::TaskId cgMaxTaskCount = 1; +constexpr bool cgAllowRegistrationLog = true; constexpr bool cgLogFromIsr = false; constexpr size_t cgTaskShutdownSleepPeriod = 100u; constexpr bool cgArchitecture64 = true; constexpr uint8_t cgAppendStackBufferSize = 100u; constexpr bool cgAppendBasePrefix = true; constexpr bool cgAlignSigned = false; +using AtomicBufferType = int32_t; +constexpr size_t cgAtomicBufferExponent = 14u; +constexpr AtomicBufferType cgAtomicBufferInvalidValue = 1234546789; constexpr size_t cgTransmitBufferSize = 444444u; constexpr size_t cgPayloadSize = 8u; constexpr bool cgSupportFloatingPoint = true; constexpr size_t cgQueueSize = 444444u; constexpr nowtech::log::LogTopic cgMaxTopicCount = 2; constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cName; -constexpr nowtech::log::ErrorLevel cgRequiredLevel = nowtech::log::ErrorLevel::Info; - constexpr size_t cgDirectBufferSize = 0u; -using LogAppInterfaceStd = nowtech::log::AppInterfaceStd; -constexpr typename LogAppInterfaceStd::LogTime cgTimeout = 123u; -constexpr typename LogAppInterfaceStd::LogTime cgRefreshPeriod = 444; +constexpr nowtech::log::ErrorLevel cgErrorLevel = nowtech::log::ErrorLevel::Info; + +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; using LogMessage = nowtech::log::MessageVariant; -using LogConverterCustomText = nowtech::log::ConverterCustomText; -using LogSender = nowtech::log::SenderStdOstream; -using LogQueue = nowtech::log::QueueStdBoost; -using Log = nowtech::log::Log; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStdOstream; +using LogQueue = nowtech::log::QueueStdBoost; +using LogAtomicBuffer = nowtech::log::AtomicBufferOperational; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; nowtech::log::TaskId gTaskId; @@ -58,8 +63,7 @@ PICOBENCH(nowtechLogCopy); int main(int argc, char* argv[]) { - nowtech::log::LogConfig logConfig; - logConfig.allowRegistrationLog = false; + nowtech::log::LogFormatConfig logConfig; std::ofstream out("tmp"); LogSender::init(&out); Log::init(logConfig); diff --git a/test/test-stdostream.cpp b/test/test-stdostream.cpp index 4050a3f..a875bc0 100644 --- a/test/test-stdostream.cpp +++ b/test/test-stdostream.cpp @@ -79,7 +79,7 @@ constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; using LogMessage = nowtech::log::MessageVariant; using LogConverterCustomText = nowtech::log::ConverterCustomText; using LogSenderStdOstream = nowtech::log::SenderStdOstream; -using LogQueueVoid = nowtech::log::QueueVoid; +using LogQueueVoid = nowtech::log::QueueVoid; using LogAtomicBuffer = nowtech::log::AtomicBufferOperational; using LogConfig = nowtech::log::Config; using Log = nowtech::log::Log; From 0317fa0c37b50825742360b7b35eb7d496fc4683 Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Fri, 1 Jan 2021 10:59:39 +0100 Subject: [PATCH 16/27] Ensured that removing the lock on notifying won't cause problem but restores old speed. --- CMakeLists.txt | 2 +- src/LogQueueStdBoost.h | 10 ++-- src/LogQueueStdBoost.h.etalon | 95 ++++++++++++++++++++++++++++++++++ test/test-stdthreadostream.cpp | 4 +- 4 files changed, 103 insertions(+), 8 deletions(-) create mode 100644 src/LogQueueStdBoost.h.etalon diff --git a/CMakeLists.txt b/CMakeLists.txt index 5b86a9f..bb77b94 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -23,4 +23,4 @@ add_executable(cpp_logger src/LogQueueVoid.h src/LogSenderStdOstream.h src/LogSenderVoid.h - test/test-sizes-atomic-stdostream.cpp) + test/test-stdthreadostream.cpp) diff --git a/src/LogQueueStdBoost.h b/src/LogQueueStdBoost.h index 7dbec29..5a8db3a 100644 --- a/src/LogQueueStdBoost.h +++ b/src/LogQueueStdBoost.h @@ -42,10 +42,7 @@ class QueueStdBoost final { void push(tMessage const &aMessage) noexcept { bool success = mQueue.bounded_push(aMessage); if(success) { - { - std::lock_guard lock(mMutex); - mNotified = true; - } + mNotified = true; mConditionVariable.notify_one(); } else { // nothing to do @@ -55,7 +52,10 @@ class QueueStdBoost final { bool pop(tMessage &aMessage, LogTime const mPauseLength) noexcept { bool result; // Safe to call empty because there will be only one consumer. - if(mQueue.empty() && !mConditionVariable.wait_for(mLock, std::chrono::milliseconds(mPauseLength), [this]{return mNotified == true;})) { + if(mQueue.empty() && + (!mConditionVariable.wait_for(mLock, std::chrono::milliseconds(mPauseLength), [this]{return mNotified == true;}) + && !mNotified )) { // This check makes the lock_guard on notifying unnecessary, + // because I don't care if I get in right during waiting or just at the beginning of next check. result = false; } else { diff --git a/src/LogQueueStdBoost.h.etalon b/src/LogQueueStdBoost.h.etalon new file mode 100644 index 0000000..7dbec29 --- /dev/null +++ b/src/LogQueueStdBoost.h.etalon @@ -0,0 +1,95 @@ +#ifndef LOG_QUEUE_STD_BOOST +#define LOG_QUEUE_STD_BOOST + +#include +#include +#include +#include + +namespace nowtech::log { + +template +class QueueStdBoost final { +public: + using tMessage_ = tMessage; + using tAppInterface_ = tAppInterface; + using LogTime = typename tAppInterface::LogTime; + + static constexpr size_t csQueueSize = tQueueSize; + +private: + class FreeRtosQueue final { + boost::lockfree::queue mQueue; + std::atomic mNotified; + std::mutex mMutex; + std::unique_lock mLock; + std::condition_variable mConditionVariable; + + public: + /// First implementation, we assume we have plenty of memory. + FreeRtosQueue() noexcept + : mQueue(tQueueSize) + , mLock(mMutex) { + mNotified = false; + } + + ~FreeRtosQueue() noexcept = default; + + bool empty() const noexcept { + return mQueue.empty(); + } + + void push(tMessage const &aMessage) noexcept { + bool success = mQueue.bounded_push(aMessage); + if(success) { + { + std::lock_guard lock(mMutex); + mNotified = true; + } + mConditionVariable.notify_one(); + } + else { // nothing to do + } + } + + bool pop(tMessage &aMessage, LogTime const mPauseLength) noexcept { + bool result; + // Safe to call empty because there will be only one consumer. + if(mQueue.empty() && !mConditionVariable.wait_for(mLock, std::chrono::milliseconds(mPauseLength), [this]{return mNotified == true;})) { + result = false; + } + else { + mNotified = false; + result = mQueue.pop(aMessage); + } + return result; + } + }; + + inline static FreeRtosQueue sQueue; + + QueueStdBoost() = delete; + +public: + static void init() { // nothing to do + } + + static void done() { // nothing to do + } + + static bool empty() noexcept { + return sQueue.empty(); + } + + static void push(tMessage const &aMessage) noexcept { + sQueue.push(aMessage); + } + + static bool pop(tMessage &aMessage, LogTime const aPauseLength) noexcept { + return sQueue.pop(aMessage, aPauseLength); + } +}; + +} + +#endif \ No newline at end of file diff --git a/test/test-stdthreadostream.cpp b/test/test-stdthreadostream.cpp index 77242c2..c60b3e9 100644 --- a/test/test-stdthreadostream.cpp +++ b/test/test-stdthreadostream.cpp @@ -35,7 +35,7 @@ // clang++ -std=c++20 -Isrc -Icpp-memory-manager test/test-stdthreadostream.cpp -lpthread -o test-stdthreadostream -constexpr size_t cgThreadCount = 2; +constexpr size_t cgThreadCount = 4; char cgThreadNames[10][10] = { "thread_0", @@ -89,7 +89,7 @@ using Log = nowtech::log::Log(n) << ": " << static_cast(0) << Log::end; - for(int64_t i = 1; i < 4; ++i) { + for(int64_t i = 1; i < 7; ++i) { std::this_thread::sleep_for(std::chrono::milliseconds(1 << i)); Log::i(nowtech::LogTopics::system) << static_cast(n) << "thread delay logarithm: " << LC::X1 << i << Log::end; } From ce677c072420f42db4316ba37e8235fff89f8b7f Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Fri, 1 Jan 2021 11:05:58 +0100 Subject: [PATCH 17/27] Added comment about removed lock_guard. --- src/LogQueueStdBoost.h | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/LogQueueStdBoost.h b/src/LogQueueStdBoost.h index 5a8db3a..0730b04 100644 --- a/src/LogQueueStdBoost.h +++ b/src/LogQueueStdBoost.h @@ -42,7 +42,7 @@ class QueueStdBoost final { void push(tMessage const &aMessage) noexcept { bool success = mQueue.bounded_push(aMessage); if(success) { - mNotified = true; + mNotified = true; // Having no lock_guard here makes tremendous speedup. mConditionVariable.notify_one(); } else { // nothing to do @@ -92,4 +92,4 @@ class QueueStdBoost final { } -#endif \ No newline at end of file +#endif From 53912dfaf38555c27617f637814fd267fbbcec86 Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Sat, 2 Jan 2021 17:05:04 +0100 Subject: [PATCH 18/27] Finished the FreeRTOS AppInterface and updated the docs with size measurements. --- README.md | 47 +++++---- sizecalc.ods | Bin 10289 -> 10431 bytes src/LogAppInterfaceFreeRtosMinimal.h | 21 +++- test/test-sizes-freertosminimal-float.cpp | 92 ++++++++++-------- test/test-sizes-freertosminimal-nofloat.cpp | 100 +++++++++++--------- 5 files changed, 152 insertions(+), 108 deletions(-) diff --git a/README.md b/README.md index 5af0dd2..1d62170 100644 --- a/README.md +++ b/README.md @@ -191,27 +191,36 @@ For desktop, I used clang version 10.0.0 on x64. For embedded, I used arm-none-e - logging with queue using MessageVariant (for multithreaded applications) - logging with queue using MessageCompact (for multithreaded applications) -### FreeRTOS with floating point STALE +### FreeRTOS with floating point To obtain net results, I put some floating-point operations in the application *test-sizes-freertosminimal-float.cpp* because a real application would use them apart of logging. -|Scenario | Text| Data| BSS| -|--------------|------:|-----:|------:| -|direct |13152 | 108 |52 | -|off |0 |0 |0 | -|MessageVariant|15304 |112 | 76 | -|MessageCompact|15024 |112 | 76 | - -### FreeRTOS without floating point STALE - -No floating point arithmetics in the application and the support is turned off in the logger. Source is *test-sizes-freertosminimal-nofloat.cpp* - -|Scenario | Text| Data| BSS| -|--------------|------:|-----:|------:| -|direct |4303 | 8 |56 | -|off |0 |0 |0 | -|MessageVariant|6440 |12 | 80 | -|MessageCompact|6192 |12 | 80 | +|Atomic|Mode | Text| Data| BSS| +|------|------------------|------:|-----:|------:| +|- |off |0 |0 |0 | +|off |direct |13072 |108 |56 | +|on |direct |13400 |108 |80 | +|off |multitask, variant|15272 |108 |88 | +|on |multitask, variant|16000 |108 |112 | +|off |multitask, compact|14984 |108 |88 | +|on |multitask, compact|15712 |108 |112 | + +### FreeRTOS without floating point + +No floating point arithmetics in the application and the support is turned off in the logger. Source is *test-sizes-freertosminimal-nofloat.cpp*. Note , only this table contains values from the _only atomic logging_ scenario, since atomic logging assumes only integral types. + +|Atomic|Mode | Text| Data| BSS| +|------|------------------|------:|-----:|------:| +|- |off |0 |0 |0 | +|only |direct * |3704 |4 |72 | +|off |direct |4212 |8 |60 | +|on |direct |4540 |8 |76 | +|off |multitask, variant|6412 |8 |84 | +|on |multitask, variant|7140 |8 |108 | +|off |multitask, compact|6140 |8 |84 | +|on |multitask, compact|6868 |8 |108 | + +* = when only using atomic logging, multitasking mode is meaningless. ## API @@ -308,7 +317,7 @@ Explanation of configuration parameters: |`typename tAppInterface` |_Queue_ |The _app interface_ type to use.| |`size_t tQueueSize` |_Queue_ |Number of items the queue should hold. This applies to the master queue and to the aggregated capacity of the per-task queues.| |`typename tAppInterface` |`AtomicBufferOperational`|The _app interface_ to use.| -|`typename tAtomicBufferType` |`AtomicBufferOperational`|The integral type to log as atomic.| +|`typename tAtomicBufferType` |`AtomicBufferOperational`|The type to log as atomic, only integral types are allowed.| |`tAtomicBufferSizeExponent` |`AtomicBufferOperational`|Exponent of the buffer size (base of the power is 2). For numeric reasons, the buffer size is always a power of 2.| |`tAtomicBufferType tInvalidValue` |`AtomicBufferOperational`|Invalid value, which won't be sent when all the buffer contents are being sent.| |`typename tQueue` |`Log` |The _Queue_ type to use.| diff --git a/sizecalc.ods b/sizecalc.ods index 3d87e19aed01b4b60425b775b3394edf4e21e305..27678cb5dfc2271d6e859bec742a11c1b35beee3 100644 GIT binary patch delta 8288 zcmZX31yEdD)-?{nAz1L>9^4axy9Rd&ZV5DjV2!&s?(Xi;xOQ-B+=9CYmp|`i=9@S3 z@2XpO+u65n)v2@hS*u2+Qx#K19v%S?1_lKN=9?FlS}djt!r$*?N)QtbYHS3`zf8{m zb3fCdg4kjI z?4N?^@T9;rcD%M5ElSs_0SY2s?SKULJ?k<}8>U|bI1j8Yhx4%<^7p6mw~&)Y0rib8 zlJU0hm*~*mJ1dYSO2)ZExVD@soYHrDeX!)(H;Qwl_cNzVFIS)OWR5j}2!!W2rl1J5 zxgWe%_Dy@z5%jVUcJ%$2f)DippHgEJ_vm6);5pBn8?#F7aYNcNo1b?wWuD z(JshZ+J^c!7|glYBV8dr5KZ9HzAljP%|FiX^p-y8kNaiXAG%^36)UmjJP6)BxwSCT zUm2LuHe*APXH#_DN=8!hB#5DD2F!gm$FRs0Ol((6V=%6@e9NXd60M4>do+ROj*PM$4gE72qZW-PtU2;; zrX7k8ShL@f*o;?XYeED!277XBv{9TkIZwQ;Em}9!N#5M@7HWs0ERnUCr%DN<=(hV| zE8E40TJH%qZQT6O8MZKW~!u4 zn5#QdW<3vN4KpOvAJk0dOhlOO@yA`{WnpMAHHnol9aF2KGKemTqafFMuPbSo+kd7u zxn2sW4I@m(ibC$|P_uxi>3CnbO|r;-7h7=dO)2B^4fJpu!~tToCYl8LzIfX zeSrtI;gV2EV8r6?i$_)B(6aV1eex0Etjtf^7EjCpY<&MMfSVVnYs@H6dqoE{$#uihC0C%6cz=L16yo zq^zZ^$Ilv>w!&nhOH9Z2p@YTUsX}t_@UYOKp(^LLkq7Z`QGP4#=-?grxpj8Z=2h<_ zmEOVyVkJSE@Gz+}^5-pO4%w?*GGG0VR8)uoqF6Jzbs_T3K71+fEnKDMS9(s_)do|6 zX*JHyT$!uo2s?b63yL}D7t{rNW2L^4yQtT>mLKy*x-RrTLnDvnxH7onyOn;XJlRELp^$7+*PbJme^=?bnW0nw`rJ~kEEdOAshI{hAYODz>L1Hj_;q0$c63HE zg=za0H)JPng{2|z-O~V)yyTcSeHSN$@{Dq*FuECDMOc24egafcB~U6|mElP2hKPC& zCo7N#A31b7p$6Sbt}A?elxBbmRa1jG_;bxlci20$x|jstKGjDyckM;&``F01f?;gAQ$({ImHq;q-SzY%>9pqb6_ejgI| zaNG{O@jAO2BxQ^`(Hsw@f+uwYWUQhHuckb2k9*5_u%Et#X*(5g1_%^0g>X zec11~I4dp#)vvEhom!bV^TU&bd#>m4xDD93a!AOOMh<@)J&}(|(aW_NDrl9m!Fjn$ zc)x^h{j9~pF*b2oR#pZ?^JwC5ly#Mv4{bv=^V)Cb7MGAb?#1g@6u1}R{x}24ieFi% z__fT6R9??x#{ht8pEh(mV7EjsDc?0ox)+o26^~}}N1+TmJ#^SvVq8Cdzs{nG)67}8 z3`cs~fMcuJn)t08C5FWlYLryWHaAx-z$7|LJekn?-gTgIyNd)UthvoIb-Ij-nEqml zhcx)0!K{+A=+gEhg-?K@Ww&mBVfe?DKE}^|*L{E<`Rvn!?+=}TkxJCPalf599Surb zAvMmWVdX|L+yLU>ybbI1+M<&NUu;LU}p|zoE`5)Cfj^<8dTD8?^(#8sggQ$E+ zKx+bzZYOH)Pv5etyAx$35sfgPCf)cch4FB<54X>v$4@8iZm)NOZE*&+fsc3&GJZJQa%SXl2XG`T4Q2Q&&E8%O24LV29NuG0zHtvewF_-*pO6+S z653d0`0&*p40WtfXWK&py)08c+vEU6W$+uj&Bpt#kV`L&X0{CMNP|F(MmDfzJn$F` zzD`ff?58`#kOMEAyeMQ|BQivktvLOSCik=gr#vU>`<@US)l89#G61$%`q}c#a3@9Y zXWW+HA2h(yH97*$1;QSvXdqIpa%jF35mz<>oQwnqO&Fb8et4dr)T$W)IkjwMneOZG z2UpUo3k^T<>unAEz>|)p&ORsc;gKmST*g2!W>nx>eVZC z-xOD@wCl}hv-d{^tcy`!@a0kklZHrFP%L7v8mU2MpKT9BHP%PYOQk8#E{@HL!pB@& ze`Z&k+v}qQ@on41yw)^q!0wIkF(t*ti;XEsI}~m!-4=abAu`z=#D+S&cyc(Vh@((hFm$vPB8%3G>8VBdcc*b+bW*5k& zK;}%Rf`XBzCi0}4enjK6K$kyQuY^pa)K{hi^DSAUwpyC&ZgD6E)L*E!pR`J}FiQ_@ zPwXU{TQ;-jgfAzMr+@vrx5{6+sr_iN%hC+E`-@hrCW;FKC)+xtJd;WM$a0e{=d7$3 z^`w!rr?|T|089SIJ(XMz7fuPIs=qdiX54y}l_ce?a(|Sm0{7>=jq6rIP+K2^6eB5@7Y`)fsx;W?lR}qu) zW!V~TWs7Th3X?tWifWi$v}BysN4(@LwIswagj!P7#S}eC_6Av7SYto6ce=uG>N|g?%F$jgQ zCOaldvD_RqGL$bgxNskSZE}c6%}|12vA_J>2YIGBN1c{!Up%H-YthLwS~>*-KVtRW zhtTXJ?fTxW!^jfRewFsrI60LEp{nHPYFGk0^FLnw3btg%uB*AbOG1_KsD3b{Wh=qO z8rXPIFX112_GsU$A~ZbB*Rd;?0Puh4E?{?(v=I;KXc@D7bJ>;2@u2OCH)#>TIGCO{ zmVAN2(MF}9(LgzvEUOsDV-38?bV*KCk2U2-W0R-jp|L$={liP=y(LV1_tXzZwUG0xG`$!yN zb3bFelJqO?^oF-_jHa%O5}Q+i-e<$nuL-1k3M6%H&P9fw&Q4f{#1*AK$_}lFnyQk- zZhvwp=R57(>d<_4%MVAaHC`yxTo>y(eY2$>QZ2-hUR^8s11=QSS9u7Jy>AGi85on$ zqESdrGib7XGqtU~@H~PwVc8Yj|qN3S&j=m(-m;}F^>gR1SNsEv=c3!wOCq0e7-bav$@WAqq$1sb+R z=;f>09*cbVHiE$M*|hi`dv9i#>>co;f}V}4#~FX08TMw~&(dF5lGk-ibl50A z*NMxMB)7nM79e@|I9G6X!*+IpQ}YvPv8dG8%{y*`!;k&>8rR=szDBwH^D-eiM1$%B zM8w=0!QHe7GeG=#c)~IG3cePO$n64=v>fq6-m?#9Uq5bg#-;1e)|N+t@0manbluapGCj%*52G>VoMSthMBqK48&()*0E`%OKaWauSZR+> znEKM%tc<10A!!aUBDtE3yEBS7^Vu^{M7h$4sE_n8$VJ5uc9aH(@YMmTZclIB&*jcy z#d{N@m8hF!8H0Sbn3l2D6T*T1+C3=~vp<76!-h^vajqO1IRv3#{Lu2WlSs8I` zgVtM9E~NCy0qEC>vJRLoiOL+jzFGP_c-vDi=^Y8vv3{k+nVRqvQrm<0>0pUSSTEwG z@hPK^IL~O?I--_!2h=mf{WBu+gaz8zlC~Uy)}vjF_FVznzVh6}jcoRep$K=E5NU?57{v9vG6ZB?bO;TZb`FahBIrKS^98arp^O#PP9VW}&x? zq)$puHS#t-+kjIZc&Y~6omk2uG>$Rq@Te2PxurCn9=F@%)_)zge(Fx-Ad%rOyo$%8 zjAX*5na_zJb8X|^gF%tKldyiAEcy^EsD>`aC>@F=E1V(~j*gau#mK^0PEc2&gOuAF zR)~MG4%qENKqsIm4S@lsl~q?iSsH$;-cBTU2Qg)g8&(JA8@vD=d1eL&RG#`jh=1oK zJ#A~@IIJ{LB=^&Fwj2>`>pTp23R)(9VHVVYcC@0cMUj*qMC2Ojc}6bdPU$LIe^BG& zQCsobx0GFvFRb`6%ffQkyv?7;xo~~;+-OwQVWsWGi)Jv6?R1&4lQJZ3z072P{A~`l z?&qaGW1z9%0>%|k>MAP*ZfU~Y^~1_hM9$!D9UG3I=4A=J9%7_4KfHnYlP=Nq!GX6z z4w%zI(lIK=SA~@YQc16dtuEllN0U01Np6F^M*?Ki!c0>1iH?g zGbErpg*aqgGhs~<y(=U_T z_OtfY2j9QiTpjxOW63aC&o)tL`CT(q^Tg^E7gKX4f96@QN2!R-d`iclRe-==G!NR!Maz>YPFpHiV9M7 z_Q7JwVLW*43CYDzy3aJniiOVCA!>jqbPetxtcQxlA?2Vavs*2--gtAITCO$q{c6iS zP_sA*Lf-}~|K%1dhU9}z6iS)+q^kvPx?s7to3p7L4J7RcTT)m}wnjYyc%~fIw3``D z!*nz2dbBdWQ;m;{PMWw%-h6n>gL;del{NDgDA*$6q;1vuE07Usl9C)vype`x! zUR+RIK~z{kN=!sSK}lS}Kwi~QMM_jdM)Z?{qOO9NuA1T}RrOC=1{yks`kJ5gv~={e z^_10()pS1V>X~Yr+Ui<B#l-oy zd~%k83J6I8gk*SxXZkss`McOg zeYXzq^ziWmM*9L{13i*LJd=an3S+(e{R095LjyyjLIMNBLIT6XBLX5~f}&HyBjUm% zlY?VYB4a=iaj6k0sd3?fagpK4(UCDxF$u9z8L`3X@sV+{aWM($!1&~h^u)OIP6a#?I*4k#r*KBFWxBQGkuA}XgYBRelOw>+kxCB3jVv!t;AoHz)E0s3%j@bIY8$}~EgdZl zwH>VuZD4Rl?LcA6NLgcdd2@eN8>FtSueSXMxTCMWdlcL=(AqQ7)Hm5OFb#%4JBH`m zr#5;jQU+?$A@y0^^(6x><&f6W?xyO#)|&42mZ6TC2{5p*yQ8bOyQ#mobF`;%xEDMQ z>74JYoak+u>TiKUz>EFW3&U+YQ|&!Hz5N3}`iDk``g?{UgCirueZy1TqYFc$lf4tm zBa_gPndQl$-sv&O@_5h8MQ zrHzS|J>bIX#>~&dm7iOSn+L0V=j+fP8}lQlO9KZ>!<)-fo2v`^tCO4SOD7x9!>#4> z{n^Wd)vc|~jh(%ngQJ7(pTD1j{k_eji@oEE9KWEckIr7y@Q#}Ewkxeh8#H*PVFmR z0QB^;YunS1AI>j=eG=zUoose5MIAkkK+i;7)3@$CNvKH>wlq_%Q*LIw{W)c4I^|87 zvP7L!=vVh~S~ZRgnU)itU>%OE^b06SNGl!s9<+2qel({hs(fPPo!{ak#bX>C)A$&5 zXuB{_k^UY2s!ms^O!&9RO>mD_hT1z-wFBks@k0oKvSN$=i1`Qco|a#(4V`svzyOzH zF-6z2mhDDGa0SrHGoW3%is|F=|*7mE# ze)w9jEpIl{H6Q%tfiNon^b|vN*`gV?y)=WjfQh31=OO} z`4EHZ0{v3=u1YW7rSPtTEHf`Eka$l!Z)Aus*yU=N*sKKXY8b6oMSW?a+3sI|KR|2` z?z~3|5|Ev7r0KY)IS713rr z_8c+am#NICSi6zEN*L-XDw&qt!MEY=vB_E4ZxIQ9Eht!FN=Cn&lVLm$(G*#r7b`Ryjp?P zQExd(x$hB0KS3esK3JGK)iy2b#XiAy?fS-lH8d!MBXAoTdR7PV7#bmBA zf<9LyIrEiPaWX7HfQ^(%xk{BKTn&jGV{#a^hrjt(TZhS`JeGtNULt=_@TfWd( z4}o-COCv{|=^`J#{?_?+fml(imwCbV-=f>n9Q@j#K z1tH0JyQ@-qXxyHsmZM}mRBAD-zSrUDEOQt6N;z<1WX#L^-~k_#Ng)FBICg3uqmuXh z$Vr#c=Exuzeu=SP&upu-K_YEQ-;34SRzC{_w#Cdv-Wl_>TPATP|6c7?pZzkT{FE*e z$WEmAJzot7iIAMe<%?6RF;ox|=9ny1mtm!yZu9i*p;uPeuKz0A$3$Pir-;j&rW0DL zRGvKXvi7Sp0!yY{Hm=KB9jB1-^sA>$*Sp~cmpnlIhrI?(&=7+NXc+!5%zqjB z|1@%G@IcQrcz>eCw8XI2u}c(~uyA-V|KZ0$1hi8BPLTMc6#vIV3__=4`r{R(ll`Lv z)A7Fgi&6iZCIt=9v1y>Ge*XnA z|3^$fa`ePHf7SlyaEJb%gx{L#>)*A_0RU?U%m1qW{|$e?2SB3#T1f|Lr>Cdp#_S&JH_28`rr-+m*PA?p}4!dYjJmXx8f8i@U{28a^L^o zb7r!VtjuK2WU_Yl>Qt^)LQ#^1g2sY?fcyP@%T$g-QG))f9Vd+o!1y-=zfd9|{gVbh zgd_!jp+W+)Lc;xv#Qs+cuJ}En3yJf0=MRgB8tH$RRzPz8d-lWMfbIgK~S9QXQic%sO(Zt#QNL zVE4T*mSxQyc(%ZrlZm);?9m66#I~#PbS_L;={KhN`)zCz68n$C z86~e#Ri}0c)oq$qgjK9z>6IBbQ@sat+(R>rW1n6w@@(C>y*Ktl`DEA8P%M7<1|U)9qLT2~ zVntI|KJULQu+$;0E8jsx%df&a((LP&I40)Jy>xilw7!C=g&xU zBucVx;Zm1gX3`-cAY`B*ApSl@aBy&cog#>T1j29Z4Y)jI(gTh z&!a1Uo^DeY^bj8TtrOn{Ng~)L#k>$pj49lCZ-VPs#CGC+_iVUXliOK&+C)QpNSr|ID>_bLId{?7_luXUm#=;3J|8nho zQXW4THc#9d?PTSY#?Fjb=jeNAh@f+=9&A(9iJ+SpT`eXWjNL%*B`ST@&Q!3oWMh7^ zj?t39b{0~y{)V6?`)(D^D!7comyxI>B$)Id32?ZVeLsU;xIEa^$o5@EY;k9*Np2?W zt#GLZ+IBdyqZGNd{KdYOCAJB_rGv4>j}@Xc=w2s#j9CN}Wgu0JkKUTkw3Kr2`29>M zNM$tqSVT3#g9Eu$eCniUu^PJ|lB&DzA}go?8BwNOQ&?B_7QGn9!Q-{HxwR6R@Dee6e69AB zQmR6%u4}@>Y)6p7^Ul>w!=eXYf^u-Vyte?&(Wd2l(S`Vw@9*k)8z7Cg>gnBQ2Kg%( z3o5u-)W>7HOYq4_bRh4FlQYfOSW=@-^#CnbJKw%54oOP%ek$2y%dX>3q$VPui7^A^ z;l3X(n)Bua9N!V_#6S8s35E1AcJZ;Dy-aO1A}y9C)#9xc-(vdbOfDIF3x^*%TfOD# zVyGq)nMI?E6UbX2aLBp-$vm?dFSWy@p9?KcI%B(nVjt$vD6;*NY+jFT=mU0tY777n z8mv2OHzIm}I618#8egd$Gu#sQ6Rpd6z^R^0BP=Pz9vMjZ2E!*#Bu;;p=6)Wlw-JO8B+42TTtc|(?Lp`r>-FUrcvjqbU9&IM0-@hnA zrGson@o7X+1UK@`hM<_w1=^ z>#lZ70G)Fcs^${A%tNW?ewI|u&z)s$xhTF;#W=Jc=BiUt*Osn4pbL$7V?zR4oKbjI zTS?aOyL8SOeTtz-N|aUR&Cb%SvcX!Z6jd1J^M`;#BG#}U_~4

JM?IGcm;SGasnL|4<$XDFTmE0i5Cn6ezqX~mT=#K`evl)(__W2`{+co))^ z$mOp+EEq$HA60{2hcv6cp0AeqSgqc>M4{4&4|qJ(m+&FX(eOy5a zOQ(lJFxSRAF9iwyjzT@@a^K0-r1p)N7VEtw4 zfdZyU#Tj(3gA4{h?Fs0>lit=5mo!ohV!8+^Hy!&i@_{&&DQo{Zv1Kh3=DW&${Q>n} zlCDi)a}egyxr^*NPR|ge@7z1Jd#({aReL0r1&bE^OE^zj6g98*xPwE_lK|=Bik|c< zl=1ThTCTmH>M}_U$(mdPc729Ir>n2ZrzMgmZqDp0#8C{^ieG?$Qxk~sL3~BT;v|?A zWdkZ+Z0K#S(2#rc7e;MQ9EH(jEz4=T;~lZGA#gUa!c%Q?VX>| zR0yl*^QCnmZR$xuQ(03lvP{HlcuP8MBTXA1-}^w-XjF= zw5l;EWqb17Dj0Z<9}V)Sj1?5tf;Ft*6oIb_jeACGoteDJY2t&YC4Mgklir-A2&T4g zWz1WBUaD3EX*pj}{|I2?tD{3JECj@7>i<^&!5}0;U`<=+x7K0#Zd9VF8iHzUmSk*M z6#S_VMHfzu&io)nNj`_ygsbETsdSt!{D^JQRG|!&IkkI-(1iYw-WzkkOw;%Sg{|H- z8L=lmksm+G7Lf)LQMyKJ3GjZ{96fV$6I`pIC5O}xVH`A0lcF&U4|-*aRp?{i)9k{G z*Ou-Fz*M3EVP*lwj7jX8HCQzHr&qu)82JIapm_JG3+RW4;fe6-`c@o=Skl7JzrnW92iEJ z?8b^oB|tZ|bp5_@tYDBU3=B>=3u+)>1pDZKWP5oBJ?X)zb=8QTfZCI7K7MW?>D_Ub zALp$^g^?o|<-d$PlY2Pr7-FypH#GcDrrDAPRW*%HYTnAkgPx7DTxCD^$)R$?9gCF> z&@r;B^^(V4(_6q|kA2ut1tUS>ekv0S;>DLQaW;%hzg!(1%TzRCM;_}nC71_cvJsO2 z2wTTlB2WT($(U4;v`TLvLxa&Nzx1W$kAMRt)+q?m$iqP;+L+ah@Yn29+4|v3gapgs z_Vd)>>QdIZa=3!*rSfFVh`YoD=b1g3_0_Y-x^Hb_*4HpZZ-XSGkNr!ZE z+*?3dO~7kr!J>}$Bt{T??)CiOT;D`0mNQ2d^2?(g5hinzGlUrk|iUo-U=X%#? zbI#y!A!&*oibtoS49y)tyeixwZY9L3FbeNjJfZoxHUwN+E*=ytbb^_zcLFRn5^IGO zG@Ir`px*~zW<&6jp%gW>j`fymH(Xhm1tmVCkK7Xpv(yu7_1GYO(+Q7+=dU;gGJoqN zi@ausxeoGogmWAFH)Igqc(rKPeXbLkFWEa?wN~5_Q?=TH=!1gqlIJZF!q#Q$?O_`+ zyvW6%;xO=qD1V^Q@R()f_BV)Wqq>J;)Ip~B+A(FpH|NHF^hIvnNH$%@ntvWJD4)1* zKV9yMsCIfXZqk%Y34)8Iw6Dtm=$mdWc98^5gWmhUOOnB$IG)X?nyBIig|~QojbL+TA5F)ytpdyPZNixWstwF)txD_s zqU0)HqG2*cQjZ;2$#_c=%4~+;HFFjcYzo|)$c&_8Iozt`lRUzS?pOuGe9RQ~0^XC9 z0{P6yrYS-2IJ0752&;=KC()~pNwy6NYyb@-H&pyUUGS9FlwPC%*LCb&&|-Szr{V=# z8BYAB+}YeCi}2lnWf^8bQ)L^C!c*%#h7MMV)-Jr-;d8QeN7P8d@twF|;v)~0(?p4z zcDyMgro7I%oDy=xEg3^A_vDN6^wg~at63LDQYza9Ba_zo9I{Gso%M<7%8cC_IfqF) zr)0pnpdmF6WH|BdfwT)C%Y-Asr4R*7IBX-0d7CQM8?t#<8L)$y7rAl~x@S>NrJ-E@3~|ztuPUh-0;UE^-Es4Am#< zV3qYy@WSZV3?iuob_sK6(-W?4HU_D#s=kcbXO%Fv%RMaw5c zr+(*jg=x*G{oBHW_4*`$*h}s9k=2MQh3y1CZ zbN&-Y8cySgfTxL=Hl%^^7|wSu`Ac6oagfzMs7udpGm!cxYfzRT+k3K2-`L0Q3UJG( zAN%ET`B)b`0M>p8HxEg2Za=iS#K43;#!&mrn%uC=zrNgG zsThO`Rq+B)p*e>(MJ31QP7dn?grAT2ZtRBoA5JqP3`@tFUM>*WGw{dX5qN|nY@=3^ zcHoP5>E#6c3}hJWu^-k$%5Xek*n?619C8bSw(cyn@kZ2Q-rx9?q}ykQ1Wb+5Shnk-a8Cr1BeU3I6rO_SSb?d3pC2nJ2Lhfk2k?e(&}y|pnIyiqYT4^Z zJIBV&A_`q=4Oe&kS-TiZe5$bMDjar1MN2tBEy;BOG(9xe z9CBung4gi+GS1`_7{oh&x^2=MI^8t{n);T})x9eKrOzB%uPnRx5*h3GsZfEh?CxthDs3rjkeo-uo< z?3@T@@$6zD-|pgYj#leFydkGDfi?;lSD?4?l#9`B|xGR)wS_oq60LTbw)sOz(HXwh(+{#8p4)t3nIoR(mj*s z!W~AJKv&oi&))PP*w^&ATUg6(`u^^~uX35Fy$4zk$~0v=15vcAdp#0r0a9Hyf?i|W zoUjYE2zi+MmK~at?$+5qo-Wr!32O5K&*dv}o~#c<5-Uojpjf3ooPew4Ec~RyZUgOi zv{;dJ;4N93y%Uh>b(&Cdjl|OypmDyP~R3OYBq$}Ui_}w zvaXkI*{s0E1ZjB@y5(Ux_20T{_BRul4STL80Sbbs7POB!_`~8ui@~uGhG3{i3NQHP z&!k)KJ6c$^YBY`1#$f&$HpmVIj;@b<)M_{gu3g3o ztByHnu<$5CBO@q*Z+F-YRw9iwo#ahOR|GT4xaZpP`?p(J2snbT|1Mv=$OX6*+@~oGVn+d%lgVTI$S704} zk+129^{G27rsIUGO>w=aJN|Jix4&&~Y3?&2-iszvI!wWR$zohrE!0{BG3y zSB;hQW!>DoVG&_e$dtNv$kd@V5YjqHBO^N_Q8Ld#UTU&>{K?GhxUR%4VKN~ykxua( z7^0WQA|)yt7;*@J#Vypisa3odYzZ1`om2A>lm@z?HaDR#B$GH!2NF~G5s2h>QR%IM ziEy-#xozLrgyLPOV(4k@@2agwb~DVbP1eE*{dD7DS+eN#Z<6BnObhn`8kte_;t&Ik z#gp=Uz1$Nk$S#Z~QHtEy_spyCQukJGnTr5F(x+sse6dRD+E%yrOHUkhByEdv{0i|r?Zz_#e>yu#@u}r$A1dE zW5d}U+oP2It~p7+9-uhOXZ6Oo7x9gnm6O5a`2azFU1s&{E6ksJn=L|5GYaN+RhQ!5 z_x8VQyjn!Xmr(E!5Kv%#d{LlSNlsOqg@TwzR8CMzMTC=8vr zsTk{Nf7aJBF*L9?)^oGeH8wUeGP5zYw6!!fv9mNc{On|D?PzK5?q&@bJA#}Y?QOgr ztel*joZWm}-96piUG*J9jO+rey`t;@FyQC!;~!-o{LLjS-6tZ!AEY1Zs2}KQ9qnQ1 z=Lf_Dx`6|nz#%>;Uz+4!loFnw8lRJqR+srDKRdlNC%wKP zxwRm^ttcTcCnqPbq@cLGI4`@TD8IC{EWflStD?E2yr#IasjRB5w6?Xbte~d6q`4xm zwyM0XwzQ_Ern;fEuDPS7zNW3YzNMulr*WjLp}V+arlzH@4rm{2?d)yr9_{GvYwjJZ z8CY%WpKKqRZl7B3nBMLwPZ_Mu=x(g&ZmJk*%o%IS?QN~?Zf_mxtRLuU9O!Bq?rIqA zZJF(_o9u6!8SGf@uU;By>;Dr&{e#1Uecj`Oy`!Tey(6=|V~eBXliic+W7D(4GpnekN6?&%dV0Kld3pI=OMZQQ_25dkfq;O;mKGCMbzeSPd<9{e5xuql zg~3Mpel#2I4Z_d|C;DxyoJ|cZ@lcyA;r#+#jS9>8@%pC%XMb*?zMMI$Mm_(Iix5KQ>6w_{^5+e$YBUrX_Ry*k^ORr8KVUoA3{o#j@0W0u0KjgCJ^+{XfzqcH7ts3P3P#UbC$dSd=Z*4N=}n-L)^!r*Ws3q(nX8^;$pimC+bY1X_oGVNaGP+GluN{&+}I}V!0 zQyA$f$$3zMv!@kMg!)O($F|VhMlmgiOx|ne5rX?pG0UMpfe7WWyC zF2QBqAD!wl`}vsOOKi*^tn!*4p5zSsjjY(BHwg>isYbxY1(Qr!i~zOminx5lnW^`q z8^<$|`xRa)nsJTPajA`J3%oSPO$DlwM0!tO)I#PvKR}P#%5u)+0;ihqL-p4S&#LaW zuj?*0DXva4)i=D^$^o0t)x_vd$%^l4VwviKO-0N4CmKOyU#-@%(%w?4>uTQFM8{58 zq%Tz6MP!WFP87FT=mW}b3fiv^{c0_nZ|SCm#>Z9E_c>~ZCqdcZ0gl5~r=73r(}g;s zb!W1-mK_^n*7t5idXK{kHZfU;lIG6^fxfNT!!#PpV=7+UxG@f{@8{GntmdY1wcG&j zjjLZ*`7le_-ycw|7xSr-%Di&i9M(fhmlS=%!r=LD8t0DPnSs$S!id}t7?PvowUa+q zb86ZdE%O+DjT4lV(mROJ|8$$nT&A7yS^{xYFS6?6>wB!^MZA{8mkuWjaZ7+@^A3rT zY5Zk8O_usy{e!^>x7>^QvRZCCvC7{*%BGTRyc809s#D}M^s+%Q@HD~JMC@tbD2F6P zBnF6z);Mz9bpW_D-J|R+HpxXuE|v-#ecNd_1+roq!B5WuF71X2=;?P>rCZ?&^$9X> zG9NWMX)hjs@NB;G$(fw{^iixI>$^zY_De^`c5!XuqP7!-GG2>-Z>PAc_0XYDdD2!- z#fj;4bN>WeFe(ubqfhF}TFQ;P9oj=;dX1$2lNzybBQHKFkpoGbX+vQFG4en%Wermk zJ0(@-6@{?~n2kIH%u4=|S`fS}=r$ZC0tZDr^2gYd7FQ6f5HSq+U(c_0o!s$X=B+B_ zzs%rCN&;{mCGFpq?j)ti-@uQW0I~~=4oQLn`34K(zuq(WHy!dPn2n0&Z(bgi#D5lm z;i&2V?r>87XH@L(kwI$dzX3K4C;T7t`Y&S=tV+W~@~8LDD(xRL^1opO&Z5EB{KNU@ zBNy?%gx^RN2?D|dWan&V=lsXNRFeIB&;NEh|Cwd|X8t2Y!05Due{JAD`PT283-2Ec p2ncwvEG^AnoaFU&CAQyQDkC%m1or=MM8I*hw6G1ovp5Kd{{vx~pT7VA diff --git a/src/LogAppInterfaceFreeRtosMinimal.h b/src/LogAppInterfaceFreeRtosMinimal.h index 2b3f8df..0254f93 100644 --- a/src/LogAppInterfaceFreeRtosMinimal.h +++ b/src/LogAppInterfaceFreeRtosMinimal.h @@ -45,16 +45,18 @@ class AppInterfaceFreeRtosMinimal final { }; private: - inline static constexpr char csUnknownTaskName[] = "UNKNOWN"; - inline static constexpr char csIsrTaskName[] = "ISR"; - inline static constexpr char csTransmitterTaskName[] = "logTx"; - inline static constexpr TickType_t csRegistrationMutexTimeout = portMAX_DELAY; + inline static constexpr char csUnknownTaskName[] = "UNKNOWN"; + inline static constexpr char csIsrTaskName[] = "ISR"; + inline static constexpr char csTransmitterTaskName[] = "logTx"; + static constexpr TickType_t csRegistrationMutexTimeout = portMAX_DELAY; + static constexpr TickType_t csAtomicSendTimeout = portMAX_DELAY; inline static std::array sTaskHandles; inline static TaskId sPreviousTaskId = csFirstNormalTaskId - 1u; inline static SemaphoreHandle_t sRegistrationMutex; + inline static std::atomic sTaskToNotify; inline static TaskHandle_t sTransmitterTask; - + AppInterfaceFreeRtosMinimal() = delete; public: @@ -160,6 +162,15 @@ class AppInterfaceFreeRtosMinimal final { static void unlock() noexcept { // Now don't care. } + static void atomicBufferSendWait() noexcept { + sTaskToNotify = xTaskGetCurrentTaskHandle(); + ulTaskNotifyTake(pdTRUE, csAtomicSendTimeout); + } + + static void atomicBufferSendFinished() noexcept { + xTaskNotifyGive(sTaskToNotify); + } + static void error(Exception const aError) { while(true) { } diff --git a/test/test-sizes-freertosminimal-float.cpp b/test/test-sizes-freertosminimal-float.cpp index 646e288..26d2572 100644 --- a/test/test-sizes-freertosminimal-float.cpp +++ b/test/test-sizes-freertosminimal-float.cpp @@ -40,32 +40,44 @@ namespace nowtech::LogTopics { } constexpr nowtech::log::TaskId cgMaxTaskCount = 1u; +constexpr bool cgAllowRegistrationLog = true; constexpr bool cgLogFromIsr = false; constexpr size_t cgTaskShutdownSleepPeriod = 100u; constexpr bool cgArchitecture64 = false; constexpr uint8_t cgAppendStackBufferSize = 100u; constexpr bool cgAppendBasePrefix = true; constexpr bool cgAlignSigned = false; +using AtomicBufferType = int32_t; +constexpr size_t cgAtomicBufferExponent = 14u; +constexpr AtomicBufferType cgAtomicBufferInvalidValue = 1234546789; constexpr size_t cgTransmitBufferSize = 123u; -constexpr size_t cgPayloadSize = 6u; // This disables 64-bit arithmetics. +constexpr size_t cgPayloadSize = 6u; constexpr bool cgSupportFloatingPoint = true; constexpr size_t cgQueueSize = 111u; constexpr nowtech::log::LogTopic cgMaxTopicCount = 2; -constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cName; +constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cId; +constexpr nowtech::log::ErrorLevel cgErrorLevel = nowtech::log::ErrorLevel::Error; + constexpr uint32_t cgLogTaskStackSize = 256u; constexpr uint32_t cgLogTaskPriority = tskIDLE_PRIORITY + 1u; +using LogAppInterface = nowtech::log::AppInterfaceFreeRtosMinimal; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; -/*constexpr size_t cgDirectBufferSize = 43u; -using LogAppInterfaceFreeRtosMinimal = nowtech::log::AppInterfaceFreeRtosMinimal; -constexpr typename LogAppInterfaceFreeRtosMinimal::LogTime cgTimeout = 123u; -constexpr typename LogAppInterfaceFreeRtosMinimal::LogTime cgRefreshPeriod = 444; +//using LogAtomicBuffer = nowtech::log::AtomicBufferVoid; +using LogAtomicBuffer = nowtech::log::AtomicBufferOperational; + +constexpr size_t cgDirectBufferSize = 43u; using LogMessage = nowtech::log::MessageCompact; -using LogConverterCustomText = nowtech::log::ConverterCustomText; -using LogSender = nowtech::log::SenderStmHalMinimal; -using LogQueue = nowtech::log::QueueVoid; -using Log = nowtech::log::Log; - text data bss dec hex filename - 22260 132 19068 41460 a1f4 cpp-logger-embedded.elf +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStmHalMinimal; +using LogQueue = nowtech::log::QueueVoid; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; +/* text data bss dec hex filename +noat 22180 132 19072 41384 a1a8 cpp-logger-embedded.elf +atom 22508 132 19096 41736 a308 cpp-logger-embedded.elf +new 22508 132 19096 41736 a308 cpp-logger-embedded.elf */ /* No log call present at all, not even cout.write, only thread creation: @@ -73,43 +85,41 @@ using Log = nowtech::log::Log; -constexpr typename LogAppInterfaceFreeRtosMinimal::LogTime cgTimeout = 123u; -constexpr typename LogAppInterfaceFreeRtosMinimal::LogTime cgRefreshPeriod = 444; using LogMessage = nowtech::log::MessageCompact; -using LogConverterCustomText = nowtech::log::ConverterCustomText; -using LogSender = nowtech::log::SenderVoid; -using LogQueue = nowtech::log::QueueVoid; -using Log = nowtech::log::Log; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderVoid; +using LogQueue = nowtech::log::QueueVoid; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; text data bss dec hex filename - 9108 24 19016 28148 6df4 cpp-logger-embedded.elf +noat 9108 24 19016 28148 6df4 cpp-logger-embedded.elf +atom 9108 24 19016 28148 6df4 cpp-logger-embedded.elf */ /*constexpr size_t cgDirectBufferSize = 0u; -using LogAppInterfaceFreeRtosMinimal = nowtech::log::AppInterfaceFreeRtosMinimal; -constexpr typename LogAppInterfaceFreeRtosMinimal::LogTime cgTimeout = 123u; -constexpr typename LogAppInterfaceFreeRtosMinimal::LogTime cgRefreshPeriod = 444; using LogMessage = nowtech::log::MessageVariant; -using LogConverterCustomText = nowtech::log::ConverterCustomText; -using LogSender = nowtech::log::SenderStmHalMinimal; -using LogQueue = nowtech::log::QueueFreeRtos; -using Log = nowtech::log::Log; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStmHalMinimal; +using LogQueue = nowtech::log::QueueFreeRtos; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; text data bss dec hex filename - 24412 136 19092 43640 aa78 cpp-logger-embedded.elf +noat 24380 132 19104 43616 aa60 cpp-logger-embedded.elf +atom 25108 132 19128 44368 ad50 cpp-logger-embedded.elf */ -constexpr size_t cgDirectBufferSize = 0u; -using LogAppInterfaceFreeRtosMinimal = nowtech::log::AppInterfaceFreeRtosMinimal; -constexpr typename LogAppInterfaceFreeRtosMinimal::LogTime cgTimeout = 123u; -constexpr typename LogAppInterfaceFreeRtosMinimal::LogTime cgRefreshPeriod = 444; +/*constexpr size_t cgDirectBufferSize = 0u; using LogMessage = nowtech::log::MessageCompact; -using LogConverterCustomText = nowtech::log::ConverterCustomText; -using LogSender = nowtech::log::SenderStmHalMinimal; -using LogQueue = nowtech::log::QueueFreeRtos; -using Log = nowtech::log::Log; -/* text data bss dec hex filename - 24132 136 19092 43360 a960 cpp-logger-embedded.elf +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStmHalMinimal; +using LogQueue = nowtech::log::QueueFreeRtos; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; + text data bss dec hex filename +noat 24092 132 19104 43328 a940 cpp-logger-embedded.elf +atom 24820 132 19128 44080 ac30 cpp-logger-embedded.elf */ void step() { @@ -130,8 +140,7 @@ extern "C" void myDefaultTask() { else { // nothing to do } HAL_GPIO_WritePin(LED_GPIO_Port, LED_Pin, real > 0.0 ? GPIO_PIN_SET : GPIO_PIN_RESET); - nowtech::log::LogConfig logConfig; - logConfig.allowRegistrationLog = true; + nowtech::log::LogFormatConfig logConfig; LogSender::init(&huart1); Log::init(logConfig, cgLogTaskStackSize, cgLogTaskPriority); @@ -144,6 +153,9 @@ extern "C" void myDefaultTask() { Log::n() << real << cgString << Log::end; Log::n() << real << LC::St << cgString << Log::end; + Log::pushAtomic(cgInt32); + Log::sendAtomicBuffer(); + while(true) { step(); } diff --git a/test/test-sizes-freertosminimal-nofloat.cpp b/test/test-sizes-freertosminimal-nofloat.cpp index dff2692..f2ce775 100644 --- a/test/test-sizes-freertosminimal-nofloat.cpp +++ b/test/test-sizes-freertosminimal-nofloat.cpp @@ -40,32 +40,44 @@ namespace nowtech::LogTopics { } constexpr nowtech::log::TaskId cgMaxTaskCount = 1u; +constexpr bool cgAllowRegistrationLog = true; constexpr bool cgLogFromIsr = false; constexpr size_t cgTaskShutdownSleepPeriod = 100u; constexpr bool cgArchitecture64 = false; constexpr uint8_t cgAppendStackBufferSize = 100u; constexpr bool cgAppendBasePrefix = true; constexpr bool cgAlignSigned = false; +using AtomicBufferType = int32_t; +constexpr size_t cgAtomicBufferExponent = 14u; +constexpr AtomicBufferType cgAtomicBufferInvalidValue = 1234546789; constexpr size_t cgTransmitBufferSize = 123u; -constexpr size_t cgPayloadSize = 6u; // This disables 64-bit integer arithmetic. +constexpr size_t cgPayloadSize = 6u; constexpr bool cgSupportFloatingPoint = false; constexpr size_t cgQueueSize = 111u; constexpr nowtech::log::LogTopic cgMaxTopicCount = 2; -constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cName; +constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cId; +constexpr nowtech::log::ErrorLevel cgErrorLevel = nowtech::log::ErrorLevel::Error; + constexpr uint32_t cgLogTaskStackSize = 256u; constexpr uint32_t cgLogTaskPriority = tskIDLE_PRIORITY + 1u; +using LogAppInterface = nowtech::log::AppInterfaceFreeRtosMinimal; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; -/*constexpr size_t cgDirectBufferSize = 43u; -using LogAppInterfaceFreeRtosMinimal = nowtech::log::AppInterfaceFreeRtosMinimal; -constexpr typename LogAppInterfaceFreeRtosMinimal::LogTime cgTimeout = 123u; -constexpr typename LogAppInterfaceFreeRtosMinimal::LogTime cgRefreshPeriod = 444; +//using LogAtomicBuffer = nowtech::log::AtomicBufferVoid; +using LogAtomicBuffer = nowtech::log::AtomicBufferOperational; + +constexpr size_t cgDirectBufferSize = 43u; using LogMessage = nowtech::log::MessageCompact; -using LogConverterCustomText = nowtech::log::ConverterCustomText; -using LogSender = nowtech::log::SenderStmHalMinimal; -using LogQueue = nowtech::log::QueueVoid; -using Log = nowtech::log::Log; - text data bss dec hex filename - 11772 32 19072 30876 789c cpp-logger-embedded.elf +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStmHalMinimal; +using LogQueue = nowtech::log::QueueVoid; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; +/* text data bss dec hex filename +noat 11680 32 19076 30788 7844 cpp-logger-embedded.elf +atom 12008 32 19092 31132 799c cpp-logger-embedded.elf +onlyat 11172 28 19088 30288 7650 cpp-logger-embedded.elf */ /* No log call present at all, not even cout.write, only thread creation: @@ -74,42 +86,40 @@ using Log = nowtech::log::Log; -constexpr typename LogAppInterfaceFreeRtosMinimal::LogTime cgTimeout = 123u; -constexpr typename LogAppInterfaceFreeRtosMinimal::LogTime cgRefreshPeriod = 444; using LogMessage = nowtech::log::MessageCompact; -using LogConverterCustomText = nowtech::log::ConverterCustomText; -using LogSender = nowtech::log::SenderVoid; -using LogQueue = nowtech::log::QueueVoid; -using Log = nowtech::log::Log; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderVoid; +using LogQueue = nowtech::log::QueueVoid; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; text data bss dec hex filename - 7468 24 19016 26508 678c cpp-logger-embedded.elf +noat 7468 24 19016 26508 678c cpp-logger-embedded.elf +atom 7468 24 19016 26508 678c cpp-logger-embedded.elf */ /*constexpr size_t cgDirectBufferSize = 0u; -using LogAppInterfaceFreeRtosMinimal = nowtech::log::AppInterfaceFreeRtosMinimal; -constexpr typename LogAppInterfaceFreeRtosMinimal::LogTime cgTimeout = 123u; -constexpr typename LogAppInterfaceFreeRtosMinimal::LogTime cgRefreshPeriod = 444; using LogMessage = nowtech::log::MessageVariant; -using LogConverterCustomText = nowtech::log::ConverterCustomText; -using LogSender = nowtech::log::SenderStmHalMinimal; -using LogQueue = nowtech::log::QueueFreeRtos; -using Log = nowtech::log::Log; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStmHalMinimal; +using LogQueue = nowtech::log::QueueFreeRtos; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; text data bss dec hex filename - 13908 36 19096 33040 8110 cpp-logger-embedded.elf +noat 13880 32 19100 33012 80f4 cpp-logger-embedded.elf +atom 14608 32 19124 33764 83e4 cpp-logger-embedded.elf */ -constexpr size_t cgDirectBufferSize = 0u; -using LogAppInterfaceFreeRtosMinimal = nowtech::log::AppInterfaceFreeRtosMinimal; -constexpr typename LogAppInterfaceFreeRtosMinimal::LogTime cgTimeout = 123u; -constexpr typename LogAppInterfaceFreeRtosMinimal::LogTime cgRefreshPeriod = 444; +/*constexpr size_t cgDirectBufferSize = 0u; using LogMessage = nowtech::log::MessageCompact; -using LogConverterCustomText = nowtech::log::ConverterCustomText; -using LogSender = nowtech::log::SenderStmHalMinimal; -using LogQueue = nowtech::log::QueueFreeRtos; -using Log = nowtech::log::Log; -/* text data bss dec hex filename - 13660 36 19096 32792 8018 cpp-logger-embedded.elf +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStmHalMinimal; +using LogQueue = nowtech::log::QueueFreeRtos; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; + text data bss dec hex filename +noat 13608 32 19100 32740 7fe4 cpp-logger-embedded.elf +atom 14336 32 19124 33492 82d4 cpp-logger-embedded.elf +onlyat 13676 28 19120 32824 8038 cpp-logger-embedded.elf */ void step() { @@ -122,19 +132,21 @@ int32_t cgInt32; char constexpr cgString[] = "string\n"; extern "C" void myDefaultTask() { - nowtech::log::LogConfig logConfig; - logConfig.allowRegistrationLog = true; + nowtech::log::LogFormatConfig logConfig; LogSender::init(&huart1); Log::init(logConfig, cgLogTaskStackSize, cgLogTaskPriority); - Log::registerTopic(nowtech::LogTopics::system, "system"); - Log::registerTopic(nowtech::LogTopics::surplus, "surplus"); +// Log::registerTopic(nowtech::LogTopics::system, "system"); +// Log::registerTopic(nowtech::LogTopics::surplus, "surplus"); Log::registerCurrentTask("main"); - Log::i(nowtech::LogTopics::surplus) << cgUint32 << Log::end; + /*Log::i(nowtech::LogTopics::surplus) << cgUint32 << Log::end; Log::i(nowtech::LogTopics::system) << cgInt32 << Log::end; Log::n() << cgString << Log::end; - Log::n() << LC::St << cgString << Log::end; + Log::n() << LC::St << cgString << Log::end;*/ + + Log::pushAtomic(cgInt32); + Log::sendAtomicBuffer(); while(true) { step(); From 988fe764cbc4ac15e96cbf79cd19c2a5f7f1f7d7 Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Sun, 31 Jan 2021 12:17:02 +0100 Subject: [PATCH 19/27] Added ROS2 sender. Note, it has a hardcoded loglevel set by trial-error. --- src/LogSenderRos2.h | 60 +++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 60 insertions(+) create mode 100644 src/LogSenderRos2.h diff --git a/src/LogSenderRos2.h b/src/LogSenderRos2.h new file mode 100644 index 0000000..ec901f8 --- /dev/null +++ b/src/LogSenderRos2.h @@ -0,0 +1,60 @@ +#ifndef NOWTECH_LOG_SENDER_ROS2 +#define NOWTECH_LOG_SENDER_ROS2 + +#include +#include "rcutils/logging.h" +#include "Log.h" + +namespace nowtech::log { + +// The buffer it gets in iterators MUST NOT contain %. Otherwise undefined behavior occurs. +template +class SenderRos2 final { +public: + using tAppInterface_ = tAppInterface; + using tConverter_ = tConverter; + using ConversionResult = typename tConverter::ConversionResult; + using Iterator = typename tConverter::Iterator; + + static constexpr bool csVoid = false; + +private: + inline static ConversionResult *sTransmitBuffer; + inline static Iterator sBegin; + inline static Iterator sEnd; + static constexpr int csDummySeverity = 50; // TODO value found by trial-error + inline static constexpr char csDummyName[] = ""; + inline static constexpr char csDummyFunctionName[] = ""; + inline static constexpr char csDummyFilename[] = ""; + inline static constexpr rcutils_log_location_t csDummyLocation = { csDummyFunctionName, csDummyFilename, 0u }; + + SenderRos2() = delete; + +public: + static void init() { + sTransmitBuffer = tAppInterface::template _newArray(tTransmitBufferSize); + sBegin = sTransmitBuffer; + sEnd = sTransmitBuffer + tTransmitBufferSize; + } + + static void done() noexcept { + tAppInterface::template _deleteArray(sTransmitBuffer); + } + + static void send(char const * const aBegin, char const * const aEnd) { + try { + std::string buffer{aBegin, static_cast(aEnd - aBegin)}; + rcutils_log(&csDummyLocation, csDummySeverity, csDummyName, buffer.c_str()); + } catch(...) { + tAppInterface::error(Exception::cSenderError); + } + } + + static auto getBuffer() { + return std::pair(sBegin, sEnd); + } +}; + +} + +#endif \ No newline at end of file From 1f1a68cae81b45c8a03223d39bc6ead90a7126f5 Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Sun, 31 Jan 2021 19:17:42 +0100 Subject: [PATCH 20/27] Bugfix. Added std::string support. Added ROS2 log support. --- README.md | 7 ++++++- src/Log.h | 14 ++++++++++---- src/LogSenderRos2.h | 32 +++++++++++++++++++++----------- 3 files changed, 37 insertions(+), 16 deletions(-) diff --git a/README.md b/README.md index 1d62170..fe924ab 100644 --- a/README.md +++ b/README.md @@ -133,6 +133,10 @@ This is a minimal implementation for STM32 UART using blocking HAL transmission. It is a simple std::ostream wrapper. +### SenderRos2 + +A simple ROS2 log wrapper. + ### AtomicBufferOperational Normal cross-platform implementaiton. @@ -247,6 +251,7 @@ As all major coding standards suggest, use of integer types with indeterminate s |`char` |no |This and the strings support only plain old 8-bit ASCII.| |`char const *` |for no prefix |Can be of arbitrary length for string constants.| |`char const *` |for `LC::St` prefix |Only a limited length of _payload size_ * 255 characters can be transferred from a transient string.| +|`std::string` |no |Implicitely adds `LC::St` prefix, since `std::string` instances are usually mutable.| 64-bit integer types require emulation on 32-bit architectures. By default, `LogConverterCustomText`'s templated conversion routine use 32-bit numbers to gain speed. Using 64-bit operands instantiates the 64-bit emulated routines as well, which takes extra flash space on embedded. @@ -329,7 +334,7 @@ Explanation of configuration parameters: |`TaskRepresentation tTaskRepresentation` |`Config` |One of `cNone` (for omitting it), `cId` (for numeric task ID), `cName` (for task name).| |`size_t tDirectBufferSize` |`Config` |When 0, the given _Queue_ will be used. Otherwise, it is the size of a buffer on stack to hold a converted item before sending it.| |`int32_t tRefreshPeriod` |`Config` |Timeout in implementation-defined unit (usually ms) for waiting on the queue before sending what already present.| -|`ErrorLevel tErrorLevel` |`Config` |The application log level with the default value `ErrorLevel::All`.| +|`ErrorLevel tErrorLevel` |`Config` |The application log level with the default value `ErrorLevel::All`.| |`LogFormat atomicFormat` |`LogFormatConfig` |Format used for converting the bulk data in the _AtomicBuffer_. |`LogFormat taskIdFormat` |`LogFormatConfig` |Format of task ID to use when `tTaskRepresentation == TaskRepresentation::cId`.| |`LogFormat tickFormat` |`LogFormatConfig` |Format for displaying the timestamp in the header, if any. Should be `LogConfig::cInvalid` to disable tick output.| diff --git a/src/Log.h b/src/Log.h index 2710f6c..e4fc7e5 100644 --- a/src/Log.h +++ b/src/Log.h @@ -6,6 +6,7 @@ #include "PoolAllocator.h" #include #include +#include #include #include #include @@ -249,6 +250,11 @@ class Log final { return sendCharPointer(aValue); } + LogShiftChainHelperBackgroundSend& operator<<(std::string const &aValue) noexcept { + mNextFormat = LogFormatConfig::St; + return sendCharPointer(aValue.c_str()); + } + LogShiftChainHelperBackgroundSend& operator<<(LogFormat const aFormat) noexcept { mNextFormat = aFormat; return *this; @@ -614,7 +620,7 @@ class Log final { static LogShiftChainHelper i(LogTopic const aTopic) noexcept { if constexpr(!csShutdownLog) { - if(sRegisteredTopics[aTopic] != nullptr) { + if(aTopic >= 0 && sRegisteredTopics[aTopic] != nullptr) { TaskId const taskId = tAppInterface::getCurrentTaskId(); return sendHeader(taskId, sRegisteredTopics[aTopic]); } @@ -629,7 +635,7 @@ class Log final { static LogShiftChainHelper i(LogTopic const aTopic, TaskId const aTaskId) noexcept { if constexpr(!csShutdownLog) { - if(sRegisteredTopics[aTopic] != nullptr) { + if(aTopic >= 0 && sRegisteredTopics[aTopic] != nullptr) { return sendHeader(aTaskId, sRegisteredTopics[aTopic]); } else { @@ -663,7 +669,7 @@ class Log final { static LogShiftChainHelper n(LogTopic const aTopic) noexcept { if constexpr(!csShutdownLog) { - if(sRegisteredTopics[aTopic] != nullptr) { + if(aTopic >= 0 && sRegisteredTopics[aTopic] != nullptr) { return LogShiftChainHelper{tAppInterface::getCurrentTaskId()}; } else { @@ -677,7 +683,7 @@ class Log final { static LogShiftChainHelper n(LogTopic const aTopic, TaskId const aTaskId) noexcept { if constexpr(!csShutdownLog) { - if(sRegisteredTopics[aTopic] != nullptr) { + if(aTopic >= 0 && sRegisteredTopics[aTopic] != nullptr) { return LogShiftChainHelper{aTaskId}; } else { diff --git a/src/LogSenderRos2.h b/src/LogSenderRos2.h index ec901f8..ce7122b 100644 --- a/src/LogSenderRos2.h +++ b/src/LogSenderRos2.h @@ -1,14 +1,15 @@ #ifndef NOWTECH_LOG_SENDER_ROS2 #define NOWTECH_LOG_SENDER_ROS2 -#include #include "rcutils/logging.h" #include "Log.h" +#include +#include namespace nowtech::log { // The buffer it gets in iterators MUST NOT contain %. Otherwise undefined behavior occurs. -template +template class SenderRos2 final { public: using tAppInterface_ = tAppInterface; @@ -19,14 +20,15 @@ class SenderRos2 final { static constexpr bool csVoid = false; private: - inline static ConversionResult *sTransmitBuffer; - inline static Iterator sBegin; - inline static Iterator sEnd; - static constexpr int csDummySeverity = 50; // TODO value found by trial-error - inline static constexpr char csDummyName[] = ""; - inline static constexpr char csDummyFunctionName[] = ""; - inline static constexpr char csDummyFilename[] = ""; - inline static constexpr rcutils_log_location_t csDummyLocation = { csDummyFunctionName, csDummyFilename, 0u }; + inline static ConversionResult *sTransmitBuffer; + inline static Iterator sBegin; + inline static Iterator sEnd; + inline static constexpr char csDummyName[] = ""; + inline static constexpr char csDummyFunctionName[] = ""; + inline static constexpr char csDummyFilename[] = ""; + inline static constexpr char csFormat[] = "%s"; + inline static constexpr rcutils_log_location_t csDummyLocation = { csDummyFunctionName, csDummyFilename, tSimulatedRos2Loglevel }; + static constexpr char csNewline = '\n'; SenderRos2() = delete; @@ -44,7 +46,15 @@ class SenderRos2 final { static void send(char const * const aBegin, char const * const aEnd) { try { std::string buffer{aBegin, static_cast(aEnd - aBegin)}; - rcutils_log(&csDummyLocation, csDummySeverity, csDummyName, buffer.c_str()); + if(aBegin < aEnd && aEnd[-1] == csNewline) { + buffer.pop_back(); + } + else { // nothing to do + } +#pragma GCC diagnostic push +#pragma GCC diagnostic ignored "-Wformat-security" + rcutils_log(&csDummyLocation, tSimulatedRos2Loglevel, csDummyName, csFormat, buffer.c_str()); +#pragma GCC diagnostic pop } catch(...) { tAppInterface::error(Exception::cSenderError); } From 21b9f3242b7c001521dd279d67d3dfa6c1697983 Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Sun, 31 Jan 2021 19:32:23 +0100 Subject: [PATCH 21/27] Removed unnecessary comment. --- src/LogSenderRos2.h | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/src/LogSenderRos2.h b/src/LogSenderRos2.h index ce7122b..de31c81 100644 --- a/src/LogSenderRos2.h +++ b/src/LogSenderRos2.h @@ -8,7 +8,6 @@ namespace nowtech::log { -// The buffer it gets in iterators MUST NOT contain %. Otherwise undefined behavior occurs. template class SenderRos2 final { public: @@ -67,4 +66,4 @@ class SenderRos2 final { } -#endif \ No newline at end of file +#endif From 2af52551b2cd0dce31d0a3b629bc877b5f2b86f9 Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Mon, 1 Feb 2021 08:01:16 +0100 Subject: [PATCH 22/27] More docs. --- README.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/README.md b/README.md index fe924ab..62e6084 100644 --- a/README.md +++ b/README.md @@ -135,7 +135,7 @@ It is a simple std::ostream wrapper. ### SenderRos2 -A simple ROS2 log wrapper. +A simple ROS2 log wrapper. This wrapper has its own loglevels and every property defined here. However, due to the architecture of this library this wrapper uses only a compile-time hardwired ROS2 loglevel. ### AtomicBufferOperational From ca44ba839836ddf188d7f3ef56d6cecd4c9bd052 Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Fri, 12 Feb 2021 11:30:30 +0100 Subject: [PATCH 23/27] Bugfix. --- src/LogConverterCustomText.h | 8 ++++++-- src/LogMessageCompact.h | 2 +- 2 files changed, 7 insertions(+), 3 deletions(-) diff --git a/src/LogConverterCustomText.h b/src/LogConverterCustomText.h index 8636939..7c9d003 100644 --- a/src/LogConverterCustomText.h +++ b/src/LogConverterCustomText.h @@ -135,8 +135,8 @@ class ConverterCustomText final { appendSpace(); } - void convert(std::array const &aValue, uint8_t const, uint8_t const aFill) noexcept { - append(aValue.data()); + void convert(char const * const aValue, uint8_t const aFill) noexcept { // extra function for MessageCompact + append(aValue); if(aFill < LogFormat::csFillValueStoreString) { // Antipattern to use the fill for other purposes, but we go for space saving. appendSpace(); } @@ -144,6 +144,10 @@ class ConverterCustomText final { } } + void convert(std::array const &aValue, uint8_t const, uint8_t const aFill) noexcept { + convert(aValue.data(), aFill); + } + void terminateSequence() noexcept { append(csEndOfLine); } diff --git a/src/LogMessageCompact.h b/src/LogMessageCompact.h index 4e62f27..f0d5f19 100644 --- a/src/LogMessageCompact.h +++ b/src/LogMessageCompact.h @@ -108,7 +108,7 @@ class MessageCompact final : public MessageBase(mData + csOffsetPayload), base, fill); + aConverter.convert(reinterpret_cast(mData + csOffsetPayload), fill); } else { if constexpr(csPayloadSize >= sizeof(int64_t) || sizeof(char*) > sizeof(int32_t)) { From ac35a7c630ca4f07e3d4bfda2db6caacb08629ac Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Wed, 25 Aug 2021 08:04:37 +0200 Subject: [PATCH 24/27] Changed the boost::lockfree::queue to have compile-time fixed capacity. --- src/LogQueueStdBoost.h | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/src/LogQueueStdBoost.h b/src/LogQueueStdBoost.h index 0730b04..d4ec328 100644 --- a/src/LogQueueStdBoost.h +++ b/src/LogQueueStdBoost.h @@ -19,7 +19,7 @@ class QueueStdBoost final { private: class FreeRtosQueue final { - boost::lockfree::queue mQueue; + boost::lockfree::queue> mQueue; std::atomic mNotified; std::mutex mMutex; std::unique_lock mLock; @@ -28,8 +28,7 @@ class QueueStdBoost final { public: /// First implementation, we assume we have plenty of memory. FreeRtosQueue() noexcept - : mQueue(tQueueSize) - , mLock(mMutex) { + : mLock(mMutex) { mNotified = false; } From 58cc37ae5454842675ca3c1286a8a94a226bc43c Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Wed, 25 Aug 2021 08:46:32 +0200 Subject: [PATCH 25/27] Added queue with lock and circular buffer. --- src/LogQueueStdCircular.h | 107 ++++++++++ ...=> test-sizes-atomic-stdostream-boost.cpp} | 0 .../test-sizes-atomic-stdostream-circular.cpp | 118 +++++++++++ ... => test-sizes-stdthreadostream-boost.cpp} | 0 test/test-sizes-stdthreadostream-circular.cpp | 149 +++++++++++++ ...am.cpp => test-stdthreadostream-boost.cpp} | 0 test/test-stdthreadostream-circular.cpp | 200 ++++++++++++++++++ 7 files changed, 574 insertions(+) create mode 100644 src/LogQueueStdCircular.h rename test/{test-sizes-atomic-stdostream.cpp => test-sizes-atomic-stdostream-boost.cpp} (100%) create mode 100644 test/test-sizes-atomic-stdostream-circular.cpp rename test/{test-sizes-stdthreadostream.cpp => test-sizes-stdthreadostream-boost.cpp} (100%) create mode 100644 test/test-sizes-stdthreadostream-circular.cpp rename test/{test-stdthreadostream.cpp => test-stdthreadostream-boost.cpp} (100%) create mode 100644 test/test-stdthreadostream-circular.cpp diff --git a/src/LogQueueStdCircular.h b/src/LogQueueStdCircular.h new file mode 100644 index 0000000..0b87edb --- /dev/null +++ b/src/LogQueueStdCircular.h @@ -0,0 +1,107 @@ +#ifndef LOG_QUEUE_STD_BOOST +#define LOG_QUEUE_STD_BOOST + +#include +#include +#include +#include + +namespace nowtech::log { + +template +class QueueStdCircular final { +public: + using tMessage_ = tMessage; + using tAppInterface_ = tAppInterface; + using LogTime = typename tAppInterface::LogTime; + + static constexpr size_t csQueueSize = tQueueSize; + +private: + class FreeRtosQueue final { + std::array mQueue; + size_t mNextWrite; + size_t mNextRead; + std::atomic mOccupied; + std::atomic mNotified; + std::mutex mMutexPush; + std::mutex mMutexCv; + std::unique_lock mLockCv; + std::condition_variable mConditionVariable; + + public: + /// First implementation, we assume we have plenty of memory. + FreeRtosQueue() noexcept + : mNextWrite(0u) + , mNextRead(0u) + , mOccupied(0u) + , mLockCv(mMutexCv) { + mNotified = false; + } + + ~FreeRtosQueue() noexcept = default; + + bool empty() const noexcept { + return mOccupied == 0u; + } + + void push(tMessage const &aMessage) noexcept { + std::lock_guard lock(mMutexPush); + if(mOccupied < tQueueSize) { + mQueue[mNextWrite] = aMessage; + mNextWrite = (mNextWrite + 1u) % tQueueSize; + ++mOccupied; + mNotified = true; // Having no lock_guard here makes tremendous speedup. + mConditionVariable.notify_one(); + } + else { // nothing to do + } + } + + bool pop(tMessage &aMessage, LogTime const mPauseLength) noexcept { + bool result; + // Safe to call empty because there will be only one consumer. + if(mOccupied == 0u && + (!mConditionVariable.wait_for(mLockCv, std::chrono::milliseconds(mPauseLength), [this]{return mNotified == true;}) + && !mNotified )) { // This check makes the lock_guard on notifying unnecessary, + // because I don't care if I get in right during waiting or just at the beginning of next check. + result = false; + } + else { + mNotified = false; + aMessage = mQueue[mNextRead]; + mNextRead = (mNextRead + 1u) % tQueueSize; + --mOccupied; + result = true; + } + return result; + } + }; + + inline static FreeRtosQueue sQueue; + + QueueStdBoost() = delete; + +public: + static void init() { // nothing to do + } + + static void done() { // nothing to do + } + + static bool empty() noexcept { + return sQueue.empty(); + } + + static void push(tMessage const &aMessage) noexcept { + sQueue.push(aMessage); + } + + static bool pop(tMessage &aMessage, LogTime const aPauseLength) noexcept { + return sQueue.pop(aMessage, aPauseLength); + } +}; + +} + +#endif diff --git a/test/test-sizes-atomic-stdostream.cpp b/test/test-sizes-atomic-stdostream-boost.cpp similarity index 100% rename from test/test-sizes-atomic-stdostream.cpp rename to test/test-sizes-atomic-stdostream-boost.cpp diff --git a/test/test-sizes-atomic-stdostream-circular.cpp b/test/test-sizes-atomic-stdostream-circular.cpp new file mode 100644 index 0000000..359a121 --- /dev/null +++ b/test/test-sizes-atomic-stdostream-circular.cpp @@ -0,0 +1,118 @@ +// +// Created by balazs on 2020. 12. 03.. +// + +#include "LogAppInterfaceStd.h" +#include "LogConverterCustomText.h" +#include "LogSenderStdOstream.h" +#include "LogSenderVoid.h" +#include "LogQueueVoid.h" +#include "LogQueueStdCircular.h" +#include "LogMessageCompact.h" +#include "Log.h" +#include +#include + +#include + +// clang++ -std=c++20 -Isrc -Icpp-memory-manager -Os -Wl,-Map,test-sizes.map -demangle test/test-sizes-stdthreadostream.cpp -lpthread -o test-sizes +// clang++ -std=c++20 -Isrc -Icpp-memory-manager -Os -S -fno-asynchronous-unwind-tables -fno-dwarf2-cfi-asm -masm=intel test/test-sizes.cpp -o test-sizes.s +// llvm-size-10 test-sizes + +constexpr size_t cgThreadCount = 0; + +constexpr nowtech::log::TaskId cgMaxTaskCount = cgThreadCount + 1; +constexpr bool cgAllowRegistrationLog = true; +constexpr bool cgLogFromIsr = false; +constexpr size_t cgTaskShutdownSleepPeriod = 100u; +constexpr bool cgArchitecture64 = true; +constexpr uint8_t cgAppendStackBufferSize = 100u; +constexpr bool cgAppendBasePrefix = true; +constexpr bool cgAlignSigned = false; +using AtomicBufferType = int32_t; +constexpr size_t cgAtomicBufferExponent = 14u; +constexpr AtomicBufferType cgAtomicBufferInvalidValue = 1234546789; +constexpr size_t cgTransmitBufferSize = 123u; +constexpr size_t cgPayloadSize = 8u; +constexpr bool cgSupportFloatingPoint = true; +constexpr size_t cgQueueSize = 444u; +constexpr nowtech::log::LogTopic cgMaxTopicCount = 2; +constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cName; +constexpr nowtech::log::ErrorLevel cgErrorLevel = nowtech::log::ErrorLevel::Error; + +constexpr size_t cgDirectBufferSize = 43u; +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; +using LogMessage = nowtech::log::MessageCompact; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStdOstream; +using LogQueue = nowtech::log::QueueVoid; +using LogAtomicBuffer = nowtech::log::AtomicBufferOperational; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; +/* + text data bss dec hex filename + 12803 1053 520 14376 3828 test-sizes +*/ + +/* No log call present at all, not even cout.write, only thread creation: + text data bss dec hex filename + 3267 820 4 4091 ffb test-sizes +*/ + +/*constexpr size_t cgDirectBufferSize = 43u; +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; +using LogMessage = nowtech::log::MessageCompact; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderVoid; +using LogQueue = nowtech::log::QueueVoid; +using LogAtomicBuffer = nowtech::log::AtomicBufferOperational; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; +text data bss dec hex filename + 3267 820 4 4091 ffb test-sizes + */ + +/*constexpr size_t cgDirectBufferSize = 0u; +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; +using LogMessage = nowtech::log::MessageCompact; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStdOstream; +using LogQueue = nowtech::log::QueueStdCircular; +using LogAtomicBuffer = nowtech::log::AtomicBufferOperational; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; + text data bss dec hex filename + 23734 1277 920 25931 654b test-sizes + */ + +int32_t gInt32 = 4; + +void todo() noexcept { + gInt32 = getpid(); +} + +int main() { + std::thread thread(todo); + thread.join(); + + nowtech::log::LogFormatConfig logConfig; + LogSender::init(&std::cout); +// LogSender::init(); + Log::init(logConfig); + Log::registerCurrentTask("main"); + + Log::pushAtomic(gInt32); + Log::sendAtomicBuffer(); + + Log::unregisterCurrentTask(); + Log::done(); + + return gInt32; +} + diff --git a/test/test-sizes-stdthreadostream.cpp b/test/test-sizes-stdthreadostream-boost.cpp similarity index 100% rename from test/test-sizes-stdthreadostream.cpp rename to test/test-sizes-stdthreadostream-boost.cpp diff --git a/test/test-sizes-stdthreadostream-circular.cpp b/test/test-sizes-stdthreadostream-circular.cpp new file mode 100644 index 0000000..cbac6fd --- /dev/null +++ b/test/test-sizes-stdthreadostream-circular.cpp @@ -0,0 +1,149 @@ +// +// Created by balazs on 2020. 12. 03.. +// + +#include "LogAppInterfaceStd.h" +#include "LogConverterCustomText.h" +#include "LogSenderStdOstream.h" +#include "LogSenderVoid.h" +#include "LogQueueStdCircular.h" +#include "LogQueueVoid.h" +#include "LogMessageCompact.h" +#include "LogMessageVariant.h" +#include "Log.h" +#include +#include + +#include + +// clang++ -std=c++20 -Isrc -Icpp-memory-manager -Os -Wl,-Map,test-sizes.map -demangle test/test-sizes-stdthreadostream.cpp -lpthread -o test-sizes +// clang++ -std=c++20 -Isrc -Icpp-memory-manager -Os -S -fno-asynchronous-unwind-tables -fno-dwarf2-cfi-asm -masm=intel test/test-sizes.cpp -o test-sizes.s +// llvm-size-10 test-sizes + +constexpr size_t cgThreadCount = 1; + +namespace nowtech::LogTopics { +nowtech::log::TopicInstance system; +nowtech::log::TopicInstance surplus; +} + +constexpr nowtech::log::TaskId cgMaxTaskCount = cgThreadCount + 1; +constexpr bool cgAllowRegistrationLog = true; +constexpr bool cgLogFromIsr = false; +constexpr size_t cgTaskShutdownSleepPeriod = 100u; +constexpr bool cgArchitecture64 = true; +constexpr uint8_t cgAppendStackBufferSize = 100u; +constexpr bool cgAppendBasePrefix = true; +constexpr bool cgAlignSigned = false; +using AtomicBufferType = int32_t; +constexpr size_t cgAtomicBufferExponent = 14u; +constexpr AtomicBufferType cgAtomicBufferInvalidValue = 1234546789; +constexpr size_t cgTransmitBufferSize = 123u; +constexpr size_t cgPayloadSize = 8u; +constexpr bool cgSupportFloatingPoint = true; +constexpr size_t cgQueueSize = 444u; +constexpr nowtech::log::LogTopic cgMaxTopicCount = 2; +constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cName; +constexpr nowtech::log::ErrorLevel cgErrorLevel = nowtech::log::ErrorLevel::Error; + +/*constexpr size_t cgDirectBufferSize = 43u; +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; +using LogMessage = nowtech::log::MessageVariant; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStdOstream; +using LogQueue = nowtech::log::QueueVoid; +using LogAtomicBuffer = nowtech::log::AtomicBufferVoid; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; + text data bss dec hex filename + 15118 1101 496 16715 414b test-sizes +*/ + +/* No log call present at all, not even cout.write, only thread creation: + text data bss dec hex filename + 3283 828 4 4115 1013 test-sizes +*/ + +/*constexpr size_t cgDirectBufferSize = 43u; +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; +using LogMessage = nowtech::log::MessageVariant; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderVoid; +using LogQueue = nowtech::log::QueueVoid; +using LogAtomicBuffer = nowtech::log::AtomicBufferVoid; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; + text data bss dec hex filename + 3283 828 4 4115 1013 test-sizes + */ + +/* +constexpr size_t cgDirectBufferSize = 0u; +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; +using LogMessage = nowtech::log::MessageVariant; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStdOstream; +using LogQueue = nowtech::log::QueueStdCircular; +using LogAtomicBuffer = nowtech::log::AtomicBufferVoid; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; + text data bss dec hex filename + 26086 1285 896 28267 6e6b test-sizes + */ + + +constexpr size_t cgDirectBufferSize = 0u; +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; +using LogMessage = nowtech::log::MessageCompact; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStdOstream; +using LogQueue = nowtech::log::QueueStdCircular; +using LogAtomicBuffer = nowtech::log::AtomicBufferVoid; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; +/* text data bss dec hex filename + 24458 1285 896 26639 680f test-sizes + */ + +uint32_t cgUint32 = 3; +int32_t cgInt32 = 4; +double constexpr cgReal = 3.3; +char constexpr cgString[] = "string\n"; + +void todo() noexcept { + cgUint32 = getpid(); +} + +int main() { + cgInt32 = getpid(); + std::thread thread(todo); + thread.join(); + + nowtech::log::LogFormatConfig logConfig; + LogSender::init(&std::cout); +// LogSender::init(); + Log::init(logConfig); + + Log::registerTopic(nowtech::LogTopics::system, "system"); + Log::registerTopic(nowtech::LogTopics::surplus, "surplus"); + Log::registerCurrentTask("main"); + + Log::i(nowtech::LogTopics::surplus) << cgUint32 << Log::end; + Log::i(nowtech::LogTopics::system) << cgInt32 << Log::end; + Log::n() << cgReal << cgString << Log::end; + Log::n() << cgReal << LC::St << cgString << Log::end; + + Log::unregisterCurrentTask(); + Log::done(); + + return cgInt32 + cgUint32; +} + diff --git a/test/test-stdthreadostream.cpp b/test/test-stdthreadostream-boost.cpp similarity index 100% rename from test/test-stdthreadostream.cpp rename to test/test-stdthreadostream-boost.cpp diff --git a/test/test-stdthreadostream-circular.cpp b/test/test-stdthreadostream-circular.cpp new file mode 100644 index 0000000..fe297dc --- /dev/null +++ b/test/test-stdthreadostream-circular.cpp @@ -0,0 +1,200 @@ +/* + * Copyright 2018 Now Technologies Zrt. + * + * Permission is hereby granted, free of charge, to any person + * obtaining a copy of this software and associated documentation + * files (the "Software"), to deal in the Software without restriction, + * including without limitation the rights to use, copy, modify, merge, + * publish, distribute, sublicense, and/or sell copies of the Software, + * and to permit persons to whom the Software is furnished to do so, + * subject to the following conditions: + * + * The above copyright notice and this permission notice shall be included + * in all copies or substantial portions of the Software. + * + * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS + * OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF + * MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. + * IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY + * CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, + * TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH + * THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE. + */ + +#include "LogAppInterfaceStd.h" +#include "LogConverterCustomText.h" +#include "LogSenderStdOstream.h" +#include "LogQueueStdCircular.h" +#include "LogMessageCompact.h" +#include "LogMessageVariant.h" +#include "Log.h" + +#include +#include +#include + +// clang++ -std=c++20 -Isrc -Icpp-memory-manager test/test-stdthreadostream.cpp -lpthread -o test-stdthreadostream + +constexpr size_t cgThreadCount = 4; + +char cgThreadNames[10][10] = { + "thread_0", + "thread_1", + "thread_2", + "thread_3", + "thread_4", + "thread_5", + "thread_6", + "thread_7", + "thread_8", + "thread_9" +}; + +namespace nowtech::LogTopics { + nowtech::log::TopicInstance system; + nowtech::log::TopicInstance surplus; +} + +constexpr nowtech::log::TaskId cgMaxTaskCount = cgThreadCount + 1; +constexpr bool cgAllowRegistrationLog = true; +constexpr bool cgLogFromIsr = false; +constexpr size_t cgTaskShutdownSleepPeriod = 100u; +constexpr bool cgArchitecture64 = true; +constexpr uint8_t cgAppendStackBufferSize = 100u; +constexpr bool cgAppendBasePrefix = true; +constexpr bool cgAlignSigned = false; +using AtomicBufferType = int32_t; +constexpr size_t cgAtomicBufferExponent = 14u; +constexpr AtomicBufferType cgAtomicBufferInvalidValue = 1234546789; +constexpr size_t cgTransmitBufferSize = 123u; +constexpr size_t cgPayloadSize = 14u; +constexpr bool cgSupportFloatingPoint = true; +constexpr size_t cgQueueSize = 444u; +constexpr nowtech::log::LogTopic cgMaxTopicCount = 2; +constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cName; +constexpr size_t cgDirectBufferSize = 0u; +constexpr nowtech::log::ErrorLevel cgErrorLevel = nowtech::log::ErrorLevel::Error; + +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; +using LogMessage = nowtech::log::MessageCompact; +using LogConverterCustomText = nowtech::log::ConverterCustomText; +using LogSenderStdOstream = nowtech::log::SenderStdOstream; +using LogQueueStdCircular = nowtech::log::QueueStdCircular; +using LogAtomicBuffer = nowtech::log::AtomicBufferOperational; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; + +void delayedLog(size_t n) { + Log::registerCurrentTask(cgThreadNames[n]); + Log::i(nowtech::LogTopics::system) << static_cast(n) << ": " << static_cast(0) << Log::end; + for(int64_t i = 1; i < 7; ++i) { + std::this_thread::sleep_for(std::chrono::milliseconds(1 << i)); + Log::i(nowtech::LogTopics::system) << static_cast(n) << "thread delay logarithm: " << LC::X1 << i << Log::end; + } + Log::unregisterCurrentTask(); +} + +std::atomic gCounter; +constexpr int32_t cgAtomicCount = 100; + +void atomicLog(size_t n) { + Log::registerCurrentTask(cgThreadNames[n]); + for(int32_t i = 0; i < cgAtomicCount; ++i) { + Log::pushAtomic(gCounter++); + } + Log::unregisterCurrentTask(); +} + +char gTextToCopy[] = "This_text_will_be_copied_in_messages."; + +int main() { + std::thread threads[cgThreadCount + 1u]; // let there be zero threads + + nowtech::log::LogFormatConfig logConfig; + LogSenderStdOstream::init(&std::cout); + Log::init(logConfig); + + Log::registerTopic(nowtech::LogTopics::system, "system"); + Log::registerTopic(nowtech::LogTopics::surplus, "surplus"); + Log::registerCurrentTask("main"); + + uint64_t const uint64 = 123456789012345; + int64_t const int64 = -123456789012345; + + Log::i(nowtech::LogTopics::surplus) << "message" << Log::end; + for(size_t remaining = std::strlen(gTextToCopy); remaining > 0u; --remaining) { + gTextToCopy[remaining] = 0; + Log::n() << LC::St << gTextToCopy << '#' << Log::end; + } + + Log::i(nowtech::LogTopics::system) << "uint64: " << uint64 << " int64: " << int64 << Log::end; + Log::n(nowtech::LogTopics::system) << "uint64: " << uint64 << " int64: " << int64 << Log::end; + Log::i() << "uint64: " << uint64 << " int64: " << int64 << Log::end; + Log::n() << "uint64: " << uint64 << " int64: " << int64 << Log::end; + + uint8_t const uint8 = 42; + int8_t const int8 = -42; + + try { + Log::i(nowtech::LogTopics::system) << uint8 << ' ' << int8 << Log::end; + Log::i(nowtech::LogTopics::system) << LC::X2 << uint8 << ' ' << LC::D3 << int8 << Log::end; + Log::i() << uint8 << ' ' << int8 << Log::end; + Log::i() << LC::X2 << uint8 << int8 << Log::end; + Log::i() << Log::end; + } + catch(std::exception &e) { + Log::i() << "Exception: " << e.what() << Log::end; + } + + Log::i() << "int8: " << static_cast(123) << Log::end; + Log::i() << "int16: " << static_cast(123) << Log::end; + Log::i() << "int32: " << static_cast(123) << Log::end; + Log::i() << "int64: " << static_cast(123) << Log::end; + Log::i() << "uint8: " << static_cast(123) << Log::end; + Log::i() << "uint16: " << static_cast(123) << Log::end; + Log::i() << "uint32: " << static_cast(123) << Log::end; + Log::i() << "uint64: " << static_cast(123) << Log::end; + Log::i() << "float: " << 1.234567890f << Log::end; + Log::i() << "double: " << -1.234567890 << Log::end; + Log::i() << "float: " << LC::Fm << -123.4567890f << Log::end; + Log::i() << "double: " << LC::Fm << 123.4567890 << Log::end; +// Log::i() << "long double: " << -0.01234567890L << Log::end; +// Log::i() << "long double: " << LC::D16 << 0.01234567890L << Log::end; + Log::i() << "bool:" << true << Log::end; + Log::i() << "bool:" << false << Log::end; + + Log::i() << "fatal" << Log::end; + Log::i() << "error" << Log::end; + Log::i() << "warning" << Log::end; + Log::i() << "info" << Log::end; + Log::i() << "debug" << Log::end; + Log::n() << "fatal" << Log::end; + Log::n() << "error" << Log::end; + Log::n() << "warning" << Log::end; + Log::n() << "info" << Log::end; + Log::n() << "debug" << Log::end; + + for(size_t i = 0; i < cgThreadCount; ++i) { + threads[i] = std::thread(delayedLog, i); + } + for(size_t i = 0; i < cgThreadCount; ++i) { + threads[i].join(); + } + + gCounter = 0; + for(size_t i = 0; i < cgThreadCount; ++i) { + threads[i] = std::thread(atomicLog, i); + } + for(size_t i = 0; i < cgThreadCount; ++i) { + threads[i].join(); + } + Log::sendAtomicBuffer(); + Log::n() << Log::end; + + Log::unregisterCurrentTask(); + Log::done(); + return 0; +} + From 8ed92cb733088df3eef1330468ad0cf5ae6e4e47 Mon Sep 17 00:00:00 2001 From: Balazs Bamer Date: Fri, 3 Sep 2021 11:23:38 +0200 Subject: [PATCH 26/27] Bugfix and new benchmark. --- README.md | 18 ++-- benchmark/picobench-direct.cpp | 26 ++++-- ...ct.cpp => picobench-msg-compact-boost.cpp} | 24 ++++- benchmark/picobench-msg-compact-circular.cpp | 93 +++++++++++++++++++ ...nt.cpp => picobench-msg-variant-boost.cpp} | 25 ++++- benchmark/picobench-msg-variant-circular.cpp | 92 ++++++++++++++++++ src/LogQueueStdCircular.h | 2 +- 7 files changed, 256 insertions(+), 24 deletions(-) rename benchmark/{picobench-msg-compact.cpp => picobench-msg-compact-boost.cpp} (84%) create mode 100644 benchmark/picobench-msg-compact-circular.cpp rename benchmark/{picobench-msg-variant.cpp => picobench-msg-variant-boost.cpp} (84%) create mode 100644 benchmark/picobench-msg-variant-circular.cpp diff --git a/README.md b/README.md index 62e6084..c835ae3 100644 --- a/README.md +++ b/README.md @@ -121,6 +121,10 @@ It uses the FreeRTOS' built-in queue, so no locking is needed on sending. Sendin This one uses a multi-producer multi-consumer lockfree queue of Boost, so no locking is needed either. +### QueueStdCircular + +This one uses a simple circular buffer with `std::lock_guard`. + ### SenderVoid Emply implementation for the case when all the log calls have to be eliminated from the binary. This happens at gcc and clang optimization levels -Os, -O1, -O2 and -O3. The application can use a template metaprogramming technique to declare a Log using this as the appropriate parameter, so no #ifdef is needed. @@ -164,19 +168,19 @@ public: ## Benchmarks -I used [picobench](https://github.com/iboB/picobench) for benchmarks using the supplied bechmark apps. Here are some averaged results measured on 8192 iterations on my _Intel(R) Xeon(R) CPU E31220L @ 2.20GHz_. Compiled using `clang++ -O2`. There were no significant differences for `MessageVariant` or `MessageCompact`. Log activity was +I used [picobench](https://github.com/iboB/picobench) for benchmarks using the supplied bechmark apps. Here are some averaged results measured on 8192 iterations on my _Intel(R) Xeon(R) CPU E31220L @ 2.20GHz_. Compiled using `clang++ -O2`. There were no significant differences for `MessageVariant` or `MessageCompact`, or whether the task ID was provided or not. Log activity was - print header - print task name - print timestamp - print the logged string -Each value is the average time required for _one_ log call in nanoseconds. +Each value is the average time required for _one_ log call in nanoseconds. Each result is an average of 8 runs, each having 262144 iterations. -|Scenario |Unknown `TaskId` (ns)|Provided `TaskId` (ns)| -|-------------------------|--------------------:|---------------------:| -|direct |250 |190 | -|Constant string (no copy)|500 |430 | -|Transient string (copy) |580 |500 | +|Scenario |Constant string (no copy)|Transient string (copy)| +|-------------------------|------------------------:|----------------------:| +|direct |230 |230 | +|Lockfree queue |310 |500 | +|Circular buffer and lock |430 |590 | Here are benchmark results of atomic logging `int32_t` values, measured on 2097152 iterations. Note that this does not include offline buffer sending, so it is the same for any logger mode: diff --git a/benchmark/picobench-direct.cpp b/benchmark/picobench-direct.cpp index 983a5f5..aa567bd 100644 --- a/benchmark/picobench-direct.cpp +++ b/benchmark/picobench-direct.cpp @@ -7,7 +7,6 @@ #include "LogConverterCustomText.h" #include "LogSenderStdOstream.h" #include "LogSenderVoid.h" -#include "LogQueueStdBoost.h" #include "LogQueueVoid.h" #include "LogMessageCompact.h" #include "LogMessageVariant.h" @@ -47,19 +46,34 @@ using Log = nowtech::log::Log; nowtech::log::TaskId gTaskId; -void nowtechLogRef(picobench::state& s) { +void nowtechLogRefTaskId(picobench::state& s) { for (auto _ : s) { Log::i(gTaskId) << "Info message" << Log::end; } } -PICOBENCH(nowtechLogRef); +PICOBENCH(nowtechLogRefTaskId); -void nowtechLogAtomic(picobench::state& s) { +void nowtechLogCopyTaskId(picobench::state& s) { for (auto _ : s) { - Log::pushAtomic(gTaskId); + Log::i(gTaskId) << LC::St << "Info message" << Log::end; } } -PICOBENCH(nowtechLogAtomic); +PICOBENCH(nowtechLogCopyTaskId); + +void nowtechLogRefNoTaskId(picobench::state& s) { + for (auto _ : s) { + Log::i() << "Info message" << Log::end; + } +} +PICOBENCH(nowtechLogRefNoTaskId); + +void nowtechLogCopyNoTaskId(picobench::state& s) { + for (auto _ : s) { + Log::i() << LC::St << "Info message" << Log::end; + } +} +PICOBENCH(nowtechLogCopyNoTaskId); + int main(int argc, char* argv[]) { diff --git a/benchmark/picobench-msg-compact.cpp b/benchmark/picobench-msg-compact-boost.cpp similarity index 84% rename from benchmark/picobench-msg-compact.cpp rename to benchmark/picobench-msg-compact-boost.cpp index e4c98a6..c1fd51c 100644 --- a/benchmark/picobench-msg-compact.cpp +++ b/benchmark/picobench-msg-compact-boost.cpp @@ -28,7 +28,7 @@ constexpr AtomicBufferType cgAtomicBufferInvalidValue = 1234546789; constexpr size_t cgTransmitBufferSize = 444444u; constexpr size_t cgPayloadSize = 8u; constexpr bool cgSupportFloatingPoint = true; -constexpr size_t cgQueueSize = 444444u; +constexpr size_t cgQueueSize = 44444u; constexpr nowtech::log::LogTopic cgMaxTopicCount = 2; constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cName; constexpr size_t cgDirectBufferSize = 0u; @@ -47,19 +47,33 @@ using Log = nowtech::log::Log; nowtech::log::TaskId gTaskId; -void nowtechLogRef(picobench::state& s) { +void nowtechLogRefTaskId(picobench::state& s) { for (auto _ : s) { Log::i(gTaskId) << "Info message" << Log::end; } } -PICOBENCH(nowtechLogRef); +PICOBENCH(nowtechLogRefTaskId); -void nowtechLogCopy(picobench::state& s) { +void nowtechLogCopyTaskId(picobench::state& s) { for (auto _ : s) { Log::i(gTaskId) << LC::St << "Info message" << Log::end; } } -PICOBENCH(nowtechLogCopy); +PICOBENCH(nowtechLogCopyTaskId); + +void nowtechLogRefNoTaskId(picobench::state& s) { + for (auto _ : s) { + Log::i() << "Info message" << Log::end; + } +} +PICOBENCH(nowtechLogRefNoTaskId); + +void nowtechLogCopyNoTaskId(picobench::state& s) { + for (auto _ : s) { + Log::i() << LC::St << "Info message" << Log::end; + } +} +PICOBENCH(nowtechLogCopyNoTaskId); int main(int argc, char* argv[]) { diff --git a/benchmark/picobench-msg-compact-circular.cpp b/benchmark/picobench-msg-compact-circular.cpp new file mode 100644 index 0000000..5b048ea --- /dev/null +++ b/benchmark/picobench-msg-compact-circular.cpp @@ -0,0 +1,93 @@ +#define PICOBENCH_IMPLEMENT +#define PICOBENCH_DEFAULT_SAMPLES 10 +#include "picobench/picobench.hpp" + +#include "LogAppInterfaceStd.h" +#include "LogConverterCustomText.h" +#include "LogSenderStdOstream.h" +#include "LogQueueStdCircular.h" +#include "LogQueueVoid.h" +#include "LogMessageCompact.h" +#include "LogMessageVariant.h" +#include "Log.h" +#include +#include + +constexpr nowtech::log::TaskId cgMaxTaskCount = 1; +constexpr bool cgAllowRegistrationLog = true; +constexpr bool cgLogFromIsr = false; +constexpr size_t cgTaskShutdownSleepPeriod = 100u; +constexpr bool cgArchitecture64 = true; +constexpr uint8_t cgAppendStackBufferSize = 100u; +constexpr bool cgAppendBasePrefix = true; +constexpr bool cgAlignSigned = false; +using AtomicBufferType = int32_t; +constexpr size_t cgAtomicBufferExponent = 14u; +constexpr AtomicBufferType cgAtomicBufferInvalidValue = 1234546789; +constexpr size_t cgTransmitBufferSize = 444444u; +constexpr size_t cgPayloadSize = 8u; +constexpr bool cgSupportFloatingPoint = true; +constexpr size_t cgQueueSize = 444444u; +constexpr nowtech::log::LogTopic cgMaxTopicCount = 2; +constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cName; +constexpr size_t cgDirectBufferSize = 0u; +constexpr nowtech::log::ErrorLevel cgErrorLevel = nowtech::log::ErrorLevel::Info; + +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; +using LogMessage = nowtech::log::MessageCompact; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStdOstream; +using LogQueue = nowtech::log::QueueStdCircular; +using LogAtomicBuffer = nowtech::log::AtomicBufferOperational; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; + +nowtech::log::TaskId gTaskId; + +void nowtechLogRefTaskId(picobench::state& s) { + for (auto _ : s) { + Log::i(gTaskId) << "Info message" << Log::end; + } +} +PICOBENCH(nowtechLogRefTaskId); + +void nowtechLogCopyTaskId(picobench::state& s) { + for (auto _ : s) { + Log::i(gTaskId) << LC::St << "Info message" << Log::end; + } +} +PICOBENCH(nowtechLogCopyTaskId); + +void nowtechLogRefNoTaskId(picobench::state& s) { + for (auto _ : s) { + Log::i() << "Info message" << Log::end; + } +} +PICOBENCH(nowtechLogRefNoTaskId); + +void nowtechLogCopyNoTaskId(picobench::state& s) { + for (auto _ : s) { + Log::i() << LC::St << "Info message" << Log::end; + } +} +PICOBENCH(nowtechLogCopyNoTaskId); + + +int main(int argc, char* argv[]) +{ + nowtech::log::LogFormatConfig logConfig; + std::ofstream out("tmp"); + LogSender::init(&out); + Log::init(logConfig); + Log::registerCurrentTask("main"); + gTaskId = Log::getCurrentTaskId(); + + picobench::runner r; + r.parse_cmd_line(argc, argv); + auto ret = r.run(); + Log::unregisterCurrentTask(); + Log::done(); + return ret; +} diff --git a/benchmark/picobench-msg-variant.cpp b/benchmark/picobench-msg-variant-boost.cpp similarity index 84% rename from benchmark/picobench-msg-variant.cpp rename to benchmark/picobench-msg-variant-boost.cpp index dac5180..5da55f9 100644 --- a/benchmark/picobench-msg-variant.cpp +++ b/benchmark/picobench-msg-variant-boost.cpp @@ -28,7 +28,7 @@ constexpr AtomicBufferType cgAtomicBufferInvalidValue = 1234546789; constexpr size_t cgTransmitBufferSize = 444444u; constexpr size_t cgPayloadSize = 8u; constexpr bool cgSupportFloatingPoint = true; -constexpr size_t cgQueueSize = 444444u; +constexpr size_t cgQueueSize = 44444u; constexpr nowtech::log::LogTopic cgMaxTopicCount = 2; constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cName; constexpr size_t cgDirectBufferSize = 0u; @@ -47,19 +47,34 @@ using Log = nowtech::log::Log; nowtech::log::TaskId gTaskId; -void nowtechLogRef(picobench::state& s) { +void nowtechLogRefTaskId(picobench::state& s) { for (auto _ : s) { Log::i(gTaskId) << "Info message" << Log::end; } } -PICOBENCH(nowtechLogRef); +PICOBENCH(nowtechLogRefTaskId); -void nowtechLogCopy(picobench::state& s) { +void nowtechLogCopyTaskId(picobench::state& s) { for (auto _ : s) { Log::i(gTaskId) << LC::St << "Info message" << Log::end; } } -PICOBENCH(nowtechLogCopy); +PICOBENCH(nowtechLogCopyTaskId); + +void nowtechLogRefNoTaskId(picobench::state& s) { + for (auto _ : s) { + Log::i() << "Info message" << Log::end; + } +} +PICOBENCH(nowtechLogRefNoTaskId); + +void nowtechLogCopyNoTaskId(picobench::state& s) { + for (auto _ : s) { + Log::i() << LC::St << "Info message" << Log::end; + } +} +PICOBENCH(nowtechLogCopyNoTaskId); + int main(int argc, char* argv[]) { diff --git a/benchmark/picobench-msg-variant-circular.cpp b/benchmark/picobench-msg-variant-circular.cpp new file mode 100644 index 0000000..0703d34 --- /dev/null +++ b/benchmark/picobench-msg-variant-circular.cpp @@ -0,0 +1,92 @@ +#define PICOBENCH_IMPLEMENT +#define PICOBENCH_DEFAULT_SAMPLES 10 +#include "picobench/picobench.hpp" + +#include "LogAppInterfaceStd.h" +#include "LogConverterCustomText.h" +#include "LogSenderStdOstream.h" +#include "LogSenderVoid.h" +#include "LogQueueStdCircular.h" +#include "LogMessageCompact.h" +#include "LogMessageVariant.h" +#include "Log.h" +#include +#include + +constexpr nowtech::log::TaskId cgMaxTaskCount = 1; +constexpr bool cgAllowRegistrationLog = true; +constexpr bool cgLogFromIsr = false; +constexpr size_t cgTaskShutdownSleepPeriod = 100u; +constexpr bool cgArchitecture64 = true; +constexpr uint8_t cgAppendStackBufferSize = 100u; +constexpr bool cgAppendBasePrefix = true; +constexpr bool cgAlignSigned = false; +using AtomicBufferType = int32_t; +constexpr size_t cgAtomicBufferExponent = 14u; +constexpr AtomicBufferType cgAtomicBufferInvalidValue = 1234546789; +constexpr size_t cgTransmitBufferSize = 444444u; +constexpr size_t cgPayloadSize = 8u; +constexpr bool cgSupportFloatingPoint = true; +constexpr size_t cgQueueSize = 444444u; +constexpr nowtech::log::LogTopic cgMaxTopicCount = 2; +constexpr nowtech::log::TaskRepresentation cgTaskRepresentation = nowtech::log::TaskRepresentation::cName; +constexpr size_t cgDirectBufferSize = 0u; +constexpr nowtech::log::ErrorLevel cgErrorLevel = nowtech::log::ErrorLevel::Info; + +using LogAppInterface = nowtech::log::AppInterfaceStd; +constexpr typename LogAppInterface::LogTime cgTimeout = 123u; +constexpr typename LogAppInterface::LogTime cgRefreshPeriod = 444; +using LogMessage = nowtech::log::MessageVariant; +using LogConverter = nowtech::log::ConverterCustomText; +using LogSender = nowtech::log::SenderStdOstream; +using LogQueue = nowtech::log::QueueStdCircular; +using LogAtomicBuffer = nowtech::log::AtomicBufferOperational; +using LogConfig = nowtech::log::Config; +using Log = nowtech::log::Log; + +nowtech::log::TaskId gTaskId; + +void nowtechLogRefTaskId(picobench::state& s) { + for (auto _ : s) { + Log::i(gTaskId) << "Info message" << Log::end; + } +} +PICOBENCH(nowtechLogRefTaskId); + +void nowtechLogCopyTaskId(picobench::state& s) { + for (auto _ : s) { + Log::i(gTaskId) << LC::St << "Info message" << Log::end; + } +} +PICOBENCH(nowtechLogCopyTaskId); + +void nowtechLogRefNoTaskId(picobench::state& s) { + for (auto _ : s) { + Log::i() << "Info message" << Log::end; + } +} +PICOBENCH(nowtechLogRefNoTaskId); + +void nowtechLogCopyNoTaskId(picobench::state& s) { + for (auto _ : s) { + Log::i() << LC::St << "Info message" << Log::end; + } +} +PICOBENCH(nowtechLogCopyNoTaskId); + +int main(int argc, char* argv[]) +{ + nowtech::log::LogFormatConfig logConfig; + std::ofstream out("tmp"); + LogSender::init(&out); + Log::init(logConfig); + Log::registerCurrentTask("main"); + gTaskId = Log::getCurrentTaskId(); + + picobench::runner r; + r.parse_cmd_line(argc, argv); + auto ret = r.run(); + Log::unregisterCurrentTask(); + Log::done(); + return ret; +} diff --git a/src/LogQueueStdCircular.h b/src/LogQueueStdCircular.h index 0b87edb..7827485 100644 --- a/src/LogQueueStdCircular.h +++ b/src/LogQueueStdCircular.h @@ -80,7 +80,7 @@ class QueueStdCircular final { inline static FreeRtosQueue sQueue; - QueueStdBoost() = delete; + QueueStdCircular() = delete; public: static void init() { // nothing to do From 5848dac574c19505345e602e45845fb438e5db07 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bal=C3=A1zs=20B=C3=A1mer?= Date: Sun, 23 Nov 2025 18:45:39 +0100 Subject: [PATCH 27/27] Fixed spelling in README.md --- README.md | 116 +++++++++++++++++++++++++++--------------------------- 1 file changed, 58 insertions(+), 58 deletions(-) diff --git a/README.md b/README.md index c835ae3..9bcd897 100644 --- a/README.md +++ b/README.md @@ -1,4 +1,4 @@ -# C++ template-based crossplatform log library +# C++ template-based cross-platform log library ```C++ // Stripped template instantiations. @@ -26,7 +26,7 @@ Log::done(); This is a complete rework of my [old logger](https://github.com/balazs-bamer/cpp-logger/tree/old/) after identifying the design flaws and performance problems. The library requires C++17. -The code was written to possibly conform MISRA C++ and High-Integrity C++. +The code was written to possibly conform to MISRA C++ and High-Integrity C++. The library is published under the [MIT license](https://opensource.org/licenses/MIT). @@ -35,18 +35,18 @@ Copyright 2020 Balázs Bámer. ## Aims - Provide a common logger API for cross-platform embedded / desktop code. -- Use as minimal code and data space as possible. I'm not sure if I'm was good enough obtaining it. On STM32 Cortex M3, flash overhead of direct sending mode is **4k**, queued multithreading mode id **6k**. Anyway, no more time to further develop this library. -- The library was designed to allow the programmer control log bandwidth usage, program and data memory consumption. +- Use as minimal code and data space as possible. I'm not sure if I was good enough to obtain it. On STM32 Cortex M3, flash overhead of direct sending mode is **4k**, queued multithreading mode id **6k**. Anyway, no more time to further develop this library. +- The library was designed to allow the programmer control of log bandwidth usage, program and data memory consumption. - Log arithmetic C++ types and strings with or without copying them (beneficial for literals). - String literals or string constants can be transferred using their pointers to save MCU cycles. - More transient strings will be copied instantly. - Operate in a _strictly typed_ way as opposed to the printf-based loggers some companies still use today. -- We needed a much finer granularity than the usual log levels, so I've introduced independently selectable topics. Recently I've also added traditional log levels. +- We needed a much finer granularity than the usual log levels, so I've introduced independently selectable topics. Recently, I've also added traditional log levels. - Provide blazing-fast atomic logging of one integral type into a buffer. Its contents can later be converted and sent. -- Important aim was to let the user log a _group of related items_ without other tasks interleaving the output of converting these items. -- Possibly minimal relying on external libraries. It does not depend on numeric to string conversion functions. +- An important aim was to let the user log a _group of related items_ without other tasks interleaving the output of converting these items. +- Possibly minimal reliance on external libraries. It does not depend on numeric-to-string conversion functions. - In contrast with the original solution, the new one extensively uses templated classes to - - implement a flexible plugin architecture for adapting different user needs + - implement a flexible plugin architecture for adapting to different user needs - let the compiler optimizer do its finest. - _totally eliminate_ logging code generation with at least -O1 optimization level with a one-line change (template logic, without #ifdef). - Let the user decide to rely on C++ exceptions or implement a different kind of error management. @@ -67,27 +67,27 @@ The logger consists of six classes: - Obtaining the task name in C string. - Obtaining timestamps using some OS / STL time routine. - Error management. -- _Message_ - used as a transfer medium in the Queue. For numeric types and strings transferred by pointers, one message is needed per item. For stored strings several messages may be necessary. There are two general-purpose implementations: - - a variant based message. +- _Message_ - used as a transfer medium in the Queue. For numeric types and strings transferred by pointers, one message is needed per item. For stored strings, several messages may be necessary. There are two general-purpose implementations: + - a variant-based message. - a more space-efficient handcrafted message. -- _AtomicBuffer_ - provides buffer and instrumentation for the atomic logging. This bypasses all the queues and logic used to log groups of various types. +- _AtomicBuffer_ - provides a buffer and instrumentation for the atomic logging. This bypasses all the queues and logic used to log groups of various types. - _Config_ - provides some configuration parameters. The logger can operate in two modes: -- Direct without queue, when the conversion and sending happens without message instantiation and queue usage. This can be useful for single-threaded applications. -- With queue, when each item sent will form one or more (in case of stored strings) message and use a central thread-safe queue. On the other end of the queue a background thread pops the messages and groups them by tasks in secondary lists. When a group of related items from a task has arrived, its conversion and sending begins. +- Direct without queue, when the conversion and sending happen without message instantiation and queue usage. This can be useful for single-threaded applications. +- With a queue, when each item is sent, it will form one or more (in case of stored strings) messages and use a central thread-safe queue. On the other end of the queue, a background thread pops the messages and groups them by tasks in secondary lists. When a group of related items from a task has arrived, its conversion and sending begin. ## Implementations -The current library provides some simple implementations for STL and Boost based desktop and server applications and FreeRTOS based embedded applications. The whole implementation assumes an architecture of at least 32 bits. +The current library offers simple implementations for STL and Boost-based desktop and server applications, as well as FreeRTOS-based embedded applications. The whole implementation assumes an architecture of at least 32 bits. ### Log This is a general implementation, but tailored for embedded requirements. -In queue-less mode, conversion and sending happens immediately for each item. Thus it is desirable that the Sender has some sort of buffering inside. +In queue-less mode, conversion and sending happen immediately for each item. Thus ,it is desirable that the Sender has some sort of buffering inside. -For the queue mode, it contains a secondary list or queue for each task, which gather the items in each logged group. After the terminal item arrives, conversion happens for each item in the sender buffer and then comes the sending. These secondary queues are backed by a pool allocator to avoid repeated dynamic memory access. +For the queue mode, it contains a secondary list or queue for each task, which gathers the items in each logged group. After the terminal item arrives, conversion occurs for each item in the sender buffer, and then the sending process begins. These secondary queues are backed by a pool allocator to avoid repeated dynamic memory access. ### ConverterCustomText @@ -102,24 +102,24 @@ A simple converter emitting character strings, with an emphasis on space-efficie ### AppInterfaceFreeRtosMinimal -This implementation assumes FreeRTOS 10.0.1, but should work as well as with 9.x or perhaps even older. The main objective was to keep it as simple and small as possible. It provides global overload of new and delete operators using FreeRTOS' dynamic memory management, but itself uses only a statically allocated array. It uses a linear array for task registry and omits unregistering, because a typical embedded application creates all the tasks beforehand and never kills them. Task names are native FreeRTOS task names. For similar reasons, logger shutdown is not implemented. -There is a design flaw in the library: checking for ISRs happen here, so the FreeRTOS implementation contains an MCU-specific function, here for STM32. However, it is easy to replace with the one for the actual MCU. +This implementation assumes FreeRTOS 10.0.1, but should also work with versions 9.x or possibly even older. The main objective was to keep it as simple and small as possible. It provides a global overload of new and delete operators using FreeRTOS' dynamic memory management, but itself uses only a statically allocated array. It uses a linear array for the task registry and omits unregistering, as a typical embedded application typically creates all tasks beforehand and never kills them. Task names are native to FreeRTOS. For similar reasons, logger shutdown is not implemented. +There is a design flaw in the library: checking for ISRs happens here, so the FreeRTOS implementation contains an MCU-specific function, here for STM32. However, it is easy to replace it with the one for the actual MCU. ### AppInterfaceStd -This is a general desktop-oriented C++17 STL implementation targeting speed over space. It uses a hash set and thread local storage for task registration, and task unregistration is also supported. The task registy API is protected by a mutex. Other, more frequently called functions work without locking. Logger initialization and shutdown are properly implemented. +This is a general, desktop-oriented C++17 STL implementation that prioritises speed over space. It uses a hash set and thread-local storage for task registration, and task unregistration is also supported. The task registry API is protected by a mutex. Other, more frequently called functions work without locking. Logger initialisation and shutdown are properly implemented. ### QueueVoid -Empty implementation, used for placeholder when no queue is needed. +An empty implementation is used as a placeholder when no queue is required. ### QueueFreeRtos -It uses the FreeRTOS' built-in queue, so no locking is needed on sending. Sending into the queue can happen from an ISR. +It utilises FreeRTOS's built-in queue, so no locking is required for sending. Sending an item into the queue can occur from an ISR. ### QueueStdBoost -This one uses a multi-producer multi-consumer lockfree queue of Boost, so no locking is needed either. +This one uses a multi-producer, multi-consumer lock-free queue of Boost, so no locking is needed either. ### QueueStdCircular @@ -127,11 +127,11 @@ This one uses a simple circular buffer with `std::lock_guard`. ### SenderVoid -Emply implementation for the case when all the log calls have to be eliminated from the binary. This happens at gcc and clang optimization levels -Os, -O1, -O2 and -O3. The application can use a template metaprogramming technique to declare a Log using this as the appropriate parameter, so no #ifdef is needed. +Empty implementation for the case when all the log calls have to be eliminated from the binary. This occurs at GCC and Clang optimisation levels -Os, -O1, -O2, and -O3. The application can utilise a template metaprogramming technique to declare a Log, using this as the appropriate parameter, so no #ifdef is required. ### SenderStmHalMinimal -This is a minimal implementation for STM32 UART using blocking HAL transmission. A more sophisticated one would use double buffering with DMA to use the MCU more efficiently and allow buffering new data during the potentially slow transmission of the old buffer. This mechanism is implemented in the old version. +This is a minimal implementation for the STM32 UART using blocking HAL transmission. A more sophisticated approach would utilise double buffering with DMA to optimise the MCU's efficiency and allow for buffering new data during the potentially slow transmission of the old buffer. This mechanism is implemented in the old version. ### SenderStdOstream @@ -139,19 +139,19 @@ It is a simple std::ostream wrapper. ### SenderRos2 -A simple ROS2 log wrapper. This wrapper has its own loglevels and every property defined here. However, due to the architecture of this library this wrapper uses only a compile-time hardwired ROS2 loglevel. +A simple ROS2 log wrapper. This wrapper has its own log levels and every property defined here. However, due to the architecture of this library, this wrapper uses only a compile-time hardwired ROS2 log level. ### AtomicBufferOperational -Normal cross-platform implementaiton. +Normal cross-platform implementation. ### AtomicBufferVoid -Used instead the normal one to strip its static variables when not in use. +Used the normal one instead to strip its static variables when not in use. ### Config -Converts the template arguments into public static variables. One can use it or write a template-less direct class instead using this example: +Converts the template arguments into public static variables. One can use it or write a template-less direct class instead, using this example: ```C++ template @@ -168,7 +168,7 @@ public: ## Benchmarks -I used [picobench](https://github.com/iboB/picobench) for benchmarks using the supplied bechmark apps. Here are some averaged results measured on 8192 iterations on my _Intel(R) Xeon(R) CPU E31220L @ 2.20GHz_. Compiled using `clang++ -O2`. There were no significant differences for `MessageVariant` or `MessageCompact`, or whether the task ID was provided or not. Log activity was +I used [picobench](https://github.com/iboB/picobench) for benchmarks using the supplied benchmark apps. Here are some averaged results measured over 8192 iterations on my Intel(R) Xeon(R) CPU E31220L @ 2.20GHz. Compiled using `clang++ -O2`. There were no significant differences for `MessageVariant` or `MessageCompact`, or whether the task ID was provided or not. Log activity was - print header - print task name - print timestamp @@ -191,10 +191,10 @@ Here are benchmark results of atomic logging `int32_t` values, measured on 20971 ## Space requirements -I have investigated several scenarios using simple applications which contain practically nothing but a task creation apart of the logging. This way I could measure the net space required by the log library and its necessary supplementary functions like std::unordered_set or floating-point emulation for log10. +I have investigated several scenarios using simple applications which contain practically nothing but a task creation apart of the logging. This way, I could measure the net space required by the log library and its necessary supplementary functions, such as std::unordered_set or floating-point emulation for log10. -For desktop, I used clang version 10.0.0 on x64. For embedded, I used arm-none-eabi-g++ 10.1.1 on STM32 Cortex M3. This MCU needs emulation for floating point. All measurements were conducted using -Os. I present the net growths in segments text, data and BSS for each of the following scenarios: -- direct logging (for single threaded applications) +For desktop, I used clang version 10.0.0 on x64. For embedded development, I used arm-none-eabi-g++ 10.1.1 on an STM32 Cortex-M3. This MCU requires emulation for floating-point operations. All measurements were conducted using -Os. I present the net growth in segments, text, data and BSS for each of the following scenarios: +- direct logging (for single-threaded applications) - logging turned off with SenderVoid - logging with queue using MessageVariant (for multithreaded applications) - logging with queue using MessageCompact (for multithreaded applications) @@ -215,7 +215,7 @@ To obtain net results, I put some floating-point operations in the application * ### FreeRTOS without floating point -No floating point arithmetics in the application and the support is turned off in the logger. Source is *test-sizes-freertosminimal-nofloat.cpp*. Note , only this table contains values from the _only atomic logging_ scenario, since atomic logging assumes only integral types. +No floating-point arithmetic is used in the application, and support is turned off in the logger. Source is *test-sizes-freertosminimal-nofloat.cpp*. Note, only this table contains values from the _only atomic logging_ scenario, since atomic logging assumes only integral types. |Atomic|Mode | Text| Data| BSS| |------|------------------|------:|-----:|------:| @@ -228,13 +228,13 @@ No floating point arithmetics in the application and the support is turned off i |off |multitask, compact|6140 |8 |84 | |on |multitask, compact|6868 |8 |108 | -* = when only using atomic logging, multitasking mode is meaningless. +* = When only using atomic logging, multitasking mode is meaningless. ## API ### Supported types -As all major coding standards suggest, use of integer types with indeterminate size is discouraged, so this library does not support `long` or `unsigned`. +As all major coding standards suggest, the use of integer types with indeterminate size is discouraged; therefore, this library does not support `long` or `unsigned`. `LogFormat` is a struct holding the numeric base and the fill value. It is easiest to reach in `LogConfig`. @@ -257,20 +257,20 @@ As all major coding standards suggest, use of integer types with indeterminate s |`char const *` |for `LC::St` prefix |Only a limited length of _payload size_ * 255 characters can be transferred from a transient string.| |`std::string` |no |Implicitely adds `LC::St` prefix, since `std::string` instances are usually mutable.| -64-bit integer types require emulation on 32-bit architectures. By default, `LogConverterCustomText`'s templated conversion routine use 32-bit numbers to gain speed. Using 64-bit operands instantiates the 64-bit emulated routines as well, which takes extra flash space on embedded. +64-bit integer types require emulation on 32-bit architectures. By default, `LogConverterCustomText`'s templated conversion routine uses 32-bit numbers to gain speed. Using 64-bit operands instantiates the 64-bit emulated routines as well, which takes extra flash space on embedded. ### Initialization -Log system initialiation consists of the following steps: +Log system initialisation consists of the following steps: 1. Declare possible topics (see next section). 2. Instantiate templates. -3. Define and fill `LogConfig` struct. All its fields have default value. -4. Initialize the _Sender_. This has implementation-specific arguments for the actual output. +3. Define and fill `LogConfig` struct. All its fields have a default value. +4. Initialise the _Sender_. This has implementation-specific arguments for the actual output. 5. Initialize the _Log_ using the _LogConfig_ instance. -6. Register the required topics (see nextr section). +6. Register the required topics (see next section). 7. Call `Log::registerCurrentTask("task name");` for each interested task. Other tasks won't be able to log. -Refer the beginning for an example for STL without the first step. Here is a FreeRTOS template declaration without floating point support but for multithreaded mode: +Refer to the beginning for an example of STL without the first step. Here is a FreeRTOS template declaration without floating point support, but for multithreaded mode: ```C++ constexpr nowtech::log::TaskId cgMaxTaskCount = cgThreadCount + 1; @@ -320,13 +320,13 @@ Explanation of configuration parameters: |`bool tAlignSigned` |_Converter_ |If true, positive numbers will get an extra ' ' to be aligned with negatives. | |`typename tAppInterface` |_Sender_ |The _app interface_ type to use.| |`typename tConverter` |_Sender_ |The _Converter_ type to use.| -|`size_t tTransmitBufferSize` |_Sender_ |Length of buffer to use for conversion. This should be sufficient for the joint size of possible items in the largest group.| +|`size_t tTransmitBufferSize` |_Sender_ |Length of buffer to use for conversion. This should be sufficient for the joint size of the largest group of possible items.| |`typename tAppInterface::LogTime tTimeout` |_Sender_ |Timeout in implementation-defined unit (usually ms) for transmission.| |`typename tMessage` |_Queue_ |The _Message_ type to use.| |`typename tAppInterface` |_Queue_ |The _app interface_ type to use.| |`size_t tQueueSize` |_Queue_ |Number of items the queue should hold. This applies to the master queue and to the aggregated capacity of the per-task queues.| |`typename tAppInterface` |`AtomicBufferOperational`|The _app interface_ to use.| -|`typename tAtomicBufferType` |`AtomicBufferOperational`|The type to log as atomic, only integral types are allowed.| +|`typename tAtomicBufferType` |`AtomicBufferOperational`|The type to log as atomic; only integral types are allowed.| |`tAtomicBufferSizeExponent` |`AtomicBufferOperational`|Exponent of the buffer size (base of the power is 2). For numeric reasons, the buffer size is always a power of 2.| |`tAtomicBufferType tInvalidValue` |`AtomicBufferOperational`|Invalid value, which won't be sent when all the buffer contents are being sent.| |`typename tQueue` |`Log` |The _Queue_ type to use.| @@ -336,8 +336,8 @@ Explanation of configuration parameters: |`bool allowRegistrationLog` |`Config` |True if task (un)registering should be logged.| |`LogTopic tMaxTopicCount` |`Config` |LogTopic is `int8_t`. Maximum is 127.| |`TaskRepresentation tTaskRepresentation` |`Config` |One of `cNone` (for omitting it), `cId` (for numeric task ID), `cName` (for task name).| -|`size_t tDirectBufferSize` |`Config` |When 0, the given _Queue_ will be used. Otherwise, it is the size of a buffer on stack to hold a converted item before sending it.| -|`int32_t tRefreshPeriod` |`Config` |Timeout in implementation-defined unit (usually ms) for waiting on the queue before sending what already present.| +|`size_t tDirectBufferSize` |`Config` |When 0, the given _Queue_ will be used. Otherwise, it is the size of a buffer on the stack to hold a converted item before sending it.| +|`int32_t tRefreshPeriod` |`Config` |Timeout in implementation-defined unit (usually ms) for waiting on the queue before sending what is already present.| |`ErrorLevel tErrorLevel` |`Config` |The application log level with the default value `ErrorLevel::All`.| |`LogFormat atomicFormat` |`LogFormatConfig` |Format used for converting the bulk data in the _AtomicBuffer_. |`LogFormat taskIdFormat` |`LogFormatConfig` |Format of task ID to use when `tTaskRepresentation == TaskRepresentation::cId`.| @@ -346,7 +346,7 @@ Explanation of configuration parameters: ### Topics and log levels -The log system supports individually selectable topics to log. I've decided so because we needed a much finer granularity than the tradiotional log levels. These topics have to be declared first, after which they still would be disabled. +The log system supports individually selectable topics to log. I've decided so because we needed a much finer granularity than the traditional log levels. These topics must be declared first, after which they will still be disabled. ```C++ namespace nowtech::LogTopics { @@ -358,13 +358,13 @@ nowtech::log::TopicInstance someOtherTopic; } ``` -To enable some of them, the interesting ones must be registered in the log system. When the log system receives `LogTopic` parameter, it will be logged regardless of the actual applicaiton log level. +To enable some of them, the interesting ones must be registered in the log system. When the log system receives the `LogTopic` parameter, it will be logged regardless of the actual application log level. There are three possibilities to use log levels. #### Native log levels -The `Log` class takes an optional template argument, the application log level. The `Log::n(...)` and `Log::i(...)` functions' overloads without operands and taking a `TaskId` (see below) are templated methods with a default value of `ErrorLevel::All`. By providing template values these for methods, the given instantiation chooses between a functional and an empty return value. As the empty one will be fully optimized out for unused log levels, this is more performant than the next one. The log system has these predefined log levels in `Log`: +The `Log` class takes an optional template argument, the application log level. The `Log::n(...)` and `Log::i(...)` functions' overloads without operands and taking a `TaskId` (see below) are templated methods with a default value of `ErrorLevel::All`. By providing template values for these methods, the given instantiation chooses between a functional and an empty return value. As the empty one will be fully optimised out for unused log levels, this is more performant than the next one. The log system has these predefined log levels in `Log`: ```C++ static constexpr ErrorLevel fatal = ErrorLevel::Fatal; @@ -383,7 +383,7 @@ Log::i() << "x:" << LC::D4 << posX << "y:" << LC::D4 << posY << Log: #### Emulated log levels -For topic declarations, please refer above. This method suits better architectures with limited flash space, since it requires no internal method instantiation for each log level used. However, checking topics is a runtime process and total elimination of unused log statements won't happen for optimizing compilation. +For topic declarations, please refer to the section above. This method suits better architectures with limited flash space, since it requires no internal method instantiation for each log level used. However, checking topics is a runtime process, and total elimination of unused log statements won't happen for optimising compilation. ```C++ #ifdef LEVEL1 @@ -400,13 +400,13 @@ Log::registerTopic(nowtech::LogTopics::level3, "level3"); #### Variadic macros -C++20 has suitable variadic macros in the preprocessor, which would enable one to use the folding expression API to define preprocessor-implemented loglevels. I didn't implement it. This would mean a perfect solution from performance and space point of view. +C++20 features suitable variadic macros in the preprocessor, enabling the use of the folding expression API to define preprocessor-implemented log levels. I didn't implement it. This would mean a perfect solution from a performance and space point of view. ### Logging #### Group logging -All the logging API is implemented as static functions in the `Log` template class. Logging happens using a `std::ostream` -like API, like in the example in the beginning. There are two overloaded functions to start the chain: +All logging APIs are implemented as static functions in the `Log` template class. Logging happens using a `std::ostream` -like API, like in the example at the beginning. There are two overloaded functions to start the chain: - `static LogShiftChainHelper i(...) noexcept` writes any header configured for the application. - `static LogShiftChainHelper n(...) noexcept` omits this header, just writes the actual stuff it receives using `<<`. Note, LogShiftChainHelper implementation depends on the given log mode (direct / queued / shut off). @@ -414,12 +414,12 @@ Note, LogShiftChainHelper implementation depends on the given log mode (direct / Each function has four overloads with the following parameter signatures: - `()` - logs unconditionally, and queries the task ID. - `(TaskId const aTaskId)` - logs unconditionally using the supplied task ID. -- `(LogTopic const aTopic)` - logs depending on the given task ID was registered, and queries the task ID. -- `(LogTopic const aTopic, TaskId const aTaskId)` - logs depending on the given task ID was registered using the supplied task ID. +- `(LogTopic const aTopic)` - logs depending on the given task ID were registered, and queries the task ID. +- `(LogTopic const aTopic, TaskId const aTaskId)` - logs depending on the given task ID were registered using the supplied task ID. -One can use the `static TaskId getCurrentTaskId() noexcept` function to query the current task ID and store it, This can be important if querying the task ID is expensive on the given platform. +One can use the `static TaskId getCurrentTaskId() noexcept` function to query the current task ID and store it. This can be important if querying the task ID is expensive on the given platform. -If you have many or unknown number of items to log, you can use the form +If you have many or an unknown number of items to log, you can use the form ```C++ auto logger = Log::n() << "someCollection contgents:"; @@ -435,7 +435,7 @@ I've implemented a function call-like entry point using C++17 folding expression Log::f(Log::i(nowtech::LogTopics::someTopic), some, variables, follow); ``` -and apart of being clumsy, it is even takes more binary space than the `std::ostream` -like API it uses under the hood. It appends `Log::end` automatically. +and apart from being clumsy, it even takes more binary space than the `std::ostream` -like API it uses under the hood. It appends `Log::end` automatically. #### Atomic logging @@ -446,10 +446,10 @@ int16_t value = 13; Log::pushAtomic(value); ``` -Of course this is only effective if the logging is on and the `AtomicBufferOperational` class is being used. These values are accepted from any task or ISR and land in a circular buffer, which is continuously overwritten. To extract the contents, first the application should stop calling `Log::pushAtomic` because the slower readout would produce undefined behaviour when still being written into. (There is no locking for maximum performance.) Then, a task with valid log registry should call +Of course, this is only effective if the logging is on and the `AtomicBufferOperational` class is being used. These values are accepted from any task or ISR and land in a circular buffer, which is continuously overwritten. To extract the contents, the application should first stop calling `Log::pushAtomic`, as the slower readout would produce undefined behaviour when it is still being written to. (There is no locking for maximum performance.) Then, a task with a valid log registry should call ```C++ Log::sendAtomicBuffer(); ``` -which is a blocking call. Note, in multithreaded mode sending from all other tasks won't happen, only the queues will hold the messages from concurrent logging as long as they can. +which is a blocking call. Note that in multithreaded mode, sending from all other tasks will not occur; only the queues will hold messages from concurrent logging as long as possible.