Ability to express or override the Message starting level logging fro…

src/Testing/CoreTests/Acceptance/logging_configuration.cs

@@ -1,6 +1,8 @@
+using System.Diagnostics;
 using JasperFx.Core.Reflection;
 using Microsoft.Extensions.Logging;
 using Wolverine.Attributes;
+using Wolverine.Logging;
 using Wolverine.Runtime.Handlers;
 using Xunit;
 
@@ -22,13 +24,64 @@ public void wolverine_logging_attribute_impacts_handler_chain()
         chain.SuccessLogLevel.ShouldBe(LogLevel.None);
         chain.ProcessingLogLevel.ShouldBe(LogLevel.Trace);
     }
+
+    [Fact]
+    public void set_log_message_activity_from_attribute_no_global_policy()
+    {
+        // Not configuration
+        with(opts => { });
+
+        chainFor<AuditedMessage3>().Middleware.OfType<LogStartingActivity>()
+            .Single().Level.ShouldBe(LogLevel.Information);
+    }
+
+    [Fact]
+    public void override_starting_message_activity_from_attribute_over_global_policy()
+    {
+        // Not configuration
+        with(opts =>
+        {
+            opts.Policies.LogMessageStarting(LogLevel.Debug);
+        });
+
+        // Still Information!
+        chainFor<AuditedMessage3>().Middleware.OfType<LogStartingActivity>()
+            .Single().Level.ShouldBe(LogLevel.Information);
+
+        // The default is still from the global policy
+        chainFor<NormalMessage>().Middleware.OfType<LogStartingActivity>()
+            .Single().Level.ShouldBe(LogLevel.Debug);
+    }
+
+    [Fact]
+    public void override_the_log_start_messaging_to_off()
+    {
+        // Not configuration
+        with(opts =>
+        {
+            opts.Policies.LogMessageStarting(LogLevel.Debug);
+        });
+
+        // Attribute says None, so it's None!!!
+        chainFor<QuietMessage2>().Middleware.OfType<LogStartingActivity>()
+            .Any().ShouldBeFalse();
+    }
+}
+
+public record NormalMessage;
+
+public static class NormalMessageHandler
+{
+    public static void Handle(NormalMessage m) => Debug.WriteLine("Got " + m);
 }
 
 #region sample_using_Wolverine_Logging_attribute
 
-public class QuietMessage;
+public record QuietMessage;
+
+public record VerboseMessage;
 
