From 4c49d5ce80f4515ac0549016822db04bbd647bb2 Mon Sep 17 00:00:00 2001 From: Nate McMaster Date: Tue, 2 Oct 2018 09:17:04 -0700 Subject: [PATCH] Resolve flaky tests (#497) 1. Prevent an ObjectDisposedException in dotnet-watch on slower machines 2. Fix flakiness caused by PID reuse 3. Fix flakiness in tests that await the restart of dotnet-watch. The `.TimeoutAfter` method doesn't cancel the long-running task. This left 2 readers running on dotnet-watch output which caused indeterminate test outcome. --- .../Internal/FileWatcher/DotnetFileWatcher.cs | 43 ++++++++++++++----- .../AwaitableProcess.cs | 27 +++++++----- .../DotNetWatcherTests.cs | 6 ++- .../GlobbingAppTests.cs | 5 ++- .../NoDepsAppTests.cs | 3 -- 5 files changed, 58 insertions(+), 26 deletions(-) diff --git a/src/dotnet-watch/Internal/FileWatcher/DotnetFileWatcher.cs b/src/dotnet-watch/Internal/FileWatcher/DotnetFileWatcher.cs index d1103c41e6..0372327819 100644 --- a/src/dotnet-watch/Internal/FileWatcher/DotnetFileWatcher.cs +++ b/src/dotnet-watch/Internal/FileWatcher/DotnetFileWatcher.cs @@ -10,6 +10,8 @@ namespace Microsoft.DotNet.Watcher.Internal { internal class DotnetFileWatcher : IFileSystemWatcher { + private volatile bool _disposed; + private readonly Func _watcherFactory; private FileSystemWatcher _fileSystemWatcher; @@ -46,6 +48,11 @@ namespace Microsoft.DotNet.Watcher.Internal private void WatcherErrorHandler(object sender, ErrorEventArgs e) { + if (_disposed) + { + return; + } + var exception = e.GetException(); // Win32Exception may be triggered when setting EnableRaisingEvents on a file system type @@ -62,6 +69,11 @@ namespace Microsoft.DotNet.Watcher.Internal private void WatcherRenameHandler(object sender, RenamedEventArgs e) { + if (_disposed) + { + return; + } + NotifyChange(e.OldFullPath); NotifyChange(e.FullPath); @@ -79,6 +91,11 @@ namespace Microsoft.DotNet.Watcher.Internal private void WatcherChangeHandler(object sender, FileSystemEventArgs e) { + if (_disposed) + { + return; + } + NotifyChange(e.FullPath); } @@ -98,15 +115,7 @@ namespace Microsoft.DotNet.Watcher.Internal { enableEvents = _fileSystemWatcher.EnableRaisingEvents; - _fileSystemWatcher.EnableRaisingEvents = false; - - _fileSystemWatcher.Created -= WatcherChangeHandler; - _fileSystemWatcher.Deleted -= WatcherChangeHandler; - _fileSystemWatcher.Changed -= WatcherChangeHandler; - _fileSystemWatcher.Renamed -= WatcherRenameHandler; - _fileSystemWatcher.Error -= WatcherErrorHandler; - - _fileSystemWatcher.Dispose(); + DisposeInnerWatcher(); } _fileSystemWatcher = _watcherFactory(BasePath); @@ -122,6 +131,19 @@ namespace Microsoft.DotNet.Watcher.Internal } } + private void DisposeInnerWatcher() + { + _fileSystemWatcher.EnableRaisingEvents = false; + + _fileSystemWatcher.Created -= WatcherChangeHandler; + _fileSystemWatcher.Deleted -= WatcherChangeHandler; + _fileSystemWatcher.Changed -= WatcherChangeHandler; + _fileSystemWatcher.Renamed -= WatcherRenameHandler; + _fileSystemWatcher.Error -= WatcherErrorHandler; + + _fileSystemWatcher.Dispose(); + } + public bool EnableRaisingEvents { get => _fileSystemWatcher.EnableRaisingEvents; @@ -130,7 +152,8 @@ namespace Microsoft.DotNet.Watcher.Internal public void Dispose() { - _fileSystemWatcher.Dispose(); + _disposed = true; + DisposeInnerWatcher(); } } } diff --git a/test/dotnet-watch.FunctionalTests/AwaitableProcess.cs b/test/dotnet-watch.FunctionalTests/AwaitableProcess.cs index 86e2f90f79..3e22d53245 100644 --- a/test/dotnet-watch.FunctionalTests/AwaitableProcess.cs +++ b/test/dotnet-watch.FunctionalTests/AwaitableProcess.cs @@ -4,9 +4,9 @@ using System; using System.Collections.Generic; using System.Diagnostics; +using System.Threading; using System.Threading.Tasks; using System.Threading.Tasks.Dataflow; -using Microsoft.AspNetCore.Testing; using Microsoft.Extensions.Internal; using Microsoft.Extensions.CommandLineUtils; using Xunit.Abstractions; @@ -80,25 +80,30 @@ namespace Microsoft.DotNet.Watcher.Tools.FunctionalTests public async Task GetOutputLineAsync(string message, TimeSpan timeout) { _logger.WriteLine($"Waiting for output line [msg == '{message}']. Will wait for {timeout.TotalSeconds} sec."); - return await GetOutputLineAsync(m => string.Equals(m, message, StringComparison.Ordinal)).TimeoutAfter(timeout); + var cts = new CancellationTokenSource(); + cts.CancelAfter(timeout); + return await GetOutputLineAsync($"[msg == '{message}']", m => string.Equals(m, message, StringComparison.Ordinal), cts.Token); } public async Task GetOutputLineStartsWithAsync(string message, TimeSpan timeout) { _logger.WriteLine($"Waiting for output line [msg.StartsWith('{message}')]. Will wait for {timeout.TotalSeconds} sec."); - return await GetOutputLineAsync(m => m != null && m.StartsWith(message, StringComparison.Ordinal)).TimeoutAfter(timeout); + var cts = new CancellationTokenSource(); + cts.CancelAfter(timeout); + return await GetOutputLineAsync($"[msg.StartsWith('{message}')]", m => m != null && m.StartsWith(message, StringComparison.Ordinal), cts.Token); } - private async Task GetOutputLineAsync(Predicate predicate) + private async Task GetOutputLineAsync(string predicateName, Predicate predicate, CancellationToken cancellationToken) { while (!_source.Completion.IsCompleted) { - while (await _source.OutputAvailableAsync()) + while (await _source.OutputAvailableAsync(cancellationToken)) { - var next = await _source.ReceiveAsync(); + var next = await _source.ReceiveAsync(cancellationToken); _lines.Add(next); - _logger.WriteLine($"{DateTime.Now}: recv: '{next}'"); - if (predicate(next)) + var match = predicate(next); + _logger.WriteLine($"{DateTime.Now}: recv: '{next}'. {(match ? "Matches" : "Does not match")} condition '{predicateName}'."); + if (match) { return next; } @@ -108,14 +113,14 @@ namespace Microsoft.DotNet.Watcher.Tools.FunctionalTests return null; } - public async Task> GetAllOutputLines() + public async Task> GetAllOutputLinesAsync(CancellationToken cancellationToken) { var lines = new List(); while (!_source.Completion.IsCompleted) { - while (await _source.OutputAvailableAsync()) + while (await _source.OutputAvailableAsync(cancellationToken)) { - var next = await _source.ReceiveAsync(); + var next = await _source.ReceiveAsync(cancellationToken); _logger.WriteLine($"{DateTime.Now}: recv: '{next}'"); lines.Add(next); } diff --git a/test/dotnet-watch.FunctionalTests/DotNetWatcherTests.cs b/test/dotnet-watch.FunctionalTests/DotNetWatcherTests.cs index 65ff6416e2..d31f650aa6 100644 --- a/test/dotnet-watch.FunctionalTests/DotNetWatcherTests.cs +++ b/test/dotnet-watch.FunctionalTests/DotNetWatcherTests.cs @@ -13,10 +13,12 @@ namespace Microsoft.DotNet.Watcher.Tools.FunctionalTests { public class DotNetWatcherTests : IDisposable { + private readonly ITestOutputHelper _logger; private readonly KitchenSinkApp _app; public DotNetWatcherTests(ITestOutputHelper logger) { + _logger = logger; _app = new KitchenSinkApp(logger); } @@ -52,8 +54,10 @@ namespace Microsoft.DotNet.Watcher.Tools.FunctionalTests File.SetLastWriteTime(source, DateTime.Now); await _app.HasRestarted(); } - catch + catch (Exception ex) { + _logger.WriteLine("Retrying. First attempt to restart app failed: " + ex.Message); + // retry File.SetLastWriteTime(source, DateTime.Now); await _app.HasRestarted(); diff --git a/test/dotnet-watch.FunctionalTests/GlobbingAppTests.cs b/test/dotnet-watch.FunctionalTests/GlobbingAppTests.cs index a01a28e7d8..3658261049 100644 --- a/test/dotnet-watch.FunctionalTests/GlobbingAppTests.cs +++ b/test/dotnet-watch.FunctionalTests/GlobbingAppTests.cs @@ -4,6 +4,7 @@ using System; using System.IO; using System.Linq; +using System.Threading; using System.Threading.Tasks; using Microsoft.DotNet.Watcher.Tools.Tests; using Xunit; @@ -101,7 +102,9 @@ namespace Microsoft.DotNet.Watcher.Tools.FunctionalTests { await _app.PrepareAsync(); _app.Start(new [] { "--list" }); - var lines = await _app.Process.GetAllOutputLines(); + var cts = new CancellationTokenSource(); + cts.CancelAfter(TimeSpan.FromSeconds(30)); + var lines = await _app.Process.GetAllOutputLinesAsync(cts.Token); var files = lines.Where(l => !l.StartsWith("watch :")); AssertEx.EqualFileList( diff --git a/test/dotnet-watch.FunctionalTests/NoDepsAppTests.cs b/test/dotnet-watch.FunctionalTests/NoDepsAppTests.cs index 55d0441552..d1eead9048 100644 --- a/test/dotnet-watch.FunctionalTests/NoDepsAppTests.cs +++ b/test/dotnet-watch.FunctionalTests/NoDepsAppTests.cs @@ -39,9 +39,6 @@ namespace Microsoft.DotNet.Watcher.Tools.FunctionalTests var pid2 = await _app.GetProcessId(); Assert.NotEqual(pid, pid2); - - // first app should have shut down - Assert.Throws(() => Process.GetProcessById(pid)); } [Fact]