Low hanging fruit performance improvements from profiling session

src/Microsoft.Framework.DesignTimeHost/ApplicationContext.cs

@@ -3,7 +3,6 @@
 
 using System;
 using System.Collections.Generic;
-using System.Diagnostics;
 using System.IO;
 using System.Linq;
 using System.Runtime.Versioning;
@@ -94,7 +93,7 @@ public void ProcessLoop(object state)
             }
             catch (Exception ex)
             {
-                Trace.TraceError("[ApplicationContext]: Error occured: {0}", ex);
+                Logger.TraceError("[ApplicationContext]: Error occured: {0}", ex);
 
                 // Unhandled errors
                 var error = new ErrorMessage
@@ -186,7 +185,7 @@ private bool ProcessMessage()
                 }
             }
 
-            Trace.TraceInformation("[ApplicationContext]: Received {0}", message.MessageType);
+            Logger.TraceInformation("[ApplicationContext]: Received {0}", message.MessageType);
 
             switch (message.MessageType)
             {
@@ -197,13 +196,18 @@ private bool ProcessMessage()
                         {
                             _initializedContext = message.Sender;
 
-                            var data = message.Payload.ToObject<InitializeMessage>();
+                            var data = new InitializeMessage
+                            {
+                                Configuration = GetValue(message.Payload, "Configuration"),
+                                ProjectFolder = GetValue(message.Payload, "ProjectFolder")
+                            };
+
                             _appPath.Value = data.ProjectFolder;
                             _configuration.Value = data.Configuration ?? "Debug";
                         }
                         else
                         {
-                            Trace.TraceInformation("[ApplicationContext]: Received Initialize message more than once for {0}", _appPath.Value);
+                            Logger.TraceInformation("[ApplicationContext]: Received Initialize message more than once for {0}", _appPath.Value);
                         }
                     }
                     break;
@@ -214,7 +218,10 @@ private bool ProcessMessage()
                     break;
                 case "ChangeConfiguration":
                     {
-                        var data = message.Payload.ToObject<ChangeConfigurationMessage>();
+                        var data = new ChangeConfigurationMessage
+                        {
+                            Configuration = GetValue(message.Payload, "Configuration")
+                        };
                         _configuration.Value = data.Configuration;
                     }
                     break;
