Merge pull request #30 from nblumhardt/template-conditionals

Template conditionals/repetition

Author: nblumhardt

README.md

@@ -1,4 +1,4 @@
-# _Serilog Expressions_ [![Build status](https://ci.appveyor.com/api/projects/status/w7igkk3w51h481r6/branch/dev?svg=true)](https://ci.appveyor.com/project/serilog/serilog-expressions/branch/dev) [![NuGet Package](https://img.shields.io/nuget/vpre/serilog.expressions)](https://nuget.org/packages/serilog.expressions)
+# _Serilog Expressions_ [![Build status](https://ci.appveyor.com/api/projects/status/vmcskdk2wjn1rpps/branch/dev?svg=true)](https://ci.appveyor.com/project/serilog/serilog-expressions/branch/dev) [![NuGet Package](https://img.shields.io/nuget/vpre/serilog.expressions)](https://nuget.org/packages/serilog.expressions)
 
 An embeddable mini-language for filtering, enriching, and formatting Serilog 
 events, ideal for use with JSON or XML configuration.
@@ -79,7 +79,7 @@ _Serilog.Expressions_ adds a number of expression-based overloads and helper met
  * `Enrich.When()` - conditionally enable an enricher when events match an expression
  * `Enrich.WithComputed()` - add or modify event properties using an expression
 
-## Formatting
+## Formatting with `ExpressionTemplate`
 
 _Serilog.Expressions_ includes the `ExpressionTemplate` class for text formatting. `ExpressionTemplate` implements `ITextFormatter`, so
 it works with any text-based Serilog sink:
@@ -89,11 +89,14 @@ it works with any text-based Serilog sink:
 
 Log.Logger = new LoggerConfiguration()
     .WriteTo.Console(new ExpressionTemplate(
-        "[{@t:HH:mm:ss} {@l:u3} ({SourceContext})] {@m} (first item is {Items[0]})\n{@x}"))
+        "[{@t:HH:mm:ss} {@l:u3} ({SourceContext})] {@m} (first item is {Cart[0]})\n{@x}"))
     .CreateLogger();
+    
+// Produces log events like:
+// [21:21:40 INF (Sample.Program)] Cart contains ["Tea","Coffee"] (first item is Tea)
 ```
 
-Note the use of `{Items[0]}`: "holes" in expression templates can include any valid expression.
+Note the use of `{Cart[0]}`: "holes" in expression templates can include any valid expression over properties from the event.
 
 Newline-delimited JSON (for example, replicating the [CLEF format](https://github.com/serilog/serilog-formatting-compact)) can be generated
 using object literals:
@@ -109,7 +112,7 @@ using object literals:
 
 The following properties are available in expressions:
 
- * **All first-class properties of the event** — no special syntax: `SourceContext` and `Items` are used in the formatting example above
+ * **All first-class properties of the event** — no special syntax: `SourceContext` and `Cart` are used in the formatting examples above
  * `@t` - the event's timestamp, as a `DateTimeOffset`
  * `@m` - the rendered message
  * `@mt` - the raw message template
@@ -149,7 +152,7 @@ A typical set of operators is supported:
  * Accessors `a.b`
  * Indexers `a['b']` and `a[0]`
  * Wildcard indexing - `a[?]` any, and `a[*]` all
- * Conditional `if a then b else c` (all branches required)
+ * Conditional `if a then b else c` (all branches required; see also the section below on _conditional blocks_)
 
 Comparision operators that act on text all accept an optional postfix `ci` modifier to select case-insensitive comparisons:
 
@@ -195,6 +198,64 @@ Functions that compare text accept an optional postfix `ci` modifier to select c
 StartsWith(User.Name, 'n') ci
 ```
 
