Reworked the way log messages are handled, to include call-context setup.

This enables modules to report messages to the message-sink, and thus to the commandline through the normal interface.
This simplifies handling multiple logging systems, and supports reporting logging from multiple concurrent controller instances.

This fixes #2225
This fixes #1575

3 files changed, 210 insertions, 18 deletions

diff --git a/Duplicati/Library/Logging/Duplicati.Library.Logging.csproj b/Duplicati/Library/Logging/Duplicati.Library.Logging.csproj
index 3d4e9e633..670f652fd 100644
--- a/Duplicati/Library/Logging/Duplicati.Library.Logging.csproj
+++ b/Duplicati/Library/Logging/Duplicati.Library.Logging.csproj
@@ -45,6 +45,7 @@
     <Compile Include="Properties\AssemblyInfo.cs" />

     <Compile Include="StreamLog.cs" />

     <Compile Include="Timer.cs" />

+    <Compile Include="LogScope.cs" />

   </ItemGroup>

   <ItemGroup>

     <None Include="app.config" />

diff --git a/Duplicati/Library/Logging/Log.cs b/Duplicati/Library/Logging/Log.cs
index 60eca9cef..f51c436a5 100644
--- a/Duplicati/Library/Logging/Log.cs
+++ b/Duplicati/Library/Logging/Log.cs
@@ -52,17 +52,29 @@ namespace Duplicati.Library.Logging
     public static class Log

     {

         /// <summary>

-        /// Static lock object to provide thread safe logging

+        /// The key used to assign the current scope into the current call-context

         /// </summary>

-        private static object m_lock = new object();

+        private const string LOGICAL_CONTEXT_KEY = "Duplicati:LoggingEntry";

+

+        /// <summary>

+        /// The root scope

+        /// </summary>

+        private static readonly LogScope m_root = new LogScope(null, LogMessageType.Error, null);

+

+        /// <summary>

+        /// The stored log instances

+        /// </summary>

+        private static readonly Dictionary<string, LogScope> m_log_instances = new Dictionary<string, LogScope>();

+

         /// <summary>

-        /// The log destination, may be null

+        /// Static lock object to provide thread safe logging

         /// </summary>

-        private static ILog m_log = null;

+        private static object m_lock = new object();

+

         /// <summary>

-        /// The minimum level of logged messages

+        /// Active message used to block recursion

         /// </summary>

-        private static LogMessageType m_logLevel = LogMessageType.Error;

+        private static string m_active_message;

 

         /// <summary>

         /// Writes a message to the current log destination

@@ -82,17 +94,27 @@ namespace Duplicati.Library.Logging
         /// <param name="ex">An exception value</param>

         public static void WriteMessage(string message, LogMessageType type, Exception ex)

         {

-            if (m_log == null)

-                return;

-

             lock (m_lock)

-                if (m_log == null)

+            {

+                if (m_active_message == message)

                     return;

-                else

+

+                m_active_message = message;

+                try

                 {

-                    if (type >= m_logLevel)

-                        m_log.WriteMessage(message, type, ex);

+                    var cs = CurrentScope;

+                    while (cs != null)

+                    {

+                        if (cs.Log != null && type >= cs.LogLevel)

+                            cs.Log.WriteMessage(message, type, ex);

+                        cs = cs.Parent;

+                    }

                 }

+                finally

+                {

+                    m_active_message = null;

+                }

+            }

         }

 

         /// <summary>

@@ -100,11 +122,20 @@ namespace Duplicati.Library.Logging
         /// </summary>

         public static LogMessageType LogLevel

         {

-            get { return m_logLevel; }

+            get 

+            {

+                var cs = CurrentScope;

+                var ll = (int)cs.LogLevel;

+                while (cs != null)

+                {

+                    ll = Math.Min(ll, (int)cs.LogLevel);

+                    cs = cs.Parent;

+                }

+                return (LogMessageType)ll;

+            }

             set

             {

-                lock (m_lock)

-                    m_logLevel = value;

+                CurrentScope.LogLevel = value;

             }

         }

 

@@ -115,12 +146,90 @@ namespace Duplicati.Library.Logging
         {

             get 

             {

-                return m_log;

+                return CurrentScope.Log;

             }

             set 

             {

+                CurrentScope.Log = value;

+            }

+        }

+

+        /// <summary>

+        /// Starts a new scope, that can be closed by disposing the returned instance

+        /// </summary>

+        /// <returns>The new scope.</returns>

+        public static IDisposable StartScope()

+        {

+            return StartScope((ILog)null);

+        }

+

+        /// <summary>

+        /// Starts a new scope, that can be stopped by disposing the returned instance

+        /// </summary>

+        /// <returns>The new scope.</returns>

+        public static IDisposable StartScope(ILog log)

+        {

+            return new LogScope(log, LogLevel, CurrentScope);

+        }

+

+        /// <summary>

+        /// Starts the scope.

+        /// </summary>

+        /// <param name="scope">The scope to start.</param>

+        internal static void StartScope(LogScope scope)

+        {

+            CurrentScope = scope;

+        }

+

+        /// <summary>

+        /// Closes the scope.

+        /// </summary>

+        /// <param name="scope">The scope to finish.</param>

+        internal static void CloseScope(LogScope scope)

+        {

+            lock(m_lock)

+            {

+                if (CurrentScope == scope && scope != m_root)

+                    CurrentScope = scope.Parent;

+                m_log_instances.Remove(scope.InstanceID);

+            }

+        }

+

+        /// <summary>

+        /// Gets or sets the current log destination in a call-context aware fashion

+        /// </summary>

+        internal static LogScope CurrentScope

+        {

+            get

+            {

                 lock (m_lock)

-                    m_log = value;

+                {

+                    var cur = System.Runtime.Remoting.Messaging.CallContext.LogicalGetData(LOGICAL_CONTEXT_KEY) as string;

+                    if (cur == null || cur == m_root.InstanceID)

+                        return m_root;

+                    

+                    LogScope sc;

+                    if (!m_log_instances.TryGetValue(cur, out sc))

+                        throw new Exception(string.Format("Unable to find log in lookup table, this may be caused by attempting to transport call contexts between AppDomains (eg. with remoting calls)"));

+

+                    return sc;

+                }

+            }

+            private set

+            {

+                lock (m_lock)

+                {

+                    if (value != null)

+                    {

+                        m_log_instances[value.InstanceID] = value;

+                        System.Runtime.Remoting.Messaging.CallContext.LogicalSetData(LOGICAL_CONTEXT_KEY, value.InstanceID);

+                    }

+                    else

+                    {

+                        System.Runtime.Remoting.Messaging.CallContext.LogicalSetData(LOGICAL_CONTEXT_KEY, null);

+                    }

+                        

+                }

             }

         }

     }

