RP412/tools/podium-repro/loop.ps1

# Repeated launches of the podium rig - escalation step 2.
#
# One mission per process is all the game gives you: the teardown IS the
# exit. So more teardowns means running the whole rig again, not raising
# -Races, and that is what this does.
#
# The point of the loop is samples. A single clean run of an intermittent
# fault says almost nothing; twenty says something. What it must never do is
# count a launch that never got to the podium as one of those samples - an
# earlier attempt did exactly that, allowing three seconds between launches
# so the next field came up on ports the last one had not released, sat
# through the race timeout with nothing placed, and recorded it as a clean
# result. Hence Wait-Quiet, and hence every iteration having to PROVE it
# reached the stand before it counts.
#
#   powershell -NoProfile -ExecutionPolicy Bypass -File tools\podium-repro\loop.ps1
#
# Page heap must already be on (elevated, once, before the loop):
#   & 'C:\Program Files (x86)\Windows Kits\10\Debuggers\x86\gflags.exe' -i rpl4opt.exe +hpa
#   ...loop.ps1 -Iterations 20 -PodCount 4
#   & '...gflags.exe' -i rpl4opt.exe -hpa
param(
  [int]$Iterations = 20,
  [ValidateRange(2, 8)]
  [int]$PodCount = 4,
  [string]$Scratch = "$env:TEMP\rp412-podium-repro",
  # cdbrun-gflags.txt: no PEB fiddling, so gflags is the only mechanism in
  # play. cdbrun.txt's PEB trick is dead on Windows 26200 (see README).
  [string]$CdbScript = 'cdbrun-gflags.txt',
  [int]$RaceSeconds = 45,
  [string]$ReleaseExe = 'C:\VWE\RP412\Release\rpl4opt.exe',
  # Run without the heap instrument on purpose. Says so in the tally.
  [switch]$AllowNoPageHeap
)

$ErrorActionPreference = 'Stop'
$rig = Split-Path -Parent $MyInvocation.MyCommand.Path
$tally = Join-Path $Scratch 'loop-tally.log'

function Log([string]$m) {
  $line = "{0} {1}" -f (Get-Date -Format 'HH:mm:ss'), $m
  Write-Output $line
  Add-Content -Path $tally -Value $line -ErrorAction SilentlyContinue
}

#-----------------------------------------------------------------
# Pre-flight: is the instrument actually on?
#
# gflags -hpa clears GlobalFlag but leaves PageHeapFlags behind, so
# PageHeapFlags alone means nothing - GlobalFlag is the one that decides.
# This reads HKLM, which does NOT need elevation, unlike gflags itself.
#-----------------------------------------------------------------
$ifeo = 'HKLM:\SOFTWARE\Microsoft\Windows NT\CurrentVersion\Image File Execution Options\rpl4opt.exe'
$pageHeapOn = $false
if (Test-Path $ifeo) {
  $gf = (Get-ItemProperty $ifeo -Name GlobalFlag -ErrorAction SilentlyContinue).GlobalFlag
  if ($null -ne $gf) {
    #
    # gflags writes GlobalFlag as a STRING in hex ("0x02000000"), not a
    # DWORD, so this has to parse rather than cast - and other tools write
    # it as a plain decimal string, so handle both.
    #
    $text = ([string]$gf).Trim()
    $gfv = 0
    if ($text -match '^0[xX]([0-9a-fA-F]+)$') {
      $gfv = [Convert]::ToUInt32($Matches[1], 16)
    } elseif ($text -match '^\d+$') {
      $gfv = [Convert]::ToUInt32($text, 10)
    }
    if ($gfv -band 0x02000000) { $pageHeapOn = $true }   # FLG_HEAP_PAGE_ALLOCS
  }
}

New-Item -ItemType Directory -Force $Scratch | Out-Null
Log "=== podium repro loop: $Iterations x $PodCount pods ==="

