Merge pull request #8040 from dotnet/fix-lsp-telemetry

Add faults to LSP logging

src/Razor/src/Microsoft.AspNetCore.Razor.Common/Telemetry/ITelemetryReporter.cs

@@ -1,13 +1,15 @@
 // Copyright (c) .NET Foundation. All rights reserved.
 // Licensed under the MIT license. See License.txt in the project root for license information.
 
+using System;
 using System.Collections.Immutable;
 using Microsoft.VisualStudio.Telemetry;
 
 namespace Microsoft.AspNetCore.Razor.Telemetry;
 
-internal interface ITelemetryReporter
+public interface ITelemetryReporter
 {
     void ReportEvent(string name, TelemetrySeverity severity);
     void ReportEvent<T>(string name, TelemetrySeverity severity, ImmutableDictionary<string, T> values);
+    void ReportFault(Exception exception, string? message, object[] @params);
 }

src/Razor/src/Microsoft.AspNetCore.Razor.Common/Telemetry/TelemetryReporter.cs

@@ -4,6 +4,7 @@
 using System;
 using System.Collections.Immutable;
 using System.Composition;
+using System.Diagnostics;
 using System.Linq;
 using Microsoft.Extensions.Logging;
 using Microsoft.VisualStudio.Telemetry;
@@ -46,8 +47,52 @@ internal class TelemetryReporter : ITelemetryReporter
         Report(telemetryEvent);
     }
 
-    private static string GetTelemetryName(string name) => "razor/" + name;
-    private static string GetPropertyName(string name) => "razor." + name;
+    public void ReportFault(Exception exception, string? message, object[] @params)
+    {
+        try
+        {
+            if (exception is OperationCanceledException { InnerException: { } oceInnerException })
+            {
+                ReportFault(oceInnerException, message, @params);
+                return;
+            }
+
+            if (exception is AggregateException aggregateException)
+            {
+                // We (potentially) have multiple exceptions; let's just report each of them
+                foreach (var innerException in aggregateException.Flatten().InnerExceptions)
+                {
+                    ReportFault(innerException, message, @params);
+                }
+
+                return;
+            }
+
+            var currentProcess = Process.GetCurrentProcess();
+
+            var faultEvent = new FaultEvent(
+                eventName: GetTelemetryName("fault"),
+                description: GetDescription(exception),
+                FaultSeverity.General,
+                exceptionObject: exception,
+                gatherEventDetails: faultUtility =>
+                {
+                    // Returning "0" signals that, if sampled, we should send data to Watson.
+                    // Any other value will cancel the Watson report. We never want to trigger a process dump manually,
+                    // we'll let TargetedNotifications determine if a dump should be collected.
+                    // See https://aka.ms/roslynnfwdocs for more details
+                    return 0;
+                });
+
+            Report(faultEvent);
+        }
+        catch (Exception)
+        {
+        }
+    }
+
+    private static string GetTelemetryName(string name) => "dotnet/razor/" + name;
+    private static string GetPropertyName(string name) => "dotnet.razor." + name;
 
     private void Report(TelemetryEvent telemetryEvent)
     {
@@ -73,4 +118,53 @@ internal class TelemetryReporter : ITelemetryReporter
             _logger?.LogError(e, "Failed logging telemetry event");
         }
     }
+
+    private static string GetDescription(Exception exception)
+    {
+        const string CodeAnalysisNamespace = nameof(Microsoft) + "." + nameof(CodeAnalysis);
+        const string AspNetCoreNamespace = nameof(Microsoft) + "." + nameof(AspNetCore);
+
+        // Be resilient to failing here.  If we can't get a suitable name, just fall back to the standard name we
+        // used to report.
+        try
+        {
+            // walk up the stack looking for the first call from a type that isn't in the ErrorReporting namespace.
+            var frames = new StackTrace(exception).GetFrames();
+
+            // On the .NET Framework, GetFrames() can return null even though it's not documented as such.
+            // At least one case here is if the exception's stack trace itself is null.
+            if (frames != null)
+            {
+                foreach (var frame in frames)
+                {
+                    var method = frame?.GetMethod();
+                    var methodName = method?.Name;
+                    if (methodName is null)
+                    {
+                        continue;
+                    }
+
+                    var declaringTypeName = method?.DeclaringType?.FullName;
+                    if (declaringTypeName == null)
+                    {
+                        continue;
+                    }
+
+                    if (!declaringTypeName.StartsWith(CodeAnalysisNamespace) &&
+                        !declaringTypeName.StartsWith(AspNetCoreNamespace))
+                    {
+                        continue;
+                    }
+
+                    return declaringTypeName + "." + methodName;
+                }
+            }
+        }
+        catch
+        {
+        }
+
+        // If we couldn't get a stack, do this
+        return exception.Message;
+    }
 }

src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/LoggerAdapter.cs

@@ -2,6 +2,9 @@
 // Licensed under the MIT license. See License.txt in the project root for license information.
 
 using System;
+using System.Collections.Immutable;
+using Microsoft.AspNetCore.Razor.PooledObjects;
+using Microsoft.AspNetCore.Razor.Telemetry;
 using Microsoft.Extensions.Logging;
 
 namespace Microsoft.AspNetCore.Razor.LanguageServer;
@@ -11,10 +14,12 @@ namespace Microsoft.AspNetCore.Razor.LanguageServer;
 public class LoggerAdapter : IRazorLogger
 {
     private readonly ILogger _logger;
+    private readonly ITelemetryReporter? _telemetryReporter;
 
-    public LoggerAdapter(ILogger logger)
+    public LoggerAdapter(ILogger logger, ITelemetryReporter? telemetryReporter)
     {
         _logger = logger;
+        _telemetryReporter = telemetryReporter;
     }
 
     public IDisposable BeginScope<TState>(TState state)
@@ -41,11 +46,26 @@ public class LoggerAdapter : IRazorLogger
     {
 #pragma warning disable CA2254 // Template should be a static expression
         _logger.LogError(message, @params);
+
+        if (_telemetryReporter is not null)
+        {
+            using var _ = DictionaryPool<string, object>.GetPooledObject(out var props);
+
+            var index = 0;
+            foreach (var param in @params)
+            {
+                props.Add("param" + index++, param);
+            }
+
+            props.Add("message", message);
+            _telemetryReporter.ReportEvent("lsperror", VisualStudio.Telemetry.TelemetrySeverity.High, props.ToImmutableDictionary());
+        }
     }
 
     public void LogException(Exception exception, string? message = null, params object[] @params)
     {
         _logger.LogError(exception, message, @params);
+        _telemetryReporter?.ReportFault(exception, message, @params);
     }
 
     public void LogInformation(string message, params object[] @params)
@@ -63,4 +83,4 @@ public class LoggerAdapter : IRazorLogger
         _logger.LogWarning(message, @params);
 #pragma warning restore CA2254 // Template should be a static expression
     }
-}
+}

src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/RazorRequestContextFactory.cs

@@ -8,6 +8,7 @@ using Microsoft.CommonLanguageServerProtocol.Framework;
 using Microsoft.AspNetCore.Razor.LanguageServer.EndpointContracts;
 using Microsoft.Extensions.Logging;
 using Microsoft.VisualStudio.LanguageServer.Protocol;
+using Microsoft.AspNetCore.Razor.Telemetry;
 
 namespace Microsoft.AspNetCore.Razor.LanguageServer;
 
@@ -51,7 +52,7 @@ internal class RazorRequestContextFactory : IRequestContextFactory<RazorRequestC
 
         var loggerFactory = _lspServices.GetRequiredService<ILoggerFactory>();
         var logger = loggerFactory.CreateLogger(queueItem.MethodName);
-        var lspLogger = new LoggerAdapter(logger);
+        var lspLogger = new LoggerAdapter(logger, _lspServices.GetRequiredService<ITelemetryReporter>());
 
         var requestContext = new RazorRequestContext(documentContext, lspLogger, _lspServices);
 

src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/RazorLanguageServerClient.cs

@@ -9,6 +9,7 @@ using System.Threading;
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Razor.LanguageServer;
 using Microsoft.AspNetCore.Razor.LanguageServer.Common;
+using Microsoft.AspNetCore.Razor.Telemetry;
 using Microsoft.CodeAnalysis.Host;
 using Microsoft.CodeAnalysis.Razor;
 using Microsoft.CodeAnalysis.Razor.ProjectSystem;
@@ -36,6 +37,7 @@ internal class RazorLanguageServerClient : ILanguageClient, ILanguageClientCusto
 
     private readonly ILanguageClientBroker _languageClientBroker;
     private readonly ILanguageServiceBroker2 _languageServiceBroker;
