Merge pull request #12956 from heejaechang/servicehublogging

added initial etw logging to code

src/VisualStudio/Core/Def/Implementation/Remote/RemoteHostClientServiceFactory.RemoteHostClientService.cs

@@ -7,6 +7,7 @@
 using Microsoft.CodeAnalysis.Diagnostics;
 using Microsoft.CodeAnalysis.ErrorReporting;
 using Microsoft.CodeAnalysis.Execution;
+using Microsoft.CodeAnalysis.Internal.Log;
 using Roslyn.Utilities;
 
 namespace Microsoft.VisualStudio.LanguageServices.Remote
@@ -47,6 +48,9 @@ public void Enable()
                         return;
                     }
 
+                    // log that remote host is enabled
+                    Logger.Log(FunctionId.RemoteHostClientService_Enabled, KeyValueLogMessage.NoProperty);
+
                     var remoteHostClientFactory = _workspace.Services.GetService<IRemoteHostClientFactory>();
                     if (remoteHostClientFactory == null)
                     {
@@ -125,23 +129,29 @@ private async Task<RemoteHostClient> EnableAsync(CancellationToken cancellationT
 
             private async Task AddGlobalAssetsAsync(CancellationToken cancellationToken)
             {
-                var snapshotService = _workspace.Services.GetService<ISolutionChecksumService>();
-                var assetBuilder = new AssetBuilder(_workspace.CurrentSolution);
-
-                foreach (var reference in _analyzerService.GetHostAnalyzerReferences())
+                using (Logger.LogBlock(FunctionId.RemoteHostClientService_AddGlobalAssetsAsync, cancellationToken))
                 {
-                    var asset = await assetBuilder.BuildAsync(reference, cancellationToken).ConfigureAwait(false);
-                    snapshotService.AddGlobalAsset(reference, asset, cancellationToken);
+                    var snapshotService = _workspace.Services.GetService<ISolutionChecksumService>();
+                    var assetBuilder = new AssetBuilder(_workspace.CurrentSolution);
+
+                    foreach (var reference in _analyzerService.GetHostAnalyzerReferences())
+                    {
+                        var asset = await assetBuilder.BuildAsync(reference, cancellationToken).ConfigureAwait(false);
+                        snapshotService.AddGlobalAsset(reference, asset, cancellationToken);
+                    }
                 }
             }
 
             private void RemoveGlobalAssets()
             {
-                var snapshotService = _workspace.Services.GetService<ISolutionChecksumService>();
-
-                foreach (var reference in _analyzerService.GetHostAnalyzerReferences())
+                using (Logger.LogBlock(FunctionId.RemoteHostClientService_RemoveGlobalAssets, CancellationToken.None))
                 {
-                    snapshotService.RemoveGlobalAsset(reference, CancellationToken.None);
+                    var snapshotService = _workspace.Services.GetService<ISolutionChecksumService>();
+
+                    foreach (var reference in _analyzerService.GetHostAnalyzerReferences())
+                    {
+                        snapshotService.RemoveGlobalAsset(reference, CancellationToken.None);
+                    }
                 }
             }
 

src/VisualStudio/Next/Remote/ServiceHubRemoteHostClient.cs

@@ -6,6 +6,7 @@
 using System.Threading.Tasks;
 using Microsoft.CodeAnalysis;
 using Microsoft.CodeAnalysis.Execution;
+using Microsoft.CodeAnalysis.Internal.Log;
 using Microsoft.CodeAnalysis.Remote;
 using Microsoft.ServiceHub.Client;
 using Roslyn.Utilities;
@@ -21,22 +22,25 @@ internal partial class ServiceHubRemoteHostClient : RemoteHostClient
 
         public static async Task<RemoteHostClient> CreateAsync(Workspace workspace, CancellationToken cancellationToken)
         {
-            var primary = new HubClient("ManagedLanguage.IDE.RemoteHostClient");
-            var remoteHostStream = await primary.RequestServiceAsync(WellKnownServiceHubServices.RemoteHostService, cancellationToken).ConfigureAwait(false);
+            using (Logger.LogBlock(FunctionId.ServiceHubRemoteHostClient_CreateAsync, cancellationToken))
+            {
+                var primary = new HubClient("ManagedLanguage.IDE.RemoteHostClient");
+                var remoteHostStream = await primary.RequestServiceAsync(WellKnownServiceHubServices.RemoteHostService, cancellationToken).ConfigureAwait(false);
 
-            var instance = new ServiceHubRemoteHostClient(workspace, primary, remoteHostStream);
+                var instance = new ServiceHubRemoteHostClient(workspace, primary, remoteHostStream);
 
-            // make sure connection is done right
-            var current = $"VS ({Process.GetCurrentProcess().Id})";
-            var host = await instance._rpc.InvokeAsync<string>(WellKnownServiceHubServices.RemoteHostService_Connect, current).ConfigureAwait(false);
+                // make sure connection is done right
+                var current = $"VS ({Process.GetCurrentProcess().Id})";
+                var host = await instance._rpc.InvokeAsync<string>(WellKnownServiceHubServices.RemoteHostService_Connect, current).ConfigureAwait(false);
 
-            // TODO: change this to non fatal watson and make VS to use inproc implementation
-            Contract.ThrowIfFalse(host == current.ToString());
+                // TODO: change this to non fatal watson and make VS to use inproc implementation
+                Contract.ThrowIfFalse(host == current.ToString());
 
-            instance.Connected();
+                instance.Connected();
 
-            // return instance
-            return instance;
+                // return instance
+                return instance;
+            }
         }
 
         private ServiceHubRemoteHostClient(Workspace workspace, HubClient hubClient, Stream stream) :

src/Workspaces/Core/Desktop/Workspaces.Desktop.csproj

@@ -109,6 +109,7 @@
     <InternalsVisibleTo Include="Microsoft.CodeAnalysis.InteractiveFeatures" />
     <InternalsVisibleTo Include="Microsoft.CodeAnalysis.InteractiveEditorFeatures" />
     <InternalsVisibleTo Include="Microsoft.CodeAnalysis.Remote.Workspaces" />
+    <InternalsVisibleTo Include="Microsoft.CodeAnalysis.Remote.ServiceHub" />
     <InternalsVisibleTo Include="Roslyn.VisualStudio.Setup" />
     <InternalsVisibleTo Include="Roslyn.VisualStudio.DiagnosticsWindow" />
     <InternalsVisibleToTest Include="Roslyn.Services.Editor.UnitTests" />

src/Workspaces/Core/Portable/Execution/Serialization/Checksum.cs

@@ -74,6 +74,11 @@ public override int GetHashCode()
             return _lazyHash;
         }
 
+        public override string ToString()
+        {
+            return Convert.ToBase64String(ToArray());
+        }
+
         private int CalculateHashCode()
         {
             // lazily calculate hash for checksum

src/Workspaces/Core/Portable/Execution/Serialization/ChecksumTreeNodeCollection.cs

@@ -4,6 +4,7 @@
 using System.Collections.Concurrent;
 using System.Threading;
 using System.Threading.Tasks;
+using Microsoft.CodeAnalysis.Internal.Log;
 using Roslyn.Utilities;
 
 namespace Microsoft.CodeAnalysis.Execution
@@ -258,33 +259,36 @@ public ChecksumObjectCache TryGetChecksumObjectEntry(object key, string kind, Ca
                 Func<TValue, string, CancellationToken, Task<TChecksumObject>> valueGetterAsync, CancellationToken cancellationToken)
                 where TKey : class where TChecksumObject : ChecksumObject
             {
-                Contract.ThrowIfNull(key);
-
-                // ask myself
-                ChecksumObject checksumObject;
-                var entry = TryGetChecksumObjectEntry(key, kind, cancellationToken);
-                if (entry != null && entry.TryGetValue(kind, out checksumObject))
+                using (Logger.LogBlock(FunctionId.ChecksumTreeNodeCache_GetOrCreateChecksumObjectAsync, CreateLogMessage, key, kind, cancellationToken))
                 {
-                    return (TChecksumObject)SaveAndReturn(key, checksumObject, entry);
-                }
+                    Contract.ThrowIfNull(key);
 
-                // ask owner
-                entry = _owner.TryGetChecksumObjectEntry(key, kind, cancellationToken);
-                if (entry == null)
-                {
-                    // owner doesn't have it, create one.
-                    checksumObject = await valueGetterAsync(value, kind, cancellationToken).ConfigureAwait(false);
-                }
-                else if (!entry.TryGetValue(kind, out checksumObject))
-                {
-                    // owner doesn't have this particular kind, create one.
-                    checksumObject = await valueGetterAsync(value, kind, cancellationToken).ConfigureAwait(false);
-                }
+                    // ask myself
+                    ChecksumObject checksumObject;
+                    var entry = TryGetChecksumObjectEntry(key, kind, cancellationToken);
+                    if (entry != null && entry.TryGetValue(kind, out checksumObject))
+                    {
+                        return (TChecksumObject)SaveAndReturn(key, checksumObject, entry);
+                    }
+
+                    // ask owner
+                    entry = _owner.TryGetChecksumObjectEntry(key, kind, cancellationToken);
+                    if (entry == null)
+                    {
+                        // owner doesn't have it, create one.
+                        checksumObject = await valueGetterAsync(value, kind, cancellationToken).ConfigureAwait(false);
+                    }
+                    else if (!entry.TryGetValue(kind, out checksumObject))
+                    {
+                        // owner doesn't have this particular kind, create one.
+                        checksumObject = await valueGetterAsync(value, kind, cancellationToken).ConfigureAwait(false);
+                    }
 
-                // record local copy (reference) and return it.
-                // REVIEW: we can go ref count route rather than this (local copy). but then we need to make sure there is no leak.
-                //         for now, we go local copy route since overhead is small (just duplicated reference pointer), but reduce complexity a lot.
-                return (TChecksumObject)SaveAndReturn(key, checksumObject, entry);
+                    // record local copy (reference) and return it.
+                    // REVIEW: we can go ref count route rather than this (local copy). but then we need to make sure there is no leak.
+                    //         for now, we go local copy route since overhead is small (just duplicated reference pointer), but reduce complexity a lot.
+                    return (TChecksumObject)SaveAndReturn(key, checksumObject, entry);
+                }
             }
 
             private ChecksumObject SaveAndReturn(object key, ChecksumObject checksumObject, ChecksumObjectCache entry = null)
@@ -300,9 +304,32 @@ private ChecksumTreeNodeCache GetOrCreateSubTreeNodeCache<TKey>(TKey key)
                 return entry.GetOrCreateSubTreeNodeCache(_owner, Solution);
             }
 
