diff --git a/docs/internal/retrospective-audit/AUDIT-015.json b/docs/internal/retrospective-audit/AUDIT-015.json new file mode 100644 index 00000000..e27efc90 --- /dev/null +++ b/docs/internal/retrospective-audit/AUDIT-015.json @@ -0,0 +1,119 @@ +{ + "schema_version": 1, + "slice_id": "AUDIT-015", + "baseline_sha": "f6273467710f596276183a808f34333d6bf3457e", + "baseline_tree": "d1d72d809024de69c5ceac740b7c0fa4b27f73b4", + "scope_manifest_sha256": "dee51e602834a18e9db858c1a90c9d437c828adba36ead360ff41fa6ec3fc904", + "paths_sha256": "2e3a6aaa024a3eeb8633090aa646336afaf04c867de6271208447890687e2ab8", + "fixed_upstream": { + "commit": "eacb323fbde3eff94d4f2ee7baacb059d84b8e3a", + "tree": "dfbaaf9ce75f9adc625352396acaa9138a8b97f8", + "boundary": "The fixed upstream tree contains product behavior but not these downstream internal cache-preparation scripts. The helper is a necessary modern Player-readiness replacement rather than upstream product behavior; no upstream anchor applies to either owned script, so both entries record explicit empty anchor lists." + }, + "scope": { + "path_count": 2, + "normalization": "Sorted UTF-8 relative paths joined by LF with no trailing LF.", + "implementation_paths": [ + "scripts/internal/prepare-player-cache.ps1", + "scripts/internal/test-player-cache-preparation.ps1" + ], + "changed_paths": [ + "scripts/internal/test-player-cache-preparation.ps1", + "docs/internal/retrospective-audit/AUDIT-015.json" + ] + }, + "entries": [ + { + "path": "scripts/internal/prepare-player-cache.ps1", + "classification": "INDEPENDENT_REIMPLEMENTATION", + "upstream_anchors": [], + "finding_ids": [], + "disposition": "NO_FINDING" + }, + { + "path": "scripts/internal/test-player-cache-preparation.ps1", + "classification": "INDEPENDENT_REIMPLEMENTATION", + "upstream_anchors": [], + "finding_ids": [ + "AUDIT-015-001" + ], + "disposition": "RESOLVED" + } + ], + "findings": [ + { + "id": "AUDIT-015-001", + "path": "scripts/internal/test-player-cache-preparation.ps1", + "severity": "HIGH", + "summary": "The integrated AUDIT-011 causal LastWriteTimeUtc probes changed one destination file and one directory without restoring their original timestamps before the idempotence rerun.", + "upstream_behavior": "The fixed upstream commit has no cache-preparation or synthetic audit equivalent. This is downstream workflow behavior and is intentionally replaced for the modern Fabric Player-readiness boundary.", + "incompatibility_at_base": "At exact master base f6273467710f596276183a808f34333d6bf3457e, the file and directory probes wrote and read back the fixed 2001-02-03T04:05:06Z and 2002-03-04T05:06:07Z values, then proceeded directly to the rerun snapshot without restoring the originals. The base suite still exited 0 because that rerun snapshot was taken after the mutations, making the no-mutation comparison a false positive.", + "replacement": "Capture the original UTC values before each probe, run the existing snapshot assertions after the causal write, and restore the original value in an exception-safe finally path. Set-LastWriteTimeUtcAndVerify verifies each restoration read-back. Forced file and directory assertion failures exercise the same path, and a complete post-restoration snapshot must equal the pre-probe snapshot before idempotence is tested.", + "resolution_scope": "DOWNSTREAM_SYNTHETIC_AUDIT_HARNESS_ONLY", + "cross_item_dependencies": [], + "preserved_contract": [ + "Complete snapshot retains path set, file/directory type, non-access attributes, reparse state, LastWriteTimeUtc, and file content hash/size.", + "LastAccessTimeUtc remains excluded and is never compared.", + "prepare-player-cache.ps1 is unchanged, retaining canonical/reparse/path escape checks, bounded owned-helper cleanup, official index/object size and SHA-1 checks, and live lock/daemon exclusion.", + "Existing synthetic negative cases and pinned fixture/index/object identities remain unchanged." + ], + "automated_evidence": [ + "Exact-base reproduction before editing: pwsh.exe -NoLogo -NoProfile -File .\\scripts\\internal\\test-player-cache-preparation.ps1 exited 0 with PLAYER_CACHE_PREPARATION_TESTS_OK count=17, while a disposable timestamp trace recorded originalsRestoredBeforeRerun=false and causalProbeLeavesMutation=true after the two causal writes.", + "Candidate focused suite: pwsh.exe -NoLogo -NoProfile -File .\\scripts\\internal\\test-player-cache-preparation.ps1 exited 0 with PLAYER_CACHE_PREPARATION_TESTS_OK count=17, including verified file/directory restoration before rerun, forced assertion-failure restoration, and complete post-restoration snapshot equality.", + "Both executable paths parsed successfully through the PowerShell AST parser; git diff --check passed.", + "The candidate source implementation is 99b28eb56ee9459bfab81d109d2e53493b97783a with tree b0e6a8810ed3bde61511ddc33e47449a4918cca5; only the test harness changed in that implementation commit.", + "No product, Player, GUI, gameplay input, telemetry, updater, Discord, Proxy, DevAuth, OneConfig, Forge, or unrelated infrastructure path was changed." + ], + "status": "RESOLVED" + } + ], + "verification": { + "resource_profile": "HEAVY", + "pending_command": null, + "sha_model": "implementation_sha/implementation_tree identify the executable implementation commit; the audit report is a later publication commit on the same branch and does not record its own publication commit identity.", + "implementation_sha": "99b28eb56ee9459bfab81d109d2e53493b97783a", + "implementation_tree": "b0e6a8810ed3bde61511ddc33e47449a4918cca5", + "branch": "codex/audit-015-lastwrite-restoration", + "pull_request": "https://github.com/Hylfrd/FarmHelper/pull/16", + "commands": [ + "Exact-base reproduction before editing: pwsh.exe -NoLogo -NoProfile -File .\\scripts\\internal\\test-player-cache-preparation.ps1; exit 0, false-positive timestamp trace recorded.", + "Candidate focused PowerShell synthetic suite run twice: exit 0; PLAYER_CACHE_PREPARATION_TESTS_OK count=17 on both runs.", + "PowerShell AST parse for scripts/internal/prepare-player-cache.ps1 and scripts/internal/test-player-cache-preparation.ps1: passed.", + "git diff --check: passed.", + ".\\gradlew.bat --no-daemon --console=plain test using worktree-local GRADLE_USER_HOME: BUILD SUCCESSFUL in 5m21s.", + ".\\gradlew.bat --offline --no-daemon --console=plain verifyDependencyProvenance: BUILD SUCCESSFUL in 11s; 3 runtime dependencies, 1 platform dependency, Loom 1.17.17.", + ".\\gradlew.bat --offline --no-daemon --console=plain check: BUILD SUCCESSFUL in 8s.", + ".\\gradlew.bat --offline --no-daemon --console=plain clean build: BUILD SUCCESSFUL in 35s; 12 actionable tasks executed." + ], + "publication_checkpoint_ci": { + "status": "SUCCESS", + "pull_request_number": 16, + "pending_checks": 0, + "workflow_runs": [ + 33318362660, + 33318365017 + ], + "verified_head": "3a9b2ce96ebdfbae2dfa8cd8775d2e70a029bdd5", + "observed": "GitHub reported Linux/build, Linux/test, Windows/build, and Windows/test passed for both workflow runs at immutable publication checkpoint 3a9b2ce96ebdfbae2dfa8cd8775d2e70a029bdd5." + }, + "external_evidence": "Report-tip CI and exact Review are external GitHub/Reviewer evidence and intentionally not self-recorded in this report.", + "resource_observations": { + "gradle_user_home": "C:\\Users\\Apostrophe\\.codex\\worktrees\\9eea\\farm-helper\\.gradle\\audit-015-user-home", + "java": "BellSoft Liberica 25.0.3", + "gradle": "9.5.1", + "daemon_mode": "All Gradle commands used --no-daemon; Gradle forked and stopped its required single-use daemon.", + "wrapper_bootstrap": "The first isolated wrapper download did not produce bytes and was terminated after its exact child process was verified; the existing extracted Gradle 9.5.1 distribution was copied into the isolated wrapper cache without copying locks or daemon state.", + "user_cache_mutated": false, + "copied_locks_or_daemon_state": false, + "oom": false, + "disk_saturation": false, + "repeated_resource_failure": false + }, + "forbidden_boundaries": [ + "No master push or history rewrite was performed.", + "No progress.md, control, test.md, product source, or unrelated path was edited.", + "No current Player task, GUI, gameplay input, or live-client interaction was performed." + ], + "blockers": [] + } +} diff --git a/scripts/internal/test-player-cache-preparation.ps1 b/scripts/internal/test-player-cache-preparation.ps1 index f5815493..9cd5bd05 100644 --- a/scripts/internal/test-player-cache-preparation.ps1 +++ b/scripts/internal/test-player-cache-preparation.ps1 @@ -83,6 +83,106 @@ function Set-LastWriteTimeUtcAndVerify { return $storedUtc } +function Invoke-LastWriteTimeProbe { + param( + [Parameter(Mandatory = $true)] + [string] $Path, + + [Parameter(Mandatory = $true)] + [DateTime] $Original, + + [Parameter(Mandatory = $true)] + [DateTime] $ProbeTimestamp, + + [Parameter(Mandatory = $true)] + [string] $Description, + + [Parameter(Mandatory = $true)] + [scriptblock] $ProbeAction + ) + + $originalUtc = [DateTime]::SpecifyKind($Original, [DateTimeKind]::Utc) + $probeFailure = $null + $restorationFailures = [System.Collections.Generic.List[string]]::new() + try { + $storedProbeUtc = Set-LastWriteTimeUtcAndVerify ` + -Path $Path ` + -Expected $ProbeTimestamp + & $ProbeAction $storedProbeUtc | Out-Null + } catch { + $probeFailure = $_ + } finally { + try { + $restoredUtc = Set-LastWriteTimeUtcAndVerify ` + -Path $Path ` + -Expected $originalUtc + if ($restoredUtc.Ticks -ne $originalUtc.Ticks) { + throw "$Description LastWriteTimeUtc restoration read-back mismatch." + } + } catch { + [void] $restorationFailures.Add($_.Exception.Message) + } + } + + if ($restorationFailures.Count -gt 0) { + $restorationMessage = "$Description LastWriteTimeUtc restoration failed: " + + ($restorationFailures -join '; ') + if ($null -ne $probeFailure) { + throw "$($probeFailure.Exception.Message); $restorationMessage" + } + throw $restorationMessage + } + if ($null -ne $probeFailure) { + throw $probeFailure.Exception + } +} + +function Assert-LastWriteTimeProbeFailureRestores { + param( + [Parameter(Mandatory = $true)] + [string] $Path, + + [Parameter(Mandatory = $true)] + [DateTime] $Original, + + [Parameter(Mandatory = $true)] + [DateTime] $ProbeTimestamp, + + [Parameter(Mandatory = $true)] + [string] $Description + ) + + $failureObserved = $false + try { + Invoke-LastWriteTimeProbe ` + -Path $Path ` + -Original $Original ` + -ProbeTimestamp $ProbeTimestamp ` + -Description $Description ` + -ProbeAction { + param($storedProbeUtc) + Assert-True ` + -Condition $false ` + -Message 'Intentional LastWriteTimeUtc probe assertion failure.' + } | Out-Null + } catch { + $failureObserved = $true + Assert-True ` + -Condition ($_.Exception.Message -match 'Intentional LastWriteTimeUtc probe assertion failure') ` + -Message "$Description failure-path probe failed for the wrong reason: $($_.Exception.Message)" + } + Assert-True ` + -Condition $failureObserved ` + -Message "$Description failure-path probe unexpectedly passed." + + $restoredItem = Get-Item -LiteralPath $Path -Force -ErrorAction Stop + $restoredUtc = [DateTime]::SpecifyKind([DateTime] $restoredItem.LastWriteTimeUtc, [DateTimeKind]::Utc) + $originalUtc = [DateTime]::SpecifyKind($Original, [DateTimeKind]::Utc) + Assert-True ` + -Condition ($restoredUtc.Ticks -eq $originalUtc.Ticks) ` + -Message "$Description LastWriteTimeUtc was not restored after the forced assertion failure." +} + function New-AssetFixture { param( [Parameter(Mandatory = $true)] @@ -622,6 +722,12 @@ try { $timestampFilePath = Join-Path $destinationRoot 'bin\loom.bin' $timestampDirectoryPath = Join-Path $destinationRoot 'nested\deep' + $fileOriginalLastWriteTimeUtc = [DateTime]::SpecifyKind( + [DateTime] (Get-Item -LiteralPath $timestampFilePath -Force -ErrorAction Stop).LastWriteTimeUtc, + [DateTimeKind]::Utc) + $directoryOriginalLastWriteTimeUtc = [DateTime]::SpecifyKind( + [DateTime] (Get-Item -LiteralPath $timestampDirectoryPath -Force -ErrorAction Stop).LastWriteTimeUtc, + [DateTimeKind]::Utc) $snapshotBeforeLastWriteProbe = Get-SourceSnapshot -Root $destinationRoot $fileBeforeLastWriteProbe = Get-SnapshotEntry ` -Snapshot $snapshotBeforeLastWriteProbe ` @@ -630,56 +736,94 @@ try { -Snapshot $snapshotBeforeLastWriteProbe ` -Path 'nested\deep' $fileProbeTimestamp = [DateTime]::new(2001, 2, 3, 4, 5, 6, 0, [DateTimeKind]::Utc) - $storedFileProbeTimestamp = Set-LastWriteTimeUtcAndVerify ` + Invoke-LastWriteTimeProbe ` -Path $timestampFilePath ` - -Expected $fileProbeTimestamp - $snapshotAfterFileLastWriteProbe = Get-SourceSnapshot -Root $destinationRoot - $fileAfterLastWriteProbe = Get-SnapshotEntry ` - -Snapshot $snapshotAfterFileLastWriteProbe ` - -Path 'bin\loom.bin' - Assert-SnapshotEntryChangedOnlyByLastWrite ` - -Before $fileBeforeLastWriteProbe ` - -After $fileAfterLastWriteProbe ` - -Path 'bin\loom.bin' + -Original $fileOriginalLastWriteTimeUtc ` + -ProbeTimestamp $fileProbeTimestamp ` + -Description 'File' ` + -ProbeAction { + param($storedFileProbeTimestamp) + $snapshotAfterFileLastWriteProbe = Get-SourceSnapshot -Root $destinationRoot + $fileAfterLastWriteProbe = Get-SnapshotEntry ` + -Snapshot $snapshotAfterFileLastWriteProbe ` + -Path 'bin\loom.bin' + Assert-SnapshotEntryChangedOnlyByLastWrite ` + -Before $fileBeforeLastWriteProbe ` + -After $fileAfterLastWriteProbe ` + -Path 'bin\loom.bin' + Assert-True ` + -Condition ((Get-SnapshotLastWriteTimeText -Entry $fileAfterLastWriteProbe) -eq (Get-StableUtcTimestamp -Value $storedFileProbeTimestamp)) ` + -Message 'File snapshot did not serialize the verified UTC LastWriteTime value.' + } + $fileAfterLastWriteRestore = Get-Item -LiteralPath $timestampFilePath -Force -ErrorAction Stop + $fileAfterLastWriteRestoreUtc = [DateTime]::SpecifyKind( + [DateTime] $fileAfterLastWriteRestore.LastWriteTimeUtc, + [DateTimeKind]::Utc) Assert-True ` - -Condition ((Get-SnapshotLastWriteTimeText -Entry $fileAfterLastWriteProbe) -eq (Get-StableUtcTimestamp -Value $storedFileProbeTimestamp)) ` - -Message 'File snapshot did not serialize the verified UTC LastWriteTime value.' + -Condition ($fileAfterLastWriteRestoreUtc.Ticks -eq $fileOriginalLastWriteTimeUtc.Ticks) ` + -Message 'File LastWriteTimeUtc was not restored before the idempotence rerun.' + $lastWriteTimestampPattern = '^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{7}Z$' $directoryProbeTimestamp = [DateTime]::new(2002, 3, 4, 5, 6, 7, 0, [DateTimeKind]::Utc) - $storedDirectoryProbeTimestamp = Set-LastWriteTimeUtcAndVerify ` + Invoke-LastWriteTimeProbe ` -Path $timestampDirectoryPath ` - -Expected $directoryProbeTimestamp - $snapshotAfterDirectoryLastWriteProbe = Get-SourceSnapshot -Root $destinationRoot - $directoryAfterLastWriteProbe = Get-SnapshotEntry ` - -Snapshot $snapshotAfterDirectoryLastWriteProbe ` - -Path 'nested\deep' - Assert-SnapshotEntryChangedOnlyByLastWrite ` - -Before $directoryBeforeLastWriteProbe ` - -After $directoryAfterLastWriteProbe ` - -Path 'nested\deep' + -Original $directoryOriginalLastWriteTimeUtc ` + -ProbeTimestamp $directoryProbeTimestamp ` + -Description 'Directory' ` + -ProbeAction { + param($storedDirectoryProbeTimestamp) + $snapshotAfterDirectoryLastWriteProbe = Get-SourceSnapshot -Root $destinationRoot + $directoryAfterLastWriteProbe = Get-SnapshotEntry ` + -Snapshot $snapshotAfterDirectoryLastWriteProbe ` + -Path 'nested\deep' + Assert-SnapshotEntryChangedOnlyByLastWrite ` + -Before $directoryBeforeLastWriteProbe ` + -After $directoryAfterLastWriteProbe ` + -Path 'nested\deep' + Assert-True ` + -Condition ((Get-SnapshotLastWriteTimeText -Entry $directoryAfterLastWriteProbe) -eq (Get-StableUtcTimestamp -Value $storedDirectoryProbeTimestamp)) ` + -Message 'Directory snapshot did not serialize the verified UTC LastWriteTime value.' + $lastWriteSnapshotData = ConvertFrom-SnapshotJson -Snapshot $snapshotAfterDirectoryLastWriteProbe + $entriesMissingLastWrite = @($lastWriteSnapshotData.entries | Where-Object { + [string]::IsNullOrEmpty((Get-SnapshotLastWriteTimeText -Entry $_)) + }) + Assert-True ` + -Condition ($entriesMissingLastWrite.Count -eq 0) ` + -Message 'Complete-tree snapshot omitted a deterministic LastWriteTimeUtc value.' + Assert-True ` + -Condition (@($lastWriteSnapshotData.entries | Where-Object { + (Get-SnapshotLastWriteTimeText -Entry $_) -notmatch $lastWriteTimestampPattern + }).Count -eq 0) ` + -Message 'Complete-tree snapshot LastWriteTimeUtc values were not stable UTC strings.' + Assert-True ` + -Condition (@($lastWriteSnapshotData.entries | Where-Object { + $_.PSObject.Properties.Name -contains 'lastAccessTimeUtc' + }).Count -eq 0) ` + -Message 'Complete-tree snapshot included excluded LastAccessTimeUtc state.' + } + $directoryAfterLastWriteRestore = Get-Item -LiteralPath $timestampDirectoryPath -Force -ErrorAction Stop + $directoryAfterLastWriteRestoreUtc = [DateTime]::SpecifyKind( + [DateTime] $directoryAfterLastWriteRestore.LastWriteTimeUtc, + [DateTimeKind]::Utc) Assert-True ` - -Condition ((Get-SnapshotLastWriteTimeText -Entry $directoryAfterLastWriteProbe) -eq (Get-StableUtcTimestamp -Value $storedDirectoryProbeTimestamp)) ` - -Message 'Directory snapshot did not serialize the verified UTC LastWriteTime value.' + -Condition ($directoryAfterLastWriteRestoreUtc.Ticks -eq $directoryOriginalLastWriteTimeUtc.Ticks) ` + -Message 'Directory LastWriteTimeUtc was not restored before the idempotence rerun.' - $lastWriteTimestampPattern = '^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{7}Z$' - $lastWriteSnapshotData = ConvertFrom-SnapshotJson -Snapshot $snapshotAfterDirectoryLastWriteProbe - $entriesMissingLastWrite = @($lastWriteSnapshotData.entries | Where-Object { - [string]::IsNullOrEmpty((Get-SnapshotLastWriteTimeText -Entry $_)) - }) - Assert-True ` - -Condition ($entriesMissingLastWrite.Count -eq 0) ` - -Message 'Complete-tree snapshot omitted a deterministic LastWriteTimeUtc value.' - Assert-True ` - -Condition (@($lastWriteSnapshotData.entries | Where-Object { - (Get-SnapshotLastWriteTimeText -Entry $_) -notmatch $lastWriteTimestampPattern - }).Count -eq 0) ` - -Message 'Complete-tree snapshot LastWriteTimeUtc values were not stable UTC strings.' + Assert-LastWriteTimeProbeFailureRestores ` + -Path $timestampFilePath ` + -Original $fileOriginalLastWriteTimeUtc ` + -ProbeTimestamp ([DateTime]::new(2003, 4, 5, 6, 7, 8, 0, [DateTimeKind]::Utc)) ` + -Description 'File' + Assert-LastWriteTimeProbeFailureRestores ` + -Path $timestampDirectoryPath ` + -Original $directoryOriginalLastWriteTimeUtc ` + -ProbeTimestamp ([DateTime]::new(2004, 5, 6, 7, 8, 9, 0, [DateTimeKind]::Utc)) ` + -Description 'Directory' + $snapshotAfterLastWriteRestoration = Get-SourceSnapshot -Root $destinationRoot Assert-True ` - -Condition (@($lastWriteSnapshotData.entries | Where-Object { - $_.PSObject.Properties.Name -contains 'lastAccessTimeUtc' - }).Count -eq 0) ` - -Message 'Complete-tree snapshot included excluded LastAccessTimeUtc state.' - Write-Output 'TEST_OK tree snapshot detects file and directory LastWriteTimeUtc changes without content mutation and excludes LastAccessTimeUtc' + -Condition ($snapshotBeforeLastWriteProbe -eq $snapshotAfterLastWriteRestoration) ` + -Message 'LastWriteTimeUtc probes changed the complete destination snapshot after restoration.' + Write-Output 'TEST_OK file and directory LastWriteTimeUtc restoration before rerun and after forced probe assertion failures' $script:passCount++ $destinationSnapshotBeforeRerun = Get-SourceSnapshot -Root $destinationRoot