Use slightly longer delays for Ubuntu tests

.github/workflows/build.yaml

@@ -49,8 +49,9 @@ jobs:
   ui-test:
     strategy:
       matrix:
-        os: [ubicloud-standard-4, windows-latest, macos-latest]
-      fail-fast: true
+        os: [ubicloud-standard-4]
+        run: [1, 2, 3, 4, 5, 6, 7, 8]
+      fail-fast: false
     env:
       CODE_VERSION: "1.90.2"
     runs-on:  ${{ matrix.os }}
@@ -113,7 +114,7 @@ jobs:
         if: contains(matrix.os, 'ubuntu') || startsWith(matrix.os, 'ubicloud-standard')
         working-directory: ./rascal-vscode-extension
         env:
-          DELAY_FACTOR: 8
+          DELAY_FACTOR: 15
           RASCAL_LSP_DEV_DEPLOY: true
           _JAVA_OPTIONS: '-Xmx5G' # we have 16gb of memory, make sure LSP, REPL & DSL-LSP can start
         run: |
@@ -122,9 +123,9 @@ jobs:
 
       - name: Upload Screenshots
         uses: actions/upload-artifact@v7
-        if: failure()
+        if: failure() || cancelled()
         with:
-          name: screenshots-${{ matrix.os }}
+          name: screenshots-${{ matrix.os }}-${{matrix.run}}
           path: ./rascal-vscode-extension/uitests/screenshots/**/*.png
           retention-days: 5
           if-no-files-found: error

rascal-lsp/src/main/java/org/rascalmpl/vscode/lsp/TextDocumentState.java

