Delay "File change detected" reporting until createProgram #47427

jakebailey · 2022-01-13T19:35:46Z

There are cases where the file/directory watching handler can't determine whether or not a change should be ignored or not. For files with unsupported extensions (like .txt), the watcher never calls the handler. However, extensionless files do cause the watcher to call the handler (among other cases).

Rather than trying to perfect the watcher logic, delay printing of the "file change detected" message until we actually know we're going to create a new program (i.e. after it's determined that something important changed, and therefore a new program needs to be created).

Fixes #46949

DanielRosenwasser

State management seems rough here. The solution seems okay, but maybe others on the team have better strategies.

jakebailey · 2022-01-14T07:02:43Z

If this is less desirable, an alternative change that I considered was to, in watchWildcardDirectory, pass the result of addOrDeleteFileOrDirectory to isIgnoredFileFromWildCardWatching, then have it explicitly ignore extensionless files (using the cached stat).

But, I feel like there are other cases that are not handled there either, e.g. consider a new file that is supported, or a new directory, but that aren't actually in the program (thanks to exclude or not being in include or something). In that case, this same bug would happen, as the file watcher would trigger, but the program would not be recreated and never log the second message. To avoid that, I thought it would be a little better to just tie this to the actual thing that prints the second message, the creation of a new program.

FWIW, changesAffectResolution is no worse when it comes to state management; it's also a value that gets set by some caller of synchronizeProgram, then is cleared when the synchronize is finished.

amcasey

I don't use watch mode very often, so I may be out of touch, but I think I'd rather see "detected change... ignoring change" than nothing if it's actually doing work.

src/compiler/watchPublic.ts

amcasey · 2022-01-15T00:09:38Z

src/compiler/watchPublic.ts

