Using FileWatcher on non-windows has a very large impact on startup time #42036
Description
Related to dotnet/aspnetcore#20488
I did some investigation about some startup cost of the filewatching we set up by default. What I found may shock you. In the case that I'm measuring on macOS - the impact of first call to IFileProvider.Watch() is 100ms in wall clock time.
Background
Some background...
One of the features of IFileProvider is that it implements globbing in a non-OS-native way. So IFileProvider implements file system globbing /**/*.cshtml which is separate from what the underlying OS does. IFileProvider also implements file-watching, and since you have mix globbing (not implemented by the OS) and file watching (implemented by the OS) it uses a big hammer to implement this. When Watch is called, IFileProvider will watch the entire directory hierarchy it has access to, and will do the filtering of notifications based on the globbing feature.
On windows watching a directory tree maps directly to the Win32 API FindFirstChangeNotification or ReadDirectoryChanges. So watching a directory and it's subdirectories is implemented by the OS directly, and it takes one call from .NET -> native to set this up.
On Linux, there isn't an API for recursive subdirectory watching, the filewatcher code has to walk the directory hierarchy and register a watch on each subdirectory.
On macOS there is an API for recursive file watching. So it's not totally clear why it's taking 100ms.
How I'm measuring
I wrote the following test code:
using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.IO;
using System.Linq;
using System.Threading.Tasks;
using Microsoft.AspNetCore.Hosting;
using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.FileProviders;
using Microsoft.Extensions.Hosting;
using Microsoft.Extensions.Logging;
namespace startupexperiment
{
public class Program
{
public static async Task Main(string[] args)
{
if (args.Contains("--empty"))
{
var stopwatch = Stopwatch.StartNew();
using (var host = CreateEmptyHostBuilder(args).Build())
{
await host.StartAsync();
Console.WriteLine($"Empty Elapsed: {stopwatch.ElapsedMilliseconds}ms");
await host.StopAsync();
}
}
else if (args.Contains("--watch"))
{
var stopwatch = Stopwatch.StartNew();
using (var host = CreateEmptyHostBuilder(args).Build())
{
await host.StartAsync();
var provider = host.Services.GetRequiredService<IHostEnvironment>().ContentRootFileProvider;
provider.Watch("appsettings.json");
Console.WriteLine($"Manual Elapsed: {stopwatch.ElapsedMilliseconds}ms");
await host.StopAsync();
}
}
else if (args.Contains("--manual"))
{
var stopwatch = Stopwatch.StartNew();
using (var host = CreateEmptyHostBuilder(args).Build())
{
await host.StartAsync();
var provider = host.Services.GetRequiredService<IHostEnvironment>().ContentRootFileProvider;
var watcher = new FileSystemWatcher(((PhysicalFileProvider)provider).Root, "appsettings.json");
watcher.EnableRaisingEvents = true;
Console.WriteLine($"Manual Elapsed: {stopwatch.ElapsedMilliseconds}ms");
await host.StopAsync();
}
}
else
{
var stopwatch = Stopwatch.StartNew();
using (var host = CreateHostBuilderDefault(args).Build())
{
await host.StartAsync();
Console.WriteLine($"Default Elapsed: {stopwatch.ElapsedMilliseconds}ms");
await host.StopAsync();
}
}
}
public static IHostBuilder CreateHostBuilderDefault(string[] args) =>
Host.CreateDefaultBuilder(args)
.ConfigureWebHostDefaults(webBuilder =>
{
webBuilder.UseStartup<Startup>();
});
public static IHostBuilder CreateEmptyHostBuilder(string[] args) =>
new HostBuilder().ConfigureWebHostDefaults(webBuilder =>
{
webBuilder.UseStartup<Startup>();
});
}
}Publishing this with -c Release and then running it repeatedly yields pretty consistent results with a variation of about ~10ms. This is measured with the MVC template, which has some files to watch. Note that I'm doing a publish so that we're measuring all of the files that need to be in the app's output, not measuring obj/.
Results on macOS
| Scenario | Approx Time (ms) | Description |
|---|---|---|
| Default | 410 ms | Uses CreateDefaultHost (default experience users get) |
| --watch | 365 ms | Uses new HostBuilder() and a single call to IFileProvider.Watch |
| --manual | 365 ms | Uses new HostBuilder() and FileSystemWatcher |
| --empty | 275 ms | Uses new HostBuilder() no configuration files or file watching |
Next Steps
My next step here is to retake these measurements on Linux. We care a little bit more about Linux as a production scenario.
I can measure that this is pretty slow on macOS, but it's not slow for the reasons I expected. Using FileSystemWatcher and IFileProvider.Watch had the same result.