Merge pull request #40 from lsst/tickets/DM-17874

DM-17874: Remove ContextLog class and related code

doc/mainpage.dox

@@ -13,7 +13,6 @@
 - Optionally include and format metadata including date, time, level, logger name, thread, function, source file, line number.
 - Optionally add arbitrary thread-scoped metadata (e.g. key/value pairs) to logging context programmatically.
 - Hierarchical, named loggers with independent configurations (e.g. levels, output channels, metadata, formatting).
-- Dynamic hierarchical logging contexts via `push()` and `pop()` functions.
 - Logging context objects automatically handle pushing/popping of names onto/off of global context in either C++ or Python.
 - Offers alternative interface that is compatible with standard Python logging module.
 - Configure loggers via single standard log4cxx XML or standard log4j Java properties file.
@@ -70,11 +69,11 @@ avoid filtering on Python side by setting logging level to DEBUG for root
 logger and instead configure log4cxx with proper logging level.
 
 
-Alternatively, get a logger through lsst.log.Log:
+Alternatively, get a logger through lsst.log:
 
-    lgr = lsst.log.Log.getLogger("myLogger")
+    lgr = lsst.log.getLogger("myLogger")
     lgr.setLevel(lgr.DEBUG)
-    lgr.info("This is an info statement via %s", "lsst.log.Log interface.")
+    lgr.info("This is an info statement via %s", "lsst.log interface.")
 
 \section exampleOutput Example output
 
@@ -290,57 +289,6 @@ In Python, the `lsst.log` module includes the following functions and variables:
 - `FATAL` Fatal logging level (50000).
 
 
-\section contexts Logging Contexts
-
-The logging context is maintained via a global stack onto which names can be pushed and popped using the lsst.log macros `LOG_PUSHCTX(name)` and `LOG_POPCTX()` within C++ or the `lsst.log` functions `pushContext(name)` and {{{popContext()}}} within Python. The default logger name is dynamically constructed each time a name is pushed onto or popped from the logging context. For example, within the Qserv demo, the following code can be found within `app.py`:
-
-    lsst.log.initLog("/u1/bchick/sandbox2/modules/etc/Log4cxxConfig.xml")
-    lsst.log.pushContext("czar")
-    [...]
-    lsst.log.debug("This is a debug statement!")
-
-The debugging statement is sent to the default logger, which in this case is ''czar''. Later, within the {{{submitQuery3()}}} function of {{{control/dispatcher.cc}}}, we have:
-
-    LOG_PUSHCTX("control");
-
-At this point, any logging statements that do not specify a logger name will be associated with a default logger of ''czar.control''. This mechanism allows dynamic hierarchical logging without hardcoding full logger names in order to accommodate better code re-use. Logging could then be configured, for example, so that the ''czar.control'' context is redirected or copied to a special file with a unique logging level.
-
-To pop a name from the logging context, invoke the {{{lsst.log.popContext()}}} function within Python or the {{{LOG_POPCTX()}}} macro within C++.
-
-The context determines the default logger, which is used whenever a logger is not explicitly indicated or an empty string is provided as the logger name.
-
-To summarize, within C++, we have the following macros:
-- `LOG_PUSHCTX(name)` Push '''`name`''' onto the global context stack such that the default logger name is appended with ".'''`name`'''".
-- `LOG_POPCTX()` Pop the last name `C` off of the global context stack such that a previous default logger name "`A`.`B`.`C`" is now "`A`.`B`".
-- `LOG_DEFAULT_NAME()` Returns the default logger name.
-
-And in Python, the following functions are available in the `lsst.log` module:
-- `pushContext(name)` Push '''`name`''' onto the global context stack such that the default logger name is appended with ".'''`name`'''".
-- `popContext()` Pop the last name `C` off of the global context stack such that a previous default logger name "`A`.`B`.`C`" is now "`A`.`B`".
-- `getDefaultLoggerName()` Returns the default logger name.
-
-
-\section ctxObj Context Objects
-
-Requiring that developers properly pop each context name is error prone. Therefore, we also provide logging context objects in both C++ and Python, which automatically pop names when the object is discarded.
-
-In C++, the context object will pop the provided name in its destructor. Contexts can therefore be managed as follows:
-
-    {
-        LOG_CTX context("demo");
-        LOG_INFO("Info statement within demo context.");
-    }
-    LOG_INFO("Info statement outside demo context.");
-
-In this example, if the context were initially "nameOne.nameTwo", the first logging statement would be sent to the logger named "nameOne.nameTwo.demo" and the second logging statement would be sent to the logger named "nameOne.nameTwo".
-
-The LogContext class defined in the Python layer is compatible with Python's `with` statement, and therefore, the above example can be implemented in Python as follows:
-
-    with LogContext(name="demo") as context:
-        lsst.log.info("Info statement within demo context.")
-    lsst.log.info("Info statement outside demo context.")
-
-
 \section flDebugging Fine-level Debugging Example
 
 The following is a simple recipe for emulating additional debugging levels using the above API within Python. Analogous code can be readily written in C++ using the corresponding macros.
