Fix ci: ensure we have a supported ghc version in PATH

.github/workflows/build.yml

@@ -24,7 +24,12 @@ jobs:
         uses: HaaLeo/publish-vscode-extension@v0
         with:
           pat: ${{ secrets.OPEN_VSX_TOKEN }}
-      - name: Upload extension vsix
+      - name: Upload extension vsix to workflow artifacts
+        uses: actions/upload-artifact@v2
+        with:
+          name: haskell-${{ github.event.release.tag_name }}.vsix
+          path: ${{ steps.publishToVSMarketplace.outputs.vsixPath }}
+      - name: Upload extension vsix to release assets
         uses: actions/upload-release-asset@v1.0.2
         env:
           GITHUB_TOKEN: ${{ secrets.GITHUB_TOKEN }}

.github/workflows/test.yml

@@ -19,9 +19,20 @@ jobs:
         uses: actions/setup-node@v1
         with:
           node-version: 10.x
+      - name: Ensure there is a supported ghc versions
+        uses: haskell/actions/setup@v1
+        with:
+          ghc-version: 9.0.1
       - run: npm ci
       - run: npm run webpack
-      - run: xvfb-run -a npm test
+      - run: xvfb-run -s '-screen 0 640x480x16' -a npm test
         if: runner.os == 'Linux'
       - run: npm test
         if: runner.os != 'Linux'
+      - name: Upload log file to workflow artifacts on error
+        if: failure()
+        uses: actions/upload-artifact@v2
+        with:
+          name: extension-${{ matrix.os }}.log
+          path: test-workspace/hls.log
+

package.json

@@ -109,9 +109,10 @@
           "enum": [
             "off",
             "error",
+            "info",
             "debug"
           ],