+### Template directives
+
+#### Conditional blocks
+
+Within an `ExpressionTemplate`, a portion of the template can be conditionally evaluated using `#if`.
+
+```csharp
+Log.Logger = new LoggerConfiguration()
+    .WriteTo.Console(new ExpressionTemplate(
+        "[{@t:HH:mm:ss} {@l:u3}{#if SourceContext is not null} ({SourceContext}){#end}] {@m}\n{@x}"))
+    .CreateLogger();
+    
+// Produces log events like:
+// [21:21:45 INF] Starting up
+// [21:21:46 INF (Sample.Program)] Firing engines   
+```
+
+The block between the `{#if <expr>}` and `{#end}` directives will only appear in the output if `<expr>` is `true` - in the example, events with a `SourceContext` include this in parentheses, while those without, don't.
+
+It's important to notice that the directive requires a Boolean `true` before the conditional block will be evaluated. It wouldn't be sufficient in this case to write `{#if SourceContext}`, since no values other than `true` are considered "truthy".
+
+The syntax supports `{#if <expr>}`, chained `{#else if <expr>}`, `{#else}`, and `{#end}`, with arbitrary nesting.
+
+#### Repetition
+
+If a log event includes structured data in arrays or objects, a template block can be repeated for each element or member using `#each`/`in` (newlines, double quotes and construction of the `ExpressionTemplate` omitted for clarity):
+
+```
+{@l:w4}: {SourceContext}
+      {#each s in Scope}=> {s}{#delimit} {#end}
+      {@m}
+{@x}
+```
+
+This example uses the optional `#delimit` to add a space between each element, producing output like:
+
+```
+info: Sample.Program
+      => Main => TextFormattingExample
+      Hello, world!
+```
+
+When using `{#each <name> in <expr>}` over an object, such as the built-in `@p` (properties) object, `<name>` will be bound to the _names_ of the properties of the object.
+
+To get to the _values_ of the properties, use a second binding:
+
+```
+{#each k, v in @p}{k} = {v}{#delimit},{#end}
+```
+
+This example, if an event has three properties, will produce output like:
+
+```
+Account = "nblumhardt", Cart = ["Tea", "Coffee"], Powerup = 42
+```
+
+The syntax supports `{#each <name>[, <name>] in <expr>}`, an optional `{#delimit}` block, and finally an optional `{#else}` block, which will be evaluated if the array or object is empty.
+
 ## Recipes
 
 **Trim down `SourceContext` to a type name only:**

example/Sample/Program.cs

@@ -12,25 +12,22 @@ public static void Main()
         {
             SelfLog.Enable(Console.Error);
 
-            TextFormattingExample();
+            TextFormattingExample1();
             JsonFormattingExample();
             PipelineComponentExample();
+            TextFormattingExample2();
         }
 
-        static void TextFormattingExample()
+        static void TextFormattingExample1()
         {
             using var log = new LoggerConfiguration()
                 .WriteTo.Console(new ExpressionTemplate(
-                    "[{@t:HH:mm:ss} " +
-                    "{@l:u3} " +
-                    "({coalesce(Substring(SourceContext, LastIndexOf(SourceContext, '.') + 1), '<no source>')})] " +
-                    "{@m} " +
-                    "(first item is {coalesce(Items[0], '<empty>')})" +
-                    "\n" +
-                    "{@x}"))
+                    "[{@t:HH:mm:ss} {@l:u3}" +
+                    "{#if SourceContext is not null} ({Substring(SourceContext, LastIndexOf(SourceContext, '.') + 1)}){#end}] " +
+                    "{@m} (first item is {coalesce(Items[0], '<empty>')})\n{@x}"))
                 .CreateLogger();
 
-            log.Information("Running {Example}", nameof(TextFormattingExample));
+            log.Information("Running {Example}", nameof(TextFormattingExample1));
 
             log.ForContext<Program>()
                 .Information("Cart contains {@Items}", new[] { "Tea", "Coffee" });
@@ -75,5 +72,26 @@ static void PipelineComponentExample()
             log.ForContext<Program>()
                 .Information("Cart contains {@Items}", new[] { "Apricots" });
         }
+        
+        static void TextFormattingExample2()
+        {
+            using var log = new LoggerConfiguration()
+                .WriteTo.Console(new ExpressionTemplate(
+                    "{@l:w4}: {SourceContext}\n" +
+                    "{#if Scope is not null}" +
+                    "      {#each s in Scope}=> {s}{#delimit} {#end}\n" +
+                    "{#end}" +
+                    "      {@m}\n" +
+                    "{@x}"))
+                .CreateLogger();
+
+            var program = log.ForContext<Program>();
+            program.Information("Starting up");
+            
+            // Emulate data produced by the Serilog.AspNetCore integration
+            var scoped = program.ForContext("Scope", new[] {"Main", "TextFormattingExample2()"});
+            
+            scoped.Information("Hello, world!");
+        }
     }
 }

serilog-expressions.sln.DotSettings

@@ -2,6 +2,7 @@
 	<s:Boolean x:Key="/Default/UserDictionary/Words/=Acerola/@EntryIndexedValue">True</s:Boolean>
 	<s:Boolean x:Key="/Default/UserDictionary/Words/=Comparand/@EntryIndexedValue">True</s:Boolean>
 	<s:Boolean x:Key="/Default/UserDictionary/Words/=Enricher/@EntryIndexedValue">True</s:Boolean>
