Logging: thread-safe

Logging must be thread-safe, because the glib log callback may be
called from arbitrary threads. This becomes more important with EDS
3.8, because it shifts the execution of synchronous calls into
threads.

Thread-safe logging will also be required for running the Synthesis
engine multithreaded, to overlap SyncML client communication with
preparing the sources.

To achieve this, the core Logging module protects its global data with
a recursive mutex. A recursive mutes is used because logging calls
themselves may be recursive, so ensuring single-lock semantic would be
hard.

Ref-counted boost pointers are used to track usage of Logger
instances.  This allows removal of an instance from the logging stack
while it may still be in use. Destruction then will be delayed until
the last user of the instance drops it. The instance itself must be
prepared to handle this.

The Logging mutex is available to users of the Logging module. Code
which holds the logging mutex should not lock any other mutex, to
avoid deadlocks. The new code is a bit fuzzy on that, because it calls
other modules (glib, Synthesis engine) while holding the mutex. If
that becomes a problem, then the mutex can be unlocked, at the risk of
leading to reordered log messages in different channels (see
ServerLogger).

Making all loggers follow the new rules uses different
approaches.

Loggers like the one in the local transport child which use a parent
logger and an additional ref-counted class like the D-Bus helper keep
a weak reference to the helper and lock it before use. If it is gone
already, the second logging part is skipped. This is the recommended
approach.

In cases where introducing ref-counting for the second class would
have been too intrusive (Server and SessionHelper), a fake
boost::shared_ptr without a destructor is used as an intermediate step
towards the recommended approach. To avoid race conditions while the
instance these fake pointers refer to destructs, an explicit
"remove()" method is necessary which must hold the Logging
mutex. Using the potentially removed pointer must do the same. Such
fake ref-counted Loggers cannot be used as parent logger of other
loggers, because then remove() would not be able to drop the last
reference to the fake boost::shared_ptr.

Loggers with fake boost::shared_ptr must keep a strong reference,
because no-one else does. The goal is to turn this into weak
references eventually.

LogDir must protect concurrent access to m_report and the Synthesis
engine.

The LogRedirectLogger assumes that it is still the active logger while
disabling itself. The remove() callback method will always be invoked
before removing a logger from the stack.

1 files changed, 161 insertions, 44 deletions

diff --git a/src/syncevo/Logging.h b/src/syncevo/Logging.h
index 283efa8d..dde9e325 100644
--- a/src/syncevo/Logging.h
+++ b/src/syncevo/Logging.h
@@ -33,8 +33,11 @@
 #endif
 
 #include <syncevo/Timespec.h>
+#include <syncevo/ThreadSupport.h>
 
 #include <boost/function.hpp>
+#include <boost/shared_ptr.hpp>
+#include <boost/noncopyable.hpp>
 
 #include <syncevo/declarations.h>
 SE_BEGIN_CXX
@@ -130,8 +133,17 @@ class Logger
      *
      * Included by LoggerStdout in the [INFO/DEBUG/...] tag.
      */
-    static void setProcessName(const std::string &name) { m_processName = name; }
-    static std::string getProcessName() { return m_processName; }
+    static void setProcessName(const std::string &name);
+    static std::string getProcessName();
+
+    /**
+     * Obtains the recursive logging mutex.
+     *
+     * All calls offered by the Logger class already lock that mutex
+     * internally, but sometimes it may be necessary to protect a larger
+     * region of logging related activity.
+     */
+    static RecMutex::Guard lock();
 
 #ifdef HAVE_GLIB
     /**
@@ -161,6 +173,15 @@ class Logger
     virtual ~Logger();
 
     /**
+     * Prepare logger for removal from logging stack. May be called
+     * multiple times.
+     *
+     * The logger should stop doing anything right away and just pass
+     * on messages until it gets deleted eventually.
+     */
+    virtual void remove() throw () {}
+
+    /**
      * Collects all the parameters which may get passed to
      * messagev.
      */
@@ -199,36 +220,69 @@ class Logger
                           const char *format,
                           va_list args) = 0;
 
