Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[heft] heft watch mode always logs the re-run requestor task as unknown #4467

Open
bartvandenende-wm opened this issue Jan 2, 2024 · 6 comments · May be fixed by #4469 or #4953
Open

[heft] heft watch mode always logs the re-run requestor task as unknown #4467

bartvandenende-wm opened this issue Jan 2, 2024 · 6 comments · May be fixed by #4469 or #4953
Labels
bug Something isn't working as intended repro confirmed The issue comments included repro instructions, and the maintainers reproduced the problem

Comments

@bartvandenende-wm
Copy link
Contributor

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

  1. cd 'rushstack/build-tests-samples/heft-webpack-basic-tutorial'
  2. rush build --to .
  3. rushx start
  4. Make a file change in the src folder
  5. 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:

terminal.writeLine(Colors.bold(`New run requested by ${requestor || 'unknown task'}`));

which uses the Operation name value here:

return requestRun(this.name);

but the name value is never set for the operation when heft initialises it:

groupName: task.parentPhase.phaseName,

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 bartvandenende-wm changed the title [heft] heft watch mode always log the re-run requestor task as unknown [heft] heft watch mode always logs the re-run requestor task as unknown Jan 2, 2024
@octogonz octogonz added bug Something isn't working as intended repro confirmed The issue comments included repro instructions, and the maintainers reproduced the problem labels Jan 2, 2024
@octogonz octogonz linked a pull request Jan 2, 2024 that will close this issue
@octogonz
Copy link
Collaborator

octogonz commented Jan 2, 2024

@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

@octogonz
Copy link
Collaborator

octogonz commented Jan 2, 2024

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?

@D4N14L @dmichon-msft

@dmichon-msft
Copy link
Contributor

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?

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.

@bartvandenende-wm
Copy link
Contributor Author

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.

@octogonz
Copy link
Collaborator

octogonz commented Jan 2, 2024

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.

@github-project-automation github-project-automation bot moved this to Needs triage in Bug Triage Jan 8, 2024
@iclanton iclanton moved this from Needs triage to In Progress in Bug Triage Jan 8, 2024
@iclanton iclanton moved this from In Progress to General Discussions in Bug Triage Jan 8, 2024
@Chinkaimu
Copy link

@octogonz any idea about how to optimize tasks for cases we want to see the globs?
I my project, I generate scss to ts through SassPlugin, the ts are saved in src folder. Then they will be compiled to js by typescript.
The SassPlugin will re-run again and again. I don't know how to fix it. If possible to give some guidance?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working as intended repro confirmed The issue comments included repro instructions, and the maintainers reproduced the problem
Projects
Status: General Discussions
4 participants