Skip to content

Integration Test

Integration Test #241

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 }}
- 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 }}
- 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 {
sudo launchctl stop "system/$($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) {
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 }}
- 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 }}