From 58c88ecbdcebddcd2e96e48597063161f5bfeb0e Mon Sep 17 00:00:00 2001 From: fadwen <110697945+fadwen@users.noreply.github.com> Date: Mon, 5 Oct 2026 10:43:46 -0700 Subject: [PATCH] fix(validation): Collect took another command's output from the guest agent for a payload chunk The QEMU guest agent keeps a result until a status call collects it and answers a call for a process id with the oldest result it holds under that id; Windows reuses the ids. The driver's synchronous qm guest exec, retried on a timeout, left results behind, and a later chunk read given the same id got an earlier chunk back: the right length, the wrong text. That is the JSON error reported in #4. GuestAgent.ps1 now carries the guest calls for the driver and Invoke-LabGuestScript.ps1. A command is started without waiting and its result asked for by process id; every command prints a marker of its own and a result without it is passed over; a result lost to a status call that timed out makes the command run again. The device reports a SHA-256 with the payload size and the assembled payload is checked against it. The detached launch sits behind a started marker, since a second runner skips the script and writes the done marker at once. --- CHANGELOG.md | 6 + Validation/GuestAgent.ps1 | 217 ++++++++++++++ Validation/Invoke-LabGuestScript.ps1 | 42 +-- Validation/Invoke-ValidationRound.ps1 | 82 ++---- Validation/README.md | 24 +- .../Unit/Invoke-ValidationRound.Tests.ps1 | 275 ++++++++++++++++-- 6 files changed, 522 insertions(+), 124 deletions(-) create mode 100644 Validation/GuestAgent.ps1 diff --git a/CHANGELOG.md b/CHANGELOG.md index 3c9ee5e..5313502 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -49,6 +49,12 @@ release notes. - Validation round 10 (Findings, "PowerShell 7 at run time, a built credential, and the drives SYSTEM sees"): seven remediations on the joined device, and `New-IslDriveFixture.ps1` in the kit for the drive state one of them reports on. +- Validation kit: `Collect` failed on a device payload in which one chunk had arrived as another + chunk's text. The QEMU guest agent answers a status call with the oldest result it holds for a + process id, and Windows reuses the ids. `GuestAgent.ps1` now carries the guest calls for the + driver and `Invoke-LabGuestScript.ps1`: every command prints a marker of its own, a result + without it is passed over, a result lost to a timed-out status call makes the command run + again, and the payload is checked against the device's SHA-256. - The README and `Get-IntuneAnalyzerRulePath`'s help say what `Invoke-ScriptAnalyzer -Severity` does with the custom rules: PSScriptAnalyzer 1.25.0 filters on the rule's registered severity, Warning for every custom rule, so `-Severity Error` returns none of the records and diff --git a/Validation/GuestAgent.ps1 b/Validation/GuestAgent.ps1 new file mode 100644 index 0000000..57a4222 --- /dev/null +++ b/Validation/GuestAgent.ps1 @@ -0,0 +1,217 @@ +# Running PowerShell inside a lab VM through the QEMU guest agent, over SSH to the Proxmox host. +# Dot-sourced by Invoke-ValidationRound.ps1 and Invoke-LabGuestScript.ps1, whose $ProxmoxHost and +# $VmId parameters the function reads, and kept apart from them so it can be unit-tested with ssh +# mocked and without the driver's #Requires lines. + +function Invoke-GuestPowerShell { + <# + .SYNOPSIS + Runs a PowerShell snippet as SYSTEM inside the VM and returns its stdout. + + .DESCRIPTION + The guest agent starts a command and hands back its process id; the result is asked for by + that id and stays with the agent until a status call collects it. Measured on the lab + device (README.md, "Timing notes"): + + A result nobody collects is kept. Windows reuses process ids within minutes, and the agent + answers a status call with the oldest result it holds for the id, so a later command given + the same id got an earlier command's output: the right shape, the wrong content. A payload + chunk replaced that way is what broke Collect on 2026-10-05. "qm guest exec" leaves such + results behind whenever its own status poll times out while the command is still running. + + A status call that times out on the host has still been answered by the agent: if the + command had finished, its result was handed over and is gone. + + So the command is started without waiting ("qm guest exec --synchronous 0"), its result is + asked for by id until it arrives, and every command prints a marker of its own first. A + reply without the marker is somebody else's result: asking for it collected it, and the + next reply under the id is this command's. When the agent holds nothing for the id after a + status call timed out, the result went with that call and the command is run again. + + A snippet therefore has to be safe to repeat, as before; what it can no longer do is come + back with another command's output. + + .PARAMETER Script + The PowerShell to run. A snippet, not a script with a param block: the marker line is put + in front of it. The guest agent's command line fails silently above a few KB. + + .PARAMETER TimeoutSeconds + How long to wait for the command to finish before giving up. Default 120. + + .EXAMPLE + Invoke-GuestPowerShell -Script '(Get-Service IntuneManagementExtension).Status' + + The agent service's state on the VM named by the caller's $VmId. + + .OUTPUTS + System.String. The command's stdout; its stderr and a non-zero exit become warnings. + #> + [CmdletBinding()] + [OutputType([string])] + param( + [Parameter(Mandatory)] + [string]$Script, + + [int]$TimeoutSeconds = 120 + ) + + $result = $null + for ($run = 1; -not $result; $run++) { + $marker = [guid]::NewGuid().ToString('N') + $encoded = [Convert]::ToBase64String([Text.Encoding]::Unicode.GetBytes("'$marker'`n$Script")) + $processId = $null + for ($attempt = 1; -not $processId; $attempt++) { + $raw = ssh -o BatchMode=yes $ProxmoxHost ("qm guest exec $VmId --synchronous 0 -- powershell " + + "-NoProfile -NonInteractive -EncodedCommand $encoded") 2>&1 + $text = ($raw -join "`n").Trim() + if ($LASTEXITCODE -eq 0 -and $text -match '"pid"\s*:\s*(\d+)') { $processId = $Matches[1]; break } + if ($attempt -ge 3) { throw "qm guest exec failed on ${ProxmoxHost}: $text" } + Write-Warning "qm guest exec attempt $attempt on ${ProxmoxHost}: $text" + Start-Sleep -Seconds 10 + } + + $deadline = (Get-Date).AddSeconds($TimeoutSeconds) + $unmarked = $null + $replyLost = $false + $failures = 0 + while (-not $result) { + Start-Sleep -Seconds 1 + $raw = ssh -o BatchMode=yes $ProxmoxHost "qm guest exec-status $VmId $processId" 2>&1 + $text = ($raw -join "`n").Trim() + if ($LASTEXITCODE -eq 0 -and $text.StartsWith('{')) { + $failures = 0 + $reply = $text | ConvertFrom-Json + if ($reply.exited) { + if ("$($reply.'out-data')".StartsWith($marker)) { $result = $reply; break } + # An earlier command's result under a reused process id; it is collected now + Write-Verbose "Process id $processId answered with another command's result; asking again" + $unmarked = $reply + } + } + elseif ($text -match 'does not exist') { + # Nothing more under this id. After a status call that timed out, the result went + # with that call's reply: run the command again + if ($replyLost) { break } + # Otherwise the reply without the marker was this command's after all: powershell.exe + # never reached the first line (a command line too long, for one) + if (-not $unmarked) { + throw "The guest agent on VM $VmId holds no result for process id $processId" + } + $result = $unmarked + break + } + else { + $failures++ + $replyLost = $true + if ($failures -ge 10) { throw "qm guest exec-status failed on ${ProxmoxHost}: $text" } + Write-Verbose "qm guest exec-status attempt $failures on ${ProxmoxHost}: $text" + } + if ((Get-Date) -gt $deadline) { + throw ("The guest command (process id $processId on VM $VmId) did not finish within " + + "$TimeoutSeconds s") + } + } + if (-not $result) { + if ($run -ge 3) { throw "The guest command's result was lost to a timed-out status call $run times" } + Write-Warning ("The result of process id $processId went with a status call that timed out; " + + 'running the command again') + } + } + + $output = "$($result.'out-data')" + if ($output.StartsWith($marker)) { $output = $output.Substring($marker.Length) -replace '^\r?\n', '' } + + # Windows PowerShell writes stderr as CLIXML: progress records ("Preparing modules for first + # use") are noise, error records are what the caller needs to read + $errorText = "$($result.'err-data')" + if ($errorText -match '#< CLIXML') { + $messages = foreach ($chunk in ($errorText -split '#< CLIXML')) { + if (-not $chunk.Trim()) { continue } + try { + foreach ($item in [System.Management.Automation.PSSerializer]::Deserialize($chunk.Trim())) { + if ($item -is [string]) { $item } + elseif ($item.PSObject.TypeNames -match 'ErrorRecord') { "$item" } + } + } + catch { $chunk.Trim() } + } + $errorText = ($messages -join "`n") + } + if ($result.exitcode -ne 0) { Write-Warning "Guest script exited $($result.exitcode): $errorText" } + elseif ($errorText.Trim()) { Write-Warning $errorText.Trim() } + elseif (-not $output) { Write-Verbose "Guest script produced no output (process id $processId)" } + $output +} + +function Read-GuestPayload { + <# + .SYNOPSIS + Fetches a base64 text file from the VM in chunks and checks it against the VM's own hash. + + .DESCRIPTION + A payload of megabytes returned in one reply makes the guest agent time out its own status + call, so it is read 100,000 characters at a time. A chunk that comes back short is asked + again. The whole text is then hashed and compared with the SHA-256 the VM computed over its + copy: a chunk with the right length and the wrong content is otherwise found only as a + parse error somewhere in the middle of the result, if at all. + + .PARAMETER RemotePath + The file on the VM. ASCII text (base64). + + .PARAMETER Size + Its length in characters, as the VM reported it. + + .PARAMETER Sha256 + The SHA-256 of its text as the VM computed it, in hex. + + .PARAMETER ChunkSize + Characters per call. Default 100000. + + .EXAMPLE + Read-GuestPayload -RemotePath 'C:\ProgramData\IntuneScriptLab\collect.b64' -Size 17838300 -Sha256 $hash + + The file's text, or an error naming both hashes when it did not arrive intact. + + .OUTPUTS + System.String. + #> + [CmdletBinding()] + [OutputType([string])] + param( + [Parameter(Mandatory)] + [string]$RemotePath, + + [Parameter(Mandatory)] + [int]$Size, + + [Parameter(Mandatory)] + [string]$Sha256, + + [int]$ChunkSize = 100000 + ) + + $parts = for ($offset = 0; $offset -lt $Size; $offset += $ChunkSize) { + $length = [Math]::Min($ChunkSize, $Size - $offset) + $read = "[IO.File]::ReadAllText('$RemotePath').Substring($offset, $length)" + # A reply without its output (the agent occasionally returns none for a large chunk) is asked again + $part = $null + for ($try = 1; $try -le 3 -and "$part".Trim().Length -ne $length; $try++) { + if ($try -gt 1) { Write-Warning "Payload chunk at $offset came back short; retrying"; Start-Sleep 5 } + $part = Invoke-GuestPowerShell -TimeoutSeconds 120 -Script $read + } + if ("$part".Trim().Length -ne $length) { throw "Payload chunk at $offset could not be read" } + "$part".Trim() + } + $text = -join $parts + $sha = [Security.Cryptography.SHA256]::Create() + try { + $digest = $sha.ComputeHash([Text.Encoding]::ASCII.GetBytes($text)) + $actual = [BitConverter]::ToString($digest) -replace '-', '' + } + finally { $sha.Dispose() } + if ($actual -ne $Sha256) { + throw ("The payload from $RemotePath did not arrive intact: $($text.Length) characters with SHA-256 " + + "$actual, the VM's copy has $Sha256") + } + $text +} diff --git a/Validation/Invoke-LabGuestScript.ps1 b/Validation/Invoke-LabGuestScript.ps1 index 8ea05d5..95cfa7e 100644 --- a/Validation/Invoke-LabGuestScript.ps1 +++ b/Validation/Invoke-LabGuestScript.ps1 @@ -51,11 +51,13 @@ System.String. The script's stdout on the VM; its stderr and a non-zero exit become warnings. .NOTES - Author: Jeffrey Stuhr. Never run two guest execs at once on the same VM; a status poll that - times out is retried, and a second exec would start a second copy. + Author: Jeffrey Stuhr. The guest agent calls are GuestAgent.ps1's: each command is started + once and its result asked for by process id, so a status call that times out is asked + again without running the script a second time. A start call that times out is retried and + can run it twice. #> [CmdletBinding()] -# ProxmoxHost is read inside Invoke-GuestPowerShell; the analyzer cannot see that +# ProxmoxHost is read inside Invoke-GuestPowerShell (GuestAgent.ps1); the analyzer cannot see that [Diagnostics.CodeAnalysis.SuppressMessageAttribute('PSReviewUnusedParameter', 'ProxmoxHost')] param( [Parameter(Mandatory)] @@ -75,39 +77,7 @@ param( $ErrorActionPreference = 'Stop' -function Invoke-GuestPowerShell { - param([Parameter(Mandatory)][string]$Script, [int]$TimeoutSeconds = 120) - $encoded = [Convert]::ToBase64String([Text.Encoding]::Unicode.GetBytes($Script)) - for ($attempt = 1; ; $attempt++) { - $raw = ssh -o BatchMode=yes $ProxmoxHost ("qm guest exec $VmId --timeout $TimeoutSeconds -- powershell " + - "-NoProfile -NonInteractive -EncodedCommand $encoded") 2>&1 - $text = ($raw -join "`n").Trim() - if ($LASTEXITCODE -eq 0 -and $text.StartsWith('{')) { break } - if ($attempt -ge 3) { throw "qm guest exec failed on ${ProxmoxHost}: $text" } - Write-Warning "qm guest exec attempt $attempt on ${ProxmoxHost}: $text" - Start-Sleep -Seconds 10 - } - $result = $text | ConvertFrom-Json - # Windows PowerShell writes stderr as CLIXML: progress records ("Preparing modules for first - # use") are noise, error records are what the caller needs to read - $errorText = "$($result.'err-data')" - if ($errorText -match '#< CLIXML') { - $messages = foreach ($chunk in ($errorText -split '#< CLIXML')) { - if (-not $chunk.Trim()) { continue } - try { - foreach ($item in [System.Management.Automation.PSSerializer]::Deserialize($chunk.Trim())) { - if ($item -is [string]) { $item } - elseif ($item.PSObject.TypeNames -match 'ErrorRecord') { "$item" } - } - } - catch { $chunk.Trim() } - } - $errorText = ($messages -join "`n") - } - if ($result.exitcode -ne 0) { Write-Warning "Guest script exited $($result.exitcode): $errorText" } - elseif ($errorText.Trim()) { Write-Warning $errorText.Trim() } - $result.'out-data' -} +. (Join-Path -Path $PSScriptRoot -ChildPath 'GuestAgent.ps1') $remote = "C:\ProgramData\IntuneScriptLab\$RemoteName" $content = Get-Content -Path (Resolve-Path -Path $ScriptPath) -Raw diff --git a/Validation/Invoke-ValidationRound.ps1 b/Validation/Invoke-ValidationRound.ps1 index 4aeeaec..a3b8096 100644 --- a/Validation/Invoke-ValidationRound.ps1 +++ b/Validation/Invoke-ValidationRound.ps1 @@ -68,6 +68,7 @@ param( $ErrorActionPreference = 'Stop' $prefix = 'ISL-' . (Join-Path -Path $PSScriptRoot -ChildPath 'GraphRules.ps1') +. (Join-Path -Path $PSScriptRoot -ChildPath 'GuestAgent.ps1') function Connect-LabGraph { if ($Action -notin 'Trigger', 'Prepare' -and -not (Get-MgContext)) { @@ -156,34 +157,10 @@ function ConvertTo-ScriptContent { } } -function Invoke-GuestPowerShell { - # Runs a script block as SYSTEM inside the VM via the QEMU guest agent; returns stdout. - param([Parameter(Mandatory)][string]$Script, [int]$TimeoutSeconds = 120) - $encoded = [Convert]::ToBase64String([Text.Encoding]::Unicode.GetBytes($Script)) - # The status poll behind qm guest exec occasionally times out at the QMP layer and prints - # "VM qmp command 'guest-exec-status' failed - got timeout" instead of the JSON reply, - # even though the command ran; an idempotent command is simply asked again - for ($attempt = 1; ; $attempt++) { - $raw = ssh -o BatchMode=yes $ProxmoxHost ("qm guest exec $VmId --timeout $TimeoutSeconds -- powershell " + - "-NoProfile -NonInteractive -EncodedCommand $encoded") 2>&1 - $text = ($raw -join "`n").Trim() - if ($LASTEXITCODE -eq 0 -and $text.StartsWith('{')) { break } - if ($attempt -ge 3) { throw "qm guest exec failed on ${ProxmoxHost}: $text" } - Write-Warning "qm guest exec attempt $attempt on ${ProxmoxHost}: $text" - Start-Sleep -Seconds 10 - } - $result = $text | ConvertFrom-Json - if ($result.exitcode -ne 0) { Write-Warning "Guest script exited $($result.exitcode): $($result.'err-data')" } - elseif (-not $result.'out-data') { - $reply = $text.Substring(0, [Math]::Min(600, $text.Length)) - Write-Verbose "Guest script produced no output; agent reply: $reply" - } - $result.'out-data' -} - function Invoke-GuestScriptFile { # Runs a script that is too long for the guest agent's command line (a few KB): the script is - # delivered as base64 in small Add-Content calls, decoded on the VM and run by path. + # delivered as base64 in numbered part files, decoded on the VM and run by path. The guest agent + # calls themselves are Invoke-GuestPowerShell's, in GuestAgent.ps1. param( [Parameter(Mandatory)][string]$Script, [int]$TimeoutSeconds = 900, @@ -194,9 +171,9 @@ function Invoke-GuestScriptFile { $remote = "C:\ProgramData\IntuneScriptLab\$RemoteName" $b64 = [Convert]::ToBase64String([Text.UTF8Encoding]::new($true).GetPreamble() + [Text.Encoding]::UTF8.GetBytes($Script)) - # One file per chunk, written with Set-Content: a chunk call retried after a host-side status timeout - # then rewrites the same part instead of appending it twice (which once produced a script that no - # longer parsed); the device joins the parts in order + # One file per chunk, written with Set-Content: a chunk call that ran twice (a start call retried + # after a host-side timeout) then rewrites the same part instead of appending it twice, which once + # produced a script that no longer parsed; the device joins the parts in order $null = Invoke-GuestPowerShell -Script "Remove-Item -Path '$remote.b64*' -ErrorAction SilentlyContinue" $index = 0 for ($offset = 0; $offset -lt $b64.Length; $offset += 1200) { @@ -214,9 +191,9 @@ function Invoke-GuestScriptFile { return Invoke-GuestPowerShell -TimeoutSeconds $TimeoutSeconds -Script ( "$decode; Set-ExecutionPolicy -Scope Process -ExecutionPolicy Bypass -Force; & '$remote'") } - # A command that runs for minutes makes the host's status poll time out, and a retry would start - # a second copy: start it detached, poll for the done marker with short calls, read the output file - foreach ($suffix in '.out', '.err', '.done') { + # A script that runs for minutes is started detached and watched through a done marker with short + # calls, so no single guest agent call has to stay open for it; its output is read from a file + foreach ($suffix in '.out', '.err', '.done', '.started') { $null = Invoke-GuestPowerShell -Script "Remove-Item -Path '$remote$suffix' -ErrorAction SilentlyContinue" } # A runner batch file carries the redirections, so the launch itself has no nested quoting; it is @@ -227,9 +204,13 @@ function Invoke-GuestScriptFile { "echo done>`"$remote.done`"" ) -join "`r`n" $runnerB64 = [Convert]::ToBase64String([Text.Encoding]::ASCII.GetBytes($runner)) - $launch = "$decode; [IO.File]::WriteAllText('$remote.cmd', " + + # A guest call can run twice (GuestAgent.ps1), and a second runner would find the output file held + # by the first, skip the script and write the done marker at once: the started marker makes a + # repeated launch a no-op + $launch = "if (-not (Test-Path -Path '$remote.started')) { " + + "Set-Content -Path '$remote.started' -Value started; $decode; [IO.File]::WriteAllText('$remote.cmd', " + "[Text.Encoding]::ASCII.GetString([Convert]::FromBase64String('$runnerB64'))); " + - "Start-Process -FilePath '$remote.cmd' -WindowStyle Hidden" + "Start-Process -FilePath '$remote.cmd' -WindowStyle Hidden }" $null = Invoke-GuestPowerShell -Script $launch $deadline = (Get-Date).AddSeconds($TimeoutSeconds) do { @@ -742,32 +723,25 @@ $ime = 'HKLM:\SOFTWARE\Microsoft\IntuneManagementExtension' # tail) made the guest agent time out its own status call $b64 = [Convert]::ToBase64String([Text.Encoding]::UTF8.GetBytes($_)) [IO.File]::WriteAllText('C:\ProgramData\IntuneScriptLab\collect.b64', $b64) - $b64.Length + # The length and a hash of the text, so the host can tell whether every chunk arrived as written + $sha = [Security.Cryptography.SHA256]::Create() + $hash = [BitConverter]::ToString($sha.ComputeHash([Text.Encoding]::ASCII.GetBytes($b64))) -replace '-', '' + "$($b64.Length) $hash" } '@ # The log filters need the policy ids; the device script is a literal, so they are spliced in $policyIds = @($remediations.Id) + @($platform.Id) | Where-Object { $_ } $deviceScript = $deviceScript.Replace('--POLICYIDS--', ($policyIds -join '|')) - $sizeText = Invoke-GuestScriptFile -Script $deviceScript -TimeoutSeconds 1500 -Detach - if (-not $sizeText) { throw 'The device collect script returned no payload size; see the warning above' } - $size = [int]$sizeText.Trim() - $chunk = 100000 - $parts = for ($offset = 0; $offset -lt $size; $offset += $chunk) { - $length = [Math]::Min($chunk, $size - $offset) - $read = "[IO.File]::ReadAllText('C:\ProgramData\IntuneScriptLab\collect.b64').Substring($offset, $length)" - # A reply without its output (the agent occasionally returns none for a large chunk) is asked again - $part = $null - for ($try = 1; $try -le 3 -and "$part".Trim().Length -ne $length; $try++) { - if ($try -gt 1) { Write-Warning "Payload chunk at $offset came back short; retrying"; Start-Sleep 5 } - $part = Invoke-GuestPowerShell -TimeoutSeconds 120 -Script $read - } - if ("$part".Trim().Length -ne $length) { throw "Payload chunk at $offset could not be read" } - "$part".Trim() - } - $encoded = -join $parts - if ($encoded.Length -ne $size) { - throw "Device payload incomplete: got $($encoded.Length) of $size characters" + $summary = Invoke-GuestScriptFile -Script $deviceScript -TimeoutSeconds 1500 -Detach + if ("$summary" -notmatch '^\s*(\d+) ([0-9A-Fa-f]{64})\s*$') { + throw "The device collect script returned no payload size and hash ('$summary'); see the warning above" + } + $payloadSplat = @{ + RemotePath = 'C:\ProgramData\IntuneScriptLab\collect.b64' + Size = [int]$Matches[1] + Sha256 = $Matches[2] } + $encoded = Read-GuestPayload @payloadSplat $device = [Text.Encoding]::UTF8.GetString([Convert]::FromBase64String($encoded)) | ConvertFrom-Json $null = New-Item -ItemType Directory -Path $ResultsPath -Force diff --git a/Validation/README.md b/Validation/README.md index c9d8107..e1654ec 100644 --- a/Validation/README.md +++ b/Validation/README.md @@ -12,6 +12,7 @@ with the documented behaviour next to the observed one. | `Probe.ps1` | Header prepended to every experiment. Records user, bitness, PowerShell version, command line, encoding and paths to `C:\ProgramData\IntuneScriptLab\.jsonl` on the device. Windows PowerShell 5.1 only. | | `Experiments.psd1` | The experiments: `Remediations`, `PlatformScripts` and `Win32Apps`. Each has a `Question`, a script body and optional `RunAs32Bit`, `RunAsAccount`, `Bom`, `Requirement`. Win32 entries can also carry `DetectionRules` / `RequirementRules` (file, registry, product code and script rule specs), `Intent` (`required` or `uninstall`), `EnforceSignatureCheck`, `Requirements` (base requirement properties by Graph name), `Filter` (an assignment filter rule and mode), `InstallContext`, `DependsOn`, `Supersedes`, `Assign = $false` and `Package` (a real MSI); remediations a `Schedule` (`RunOnce`, `Daily` or hourly with an `Interval`) and `DetectOnly`. | | `GraphRules.ps1` | Builds the Graph rule objects (`win32LobAppFileSystemRule`, `win32LobAppRegistryRule`, `win32LobAppProductCodeRule`, `win32LobAppPowerShellScriptRule`) and remediation run schedules from experiment entries. No Graph calls, so `Tests\Unit` covers it directly. | +| `GuestAgent.ps1` | Runs PowerShell inside a lab VM through the QEMU guest agent (`Invoke-GuestPowerShell`) and fetches a large text file from it in checked chunks (`Read-GuestPayload`). Dot-sourced by the driver and by `Invoke-LabGuestScript.ps1`; see the guest agent notes under "Timing notes" for why it works the way it does. | | `Fixtures.ps1` | Device-side fixtures the file, registry and MSI rule experiments look at: files with a known version, size and modified date, a `Program Files (x86)`-only file, `HKLM\SOFTWARE\IntuneScriptLab` in both registry views, and an MSI product survey. Run by `Prepare`. | | `Invoke-ValidationRound.ps1` | Driver: `Prepare`, `Deploy`, `Trigger`, `Collect`, `Remove`. `Deploy -Name` and `Collect -AppName` take wildcards to keep a round to its own experiments (each app's install status is one report export job of 20-30 seconds, and the service runs them one at a time). | | `Win32Content.ps1` | Packages `Win32Install.ps1` with IntuneWinAppUtil.exe and uploads the content to each app. | @@ -101,9 +102,26 @@ Every action supports `-WhatIf`. - The OOBE web sign-in expires after ~10 minutes idle ("Sorry, your sign-in timed out"); a user with no MFA method cannot get past "Keep your account secure" while the tenant requires MFA to register or join devices, and the Windows Hello PIN page after the account phase has no skip either. -- The guest agent's status poll times out on commands that run for minutes, and a retry would start - a second copy; `Collect` therefore runs the device script detached and polls a done marker, and - uploads are numbered part files so a retried chunk cannot be appended twice. +- The guest agent as a transport, measured on VM 125 on 2026-10-05 after `Collect` failed with a + JSON error in the middle of the device payload (the payload file on the device was intact; chunk + 154 of 179 had arrived with the right length and another chunk's text): + - A result nobody collects stays with the agent, and a status call for a process id returns the + **oldest** result held under it. Windows reuses process ids quickly: of 245 commands started + without collecting their results, 29 ids were used two or three times, and asking for one of + them returned the first command's output, then the second's, then the third's. + - A status call that times out on the host (`qmp command 'guest-exec-status' failed - got + timeout`) has still been answered by the agent. If the command had finished, the next call + says `PID does not exist`: the result went with the reply nobody read. + - So `GuestAgent.ps1` starts each command without waiting, asks for its result by id, has every + command print a marker of its own first and passes over a result without it, and runs the + command again when the agent holds nothing after a timed-out call. A snippet sent this way has + to be safe to run twice. `Collect` also compares the SHA-256 of the assembled payload with the + one the device computed. + - A second copy of the detached runner finds the output file held by the first, skips the script + and writes the done marker at once, so the launch sits behind a started marker. +- `Collect` runs the device script detached and polls a done marker, so no single guest agent call + has to stay open for minutes, and uploads are numbered part files so a chunk written twice + replaces itself. ## Adding an experiment diff --git a/Validation/Tests/Unit/Invoke-ValidationRound.Tests.ps1 b/Validation/Tests/Unit/Invoke-ValidationRound.Tests.ps1 index 9dd860c..0313013 100644 --- a/Validation/Tests/Unit/Invoke-ValidationRound.Tests.ps1 +++ b/Validation/Tests/Unit/Invoke-ValidationRound.Tests.ps1 @@ -5,7 +5,8 @@ #Requires lines for PowerShell 7.6 and Microsoft.Graph.Authentication and runs an action when dot-sourced, so its functions are lifted out through the AST into a file under TestDrive and dot-sourced from there; Probe.ps1 is copied beside it because ConvertTo-ScriptContent reads it - from $PSScriptRoot. ssh and Invoke-MgGraphRequest are stubbed, then mocked. + from $PSScriptRoot. GuestAgent.ps1, the guest agent transport both kit scripts dot-source, is + dot-sourced as it is. ssh and Invoke-MgGraphRequest are stubbed, then mocked. #> BeforeAll { @@ -33,10 +34,20 @@ BeforeAll { function Invoke-MgGraphRequest { param($Method, $Uri, $Body) throw "Graph stub called: $Method $Uri $Body" } . $script:Lifted + . (Join-Path $script:KitRoot 'GuestAgent.ps1') # Mock bodies see only their own parameters, so call records go through a file under TestDrive $script:CallLog = Join-Path $TestDrive 'calls.log' function Get-CallLog { if (Test-Path $script:CallLog) { @(Get-Content $script:CallLog) } else { @() } } + + # What the fake Proxmox host answers, one line per call and the last line repeated: the start + # calls ("qm guest exec") and the result calls ("qm guest exec-status") each have a queue. + # "{M}" stands for the marker the command under test printed first; "!255 text" is a failed call + function Use-HostReply { + param([string[]]$Start = '{"pid":4242}', [Parameter(Mandatory)][string[]]$Status) + Set-Content -Path (Join-Path $TestDrive 'start-replies.txt') -Value $Start + Set-Content -Path (Join-Path $TestDrive 'status-replies.txt') -Value $Status + } } # The driver targets PowerShell 7.6 (Convert.ToHexString, SHA256.HashData); under Windows PowerShell @@ -88,56 +99,238 @@ Describe 'Invoke-ValidationRound helpers' -Tag 'Unit', 'Validation' -Skip:($PSVe } Context 'Invoke-GuestPowerShell' { - It 'runs the script through qm guest exec as an encoded command and returns stdout' { + BeforeEach { + # The fake host: logs every call, remembers the marker of the command it was asked to + # start, and answers from the queues Use-HostReply wrote Mock ssh { - Add-Content -Path (Join-Path $TestDrive 'calls.log') -Value ($args -join ' ') + $line = $args -join ' ' + Add-Content -Path (Join-Path $TestDrive 'calls.log') -Value $line + $kind = if ($line -like '*guest exec-status*') { 'status' } else { 'start' } + if ($kind -eq 'start') { + $encoded = ($line -split ' ')[-1] + $decoded = [Text.Encoding]::Unicode.GetString([Convert]::FromBase64String($encoded)) + $marker = ($decoded -split "`n")[0].Trim("'") + Set-Content -Path (Join-Path $TestDrive 'marker.txt') -Value $marker + Set-Content -Path (Join-Path $TestDrive 'sent.txt') -Value $decoded -NoNewline + } + $queue = Join-Path $TestDrive "$kind-replies.txt" + $replies = @(Get-Content -Path $queue) + $reply = $replies[0] + if ($replies.Count -gt 1) { Set-Content -Path $queue -Value $replies[1..($replies.Count - 1)] } $global:LASTEXITCODE = 0 - '{"exitcode":0,"exited":1,"out-data":"hello\n"}' + if ($reply -match '^!(\d+) (.*)$') { + $global:LASTEXITCODE = [int]$Matches[1] + $reply = $Matches[2] + } + $reply.Replace('{M}', (Get-Content -Path (Join-Path $TestDrive 'marker.txt') -Raw).Trim()) } + } + + It 'starts the command without waiting, asks for its result by process id and returns stdout' { + Use-HostReply -Status '{"exitcode":0,"exited":1,"out-data":"{M}\r\nhello\n"}' $result = Invoke-GuestPowerShell -Script 'Write-Output hello' -TimeoutSeconds 30 $result | Should-Be "hello`n" - $call = @(Get-CallLog)[0] - $call | Should-BeLikeString '-o BatchMode=yes pve qm guest exec 125 --timeout 30 -- powershell*' - $call | Should-BeLikeString '* -NoProfile -NonInteractive -EncodedCommand *' - $encoded = ($call -split ' ')[-1] - $decoded = [Text.Encoding]::Unicode.GetString([Convert]::FromBase64String($encoded)) - $decoded | Should-Be 'Write-Output hello' + + $calls = @(Get-CallLog) + $calls.Count | Should-Be 2 + $calls[0] | Should-BeLikeString '-o BatchMode=yes pve qm guest exec 125 --synchronous 0 -- powershell*' + $calls[0] | Should-BeLikeString '* -NoProfile -NonInteractive -EncodedCommand *' + $calls[1] | Should-Be '-o BatchMode=yes pve qm guest exec-status 125 4242' + # The command prints a marker of its own before anything else + $marker = (Get-Content (Join-Path $TestDrive 'marker.txt') -Raw).Trim() + $marker | Should-MatchString '^[0-9a-f]{32}$' + Get-Content (Join-Path $TestDrive 'sent.txt') -Raw | Should-Be "'$marker'`nWrite-Output hello" } - It 'retries a QMP status timeout and succeeds on a later attempt' { - Mock ssh { - Add-Content -Path (Join-Path $TestDrive 'calls.log') -Value 'call' - if (@(Get-Content (Join-Path $TestDrive 'calls.log')).Count -lt 3) { - $global:LASTEXITCODE = 255 - "VM 125 qmp command 'guest-exec-status' failed - got timeout" - } - else { - $global:LASTEXITCODE = 0 - '{"exitcode":0,"exited":1,"out-data":"third"}' - } - } - Invoke-GuestPowerShell -Script 'x' -WarningAction SilentlyContinue | Should-Be 'third' - @(Get-CallLog).Count | Should-Be 3 - Should-Invoke Start-Sleep -Exactly -Times 2 + It 'uses a different marker for every command' { + Use-HostReply -Status '{"exitcode":0,"exited":1,"out-data":"{M}\r\n"}' + $null = Invoke-GuestPowerShell -Script 'x' + $first = (Get-Content (Join-Path $TestDrive 'marker.txt') -Raw).Trim() + $null = Invoke-GuestPowerShell -Script 'x' + (Get-Content (Join-Path $TestDrive 'marker.txt') -Raw).Trim() | Should-NotBe $first + } + + It 'asks again while the command is still running' { + $running = '{"exited":0}' + Use-HostReply -Status $running, $running, '{"exitcode":0,"exited":1,"out-data":"{M}\r\ndone"}' + Invoke-GuestPowerShell -Script 'x' | Should-Be 'done' + @(Get-CallLog | Where-Object { $_ -like '*exec-status*' }).Count | Should-Be 3 + } + + It 'keeps asking after a status call times out while the agent still holds the result' { + # The call timed out with the command still running: nothing was handed over, so the + # result is still there to collect and the command is not started a second time + $timeout = "!255 VM 125 qmp command 'guest-exec-status' failed - got timeout" + Use-HostReply -Status $timeout, $timeout, '{"exitcode":0,"exited":1,"out-data":"{M}\r\nthird"}' + Invoke-GuestPowerShell -Script 'x' | Should-Be 'third' + @(Get-CallLog | Where-Object { $_ -like '*guest exec 125 --synchronous*' }).Count | Should-Be 1 + @(Get-CallLog | Where-Object { $_ -like '*exec-status*' }).Count | Should-Be 3 + } + + It 'runs the command again when a status call that timed out took the result with it (VM 125)' { + # Traced on the device: "got timeout", then "PID does not exist". The agent had answered + # the call that the host gave up on, and a result is handed over once + $timeout = "!255 VM 125 qmp command 'guest-exec-status' failed - got timeout" + $gone = '!29 Agent error: PID lld does not exist' + Use-HostReply -Status $timeout, $gone, '{"exitcode":0,"exited":1,"out-data":"{M}\r\nsecond run"}' + $warnings = @() + Invoke-GuestPowerShell -Script 'x' -WarningVariable warnings 3>$null | Should-Be 'second run' + @(Get-CallLog | Where-Object { $_ -like '*guest exec 125 --synchronous*' }).Count | Should-Be 2 + "$(@($warnings)[0])" | + Should-BeLikeString '*went with a status call that timed out*running the command again' + } + + It 'does not take another command''s result for its own when its own was lost' { + $stale = '{"exitcode":0,"exited":1,"out-data":"0123456789abcdef0123456789abcdef\r\nsomeone else"}' + $timeout = "!255 VM 125 qmp command 'guest-exec-status' failed - got timeout" + $gone = '!29 Agent error: PID lld does not exist' + Use-HostReply -Status $stale, $timeout, $gone, '{"exitcode":0,"exited":1,"out-data":"{M}\r\nmine"}' + Invoke-GuestPowerShell -Script 'x' -WarningAction SilentlyContinue | Should-Be 'mine' + @(Get-CallLog | Where-Object { $_ -like '*guest exec 125 --synchronous*' }).Count | Should-Be 2 + } + + It 'gives up when the result is lost three times running' { + $timeout = "!255 VM 125 qmp command 'guest-exec-status' failed - got timeout" + $gone = '!29 Agent error: PID lld does not exist' + Use-HostReply -Status $timeout, $gone, $timeout, $gone, $timeout, $gone + { Invoke-GuestPowerShell -Script 'x' -WarningAction SilentlyContinue } | + Should-Throw -ExceptionMessage '*result was lost to a timed-out status call 3 times*' + @(Get-CallLog | Where-Object { $_ -like '*guest exec 125 --synchronous*' }).Count | Should-Be 3 + } + + It 'passes over an earlier command''s result held under the same process id (Collect, 2026-10-05)' { + # The agent answers with the oldest result it holds for a process id, and Windows reuses + # ids: a payload chunk came back as another chunk, the right length and the wrong text + $stale = '{"exitcode":0,"exited":1,"out-data":"0123456789abcdef0123456789abcdef\r\nsomeone else"}' + Use-HostReply -Status $stale, '{"exitcode":0,"exited":1,"out-data":"{M}\r\nmine"}' + Invoke-GuestPowerShell -Script 'x' | Should-Be 'mine' + @(Get-CallLog | Where-Object { $_ -like '*guest exec 125 --synchronous*' }).Count | Should-Be 1 + @(Get-CallLog | Where-Object { $_ -like '*exec-status*' }).Count | Should-Be 2 + } + + It 'takes a reply without the marker as its own when the agent holds nothing else for the id' { + # powershell.exe that never reached the first line: no marker, and no second result + $gone = '!29 Agent error: PID lld does not exist' + Use-HostReply -Status '{"exitcode":1,"exited":1,"err-data":"boom"}', $gone + $warnings = @() + $result = Invoke-GuestPowerShell -Script 'x' -WarningVariable warnings 3>$null + $result | Should-Be '' + "$(@($warnings)[0])" | Should-BeLikeString '*exited 1*boom*' + } + + It 'fails when the agent holds no result at all for the process id' { + Use-HostReply -Status '!29 Agent error: PID lld does not exist' + { Invoke-GuestPowerShell -Script 'x' } | + Should-Throw -ExceptionMessage '*holds no result for process id 4242*' + } + + It 'retries a start call that times out and succeeds on a later attempt' { + $timeout = "!255 VM 125 qmp command 'guest-exec' failed - got timeout" + $finished = '{"exitcode":0,"exited":1,"out-data":"{M}\r\nok"}' + Use-HostReply -Start $timeout, $timeout, '{"pid":4242}' -Status $finished + Invoke-GuestPowerShell -Script 'x' -WarningAction SilentlyContinue | Should-Be 'ok' + @(Get-CallLog | Where-Object { $_ -like '*guest exec 125 --synchronous*' }).Count | Should-Be 3 + Should-Invoke Start-Sleep -Exactly -Times 2 -ParameterFilter { $Seconds -eq 10 } } - It 'gives up after three attempts with the host output in the error' { - Mock ssh { $global:LASTEXITCODE = 255; 'connection refused' } + It 'gives up after three failed starts with the host output in the error' { + Use-HostReply -Start '!255 connection refused' -Status '{"exited":0}' { Invoke-GuestPowerShell -Script 'x' -WarningAction SilentlyContinue } | Should-Throw -ExceptionMessage '*qm guest exec failed on pve: connection refused*' Should-Invoke ssh -Exactly -Times 3 } + It 'gives up when the command has not finished by the timeout' { + Use-HostReply -Status '{"exited":0}' + { Invoke-GuestPowerShell -Script 'x' -TimeoutSeconds 0 } | + Should-Throw -ExceptionMessage '*process id 4242 on VM 125) did not finish within 0 s*' + } + + It 'gives up when the result calls keep failing' { + Use-HostReply -Status '!255 connection refused' + { Invoke-GuestPowerShell -Script 'x' -TimeoutSeconds 600 } | + Should-Throw -ExceptionMessage '*qm guest exec-status failed on pve: connection refused*' + @(Get-CallLog | Where-Object { $_ -like '*exec-status*' }).Count | Should-Be 10 + } + It 'warns, but still returns stdout, when the guest script exits non-zero' { - Mock ssh { - $global:LASTEXITCODE = 0 - '{"exitcode":1,"exited":1,"out-data":"partial","err-data":"boom"}' - } + Use-HostReply -Status '{"exitcode":1,"exited":1,"out-data":"{M}\r\npartial","err-data":"boom"}' $warnings = @() $result = Invoke-GuestPowerShell -Script 'x' -WarningVariable warnings 3>$null $result | Should-Be 'partial' "$(@($warnings)[0])" | Should-BeLikeString '*exited 1*boom*' } + + It 'warns about stderr on a zero exit and leaves progress records out' { + $progress = '#< CLIXML\r\n' + + '' + + 'System.Management.Automation.PSCustomObject' + + 'System.Object1' + $withProgress = '{"exitcode":0,"exited":1,"out-data":"{M}\r\nfine","err-data":"' + $progress + '"}' + Use-HostReply -Status $withProgress + $quiet = @() + Invoke-GuestPowerShell -Script 'x' -WarningVariable quiet 3>$null | Should-Be 'fine' + @($quiet).Count | Should-Be 0 + + Use-HostReply -Status '{"exitcode":0,"exited":1,"out-data":"{M}\r\nfine","err-data":"not good"}' + $warnings = @() + $null = Invoke-GuestPowerShell -Script 'x' -WarningVariable warnings 3>$null + "$(@($warnings)[0])" | Should-Be 'not good' + } + } + + Context 'Read-GuestPayload' { + BeforeAll { + $script:Payload = 'QUJDREVGR0hJSktMTU5PUFFSU1RVVg==' # 32 characters, read 10 at a time + $sha = [Security.Cryptography.SHA256]::Create() + $bytes = $sha.ComputeHash([Text.Encoding]::ASCII.GetBytes($script:Payload)) + $script:PayloadHash = [BitConverter]::ToString($bytes) -replace '-', '' + $sha.Dispose() + $script:PayloadSplat = @{ + RemotePath = 'C:\ProgramData\IntuneScriptLab\collect.b64'; Size = 32 + Sha256 = $script:PayloadHash; ChunkSize = 10 + } + } + + BeforeEach { + Set-Content -Path (Join-Path $TestDrive 'payload.txt') -Value $script:Payload -NoNewline + Remove-Item -Path (Join-Path $TestDrive 'fault.txt') -ErrorAction SilentlyContinue + # The VM: answers a Substring read from the payload. fault.txt names one offset and what + # goes wrong there once ('short') or always ('stale': the chunk at offset 0 instead) + Mock Invoke-GuestPowerShell { + Add-Content -Path (Join-Path $TestDrive 'calls.log') -Value $Script + $payload = Get-Content -Path (Join-Path $TestDrive 'payload.txt') -Raw + $null = $Script -match '\.Substring\((\d+), (\d+)\)' + $offset, $length = [int]$Matches[1], [int]$Matches[2] + $faultFile = Join-Path $TestDrive 'fault.txt' + $fault = if (Test-Path -Path $faultFile) { (Get-Content -Path $faultFile -Raw).Trim() } + if ($fault -eq "short $offset") { Remove-Item -Path $faultFile; return '' } + if ($fault -eq "stale $offset") { return $payload.Substring(0, $length) + "`r`n" } + $payload.Substring($offset, $length) + "`r`n" + } + } + + It 'reads the file in chunks, in order, and returns its text when the hash matches' { + Read-GuestPayload @script:PayloadSplat | Should-Be $script:Payload + $calls = @(Get-CallLog) + $calls.Count | Should-Be 4 + $calls[0] | + Should-Be "[IO.File]::ReadAllText('C:\ProgramData\IntuneScriptLab\collect.b64').Substring(0, 10)" + $calls[3] | Should-BeLikeString '*.Substring(30, 2)' + } + + It 'asks again for a chunk that comes back short' { + Set-Content -Path (Join-Path $TestDrive 'fault.txt') -Value 'short 10' + Read-GuestPayload @script:PayloadSplat -WarningAction SilentlyContinue | Should-Be $script:Payload + @(Get-CallLog | Where-Object { $_ -like '*.Substring(10, 10)' }).Count | Should-Be 2 + } + + It 'refuses a payload whose chunk has the right length and the wrong content' { + Set-Content -Path (Join-Path $TestDrive 'fault.txt') -Value 'stale 10' + $expected = "*did not arrive intact: 32 characters*the VM's copy has $($script:PayloadHash)*" + { Read-GuestPayload @script:PayloadSplat } | Should-Throw -ExceptionMessage $expected + } } Context 'Invoke-GuestScriptFile' { @@ -176,6 +369,26 @@ Describe 'Invoke-ValidationRound helpers' -Tag 'Unit', 'Validation' -Skip:($PSVe "-Force; & 'C:\ProgramData\IntuneScriptLab\collect.ps1'") } + It 'starts a detached script behind a started marker, so a launch that runs twice starts it once' { + Mock Invoke-GuestPowerShell { + Add-Content -Path (Join-Path $TestDrive 'calls.log') -Value $Script + if ($Script -like "Test-Path -Path '*.done'") { 'True' } + elseif ($Script -like "Get-Content -Path '*.out'*") { 'output' } + } + Invoke-GuestScriptFile -Script 'x' -Detach -TimeoutSeconds 60 | Should-Be 'output' + + $calls = [System.Collections.Generic.List[string]]@(Get-CallLog) + $started = "'C:\ProgramData\IntuneScriptLab\collect.ps1.started'" + $clear = "Remove-Item -Path $started -ErrorAction SilentlyContinue" + $calls | Should-ContainCollection $clear + $launch = @($calls | Where-Object { $_ -like '*Start-Process*' }) + $launch.Count | Should-Be 1 + $launch[0] | Should-BeLikeString ("if (-not (Test-Path -Path $started)) { Set-Content " + + "-Path $started -Value started; *Start-Process -FilePath '*collect.ps1.cmd' -WindowStyle Hidden }") + # The marker of an earlier run is cleared before the launch, not after it + $calls.IndexOf($launch[0]) | Should-BeGreaterThan $calls.IndexOf($clear) + } + It 'names the remote file after -RemoteName' { $null = Invoke-GuestScriptFile -Script 'x' -RemoteName 'fixtures.ps1' (Get-CallLog)[-1] | Should-BeLikeString "*& 'C:\ProgramData\IntuneScriptLab\fixtures.ps1'"