diff --git a/Duplicati/Library/Logging/LogScope.cs b/Duplicati/Library/Logging/LogScope.cs
new file mode 100644
index 000000000..a0de5a09c
--- /dev/null
+++ b/Duplicati/Library/Logging/LogScope.cs
@@ -0,0 +1,82 @@
+//  Copyright (C) 2017, The Duplicati Team

+//  http://www.duplicati.com, info@duplicati.com

+//

+//  This library is free software; you can redistribute it and/or modify

+//  it under the terms of the GNU Lesser General Public License as

+//  published by the Free Software Foundation; either version 2.1 of the

+//  License, or (at your option) any later version.

+//

+//  This library is distributed in the hope that it will be useful, but

+//  WITHOUT ANY WARRANTY; without even the implied warranty of

+//  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU

+//  Lesser General Public License for more details.

+//

+//  You should have received a copy of the GNU Lesser General Public

+//  License along with this library; if not, write to the Free Software

+//  Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA

+using System;

+namespace Duplicati.Library.Logging

+{

+    /// <summary>

+    /// Internal class for keeping log instance relations

+    /// </summary>

+    internal class LogScope : IDisposable

+    {

+        /// <summary>

+        /// The unique ID of this log instance

+        /// </summary>

+        public readonly string InstanceID = Guid.NewGuid().ToString();

+

+        /// <summary>

+        /// The log instance assigned to this scope

+        /// </summary>

+        public ILog Log;

+

+        /// <summary>

+        /// The current log level

+        /// </summary>

+        public LogMessageType LogLevel;

+

+        /// <summary>

+        /// The log scope parent

+        /// </summary>

+        public readonly LogScope Parent;

+

+        /// <summary>

+        /// A flag indicating if the scope is disposed

+        /// </summary>

+        private bool m_isDisposed = false;

+

+        /// <summary>

+        /// Initializes a new instance of the <see cref="T:Duplicati.Library.Logging.LogWrapper"/> class.

+        /// </summary>

+        /// <param name="self">The log instance to wrap.</param>

+        public LogScope(ILog self, LogMessageType level, LogScope parent)

+        {

+            Log = self;

+            LogLevel = level;

+            Parent = parent;

+

+            if (parent != null)

+                Logging.Log.StartScope(this);

+        }

+

+        /// <summary>

+        /// Releases all resource used by the <see cref="T:Duplicati.Library.Logging.LogScope"/> object.

+        /// </summary>

+        /// <remarks>Call <see cref="Dispose"/> when you are finished using the

+        /// <see cref="T:Duplicati.Library.Logging.LogScope"/>. The <see cref="Dispose"/> method leaves the

+        /// <see cref="T:Duplicati.Library.Logging.LogScope"/> in an unusable state. After calling

+        /// <see cref="Dispose"/>, you must release all references to the

+        /// <see cref="T:Duplicati.Library.Logging.LogScope"/> so the garbage collector can reclaim the memory that the

+        /// <see cref="T:Duplicati.Library.Logging.LogScope"/> was occupying.</remarks>

+        public void Dispose()

+        {

+            if (!m_isDisposed && Parent != null)

+            {

+                Logging.Log.CloseScope(this);

+                m_isDisposed = true;

+            }

+        }

+    }

+}