@@ -434,15 +435,22 @@ namespace ts {
            const hasInvalidatedResolution = resolutionCache.createHasInvalidatedResolution(userProvidedResolution || changesAffectResolution);
            if (isProgramUptoDate(getCurrentProgram(), rootFileNames, compilerOptions, getSourceVersion, fileExists, hasInvalidatedResolution, hasChangedAutomaticTypeDirectiveNames, getParsedCommandLine, projectReferences)) {
                if (hasChangedConfigFileParsingErrors) {
+                    if (reportWatchDiagnosticOnCreateProgram) {


Seems like this has to be true? How could the config file change without triggering a program refresh?

Unless I'm mistaken, hasChangedConfigFileParsingErrors can be true if reloadFileNamesFromConfigFile was called, which can happen if the refresh level was ConfigFileProgramReloadLevel.Partial (and then those call sites are outside of the watcher changes, entirely, I think). I'll remove the if and see if there are any tests for this, though.

It seems like that if there's a case where hasChangedConfigFileParsingErrors is true but reportWatchDiagnosticOnCreateProgram is false, there's no test for it.

I can change this to unconditionally report the message, but I'm not entirely confident that there's no code path where this breaks.

I'm not familiar from this code - I'm just pointing out that, abstractly, it seems like a config file change will always be a relevant file change (i.e. will require the message to be printed).

amcasey · 2022-01-15T00:13:51Z

@jakebailey Do you have a link to the kick-out that's causing the problem (i.e. preventing the second log message from being printed)?

jakebailey · 2022-01-15T01:57:40Z

I believe it's

TypeScript/src/compiler/watchUtilities.ts

Line 503 in 28c2084

return false;

.

(I can check when I have a chance and I'm back at my machine)

jakebailey · 2022-01-18T21:31:42Z

I think I'd rather see "detected change... ignoring change" than nothing if it's actually doing work.

This is a little tricky due to how this thing is printed; it goes via afterProgramCreate below which is a result of the emitFilesAndReportErrors callback.

amcasey · 2022-01-18T23:18:30Z

I believe it's

TypeScript/src/compiler/watchUtilities.ts

Line 503 in 28c2084

return false;

.
(I can check when I have a chance and I'm back at my machine)

false doesn't mean it's not ignored?

amcasey

I think I'd rather see "detected change... ignoring change" than nothing if it's actually doing work.

This is a little tricky due to how this thing is printed; it goes via afterProgramCreate below which is a result of the emitFilesAndReportErrors callback.

I might be missing something obvious, but wouldn't it just be a matter of updating synchronizeProgram to print "ignoring" in cases where this PR does not print "change detected"?

amcasey · 2022-01-18T23:24:55Z

src/compiler/watchPublic.ts

                createNewProgram(hasInvalidatedResolution);
            }

            changesAffectResolution = false; // reset for next sync
+            reportFileChangeDetectedOnCreateProgram = false;


Can this be cleared in updateProgramWithWatchStatus? I think that would make its lifetime/scope much clearer.

I can clear it there instead, but I had been modelling changesAffectResolution.

My main concern was a case where it may be left over for another synchronize later, but I don't know why I thought that.

Personally, I think it's clearer to set it and call it in the same place, but I'm also fine with following local conventions. If this is where things are cleared after sync, then go for it.

amcasey · 2022-01-18T23:26:35Z

src/compiler/watchPublic.ts

@@ -434,15 +435,22 @@ namespace ts {
            const hasInvalidatedResolution = resolutionCache.createHasInvalidatedResolution(userProvidedResolution || changesAffectResolution);
            if (isProgramUptoDate(getCurrentProgram(), rootFileNames, compilerOptions, getSourceVersion, fileExists, hasInvalidatedResolution, hasChangedAutomaticTypeDirectiveNames, getParsedCommandLine, projectReferences)) {
                if (hasChangedConfigFileParsingErrors) {
+                    if (reportFileChangeDetectedOnCreateProgram) {
+                        reportWatchDiagnostic(Diagnostics.File_change_detected_Starting_incremental_compilation);


How much work is done between where this used to be reported and here? I'm concerned that it will look like the compiler is frozen if it reacts "late" to a file change.

That's a good question; my skimming says that isProgramUptoDate will:

Compare a few arrays for equality

Check for not-up-to-date source files, which appears to be checking a number of caches

Check for files that the program thought were missing on disk

Compare compiler options

Compare tsconfig contents by text for position changes for diagnostics

I'm not sure that it's a huge amount of work.

I could try and have it unconditionally run afterProgramCreate, but based on #37266, it seems like this was an intentional change (but, hard to tell entirely, given it's one part of a lot of other tweaks). I'll try it and see if anything breaks catastrophically, but I don't know exactly how to double check that I don't undo a perf fix.

I think we convinced ourselves that it should be cheap. I'm fine bugging this into shape if we get complaints.

jakebailey · 2022-01-18T23:29:38Z

false doesn't mean it's not ignored?

It does mean it's not ignored (so the watcher will emit the event), but in this case, adding the extensionless file doesn't actually cause the program to change.

I debugged and I did note the correct return statement.

It occurs to me that my alternative fix (using the stat info) is likely to not work right when that same extensionless file is deleted later, since we won't have any idea if that was a directory or not that changed.

amcasey · 2022-01-19T00:26:04Z

@jakebailey's offline explanation - we can't break existing consumers by changing our output - convinced me that printing an explicit ignore message would be worse.

jakebailey · 2022-01-19T01:37:39Z

tests/baselines/reference/tscWatch/programUpdates/config-file-is-deleted.js

@@ -84,9 +84,6 @@ Input::
 //// [/a/b/tsconfig.json] deleted

 Output::
->> Screen clear
-[[90m12:00:24 AM[0m] File change detected. Starting incremental compilation...
-
 [91merror[0m[90m TS5083: [0mCannot read file '/a/b/tsconfig.json'.


It's hard to tell in the diff here, but after this message is printed, the process exits (see exitCode below), so it's sort of pointless if this message is printed or not here other than to maybe indicate that we noticed because of a file watcher update.

This same error is printed if we start with a missing config file in the first place.

amcasey

Thanks for investigating!

jakebailey added 4 commits January 13, 2022 11:27

Add test based on issue

590166a

Delay "File change detected" reporting until createProgram

a2c9d9c

Accept new baseline for new test

7f5f56e

Update baselines for existing tests

3c844cf

typescript-bot assigned jakebailey Jan 13, 2022

typescript-bot added Author: Team For Milestone Bug PRs that fix a bug with a specific milestone labels Jan 13, 2022

jakebailey added 3 commits January 13, 2022 12:16

Ensure diag is cleared on synchronizeProgram

e59d8f5

Be less clever

582a8da

Fix missing baselines

67e8cff

DanielRosenwasser requested review from weswigham, amcasey and orta January 14, 2022 01:44

DanielRosenwasser approved these changes Jan 14, 2022

View reviewed changes

amcasey reviewed Jan 15, 2022

View reviewed changes

jakebailey added 2 commits January 18, 2022 11:01

Switch to a boolean

8b21e9b

Clarify bool

d5d0bc6

amcasey reviewed Jan 18, 2022

View reviewed changes

jakebailey commented Jan 19, 2022

View reviewed changes

Add test for deleting a file declared in files

e7fc25d

amcasey approved these changes Jan 19, 2022

View reviewed changes

jakebailey merged commit 97017ee into microsoft:main Jan 19, 2022

jakebailey deleted the fix-46949-2 branch January 19, 2022 02:13

Delay "File change detected" reporting until createProgram #47427

Delay "File change detected" reporting until createProgram #47427

Uh oh!

Conversation

jakebailey commented Jan 13, 2022

Uh oh!

DanielRosenwasser left a comment

Choose a reason for hiding this comment

Uh oh!

jakebailey commented Jan 14, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

amcasey left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

jakebailey Jan 18, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

amcasey commented Jan 15, 2022

Uh oh!

jakebailey commented Jan 15, 2022

Uh oh!

jakebailey commented Jan 18, 2022

Uh oh!

amcasey commented Jan 18, 2022

Uh oh!

amcasey left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

jakebailey commented Jan 18, 2022

Uh oh!

amcasey commented Jan 19, 2022

Uh oh!

jakebailey Jan 19, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

amcasey left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

jakebailey commented Jan 14, 2022 •

edited

Loading

jakebailey Jan 18, 2022 •

edited

Loading

jakebailey Jan 19, 2022 •

edited

Loading