diff --git a/eng/test-configuration.json b/eng/test-configuration.json index 3f5af7a1b766..2dd203e2ea05 100644 --- a/eng/test-configuration.json +++ b/eng/test-configuration.json @@ -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)"}}, diff --git a/src/Servers/Kestrel/Core/src/Internal/CertificatePathWatcher.cs b/src/Servers/Kestrel/Core/src/Internal/CertificatePathWatcher.cs index 7cb7234ac0a8..052255e1a343 100644 --- a/src/Servers/Kestrel/Core/src/Internal/CertificatePathWatcher.cs +++ b/src/Servers/Kestrel/Core/src/Internal/CertificatePathWatcher.cs @@ -29,9 +29,17 @@ internal sealed partial class CertificatePathWatcher : IDisposable public CertificatePathWatcher(IHostEnvironment hostEnvironment, ILogger 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, + UsePollingFileWatcher = true, + } + : null) { } @@ -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); } @@ -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 @@ -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; } @@ -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. @@ -321,7 +298,6 @@ private sealed class FileWatchMetadata(IDisposable disposable) : IDisposable { public readonly IDisposable Disposable = disposable; public readonly HashSet Configs = new(ReferenceEqualityComparer.Instance); - public DateTimeOffset LastModifiedTime = DateTimeOffset.MinValue; public void Dispose() => Disposable.Dispose(); } diff --git a/src/Servers/Kestrel/Core/src/Internal/CertificatePathWatcherLoggerExtensions.cs b/src/Servers/Kestrel/Core/src/Internal/CertificatePathWatcherLoggerExtensions.cs index d41543a342a6..53f1415d278b 100644 --- a/src/Servers/Kestrel/Core/src/Internal/CertificatePathWatcherLoggerExtensions.cs +++ b/src/Servers/Kestrel/Core/src/Internal/CertificatePathWatcherLoggerExtensions.cs @@ -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 logger, string path); - [LoggerMessage(10, LogLevel.Debug, "Ignored out-of-order event for file '{Path}'.", EventName = "OutOfOrderEvent")] - public static partial void OutOfOrderEvent(this ILogger 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 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 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 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 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 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 logger, string path); - - [LoggerMessage(17, LogLevel.Trace, "Ignored redundant event for '{Path}'.", EventName = "RedundantEvent")] - public static partial void RedundantEvent(this ILogger 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 logger, string path, int count); + + [LoggerMessage(16, LogLevel.Trace, "Ignored event since '{Path}' was unavailable.", EventName = "EventWithoutFile")] + public static partial void EventWithoutFile(this ILogger logger, string path); } diff --git a/src/Servers/Kestrel/Core/test/CertificatePathWatcherTests.cs b/src/Servers/Kestrel/Core/test/CertificatePathWatcherTests.cs index b4be5350f81c..60b1343ac8d5 100644 --- a/src/Servers/Kestrel/Core/test/CertificatePathWatcherTests.cs +++ b/src/Servers/Kestrel/Core/test/CertificatePathWatcherTests.cs @@ -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)); @@ -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] @@ -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(); @@ -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)); @@ -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] diff --git a/src/Servers/Kestrel/Kestrel/test/KestrelConfigurationLoaderTests.cs b/src/Servers/Kestrel/Kestrel/test/KestrelConfigurationLoaderTests.cs index 197128b72907..03265c68ebe9 100644 --- a/src/Servers/Kestrel/Kestrel/test/KestrelConfigurationLoaderTests.cs +++ b/src/Servers/Kestrel/Kestrel/test/KestrelConfigurationLoaderTests.cs @@ -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 { @@ -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("Endpoints:End1:Url", "https://*:5001"), + new KeyValuePair("Endpoints:End1:Certificate:Path", fileLink.FullName), + new KeyValuePair("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