From 243b22e4c1b6337204923f7e2cc48b179dc799d9 Mon Sep 17 00:00:00 2001 From: nojhan Date: Tue, 15 Sep 2020 23:07:42 +0200 Subject: [PATCH] feat: optimize out in Release builds - fix: fastest scope matching, - feat: try to allow the compiler to optimize out as many conditional statements as possible, which allow to use clutchlog for progress-only messages in Release mode. - feat: build_all.sh test script, - fix: typo in macro declarations in builds without clutchlog, - update the README accordingly. --- CMakeLists.txt | 7 +- README.md | 47 ++++++++++- build_all.sh | 25 ++++++ clutchlog/clutchlog.h | 182 ++++++++++++++++++++++++++++++++++++++---- tests/t-dump.cpp | 3 - tests/t-log.cpp | 4 - 6 files changed, 239 insertions(+), 29 deletions(-) create mode 100755 build_all.sh diff --git a/CMakeLists.txt b/CMakeLists.txt index e2ddb63..12d1386 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -16,9 +16,6 @@ set(VERSION_MINOR 1 CACHE STRING "Minor version number" ) set(VERSION_PATCH 0 CACHE STRING "Patch version number" ) mark_as_advanced(VERSION_MAJOR VERSION_MINOR VERSION_PATCH) -# There's no point building clutchlog tests in Release -set(CMAKE_BUILD_TYPE Debug) - set(CMAKE_CXX_STANDARD_LIBRARIES -lstdc++fs) ###################################################################################### @@ -33,6 +30,10 @@ set(CMAKE_RUNTIME_OUTPUT_DIRECTORY ${CMAKE_BINARY_DIR}) # Dump used compiler flags. set(CMAKE_EXPORT_COMPILE_COMMANDS ON) +option(WITH_CLUTCHLOG "Define WITH_CLUTCHLOG, whatever the build type." OFF) +if(WITH_CLUTCHLOG) + add_definitions(-DWITH_CLUTCHLOG) +endif() ###################################################################################### # Start building diff --git a/README.md b/README.md index 8b07a1c..6556b7a 100644 --- a/README.md +++ b/README.md @@ -12,7 +12,7 @@ Clutchlog allows to select which log messages will be displayed, based on their - *source code location*: you can ask to display messages called from given files, functions and line number, all based on regular expressions. -Of course, Clutchlog is disabled by default if `NDEBUG` is not defined. +Of course, Clutchlog is disabled by default if not in "Debug" mode. Example @@ -165,6 +165,37 @@ and its default with the `CLUTCHLOG_DEFAULT_DEPTH_MARK` macro: log.depth_mark(CLUTCHLOG_DEFAULT_DEPTH_MARK); // Defaults to ">". ``` + +Disabled calls +-------------- + +By default, clutchlog is always enabled if the `NDEBUG` preprocessor variable is not defined +(this variable is set by CMake in build types that differs from `Debug`). + +You can however force clutchlog to be enabled in any build type +by setting the `WITH_CLUTCHLOG` preprocessor variable. + +When the `NDEBUG` preprocessor variable is set (e.g. in `Release` build), +clutchlog will do its best to allow the compiler to optimize out any calls +for log levels which are under or equal to `progress`. + +You can change this behavior at compile time by setting the +`CLUTCHLOG_DEFAULT_DEPTH_BUILT_NODEBUG` preprocessor variable +to the desired maximum log level, for example: +``` +// Will always allow to log everything even in Release mode. +#define CLUTCHLOG_DEFAULT_DEPTH_BUILT_NODEBUG clutchlog::level::xdebug +``` + +Note that allowing a log level does not mean that it will actually output something. +If the configured log level at runtime is lower than the log level of the message, +it will still not be printed. + +This behavior intend to remove as many conditional statements as possible +when not debugging, without having to use preprocessor guards around +calls to clutchlog, thus saving run time at no readability cost. + + Low-level API ------------- @@ -199,15 +230,23 @@ Clutchlog is only implemented for Linux at the moment. Build and tests =============== -To use clutchlog, just include its header in your code. +To use clutchlog, just include its header in your code +and either ensure that the `NDEBUG` preprocessor variable is not set, +either define the `WITH_CLUTCHLOG` preprocessor variable. + +If you're using CMake (or another modern build system), +it will unset `NDEBUG` ---and thus enable clutchlog--- +only for the "Debug" build type, +which is usually what you want if you use clutchlog, anyway. To build and run the tests, just use a classical CMake workflow: ```sh mkdir build cd build -# There's no point building in Release mode, at clutchlog is declutched. -cmake -DCMAKE_BUILD_TYPE=Debug .. +cmake -DCMAKE_BUILD_TYPE=Debug -DWITH_CLUTCHLOG=ON .. make ctest ``` +There's a script which tests all the build types combinations: `./build_all.sh`. + diff --git a/build_all.sh b/build_all.sh new file mode 100755 index 0000000..09c3562 --- /dev/null +++ b/build_all.sh @@ -0,0 +1,25 @@ +#!/bin/bash + +build() +{ + build_dir="$1_$2" + mkdir -p $build_dir + cd $build_dir + echo -ne "Build type: $1,\twith clutchlog: $2...\t" + (cmake -DCMAKE_BUILD_TYPE=$1 -DWITH_CLUTCHLOG=$2 .. && make && ctest) 2>&1 >> ../build_all.log + if [[ $? == 0 ]]; then + echo "OK" + else + echo "ERROR" + fi + cd .. +} + +rm -f build_all.log + +for t in "Debug" "Release" "RelWithDebInfo"; do + for w in "ON" "OFF"; do + build $t $w + done +done + diff --git a/clutchlog/clutchlog.h b/clutchlog/clutchlog.h index f25d299..3fae2b0 100644 --- a/clutchlog/clutchlog.h +++ b/clutchlog/clutchlog.h @@ -1,5 +1,6 @@ #ifndef __CLUTCHLOG_H__ #define __CLUTCHLOG_H__ +#pragma once #include #include @@ -36,48 +37,74 @@ #ifndef CLUTCHLOG_DEFAULT_FORMAT //! Default format of the messages. #define CLUTCHLOG_DEFAULT_FORMAT "[{name}] {level_letter}:{depth_marks} {msg}\t\t\t\t\t{func} @ {file}:{line}\n" -#endif +#endif // CLUTCHLOG_DEFAULT_FORMAT #ifndef CLUTCHDUMP_DEFAULT_FORMAT //! Default format of the comment line in file dump. #define CLUTCHDUMP_DEFAULT_FORMAT "# [{name}] {level} in {func} (at depth {depth}) @ {file}:{line}" -#endif +#endif // CLUTCHDUMP_DEFAULT_FORMAT #ifndef CLUTCHDUMP_DEFAULT_SEP //! Default item separator for dump. #define CLUTCHDUMP_DEFAULT_SEP "\n" -#endif +#endif // CLUTCHDUMP_DEFAULT_SEP #ifndef CLUTCHLOG_DEFAULT_DEPTH_MARK #define CLUTCHLOG_DEFAULT_DEPTH_MARK ">" -#endif +#endif // CLUTCHLOG_DEFAULT_DEPTH_MARK + +#ifndef CLUTCHLOG_DEFAULT_DEPTH_BUILT_NODEBUG +#define CLUTCHLOG_DEFAULT_DEPTH_BUILT_NODEBUG clutchlog::level::progress +#endif // CLUTCHLOG_DEFAULT_DEPTH_BUILT //! Handy shortcuts to location. #define CLUTCHLOC __FILE__, __FUNCTION__, __LINE__ //! Log a message at the given level. +#ifndef NDEBUG #define CLUTCHLOG( LEVEL, WHAT ) { \ auto& logger = clutchlog::logger(); \ std::ostringstream msg ; msg << WHAT; \ logger.log(clutchlog::level::LEVEL, msg.str(), CLUTCHLOC); \ } +#else // not Debug build. +#define CLUTCHLOG( LEVEL, WHAT ) { \ + if(clutchlog::level::LEVEL <= CLUTCHLOG_DEFAULT_DEPTH_BUILT_NODEBUG) { \ + auto& logger = clutchlog::logger(); \ + std::ostringstream msg ; msg << WHAT; \ + logger.log(clutchlog::level::LEVEL, msg.str(), CLUTCHLOC); \ + } \ +} +#endif // NDEBUG //! Dump the given container. +#ifndef NDEBUG #define CLUTCHDUMP( LEVEL, CONTAINER, FILENAME ) { \ auto& logger = clutchlog::logger(); \ - logger.dump(clutchlog::level::LEVEL, std::begin(CONTAINER), std::end(CONTAINER), CLUTCHLOC, FILENAME, CLUTCHDUMP_DEFAULT_SEP); \ + logger.dump(clutchlog::level::LEVEL, std::begin(CONTAINER), std::end(CONTAINER), \ + CLUTCHLOC, FILENAME, CLUTCHDUMP_DEFAULT_SEP); \ } +#else // not Debug build. +#define CLUTCHDUMP( LEVEL, CONTAINER, FILENAME ) { \ + if(clutchlog::level::LEVEL <= CLUTCHLOG_DEFAULT_DEPTH_BUILT_NODEBUG) { \ + auto& logger = clutchlog::logger(); \ + logger.dump(clutchlog::level::LEVEL, std::begin(CONTAINER), std::end(CONTAINER), \ + CLUTCHLOC, FILENAME, CLUTCHDUMP_DEFAULT_SEP); \ + } \ +} +#endif // NDEBUG -#else +#else // not WITH_CLUTCHLOG // Disabled macros can still be used in Release builds. -#define CLUTCHLOG ( LEVEL, WHAT ) { do {/*nothing*/} while(false); } -#define CLUTCHDUMP ( LEVEL, CONTAINER, FILENAME ) { do {/*nothing*/} while(false); } -#endif +#define CLUTCHLOG( LEVEL, WHAT ) { do {/*nothing*/} while(false); } +#define CLUTCHDUMP( LEVEL, CONTAINER, FILENAME ) { do {/*nothing*/} while(false); } +#endif // WITH_CLUTCHLOG /********************************************************************** * Implementation **********************************************************************/ +#ifdef WITH_CLUTCHLOG //! Singleton class. class clutchlog { @@ -149,6 +176,12 @@ class clutchlog level stage; // current log level size_t depth; // current depth bool there; // location is compatible + scope_t() : + matches(false), + stage(level::xdebug), + depth(0), + there(false) + {} }; //! Gather information on the current location of the call. @@ -159,24 +192,39 @@ class clutchlog const size_t line ) const { + scope_t scope; // False scope by default. + + /***** Log level stage *****/ + // Test stage first, because it's fastest. + scope.stage = stage; + if(not (scope.stage <= _stage)) { + // Bypass useless computations if no match + // because of the stage. + return scope; + } + + /***** Stack depth *****/ + // Backtrace in second, quite fast. const size_t max_buffer = 4096; size_t stack_depth; void *buffer[max_buffer]; stack_depth = backtrace(buffer, max_buffer); - - scope_t scope; - scope.stage = stage; scope.depth = stack_depth; + if(not (scope.depth <= _depth + _strip_calls)) { + // Bypass if no match. + return scope; + } + /***** Location *****/ + // Location last, slowest. std::ostringstream sline; sline << line; scope.there = std::regex_search(file, _in_file) and std::regex_search(func, _in_func) and std::regex_search(sline.str(), _in_line); - scope.matches = scope.stage <= _stage - and scope.depth <= _depth + _strip_calls - and scope.there; + // No need to retest stage and depth, which are true here. + scope.matches = scope.there; return scope; } @@ -396,4 +444,108 @@ class clutchlog /** }@ Low-level API */ }; +#else // not WITH_CLUTCHLOG + +// Equivalent class with empty methods, will be optimized out +// while allowing to actually have calls implemented without WITH_CLUTCHLOG guards. +#pragma GCC diagnostic push +#pragma GCC diagnostic ignored "-Wreturn-type" +class clutchlog +{ + public: + static clutchlog& logger() { } + enum level {quiet=0, error=1, warning=2, progress=3, info=4, debug=5, xdebug=6}; + public: + clutchlog(clutchlog const&) = delete; + void operator=(clutchlog const&) = delete; + private: + clutchlog() {} + protected: + struct scope_t {}; + scope_t locate( + const level&, + const std::string&, + const std::string&, + const size_t + ) const + { } + public: + void format(const std::string&) {} + std::string format() const {} + + void format_comment(const std::string&) {} + std::string format_comment() const {} + + void out(std::ostream&) {} + std::ostream& out() {} + + void depth(size_t) {} + size_t depth() const {} + + void depth_mark(std::string) {} + std::string depth_mark() const {} + + void threshold(level) {} + level threshold() const {} + + void file(std::string) {} + void func(std::string) {} + void line(std::string) {} + +#pragma GCC diagnostic push +#pragma GCC diagnostic ignored "-Wunused-parameter" + void location( + const std::string&, + const std::string& in_function=".*", + const std::string& in_line=".*" + ) + { } +#pragma GCC diagnostic pop + public: + std::string replace( + const std::string&, + const std::string&, + const std::string& + ) const + { } + + std::string replace( + const std::string&, + const std::string&, + const size_t + ) const + { } + + std::string format( + std::string, + const std::string&, + const std::string&, + const level&, + const std::string&, + const std::string&, + const size_t, + const size_t + ) const + { } + + void log( + const level&, + const std::string&, + const std::string&, const std::string&, size_t + ) const + { } + + template + void dump( + const level&, + const In, const In, + const std::string&, const std::string&, size_t, + const std::string&, + const std::string + ) const + { } +}; +#pragma GCC diagnostic pop +#endif // WITH_CLUTCHLOG + #endif // __CLUTCHLOG_H__ diff --git a/tests/t-dump.cpp b/tests/t-dump.cpp index 0dcee47..e28818b 100644 --- a/tests/t-dump.cpp +++ b/tests/t-dump.cpp @@ -6,8 +6,6 @@ int main(/*const int argc, char* argv[]*/) { -#ifdef WITH_CLUTCHLOG - auto& log = clutchlog::logger(); log.out(std::clog); @@ -20,5 +18,4 @@ int main(/*const int argc, char* argv[]*/) std::vector v(3); std::generate(v.begin(), v.end(), std::rand); CLUTCHDUMP(info, v, "rand_{n}.dat"); -#endif } diff --git a/tests/t-log.cpp b/tests/t-log.cpp index 5c75029..e7669c3 100644 --- a/tests/t-log.cpp +++ b/tests/t-log.cpp @@ -22,8 +22,6 @@ void f() int main(/*const int argc, char* argv[]*/) { -#ifdef WITH_CLUTCHLOG - auto& log = clutchlog::logger(); log.out(std::clog); @@ -57,6 +55,4 @@ int main(/*const int argc, char* argv[]*/) log.threshold(clutchlog::level::debug); log.location(".*","(g|h)"); f(); - -#endif }