Merge pull request #422 from jneira/fix-ghc-version

- Add much more logging in the client side, configured with haskell.trace.client
- Fix error handling of working out project ghc (See #421)
  - And dont use a shell to spawn the subprocess in non windows systems
- Add commands Start Haskell LSP server and Stop Haskell LSP server

Author: jneira

Changelog.md

@@ -2,6 +2,14 @@
 
 - Add tracking of cabal files to work together with the incoming cabal formatter plugin
 
+### 1.5.1
+
+- Add much more logging in the client side, configured with `haskell.trace.client`
+- Fix error handling of `working out project ghc` (See #421)
+  - And dont use a shell to spawn the subprocess in non windows systems
+  - Show the progress as a cancellable notification
+- Add commands `Start Haskell LSP server` and `Stop Haskell LSP server`
+
 ### 1.5.0
 
 - Emit warning about limited support for ghc-9.x on hls executable download

package-lock.json

@@ -2,7 +2,7 @@
   "name": "haskell",
   "displayName": "Haskell",
   "description": "Haskell language support powered by the Haskell Language Server",
-  "version": "1.5.0",
+  "version": "1.5.1",
   "license": "MIT",
   "publisher": "haskell",
   "engines": {
@@ -103,6 +103,17 @@
           "default": "off",
           "description": "Traces the communication between VS Code and the language server."
         },
+        "haskell.trace.client": {
+          "scope": "resource",
+          "type": "string",
+          "enum": [
+            "off",
+            "error",
+            "debug"
+          ],
+          "default": "error",
+          "description": "Traces the communication between VS Code and the language server."
+        },
         "haskell.logFile": {
           "scope": "resource",
           "type": "string",
@@ -312,6 +323,16 @@
         "command": "haskell.commands.restartServer",
         "title": "Haskell: Restart Haskell LSP server",
         "description": "Restart the Haskell LSP server"
+      },
+      {
+        "command": "haskell.commands.startServer",
+        "title": "Haskell: Start Haskell LSP server",
+        "description": "Start the Haskell LSP server"
+      },
+      {
+        "command": "haskell.commands.stopServer",
+        "title": "Haskell: Stop Haskell LSP server",
+        "description": "Stop the Haskell LSP server"
       }
     ]
   },

package.json

@@ -1,4 +1,6 @@
 export namespace CommandNames {
   export const ImportIdentifierCommandName = 'haskell.commands.importIdentifier';
   export const RestartServerCommandName = 'haskell.commands.restartServer';
+  export const StartServerCommandName = 'haskell.commands.startServer';
+  export const StopServerCommandName = 'haskell.commands.stopServer';
 }

src/commands/constants.ts