-            internal void TestOnly_ClearCache()
+            private static string CreateLogMessage<T>(T key, string kind)
             {
-                _cache.Clear();
+                return $"{kind} - {GetLogInfo(key) ?? "unknown"}";
+            }
+
+            private static string GetLogInfo<T>(T key)
+            {
+                var solution = key as Solution;
+                if (solution != null)
+                {
+                    return solution.FilePath;
+                }
+
+                var projectState = key as ProjectState;
+                if (projectState != null)
+                {
+                    return projectState.FilePath;
+                }
+
+                var documentState = key as DocumentState;
+                if (documentState != null)
+                {
+                    return documentState.FilePath;
+                }
+
+                return "no detail";
             }
         }
 

src/Workspaces/Core/Portable/Execution/Serialization/Serializer.cs

@@ -4,6 +4,7 @@
 using System.Linq;
 using System.Threading;
 using Microsoft.CodeAnalysis.Host;
+using Microsoft.CodeAnalysis.Internal.Log;
 using Roslyn.Utilities;
 
 namespace Microsoft.CodeAnalysis.Execution
@@ -36,46 +37,49 @@ public Serializer(HostWorkspaceServices workspaceServices)
 
         public T Deserialize<T>(string kind, ObjectReader reader, CancellationToken cancellationToken)
         {
-            cancellationToken.ThrowIfCancellationRequested();
-
-            switch (kind)
+            using (Logger.LogBlock(FunctionId.Serializer_Deserialize, kind, cancellationToken))
             {
-                case SolutionChecksumObject.Name:
-                    return (T)(object)DeserializeChecksumObjectWithChildren(reader, cancellationToken);
-                case ProjectChecksumObject.Name:
-                    return (T)(object)DeserializeChecksumObjectWithChildren(reader, cancellationToken);
-                case DocumentChecksumObject.Name:
-                    return (T)(object)DeserializeChecksumObjectWithChildren(reader, cancellationToken);
+                cancellationToken.ThrowIfCancellationRequested();
+
+                switch (kind)
+                {
+                    case SolutionChecksumObject.Name:
+                        return (T)(object)DeserializeChecksumObjectWithChildren(reader, cancellationToken);
+                    case ProjectChecksumObject.Name:
+                        return (T)(object)DeserializeChecksumObjectWithChildren(reader, cancellationToken);
+                    case DocumentChecksumObject.Name:
+                        return (T)(object)DeserializeChecksumObjectWithChildren(reader, cancellationToken);
 
-                case WellKnownChecksumObjects.Projects:
-                case WellKnownChecksumObjects.Documents:
-                case WellKnownChecksumObjects.TextDocuments:
-                case WellKnownChecksumObjects.ProjectReferences:
-                case WellKnownChecksumObjects.MetadataReferences:
-                case WellKnownChecksumObjects.AnalyzerReferences:
-                    return (T)(object)DeserializeChecksumObjectWithChildren(reader, cancellationToken);
+                    case WellKnownChecksumObjects.Projects:
+                    case WellKnownChecksumObjects.Documents:
+                    case WellKnownChecksumObjects.TextDocuments:
+                    case WellKnownChecksumObjects.ProjectReferences:
+                    case WellKnownChecksumObjects.MetadataReferences:
+                    case WellKnownChecksumObjects.AnalyzerReferences:
+                        return (T)(object)DeserializeChecksumObjectWithChildren(reader, cancellationToken);
 
-                case WellKnownChecksumObjects.SolutionChecksumObjectInfo:
-                    return (T)(object)DeserializeSolutionSnapshotInfo(reader, cancellationToken);
-                case WellKnownChecksumObjects.ProjectChecksumObjectInfo:
-                    return (T)(object)DeserializeProjectSnapshotInfo(reader, cancellationToken);
-                case WellKnownChecksumObjects.DocumentChecksumObjectInfo:
-                    return (T)(object)DeserializeDocumentSnapshotInfo(reader, cancellationToken);
-                case WellKnownChecksumObjects.CompilationOptions:
-                    return (T)(object)DeserializeCompilationOptions(reader, cancellationToken);
-                case WellKnownChecksumObjects.ParseOptions:
-                    return (T)(object)DeserializeParseOptions(reader, cancellationToken);
-                case WellKnownChecksumObjects.ProjectReference:
-                    return (T)(object)DeserializeProjectReference(reader, cancellationToken);
-                case WellKnownChecksumObjects.MetadataReference:
-                    return (T)(object)DeserializeMetadataReference(reader, cancellationToken);
-                case WellKnownChecksumObjects.AnalyzerReference:
-                    return (T)(object)DeserializeAnalyzerReference(reader, cancellationToken);
-                case WellKnownChecksumObjects.SourceText:
-                    return (T)(object)DeserializeSourceText(reader, cancellationToken);
+                    case WellKnownChecksumObjects.SolutionChecksumObjectInfo:
+                        return (T)(object)DeserializeSolutionSnapshotInfo(reader, cancellationToken);
+                    case WellKnownChecksumObjects.ProjectChecksumObjectInfo:
+                        return (T)(object)DeserializeProjectSnapshotInfo(reader, cancellationToken);
+                    case WellKnownChecksumObjects.DocumentChecksumObjectInfo:
+                        return (T)(object)DeserializeDocumentSnapshotInfo(reader, cancellationToken);
+                    case WellKnownChecksumObjects.CompilationOptions:
+                        return (T)(object)DeserializeCompilationOptions(reader, cancellationToken);
+                    case WellKnownChecksumObjects.ParseOptions:
+                        return (T)(object)DeserializeParseOptions(reader, cancellationToken);
+                    case WellKnownChecksumObjects.ProjectReference:
+                        return (T)(object)DeserializeProjectReference(reader, cancellationToken);
+                    case WellKnownChecksumObjects.MetadataReference:
+                        return (T)(object)DeserializeMetadataReference(reader, cancellationToken);
+                    case WellKnownChecksumObjects.AnalyzerReference:
+                        return (T)(object)DeserializeAnalyzerReference(reader, cancellationToken);
+                    case WellKnownChecksumObjects.SourceText:
+                        return (T)(object)DeserializeSourceText(reader, cancellationToken);
 
-                default:
-                    throw ExceptionUtilities.UnexpectedValue(kind);
+                    default:
+                        throw ExceptionUtilities.UnexpectedValue(kind);
+                }
             }
         }
 