-    /** redirect into messagev() */
-    void message(Level level,
-                 const std::string *prefix,
-                 const char *file,
-                 int line,
-                 const char *function,
-                 const char *format,
-                 ...)
+    /**
+     * A convenience and backwards-compatibility class which allows
+     * calling some methods of the underlying pointer directly similar
+     * to the Logger reference returned in previous SyncEvolution
+     * releases.
+     */
+    class Handle
+    {
+        boost::shared_ptr<Logger> m_logger;
+
+    public:
+        Handle() throw ();
+        Handle(Logger *logger) throw ();
+        template<class L> Handle(const boost::shared_ptr<L> &logger) throw () : m_logger(logger) {}
+        template<class L> Handle(const boost::weak_ptr<L> &logger) throw () : m_logger(logger.lock()) {}
+        Handle(const Handle &other) throw ();
+        Handle &operator = (const Handle &other) throw ();
+        ~Handle() throw ();
+
+        operator bool () const { return m_logger; }
+        bool operator == (Logger *logger) const { return m_logger.get() == logger; }
+        Logger *get() const { return m_logger.get(); }
+
+        void messagev(const MessageOptions &options,
+                      const char *format,
+                      va_list args)
+        {
+            m_logger->messagev(options, format, args);
+        }
+
+        void message(Level level,
+                     const std::string *prefix,
+                     const char *file,
+                     int line,
+                     const char *function,
+                     const char *format,
+                     ...)
 #ifdef __GNUC__
-        __attribute__((format(printf, 7, 8)))
+            __attribute__((format(printf, 7, 8)))
 #endif
-        ;
-    void message(Level level,
-                 const std::string &prefix,
-                 const char *file,
-                 int line,
-                 const char *function,
-                 const char *format,
-                 ...)
+            ;
+        void message(Level level,
+                     const std::string &prefix,
+                     const char *file,
+                     int line,
+                     const char *function,
+                     const char *format,
+                     ...)
 #ifdef __GNUC__
-        __attribute__((format(printf, 7, 8)))
+            __attribute__((format(printf, 7, 8)))
 #endif
-        ;
-    void messageWithOptions(const MessageOptions &options,
-                            const char *format,
-                            ...)
+            ;
+        void messageWithOptions(const MessageOptions &options,
+                                const char *format,
+                                ...)
 #ifdef __GNUC__
-        __attribute__((format(printf, 3, 4)))
+            __attribute__((format(printf, 3, 4)))
 #endif
-        ;
+            ;
+        void setLevel(Level level) { m_logger->setLevel(level); }
+        Level getLevel() { return m_logger->getLevel(); }
+        void remove() throw () { m_logger->remove(); }
+    };
 
     /**
      * Grants access to the singleton which implements logging.
@@ -236,31 +290,25 @@ class Logger
      * class itself is platform specific: if no Log instance
      * has been set yet, then this call has to create one.
      */
-    static Logger &instance();
+    static Handle instance();
 
     /**
-     * Overrides the default Logger implementation. The Logger class
-     * itself will never delete the active logger.
+     * Overrides the current default Logger implementation.
      *
      * @param logger    will be used for all future logging activities
      */
-    static void pushLogger(Logger *logger);
+    static void addLogger(const Handle &logger);
 
     /**
-     * Remove the current logger and restore previous one.
-     * Must match a pushLogger() call.
-     */
-    static void popLogger();
-
-    /** total number of active loggers */
-    static int numLoggers();
-
-    /**
-     * access to active logger
-     * @param index    0 for oldest (inner-most) logger
-     * @return pointer or NULL for invalid index
+     * Remove the specified logger.
+     *
+     * Note that the logger might still be in use afterwards, for
+     * example when a different thread currently uses it. Therefore
+     * loggers should be small stub classes. If they need access to
+     * more expensive classes to do their work, they shold hold weak
+     * reference to those and only lock them when logging.
      */
-    static Logger *loggerAt(int index);
+    static void removeLogger(Logger *logger);
 
     virtual void setLevel(Level level) { m_level = level; }
     virtual Level getLevel() { return m_level; }
@@ -288,7 +336,6 @@ class Logger
                      boost::function<void (std::string &chunk, size_t expectedTotal)> print);
 
  private:
-    static std::string m_processName;
     Level m_level;
 
     /**
@@ -299,6 +346,76 @@ class Logger
     Timespec m_startTime;
 };
 
+/**
+ * Takes a logger and adds it to the stack
+ * as long as the instance exists.
+ */
+template<class L> class PushLogger : boost::noncopyable
+{
+    Logger::Handle m_logger;
+
+ public:
+    PushLogger() {}
+    /**
+     * Can use Handle directly here.
+     */
+    PushLogger(const Logger::Handle &logger) : m_logger(logger)
+    {
+        if (m_logger) {
+            Logger::addLogger(m_logger);
+        }
+    }
+    /**
+     * Take any type that a Handle constructor accepts, then use it as
+     * Handle.
+     */
+    template <class M> PushLogger(M logger) : m_logger(Logger::Handle(logger))
+    {
+        if (m_logger) {
+            Logger::addLogger(m_logger);
+        }
+    }
+    ~PushLogger() throw ()
+    {
+        if (m_logger) {
+            Logger::removeLogger(m_logger.get());
+        }
+    }
+
+    operator bool () const { return m_logger; }
+
+    void reset(const Logger::Handle &logger)
+    {
+        if (m_logger) {
+            Logger::removeLogger(m_logger.get());
+        }
+        m_logger = logger;
+        if (m_logger) {
+            Logger::addLogger(m_logger);
+        }
+    }
+    template<class M> void reset(M logger)
+    {
+        if (m_logger) {
+            Logger::removeLogger(m_logger.get());
+        }
+        m_logger = Logger::Handle(logger);
+        if (m_logger) {
+            Logger::addLogger(m_logger);
+        }
+    }
+
+    void reset()
+    {
+        if (m_logger) {
+            Logger::removeLogger(m_logger.get());
+        }
+        m_logger = Logger::Handle();
+    }
+
+    L *get() { return static_cast<L *>(m_logger.get()); }
+    L * operator -> () { return get(); }
+};
 
 /**
  * Wraps Logger::message() in the current default logger.