@@ -235,7 +242,14 @@ private bool ProcessMessage()
                     break;
                 case "GetCompiledAssembly":
                     {
-                        var libraryKey = message.Payload.ToObject<RemoteLibraryKey>();
+                        var libraryKey = new RemoteLibraryKey
+                        {
+                            Name = GetValue(message.Payload, "Name"),
+                            TargetFramework = GetValue(message.Payload, "TargetFramework"),
+                            Configuration = GetValue(message.Payload, "Configuration"),
+                            Aspect = GetValue(message.Payload, "Aspect")
+                        };
+
                         var targetFramework = new FrameworkName(libraryKey.TargetFramework);
 
                         // Only set this the first time for the project
@@ -479,7 +493,7 @@ private void Reconcile()
         {
             if (IsDifferent(_local.ProjectInformation, _remote.ProjectInformation))
             {
-                Trace.TraceInformation("[ApplicationContext]: OnTransmit(ProjectInformation)");
+                Logger.TraceInformation("[ApplicationContext]: OnTransmit(ProjectInformation)");
 
                 _initializedContext.Transmit(new Message
                 {
@@ -514,7 +528,7 @@ private void Reconcile()
 
                 if (IsDifferent(localProject.Dependencies, remoteProject.Dependencies))
                 {
-                    Trace.TraceInformation("[ApplicationContext]: OnTransmit(Dependencies)");
+                    Logger.TraceInformation("[ApplicationContext]: OnTransmit(Dependencies)");
 
                     _initializedContext.Transmit(new Message
                     {
@@ -528,7 +542,7 @@ private void Reconcile()
 
                 if (IsDifferent(localProject.CompilerOptions, remoteProject.CompilerOptions))
                 {
-                    Trace.TraceInformation("[ApplicationContext]: OnTransmit(CompilerOptions)");
+                    Logger.TraceInformation("[ApplicationContext]: OnTransmit(CompilerOptions)");
 
                     _initializedContext.Transmit(new Message
                     {
@@ -542,7 +556,7 @@ private void Reconcile()
 
                 if (IsDifferent(localProject.References, remoteProject.References))
                 {
-                    Trace.TraceInformation("[ApplicationContext]: OnTransmit(References)");
+                    Logger.TraceInformation("[ApplicationContext]: OnTransmit(References)");
 
                     _initializedContext.Transmit(new Message
                     {
@@ -556,7 +570,7 @@ private void Reconcile()
 
                 if (IsDifferent(localProject.Sources, remoteProject.Sources))
                 {
-                    Trace.TraceInformation("[ApplicationContext]: OnTransmit(Sources)");
+                    Logger.TraceInformation("[ApplicationContext]: OnTransmit(Sources)");
 
                     _initializedContext.Transmit(new Message
                     {
@@ -615,7 +629,7 @@ private void TriggerProjectOutputsChanged()
 
                     if (waitingForCompiledAssembly.AssemblySent)
                     {
-                        Trace.TraceInformation("[ApplicationContext]: OnTransmit(ProjectChanged)");
+                        Logger.TraceInformation("[ApplicationContext]: OnTransmit(ProjectChanged)");
 
                         waitingForCompiledAssembly.Connection.Transmit(writer =>
                         {
@@ -643,7 +657,7 @@ private void SendCompiledAssemblies(ProjectWorld localProject)
                 {
                     if (!waitingForCompiledAssembly.AssemblySent)
                     {
-                        Trace.TraceInformation("[ApplicationContext]: OnTransmit(Assembly)");
+                        Logger.TraceInformation("[ApplicationContext]: OnTransmit(Assembly)");
 
                         waitingForCompiledAssembly.Connection.Transmit(writer =>
                         {
@@ -989,6 +1003,11 @@ private static DependencyDescription CreateDependencyDescription(LibraryDescript
             };
         }
 
+        private static string GetValue(JToken token, string name)
+        {
+            return token?[name]?.Value<string>() ?? default(string);
+        }
+
         private class Trigger<TValue>
         {
             private TValue _value;

src/Microsoft.Framework.DesignTimeHost/ConnectionContext.cs

@@ -3,7 +3,6 @@
 
 using System;
 using System.Collections.Generic;
-using System.Diagnostics;
 using System.IO;
 using Microsoft.Framework.DesignTimeHost.Models;
 using Microsoft.Framework.Runtime;
@@ -57,7 +56,7 @@ public void OnReceive(Message message)
             ApplicationContext applicationContext;
             if (!_contexts.TryGetValue(message.ContextId, out applicationContext))
             {
-                Trace.TraceInformation("[ConnectionContext]: Creating new application context for {0}", message.ContextId);
+                Logger.TraceInformation("[ConnectionContext]: Creating new application context for {0}", message.ContextId);
 
                 applicationContext = new ApplicationContext(_services,
                                                             _cache,

src/Microsoft.Framework.DesignTimeHost/ProcessingQueue.cs

@@ -2,10 +2,10 @@
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
 using System;
-using System.Diagnostics;
 using System.IO;
 using System.Threading;
 using Microsoft.Framework.DesignTimeHost.Models;
+using Microsoft.Framework.Runtime;
 using Newtonsoft.Json;
 
 namespace Microsoft.Framework.DesignTimeHost
@@ -25,7 +25,7 @@ public ProcessingQueue(Stream stream)
 
         public void Start()
         {
-            Trace.TraceInformation("[ProcessingQueue]: Start()");
+            Logger.TraceInformation("[ProcessingQueue]: Start()");
             new Thread(ReceiveMessages).Start();
         }
 
@@ -45,7 +45,7 @@ public bool Send(Action<BinaryWriter> write)
             }
             catch (Exception ex)
             {
-                Trace.TraceInformation("[ProcessingQueue]: Error sending {0}", ex);
+                Logger.TraceInformation("[ProcessingQueue]: Error sending {0}", ex);
             }
 
             return false;
@@ -57,7 +57,7 @@ public bool Send(Message message)
             {
                 try
                 {
-                    Trace.TraceInformation("[ProcessingQueue]: Send({0})", message);
+                    Logger.TraceInformation("[ProcessingQueue]: Send({0})", message);
                     _writer.Write(JsonConvert.SerializeObject(message));
 
                     return true;
@@ -68,7 +68,7 @@ public bool Send(Message message)
                 }
                 catch (Exception ex)
                 {
-                    Trace.TraceInformation("[ProcessingQueue]: Error sending {0}", ex);
+                    Logger.TraceInformation("[ProcessingQueue]: Error sending {0}", ex);
                 }
             }
 
@@ -82,7 +82,7 @@ private void ReceiveMessages()
                 while (true)
                 {
                     var message = JsonConvert.DeserializeObject<Message>(_reader.ReadString());
-                    Trace.TraceInformation("[ProcessingQueue]: OnReceive({0})", message);
+                    Logger.TraceInformation("[ProcessingQueue]: OnReceive({0})", message);
                     OnReceive(message);
                 }
             }
@@ -92,7 +92,7 @@ private void ReceiveMessages()
             }
             catch (Exception ex)
             {
-                Trace.TraceInformation("[ProcessingQueue]: Error occurred: {0}", ex);
+                Logger.TraceInformation("[ProcessingQueue]: Error occurred: {0}", ex);
             }
         }
     }

src/Microsoft.Framework.Runtime.Common/Impl/Trace.cs → src/Microsoft.Framework.Runtime.Common/Impl/Logger.cs

@@ -1,14 +1,11 @@
 // Copyright (c) Microsoft Open Technologies, Inc. All rights reserved.
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
-#if ASPNETCORE50
 using System;
-using System.Reflection;
-using Microsoft.Framework.Runtime;
 
-namespace System.Diagnostics
+namespace Microsoft.Framework.Runtime
 {
-    internal static class Trace
+    internal static class Logger
     {
         public static void TraceError(string message, params object[] args)
         {
@@ -42,5 +39,4 @@ private static bool IsEnabled
             }
         }
     }
-}
-#endif
+}

src/Microsoft.Framework.Runtime.Roslyn/CompilationContext.cs

@@ -60,20 +60,20 @@ private static IList<ResourceDescription> GetResources(CompilationContext contex
             var resourceProvider = new CompositeResourceProvider(new IResourceProvider[] { resxProvider, embeddedResourceProvider });
 
             var sw = Stopwatch.StartNew();
-            Trace.TraceInformation("[{0}]: Generating resources for {1}", nameof(CompilationContext), context.Project.Name);
+            Logger.TraceInformation("[{0}]: Generating resources for {1}", nameof(CompilationContext), context.Project.Name);
 
             var resources = resourceProvider.GetResources(context.Project);
 
             sw.Stop();
-            Trace.TraceInformation("[{0}]: Generated resources for {1} in {2}ms", nameof(CompilationContext), context.Project.Name, sw.ElapsedMilliseconds);
+            Logger.TraceInformation("[{0}]: Generated resources for {1} in {2}ms", nameof(CompilationContext), context.Project.Name, sw.ElapsedMilliseconds);
 
             sw = Stopwatch.StartNew();
-            Trace.TraceInformation("[{0}]: Resolving required assembly neutral references for {1}", nameof(CompilationContext), context.Project.Name);
+            Logger.TraceInformation("[{0}]: Resolving required assembly neutral references for {1}", nameof(CompilationContext), context.Project.Name);
 
             var embeddedReferences = EmbeddedReferencesHelper.GetRequiredEmbeddedReferences(context);
             resources.AddEmbeddedReferences(embeddedReferences);
 
-            Trace.TraceInformation("[{0}]: Resolved {1} required assembly neutral references for {2} in {3}ms",
+            Logger.TraceInformation("[{0}]: Resolved {1} required assembly neutral references for {2} in {3}ms",
                 nameof(CompilationContext),
                 embeddedReferences.Count,
                 context.Project.Name,

src/Microsoft.Framework.Runtime.Roslyn/ResxResourceProvider.cs

@@ -3,7 +3,6 @@
 
 using System;
 using System.Collections.Generic;
-using System.Diagnostics;
 using System.IO;
 using System.Linq;
 using System.Resources;
@@ -25,7 +24,7 @@ public IList<ResourceDescription> GetResources(Project project)
 
         private static string GetResourceName(string projectName, string resxFilePath)
         {
-            Trace.TraceInformation("[{0}]: Found resource {1}", typeof(ResxResourceProvider).Name, resxFilePath);
+            Logger.TraceInformation("[{0}]: Found resource {1}", typeof(ResxResourceProvider).Name, resxFilePath);
 
             string fileNameWithoutExtension = Path.GetFileNameWithoutExtension(resxFilePath);
 
@@ -62,4 +61,4 @@ private static Stream GetResourceStream(string resxFilePath)
             }
         }
     }
-}
+}

src/Microsoft.Framework.Runtime.Roslyn/RoslynCompiler.cs

@@ -80,7 +80,7 @@ public CompilationContext CompileProject(
 
             var exportedReferences = incomingReferences.Select(ConvertMetadataReference);
 
-            Trace.TraceInformation("[{0}]: Compiling '{1}'", GetType().Name, name);
+            Logger.TraceInformation("[{0}]: Compiling '{1}'", GetType().Name, name);
             var sw = Stopwatch.StartNew();
 
             var compilationSettings = project.GetCompilerOptions(target.TargetFramework, target.Configuration)
@@ -119,7 +119,7 @@ public CompilationContext CompileProject(
                 compilationSettings.CompilationOptions);
 
             var aniSw = Stopwatch.StartNew();
-            Trace.TraceInformation("[{0}]: Scanning '{1}' for assembly neutral interfaces", GetType().Name, name);
+            Logger.TraceInformation("[{0}]: Scanning '{1}' for assembly neutral interfaces", GetType().Name, name);
 
             var assemblyNeutralWorker = new AssemblyNeutralWorker(compilation, embeddedReferences);
             assemblyNeutralWorker.FindTypeCompilations(compilation.Assembly.GlobalNamespace);
@@ -130,7 +130,7 @@ public CompilationContext CompileProject(
             assemblyNeutralWorker.Generate();
 
             aniSw.Stop();
-            Trace.TraceInformation("[{0}]: Found {1} assembly neutral interfaces for '{2}' in {3}ms", GetType().Name, assemblyNeutralWorker.TypeCompilations.Count(), name, aniSw.ElapsedMilliseconds);
+            Logger.TraceInformation("[{0}]: Found {1} assembly neutral interfaces for '{2}' in {3}ms", GetType().Name, assemblyNeutralWorker.TypeCompilations.Count(), name, aniSw.ElapsedMilliseconds);
 
             foreach (var t in assemblyNeutralWorker.TypeCompilations)
             {
@@ -166,11 +166,11 @@ public CompilationContext CompileProject(
                             compilationContext.Diagnostics.Add(diag);
                         }
 
-                        Trace.TraceError("[{0}]: Failed loading meta assembly '{1}'", GetType().Name, name);
+                        Logger.TraceError("[{0}]: Failed loading meta assembly '{1}'", GetType().Name, name);
                     }
                     else
                     {
-                        Trace.TraceError("[{0}]: Failed loading meta assembly '{1}':\n {2}", GetType().Name, name, ex);
+                        Logger.TraceError("[{0}]: Failed loading meta assembly '{1}':\n {2}", GetType().Name, name, ex);
                     }
                 }
             }
@@ -184,11 +184,11 @@ public CompilationContext CompileProject(
                 }
 
                 precompSw.Stop();
-                Trace.TraceInformation("[{0}]: Compile modules ran in in {1}ms", GetType().Name, precompSw.ElapsedMilliseconds);
+                Logger.TraceInformation("[{0}]: Compile modules ran in in {1}ms", GetType().Name, precompSw.ElapsedMilliseconds);
             }
 
             sw.Stop();
-            Trace.TraceInformation("[{0}]: Compiled '{1}' in {2}ms", GetType().Name, name, sw.ElapsedMilliseconds);
+            Logger.TraceInformation("[{0}]: Compiled '{1}' in {2}ms", GetType().Name, name, sw.ElapsedMilliseconds);
 
             return compilationContext;
         }