diff --git a/CMakeLists.txt b/CMakeLists.txt index 2cc662e..80298d2 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -22,6 +22,15 @@ message(STATUS "${BWhite}${PROJECT_NAME}${CR} ${FairLogger_GIT_VERSION} from ${F set_fairlogger_defaults() include(CTest) + +option(USE_BOOST_PRETTY_FUNCTION "Use Boost BOOST_PRETTY_FUNCTION macro" OFF) +################################################################################ + + +# Dependency ################################################################### +if(USE_BOOST_PRETTY_FUNCTION) + find_package(Boost REQUIRED) +endif() ################################################################################ @@ -37,6 +46,11 @@ add_library(FairLogger logger/Logger.h ) +if(USE_BOOST_PRETTY_FUNCTION) + target_link_libraries(FairLogger PUBLIC Boost::boost) + target_compile_definitions(FairLogger PUBLIC FAIRLOGGER_USE_BOOST_PRETTY_FUNCTION) +endif() + target_include_directories(FairLogger PUBLIC $ diff --git a/README.md b/README.md index 3dd6bfc..ff0a56b 100644 --- a/README.md +++ b/README.md @@ -41,6 +41,144 @@ On command line: * `-DDISABLE_COLOR=ON` disables coloured console output. * `-DBUILD_TESTING=OFF` disables building of unit tests. + * `-DUSE_BOOST_PRETTY_FUNCTION=ON` enables usage of `BOOST_PRETTY_FUNCTION` macro. + +## Documentation + +## 1. General + +All log calls go through the provided LOG(severity) macro. Output through this macro is thread-safe. Logging is done to cout, file output and/or custom sinks. + +## 2. Severity + +The log severity is controlled via: +```C++ +fair::Logger::SetConsoleSeverity(""); +// and/or +fair::Logger::SetFileSeverity(""); +// and/or +fair::Logger::SetCustomSeverity("", ""); +``` + +where severity level is one of the following: + +```C++ +"nolog", +"fatal", +"error", +"warn", +"state", +"info", +"debug", +"debug1", +"debug2", +"debug3", +"debug4", +"trace", +``` + +Logger will log the chosen severity and all above it (except "nolog", which deactivates logging for that sink completely). Fatal severity is always logged. + +## 3. Verbosity + +The log verbosity is controlled via: +```C++ +fair::Logger::SetVerbosity(""); +``` + +it is same for all sinks, and is one of the following values: `verylow`, `low`, `medium`, `high`, `veryhigh`, which translates to following output: + +``` +verylow: message +low: [severity] message +medium: [HH:MM:SS][severity] message +high: [process name][HH:MM:SS:µS][severity] message +veryhigh: [process name][HH:MM:SS:µS][severity][file:line:function] message +``` + +When running a FairMQ device, the log severity can be simply provided via `--verbosity ` cmd option. + +The user may customize the existing verbosities or any of `user1`, `user2`, `user3`, `user4` verbosities via: +```C++ +void fair::Logger::DefineVerbosity(fair::Verbosity, fair::VerbositySpec); +void fair::Logger::DefineVerbosity("", fair::VerbositySpec); +``` + +The `fair::Logger::VerbositySpec` object can e.g. be created like this: +```C++ +auto spec = fair::VerbositySpec::Make(VerbositySpec::Info::timestamp_s, + VerbositySpec::Info::process_name); +// results in [HH:MM:SS][process name] message +``` + +| **Argument** | **Result** | +| --- | --- | +| `fair::VerbositySpec::Info::process_name` | `[process name]` | +| `fair::VerbositySpec::Info::timestamp_s` | `[HH:MM:SS]` | +| `fair::VerbositySpec::Info::timestamp_us` | `[HH:MM:SS:µS]` | +| `fair::VerbositySpec::Info::severity` | `[severity]` | +| `fair::VerbositySpec::Info::file` | `[file]` | +| `fair::VerbositySpec::Info::file_line` | `[file:line]` | +| `fair::VerbositySpec::Info::file_line_function` | `[file:line:function]` | + + +### 3.1 `BOOST_PRETTY_FUNCTION` support + +By default, the `veryhigh` verbosity prints the function name from which the `LOG` macro was invoked. If you desire a more verbose function signature including the full namespace, return value and function arguments, you can enable support for `BOOST_PRETTY_FUNCTION` + +* **globally** by compiling FairLogger with the CMake option `-DUSE_BOOST_PRETTY_FUNCTION=ON`, or +* **per translation unit** by defining `FAIRLOGGER_USE_BOOST_PRETTY_FUNCTION` before including the FairLogger header, e.g. + +```C++ +#define FAIRLOGGER_USE_BOOST_PRETTY_FUNCTION +#include +``` + +In the latter case, the user needs to take care of adding the boost include path to the compiler search path manually (e.g. `-I/path/to/boost/include`). + +## 4. Color + +Colored output on console can be activated with: +```C++ +Logger::SetConsoleColor(true); +``` + +When running a FairMQ device, the log color (console) can be simply provided via `--color ` cmd option (default is true). + +## 5. File output + +Output to file can be enabled via: +```C++ +Logger::InitFileSink("", "test_log", true); +``` +which will add output to "test_log" filename (if third parameter is `true` it will add timestamp to the file name) with `` severity. + +When running a FairMQ device, the log file can be simply provided via `--log-to-file ` cmd option (this will also turn off console output). + +## 5.5 Custom sinks + +Custom sinks can be added via `Logger::AddCustomSink("sink name", "", callback)` method. + +Here is an example adding a custom sink for all severities ("trace" and above). It has access to the log content and meta data. Custom log calls are also thread-safe. + +```C++ + Logger::AddCustomSink("MyCustomSink", "trace", [](const string& content, const LogMetaData& metadata) + { + cout << "content: " << content << endl; + + cout << "available metadata: " << endl; + cout << "std::time_t timestamp: " << metadata.timestamp << endl; + cout << "std::chrono::microseconds us: " << metadata.us.count() << endl; + cout << "std::string process_name: " << metadata.process_name << endl; + cout << "std::string file: " << metadata.file << endl; + cout << "std::string line: " << metadata.line << endl; + cout << "std::string func: " << metadata.func << endl; + cout << "std::string severity_name: " << metadata.severity_name << endl; + cout << "fair::Severity severity: " << static_cast(metadata.severity) << endl; + }); +``` + +If only output from custom sinks is desirable, console/file sinks must be deactivated by setting their severity to `"nolog"`. ## License diff --git a/logger/Logger.cxx b/logger/Logger.cxx index 351f807..0df4ed9 100644 --- a/logger/Logger.cxx +++ b/logger/Logger.cxx @@ -143,16 +143,20 @@ const string Logger::fProcessName = "?"; const unordered_map Logger::fVerbosityMap = { - { "veryhigh", Verbosity::veryhigh }, - { "high", Verbosity::high }, - { "medium", Verbosity::medium }, - { "low", Verbosity::low }, - { "verylow", Verbosity::verylow }, - { "VERYHIGH", Verbosity::veryhigh }, - { "HIGH", Verbosity::high }, - { "MEDIUM", Verbosity::medium }, - { "LOW", Verbosity::low }, - { "VERYLOW", Verbosity::verylow } + { "veryhigh", Verbosity::veryhigh }, + { "high", Verbosity::high }, + { "medium", Verbosity::medium }, + { "low", Verbosity::low }, + { "verylow", Verbosity::verylow }, + { "VERYHIGH", Verbosity::veryhigh }, + { "HIGH", Verbosity::high }, + { "MEDIUM", Verbosity::medium }, + { "LOW", Verbosity::low }, + { "VERYLOW", Verbosity::verylow }, + { "user1", Verbosity::user1 }, + { "user2", Verbosity::user2 }, + { "user3", Verbosity::user3 }, + { "user4", Verbosity::user4 } }; const unordered_map Logger::fSeverityMap = @@ -212,6 +216,34 @@ const array Logger::fVerbosityNames = } }; +std::map Logger::fVerbosities = +{ + { Verbosity::verylow, VerbositySpec::Make() + }, + { Verbosity::low, VerbositySpec::Make(VerbositySpec::Info::severity) + }, + { Verbosity::medium, VerbositySpec::Make(VerbositySpec::Info::timestamp_s, + VerbositySpec::Info::severity) + }, + { Verbosity::high, VerbositySpec::Make(VerbositySpec::Info::process_name, + VerbositySpec::Info::timestamp_s, + VerbositySpec::Info::severity) + }, + { Verbosity::veryhigh, VerbositySpec::Make(VerbositySpec::Info::process_name, + VerbositySpec::Info::timestamp_s, + VerbositySpec::Info::severity, + VerbositySpec::Info::file_line_function) + }, + { Verbosity::user1, VerbositySpec::Make(VerbositySpec::Info::severity) + }, + { Verbosity::user2, VerbositySpec::Make(VerbositySpec::Info::severity) + }, + { Verbosity::user3, VerbositySpec::Make(VerbositySpec::Info::severity) + }, + { Verbosity::user4, VerbositySpec::Make(VerbositySpec::Info::severity) + } +}; + string Logger::SeverityName(Severity severity) { return fSeverityNames.at(static_cast(severity)); @@ -440,6 +472,23 @@ Verbosity Logger::GetVerbosity() return fVerbosity; } +void Logger::DefineVerbosity(const Verbosity verbosity, const VerbositySpec spec) +{ + fVerbosities[verbosity] = spec; +} + +void Logger::DefineVerbosity(const std::string& verbosityStr, const VerbositySpec spec) +{ + if (fVerbosityMap.count(verbosityStr)) + { + DefineVerbosity(fVerbosityMap.at(verbosityStr), spec); + } + else + { + LOG(error) << "Unknown verbosity: '" << verbosityStr; + } +} + void Logger::SetConsoleColor(const bool colored) { fColored = colored; @@ -583,57 +632,99 @@ Logger& Logger::Log() } } + auto spec = fVerbosities[fVerbosity]; + if ((!fColored && LoggingToConsole()) || LoggingToFile()) { - if (fVerbosity >= Verbosity::high) + bool append_space = false; + for (const auto info : spec.fOrder) { - fBWOut << "[" << fMetaData.process_name << "]" - << "[" << tsstr << "." << setw(6) << setfill('0') << fMetaData.us.count() << "]"; - } - else if (fVerbosity == Verbosity::medium) - { - fBWOut << "[" << tsstr << "]"; + switch (info) + { + case VerbositySpec::Info::process_name: + fBWOut << "[" << fMetaData.process_name << "]"; + append_space = true; + break; + case VerbositySpec::Info::timestamp_us: + fBWOut << "[" << tsstr << "." << setw(6) << setfill('0') << fMetaData.us.count() << "]"; + append_space = true; + break; + case VerbositySpec::Info::timestamp_s: + fBWOut << "[" << tsstr << "]"; + append_space = true; + break; + case VerbositySpec::Info::severity: + fBWOut << "[" << fMetaData.severity_name << "]"; + append_space = true; + break; + case VerbositySpec::Info::file_line_function: + fBWOut << "[" << fMetaData.file << ":" << fMetaData.line << ":" << fMetaData.func << "]"; + append_space = true; + break; + case VerbositySpec::Info::file_line: + fBWOut << "[" << fMetaData.file << ":" << fMetaData.line << "]"; + append_space = true; + break; + case VerbositySpec::Info::file: + fBWOut << "[" << fMetaData.file << "]"; + append_space = true; + break; + default: + break; + } } - if (fVerbosity > Verbosity::verylow) - { - fBWOut << "[" << fMetaData.severity_name << "]"; - } - - if (fVerbosity == Verbosity::veryhigh) - { - fBWOut << "[" << fMetaData.file << ":" << fMetaData.line << ":" << fMetaData.func << "]"; - } - - if (fVerbosity != Verbosity::verylow) + if (append_space) { fBWOut << " "; } } - if (fColored && (LoggingToConsole())) + if (fColored && LoggingToConsole()) { - if (fVerbosity >= Verbosity::high) + bool append_space = false; + for (const auto info : spec.fOrder) { - fColorOut << "[" << ColorOut(Color::fgBlue, fMetaData.process_name) << "]" - << "[" << startColor(Color::fgCyan) << tsstr << "." << setw(6) << setfill('0') << fMetaData.us.count() << endColor() << "]"; - } - else if (fVerbosity == Verbosity::medium) - { - fColorOut << "[" << startColor(Color::fgCyan) << tsstr << endColor() << "]"; + switch (info) + { + case VerbositySpec::Info::process_name: + fColorOut << "[" << ColorOut(Color::fgBlue, fMetaData.process_name) << "]"; + append_space = true; + break; + case VerbositySpec::Info::timestamp_us: + fColorOut << "[" << startColor(Color::fgCyan) << tsstr << "." + << setw(6) << setfill('0') << fMetaData.us.count() << endColor() << "]"; + append_space = true; + break; + case VerbositySpec::Info::timestamp_s: + fColorOut << "[" << startColor(Color::fgCyan) << tsstr << endColor() << "]"; + append_space = true; + break; + case VerbositySpec::Info::severity: + fColorOut << "[" << ColoredSeverityWriter(fMetaData.severity) << "]"; + append_space = true; + break; + case VerbositySpec::Info::file_line_function: + fColorOut << "[" << ColorOut(Color::fgBlue, fMetaData.file) << ":" + << ColorOut(Color::fgYellow, fMetaData.line) << ":" + << ColorOut(Color::fgBlue, fMetaData.func) << "]"; + append_space = true; + break; + case VerbositySpec::Info::file_line: + fColorOut << "[" << ColorOut(Color::fgBlue, fMetaData.file) << ":" + << ColorOut(Color::fgYellow, fMetaData.line) << "]"; + append_space = true; + break; + case VerbositySpec::Info::file: + fColorOut << "[" << ColorOut(Color::fgBlue, fMetaData.file) << "]"; + append_space = true; + break; + default: + break; + } } - if (fVerbosity > Verbosity::verylow) - { - fColorOut << "[" << ColoredSeverityWriter(fMetaData.severity) << "]"; - } - - if (fVerbosity == Verbosity::veryhigh) - { - fColorOut << "[" << ColorOut(Color::fgBlue, fMetaData.file) << ":" << ColorOut(Color::fgYellow, fMetaData.line) << ":" << ColorOut(Color::fgBlue, fMetaData.func) << "]"; - } - - if (fVerbosity != Verbosity::verylow) + if (append_space) { fColorOut << " "; } diff --git a/logger/Logger.h b/logger/Logger.h index d7c9b37..c5374db 100644 --- a/logger/Logger.h +++ b/logger/Logger.h @@ -18,11 +18,19 @@ #include #include #include -#include +#include #include #include #include // pair #include // time_t +#include +#include +#include +#include + +#ifdef FAIRLOGGER_USE_BOOST_PRETTY_FUNCTION +#include +#endif namespace fair { @@ -76,7 +84,64 @@ enum class Verbosity : int LOW = low, MEDIUM = medium, HIGH = high, - VERYHIGH = veryhigh + VERYHIGH = veryhigh, + // extra slots for user-defined verbosities: + user1, + user2, + user3, + user4, +}; + +struct VerbositySpec +{ + enum class Info : int + { + __empty__ = 0, // used to initialize order array + process_name, // [process name] + timestamp_s, // [HH:MM:SS] + timestamp_us, // [HH:MM:SS:µS] + severity, // [severity] + file, // [file] + file_line, // [file:line] + file_line_function, // [file:line:function] + __max__ // needs to be last in enum + }; + + std::array(Info::__max__)> fOrder; + + VerbositySpec() : fOrder({Info::__empty__}) {} + + template + static VerbositySpec Make(Ts ... options) + { + static_assert(sizeof...(Ts) < static_cast(Info::__max__), + "Maximum number of VerbositySpec::Info parameters exceeded."); + + return Make(VerbositySpec(), 0, options...); + } + + private: + template + static VerbositySpec Make(VerbositySpec spec, int i, T option, Ts ... options) + { + static_assert(std::is_same::value, + "Only arguments of type VerbositySpec::Info are allowed."); + + assert(option > Info::__empty__); + assert(option < Info::__max__); + + if (std::find(spec.fOrder.begin(), spec.fOrder.end(), option) == spec.fOrder.end()) { + spec.fOrder[i] = option; + ++i; + } + + return Make(spec, i, options ...); + } + + static VerbositySpec Make(VerbositySpec spec, int) + { + return spec; + } }; // non-std exception to avoid undesirable catches - fatal should exit in a way we want. @@ -138,6 +203,8 @@ class Logger static void SetVerbosity(const Verbosity verbosity); static void SetVerbosity(const std::string& verbosityStr); static Verbosity GetVerbosity(); + static void DefineVerbosity(const Verbosity, VerbositySpec); + static void DefineVerbosity(const std::string& verbosityStr, VerbositySpec); static void SetConsoleColor(const bool colored = true); @@ -217,6 +284,8 @@ class Logger bool LoggingCustom(const Severity) const; static void UpdateMinSeverity(); + + static std::map fVerbosities; }; } // namespace fair @@ -224,9 +293,15 @@ class Logger #define IMP_CONVERTTOSTRING(s) # s #define CONVERTTOSTRING(s) IMP_CONVERTTOSTRING(s) +#ifdef FAIRLOGGER_USE_BOOST_PRETTY_FUNCTION +#define LOG(severity) \ + for (bool fairLOggerunLikelyvariable = false; fair::Logger::Logging(fair::Severity::severity) && !fairLOggerunLikelyvariable; fairLOggerunLikelyvariable = true) \ + fair::Logger(fair::Severity::severity, __FILE__, CONVERTTOSTRING(__LINE__), BOOST_CURRENT_FUNCTION).Log() +#else #define LOG(severity) \ for (bool fairLOggerunLikelyvariable = false; fair::Logger::Logging(fair::Severity::severity) && !fairLOggerunLikelyvariable; fairLOggerunLikelyvariable = true) \ fair::Logger(fair::Severity::severity, __FILE__, CONVERTTOSTRING(__LINE__), __FUNCTION__).Log() +#endif // with custom file, line, function #define LOGD(severity, file, line, function) \ diff --git a/test/loggerTest.cxx b/test/loggerTest.cxx index 913ecda..0af7a29 100644 --- a/test/loggerTest.cxx +++ b/test/loggerTest.cxx @@ -18,6 +18,9 @@ using namespace std; using namespace fair; +namespace test +{ + void printEverySeverity() { static int i = 1; @@ -35,25 +38,39 @@ void printEverySeverity() LOG(trace) << "trace message " << i++; } +} + void printAllVerbositiesWithSeverity(Severity sev) { Logger::SetConsoleSeverity(sev); cout << endl << "cout: >>> testing severity '" << Logger::SeverityName(sev) << "' with 'verylow' verbosity..." << endl; Logger::SetVerbosity(Verbosity::verylow); - printEverySeverity(); + test::printEverySeverity(); cout << endl << "cout: >>> testing severity '" << Logger::SeverityName(sev) << "' with 'low' verbosity..." << endl; Logger::SetVerbosity(Verbosity::low); - printEverySeverity(); + test::printEverySeverity(); cout << endl << "cout: >>> testing severity '" << Logger::SeverityName(sev) << "' with 'medium' verbosity..." << endl; Logger::SetVerbosity(Verbosity::medium); - printEverySeverity(); + test::printEverySeverity(); cout << endl << "cout: >>> testing severity '" << Logger::SeverityName(sev) << "' with 'high' verbosity..." << endl; Logger::SetVerbosity(Verbosity::high); - printEverySeverity(); + test::printEverySeverity(); cout << endl << "cout: >>> testing severity '" << Logger::SeverityName(sev) << "' with 'veryhigh' verbosity..." << endl; Logger::SetVerbosity(Verbosity::veryhigh); - printEverySeverity(); + test::printEverySeverity(); + cout << endl << "cout: >>> testing severity '" << Logger::SeverityName(sev) << "' with 'user1' verbosity..." << endl; + Logger::SetVerbosity(Verbosity::user1); + test::printEverySeverity(); + cout << endl << "cout: >>> testing severity '" << Logger::SeverityName(sev) << "' with 'user2' verbosity..." << endl; + Logger::SetVerbosity(Verbosity::user2); + test::printEverySeverity(); + cout << endl << "cout: >>> testing severity '" << Logger::SeverityName(sev) << "' with 'user3' verbosity..." << endl; + Logger::SetVerbosity(Verbosity::user3); + test::printEverySeverity(); + cout << endl << "cout: >>> testing severity '" << Logger::SeverityName(sev) << "' with 'user4' verbosity..." << endl; + Logger::SetVerbosity(Verbosity::user4); + test::printEverySeverity(); } void silentlyPrintAllVerbositiesWithSeverity(Severity sev) @@ -61,21 +78,34 @@ void silentlyPrintAllVerbositiesWithSeverity(Severity sev) Logger::SetConsoleSeverity(sev); Logger::SetVerbosity(Verbosity::verylow); - printEverySeverity(); + test::printEverySeverity(); Logger::SetVerbosity(Verbosity::low); - printEverySeverity(); + test::printEverySeverity(); Logger::SetVerbosity(Verbosity::medium); - printEverySeverity(); + test::printEverySeverity(); Logger::SetVerbosity(Verbosity::high); - printEverySeverity(); + test::printEverySeverity(); Logger::SetVerbosity(Verbosity::veryhigh); - printEverySeverity(); + test::printEverySeverity(); + Logger::SetVerbosity(Verbosity::user1); + test::printEverySeverity(); + Logger::SetVerbosity(Verbosity::user2); + test::printEverySeverity(); + Logger::SetVerbosity(Verbosity::user3); + test::printEverySeverity(); + Logger::SetVerbosity(Verbosity::user4); + test::printEverySeverity(); } int main() { Logger::SetConsoleColor(true); + auto spec = VerbositySpec::Make(VerbositySpec::Info::file_line_function, + VerbositySpec::Info::process_name,VerbositySpec::Info::process_name); + cout << "Defining custom verbosity \"user2\"" << endl; + Logger::DefineVerbosity(Verbosity::user2, spec); + cout << "cout: testing severities..." << endl; printAllVerbositiesWithSeverity(Severity::trace); @@ -133,7 +163,7 @@ int main() cout << "cout: ----------------------------" << endl; cout << "cout: open log file with severity 'error'" << endl; Logger::InitFileSink(Severity::error, "test_log", true); - printEverySeverity(); + test::printEverySeverity(); cout << "cout: closing log file" << endl; Logger::RemoveFileSink(); @@ -158,7 +188,7 @@ int main() cout << "CustomSink: \tfair::Severity severity: " << static_cast(metadata.severity) << endl; }); - printEverySeverity(); + test::printEverySeverity(); cout << endl << "cout: removing custom sink with info severity" << endl; @@ -166,6 +196,5 @@ int main() Logger::RemoveCustomSink("CustomSink"); Logger::RemoveCustomSink("bla"); - return 0; }