[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=(?\d+)') { $values.FrameCount = [int]$Matches.n } if ($Line -match 'cpu_ms p50=(?[\d.]+) p95=(?[\d.]+) p99=(?[\d.]+) 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=(?[\d.]+) p95=(?[\d.]+)') { $values.GpuP50Ms = [double]$Matches.p50 $values.GpuP95Ms = [double]$Matches.p95 } if ($Line -match 'alloc_kb p50=(?[\d.]+) max=(?[\d.]+)') { $values.AllocP50Kb = [double]$Matches.p50 $values.AllocMaxKb = [double]$Matches.max } if ($Line -match 'upd p50=(?[\d.]+) 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 \| (?\d+) fps \| (?[\d.]+) ms \| lb (?\d+)/(?\d+) \| ent (?\d+)/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 }