Skip to content

Use polling to watch certificate paths #50251

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

Merged
merged 7 commits into from
Aug 24, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions eng/test-configuration.json
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@
{"testName": {"contains": "HEADERS_Received_SecondRequest_ConnectProtocolReset"}},
{"testName": {"contains": "ClientUsingOldCallWithNewProtocol"}},
{"testName": {"contains": "CertificateChangedOnDisk"}},
{"testName": {"contains": "CertificateChangedOnDisk_Symlink"}},
{"testAssembly": {"contains": "IIS"}},
{"testAssembly": {"contains": "Template"}},
{"failureMessage": {"contains":"(Site is started but no worker process found)"}},
Expand Down
60 changes: 18 additions & 42 deletions src/Servers/Kestrel/Core/src/Internal/CertificatePathWatcher.cs
Original file line number Diff line number Diff line change
Expand Up @@ -29,9 +29,17 @@ internal sealed partial class CertificatePathWatcher : IDisposable

public CertificatePathWatcher(IHostEnvironment hostEnvironment, ILogger<CertificatePathWatcher> logger)
: this(
hostEnvironment.ContentRootPath,
logger,
dir => Directory.Exists(dir) ? new PhysicalFileProvider(dir, ExclusionFilters.None) : null)
hostEnvironment.ContentRootPath,
logger,
dir => Directory.Exists(dir)
? new PhysicalFileProvider(dir, ExclusionFilters.None)
{
// Force polling because it monitors both symlinks and their targets,
// whereas the non-polling watcher only monitors the symlinks themselves
UseActivePolling = true,
Copy link
Member

Choose a reason for hiding this comment

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

Do we know the performance impact of always doing this?

Copy link
Member Author

Choose a reason for hiding this comment

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

How many certs do we expect an app to have? I was assuming < 10. We only poll every four seconds, so I was expecting the CPU usage to be negligible. If the certs aren't all in the same directory, then there will likely be some overhead from having multiple timer loops.

I think a lot of apps would be fine with a longer polling period, but I don't actually see a way to configure it.

If an app has 100 certs, each in a different directory and they find the overhead is too high, there's an appcontext switch to disable watching certificates.

Copy link
Member

Choose a reason for hiding this comment

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

Polling isn't on by default (for the IHostingEnvironment.ContentRootFileProvider), I'm not sure it's about the number of apps, it might be the number of files being polled in the common case. Is this just polling the path specified by the cert in the 90% scenario?

Copy link
Member Author

Choose a reason for hiding this comment

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

Sorry, I'm not sure I understand the question. This change should have no effect on whether or not IHostingEnvironment.ContentRootFileProvider uses polling. It instantiates PhysicalFileProviders directly for paths to certificates and enables polling for those specifically.

You've previously pointed out that that's wrong, that certificates should be watched using the host env file provider. There are two reasons I didn't do that: first, the users requesting this functionality made clear that they wanted to be able to load and watch certificates that were not under their content root; second, I didn't want to enable polling for all files in the content root because I was worried about the perf (and respecting user settings).

Copy link
Member

@davidfowl davidfowl Aug 29, 2023

Choose a reason for hiding this comment

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

My point is that this change always turns on file watching no matter what. That’s not something we’ve tested before. I just wanted to understand the scope and impact of the polling.

Copy link
Member Author

Choose a reason for hiding this comment

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

If ReloadOnChange is true, then we will poll files in your (non-code) configuration for the default certificate and for each endpoint's certificate and SNI certificates. Obviously, this only applies to file-based certs (vs from the store). If the same certificate file appears in more than one of those locations, it will only be polled once. (There's a corner case where two different symlinks point to the same file, in which case it would be polled twice.)

UsePollingFileWatcher = true,
}
: null)
{
}

Expand Down Expand Up @@ -138,9 +146,6 @@ internal void AddWatchUnsynchronized(CertificateConfig certificateConfig)
_metadataForFile.Add(path, fileMetadata);
dirMetadata.FileWatchCount++;

// We actually don't care if the file doesn't exist - we'll watch in case it is created
fileMetadata.LastModifiedTime = GetLastModifiedTimeOrMinimum(path, dirMetadata.FileProvider);

_logger.CreatedFileWatcher(path);
}

Expand All @@ -156,20 +161,6 @@ internal void AddWatchUnsynchronized(CertificateConfig certificateConfig)
_logger.FileCount(dir, dirMetadata.FileWatchCount);
}

private DateTimeOffset GetLastModifiedTimeOrMinimum(string path, IFileProvider fileProvider)
{
try
{
return fileProvider.GetFileInfo(Path.GetFileName(path)).LastModified;
}
catch (Exception e)
{
_logger.LastModifiedTimeError(path, e);
}

return DateTimeOffset.MinValue;
}

