Merge pull request #61 from nblumhardt/dev

3.1.0 Release

appveyor.yml

@@ -9,7 +9,7 @@ artifacts:
 deploy:
 - provider: NuGet
   api_key:
-    secure: 6m2isg5p2eMqbdrcnt0CXpgN0G3QMoUiRZsrSHJx94gSUECf8xl+zvwkFLmZYRSI
+    secure: PNt/eGIH1e+7YX5jjXKmBDz4QKZ6RvpoIkTz1SYzJJHPYBUnzGY0EiBH9ylG19is
   skip_symbols: true
   on:
     branch: /^(dev|main)$/

src/SerilogTimings/Configuration/LevelledOperation.cs

@@ -13,6 +13,7 @@
 // limitations under the License.
 
 using Serilog;
+using Serilog.Core;
 using Serilog.Events;
 
 namespace SerilogTimings.Configuration
@@ -59,6 +60,7 @@ internal LevelledOperation(ILogger logger, LogEventLevel completion, LogEventLev
         /// <param name="args">Arguments to the log message. These will be stored and captured only when the
         /// operation completes, so do not pass arguments that are mutated during the operation.</param>
         /// <returns>An <see cref="Operation"/> object.</returns>
+        [MessageTemplateFormatMethod("messageTemplate")]
         public Operation Begin(string messageTemplate, params object[] args)
         {
             return _cachedResult ?? new Operation(_logger!, messageTemplate, args, CompletionBehaviour.Abandon, _completion, _abandonment, _warningThreshold);
@@ -71,6 +73,7 @@ public Operation Begin(string messageTemplate, params object[] args)
         /// <param name="args">Arguments to the log message. These will be stored and captured only when the
         /// operation completes, so do not pass arguments that are mutated during the operation.</param>
         /// <returns>An <see cref="Operation"/> object.</returns>
+        [MessageTemplateFormatMethod("messageTemplate")]
         public IDisposable Time(string messageTemplate, params object[] args)
         {
             return _cachedResult ?? new Operation(_logger!, messageTemplate, args, CompletionBehaviour.Complete, _completion, _abandonment, _warningThreshold);

src/SerilogTimings/Extensions/LoggerOperationExtensions.cs

@@ -13,6 +13,7 @@
 // limitations under the License.
 
 using Serilog;
+using Serilog.Core;
 using Serilog.Events;
 using SerilogTimings.Configuration;
 
@@ -31,6 +32,7 @@ public static class LoggerOperationExtensions
         /// <param name="args">Arguments to the log message. These will be stored and captured only when the
         /// operation completes, so do not pass arguments that are mutated during the operation.</param>
         /// <returns>An <see cref="Operation"/> object.</returns>
+        [MessageTemplateFormatMethod("messageTemplate")]
         public static IDisposable TimeOperation(this ILogger logger, string messageTemplate, params object[] args)
         {
             return new Operation(logger, messageTemplate, args, CompletionBehaviour.Complete, LogEventLevel.Information, LogEventLevel.Warning);
@@ -45,6 +47,7 @@ public static IDisposable TimeOperation(this ILogger logger, string messageTempl
         /// <param name="args">Arguments to the log message. These will be stored and captured only when the
         /// operation completes, so do not pass arguments that are mutated during the operation.</param>
         /// <returns>An <see cref="Operation"/> object.</returns>
+        [MessageTemplateFormatMethod("messageTemplate")]
         public static Operation BeginOperation(this ILogger logger, string messageTemplate, params object[] args)
         {
             return new Operation(logger, messageTemplate, args, CompletionBehaviour.Abandon, LogEventLevel.Information, LogEventLevel.Warning);

src/SerilogTimings/Operation.cs

@@ -69,7 +69,7 @@ public enum Properties
         readonly LogEventLevel _abandonmentLevel;
         readonly TimeSpan? _warningThreshold;
         Exception? _exception;
-        
+
         internal Operation(ILogger target, string messageTemplate, object[] args,
             CompletionBehaviour completionBehaviour, LogEventLevel completionLevel, LogEventLevel abandonmentLevel,
             TimeSpan? warningThreshold = null)
@@ -98,6 +98,7 @@ static long GetTimestamp()
         /// <param name="args">Arguments to the log message. These will be stored and captured only when the
         /// operation completes, so do not pass arguments that are mutated during the operation.</param>
         /// <returns>An <see cref="Operation"/> object.</returns>
+        [MessageTemplateFormatMethod("messageTemplate")]
         public static Operation Begin(string messageTemplate, params object[] args)
         {
             return Log.Logger.BeginOperation(messageTemplate, args);
@@ -110,6 +111,7 @@ public static Operation Begin(string messageTemplate, params object[] args)
         /// <param name="args">Arguments to the log message. These will be stored and captured only when the
         /// operation completes, so do not pass arguments that are mutated during the operation.</param>
         /// <returns>An <see cref="Operation"/> object.</returns>
+        [MessageTemplateFormatMethod("messageTemplate")]
         public static IDisposable Time(string messageTemplate, params object[] args)
         {
             return Log.Logger.TimeOperation(messageTemplate, args);
@@ -147,7 +149,7 @@ public TimeSpan Elapsed
                     // (HAL) on machines with variable-speed CPUs (e.g. Intel SpeedStep).
                     return TimeSpan.Zero;
                 }
-                
+
                 return TimeSpan.FromTicks(elapsedTicks);
             }
         }
@@ -163,6 +165,20 @@ public void Complete()
             Write(_target, _completionLevel, OutcomeCompleted);
         }
 
+        /// <summary>
+        /// Complete the timed operation with the given Log Event level. This will write the event and elapsed time to the log.
+        /// </summary>
+        /// <param name="level">The log event level with which the complete operation will be logged</param>
+
+        public void Complete(LogEventLevel level)
+        {
+            if (_completionBehaviour == CompletionBehaviour.Silent)
+                return;
+
+            Write(_target, level, OutcomeCompleted);
+        }
+
+
         /// <summary>
         /// Complete the timed operation with an included result value.
         /// </summary>
@@ -179,6 +195,23 @@ public void Complete(string resultPropertyName, object result, bool destructureO
             Write(_target.ForContext(resultPropertyName, result, destructureObjects), _completionLevel, OutcomeCompleted);
         }
 
+        /// <summary>
+        /// Complete the timed operation with an included result value and log event level.
+        /// </summary>
+        /// <param name="level">The log event level with which the complete operation will be logged</param>
+        /// <param name="resultPropertyName">The name for the property to attach to the event.</param>
+        /// <param name="result">The result value.</param>
+        /// <param name="destructureObjects">If true, the property value will be destructured (serialized).</param>
+        public void Complete(string resultPropertyName, object result, LogEventLevel level, bool destructureObjects = false)
+        {
+            if (resultPropertyName == null) throw new ArgumentNullException(nameof(resultPropertyName));
+
+            if (_completionBehaviour == CompletionBehaviour.Silent)
+                return;
+
+            Write(_target.ForContext(resultPropertyName, result, destructureObjects), level, OutcomeCompleted);
+        }
+
         /// <summary>
         /// Abandon the timed operation. This will write the event and elapsed time to the log.
         /// </summary>
@@ -243,10 +276,10 @@ void Write(ILogger target, LogEventLevel level, string outcome)
             _completionBehaviour = CompletionBehaviour.Silent;
 
             var elapsed = Elapsed.TotalMilliseconds;
-            
+
             level = elapsed > _warningThreshold?.TotalMilliseconds && level < LogEventLevel.Warning
                 ? LogEventLevel.Warning
-                : level; 
+                : level;
 
             target.Write(level, _exception, $"{_messageTemplate} {{{nameof(Properties.Outcome)}}} in {{{nameof(Properties.Elapsed)}:0.0}} ms", _args.Concat(new object[] { outcome, elapsed }).ToArray());
 

src/SerilogTimings/SerilogTimings.csproj

@@ -2,7 +2,7 @@
 
   <PropertyGroup>
     <Description>Extend Serilog with timed operations.</Description>
-    <VersionPrefix>3.0.1</VersionPrefix>
+    <VersionPrefix>3.1.0</VersionPrefix>
     <Authors>nblumhardt;SerilogTimings Contributors</Authors>
     <TargetFrameworks>netstandard2.0;net6.0</TargetFrameworks>
     <TreatWarningsAsErrors>true</TreatWarningsAsErrors>

test/SerilogTimings.Tests/OperationTests.cs

@@ -1,10 +1,10 @@
-using System;
-using System.Linq;
-using System.Threading.Tasks;
-using Serilog;
+using Serilog;
 using Serilog.Events;
 using SerilogTimings.Extensions;
 using SerilogTimings.Tests.Support;
+using System;
+using System.Linq;
+using System.Threading.Tasks;
 using Xunit;
 
 namespace SerilogTimings.Tests
@@ -94,6 +94,36 @@ public void CompleteRecordsResultsOfOperations()
             Assert.True(logger.Events.Single().Properties.ContainsKey("Value"));
         }
 
+        [Fact]
+        public void CompleteRecordsResultsOfOperationsWithGivenLogLevel()
+        {
+            var logger = new CollectingLogger();
+            var op = logger.Logger.BeginOperation("Test");
+            op.Complete("Value", 42, LogEventLevel.Warning);
+            Assert.Single(logger.Events);
+            Assert.True(logger.Events.Single().Properties.ContainsKey("Value"));
+            Assert.Equal(LogEventLevel.Warning, logger.Events.Single().Level);
+        }
+
+        [Fact]
+        public void CompletesWithGivenLogLevel()
+        {
+            var logger = new CollectingLogger();
+            var op = logger.Logger.BeginOperation("Test");
+            op.Complete(LogEventLevel.Error);
+            Assert.Equal(LogEventLevel.Error, logger.Events.Single().Level);
+        }
+
+        [Fact]
+        public void DoesNotCompleteWithGivenLevelIfAbandonedBeforehand()
+        {
+            var logger = new CollectingLogger();
+            var op = logger.Logger.BeginOperation("Test");
+            op.Abandon();
+            op.Complete(LogEventLevel.Error);
+            Assert.Equal(LogEventLevel.Warning, logger.Events.Single().Level);
+        }
+
         [Fact]
         public void OnceCanceledDisposeDoesNotRecordCompletionOfOperations()
         {
@@ -271,7 +301,7 @@ public async Task ElapsedUpdatesDuringOperation()
             Assert.Equal(third, fourth);
             Assert.Equal(fourth, fifth);
         }
-        
+
         [Fact]
         public async Task LongOperationsAreLoggedAsWarnings()
         {