[heft] heft watch mode always logs the re-run requestor task as `unknown`
bartvandenende-wm opened this issue · 5 comments
Summary
When using the heft watch mode using heft start a re-run triggered by a heft-plugin is not properly logged as requestor in the console.
Repro steps
cd 'rushstack/build-tests-samples/heft-webpack-basic-tutorial'rush build --to .rushx start- Make a file change in the
srcfolder - Observe the console print ````New run requested by unknown task```
Expected result:
I would expect heft to print the name of the task operation that triggered to re-run, for example if the heft-typescript-plugin triggers runOptions.requestRun it should print something along the below lines:
New run requested by typescript
Actual result:
The operation task is always undefined
New run requested by undefined task
Details
Heft logs the message with the requestor here:
which uses the Operation name value here:
but the name value is never set for the operation when heft initialises it:
Adding the task name explicitly to the Operation initialisation in HeftActionRunner.ts solves this:
groupName: task.parentPhase.phaseName,
name: task.taskName,
Standard questions
Please answer these questions to help us investigate your issue more quickly:
| Question | Answer |
|---|---|
@rushstack/heft version? |
0.63.5 |
| Operating system? | Mac |
| Would you consider contributing a PR? | Yes |
Node.js version (node -v)? |
v18.16.1 |
@bartvandenende-wm has proposed a simple fix in #4468
However I'd like to consider requiring a logging name for every operation, as illustrated in my alternate PR #4469
Also, in testing this change, I noticed that the reported watcher seems a bit counterintuitive:
Using heft start in heft-web-rig-app-tutorial:
-
Saving a change to start.tsx prints these logs:
New run requested by typescript task 👈👈👈 Starting incremental build... ---- build started ---- [build:typescript] File change detected. Starting incremental compilation... [build:typescript] Found 0 errors. Watching for file changes. New run requested by sass task 👈👈👈 Cancelling incremental build... -------------------- Aborted (0.213s) -------------------- Starting incremental build... ---- build started ---- [build:webpack] Running incremental Webpack compilation ---- build finished (0.071s) ---- -------------------- Finished (0.073s) -------------------- Waiting for changes. Press CTRL + C to exit... -
Saving a change to start.css prints these logs:
New run requested by sass task 👈👈👈 Starting incremental build... ---- build started ---- [build:typescript] Copied 2 folders or files and linked 0 files [build:webpack] Running incremental Webpack compilation ---- build finished (0.064s) ---- -------------------- Finished (0.066s) -------------------- Waiting for changes. Press CTRL + C to exit... New run requested by webpack task 👈👈👈 Starting incremental build... ---- build started ---- [build:webpack] Running incremental Webpack compilation ---- build finished (0.056s) ---- -------------------- Finished (0.072s) -------------------- Waiting for changes. Press CTRL + C to exit...
To a casual observer, it seems counterintuitive that modifying *.tsx would trigger the sass task. If the underlying logic is working as expected, maybe the logging message could be rephrased to better capture what's going on?
To a casual observer, it seems counterintuitive that modifying *.tsx would trigger the
sasstask. If the underlying logic is working as expected, maybe the logging message could be rephrased to better capture what's going on?
The run is triggered by the SASS task because Heft's file watcher support doesn't actually monitor the output of globs, it monitors all the file system calls made to evaluate them. This is something that could be changed, but at the time of implementation it was easier to provide a watching file system adapter.
TL;DR, the SASS task triggers a rerun because a folder that was readdir'd during the evaluation of the SASS glob had a change to its directory listing.
good callout @octogonz, does it mean we have 2 plugins (sass and typescript) that trigger from the same Heft's file watcher support event simultaneously causing the first abort run?
A suggestion for further improved (verbose) log traceability would be for the task plugin to provide a trigger reason on the requestRun callback.
The run is triggered by the SASS task because Heft's file watcher support doesn't actually monitor the output of globs, it monitors all the file system calls made to evaluate them. This is something that could be changed, but at the time of implementation it was easier to provide a watching file system adapter.
I see, so Heft's watcher cannot see the globs themselves? And therefore it does not have enough information to determine whether the disk events actually affect the actual input files for SASS?
Then maybe the log message is correct, and we should instead focus on optimizing specific tasks such as sass.