private void OnChange(string path)
{
// Block until any in-progress updates are complete
Expand All @@ -184,33 +175,17 @@ private void OnChange(string path)
// Existence implied by the fact that we're tracking the file
var dirMetadata = _metadataForDirectory[Path.GetDirectoryName(path)!];

// We ignore file changes that don't advance the last modified time.
// We ignore file changes that result in a file becoming unavailable.
// For example, if we lose access to the network share the file is
// stored on, we don't notify our listeners because no one wants
// their endpoint/server to shutdown when that happens.
// We also anticipate that a cert file might be renamed to cert.bak
// before a new cert is introduced with the old name.
// This also helps us in scenarios where the underlying file system
// reports more than one change for a single logical operation.
var lastModifiedTime = GetLastModifiedTimeOrMinimum(path, dirMetadata.FileProvider);
if (lastModifiedTime > fileMetadata.LastModifiedTime)
{
fileMetadata.LastModifiedTime = lastModifiedTime;
}
else

var fileInfo = dirMetadata.FileProvider.GetFileInfo(Path.GetFileName(path));
if (!fileInfo.Exists)
{
if (lastModifiedTime == DateTimeOffset.MinValue)
{
_logger.EventWithoutLastModifiedTime(path);
}
else if (lastModifiedTime == fileMetadata.LastModifiedTime)
{
_logger.RedundantEvent(path);
}
else
{
_logger.OutOfOrderEvent(path);
}
_logger.EventWithoutFile(path);
return;
}

Expand All @@ -219,6 +194,8 @@ private void OnChange(string path)
{
config.FileHasChanged = true;
}

_logger.FlaggedObservers(path, configs.Count);
}

// AddWatch and RemoveWatch don't affect the token, so this doesn't need to be under the semaphore.
Expand Down Expand Up @@ -321,7 +298,6 @@ private sealed class FileWatchMetadata(IDisposable disposable) : IDisposable
{
public readonly IDisposable Disposable = disposable;
public readonly HashSet<CertificateConfig> Configs = new(ReferenceEqualityComparer.Instance);
public DateTimeOffset LastModifiedTime = DateTimeOffset.MinValue;

public void Dispose() => Disposable.Dispose();
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -34,30 +34,24 @@ internal static partial class CertificatePathWatcherLoggerExtensions
[LoggerMessage(9, LogLevel.Debug, "Ignored event for presently untracked file '{Path}'.", EventName = "UntrackedFileEvent")]
public static partial void UntrackedFileEvent(this ILogger<CertificatePathWatcher> logger, string path);

[LoggerMessage(10, LogLevel.Debug, "Ignored out-of-order event for file '{Path}'.", EventName = "OutOfOrderEvent")]
public static partial void OutOfOrderEvent(this ILogger<CertificatePathWatcher> logger, string path);

[LoggerMessage(11, LogLevel.Trace, "Reused existing observer on file watcher for '{Path}'.", EventName = "ReusedObserver")]
[LoggerMessage(10, LogLevel.Trace, "Reused existing observer on file watcher for '{Path}'.", EventName = "ReusedObserver")]
public static partial void ReusedObserver(this ILogger<CertificatePathWatcher> logger, string path);

[LoggerMessage(12, LogLevel.Trace, "Added observer to file watcher for '{Path}'.", EventName = "AddedObserver")]
[LoggerMessage(11, LogLevel.Trace, "Added observer to file watcher for '{Path}'.", EventName = "AddedObserver")]
public static partial void AddedObserver(this ILogger<CertificatePathWatcher> logger, string path);

[LoggerMessage(13, LogLevel.Trace, "Removed observer from file watcher for '{Path}'.", EventName = "RemovedObserver")]
[LoggerMessage(12, LogLevel.Trace, "Removed observer from file watcher for '{Path}'.", EventName = "RemovedObserver")]
public static partial void RemovedObserver(this ILogger<CertificatePathWatcher> logger, string path);

[LoggerMessage(14, LogLevel.Trace, "File '{Path}' now has {Count} observers.", EventName = "ObserverCount")]
[LoggerMessage(13, LogLevel.Trace, "File '{Path}' now has {Count} observers.", EventName = "ObserverCount")]
public static partial void ObserverCount(this ILogger<CertificatePathWatcher> logger, string path, int count);

[LoggerMessage(15, LogLevel.Trace, "Directory '{Directory}' now has watchers on {Count} files.", EventName = "FileCount")]
[LoggerMessage(14, LogLevel.Trace, "Directory '{Directory}' now has watchers on {Count} files.", EventName = "FileCount")]
public static partial void FileCount(this ILogger<CertificatePathWatcher> logger, string directory, int count);

[LoggerMessage(16, LogLevel.Trace, "Ignored event since last modified time for '{Path}' was unavailable.", EventName = "EventWithoutLastModifiedTime")]
public static partial void EventWithoutLastModifiedTime(this ILogger<CertificatePathWatcher> logger, string path);

[LoggerMessage(17, LogLevel.Trace, "Ignored redundant event for '{Path}'.", EventName = "RedundantEvent")]
public static partial void RedundantEvent(this ILogger<CertificatePathWatcher> logger, string path);

[LoggerMessage(18, LogLevel.Trace, "Flagged {Count} observers of '{Path}' as changed.", EventName = "FlaggedObservers")]
[LoggerMessage(15, LogLevel.Trace, "Flagged {Count} observers of '{Path}' as changed.", EventName = "FlaggedObservers")]
public static partial void FlaggedObservers(this ILogger<CertificatePathWatcher> logger, string path, int count);

[LoggerMessage(16, LogLevel.Trace, "Ignored event since '{Path}' was unavailable.", EventName = "EventWithoutFile")]
public static partial void EventWithoutFile(this ILogger<CertificatePathWatcher> logger, string path);
}
49 changes: 11 additions & 38 deletions src/Servers/Kestrel/Core/test/CertificatePathWatcherTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -187,17 +187,10 @@ public async Task OutOfOrderLastModifiedTime()