-          "default": "error",
+          "default": "info",
           "description": "Sets the log level in the client side."
         },
         "haskell.logFile": {
@@ -398,7 +399,7 @@
     "@types/request-promise-native": "^1.0.17",
     "@types/vscode": "^1.52.0",
     "@types/yauzl": "^2.9.1",
-    "@vscode/test-electron": "^1.6.1",
+    "@vscode/test-electron": "^1.6.2",
     "glob": "^7.1.4",
     "husky": "^7.0.2",
     "mocha": "^9.1.2",

src/extension.ts

@@ -108,7 +108,7 @@ function findManualExecutable(logger: Logger, uri: Uri, folder?: WorkspaceFolder
   }
   logger.info(`Trying to find the server executable in: ${exePath}`);
   exePath = resolvePathPlaceHolders(exePath, folder);
-  logger.info(`Location after path variables substitution: ${exePath}`);
+  logger.log(`Location after path variables substitution: ${exePath}`);
 
   if (!executableExists(exePath)) {
     let msg = `serverExecutablePath is set to ${exePath}`;
@@ -164,6 +164,8 @@ async function activateServerForFolder(context: ExtensionContext, uri: Uri, fold
     return;
   }
 
+  const currentWorkingDir = folder ? folder.uri.fsPath : path.dirname(uri.fsPath);
+
   // Set the key to null to prevent multiple servers being launched at once
   clients.set(clientsKey, null);
 
@@ -173,11 +175,14 @@ async function activateServerForFolder(context: ExtensionContext, uri: Uri, fold
 
   const outputChannel: OutputChannel = window.createOutputChannel(langName);
 
-  const logger: Logger = new ExtensionLogger('client', clientLogLevel, outputChannel);
-
-  logger.info('Environment variables:');
+  const logFilePath = logFile ? path.resolve(currentWorkingDir, logFile) : undefined;
+  const logger: Logger = new ExtensionLogger('client', clientLogLevel, outputChannel, logFilePath);
+  if (logFilePath) {
+    logger.info(`Writing client log to file ${logFilePath}`);
+  }
+  logger.log('Environment variables:');
   Object.entries(process.env).forEach(([key, value]: [string, string | undefined]) => {
-    logger.info(`  ${key}: ${value}`);
+    logger.log(`  ${key}: ${value}`);
   });
 
   let serverExecutable;
@@ -217,11 +222,13 @@ 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!
+  let cwdMsg = `Activating the language server in working dir: ${currentWorkingDir}`;
   if (folder) {
-    logger.info(`Activating the language server in the workspace folder: ${folder?.uri.fsPath}`);
+    cwdMsg += ' (the workspace folder)';
   } else {
-    logger.info(`Activating the language server in the parent dir of the file: ${uri.fsPath}`);
+    cwdMsg += ` (parent dir of loaded file ${uri.fsPath})`;
   }
+  logger.info(cwdMsg);
 
   const serverEnvironment: IEnvVars = workspace.getConfiguration('haskell', uri).serverEnvironment;
   const exeOptions: ExecutableOptions = {
@@ -252,7 +259,7 @@ async function activateServerForFolder(context: ExtensionContext, uri: Uri, fold
   }
 
   const pat = folder ? `${folder.uri.fsPath}/**/*` : '**/*';
-  logger.info(`document selector patten: ${pat}`);
+  logger.log(`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.

src/utils.ts

@@ -18,16 +18,19 @@ enum LogLevel {
   Error,
   Warn,
   Info,
+  Debug
 }
 export class ExtensionLogger implements Logger {
   public readonly name: string;
   public readonly level: LogLevel;
   public readonly channel: OutputChannel;
+  public readonly logFile: string | undefined;
 
-  constructor(name: string, level: string, channel: OutputChannel) {
+  constructor(name: string, level: string, channel: OutputChannel, logFile: string | undefined) {
     this.name = name;
     this.level = this.getLogLevel(level);
     this.channel = channel;
+    this.logFile = logFile;
   }
   public warn(message: string): void {
     this.logLevel(LogLevel.Warn, message);
@@ -41,13 +44,25 @@ export class ExtensionLogger implements Logger {
     this.logLevel(LogLevel.Error, message);
   }
 
-  public log(msg: string) {
-    this.channel.appendLine(msg);
+  public log(message: string) {
+    this.logLevel(LogLevel.Debug, message);
+  }
+
+  private write(msg: string) {
+    let now = new Date();
+    // Ugly hack to make js date iso format similar to hls one
+    const offset = now.getTimezoneOffset();
+    now = new Date(now.getTime() - (offset * 60 * 1000));
+    const timedMsg = `${new Date().toISOString().replace('T', ' ').replace('Z', '0000')} ${msg}`;
+    this.channel.appendLine(timedMsg);
+    if (this.logFile) {
+      fs.appendFileSync(this.logFile, timedMsg + '\n');
+    }
   }
 
   private logLevel(level: LogLevel, msg: string) {
     if (level <= this.level) {
-      this.log(`[${this.name}][${LogLevel[level].toUpperCase()}] ${msg}`);
+      this.write(`[${this.name}] ${LogLevel[level].toUpperCase()} ${msg}`);
     }
   }
 
@@ -57,6 +72,8 @@ export class ExtensionLogger implements Logger {
         return LogLevel.Off;
       case 'error':
         return LogLevel.Error;
+      case 'debug':
+        return LogLevel.Debug;
       default:
         return LogLevel.Info;
     }

test/runTest.ts

@@ -1,3 +1,4 @@
+// tslint:disable: no-console
 import * as cp from 'child_process';
 import * as fs from 'fs';
 import * as path from 'path';
@@ -28,6 +29,7 @@ async function main() {
     const extensionTestsPath = path.resolve(__dirname, './suite/index');
 
     const testWorkspace = path.resolve(__dirname, '../../test-workspace');
+    console.log(`Test workspace: ${testWorkspace}`);
 
     if (!fs.existsSync(testWorkspace)) {
       fs.mkdirSync(testWorkspace);

test/suite/extension.test.ts

@@ -1,5 +1,6 @@
 // tslint:disable: no-console
 import * as assert from 'assert';
+import * as fs from 'fs';
 import * as os from 'os';
 import * as path from 'path';
 import { TextEncoder } from 'util';
@@ -10,12 +11,12 @@ function getExtension() {
   return vscode.extensions.getExtension('haskell.haskell');
 }
 
-async function delay(ms: number) {
-  return new Promise((resolve) => setTimeout(() => resolve(false), ms));
+async function delay(seconds: number) {
+  return new Promise((resolve) => setTimeout(() => resolve(false), seconds * 1000));
 }
 
 async function withTimeout(seconds: number, f: Promise<any>) {
-  return Promise.race([f, delay(seconds * 1000)]);
+  return Promise.race([f, delay(seconds)]);
 }
 
 function getHaskellConfig() {
@@ -31,18 +32,39 @@ function getWorkspaceFile(name: string) {
   return wsroot.with({ path: path.posix.join(wsroot.path, name) });
 }
 
-async function deleteWorkspaceFiles() {
-  const dirContents = await vscode.workspace.fs.readDirectory(getWorkspaceRoot().uri);
-  console.log(`Deleting test ws contents: ${dirContents}`);
+async function deleteWorkspaceFiles(pred?: (fileType: [string, vscode.FileType]) => boolean) {
+  await deleteFiles(getWorkspaceRoot().uri, pred);
+}
+
+function getExtensionLogContent(): string | undefined {
+  const extLog = getWorkspaceFile('hls.log').fsPath;
+  if (fs.existsSync(extLog)) {
+    const logContents = fs.readFileSync(extLog);
+    return logContents.toString();
+  } else {
+    console.log(`${extLog} does not exist!`);
+    return undefined;
+  }
+}
+
+async function deleteFiles(dir: vscode.Uri, pred?: (fileType: [string, vscode.FileType]) => boolean) {
+  const dirContents = await vscode.workspace.fs.readDirectory(dir);
+  console.log(`Deleting ${dir} contents: ${dirContents}`);
   dirContents.forEach(async ([name, type]) => {
     const uri: vscode.Uri = getWorkspaceFile(name);
-    console.log(`Deleting ${uri}`);
-    await vscode.workspace.fs.delete(getWorkspaceFile(name), { recursive: true });
+    if (!pred || pred([name, type])) {
+      console.log(`Deleting ${uri}`);
+      await vscode.workspace.fs.delete(getWorkspaceFile(name), {
+        recursive: true,
+        useTrash: false,
+      });
+    }
   });
 }
 
 suite('Extension Test Suite', () => {
   const disposables: vscode.Disposable[] = [];
+  const filesCreated: Map<string, Promise<vscode.Uri>> = new Map();
 
   async function existsWorkspaceFile(pattern: string, pred?: (uri: vscode.Uri) => boolean) {
     const relPath: vscode.RelativePattern = new vscode.RelativePattern(getWorkspaceRoot(), pattern);
@@ -65,9 +87,19 @@ suite('Extension Test Suite', () => {
     await getHaskellConfig().update('logFile', 'hls.log');
     await getHaskellConfig().update('trace.server', 'messages');
     await getHaskellConfig().update('releasesDownloadStoragePath', path.normalize(getWorkspaceFile('bin').fsPath));
-    await getHaskellConfig().update('serverEnvironment', { XDG_CACHE_HOME: path.normalize(getWorkspaceFile('cache-test').fsPath) });
+    await getHaskellConfig().update('serverEnvironment', {
+      XDG_CACHE_HOME: path.normalize(getWorkspaceFile('cache-test').fsPath),
+    });
     const contents = new TextEncoder().encode('main = putStrLn "hi vscode tests"');
     await vscode.workspace.fs.writeFile(getWorkspaceFile('Main.hs'), contents);
+
+    const pred = (uri: vscode.Uri) => !['download', 'gz', 'zip'].includes(path.extname(uri.fsPath));
+    const exeExt = os.platform.toString() === 'win32' ? '.exe' : '';
+    // Setting up watchers before actual tests start, to ensure we will got the created event
+    filesCreated.set('wrapper', existsWorkspaceFile(`bin/haskell-language-server-wrapper*${exeExt}`, pred));
+    filesCreated.set('server', existsWorkspaceFile(`bin/haskell-language-server-[1-9]*${exeExt}`, pred));
+    filesCreated.set('log', existsWorkspaceFile('hls.log'));
+    filesCreated.set('cache', existsWorkspaceFile('cache-test'));
   });
 
   test('Extension should be present', () => {
@@ -79,40 +111,53 @@ suite('Extension Test Suite', () => {
     assert.ok(true);
   });
 
+  test('Extension should create the extension log file', async () => {
+    await vscode.workspace.openTextDocument(getWorkspaceFile('Main.hs'));
+    assert.ok(await withTimeout(30, filesCreated.get('log')!), 'Extension log not created in 30 seconds');
+  });
+
   test('HLS executables should be downloaded', async () => {
     await vscode.workspace.openTextDocument(getWorkspaceFile('Main.hs'));
-    const exeExt = os.platform.toString() === 'win32' ? '.exe' : '';
     console.log('Testing wrapper');
-    const pred = (uri: vscode.Uri) => !['download', 'gz', 'zip'].includes(path.extname(uri.fsPath));
     assert.ok(
-      await withTimeout(30, existsWorkspaceFile(`bin/haskell-language-server-wrapper*${exeExt}`, pred)),
+      await withTimeout(30, filesCreated.get('wrapper')!),
       'The wrapper executable was not downloaded in 30 seconds'
     );
     console.log('Testing server');
     assert.ok(
-      await withTimeout(60, existsWorkspaceFile(`bin/haskell-language-server-[1-9]*${exeExt}`, pred)),
+      await withTimeout(60, filesCreated.get('server')!),
       'The server executable was not downloaded in 60 seconds'
     );
   });
 
-  test('Server log should be created', async () => {
+  test('Extension log should have server output', async () => {
     await vscode.workspace.openTextDocument(getWorkspaceFile('Main.hs'));
-    assert.ok(await withTimeout(30, existsWorkspaceFile('hls.log')), 'Server log not created in 30 seconds');
+    await delay(10);
+    const logContents = getExtensionLogContent();
+    assert.ok(logContents, 'Extension log file does not exist');
+    assert.match(logContents, /INFO hls:\s+Registering ide configuration/, 'Extension log file has no hls output');
   });
 
   test('Server should inherit environment variables defined in the settings', async () => {
     await vscode.workspace.openTextDocument(getWorkspaceFile('Main.hs'));
     assert.ok(
-      // Folder will have already been created by this point, so it will not trigger watcher in existsWorkspaceFile()
-      vscode.workspace.getWorkspaceFolder(getWorkspaceFile('cache-test')),
+      await withTimeout(30, filesCreated.get('cache')!),
       'Server did not inherit XDG_CACHE_DIR from environment variables set in the settings'
     );
   });
 
   suiteTeardown(async () => {
+    console.log('Disposing all resources');
     disposables.forEach((d) => d.dispose());
+    console.log('Stopping the lsp server');
     await vscode.commands.executeCommand(CommandNames.StopServerCommandName);
-    delay(5); // to give time to shutdown server
-    await deleteWorkspaceFiles();
+    await delay(5);
+    console.log('Contents of the extension log:');
+    const logContent = getExtensionLogContent();
+    if (logContent) {
+      console.log(logContent);
+    }
+    console.log('Deleting test workspace contents');
+    await deleteWorkspaceFiles(([name, type]) => !name.includes('.log'));
   });
 });