From 2c53f99ee146b6591b65e5db011ff184da79cf07 Mon Sep 17 00:00:00 2001 From: Larry Golding Date: Fri, 1 Apr 2016 06:07:44 -0700 Subject: [PATCH] Integrate ProcessWatchdog into future branch --- BuildAndTest.proj | 33 ++++++- .../scripts/Run-TestsWithProcessWatchdog.ps1 | 87 +++++++++++++++++++ cibuild.cmd | 28 +++--- src/Tools/ProcessWatchdog/ConsoleUtils.cs | 10 ++- src/Tools/ProcessWatchdog/ErrorCode.cs | 15 ++++ src/Tools/ProcessWatchdog/ProcessTracker.cs | 4 +- .../ProcessWatchdog/ProcessWatchdog.csproj | 1 + src/Tools/ProcessWatchdog/Program.cs | 22 +++-- .../ProcessWatchdog/Resources.Designer.cs | 2 +- src/Tools/ProcessWatchdog/Resources.resx | 2 +- src/Tools/ProcessWatchdog/ScreenShotSaver.cs | 4 +- 11 files changed, 181 insertions(+), 27 deletions(-) create mode 100644 build/scripts/Run-TestsWithProcessWatchdog.ps1 create mode 100644 src/Tools/ProcessWatchdog/ErrorCode.cs diff --git a/BuildAndTest.proj b/BuildAndTest.proj index e6b27797e3c..9bbd29d9c41 100644 --- a/BuildAndTest.proj +++ b/BuildAndTest.proj @@ -94,9 +94,36 @@ Text="Found test assemblies outside a well-known test directory: @(MisplacedTestAssemblies, '%0a')" /> - - - + + $(CoreClrTestDirectory)\CoreRun.exe + $(CoreClrTestDirectory)\xunit.console.netcore.exe @(CoreTestAssemblies, ' ') -parallel all -xml $(CoreClrTestDirectory)\xUnitResults\TestResults.xml + Binaries\$(Configuration)\RunTests\RunTests.exe + $(NuGetPackageRoot)\xunit.runner.console\$(XunitVersion)\tools $(RunTestArgs) @(TestAssemblies, ' ') + + + + + + + + $(OutputDirectory)\ProcessWatchdog\ProcessWatchdog.exe + $(OutputDirectory)\ProcessWatchdogOutput + C:\Sysinternals\Procdump.exe + + + 300 + + + PowerShell.exe -ExecutionPolicy RemoteSigned -NoProfile .\build\scripts\Run-TestsWithProcessWatchdog.ps1 -ProcessWatchDogExe $(ProcessWatchDogExe) -ProcessWatchdogOutputDirectory $(ProcessWatchdogOutputDirectory) -ProcDumpExe $(ProcDumpExe) -CoreRunExe '$(CoreRunExe)' -CoreRunArgs '$(CoreRunArgs)' -RunTestsExe '$(RunTestsExe)' -RunTestsArgs '$(RunTestsArgs)' -BuildStartTime $(BuildStartTime) -BuildTimeLimit $(BuildTimeLimit) -BufferTime $(BufferTime) + + + diff --git a/build/scripts/Run-TestsWithProcessWatchdog.ps1 b/build/scripts/Run-TestsWithProcessWatchdog.ps1 new file mode 100644 index 00000000000..56306da8a1e --- /dev/null +++ b/build/scripts/Run-TestsWithProcessWatchdog.ps1 @@ -0,0 +1,87 @@ +<# +.SYNOPSIS +Run the unit tests under the control of the process watchdog. + +.DESCRIPTION +This script runs the unit tests under the control of the process watchdog. +The process watchdog allows the unit tests a certain amount of time to +run. If they don't complete in the allotted time, then the watchdog +obtains memory dumps from the test process and all its descendant processes, +takes a screen shot, and kills the processes. + +.PARAMETER ProcessWatchdogExe +The path to the executable ProcessWatchdog.exe, which sets time limits on +the unit tests. + +.PARAMETER ProcessWatchdogOutputDirectory +The directory into which ProcessWatchdog.exe should write memory dumps and screen shots. + +.PARAMETER ProcDumpExe +The path to the SysInternals executable ProcDump.exe, which produces memory dumps. + +.PARAMETER CoreRunExe +The path to the executable CoreRun.exe, which runs the Core CLR unit tests. + +.PARAMETER CoreRunArgs +The arguments to be passed to CoreRun.exe. + +.PARAMETER RunTestsExe +The path to the executable RunTests.exe, which runs the desktop unit tests. + +.PARAMETER RunTestsArgs +The arguments to be passed to RunTests.exe. + +.PARAMETER BuildStartTime +The time the Jenkins build started, in the ISO 8601-compatible format YYYY-MM-DDThh:mm:ss. + +.PARAMETER BuildTimeLimit +The total time allowed for the Jenkins build, measured in minutes. + +.PARAMETER BufferTime +The time reserved for the process watchdog to kill all test processes and obtain crash +dumps from them, measure in seconds. +#> + +[CmdletBinding()] +Param( + [Parameter(Mandatory=$true)] [string] $ProcessWatchdogExe, + [Parameter(Mandatory=$true)] [string] $ProcessWatchdogOutputDirectory, + [Parameter(Mandatory=$true)] [string] $ProcDumpExe, + [Parameter(Mandatory=$true)] [string] $CoreRunExe, + [Parameter(Mandatory=$true)] [string] $CoreRunArgs, + [Parameter(Mandatory=$true)] [string] $RunTestsExe, + [Parameter(Mandatory=$true)] [string] $RunTestsArgs, + [Parameter(Mandatory=$true)] [string] $BuildStartTime, + [Parameter(Mandatory=$true)] [int] $BuildTimeLimit, + [Parameter(Mandatory=$true)] [int] $BufferTime +) + +Set-StrictMode -Version 2.0 +$ErrorActionPreference = "Stop" + +$BuildStartSeconds = [DateTime]::ParseExact($BuildStartTime, "yyyy'-'MM'-'dd'T'HH':'mm':'ss'.'ff", [CultureInfo]::InvariantCulture) + +function Check-TimeRemaining($testGroupName) +{ + $timeRemaining = Get-TimeRemaining + if ($timeRemaining -gt 0) { + Write-Host "$timeRemaining seconds remain to run the $testGroupName unit tests." + $timeRemaining + } else { + Write-Host "There is no time remaining to run the $testGroupName unit tests." + exit 1; + } +} + +function Get-TimeRemaining() { + $secondsSinceStart = ([DateTime]::Now - $BuildStartSeconds).TotalSeconds + [Math]::Truncate($BuildTimeLimit * 60 - $secondsSinceStart - $BufferTime) +} + +$timeRemaining = Check-TimeRemaining "Core CLR" + +& $ProcessWatchdogExe --executable $CoreRunExe --arguments "$CoreRunArgs" --time-limit $timeRemaining --output-folder "$ProcessWatchdogOutputDirectory" --screenshot --procdump-path "$ProcDumpExe" + +$timeRemaining = Check-TimeRemaining "desktop" + +& $ProcessWatchdogExe --executable $RunTestsExe --arguments "$RunTestsArgs" --time-limit $timeRemaining --output-folder "$ProcessWatchdogOutputDirectory" --screenshot --procdump-path "$ProcDumpExe" \ No newline at end of file diff --git a/cibuild.cmd b/cibuild.cmd index 5dbb5faf1d6..2232028faf1 100644 --- a/cibuild.cmd +++ b/cibuild.cmd @@ -21,19 +21,27 @@ if /I "%1" == "/testDeterminism" set TestDeterminism=true&&shift&& goto :ParseAr REM /buildTimeLimit is the time limit, measured in minutes, for the Jenkins job that runs REM the build. The Jenkins script netci.groovy passes the time limit to this script. - -REM netci.groovy does not yet pass the time limit to cibuild.cmd. We are making this -REM change to cibuild.cmd in all branches *before* modifying netci.groovy. If we didn't -REM do things in this order, we'd have to modify cibuild.cmd in *all* branches *at the -REM same time* we made the change to netci.groovy. This way, we'll be able to first -REM modify netci.groovy to pass the new parameter without causing any harm. Then we'll -REM be able go to each branch in turn, modifying cibuild.cmd and BuildAndTest.cmd to -REM actually make use of the new parameter. -if /I "%1" == "/buildTimeLimit" set BuildTimeLimit=%2&&shift&&shift&& goto:ParseArguments +if /I "%1" == "/buildTimeLimit" set BuildTimeLimit=%2&&shift&&shift&& goto :ParseArguments call :Usage && exit /b 1 :DoneParsing +REM This script takes the presence of the /buildTimeLimit option as an indication that it +REM should run the tests under the control of the ProcessWatchdog, which, if the tests +REM exceed the time limit, will take a screenshot, obtain memory dumps from the test +REM process and all its descendants, and shut those processes down. +REM +REM Developers building from the command line will presumably not pass /buildTimeLimit, +REM and so the tests will not run under the ProcessWatchdog. +if not "%BuildTimeLimit%" == "" ( + set CurrentDate=%date% + set CurrentTime=%time: =0% + set BuildStartTime=!CurrentDate:~-4!-!CurrentDate:~-10,2!-!CurrentDate:~-7,2!T!CurrentTime! + set RunProcessWatchdog=true +) else ( + set RunProcessWatchdog=false +) + call "C:\Program Files (x86)\Microsoft Visual Studio 14.0\Common7\Tools\VsDevCmd.bat" || goto :BuildFailed powershell -noprofile -executionPolicy RemoteSigned -file "%RoslynRoot%\build\scripts\check-branch.ps1" || goto :BuildFailed @@ -70,7 +78,7 @@ if defined TestDeterminism ( exit /b 0 ) -msbuild %MSBuildAdditionalCommandLineArgs% /p:BootstrapBuildPath="%bindir%\Bootstrap" BuildAndTest.proj /p:Configuration=%BuildConfiguration% /p:Test64=%Test64% /p:PathMap="%RoslynRoot%=q:\roslyn" /p:Feature=pdb-path-determinism /fileloggerparameters:LogFile="%bindir%\Build.log";verbosity=diagnostic || goto :BuildFailed +msbuild %MSBuildAdditionalCommandLineArgs% /p:BootstrapBuildPath="%bindir%\Bootstrap" BuildAndTest.proj /p:Configuration=%BuildConfiguration% /p:Test64=%Test64% /p:RunProcessWatchdog=%RunProcessWatchdog% /p:BuildStartTime=%BuildStartTime% /p:"ProcDumpExe=%ProcDumpExe%" /p:BuildTimeLimit=%BuildTimeLimit% /p:PathMap="%RoslynRoot%=q:\roslyn" /p:Feature=pdb-path-determinism /fileloggerparameters:LogFile="%bindir%\Build.log";verbosity=diagnostic || goto :BuildFailed powershell -noprofile -executionPolicy RemoteSigned -file "%RoslynRoot%\build\scripts\check-msbuild.ps1" "%bindir%\Build.log" || goto :BuildFailed call :TerminateBuildProcesses diff --git a/src/Tools/ProcessWatchdog/ConsoleUtils.cs b/src/Tools/ProcessWatchdog/ConsoleUtils.cs index aa3841b434f..544a42aa5ee 100644 --- a/src/Tools/ProcessWatchdog/ConsoleUtils.cs +++ b/src/Tools/ProcessWatchdog/ConsoleUtils.cs @@ -13,14 +13,20 @@ internal static void LogMessage(string format, params object[] args) string.Format(CultureInfo.CurrentCulture, format, args)); } - internal static void LogError(string messageFormat, params object[] args) + internal static void LogError(ErrorCode errorCode, string messageFormat, params object[] args) { string fullMessage = string.Format( - CultureInfo.CurrentCulture, + CultureInfo.InvariantCulture, Resources.ErrorFormat, + FormatErrorCode(errorCode), string.Format(CultureInfo.CurrentCulture, messageFormat, args)); Console.Error.WriteLine(fullMessage); } + + private static string FormatErrorCode(ErrorCode errorCode) + { + return string.Format(CultureInfo.InvariantCulture, "PW{0:D4}", (int)errorCode); + } } } \ No newline at end of file diff --git a/src/Tools/ProcessWatchdog/ErrorCode.cs b/src/Tools/ProcessWatchdog/ErrorCode.cs new file mode 100644 index 00000000000..8bf23b4ee35 --- /dev/null +++ b/src/Tools/ProcessWatchdog/ErrorCode.cs @@ -0,0 +1,15 @@ +// Copyright (c) Microsoft. All Rights Reserved. Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +namespace ProcessWatchdog +{ + internal enum ErrorCode + { + None = 0, + ProcessTimedOut = 1, + InvalidTimeLimit = 2, + InvalidPollingInterval = 3, + ProcDumpNotFound = 4, + CannotTakeScreenShotNoConsoleSession = 5, + CannotTakeScreenShotUnexpectedError = 6 + } +} diff --git a/src/Tools/ProcessWatchdog/ProcessTracker.cs b/src/Tools/ProcessWatchdog/ProcessTracker.cs index 91ddfd46739..90d2e33cfff 100644 --- a/src/Tools/ProcessWatchdog/ProcessTracker.cs +++ b/src/Tools/ProcessWatchdog/ProcessTracker.cs @@ -114,9 +114,11 @@ private IList GetDescendants(int processId) { var descendants = new List(); + // Don't include procdump itself in the descendants, because + // we don't want to kill procdump. string query = string.Format( CultureInfo.InvariantCulture, - "SELECT * FROM Win32_Process WHERE ParentProcessId={0}", + "SELECT * FROM Win32_Process WHERE ParentProcessId = {0} AND Name <> \"procdump.exe\"", processId); var searcher = new ManagementObjectSearcher(query); diff --git a/src/Tools/ProcessWatchdog/ProcessWatchdog.csproj b/src/Tools/ProcessWatchdog/ProcessWatchdog.csproj index d2dfa470484..a8f6f29ae9b 100644 --- a/src/Tools/ProcessWatchdog/ProcessWatchdog.csproj +++ b/src/Tools/ProcessWatchdog/ProcessWatchdog.csproj @@ -30,6 +30,7 @@ + diff --git a/src/Tools/ProcessWatchdog/Program.cs b/src/Tools/ProcessWatchdog/Program.cs index eeb4576bc4c..5de3ef4baa0 100644 --- a/src/Tools/ProcessWatchdog/Program.cs +++ b/src/Tools/ProcessWatchdog/Program.cs @@ -26,7 +26,7 @@ private int Run() { if (_options.TimeLimit <= 0) { - ConsoleUtils.LogError(Resources.ErrorInvalidTimeLimit, _options.TimeLimit); + ConsoleUtils.LogError(ErrorCode.InvalidTimeLimit, Resources.ErrorInvalidTimeLimit, _options.TimeLimit); return 1; } @@ -34,20 +34,22 @@ private int Run() if (_options.PollingInterval <= 0) { - ConsoleUtils.LogError(Resources.ErrorInvalidPollingInterval, _options.PollingInterval); + ConsoleUtils.LogError(ErrorCode.InvalidPollingInterval, Resources.ErrorInvalidPollingInterval, _options.PollingInterval); return 1; } if (!File.Exists(_options.ProcDumpPath)) { - ConsoleUtils.LogError(Resources.ErrorProcDumpNotFound, _options.ProcDumpPath); + ConsoleUtils.LogError(ErrorCode.ProcDumpNotFound, Resources.ErrorProcDumpNotFound, _options.ProcDumpPath); return 1; } var processStartInfo = new ProcessStartInfo { FileName = _options.Executable, - Arguments = _options.Arguments + Arguments = _options.Arguments, + CreateNoWindow = true, + UseShellExecute = false }; Process parentProcess = Process.Start(processStartInfo); @@ -60,6 +62,7 @@ private int Run() if (DateTime.Now - parentProcess.StartTime > _timeLimit) { ConsoleUtils.LogError( + ErrorCode.ProcessTimedOut, Resources.ErrorProcessTimedOut, _options.Executable, parentProcess.Id, @@ -67,7 +70,8 @@ private int Run() if (_options.Screenshot) { - ScreenshotSaver.SaveScreen(_options.Executable, _options.OutputFolder); + string description = Path.GetFileNameWithoutExtension(_options.Executable); + ScreenshotSaver.SaveScreen(description, _options.OutputFolder); } processTracker.TerminateAll(); @@ -90,8 +94,6 @@ private int Run() private static void Main(string[] args) { - Banner(); - Parser.Default.ParseArguments(args) .MapResult( options => Run(options), @@ -100,6 +102,12 @@ private static void Main(string[] args) private static int Run(Options options) { + // Don't display the banner until after the command line parser has + // validated the arguments, because when the command line arguments are + // invalid, the command line parse itself displays an banner. In that case, + // if we displayed our banner first, you would see two of them. + Banner(); + var program = new Program(options); return program.Run(); } diff --git a/src/Tools/ProcessWatchdog/Resources.Designer.cs b/src/Tools/ProcessWatchdog/Resources.Designer.cs index ed5a3bca704..576dfb6c8b4 100644 --- a/src/Tools/ProcessWatchdog/Resources.Designer.cs +++ b/src/Tools/ProcessWatchdog/Resources.Designer.cs @@ -97,7 +97,7 @@ internal class Resources { } /// - /// Looks up a localized string similar to Error: {0}. + /// Looks up a localized string similar to Error {0}: {1}. /// internal static string ErrorFormat { get { diff --git a/src/Tools/ProcessWatchdog/Resources.resx b/src/Tools/ProcessWatchdog/Resources.resx index 3c87ef63f27..580d9c935a2 100644 --- a/src/Tools/ProcessWatchdog/Resources.resx +++ b/src/Tools/ProcessWatchdog/Resources.resx @@ -130,7 +130,7 @@ Could not take screenshot for process {0}. - Error: {0} + Error {0}: {1} The value {0} is not a valid polling interval. Please specify the polling interval as a positive number of milliseconds. diff --git a/src/Tools/ProcessWatchdog/ScreenShotSaver.cs b/src/Tools/ProcessWatchdog/ScreenShotSaver.cs index 13f5dd0a01b..3400c9706f4 100644 --- a/src/Tools/ProcessWatchdog/ScreenShotSaver.cs +++ b/src/Tools/ProcessWatchdog/ScreenShotSaver.cs @@ -24,12 +24,12 @@ public static void SaveScreen(string description, string outputFolder) // System.ComponentModel.Win32Exception (0x80004005): The handle is invalid. This // means we're not running in a console session, hence there's no UI to take a // screenshot of. This is perfectly normal on the server. - ConsoleUtils.LogError(Resources.ErrorCannotTakeScreenshotNoConsoleSession, ex); + ConsoleUtils.LogError(ErrorCode.CannotTakeScreenShotNoConsoleSession, Resources.ErrorCannotTakeScreenshotNoConsoleSession, ex); } catch (Exception ex) { // This is something else, we'd better know about this. - ConsoleUtils.LogError(Resources.ErrorCannotTakeScreenshotUnexpectedError, ex); + ConsoleUtils.LogError(ErrorCode.CannotTakeScreenShotUnexpectedError, Resources.ErrorCannotTakeScreenshotUnexpectedError, ex); } } -- GitLab