@@ -15,6 +15,7 @@ import {
   ExecutableOptions,
   LanguageClient,
   LanguageClientOptions,
+  Logger,
   RevealOutputChannelOn,
   ServerOptions,
   TransportKind,
@@ -23,7 +24,7 @@ import { CommandNames } from './commands/constants';
 import { ImportIdentifier } from './commands/importIdentifier';
 import { DocsBrowser } from './docsBrowser';
 import { downloadHaskellLanguageServer } from './hlsBinaries';
-import { executableExists } from './utils';
+import { executableExists, ExtensionLogger } from './utils';
 
 // The current map of documents & folders to language servers.
 // It may be null to indicate that we are in the process of launching a server,
@@ -45,7 +46,10 @@ export async function activate(context: ExtensionContext) {
     for (const folder of event.removed) {
       const client = clients.get(folder.uri.toString());
       if (client) {
-        clients.delete(folder.uri.toString());
+        const uri = folder.uri.toString();
+        client.info(`Deleting folder for clients: ${uri}`);
+        clients.delete(uri);
+        client.info('Stopping the server');
         client.stop();
       }
     }
@@ -54,12 +58,35 @@ export async function activate(context: ExtensionContext) {
   // Register editor commands for HIE, but only register the commands once at activation.
   const restartCmd = commands.registerCommand(CommandNames.RestartServerCommandName, async () => {
     for (const langClient of clients.values()) {
+      langClient?.info('Stopping the server');
       await langClient?.stop();
+      langClient?.info('Starting the server');
       langClient?.start();
     }
   });
+
   context.subscriptions.push(restartCmd);
 
+  const stopCmd = commands.registerCommand(CommandNames.StopServerCommandName, async () => {
+    for (const langClient of clients.values()) {
+      langClient?.info('Stopping the server');
+      await langClient?.stop();
+      langClient?.info('Server stopped');
+    }
+  });
+
+  context.subscriptions.push(stopCmd);
+
+  const startCmd = commands.registerCommand(CommandNames.StartServerCommandName, async () => {
+    for (const langClient of clients.values()) {
+      langClient?.info('Starting the server');
+      langClient?.start();
+      langClient?.info('Server started');
+    }
+  });
+
+  context.subscriptions.push(startCmd);
+
   context.subscriptions.push(ImportIdentifier.registerCommand());
 
   // Set up the documentation browser.
@@ -70,30 +97,31 @@ export async function activate(context: ExtensionContext) {
   context.subscriptions.push(openOnHackageDisposable);
 }
 
-function findManualExecutable(uri: Uri, folder?: WorkspaceFolder): string | null {
+function findManualExecutable(logger: Logger, uri: Uri, folder?: WorkspaceFolder): string | null {
   let exePath = workspace.getConfiguration('haskell', uri).serverExecutablePath;
   if (exePath === '') {
     return null;
   }
-
+  logger.info(`Trying to find the server executable in: ${exePath}`);
   // Substitute path variables with their corresponding locations.
   exePath = exePath.replace('${HOME}', os.homedir).replace('${home}', os.homedir).replace(/^~/, os.homedir);
   if (folder) {
     exePath = exePath.replace('${workspaceFolder}', folder.uri.path).replace('${workspaceRoot}', folder.uri.path);
   }
-
+  logger.info(`Location after path variables subsitution: ${exePath}`);
   if (!executableExists(exePath)) {
-    throw new Error(`serverExecutablePath is set to ${exePath} but it doesn't exist and is not on the PATH`);
+    throw new Error(`serverExecutablePath is set to ${exePath} but it doesn't exist and it is not on the PATH`);
   }
   return exePath;
 }
 
 /** Searches the PATH for whatever is set in serverVariant */
-function findLocalServer(context: ExtensionContext, uri: Uri, folder?: WorkspaceFolder): string | null {
+function findLocalServer(context: ExtensionContext, logger: Logger, uri: Uri, folder?: WorkspaceFolder): string | null {
   const exes: string[] = ['haskell-language-server-wrapper', 'haskell-language-server'];
-
+  logger.info(`Searching for server executables ${exes.join(',')} in $PATH`);
   for (const exe of exes) {
     if (executableExists(exe)) {
+      logger.info(`Found server executable in $PATH: ${exe}`);
       return exe;
     }
   }
@@ -120,6 +148,9 @@ async function activeServer(context: ExtensionContext, document: TextDocument) {
 
 async function activateServerForFolder(context: ExtensionContext, uri: Uri, folder?: WorkspaceFolder) {
   const clientsKey = folder ? folder.uri.toString() : uri.toString();
+  // Set a unique name per workspace folder (useful for multi-root workspaces).
+  const langName = 'Haskell' + (folder ? ` (${folder.name})` : '');
+  const outputChannel: OutputChannel = window.createOutputChannel(langName);
 
   // If the client already has an LSP server for this uri/folder, then don't start a new one.
   if (clients.has(clientsKey)) {
@@ -129,21 +160,25 @@ async function activateServerForFolder(context: ExtensionContext, uri: Uri, fold
   clients.set(clientsKey, null);
 
   const logLevel = workspace.getConfiguration('haskell', uri).trace.server;
+  const clientLogLevel = workspace.getConfiguration('haskell', uri).trace.client;
   const logFile = workspace.getConfiguration('haskell', uri).logFile;
 
+  const logger: Logger = new ExtensionLogger('client', clientLogLevel, outputChannel);
+
   let serverExecutable;
   try {
     // Try and find local installations first
-    serverExecutable = findManualExecutable(uri, folder) ?? findLocalServer(context, uri, folder);
+    serverExecutable = findManualExecutable(logger, uri, folder) ?? findLocalServer(context, logger, uri, folder);
     if (serverExecutable === null) {
       // If not, then try to download haskell-language-server binaries if it's selected
-      serverExecutable = await downloadHaskellLanguageServer(context, uri, folder);
+      serverExecutable = await downloadHaskellLanguageServer(context, logger, uri, folder);
       if (!serverExecutable) {
         return;
       }
     }
   } catch (e) {
     if (e instanceof Error) {
+      logger.error(`Error getting the server executable: ${e.message}`);
       window.showErrorMessage(e.message);
     }
     return;
@@ -162,6 +197,12 @@ async function activateServerForFolder(context: ExtensionContext, uri: Uri, fold
   // If we're operating on a standalone file (i.e. not in a folder) then we need
   // to launch the server in a reasonable current directory. Otherwise the cradle
   // guessing logic in hie-bios will be wrong!
+  if (folder) {
+    logger.info(`Activating the language server in the workspace folder: ${folder?.uri.fsPath}`);
+  } else {
+    logger.info(`Activating the language server in the parent dir of the file: ${uri.fsPath}`);
+  }
+
   const exeOptions: ExecutableOptions = {
     cwd: folder ? undefined : path.dirname(uri.fsPath),
   };
@@ -173,15 +214,14 @@ async function activateServerForFolder(context: ExtensionContext, uri: Uri, fold
     debug: { command: serverExecutable, transport: TransportKind.stdio, args, options: exeOptions },
   };
 
-  // Set a unique name per workspace folder (useful for multi-root workspaces).
-  const langName = 'Haskell' + (folder ? ` (${folder.name})` : '');
-  const outputChannel: OutputChannel = window.createOutputChannel(langName);
-  outputChannel.appendLine('[client] run command: "' + serverExecutable + ' ' + args.join(' ') + '"');
-  outputChannel.appendLine('[client] debug command: "' + serverExecutable + ' ' + args.join(' ') + '"');
-
-  outputChannel.appendLine(`[client] server cwd: ${exeOptions.cwd}`);
+  logger.info(`run command: ${serverExecutable} ${args.join(' ')}`);
+  logger.info(`debug command: ${serverExecutable} ${args.join(' ')}`);
+  if (exeOptions.cwd) {
+    logger.info(`server cwd: ${exeOptions.cwd}`);
+  }
 
   const pat = folder ? `${folder.uri.fsPath}/**/*` : '**/*';
+  logger.info(`document selector patten: ${pat}`);
   const clientOptions: LanguageClientOptions = {
     // Use the document selector to only notify the LSP on files inside the folder
     // path for the specific workspace.
@@ -213,6 +253,7 @@ async function activateServerForFolder(context: ExtensionContext, uri: Uri, fold
   langClient.registerProposedFeatures();
 
   // Finally start the client and add it to the list of clients.
+  logger.info('Starting language server');
   langClient.start();
   clients.set(clientsKey, langClient);
 }

src/extension.ts

@@ -6,6 +6,7 @@ import * as path from 'path';
 import * as url from 'url';
 import { promisify } from 'util';
 import { env, ExtensionContext, ProgressLocation, Uri, window, workspace, WorkspaceFolder } from 'vscode';
+import { Logger } from 'vscode-languageclient';
 import { downloadFile, executableExists, httpsGetSilently } from './utils';
 import * as validate from './validation';
 
@@ -97,33 +98,69 @@ class NoBinariesError extends Error {
  * if needed. Returns null if there was an error in either downloading the wrapper or
  * in working out the ghc version
  */
-async function getProjectGhcVersion(context: ExtensionContext, dir: string, release: IRelease): Promise<string> {
+async function getProjectGhcVersion(
+  context: ExtensionContext,
+  logger: Logger,
+  dir: string,
+  release: IRelease
+): Promise<string> {
+  const title: string = 'Working out the project GHC version. This might take a while...';
+  logger.info(title);
   const callWrapper = (wrapper: string) => {
     return window.withProgress(
       {
-        location: ProgressLocation.Window,
-        title: 'Working out the project GHC version. This might take a while...',
+        location: ProgressLocation.Notification,
+        title: `${title}`,
+        cancellable: true,
       },
-      async () => {
+      async (progress, token) => {
         return new Promise<string>((resolve, reject) => {
+          const args = ['--project-ghc-version'];
+          const command: string = wrapper + args.join(' ');
+          logger.info(`Executing '${command}' in cwd '${dir}' to get the project or file ghc version`);
+          token.onCancellationRequested(() => {
+            logger.warn(`User canceled the execution of '${command}'`);
+          });
           // Need to set the encoding to 'utf8' in order to get back a string
-          child_process.exec(
-            wrapper + ' --project-ghc-version',
-            { encoding: 'utf8', cwd: dir },
-            (err, stdout, stderr) => {
-              if (err) {
-                const regex = /Cradle requires (.+) but couldn't find it/;
-                const res = regex.exec(stderr);
-                if (res) {
-                  throw new MissingToolError(res[1]);
+          // We execute the command in a shell for windows, to allow use .cmd or .bat scripts
+          const childProcess = child_process
+            .execFile(
+              wrapper,
+              args,
+              { encoding: 'utf8', cwd: dir, shell: getGithubOS() === 'Windows' },
+              (err, stdout, stderr) => {
+                if (err) {
+                  logger.error(`Error executing '${command}' with error code ${err.code}`);
+                  logger.error(`stderr: ${stderr}`);
+                  if (stdout) {
+                    logger.error(`stdout: ${stdout}`);
+                  }
+                  const regex = /Cradle requires (.+) but couldn't find it/;
+                  const res = regex.exec(stderr);
+                  if (res) {
+                    reject(new MissingToolError(res[1]));
+                  }
+                  reject(
+                    Error(`${wrapper} --project-ghc-version exited with exit code ${err.code}:\n${stdout}\n${stderr}`)
+                  );
+                } else {
+                  logger.info(`The GHC version for the project or file: ${stdout?.trim()}`);
+                  resolve(stdout?.trim());
                 }
-                throw Error(
-                  `${wrapper} --project-ghc-version exited with exit code ${err.code}:\n${stdout}\n${stderr}`
-                );
               }
-              resolve(stdout.trim());
-            }
-          );
+            )
+            .on('exit', (code, signal) => {
+              const msg =
+                `Execution of '${command}' terminated with code ${code}` + (signal ? `and signal ${signal}` : '');
+              logger.info(msg);
+            })
+            .on('error', (err) => {
+              if (err) {
+                logger.error(`Error executing '${command}': name = ${err.name}, message = ${err.message}`);
+                reject(err);
+              }
+            });
+          token.onCancellationRequested((_) => childProcess.kill());
         });
       }
     );
@@ -250,10 +287,12 @@ async function getLatestReleaseMetadata(context: ExtensionContext): Promise<IRel
  */
 export async function downloadHaskellLanguageServer(
   context: ExtensionContext,
+  logger: Logger,
   resource: Uri,
   folder?: WorkspaceFolder
 ): Promise<string | null> {
   // Make sure to create this before getProjectGhcVersion
+  logger.info('Downloading haskell-language-server');
   if (!fs.existsSync(context.globalStoragePath)) {
     fs.mkdirSync(context.globalStoragePath);
   }
@@ -265,7 +304,7 @@ export async function downloadHaskellLanguageServer(
     return null;
   }
 
-  // Fetch the latest release from GitHub or from cache
+  logger.info('Fetching the latest release from GitHub or from cache');
   const release = await getLatestReleaseMetadata(context);
   if (!release) {
     let message = "Couldn't find any pre-built haskell-language-server binaries";
@@ -276,12 +315,12 @@ export async function downloadHaskellLanguageServer(
     window.showErrorMessage(message);
     return null;
   }
-
-  // Figure out the ghc version to use or advertise an installation link for missing components
+  logger.info(`The latest release is ${release.tag_name}`);
+  logger.info('Figure out the ghc version to use or advertise an installation link for missing components');
   const dir: string = folder?.uri?.fsPath ?? path.dirname(resource.fsPath);
   let ghcVersion: string;
   try {
-    ghcVersion = await getProjectGhcVersion(context, dir, release);
+    ghcVersion = await getProjectGhcVersion(context, logger, dir, release);
   } catch (error) {
     if (error instanceof MissingToolError) {
       const link = error.installLink();
@@ -304,8 +343,12 @@ export async function downloadHaskellLanguageServer(
   // When searching for binaries, use startsWith because the compression may differ
   // between .zip and .gz
   const assetName = `haskell-language-server-${githubOS}-${ghcVersion}${exeExt}`;
+  logger.info(`Search for binary ${assetName} in release assests`);
   const asset = release?.assets.find((x) => x.name.startsWith(assetName));
   if (!asset) {
+    logger.error(
+      `No binary ${assetName} found in the release assets: ${release?.assets.map((value) => value.name).join(',')}`
+    );
     window.showInformationMessage(new NoBinariesError(release.tag_name, ghcVersion).message);
     return null;
   }
@@ -314,12 +357,14 @@ export async function downloadHaskellLanguageServer(
   const binaryDest = path.join(context.globalStoragePath, serverName);
 
   const title = `Downloading haskell-language-server ${release.tag_name} for GHC ${ghcVersion}`;
+  logger.info(title);
   await downloadFile(title, asset.browser_download_url, binaryDest);
   if (ghcVersion.startsWith('9.')) {
-    window.showWarningMessage(
+    const warning =
       'Currently, HLS supports GHC 9 only partially. ' +
-        'See [issue #297](https://github.com/haskell/haskell-language-server/issues/297) for more detail.'
-    );
+      'See [issue #297](https://github.com/haskell/haskell-language-server/issues/297) for more detail.';
+    logger.warn(warning);
+    window.showWarningMessage(warning);
   }
   return binaryDest;
 }

src/hlsBinaries.ts

@@ -7,10 +7,61 @@ import * as https from 'https';
 import { extname } from 'path';
 import * as url from 'url';
 import { promisify } from 'util';
-import { ProgressLocation, window } from 'vscode';
+import { OutputChannel, ProgressLocation, window } from 'vscode';
+import { Logger } from 'vscode-languageclient';
 import * as yazul from 'yauzl';
 import { createGunzip } from 'zlib';
 
+enum LogLevel {
+  Off,
+  Error,
+  Warn,
+  Info,
+}
+export class ExtensionLogger implements Logger {
+  public readonly name: string;
+  public readonly level: LogLevel;
+  public readonly channel: OutputChannel;
+
+  constructor(name: string, level: string, channel: OutputChannel) {
+    this.name = name;
+    this.level = this.getLogLevel(level);
+    this.channel = channel;
+  }
+  public warn(message: string): void {
+    this.logLevel(LogLevel.Warn, message);
+  }
+
+  public info(message: string): void {
+    this.logLevel(LogLevel.Info, message);
+  }
+
+  public error(message: string) {
+    this.logLevel(LogLevel.Error, message);
+  }
+
+  public log(msg: string) {
+    this.channel.appendLine(msg);
+  }
+
+  private logLevel(level: LogLevel, msg: string) {
+    if (level <= this.level) {
+      this.log(`[${this.name}][${LogLevel[level].toUpperCase()}] ${msg}`);
+    }
+  }
+
+  private getLogLevel(level: string) {
+    switch (level) {
+      case 'off':
+        return LogLevel.Off;
+      case 'error':
+        return LogLevel.Error;
+      default:
+        return LogLevel.Info;
+    }
+  }
+}
+
 /** When making http requests to github.com, use this header otherwise
  * the server will close the request
  */