@@ -350,7 +298,7 @@ The following is a simple recipe for emulating additional debugging levels using
         """
         Returns the logger name that corresponds to fine-level debugging number NUM.
         """
-        return '%s.debug%d' % (lsst.log.getDefaultLoggerName(), num)
+        return 'MyLogger.debug{}'.format(num)
 
     def debugAt(num, fmt, *args):
         """

examples/mp.py

@@ -5,37 +5,38 @@
 
 
 def main():
-    # Set component to "main" (from "root")
-    with log.LogContext("main"):
-        log.info("In main")
-        visits = [12345, 67890, 27182, 31415]
-        pool = mp.Pool(processes=2)
-        pool.map_async(a, visits)
-        pool.close()
-        pool.join()
-        b()
-        log.info("Leaving main")
-
-
-def a(visit):
+    # Use logger "main"
+    logger = log.getLogger("main")
+    logger.info("In main")
+    visits = [12345, 67890, 27182, 31415]
+    pool = mp.Pool(processes=2)
+    pool.map_async(a, [(visit, logger) for visit in visits])
+    pool.close()
+    pool.join()
+    b(logger)
+    log.info("Leaving main")
+
+
+def a(args):
+    visit, parentLogger = args
     # Set subcomponent to "a" (sets component to "main.a")
-    with log.LogContext("a"):
-        # Clean out any previous MDC for visit
-        log.MDCRemove("visit")
-        # All subsequent log messages will have visit id
-        log.MDC("visit", visit)
-        log.info("In a, %d", visit)
-        log.debug("Debug message in a")
-        b()
-        log.info("Leaving a")
-
-
-def b():
+    logger = parentLogger.getChild("a")
+    # Clean out any previous MDC for visit
+    logger.MDCRemove("visit")
+    # All subsequent log messages will have visit id
+    logger.MDC("visit", str(visit))
+    logger.info("In a, %d", visit)
+    logger.debug("Debug message in a")
+    b(logger)
+    logger.info("Leaving a")
+
+
+def b(parentLogger):
     # Set subcomponent to "b" (sets component to "main.a.b" or "main.b")
-    with log.LogContext("b"):
-        log.info("In b")
-        log.debug("Testing; logged only when called by a")
-        log.info("Leaving b")
+    logger = parentLogger.getChild("b")
+    logger.info("In b")
+    logger.debug("Testing; logged only when called by a")
+    logger.info("Leaving b")
 
 
 if __name__ == "__main__":

include/lsst/log/Log.h

@@ -38,7 +38,6 @@
 #include <sstream>
 #include <stdarg.h>
 #include <string>
-#include <vector>
 
 // Third-party headers
 #include <log4cxx/logger.h>
@@ -66,13 +65,6 @@
   */
 #define LOG_CONFIG_PROP(string) lsst::log::Log::configure_prop(string)
 
-/**
-  * @def LOG_DEFAULT_NAME()
-  * Get the current default logger name. Returns empty string for root logger.
-  * @return String containing the default logger name.
-  */
-#define LOG_DEFAULT_NAME() lsst::log::Log::getDefaultLoggerName()
-
 /**
   * @def LOG_GET(logger)
   * Returns a Log object associated with logger.
@@ -83,30 +75,14 @@
 #define LOG_GET(logger) lsst::log::Log::getLogger(logger)
 
 /**
-  * @def LOG_PUSHCTX(name)
-  * Pushes name onto the global hierarchical default logger name.
-  * Note that we only allow simple non-dotted names to be used for
-  * context names, multi-level context name (e.g. "componen1.component2")
-  * will result in exception. Empty context names are disallowed as
-  * well, exception will be raised for empty name.
+  * @def LOG_GET_CHILD(logger)
+  * Returns a Log object associated with descendant of a logger.
+  * @return Log object corresponding to logger's descendant.
   *
-  * @note Call to this macro is not thread-safe, moreover context is
-  * global and applies to all threads (which means you want to avoid
-  * using this in multi-threaded applications).
-  *
-  * @param name  String to push onto logging context.
-  * @throw std::invalid_argument raised for empty name or when name contains dot.
-  */
-#define LOG_PUSHCTX(name) lsst::log::Log::pushContext(name)
-
-/**
-  * @def LOG_POPCTX()
-  * Pops the last pushed name off the global hierarchical default logger
-  * name.
-  *
-  * @note Call to this macro is not thread-safe.
+  * @param logger  Either a logger name or a Log object.
+  * @param suffix  Suffix of a descendant.
   */
-#define LOG_POPCTX() lsst::log::Log::popContext()
+#define LOG_GET_CHILD(logger, suffix) lsst::log::Log::getLogger(logger).getChild(suffix)
 
 /**
   * @def LOG_MDC(key, value)
@@ -710,7 +686,6 @@
 #define LOG_LVL_FATAL static_cast<int>(log4cxx::Level::FATAL_INT)
 
 #define LOG_LOGGER lsst::log::Log
-#define LOG_CTX lsst::log::LogContext
 
 namespace lsst {
 namespace log {
@@ -724,10 +699,7 @@ class Log {
 public:
 
     /***
-     *  Default constructor creates an instance of "current" logger.
-     *
-     *  Initially current logger is the same as root logger, but
-     *  current can be changed via pushContext()/popContext().
+     *  Default constructor creates an instance of root logger.
      */
     Log() : _logger(_defaultLogger()) { }
 
@@ -761,9 +733,10 @@ class Log {
     int getLevel() const;
     bool isEnabledFor(int level) const;
 
+    Log getChild(std::string const& suffix) const;
+
     /// Return default logger instance, same as default constructor.
-    static Log getDefaultLogger() { return Log(_defaultLogger()); }
-    static std::string getDefaultLoggerName();
+    static Log getDefaultLogger() { return Log(); }
 
     static void configure();
     static void configure(std::string const& filename);
@@ -772,8 +745,6 @@ class Log {
     static Log getLogger(Log const& logger) { return logger; }
     static Log getLogger(std::string const& loggername);
 
-    static void pushContext(std::string const& name);
-    static void popContext();
     static void MDC(std::string const& key, std::string const& value);
     static void MDCRemove(std::string const& key);
     static int MDCRegisterInit(std::function<void()> function);
@@ -788,46 +759,24 @@ class Log {
 private:
 
     /**
-     *  Returns default LOG4CXX logger.
+     *  Returns default LOG4CXX logger, which is the same as root logger.
      *
-     *  @param newDefault if non-zero then default is set to this value first.
+     *  This method is needed to ensure proper LOG4CXX initialization before
+     *  any code uses any logger instance.
      */
-    static log4cxx::LoggerPtr const& _defaultLogger(log4cxx::LoggerPtr const& newDefault=log4cxx::LoggerPtr());
+    static log4cxx::LoggerPtr const& _defaultLogger();
 
     /**
      *  Construct a Log using a LOG4CXX logger.
      *
-     *  The default constructor is called to ensure the default logger is initialized and LOG4CXX is configured.
+     *  The default constructor is called to ensure the default logger is
+     *  initialized and LOG4CXX is configured.
      */
     Log(log4cxx::LoggerPtr const& logger) : Log() { _logger = logger; }
 
     log4cxx::LoggerPtr _logger;
 };
 
-/** This class handles the default logger name of a logging context.
-  */
-class LogContext {
-public:
-    /** Create a logging context associated with a default logger name
-      * constructed by pushing \p name onto the pre-existing hierarchical default
-      * logger name. See comment to \c LOG_PUSHCTX about allowed names.
-      *
-      * @param name  String to push onto logging context.
-      */
-    explicit LogContext(std::string const& name) {
-        Log::pushContext(name);
-    }
-    ~LogContext() {
-        Log::popContext();
-    }
-
-private:
-    // cannot copy instances
-    LogContext(const LogContext&);
-    LogContext& operator=(const LogContext&);
-};
-
-
 /**
  * Function which returns LWP ID on platforms which support it.
  *

python/lsst/log/log/log.cc

@@ -74,6 +74,7 @@ PYBIND11_MODULE(log, mod) {
     cls.def("setLevel", &Log::setLevel);
     cls.def("getLevel", &Log::getLevel);
     cls.def("isEnabledFor", &Log::isEnabledFor);
+    cls.def("getChild", &Log::getChild);
     cls.def("logMsg", [](Log& log, int level, std::string const& filename, std::string const& funcname,
                          unsigned int lineno, std::string const& msg) {
         log.logMsg(log4cxx::Level::toLevel(level),
@@ -82,14 +83,11 @@ PYBIND11_MODULE(log, mod) {
     cls.def("lwpID", [](Log const& log) -> unsigned { return lsst::log::lwpID(); });
 
     cls.def_static("getDefaultLogger", Log::getDefaultLogger);
-    cls.def_static("getDefaultLoggerName", Log::getDefaultLoggerName);
     cls.def_static("configure", (void (*)())Log::configure);
     cls.def_static("configure", (void (*)(std::string const&))Log::configure);
     cls.def_static("configure_prop", Log::configure_prop);
     cls.def_static("getLogger", (Log(*)(Log const&))Log::getLogger);
     cls.def_static("getLogger", (Log(*)(std::string const&))Log::getLogger);
-    cls.def_static("pushContext", Log::pushContext);
-    cls.def_static("popContext", Log::popContext);
     cls.def_static("MDC", Log::MDC);
     cls.def_static("MDCRemove", Log::MDCRemove);
     cls.def_static("MDCRegisterInit", [](py::function func) {