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

Reduce IVsFreeThreadedFileChangeEvents2.DirectoryChangedEx2 notifications from VS shell #75815

Merged
merged 6 commits into from
Nov 16, 2024

Conversation

ToddGrun
Copy link
Contributor

@ToddGrun ToddGrun commented Nov 8, 2024

While looking into another FileWatcher issue, I noticed that we were getting more notifications from shell on directory changes than I would have expected. It turns out this is because we don't currently combine WatchDirectory operations as we do WatchFile/UnwatchFile/UnwatchDirectories.

This is generally the desired behavior as vs shell doesn't support multiple directories being supported by a single notification. However, they do support multiple filters on the same directory, and this is exactly the case that we usualy experience when processing a batch of WatcherOperations. This PR simply allows combining of directory watch notifications for the same directory (and sink), keeping track of the combined set of filters that all requests had.

Note that this PR also changed the mergability of WatchFiles by only allowing merging if the sinks are the same. I don't have context to be completely confident the prior behavior is a bug, but it sure seems wrong.

…ions from VS shell

While looking into another FileWatcher issue, I noticed that we were getting more notifications from shell on directory changes than I would have expected. It turns out this is because we don't currently combine WatchDirectory operations as we do WatchFile/UnwatchFile/UnwatchDirectories.

This is generally the desired behavior as vs shell doesn't support multiple directories being supported by a single notification. However, they do support multiple filters on the same directory, and this is exactly the case that we usualy experience when processing a batch of WatcherOperations. This PR simply allows combining of directory watch notifications for the same directory (and sink), keeping track of the combined set of filters that all requests had.