src/Workspaces/Core/Portable/Execution/Serialization/SnapshotBuilder.cs

@@ -2,7 +2,6 @@
 
 using System;
 using System.Collections.Generic;
-using System.Collections.Immutable;
 using System.Threading;
 using System.Threading.Tasks;
 using Microsoft.CodeAnalysis.Diagnostics;

src/Workspaces/Core/Portable/Execution/Serialization/SolutionChecksumService.cs

 // Copyright (c) Microsoft.  All Rights Reserved.  Licensed under the Apache License, Version 2.0.  See License.txt in the project root for license information.
 
 using System.Composition;
-using System.Diagnostics;
 using System.Threading;
 using System.Threading.Tasks;
 using Microsoft.CodeAnalysis.Host;
 using Microsoft.CodeAnalysis.Host.Mef;
+using Microsoft.CodeAnalysis.Internal.Log;
 
 namespace Microsoft.CodeAnalysis.Execution
 {
@@ -49,18 +49,28 @@ public void RemoveGlobalAsset(object value, CancellationToken cancellationToken)
 
             public async Task<ChecksumScope> CreateChecksumAsync(Solution solution, CancellationToken cancellationToken)
             {
-                // TODO: add logging mechanism
-                var cache = _caches.CreateRootTreeNodeCache(solution);
+                using (Logger.LogBlock(FunctionId.SolutionChecksumServiceFactory_CreateChecksumAsync, cancellationToken))
+                {
+                    var cache = _caches.CreateRootTreeNodeCache(solution);
 
-                var builder = new SnapshotBuilder(cache);
-                var snapshot = new ChecksumScope(_caches, cache, await builder.BuildAsync(solution, cancellationToken).ConfigureAwait(false));
+                    var builder = new SnapshotBuilder(cache);
+                    var snapshot = new ChecksumScope(_caches, cache, await builder.BuildAsync(solution, cancellationToken).ConfigureAwait(false));
 
-                return snapshot;
+                    return snapshot;
+                }
             }
 
             public ChecksumObject GetChecksumObject(Checksum checksum, CancellationToken cancellationToken)
             {
-                return _caches.GetChecksumObject(checksum, cancellationToken);
+                using (Logger.LogBlock(FunctionId.SolutionChecksumServiceFactory_GetChecksumObject, GetChecksumLogInfo, checksum, cancellationToken))
+                {
+                    return _caches.GetChecksumObject(checksum, cancellationToken);
+                }
+            }
+
+            private static string GetChecksumLogInfo(Checksum checksum)
+            {
+                return checksum.ToString();
             }
         }
     }

