Widen retry window for salt-minion service re-registration race

.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

pkg/windows/nsis/installer/Salt-Minion-Setup.nsi

@@ -1090,20 +1090,45 @@ 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:
     nsExec::ExecToStack `"$INSTDIR\ssm.exe" install salt-minion "$INSTDIR\salt-minion.exe" -c """$RootDir\conf""" -l quiet`
     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}

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