Fix logging and configuration watching in LSP (#750)

* Log LSP messages

* Log via LSP once we're connected

* Don't log time twice now that time is added on the frontend side

* Add `justfile` for CLI shortcuts

* Finish plumbing configuration change notifications

* Make log level a quarto setting

* Take info, warn, and error log levels

* Add `log()` wrappers

* Pass `logLevel` via init options

* Pass log level to client

* Ignore format commit in git blame

* Fix default setting

* Revert propagation of log level to client

* Rename `LogFunctionLogger` to `Logger`

* Add comment about default `console.log` handling

* Actually pass init option to logger

* Remove justfile

* Remove redundant config watching

Author: lionel-

.git-blame-ignore-revs

@@ -0,0 +1,8 @@
+# This file lists revisions of large-scale formatting/style changes so that
+# they can be excluded from git blame results.
+#
+# To set this file as the default ignore file for git blame, run:
+#   $ git config blame.ignoreRevsFile .git-blame-ignore-revs
+
+# Format vscode extention and LSP files consistently (#748)
+a1513effc913e6e59651256d79295da37134dbbf

apps/lsp/.eslintrc.js

@@ -1,4 +1,7 @@
 module.exports = {
   root: true,
   extends: ["custom-server"],
+  rules: {
+    '@typescript-eslint/no-unused-vars': ['error', { argsIgnorePattern: '^_' }],
+  },
 };

apps/lsp/src/config.ts

@@ -24,8 +24,11 @@ import {
   IncludeWorkspaceHeaderCompletions,
   LsConfiguration,
   defaultLsConfiguration,
-  PreferredMdPathExtensionStyle
+  PreferredMdPathExtensionStyle,
+  ILogger,
+  LogLevel
 } from './service';
+import { Logger } from './logging';
 
 export type ValidateEnabled = 'ignore' | 'warning' | 'error' | 'hint';
 
@@ -34,17 +37,14 @@ export interface Settings {
     readonly colorTheme: string;
   };
   readonly quarto: {
+    readonly logLevel: LogLevel;
     readonly path: string;
     readonly mathjax: {
       readonly scale: number;
       readonly extensions: MathjaxSupportedExtension[];
     }
   };
   readonly markdown: {
-    readonly server: {
-      readonly log: 'off' | 'debug' | 'trace';
-    };
-
     readonly preferredMdPathExtensionStyle: 'auto' | 'includeExtension' | 'removeExtension';
 
     readonly suggest: {
@@ -83,16 +83,14 @@ function defaultSettings(): Settings {
       colorTheme: 'Dark+'
     },
     quarto: {
+      logLevel: LogLevel.Warn,
       path: "",
       mathjax: {
         scale: 1,
         extensions: []
       }
     },
     markdown: {
-      server: {
-        log: 'off'
-      },
       preferredMdPathExtensionStyle: 'auto',
       suggest: {
         paths: {
@@ -131,13 +129,29 @@ export class ConfigurationManager extends Disposable {
   public readonly onDidChangeConfiguration = this._onDidChangeConfiguration.event;
 
   private _settings: Settings;
+  private _logger: ILogger;
 
-  constructor(private readonly connection_: Connection) {
+  constructor(
+    private readonly connection_: Connection,
+    logger: ILogger,
+  ) {
     super();
+    this._logger = logger;
     this._settings = defaultSettings();
   }
 
+  public init(logLevel: LogLevel) {
+    this._settings = {
+      ...this._settings,
+      quarto: {
+        ...this._settings.quarto,
+        logLevel,
+      }
+    };
+  }
+
   public async update() {
+    this._logger.logTrace('Sending \'configuration\' request');
     const settings = await this.connection_.workspace.getConfiguration();
 
     this._settings = {
@@ -146,6 +160,7 @@ export class ConfigurationManager extends Disposable {
         colorTheme: settings.workbench.colorTheme
       },
       quarto: {
+        logLevel: Logger.parseLogLevel(settings.quarto.server.logLevel),
         path: settings.quarto.path,
         mathjax: {
           scale: settings.quarto.mathjax.scale,
@@ -157,14 +172,22 @@ export class ConfigurationManager extends Disposable {
   }
 
   public async subscribe() {
-    await this.update();
+    // Ignore the settings in parameters, the modern usage is to fetch the
+    // settings when we get this notification. This causes the client to send
+    // any updates for settings under the `quarto` section.
+    this.connection_.onDidChangeConfiguration((_params) => {
+      this._logger.logNotification('didChangeConfiguration');
+      this.update();
+    });
+
+    // Get notified of configuration changes by client
     await this.connection_.client.register(
       DidChangeConfigurationNotification.type,
       undefined
     );
-    this.connection_.onDidChangeConfiguration(() => {
-      this.update();
-    });
+
+    // Retrieve initial values for settings of interest
+    await this.update();
   }
 
   public getSettings(): Settings {

apps/lsp/src/diagnostics.ts

@@ -35,7 +35,6 @@ import {
   ILogger,
   IMdLanguageService,
   IWorkspace,
-  LogLevel,
 } from "./service";
 import {
   ConfigurationManager,
@@ -130,7 +129,7 @@ export async function registerDiagnostics(
         FullDocumentDiagnosticReport | UnchangedDocumentDiagnosticReport
       > => {
 
-        logger.log(LogLevel.Debug, "connection.languages.diagnostics.on", {
+        logger.logDebug("connection.languages.diagnostics.on", {
           document: params.textDocument.uri,
         });
 

apps/lsp/src/index.ts

@@ -40,7 +40,7 @@ import { registerCustomMethods } from "./custom";
 import { isWindows, LspConnection } from "core-node";
 import { initQuartoContext, Document, markdownitParser, LspInitializationOptions } from "quarto-core";
 import { ConfigurationManager, lsConfiguration } from "./config";
-import { LogFunctionLogger } from "./logging";
+import { Logger } from "./logging";
 import { languageServiceWorkspace } from "./workspace";
 import { middlewareCapabilities, middlewareRegister } from "./middleware";
 import { createLanguageService, IMdLanguageService } from "./service";
@@ -52,12 +52,15 @@ import { registerDiagnostics } from "./diagnostics";
 // Also include all preview / proposed LSP features.
 const connection = createConnection(ProposedFeatures.all);
 
+// Initialize logger
+const logger = new Logger(console.log.bind(console));
+
 // Create text document manager
 const documents: TextDocuments<Document> = new TextDocuments(TextDocument);
 documents.listen(connection);
 
 // Configuration
-const configManager = new ConfigurationManager(connection);
+const configManager = new ConfigurationManager(connection, logger);
 const config = lsConfiguration(configManager);
 
 // Capabilities
@@ -66,16 +69,29 @@ let capabilities: ClientCapabilities | undefined;
 // Initialization options
 let initializationOptions: LspInitializationOptions | undefined;
 
-// Markdowdn language service
+// Markdown language service
 let mdLs: IMdLanguageService | undefined;
 
 connection.onInitialize((params: InitializeParams) => {
+  // Set log level from initialization options if provided so that we use the
+  // expected level as soon as possible
+  const initLogLevel = Logger.parseLogLevel(
+    params.initializationOptions?.logLevel ?? "warn"
+  );
+  logger.init(initLogLevel);
+  configManager.init(initLogLevel);
+
+  // We're connected, log messages via LSP
+  logger.setConnection(connection);
+  logger.logRequest('initialize');
 
   // alias options and capabilities
   initializationOptions = params.initializationOptions;
   capabilities = params.capabilities;
 
   connection.onCompletion(async (params, token): Promise<CompletionItem[]> => {
+    logger.logRequest('completion');
+
     const document = documents.get(params.textDocument.uri);
     if (!document) {
       return [];
@@ -85,6 +101,8 @@ connection.onInitialize((params: InitializeParams) => {
   })
 
   connection.onHover(async (params, token): Promise<Hover | null | undefined> => {
+    logger.logRequest('hover');
+
     const document = documents.get(params.textDocument.uri);
     if (!document) {
       return null;
@@ -94,6 +112,8 @@ connection.onInitialize((params: InitializeParams) => {
 
 
   connection.onDocumentLinks(async (params, token): Promise<DocumentLink[]> => {
+    logger.logRequest('documentLinks');
+
     const document = documents.get(params.textDocument.uri);
     if (!document) {
       return [];
@@ -102,10 +122,13 @@ connection.onInitialize((params: InitializeParams) => {
   });
 
   connection.onDocumentLinkResolve(async (link, token): Promise<DocumentLink | undefined> => {
+    logger.logRequest('documentLinksResolve');
     return mdLs?.resolveDocumentLink(link, token);
   });
 
   connection.onDocumentSymbol(async (params, token): Promise<DocumentSymbol[]> => {
+    logger.logRequest('documentSymbol');
+
     const document = documents.get(params.textDocument.uri);
     if (!document) {
       return [];
@@ -114,6 +137,8 @@ connection.onInitialize((params: InitializeParams) => {
   });
 
   connection.onFoldingRanges(async (params, token): Promise<FoldingRange[]> => {
+    logger.logRequest('foldingRanges');
+
     const document = documents.get(params.textDocument.uri);
     if (!document) {
       return [];
@@ -122,6 +147,8 @@ connection.onInitialize((params: InitializeParams) => {
   });
 
   connection.onSelectionRanges(async (params, token): Promise<SelectionRange[] | undefined> => {
+    logger.logRequest('selectionRanges');
+
     const document = documents.get(params.textDocument.uri);
     if (!document) {
       return [];
@@ -130,10 +157,13 @@ connection.onInitialize((params: InitializeParams) => {
   });
 
   connection.onWorkspaceSymbol(async (params, token): Promise<WorkspaceSymbol[]> => {
+    logger.logRequest('workspaceSymbol');
     return mdLs?.getWorkspaceSymbols(params.query, token) || [];
   });
 
   connection.onReferences(async (params, token): Promise<Location[]> => {
+    logger.logRequest('references');
+
     const document = documents.get(params.textDocument.uri);
     if (!document) {
       return [];
@@ -142,6 +172,8 @@ connection.onInitialize((params: InitializeParams) => {
   });
 
   connection.onDefinition(async (params, token): Promise<Definition | undefined> => {
+    logger.logRequest('definition');
+
     const document = documents.get(params.textDocument.uri);
     if (!document) {
       return undefined;
@@ -182,10 +214,12 @@ connection.onInitialize((params: InitializeParams) => {
 
 // further config dependent initialization
 connection.onInitialized(async () => {
+  logger.logNotification('initialized');
 
   // sync config if possible
   if (capabilities?.workspace?.configuration) {
     await configManager.subscribe();
+    logger.setConfigurationManager(configManager);
   }
 
   // initialize connection to quarto
@@ -207,12 +241,6 @@ connection.onInitialized(async () => {
   );
   const quarto = await initializeQuarto(quartoContext);
 
-  // initialize logger
-  const logger = new LogFunctionLogger(
-    console.log.bind(console),
-    configManager
-  );
-
   // initialize workspace
   const workspace = languageServiceWorkspace(
     workspaceFolders?.map(value => URI.parse(value.uri)) || [],
@@ -255,7 +283,6 @@ connection.onInitialized(async () => {
 
   // register custom methods
   registerCustomMethods(quarto, lspConnection, documents);
-
 });