Note that this PR also changed the mergability of WatchFiles by only allowing merging if the sinks are the same. I don't have context to be completely confident the prior behavior is a bug, but it sure seems wrong.
@ToddGrun ToddGrun requested a review from a team as a code owner November 8, 2024 00:17
@dotnet-issue-labeler dotnet-issue-labeler bot added Area-IDE untriaged Issues and PRs which have not yet been triaged by a lead labels Nov 8, 2024
return (_kind == other._kind);
if (_kind == Kind.WatchFiles)
{
return other._sink == _sink;
Copy link
Contributor Author

Choose a reason for hiding this comment

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

@jasonmalinowski -- This is the code that seemed like a bug before. I definitely see WatchFiles requests with different sinks getting merged.

Copy link
Member

Choose a reason for hiding this comment

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

Looks like this is fixing #74716 then.

@CyrusNajmabadi
Copy link
Member

In this PR, or in a followup, can you examine if TimeSpan.Zero is really a good idea for the ABWQ delay. As this is IO and FS stuff, i really think it would make more sense to have a more reasonable delay (like 500ms or a second). From user perspective, they'll never notice this. But it means we can collect a tremendous amount more, and process and analyze the results in much larger batches for things like deduping and whatnot. TimeSpan.Zero is really for cases of "we are both going to getting an insane firehose of messages AND we must issue them immediately or else badness will occur". For disk notifications, the latter just doesn't apply here. No one will be harmed AFAICT if we wait 500ms.

@ToddGrun
Copy link
Contributor Author

ToddGrun commented Nov 8, 2024

In this PR, or in a followup, can you examine if TimeSpan.Zero is really a good idea for the ABWQ delay. As this is IO and FS stuff, i really think it would make more sense to have a more reasonable delay (like 500ms or a second). From user perspective, they'll never notice this. But it means we can collect a tremendous amount more, and process and analyze the results in much larger batches for things like deduping and whatnot. TimeSpan.Zero is really for cases of "we are both going to getting an insane firehose of messages AND we must issue them immediately or else badness will occur". For disk notifications, the latter just doesn't apply here. No one will be harmed AFAICT if we wait 500ms.

From local testing of open/close roslyn sln, I saw the following:

0 ms delay
2046 calls to ProcessBatchAsync
19942 total operations passed in
8502 merged batches created

100 ms
47 calls to ProcessBatchAsync
19942 total operations passed in
6972 merged batches created

500 ms
18 calls to ProcessBatchAsync
19942 total operations passed in
6518 merged batches created

@CyrusNajmabadi
Copy link
Member

Love it. This is also nice as we really do want to "back off" when notifications come in. They often come in in huge flurries, and we don't want to then be contending with the disk while we're being notified about chnages from other files. 500ms is a nice compromise.

Copy link
Member

@jasonmalinowski jasonmalinowski left a comment

Choose a reason for hiding this comment

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

I believe this breaks how the cookies have to get back to the original context for the directory watch, so later unsubscribes won't unsubscribe. I could be wrong, but we should really have a test either way that two directory watches combine, and you can successfully remove them later.

…issues with that approach.

However, we can still improve batching by changing the WatchDirectory callers to create fewer WatchedDirectory objects that instead specify multiple filters each.
@@ -367,8 +361,13 @@ public Context(FileChangeWatcher fileChangeWatcher, ImmutableArray<WatchedDirect

foreach (var watchedDirectory in watchedDirectories)
{
_fileChangeWatcher._taskQueue.AddWork(watchedDirectories.Select(
watchedDirectory => WatcherOperation.WatchDirectory(watchedDirectory.Path, watchedDirectory.ExtensionFilter, this, _directoryWatchCookies)));
var item = WatcherOperation.WatchDirectory(
Copy link
Contributor Author

Choose a reason for hiding this comment

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

var item = WatcherOperation.WatchDirectory(

Noticed there was a bug here in that every watched directory caused an operation to be created for the whole immutable array, not just for itself.

Copy link
Member

Choose a reason for hiding this comment

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

Good catch!

@ToddGrun
Copy link
Contributor Author

ToddGrun commented Nov 9, 2024

Backed out the watch directory merging, wasn't going to be easy to solve and found a different way to get some watcher reductions.


In reply to: 2424933376

Copy link
Member

@jasonmalinowski jasonmalinowski left a comment

Choose a reason for hiding this comment

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

Approved generally; there's one suspicious null check of an ImmutableArray which I think is harmless but might need a small change.

@@ -310,8 +305,8 @@ public async ValueTask ApplyAsync(IVsAsyncFileChangeEx2 service, CancellationTok
var cookie = await service.AdviseDirChangeAsync(_paths[0], watchSubdirectories: true, _sink, cancellationToken).ConfigureAwait(false);
_cookies.Add(cookie);

if (_filter != null)
await service.FilterDirectoryChangesAsync(cookie, [_filter], cancellationToken).ConfigureAwait(false);
if (_filters != null)
Copy link
Member

Choose a reason for hiding this comment

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

Did you meant to check for non-empty, not non-null/default if this is an ImmutableArray? I imagine this will work no matter what (FilterDirectoryChangesAsync says an empty array means no filter) but it's either an unnecessary call, or an unnecessary check.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

That was an oops when converting from a nullable type to an ImmutableArray. Good catch!

@@ -367,8 +361,13 @@ public Context(FileChangeWatcher fileChangeWatcher, ImmutableArray<WatchedDirect

foreach (var watchedDirectory in watchedDirectories)
{
_fileChangeWatcher._taskQueue.AddWork(watchedDirectories.Select(
watchedDirectory => WatcherOperation.WatchDirectory(watchedDirectory.Path, watchedDirectory.ExtensionFilter, this, _directoryWatchCookies)));
var item = WatcherOperation.WatchDirectory(
Copy link
Member

Choose a reason for hiding this comment

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

Good catch!

@ToddGrun
Copy link
Contributor Author

@jdrobison -- Is there any telemetry we can query to see how common the overflow case is compared to the amount of feedback we're getting that could be attributed to this? If overflow is fairly uncommon in the wild, that would increase the confidence that our recently introduced change would be addressing our customer issues.

I looked through the code handling the OS notification and wasn't sure if getting overflow frequency was easily queryable.

@jdrobison
Copy link
Contributor

Yes. The telemetry event is vs/filewatcher/internalbufferoverflow.

@ToddGrun
Copy link
Contributor Author

There are a bunch of hits for this. I'm not clear what sort of useful data I can get from the telemetry. @jdrobison -- is there guidance on how consumers of IVsFreeThreadedFileChangeEvents2 should be reacting to this? Is there anything that could be done at the platform level to reduce the likelihood of this further? I was able to hit this locally by having a debugger attached to VS and then doing some file modifications. I doubt that's the common reason for hitting this, but it might be good information to include in the telemetry.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Area-IDE untriaged Issues and PRs which have not yet been triaged by a lead VSCode
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants