File: Logging\RoslynLogger.cs
Web Access
Project: src\src\LanguageServer\Microsoft.CodeAnalysis.LanguageServer\Microsoft.CodeAnalysis.LanguageServer.csproj (Microsoft.CodeAnalysis.LanguageServer)
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.
// See the LICENSE file in the project root for more information.
 
using System.Collections.Concurrent;
using System.Diagnostics;
using System.Diagnostics.CodeAnalysis;
using Microsoft.CodeAnalysis.Common;
using Microsoft.CodeAnalysis.Contracts.Telemetry;
using Microsoft.CodeAnalysis.ErrorReporting;
using Microsoft.CodeAnalysis.Internal.Log;
using Microsoft.CodeAnalysis.PooledObjects;
 
namespace Microsoft.CodeAnalysis.LanguageServer.Logging;
 
internal sealed class RoslynLogger : ILogger
{
    private static RoslynLogger? _instance;
    private static readonly ConcurrentDictionary<FunctionId, string> s_eventMap = [];
    private static readonly ConcurrentDictionary<(FunctionId id, string name), string> s_propertyMap = [];
 
    private readonly ConcurrentDictionary<int, object> _pendingScopes = new(concurrencyLevel: 2, capacity: 10);
    private static ITelemetryReporter? _telemetryReporter;
    private static readonly ObjectPool<List<KeyValuePair<string, object?>>> s_propertyPool = new(() => new());
 
    private RoslynLogger()
    {
    }
 
    public static void Initialize(ITelemetryReporter? reporter, string? telemetryLevel, string? sessionId)
    {
        Contract.ThrowIfTrue(_instance is not null);
 
        FatalError.ErrorReporterHandler handler = ReportFault;
        FatalError.SetHandlers(handler, nonFatalHandler: handler);
        FatalError.CopyHandlersTo(typeof(Compilation).Assembly);
 
        if (reporter is not null && telemetryLevel is not null)
        {
            reporter.InitializeSession(telemetryLevel, sessionId, isDefaultSession: true);
            _telemetryReporter = reporter;
        }
 
        _instance = new();
 
        var currentLogger = Logger.GetLogger();
        if (currentLogger is null)
        {
            Logger.SetLogger(_instance);
        }
        else
        {
            Logger.SetLogger(AggregateLogger.Create(currentLogger, _instance));
        }
    }
 
    private static void ReportFault(Exception exception, ErrorSeverity severity, bool forceDump)
    {
        try
        {
            if (exception is OperationCanceledException { InnerException: { } oceInnerException })
            {
                ReportFault(oceInnerException, severity, forceDump);
                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, severity, forceDump);
 
                return;
            }
 
            // Copy locally, as otherwise if we report a fault during shutdown we might also null reference (and then fatally crash the process)
            var telemetryReporter = _telemetryReporter;
            if (telemetryReporter is not null)
            {
                var eventName = GetEventName(FunctionId.NonFatalWatson);
                var description = GetDescription(exception);
                var currentProcess = Process.GetCurrentProcess();
                telemetryReporter.ReportFault(eventName, description, (int)severity, forceDump, currentProcess.Id, exception);
            }
        }
        catch (OutOfMemoryException)
        {
            FailFast.OnFatalException(exception);
        }
        catch (Exception e)
        {
            FailFast.OnFatalException(e);
        }
    }
 
    public bool IsEnabled(FunctionId functionId)
        => _telemetryReporter is not null;
 
    public void Log(FunctionId functionId, LogMessage logMessage)
    {
        if (IgnoreReporting(logMessage))
        {
            return;
        }
 
        using var pooledObject = s_propertyPool.GetPooledObject();
        var properties = pooledObject.Object;
 
        var name = GetEventName(functionId);
        AddProperties(properties, functionId, logMessage, delta: null);
 
        try
        {
            _telemetryReporter.Log(name, properties);
        }
        catch
        {
        }
    }
 
    public void LogBlockStart(FunctionId functionId, LogMessage logMessage, int blockId, CancellationToken cancellationToken)
    {
        if (IgnoreReporting(logMessage))
        {
            return;
        }
 
        var eventName = GetEventName(functionId);
        var kind = GetKind(logMessage);
 
        try
        {
            _telemetryReporter.LogBlockStart(eventName, (int)kind, blockId);
        }
        catch
        {
        }
    }
 
    public void LogBlockEnd(FunctionId functionId, LogMessage logMessage, int blockId, int delta, CancellationToken cancellationToken)
    {
        if (IgnoreReporting(logMessage))
        {
            return;
        }
 
        using var pooledObject = s_propertyPool.GetPooledObject();
        var properties = pooledObject.Object;
 
        AddProperties(properties, functionId, logMessage, delta);
        try
        {
            _telemetryReporter.LogBlockEnd(blockId, properties, cancellationToken);
        }
        catch
        {
        }
    }
 
    public static void ShutdownAndReportSessionTelemetry()
    {
        if (_instance is null)
        {
            return;
        }
 
        FeaturesSessionTelemetry.Report();
 
        (var currentReporter, _telemetryReporter) = (_telemetryReporter, null);
        currentReporter?.Dispose();
        _instance = null;
    }
 
    [MemberNotNullWhen(false, nameof(_telemetryReporter))]
    private static bool IgnoreReporting(LogMessage logMessage)
        => _telemetryReporter is null ||
           logMessage.LogLevel < LogLevel.Information;
 
    private static string GetDescription(Exception exception)
    {
        const string CodeAnalysisNamespace = nameof(Microsoft) + "." + nameof(CodeAnalysis);
 
        // 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 == null)
                        continue;
 
                    var declaringTypeName = method?.DeclaringType?.FullName;
                    if (declaringTypeName == null)
                        continue;
 
                    if (!declaringTypeName.StartsWith(CodeAnalysisNamespace))
                        continue;
 
                    return declaringTypeName + "." + methodName;
                }
            }
        }
        catch
        {
        }
 
        // If we couldn't get a stack, do this
        return exception.Message;
    }
 
    private const string EventPrefix = "vs/ide/vbcs/";
    private const string PropertyPrefix = "vs.ide.vbcs.";
 
    private static string GetEventName(FunctionId id)
        => s_eventMap.GetOrAdd(id, id => EventPrefix + GetTelemetryName(id, separator: '/'));
 
    private static string GetPropertyName(FunctionId id, string name)
        => s_propertyMap.GetOrAdd((id, name), key => PropertyPrefix + GetTelemetryName(id, separator: '.') + "." + key.name.ToLowerInvariant());
 
    private static string GetTelemetryName(FunctionId id, char separator)
            => Enum.GetName(typeof(FunctionId), id)!.Replace('_', separator).ToLowerInvariant();
 
    private static LogType GetKind(LogMessage logMessage)
            => logMessage is KeyValueLogMessage kvLogMessage
                                ? kvLogMessage.Kind
                                : logMessage.LogLevel switch
                                {
                                    >= LogLevel.Information => LogType.UserAction,
                                    _ => LogType.Trace
                                };
 
    private static void AddProperties(List<KeyValuePair<string, object?>> properties, FunctionId id, LogMessage logMessage, int? delta)
    {
        if (logMessage is KeyValueLogMessage kvLogMessage)
        {
            foreach (var (name, val) in kvLogMessage.Properties)
            {
                properties.Add(new(GetPropertyName(id, name), val));
            }
        }
        else
        {
            properties.Add(new(GetPropertyName(id, "Message"), logMessage.GetMessage()));
        }
 
        if (delta.HasValue)
        {
            properties.Add(new(GetPropertyName(id, "Delta"), delta.Value));
        }
    }
}