log: Added more comments and manual page

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);
     }