diff options
| -rw-r--r-- | host/docs/logging.dox | 89 | ||||
| -rw-r--r-- | host/docs/uhd.dox | 1 | ||||
| -rw-r--r-- | host/include/uhd/utils/log.hpp | 56 | ||||
| -rw-r--r-- | host/lib/utils/log.cpp | 22 |
4 files changed, 141 insertions, 27 deletions
diff --git a/host/docs/logging.dox b/host/docs/logging.dox new file mode 100644 index 000000000..12ccbd789 --- /dev/null +++ b/host/docs/logging.dox @@ -0,0 +1,89 @@ +/*! \page page_logging UHD Logging + +During the operation of UHD, logging messages are created which UHD handles in a +logging subsystem. Everything logging-related is defined in +include/uhd/utils/log.hpp. See also \ref loghpp_logging + +UHD itself never prints anything to stdout, which means that stdout can be used +for applications using UHD. Actual logging messages are handled by separate +logging backends. By default, UHD has two backends: A *console* backend, which +prints logging messages to stderr (more accurately, to `std::clog`), and +a *file* backend, which writes all logging messages into a log file. + + +\section logging_levels Log levels + +UHD defines the following log levels (see also \ref loghpp_levels): + +- Trace: Typical trace messages are along the lines of "this function is + currently being executed" or "this is the current state of my local scope, the + following variables have the following values". Trace message are numerous, + and should usually be safe to ignore, unless some tricky debugging is + happening which requires knowing exactly what UHD is doing when and where and + how. +- Debug: Messages should have this level when it's likely the message can be + useful for debugging errorneus behaviour. A good reason to use debug level + messages is when user input is in the mix. +- Info: Whenever a message is usually supposed to be seen by the user, but it's + indicating regular behaviour, it's 'info'. Message at this level are rare. +- Warning: Anything that indicates something could be wrong, but operation can + continue for now, is a warning. +- Error: If something goes wrong, it's an error message. This is typically + accompanied by termination of the program. +- Fatal: SOMETHING'S REALLY WRONG + +Whenever a log level is set, it means all log levels with higher severity are +also printed. Example: If the log level is set to 'debug', it won't print +messages that are at 'trace' severity, but it will print 'info' and all the +other levels. + +There are multiple ways to set the log level: + +- Minimum level: This is a compile-time option. At compile-time, it disables + all log messages permanently that are below this log level. +- Global level: The global level can be changed at runtime, and applies to all + backends. +- Per-backend level: For example, The logfile and the console output could have + different logging levels. + +Log levels are evaluated in this order. If the minimum level is 'debug', no +'trace' message will ever be printed. If the global level is 'info', no 'debug' +message will ever be printed -- but this can be changed at runtime. Finally, +if a message has passed both the minimum and global levels, it is handled by +the individual backends if their log levels are appropriately set. + +For more info on how to set the individual log levels, see +include/uhd/utils/log.hpp. + +\section logging_macros Logging Macros + +When log messages are generated, the appropriate logging macros should always +be used. There are two types of macros: + +~~~~~~~~~~~~~~{.cpp} +UHD_LOG_DEBUG("component", "message"); +UHD_LOGGER_DEBUG("component") << "message"; +~~~~~~~~~~~~~~ + +The difference between those is, the former style is completely compiled out +when the minimum log level is set accordingly, whereas the second one is not, +but offers more flexibility through the streaming operators. +Use the former if speed matters. + +The macros require three pieces of information: + +- The log level. This is done by choosing the appropriate macro, e.g., + `UHD_LOGGER_DEBUG` vs. `UHD_LOGGER_INFO`. +- The component where the log message is originating from. This allows to filter + log messages more easily. +- The log message itself. + +\section logging_backends Logging Backends + +Anything that acts upon a log message is called a backend. UHD defines two by +default: A logfile, and a console backend. More backends can be added by +calling uhd::log::add_logger(). + +*/ +// vim:ft=doxygen: + diff --git a/host/docs/uhd.dox b/host/docs/uhd.dox index 5474d42e2..099bbe415 100644 --- a/host/docs/uhd.dox +++ b/host/docs/uhd.dox @@ -14,6 +14,7 @@ Some additional pages on developing UHD are also available here: \li \subpage page_stream \li \subpage page_rtp \li \subpage page_semver +\li \subpage page_logging \li \subpage page_rdtesting */ diff --git a/host/include/uhd/utils/log.hpp b/host/include/uhd/utils/log.hpp index 62cf20ff2..68c279036 100644 --- a/host/include/uhd/utils/log.hpp +++ b/host/include/uhd/utils/log.hpp @@ -19,7 +19,6 @@ #define INCLUDED_UHD_UTILS_LOG_HPP #include <uhd/config.hpp> -#include <uhd/utils/pimpl.hpp> #include <boost/current_function.hpp> #include <boost/thread/thread.hpp> #include <ostream> @@ -28,34 +27,41 @@ #include <iostream> /*! \file log.hpp - * The UHD logging facility - * ========================= * - * The logger enables UHD library code to easily log events into a file and display - * messages above a certain level in the terminal. + * \section loghpp_logging The UHD logging facility + * + * The logger enables UHD library code to easily log events into a file and + * display messages above a certain level in the terminal. * Log entries are time-stamped and stored with file, line, and function. - * Each call to the UHD_LOG macros is thread-safe. Each thread will aquire the lock - * for the logger. + * Each call to the UHD_LOG macros is thread-safe. Each thread will aquire the + * lock for the logger. + * + * Note: More information on the logging subsystem can be found on + * \ref page_logging. * * To disable console logging completely at compile time specify * `-DUHD_LOG_CONSOLE_DISABLE` during configuration with CMake. * * By default no file logging will occur. Set a log file path: * - at compile time by specifying `-DUHD_LOG_FILE=$file_path` - * - and/or override at runtime by setting the environment variable `UHD_LOG_FILE` + * - and/or override at runtime by setting the environment variable + * `UHD_LOG_FILE` + * + * \subsection loghpp_levels Log levels * - * Log levels - * ---------- + * See also \ref logging_levels. * * All log messages with verbosity greater than or equal to the log level * (in other words, as often or less often than the current log level) * are recorded to std::clog and/or the log file. - * Log levels can be specified using string or numeric values of uhd::log::severity_level. + * Log levels can be specified using string or numeric values of + * uhd::log::severity_level. * * The default log level is "info", but can be overridden: * - at compile time by setting the pre-processor define `-DUHD_LOG_MIN_LEVEL`. * - at runtime by setting the environment variable `UHD_LOG_LEVEL`. - * - for console logging by setting `(-D)UHD_LOG_CONSOLE_LEVEL` at run-/compiletime + * - for console logging by setting `(-D)UHD_LOG_CONSOLE_LEVEL` at + * run-/compiletime * - for file logging by setting `(-D)UHD_LOG_FILE_LEVEL` at run-/compiletime * * UHD_LOG_LEVEL can be the name of a verbosity enum or integer value: @@ -64,8 +70,7 @@ * - Example environment variable: `export UHD_LOG_LEVEL=3` * - Example environment variable: `export UHD_LOG_LEVEL=info` * - * Log formatting - * -------------- + * \subsection loghpp_formatting Log formatting * * The log format for messages going into a log file is CSV. * All log messages going into a logfile will contain following fields: @@ -76,11 +81,13 @@ * - component/channel information which logged the information * - the actual log message * - * The log format of log messages displayed on the terminal is plain text with space separated tags prepended. + * The log format of log messages displayed on the terminal is plain text with + * space separated tags prepended. * For example: - * - `[INFO] [x300] This is a informational log message` + * - `[INFO] [X300] This is a informational log message` * - * The log format for log output on the console by using these preprocessor defines in CMake: + * The log format for log output on the console by using these preprocessor + * defines in CMake: * - `-DUHD_LOG_CONSOLE_TIME` adds a timestamp [2017-01-01 00:00:00.000000] * - `-DUHD_LOG_CONSOLE_THREAD` adds a thread-id `[0x001234]` * - `-DUHD_LOG_CONSOLE_SRC` adds a sourcefile and line tag `[src_file:line]` @@ -101,7 +108,8 @@ namespace uhd { namespace log { /*! Logging severity levels * - * Either numeric value or string can be used to define loglevel in CMake and environment variables + * Either numeric value or string can be used to define loglevel in + * CMake and environment variables */ enum UHD_API severity_level { trace = 0, /**< displays every available log message */ @@ -209,10 +217,11 @@ namespace uhd { } } - -// internal logging macro to be used in other macros +//! \cond +//! Internal logging macro to be used in other macros #define _UHD_LOG_INTERNAL(component, level) \ uhd::_log::log(level, __FILE__, __LINE__, component, boost::this_thread::get_id()) +//! \endcond // macro-style logging (compile-time determined) #if UHD_LOG_MIN_LEVEL < 1 @@ -278,6 +287,7 @@ namespace uhd { #define UHD_HERE() \ UHD_LOGGER_DEBUG("DEBUG") << __FILE__ << ":" << __LINE__ << " (" << __PRETTY_FUNCTION__ << ")"; #else +//! Helpful debug tool to print site info #define UHD_HERE() \ UHD_LOGGER_DEBUG("DEBUG") << __FILE__ << ":" << __LINE__; #endif @@ -290,9 +300,10 @@ namespace uhd { #define UHD_HEX(var) \ UHD_LOGGER_DEBUG("DEBUG") << #var << " = 0x" << std::hex << std::setfill('0') << std::setw(8) << var << std::dec; +//! \cond namespace uhd{ namespace _log { - //! Internal logging object (called by UHD_LOG macros) + //! \internal Internal logging object (called by UHD_LOG macros) class UHD_API log { public: log( @@ -305,7 +316,7 @@ namespace uhd{ namespace _log { ~log(void); - // Macro for overloading insertion operators to avoid costly + // \internal Macro for overloading insertion operators to avoid costly // conversion of types if not logging. #define INSERTION_OVERLOAD(x) log& operator<< (x) \ { \ @@ -331,6 +342,7 @@ namespace uhd{ namespace _log { }; } //namespace uhd::_log +//! \endcond } /* namespace uhd */ #endif /* INCLUDED_UHD_UTILS_LOG_HPP */ diff --git a/host/lib/utils/log.cpp b/host/lib/utils/log.cpp index 5d0a9cf5b..2b6da2297 100644 --- a/host/lib/utils/log.cpp +++ b/host/lib/utils/log.cpp @@ -97,6 +97,11 @@ void console_log( ; } +/*! Helper class to implement file logging + * + * The class holds references to the file stream object, and handles closing + * and cleanup. + */ class file_logger_backend { public: @@ -157,28 +162,34 @@ public: _exit(false), _log_queue(10) { - //allow override from macro definition #ifdef UHD_LOG_MIN_LEVEL this->global_level = _get_log_level(BOOST_STRINGIZE(UHD_LOG_MIN_LEVEL), this->global_level); #endif //allow override from environment variables const char * log_level_env = std::getenv("UHD_LOG_LEVEL"); - if (log_level_env != NULL && log_level_env[0] != '\0') this->global_level = _get_log_level(log_level_env, this->global_level); + if (log_level_env != NULL && log_level_env[0] != '\0') { + this->global_level = + _get_log_level(log_level_env, this->global_level); + } -// console logging support + /***** Console logging ***********************************************/ #ifndef UHD_LOG_CONSOLE_DISABLE uhd::log::severity_level console_level = uhd::log::trace; #ifdef UHD_LOG_CONSOLE_LEVEL console_level = _get_log_level(BOOST_STRINGIZE(UHD_LOG_CONSOLE_LEVEL), console_level); #endif const char * log_console_level_env = std::getenv("UHD_LOG_CONSOLE_LEVEL"); - if (log_console_level_env != NULL && log_console_level_env[0] != '\0') console_level = _get_log_level(log_console_level_env, console_level); + if (log_console_level_env != NULL && log_console_level_env[0] != '\0') { + console_level = + _get_log_level(log_console_level_env, console_level); + } logger_level[UHD_CONSOLE_LOGGER_KEY] = console_level; _loggers[UHD_CONSOLE_LOGGER_KEY] = &console_log; #endif + /***** File logging **************************************************/ uhd::log::severity_level file_level = uhd::log::trace; std::string log_file_target; #if defined(UHD_LOG_FILE_LEVEL) && defined(UHD_LOG_FILE_PATH) @@ -198,6 +209,8 @@ public: auto F = boost::make_shared<file_logger_backend>(log_file_target); _loggers[UHD_FILE_LOGGER_KEY] = [F](const uhd::log::logging_info& log_info){F->log(log_info);}; } + + // Launch log message consumer _pop_task = uhd::task::make([this](){this->pop_task();}); } @@ -209,7 +222,6 @@ public: void push(const uhd::log::logging_info& log_info) { - _log_queue.push_with_haste(log_info); } |