if (-not $pageHeapOn) {
  Log 'PAGE HEAP IS OFF (IFEO GlobalFlag lacks FLG_HEAP_PAGE_ALLOCS)'
  if (-not $AllowNoPageHeap) {
    Log 'Refusing to run. From an ELEVATED shell:'
    Log "  & 'C:\Program Files (x86)\Windows Kits\10\Debuggers\x86\gflags.exe' -i rpl4opt.exe +hpa"
    Log '  ...then re-run this loop, and afterwards -hpa to put it back.'
    Log 'Or pass -AllowNoPageHeap to gather uninstrumented samples on purpose.'
    exit 1
  }
  Log 'CONTINUING UNINSTRUMENTED - these samples cannot catch an overrun or a'
  Log 'double free, only a fault that happens to land on its own.'
} else {
  Log 'page heap ON (IFEO GlobalFlag has FLG_HEAP_PAGE_ALLOCS)'
}

#-----------------------------------------------------------------
# Put THIS build in the sandboxes.
#
# Each pod dir keeps its own copy of the exe, planted by setup.ps1. Run a
# batch without refreshing it and you test whatever was built whenever
# setup.ps1 last ran - so a freshly fixed bug reproduces perfectly, on the
# binary that still has it, and reads as the fix having failed. That
# happened: the fix went in at 11:20 and a 20-launch batch trapped at the
# same address on the 09:33 exe.
#-----------------------------------------------------------------
if (-not (Test-Path $ReleaseExe)) {
  Log "ReleaseExe missing: $ReleaseExe - build Release first"
  exit 1
}
$relHash = (Get-FileHash $ReleaseExe -Algorithm MD5).Hash
$refreshed = 0
for ($i = 0; $i -lt $PodCount; $i++) {
  $podDir = Join-Path $Scratch ('pod' + [char](65 + $i))
  if (Test-Path $podDir) {
    Copy-Item $ReleaseExe (Join-Path $podDir 'rpl4opt.exe') -Force
    $refreshed++
  } else {
    Log "pod dir missing: $podDir - run setup.ps1 -PodCount $PodCount first"
    exit 1
  }
}
Log "exe: $($relHash.Substring(0,12)) built $((Get-Item $ReleaseExe).LastWriteTime.ToString('MM-dd HH:mm:ss')) -> $refreshed pod(s)"

#-----------------------------------------------------------------
# A quiet machine before each launch.
#
# Not a sleep: leftover pods hold their console and game ports, and the
# next field cannot bind them. Wait for the processes to be gone AND the
# ports to leave TIME_WAIT, or say plainly that they did not.
#-----------------------------------------------------------------
$ports = @()
for ($i = 0; $i -lt $PodCount; $i++) { $ports += (1501 + 100 * $i); $ports += (1502 + 100 * $i) }

function Wait-Quiet([int]$TimeoutSeconds = 120) {
  Get-Process rpl4opt, cdb -ErrorAction SilentlyContinue |
    Stop-Process -Force -Confirm:$false -ErrorAction SilentlyContinue

  $deadline = (Get-Date).AddSeconds($TimeoutSeconds)
  while ((Get-Date) -lt $deadline) {
    $live = @(Get-Process rpl4opt, cdb -ErrorAction SilentlyContinue).Count
    $held = @(Get-NetTCPConnection -LocalPort $ports -ErrorAction SilentlyContinue).Count
    if ($live -eq 0 -and $held -eq 0) { return $true }
    Start-Sleep -Seconds 2
  }
  $live = @(Get-Process rpl4opt, cdb -ErrorAction SilentlyContinue).Count
  $held = @(Get-NetTCPConnection -LocalPort $ports -ErrorAction SilentlyContinue).Count
  Log "  still busy after ${TimeoutSeconds}s: $live process(es), $held port(s)"
  return $false
}

# A real fault, not the normal exit-at-teardown. cdb's `g` returns on exit
# too, so the break banner alone means nothing - ExceptionAddress is the tell.
function Find-Trap {
  Get-ChildItem $Scratch -Filter 'pod?-cdb.log' -ErrorAction SilentlyContinue | ForEach-Object {
    $e = Select-String -Path $_.FullName -Pattern 'ExceptionAddress' -ErrorAction SilentlyContinue
    if ($e) { "$($_.Name): $($e[0].Line.Trim())" }
  }
}

# Wipe every pod's log before a launch, so a podium line found afterwards
# can only have come from THIS launch. Without this the check reads the
# previous run's log and reports a launch that never happened as a clean
# sample - which it did, twice, before this existed.
function Clear-PodLogs {
  for ($i = 0; $i -lt $PodCount; $i++) {
    $log = Join-Path $Scratch (('pod' + [char](65 + $i)) + '\rpl4.log')
    Remove-Item $log -Force -ErrorAction SilentlyContinue
  }
}

