OSOE-464: Executing dotnet test with process timeout

.github/actions/test-dotnet/Invoke-SolutionTests.ps1

@@ -1,4 +1,4 @@
-param ($Solution, $Verbosity, $Filter, $Configuration, $BlameHangTimeout)
+param ($Solution, $Verbosity, $Filter, $Configuration, $BlameHangTimeout, $TestProcessTimeout)
 
 # Note that this script will only find tests if they were previously build in Release mode.
 
@@ -10,22 +10,25 @@ param ($Solution, $Verbosity, $Filter, $Configuration, $BlameHangTimeout)
 # the Actions web UI. Note that we use bash to output the log using bash to avoid pwsh wrapping the output to the
 # default buffer width.
 
-$connectionStringSuffix = @(
-    ';MultipleActiveResultSets=True;Connection Timeout=60;ConnectRetryCount=15;ConnectRetryInterval=5;Encrypt=false;'
-    'TrustServerCertificate=true'
-) -join ''
 if ($Env:RUNNER_OS -eq 'Windows')
 {
-    $connectionStringStem = 'Server=.;Database=LombiqUITestingToolbox_{{id}};Integrated Security=True'
+    $connectionSecurity = 'Integrated Security=True'
 }
 else
 {
-    $connectionStringStem = 'Server=.;Database=LombiqUITestingToolbox_{{id}};User Id=sa;Password=Password1!'
+    $connectionSecurity = 'User Id=sa;Password=Password1!'
 
     $Env:Lombiq_Tests_UI__DockerConfiguration__ContainerName = 'uitt-sqlserver'
 }
 
-$Env:Lombiq_Tests_UI__SqlServerDatabaseConfiguration__ConnectionStringTemplate = $connectionStringStem + $connectionStringSuffix
+$connectionString = @(
+    'Server=.;Database=LombiqUITestingToolbox_{{id}}'
+    $connectionSecurity
+    'MultipleActiveResultSets=True;Connection Timeout=60;ConnectRetryCount=15;ConnectRetryInterval=5;Encrypt=false'
+    'TrustServerCertificate=true'
+) -join ';'
+
+$Env:Lombiq_Tests_UI__SqlServerDatabaseConfiguration__ConnectionStringTemplate = $connectionString
 $Env:Lombiq_Tests_UI__BrowserConfiguration__Headless = 'true'
 
 $solutionName = [System.IO.Path]::GetFileNameWithoutExtension($Solution)
@@ -63,9 +66,112 @@ $tests = dotnet sln $Solution list |
     }
 
 Set-GitHubOutput 'test-count' $tests.Length
+Set-GitHubOutput 'dotnet-test-hang-dump' 0
 
 Write-Output "Starting to execute tests from $($tests.Length) project(s)."
 