src/Workspaces/Core/Portable/Log/FunctionId.cs

@@ -329,6 +329,21 @@ internal enum FunctionId
 
         // Generic performance measurement action IDs
         MeasurePerformance_StartAction,
-        MeasurePerformance_StopAction
+        MeasurePerformance_StopAction,
+
+        RemoteHostClientService_AddGlobalAssetsAsync,
+        RemoteHostClientService_RemoveGlobalAssets,
+        RemoteHostClientService_Enabled,
+        ServiceHubRemoteHostClient_CreateAsync,
+        SolutionChecksumServiceFactory_CreateChecksumAsync,
+        SolutionChecksumServiceFactory_GetChecksumObject,
+        ChecksumTreeNodeCache_GetOrCreateChecksumObjectAsync,
+        Serializer_Deserialize,
+        CodeAnalysisService_CalculateDiagnosticsAsync,
+        CodeAnalysisService_SerializeDiagnosticResultAsync,
+        AssetService_CleanAssets,
+        AssetService_GetAssetAsync,
+        SnapshotService_RequestAssetAsync,
+        CompilationService_GetCompilationAsync,
     }
 }

src/Workspaces/Core/Portable/Log/KeyValueLogMessage.cs

@@ -14,6 +14,8 @@ internal sealed class KeyValueLogMessage : LogMessage
     {
         private static readonly ObjectPool<KeyValueLogMessage> s_pool = new ObjectPool<KeyValueLogMessage>(() => new KeyValueLogMessage(), 20);
 
+        public static readonly KeyValueLogMessage NoProperty = new KeyValueLogMessage();
+
         public static KeyValueLogMessage Create(Action<Dictionary<string, object>> propertySetter)
         {
             var logMessage = s_pool.Allocate();
@@ -40,7 +42,7 @@ public bool ContainsProperty
             get
             {
                 EnsureMap();
-                return _map.Count > 0;
+                return _map?.Count > 0;
             }
         }
 

src/Workspaces/Remote/Core/Services/AssetService.cs

@@ -6,6 +6,7 @@
 using System.Threading;
 using System.Threading.Tasks;
 using Microsoft.CodeAnalysis.Execution;
+using Microsoft.CodeAnalysis.Internal.Log;
 using Roslyn.Utilities;
 
 namespace Microsoft.CodeAnalysis.Remote
@@ -20,6 +21,9 @@ internal class AssetService
         private const int CleanupInterval = 3; // 3 minutes
         private const int PurgeAfter = 30; // 30 minutes
 
+        private static readonly TimeSpan s_purgeAfterTimeSpan = TimeSpan.FromMinutes(PurgeAfter);
+        private static readonly TimeSpan s_cleanupIntervalTimeSpan = TimeSpan.FromMinutes(CleanupInterval);
+
         // PREVIEW: unfortunately, I need dummy workspace since workspace services can be workspace specific
         private static readonly Serializer s_serializer = new Serializer(new AdhocWorkspace(RoslynServices.HostServices, workspaceKind: "dummy").Services);
 
@@ -36,16 +40,23 @@ public AssetService()
 
         private async Task CleanAssetsAsync()
         {
-            var purgeAfterTimeSpan = TimeSpan.FromMinutes(PurgeAfter);
-            var cleanupIntervalTimeSpan = TimeSpan.FromMinutes(CleanupInterval);
-
             while (true)
             {
-                var current = DateTime.UtcNow;
+                CleanAssets();
+
+                await Task.Delay(s_cleanupIntervalTimeSpan).ConfigureAwait(false);
+            }
+        }
+
+        private void CleanAssets()
+        {
+            var current = DateTime.UtcNow;
 
+            using (Logger.LogBlock(FunctionId.AssetService_CleanAssets, CancellationToken.None))
+            {
                 foreach (var kvp in _assets.ToArray())
                 {
-                    if (current - kvp.Value.LastAccessed <= purgeAfterTimeSpan)
+                    if (current - kvp.Value.LastAccessed <= s_purgeAfterTimeSpan)
                     {
                         continue;
                     }
@@ -54,33 +65,45 @@ private async Task CleanAssetsAsync()
                     Entry entry;
                     _assets.TryRemove(kvp.Key, out entry);
                 }
-
-                await Task.Delay(cleanupIntervalTimeSpan).ConfigureAwait(false);
             }
         }
 
+        public T Deserialize<T>(string kind, ObjectReader reader, CancellationToken cancellationToken)
+        {
+            return s_serializer.Deserialize<T>(kind, reader, cancellationToken);
+        }
+
+        public void RegisterAssetSource(int serviceId, AssetSource assetSource)
+        {
+            Contract.ThrowIfFalse(_assetSources.TryAdd(serviceId, assetSource));
+        }
+
+        public void UnregisterAssetSource(int serviceId)
+        {
+            AssetSource dummy;
+            _assetSources.TryRemove(serviceId, out dummy);
+        }
+
         public async Task<T> GetAssetAsync<T>(Checksum checksum, CancellationToken cancellationToken)
         {
-            Entry entry;
-            if (!_assets.TryGetValue(checksum, out entry))
+            using (Logger.LogBlock(FunctionId.AssetService_GetAssetAsync, GetChecksumLogInfo, checksum, cancellationToken))
             {
-                // TODO: what happen if service doesn't come back. timeout?
-                var value = await RequestAssetAsync(checksum, cancellationToken).ConfigureAwait(false);
+                Entry entry;
+                if (!_assets.TryGetValue(checksum, out entry))
+                {
+                    // TODO: what happen if service doesn't come back. timeout?
+                    var value = await RequestAssetAsync(checksum, cancellationToken).ConfigureAwait(false);
 
-                Set(checksum, value);
+                    _assets.TryAdd(checksum, new Entry(value));
 
-                return (T)value;
-            }
+                    return (T)value;
+                }
 
-            // Update timestamp
-            Update(checksum, entry);
+                // Update timestamp
+                Update(checksum, entry);
 
-            return (T)entry.Object;
-        }
-
-        private void Set(Checksum checksum, object value)
-        {
-            _assets.TryAdd(checksum, new Entry(value));
+                return (T)entry.Object;
+            }
         }
 
         private void Update(Checksum checksum, Entry entry)
