Merge branch 'feature/fix_log_spam'

Duplicati/CommandLine/ConsoleLogTarget.cs

@@ -64,7 +64,7 @@ public ConsoleLogTarget(TextWriter stdout, TextWriter stderr, LogMessageType lev
         /// <param name="entry">The entry to write.</param>
         public void WriteMessage(LogEntry entry)
         {
-            var found = m_filter.Matches(entry.Tag, out var result, out var match);
+            var found = m_filter.Matches(entry.FilterTag, out var result, out var match);
             // If there is a filter match, use that
             if (found)
             {

Duplicati/Library/Logging/Log.cs

@@ -282,6 +282,7 @@ public static void WriteWarningMessage(string tag, string id, Exception ex, stri
         /// <param name="message">The message to write</param>
         /// <param name="tag">The tag-type for this message</param>
         /// <param name="id">The message id</param>
+        /// <param name="ex">The exception to attach</param>
         /// <param name="arguments">The message format arguments</param>
         public static void WriteErrorMessage(string tag, string id, Exception ex, string message, params object[] arguments)
         {
@@ -308,9 +309,10 @@ public static void WriteMessage(LogMessageType type, string tag, string id, stri
         /// <param name="ex">An exception value</param>
         /// <param name="tag">The tag-type for this message</param>
         /// <param name="id">The message id</param>
+        /// <param name="arguments">The arguments to format the log message with</param>
         public static void WriteMessage(LogMessageType type, string tag, string id, Exception ex, string message, params object[] arguments)
         {
-            var msg = new LogEntry(message, arguments, type, type + "-" + tag + "-" + id, id, ex);
+            var msg = new LogEntry(message, arguments, type, tag, id, ex);
 
             lock (m_lock)
             {

Duplicati/Library/Logging/LogEntry.cs

@@ -46,7 +46,12 @@ public class LogEntry
         public LogMessageType Level;
 
         /// <summary>
-        /// The tag for the message
+        /// The filter tag for the message
+        /// </summary>
+        public readonly string FilterTag;
+
+        /// <summary>
+        /// The filter tag for the message
         /// </summary>
         public readonly string Tag;
 
@@ -147,6 +152,7 @@ public LogEntry(string message, object[] arguments, LogMessageType level, string
             Tag = tag;
             Id = id;
             Exception = exception;
+            FilterTag = level + "-" + tag + "-" + id;
         }
 
         /// <summary>
@@ -155,7 +161,7 @@ public LogEntry(string message, object[] arguments, LogMessageType level, string
         /// <returns>A <see cref="T:System.String"/> that represents the current <see cref="T:Duplicati.Library.Logging.LogEntry"/>.</returns>
         public override string ToString()
         {
-            return string.Format("{0:yyyy-MM-dd HH:mm:ss zz} - [{1}]: {2}", When.ToLocalTime(), Tag, FormattedMessage);
+            return string.Format("{0:yyyy-MM-dd HH:mm:ss zz} - [{1}]: {2}", When.ToLocalTime(), FilterTag, FormattedMessage);
         }
 
         /// <summary>

Duplicati/Library/Logging/LogTagFilter.cs

@@ -57,11 +57,11 @@ public LogTagFilter(LogMessageType logLevel, string[] excludeTags, string[] incl
         public bool Accepts(LogEntry entry)
         {
             // Skip all explicitly excluded
-            if (m_excludeTags.Any(x => entry.Tag.StartsWith(x, StringComparison.OrdinalIgnoreCase)))
+            if (m_excludeTags.Any(x => entry.FilterTag.StartsWith(x, StringComparison.OrdinalIgnoreCase)))
                 return false;
 
             // Include all explicitly included or under threshold
-            return entry.Level >= m_logLevel || m_includeTags.Any(x => entry.Tag.StartsWith(x, StringComparison.OrdinalIgnoreCase));
+            return entry.Level >= m_logLevel || m_includeTags.Any(x => entry.FilterTag.StartsWith(x, StringComparison.OrdinalIgnoreCase));
         }
     }
 }

Duplicati/Library/Logging/RepeatingLogScope.cs

@@ -27,7 +27,7 @@ public class RepeatingLogScope : ILogDestination, IDisposable
         /// <summary>
         /// A string that is written as the message to the log
         /// </summary>
-        private const string STILL_RUNNING = "...";
+        private const string STILL_RUNNING = "... ";
         /// <summary>
         /// The scope that we dispose when we are done
         /// </summary>
@@ -77,15 +77,23 @@ private async void RepeatedRunner()
 
                 if (remainingTime < 0)
                 {
+                    var last = m_lastEntry;
+                    var recmsg = STILL_RUNNING + m_lastEntry.FormattedMessage;
+
                     Logging.Log.WriteMessage(
                         m_lastEntry.Level,
                         m_lastEntry.Tag,
                         m_lastEntry.Id,
                         m_lastEntry.Exception,
-                        STILL_RUNNING,
-                        m_lastEntry.Arguments
+                        recmsg,
+                        null
                     );
 
+                    // If the last message written is our own message,
+                    // don't use the generated one
+                    if (object.ReferenceEquals(m_lastEntry.Message, recmsg))
+                        m_lastEntry = last;
+
                     remainingTime = m_maxIdleTime;
                 }
             }

Duplicati/Library/Main/Controller.cs

@@ -441,7 +441,7 @@ public Library.Interface.ITestFilterResults TestFilter(string[] paths, Library.U
 
             // Redirect all messages from the filter to the message sink
             var filtertag = Logging.Log.LogTagFromType<Operation.BackupHandler.FilterHandler>();
-            using (Logging.Log.StartScope(m_messageSink.WriteMessage, x => x.Tag.Contains(filtertag)))
+            using (Logging.Log.StartScope(m_messageSink.WriteMessage, x => x.FilterTag.Contains(filtertag)))
             {
                 return RunAction(new TestFilterResults(), ref paths, ref filter, (result) =>
                 {
@@ -501,7 +501,7 @@ public Library.Interface.ISendMailResults SendMail()
 
             /// Forward all messages from the email module to the message sink
             var filtertag = Logging.Log.LogTagFromType<Modules.Builtin.SendMail>();
-            using (Logging.Log.StartScope(m_messageSink.WriteMessage, x => x.Tag.Contains(filtertag)))
+            using (Logging.Log.StartScope(m_messageSink.WriteMessage, x => x.FilterTag.Contains(filtertag)))
             {
                 return RunAction(new SendMailResults(), result =>
                 {
@@ -559,7 +559,6 @@ private T RunAction<T>(T result, ref string[] paths, ref IFilter filter, Action<
 
                     using (new ProcessController(m_options))
                     using (new Logging.Timer(LOGTAG, string.Format("Run{0}", result.MainOperation), string.Format("Running {0}", result.MainOperation)))
-                    using (new Logging.RepeatingLogScope())
                         method(result);
 
                     if (result.EndTime.Ticks == 0)

Duplicati/Library/Main/ControllerMultiLogTarget.cs

@@ -79,7 +79,7 @@ public void WriteMessage(LogEntry entry)
         {
             foreach (var e in m_targets)
             {
-                var found = e.Item3.Matches(entry.Tag, out var result, out var match);
+                var found = e.Item3.Matches(entry.FilterTag, out var result, out var match);
 
                 // If there is a filter match, use that
                 if (found)

Duplicati/Server/LogWriteHandler.cs

@@ -118,7 +118,7 @@ public LogEntry(Duplicati.Library.Logging.LogEntry entry)
                 this.Message = entry.FormattedMessage;
                 this.Type = entry.Level;
                 this.Exception = entry.Exception;
-                this.Tag = entry.Tag;
+                this.Tag = entry.FilterTag;
                 this.MessageID = entry.Id;
                 this.BackupID = entry[LOG_EXTRA_BACKUPID];
                 this.TaskID = entry[LOG_EXTRA_TASKID];