+function GetChildProcesses($Id)
+{
+    return Get-Process | Where-Object { $PSItem.Parent -and $PSItem.Parent.Id -eq $Id }
+}
+
+function DumpProcess($Output, $RootProcess, $DumpRootPath, $Process)
+{
+    if (!$Process)
+    {
+        return
+    }
+
+    $output.AppendLine("::warning::Collecting a dump of the process $($Process.Id).")
+
+    dotnet-dump collect -p $Process.Id --type Full -o "$DumpRootPath/dotnet-test-hang-dump-$($RootProcess.Id)-$($Process.Name)_$($Process.Id).dmp"
+}
+
+function DumpProcessTree($Output, $RootProcess, $DumpRootPath, $CurrentProcess)
+{
+    foreach ($child in GetChildProcesses -Id $CurrentProcess.Id)
+    {
+        DumpProcessTree -Output $Output -RootProcess $RootProcess -DumpRootPath $DumpRootPath -CurrentProcess $child
+    }
+
+    DumpProcess -Output $Output -RootProcess $RootProcess -DumpRootPath $DumpRootPath -Process $CurrentProcess
+}
+
+function KillProcessTree($Output, $Process)
+{
+    $Output.AppendLine("::warning::Killing the process $($Process.Name)($($Process.Id)).")
+
+    foreach ($child in GetChildProcesses -Id $Process.Id)
+    {
+        KillProcessTree -Output $Output -Process $child
+    }
+
+    Stop-Process -Force -InputObject $Process
+}
+
+function StartProcessAndWaitForExit($FileName, $Arguments, $Timeout = -1)
+{
+    $process = [System.Diagnostics.Process]@{
+        StartInfo = @{
+            FileName = 'pwsh'
+            Arguments = "-c `"$FileName $Arguments 2>&1`""
+            RedirectStandardOutput = $true
+            RedirectStandardError = $true
+            UseShellExecute = $false
+            WorkingDirectory = Get-Location
+        }
+    }
+
+    $output = New-Object System.Text.StringBuilder
+    $eventHandlerArgs = @{
+        Output = $output
+        Process = $process
+    }
+
+    $stdoutEvent = Register-ObjectEvent $process -EventName OutputDataReceived -MessageData $eventHandlerArgs -Action {
+        $Event.MessageData.Output.AppendLine($Event.SourceEventArgs.Data)
+    }
+
+    $stderrEvent = Register-ObjectEvent $process -EventName ErrorDataReceived -MessageData $eventHandlerArgs -Action {
+        $Event.MessageData.Output.AppendLine($Event.SourceEventArgs.Data)
+    }
+
+    $process.Start() | Out-Null
+    $process.BeginOutputReadLine()
+    $process.BeginErrorReadLine()
+
+    $process.WaitForExit($Timeout)
+    $hasExited = $process.HasExited
+    if ($hasExited)
+    {
+        $exitCode = $process.ExitCode
+    }
+    else
+    {
+        $output.AppendLine("::warning::The process $($process.Id) didn't exit in $Timeout seconds.")
+
+        $output.AppendLine("::warning::Collecting a dump of the process $($process.Id) tree.")
+        $dumpRootPath = './DotnetTestHangDumps'
+        New-Item -ItemType 'directory' -Path $dumpRootPath -Force | Out-Null
+
+        $rootProcess = Get-Process -Id $process.Id
+        DumpProcessTree -RootProcess $rootProcess -DumpRootPath $dumpRootPath -CurrentProcess $rootProcess
+
+        Set-GitHubOutput 'dotnet-test-hang-dump' 1
+
+        KillProcessTree -Output $output -Process $rootProcess
+    }
+
+    Unregister-Event $stdoutEvent.Id
+    Unregister-Event $stderrEvent.Id
+
+    return @{
+        Output = $output.ToString()
+        ExitCode = $exitCode
+        HasExited = $hasExited
+    }
+}
+
 foreach ($test in $tests)
 {
     # This could benefit from grouping, above the level of the potential groups created by the tests (the Lombiq UI
@@ -78,9 +184,9 @@ foreach ($test in $tests)
     $dotnetTestSwitches = @(
         '--configuration', $Configuration
         '--nologo',
-        '--logger', 'trx;LogFileName=test-results.trx'
+        '--logger', '''trx;LogFileName=test-results.trx'''
         # This is for xUnit ITestOutputHelper, see https://xunit.net/docs/capturing-output.
-        '--logger', 'console;verbosity=detailed'
+        '--logger', '''console;verbosity=detailed'''
         '--verbosity', $Verbosity
         $BlameHangTimeout ? ('--blame-hang-timeout', $BlameHangTimeout, '--blame-hang-dump-type', 'full') : ''
         $Filter ? '--filter', $Filter : ''
@@ -89,12 +195,19 @@ foreach ($test in $tests)
 
     Write-Output "Starting testing with ``dotnet test $($dotnetTestSwitches -join ' ')``."
 
-    dotnet test @dotnetTestSwitches 2>&1 |
-        Where-Object { $PSItem -NotLike '*Connection refused [[]::ffff:127.0.0.1[]]*' -and $PSItem -NotLike '*ChromeDriver was started successfully*' }
+    $processResult = StartProcessAndWaitForExit -FileName 'dotnet' -Arguments "test $($dotnetTestSwitches -join ' ')" -Timeout $TestProcessTimeout
+
+    Write-Output $processResult.Output
 
-    if ($?)
+    if ($processResult.ExitCode -eq 0 || (!$processResult.HasExited && $processResult.Output -Like '*Test Run Successful.*'))
     {
+        if (!$processResult.HasExited)
+        {
+            Write-Output "::warning::The process $($process.Id) was killed but the tests were successful."
+        }
+
         Write-Output "Test successful: $test"
+
         continue
     }
 

.github/actions/test-dotnet/action.yml

@@ -15,6 +15,11 @@ inputs:
     required: false
     default: .
     description: Path to the directory where a solution file can be found and thus the .NET build has run.
+  dotnet-test-process-timeout:
+    required: false
+    type: number
+    default: -1
+    description: Run the dotnet test process with the given timeout in milliseconds. -1 means no timeout.
   solution-path:
     required: false
     default: "*.sln"
@@ -80,6 +85,12 @@ runs:
 
         "Lombiq_Tests_UI__OrchardCoreUITestExecutorConfiguration__MaxParallelTests=${{ inputs.ui-test-parallelism }}" >> $Env:GITHUB_ENV
 
+    - name: Install dotnet-dump
+      uses: Lombiq/GitHub-Actions/.github/actions/install-dotnet-tool@dev
+      with:
+        name: dotnet-dump
+        version: 7.0.421201
+
     - name: Run Tests
       id: run-tests
       shell: pwsh
@@ -91,6 +102,7 @@ runs:
           Filter = "${{ inputs.test-filter }}"
           Configuration = "${{ inputs.test-configuration }}"
           BlameHangTimeout = "${{ inputs.blame-hang-timeout }}"
+          TestProcessTimeout = ${{ inputs.dotnet-test-process-timeout }}
         }
 
         Invoke-SolutionTests @switches
@@ -131,6 +143,15 @@ runs:
         if-no-files-found: ignore
         retention-days: ${{ inputs.ui-test-artifact-retention-days }}
 
+    - name: Upload DotnetTestHangDumps
+      uses: actions/upload-artifact@v3.1.1
+      if: (success() || failure()) && steps.run-tests.outputs.test-count != 0 && steps.run-tests.outputs.dotnet-test-hang-dump != 0
+      with:
+        name: dotnet-test-hang-dump-${{ steps.setup.outputs.artifact-name-suffix }}
+        path: ${{ inputs.build-directory }}/DotnetTestHangDumps/
+        if-no-files-found: ignore
+        retention-days: ${{ inputs.ui-test-artifact-retention-days }}
+
     - name: Test Report
       # v10
       uses: phoenix-actions/test-reporting@93ce19fa5882ebe3969ebdb9ee1024b3d29e776f

.github/workflows/build-and-test-dotnet.yml

@@ -101,6 +101,11 @@ on:
         description: >
           Duration in days after which the artifact of the build's binary log (if any) will expire. See
           https://github.com/actions/upload-artifact#retention-period for more details.
+      dotnet-test-process-timeout:
+        required: false
+        type: number
+        default: -1
+        description: Run the dotnet test process with the given timeout in milliseconds. -1 means no timeout.
       test-disable:
         type: string
         default: 'false'
@@ -205,10 +210,11 @@ jobs:
 
       - name: Tests
         if: inputs.test-disable == 'false'
-        uses: Lombiq/GitHub-Actions/.github/actions/test-dotnet@dev
+        uses: Lombiq/GitHub-Actions/.github/actions/test-dotnet@issue/OSOE-464-executing-dotnet-test-with-process-timeout
         with:
           blame-hang-timeout: ${{ inputs.blame-hang-timeout }}
           build-directory: ${{ inputs.build-directory }}
+          dotnet-test-process-timeout: ${{ inputs.dotnet-test-process-timeout }}
           solution-path: ${{ inputs.build-solution-path }}
           test-verbosity: ${{ inputs.build-verbosity }}
           test-filter: ${{ inputs.test-filter }}

.github/workflows/build-and-test-orchard-core.yml

@@ -99,6 +99,11 @@ on:
         description: >
           Duration in days after which the artifact of the build's binary log (if any) will expire. See
           https://github.com/actions/upload-artifact#retention-period for more details.
+      dotnet-test-process-timeout:
+        required: false
+        type: number
+        default: -1
+        description: Run the dotnet test process with the given timeout in milliseconds. -1 means no timeout.
       print-config-summary:
         type: string
         default: 'false'
@@ -245,10 +250,11 @@ jobs:
 
       - name: Tests
         if: inputs.test-disable == 'false'
-        uses: Lombiq/GitHub-Actions/.github/actions/test-dotnet@dev
+        uses: Lombiq/GitHub-Actions/.github/actions/test-dotnet@issue/OSOE-464-executing-dotnet-test-with-process-timeout
         with:
           blame-hang-timeout: ${{ inputs.blame-hang-timeout }}
           build-directory: ${{ inputs.build-directory }}
+          dotnet-test-process-timeout: ${{ inputs.dotnet-test-process-timeout }}
           solution-path: ${{ inputs.build-solution-path }}
           test-verbosity: ${{ inputs.build-verbosity }}
           test-filter: ${{ inputs.test-filter }}

.github/workflows/msbuild-and-test.yml

@@ -77,6 +77,11 @@ on:
         type: string
         default: 'true'
         description: Indicates whether to enable static code analysis during msbuild.
+      dotnet-test-process-timeout:
+        required: false
+        type: number
+        default: -1
+        description: Run the dotnet test process with the given timeout in milliseconds. -1 means no timeout.
       test-disable:
         type: string
         default: 'false'
@@ -120,9 +125,10 @@ jobs:
 
       - name: Tests
         if: inputs.test-disable == 'false'
-        uses: Lombiq/GitHub-Actions/.github/actions/test-dotnet@dev
+        uses: Lombiq/GitHub-Actions/.github/actions/test-dotnet@issue/OSOE-464-executing-dotnet-test-with-process-timeout
         with:
           build-directory: ${{ inputs.build-directory }}
+          dotnet-test-process-timeout: ${{ inputs.dotnet-test-process-timeout }}
           test-verbosity: ${{ inputs.build-verbosity }}
           test-filter: ${{ inputs.test-filter }}
           test-configuration: 'Release'