+	<s:Boolean x:Key="/Default/UserDictionary/Words/=Evaluatable/@EntryIndexedValue">True</s:Boolean>
 	<s:Boolean x:Key="/Default/UserDictionary/Words/=Existentials/@EntryIndexedValue">True</s:Boolean>
 	<s:Boolean x:Key="/Default/UserDictionary/Words/=formattable/@EntryIndexedValue">True</s:Boolean>
 	<s:Boolean x:Key="/Default/UserDictionary/Words/=nblumhardt/@EntryIndexedValue">True</s:Boolean>

src/Serilog.Expressions/System.Diagnostics.CodeAnalysis/NotNullAttributes.cs renamed to src/Serilog.Expressions/Compatibility/NotNullAttributes.cs

@@ -2,15 +2,15 @@
 
 namespace Serilog.Expressions.Ast
 {
-    class AmbientPropertyExpression : Expression
+    class AmbientNameExpression : Expression
     {
         readonly bool _requiresEscape;
 
-        public AmbientPropertyExpression(string propertyName, bool isBuiltIn)
+        public AmbientNameExpression(string Name, bool isBuiltIn)
         {
-            PropertyName = propertyName ?? throw new ArgumentNullException(nameof(propertyName));
+            PropertyName = Name ?? throw new ArgumentNullException(nameof(Name));
             IsBuiltIn = isBuiltIn;
-            _requiresEscape = !SerilogExpression.IsValidIdentifier(propertyName);
+            _requiresEscape = !SerilogExpression.IsValidIdentifier(Name);
         }
 
         public string PropertyName { get; }
@@ -25,4 +25,4 @@ public override string ToString()
             return (IsBuiltIn ? "@" : "") + PropertyName;
         }
     }
-}
+}

src/Serilog.Expressions/Expressions/Ast/AmbientPropertyExpression.cs renamed to src/Serilog.Expressions/Expressions/Ast/AmbientNameExpression.cs

@@ -0,0 +1,21 @@
+using System;
+
+namespace Serilog.Expressions.Ast
+{
+    class LocalNameExpression : Expression
+    {
+        public LocalNameExpression(string name)
+        {
+            Name = name ?? throw new ArgumentNullException(nameof(name));
+        }
+
+        public string Name { get; }
+
+        public override string ToString()
+        {
+            // No unambiguous syntax for this right now, `$` will do to make these stand out when debugging,
+            // but the result won't round-trip parse.
+            return $"${Name}";
+        }
+    }
+}

src/Serilog.Expressions/Expressions/Ast/LocalNameExpression.cs

@@ -22,7 +22,7 @@ public static Expression Translate(Expression expression)
             return actual;
         }
 
-        public static CompiledExpression Compile(Expression expression, NameResolver nameResolver)
+        public static Evaluatable Compile(Expression expression, NameResolver nameResolver)
         {
             var actual = Translate(expression);
             return LinqExpressionCompiler.Compile(actual, nameResolver);

src/Serilog.Expressions/Expressions/Compilation/ExpressionCompiler.cs

@@ -5,6 +5,7 @@
 using System.Linq;
 using System.Text.RegularExpressions;
 using Serilog.Events;
+using Serilog.Expressions.Runtime;
 using Serilog.Formatting.Display;
 using Serilog.Parsing;
 
@@ -131,9 +132,17 @@ public static bool CoerceToScalarBoolean(LogEventPropertyValue value)
             return null;
         }
 
-        public static LogEventPropertyValue? GetPropertyValue(LogEvent context, string propertyName)
+        public static LogEventPropertyValue? GetPropertyValue(EvaluationContext ctx, string propertyName)
         {
-            if (!context.Properties.TryGetValue(propertyName, out var value))
+            if (!ctx.LogEvent.Properties.TryGetValue(propertyName, out var value))
+                return null;
+
+            return value;
+        }
+
+        public static LogEventPropertyValue? GetLocalValue(EvaluationContext ctx, string localName)
+        {
+            if (!Locals.TryGetValue(ctx.Locals, localName, out var value))
                 return null;
 
             return value;

src/Serilog.Expressions/Expressions/Compilation/Linq/Intrinsics.cs

@@ -68,22 +68,22 @@ class LinqExpressionCompiler : SerilogExpressionTransformer<ExpressionBody>
         static readonly MethodInfo TryGetStructurePropertyValueMethod = typeof(Intrinsics)
             .GetMethod(nameof(Intrinsics.TryGetStructurePropertyValue), BindingFlags.Static | BindingFlags.Public)!;
 
-        ParameterExpression Context { get; } = LX.Variable(typeof(LogEvent), "evt");
+        ParameterExpression Context { get; } = LX.Variable(typeof(EvaluationContext), "ctx");
 
         LinqExpressionCompiler(NameResolver nameResolver)
         {
             _nameResolver = nameResolver;
         }
 
-        public static CompiledExpression Compile(Expression expression, NameResolver nameResolver)
+        public static Evaluatable Compile(Expression expression, NameResolver nameResolver)
         {
             if (expression == null) throw new ArgumentNullException(nameof(expression));
             var compiler = new LinqExpressionCompiler(nameResolver);
             var body = compiler.Transform(expression); 
-            return LX.Lambda<CompiledExpression>(body, compiler.Context).Compile();
+            return LX.Lambda<Evaluatable>(body, compiler.Context).Compile();
         }
 
-        ExpressionBody Splice(Expression<CompiledExpression> lambda)
+        ExpressionBody Splice(Expression<Evaluatable> lambda)
         {
             return ParameterReplacementVisitor.ReplaceParameters(lambda, Context);
         }
@@ -134,32 +134,40 @@ protected override ExpressionBody Transform(ConstantExpression cx)
             return LX.Constant(cx.Constant);
         }
 
