DYN-1754: As a developer I want detailed per node profiling during perf benchmarks

src/DynamoCore/DynamoCore.csproj

@@ -112,6 +112,14 @@ limitations under the License.
     <Compile Include="Configuration\DebugSettings.cs" />
     <Compile Include="Configuration\Context.cs" />
     <Compile Include="Core\DynamoMigrator.cs" />
+    <Compile Include="Engine\CodeGeneration\CompilationContext.cs" />
+    <Compile Include="Engine\CodeGeneration\CompiledEventArgs.cs" />
+    <Compile Include="Engine\CodeGeneration\CompilingEventArgs.cs" />
+    <Compile Include="Engine\CodeGeneration\IAstNodeContainer.cs" />
+    <Compile Include="Engine\Profiling\IProfilingExecutionTimeData.cs" />
+    <Compile Include="Engine\Profiling\NodeProfilingData.cs" />
+    <Compile Include="Engine\Profiling\ProfilingData.cs" />
+    <Compile Include="Engine\Profiling\ProfilingSession.cs" />
     <Compile Include="Engine\ShortestQualifiedNameReplacer.cs" />
     <Compile Include="Exceptions\LibraryLoadFailedException.cs" />
     <Compile Include="Graph\Nodes\NodeOutputData.cs" />
@@ -342,6 +350,10 @@ limitations under the License.
       <Project>{6e0a079e-85f1-45a1-ad5b-9855e4344809}</Project>
       <Name>Units</Name>
     </ProjectReference>
+    <ProjectReference Include="..\Libraries\VMDataBridge\VMDataBridge.csproj">
+      <Project>{ccb6e56b-2da1-4eba-a1f9-e8510e129d12}</Project>
+      <Name>VMDataBridge</Name>
+    </ProjectReference>
     <ProjectReference Include="..\NodeServices\DynamoServices.csproj">
       <Project>{ef879a10-041d-4c68-83e7-3192685f1bae}</Project>
       <Name>DynamoServices</Name>
@@ -360,6 +372,7 @@ limitations under the License.
   <ItemGroup>
     <Resource Include="BuiltInAndOperators\BuiltIn.Migrations.xml" />
   </ItemGroup>
+  <ItemGroup />
   <Import Project="$(MSBuildToolsPath)\Microsoft.CSharp.targets" />
   <Target Name="BeforeBuild">
     <ItemGroup>

src/DynamoCore/Engine/CodeGeneration/AstBuilder.cs

@@ -1,125 +1,36 @@
-#region
-
-using System;
+using System;
 using System.Collections.Generic;
 using System.Linq;
 using Dynamo.Graph.Nodes;
 using Dynamo.Library;
 using Dynamo.Logging;
+using Dynamo.Engine.Profiling;
 
 using ProtoCore;
 using ProtoCore.AST.AssociativeAST;
 using ProtoCore.Utils;
 using Type = ProtoCore.Type;
 
