dart-lang / sdk

The Dart SDK, including the VM, JS and Wasm compilers, analysis, core libraries, and more.
https://dart.dev
BSD 3-Clause "New" or "Revised" License
10.09k stars 1.56k forks source link

First analysis is much slower on Windows after a reboot (because of Windows Defender scanning files as they're read) #56755

Open DanTup opened 7 hours ago

DanTup commented 7 hours ago

There have been a few issues about the first analysis on Windows being really slow. Some have noted it's only the first time after a reboot, for example:

When it came up again recently I spent some time trying to reproduce it (I had in the past, but was failing recently) and discovered that in my Windows Defender settings, I had exclusions for:

When I removed those exclusions, I was able to reproduce 30+ seconds of initial analysis after a reboot (both via IDEs and dart analyze), with analysis being just a few seconds subsequently. It appears that the first read of a file is significantly slower due to scanning by Windows Defender and because the analysis server reads a lot of files (from .dartServer\.analysis-driver) synchronously (and sequentially), this has a big impact on the initial analysis time (after a reboot).

I was able to reproduce the same behaviour from a standalone script that just tries to read the same files that the analyzer ends up reading at startup:

import 'dart:io';
import 'files.dart'; // A list of 2760 files that exist in '.dartServer\.analysis-driver'

var totalBytes = 0;
var totalFiles = 0;

void main(List<String> arguments) {
  var sw = Stopwatch()..start();
  files.map(read).toList();
  print('Took ${sw.elapsed} to read $totalBytes bytes from $totalFiles files');
}

void read(String path) {
  totalBytes += File(path).readAsBytesSync().length;
  totalFiles++;
}

Results look like:

// First:
// Took 0:00:15.280430 to read 34865125 bytes from 2760 files
// Subsequent:
// Took 0:00:00.123502 to read 34865125 bytes from 2760 files
// Took 0:00:00.115271 to read 34865125 bytes from 2760 files
// Took 0:00:00.112667 to read 34865125 bytes from 2760 files

Dart generally discourages async IO but I was curious what the difference would be if we were able to trigger the reads all up-front simultaneously, so I wrote an equivalent script that uses async IO (and triggered readBytes all at the same time - although this is something that the analyzer is unlikely to be able to do):

import 'dart:io';
import 'files.dart';

var totalBytes = 0;
var totalFiles = 0;

Future<void> main(List<String> arguments) async {
  var sw = Stopwatch()..start();
  await Future.wait(files.map(readAsync));
  print('Took ${sw.elapsed} to read $totalBytes bytes from $totalFiles files');
}

Future<void> readAsync(String path) async {
  var bytes = (await File(path).readAsBytes()).length;
  totalBytes += bytes;
  totalFiles++;
}

The results are (perhaps unsurprisingly) much better that way:

// First:
// Took 0:00:01.142500 to read 34865125 bytes from 2760 files
// Subsequent:
// Took 0:00:00.156074 to read 34865125 bytes from 2760 files
// Took 0:00:00.160162 to read 34865125 bytes from 2760 files
// Took 0:00:00.158144 to read 34865125 bytes from 2760 files

Since changing sync->async isn't always easy, I also measured opening/closing all files asynchronously in advance of reading them all synchronously to see how that worked (this results in duplicate work but avoids changing the real "implementation" from sync):

import 'dart:io';
import 'files.dart';

var totalBytes = 0;
var totalFiles = 0;

Future<void> main(List<String> arguments) async {
  var sw = Stopwatch()..start();
  // Open and close every file 😬
  await Future.wait(files.map((path) async => (await File(path).open()).close()));
  // Original sync work
  files.map(read).toList();
  print('Took ${sw.elapsed} to read $totalBytes bytes from $totalFiles files');
}

void read(String path) {
  totalBytes += File(path).readAsBytesSync().length;
  totalFiles++;
}

The results looked like:

// First:
// Took 0:00:03.723306 to read 34865125 bytes from 2760 files
// Subsequent:
// Took 0:00:00.187244 to read 34865125 bytes from 2760 files
// Took 0:00:00.113760 to read 34865125 bytes from 2760 files
// Took 0:00:00.185479 to read 34865125 bytes from 2760 files

Given how the filenames are computed, I'm not sure if it's feasible to change anything in the analyzer to improve this, nor am I sure how worthwhile trying to solve this is (probably most Windows users are affected to some degree, but only the first time they open their projects after a reboot and the impact might depend on the specs of their machine and size of their workspace). I thought it was worth capturing this here though in case others have ideas, or at least as a summary that can be referenced by other issues that might be related.

(@bwilkerson @scheglov FYI)

parlough commented 6 hours ago

I'm not much of a Windows user, but outside of any changes to the analyzer, does the default configuration of Windows 11 Dev Drives make any difference here?

If so, should we be suggesting new devs install Dart/Flutter and store their projects in one?

DanTup commented 6 hours ago

does the default configuration of Windows 11 Dev Drives make any difference here?

Good question! I haven't tried using a Dev Drive yet.. when it was announced I couldn't find any details on what the security trade-offs were, but it seems there's more info now. It seems that the scanning may be asynchronous which certainly sounds like it would avoid these delays.

I guess I should set one up and do some testing - thanks for the reminder about this :-)

DanTup commented 5 hours ago

does the default configuration of Windows 11 Dev Drives make any difference here?

It made a huge difference. In my simple repro it's not quite as fast as the async version (it was 2s), but I tried the real world example too, and the initial analysis is down from ~30s to about 2-3s. It might be a reasonable recommendation, although it comes with the security caveats you link.

Unfortunately I don't know how easy it would be for people to move to.. A few things I noted while setting it up:

  1. You need to create a new volume... It turns out to be difficult to get Windows to shrink an existing volume on an SSD.. you can't defrag it and there are system files that may be near the end of a volume that prevent shrinking. I ended up deleting the usn journal with fsutil that got me 100GB to try this out, but that's not enough for my current Dev folder.
  2. Creating the dev drive failed for me with "Unable to format volume. Error: Cannot perform the requested operation when the drive is read-only (8)" I was able to do the format from a PoSh terminal with Format-Volume -DriveLetter D -DevDrive (where D was my drive letter) as noted here.
  3. Most of the affected files are outside of a users project in %LOCALAPPDATA%\.dartServer\analysis-driver I was overriding this folder when testing so it was also on the Dev Drive for my testing. You'd have to also set the PUB_CACHE and ANALYZER_STATE_LOCATION_OVERRIDE env variables to point to folders on the Dev Drive to get that benefit.

I also don't know if there is anything that can go wrong using it, but I'll try to sort out my size/space issues and move over to it fully to see if anything comes up.