Make VS Code logging use LogLevel, and filter appropriately (#9745)

Fixes #9142

Client side that "consumes" this is
dotnet/vscode-csharp#6770

azure-pipelines-conditional-integration.yml

@@ -11,9 +11,7 @@ variables:
 - name: DOTNET_SKIP_FIRST_TIME_EXPERIENCE
   value: true
 - name: LogLevel
-  value: 'Verbose'
-- name: RAZOR_TRACE
-  value: 'Verbose'
+  value: 'All'
 - name: RAZOR_RUN_CONDITIONAL_IDE_TESTS
   value: 'true'
 

azure-pipelines-integration-dartlab.yml

@@ -30,9 +30,7 @@ variables:
 - name: __VSNeverShowWhatsNew
   value: 1
 - name: LogLevel
-  value: 'Verbose'
-- name: RAZOR_TRACE
-  value: 'Verbose'
+  value: 'All'
 
 stages:
 - template: \stages\visual-studio\agent.yml@DartLabTemplates

azure-pipelines.yml

@@ -13,9 +13,7 @@ variables:
 - name: Codeql.Enabled
   value: true
 - name: LogLevel
-  value: 'Verbose'
-- name: RAZOR_TRACE
-  value: 'Verbose'
+  value: 'All'
 - name: RunIntegrationTests
   value: false
 - ${{ if ne(variables['System.TeamProject'], 'public') }}:

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

@@ -95,22 +95,20 @@ internal RazorLSPOptions BuildOptions(JObject[] result)
         }
         else
         {
-            ExtractVSCodeOptions(result, out var trace, out var enableFormatting, out var autoClosingTags, out var commitElementsWithSpace);
-            return new RazorLSPOptions(trace, enableFormatting, autoClosingTags, commitElementsWithSpace, ClientSettings.Default);
+            ExtractVSCodeOptions(result, out var enableFormatting, out var autoClosingTags, out var commitElementsWithSpace);
+            return new RazorLSPOptions(enableFormatting, autoClosingTags, commitElementsWithSpace, ClientSettings.Default);
         }
     }
 
     private void ExtractVSCodeOptions(
         JObject[] result,
-        out Trace trace,
         out bool enableFormatting,
         out bool autoClosingTags,
         out bool commitElementsWithSpace)
     {
         var razor = result[0];
         var html = result[1];
 
-        trace = RazorLSPOptions.Default.Trace;
         enableFormatting = RazorLSPOptions.Default.EnableFormatting;
         autoClosingTags = RazorLSPOptions.Default.AutoClosingTags;
         // Deliberately not using the "default" here because we want a different default for VS Code, as
@@ -119,11 +117,6 @@ private void ExtractVSCodeOptions(
 
         if (razor != null)
         {
-            if (razor.TryGetValue("trace", out var parsedTrace))
-            {
-                trace = GetObjectOrDefault(parsedTrace, trace);
-            }
-
             if (razor.TryGetValue("format", out var parsedFormat))
             {
                 if (parsedFormat is JObject jObject &&

src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/Diagnostics/RazorTranslateDiagnosticsService.cs

@@ -88,12 +88,12 @@ internal async Task<Diagnostic[]> TranslateAsync(
             : FilterHTMLDiagnostics(diagnostics, codeDocument, sourceText, _logger);
         if (!filteredDiagnostics.Any())
         {
-            _logger.LogInformation("No diagnostics remaining after filtering.");
+            _logger.LogDebug("No diagnostics remaining after filtering.");
 
             return Array.Empty<Diagnostic>();
         }
 
-        _logger.LogInformation("{filteredDiagnosticsLength}/{unmappedDiagnosticsLength} diagnostics remain after filtering.", filteredDiagnostics.Length, diagnostics.Length);
+        _logger.LogDebug("{filteredDiagnosticsLength}/{unmappedDiagnosticsLength} diagnostics remain after filtering.", filteredDiagnostics.Length, diagnostics.Length);
 
         var mappedDiagnostics = MapDiagnostics(
             diagnosticKind,

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

@@ -14,15 +14,8 @@ internal class LspLogger : IRazorLogger
     private readonly string _categoryName;
     private IClientConnection? _clientConnection;
 
-    public LspLogger(string categoryName, Trace trace, IClientConnection? clientConnection)
+    public LspLogger(string categoryName, LogLevel logLevel, IClientConnection? clientConnection)
     {
-        var logLevel = trace switch
-        {
-            Trace.Off => LogLevel.None,
-            Trace.Messages => LogLevel.Information,
-            Trace.Verbose => LogLevel.Trace,
-            _ => throw new NotImplementedException(),
-        };
         _logLevel = logLevel;
         _categoryName = categoryName;
         _clientConnection = clientConnection;
@@ -40,12 +33,12 @@ public IDisposable BeginScope<TState>(TState state)
 
     public bool IsEnabled(LogLevel logLevel)
     {
-        return true;
+        return logLevel >= _logLevel;
     }
 
     public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter)
     {
-        if (logLevel is LogLevel.None)
+        if (!IsEnabled(logLevel))
         {
             return;
         }

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

@@ -2,12 +2,10 @@
 // Licensed under the MIT license. See License.txt in the project root for license information.
 
 using Microsoft.CodeAnalysis.Razor.Editor;
-using Microsoft.Extensions.Logging;
 
 namespace Microsoft.AspNetCore.Razor.LanguageServer;
 
 internal record RazorLSPOptions(
-    Trace Trace,
     bool EnableFormatting,
     bool AutoClosingTags,
     bool InsertSpaces,
@@ -19,9 +17,8 @@ internal record RazorLSPOptions(
     bool ColorBackground,
     bool CommitElementsWithSpace)
 {
-    public RazorLSPOptions(Trace trace, bool enableFormatting, bool autoClosingTags, bool commitElementsWithSpace, ClientSettings settings)
-        : this(trace,
-              enableFormatting,
+    public RazorLSPOptions(bool enableFormatting, bool autoClosingTags, bool commitElementsWithSpace, ClientSettings settings)
+        : this(enableFormatting,
               autoClosingTags,
               !settings.ClientSpaceSettings.IndentWithTabs,
               settings.ClientSpaceSettings.IndentSize,
@@ -34,10 +31,9 @@ public RazorLSPOptions(Trace trace, bool enableFormatting, bool autoClosingTags,
     {
     }
 
-    public readonly static RazorLSPOptions Default = new(Trace: default,
-                                                         EnableFormatting: true,
+    public readonly static RazorLSPOptions Default = new(EnableFormatting: true,
                                                          AutoClosingTags: true,
-                                                         AutoListParams:true,
+                                                         AutoListParams: true,
                                                          InsertSpaces: true,
                                                          TabSize: 4,
                                                          AutoShowCompletion: true,
@@ -46,24 +42,12 @@ public RazorLSPOptions(Trace trace, bool enableFormatting, bool autoClosingTags,
                                                          ColorBackground: false,
                                                          CommitElementsWithSpace: true);
 
-    public LogLevel MinLogLevel => GetLogLevelForTrace(Trace);
-
-    public static LogLevel GetLogLevelForTrace(Trace trace)
-        => trace switch
-        {
-            Trace.Off => LogLevel.None,
-            Trace.Messages => LogLevel.Information,
-            Trace.Verbose => LogLevel.Trace,
-            _ => LogLevel.None,
-        };
-
     /// <summary>
     /// Initializes the LSP options with the settings from the passed in client settings, and default values for anything
     /// not defined in client settings.
     /// </summary>
     internal static RazorLSPOptions From(ClientSettings clientSettings)
-        => new(Default.Trace,
-            Default.EnableFormatting,
+        => new(Default.EnableFormatting,
             clientSettings.AdvancedSettings.AutoClosingTags,
             clientSettings.AdvancedSettings.CommitElementsWithSpace,
             clientSettings);

src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/README.md

@@ -22,7 +22,8 @@ After doing either of the above running the `Microsoft.VisualStudio.RazorExtensi
 
 ### How do I view the logs?
 
-Logs are off by default. If you'd like to adjust that set the `RAZOR_TRACE` environment variable to `Verbose`, `Messages` or `Off` depending on your needs.
+Logs are written to the %temp%\vslogs folder, in `.svclog` files with "Razor" in the name. You can increase logging here by passing `/log` on the command line when launching VS, or by setting an environment variable called `LogLevel` to `All`.
+Logs are also written to the "Razor Logger Output" category of the Output Window in VS. You can increase logging here by changing the "Log Level" option in Tools, Options, Text Editor, Razor, Advanced.
 
 ### Opening a project results in my Razor file saying "waiting for IntelliSense to initialize", why does it never stop?
 

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

@@ -65,8 +65,6 @@ internal class RazorLanguageServerClient(
 
     private RazorLanguageServerWrapper? _server;
 
-    private const string RazorLSPLogLevel = "RAZOR_TRACE";
-
     public event AsyncEventHandler<EventArgs>? StartAsync;
     public event AsyncEventHandler<EventArgs>? StopAsync
     {
@@ -102,8 +100,6 @@ public event AsyncEventHandler<EventArgs>? StopAsync
 
         await EnsureCleanedUpServerAsync().ConfigureAwait(false);
 
-        var traceLevel = GetVerbosity();
-
         // Initialize Logging Infrastructure
         var traceSource = _traceProvider.GetTraceSource();
 
@@ -198,14 +194,6 @@ private void ConfigureLanguageServer(IServiceCollection serviceCollection)
         }
     }
 
-    private Trace GetVerbosity()
-    {
-        var logString = Environment.GetEnvironmentVariable(RazorLSPLogLevel);
-        var result = Enum.TryParse<Trace>(logString, out var parsedTrace) ? parsedTrace : Trace.Off;
-
-        return result;
-    }
-
     private async Task EnsureCleanedUpServerAsync()
     {
         if (_server is null)

src/Razor/src/rzls/LoggerProvider.cs

@@ -6,16 +6,16 @@
 
 namespace Microsoft.AspNetCore.Razor.LanguageServer;
 
-internal class LoggerProvider(Trace trace, LspLogger mainLspLogger) : IRazorLoggerProvider
+internal class LoggerProvider(LogLevel logLevel, LspLogger mainLspLogger) : IRazorLoggerProvider
 {
-    private readonly Trace _trace = trace;
+    private readonly LogLevel _logLevel = logLevel;
     private readonly LspLogger _mainLspLogger = mainLspLogger;
 
     public ILogger CreateLogger(string categoryName)
     {
         // The main LSP logger is the only one the server will have initialized with a client connection, so
         // we have to make sure we pass it along.
-        return new LspLogger(categoryName, _trace, _mainLspLogger.GetClientConnection());
+        return new LspLogger(categoryName, _logLevel, _mainLspLogger.GetClientConnection());
     }
 
     public void Dispose()

src/Razor/src/rzls/Program.cs

@@ -10,14 +10,15 @@
 using Microsoft.AspNetCore.Razor.LanguageServer.Exports;
 using Microsoft.AspNetCore.Razor.Telemetry;
 using Microsoft.CodeAnalysis.Razor.Logging;
+using Microsoft.Extensions.Logging;
 
 namespace Microsoft.AspNetCore.Razor.LanguageServer;
 
 public class Program
 {
     public static async Task Main(string[] args)
     {
-        var traceLevel = Trace.Messages;
+        var logLevel = LogLevel.Information;
         var telemetryLevel = string.Empty;
         var sessionId = string.Empty;
         var telemetryExtensionPath = string.Empty;
@@ -46,13 +47,13 @@ public static async Task Main(string[] args)
                 continue;
             }
 
-            if (args[i] == "--trace" && i + 1 < args.Length)
+            if (args[i] == "--logLevel" && i + 1 < args.Length)
             {
-                var traceArg = args[++i];
-                if (!Enum.TryParse(traceArg, out traceLevel))
+                var logLevelArg = args[++i];
+                if (!Enum.TryParse(logLevelArg, out logLevel))
                 {
-                    traceLevel = Trace.Messages;
-                    await Console.Error.WriteLineAsync($"Invalid Razor trace '{traceArg}'. Defaulting to {traceLevel}.").ConfigureAwait(true);
+                    logLevel = LogLevel.Information;
+                    await Console.Error.WriteLineAsync($"Invalid Razor log level '{logLevelArg}'. Defaulting to {logLevel}.").ConfigureAwait(true);
                 }
             }
 
@@ -77,8 +78,8 @@ public static async Task Main(string[] args)
         var devKitTelemetryReporter = await TryGetTelemetryReporterAsync(telemetryLevel, sessionId, telemetryExtensionPath).ConfigureAwait(true);
 
         // Client connection will be initialized by the language server when it creates the connection
-        var logger = new LspLogger("LSP", traceLevel, clientConnection: null);
-        var loggerFactory = new RazorLoggerFactory([new LoggerProvider(traceLevel, logger)]);
+        var logger = new LspLogger("LSP", logLevel, clientConnection: null);
+        var loggerFactory = new RazorLoggerFactory([new LoggerProvider(logLevel, logger)]);
 
         var server = RazorLanguageServerWrapper.Create(
             Console.OpenStandardInput(),

src/Razor/test/Microsoft.AspNetCore.Razor.LanguageServer.Test/CodeActions/CodeActionEndToEndTest.NetFx.cs

@@ -711,7 +711,6 @@ public async Task Handle_GenerateMethod_VaryIndentSize(bool insertSpaces, int ta
             """;
 
         var razorLSPOptions = new RazorLSPOptions(
-            Trace: default,
             EnableFormatting: true,
             AutoClosingTags: true,
             insertSpaces,

src/Razor/test/Microsoft.AspNetCore.Razor.LanguageServer.Test/DefaultRazorConfigurationServiceTest.cs

@@ -21,12 +21,11 @@ public async Task GetLatestOptionsAsync_ReturnsExpectedOptions()
     {
         // Arrange
         var expectedOptions = new RazorLSPOptions(
-            Trace.Messages, EnableFormatting: false, AutoClosingTags: false, InsertSpaces: true, TabSize: 4, AutoShowCompletion: true, AutoListParams: true, FormatOnType: true, AutoInsertAttributeQuotes: true, ColorBackground: false, CommitElementsWithSpace: false);
+            EnableFormatting: false, AutoClosingTags: false, InsertSpaces: true, TabSize: 4, AutoShowCompletion: true, AutoListParams: true, FormatOnType: true, AutoInsertAttributeQuotes: true, ColorBackground: false, CommitElementsWithSpace: false);
         var razorJsonString =
             """
 
             {
-              "trace": "Messages",
               "format": {
                 "enable": "false"
               }
@@ -93,10 +92,9 @@ public void BuildOptions_VSCodeOptionsOnly_ReturnsExpected()
     {
         // Arrange - purposely choosing options opposite of default
         var expectedOptions = new RazorLSPOptions(
-            Trace.Verbose, EnableFormatting: false, AutoClosingTags: false, InsertSpaces: true, TabSize: 4, AutoShowCompletion: true, AutoListParams: true, FormatOnType: true, AutoInsertAttributeQuotes: true, ColorBackground: false, CommitElementsWithSpace: false);
+            EnableFormatting: false, AutoClosingTags: false, InsertSpaces: true, TabSize: 4, AutoShowCompletion: true, AutoListParams: true, FormatOnType: true, AutoInsertAttributeQuotes: true, ColorBackground: false, CommitElementsWithSpace: false);
         var razorJsonString = """
             {
-              "trace": "Verbose",
               "format": {
                 "enable": "false"
               }
@@ -130,7 +128,7 @@ public void BuildOptions_VSOptionsOnly_ReturnsExpected()
     {
         // Arrange - purposely choosing options opposite of default
         var expectedOptions = new RazorLSPOptions(
-            Trace.Off, EnableFormatting: true, AutoClosingTags: false, InsertSpaces: false, TabSize: 8, AutoShowCompletion: true, AutoListParams: true, FormatOnType: false, AutoInsertAttributeQuotes: false, ColorBackground: false, CommitElementsWithSpace: false);
+            EnableFormatting: true, AutoClosingTags: false, InsertSpaces: false, TabSize: 8, AutoShowCompletion: true, AutoListParams: true, FormatOnType: false, AutoInsertAttributeQuotes: false, ColorBackground: false, CommitElementsWithSpace: false);
         var razorJsonString = """
             {
             }
@@ -176,7 +174,6 @@ public void BuildOptions_MalformedOptions()
         var expectedOptions = RazorLSPOptions.Default with { CommitElementsWithSpace = false};
         var razorJsonString = @"
 {
-  ""trace"": 0,
   ""format"": {
     ""enable"": ""fals""
   }

src/Razor/test/Microsoft.AspNetCore.Razor.LanguageServer.Test/RazorLSPOptionsMonitorTest.cs

@@ -28,7 +28,7 @@ public RazorLSPOptionsMonitorTest(ITestOutputHelper testOutput)
     public async Task UpdateAsync_Invokes_OnChangeRegistration()
     {
         // Arrange
-        var expectedOptions = new RazorLSPOptions(Trace.Messages, EnableFormatting: false, AutoClosingTags: true, InsertSpaces: true, TabSize: 4, AutoShowCompletion: true, AutoListParams: true, FormatOnType: true, AutoInsertAttributeQuotes: true, ColorBackground: false, CommitElementsWithSpace: true);
+        var expectedOptions = new RazorLSPOptions(EnableFormatting: false, AutoClosingTags: true, InsertSpaces: true, TabSize: 4, AutoShowCompletion: true, AutoListParams: true, FormatOnType: true, AutoInsertAttributeQuotes: true, ColorBackground: false, CommitElementsWithSpace: true);
         var configService = Mock.Of<IConfigurationSyncService>(
             f => f.GetLatestOptionsAsync(DisposalToken) == Task.FromResult(expectedOptions),
             MockBehavior.Strict);
@@ -50,7 +50,7 @@ public async Task UpdateAsync_Invokes_OnChangeRegistration()
     public async Task UpdateAsync_DoesNotInvoke_OnChangeRegistration_AfterDispose()
     {
         // Arrange
-        var expectedOptions = new RazorLSPOptions(Trace.Messages, EnableFormatting: false, AutoClosingTags: true, InsertSpaces: true, TabSize: 4, AutoShowCompletion: true, AutoListParams: true, FormatOnType: true, AutoInsertAttributeQuotes: true, ColorBackground: false, CommitElementsWithSpace: true);
+        var expectedOptions = new RazorLSPOptions(EnableFormatting: false, AutoClosingTags: true, InsertSpaces: true, TabSize: 4, AutoShowCompletion: true, AutoListParams: true, FormatOnType: true, AutoInsertAttributeQuotes: true, ColorBackground: false, CommitElementsWithSpace: true);
         var configService = Mock.Of<IConfigurationSyncService>(
             f => f.GetLatestOptionsAsync(DisposalToken) == Task.FromResult(expectedOptions),
             MockBehavior.Strict);
@@ -96,7 +96,7 @@ public async Task UpdateAsync_ConfigReturnsNull_DoesNotInvoke_OnChangeRegistrati
     public void InitializedOptionsAreCurrent()
     {
         // Arrange
-        var expectedOptions = new RazorLSPOptions(Trace.Messages, EnableFormatting: false, AutoClosingTags: true, InsertSpaces: true, TabSize: 4, AutoShowCompletion: true, AutoListParams: true, FormatOnType: true, AutoInsertAttributeQuotes: true, ColorBackground: false, CommitElementsWithSpace: true);
+        var expectedOptions = new RazorLSPOptions(EnableFormatting: false, AutoClosingTags: true, InsertSpaces: true, TabSize: 4, AutoShowCompletion: true, AutoListParams: true, FormatOnType: true, AutoInsertAttributeQuotes: true, ColorBackground: false, CommitElementsWithSpace: true);
         var configService = Mock.Of<IConfigurationSyncService>(
             f => f.GetLatestOptionsAsync(DisposalToken) == Task.FromResult(expectedOptions),
             MockBehavior.Strict);

src/Razor/test/Microsoft.AspNetCore.Razor.Test.Common.Tooling/LanguageServer/LanguageServerTestBase.cs

@@ -120,7 +120,7 @@ internal static VersionedDocumentContext CreateDocumentContext(Uri uri, IDocumen
     internal static IOptionsMonitor<RazorLSPOptions> GetOptionsMonitor(bool enableFormatting = true, bool autoShowCompletion = true, bool autoListParams = true, bool formatOnType = true, bool autoInsertAttributeQuotes = true, bool colorBackground = false, bool commitElementsWithSpace = true)
     {
         var monitor = new Mock<IOptionsMonitor<RazorLSPOptions>>(MockBehavior.Strict);
-        monitor.SetupGet(m => m.CurrentValue).Returns(new RazorLSPOptions(default, enableFormatting, true, InsertSpaces: true, TabSize: 4, autoShowCompletion, autoListParams, formatOnType, autoInsertAttributeQuotes, colorBackground, commitElementsWithSpace));
+        monitor.SetupGet(m => m.CurrentValue).Returns(new RazorLSPOptions(enableFormatting, true, InsertSpaces: true, TabSize: 4, autoShowCompletion, autoListParams, formatOnType, autoInsertAttributeQuotes, colorBackground, commitElementsWithSpace));
         return monitor.Object;
     }