@@ -90,7 +113,7 @@ private void Update(Checksum checksum, Entry entry)
             entry.LastAccessed = DateTime.UtcNow;
         }
 
-        public async Task<object> RequestAssetAsync(Checksum checksum, CancellationToken cancellationToken)
+        private async Task<object> RequestAssetAsync(Checksum checksum, CancellationToken cancellationToken)
         {
             // the service doesn't care which asset source it uses to get the asset. if there are multiple
             // channel created (multiple caller to code analysis service), we will have multiple asset sources
@@ -130,20 +153,9 @@ private bool IsExpected(Exception ex)
             return ex is OperationCanceledException || ex is IOException || ex is ObjectDisposedException;
         }
 
-        public T Deserialize<T>(string kind, ObjectReader reader, CancellationToken cancellationToken)
-        {
-            return s_serializer.Deserialize<T>(kind, reader, cancellationToken);
-        }
-
-        public void RegisterAssetSource(int serviceId, AssetSource assetSource)
+        private static string GetChecksumLogInfo(Checksum checksum)
         {
-            Contract.ThrowIfFalse(_assetSources.TryAdd(serviceId, assetSource));
-        }
-
-        public void UnregisterAssetSource(int serviceId)
-        {
-            AssetSource dummy;
-            _assetSources.TryRemove(serviceId, out dummy);
+            return checksum.ToString();
         }
 
         private class Entry