-public class QuietMessageHandler
+public class QuietAndVerboseMessageHandler
 {
     [WolverineLogging(
         telemetryEnabled:false,
@@ -38,6 +91,40 @@ public void Handle(QuietMessage message)
     {
         Console.WriteLine("Hush!");
     }
+
+    [WolverineLogging(
+        // Enable Open Telemetry tracing
+        TelemetryEnabled = true, 
+
+        // Log on successful completion of this message
+        SuccessLogLevel = LogLevel.Information, 
+
+        // Log on execution being complete, but before Wolverine does its own book keeping
+        ExecutionLogLevel = LogLevel.Information, 
+
+        // Throw in yet another contextual logging statement
+        // at the beginning of message execution
+        MessageStartingLevel = LogLevel.Debug)]
+    public void Handle(VerboseMessage message)
+    {
+        Console.WriteLine("Tell me about it!");
+    }
 }
 
-#endregion
+#endregion
+
+public record AuditedMessage3;
+
+public record QuietMessage2;
+
+public static class QuietMessage2Handler
+{
+    [WolverineLogging(MessageStartingLevel = LogLevel.None)]
+    public static void Handle(QuietMessage2 m) => Debug.WriteLine("Got " + m);
+}
+
+public static class AuditedMessage3Handler
+{
+    [WolverineLogging(MessageStartingLevel = LogLevel.Information)]
+    public static void Handle(AuditedMessage3 m) => Debug.WriteLine("Got " + m);
+}

src/Wolverine/Attributes/WolverineLoggingAttribute.cs

@@ -1,5 +1,6 @@
 using JasperFx.CodeGeneration;
 using Microsoft.Extensions.Logging;
+using Wolverine.Logging;
 using Wolverine.Runtime.Handlers;
 
 namespace Wolverine.Attributes;
@@ -9,9 +10,7 @@ namespace Wolverine.Attributes;
 /// </summary>
 public class WolverineLoggingAttribute : ModifyHandlerChainAttribute
 {
-    private readonly bool _telemetryEnabled;
-    private readonly LogLevel _successLogLevel;
-    private readonly LogLevel _executionLogLevel;
+    private LogLevel? _messageStartingLogLevel;
 
     /// <summary>
     /// 
@@ -21,15 +20,54 @@ public class WolverineLoggingAttribute : ModifyHandlerChainAttribute
     /// <param name="executionLogLevel">LogLevel for when Wolverine starts or finishes executing a message</param>
     public WolverineLoggingAttribute(bool telemetryEnabled = true, LogLevel successLogLevel = LogLevel.Information, LogLevel executionLogLevel = LogLevel.Debug)
     {
-        _telemetryEnabled = telemetryEnabled;
-        _successLogLevel = successLogLevel;
-        _executionLogLevel = executionLogLevel;
+        TelemetryEnabled = telemetryEnabled;
+        SuccessLogLevel = successLogLevel;
+        ExecutionLogLevel = executionLogLevel;
     }
 
     public override void Modify(HandlerChain chain, GenerationRules rules)
     {
-        chain.TelemetryEnabled = _telemetryEnabled;
-        chain.SuccessLogLevel = _successLogLevel;
-        chain.ProcessingLogLevel = _executionLogLevel;
+        chain.TelemetryEnabled = TelemetryEnabled;
+        chain.SuccessLogLevel = SuccessLogLevel;
+        chain.ProcessingLogLevel = ExecutionLogLevel;
+
+        if (_messageStartingLogLevel.HasValue)
+        {
+            // Check if the frame already exists!
+            var existing = chain.Middleware.OfType<LogStartingActivity>().FirstOrDefault();
+            if (_messageStartingLogLevel.Value == LogLevel.None && existing != null)
+            {
+                chain.Middleware.Remove(existing);
+            }
+            else if (existing != null)
+            {
+                existing.Level = _messageStartingLogLevel.Value;
+            }
+            else if (_messageStartingLogLevel.Value != LogLevel.None)
+            {
+                chain.Middleware.Insert(0, new LogStartingActivity(_messageStartingLogLevel.Value, chain));
+            }
+        }
     }
+
+    public bool TelemetryEnabled { get; set; }
+
+    public LogLevel SuccessLogLevel { get; set; }
+
+    public LogLevel ExecutionLogLevel { get; set; }
+
+    /// <summary>
+    /// If set to a value (besides LogLevel.None!), this attribute will direct Wolverine to generate code
+    /// logging the beginning of execution of the handler code
+    /// </summary>
+    public LogLevel MessageStartingLevel {
+        set
+        {
+            _messageStartingLogLevel = value;
+        }
+        get
+        {
+            return _messageStartingLogLevel ?? LogLevel.None;
+        }
+    } 
 }

src/Wolverine/Logging/LogStartingActivity.cs

@@ -11,7 +11,6 @@ namespace Wolverine.Logging;
 internal class LogStartingActivity : SyncFrame
 {
     private readonly Type _inputType;
-    private readonly LogLevel _level;
     private readonly IChain _chain;
     private readonly List<AuditedMember> _members;
     private Variable? _envelope;
@@ -20,12 +19,14 @@ internal class LogStartingActivity : SyncFrame
 
     public LogStartingActivity(LogLevel level, IChain chain)
     {
-        _level = level;
+        Level = level;
         _chain = chain;
         _inputType = chain.InputType()!;
         _members = chain.AuditedMembers;
     }
 
+    public LogLevel Level { get; set; }
+
     public override IEnumerable<Variable> FindVariables(IMethodVariables chain)
     {
         _envelope = chain.FindVariable(typeof(Envelope));
@@ -51,7 +52,7 @@ public override void GenerateCode(GeneratedMethod method, ISourceWriter writer)
         args = args.Concat(_members.Select(x => $"{_input!.Usage}.{x.Member.Name}")).ToArray();
 
         writer.WriteLine(
-            $"{_logger!.Usage}.{nameof(ILogger.Log)}({typeof(LogLevel).FullNameInCode()}.{_level.ToString()}, \"{template}\", {args.Join(", ")});");
+            $"{_logger!.Usage}.{nameof(ILogger.Log)}({typeof(LogLevel).FullNameInCode()}.{Level.ToString()}, \"{template}\", {args.Join(", ")});");
 
         Next?.GenerateCode(method, writer);
     }