Introduce a fhirpath debug tracer

src/Hl7.Fhir.Base/FhirPath/DiagnosticsDebugTracer.cs

@@ -0,0 +1,139 @@
+/*
+ * Copyright (c) 2015, Firely (info@fire.ly) and contributors
+ * See the file CONTRIBUTORS for details.
+ *
+ * This file is licensed under the BSD 3-Clause license
+ * available at https://github.com/FirelyTeam/firely-net-sdk/master/LICENSE
+ */
+using Hl7.Fhir.ElementModel;
+using Hl7.FhirPath.Expressions;
+using System;
+using System.Collections.Generic;
+using System.Diagnostics;
+using System.Linq;
+
+namespace Hl7.FhirPath
+{
+
+    public class DiagnosticsDebugTracer : IDebugTracer
+    {
+
+        public void TraceCall(
+            Expression expr,
+            IEnumerable<ITypedElement> focus,
+            IEnumerable<ITypedElement> thisValue,
+            ITypedElement index,
+            IEnumerable<ITypedElement> totalValue,
+            IEnumerable<ITypedElement> result,
+            IEnumerable<KeyValuePair<string, IEnumerable<ITypedElement>>> variables)
+        {
+            string exprName;
+            if (expr is IdentifierExpression ie)
+                return;
+
+            if (expr is ConstantExpression ce)
+            {
+                Trace.WriteLine($"{expr.Location.LineNumber},{expr.Location.LinePosition},constant");
+                exprName = "constant";
+            }
+            else if (expr is ChildExpression child)
+            {
+                Trace.WriteLine($"{expr.Location.LineNumber},{expr.Location.LinePosition},{child.ChildName}");
+                exprName = child.ChildName;
+            }
+            else if (expr is IndexerExpression indexer)
+            {
+                Trace.WriteLine($"{expr.Location.LineNumber},{expr.Location.LinePosition},[]");
+                exprName = "[]";
+            }
+            else if (expr is UnaryExpression ue)
+            {
+                Trace.WriteLine($"{expr.Location.LineNumber},{expr.Location.LinePosition},{ue.Op}");
+                exprName = ue.Op;
+            }
+            else if (expr is BinaryExpression be)
+            {
+                Trace.WriteLine($"{expr.Location.LineNumber},{expr.Location.LinePosition},{be.Op}");
+                exprName = be.Op;
+            }
+            else if (expr is FunctionCallExpression fe)
+            {
+                Trace.WriteLine($"{expr.Location.LineNumber},{expr.Location.LinePosition},{fe.FunctionName}");
+                exprName = fe.FunctionName;
+            }
+            else if (expr is NewNodeListInitExpression)
+            {
+                Trace.WriteLine($"{expr.Location.LineNumber},{expr.Location.LinePosition},{{}} (empty)");
+                exprName = "{}";
+            }
+            else if (expr is AxisExpression ae)
+            {
+                if (ae.AxisName == "that")
+                    return;
+                Trace.WriteLine($"Evaluated: {ae.AxisName} results: {result.Count()}");
+                exprName = "$" + ae.AxisName;
+            }
+            else if (expr is VariableRefExpression ve)
+            {
+                Trace.WriteLine($"{expr.Location.LineNumber},{expr.Location.LinePosition},%{ve.Name}");
+                exprName = "%" + ve.Name;
+            }
+            else
+            {
+                exprName = expr.GetType().Name;
+#if DEBUG
+                Debugger.Break();
+#endif
+                throw new Exception($"Unknown expression type: {expr.GetType().Name}");
+                // Trace.WriteLine($"Evaluated: {expr} results: {result.Count()}");
+            }
+
+            if (focus != null)
+            {
+                foreach (var item in focus)
+                {
+                    DebugTraceValue($"$focus", item);
+                }
+            }
+
+            if (thisValue != null)
+            {
+                foreach (var item in thisValue)
+                {
+                    DebugTraceValue("$this", item);
+                }
+            }
+
+            if (index != null)
+            {
+                DebugTraceValue("$index", index);
+            }
+
+            if (totalValue != null)
+            {
+                foreach (var item in totalValue)
+                {
+                    DebugTraceValue($"{exprName} »", item);
+                }
+            }
+
+            if (result != null)
+            {
+                foreach (var item in result)
+                {
+                    DebugTraceValue($"{exprName} »", item);
+                }
+            }
+        }
+
+        private static void DebugTraceValue(string exprName, ITypedElement item)
+        {
+            if (item == null)
+                return; // possible with a null focus to kick things off
+            if (item.Location == "@primitivevalue@" || item.Location == "@QuantityAsPrimitiveValue@")
+                Trace.WriteLine($"  {exprName}:\t{item.Value}\t({item.InstanceType})");
+            else
+                Trace.WriteLine($"  {exprName}:\t{item.Value}\t({item.InstanceType})\t{item.Location}");
+        }
+    }
+}

