Integrate ProcessWatchdog into future branch

BuildAndTest.proj

@@ -94,9 +94,36 @@
         Text="Found test assemblies outside a well-known test directory: 
 @(MisplacedTestAssemblies, '%0a')" />
 
-    <Exec Command="$(CoreClrTestDirectory)\CoreRun.exe $(CoreClrTestDirectory)\xunit.console.netcore.exe @(CoreTestAssemblies, ' ') -parallel all -xml $(CoreClrTestDirectory)\xUnitResults\TestResults.xml" />
-
-    <Exec Command="Binaries\$(Configuration)\RunTests\RunTests.exe &quot;$(NuGetPackageRoot)\xunit.runner.console\$(XunitVersion)\tools&quot; $(RunTestArgs) @(TestAssemblies, ' ')" />
+    <PropertyGroup>
+      <CoreRunExe>$(CoreClrTestDirectory)\CoreRun.exe</CoreRunExe>
+      <CoreRunArgs>$(CoreClrTestDirectory)\xunit.console.netcore.exe @(CoreTestAssemblies, ' ') -parallel all -xml $(CoreClrTestDirectory)\xUnitResults\TestResults.xml</CoreRunArgs>
+      <RunTestsExe>Binaries\$(Configuration)\RunTests\RunTests.exe</RunTestsExe>
+      <RunTestsArgs>$(NuGetPackageRoot)\xunit.runner.console\$(XunitVersion)\tools $(RunTestArgs) @(TestAssemblies, ' ')</RunTestsArgs>
+    </PropertyGroup>
+    
+    <Exec Condition="'$(RunProcessWatchdog)' != 'true'" Command="&quot;$(CoreRunExe)&quot; $(CoreRunArgs)" />
+
+    <Exec Condition="'$(RunProcessWatchdog)' != 'true'" Command="&quot;$(RunTestsExe)&quot; $(RunTestsArgs)" />
+
+    <PropertyGroup Condition="'$(RunProcessWatchdog)' == 'true'">
+      <ProcessWatchDogExe>$(OutputDirectory)\ProcessWatchdog\ProcessWatchdog.exe</ProcessWatchDogExe>
+      <ProcessWatchdogOutputDirectory Condition="'$(ProcessWatchdogOutputDirectory)' == ''">$(OutputDirectory)\ProcessWatchdogOutput</ProcessWatchdogOutputDirectory>
+      <ProcDumpExe Condition="'$(ProcDumpExe)' == ''">C:\Sysinternals\Procdump.exe</ProcDumpExe>
+
+      <!--
+      The time reserved for the process watchdog to kill all test processes and obtain crash
+      dumps from them, measure in seconds.
+      -->
+      <BufferTime>300</BufferTime>
+
+      <!--
+      The fully constructed command line which runs a PowerShell script that runs both the
+      Core CLR unit tests and the desktop unit tests under the control of the process watchdog.
+      -->
+      <RunProcessWatchdogScriptCommand>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)</RunProcessWatchdogScriptCommand>
+    </PropertyGroup>
+
+    <Exec Condition="'$(RunProcessWatchdog)' == 'true'" Command="$(RunProcessWatchdogScriptCommand)" />
 
   </Target>
 

build/scripts/Run-TestsWithProcessWatchdog.ps1

+<#
+.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

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

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

src/Tools/ProcessWatchdog/ErrorCode.cs

+// 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
+    }
+}

src/Tools/ProcessWatchdog/ProcessTracker.cs

@@ -114,9 +114,11 @@ private IList<Process> GetDescendants(int processId)
         {
             var descendants = new List<Process>();
 
+            // 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);
 

src/Tools/ProcessWatchdog/ProcessWatchdog.csproj

@@ -30,6 +30,7 @@
   </ItemGroup>
   <ItemGroup>
     <Compile Include="ConsoleUtils.cs" />
+    <Compile Include="ErrorCode.cs" />
     <Compile Include="ProcDump.cs" />
     <Compile Include="Options.cs" />
     <Compile Include="ProcessTracker.cs" />

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<Options>(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();
         }

src/Tools/ProcessWatchdog/Resources.Designer.cs

@@ -97,7 +97,7 @@ internal class Resources {
         }
         
         /// <summary>
-        ///   Looks up a localized string similar to Error: {0}.
+        ///   Looks up a localized string similar to Error {0}: {1}.
         /// </summary>
         internal static string ErrorFormat {
             get {

src/Tools/ProcessWatchdog/Resources.resx

@@ -130,7 +130,7 @@
     <value>Could not take screenshot for process {0}.</value>
   </data>
   <data name="ErrorFormat" xml:space="preserve">
-    <value>Error: {0}</value>
+    <value>Error {0}: {1}</value>
   </data>
   <data name="ErrorInvalidPollingInterval" xml:space="preserve">
     <value>The value {0} is not a valid polling interval. Please specify the polling interval as a positive number of milliseconds.</value>

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);
             }
         }