-#endregion
-
 namespace Dynamo.Engine.CodeGeneration
 {
-    /// <summary>
-    /// Returns notification for AST compilation events.                                                 
-    /// </summary>
-    public interface IAstNodeContainer
-    {
-        /// <summary>
-        /// Indicates to start compiling a NodeModel to AST nodes.
-        /// </summary>
-        /// <param name="nodeGuid"></param>
-        void OnCompiling(Guid nodeGuid);
-
-        /// <summary>
-        /// Indicates a NodeModel has been compiled to AST nodes. 
-        /// </summary>
-        /// <param name="nodeGuid"></param>
-        /// <param name="astNodes"></param>
-        void OnCompiled(Guid nodeGuid, IEnumerable<AssociativeNode> astNodes);
-    }
-
-    /// <summary>
-    /// This event is triggerred when compiling a NodeModel to AST nodes.
-    /// </summary>
-    public class CompilingEventArgs : EventArgs
-    {
-        /// Construct ASTBuildingEventArgs with NodeModel.
-        public CompilingEventArgs(Guid node)
-        {
-            Node = node;
-        }
-
-        /// <summary>
-        /// Guid of NodeModel that is being compiled to AST.
-        /// </summary>
-        public Guid Node { get; private set; }
-    }
-
-    /// <summary>
-    /// This event is triggered when a NodeModel has been compiled to a list of
-    /// AST nodes.
-    /// </summary>
-    public class CompiledEventArgs : EventArgs
-    {
-        /// <summary>
-        /// Construct ASTBuiltEventArgs with NodeModel and AST nodes.
-        /// </summary>
-        /// <param name="node"></param>
-        /// <param name="astNodes"></param>
-        internal CompiledEventArgs(Guid node, IEnumerable<AssociativeNode> astNodes)
-        {
-            Node = node;
-            AstNodes = astNodes;
-        }
-
-        /// <summary>
-        /// Guid of node that has been built to AST nodes.
-        /// </summary>
-        public Guid Node { get; private set; }
-
-        /// <summary>
-        /// Built AST nodes.
-        /// </summary>
-        public IEnumerable<AssociativeNode> AstNodes { get; private set; }
-    }
-
-    /// <summary>
-    /// The context of AST compilation
-    /// </summary>
-    public enum CompilationContext
-    {
-        /// <summary>
-        /// No specific context.
-        /// </summary>
-        None,
-
-        /// <summary>
-        /// Compiled AST nodes finally will be executed.
-        /// </summary>
-        DeltaExecution,
-
-        /// <summary>
-        /// Compiled AST nodes used in node to code.
-        /// </summary>
-        NodeToCode,
-
-        /// <summary>
-        /// Compiled AST nodes used in previwing graph.
-        /// </summary>
-        PreviewGraph,
-    }
-
     /// <summary>
     /// AstBuilder is a factory class to create different kinds of AST nodes.
     /// </summary>
     public class AstBuilder : LogSourceBase
     {
         private readonly IAstNodeContainer nodeContainer;
 
+        private ProfilingSession profilingSession = null;
+
         /// <summary>
         /// Construct a AstBuilder with AST node contiainer.
         /// </summary>
         /// <param name="nodeContainer"></param>
-        internal AstBuilder(IAstNodeContainer nodeContainer)
+        /// <param name="profilingSession"></param>
+        internal AstBuilder(IAstNodeContainer nodeContainer, ProfilingSession profilingSession)
         {
             this.nodeContainer = nodeContainer;
+            this.profilingSession = profilingSession;
         }
 
         // Reverse post-order to sort nodes
@@ -262,7 +173,11 @@ private static IEnumerable<NodeModel> GetUnvisitedNodes(Dictionary<NodeModel, Ma
             }
         }
 
-        private void CompileToAstNodes(NodeModel node, List<AssociativeNode> resultList, CompilationContext context, bool verboseLogging)
+        private void CompileToAstNodes(
+            NodeModel node, 
+            List<AssociativeNode> resultList, 
+            CompilationContext context, 
+            bool verboseLogging)
         {
 
             var inputAstNodes = new List<AssociativeNode>();
@@ -309,8 +224,19 @@ private void CompileToAstNodes(NodeModel node, List<AssociativeNode> resultList,
             if (node.State == ElementState.Error)
                 Log("Error in Node. Not sent for building and compiling");
 
-            if (context == CompilationContext.DeltaExecution || context == CompilationContext.PreviewGraph)
+            if (context == CompilationContext.DeltaExecution)
+            {
+                OnAstNodeBuilding(node.GUID);
+                if (profilingSession != null)
+                {
+                    profilingSession.RegisterNode(node);
+                    resultList.Add(profilingSession.CreatePreCompilationAstNode(node, inputAstNodes));
+                }
+            }
+            else if (context == CompilationContext.PreviewGraph)
+            {
                 OnAstNodeBuilding(node.GUID);
+            }
 
 #if DEBUG
             Validity.Assert(inputAstNodes.All(n => n != null), 
@@ -331,42 +257,62 @@ private void CompileToAstNodes(NodeModel node, List<AssociativeNode> resultList,
                 }
             }
 
-            if (verboseLogging)
+            if (null == astNodes)
+            {
+                resultList.AddRange(new AssociativeNode[0]);
+            }
+            else if (context == CompilationContext.DeltaExecution)
             {
-                foreach (var n in astNodes)
+                resultList.AddRange(astNodes);
+                if (profilingSession != null)
                 {
-                    Log(n.ToString());
+                    resultList.Add(profilingSession.CreatePostCompilationAstNode(node, inputAstNodes));
                 }
-            }
 
-            if(null == astNodes)
-                resultList.AddRange(new AssociativeNode[0]);
-            else if (context == CompilationContext.DeltaExecution || context == CompilationContext.PreviewGraph)
+                OnAstNodeBuilt(node.GUID, resultList);
+            }
+            else if (context == CompilationContext.PreviewGraph)
             {
-                OnAstNodeBuilt(node.GUID, astNodes);
                 resultList.AddRange(astNodes);
+
+                OnAstNodeBuilt(node.GUID, resultList);
             }
             else if (context == CompilationContext.NodeToCode)
             {
                 resultList.AddRange(astNodes);
             }
-            else //Inside custom node compilation.
+            else
             {
+                // Inside custom node compilation
                 bool notified = false;
                 foreach (var item in astNodes)
                 {
                     if (item is FunctionDefinitionNode)
                     {
                         if (!notified)
+                        {
                             OnAstNodeBuilding(node.GUID);
+                        }
+
                         notified = true;
-                        //Register the function node in global scope with Graph Sync data,
-                        //so that we don't have a function definition inside the function def
-                        //of custom node.
+
+                        // Register the function node in global scope with Graph Sync data,
+                        // so that we don't have a function definition inside the function def
+                        // of custom node.
                         OnAstNodeBuilt(node.GUID, new[] { item });
                     }
                     else
+                    {
                         resultList.Add(item);
+                    }
+                }
+
+                if (verboseLogging)
+                {
+                    foreach (var n in resultList)
+                    {
+                        Log(n.ToString());
+                    }
                 }
             }
         }
@@ -498,8 +444,7 @@ internal void CompileCustomNodeDefinition(
         /// <param name="nodeGuid"></param>
         private void OnAstNodeBuilding(Guid nodeGuid)
         {
-            if (nodeContainer != null)
-                nodeContainer.OnCompiling(nodeGuid);
+            nodeContainer?.OnCompiling(nodeGuid);
         }
 
         /// <summary>
@@ -509,8 +454,7 @@ private void OnAstNodeBuilding(Guid nodeGuid)
         /// <param name="astNodes"></param>
         private void OnAstNodeBuilt(Guid nodeGuid, IEnumerable<AssociativeNode> astNodes)
         {
-            if (nodeContainer != null)
-                nodeContainer.OnCompiled(nodeGuid, astNodes);
+            nodeContainer?.OnCompiled(nodeGuid, astNodes);
         }
 
         private enum MarkFlag

src/DynamoCore/Engine/CodeGeneration/CompilationContext.cs

@@ -0,0 +1,28 @@
+namespace Dynamo.Engine.CodeGeneration
+{
+    /// <summary>
+    /// The context of AST compilation
+    /// </summary>
+    public enum CompilationContext
+    {
+        /// <summary>
+        /// No specific context.
+        /// </summary>
+        None,
+
+        /// <summary>
+        /// Compiled AST nodes finally will be executed.
+        /// </summary>
+        DeltaExecution,
+
+        /// <summary>
+        /// Compiled AST nodes used in node to code.
+        /// </summary>
+        NodeToCode,
+
+        /// <summary>
+        /// Compiled AST nodes used in previwing graph.
+        /// </summary>
+        PreviewGraph,
+    }
+}

src/DynamoCore/Engine/CodeGeneration/CompiledEventArgs.cs

@@ -0,0 +1,34 @@
+using System;
+using System.Collections.Generic;
+using ProtoCore.AST.AssociativeAST;
+
+namespace Dynamo.Engine.CodeGeneration
+{
+    /// <summary>
+    /// This event is triggered when a NodeModel has been compiled to a list of
+    /// AST nodes.
+    /// </summary>
+    public class CompiledEventArgs : EventArgs
+    {
+        /// <summary>
+        /// Construct ASTBuiltEventArgs with NodeModel and AST nodes.
+        /// </summary>
+        /// <param name="node"></param>
+        /// <param name="astNodes"></param>
+        internal CompiledEventArgs(Guid node, IEnumerable<AssociativeNode> astNodes)
+        {
+            Node = node;
+            AstNodes = astNodes;
+        }
+
+        /// <summary>
+        /// Guid of node that has been built to AST nodes.
+        /// </summary>
+        public Guid Node { get; private set; }
+
+        /// <summary>
+        /// Built AST nodes.
+        /// </summary>
+        public IEnumerable<AssociativeNode> AstNodes { get; private set; }
+    }
+}

src/DynamoCore/Engine/CodeGeneration/CompilingEventArgs.cs

@@ -0,0 +1,21 @@
+using System;
+
+namespace Dynamo.Engine.CodeGeneration
+{
+    /// <summary>
+    /// This event is triggerred when compiling a NodeModel to AST nodes.
+    /// </summary>
+    public class CompilingEventArgs : EventArgs
+    {
+        /// Construct ASTBuildingEventArgs with NodeModel.
+        public CompilingEventArgs(Guid node)
+        {
+            Node = node;
+        }
+
+        /// <summary>
+        /// Guid of NodeModel that is being compiled to AST.
+        /// </summary>
+        public Guid Node { get; private set; }
+    }
+}