Skip to content

fix(tutorial): report a run's start before the project's code runs - #3766

Merged
nighca merged 3 commits into
goplus:devfrom
Ethanlita:issue-3744-runtime-start-before-logs
Nov 13, 2026
Merged

nighca merged 3 commits into
goplus:devfrom
Ethanlita:issue-3744-runtime-start-before-logs

Conversation

@Ethanlita

@Ethanlita Ethanlita commented Nov 12, 2026 •

Copy link
Copy Markdown
Collaborator

Fixes #3744.

Summary

A course now receives editor.runtime.start before every editor.runtime.log and the editor.runtime.exit of the same run. Until now, the lines a learner's project printed from its top-level code reached Editor.Runtime.onLog before Editor.Runtime.onStart, in every run.

Where the start was emitted

  • EditorPreview.executeRun emitted didStart once surface.run() resolved (EditorPreview.vue).
  • run() is ProjectRunner.runInternal, which resolves only after startGame has returned and the project's files have been hashed (ProjectRunner.vue).
  • The Playground course program forwards didStart as editor.runtime.start (program.ts).

Why top-level logs arrived first

The project's code does not wait for startGame to return. It runs inside it:

  1. spx's startGame restarts the engine and then calls window.ispx_start, a synchronous call into Go. ispxStart starts the game in a goroutine and returns.
  2. When JavaScript calls into Go, Go's wasm runtime runs every runnable goroutine until all are blocked before it gives control back to JavaScript (handleEvent). The game's bootstrap therefore runs inside that call: the stage's top-level code, then each sprite's from the bottom layer up, each until its first wait.
  3. Every line printed there goes through the runner iframe's console.log, which ProjectRunner replaces (ProjectRunner.vue). The line is emitted as log right away, appended by EditorPreview.handleLog (EditorPreview.vue), and posted to the course program as editor.runtime.log as soon as the call returns to JavaScript (program.ts).
  4. Only after that does startGame resolve, the files get hashed, and didStart get emitted.

So a course saw the top-level lines, then the start, then the lines printed in the project's own onStart callbacks, which run from the first frame. On the test environment all 10 runs had this order, with the start 0.9–1.5 ms after the first line (details in #3744). A course that resets per-run state in Editor.Runtime.onStart erased what those lines had just recorded. Code: Lita lessons 34, 37–41 and 43 could never be completed because of it.

The fix

  • ProjectRunner emits a new start event right before it calls startGame, the last point before the project's code runs that builder controls. ProjectRunnerSurface forwards it, and EditorPreview emits didStart on it instead of after run() resolves.
  • Logs are still forwarded as they are printed. Nothing is buffered, so they reach the course as promptly as before.
  • What changes for didStart, and so for editor.runtime.start:
    • It is emitted while the runtime state is still initializing. The state and filesHash are updated when run() resolves, as before.
    • Initialization that fails or is cancelled before startGame emits no start, as before. A run that fails inside startGame has already emitted one, so a course can receive a start with no log or exit after it.
    • It comes before the project's first output by the time startGame spends restarting the engine: about 70–90 ms on a rerun on the test environment, and longer on the first run after the page loads.
  • A rerun keeps its order: rerun() stops the previous run first, and stopping emits that run's exit, so a course sees the old exit, the new start, then the new run's logs.
  • The project's own onStart callbacks, and the order of the code inside the project, are unchanged.
  • Comments and documents that described the timing now state the order: Runtime.didStart, Runtime.OnStart in tools/tutorial, module_SpxProjectEditor.ts, module_TutorialFramework.ts, tutorial-class-framework.go, tutorial-lifecycle-implementation.md, and the Editor.Runtime.onStart row of course-program.md, which goplus/xbuilder-courses syncs into its playground-course skill.