-        protected override ExpressionBody Transform(AmbientPropertyExpression px)
+        protected override ExpressionBody Transform(AmbientNameExpression px)
         {
             if (px.IsBuiltIn)
             {
                 return px.PropertyName switch
                 {
-                    BuiltInProperty.Level => Splice(context => new ScalarValue(context.Level)),
-                    BuiltInProperty.Message => Splice(context => new ScalarValue(Intrinsics.RenderMessage(context))),
+                    BuiltInProperty.Level => Splice(context => new ScalarValue(context.LogEvent.Level)),
+                    BuiltInProperty.Message => Splice(context => new ScalarValue(Intrinsics.RenderMessage(context.LogEvent))),
                     BuiltInProperty.Exception => Splice(context =>
-                        context.Exception == null ? null : new ScalarValue(context.Exception)),
-                    BuiltInProperty.Timestamp => Splice(context => new ScalarValue(context.Timestamp)),
-                    BuiltInProperty.MessageTemplate => Splice(context => new ScalarValue(context.MessageTemplate.Text)),
+                        context.LogEvent.Exception == null ? null : new ScalarValue(context.LogEvent.Exception)),
+                    BuiltInProperty.Timestamp => Splice(context => new ScalarValue(context.LogEvent.Timestamp)),
+                    BuiltInProperty.MessageTemplate => Splice(context => new ScalarValue(context.LogEvent.MessageTemplate.Text)),
                     BuiltInProperty.Properties => Splice(context =>
-                        new StructureValue(context.Properties.Select(kvp => new LogEventProperty(kvp.Key, kvp.Value)),
+                        new StructureValue(context.LogEvent.Properties.Select(kvp => new LogEventProperty(kvp.Key, kvp.Value)),
                             null)),
-                    BuiltInProperty.Renderings => Splice(context => Intrinsics.GetRenderings(context)),
+                    BuiltInProperty.Renderings => Splice(context => Intrinsics.GetRenderings(context.LogEvent)),
                     BuiltInProperty.EventId => Splice(context =>
-                        new ScalarValue(EventIdHash.Compute(context.MessageTemplate.Text))),
+                        new ScalarValue(EventIdHash.Compute(context.LogEvent.MessageTemplate.Text))),
                     _ => LX.Constant(null, typeof(LogEventPropertyValue))
                 };
             }
 
+            // Don't close over the AST node.
             var propertyName = px.PropertyName;
             return Splice(context => Intrinsics.GetPropertyValue(context, propertyName));
         }
 
+        protected override ExpressionBody Transform(LocalNameExpression nlx)
+        {
+            // Don't close over the AST node.
+            var name = nlx.Name;
+            return Splice(context => Intrinsics.GetLocalValue(context, name));
+        }
+
         protected override ExpressionBody Transform(Ast.LambdaExpression lmx)
         {
             var parameters = lmx.Parameters.Select(px => Tuple.Create(px, LX.Parameter(typeof(LogEventPropertyValue), px.ParameterName))).ToList();

src/Serilog.Expressions/Expressions/Compilation/Linq/LinqExpressionCompiler.cs

@@ -8,7 +8,7 @@ static class Pattern
     {
         public static bool IsAmbientProperty(Expression expression, string name, bool isBuiltIn)
         {
-            return expression is AmbientPropertyExpression px &&
+            return expression is AmbientNameExpression px &&
                    px.PropertyName == name &&
                    px.IsBuiltIn == isBuiltIn;
         }