acdream/tools/run-connected-r6-soak.ps1
Erik a755b764bf test(runtime): add unattended connected R6 soak
Drive turn, movement, jump, and combat through the production InputDispatcher so connected Release testing works without an interactive Windows desktop. Track held automation actions through normal completion and every shutdown path.

Add a seven-destination ACE route with post-liveness memory, allocation, update, fatal-log, outbound-movement, and graceful-close gates. Record dynamic ACE population changes as context instead of a false lifetime oracle, and document the accepted rebaseline.

Co-authored-by: OpenAI Codex <codex@openai.com>
2026-07-20 12:12:08 +02:00

485 lines
21 KiB
PowerShell

[CmdletBinding()]
param(
[string]$Repository = (Resolve-Path (Join-Path $PSScriptRoot '..')).Path,
[string]$Account = $env:ACDREAM_TEST_USER,
[string]$Password = $env:ACDREAM_TEST_PASS,
[switch]$SkipBuild,
[int]$LoginTimeoutSeconds = 90
)
Set-StrictMode -Version Latest
$ErrorActionPreference = 'Stop'
if ([string]::IsNullOrWhiteSpace($Account)) { $Account = 'testaccount' }
if ([string]::IsNullOrWhiteSpace($Password)) { $Password = 'testpassword' }
$destinations = @(
[pscustomobject]@{ Name = 'Caul'; Occurrence = 1; Exercise = $true },
[pscustomobject]@{ Name = 'Sawato'; Occurrence = 2; Exercise = $false },
[pscustomobject]@{ Name = 'Rynthid'; Occurrence = 3; Exercise = $false },
[pscustomobject]@{ Name = 'Aerlinthe'; Occurrence = 4; Exercise = $false },
[pscustomobject]@{ Name = 'Sawato revisit'; Occurrence = 5; Exercise = $false },
[pscustomobject]@{ Name = 'Holtburg'; Occurrence = 6; Exercise = $true },
[pscustomobject]@{ Name = 'Caul return'; Occurrence = 7; Exercise = $true }
)
$stamp = Get-Date -Format 'yyyyMMdd-HHmmss'
$logDir = Join-Path $Repository 'logs'
$null = New-Item -ItemType Directory -Force -Path $logDir
$prefix = Join-Path $logDir "connected-r6-soak-$stamp"
$stdoutLog = "$prefix.out.log"
$stderrLog = "$prefix.err.log"
$markerLog = "$prefix.markers.log"
$sampleCsv = "$prefix.samples.csv"
$reportJson = "$prefix.report.json"
$routePath = Join-Path $Repository 'tools\connected-r6-soak.route.txt'
$exe = Join-Path $Repository 'src\AcDream.App\bin\Release\net10.0\AcDream.App.exe'
$samples = [System.Collections.Generic.List[object]]::new()
$failures = [System.Collections.Generic.List[string]]::new()
$warnings = [System.Collections.Generic.List[string]]::new()
$process = $null
$stopwatch = [Diagnostics.Stopwatch]::StartNew()
$gracefulExit = $false
$exitCode = $null
function Read-LogLines([string]$Path) {
if (-not (Test-Path -LiteralPath $Path)) { return @() }
return @(Get-Content -LiteralPath $Path -ErrorAction SilentlyContinue)
}
function Write-Marker([string]$Text) {
$line = "{0:O} {1}" -f [DateTime]::UtcNow, $Text
Add-Content -LiteralPath $markerLog -Value $line
Write-Output $line
}
function Get-PatternCount([string]$Path, [string]$Pattern) {
return @(Read-LogLines $Path | Select-String -SimpleMatch $Pattern).Count
}
function Get-FrameProfiles([string]$Path) {
return @(Read-LogLines $Path | Where-Object { $_.StartsWith('[frame-prof]', [StringComparison]::Ordinal) })
}
function Wait-ForLogPattern(
[Diagnostics.Process]$Client,
[string]$Path,
[string]$Pattern,
[int]$MinimumCount,
[int]$TimeoutSeconds)
{
$deadline = [DateTime]::UtcNow.AddSeconds($TimeoutSeconds)
while ([DateTime]::UtcNow -lt $deadline) {
$Client.Refresh()
if ($Client.HasExited) {
throw "client exited with code $($Client.ExitCode) while waiting for '$Pattern'"
}
$count = Get-PatternCount $Path $Pattern
if ($count -ge $MinimumCount) { return $count }
Start-Sleep -Milliseconds 250
}
throw "timed out after $TimeoutSeconds seconds waiting for occurrence $MinimumCount of '$Pattern'"
}
function Wait-ForNextFrameProfile(
[Diagnostics.Process]$Client,
[string]$Path,
[int]$AfterCount,
[int]$TimeoutSeconds)
{
$deadline = [DateTime]::UtcNow.AddSeconds($TimeoutSeconds)
while ([DateTime]::UtcNow -lt $deadline) {
$Client.Refresh()
if ($Client.HasExited) {
throw "client exited with code $($Client.ExitCode) while waiting for a frame-prof boundary"
}
$profiles = Get-FrameProfiles $Path
if ($profiles.Count -gt $AfterCount) {
return [pscustomobject]@{ Count = $profiles.Count; Line = $profiles[-1] }
}
Start-Sleep -Milliseconds 100
}
throw "timed out after $TimeoutSeconds seconds waiting for a frame-prof boundary"
}
function Parse-FrameProfile([string]$Line) {
$values = [ordered]@{
FrameCount = $null
CpuP50Ms = $null
CpuP95Ms = $null
CpuP99Ms = $null
CpuMaxMs = $null
GpuP50Ms = $null
GpuP95Ms = $null
AllocP50Kb = $null
AllocMaxKb = $null
UpdateP50Ms = $null
UpdateP95Ms = $null
}
if ($Line -match '^\[frame-prof\] n=(?<n>\d+)') {
$values.FrameCount = [int]$Matches.n
}
if ($Line -match 'cpu_ms p50=(?<p50>[\d.]+) p95=(?<p95>[\d.]+) p99=(?<p99>[\d.]+) max=(?<max>[\d.]+)') {
$values.CpuP50Ms = [double]$Matches.p50
$values.CpuP95Ms = [double]$Matches.p95
$values.CpuP99Ms = [double]$Matches.p99
$values.CpuMaxMs = [double]$Matches.max
}
if ($Line -match 'gpu_ms p50=(?<p50>[\d.]+) p95=(?<p95>[\d.]+)') {
$values.GpuP50Ms = [double]$Matches.p50
$values.GpuP95Ms = [double]$Matches.p95
}
if ($Line -match 'alloc_kb p50=(?<p50>[\d.]+) max=(?<max>[\d.]+)') {
$values.AllocP50Kb = [double]$Matches.p50
$values.AllocMaxKb = [double]$Matches.max
}
if ($Line -match 'upd p50=(?<p50>[\d.]+) p95=(?<p95>[\d.]+)') {
$values.UpdateP50Ms = [double]$Matches.p50
$values.UpdateP95Ms = [double]$Matches.p95
}
return [pscustomobject]$values
}
function Parse-WindowTitle([string]$Title) {
$values = [ordered]@{
Fps = $null
FrameMs = $null
LoadedLandblocks = $null
TotalLandblocks = $null
EntityCount = $null
AnimationCount = $null
}
if ($Title -match 'acdream \| (?<fps>\d+) fps \| (?<ms>[\d.]+) ms \| lb (?<loaded>\d+)/(?<total>\d+) \| ent (?<ent>\d+)/anim (?<anim>\d+)') {
$values.Fps = [int]$Matches.fps
$values.FrameMs = [double]$Matches.ms
$values.LoadedLandblocks = [int]$Matches.loaded
$values.TotalLandblocks = [int]$Matches.total
$values.EntityCount = [int]$Matches.ent
$values.AnimationCount = [int]$Matches.anim
}
return [pscustomobject]$values
}
function Capture-Sample(
[Diagnostics.Process]$Client,
[string]$Destination,
[string]$Phase,
[string]$ProfileLine)
{
$Client.Refresh()
$profile = Parse-FrameProfile $ProfileLine
$title = Parse-WindowTitle $Client.MainWindowTitle
$sample = [pscustomobject][ordered]@{
Destination = $Destination
Phase = $Phase
ElapsedSeconds = [Math]::Round($stopwatch.Elapsed.TotalSeconds, 3)
WorkingSetMiB = [Math]::Round($Client.WorkingSet64 / 1MB, 1)
PrivateMiB = [Math]::Round($Client.PrivateMemorySize64 / 1MB, 1)
HandleCount = $Client.HandleCount
ThreadCount = $Client.Threads.Count
Fps = $title.Fps
TitleFrameMs = $title.FrameMs
LoadedLandblocks = $title.LoadedLandblocks
TotalLandblocks = $title.TotalLandblocks
EntityCount = $title.EntityCount
AnimationCount = $title.AnimationCount
ProfileFrames = $profile.FrameCount
CpuP50Ms = $profile.CpuP50Ms
CpuP95Ms = $profile.CpuP95Ms
CpuP99Ms = $profile.CpuP99Ms
CpuMaxMs = $profile.CpuMaxMs
GpuP50Ms = $profile.GpuP50Ms
GpuP95Ms = $profile.GpuP95Ms
AllocP50Kb = $profile.AllocP50Kb
AllocMaxKb = $profile.AllocMaxKb
UpdateP50Ms = $profile.UpdateP50Ms
UpdateP95Ms = $profile.UpdateP95Ms
Profile = $ProfileLine
}
$samples.Add($sample)
return $sample
}
function Observe-R6Exercise(
[Diagnostics.Process]$Client,
[string]$Destination,
[pscustomobject]$Before)
{
$null = Wait-ForLogPattern $Client $stdoutLog '[input] MovementForward Press' ($Before.ForwardPress + 5) 30
$null = Wait-ForLogPattern $Client $stdoutLog '[input] MovementForward Release' ($Before.ForwardRelease + 5) 10
$null = Wait-ForLogPattern $Client $stdoutLog '[input] MovementJump Press' ($Before.JumpPress + 1) 10
$null = Wait-ForLogPattern $Client $stdoutLog '[input] MovementJump Release' ($Before.JumpRelease + 1) 10
$null = Wait-ForLogPattern $Client $stdoutLog '[input] CombatToggleCombat Press' ($Before.Combat + 2) 15
$null = Wait-ForLogPattern $Client $stdoutLog 'move-truth OUT' ($Before.MoveTruth + 2) 10
$forwardPressDelta = (Get-PatternCount $stdoutLog '[input] MovementForward Press') - $Before.ForwardPress
$forwardReleaseDelta = (Get-PatternCount $stdoutLog '[input] MovementForward Release') - $Before.ForwardRelease
$jumpPressDelta = (Get-PatternCount $stdoutLog '[input] MovementJump Press') - $Before.JumpPress
$jumpReleaseDelta = (Get-PatternCount $stdoutLog '[input] MovementJump Release') - $Before.JumpRelease
$combatDelta = (Get-PatternCount $stdoutLog '[input] CombatToggleCombat Press') - $Before.Combat
$moveTruthDelta = (Get-PatternCount $stdoutLog 'move-truth OUT') - $Before.MoveTruth
if ($forwardPressDelta -lt 5 -or $forwardReleaseDelta -lt 5) {
$failures.Add("${Destination}: production forward input did not deliver five press/release pairs ($forwardPressDelta/$forwardReleaseDelta)")
}
if ($jumpPressDelta -lt 1 -or $jumpReleaseDelta -lt 1) {
$failures.Add("${Destination}: production jump input did not deliver a press/release pair ($jumpPressDelta/$jumpReleaseDelta)")
}
if ($combatDelta -lt 2) {
$failures.Add("${Destination}: combat toggle did not dispatch twice ($combatDelta)")
}
if ($moveTruthDelta -lt 2) {
$failures.Add("${Destination}: movement/jump exercise produced too few outbound movement records ($moveTruthDelta)")
}
Write-Marker "exercise destination='$Destination' forward=$forwardPressDelta/$forwardReleaseDelta jump=$jumpPressDelta/$jumpReleaseDelta combat=$combatDelta moveTruth=$moveTruthDelta"
}
function Add-RelativeGateFailures {
$caulFirst = $samples | Where-Object { $_.Destination -eq 'Caul' -and $_.Phase -eq 'stationary' } | Select-Object -First 1
$caulReturn = $samples | Where-Object { $_.Destination -eq 'Caul return' -and $_.Phase -eq 'stationary' } | Select-Object -First 1
$sawatoFirst = $samples | Where-Object { $_.Destination -eq 'Sawato' -and $_.Phase -eq 'stationary' } | Select-Object -First 1
$sawatoReturn = $samples | Where-Object { $_.Destination -eq 'Sawato revisit' -and $_.Phase -eq 'stationary' } | Select-Object -First 1
foreach ($pair in @(
[pscustomobject]@{ Label = 'Caul return'; First = $caulFirst; Return = $caulReturn },
[pscustomobject]@{ Label = 'Sawato revisit'; First = $sawatoFirst; Return = $sawatoReturn }))
{
if ($null -eq $pair.First -or $null -eq $pair.Return) {
$failures.Add("$($pair.Label): missing same-location stationary sample")
continue
}
# A connected ACE world is not a fixed fixture: generators can spawn or
# despawn creatures while this four-minute route is away from a location.
# Keep the counts in the report as a population/workload signal, but do
# not mistake an authoritative server population change for a client
# lifetime leak. Retention is gated below through same-location memory,
# allocation, and update-cost growth; deterministic lifecycle ownership
# remains covered by LiveEntityLifecycleStressTests.
if ($pair.First.EntityCount -ne $pair.Return.EntityCount) {
$warnings.Add("$($pair.Label): connected entity population changed $($pair.First.EntityCount) -> $($pair.Return.EntityCount)")
}
if ($pair.First.AnimationCount -ne $pair.Return.AnimationCount) {
$warnings.Add("$($pair.Label): connected animation population changed $($pair.First.AnimationCount) -> $($pair.Return.AnimationCount)")
}
$privateLimit = [Math]::Max(384.0, $pair.First.PrivateMiB * 0.35)
$workingLimit = [Math]::Max(384.0, $pair.First.WorkingSetMiB * 0.35)
if (($pair.Return.PrivateMiB - $pair.First.PrivateMiB) -gt $privateLimit) {
$failures.Add("$($pair.Label): private memory grew by $([Math]::Round($pair.Return.PrivateMiB - $pair.First.PrivateMiB, 1)) MiB")
}
if (($pair.Return.WorkingSetMiB - $pair.First.WorkingSetMiB) -gt $workingLimit) {
$failures.Add("$($pair.Label): working set grew by $([Math]::Round($pair.Return.WorkingSetMiB - $pair.First.WorkingSetMiB, 1)) MiB")
}
if ($null -ne $pair.First.UpdateP95Ms -and $null -ne $pair.Return.UpdateP95Ms) {
$updateLimit = $pair.First.UpdateP95Ms * 1.5 + 0.5
if ($pair.Return.UpdateP95Ms -gt $updateLimit) {
$failures.Add("$($pair.Label): update p95 regressed $($pair.First.UpdateP95Ms) -> $($pair.Return.UpdateP95Ms) ms")
}
}
if ($null -ne $pair.First.AllocP50Kb -and $null -ne $pair.Return.AllocP50Kb) {
$allocLimit = $pair.First.AllocP50Kb * 1.5 + 16.0
if ($pair.Return.AllocP50Kb -gt $allocLimit) {
$failures.Add("$($pair.Label): allocation p50 regressed $($pair.First.AllocP50Kb) -> $($pair.Return.AllocP50Kb) KiB/frame")
}
}
}
}
function Add-LogFailures {
$fatalPatterns = @(
'Unhandled exception',
'AccessViolation',
'OutOfMemoryException',
'WeenieError',
'device removed',
'GPU reset',
'live: disconnected'
)
foreach ($pattern in $fatalPatterns) {
$count = (Get-PatternCount $stdoutLog $pattern) + (Get-PatternCount $stderrLog $pattern)
if ($count -gt 0) { $failures.Add("diagnostic '$pattern' appeared $count time(s)") }
}
$missingVfx = (Get-PatternCount $stderrLog 'No PhysicsScriptTable') +
(Get-PatternCount $stderrLog 'ParticleEmitterInfo')
if ($missingVfx -gt 0) {
$warnings.Add("DAT-driven VFX diagnostics: $missingVfx missing table/emitter message(s)")
}
$missingLandblocks = Get-PatternCount $stdoutLog 'LandblockLoader.Load returned null'
if ($missingLandblocks -gt 0) {
$warnings.Add("World-edge empty landblocks: $missingLandblocks load miss(es)")
}
}
function Close-ClientGracefully([Diagnostics.Process]$Client) {
$Client.Refresh()
if ($Client.HasExited) { return $true }
$requested = $Client.CloseMainWindow()
if (-not $requested) { return $false }
if (-not $Client.WaitForExit(30000)) { return $false }
$Client.WaitForExit()
return $true
}
if (-not (Test-Path -LiteralPath $routePath)) { throw "route file not found: $routePath" }
if (@(Get-Process -Name AcDream.App -ErrorAction SilentlyContinue).Count -gt 0) {
throw 'an AcDream.App client is already running; close it gracefully before the soak'
}
$udpOwner = @(Get-NetUDPEndpoint -LocalPort 9000 -ErrorAction SilentlyContinue)
if ($udpOwner.Count -eq 0) {
throw 'local ACE is not listening on UDP port 9000'
}
if (-not $SkipBuild) {
Write-Output 'Building Release solution...'
& dotnet build (Join-Path $Repository 'AcDream.slnx') -c Release --no-restore
if ($LASTEXITCODE -ne 0) { throw "Release build failed with exit code $LASTEXITCODE" }
}
if (-not (Test-Path -LiteralPath $exe)) { throw "client executable not found: $exe" }
$commit = (& git -C $Repository rev-parse HEAD).Trim()
$sourceStatus = @(& git -C $Repository status --short)
$videoControllers = @(Get-CimInstance Win32_VideoController -ErrorAction SilentlyContinue | ForEach-Object {
[pscustomobject]@{ Name = $_.Name; DriverVersion = $_.DriverVersion; AdapterRam = $_.AdapterRAM }
})
$env:ACDREAM_DAT_DIR = "$env:USERPROFILE\Documents\Asheron's Call"
$env:ACDREAM_LIVE = '1'
$env:ACDREAM_TEST_HOST = '127.0.0.1'
$env:ACDREAM_TEST_PORT = '9000'
$env:ACDREAM_TEST_USER = $Account
$env:ACDREAM_TEST_PASS = $Password
$env:ACDREAM_RETAIL_UI = '1'
$env:ACDREAM_FRAME_PROF = '1'
$env:ACDREAM_UNCAPPED_RENDER = '1'
$env:ACDREAM_DEVTOOLS = '0'
$env:ACDREAM_UI_PROBE_DUMP = '0'
$env:ACDREAM_UI_PROBE_SCRIPT = $routePath
$env:ACDREAM_DUMP_MOVE_TRUTH = '1'
$env:ACDREAM_NO_AUDIO = $null
$env:ACDREAM_WB_DIAG = $null
try {
$process = Start-Process -FilePath $exe -WorkingDirectory $Repository `
-RedirectStandardOutput $stdoutLog -RedirectStandardError $stderrLog -PassThru
Write-Marker "launch pid=$($process.Id) commit=$commit session='$env:SESSIONNAME'"
$null = Wait-ForLogPattern $process $stdoutLog 'live: in world' 1 $LoginTimeoutSeconds
$null = Wait-ForLogPattern $process $stdoutLog 'live: first player position' 1 $LoginTimeoutSeconds
Write-Marker ("in-world elapsed={0:N1}s" -f $stopwatch.Elapsed.TotalSeconds)
foreach ($destination in $destinations) {
$null = Wait-ForLogPattern $process $stdoutLog 'live: teleport materialized' $destination.Occurrence 60
Write-Marker ("materialized destination='{0}' occurrence={1} elapsed={2:N1}s" -f `
$destination.Name, $destination.Occurrence, $stopwatch.Elapsed.TotalSeconds)
$exerciseBaseline = [pscustomobject]@{
ForwardPress = Get-PatternCount $stdoutLog '[input] MovementForward Press'
ForwardRelease = Get-PatternCount $stdoutLog '[input] MovementForward Release'
JumpPress = Get-PatternCount $stdoutLog '[input] MovementJump Press'
JumpRelease = Get-PatternCount $stdoutLog '[input] MovementJump Release'
Combat = Get-PatternCount $stdoutLog '[input] CombatToggleCombat Press'
MoveTruth = Get-PatternCount $stdoutLog 'move-truth OUT'
}
$null = Wait-ForLogPattern $process $stdoutLog '[input] MovementTurnRight Press' $destination.Occurrence 25
$turnProfileStart = (Get-FrameProfiles $stdoutLog).Count
$turnResult = Wait-ForNextFrameProfile $process $stdoutLog $turnProfileStart 12
$turnSample = Capture-Sample $process $destination.Name 'turn' $turnResult.Line
Write-Marker "turn-sample destination='$($destination.Name)' cpuP95=$($turnSample.CpuP95Ms) gpuP95=$($turnSample.GpuP95Ms)"
$null = Wait-ForLogPattern $process $stdoutLog '[input] MovementTurnRight Release' $destination.Occurrence 12
# LiveEntityLivenessController's authoritative absence deadline is 25
# seconds. Sample only after that deadline so a previous destination's
# records cannot masquerade as retained memory in the return gate.
Start-Sleep -Seconds 12
$stationaryProfileStart = (Get-FrameProfiles $stdoutLog).Count
$stationaryResult = Wait-ForNextFrameProfile $process $stdoutLog $stationaryProfileStart 12
$stationarySample = Capture-Sample $process $destination.Name 'stationary' $stationaryResult.Line
Write-Marker "stationary-sample destination='$($destination.Name)' wsMiB=$($stationarySample.WorkingSetMiB) privateMiB=$($stationarySample.PrivateMiB) ent=$($stationarySample.EntityCount) anim=$($stationarySample.AnimationCount) updateP95=$($stationarySample.UpdateP95Ms)"
if ($destination.Exercise) {
Observe-R6Exercise $process $destination.Name $exerciseBaseline
}
}
if ((Get-PatternCount $stdoutLog 'live: teleport materialized') -ne $destinations.Count) {
$failures.Add("expected $($destinations.Count) teleport materializations")
}
Add-RelativeGateFailures
Add-LogFailures
Write-Marker 'route-complete requesting graceful close'
$gracefulExit = Close-ClientGracefully $process
$process.Refresh()
if ($process.HasExited) { $exitCode = [int]$process.ExitCode }
if (-not $gracefulExit) { $failures.Add('client did not exit through the graceful WM_CLOSE path') }
if ($null -ne $exitCode -and $exitCode -ne 0) { $failures.Add("client exit code was $exitCode") }
}
catch {
$failures.Add($_.Exception.Message)
Write-Marker "ERROR $($_.Exception.Message)"
}
finally {
if ($null -ne $process) {
$process.Refresh()
if (-not $process.HasExited) {
$gracefulExit = Close-ClientGracefully $process
if (-not $gracefulExit -and -not $process.HasExited) {
$failures.Add('client remained alive 30 seconds after WM_CLOSE and required forced termination')
Stop-Process -Id $process.Id -Force
$process.WaitForExit(10000)
}
}
if ($process.HasExited -and $null -eq $exitCode) { $exitCode = [int]$process.ExitCode }
$process.Dispose()
}
$samples | Export-Csv -LiteralPath $sampleCsv -NoTypeInformation
$report = [pscustomobject][ordered]@{
Passed = $failures.Count -eq 0
StartedUtc = [DateTime]::UtcNow.Subtract($stopwatch.Elapsed).ToString('O')
FinishedUtc = [DateTime]::UtcNow.ToString('O')
ElapsedSeconds = [Math]::Round($stopwatch.Elapsed.TotalSeconds, 3)
Commit = $commit
SessionName = $env:SESSIONNAME
ExitCode = $exitCode
GracefulExit = $gracefulExit
Failures = @($failures)
Warnings = @($warnings)
SourceStatus = $sourceStatus
VideoControllers = $videoControllers
Samples = @($samples)
Artifacts = [pscustomobject]@{
Stdout = $stdoutLog
Stderr = $stderrLog
Markers = $markerLog
SamplesCsv = $sampleCsv
ReportJson = $reportJson
}
}
$report | ConvertTo-Json -Depth 8 | Set-Content -LiteralPath $reportJson -Encoding utf8
Write-Output "REPORT=$reportJson"
Write-Output "SAMPLES=$sampleCsv"
Write-Output "RESULT=$(if ($report.Passed) { 'PASS' } else { 'FAIL' })"
foreach ($failure in $failures) { Write-Output "FAILURE=$failure" }
foreach ($warning in $warnings) { Write-Output "WARNING=$warning" }
}
if ($failures.Count -gt 0) { exit 1 }