Validation

  • EditorPreview.test.ts and session.test.ts passed (41 tests). Three cases in EditorPreview.test.ts cover the new behavior: a start the runner reports is emitted at once, while still initializing; a run's start comes before its output and exit; and a run that fails after reporting its start keeps it. All three fail without this change.
  • ProjectRunner.test.ts runs the runner against a fake runner page whose startGame prints a line, and expects start, then startGame, then that line. It fails with emit('start') moved after startGame.
  • vue-tsc --build, ESLint and Prettier passed. TestGuideCoursesBuild in tools/xgoexec-bundle passed.
  • Checked in a browser on this PR's preview, which uses staging, with a test course on staging: #3744 运行开始顺序验证. Its stage prints 本次局面 甲 at the top level, and its sprite prints one line at the top level and one in onStart. The course program clears the situation in Editor.Runtime.onStart, records it from that line in onLog, and shows the order the events arrived in. On this preview all 3 runs kept the situation, in the order start, 本次局面 甲, the sprite's top-level line, its onStart line. On the dev preview (same course) the runs lost it: the start arrived after both top-level lines.
  • Recording the editor.runtime.* events posted to the course program's worker on another staging course, "两朵蘑菇不一样" (11615), showed the start first in all 25 runs on this preview, 50–170 ms before the first line.

The editor emitted didStart only after the runner's run() resolved, that
is after startGame and file hashing, while the project's top-level code
already runs and prints inside startGame. Courses therefore received
editor.runtime.start after the first logs of the same run.

ProjectRunner now emits start right before calling startGame, and the
editor preview forwards it as didStart. Logs are still forwarded as they
are printed.

Fixes goplus#3744

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@codecov

codecov Bot commented Nov 12, 2026 •

Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 59.95%. Comparing base (bc72ffa) to head (e7300ac).
⚠️ Report is 3 commits behind head on dev.

Additional details and impacted files
@@            Coverage Diff             @@
##              dev    #3766      +/-   ##
==========================================
+ Coverage   59.14%   59.95%   +0.81%     
==========================================
  Files         771      772       +1     
  Lines       27701    27728      +27     
  Branches     5229     5231       +2     
==========================================
+ Hits        16383    16625     +242     
+ Misses       9829     9590     -239     
- Partials     1489     1513      +24     
Flag Coverage Δ
gui 59.42% <100.00%> (+0.83%) ⬆️
tools-ai 79.61% <ø> (ø)

Flags with carried forward coverage won't be shown. Click here to find out more.

Files with missing lines Coverage Δ
...ui/src/components/editor/preview/EditorPreview.vue 67.46% <100.00%> (+1.20%) ⬆️
gui/src/components/editor/runtime.ts 97.18% <ø> (ø)
...ui/src/components/project/runner/ProjectRunner.vue 62.34% <100.00%> (+36.25%) ⬆️
...components/project/runner/ProjectRunnerSurface.vue 33.17% <100.00%> (+0.30%) ⬆️

... and 26 files with indirect coverage changes

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.
  • 📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

@fennoai fennoai Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Review: report a run's start before the project's code runs

Solid, well-scoped change. Moving emit('start') to just before startGame() in ProjectRunner.vue and relaying it synchronously up to runtime.emit('didStart') correctly upholds the new ordering guarantee (start before any of that run's log output or exit), since logs/exit originate inside the subsequent await startGame(). Tests cover the happy path, the "fails after start" path, and ordering of start/log/exit. The old post-success emit was cleanly removed, and start is a zero-payload signal — no data or secrets flow through it.

Two items below; the rest (performance, security) found nothing.

Reviewed areas: code quality, performance, security, documentation accuracy.

… game

ProjectRunner had no tests, and the editor preview's tests use a stubbed
runner, so nothing guarded where start is emitted. The new test runs the
runner against a fake runner page whose startGame prints a line, and
expects start, then startGame, then that line.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
The didStart documentation now states both sides: a run that fails or is
stopped before the project's code starts emits no start, and one that
fails or is stopped after it keeps the start it emitted. The comment on
emit('start') now reads as a full sentence.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@nighca
nighca merged commit 7bb2013 into goplus:dev Nov 13, 2026
8 checks passed

This branch was successfully deployed

1 active deployment
Preview – builder — e7300acc Deployed Nov 12, 2026 by vercel[bot]
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Editor.Runtime.onStart reaches a course after the run's first logs

2 participants