|
| 1 | +<# |
| 2 | +.SYNOPSIS |
| 3 | + Lightweight background resource sampler for Windows CI jobs. |
| 4 | +
|
| 5 | +.DESCRIPTION |
| 6 | + Diagnostics only: records machine pressure while a job runs so slow, hung, or |
| 7 | + lost Windows runners can be correlated with CPU, memory, commit, page file, and |
| 8 | + disk usage. See https://github.com/microsoft/aspire/issues/21570. |
| 9 | +
|
| 10 | + -Mode Start Launches a detached, below-normal-priority pwsh sampler and returns. |
| 11 | + -Mode Sample The sampler loop itself (started by -Mode Start). |
| 12 | + -Mode Stop Stops the sampler and prints a peak/minimum summary to the log and |
| 13 | + the job summary. |
| 14 | +
|
| 15 | + Output goes to -OutputDirectory, which callers place under a directory that an |
| 16 | + existing `if: always()` upload already collects: |
| 17 | + resources.csv One row per sample with system-wide counters. |
| 18 | + processes.log Top processes by CPU (since the previous sample) and by memory. |
| 19 | + sampler.log Sampler errors, if any. |
| 20 | +
|
| 21 | + Every mode always exits 0: telemetry must never change the job result. |
| 22 | + A runner that loses communication uploads nothing, so this cannot capture the |
| 23 | + last minutes of a lost runner. It covers slow, failed, cancelled, and passing jobs. |
| 24 | +#> |
| 25 | +param( |
| 26 | + [Parameter(Mandatory = $true)] |
| 27 | + [ValidateSet('Start', 'Sample', 'Stop')] |
| 28 | + [string]$Mode, |
| 29 | + |
| 30 | + [Parameter(Mandatory = $true)] |
| 31 | + [string]$OutputDirectory, |
| 32 | + |
| 33 | + [ValidateRange(5, 600)] |
| 34 | + [int]$IntervalSeconds = 20, |
| 35 | + |
| 36 | + [ValidateRange(1, 50)] |
| 37 | + [int]$TopProcessCount = 5 |
| 38 | +) |
| 39 | + |
| 40 | +$ErrorActionPreference = 'Continue' |
| 41 | +$pidFile = Join-Path $OutputDirectory 'sampler.pid' |
| 42 | +$csvFile = Join-Path $OutputDirectory 'resources.csv' |
| 43 | +$processFile = Join-Path $OutputDirectory 'processes.log' |
| 44 | +$errorFile = Join-Path $OutputDirectory 'sampler.log' |
| 45 | + |
| 46 | +$counterPaths = [ordered]@{ |
| 47 | + CpuPercent = '\Processor(_Total)\% Processor Time' |
| 48 | + ProcessorQueue = '\System\Processor Queue Length' |
| 49 | + AvailableMB = '\Memory\Available MBytes' |
| 50 | + CommittedPercent = '\Memory\% Committed Bytes In Use' |
| 51 | + CommittedBytes = '\Memory\Committed Bytes' |
| 52 | + CommitLimitBytes = '\Memory\Commit Limit' |
| 53 | + PagesPerSec = '\Memory\Pages/sec' |
| 54 | + PageFilePercent = '\Paging File(_Total)\% Usage' |
| 55 | + DiskQueueLength = '\PhysicalDisk(_Total)\Avg. Disk Queue Length' |
| 56 | + DiskPercentTime = '\PhysicalDisk(_Total)\% Disk Time' |
| 57 | +} |
| 58 | + |
| 59 | +$script:loggedCounterErrors = [System.Collections.Generic.HashSet[string]]::new() |
| 60 | + |
| 61 | +function Write-SamplerError([string]$message) { |
| 62 | + try { Add-Content -LiteralPath $errorFile -Value "[$([DateTime]::UtcNow.ToString('o'))] $message" } catch { } |
| 63 | +} |
| 64 | + |
| 65 | +function Invoke-Start { |
| 66 | + try { |
| 67 | + New-Item -ItemType Directory -Force -Path $OutputDirectory | Out-Null |
| 68 | + $arguments = @( |
| 69 | + '-NoLogo', '-NoProfile', '-NonInteractive', '-ExecutionPolicy', 'Bypass', |
| 70 | + '-File', "`"$PSCommandPath`"", |
| 71 | + '-Mode', 'Sample', |
| 72 | + '-OutputDirectory', "`"$OutputDirectory`"", |
| 73 | + '-IntervalSeconds', $IntervalSeconds, |
| 74 | + '-TopProcessCount', $TopProcessCount |
| 75 | + ) |
| 76 | + $startArgs = @{ FilePath = 'pwsh'; ArgumentList = $arguments; PassThru = $true } |
| 77 | + if ($IsWindows) { $startArgs.WindowStyle = 'Hidden' } |
| 78 | + $process = Start-Process @startArgs |
| 79 | + try { $process.PriorityClass = [System.Diagnostics.ProcessPriorityClass]::BelowNormal } catch { } |
| 80 | + Set-Content -LiteralPath $pidFile -Value $process.Id |
| 81 | + Write-Host "Resource monitor started (pid $($process.Id), every $IntervalSeconds s) -> $OutputDirectory" |
| 82 | + } |
| 83 | + catch { |
| 84 | + Write-Host "::warning::Resource monitor failed to start: $_" |
| 85 | + } |
| 86 | +} |
| 87 | + |
| 88 | +function Get-CounterValues { |
| 89 | + $values = @{} |
| 90 | + try { |
| 91 | + # Counters that do not exist on this machine are skipped rather than failing the sample. |
| 92 | + $counterErrors = $null |
| 93 | + $samples = (Get-Counter -Counter @($counterPaths.Values) -ErrorAction SilentlyContinue -ErrorVariable counterErrors).CounterSamples |
| 94 | + foreach ($counterError in @($counterErrors | Where-Object { $_ })) { |
| 95 | + # Log each distinct failure once instead of on every sample. |
| 96 | + if ($script:loggedCounterErrors.Add("$counterError")) { |
| 97 | + Write-SamplerError "Get-Counter error: $counterError" |
| 98 | + } |
| 99 | + } |
| 100 | + foreach ($entry in $counterPaths.GetEnumerator()) { |
| 101 | + $leaf = $entry.Value.Split('\')[-1] |
| 102 | + $object = $entry.Value.Split('\')[1].Split('(')[0] |
| 103 | + $match = $samples | Where-Object { $_.Path -like "*\$object*\$leaf" } | Select-Object -First 1 |
| 104 | + if ($match) { $values[$entry.Key] = $match.CookedValue } |
| 105 | + } |
| 106 | + } |
| 107 | + catch { |
| 108 | + if ($script:loggedCounterErrors.Add("$_")) { |
| 109 | + Write-SamplerError "Get-Counter failed: $_" |
| 110 | + } |
| 111 | + } |
| 112 | + return $values |
| 113 | +} |
| 114 | + |
| 115 | +function Format-Number($value, [string]$format = 'F1') { |
| 116 | + if ($null -eq $value) { return '' } |
| 117 | + return ([double]$value).ToString($format, [System.Globalization.CultureInfo]::InvariantCulture) |
| 118 | +} |
| 119 | + |
| 120 | +function Invoke-Sample { |
| 121 | + $logicalProcessors = [Environment]::ProcessorCount |
| 122 | + $columns = @('TimestampUtc', 'CpuPercent', 'ProcessorQueue', 'AvailableMB', 'CommittedPercent', 'CommittedGB', 'CommitLimitGB', |
| 123 | + 'PagesPerSec', 'PageFilePercent', 'DiskQueueLength', 'DiskPercentTime', 'SystemDriveFreeGB', 'WorkspaceDriveFreeGB', 'ProcessCount') |
| 124 | + if (-not (Test-Path -LiteralPath $csvFile)) { |
| 125 | + Set-Content -LiteralPath $csvFile -Value ($columns -join ',') |
| 126 | + } |
| 127 | + |
| 128 | + $systemRoot = if ($env:SystemDrive) { "$($env:SystemDrive)\" } else { [System.IO.Path]::GetPathRoot($PSHOME) } |
| 129 | + $workspaceRoot = if ($env:GITHUB_WORKSPACE) { [System.IO.Path]::GetPathRoot($env:GITHUB_WORKSPACE) } else { $systemRoot } |
| 130 | + $previousCpu = @{} |
| 131 | + $previousTime = $null |
| 132 | + |
| 133 | + while ($true) { |
| 134 | + $sampleStart = [DateTime]::UtcNow |
| 135 | + try { |
| 136 | + $counters = Get-CounterValues |
| 137 | + |
| 138 | + $systemFree = $null |
| 139 | + $workspaceFree = $null |
| 140 | + try { $systemFree = [System.IO.DriveInfo]::new($systemRoot).AvailableFreeSpace / 1GB } catch { } |
| 141 | + try { $workspaceFree = [System.IO.DriveInfo]::new($workspaceRoot).AvailableFreeSpace / 1GB } catch { } |
| 142 | + |
| 143 | + $processes = @(Get-Process -ErrorAction SilentlyContinue) |
| 144 | + $now = [DateTime]::UtcNow |
| 145 | + $currentCpu = @{} |
| 146 | + $cpuRows = foreach ($p in $processes) { |
| 147 | + $total = $null |
| 148 | + try { $total = $p.TotalProcessorTime.TotalSeconds } catch { } |
| 149 | + if ($null -eq $total) { continue } |
| 150 | + $key = "$($p.Id):$($p.ProcessName)" |
| 151 | + $currentCpu[$key] = $total |
| 152 | + if ($null -eq $previousTime) { continue } |
| 153 | + $delta = $null |
| 154 | + if ($previousCpu.ContainsKey($key)) { |
| 155 | + $delta = $total - $previousCpu[$key] |
| 156 | + } |
| 157 | + else { |
| 158 | + # A process that started during this interval spent all of its CPU time in it. |
| 159 | + try { |
| 160 | + if ($p.StartTime.ToUniversalTime() -ge $previousTime) { $delta = $total } |
| 161 | + } |
| 162 | + catch { } |
| 163 | + } |
| 164 | + $elapsed = ($now - $previousTime).TotalSeconds |
| 165 | + if ($null -ne $delta -and $elapsed -gt 0) { |
| 166 | + [pscustomobject]@{ Process = $p; Percent = 100 * $delta / $elapsed / $logicalProcessors } |
| 167 | + } |
| 168 | + } |
| 169 | + $previousCpu = $currentCpu |
| 170 | + $previousTime = $now |
| 171 | + |
| 172 | + $row = @( |
| 173 | + $sampleStart.ToString('o'), |
| 174 | + (Format-Number $counters.CpuPercent), |
| 175 | + (Format-Number $counters.ProcessorQueue 'F0'), |
| 176 | + (Format-Number $counters.AvailableMB 'F0'), |
| 177 | + (Format-Number $counters.CommittedPercent), |
| 178 | + (Format-Number $(if ($null -ne $counters.CommittedBytes) { $counters.CommittedBytes / 1GB }) 'F2'), |
| 179 | + (Format-Number $(if ($null -ne $counters.CommitLimitBytes) { $counters.CommitLimitBytes / 1GB }) 'F2'), |
| 180 | + (Format-Number $counters.PagesPerSec 'F0'), |
| 181 | + (Format-Number $counters.PageFilePercent), |
| 182 | + (Format-Number $counters.DiskQueueLength 'F2'), |
| 183 | + (Format-Number $counters.DiskPercentTime), |
| 184 | + (Format-Number $systemFree 'F1'), |
| 185 | + (Format-Number $workspaceFree 'F1'), |
| 186 | + $processes.Count |
| 187 | + ) |
| 188 | + Add-Content -LiteralPath $csvFile -Value ($row -join ',') |
| 189 | + |
| 190 | + $topCpu = $cpuRows | Sort-Object Percent -Descending | Select-Object -First $TopProcessCount | |
| 191 | + ForEach-Object { "$($_.Process.ProcessName)[$($_.Process.Id)] $(Format-Number $_.Percent)%" } |
| 192 | + $topMemory = $processes | Sort-Object WorkingSet64 -Descending | Select-Object -First $TopProcessCount | |
| 193 | + ForEach-Object { "$($_.ProcessName)[$($_.Id)] ws=$(Format-Number ($_.WorkingSet64 / 1MB) 'F0')MB private=$(Format-Number ($_.PrivateMemorySize64 / 1MB) 'F0')MB" } |
| 194 | + Add-Content -LiteralPath $processFile -Value @( |
| 195 | + "[$($sampleStart.ToString('o'))]", |
| 196 | + " cpu: $($topCpu -join '; ')", |
| 197 | + " mem: $($topMemory -join '; ')" |
| 198 | + ) |
| 199 | + } |
| 200 | + catch { |
| 201 | + Write-SamplerError "Sample failed: $_" |
| 202 | + } |
| 203 | + |
| 204 | + $remaining = $IntervalSeconds - ([DateTime]::UtcNow - $sampleStart).TotalSeconds |
| 205 | + if ($remaining -gt 0) { Start-Sleep -Milliseconds ([int]($remaining * 1000)) } |
| 206 | + } |
| 207 | +} |
| 208 | + |
| 209 | +function Get-Stat([object[]]$rows, [string]$column, [string]$kind) { |
| 210 | + $values = @($rows | ForEach-Object { $_.$column } | Where-Object { $_ -ne '' -and $null -ne $_ } | |
| 211 | + ForEach-Object { [double]::Parse($_, [System.Globalization.CultureInfo]::InvariantCulture) }) |
| 212 | + if ($values.Count -eq 0) { return 'n/a' } |
| 213 | + $measure = $values | Measure-Object -Maximum -Minimum -Average |
| 214 | + switch ($kind) { |
| 215 | + 'max' { return Format-Number $measure.Maximum } |
| 216 | + 'min' { return Format-Number $measure.Minimum } |
| 217 | + 'avg' { return Format-Number $measure.Average } |
| 218 | + } |
| 219 | +} |
| 220 | + |
| 221 | +function Invoke-Stop { |
| 222 | + try { |
| 223 | + if (Test-Path -LiteralPath $pidFile) { |
| 224 | + $samplerPid = [int](Get-Content -LiteralPath $pidFile -Raw) |
| 225 | + try { [System.Diagnostics.Process]::GetProcessById($samplerPid).Kill($true) } catch { } |
| 226 | + Remove-Item -LiteralPath $pidFile -Force -ErrorAction SilentlyContinue |
| 227 | + } |
| 228 | + |
| 229 | + if (-not (Test-Path -LiteralPath $csvFile)) { |
| 230 | + Write-Host 'Resource monitor produced no samples.' |
| 231 | + return |
| 232 | + } |
| 233 | + |
| 234 | + $rows = @(Import-Csv -LiteralPath $csvFile) |
| 235 | + if ($rows.Count -eq 0) { |
| 236 | + Write-Host 'Resource monitor produced no samples.' |
| 237 | + return |
| 238 | + } |
| 239 | + $maxGap = 0 |
| 240 | + for ($i = 1; $i -lt $rows.Count; $i++) { |
| 241 | + $gap = ([DateTime]::Parse($rows[$i].TimestampUtc, $null, 'RoundtripKind') - [DateTime]::Parse($rows[$i - 1].TimestampUtc, $null, 'RoundtripKind')).TotalSeconds |
| 242 | + if ($gap -gt $maxGap) { $maxGap = $gap } |
| 243 | + } |
| 244 | + # Surface collection failures: an empty core counter column means Get-Counter is not working. |
| 245 | + $missingCounters = @('CpuPercent', 'AvailableMB', 'CommittedPercent', 'CommittedGB', 'CommitLimitGB', 'PageFilePercent', 'DiskQueueLength' | Where-Object { |
| 246 | + $column = $_ |
| 247 | + -not ($rows | Where-Object { $_.$column -ne '' -and $null -ne $_.$column }) |
| 248 | + }) |
| 249 | + if ($missingCounters.Count -gt 0) { |
| 250 | + Write-Host "::warning::Resource monitor collected no values for: $($missingCounters -join ', '). See sampler.log in the artifact." |
| 251 | + } |
| 252 | + $highCpuSamples = @($rows | Where-Object { $_.CpuPercent -ne '' -and [double]::Parse($_.CpuPercent, [System.Globalization.CultureInfo]::InvariantCulture) -ge 90 }).Count |
| 253 | + |
| 254 | + $summary = @( |
| 255 | + '### Windows runner resource monitor', |
| 256 | + '', |
| 257 | + "Samples: $($rows.Count), first $($rows[0].TimestampUtc), last $($rows[-1].TimestampUtc), largest gap between samples $(Format-Number $maxGap 'F0') s (a gap far above the interval means the machine stalled).", |
| 258 | + '', |
| 259 | + '| Metric | Average | Peak / minimum |', |
| 260 | + '|---|---|---|', |
| 261 | + "| CPU % | $(Get-Stat $rows CpuPercent avg) | max $(Get-Stat $rows CpuPercent max) ($highCpuSamples samples >= 90%) |", |
| 262 | + "| Processor queue length | $(Get-Stat $rows ProcessorQueue avg) | max $(Get-Stat $rows ProcessorQueue max) |", |
| 263 | + "| Available memory MB | $(Get-Stat $rows AvailableMB avg) | min $(Get-Stat $rows AvailableMB min) |", |
| 264 | + "| Commit charge % | $(Get-Stat $rows CommittedPercent avg) | max $(Get-Stat $rows CommittedPercent max) (limit $(Get-Stat $rows CommitLimitGB max) GB) |", |
| 265 | + "| Page file usage % | $(Get-Stat $rows PageFilePercent avg) | max $(Get-Stat $rows PageFilePercent max) |", |
| 266 | + "| Hard-fault paging pages/s | $(Get-Stat $rows PagesPerSec avg) | max $(Get-Stat $rows PagesPerSec max) |", |
| 267 | + "| Disk queue length | $(Get-Stat $rows DiskQueueLength avg) | max $(Get-Stat $rows DiskQueueLength max) |", |
| 268 | + "| System drive free GB | $(Get-Stat $rows SystemDriveFreeGB avg) | min $(Get-Stat $rows SystemDriveFreeGB min) |", |
| 269 | + "| Workspace drive free GB | $(Get-Stat $rows WorkspaceDriveFreeGB avg) | min $(Get-Stat $rows WorkspaceDriveFreeGB min) |", |
| 270 | + '', |
| 271 | + "Raw samples and top processes are in the job's diagnostics artifact under ``$(Split-Path -Leaf $OutputDirectory)``." |
| 272 | + ) |
| 273 | + $summary | ForEach-Object { Write-Host $_ } |
| 274 | + if ($env:GITHUB_STEP_SUMMARY) { |
| 275 | + Add-Content -LiteralPath $env:GITHUB_STEP_SUMMARY -Value $summary |
| 276 | + } |
| 277 | + } |
| 278 | + catch { |
| 279 | + Write-Host "::warning::Resource monitor summary failed: $_" |
| 280 | + } |
| 281 | +} |
| 282 | + |
| 283 | +try { |
| 284 | + switch ($Mode) { |
| 285 | + 'Start' { Invoke-Start } |
| 286 | + 'Sample' { Invoke-Sample } |
| 287 | + 'Stop' { Invoke-Stop } |
| 288 | + } |
| 289 | +} |
| 290 | +catch { |
| 291 | + Write-Host "::warning::Resource monitor $Mode failed: $_" |
| 292 | +} |
| 293 | +exit 0 |
0 commit comments