src/Workspaces/Remote/Core/Services/CompilationService.cs

 // Copyright (c) Microsoft.  All Rights Reserved.  Licensed under the Apache License, Version 2.0.  See License.txt in the project root for license information.
 
+using System;
 using System.Threading;
 using System.Threading.Tasks;
 using Microsoft.CodeAnalysis.Execution;
+using Microsoft.CodeAnalysis.Internal.Log;
 
 namespace Microsoft.CodeAnalysis.Remote
 {
@@ -15,10 +17,17 @@ internal class CompilationService
     {
         public async Task<Compilation> GetCompilationAsync(Checksum solutionChecksum, ProjectId projectId, CancellationToken cancellationToken)
         {
-            var solution = await RoslynServices.SolutionService.GetSolutionAsync(solutionChecksum, cancellationToken).ConfigureAwait(false);
+            using (Logger.LogBlock(FunctionId.CompilationService_GetCompilationAsync, GetLogInfo, solutionChecksum, projectId, cancellationToken))
+            {
+                var solution = await RoslynServices.SolutionService.GetSolutionAsync(solutionChecksum, cancellationToken).ConfigureAwait(false);
 
-            // TODO: need to figure out how to deal with exceptions in service hub
-            return await solution.GetProject(projectId).GetCompilationAsync(cancellationToken).ConfigureAwait(false);
+                return await solution.GetProject(projectId).GetCompilationAsync(cancellationToken).ConfigureAwait(false);
+            }
+        }
+
+        private static string GetLogInfo(Checksum checksum, ProjectId projectId)
+        {
+            return $"{checksum.ToString()} - {projectId.ToString()}";
         }
     }
 }