# The launch only counts if every pod actually stood on the podium, in a log
# written after the launch began. Both halves matter.
function Count-Placed([datetime]$since) {
  $n = 0
  for ($i = 0; $i -lt $PodCount; $i++) {
    $log = Join-Path $Scratch (('pod' + [char](65 + $i)) + '\rpl4.log')
    if (Test-Path $log) {
      $file = Get-Item $log
      if ($file.LastWriteTime -ge $since -and
          (Select-String -Path $log -Pattern 'WinnersCircle: \d+ placed' -ErrorAction SilentlyContinue)) {
        $n++
      }
    }
  }
  return $n
}

$valid = 0; $invalid = 0; $trapped = $false

for ($iter = 1; $iter -le $Iterations; $iter++) {
  Log "---------- launch $iter of $Iterations ----------"

  if (-not (Wait-Quiet)) {
    Log "  launch ${iter}: SKIPPED - machine never went quiet"
    $invalid++
    continue
  }

  #
  # To a file, not down the pipeline. Under $ErrorActionPreference='Stop'
  # a native command's stderr comes back as ErrorRecords and the first
  # warning the feeder prints would end the loop - which is how the first
  # version of this died on launch 1. It also leaves a per-launch record.
  #
  Clear-PodLogs
  $launchedAt = Get-Date

  #
  # An argument ARRAY, because `powershell -File` cannot take a switch in
  # the -Switch:$value form - it arrives as a string and the callee refuses
  # it, which silently turned two launches into no launch at all.
  #
  $feedArgs = @(
    '-NoProfile', '-ExecutionPolicy', 'Bypass',
    '-File', (Join-Path $rig 'feeder.ps1'),
    '-PodCount', $PodCount, '-Races', 1,
    '-RaceSeconds', $RaceSeconds, '-CdbScript', $CdbScript
  )
  if ($AllowNoPageHeap) { $feedArgs += '-AllowNoPageHeap' }

  $runLog = Join-Path $Scratch ("loop-run-{0:d3}.log" -f $iter)
  $previousEAP = $ErrorActionPreference
  $ErrorActionPreference = 'Continue'
  try {
    & powershell @feedArgs *> $runLog
  } finally {
    $ErrorActionPreference = $previousEAP
  }
  Select-String -Path $runLog -Pattern 'FINAL SCORE|ABORTING|console connect FAILED' -ErrorAction SilentlyContinue |
    ForEach-Object { Log "  $($_.Line)" }

  $trap = Find-Trap
  if ($trap) {
    Log '*** TRAPPED ***'
    $trap | ForEach-Object { Log "  $_" }
    Log '  everything LEFT UP and dumps preserved - do not clean this one'
    $trapped = $true
    break
  }

  $placed = Count-Placed $launchedAt
  if ($placed -eq $PodCount) {
    $valid++
    Log "  launch ${iter}: VALID sample - $placed of $PodCount reached the podium, no fault"
  } else {
    $invalid++
    Log "  launch ${iter}: INVALID - only $placed of $PodCount reached the podium (proves nothing)"
  }

  # ~580 MB per pod per launch; a 20-launch loop would be 46 GB
  Get-ChildItem $Scratch -Recurse -Filter 'podbreak*.dmp' -ErrorAction SilentlyContinue |
    Remove-Item -Force -ErrorAction SilentlyContinue

  Log "  running tally: $valid valid, $invalid invalid"
}

Log '=== LOOP DONE ==='
if ($trapped) {
  Log "TRAPPED after $valid valid sample(s). Read the pod?-cdb.log after"
  Log '=== POD BREAK ===, and !heap -p -a on the plug address: the free stack'
  Log 'that is NOT ~JointedMover is the first free, and that is the bug.'
} else {
  Log "$valid valid sample(s), $invalid invalid, NO fault."
  if (-not $pageHeapOn) {
    Log 'UNINSTRUMENTED - not evidence of absence.'
  } else {
    Log 'Full page heap was on throughout, so a double free or an overrun in'
    Log 'this path would have trapped. It did not happen in these samples.'
  }
}
Log "tally: $tally"