watcher.AddWatchUnsynchronized(certificateConfig);

var logTcs = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);

TestSink.MessageLogged += writeContext =>
{
if (writeContext.EventId.Name == "OutOfOrderEvent")
{
logTcs.SetResult();
}
};
var signalTcs = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);

var oldChangeToken = watcher.GetChangeToken();
oldChangeToken.RegisterChangeCallback(_ => signalTcs.SetResult(), state: null);

Assert.Equal(1, watcher.TestGetDirectoryWatchCountUnsynchronized());
Assert.Equal(1, watcher.TestGetFileWatchCountUnsynchronized(dir));
Expand All @@ -207,9 +200,9 @@ public async Task OutOfOrderLastModifiedTime()
fileProvider.SetLastModifiedTime(fileName, fileLastModifiedTime.AddSeconds(-1));
fileProvider.FireChangeToken(fileName);

await logTcs.Task.DefaultTimeout();
await signalTcs.Task.DefaultTimeout();

Assert.False(oldChangeToken.HasChanged);
Assert.True(oldChangeToken.HasChanged);
}

[Fact]
Expand Down Expand Up @@ -342,12 +335,10 @@ public void ReuseFileObserver()
}

[Theory]
[InlineData(true, true)]
[InlineData(true, false)]
[InlineData(false, true)]
[InlineData(false, false)]
[InlineData(true)]
[InlineData(false)]
[LogLevel(LogLevel.Trace)]
public async Task IgnoreDeletion(bool seeChangeForDeletion, bool restoredWithNewerLastModifiedTime)
public async Task IgnoreDeletion(bool restoredWithNewerLastModifiedTime)
{
var dir = Directory.GetCurrentDirectory();
var fileName = Path.GetRandomFileName();
Expand Down Expand Up @@ -377,30 +368,21 @@ public async Task IgnoreDeletion(bool seeChangeForDeletion, bool restoredWithNew
watcher.GetChangeToken().RegisterChangeCallback(_ => changeTcs.SetResult(), state: null);

var logNoLastModifiedTcs = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);
var logSameLastModifiedTcs = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);

TestSink.MessageLogged += writeContext =>
{
if (writeContext.EventId.Name == "EventWithoutLastModifiedTime")
if (writeContext.EventId.Name == "EventWithoutFile")
{
logNoLastModifiedTcs.SetResult();
}
else if (writeContext.EventId.Name == "RedundantEvent")
{
logSameLastModifiedTcs.SetResult();
}
};

// Simulate file deletion
fileProvider.SetLastModifiedTime(fileName, null);

// In some file systems and watch modes, there's no event when (e.g.) the directory containing the watched file is deleted
if (seeChangeForDeletion)
{
fileProvider.FireChangeToken(fileName);
fileProvider.FireChangeToken(fileName);

await logNoLastModifiedTcs.Task.DefaultTimeout();
}
await logNoLastModifiedTcs.Task.DefaultTimeout();

Assert.Equal(1, watcher.TestGetDirectoryWatchCountUnsynchronized());
Assert.Equal(1, watcher.TestGetFileWatchCountUnsynchronized(dir));
Expand All @@ -412,16 +394,7 @@ public async Task IgnoreDeletion(bool seeChangeForDeletion, bool restoredWithNew
fileProvider.SetLastModifiedTime(fileName, restoredWithNewerLastModifiedTime ? fileLastModifiedTime.AddSeconds(1) : fileLastModifiedTime);
fileProvider.FireChangeToken(fileName);

if (restoredWithNewerLastModifiedTime)
{
await changeTcs.Task.DefaultTimeout();
Assert.False(logSameLastModifiedTcs.Task.IsCompleted);
}
else
{
await logSameLastModifiedTcs.Task.DefaultTimeout();
Assert.False(changeTcs.Task.IsCompleted);
}
await changeTcs.Task.DefaultTimeout();
}

