Skip to content

Integration Test

Integration Test #253

name: Integration Test
on:
workflow_dispatch:
inputs:
os:
description: "Platform to test"
required: true
type: choice
options:
- all
- windows-latest
- ubuntu-latest
- macos-latest
jobs:
build:
permissions:
contents: read
uses: ./.github/workflows/build.yml
with:
os_list: "${{ inputs.os == 'all' && '[''windows-latest'',''ubuntu-latest'',''macos-latest'']' || format('[{0}{1}{0}]', '''', inputs.os) }}"
cache: true
build-integration-test:
permissions:
contents: read
strategy:
fail-fast: false
matrix:
os: ${{ fromJson(inputs.os == 'all' && '[''windows-latest'',''ubuntu-latest'',''macos-latest'']' || format('[{0}{1}{0}]', '''', inputs.os)) }}
runs-on: ${{ matrix.os }}
steps:
- name: Checkout code
uses: actions/checkout@v5
with:
ref: ${{ github.ref }}
fetch-depth: 0
- name: Cache integration test build output
id: cache-build
uses: actions/cache@v5
with:
path: ./dist
key: build-it-${{ matrix.os }}-go1.25.0-${{ hashFiles('**/*.go', 'go.sum', 'go.mod') }}
- name: Setup go
if: steps.cache-build.outputs.cache-hit != 'true'
uses: actions/setup-go@v6
with:
go-version: "1.25.0"
cache: true
- name: Build integration test binary
if: steps.cache-build.outputs.cache-hit != 'true'
shell: pwsh
id: build
run: ./scripts/build_integration_test.ps1 | % { "binary_path=$_" } >> $env:GITHUB_OUTPUT
- name: Upload integration test binary
uses: actions/upload-artifact@v6
with:
name: it-${{ matrix.os }}
path: ${{ steps.build.outputs.binary_path || './dist/*' }}
set-matrix:
permissions:
contents: read
runs-on: ubuntu-latest
outputs:
matrix: ${{ steps.gen.outputs.matrix }}
steps:
- name: Build test matrix include
id: gen
shell: pwsh
env:
OS_INPUT: ${{ inputs.os }}
ORG_ID: ${{ vars.IT_ORG_ID }}
run: |
$winSuccess = @'
"[Net.ServicePointManager]::SecurityProtocol = [Net.SecurityProtocolType]::Tls12
$PS_Results = New-Object -TypeName psobject
# Start of typed powershell
$PS_Results | Add-Member -MemberType NoteProperty -Name \"error\" -Value \"\"
$PS_Results | Add-Member -MemberType NoteProperty -Name \"output\" -Value \"hello world`n\"
# Post results back to Rewst
$postData = $PS_Results | ConvertTo-Json
Invoke-RestMethod -Method \"Post\" -Uri $post_url -Body $postData -ContentType \"application/json\""
'@
$winFailure = @'
"[Net.ServicePointManager]::SecurityProtocol = [Net.SecurityProtocolType]::Tls12
$PS_Results = New-Object -TypeName psobject
# Start of typed powershell
throw \"this is a test error\"
# Post results back to Rewst
$postData = $PS_Results | ConvertTo-Json
Invoke-RestMethod -Method \"Post\" -Uri $post_url -Body $postData -ContentType \"application/json\""
'@
$orgId = $env:ORG_ID
# Output-flood scripts for the bounded-output scenario (sc-106105).
# Deliberately quote-free and backslash-free so they survive the trip
# through the trigger's JSON-quoted commands field unchanged, and
# byte-exact so the produced counts the agent reports are predictable:
# verbose 200 MiB to stdout, then a clean exit
# verbose_stderr a short stdout line, then 200 MiB to stderr
# verbose_hang 200 MiB to stdout, then a hang past the timeout
# All three write 200 MiB - three orders of magnitude past the ceiling
# the scenario configures - so the RSS ceiling asserted while they run
# is far below what buffering the output whole would cost.
$winVerbose = '"$chunk = [string]::new([char]120, 1048576); 1..200 | ForEach-Object { $chunk }"'
$winVerboseStderr = '"Write-Output keep-stdout; $chunk = [string]::new([char]101, 1048576); 1..200 | ForEach-Object { [Console]::Error.Write($chunk) }"'
$winVerboseHang = '"$chunk = [string]::new([char]120, 1048576); 1..200 | ForEach-Object { $chunk }; Start-Sleep -Seconds 60"'
$unixVerbose = '"yes x | head -c 209715200"'
$unixVerboseStderr = '"echo keep-stdout; yes e | head -c 209715200 >&2"'
$unixVerboseHang = '"yes x | head -c 209715200; sleep 60"'
$entries = @(
[ordered]@{
os = 'ubuntu-latest'
binary = 'rewst_agent_config.linux.bin'
it_binary = 'rewst_agent_config.linux.it.bin'
config_dir = '/etc/rewst_remote_agent'
log_file = "/etc/rewst_remote_agent/$orgId/rewst_agent.log"
service = "rewst_remote_agent_$orgId"
success_commands = '"echo \"hello world\""'
failure_commands = '"exit 1"'
timeout_commands = '"sleep 30"'
sweep_commands = '"sleep 180"'
verbose_commands = $unixVerbose
verbose_stderr_commands = $unixVerboseStderr
verbose_hang_commands = $unixVerboseHang
success_patterns = "Command completed`nSending postback`nPostback sent"
no_auto_updates_extra = ''
uninstall_paths = "/etc/rewst_remote_agent/$orgId`n/usr/local/bin/rewst_remote_agent/$orgId`n/tmp/rewst_remote_agent/scripts/$orgId"
service_user = 'rewst-it-svc'
service_username_arg = 'rewst-it-svc'
service_identity = 'rewst-it-svc'
},
[ordered]@{
os = 'windows-latest'
binary = 'rewst_agent_config.win.exe'
it_binary = 'rewst_agent_config.win.it.exe'
config_dir = 'C:\ProgramData\RewstRemoteAgent'
log_file = "C:\ProgramData\RewstRemoteAgent\$orgId\rewst_agent.log"
service = "RewstRemoteAgent_$orgId"
success_commands = $winSuccess
failure_commands = $winFailure
timeout_commands = '"Start-Sleep -Seconds 30"'
sweep_commands = '"Start-Sleep -Seconds 180"'
verbose_commands = $winVerbose
verbose_stderr_commands = $winVerboseStderr
verbose_hang_commands = $winVerboseHang
success_patterns = "Command completed`nSending postback`nPostback already sent"
no_auto_updates_extra = '--disable-agent-postback'
uninstall_paths = "C:\ProgramData\RewstRemoteAgent\$orgId`nC:\Program Files\RewstRemoteAgent\$orgId`nC:\RewstRemoteAgent\scripts\$orgId"
service_user = 'rewst-it-svc'
service_username_arg = '.\rewst-it-svc'
service_identity = '.\rewst-it-svc'
},
[ordered]@{
os = 'macos-latest'
binary = 'rewst_agent_config.mac-os.bin'
it_binary = 'rewst_agent_config.mac-os.it.bin'
config_dir = '/Library/Application Support/rewst_remote_agent'
log_file = "/Library/Application Support/rewst_remote_agent/$orgId/rewst_agent.log"
service = "io.rewst.remote_agent_$orgId"
success_commands = '"echo \"hello world\""'
failure_commands = '"exit 1"'
timeout_commands = '"sleep 30"'
sweep_commands = '"sleep 180"'
verbose_commands = $unixVerbose
verbose_stderr_commands = $unixVerboseStderr
verbose_hang_commands = $unixVerboseHang
success_patterns = "Command completed`nSending postback`nPostback sent"
no_auto_updates_extra = ''
uninstall_paths = "/Library/Application Support/rewst_remote_agent/$orgId`n/usr/local/bin/rewst_remote_agent/$orgId`n`$env:TMPDIR/rewst_remote_agent/scripts/$orgId"
service_user = 'rewst-it-svc'
service_username_arg = 'rewst-it-svc'
service_identity = 'rewst-it-svc'
}
)
if ($env:OS_INPUT -ne 'all') {
$entries = @($entries | Where-Object { $_.os -eq $env:OS_INPUT })
}
$payload = @{ include = $entries }
$json = ConvertTo-Json -InputObject $payload -Depth 10 -Compress
Write-Output $json
"matrix=$json" >> $env:GITHUB_OUTPUT
test:
permissions:
contents: read
env:
GITHUB_TOKEN: ${{ secrets.GITHUB_TOKEN }}
needs: [build, build-integration-test, set-matrix]
strategy:
fail-fast: false
matrix: ${{ fromJson(needs.set-matrix.outputs.matrix) }}
runs-on: ${{ matrix.os }}
steps:
- name: Checkout code
uses: actions/checkout@v5
- name: Inject PowerShell profile noise
if: matrix.os == 'windows-latest'
id: inject_profile_noise
uses: ./.github/actions/inject-profile-noise
- name: Install agent
id: install_agent
uses: ./.github/actions/install-agent
with:
os: ${{ matrix.os }}
binary: ${{ matrix.binary }}
it_binary: ${{ matrix.it_binary }}
config_url: ${{ vars.IT_CONFIG_URL }}
config_secret: ${{ secrets.IT_CONFIG_SECRET }}
org_id: ${{ vars.IT_ORG_ID }}
github_token: ${{ secrets.GITHUB_TOKEN }}
- name: Check install output for profile noise
if: matrix.os == 'windows-latest'
uses: ./.github/actions/check-profile-noise
with:
install_output_path: ${{ steps.install_agent.outputs.install_output_path }}
noise: ${{ steps.inject_profile_noise.outputs.noise }}
- name: Check service
uses: ./.github/actions/check-service
with:
service: ${{ matrix.service }}
- name: Validate config and get device id
id: config
uses: ./.github/actions/validate-config
with:
config_dir: ${{ matrix.config_dir }}
org_id: ${{ vars.IT_ORG_ID }}
- name: Check subscribed messages log for topic and QoS
uses: ./.github/actions/assert-log-contains
with:
log_file: ${{ matrix.log_file }}
patterns: Subscribed to messages
subscribed_topic_qos: "true"
wait_seconds: "10"
- name: Send success command
uses: ./.github/actions/send-command
with:
trigger_url: ${{ vars.IT_SEND_COMMAND_TRIGGER_URL }}
device_id: ${{ steps.config.outputs.device_id }}
commands: ${{ matrix.success_commands }}
- name: Check logs for successful command
uses: ./.github/actions/assert-log-contains
with:
log_file: ${{ matrix.log_file }}
patterns: ${{ matrix.success_patterns }}
- name: Send failing command
uses: ./.github/actions/send-command
with:
trigger_url: ${{ vars.IT_SEND_COMMAND_TRIGGER_URL }}
device_id: ${{ steps.config.outputs.device_id }}
commands: ${{ matrix.failure_commands }}
- name: Check logs for error handling
uses: ./.github/actions/assert-log-contains
with:
log_file: ${{ matrix.log_file }}
patterns: Command failed
wait_seconds: "15"
- name: Install integration test binary (old version)
uses: ./.github/actions/run-agent
with:
binary: ${{ matrix.it_binary }}
args: --update --org-id ${{ vars.IT_ORG_ID }} --github-token ${{ secrets.GITHUB_TOKEN }}
# Captured before the real auto-update fires, so the assertions below
# measure what that update did rather than the restart the IT binary
# install above already caused.
- name: Capture pre-auto-update baseline counts
id: autoupdate_baseline
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
run: |
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
function Get-PatternCount($text, $needle) {
if ($text) { ([regex]::Matches($text, [regex]::Escape($needle))).Count } else { 0 }
}
$started = Get-PatternCount $content "Service started"
$subscribed = Get-PatternCount $content "Subscribed to messages"
"started=$started" >> $env:GITHUB_OUTPUT
"subscribed=$subscribed" >> $env:GITHUB_OUTPUT
Write-Output "Baseline counts -> started=$started subscribed=$subscribed"
- name: Wait for auto updater to trigger and update
uses: ./.github/actions/wait-for-log-line
with:
log_file: ${{ matrix.log_file }}
pattern: Updating agent
- name: Verify auto update completed
uses: ./.github/actions/verify-auto-update
with:
log_file: ${{ matrix.log_file }}
# ---- Linux systemd cgroup-kill regression (sc-109762) ----
# verify-auto-update above only checks the log for "Updating agent" and
# that the last "Agent Smith started" line isn't the IT version - but
# that line is logged by the --update helper on its own startup, before
# it ever stops the old service, so it already names the new version
# even when the helper is killed moments later and never restarts
# anything. On Linux, the helper used to inherit the running service's
# systemd cgroup, so calling `systemctl stop` on its own unit triggered
# KillMode=control-group and killed the helper along with the service it
# asked to stop - the endpoint was left offline with the old binary
# still in place and no automatic recovery. The real proof the update
# finished is the helper's own "Service started" line, logged only after
# it replaced the binary and called svc.Start() - the exact point the
# cgroup kill used to cut it off. Counts are compared as deltas because
# "Service started" also appears once from installing the IT binary
# above, and "Subscribed to messages" already has lines from earlier
# scenarios.
- name: Assert the update helper survived to restart the service
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.autoupdate_baseline.outputs.started }}
run: |
$baseline = [int]$env:BASELINE
for ($i = 1; $i -le 30; $i++) {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$count = if ($content) { ([regex]::Matches($content, [regex]::Escape("Service started"))).Count } else { 0 }
if ($count -gt $baseline) {
Write-Output "Update helper restarted the service (count $count > baseline $baseline) after ~$($i * 2)s"
exit 0
}
Start-Sleep -Seconds 2
}
Write-Output "---- last 60 lines of the agent log ----"
Get-Content $env:LOG_FILE -Tail 60 -ErrorAction SilentlyContinue
Write-Error "Update helper never logged 'Service started' after the auto-update; it was likely killed mid-update (count stayed at $baseline)"
exit 1
- name: Check service is active after auto-update
uses: ./.github/actions/check-service
with:
service: ${{ matrix.service }}
- name: Wait for fresh subscription after auto-update
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.autoupdate_baseline.outputs.subscribed }}
run: |
$baseline = [int]$env:BASELINE
for ($i = 1; $i -le 30; $i++) {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$count = if ($content) { ([regex]::Matches($content, [regex]::Escape("Subscribed to messages"))).Count } else { 0 }
if ($count -gt $baseline) {
Write-Output "Agent resubscribed after auto-update (count $count > baseline $baseline) after ~$($i * 2)s"
exit 0
}
Start-Sleep -Seconds 2
}
Write-Error "Agent never resubscribed after auto-update (subscribed count stayed at $baseline)"
exit 1
- name: Send command after auto-update
uses: ./.github/actions/send-command
with:
trigger_url: ${{ vars.IT_SEND_COMMAND_TRIGGER_URL }}
device_id: ${{ steps.config.outputs.device_id }}
commands: ${{ matrix.success_commands }}
- name: Check logs for command completion after auto-update
uses: ./.github/actions/assert-log-contains
with:
log_file: ${{ matrix.log_file }}
patterns: ${{ matrix.success_patterns }}
wait_seconds: "15"
- name: Update logging level to debug
uses: ./.github/actions/run-agent
with:
binary: ${{ matrix.binary }}
args: --update --org-id ${{ vars.IT_ORG_ID }} --logging-level debug --github-token ${{ secrets.GITHUB_TOKEN }}
- name: Send test command (debug)
uses: ./.github/actions/send-command
with:
trigger_url: ${{ vars.IT_SEND_COMMAND_TRIGGER_URL }}
device_id: ${{ steps.config.outputs.device_id }}
commands: ${{ matrix.success_commands }}
- name: Check logs for debug level
uses: ./.github/actions/assert-log-contains
with:
log_file: ${{ matrix.log_file }}
patterns: DEBUG
- name: Stop service
uses: ./.github/actions/stop-service
with:
service: ${{ matrix.service }}
- name: Delete log file
uses: ./.github/actions/delete-log
with:
log_file: ${{ matrix.log_file }}
- name: Update agent (no auto updates)
uses: ./.github/actions/run-agent
with:
binary: ${{ matrix.binary }}
args: --update --org-id ${{ vars.IT_ORG_ID }} --no-auto-updates ${{ matrix.no_auto_updates_extra }} --github-token ${{ secrets.GITHUB_TOKEN }}
- name: Check logs for no auto updater
uses: ./.github/actions/assert-log-missing
with:
log_file: ${{ matrix.log_file }}
pattern: Starting auto updater
wait_for_file_seconds: "30"
- name: Send test command (windows postback verification)
if: matrix.os == 'windows-latest'
uses: ./.github/actions/send-command
with:
trigger_url: ${{ vars.IT_SEND_COMMAND_TRIGGER_URL }}
device_id: ${{ steps.config.outputs.device_id }}
commands: ${{ matrix.success_commands }}
- name: Check logs for command received (windows)
if: matrix.os == 'windows-latest'
uses: ./.github/actions/assert-log-contains
with:
log_file: ${{ matrix.log_file }}
patterns: Command completed
- name: Check logs absent postback (windows)
if: matrix.os == 'windows-latest'
uses: ./.github/actions/assert-log-missing
with:
log_file: ${{ matrix.log_file }}
pattern: Postback already sent
- name: Update agent with syslog
uses: ./.github/actions/run-agent
with:
binary: ${{ matrix.binary }}
args: --update --org-id ${{ vars.IT_ORG_ID }} --syslog --github-token ${{ secrets.GITHUB_TOKEN }}
- name: Send test command (syslog)
uses: ./.github/actions/send-command
with:
trigger_url: ${{ vars.IT_SEND_COMMAND_TRIGGER_URL }}
device_id: ${{ steps.config.outputs.device_id }}
commands: ${{ matrix.success_commands }}
- name: Check syslog for command completed
uses: ./.github/actions/assert-syslog-contains
with:
service: ${{ matrix.service }}
pattern: Command completed
# ---- MQTT reconnection scenario ----
# Force a transient broker outage and verify the agent tears down, backs
# off, resubscribes, and resumes command delivery exactly once. Counts are
# captured up front and compared as deltas because the log already contains
# "Subscribed to messages"/"Command completed" lines from earlier cycles
# (the service has restarted several times by now and the log is not reset
# while the service holds it open).
- name: Capture reconnect baseline counts
id: reconnect_baseline
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
run: |
$content = Get-Content $env:LOG_FILE -Raw
$subscribed = ([regex]::Matches($content, [regex]::Escape("Subscribed to messages"))).Count
$completed = ([regex]::Matches($content, [regex]::Escape("Command completed"))).Count
"subscribed=$subscribed" >> $env:GITHUB_OUTPUT
"completed=$completed" >> $env:GITHUB_OUTPUT
Write-Output "Baseline counts -> subscribed=$subscribed completed=$completed"
- name: Disrupt broker connection
uses: ./.github/actions/disrupt-connection
with:
mode: block
host: ${{ steps.config.outputs.azure_iot_hub_host }}
- name: Wait for connection lost detection
uses: ./.github/actions/wait-for-log-line
with:
log_file: ${{ matrix.log_file }}
pattern: Connection lost
max_attempts: "60"
interval_seconds: "2"
- name: Assert connection lost and reconnect/backoff activity
uses: ./.github/actions/assert-log-contains
with:
log_file: ${{ matrix.log_file }}
patterns: |
Connection lost
Reconnecting in
Reconnecting...
wait_seconds: "10"
- name: Restore broker connection
if: always()
uses: ./.github/actions/disrupt-connection
with:
mode: restore
host: ${{ steps.config.outputs.azure_iot_hub_host }}
- name: Wait for fresh subscription after reconnect
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.reconnect_baseline.outputs.subscribed }}
run: |
$baseline = [int]$env:BASELINE
for ($i = 1; $i -le 60; $i++) {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$count = if ($content) { ([regex]::Matches($content, [regex]::Escape("Subscribed to messages"))).Count } else { 0 }
if ($count -gt $baseline) {
Write-Output "Agent resubscribed after reconnect (count $count > baseline $baseline) after ~$($i * 2)s"
exit 0
}
Start-Sleep -Seconds 2
}
Write-Error "Agent did not resubscribe after reconnect (subscribed count stayed at $baseline)"
exit 1
- name: Send command after reconnect
uses: ./.github/actions/send-command
with:
trigger_url: ${{ vars.IT_SEND_COMMAND_TRIGGER_URL }}
device_id: ${{ steps.config.outputs.device_id }}
commands: ${{ matrix.success_commands }}
- name: Assert command executed exactly once after reconnect
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.reconnect_baseline.outputs.completed }}
run: |
$baseline = [int]$env:BASELINE
$observed = $baseline
# Wait for the post-reconnect command to complete.
for ($i = 1; $i -le 30; $i++) {
Start-Sleep -Seconds 2
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$observed = if ($content) { ([regex]::Matches($content, [regex]::Escape("Command completed"))).Count } else { 0 }
if ($observed -gt $baseline) { break }
}
if (($observed - $baseline) -lt 1) {
Write-Error "Post-reconnect command never completed (count stayed at $baseline)"
exit 1
}
# Allow a brief window for any duplicate delivery to surface, then
# require the delta to be exactly one - guarding against re-delivery of
# the buffered message on a non-clean reconnected session.
Start-Sleep -Seconds 10
$content = Get-Content $env:LOG_FILE -Raw
$final = ([regex]::Matches($content, [regex]::Escape("Command completed"))).Count
$delta = $final - $baseline
Write-Output "Post-reconnect 'Command completed' delta: $delta (baseline $baseline, final $final)"
if ($delta -ne 1) {
Write-Error "Expected exactly one post-reconnect 'Command completed', got $delta (duplicate delivery?)"
exit 1
}
Write-Output "Confirmed exactly one post-reconnect command execution"
# ---- Withheld-SUBACK scenario (sc-106107) ----
# The reconnection scenario above severs the connection, which keepalive
# detects and the agent handles as an ordinary reconnect. This one covers
# the harder case it cannot reach: a broker that stays alive - completing
# the TLS handshake, answering CONNECT with CONNACK, and answering every
# PINGREQ - while never sending SUBACK. That is what Azure IoT Hub does when
# it throttles a device, and what a middlebox that half-opens a connection
# produces. Before the fix it left the agent connected but never subscribed,
# silently running no commands and unable to honor a stop; now the subscribe
# wait is bounded and stop-interruptible, so the agent fails cleanly, backs
# off, and recovers on a later cycle once the broker starts acknowledging.
# Counts are compared as deltas because the log already carries lines from
# earlier cycles.
- name: Capture SUBACK-withheld baseline counts
id: suback_baseline
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
run: |
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
function Get-PatternCount($text, $needle) {
if ($text) { ([regex]::Matches($text, [regex]::Escape($needle))).Count } else { 0 }
}
$subscribed = Get-PatternCount $content "Subscribed to messages"
$timedOut = Get-PatternCount $content "Failed to subscribe: timed out waiting for broker acknowledgement"
$backoffs = Get-PatternCount $content "Reconnecting in"
"subscribed=$subscribed" >> $env:GITHUB_OUTPUT
"timed_out=$timedOut" >> $env:GITHUB_OUTPUT
"backoffs=$backoffs" >> $env:GITHUB_OUTPUT
Write-Output "Baseline -> subscribed=$subscribed timed_out=$timedOut backoffs=$backoffs"
# Read off a logged path rather than re-deriving the platform path; see the
# fuller note on the bounded-output scenario's copy of this step.
- name: Resolve the scripts directory (SUBACK scenario)
id: suback_scripts_dir
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
run: |
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$found = if ($content) { [regex]::Matches($content, 'Command saved to[^\r\n]*path=(?<p>\S+)') } else { @() }
if ($found.Count -eq 0) {
Write-Error "No 'Command saved to' line in the log; cannot resolve the scripts directory"
exit 1
}
$dir = Split-Path -Parent $found[$found.Count - 1].Groups['p'].Value.Trim('"')
"path=$dir" >> $env:GITHUB_OUTPUT
Write-Output "Scripts directory: $dir"
- name: Snapshot temp script files before the withheld-SUBACK scenario
uses: ./.github/actions/assert-no-orphaned-scripts
with:
mode: snapshot
scripts_dir: ${{ steps.suback_scripts_dir.outputs.path }}
- name: Start stub broker withholding SUBACK
id: stub_broker
uses: ./.github/actions/stub-broker
with:
mode: start
- name: Point agent at the stub broker
id: stub_host
uses: ./.github/actions/set-broker-host
with:
config_dir: ${{ matrix.config_dir }}
org_id: ${{ vars.IT_ORG_ID }}
host: ${{ steps.stub_broker.outputs.host }}
# --update restarts the service, so the rewritten broker host takes effect.
# The short subscribe timeout keeps each wedged cycle to ~10s so several
# backoff slots are observable inside the job.
- name: Restart agent against the stub broker
uses: ./.github/actions/run-agent
with:
binary: ${{ matrix.binary }}
args: --update --org-id ${{ vars.IT_ORG_ID }} --mqtt-subscribe-timeout-seconds 10 --github-token ${{ secrets.GITHUB_TOKEN }}
- name: Assert bounded subscribe failure and growing backoff
id: assert_suback_withheld
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASE_TIMED_OUT: ${{ steps.suback_baseline.outputs.timed_out }}
BASE_BACKOFFS: ${{ steps.suback_baseline.outputs.backoffs }}
BASE_SUBSCRIBED: ${{ steps.suback_baseline.outputs.subscribed }}
run: |
$baseTimedOut = [int]$env:BASE_TIMED_OUT
$baseBackoffs = [int]$env:BASE_BACKOFFS
$baseSubscribed = [int]$env:BASE_SUBSCRIBED
$needle = "Failed to subscribe: timed out waiting for broker acknowledgement"
# Two wedged cycles plus their backoff waits take roughly 10+2+10+4s.
$content = ""
for ($i = 1; $i -le 60; $i++) {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$timedOut = if ($content) { ([regex]::Matches($content, [regex]::Escape($needle))).Count } else { 0 }
$backoffs = if ($content) { ([regex]::Matches($content, [regex]::Escape("Reconnecting in"))).Count } else { 0 }
if (($timedOut - $baseTimedOut) -ge 2 -and ($backoffs - $baseBackoffs) -ge 2) { break }
Start-Sleep -Seconds 2
}
$timedOut = if ($content) { ([regex]::Matches($content, [regex]::Escape($needle))).Count } else { 0 }
if (($timedOut - $baseTimedOut) -lt 2) {
Write-Error "Expected at least two bounded subscribe timeouts, got $($timedOut - $baseTimedOut)"
exit 1
}
Write-Output "Bounded subscribe timeouts observed: $($timedOut - $baseTimedOut)"
# The agent must not have subscribed: a withheld SUBACK means no
# subscription, and a "Subscribed to messages" line here would mean the
# stub broker is not the broker the agent reached.
$subscribed = ([regex]::Matches($content, [regex]::Escape("Subscribed to messages"))).Count
if ($subscribed -ne $baseSubscribed) {
Write-Error "Agent reported a subscription against a broker that withholds SUBACK"
exit 1
}
# The backoff must not be cleared by a timed-out subscribe: a throttling
# broker needs progressively longer waits, not a tight reconnect loop.
# Go renders a duration as concatenated unit components ("4.1s",
# "1m4s"), so each component is summed rather than parsed as one number.
function ConvertTo-Seconds([string]$value) {
$total = 0.0
foreach ($m in [regex]::Matches($value, '(?<n>[0-9.]+)(?<u>ms|us|ns|h|m|s)')) {
$n = [double]$m.Groups['n'].Value
switch ($m.Groups['u'].Value) {
'ns' { $total += $n / 1e9 }
'us' { $total += $n / 1e6 }
'ms' { $total += $n / 1e3 }
's' { $total += $n }
'm' { $total += $n * 60 }
'h' { $total += $n * 3600 }
}
}
return $total
}
$waits = [regex]::Matches($content, 'Reconnecting in: timeout=(?<t>[0-9.a-z]+)') |
ForEach-Object { ConvertTo-Seconds $_.Groups['t'].Value }
$new = @($waits | Select-Object -Skip $baseBackoffs)
if ($new.Count -lt 2) {
Write-Error "Expected at least two reconnect waits after the subscribe timeouts, got $($new.Count)"
exit 1
}
Write-Output "Reconnect waits after the subscribe timeouts: $($new -join ', ')"
if ($new[1] -le $new[0]) {
Write-Error "Reconnect backoff did not grow ($($new[0]) then $($new[1])); a timed-out subscribe must not clear it"
exit 1
}
Write-Output "Confirmed the reconnect backoff grows after a withheld SUBACK"
# What the agent actually did against the stub is only visible in its own
# log, and the assertion above deliberately reads counts rather than lines.
# Dumping the tail on failure makes a fixture problem (never reached the
# broker at all) distinguishable from a real regression (reached it and
# blocked) without re-running the job.
- name: Dump agent log on withheld-SUBACK failure
if: failure() && steps.assert_suback_withheld.outcome == 'failure'
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
run: |
Write-Output "---- last 100 lines of $($env:LOG_FILE) ----"
Get-Content $env:LOG_FILE -Tail 100 -ErrorAction SilentlyContinue
# The original defect made this impossible: with the cycle parked in
# token.Wait() the stop signal was never reached, the platform waited out
# its stop deadline (30s on the Windows SCM) and force-killed the process.
- name: Assert the service stops promptly while wedged on the stub broker
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
SERVICE: ${{ matrix.service }}
run: |
function Get-StopCount {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
if ($content) { ([regex]::Matches($content, [regex]::Escape("Service stopped"))).Count } else { 0 }
}
# Counted here rather than reusing the scenario-wide baseline: the
# --update that pointed the agent at the stub broker restarts the
# service, and that restart logs its own "Service stopped". Measured
# against the older baseline the delta was already satisfied before this
# stop was even issued, so the assertion "passed" in 0.2s without
# observing the stop it exists to test.
$before = Get-StopCount
Write-Output "Service stopped lines before issuing the stop: $before"
$sw = [System.Diagnostics.Stopwatch]::StartNew()
if ($IsWindows) {
sc.exe stop $env:SERVICE | Out-Null
} elseif ($IsLinux) {
sudo systemctl stop $env:SERVICE
} else {
# Bare label, not a "system/<label>" service target. launchctl's
# `stop` is a legacy subcommand that resolves a label in the current
# domain, so the target form is taken as a literal label, matches
# nothing, and exits 3 (ESRCH) without ever signalling the agent.
# This mirrors what the agent's own darwinService.Stop does. `stop`
# leaves the job loaded, so the later start-service can run it again.
sudo launchctl stop $env:SERVICE
}
# launchctl exits non-zero in situations that are not failures here -
# the repo's own stop-service action already guards it with `|| true` -
# and the pwsh shell ends by exiting with $LASTEXITCODE, which failed
# this step on macOS even after the assertion below had passed. Report
# the code and clear it; whether the stop was honored is decided by the
# agent's log, not by the service manager's exit status.
Write-Output "Stop command exit code: $LASTEXITCODE"
$global:LASTEXITCODE = 0
# A clean exit runs the agent's deferred teardown, whose last act is the
# "Service stopped" line; a force-kill past the stop deadline never
# produces one.
$stopped = $false
while ($sw.Elapsed.TotalSeconds -lt 30) {
if ((Get-StopCount) -gt $before) { $stopped = $true; break }
Start-Sleep -Milliseconds 500
}
$sw.Stop()
if (-not $stopped) {
# Both halves matter when this fails: the agent log says whether the
# stop was received and ignored, and the service manager says whether
# it was ever delivered.
Write-Output "---- last 60 lines of the agent log ----"
Get-Content $env:LOG_FILE -Tail 60 -ErrorAction SilentlyContinue
Write-Output "---- service manager state ----"
if ($IsWindows) {
sc.exe query $env:SERVICE
} elseif ($IsLinux) {
sudo systemctl status $env:SERVICE --no-pager
} else {
# print, unlike stop, is a modern subcommand and does take the
# system/<label> service target.
sudo launchctl print "system/$($env:SERVICE)"
}
$global:LASTEXITCODE = 0
Write-Error "Service did not log a clean stop within 30s while wedged on a withholding broker"
exit 1
}
Write-Output "Service stopped cleanly after $([math]::Round($sw.Elapsed.TotalSeconds, 1))s while wedged"
exit 0
- name: Assert no orphaned scripts after the wedged stop
uses: ./.github/actions/assert-no-orphaned-scripts
with:
mode: assert
scripts_dir: ${{ steps.suback_scripts_dir.outputs.path }}
- name: Restart the service against the still-withholding broker
uses: ./.github/actions/start-service
with:
service: ${{ matrix.service }}
- name: Wait for the agent to wedge on the stub broker again
uses: ./.github/actions/wait-for-log-line
with:
log_file: ${{ matrix.log_file }}
pattern: "Failed to subscribe: timed out waiting for broker acknowledgement"
max_attempts: "60"
interval_seconds: "2"
# Flipped on the live connection - the stub re-reads its mode per packet -
# so recovery is the agent's own next reconnect cycle, not a restart.
- name: Switch stub broker to acknowledge SUBACK
uses: ./.github/actions/stub-broker
with:
mode: ack
- name: Assert the agent recovers on a later cycle
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.suback_baseline.outputs.subscribed }}
run: |
$baseline = [int]$env:BASELINE
for ($i = 1; $i -le 60; $i++) {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$count = if ($content) { ([regex]::Matches($content, [regex]::Escape("Subscribed to messages"))).Count } else { 0 }
if ($count -gt $baseline) {
Write-Output "Agent subscribed on a later cycle once SUBACK arrived (count $count > baseline $baseline) after ~$($i * 2)s"
exit 0
}
Start-Sleep -Seconds 2
}
Write-Error "Agent never subscribed after the stub broker started acknowledging"
exit 1
- name: Restore the real broker host
if: always() && steps.stub_host.outputs.previous_host != ''
uses: ./.github/actions/set-broker-host
with:
config_dir: ${{ matrix.config_dir }}
org_id: ${{ vars.IT_ORG_ID }}
host: ${{ steps.stub_host.outputs.previous_host }}
- name: Stop stub broker
if: always()
uses: ./.github/actions/stub-broker
with:
mode: stop
- name: Restart agent against the real broker
if: always() && steps.stub_host.outputs.previous_host != ''
uses: ./.github/actions/run-agent
with:
binary: ${{ matrix.binary }}
args: --update --org-id ${{ vars.IT_ORG_ID }} --mqtt-subscribe-timeout-seconds 30 --github-token ${{ secrets.GITHUB_TOKEN }}
- name: Wait for resubscription to the real broker
if: always() && steps.stub_host.outputs.previous_host != ''
uses: ./.github/actions/wait-for-log-line
with:
log_file: ${{ matrix.log_file }}
pattern: Subscribed to messages
max_attempts: "60"
interval_seconds: "2"
# ---- Per-command execution timeout scenario (sc-103835) ----
# Configure a short per-command timeout, dispatch a script that sleeps well
# beyond it, and confirm the agent kills the command (logging a timeout) and
# that a subsequent ordinary command still completes - i.e. the worker pool
# recovered instead of staying wedged. Counts are compared as deltas because
# the log already carries lines from earlier cycles.
- name: Enable short command timeout
uses: ./.github/actions/run-agent
with:
binary: ${{ matrix.binary }}
args: --update --org-id ${{ vars.IT_ORG_ID }} --command-timeout-seconds 5 --github-token ${{ secrets.GITHUB_TOKEN }}
- name: Wait for fresh subscription after timeout update
uses: ./.github/actions/wait-for-log-line
with:
log_file: ${{ matrix.log_file }}
pattern: Subscribed to messages
max_attempts: "60"
interval_seconds: "2"
- name: Capture command-timeout baseline counts
id: timeout_baseline
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
run: |
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$timedOut = if ($content) { ([regex]::Matches($content, [regex]::Escape("Command timed out"))).Count } else { 0 }
$completed = if ($content) { ([regex]::Matches($content, [regex]::Escape("Command completed"))).Count } else { 0 }
"timed_out=$timedOut" >> $env:GITHUB_OUTPUT
"completed=$completed" >> $env:GITHUB_OUTPUT
Write-Output "Baseline counts -> timed_out=$timedOut completed=$completed"
- name: Send hanging command
uses: ./.github/actions/send-command
with:
trigger_url: ${{ vars.IT_SEND_COMMAND_TRIGGER_URL }}
device_id: ${{ steps.config.outputs.device_id }}
commands: ${{ matrix.timeout_commands }}
- name: Assert hanging command was killed by the timeout
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.timeout_baseline.outputs.timed_out }}
run: |
$baseline = [int]$env:BASELINE
for ($i = 1; $i -le 30; $i++) {
Start-Sleep -Seconds 2
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$count = if ($content) { ([regex]::Matches($content, [regex]::Escape("Command timed out"))).Count } else { 0 }
if ($count -gt $baseline) {
Write-Output "Command timed out as expected (count $count > baseline $baseline) after ~$($i * 2)s"
exit 0
}
}
Write-Error "Hanging command was not killed by the per-command timeout (count stayed at $baseline)"
exit 1
- name: Send command after timeout
uses: ./.github/actions/send-command
with:
trigger_url: ${{ vars.IT_SEND_COMMAND_TRIGGER_URL }}
device_id: ${{ steps.config.outputs.device_id }}
commands: ${{ matrix.success_commands }}
- name: Assert worker pool recovered after timeout
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.timeout_baseline.outputs.completed }}
run: |
$baseline = [int]$env:BASELINE
for ($i = 1; $i -le 30; $i++) {
Start-Sleep -Seconds 2
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$count = if ($content) { ([regex]::Matches($content, [regex]::Escape("Command completed"))).Count } else { 0 }
if ($count -gt $baseline) {
Write-Output "Worker pool recovered; a later command completed (count $count > baseline $baseline)"
exit 0
}
}
Write-Error "Worker pool did not process a command after the timeout (count stayed at $baseline)"
exit 1
# ---- SAS token proactive renewal scenario (sc-103969) ----
# The integration test binary is built with a short SAS token lifetime
# (sasTokenLifetimeOverrideStr=90s), so the agent must proactively
# reconnect with a freshly minted token a safety margin BEFORE the token
# expires rather than being forcibly disconnected by the broker on expiry.
# Install the IT binary with auto-updates disabled so it stays the running
# service (otherwise the 30s auto-updater would swap it for the real
# release before renewal fires), then confirm: the renewal fires (distinct
# Info log), the agent re-subscribes with the fresh token, and it is
# graceful - no Error "Connection lost" is produced. Deltas are compared
# because earlier cycles already left "Subscribed to messages"/"Connection
# lost" lines in the log.
- name: Install IT binary with short SAS token lifetime
uses: ./.github/actions/run-agent
with:
binary: ${{ matrix.it_binary }}
args: --update --org-id ${{ vars.IT_ORG_ID }} --no-auto-updates ${{ matrix.no_auto_updates_extra }} --github-token ${{ secrets.GITHUB_TOKEN }}
- name: Wait for fresh subscription after SAS lifetime update
uses: ./.github/actions/wait-for-log-line
with:
log_file: ${{ matrix.log_file }}
pattern: Subscribed to messages
max_attempts: "60"
interval_seconds: "2"
- name: Capture SAS renewal baseline counts
id: sas_renewal_baseline
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
run: |
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$renewed = if ($content) { ([regex]::Matches($content, [regex]::Escape("Renewing SAS token before expiry"))).Count } else { 0 }
$subscribed = if ($content) { ([regex]::Matches($content, [regex]::Escape("Subscribed to messages"))).Count } else { 0 }
$lost = if ($content) { ([regex]::Matches($content, [regex]::Escape("Connection lost"))).Count } else { 0 }
$completed = if ($content) { ([regex]::Matches($content, [regex]::Escape("Command completed"))).Count } else { 0 }
"renewed=$renewed" >> $env:GITHUB_OUTPUT
"subscribed=$subscribed" >> $env:GITHUB_OUTPUT
"lost=$lost" >> $env:GITHUB_OUTPUT
"completed=$completed" >> $env:GITHUB_OUTPUT
Write-Output "Baseline counts -> renewed=$renewed subscribed=$subscribed lost=$lost completed=$completed"
- name: Wait for proactive SAS token renewal
uses: ./.github/actions/wait-for-log-line
with:
log_file: ${{ matrix.log_file }}
pattern: Renewing SAS token before expiry
max_attempts: "60"
interval_seconds: "2"
- name: Assert SAS token renewed and agent resubscribed with fresh token
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
RENEWED_BASELINE: ${{ steps.sas_renewal_baseline.outputs.renewed }}
SUBSCRIBED_BASELINE: ${{ steps.sas_renewal_baseline.outputs.subscribed }}
run: |
$renewedBaseline = [int]$env:RENEWED_BASELINE
$subscribedBaseline = [int]$env:SUBSCRIBED_BASELINE
for ($i = 1; $i -le 60; $i++) {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$renewed = if ($content) { ([regex]::Matches($content, [regex]::Escape("Renewing SAS token before expiry"))).Count } else { 0 }
$subscribed = if ($content) { ([regex]::Matches($content, [regex]::Escape("Subscribed to messages"))).Count } else { 0 }
if (($renewed -gt $renewedBaseline) -and ($subscribed -gt $subscribedBaseline)) {
Write-Output "SAS token renewed (count $renewed > baseline $renewedBaseline) and agent resubscribed (count $subscribed > baseline $subscribedBaseline) after ~$($i * 2)s"
exit 0
}
Start-Sleep -Seconds 2
}
Write-Error "Proactive SAS renewal did not fire and resubscribe (renewed stayed <= $renewedBaseline or subscribed stayed <= $subscribedBaseline)"
exit 1
- name: Assert SAS renewal was graceful (no forced disconnect)
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
LOST_BASELINE: ${{ steps.sas_renewal_baseline.outputs.lost }}
run: |
$baseline = [int]$env:LOST_BASELINE
$content = Get-Content $env:LOG_FILE -Raw
$lost = ([regex]::Matches($content, [regex]::Escape("Connection lost"))).Count
if ($lost -gt $baseline) {
Write-Error "SAS renewal was not graceful: 'Connection lost' count rose from $baseline to $lost (token expired before renewal fired?)"
exit 1
}
Write-Output "Confirmed graceful renewal: no new 'Connection lost' (count stayed at $baseline)"
- name: Send command after SAS renewal
uses: ./.github/actions/send-command
with:
trigger_url: ${{ vars.IT_SEND_COMMAND_TRIGGER_URL }}
device_id: ${{ steps.config.outputs.device_id }}
commands: ${{ matrix.success_commands }}
- name: Assert command delivery continues after SAS renewal
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.sas_renewal_baseline.outputs.completed }}
run: |
$baseline = [int]$env:BASELINE
for ($i = 1; $i -le 30; $i++) {
Start-Sleep -Seconds 2
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$count = if ($content) { ([regex]::Matches($content, [regex]::Escape("Command completed"))).Count } else { 0 }
if ($count -gt $baseline) {
Write-Output "Command delivery continues after renewal (count $count > baseline $baseline)"
exit 0
}
}
Write-Error "No command completed after SAS renewal (count stayed at $baseline)"
exit 1
# ---- Bounded command output scenario (sc-106105) ----
# A command's stdout and stderr used to be buffered whole in memory, so the
# agent's heap tracked however much a script decided to write and a verbose
# one could OOM-kill the service. Configure a deliberately small ceiling,
# flood it by three orders of magnitude, and assert the two properties that
# matter: the agent's RSS stays near the ceiling instead of near the output
# size, and the discarded output is reported rather than silently dropped.
#
# The release binary is installed first with the per-command timeout raised
# well past the floods' runtime, because the earlier timeout scenario left a
# 5s deadline in the config that would kill these commands mid-write, and
# the SAS scenario left the IT binary running with a 90s token lifetime
# whose reconnect would cancel them. --logging-level is deliberately not
# passed: it resets to the default (Info), which keeps the Warn under test
# visible while leaving the debug handler that dumps whole command outputs
# into the log switched off. --disable-agent-postback is likewise not
# passed (unlike the sweep scenario) so the truncated result actually
# traverses the postback path on every platform.
#
# Coverage note: these steps assert on the agent log, which is where the
# byte counts are observable on the endpoint. The same counts are what the
# postback carries as truncated/output_bytes_produced/output_bytes_kept -
# both come from one value computed once per command - but the postback body
# is never logged, so confirming the workflow's received payload stays a
# Rewst-side QA step.
- name: Resolve the scripts directory
id: scripts_dir
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
run: |
# Read the directory off a "Command saved to" line rather than
# re-deriving the platform path: the service's temp directory is not the
# runner's, notably root's private TMPDIR on macOS. Many earlier
# scenarios have already logged one.
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$found = if ($content) { [regex]::Matches($content, 'Command saved to[^\r\n]*path=(?<p>\S+)') } else { @() }
if ($found.Count -eq 0) {
Write-Error "No 'Command saved to' line in the log; cannot resolve the scripts directory"
exit 1
}
$path = $found[$found.Count - 1].Groups['p'].Value.Trim('"')
$dir = Split-Path -Parent $path
"path=$dir" >> $env:GITHUB_OUTPUT
Write-Output "Scripts directory: $dir"
- name: Snapshot temp script files before the output floods
uses: ./.github/actions/assert-no-orphaned-scripts
with:
mode: snapshot
scripts_dir: ${{ steps.scripts_dir.outputs.path }}
# Captured before the update below restarts the service: the restart's own
# "Subscribed to messages" line must land after this snapshot for the delta
# wait to mean anything.
- name: Capture bounded-output baseline counts
id: output_baseline
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
run: |
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$subscribed = if ($content) { ([regex]::Matches($content, [regex]::Escape("Subscribed to messages"))).Count } else { 0 }
$truncated = if ($content) { ([regex]::Matches($content, [regex]::Escape("Command output truncated"))).Count } else { 0 }
$completed = if ($content) { ([regex]::Matches($content, [regex]::Escape("Command completed"))).Count } else { 0 }
"subscribed=$subscribed" >> $env:GITHUB_OUTPUT
"truncated=$truncated" >> $env:GITHUB_OUTPUT
"completed=$completed" >> $env:GITHUB_OUTPUT
Write-Output "Baseline counts -> subscribed=$subscribed truncated=$truncated completed=$completed"
- name: Configure a small output ceiling
uses: ./.github/actions/run-agent
with:
binary: ${{ matrix.binary }}
args: --update --org-id ${{ vars.IT_ORG_ID }} --no-auto-updates --max-output-bytes 262144 --command-timeout-seconds 600 --github-token ${{ secrets.GITHUB_TOKEN }}
- name: Assert a non-positive output ceiling is rejected
shell: pwsh
env:
BINARY: ${{ matrix.binary }}
ORG_ID: ${{ vars.IT_ORG_ID }}
run: |
# The bound must not be disablable by configuration: a non-positive
# value is refused outright rather than accepted as "no limit" (a
# hand-edited config falls back to the documented default instead).
foreach ($value in @('0', '-1')) {
if ($IsWindows) {
$out = & "./dist/$env:BINARY" --update --org-id $env:ORG_ID --max-output-bytes $value 2>&1 | Out-String
} else {
$out = & sudo "./dist/$env:BINARY" --update --org-id $env:ORG_ID --max-output-bytes $value 2>&1 | Out-String
}
$code = $LASTEXITCODE
if ($code -eq 0) {
Write-Output $out
Write-Error "--max-output-bytes $value was accepted (exit 0); the bound must not be disablable"
exit 1
}
if ($out -notmatch 'invalid max-output-bytes: must be a positive integer') {
Write-Output $out
Write-Error "--max-output-bytes $value was rejected without the expected validation message"
exit 1
}
Write-Output "OK: --max-output-bytes $value rejected (exit $code) with the expected message"
}
# Explicit success: the runner appends "exit $LASTEXITCODE" to pwsh
# steps, and the last thing this step ran was a deliberately failing
# agent invocation, so falling off the end would report that failure as
# the step's own.
exit 0
- name: Wait for fresh subscription after the output ceiling update
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.output_baseline.outputs.subscribed }}
run: |
# A delta, not a bare match: the log already carries many "Subscribed to
# messages" lines, so only a new one proves the restarted agent is
# connected with the new ceiling in effect.
$baseline = [int]$env:BASELINE
for ($i = 1; $i -le 60; $i++) {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$count = if ($content) { ([regex]::Matches($content, [regex]::Escape("Subscribed to messages"))).Count } else { 0 }
if ($count -gt $baseline) {
Write-Output "Agent subscribed with the new output ceiling (count $count > baseline $baseline) after ~$($i * 2)s"
exit 0
}
Start-Sleep -Seconds 2
}
Write-Error "Agent did not subscribe after the output ceiling update (count stayed at $baseline)"
exit 1
- name: Send stdout flood command
uses: ./.github/actions/send-command
with:
trigger_url: ${{ vars.IT_SEND_COMMAND_TRIGGER_URL }}
device_id: ${{ steps.config.outputs.device_id }}
commands: ${{ matrix.verbose_commands }}
- name: Assert the stdout flood was bounded
uses: ./.github/actions/assert-output-bounded
with:
service: ${{ matrix.service }}
log_file: ${{ matrix.log_file }}
baseline_truncations: ${{ steps.output_baseline.outputs.truncated }}
expected_ceiling_bytes: "262144"
# At least the whole ceiling, since stdout alone floods it. The upper
# bound carries 4 KiB of headroom rather than being exact because the
# shell contributes a preamble of its own that is not this scenario's to
# control - on Windows the run deliberately injects a
# PROFILE_NOISE_<guid> marker into the all-users PowerShell profile,
# which every agent-spawned PowerShell echoes. What the bound has to
# catch is a stream that was not capped at all, and that would land
# near the 200 MiB produced, not a few bytes over.
min_kept_bytes: "262144"
max_kept_bytes: "266240"
min_produced_bytes: "209715200"
max_rss_mb: "250"
- name: Assert the flooding command still succeeded
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.output_baseline.outputs.completed }}
run: |
# Being verbose is not a failure: the command runs to completion with the
# excess discarded, so it reports "Command completed", not "Command
# failed" or "Command timed out".
$baseline = [int]$env:BASELINE
for ($i = 1; $i -le 30; $i++) {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$count = if ($content) { ([regex]::Matches($content, [regex]::Escape("Command completed"))).Count } else { 0 }
if ($count -gt $baseline) {
Write-Output "Flooding command completed normally (count $count > baseline $baseline)"
exit 0
}
Start-Sleep -Seconds 2
}
Write-Error "The flooding command never completed (count stayed at $baseline): it was killed for being verbose"
exit 1
- name: Capture small-output baseline counts
id: small_output_baseline
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
run: |
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$truncated = if ($content) { ([regex]::Matches($content, [regex]::Escape("Command output truncated"))).Count } else { 0 }
$completed = if ($content) { ([regex]::Matches($content, [regex]::Escape("Command completed"))).Count } else { 0 }
"truncated=$truncated" >> $env:GITHUB_OUTPUT
"completed=$completed" >> $env:GITHUB_OUTPUT
Write-Output "Baseline counts -> truncated=$truncated completed=$completed"
- name: Send ordinary command after the flood
uses: ./.github/actions/send-command
with:
trigger_url: ${{ vars.IT_SEND_COMMAND_TRIGGER_URL }}
device_id: ${{ steps.config.outputs.device_id }}
commands: ${{ matrix.success_commands }}
- name: Assert output below the ceiling is untouched and the worker recovered
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
COMPLETED_BASELINE: ${{ steps.small_output_baseline.outputs.completed }}
TRUNCATED_BASELINE: ${{ steps.small_output_baseline.outputs.truncated }}
run: |
# Two things at once: the worker the flood used was released (a later
# command completes), and a command whose output fits under the ceiling
# is not flagged - the bound only engages on the output that exceeds it.
$completedBaseline = [int]$env:COMPLETED_BASELINE
$truncatedBaseline = [int]$env:TRUNCATED_BASELINE
$completed = $completedBaseline
for ($i = 1; $i -le 30; $i++) {
Start-Sleep -Seconds 2
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$completed = if ($content) { ([regex]::Matches($content, [regex]::Escape("Command completed"))).Count } else { 0 }
if ($completed -gt $completedBaseline) { break }
}
if ($completed -le $completedBaseline) {
Write-Error "No command completed after the flood (count stayed at $completedBaseline): the worker was not released"
exit 1
}
Write-Output "Worker released; a later command completed (count $completed > baseline $completedBaseline)"
$content = Get-Content $env:LOG_FILE -Raw
$truncated = ([regex]::Matches($content, [regex]::Escape("Command output truncated"))).Count
if ($truncated -ne $truncatedBaseline) {
Write-Error "A small-output command was flagged as truncated (count rose from $truncatedBaseline to $truncated)"
exit 1
}
Write-Output "Confirmed small-output command was not truncated (count stayed at $truncatedBaseline)"
- name: Capture stderr-flood baseline counts
id: stderr_flood_baseline
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
run: |
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$truncated = if ($content) { ([regex]::Matches($content, [regex]::Escape("Command output truncated"))).Count } else { 0 }
"truncated=$truncated" >> $env:GITHUB_OUTPUT
Write-Output "Baseline counts -> truncated=$truncated"
- name: Send stderr flood command
uses: ./.github/actions/send-command
with:
trigger_url: ${{ vars.IT_SEND_COMMAND_TRIGGER_URL }}
device_id: ${{ steps.config.outputs.device_id }}
commands: ${{ matrix.verbose_stderr_commands }}
- name: Assert stderr is bounded independently of stdout
uses: ./.github/actions/assert-output-bounded
with:
service: ${{ matrix.service }}
log_file: ${{ matrix.log_file }}
baseline_truncations: ${{ steps.stderr_flood_baseline.outputs.truncated }}
expected_ceiling_bytes: "262144"
# Above the ceiling on purpose: the script floods stderr to its full
# ceiling AND writes a short stdout line, so the kept total can only
# exceed the ceiling if the two streams have separate budgets. A shared
# budget would cap the total at 262144 and starve one of them. The upper
# bound has the same 4 KiB of headroom as the stdout flood, for the same
# reason: the stdout side carries the shell's preamble as well as the
# scenario's own line.
min_kept_bytes: "262145"
max_kept_bytes: "266240"
min_produced_bytes: "209715200"
max_rss_mb: "250"
# Captured before the update below restarts the service, for the same
# reason as the bounded-output baseline.
- name: Capture timeout-composition baseline counts
id: compose_baseline
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
run: |
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$subscribed = if ($content) { ([regex]::Matches($content, [regex]::Escape("Subscribed to messages"))).Count } else { 0 }
$truncated = if ($content) { ([regex]::Matches($content, [regex]::Escape("Command output truncated"))).Count } else { 0 }
$timedOut = if ($content) { ([regex]::Matches($content, [regex]::Escape("Command timed out"))).Count } else { 0 }
$completed = if ($content) { ([regex]::Matches($content, [regex]::Escape("Command completed"))).Count } else { 0 }
"subscribed=$subscribed" >> $env:GITHUB_OUTPUT
"truncated=$truncated" >> $env:GITHUB_OUTPUT
"timed_out=$timedOut" >> $env:GITHUB_OUTPUT
"completed=$completed" >> $env:GITHUB_OUTPUT
Write-Output "Baseline counts -> subscribed=$subscribed truncated=$truncated timed_out=$timedOut completed=$completed"
- name: Shorten the command timeout for the composition check
uses: ./.github/actions/run-agent
with:
binary: ${{ matrix.binary }}
args: --update --org-id ${{ vars.IT_ORG_ID }} --no-auto-updates --max-output-bytes 262144 --command-timeout-seconds 30 --github-token ${{ secrets.GITHUB_TOKEN }}
- name: Wait for fresh subscription after the timeout update
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.compose_baseline.outputs.subscribed }}
run: |
$baseline = [int]$env:BASELINE
for ($i = 1; $i -le 60; $i++) {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$count = if ($content) { ([regex]::Matches($content, [regex]::Escape("Subscribed to messages"))).Count } else { 0 }
if ($count -gt $baseline) {
Write-Output "Agent subscribed with the short timeout (count $count > baseline $baseline) after ~$($i * 2)s"
exit 0
}
Start-Sleep -Seconds 2
}
Write-Error "Agent did not subscribe after the timeout update (count stayed at $baseline)"
exit 1
- name: Send verbose command that then hangs
uses: ./.github/actions/send-command
with:
trigger_url: ${{ vars.IT_SEND_COMMAND_TRIGGER_URL }}
device_id: ${{ steps.config.outputs.device_id }}
commands: ${{ matrix.verbose_hang_commands }}
- name: Assert the hanging command's output was still bounded
uses: ./.github/actions/assert-output-bounded
with:
service: ${{ matrix.service }}
log_file: ${{ matrix.log_file }}
baseline_truncations: ${{ steps.compose_baseline.outputs.truncated }}
expected_ceiling_bytes: "262144"
# Same headroom as the other floods: stdout fills the ceiling on its
# own, and anything the shell adds on either stream is incidental.
min_kept_bytes: "262144"
max_kept_bytes: "266240"
# Lower than the flood's full 200 MiB: the command is killed at its
# deadline, so only the volume written before the kill is counted.
min_produced_bytes: "104857600"
max_rss_mb: "250"
# The warning lands once the deadline kills the process group, and
# cmd.WaitDelay can hold Run for up to 10s more after that.
max_attempts: "120"
- name: Assert the hanging command also timed out and released its worker
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
TIMED_OUT_BASELINE: ${{ steps.compose_baseline.outputs.timed_out }}
run: |
# The two bounds compose: the same command is reported as truncated
# (asserted above) and as timed out, neither masking the other.
$baseline = [int]$env:TIMED_OUT_BASELINE
for ($i = 1; $i -le 30; $i++) {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$count = if ($content) { ([regex]::Matches($content, [regex]::Escape("Command timed out"))).Count } else { 0 }
if ($count -gt $baseline) {
Write-Output "Verbose hanging command was killed by the timeout (count $count > baseline $baseline) after ~$($i * 2)s"
exit 0
}
Start-Sleep -Seconds 2
}
Write-Error "Verbose hanging command was not killed by the per-command timeout (count stayed at $baseline)"
exit 1
- name: Send command after the verbose timeout
uses: ./.github/actions/send-command
with:
trigger_url: ${{ vars.IT_SEND_COMMAND_TRIGGER_URL }}
device_id: ${{ steps.config.outputs.device_id }}
commands: ${{ matrix.success_commands }}
- name: Assert the worker recovered after the verbose timeout
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.compose_baseline.outputs.completed }}
run: |
$baseline = [int]$env:BASELINE
for ($i = 1; $i -le 30; $i++) {
Start-Sleep -Seconds 2
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$count = if ($content) { ([regex]::Matches($content, [regex]::Escape("Command completed"))).Count } else { 0 }
if ($count -gt $baseline) {
Write-Output "Worker recovered after the verbose timeout (count $count > baseline $baseline)"
exit 0
}
}
Write-Error "No command completed after the verbose timeout (count stayed at $baseline)"
exit 1
- name: Assert the output floods left no orphaned script files
uses: ./.github/actions/assert-no-orphaned-scripts
with:
mode: assert
scripts_dir: ${{ steps.scripts_dir.outputs.path }}
# ---- Stale script file sweep scenario (sc-103967) ----
# A command interrupted by an abrupt kill (force-stop, OOM kill, power
# loss) never runs its deferred temp-file cleanup, so its script file is
# stranded in the scripts directory and nothing used to reclaim it. Verify
# the startup sweep now does: force-kill the service mid-command to strand
# a real script file, age it (plus a control set) into the months-old
# debris a long-lived install accumulates, restart, and confirm only the
# agent's own stale files are removed.
#
# The release binary is reinstalled first, with auto-updates off and the
# per-command timeout raised well past the command's runtime, so nothing
# ends the command before the kill lands - not the 5s timeout from the
# earlier scenario, the 30s auto-updater, or the IT binary's 90s SAS
# lifetime. Each of those tears the command down gracefully, and graceful
# teardown DOES run the cleanup, leaving no stranded file to sweep.
- name: Capture sweep scenario baseline counts
id: sweep_baseline
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
run: |
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$subscribed = if ($content) { ([regex]::Matches($content, [regex]::Escape("Subscribed to messages"))).Count } else { 0 }
$saved = if ($content) { ([regex]::Matches($content, [regex]::Escape("Command saved to"))).Count } else { 0 }
"subscribed=$subscribed" >> $env:GITHUB_OUTPUT
"saved=$saved" >> $env:GITHUB_OUTPUT
Write-Output "Baseline counts -> subscribed=$subscribed saved=$saved"
- name: Install release binary for the sweep scenario
uses: ./.github/actions/run-agent
with:
binary: ${{ matrix.binary }}
args: --update --org-id ${{ vars.IT_ORG_ID }} --no-auto-updates ${{ matrix.no_auto_updates_extra }} --command-timeout-seconds 600 --github-token ${{ secrets.GITHUB_TOKEN }}
- name: Wait for fresh subscription before the sweep scenario
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.sweep_baseline.outputs.subscribed }}
run: |
# A delta, not a bare match: the log already carries many "Subscribed to
# messages" lines from earlier scenarios, so only a new one proves the
# restarted agent is connected and ready to receive the command.
$baseline = [int]$env:BASELINE
for ($i = 1; $i -le 60; $i++) {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$count = if ($content) { ([regex]::Matches($content, [regex]::Escape("Subscribed to messages"))).Count } else { 0 }
if ($count -gt $baseline) {
Write-Output "Agent subscribed after the sweep-scenario install (count $count > baseline $baseline) after ~$($i * 2)s"
exit 0
}
Start-Sleep -Seconds 2
}
Write-Error "Agent did not subscribe after the sweep-scenario install (count stayed at $baseline)"
exit 1
- name: Send long-running command
uses: ./.github/actions/send-command
with:
trigger_url: ${{ vars.IT_SEND_COMMAND_TRIGGER_URL }}
device_id: ${{ steps.config.outputs.device_id }}
commands: ${{ matrix.sweep_commands }}
- name: Capture the in-flight script file path
id: inflight_script
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.sweep_baseline.outputs.saved }}
run: |
# The agent logs the temp file it wrote the command to, so read the path
# (and the scripts directory) straight from the log instead of
# re-deriving the platform path - the service's temp directory is not
# the runner's, notably root's private TMPDIR on macOS.
$baseline = [int]$env:BASELINE
for ($i = 1; $i -le 30; $i++) {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$found = if ($content) { [regex]::Matches($content, 'Command saved to[^\r\n]*path=(?<p>\S+)') } else { @() }
if ($found.Count -gt $baseline) {
$path = $found[$found.Count - 1].Groups['p'].Value.Trim('"')
$dir = Split-Path -Parent $path
"path=$path" >> $env:GITHUB_OUTPUT
"scripts_dir=$dir" >> $env:GITHUB_OUTPUT
Write-Output "In-flight script file: $path (scripts directory $dir)"
exit 0
}
Start-Sleep -Seconds 2
}
Write-Error "Agent never logged a script file for the long-running command (count stayed at $baseline)"
exit 1
- name: Force-kill the agent mid-command
uses: ./.github/actions/kill-service
with:
service: ${{ matrix.service }}
- name: Age the stranded script file and seed sweep control files
uses: ./.github/actions/script-sweep-fixture
with:
mode: seed
scripts_dir: ${{ steps.inflight_script.outputs.scripts_dir }}
orphan_path: ${{ steps.inflight_script.outputs.path }}
- name: Capture sweep log baseline count
id: sweep_log_baseline
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
run: |
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$swept = if ($content) { ([regex]::Matches($content, [regex]::Escape("Swept stale script files"))).Count } else { 0 }
"swept=$swept" >> $env:GITHUB_OUTPUT
Write-Output "Baseline counts -> swept=$swept"
- name: Restart agent to trigger the startup sweep
uses: ./.github/actions/run-agent
with:
binary: ${{ matrix.binary }}
args: --update --org-id ${{ vars.IT_ORG_ID }} --no-auto-updates ${{ matrix.no_auto_updates_extra }} --github-token ${{ secrets.GITHUB_TOKEN }}
- name: Wait for and assert the startup sweep was logged
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.sweep_log_baseline.outputs.swept }}
run: |
$baseline = [int]$env:BASELINE
for ($i = 1; $i -le 60; $i++) {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$swept = if ($content) { ([regex]::Matches($content, [regex]::Escape("Swept stale script files"))).Count } else { 0 }
if ($swept -gt $baseline) {
Write-Output "Startup sweep logged (count $swept > baseline $baseline) after ~$($i * 2)s"
exit 0
}
Start-Sleep -Seconds 2
}
Write-Error "Startup sweep was never logged (count stayed at $baseline)"
exit 1
- name: Assert stale script files swept and live files untouched
uses: ./.github/actions/script-sweep-fixture
with:
mode: assert
scripts_dir: ${{ steps.inflight_script.outputs.scripts_dir }}
orphan_path: ${{ steps.inflight_script.outputs.path }}
# ---- Downloaded installer sweep scenario (sc-106111) ----
# Every auto-update downloads a full agent binary and executes it as the
# installer. The installer is spawned detached and the process that could
# delete it afterwards is the one the installer replaces, so the download
# path cannot clean up after itself and nothing else used to - one
# orphaned binary accumulated per update for the lifetime of the install,
# until the volume filled and took future updates and command execution
# with it. Verify the startup sweep now reclaims them.
#
# The fixture is planted rather than produced by a real update cycle: the
# sweep is what this ticket changed, and the download side (where the file
# lands, under what name) is covered by unit tests that assert the two
# halves share one pattern constant. Ageing is the only simulated part, so
# the production 24h threshold stays in play with no test-only override.
#
# Only the org's own updates directory is asserted here. The sweep also
# covers the legacy shared temp directory that older agents downloaded
# into, but that is the *service account's* temp directory - notably root's
# private TMPDIR on macOS, not the runner's - so a fixture planted from
# the runner would land somewhere the service never reads. That half is
# covered by TestExecute_SweepsStaleInstallerFilesOnStartup, which runs
# Execute in-process and can see its own temp directory.
- name: Seed the installer sweep fixture
uses: ./.github/actions/installer-sweep-fixture
with:
mode: seed
updates_dir: ${{ matrix.config_dir }}/${{ vars.IT_ORG_ID }}/updates
- name: Capture installer sweep log baseline count
id: installer_sweep_baseline
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
run: |
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$swept = if ($content) { ([regex]::Matches($content, [regex]::Escape("Swept stale installer files"))).Count } else { 0 }
"swept=$swept" >> $env:GITHUB_OUTPUT
Write-Output "Baseline counts -> swept=$swept"
- name: Restart agent to trigger the installer sweep
uses: ./.github/actions/run-agent
with:
binary: ${{ matrix.binary }}
args: --update --org-id ${{ vars.IT_ORG_ID }} --no-auto-updates ${{ matrix.no_auto_updates_extra }} --github-token ${{ secrets.GITHUB_TOKEN }}
- name: Wait for and assert the installer sweep was logged
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.installer_sweep_baseline.outputs.swept }}
run: |
$baseline = [int]$env:BASELINE
for ($i = 1; $i -le 60; $i++) {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$swept = if ($content) { ([regex]::Matches($content, [regex]::Escape("Swept stale installer files"))).Count } else { 0 }
if ($swept -gt $baseline) {
Write-Output "Installer sweep logged (count $swept > baseline $baseline) after ~$($i * 2)s"
exit 0
}
Start-Sleep -Seconds 2
}
Write-Output "---- last 40 log lines ----"
Get-Content $env:LOG_FILE -Tail 40 -ErrorAction SilentlyContinue
Write-Error "Installer sweep was never logged (count stayed at $baseline)"
exit 1
- name: Assert stale installers swept and live files untouched
uses: ./.github/actions/installer-sweep-fixture
with:
mode: assert
updates_dir: ${{ matrix.config_dir }}/${{ vars.IT_ORG_ID }}/updates
# ---- Capped and jittered auto-update retry scenario (sc-106110) ----
# The auto-update retry delay was base * (1 << attempt) with no ceiling and
# no jitter. Unjittered, every agent that failed against the release
# endpoint at the same moment retried at the same instants, so an outage or
# rate limit was sustained by the fleet trying to recover from it; uncapped,
# a large retry count overflowed the shift into a negative duration, which
# made the wait return immediately and spun the loop against the endpoint.
#
# A GitHub outage is not something CI can arrange and an unroutable address
# produces connection errors rather than the HTTP failure the ticket
# describes, so the agent is pointed at the test/stubrelease fixture through
# the override file the integration build honors. The fixture fails every
# request until it is flipped, which puts the agent into retryWithBackoff
# with the shortened build knobs - base 2s, 6 retries, 30s check interval,
# so the cap is a quarter of that interval (7.5s) - and makes a full
# schedule observable in under a minute.
#
# Fleet-wide de-synchronization needs many agents and is covered by unit
# tests over the schedule itself. What one endpoint can show, and what these
# steps assert, is that every slot is strictly positive, bounded by the cap,
# varies rather than repeating, and is never served back to back.
- name: Start stub release endpoint (failing)
id: stub_release
uses: ./.github/actions/stub-release
with:
mode: start
- name: Capture auto-update retry baseline counts
id: retry_baseline
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
run: |
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$retrying = if ($content) { ([regex]::Matches($content, [regex]::Escape("Retrying update"))).Count } else { 0 }
$succeeded = if ($content) { ([regex]::Matches($content, [regex]::Escape("Update succeeded on retry"))).Count } else { 0 }
"retrying=$retrying" >> $env:GITHUB_OUTPUT
"succeeded=$succeeded" >> $env:GITHUB_OUTPUT
Write-Output "Baseline counts -> retrying=$retrying succeeded=$succeeded"
# Written before the install, because the updater reads the override when a
# service cycle constructs it - a file written afterwards would not be seen
# until the next restart, and the agent would spend the scenario updating
# itself from the real releases API instead.
- name: Point the agent at the stub release endpoint
uses: ./.github/actions/set-release-url
with:
mode: set
config_dir: ${{ matrix.config_dir }}
org_id: ${{ vars.IT_ORG_ID }}
url: ${{ steps.stub_release.outputs.url }}
- name: Install integration test binary with auto-updates on
uses: ./.github/actions/run-agent
with:
binary: ${{ matrix.it_binary }}
args: --update --org-id ${{ vars.IT_ORG_ID }} --github-token ${{ secrets.GITHUB_TOKEN }}
- name: Wait for the update retry schedule to run
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.retry_baseline.outputs.retrying }}
run: |
# The first check fires 30s after the service starts, then the schedule
# is roughly 2s, 4s, 7.5s, 7.5s... Four new lines put two slots at the
# ceiling, which is what the jitter assertion below needs to tell a
# jittered schedule from one that is merely capped, and still leave two
# more slots (~15s) for the recovery flip to land in, so the flip cannot
# race the end of the retry budget.
$baseline = [int]$env:BASELINE
for ($i = 1; $i -le 150; $i++) {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$count = if ($content) { ([regex]::Matches($content, [regex]::Escape("Retrying update"))).Count } else { 0 }
if (($count - $baseline) -ge 4) {
Write-Output "Observed $($count - $baseline) update retries after ~${i}s"
exit 0
}
Start-Sleep -Seconds 1
}
Write-Error "The agent never retried the update against the failing release endpoint"
exit 1
# Flipped mid-sequence - the fixture re-reads its mode per request - so the
# recovery is the agent's own next retry, not a restart.
- name: Serve a valid release payload mid-sequence
uses: ./.github/actions/stub-release
with:
mode: ok
- name: Assert the update succeeds on a retry
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.retry_baseline.outputs.succeeded }}
run: |
# The fixture serves the running agent's own version as tag_name, so a
# recovered check ends at "No updates available" and the retry is seen
# succeeding without downloading or executing anything - the recovery is
# what is under test here, not the installer.
$baseline = [int]$env:BASELINE
for ($i = 1; $i -le 60; $i++) {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$count = if ($content) { ([regex]::Matches($content, [regex]::Escape("Update succeeded on retry"))).Count } else { 0 }
if ($count -gt $baseline) {
Write-Output "Update succeeded on a retry after ~$($i * 2)s (count $count > baseline $baseline)"
exit 0
}
Start-Sleep -Seconds 2
}
# Separates a real regression from a flip that landed after the budget
# was already spent, which would leave the next check succeeding on its
# first try and logging no retry at all.
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
if ($content -and $content.Contains("All retries exhausted")) {
Write-Output "Note: the log records an exhausted retry budget; the recovery flip may have landed after the last slot"
}
Write-Output "---- last 40 log lines ----"
Get-Content $env:LOG_FILE -Tail 40 -ErrorAction SilentlyContinue
Write-Error "The agent never logged a successful update retry after the endpoint recovered"
exit 1
- name: Assert the retry schedule is capped, jittered and never immediate
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.retry_baseline.outputs.retrying }}
run: |
# The cap the integration build lands on: a quarter of its 30s check
# interval, which is below the absolute 1h ceiling a released build uses.
$cap = 7.5
$baseline = [int]$env:BASELINE
$failures = @()
function ConvertTo-Seconds([string]$value) {
# Go renders a duration as concatenated unit components ("4.1s",
# "1m4s"), and a negative one with a leading '-'. The sign is read
# separately because the overflow this scenario guards against
# produced exactly that negative value, and summing the components
# alone would report it as positive.
$sign = if ($value.StartsWith('-')) { -1.0 } else { 1.0 }
$total = 0.0
foreach ($m in [regex]::Matches($value, '(?<n>[0-9.]+)(?<u>ms|us|ns|h|m|s)')) {
$n = [double]$m.Groups['n'].Value
switch ($m.Groups['u'].Value) {
'ns' { $total += $n / 1e9 }
'us' { $total += $n / 1e6 }
'ms' { $total += $n / 1e3 }
's' { $total += $n }
'm' { $total += $n * 60 }
'h' { $total += $n * 3600 }
}
}
return $sign * $total
}
$lines = @(Get-Content $env:LOG_FILE -ErrorAction SilentlyContinue |
Where-Object { $_ -match 'Retrying update' } |
Select-Object -Skip $baseline)
$slots = @()
foreach ($line in $lines) {
# hclog writes "<timestamp> [INFO] agent_smith: Retrying update: attempt=N backoff=D".
# The timestamp is a fixed-width local time followed by its offset, so
# the first 23 characters parse without worrying about the offset form.
$m = [regex]::Match($line, '^(?<ts>\S{23}).*Retrying update: attempt=(?<attempt>\d+) backoff=(?<backoff>\S+)')
if (-not $m.Success) {
$failures += "could not parse a retry line: $line"
continue
}
$stamp = $null
try {
$stamp = [datetime]::ParseExact(
$m.Groups['ts'].Value,
'yyyy-MM-ddTHH:mm:ss.fff',
[Globalization.CultureInfo]::InvariantCulture)
} catch {
$failures += "could not parse the timestamp of: $line"
}
$slots += [pscustomobject]@{
Attempt = [int]$m.Groups['attempt'].Value
Backoff = ConvertTo-Seconds $m.Groups['backoff'].Value
Time = $stamp
}
}
if ($slots.Count -lt 3) {
Write-Error "Expected at least three retry slots to inspect, got $($slots.Count)"
exit 1
}
# The timestamp table the ticket asks for: every slot, what it waited,
# and how long actually elapsed before the next one arrived.
Write-Output "---- observed update retry schedule ----"
for ($i = 0; $i -lt $slots.Count; $i++) {
$gap = ''
if ($i -lt $slots.Count - 1 -and $slots[$i].Time -and $slots[$i + 1].Time) {
$gap = [math]::Round(($slots[$i + 1].Time - $slots[$i].Time).TotalSeconds, 3)
}
Write-Output ("attempt={0} backoff={1}s elapsed_to_next={2}" -f $slots[$i].Attempt, [math]::Round($slots[$i].Backoff, 3), $gap)
}
foreach ($slot in $slots) {
# A zero or negative slot is the overflow busy-spin: time.After fires
# immediately and the loop issues requests as fast as it can.
if ($slot.Backoff -le 0) {
$failures += "attempt $($slot.Attempt): backoff $($slot.Backoff)s is not strictly positive"
}
# The tolerance covers the millisecond rendering, not the cap itself.
if ($slot.Backoff -gt ($cap + 0.05)) {
$failures += "attempt $($slot.Attempt): backoff $($slot.Backoff)s exceeds the ${cap}s cap"
}
}
# Jitter: a fixed schedule repeats the same values bit for bit.
$distinct = @($slots | ForEach-Object { [math]::Round($_.Backoff, 3) } | Select-Object -Unique)
if ($distinct.Count -lt 2) {
$failures += "every retry slot was $($distinct -join ', ')s - the schedule is not jittered"
}
# Distinct values alone are weak evidence, because the doubling produces
# distinct values on its own until it reaches the ceiling. The slots that
# do reach it are the discriminator: an unjittered schedule pins every
# one of them to exactly the cap, while jitter spreads them across the
# band below it. Skipped when the sequence was cut short by the recovery
# flip before two slots got that far.
$nearCap = @($slots | Where-Object { $_.Backoff -ge ($cap * 0.75) })
if ($nearCap.Count -ge 2) {
$distinctNearCap = @($nearCap | ForEach-Object { [math]::Round($_.Backoff, 3) } | Select-Object -Unique)
if ($distinctNearCap.Count -lt 2) {
$failures += "the capped slots all measured $($distinctNearCap -join ', ')s - the jitter is not being applied"
}
}
# Growth: the schedule still doubles up to the cap rather than being flat.
$maxBackoff = ($slots | Measure-Object -Property Backoff -Maximum).Maximum
if ($maxBackoff -le $slots[0].Backoff) {
$failures += "the schedule never grew (first $($slots[0].Backoff)s, largest ${maxBackoff}s)"
}
# Spacing: consecutive slots of one sequence must be separated by at
# least the wait that was logged. Pairs that are not consecutive attempts
# belong to different retry sequences and are skipped.
for ($i = 0; $i -lt $slots.Count - 1; $i++) {
if ($slots[$i + 1].Attempt -ne $slots[$i].Attempt + 1) { continue }
if (-not $slots[$i].Time -or -not $slots[$i + 1].Time) { continue }
$gap = ($slots[$i + 1].Time - $slots[$i].Time).TotalSeconds
if ($gap -lt 1) {
$failures += "attempts $($slots[$i].Attempt) and $($slots[$i + 1].Attempt) arrived ${gap}s apart - back to back"
}
if ($gap -lt ($slots[$i].Backoff * 0.8)) {
$failures += "attempt $($slots[$i].Attempt) logged a $($slots[$i].Backoff)s backoff but the next retry came after ${gap}s"
}
}
if ($failures.Count -gt 0) {
$failures | ForEach-Object { Write-Output "FAIL: $_" }
Write-Error "the update retry schedule is not capped, jittered and spaced as expected"
exit 1
}
Write-Output "Retry schedule bounded by ${cap}s, jittered across $($distinct.Count) distinct values, and never served back to back"
exit 0
- name: Fail the release endpoint again for the stop check
uses: ./.github/actions/stub-release
with:
mode: fail
- name: Capture stop-during-backoff baseline counts
id: retry_stop_baseline
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
run: |
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$retrying = if ($content) { ([regex]::Matches($content, [regex]::Escape("Retrying update"))).Count } else { 0 }
$stopped = if ($content) { ([regex]::Matches($content, [regex]::Escape("Auto updater stopped"))).Count } else { 0 }
"retrying=$retrying" >> $env:GITHUB_OUTPUT
"stopped=$stopped" >> $env:GITHUB_OUTPUT
Write-Output "Baseline counts -> retrying=$retrying stopped=$stopped"
- name: Wait for a fresh backoff to be entered
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.retry_stop_baseline.outputs.retrying }}
run: |
$baseline = [int]$env:BASELINE
for ($i = 1; $i -le 90; $i++) {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$count = if ($content) { ([regex]::Matches($content, [regex]::Escape("Retrying update"))).Count } else { 0 }
if ($count -gt $baseline) {
Write-Output "Agent is in a retry backoff again after ~${i}s"
exit 0
}
Start-Sleep -Seconds 1
}
Write-Error "The agent never entered a retry backoff after the endpoint was failed again"
exit 1
- name: Assert a service stop during a backoff is prompt
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
SERVICE: ${{ matrix.service }}
BASELINE: ${{ steps.retry_stop_baseline.outputs.stopped }}
run: |
# The agent has just entered a backoff with most of its 6-slot budget
# left (~30s of waiting at the 7.5s cap). A stop that has to wait out
# the pending slot - or worse, the whole budget - delays every caller of
# Stop(): the installer, an upgrade, and an uninstall.
$baseline = [int]$env:BASELINE
$sw = [System.Diagnostics.Stopwatch]::StartNew()
if ($IsWindows) {
sc.exe stop $env:SERVICE | Out-Null
} elseif ($IsLinux) {
sudo systemctl stop $env:SERVICE
} else {
# Bare label, not "system/<label>": stop is a legacy launchctl
# subcommand that resolves a label in the current domain, and a
# service-target form is read as a literal label that matches nothing.
sudo launchctl stop $env:SERVICE
}
# The service managers disagree about exit status for a stop that was
# delivered; the verdict here comes from the agent's own log.
$global:LASTEXITCODE = 0
for ($i = 1; $i -le 60; $i++) {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$count = if ($content) { ([regex]::Matches($content, [regex]::Escape("Auto updater stopped"))).Count } else { 0 }
if ($count -gt $baseline) {
$sw.Stop()
$elapsed = [math]::Round($sw.Elapsed.TotalSeconds, 1)
if ($sw.Elapsed.TotalSeconds -gt 20) {
Write-Error "The auto updater stopped only after ${elapsed}s, long enough to have waited out its retry schedule"
exit 1
}
Write-Output "Auto updater stopped ${elapsed}s after the stop was issued, mid-backoff"
exit 0
}
Start-Sleep -Milliseconds 500
}
$sw.Stop()
Write-Output "---- last 40 log lines ----"
Get-Content $env:LOG_FILE -Tail 40 -ErrorAction SilentlyContinue
Write-Error "The auto updater never logged a stop after the service was stopped mid-backoff"
exit 1
# The restore steps run under always() so a failed assertion above cannot
# leave the rest of the job running an agent that points at a stub release
# endpoint (or leave the service stopped for the scenarios that follow).
- name: Capture restore baseline counts
if: always()
id: retry_restore_baseline
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
run: |
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$subscribed = if ($content) { ([regex]::Matches($content, [regex]::Escape("Subscribed to messages"))).Count } else { 0 }
"subscribed=$subscribed" >> $env:GITHUB_OUTPUT
Write-Output "Baseline counts -> subscribed=$subscribed"
- name: Clear the release url override
if: always()
uses: ./.github/actions/set-release-url
with:
mode: clear
config_dir: ${{ matrix.config_dir }}
org_id: ${{ vars.IT_ORG_ID }}
- name: Stop stub release endpoint
if: always()
uses: ./.github/actions/stub-release
with:
mode: stop
- name: Reinstall the release binary after the retry scenario
if: always()
uses: ./.github/actions/run-agent
with:
binary: ${{ matrix.binary }}
args: --update --org-id ${{ vars.IT_ORG_ID }} --no-auto-updates ${{ matrix.no_auto_updates_extra }} --github-token ${{ secrets.GITHUB_TOKEN }}
- name: Wait for resubscription after the retry scenario
if: always()
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.retry_restore_baseline.outputs.subscribed }}
run: |
$baseline = [int]$env:BASELINE
for ($i = 1; $i -le 60; $i++) {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$count = if ($content) { ([regex]::Matches($content, [regex]::Escape("Subscribed to messages"))).Count } else { 0 }
if ($count -gt $baseline) {
Write-Output "Agent resubscribed after the retry scenario (count $count > baseline $baseline) after ~$($i * 2)s"
exit 0
}
Start-Sleep -Seconds 2
}
Write-Error "Agent never resubscribed after the retry scenario"
exit 1
# ---- Wedged Windows service stop scenario (sc-106108) ----
# windowsService.Stop() polled the service state every 250ms in an
# unbounded loop, so a service that never reached Stopped hung its caller
# forever - and every caller is blocking: the unattended auto-updater, the
# installer, and uninstall. The symptom was a device that went offline
# during a routine update with no error logged anywhere.
#
# The wedge is produced by pointing the agent's own service registration at
# the test/wedgedservice fixture, which accepts the stop control, reports
# StopPending, and never stops (see the action for why killing or
# suspending the agent will not do). The installed agent executable and
# config file are left alone, so they can be hashed before and after to
# prove an aborted update did not touch them.
#
# Windows only: the Unix service implementations have no such polling loop.
- name: Capture installed file hashes before the wedge
if: matrix.os == 'windows-latest'
id: wedge_hashes
shell: pwsh
env:
ORG_ID: ${{ vars.IT_ORG_ID }}
CONFIG_DIR: ${{ matrix.config_dir }}
run: |
$ErrorActionPreference = 'Stop'
$exe = Join-Path $env:PROGRAMFILES "RewstRemoteAgent\$($env:ORG_ID)\agent_smith.win.exe"
$config = Join-Path $env:CONFIG_DIR "$($env:ORG_ID)\config.json"
foreach ($path in @($exe, $config)) {
if (-not (Test-Path $path)) { throw "expected installed file is missing: $path" }
}
$exeHash = (Get-FileHash -Path $exe -Algorithm SHA256).Hash
$configHash = (Get-FileHash -Path $config -Algorithm SHA256).Hash
"exe_path=$exe" >> $env:GITHUB_OUTPUT
"config_path=$config" >> $env:GITHUB_OUTPUT
"exe_hash=$exeHash" >> $env:GITHUB_OUTPUT
"config_hash=$configHash" >> $env:GITHUB_OUTPUT
Write-Output "agent executable $exe sha256=$exeHash"
Write-Output "config file $config sha256=$configHash"
- name: Wedge the agent service in StopPending
if: matrix.os == 'windows-latest'
uses: ./.github/actions/wedged-service
with:
mode: wedge
service: ${{ matrix.service }}
- name: Assert the update aborts on a wedged stop
if: matrix.os == 'windows-latest'
shell: pwsh
env:
IT_BINARY: ${{ matrix.it_binary }}
ORG_ID: ${{ vars.IT_ORG_ID }}
GH_TOKEN: ${{ secrets.GITHUB_TOKEN }}
run: |
# The integration binary is the invoker because its stop deadline is
# overridden to 25s (see scripts/build_integration_test.ps1). The
# released default is five minutes; that the constant is what governs a
# production build is covered by unit tests rather than by keeping a
# runner idle for five minutes here.
$sw = [System.Diagnostics.Stopwatch]::StartNew()
$out = & "./dist/$($env:IT_BINARY)" --update --org-id $env:ORG_ID `
--github-token $env:GH_TOKEN 2>&1 | Out-String
$sw.Stop()
# The updater reports an aborted update through its log, not its exit
# status, and this step's verdict comes from the log below.
$global:LASTEXITCODE = 0
$elapsed = [math]::Round($sw.Elapsed.TotalSeconds, 1)
Write-Output "---- updater output after ${elapsed}s ----"
Write-Output $out
$failures = @()
# Returning at all is the headline: before the fix this call never came
# back. The floor proves it waited out its deadline rather than failing
# fast for an unrelated reason; the ceiling is far above the 25s
# deadline yet far below an unbounded hang.
if ($sw.Elapsed.TotalSeconds -lt 20) {
$failures += "update returned after ${elapsed}s, before its 25s stop deadline could elapse"
}
if ($sw.Elapsed.TotalSeconds -gt 180) {
$failures += "update took ${elapsed}s, far past its 25s stop deadline"
}
# The log has to name the service, the deadline and the last observed
# state, since that is the only account of why an unattended update
# aborted.
foreach ($needle in @(
'Failed to stop service',
'did not stop within',
'last observed state StopPending',
'Update aborted; existing installation left untouched'
)) {
if (-not $out.Contains($needle)) { $failures += "missing from the log: '$needle'" }
}
# And it must not have carried on as if the stop had succeeded.
foreach ($absent in @(
'Configuration successfully updated',
'Agent installed to',
'Service started'
)) {
if ($out.Contains($absent)) { $failures += "update proceeded past the failed stop: '$absent'" }
}
if ($failures.Count -gt 0) {
$failures | ForEach-Object { Write-Output "FAIL: $_" }
Write-Error "the update did not abort cleanly on a wedged stop"
exit 1
}
Write-Output "Update aborted on the wedged stop after ${elapsed}s, as expected"
exit 0
- name: Assert the aborted update left the installation untouched
if: matrix.os == 'windows-latest'
shell: pwsh
env:
EXE_PATH: ${{ steps.wedge_hashes.outputs.exe_path }}
CONFIG_PATH: ${{ steps.wedge_hashes.outputs.config_path }}
EXE_HASH: ${{ steps.wedge_hashes.outputs.exe_hash }}
CONFIG_HASH: ${{ steps.wedge_hashes.outputs.config_hash }}
run: |
# The whole point of aborting: the wedged process may still hold the
# executable open, so a half-written binary or a rewritten config would
# leave the endpoint unrecoverable without hands on it.
$ErrorActionPreference = 'Stop'
$failures = @()
foreach ($pair in @(
@{ Path = $env:EXE_PATH; Expected = $env:EXE_HASH; Label = 'agent executable' },
@{ Path = $env:CONFIG_PATH; Expected = $env:CONFIG_HASH; Label = 'config file' }
)) {
if (-not (Test-Path $pair.Path)) {
$failures += "$($pair.Label) was removed: $($pair.Path)"
continue
}
$actual = (Get-FileHash -Path $pair.Path -Algorithm SHA256).Hash
if ($actual -ne $pair.Expected) {
$failures += "$($pair.Label) changed: $($pair.Expected) -> $actual"
} else {
Write-Output "$($pair.Label) unchanged (sha256=$actual)"
}
}
if ($failures.Count -gt 0) {
$failures | ForEach-Object { Write-Output "FAIL: $_" }
Write-Error "the aborted update modified the installation"
exit 1
}
exit 0
# The failed stop above left the service in StopPending, and the agent
# treats only Running as active - so an uninstall issued now would skip the
# stop entirely instead of exercising it. Start a fresh wedged run so the
# uninstall meets a Running service, as an operator would.
- name: Re-wedge the service for the uninstall check
if: matrix.os == 'windows-latest'
uses: ./.github/actions/wedged-service
with:
mode: rewedge
service: ${{ matrix.service }}
- name: Assert the uninstall aborts on a wedged stop
if: matrix.os == 'windows-latest'
shell: pwsh
env:
IT_BINARY: ${{ matrix.it_binary }}
ORG_ID: ${{ vars.IT_ORG_ID }}
SERVICE: ${{ matrix.service }}
EXE_PATH: ${{ steps.wedge_hashes.outputs.exe_path }}
CONFIG_PATH: ${{ steps.wedge_hashes.outputs.config_path }}
EXE_HASH: ${{ steps.wedge_hashes.outputs.exe_hash }}
CONFIG_HASH: ${{ steps.wedge_hashes.outputs.config_hash }}
UNINSTALL_PATHS: ${{ matrix.uninstall_paths }}
run: |
$sw = [System.Diagnostics.Stopwatch]::StartNew()
$out = & "./dist/$($env:IT_BINARY)" --uninstall --org-id $env:ORG_ID 2>&1 | Out-String
$sw.Stop()
$global:LASTEXITCODE = 0
$elapsed = [math]::Round($sw.Elapsed.TotalSeconds, 1)
Write-Output "---- uninstaller output after ${elapsed}s ----"
Write-Output $out
$failures = @()
if ($sw.Elapsed.TotalSeconds -lt 20) {
$failures += "uninstall returned after ${elapsed}s, before its 25s stop deadline could elapse"
}
if ($sw.Elapsed.TotalSeconds -gt 180) {
$failures += "uninstall took ${elapsed}s, far past its 25s stop deadline"
}
foreach ($needle in @(
'Failed to stop service',
'did not stop within',
'Uninstall aborted; nothing was removed'
)) {
if (-not $out.Contains($needle)) { $failures += "missing from the log: '$needle'" }
}
foreach ($absent in @('Service deleted', 'Directory deleted')) {
if ($out.Contains($absent)) { $failures += "uninstall proceeded past the failed stop: '$absent'" }
}
# Fully intact or fully removed, never mixed: the registration, the
# installed directories, and both hashed files must all still be there.
if (-not (Get-Service -Name $env:SERVICE -ErrorAction SilentlyContinue)) {
$failures += "service registration $($env:SERVICE) was deleted"
}
foreach ($path in ($env:UNINSTALL_PATHS -split "`n" | ForEach-Object { $_.Trim() } |
Where-Object { $_ })) {
if (-not (Test-Path $path)) { $failures += "installed directory was removed: $path" }
}
foreach ($pair in @(
@{ Path = $env:EXE_PATH; Expected = $env:EXE_HASH; Label = 'agent executable' },
@{ Path = $env:CONFIG_PATH; Expected = $env:CONFIG_HASH; Label = 'config file' }
)) {
if (-not (Test-Path $pair.Path)) {
$failures += "$($pair.Label) was removed: $($pair.Path)"
} elseif ((Get-FileHash -Path $pair.Path -Algorithm SHA256).Hash -ne $pair.Expected) {
$failures += "$($pair.Label) changed during the aborted uninstall"
}
}
if ($failures.Count -gt 0) {
$failures | ForEach-Object { Write-Output "FAIL: $_" }
Write-Error "the uninstall did not abort cleanly on a wedged stop"
exit 1
}
Write-Output "Uninstall aborted on the wedged stop after ${elapsed}s with nothing removed"
exit 0
# Captured before the restore restarts the real agent, so the delta below
# can only come from the recovered service.
- name: Capture recovery baseline counts
if: matrix.os == 'windows-latest'
id: wedge_recovery_baseline
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
run: |
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$subscribed = if ($content) { ([regex]::Matches($content, [regex]::Escape("Subscribed to messages"))).Count } else { 0 }
"subscribed=$subscribed" >> $env:GITHUB_OUTPUT
Write-Output "Baseline counts -> subscribed=$subscribed"
# always(): a failed assertion above must not leave the runner's service
# registration pointing at the fixture, or the rest of the job (and the
# final uninstall) would be testing the fixture instead of the agent.
- name: Restore the agent service after the wedge
if: always() && matrix.os == 'windows-latest'
uses: ./.github/actions/wedged-service
with:
mode: restore
service: ${{ matrix.service }}
- name: Assert the recovered endpoint comes back online
if: matrix.os == 'windows-latest'
shell: pwsh
env:
LOG_FILE: ${{ matrix.log_file }}
BASELINE: ${{ steps.wedge_recovery_baseline.outputs.subscribed }}
run: |
$baseline = [int]$env:BASELINE
for ($i = 1; $i -le 60; $i++) {
$content = Get-Content $env:LOG_FILE -Raw -ErrorAction SilentlyContinue
$count = if ($content) { ([regex]::Matches($content, [regex]::Escape("Subscribed to messages"))).Count } else { 0 }
if ($count -gt $baseline) {
Write-Output "Recovered agent subscribed again (count $count > baseline $baseline) after ~$($i * 2)s"
exit 0
}
Start-Sleep -Seconds 2
}
Write-Error "Recovered agent never resubscribed (count stayed at $baseline)"
exit 1
- name: Assert a subsequent update succeeds after recovery
if: matrix.os == 'windows-latest'
shell: pwsh
env:
BINARY: ${{ matrix.binary }}
ORG_ID: ${{ vars.IT_ORG_ID }}
GH_TOKEN: ${{ secrets.GITHUB_TOKEN }}
NO_AUTO_UPDATES_EXTRA: ${{ matrix.no_auto_updates_extra }}
run: |
# The bound must only catch a wedge: once the endpoint is recovered, an
# ordinary update stops the service, replaces the binary and starts it
# again with no behavioral change.
$out = & "./dist/$($env:BINARY)" --update --org-id $env:ORG_ID --no-auto-updates `
$env:NO_AUTO_UPDATES_EXTRA --github-token $env:GH_TOKEN 2>&1 | Out-String
$global:LASTEXITCODE = 0
Write-Output $out
$failures = @()
foreach ($needle in @('Agent installed to', 'Service started')) {
if (-not $out.Contains($needle)) { $failures += "missing from the log: '$needle'" }
}
if ($out.Contains('Failed to stop service')) {
$failures += "a healthy stop was reported as a failure"
}
if ($failures.Count -gt 0) {
$failures | ForEach-Object { Write-Output "FAIL: $_" }
Write-Error "the post-recovery update did not complete normally"
exit 1
}
Write-Output "Post-recovery update completed normally"
exit 0
- name: Uninstall agent
uses: ./.github/actions/run-agent
with:
binary: ${{ matrix.binary }}
args: --uninstall --org-id ${{ vars.IT_ORG_ID }}
- name: Check deleted directories
uses: ./.github/actions/assert-uninstalled
with:
paths: ${{ matrix.uninstall_paths }}
test-service-user:
permissions:
contents: read
env:
GITHUB_TOKEN: ${{ secrets.GITHUB_TOKEN }}
needs: [build, build-integration-test, set-matrix]
strategy:
fail-fast: false
matrix: ${{ fromJson(needs.set-matrix.outputs.matrix) }}
runs-on: ${{ matrix.os }}
steps:
- name: Checkout code
uses: actions/checkout@v5
- name: Provision service account
id: provision
uses: ./.github/actions/provision-service-user
with:
username: ${{ matrix.service_user }}
- name: Install agent as service account
uses: ./.github/actions/install-agent
with:
os: ${{ matrix.os }}
binary: ${{ matrix.binary }}
it_binary: ${{ matrix.it_binary }}
config_url: ${{ vars.IT_CONFIG_URL }}
config_secret: ${{ secrets.IT_CONFIG_SECRET }}
org_id: ${{ vars.IT_ORG_ID }}
github_token: ${{ secrets.GITHUB_TOKEN }}
service_username: ${{ matrix.service_username_arg }}
service_password: ${{ steps.provision.outputs.password }}
- name: Assert service runs as account (config flow)
uses: ./.github/actions/assert-service-identity
with:
service: ${{ matrix.service }}
expected_identity: ${{ matrix.service_identity }}
- name: Validate config and get device id
uses: ./.github/actions/validate-config
with:
config_dir: ${{ matrix.config_dir }}
org_id: ${{ vars.IT_ORG_ID }}
- name: Assert password absent from config (config flow)
uses: ./.github/actions/assert-config-secret-absent
with:
config_dir: ${{ matrix.config_dir }}
org_id: ${{ vars.IT_ORG_ID }}
secret: ${{ steps.provision.outputs.password }}
- name: Re-register service via update flow (Unix)
if: runner.os != 'Windows'
shell: bash
env:
ORG_ID: ${{ vars.IT_ORG_ID }}
GH_TOKEN: ${{ secrets.GITHUB_TOKEN }}
SERVICE_USERNAME: ${{ matrix.service_username_arg }}
run: |
sudo "./dist/${{ matrix.binary }}" \
--update \
--org-id "$ORG_ID" \
--github-token "$GH_TOKEN" \
--service-username "$SERVICE_USERNAME"
- name: Re-register service via update flow (Windows)
if: runner.os == 'Windows'
shell: pwsh
env:
ORG_ID: ${{ vars.IT_ORG_ID }}
GH_TOKEN: ${{ secrets.GITHUB_TOKEN }}
SERVICE_USERNAME: ${{ matrix.service_username_arg }}
SERVICE_PASSWORD: ${{ steps.provision.outputs.password }}
run: |
& "./dist/${{ matrix.binary }}" `
--update `
--org-id $env:ORG_ID `
--github-token $env:GH_TOKEN `
--service-username $env:SERVICE_USERNAME `
--service-password $env:SERVICE_PASSWORD
- name: Assert service runs as account (update flow)
uses: ./.github/actions/assert-service-identity
with:
service: ${{ matrix.service }}
expected_identity: ${{ matrix.service_identity }}
- name: Assert password absent from config (update flow)
uses: ./.github/actions/assert-config-secret-absent
with:
config_dir: ${{ matrix.config_dir }}
org_id: ${{ vars.IT_ORG_ID }}
secret: ${{ steps.provision.outputs.password }}
- name: Uninstall agent
uses: ./.github/actions/run-agent
with:
binary: ${{ matrix.binary }}
args: --uninstall --org-id ${{ vars.IT_ORG_ID }}
- name: Check deleted directories
uses: ./.github/actions/assert-uninstalled
with:
paths: ${{ matrix.uninstall_paths }}
- name: Remove service account
if: always()
uses: ./.github/actions/remove-service-user
with:
username: ${{ matrix.service_user }}