From 6272b3625eb127d5d6ca248f34facba9bd7016a4 Mon Sep 17 00:00:00 2001 From: Nate McMaster Date: Mon, 14 May 2018 14:17:27 -0700 Subject: [PATCH] Dispatch cancellation on CTRL+C to avoid deadlocks in killing the process tree --- shared/CliContext.cs | 9 ++-- src/dotnet-watch/DotNetWatcher.cs | 4 +- src/dotnet-watch/Internal/ProcessRunner.cs | 50 +++++++++++++------ src/dotnet-watch/Program.cs | 3 +- .../AwaitableProcess.cs | 25 ++++++++-- .../GlobbingAppTests.cs | 3 +- .../NoDepsAppTests.cs | 28 +++++++++++ .../Scenario/ProjectToolScenario.cs | 4 +- test/dotnet-watch.Tests/ProgramTests.cs | 22 ++++---- 9 files changed, 109 insertions(+), 39 deletions(-) diff --git a/shared/CliContext.cs b/shared/CliContext.cs index ad766a2e3b..854ea0fef6 100644 --- a/shared/CliContext.cs +++ b/shared/CliContext.cs @@ -1,4 +1,4 @@ -// Copyright (c) .NET Foundation. All rights reserved. +// Copyright (c) .NET Foundation. All rights reserved. // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. using System; @@ -8,14 +8,13 @@ namespace Microsoft.Extensions.Tools.Internal public static class CliContext { /// - /// dotnet --verbose subcommand + /// dotnet -d|--diagnostics subcommand /// /// public static bool IsGlobalVerbose() { - bool globalVerbose; - bool.TryParse(Environment.GetEnvironmentVariable("DOTNET_CLI_CONTEXT_VERBOSE"), out globalVerbose); + bool.TryParse(Environment.GetEnvironmentVariable("DOTNET_CLI_CONTEXT_VERBOSE"), out bool globalVerbose); return globalVerbose; } } -} \ No newline at end of file +} diff --git a/src/dotnet-watch/DotNetWatcher.cs b/src/dotnet-watch/DotNetWatcher.cs index f4b0423511..476acfcb43 100644 --- a/src/dotnet-watch/DotNetWatcher.cs +++ b/src/dotnet-watch/DotNetWatcher.cs @@ -69,8 +69,10 @@ namespace Microsoft.DotNet.Watcher await Task.WhenAll(processTask, fileSetTask); - if (processTask.Result != 0 && finishedTask == processTask) + if (processTask.Result != 0 && finishedTask == processTask && !cancellationToken.IsCancellationRequested) { + // Only show this error message if the process exited non-zero due to a normal process exit. + // Don't show this if dotnet-watch killed the inner process due to file change or CTRL+C by the user _reporter.Error($"Exited with error code {processTask.Result}"); } else diff --git a/src/dotnet-watch/Internal/ProcessRunner.cs b/src/dotnet-watch/Internal/ProcessRunner.cs index a5f7cac8ef..bbded25611 100644 --- a/src/dotnet-watch/Internal/ProcessRunner.cs +++ b/src/dotnet-watch/Internal/ProcessRunner.cs @@ -1,4 +1,4 @@ -// Copyright (c) .NET Foundation. All rights reserved. +// Copyright (c) .NET Foundation. All rights reserved. // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. using System; @@ -33,7 +33,7 @@ namespace Microsoft.DotNet.Watcher.Internal var stopwatch = new Stopwatch(); using (var process = CreateProcess(processSpec)) - using (var processState = new ProcessState(process)) + using (var processState = new ProcessState(process, _reporter)) { cancellationToken.Register(() => processState.TryKill()); @@ -97,27 +97,36 @@ namespace Microsoft.DotNet.Watcher.Internal private class ProcessState : IDisposable { + private readonly IReporter _reporter; private readonly Process _process; private readonly TaskCompletionSource _tcs = new TaskCompletionSource(); private volatile bool _disposed; - public ProcessState(Process process) + public ProcessState(Process process, IReporter reporter) { + _reporter = reporter; _process = process; _process.Exited += OnExited; Task = _tcs.Task.ContinueWith(_ => { - // We need to use two WaitForExit calls to ensure that all of the output/events are processed. Previously - // this code used Process.Exited, which could result in us missing some output due to the ordering of - // events. - // - // See the remarks here: https://docs.microsoft.com/en-us/dotnet/api/system.diagnostics.process.waitforexit#System_Diagnostics_Process_WaitForExit_System_Int32_ - if (!process.WaitForExit(Int32.MaxValue)) + try { - throw new TimeoutException(); - } + // We need to use two WaitForExit calls to ensure that all of the output/events are processed. Previously + // this code used Process.Exited, which could result in us missing some output due to the ordering of + // events. + // + // See the remarks here: https://docs.microsoft.com/en-us/dotnet/api/system.diagnostics.process.waitforexit#System_Diagnostics_Process_WaitForExit_System_Int32_ + if (!_process.WaitForExit(Int32.MaxValue)) + { + throw new TimeoutException(); + } - process.WaitForExit(); + _process.WaitForExit(); + } + catch (InvalidOperationException) + { + // suppress if this throws if no process is associated with this object anymore. + } }); } @@ -125,15 +134,26 @@ namespace Microsoft.DotNet.Watcher.Internal public void TryKill() { + if (_disposed) + { + return; + } + try { if (!_process.HasExited) { + _reporter.Verbose($"Killing process {_process.Id}"); _process.KillTree(); } } - catch - { } + catch (Exception ex) + { + _reporter.Verbose($"Error while killing process '{_process.StartInfo.FileName} {_process.StartInfo.Arguments}': {ex.Message}"); +#if DEBUG + _reporter.Verbose(ex.ToString()); +#endif + } } private void OnExited(object sender, EventArgs args) @@ -143,8 +163,8 @@ namespace Microsoft.DotNet.Watcher.Internal { if (!_disposed) { - _disposed = true; TryKill(); + _disposed = true; _process.Exited -= OnExited; _process.Dispose(); } diff --git a/src/dotnet-watch/Program.cs b/src/dotnet-watch/Program.cs index 7e8200b102..3ef376d048 100644 --- a/src/dotnet-watch/Program.cs +++ b/src/dotnet-watch/Program.cs @@ -121,7 +121,8 @@ namespace Microsoft.DotNet.Watcher _reporter.Output("Shutdown requested. Press Ctrl+C again to force exit."); } - _cts.Cancel(); + // Invoke the cancellation on the default thread pool to workaround https://github.com/dotnet/corefx/issues/29699 + ThreadPool.QueueUserWorkItem(_ => _cts.Cancel()); } private async Task MainInternalAsync( diff --git a/test/dotnet-watch.FunctionalTests/AwaitableProcess.cs b/test/dotnet-watch.FunctionalTests/AwaitableProcess.cs index 91b53133eb..86e2f90f79 100644 --- a/test/dotnet-watch.FunctionalTests/AwaitableProcess.cs +++ b/test/dotnet-watch.FunctionalTests/AwaitableProcess.cs @@ -1,4 +1,4 @@ -// Copyright (c) .NET Foundation. All rights reserved. +// Copyright (c) .NET Foundation. All rights reserved. // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. using System; @@ -17,16 +17,26 @@ namespace Microsoft.DotNet.Watcher.Tools.FunctionalTests { private Process _process; private readonly ProcessSpec _spec; + private readonly List _lines; private BufferBlock _source; private ITestOutputHelper _logger; + private TaskCompletionSource _exited; public AwaitableProcess(ProcessSpec spec, ITestOutputHelper logger) { _spec = spec; _logger = logger; _source = new BufferBlock(); + _lines = new List(); + _exited = new TaskCompletionSource(); } + public IEnumerable Output => _lines; + + public Task Exited => _exited.Task; + + public int Id => _process.Id; + public void Start() { if (_process != null) @@ -52,6 +62,11 @@ namespace Microsoft.DotNet.Watcher.Tools.FunctionalTests } }; + foreach (var env in _spec.EnvironmentVariables) + { + _process.StartInfo.EnvironmentVariables[env.Key] = env.Value; + } + _process.OutputDataReceived += OnData; _process.ErrorDataReceived += OnData; _process.Exited += OnExit; @@ -65,13 +80,13 @@ 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 => message == m).TimeoutAfter(timeout); + return await GetOutputLineAsync(m => string.Equals(m, message, StringComparison.Ordinal)).TimeoutAfter(timeout); } 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.StartsWith(message)).TimeoutAfter(timeout); + return await GetOutputLineAsync(m => m != null && m.StartsWith(message, StringComparison.Ordinal)).TimeoutAfter(timeout); } private async Task GetOutputLineAsync(Predicate predicate) @@ -81,6 +96,7 @@ namespace Microsoft.DotNet.Watcher.Tools.FunctionalTests while (await _source.OutputAvailableAsync()) { var next = await _source.ReceiveAsync(); + _lines.Add(next); _logger.WriteLine($"{DateTime.Now}: recv: '{next}'"); if (predicate(next)) { @@ -119,6 +135,8 @@ namespace Microsoft.DotNet.Watcher.Tools.FunctionalTests // Wait to ensure the process has exited and all output consumed _process.WaitForExit(); _source.Complete(); + _exited.TrySetResult(_process.ExitCode); + _logger.WriteLine($"Process {_process.Id} has exited"); } public void Dispose() @@ -135,6 +153,7 @@ namespace Microsoft.DotNet.Watcher.Tools.FunctionalTests _process.ErrorDataReceived -= OnData; _process.OutputDataReceived -= OnData; _process.Exited -= OnExit; + _process.Dispose(); } } } diff --git a/test/dotnet-watch.FunctionalTests/GlobbingAppTests.cs b/test/dotnet-watch.FunctionalTests/GlobbingAppTests.cs index 71b5d068bf..a01a28e7d8 100644 --- a/test/dotnet-watch.FunctionalTests/GlobbingAppTests.cs +++ b/test/dotnet-watch.FunctionalTests/GlobbingAppTests.cs @@ -102,6 +102,7 @@ namespace Microsoft.DotNet.Watcher.Tools.FunctionalTests await _app.PrepareAsync(); _app.Start(new [] { "--list" }); var lines = await _app.Process.GetAllOutputLines(); + var files = lines.Where(l => !l.StartsWith("watch :")); AssertEx.EqualFileList( _app.Scenario.WorkFolder, @@ -111,7 +112,7 @@ namespace Microsoft.DotNet.Watcher.Tools.FunctionalTests "GlobbingApp/include/Foo.cs", "GlobbingApp/GlobbingApp.csproj", }, - lines); + files); } public void Dispose() diff --git a/test/dotnet-watch.FunctionalTests/NoDepsAppTests.cs b/test/dotnet-watch.FunctionalTests/NoDepsAppTests.cs index 8ac2f694e7..df2521b5d3 100644 --- a/test/dotnet-watch.FunctionalTests/NoDepsAppTests.cs +++ b/test/dotnet-watch.FunctionalTests/NoDepsAppTests.cs @@ -5,6 +5,8 @@ using System; using System.Diagnostics; using System.IO; using System.Threading.Tasks; +using Microsoft.AspNetCore.Testing; +using Microsoft.AspNetCore.Testing.xunit; using Xunit; using Xunit.Abstractions; @@ -15,10 +17,34 @@ namespace Microsoft.DotNet.Watcher.Tools.FunctionalTests private static readonly TimeSpan DefaultTimeout = TimeSpan.FromSeconds(30); private readonly WatchableApp _app; + private readonly ITestOutputHelper _output; public NoDepsAppTests(ITestOutputHelper logger) { _app = new WatchableApp("NoDepsApp", logger); + _output = logger; + } + + [ConditionalFact] + [OSSkipCondition(OperatingSystems.Windows, SkipReason = "Testing SIGINT is specific to macOS/Linux")] + public async Task KillsProcessOnSigInt() + { + void SendSigInt(int pid) + { + _output.WriteLine($"kill -SIGINT {pid}"); + Process.Start("kill", $"-SIGINT {pid}"); + } + + await _app.StartWatcherAsync(new[] { "--no-exit" }); + + var childPid = await _app.GetProcessId(); + + SendSigInt(_app.Process.Id); + SendSigInt(childPid); + + await _app.Process.Exited.TimeoutAfter(TimeSpan.FromSeconds(30)); + + Assert.DoesNotContain(_app.Process.Output, l => l.StartsWith("Exited with error code")); } [Fact] @@ -33,6 +59,8 @@ namespace Microsoft.DotNet.Watcher.Tools.FunctionalTests File.WriteAllText(fileToChange, programCs); await _app.HasRestarted(); + Assert.DoesNotContain(_app.Process.Output, l => l.StartsWith("Exited with error code")); + var pid2 = await _app.GetProcessId(); Assert.NotEqual(pid, pid2); diff --git a/test/dotnet-watch.FunctionalTests/Scenario/ProjectToolScenario.cs b/test/dotnet-watch.FunctionalTests/Scenario/ProjectToolScenario.cs index a0a14093ec..b5c064563b 100644 --- a/test/dotnet-watch.FunctionalTests/Scenario/ProjectToolScenario.cs +++ b/test/dotnet-watch.FunctionalTests/Scenario/ProjectToolScenario.cs @@ -1,8 +1,7 @@ -// Copyright (c) .NET Foundation. All rights reserved. +// Copyright (c) .NET Foundation. All rights reserved. // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. using System; -using System.Collections.Generic; using System.Diagnostics; using System.IO; using System.Linq; @@ -12,7 +11,6 @@ using System.Threading.Tasks; using System.Xml.Linq; using Microsoft.Extensions.CommandLineUtils; using Microsoft.Extensions.Internal; -using Microsoft.Extensions.Tools.Internal; using Xunit.Abstractions; namespace Microsoft.DotNet.Watcher.Tools.FunctionalTests diff --git a/test/dotnet-watch.Tests/ProgramTests.cs b/test/dotnet-watch.Tests/ProgramTests.cs index 8c116b5595..a5998b25c8 100644 --- a/test/dotnet-watch.Tests/ProgramTests.cs +++ b/test/dotnet-watch.Tests/ProgramTests.cs @@ -28,23 +28,25 @@ namespace Microsoft.DotNet.Watcher.Tools.Tests { _tempDir .WithCSharpProject("testproj") - .WithTargetFrameworks("netcoreapp1.0") + .WithTargetFrameworks("netcoreapp2.2") .Dir() .WithFile("Program.cs") .Create(); - var stdout = new StringBuilder(); - _console.Out = new StringWriter(stdout); - var program = new Program(_console, _tempDir.Root) - .RunAsync(new[] { "run" }); + var output = new StringBuilder(); + _console.Error = _console.Out = new StringWriter(output); + using (var app = new Program(_console, _tempDir.Root)) + { + var run = app.RunAsync(new[] { "run" }); - await _console.CancelKeyPressSubscribed.TimeoutAfter(TimeSpan.FromSeconds(30)); - _console.ConsoleCancelKey(); + await _console.CancelKeyPressSubscribed.TimeoutAfter(TimeSpan.FromSeconds(30)); + _console.ConsoleCancelKey(); - var exitCode = await program.TimeoutAfter(TimeSpan.FromSeconds(30)); + var exitCode = await run.TimeoutAfter(TimeSpan.FromSeconds(30)); - Assert.Contains("Shutdown requested. Press Ctrl+C again to force exit.", stdout.ToString()); - Assert.Equal(0, exitCode); + Assert.Contains("Shutdown requested. Press Ctrl+C again to force exit.", output.ToString()); + Assert.Equal(0, exitCode); + } } public void Dispose()