BufferingTargetWrapper - Avoid Timer starvation when SlidingTimeout = true

snakefoot · 304NotModified · commit 267d29ea3b1a · 2019-05-28T20:24:07.000+02:00
diff --git a/src/NLog/Common/LogEventInfoBuffer.cs b/src/NLog/Common/LogEventInfoBuffer.cs
@@ -65,10 +65,15 @@ public LogEventInfoBuffer(int size, bool growAsNeeded, int growLimit)
         }
 
         /// <summary>
-        /// Gets the number of items in the array.
+        /// Gets the capacity of the buffer
         /// </summary>
         public int Size => _buffer.Length;
 
+        /// <summary>
+        /// Gets the number of items in the buffer
+        /// </summary>
+        internal int Count { get { lock (_lockObject) return _count; } }
+
         /// <summary>
         /// Adds the specified log event to the buffer.
         /// </summary>
diff --git a/src/NLog/Targets/Wrappers/BufferingTargetWrapper.cs b/src/NLog/Targets/Wrappers/BufferingTargetWrapper.cs
@@ -187,10 +187,7 @@ protected override void CloseTarget()
                 _flushTimer = null;
                 if (currentTimer.WaitForDispose(TimeSpan.FromSeconds(1)))
                 {
-                    lock (_lockObject)
-                    {
-                        WriteEventsInBuffer("Closing Target");
-                    }
+                    WriteEventsInBuffer("Closing Target");
                 }
             }
 
@@ -228,15 +225,24 @@ protected override void Write(AsyncLogEventInfo logEvent)
 
         private void FlushCallback(object state)
         {
+            bool lockTaken = false;
+
             try
             {
-                lock (_lockObject)
+                int timeoutMilliseconds = Math.Min(FlushTimeout / 2, 100);
+                lockTaken = Monitor.TryEnter(_lockObject, timeoutMilliseconds);
+                if (lockTaken)
                 {
                     if (_flushTimer == null)
                         return;
 
                     WriteEventsInBuffer(null);
                 }
+                else
+                {
+                    if (_buffer.Count > 0)
+                        _flushTimer?.Change(FlushTimeout, -1);   // Schedule new retry timer
+                }
             }
             catch (Exception exception)
             {
@@ -247,6 +253,13 @@ private void FlushCallback(object state)
                     throw;  // Throwing exceptions here will crash the entire application (.NET 2.0 behavior)
                 }
             }
+            finally
+            {
+                if (lockTaken)
+                {
+                    Monitor.Exit(_lockObject);
+                }
+            }
         }
 
         private void WriteEventsInBuffer(string reason)

Original file line number	Diff line number	Diff line change
`@@ -187,10 +187,7 @@ protected override void CloseTarget()`
`187`	`187`	`_flushTimer = null;`
`188`	`188`	`if (currentTimer.WaitForDispose(TimeSpan.FromSeconds(1)))`
`189`	`189`	`{`
`190`		`- lock (_lockObject)`
`191`		`- {`
`192`		`- WriteEventsInBuffer("Closing Target");`
`193`		`- }`
	`190`	`+ WriteEventsInBuffer("Closing Target");`
`194`	`191`	`}`
`195`	`192`	`}`
`196`	`193`
`@@ -228,15 +225,24 @@ protected override void Write(AsyncLogEventInfo logEvent)`
`228`	`225`
`229`	`226`	`private void FlushCallback(object state)`
`230`	`227`	`{`
	`228`	`+ bool lockTaken = false;`
	`229`	`+`
`231`	`230`	`try`
`232`	`231`	`{`
`233`		`- lock (_lockObject)`
	`232`	`+ int timeoutMilliseconds = Math.Min(FlushTimeout / 2, 100);`
	`233`	`+ lockTaken = Monitor.TryEnter(_lockObject, timeoutMilliseconds);`
	`234`	`+ if (lockTaken)`
`234`	`235`	`{`
`235`	`236`	`if (_flushTimer == null)`
`236`	`237`	`return;`
`237`	`238`
`238`	`239`	`WriteEventsInBuffer(null);`
`239`	`240`	`}`
	`241`	`+ else`
	`242`	`+ {`
	`243`	`+ if (_buffer.Count > 0)`
	`244`	`+ _flushTimer?.Change(FlushTimeout, -1); // Schedule new retry timer`
	`245`	`+ }`
`240`	`246`	`}`
`241`	`247`	`catch (Exception exception)`
`242`	`248`	`{`
`@@ -247,6 +253,13 @@ private void FlushCallback(object state)`
`247`	`253`	`throw; // Throwing exceptions here will crash the entire application (.NET 2.0 behavior)`
`248`	`254`	`}`
`249`	`255`	`}`
	`256`	`+ finally`
	`257`	`+ {`
	`258`	`+ if (lockTaken)`
	`259`	`+ {`
	`260`	`+ Monitor.Exit(_lockObject);`
	`261`	`+ }`
	`262`	`+ }`
`250`	`263`	`}`
`251`	`264`
`252`	`265`	`private void WriteEventsInBuffer(string reason)`