src/Workspaces/Remote/ServiceHub/Services/CodeAnalysisService_Diagnostics.cs

@@ -6,9 +6,11 @@
 using System.Threading.Tasks;
 using Microsoft.CodeAnalysis.Diagnostics;
 using Microsoft.CodeAnalysis.Execution;
+using Microsoft.CodeAnalysis.Internal.Log;
 using Microsoft.CodeAnalysis.Remote.Diagnostics;
 using Microsoft.CodeAnalysis.Workspaces.Diagnostics;
 using Roslyn.Utilities;
+using RoslynLogger = Microsoft.CodeAnalysis.Internal.Log.Logger;
 
 namespace Microsoft.CodeAnalysis.Remote
 {
@@ -22,28 +24,31 @@ internal partial class CodeAnalysisService
         /// </summary>
         public async Task CalculateDiagnosticsAsync(DiagnosticArguments arguments, byte[] solutionChecksum, string streamName)
         {
-            try
+            using (RoslynLogger.LogBlock(FunctionId.CodeAnalysisService_CalculateDiagnosticsAsync, arguments.ProjectIdDebugName, CancellationToken))
             {
-                // entry point for diagnostic service
-                var solution = await RoslynServices.SolutionService.GetSolutionAsync(new Checksum(solutionChecksum), CancellationToken).ConfigureAwait(false);
-                var projectId = arguments.GetProjectId();
-                var analyzers = await GetHostAnalyzerReferences(arguments.GetHostAnalyzerChecksums()).ConfigureAwait(false);
+                try
+                {
+                    // entry point for diagnostic service
+                    var solution = await RoslynServices.SolutionService.GetSolutionAsync(new Checksum(solutionChecksum), CancellationToken).ConfigureAwait(false);
+                    var projectId = arguments.GetProjectId();
+                    var analyzers = await GetHostAnalyzerReferences(arguments.GetHostAnalyzerChecksums()).ConfigureAwait(false);
 
-                var result = await (new DiagnosticComputer(solution.GetProject(projectId))).GetDiagnosticsAsync(
-                    analyzers, arguments.AnalyzerIds, arguments.ReportSuppressedDiagnostics, arguments.LogAnalyzerExecutionTime, CancellationToken).ConfigureAwait(false);
+                    var result = await (new DiagnosticComputer(solution.GetProject(projectId))).GetDiagnosticsAsync(
+                        analyzers, arguments.AnalyzerIds, arguments.ReportSuppressedDiagnostics, arguments.LogAnalyzerExecutionTime, CancellationToken).ConfigureAwait(false);
 
-                await SerializeDiagnosticResultAsync(streamName, result).ConfigureAwait(false);
-            }
-            catch (IOException)
-            {
-                // stream to send over result has closed before we
-                // had chance to check cancellation
-            }
-            catch (OperationCanceledException)
-            {
-                // rpc connection has closed.
-                // this can happen if client side cancelled the
-                // operation
+                    await SerializeDiagnosticResultAsync(streamName, result).ConfigureAwait(false);
+                }
+                catch (IOException)
+                {
+                    // stream to send over result has closed before we
+                    // had chance to check cancellation
+                }
+                catch (OperationCanceledException)
+                {
+                    // rpc connection has closed.
+                    // this can happen if client side cancelled the
+                    // operation
+                }
             }
         }
 
@@ -60,6 +65,7 @@ private async Task<List<AnalyzerReference>> GetHostAnalyzerReferences(IEnumerabl
 
         private async Task SerializeDiagnosticResultAsync(string streamName, DiagnosticAnalysisResultMap<string, DiagnosticAnalysisResultBuilder> result)
         {
+            using (RoslynLogger.LogBlock(FunctionId.CodeAnalysisService_SerializeDiagnosticResultAsync, GetResultLogInfo, result, CancellationToken))
             using (var stream = await DirectStream.GetAsync(streamName, CancellationToken).ConfigureAwait(false))
             {
                 using (var writer = new ObjectWriter(stream))
@@ -70,5 +76,11 @@ private async Task SerializeDiagnosticResultAsync(string streamName, DiagnosticA
                 await stream.FlushAsync(CancellationToken).ConfigureAwait(false);
             }
         }
+
+        private static string GetResultLogInfo(DiagnosticAnalysisResultMap<string, DiagnosticAnalysisResultBuilder> result)
+        {
+            // for now, simple logging
+            return $"Analyzer: {result.AnalysisResult.Count}, Telemetry: {result.TelemetryInfo.Count}, Exceptions: {result.Exceptions.Count}";
+        }
     }
 }

src/Workspaces/Remote/ServiceHub/Services/RemoteHostService.cs

 // Copyright (c) Microsoft.  All Rights Reserved.  Licensed under the Apache License, Version 2.0.  See License.txt in the project root for license information.
 
 using System;
+using System.Collections.Generic;
 using System.IO;
 using System.Threading;
+using Microsoft.CodeAnalysis.Internal.Log;
+using RoslynLogger = Microsoft.CodeAnalysis.Internal.Log.Logger;
 
 namespace Microsoft.CodeAnalysis.Remote
 {
@@ -14,8 +17,17 @@ namespace Microsoft.CodeAnalysis.Remote
     /// </summary>
     internal class RemoteHostService : ServiceHubServiceBase
     {
+        private const string LoggingFunctionIdTextFileName = "ServiceHubFunctionIds.txt";
+
         private string _host;
 
+        static RemoteHostService()
+        {
+            // this is the very first service which will be called from client (VS)
+            // we set up logger here
+            RoslynLogger.SetLogger(new EtwLogger(GetLoggingChecker()));
+        }
+
         public RemoteHostService(Stream stream, IServiceProvider serviceProvider) :
             base(stream, serviceProvider)
         {
@@ -33,5 +45,45 @@ public string Connect(string host)
 
             return _host;
         }
+
+        private static Func<FunctionId, bool> GetLoggingChecker()
+        {
+            try
+            {
+                var loggingConfigFile = Path.Combine(typeof(RemoteHostService).Assembly.Location, LoggingFunctionIdTextFileName);
+
+                if (File.Exists(loggingConfigFile))
+                {
+                    var set = new HashSet<FunctionId>();
+
+                    var functionIdType = typeof(FunctionId);
+                    var functionIdStrings = File.ReadAllLines(loggingConfigFile);
+
+                    foreach (var functionIdString in functionIdStrings)
+                    {
+                        try
+                        {
+                            set.Add((FunctionId)Enum.Parse(functionIdType, functionIdString.Trim(), ignoreCase: true));
+                        }
+                        catch
+                        {
+                            // unknown functionId, move on
+                            continue;
+                        }
+                    }
+
+                    return id => set.Contains(id);
+                }
+            }
+            catch
+            {
+                // we don't care any exception here. 
+                // this is for debugging and performance investigation purpose.
+            }
+
+            // if there was any kind of issue, 
+            // don't log anything
+            return _ => false;
+        }
     }
 }

src/Workspaces/Remote/ServiceHub/Services/SnapshotService.JsonRpcAssetSource.cs

@@ -5,8 +5,10 @@
 using System.Threading;
 using System.Threading.Tasks;
 using Microsoft.CodeAnalysis.Execution;
+using Microsoft.CodeAnalysis.Internal.Log;
 using Roslyn.Utilities;
 using StreamJsonRpc;
+using RoslynLogger = Microsoft.CodeAnalysis.Internal.Log.Logger;
 
 namespace Microsoft.CodeAnalysis.Remote
 {
@@ -42,6 +44,7 @@ public override async Task<object> RequestAssetAsync(int serviceId, Checksum che
                 //
                 // 2. Request to required this asset has cancelled. (callerCancellationToken)
                 using (var mergedCancellationToken = CancellationTokenSource.CreateLinkedTokenSource(_assetChannelCancellationToken, callerCancellationToken))
+                using (RoslynLogger.LogBlock(FunctionId.SnapshotService_RequestAssetAsync, GetRequestLogInfo, serviceId, checksum, mergedCancellationToken.Token))
                 {
                     return await _rpc.InvokeAsync(WellKnownServiceHubServices.AssetService_RequestAssetAsync,
                         new object[] { serviceId, checksum.ToArray() },
@@ -68,6 +71,11 @@ public override async Task<object> RequestAssetAsync(int serviceId, Checksum che
                     return Task.FromResult(@object);
                 }
             }
+
+            private static string GetRequestLogInfo(int serviceId, Checksum checksum)
+            {
+                return $"{serviceId} - {checksum.ToString()}";
+            }
         }
     }
 }
\ No newline at end of file