src/Hl7.Fhir.Base/FhirPath/Expressions/Closure.cs

@@ -63,6 +63,11 @@ public static Closure Root(ITypedElement root, EvaluationContext ctx = null)
 
         private Dictionary<string, IEnumerable<ITypedElement>> _namedValues = new Dictionary<string, IEnumerable<ITypedElement>>();
 
+        internal IEnumerable<KeyValuePair<string, IEnumerable<ITypedElement>>> Variables()
+        {
+            return _namedValues;
+        }
+
         public virtual void SetValue(string name, IEnumerable<ITypedElement> value)
         {
             _namedValues.Remove(name);

src/Hl7.Fhir.Base/FhirPath/Expressions/EvaluatorVisitor.cs

@@ -1,7 +1,7 @@
-/* 
+/*
  * Copyright (c) 2015, Firely (info@fire.ly) and contributors
  * See the file CONTRIBUTORS for details.
- * 
+ *
  * This file is licensed under the BSD 3-Clause license
  * available at https://github.com/FirelyTeam/firely-net-sdk/master/LICENSE
  */
@@ -16,24 +16,40 @@ namespace Hl7.FhirPath.Expressions
 {
     internal class EvaluatorVisitor : FP.ExpressionVisitor<Invokee>
     {
+        private Invokee WrapForDebugTracer(Invokee invokee, Expression expression)
+        {
+            if (_debugTrace != null)
+            {
+                return (Closure context, IEnumerable<Invokee> arguments) => {
+                    var result = invokee(context, arguments);
+                    var focus = context.GetThat();
+                    _debugTrace?.TraceCall(expression, focus, context.GetThis(), context.GetIndex()?.FirstOrDefault(), context.GetTotal(), result, context.Variables());
+                    return result;
+                };
+            }
+            return invokee;
+        }
+
         public SymbolTable Symbols { get; }
+        private IDebugTracer _debugTrace;
 
-        public EvaluatorVisitor(SymbolTable symbols)
+        public EvaluatorVisitor(SymbolTable symbols, IDebugTracer debugTrace = null)
         {
             Symbols = symbols;
+            _debugTrace = debugTrace;
         }
 
 
         public override Invokee VisitConstant(FP.ConstantExpression expression)
         {
-            return InvokeeFactory.Return(ElementNode.ForPrimitive(expression.Value));
+            return WrapForDebugTracer(InvokeeFactory.Return(ElementNode.ForPrimitive(expression.Value)), expression);
         }
 
         public override Invokee VisitFunctionCall(FP.FunctionCallExpression expression)
         {
-            var focus = expression.Focus.ToEvaluator(Symbols);
+            var focus = expression.Focus.ToEvaluator(Symbols, _debugTrace);
             var arguments = new List<Invokee>() { focus };
-            arguments.AddRange(expression.Arguments.Select(arg => arg.ToEvaluator(Symbols)));
+            arguments.AddRange(expression.Arguments.Select(arg => arg.ToEvaluator(Symbols, _debugTrace)));
 
             // We have no real type information, so just pass object as the type
             var types = new List<Type>() { typeof(object) }; //   for the focus;
@@ -42,52 +58,52 @@ public override Invokee VisitFunctionCall(FP.FunctionCallExpression expression)
             // Now locate the function based on the types and name
             Invokee boundFunction = resolve(Symbols, expression.FunctionName, types);
 
-            return InvokeeFactory.Invoke(expression.FunctionName, arguments, boundFunction);
+            return WrapForDebugTracer(InvokeeFactory.Invoke(expression.FunctionName, arguments, boundFunction), expression);
         }
 
         public override Invokee VisitNewNodeListInit(FP.NewNodeListInitExpression expression)
         {
-            return InvokeeFactory.Return(ElementNode.EmptyList);
+            return WrapForDebugTracer(InvokeeFactory.Return(ElementNode.EmptyList), expression);
         }
 
         public override Invokee VisitVariableRef(FP.VariableRefExpression expression)
         {
             // HACK, for now, $this is special, and we handle in run-time, not compile time...
             if (expression.Name == "builtin.this")
-                return InvokeeFactory.GetThis;
+                return WrapForDebugTracer(InvokeeFactory.GetThis, expression);
 
             // HACK, for now, $this is special, and we handle in run-time, not compile time...
             if (expression.Name == "builtin.that")
                 return InvokeeFactory.GetThat;
 
             // HACK, for now, $total is special, and we handle in run-time, not compile time...
             if (expression.Name == "builtin.total")
-                return InvokeeFactory.GetTotal;
+                return WrapForDebugTracer(InvokeeFactory.GetTotal, expression);
 
             // HACK, for now, $index is special, and we handle in run-time, not compile time...
             if (expression.Name == "builtin.index")
-                return InvokeeFactory.GetIndex;
+                return WrapForDebugTracer(InvokeeFactory.GetIndex, expression);
 
             // HACK, for now, %context is special, and we handle in run-time, not compile time...
             if (expression.Name == "context")
-                return InvokeeFactory.GetContext;
+                return WrapForDebugTracer(InvokeeFactory.GetContext, expression);
 
             // HACK, for now, %resource is special, and we handle in run-time, not compile time...
             if (expression.Name == "resource")
-                return InvokeeFactory.GetResource;
+                return WrapForDebugTracer(InvokeeFactory.GetResource, expression);
 
             // HACK, for now, %rootResource is special, and we handle in run-time, not compile time...
             if (expression.Name == "rootResource")
-                return InvokeeFactory.GetRootResource;
+                return WrapForDebugTracer(InvokeeFactory.GetRootResource, expression);
+
+            return WrapForDebugTracer(chainResolves, expression);
 
-            return chainResolves;
-
             IEnumerable<ITypedElement> chainResolves(Closure context, IEnumerable<Invokee> invokees)
             {
                 return context.ResolveValue(expression.Name) ?? resolve(Symbols, expression.Name, Enumerable.Empty<Type>())(context, []);
             }
         }
-        
+
         private static Invokee resolve(SymbolTable scope, string name, IEnumerable<Type> argumentTypes)
         {
             // For now, we don't have the types or the parameters statically, so we just match on name
@@ -113,7 +129,7 @@ private static Invokee resolve(SymbolTable scope, string name, IEnumerable<Type>
             }
             else
             {
-                // No function could be found, but there IS a function with the given name, 
+                // No function could be found, but there IS a function with the given name,
                 // report an error about the fact that the function is known, but could not be bound
                 throw Error.Argument("Unknown symbol '{0}'".FormatWith(name));
             }
@@ -123,11 +139,10 @@ private static Invokee resolve(SymbolTable scope, string name, IEnumerable<Type>
 
     internal static class EvaluatorExpressionExtensions
     {
-        public static Invokee ToEvaluator(this FP.Expression expr, SymbolTable scope)
+        public static Invokee ToEvaluator(this FP.Expression expr, SymbolTable scope, IDebugTracer debugTrace = null)
         {
-            var compiler = new EvaluatorVisitor(scope);
+            var compiler = new EvaluatorVisitor(scope, debugTrace);
             return expr.Accept(compiler);
         }
     }
-
 }

src/Hl7.Fhir.Base/FhirPath/Expressions/ExpressionNode.cs

@@ -356,12 +356,12 @@ public string DebuggerDisplay
     public class ChildExpression : FunctionCallExpression, Sprache.IPositionAware<ChildExpression>
     {
         public ChildExpression(Expression focus, string name) : base(focus, OP_PREFIX + "children", TypeSpecifier.Any,
-                new ConstantExpression(name, TypeSpecifier.String))
+                new IdentifierExpression(name, TypeSpecifier.String))
         {
         }
 
         public ChildExpression(Expression focus, string name, ISourcePositionInfo location) : base(focus, OP_PREFIX + "children", TypeSpecifier.Any,
-                new ConstantExpression(name, TypeSpecifier.String), location)
+                new IdentifierExpression(name, TypeSpecifier.String), location)
         {
         }
 

src/Hl7.Fhir.Base/FhirPath/FhirPathCompiler.cs

@@ -1,7 +1,7 @@
-/* 
+/*
  * Copyright (c) 2015, Firely (info@fire.ly) and contributors
  * See the file CONTRIBUTORS for details.
- * 
+ *
  * This file is licensed under the BSD 3-Clause license
  * available at https://github.com/FirelyTeam/firely-net-sdk/master/LICENSE
  */
@@ -48,9 +48,15 @@ public Expression Parse(string expression)
             return parse.WasSuccessful ? parse.Value : throw new FormatException("Compilation failed: " + parse.ToString());
         }
 
-        public CompiledExpression Compile(Expression expression)
+        /// <summary>
+        /// Compiles a parsed FHIRPath expression into a delegate that can be used to evaluate the expression
+        /// </summary>
+        /// <param name="expression">the parsed fhirpath expression to compile</param>
+        /// <param name="debugTrace">An optional delegate to wire into the compilation that traces the processing steps</param>
+        /// <returns></returns>
+        public CompiledExpression Compile(Expression expression, IDebugTracer debugTrace = null)
         {
-            Invokee inv = expression.ToEvaluator(Symbols);
+            Invokee inv = expression.ToEvaluator(Symbols, debugTrace);
 
             return (ITypedElement focus, EvaluationContext ctx) =>
                 {
@@ -59,9 +65,15 @@ public CompiledExpression Compile(Expression expression)
                 };
         }
 
-        public CompiledExpression Compile(string expression)
+        /// <summary>
+        /// Compiles a FHIRPath expression string into a delegate that can be used to evaluate the expression
+        /// </summary>
+        /// <param name="expression">the fhirpath expression to parse then compile</param>
+        /// <param name="debugTrace">An optional delegate to wire into the compilation that traces the processing steps</param>
+        /// <returns></returns>
+        public CompiledExpression Compile(string expression, IDebugTracer debugTrace = null)
         {
-            return Compile(Parse(expression));
+            return Compile(Parse(expression), debugTrace);
         }
     }
 }

src/Hl7.Fhir.Base/FhirPath/IDebugTracer.cs

@@ -0,0 +1,27 @@
+/*
+ * Copyright (c) 2015, Firely (info@fire.ly) and contributors
+ * See the file CONTRIBUTORS for details.
+ *
+ * This file is licensed under the BSD 3-Clause license
+ * available at https://github.com/FirelyTeam/firely-net-sdk/master/LICENSE
+ */
+using Hl7.Fhir.ElementModel;
+using Hl7.FhirPath.Expressions;
+using System.Collections.Generic;
+
+namespace Hl7.FhirPath
+{
+    /// <summary>
+    /// An interface for tracing FHIRPath expression results during evaluation.
+    /// </summary>
+    public interface IDebugTracer
+    {
+        void TraceCall(Expression expr,
+            IEnumerable<ITypedElement> focus,
+            IEnumerable<ITypedElement> thisValue,
+            ITypedElement index,
+            IEnumerable<ITypedElement> totalValue,
+            IEnumerable<ITypedElement> result,
+            IEnumerable<KeyValuePair<string, IEnumerable<ITypedElement>>> variables);
+    }
+}