+    private readonly ITelemetryReporter _telemetryReporter;
     private readonly RazorLanguageServerCustomMessageTarget _customMessageTarget;
     private readonly ILanguageClientMiddleLayer _middleLayer;
     private readonly LSPRequestInvoker _requestInvoker;
@@ -67,6 +69,7 @@ internal class RazorLanguageServerClient : ILanguageClient, ILanguageClientCusto
         ProjectSnapshotManagerDispatcher projectSnapshotManagerDispatcher,
         ILanguageClientBroker languageClientBroker,
         ILanguageServiceBroker2 languageServiceBroker,
+        ITelemetryReporter telemetryReporter,
         [Import(AllowDefault = true)] VisualStudioHostServicesProvider? vsHostWorkspaceServicesProvider)
     {
         if (customTarget is null)
@@ -114,6 +117,11 @@ internal class RazorLanguageServerClient : ILanguageClient, ILanguageClientCusto
             throw new ArgumentNullException(nameof(languageServiceBroker));
         }
 
+        if (telemetryReporter is null)
+        {
+            throw new ArgumentNullException(nameof(telemetryReporter));
+        }
+
         _customMessageTarget = customTarget;
         _middleLayer = middleLayer;
         _requestInvoker = requestInvoker;
@@ -124,6 +132,7 @@ internal class RazorLanguageServerClient : ILanguageClient, ILanguageClientCusto
         _languageClientBroker = languageClientBroker;
         _languageServiceBroker = languageServiceBroker;
         _projectSnapshotManagerDispatcher = projectSnapshotManagerDispatcher;
+        _telemetryReporter = telemetryReporter;
     }
 
     public string Name => RazorLSPConstants.RazorLanguageServerName;
@@ -160,7 +169,7 @@ internal class RazorLanguageServerClient : ILanguageClient, ILanguageClientCusto
         _loggerProvider = (LogHubLoggerProvider)await _logHubLoggerProviderFactory.GetOrCreateAsync(LogFileIdentifier, token).ConfigureAwait(false);
 
         var logHubLogger = _loggerProvider.CreateLogger("Razor");
-        var razorLogger = new LoggerAdapter(logHubLogger);
+        var razorLogger = new LoggerAdapter(logHubLogger, _telemetryReporter);
         _server = RazorLanguageServerWrapper.Create(serverStream, serverStream, razorLogger, _projectSnapshotManagerDispatcher, ConfigureLanguageServer, _languageServerFeatureOptions);
         // This must not happen on an RPC endpoint due to UIThread concerns, so ActivateAsync was chosen.
         await EnsureContainedLanguageServersInitializedAsync();

src/Razor/test/Microsoft.AspNetCore.Razor.Test.Common/NoOpTelemetryReporter.cs

@@ -1,6 +1,7 @@
 // Copyright (c) .NET Foundation. All rights reserved.
 // Licensed under the MIT license. See License.txt in the project root for license information.
 
+using System;
 using System.Collections.Immutable;
 using Microsoft.AspNetCore.Razor.Telemetry;
 using Microsoft.VisualStudio.Telemetry;
@@ -22,4 +23,8 @@ public class NoOpTelemetryReporter : ITelemetryReporter
     public void ReportEvent<T>(string name, TelemetrySeverity severity, ImmutableDictionary<string, T> values)
     {
     }
+
+    public void ReportFault(Exception exception, string? message, object[] @params)
+    {
+    }
 }

src/Razor/test/Microsoft.AspNetCore.Razor.Test.Common/TestBase.cs

@@ -6,6 +6,7 @@ using System.Collections.Generic;
 using System.Threading;
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Razor.LanguageServer;
+using Microsoft.AspNetCore.Razor.Telemetry;
 using Microsoft.AspNetCore.Razor.Test.Common.Logging;
 using Microsoft.Extensions.Logging;
 using Microsoft.VisualStudio.Threading;
@@ -69,7 +70,7 @@ public abstract class TestBase : IAsyncLifetime
     /// <summary>
     ///  An <see cref="IRazorLogger"/> for the currently running test.
     /// </summary>
-    protected IRazorLogger Logger => _logger ??= new LoggerAdapter(LoggerFactory.CreateLogger(GetType()));
+    protected IRazorLogger Logger => _logger ??= new LoggerAdapter(LoggerFactory.CreateLogger(GetType()), new TelemetryReporter(LoggerFactory));
 
     protected TestBase(ITestOutputHelper testOutput)
     {