diff --git a/.github/workflows/nsis-tests.yml b/.github/workflows/nsis-tests.yml index 5fecd1e6bc94..cd4fe306b0fb 100644 --- a/.github/workflows/nsis-tests.yml +++ b/.github/workflows/nsis-tests.yml @@ -47,6 +47,24 @@ jobs: run: .\pkg\windows\nsis\tests\test.cmd -CICD .\config_tests shell: cmd + - name: Collect NSIS Installer Logs + if: always() + shell: pwsh + run: | + $dest = "$env:GITHUB_WORKSPACE\nsis-install-logs" + New-Item -ItemType Directory -Force -Path $dest | Out-Null + if (Test-Path "$env:TEMP\SaltInstaller") { + Copy-Item "$env:TEMP\SaltInstaller\*" $dest -Recurse -Force + } + + - name: Upload NSIS Installer Logs + if: always() + uses: actions/upload-artifact@ea165f8d65b6e75b540449e92b4886f43607fa02 # v4 + with: + name: nsis-logic-test-logs + path: nsis-install-logs + if-no-files-found: ignore + Test-NSIS-Stress: name: Stress Tests runs-on: @@ -74,3 +92,21 @@ jobs: - name: Run Stress Test run: .\pkg\windows\nsis\tests\test.cmd -CICD .\stress_tests shell: cmd + + - name: Collect NSIS Installer Logs + if: always() + shell: pwsh + run: | + $dest = "$env:GITHUB_WORKSPACE\nsis-install-logs" + New-Item -ItemType Directory -Force -Path $dest | Out-Null + if (Test-Path "$env:TEMP\SaltInstaller") { + Copy-Item "$env:TEMP\SaltInstaller\*" $dest -Recurse -Force + } + + - name: Upload NSIS Installer Logs + if: always() + uses: actions/upload-artifact@ea165f8d65b6e75b540449e92b4886f43607fa02 # v4 + with: + name: nsis-stress-test-logs + path: nsis-install-logs + if-no-files-found: ignore diff --git a/pkg/windows/nsis/installer/Salt-Minion-Setup.nsi b/pkg/windows/nsis/installer/Salt-Minion-Setup.nsi index 67cf43e3904b..5f066bdbd35c 100644 --- a/pkg/windows/nsis/installer/Salt-Minion-Setup.nsi +++ b/pkg/windows/nsis/installer/Salt-Minion-Setup.nsi @@ -1090,9 +1090,34 @@ Section -Post # races that pending delete and fails, which used to Abort the install # (NSIS error level 2 -- the intermittent installer failure). # - # The condition is self-clearing within a second or two once the handles - # close, so retry a handful of times before giving up rather than aborting - # on the first failure. + # CI stress runs have measured this pending-delete window taking well + # over 10 seconds under load -- both the uninstaller's own + # wait_svc_deleted loop and the test harness's post-uninstall wait have + # been observed to exhaust their budgets while the service key was still + # present, which then burned through the retry loop below and Aborted. + # So, before even attempting CreateService, wait for the service registry + # key to disappear. This costs 0s on a normal install (the key was never + # present, so ReadRegDWORD errors immediately) and only spends time in + # the race case this is meant to cover. + ${LogMsg} "Checking for a pending salt-minion service deletion" + StrCpy $R0 0 + wait_svc_deleted_before_install: + ClearErrors + ReadRegDWORD $R1 HKLM "SYSTEM\CurrentControlSet\Services\salt-minion" "Type" + ${If} ${Errors} + ${LogMsg} "No pending service deletion detected" + ${ElseIf} $R0 < 30 + IntOp $R0 $R0 + 1 + Sleep 500 + Goto wait_svc_deleted_before_install + ${Else} + ${LogMsg} "Service key still present after 15s -- proceeding anyway" + ${EndIf} + + # The condition is also self-clearing within a couple of seconds once the + # SCM finishes closing out the old service's handles, so retry + # CreateService itself a number of times before giving up rather than + # aborting on the first failure. ${LogMsg} "Registering the salt-minion service" StrCpy $SvcInstallTries 0 retry_svc_install: @@ -1100,10 +1125,10 @@ Section -Post pop $0 # ExitCode pop $1 # StdOut ${If} $0 != 0 - ${AndIf} $SvcInstallTries < 5 + ${AndIf} $SvcInstallTries < 10 IntOp $SvcInstallTries $SvcInstallTries + 1 ${LogMsg} "Service registration failed (ExitCode: $0). \ - Retry $SvcInstallTries/5 in 2s (SCM delete may still be pending)" + Retry $SvcInstallTries/10 in 2s (SCM delete may still be pending)" ${LogMsg} "StdOut: $1" Sleep 2000 Goto retry_svc_install @@ -1362,12 +1387,12 @@ Function ${un}uninstallSalt ReadRegDWORD $R1 HKLM "SYSTEM\CurrentControlSet\Services\salt-minion" "Type" ${If} ${Errors} ${LogMsg} "Service key removed" - ${ElseIf} $R0 < 20 + ${ElseIf} $R0 < 30 IntOp $R0 $R0 + 1 Sleep 500 Goto wait_svc_deleted ${Else} - ${LogMsg} "Service key still present after 10s — continuing anyway" + ${LogMsg} "Service key still present after 15s — continuing anyway" ${EndIf} ${Else} diff --git a/pkg/windows/nsis/tests/conftest.py b/pkg/windows/nsis/tests/conftest.py index b404ec2402ae..c37488b72bfe 100644 --- a/pkg/windows/nsis/tests/conftest.py +++ b/pkg/windows/nsis/tests/conftest.py @@ -349,6 +349,41 @@ def install_salt(args): pass +SALT_INSTALLER_LOG_DIR = os.path.join(os.environ.get("TEMP", ""), "SaltInstaller") + + +def _print_latest_installer_log(tail_lines=100): + """ + Print the tail of the most recently modified NSIS install/uninstall log. + + ${LogMsg} in the NSIS script writes a timestamped log for every + install/uninstall run to %TEMP%\\SaltInstaller. Surfacing the tail here + means a failure (e.g. an Abort during service registration) shows the + NSIS-side detail -- including ssm.exe's exit code and stdout -- directly + in the pytest failure output, without needing to dig through CI + artifacts or reproduce locally. + """ + if not os.path.isdir(SALT_INSTALLER_LOG_DIR): + return + try: + logs = [ + os.path.join(SALT_INSTALLER_LOG_DIR, name) + for name in os.listdir(SALT_INSTALLER_LOG_DIR) + if name.endswith(".log") + ] + if not logs: + return + latest = max(logs, key=os.path.getmtime) + with open(latest, encoding="utf-8", errors="replace") as fp: + lines = fp.readlines() + print(f"\n----- tail of {latest} -----") + for line in lines[-tail_lines:]: + print(line.rstrip()) + print("----- end of log -----") + except OSError as exc: + print(f"\nWARNING: could not read installer log: {exc}") + + def is_file_locked(path): """ Try to see if a file is locked @@ -418,6 +453,7 @@ def run_command(cmd_args, timeout=60): print( f"\nWARNING: process exited with code {proc.returncode}: {cmd_args[:120]}" ) + _print_latest_installer_log() return False return True except subprocess.TimeoutExpired: @@ -426,5 +462,6 @@ def run_command(cmd_args, timeout=60): print( f"\nWARNING: process timed out after {timeout}s — force-killing: {cmd_args[:120]}" ) + _print_latest_installer_log() _kill_process_tree(proc) return False