Added debug logging to tutorial precondition validation

packages/lib-common/src/ide/normalized/NormalizedIDE.ts

@@ -26,6 +26,9 @@ export class NormalizedIDE extends PassthroughIDE {
   }
 
   private initializeConfiguration() {
+    if (this.runMode === "development") {
+      this.configuration.mockConfiguration("debug", true);
+    }
     this.configuration.mockConfigurationScope(
       { languageId: "css" },
       { wordSeparators: ["_", "-"] },

packages/lib-engine/src/core/HatTokenMapImpl.ts

@@ -139,7 +139,7 @@ export class HatTokenMapImpl implements HatTokenMap {
       await this.commandServerApi.signals.prePhrase.getVersion();
 
     if (newSignalVersion !== this.lastSignalVersion) {
-      this.debug.log("taking snapshot");
+      this.debug.log("Taking snapshot");
       this.lastSignalVersion = newSignalVersion;
 
       if (newSignalVersion != null) {

packages/lib-tutorial/src/TutorialImpl.ts

@@ -278,7 +278,6 @@ export class TutorialImpl implements Tutorial, CommandRunnerDecorator {
 
   async resume() {
     await this.setupStep();
-    await this.checkPreconditions();
   }
 
   async list() {
@@ -353,17 +352,30 @@ export class TutorialImpl implements Tutorial, CommandRunnerDecorator {
 
     const currentStep = this.currentTutorial!.steps[state.stepNumber];
 
-    const preConditionsMet = await arePreconditionsMet(
+    const preconditionError = await arePreconditionsMet(
       this.ide.activeTextEditor,
       this.editor,
       this.hatTokenMap,
       currentStep,
     );
 
+    // Verify that the state hasn't changed since we started checking preconditions
     if (this.state_ !== state) {
+      this.debug(
+        `Tutorial ${state.id} step ${state.stepNumber + 1}: precondition check discarded because the tutorial state changed`,
+      );
       return;
     }
 
+    const preConditionsMet = preconditionError == null;
+
+    if (!preConditionsMet) {
+      this.debug(
+        `Tutorial ${state.id} step ${state.stepNumber + 1}: ${preconditionError}`,
+      );
+    }
+
+    // Update the state if the preconditions have changed
     if (preConditionsMet !== state.preConditionsMet) {
       this.setState({
         ...state,
@@ -372,4 +384,11 @@ export class TutorialImpl implements Tutorial, CommandRunnerDecorator {
       await this.ensureHighlights();
     }
   }
+
+  private debug(message: string) {
+    const debug = this.ide.configuration.getOwnConfiguration("debug");
+    if (debug) {
+      console.log(message);
+    }
+  }
 }

packages/lib-tutorial/src/arePreconditionsMet.ts

@@ -13,46 +13,56 @@ import type { TutorialStep } from "./types/tutorial.types";
  * @param editor The editor to check.
  * @param hatTokenMap The hat token map to use for checking if hats are correct.
  * @param step The tutorial step whose prerequesites are to be checked.
- * @returns `true` if the preconditions are met, `false` otherwise.
+ * @returns A description of the first failed precondition, or `undefined` if
+ * all preconditions are met.
  */
 export async function arePreconditionsMet(
   activeTextEditor: TextEditor | undefined,
   editor: TextEditor | undefined,
   hatTokenMap: HatTokenMap,
   { initialState: snapshot, languageId }: TutorialStep,
-): Promise<boolean> {
+): Promise<string | undefined> {
   if (snapshot == null) {
-    return true;
+    return undefined;
   }
 
   if (activeTextEditor !== editor) {
-    return false;
+    return `Active editor differs from tutorial editor`;
   }
 
-  if (editor == null || editor.document.languageId !== languageId) {
-    return false;
+  if (editor == null) {
+    return "Tutorial editor is unavailable";
+  }
+
+  if (editor.document.languageId !== languageId) {
+    return `Language differs (expected: ${languageId}, actual: ${editor.document.languageId})`;
   }
 
   if (editor.document.getText() !== snapshot.documentContents) {
-    return false;
+    return "Document contents differ";
   }
 
-  if (
-    !isEqual(editor.selections, snapshot.selections.map(plainObjectToSelection))
-  ) {
-    return false;
+  const expectedSelections = snapshot.selections.map(plainObjectToSelection);
+  if (!isEqual(editor.selections, expectedSelections)) {
+    const expected = expectedSelections
+      .map((selection) => selection.concise())
+      .join(", ");
+    const actual = editor.selections
+      .map((selection) => selection.concise())
+      .join(", ");
+    return `Selections differ (expected: ${expected}, actual: ${actual})`;
   }
 
   const readableHatMap = await hatTokenMap.getReadableMap(false);
   for (const mark of serializedMarksToTokenHats(snapshot.marks, editor)) {
-    if (
-      !readableHatMap
-        .getToken(mark.hatStyle, mark.grapheme)
-        ?.range.isRangeEqual(mark.hatRange)
-    ) {
-      return false;
+    const actualRange = readableHatMap.getToken(
+      mark.hatStyle,
+      mark.grapheme,
+    )?.range;
+    if (!actualRange?.isRangeEqual(mark.hatRange)) {
+      return `Hat ${mark.hatStyle}.${mark.grapheme} differs (expected: ${mark.hatRange.concise()}, actual: ${actualRange?.concise() ?? "none"})`;
     }
   }
 
-  return true;
+  return undefined;
 }

packages/test-vscode-e2e/src/suite/tutorial/tutorial.vscode.test.ts

@@ -154,9 +154,6 @@ async function runBasicTutorialTest(spyIde: SpyIDE) {
   // Test resuming tutorial
   await commands.executeCommand("cursorless.tutorial.resume");
   await checkStepSetup(fixtures[0]);
-  const resumedStateEvent = getTutorialWebviewEventLog().at(-2);
-  assert.ok(resumedStateEvent?.type === "messageSent");
-  assert.equal(resumedStateEvent.data.preConditionsMet, true);
 
   // Test automatic advancing
   await runCursorlessCommand({