Fixes #41 - level switch behaviour when server sends no level

sample/Sample/Program.cs

@@ -23,7 +23,7 @@ public static void Main(string[] args)
 
             Log.Information("Sample starting up");
 
-            foreach (var i in Enumerable.Range(0, 1000))
+            foreach (var i in Enumerable.Range(0, 10))
             {
                 Log.Information("Running loop {Counter}", i);
 

src/Serilog.Sinks.Seq/Sinks/Seq/ControlledLevelSwitch.cs

@@ -0,0 +1,73 @@
+// Serilog.Sinks.Seq Copyright 2016 Serilog Contributors
+// 
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+// 
+//     http://www.apache.org/licenses/LICENSE-2.0
+// 
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+using System;
+using Serilog.Core;
+using Serilog.Events;
+
+namespace Serilog.Sinks.Seq
+{
+    /// <summary>
+    /// Instances of this type are single-threaded, generally only updated on a background
+    /// timer thread. An exception is <see cref="IsIncluded(LogEvent)"/>, which may be called
+    /// concurrently but performs no synchronization.
+    /// </summary>
+    class ControlledLevelSwitch
+    {
+        // If non-null, then background level checks will be performed; set either through the constructor
+        // or in response to a level specification from the server. Never set to null after being made non-null.
+        LoggingLevelSwitch _controlledSwitch;
+        LogEventLevel? _originalLevel;
+
+        public ControlledLevelSwitch(LoggingLevelSwitch controlledSwitch = null)
+        {
+            _controlledSwitch = controlledSwitch;
+        }
+
+        public bool IsActive => _controlledSwitch != null;
+
+        public bool IsIncluded(LogEvent evt)
+        {
+            // Concurrent, but not synchronized.
+            var controlledSwitch = _controlledSwitch;
+            return controlledSwitch == null ||
+                (int)controlledSwitch.MinimumLevel <= (int)evt.Level;
+        }
+
+        public void Update(LogEventLevel? minimumAcceptedLevel)
+        {
+            if (minimumAcceptedLevel == null)
+            {
+                if (_controlledSwitch != null && _originalLevel.HasValue)
+                    _controlledSwitch.MinimumLevel = _originalLevel.Value;
+
+                return;
+            }
+
+            if (_controlledSwitch == null)
+            {
+                // The server is controlling the logging level, but not the overall logger. Hence, if the server
+                // stops controlling the level, the switch should become transparent.
+                _originalLevel = LevelAlias.Minimum;
+                _controlledSwitch = new LoggingLevelSwitch(minimumAcceptedLevel.Value);
+                return;
+            }
+
+            if (!_originalLevel.HasValue)
+                _originalLevel = _controlledSwitch.MinimumLevel;
+
+            _controlledSwitch.MinimumLevel = minimumAcceptedLevel.Value;
+        }
+    }
+}

src/Serilog.Sinks.Seq/Sinks/Seq/DurableSeqSink.cs

@@ -72,9 +72,7 @@ public void Emit(LogEvent logEvent)
         {
             // This is a lagging indicator, but the network bandwidth usage benefits
             // are worth the ambiguity.
-            var minimumAcceptedLevel = _shipper.MinimumAcceptedLevel;
-            if (minimumAcceptedLevel == null ||
-                (int)minimumAcceptedLevel <= (int)logEvent.Level)
+            if (_shipper.IsIncluded(logEvent))
             {
                 _sink.Emit(logEvent);
             }

src/Serilog.Sinks.Seq/Sinks/Seq/HttpLogShipper.cs

@@ -50,7 +50,7 @@ class HttpLogShipper : IDisposable
         readonly object _stateLock = new object();
         readonly PortableTimer _timer;
 
-        LoggingLevelSwitch _levelControlSwitch;
+        ControlledLevelSwitch _controlledSwitch;
         DateTime _nextRequiredLevelCheckUtc = DateTime.UtcNow.Add(RequiredLevelCheckInterval);
         volatile bool _unloading;
 
@@ -68,7 +68,7 @@ public HttpLogShipper(
             _apiKey = apiKey;
             _batchPostingLimit = batchPostingLimit;
             _eventBodyLimitBytes = eventBodyLimitBytes;
-            _levelControlSwitch = levelControlSwitch;
+            _controlledSwitch = new ControlledLevelSwitch(levelControlSwitch);
             _connectionSchedule = new ExponentialBackoffConnectionSchedule(period);
             _retainedInvalidPayloadsLimitBytes = retainedInvalidPayloadsLimitBytes;
             _httpClient = messageHandler != null ?
@@ -100,35 +100,14 @@ void CloseAndFlush()
             OnTick().ConfigureAwait(false).GetAwaiter().GetResult();
         }
 
-        /// <summary>
-        /// Get the last "minimum level" indicated by the Seq server, if any.
-        /// </summary>
-        public LogEventLevel? MinimumAcceptedLevel
+        public bool IsIncluded(LogEvent logEvent)
         {
-            get
-            {
-                lock (_stateLock)
-                    return _levelControlSwitch?.MinimumLevel;
-            }
+            return _controlledSwitch.IsIncluded(logEvent);
         }
 
-        /// <summary>
-        /// Performs application-defined tasks associated with freeing, releasing, or resetting unmanaged resources.
-        /// </summary>
-        /// <filterpriority>2</filterpriority>
+        /// <inheritdoc/>
         public void Dispose()
         {
-            Dispose(true);
-        }
-
-        /// <summary>
-        /// Free resources held by the sink.
-        /// </summary>
-        /// <param name="disposing">If true, called because the object is being disposed; if false,
-        /// the object is being disposed from the finalizer.</param>
-        protected virtual void Dispose(bool disposing)
-        {
-            if (!disposing) return;
             CloseAndFlush();
         }
 
@@ -172,7 +151,7 @@ async Task OnTick()
 
                         var payload = ReadPayload(currentFile, ref nextLineBeginsAtOffset, ref count);
 
-                        if (count > 0 || _levelControlSwitch != null && _nextRequiredLevelCheckUtc < DateTime.UtcNow)
+                        if (count > 0 || _controlledSwitch.IsActive && _nextRequiredLevelCheckUtc < DateTime.UtcNow)
                         {
                             lock (_stateLock)
                             {
@@ -244,7 +223,7 @@ async Task OnTick()
             {
                 lock (_stateLock)
                 {
-                    UpdateLevelControlSwitch(minimumAcceptedLevel);
+                    _controlledSwitch.Update(minimumAcceptedLevel);
 
                     if (!_unloading)
                         SetTimer();
@@ -315,22 +294,6 @@ orderby candiateFileInfo.LastAccessTimeUtc descending
             }
         }
 
-        void UpdateLevelControlSwitch(LogEventLevel? minimumAcceptedLevel)
-        {
-            if (minimumAcceptedLevel == null)
-            {
-                if (_levelControlSwitch != null)
-                    _levelControlSwitch.MinimumLevel = LevelAlias.Minimum;
-            }
-            else
-            {
-                if (_levelControlSwitch == null)
-                    _levelControlSwitch = new LoggingLevelSwitch(minimumAcceptedLevel.Value);
-                else
-                    _levelControlSwitch.MinimumLevel = minimumAcceptedLevel.Value;
-            }
-        }
-
         string ReadPayload(string currentFile, ref long nextLineBeginsAtOffset, ref int count)
         {
             var payload = new StringWriter();

src/Serilog.Sinks.Seq/Sinks/Seq/SeqSink.cs

@@ -30,22 +30,20 @@ namespace Serilog.Sinks.Seq
 {
     class SeqSink : PeriodicBatchingSink
     {
-        readonly string _apiKey;
-        readonly long? _eventBodyLimitBytes;
-        readonly HttpClient _httpClient;
+        public const int DefaultBatchPostingLimit = 1000;
+        public static readonly TimeSpan DefaultPeriod = TimeSpan.FromSeconds(2);
+        public const int DefaultQueueSizeLimit = 100000;
 
+        static readonly TimeSpan RequiredLevelCheckInterval = TimeSpan.FromMinutes(2);
         static readonly JsonValueFormatter JsonValueFormatter = new JsonValueFormatter();
 
-        // If non-null, then background level checks will be performed; set either through the constructor
-        // or in response to a level specification from the server. Never set to null after being made non-null.
-        LoggingLevelSwitch _levelControlSwitch;
+        readonly string _apiKey;
+        readonly long? _eventBodyLimitBytes;
+        readonly HttpClient _httpClient;
         readonly bool _useCompactFormat;
-        static readonly TimeSpan RequiredLevelCheckInterval = TimeSpan.FromMinutes(2);
-        DateTime _nextRequiredLevelCheckUtc = DateTime.UtcNow.Add(RequiredLevelCheckInterval);
 
-        public const int DefaultBatchPostingLimit = 1000;
-        public static readonly TimeSpan DefaultPeriod = TimeSpan.FromSeconds(2);
-        public const int DefaultQueueSizeLimit = 100000;
+        DateTime _nextRequiredLevelCheckUtc = DateTime.UtcNow.Add(RequiredLevelCheckInterval);
+        ControlledLevelSwitch _controlledSwitch;
 
         public SeqSink(
             string serverUrl,
@@ -62,7 +60,7 @@ public SeqSink(
             if (serverUrl == null) throw new ArgumentNullException(nameof(serverUrl));
             _apiKey = apiKey;
             _eventBodyLimitBytes = eventBodyLimitBytes;
-            _levelControlSwitch = levelControlSwitch;
+            _controlledSwitch = new ControlledLevelSwitch(levelControlSwitch);
             _useCompactFormat = useCompactFormat;
             _httpClient = messageHandler != null ? new HttpClient(messageHandler) : new HttpClient();
             _httpClient.BaseAddress = new Uri(SeqApi.NormalizeServerBaseAddress(serverUrl));
@@ -80,7 +78,7 @@ protected override void Dispose(bool disposing)
         // configured to set a specific level, before background level checks will be performed.
         protected override void OnEmptyBatch()
         {
-            if (_levelControlSwitch != null &&
+            if (_controlledSwitch.IsActive &&
                 _nextRequiredLevelCheckUtc < DateTime.UtcNow)
             {
                 EmitBatch(Enumerable.Empty<LogEvent>());
@@ -112,19 +110,7 @@ protected override async Task EmitBatchAsync(IEnumerable<LogEvent> events)
                 throw new LoggingFailedException($"Received failed result {result.StatusCode} when posting events to Seq");
 
             var returned = await result.Content.ReadAsStringAsync();
-            var minimumAcceptedLevel = SeqApi.ReadEventInputResult(returned);
-            if (minimumAcceptedLevel == null)
-            {
-                if (_levelControlSwitch != null)
-                    _levelControlSwitch.MinimumLevel = LevelAlias.Minimum;
-            }
-            else
-            {
-                if (_levelControlSwitch == null)
-                    _levelControlSwitch = new LoggingLevelSwitch(minimumAcceptedLevel.Value);
-                else
-                    _levelControlSwitch.MinimumLevel = minimumAcceptedLevel.Value;
-            }
+            _controlledSwitch.Update(SeqApi.ReadEventInputResult(returned));
         }
 
         internal static string FormatCompactPayload(IEnumerable<LogEvent> events, long? eventBodyLimitBytes)
@@ -190,9 +176,7 @@ internal static string FormatRawPayload(IEnumerable<LogEvent> events, long? even
 
         protected override bool CanInclude(LogEvent evt)
         {
-            var levelControlSwitch = _levelControlSwitch;
-            return levelControlSwitch == null ||
-                (int)levelControlSwitch.MinimumLevel <= (int)evt.Level;
+            return _controlledSwitch.IsIncluded(evt);
         }
 
         static bool CheckEventBodySize(string json, long? eventBodyLimitBytes)

test/Serilog.Sinks.Seq.Tests/ControlledLevelSwitchTests.cs

@@ -0,0 +1,90 @@
+using Serilog.Core;
+using Serilog.Events;
+using Serilog.Sinks.Seq.Tests.Support;
+using Xunit;
+
+namespace Serilog.Sinks.Seq.Tests
+{
+    public class ControlledLevelSwitchTests
+    {
+        [Fact]
+        public void WhenTheServerSendsALevelTheSwitchIsAdjusted()
+        {
+            var lls = new LoggingLevelSwitch(LogEventLevel.Warning);
+            var cls = new ControlledLevelSwitch(lls);
+            cls.Update(LogEventLevel.Debug);
+            Assert.Equal(LogEventLevel.Debug, lls.MinimumLevel);
+        }
+
+        [Fact]
+        public void WhenTheServerSendsNoLevelTheSwitchIsNotInitiallyAdjusted()
+        {
+            var lls = new LoggingLevelSwitch(LogEventLevel.Warning);
+            lls.MinimumLevel = LogEventLevel.Fatal;
+            var cls = new ControlledLevelSwitch(lls);
+            cls.Update(null);
+            Assert.Equal(LogEventLevel.Fatal, lls.MinimumLevel);
+        }
+
+        [Fact]
+        public void WhenTheServerSendsNoLevelTheSwitchIsResetIfPreviouslyAdjusted()
+        {
+            var lls = new LoggingLevelSwitch(LogEventLevel.Warning);
+            var cls = new ControlledLevelSwitch(lls);
+            cls.Update(LogEventLevel.Information);
+            cls.Update(null);
+            Assert.Equal(LogEventLevel.Warning, lls.MinimumLevel);
+        }
+
+        [Fact]
+        public void WithNoSwitchToControlAllEventsAreIncluded()
+        {
+            var cls = new ControlledLevelSwitch(null);
+            Assert.True(cls.IsIncluded(Some.DebugEvent()));
+        }
+
+        [Fact]
+        public void WithNoSwitchToControlEventsAreStillFiltered()
+        {
+            var cls = new ControlledLevelSwitch(null);
+            cls.Update(LogEventLevel.Warning);
+            Assert.True(cls.IsIncluded(Some.ErrorEvent()));
+            Assert.False(cls.IsIncluded(Some.InformationEvent()));
+        }
+
+        [Fact]
+        public void WithNoSwitchToControlAllEventsAreIncludedAfterReset()
+        {
+            var cls = new ControlledLevelSwitch(null);
+            cls.Update(LogEventLevel.Warning);
+            cls.Update(null);
+            Assert.True(cls.IsIncluded(Some.DebugEvent()));
+        }
+
+        [Fact]
+        public void WhenControllingASwitchTheControllerIsActive()
+        {
+            var cls = new ControlledLevelSwitch(new LoggingLevelSwitch());
+            Assert.True(cls.IsActive);
+        }
+
+        [Fact]
+        public void WhenNotControllingASwitchTheControllerIsNotActive()
+        {
+            var cls = new ControlledLevelSwitch();
+            Assert.False(cls.IsActive);
+        }
+
+        [Fact]
+        public void AfterServerControlhTheControllerIsAlwaysActive()
+        {
+            var cls = new ControlledLevelSwitch();
+
+            cls.Update(LogEventLevel.Information);
+            Assert.True(cls.IsActive);
+
+            cls.Update(null);
+            Assert.True(cls.IsActive);
+        }
+    }
+}