test: correlate original MSVC invocations with calibrated PDB events

.github/workflows/pdb-file-trace.yml

@@ -4,6 +4,8 @@ on:
   pull_request:
     paths:
       - 'cpp/tests/platform/windows/pdb_file_event_probe.cpp'
+      - 'cpp/tests/platform/windows/msvc_service_ownership_probe.cpp'
+      - 'tests/native/verify_pdb_invocations.py'
       - 'tests/native/collect_pdb_file_trace.ps1'
       - 'tests/native/verify_pdb_file_trace.py'
       - '.github/workflows/pdb-file-trace.yml'
@@ -27,6 +29,8 @@ jobs:
         run: |
           python tests/native/verify_pdb_file_trace.py --self-test --output .mqb/file-trace-contracts.json
           if ($LASTEXITCODE -ne 0) { exit $LASTEXITCODE }
+          python tests/native/verify_pdb_invocations.py --self-test --output .mqb/invocation-contracts.json
+          if ($LASTEXITCODE -ne 0) { exit $LASTEXITCODE }
           $tokens=$null; $errors=$null
           [void][Management.Automation.Language.Parser]::ParseFile(
             (Join-Path $PWD 'tests/native/collect_pdb_file_trace.ps1'),[ref]$tokens,[ref]$errors)
@@ -35,7 +39,9 @@ jobs:
         if: always()
         with:
           name: file-trace-contracts
-          path: .mqb/file-trace-contracts.json
+          path: |
+            .mqb/file-trace-contracts.json
+            .mqb/invocation-contracts.json
           include-hidden-files: true
           retention-days: 30
   build:
@@ -120,3 +126,39 @@ jobs:
           include-hidden-files: true
           if-no-files-found: warn
           retention-days: 30