[Fact]
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -894,7 +894,7 @@ public async Task CertificateChangedOnDisk(bool reloadOnChange)

if (reloadOnChange)
{
await fileTcs.Task.DefaultTimeout();
await fileTcs.Task.TimeoutAfter(TimeSpan.FromSeconds(10)); // Needs to be meaningfully longer than the polling period - 4 seconds
}
else
{
Expand Down Expand Up @@ -922,6 +922,94 @@ public async Task CertificateChangedOnDisk(bool reloadOnChange)
}
}

[ConditionalFact]
[OSSkipCondition(OperatingSystems.Windows)] // Windows has poor support for directory symlinks (e.g. https://github.com/dotnet/runtime/issues/27826)
public async Task CertificateChangedOnDisk_Symlink()
{
var tempDir = Directory.CreateTempSubdirectory().FullName;

try
{
// temp/
// tls.key -> link/tls.key
// link/ -> old/
// old/
// tls.key
// new/
// tls.key

var oldDir = Directory.CreateDirectory(Path.Combine(tempDir, "old"));
var newDir = Directory.CreateDirectory(Path.Combine(tempDir, "new"));
var oldCertPath = Path.Combine(oldDir.FullName, "tls.key");
var newCertPath = Path.Combine(newDir.FullName, "tls.key");

var dirLink = Directory.CreateSymbolicLink(Path.Combine(tempDir, "link"), "./old");
var fileLink = File.CreateSymbolicLink(Path.Combine(tempDir, "tls.key"), "./link/tls.key");

var serverOptions = CreateServerOptions();

var certificatePassword = "1234";

var oldCertificate = new X509Certificate2(TestResources.GetCertPath("aspnetdevcert.pfx"), "testPassword", X509KeyStorageFlags.Exportable);
var oldCertificateBytes = oldCertificate.Export(X509ContentType.Pkcs12, certificatePassword);

File.WriteAllBytes(oldCertPath, oldCertificateBytes);

var newCertificate = new X509Certificate2(TestResources.TestCertificatePath, "testPassword", X509KeyStorageFlags.Exportable);
var newCertificateBytes = newCertificate.Export(X509ContentType.Pkcs12, certificatePassword);

File.WriteAllBytes(newCertPath, newCertificateBytes);

var endpointConfigurationCallCount = 0;
var config = new ConfigurationBuilder().AddInMemoryCollection(new[]
{
new KeyValuePair<string, string>("Endpoints:End1:Url", "https://*:5001"),
new KeyValuePair<string, string>("Endpoints:End1:Certificate:Path", fileLink.FullName),
new KeyValuePair<string, string>("Endpoints:End1:Certificate:Password", certificatePassword),
}).Build();

var configLoader = serverOptions
.Configure(config, reloadOnChange: true)
.Endpoint("End1", opt =>
{
Assert.True(opt.IsHttps);
var expectedSerialNumber = endpointConfigurationCallCount == 0
? oldCertificate.SerialNumber
: newCertificate.SerialNumber;
Assert.Equal(opt.HttpsOptions.ServerCertificate.SerialNumber, expectedSerialNumber);
endpointConfigurationCallCount++;
});

configLoader.Load();

var fileTcs = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);

configLoader.GetReloadToken().RegisterChangeCallback(_ => fileTcs.SetResult(), state: null);

// Clobber link/ directory symlink - this will effectively cause the cert to be updated.
// Unfortunately, it throws (file exists) if we don't delete the old one first so it's not a single, clean FS operation.
dirLink.Delete();
dirLink = Directory.CreateSymbolicLink(Path.Combine(tempDir, "link"), "./new");

// This can fail in local runs where the timeout is 5 seconds and polling period is 4 seconds - just re-run
await fileTcs.Task.DefaultTimeout();

Assert.Equal(1, endpointConfigurationCallCount);

configLoader.Reload();

Assert.Equal(2, endpointConfigurationCallCount);
}
finally
{
if (Directory.Exists(tempDir))
{
// Note: the watcher will see this event, but we ignore deletions, so it shouldn't matter
Directory.Delete(tempDir, recursive: true);
}
}
}

[ConditionalTheory]
[InlineData("http1", HttpProtocols.Http1)]
// [InlineData("http2", HttpProtocols.Http2)] // Not supported due to missing ALPN support. https://github.com/dotnet/corefx/issues/33016
Expand Down