@@ -74,11 +74,11 @@ public TextDocumentState(
 
         this.parser = parser;
         this.location = location;
+        this.lastWithoutErrors = new AtomicReference<>();
+        this.last = new AtomicReference<>();
 
         var u = new Update(initialVersion, initialContent, initialTimestamp);
         this.current = new AtomicReference<>(new Versioned<>(initialVersion, u));
-        this.lastWithoutErrors = new AtomicReference<>();
-        this.last = new AtomicReference<>();
     }
 
     public ISourceLocation getLocation() {
@@ -132,7 +132,7 @@ public CompletableFuture<Versioned<ITree>> getCurrentTreeAsync(boolean allowReco
     }
 
     /**
-     * Wait for current tree to parse. Then return the last tree that matches the allowRecoveredErrors conditation.
+     * Wait for current tree to parse. Then return the last tree that matches the allowRecoveredErrors condition.
      * @param allowRecoveredErrors if false, the result will not contain a tree with recovered errors.
      * @return the last parse tree, or an exception if non existed.
      */
@@ -198,6 +198,7 @@ public CompletableFuture<Versioned<List<Diagnostics.Template>>> getDiagnosticsAs
         }
 
         private void parse() {
+            logger.debug("Triggering parse for {}", location);
             try {
                 parser.apply(location, content)
                     .whenComplete((ITree t, Throwable e) -> {
@@ -208,13 +209,17 @@ private void parse() {
 
                         // Complete future to get the tree
                         if (t == null) {
+                            logger.error("Parse completed exceptionally: {}", location);
                             treeAsync.completeExceptionally(e);
                         } else {
                             var tree = new Versioned<>(version, t, timestamp);
+                            logger.error("Parse completed: {}", location);
                             Versioned.replaceIfNewer(last, tree);
                             if (diagnosticsList.isEmpty()) {
+                                logger.error("Parse completed without errors: {}", location);
                                 Versioned.replaceIfNewer(lastWithoutErrors, tree);
                             }
+                            logger.error("TreeAsync completed: {}", location);
                             treeAsync.complete(tree);
                         }
 

rascal-lsp/src/main/java/org/rascalmpl/vscode/lsp/parametric/NoContributions.java

@@ -87,7 +87,8 @@
 
     @Override
     public CompletableFuture<ITree> parsing(ISourceLocation loc, String input) {
-        return CompletableFuture.failedFuture(new NoContributionException("parsing"));
+        logger.error("NoContributions::parsing()", loc);
+        throw new NoContributionException("parsing");
     }
 
     @Override

rascal-lsp/src/main/java/org/rascalmpl/vscode/lsp/parametric/ParametricTextDocumentService.java

@@ -360,6 +360,7 @@ public void didClose(DidCloseTextDocumentParams params) {
         logger.debug("Did Close file: {}", params.getTextDocument());
         var loc = Locations.toLoc(params.getTextDocument());
         if (files.remove(loc) == null) {
+            logger.error("Received `didClose` for unknown file: {}", loc);
             throw new ResponseErrorException(unknownFileError(loc, params));
         }
         facts(loc).close(loc);
@@ -372,9 +373,11 @@ public void didClose(DidCloseTextDocumentParams params) {
 
     @Override
     public void didDeleteFiles(DeleteFilesParams params) {
+        logger.debug("textDocument/didDeleteFiles({})", params);
         exec.submit(() -> {
             // if a file is deleted, and we were tracking it, we remove our diagnostics
             for (var f : params.getFiles()) {
+                logger.debug("Received `didDelete` for {}", f);
                 availableClient().publishDiagnostics(new PublishDiagnosticsParams(f.getUri(), List.of()));
             }
         });
@@ -421,7 +424,7 @@ private void handleParsingErrors(TextDocumentState file, CompletableFuture<Versi
                 .map(diagnostic -> diagnostic.instantiate(columns))
                 .collect(Collectors.toList());
 
-            logger.trace("Finished parsing tree, reporting new parse errors: {} for: {}", parseErrors, file.getLocation());
+            logger.info("Finished parsing tree, reporting new parse errors: {} for: {}", parseErrors, file.getLocation());
             facts(file.getLocation()).reportParseErrors(file.getLocation(), diagnostics.version(), parseErrors);
         });
     }
@@ -694,7 +697,10 @@ private ILanguageContributions contributions(ISourceLocation doc) {
             .map(contributions::get)
             .map(ILanguageContributions.class::cast)
             .flatMap(Optional::ofNullable)
-            .orElseGet(() -> new NoContributions(extension(doc), exec));
+            .orElseGet(() -> {
+                logger.error("No contributions for {}", doc);
+                return new NoContributions(extension(doc), exec);
+            });
     }
 
     private static String extension(ISourceLocation doc) {
@@ -1042,7 +1048,7 @@ public Set<String> fileExtensions() {
 
     private void updateFileState(LanguageParameter lang, ISourceLocation f) {
         f = f.top();
-        logger.trace("File of language {} - updating state: {}", lang.getName(), f);
+        logger.info("File of language {} - updating state: {}", lang.getName(), f);
         // Since we cannot know what happened to this file before we were called, we need to be careful about races.
         // It might have been closed in the meantime, so we compute the new value if the key still exists, based on the current value.
         var state = files.computeIfPresent(f, (loc, currentState) -> currentState.changeParser(contributions(loc)::parsing));

rascal-lsp/src/main/java/org/rascalmpl/vscode/lsp/util/Versioned.java

@@ -27,9 +27,14 @@
 package org.rascalmpl.vscode.lsp.util;
 
 import java.util.concurrent.atomic.AtomicReference;
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.checkerframework.checker.nullness.qual.PolyNull;
 
 public class Versioned<T> {
+
+    private static final Logger logger = LogManager.getLogger(Versioned.class);
+
     private final int version;
     private final T object;
     private final long timestamp;
@@ -66,13 +71,34 @@
     }
 
     public static <T> boolean replaceIfNewer(AtomicReference<@PolyNull Versioned<T>> current, Versioned<T> maybeNewer) {
+        logger.debug("Versioned.replaceIfNewer({}, {})", current, maybeNewer);
+        logger.debug("current==null: {}; maybeNewer.version: {}", current == null, maybeNewer.version());
+        int i = 1;
         while (true) {
-            var old = current.get();
-            if (old == null || old.version() < maybeNewer.version()) {
+            Versioned<T> old = null;
+            logger.debug("Iteration {}: Getting `old`...", i++);
+            try {
+                old = current.get();
+            } catch (Throwable t) {
+                logger.error("{}: {}", t.getClass(), t.getMessage());
+                // t.printStackTrace();
+                throw t;
+            }
+            logger.debug("Iteration {}: `old` = `{}`", i++, old);
+            if (old == null) {
+                logger.debug("old == null");
+                if (current.compareAndSet(old, maybeNewer)) {
+                    return true;
+                }
+            } else if (old.version() < maybeNewer.version()) {
+                logger.debug("old version ({}) < new version ({})", old.version, maybeNewer.version);
                 if (current.compareAndSet(old, maybeNewer)) {
                     return true;
+                } else {
+                    logger.debug("compareAndSet failed: {}, {}", current, old);
                 }
             } else {
+                logger.debug("old version ({}) >= new version ({})", old.version, maybeNewer.version);
                 return false;
             }
         }

rascal-vscode-extension/package.json

@@ -329,6 +329,6 @@
     "license-check-and-add": "4.x",
     "mocha": "11.x",
     "typescript": "5.x",
-    "vscode-extension-tester": "8.x"
+    "vscode-extension-tester": "8.22.1"
   }
 }

rascal-vscode-extension/src/test/vscode-suite/dsl.test.ts

@@ -76,40 +76,61 @@ parameterizedDescribe(function (errorRecovery: boolean) {
     }
 
     before(async () => {
+        console.log("Initializing browser");
         browser = VSBrowser.instance;
+        console.log("Initializing driver");
         driver = browser.driver;
+        console.log("Initializing workbench");
         bench = new Workbench();
+        console.log("Waiting for worbench");
         await ignoreFails(browser.waitForWorkbench());
+        console.log("Initializing IDE operations");
         ide = new IDEOperations(browser);
+        console.log("Loading IDE");
         await ide.load();
+        console.log("Loading Pico");
         await loadPico();
+        console.log("Reading backup file");
         picoFileBackup = await fs.readFile(TestWorkspace.picoFile);
-        ide = new IDEOperations(browser);
-        await ide.load();
+        await ide.screenshot("after [before] init");
     });
 
     beforeEach(async function () {
+        console.log(`[begin] beforeEach(${this.test?.title})`);
         if (this.test?.title) {
             await ide.screenshot(`DSL-${errorRecovery}-` + this.test?.title);
         }
+        console.log(`[end] beforeEach(${this.test?.title})`);
     });
 
     afterEach(async function () {
+        console.log(`[begin] afterEach(${this.test?.title})`);
         if (this.test?.title) {
+            const bb = await new Workbench().getBottomBar();
+            await bb.openProblemsView();
             await ide.screenshot(`DSL-${errorRecovery}-`+ this.test?.title);
         }
         await ide.cleanup();
         await fs.writeFile(TestWorkspace.picoFile, picoFileBackup);
+        console.log(`[end] afterEach(${this.test?.title})`);
     });
 
     it("has highlighting and parse errors", async function () {
+        console.log("Closing all editors");
         await ignoreFails(new Workbench().getEditorView().closeAllEditors());
+        console.log(`Opening Pico file ${TestWorkspace.picoFile}`);
         const editor = await ide.openModule(TestWorkspace.picoFile);
+        await ide.screenshot("after-opening-pico-file");
         const isPicoLoading = ide.statusContains("Pico");
         // we might miss this event, but we wait for it to show up
         await ignoreFails(driver.wait(isPicoLoading, Delays.normal, "Pico parser generator should have started"));
         // now wait for the Pico parser generator to disappear
-        await driver.wait(async () => !(await isPicoLoading()), Delays.verySlow, "Pico parser generator should have finished", 100);
+        await driver.wait(async () => {
+            console.log("Awaiting Pico parser generator finish");
+            await ide.screenshot("is-pico-loading-finished");
+            return !(await isPicoLoading());
+        }, Delays.verySlow, "Pico parser generator should have finished", 100);
+        console.log("hHas syntax highilighting?");
         await ide.hasSyntaxHighlighting(editor, Delays.slow);
         console.log("We got syntax highlighting");
         try {
@@ -222,8 +243,15 @@ end
     it("code lens works", async function() {
         if (errorRecovery) { this.skip(); }
         const editor = await ide.openModule(TestWorkspace.picoFile);
-        const lens = await driver.wait(() => editor.getCodeLens("Rename variables a to b."), Delays.verySlow, "Rename lens should be available");
-        await lens!.click();
+        await driver.wait(async () => {
+            const lens = await editor.getCodeLens("Rename variables a to b.");
+            try {
+                await lens!.click();
+                return true;
+            } catch (e) {
+                return false;
+            }
+        }, Delays.verySlow, "Rename lens should be available");
         await ide.assertLineBecomes(editor, 9, "b := 2;", "a variable should be changed to b");
     });
 
@@ -248,9 +276,11 @@ end
         const editor = await ide.openModule(TestWorkspace.picoFile);
         await editor.moveCursor(5, 6);
 
-        ide.renameSymbol(editor, bench, "z");
-
-        await driver.wait(() => (editor.isDirty()), Delays.extremelySlow, "Rename should have resulted in changes in the editor");
+        await ide.renameSymbol(editor, bench, "z");
+        await driver.wait(async () => {
+            await ide.screenshot("rename-dirty-check");
+            return editor.isDirty();
+        }, Delays.extremelySlow, "Rename should have resulted in changes in the editor");
 
         const editorText = await editor.getText();
         expect(editorText).to.contain("z : natural");
@@ -295,6 +325,7 @@ end
         await driver.wait(async () => {
             const outgoing = await ignoreFails(new SideBarView().getContent().getSection("Callers Of"));
             const items = await ignoreFails(outgoing!.getVisibleItems());
+            await ide.screenshot("call-hierarchy-incoming");
             return items?.length === 2;
         }, Delays.normal, "Call hierarchy should show `multiply` and its recursive call.");
 
@@ -303,6 +334,7 @@ end
         await driver.wait(async () => {
             const incoming = await ignoreFails(new SideBarView().getContent().getSection("Calls From"));
             const items = await ignoreFails(incoming!.getVisibleItems());
+            await ide.screenshot("call-hierarchy-outgoing");
             return items?.length === 3;
         }, Delays.normal, "Call hierarchy should show `multiply` and its two outgoing calls.");
     });

rascal-vscode-extension/src/test/vscode-suite/ide.test.ts

@@ -196,8 +196,7 @@ describe('IDE', function () {
         const checkRascalStatus = ide.statusContains("Loading Rascal");
         await driver.wait(async () => !(await checkRascalStatus()), Delays.extremelySlow, "Rascal evaluators have not finished loading");
 
-        ide.renameSymbol(editor, bench, "i");
-
+        await ide.renameSymbol(editor, bench, "i");
         await driver.wait(() => (editor.isDirty()), Delays.extremelySlow, "Rename should have resulted in changes in the editor");
 
         const editorText = await editor.getText();