+
+  investigate:
+    name: Eight fixed historical-profile invocation traces
+    needs: [build, contract]
+    # Different disposable VM; never compile tools on the observation host.
+    runs-on: windows-latest
+    timeout-minutes: 25
+    steps:
+      - uses: actions/checkout@v7
+        with:
+          ref: ${{ github.event.pull_request.head.sha || github.sha }}
+      - uses: actions/download-artifact@v8
+        with:
+          name: file-trace-input
+          path: native-input
+      - shell: pwsh
+        env:
+          MQB_OWNERSHIP_DISPOSABLE_HOST: '1'
+        run: |
+          & ./tests/native/collect_pdb_file_trace.ps1 -InputRoot (Join-Path $PWD 'native-input') `
+            -OutputRoot (Join-Path $PWD '.mqb/pdb-invocation-trace') -RepoRoot $PWD -Study invocations
+          if ($LASTEXITCODE -ne 0) { exit $LASTEXITCODE }
+      - name: Preserve raw ETL, decoded events and original diagnostics on every outcome
+        uses: actions/upload-artifact@v7
+        if: always()
+        with:
+          name: pdb-invocation-evidence
+          path: |
+            .mqb/pdb-invocation-trace/**
+            !.mqb/pdb-invocation-trace/**/*.obj
+            !.mqb/pdb-invocation-trace/**/*.pdb
+            !.mqb/pdb-invocation-trace/**/*.pch
+            !.mqb/pdb-invocation-trace/**/*.exe
+          include-hidden-files: true
+          if-no-files-found: warn
+          retention-days: 30

cpp/tests/platform/windows/msvc_service_ownership_probe.cpp

@@ -8,6 +8,7 @@
 
 #include <algorithm>
 #include <chrono>
+#include <cstdint>
 #include <expected>
 #include <filesystem>
 #include <fstream>
@@ -388,6 +389,54 @@ void save_result(const fs::path& dir, const std::string& label, const RunResult&
               + std::to_string(result.error().native_code) + "}\n");
     }
 }
+// Set only by explicit investigation entry points, before launching any worker.
+// Each helper is a separate process. Normal matrices do not take new timestamps.
+bool record_invocation_spans = false;
+std::uint64_t invocation_tick() {
+    LARGE_INTEGER value{};
+    require(::QueryPerformanceCounter(&value) && value.QuadPart >= 0, "invocation QPC failed");
+    return static_cast<std::uint64_t>(value.QuadPart);
+}
+struct InvocationSpan {
+    fs::path directory;
+    std::string label;
+    bool enabled{record_invocation_spans};
+    std::uint64_t begin{};
+    InvocationSpan(const fs::path& dir, const std::string& name, const fs::path& executable)
+        : directory(dir), label(name) {
+        if (!enabled) return;
+        LARGE_INTEGER frequency{};
+        FILETIME created{}, exited{}, kernel{}, user{};
+        require(::QueryPerformanceFrequency(&frequency) && frequency.QuadPart > 0, "invocation QPF failed");
+        require(::GetProcessTimes(::GetCurrentProcess(), &created, &exited, &kernel, &user), "invocation owner identity failed");
+        // The compiler and fixture may reside on different volumes. Preserve
+        // the executable's native DOS-device mapping; do not guess from the ETL directory.
+        const auto executable_root = executable.root_name().wstring();
+        wchar_t executable_device[32768]{};
+        require(executable_root.size() == 2 && executable_root[1] == L':' &&
+                ::QueryDosDeviceW(executable_root.c_str(), executable_device, 32768) != 0,
+                "invocation executable device mapping unavailable");
+        begin = invocation_tick();
+        write(directory / (label + ".invocation-begin.json"),
+              "{\"schema\":1,\"clock\":\"QPC\",\"label\":" + (quoted)(label)
+              + ",\"executable\":" + (quoted)(path_text(executable))
+              + ",\"executable_dos_root\":" + (quoted)(utf8(executable_root))
+              + ",\"executable_device_root\":" + (quoted)(utf8(executable_device))
+              + ",\"owner_pid\":" + std::to_string(::GetCurrentProcessId())
+              + ",\"owner_created_filetime\":" + std::to_string(ticks(created))
+              + ",\"frequency\":" + std::to_string(frequency.QuadPart)
+              + ",\"before_run_qpc\":" + std::to_string(begin) + "}\n");
+    }
+    void finish(std::uint64_t returned, const RunResult& result) const {
+        if (!enabled) return;
+        write(directory / (label + ".invocation-end.json"),
+              "{\"schema\":1,\"before_run_qpc\":" + std::to_string(begin)
+              + ",\"after_run_qpc\":" + std::to_string(returned)
+              + ",\"infrastructure_error\":" + (result ? "false" : "true")
+              + ",\"exit_code\":" + (result ? std::to_string(result->exit_code) : "null")
+              + ",\"safe_to_transfer_write_lease\":false}\n");
+    }
+};
 RunResult invoke(const MsvcToolchain& toolchain, const fs::path& executable,
                  const fs::path& dir, const std::string& label, std::vector<std::string> arguments) {
     ProcessSpec spec;
@@ -399,8 +448,11 @@ RunResult invoke(const MsvcToolchain& toolchain, const fs::path& executable,
     for (const auto& arg : spec.arguments) command += arg + '\n';
     write(dir / (label + ".argv.txt"), command);
     WindowsProcessRunner runner;
+    InvocationSpan span{dir, label, executable};
     auto result = runner.run(spec); // Deliberately unmanaged real compiler / linker.
-    save_result(dir, label, result);
+    save_result(dir, label, result); // Original diagnostics survive a later timestamp/span-write failure.
+    const auto returned = span.enabled ? invocation_tick() : 0; // Includes diagnostic serialization.
+    span.finish(returned, result);
     return result;
 }
 int exit_code(const RunResult& r) { return r ? r->exit_code : -1; }
@@ -508,13 +560,18 @@ int root(int argc, wchar_t** argv, bool drain) {
     return stopped && exit_code(first) == 0 ? 0 : 1;
 }
 
-int measure(int argc, wchar_t** argv, bool default_endpoint, bool pdb_study = false) {
+int measure(int argc, wchar_t** argv, bool default_endpoint, bool pdb_study = false, bool failure_study = false) {
     require(argc == (pdb_study ? 8 : 7), "measure arguments");
     if (default_endpoint) require_default_host();
     const fs::path dir = fs::absolute(argv[2]);
     const std::string profile = utf8(argv[3]), origin = utf8(argv[4]), ending = utf8(argv[5]);
     const std::wstring fixture_id = argv[6];
     const bool drain = ending == "drain";
+    if (failure_study) {
+        require(default_endpoint && !pdb_study && origin == "A-started" && drain &&
+                (profile == "pch-release" || profile == "modules-debug"), "unsupported invocation study case");
+        record_invocation_spans = true;
+    }
     const bool query_enabled = !pdb_study || std::wstring{argv[7]} == L"rm-on";
     if (pdb_study) {
         require(default_endpoint && profile == "pch-release" && origin == "A-started" && drain,
@@ -556,7 +613,7 @@ int measure(int argc, wchar_t** argv, bool default_endpoint, bool pdb_study = fa
     std::stop_source stop;
     ProcessSpec a;
     a.executable = self();
-    a.arguments = {drain ? "--drain-root" : "--root", path_text(tc.identity.compiler), path_text(dir / "A"), profile,
+    a.arguments = {failure_study ? "--invocation-drain-root" : (drain ? "--drain-root" : "--root"), path_text(tc.identity.compiler), path_text(dir / "A"), profile,
                    utf8(ready_name), utf8(release_name)};
     if (drain) a.arguments.push_back(utf8(cancel_name));
     a.environment = tc.environment;
@@ -603,7 +660,7 @@ int measure(int argc, wchar_t** argv, bool default_endpoint, bool pdb_study = fa
         return result;
     };
     auto warm_owners = resource_owners(dir / "B/compiler.pdb");
-    if (pdb_study) pdb_snapshot(dir, "before-A");
+    if (pdb_study || failure_study) pdb_snapshot(dir, "before-A");
     workload(dir / "B", profile);
     std::vector<Process> active_a;
     if (drain) {
@@ -644,15 +701,15 @@ int measure(int argc, wchar_t** argv, bool default_endpoint, bool pdb_study = fa
     else require(::SetEvent(release.value) != FALSE, "release A failed");
     auto a_result = a_future.get();
     const auto settled = std::chrono::steady_clock::now();
-    if (pdb_study) pdb_snapshot(dir, "after-A");
+    if (pdb_study || failure_study) pdb_snapshot(dir, "after-A");
     const bool service_survived = alive(server.handle.value);
     // The surviving service can still own PDB resources after the A client exits.
     // An empty snapshot is not a durable no-writer certificate either.
     const auto a_owners_after = default_endpoint ? resource_owners(dir / "A/compiler.pdb") : Owners{};
     const bool a_handles_signaled = std::all_of(active_a.begin(), active_a.end(), [](const auto& p) { return !alive(p.handle.value); });
     const bool pending_dispatched = fs::exists(dir / "A/work1.argv.txt");
     auto b0_result = b0.get(), b1_result = b1.get();
-    if (pdb_study) pdb_snapshot(dir, "after-B");
+    if (pdb_study || failure_study) pdb_snapshot(dir, "after-B");
     int linked = -2, executed = -2;
     if (exit_code(b0_result) == 0 && exit_code(b1_result) == 0) {
         std::vector<std::string> args{"/NOLOGO", "/DEBUG", "/INCREMENTAL:NO", "/OUT:" + path_text(dir / "B/result.exe"),
@@ -723,11 +780,17 @@ int wmain(int argc, wchar_t** argv) {
             require(argc == 3, "identity test arguments"); return pdb_identity_self_test(fs::absolute(argv[2]));
         }
         if (mode == L"--evidence-contract-self-test") return evidence_contract_self_test();
+        if (mode == L"--invocation-drain-root") {
+            record_invocation_spans = true;
+            return root(argc, argv, true);
+        }
+        if (mode == L"--measure-invocations") return measure(argc, argv, true, false, true);
         if (mode == L"--root" || mode == L"--drain-root") return root(argc, argv, mode == L"--drain-root");
         if (mode == L"--measure-pdb") return measure(argc, argv, true, true);
         if (mode == L"--measure" || mode == L"--measure-default") return measure(argc, argv, mode == L"--measure-default");
         const bool pdb_study = mode == L"--pdb-case";
-        const bool default_endpoint = mode == L"--default-case" || pdb_study;
+        const bool failure_study = mode == L"--invocation-case";
+        const bool default_endpoint = mode == L"--default-case" || pdb_study || failure_study;
         require((mode == L"--case" || default_endpoint) && argc == (pdb_study ? 8 : 7), "case arguments");
         const fs::path dir = fs::absolute(argv[2]);
         fs::create_directories(dir);
@@ -743,7 +806,7 @@ int wmain(int argc, wchar_t** argv) {
         // No global service termination, PID-authorized kill, or product changes.
         ProcessSpec spec;
         spec.executable = self();
-        spec.arguments = {pdb_study ? "--measure-pdb" : (default_endpoint ? "--measure-default" : "--measure")};
+        spec.arguments = {failure_study ? "--measure-invocations" : (pdb_study ? "--measure-pdb" : (default_endpoint ? "--measure-default" : "--measure"))};
         for (int i = 2; i < argc; ++i) spec.arguments.push_back(utf8(argv[i]));
         std::stop_source lifetime;
         spec.cancellation = lifetime.get_token();

tests/native/collect_pdb_file_trace.ps1

@@ -2,7 +2,8 @@
 param(
     [Parameter(Mandatory)][string]$InputRoot,
     [Parameter(Mandatory)][string]$OutputRoot,
-    [string]$RepoRoot = (Join-Path $PSScriptRoot '../..')
+    [string]$RepoRoot = (Join-Path $PSScriptRoot '../..'),
+    [ValidateSet('calibration', 'invocations')][string]$Study = 'calibration'
 )
 $ErrorActionPreference = 'Stop'
 $PSNativeCommandUseErrorActionPreference = $false
@@ -41,8 +42,13 @@ Write-Json (Join-Path $OutputRoot 'identity.json') @{
 # Complete plan before the first native capture. Neither outcomes nor runtime
 # affect this budget. Boundary calibration files are not compiler PDB failures.
 $plan = @('rm-on','rm-off','rm-off','rm-on')
+if ($Study -eq 'invocations') {
+    $plan = @('pch-release','modules-debug','modules-debug','pch-release',
+              'pch-release','modules-debug','modules-debug','pch-release')
+}
+$expected = $plan.Count
 Write-Json (Join-Path $OutputRoot 'plan.json') @{
-    modes=$plan; cases=4; pairs=2; controlled_conflicts_per_trace=2; adaptive_retries=$false
+    study=$Study; modes=$plan; cases=$expected; pairs=($expected/2); controlled_conflicts_per_trace=2; adaptive_retries=$false
     readiness_wait_limit_ms=10000; negative_readiness_cases=1
     note='Positive native sharing conflicts are separate from original MSVC outcomes; no forced C1041.'
 }
@@ -54,7 +60,7 @@ New-Item -ItemType Directory -Path $negative | Out-Null
 $negativeTrace = Join-Path $negative 'trace'
 $sentinel = Join-Path $negative 'child-was-admitted.txt'
 Write-Json (Join-Path $OutputRoot 'summary.json') @{
-    expected=4; completed=0; cases=@(); not_run=4; negative_readiness_verified=$false
+    expected=$expected; completed=0; cases=@(); not_run=$expected; negative_readiness_verified=$false
     historical_cause_resolved=$false; authorizes_held_pr_merge=$false; safe_to_transfer_write_lease=$false
 }
 $negativeArguments = @('--test-withhold-file-provider',$negativeTrace,$tracer,'--test-child-sentinel',$sentinel)
@@ -87,48 +93,62 @@ foreach ($definition in @(
     }
 }
 $rows = [Collections.Generic.List[object]]::new()
-foreach ($index in 0..3) {
+foreach ($index in 0..($expected-1)) {
     $mode = $plan[$index]; $name = ('{0:D2}-{1}' -f ($index+1),$mode)
     $slot = Join-Path $OutputRoot $name
     $fixture = Join-Path $slot 'fixture'; $trace = Join-Path $slot 'trace'
     New-Item -ItemType Directory -Path $slot | Out-Null
-    $arguments = @($trace,$probe,'--pdb-case',$fixture,'pch-release','A-started','drain',('trace-'+[guid]::NewGuid().ToString('N')),$mode)
+    $profile = if ($Study -eq 'invocations') { $mode } else { 'pch-release' }
+    $probeMode = if ($Study -eq 'invocations') { '--invocation-case' } else { '--pdb-case' }
+    $arguments = @($trace,$probe,$probeMode,$fixture,$profile,'A-started','drain',('trace-'+[guid]::NewGuid().ToString('N')))
+    if ($Study -eq 'calibration') { $arguments += $mode }
     Write-Json (Join-Path $slot 'arguments.json') $arguments
     $output = @(& $tracer @arguments 2>&1); $code = $LASTEXITCODE
     $output | Set-Content -LiteralPath (Join-Path $slot 'output.txt') -Encoding utf8
     $errors = [Collections.Generic.List[string]]::new(); $originalOk=$null; $cleanup=$null
+    $outcomeExit=$null
+    if ($Study -eq 'invocations') {
+        # Always preserve original outcome diagnostics, even when the recorder
+        # failed. An independently complete trace is not compiler success.
+        & python (Join-Path $PSScriptRoot 'verify_pdb_invocations.py') --trace $trace --fixture $fixture `
+            --native-root $fixture --profile $profile --output (Join-Path $slot 'invocation-audit.json')
+        $outcomeExit=$LASTEXITCODE
+    }
     try {
         if ($code -ne 0) { throw "Native trace capture failed with $code; no retry." }
+        if ($Study -eq 'invocations' -and $outcomeExit -ne 0) { throw 'Invocation evidence or original compiler control failed.' }
         & python (Join-Path $PSScriptRoot 'verify_pdb_file_trace.py') --trace $trace --case-root $fixture --require-readiness --output (Join-Path $slot 'trace-audit.json')
         if ($LASTEXITCODE -ne 0) { throw 'Trace integrity/calibration gate failed.' }
         $envelope=Get-Content -LiteralPath (Join-Path $fixture 'default-envelope.json') -Raw | ConvertFrom-Json
         $cleanup=Test-OwnershipCleanupEnvelope $envelope
         if (-not $cleanup) { throw 'Original fixture cleanup unproven.' }
         $observation=Get-Content -LiteralPath (Join-Path $fixture 'observation.json') -Raw | ConvertFrom-Json
-        if ($observation.profile -cne 'pch-release' -or $observation.origin -cne 'A-started' -or $observation.ending -cne 'drain' -or
+        if ($observation.profile -cne $profile -or $observation.origin -cne 'A-started' -or $observation.ending -cne 'drain' -or
             $observation.endpoint_mode -cne 'default' -or $observation.safe_to_transfer_write_lease -isnot [bool] -or
             $observation.safe_to_transfer_write_lease -or $observation.safe_to_integrate_cancellation -isnot [bool] -or
             $observation.safe_to_integrate_cancellation) { throw 'Wrong original fixture identity/safety fields.' }
-        $diagnostics=@(Get-OwnershipDiagnosticErrors $fixture 'pch-release' 'A-started' 'drain' $observation)
+        $diagnostics=@(Get-OwnershipDiagnosticErrors $fixture $profile 'A-started' 'drain' $observation)
         # This prior helper is strict about successful drain controls. Preserve
         # failures as failures; do not relabel an A compiler failure as calibration.
         if ($diagnostics.Count) { throw ($diagnostics -join '; ') }
-        foreach ($i in 0..3) {
-            $query=Get-Content -LiteralPath (Join-Path $fixture "rm-query-$i.json") -Raw | ConvertFrom-Json
-            Assert-PdbQuery $query ($mode -eq 'rm-on')
-        }
-        foreach ($phase in @('before-A','after-A','after-B')) {
-            $snapshot=Get-Content -LiteralPath (Join-Path $fixture "pdb-$phase.json") -Raw | ConvertFrom-Json
-            Assert-PdbPair $snapshot.pdb; Assert-PdbPair $snapshot.pch
+        if ($Study -eq 'calibration') {
+            foreach ($i in 0..3) {
+                $query=Get-Content -LiteralPath (Join-Path $fixture "rm-query-$i.json") -Raw | ConvertFrom-Json
+                Assert-PdbQuery $query ($mode -eq 'rm-on')
+            }
+            foreach ($phase in @('before-A','after-A','after-B')) {
+                $snapshot=Get-Content -LiteralPath (Join-Path $fixture "pdb-$phase.json") -Raw | ConvertFrom-Json
+                Assert-PdbPair $snapshot.pdb; Assert-PdbPair $snapshot.pch
+            }
         }
         $capture=Get-Content -LiteralPath (Join-Path $trace 'capture.json') -Raw | ConvertFrom-Json
         $originalOk=$capture.child.exit_code -eq 0 -and $observation.lifecycle_ok -eq $true -and $observation.drain_control_ok -eq $true
         if (-not $originalOk) { throw 'Original natural-drain control failed; traced failure is not a passing control.' }
     } catch { $errors.Add($_.Exception.Message) }
-    $rows.Add([pscustomobject]@{ name=$name; mode=$mode; capture_exit=$code; cleanup_verified=$cleanup
+    $rows.Add([pscustomobject]@{ name=$name; mode=$mode; capture_exit=$code; invocation_audit_exit=$outcomeExit; cleanup_verified=$cleanup
         original_control_ok=$originalOk; accepted=($errors.Count -eq 0); errors=@($errors.ToArray()) })
     Write-Json (Join-Path $OutputRoot 'summary.json') @{
-        expected=4; completed=$rows.Count; cases=@($rows.ToArray()); not_run=(4-$rows.Count)
+        study=$Study; expected=$expected; completed=$rows.Count; cases=@($rows.ToArray()); not_run=($expected-$rows.Count)
         negative_readiness_verified=$negativeOk
         historical_cause_resolved=$false; authorizes_held_pr_merge=$false; safe_to_transfer_write_lease=$false
     }