add more wolfsshd windows debugging

JacobBarthelmeh · JacobBarthelmeh · commit 13c043f75694 · 2026-02-09T14:54:28.000-07:00
diff --git a/.github/workflows/windows-cert-store-test.yml b/.github/workflows/windows-cert-store-test.yml
@@ -1201,6 +1201,73 @@ jobs:
         Remove-Item $scriptPath -ErrorAction SilentlyContinue
         Remove-Item $outputFile -ErrorAction SilentlyContinue
 
+    - name: Dry-run wolfsshd as LocalSystem (cert store diagnostics)
+      if: matrix.server_key_source == 'store'
+      working-directory: ${{ github.workspace }}\wolfssh
+      shell: pwsh
+      run: |
+        # Run wolfsshd in non-daemon test mode AS LOCALSYSTEM via scheduled
+        # task.  This captures the exact error that the service would hit.
+        $sshdPath = (Get-Content env:SSHD_PATH -ErrorAction SilentlyContinue)
+        if (-not $sshdPath -or -not (Test-Path $sshdPath)) {
+            Write-Host "Skipping: wolfsshd.exe not found"
+            exit 0
+        }
+        $sshdPathFull = (Resolve-Path $sshdPath).Path
+        $configPathFull = (Resolve-Path "sshd_config_test").Path
+        $port = ${{env.TEST_PORT}}
+
+        # Output goes to a temp file that LocalSystem can write to
+        $outFile = "$env:TEMP\wolfsshd-localsystem-dryrun.txt"
+
+        # We wrap the call in cmd /c so stdout+stderr go to the file
+        $cmdLine = "`"$sshdPathFull`" -D -t -d -f `"$configPathFull`" -p $port"
+        Write-Host "Will run as SYSTEM: $cmdLine"
+
+        # Create scheduled task to run as SYSTEM
+        $taskName = "WolfSSH-DryRunLocalSystem"
+        $action = New-ScheduledTaskAction `
+            -Execute "cmd.exe" `
+            -Argument "/c $cmdLine > `"$outFile`" 2>&1"
+        $principal = New-ScheduledTaskPrincipal `
+            -UserId "NT AUTHORITY\SYSTEM" `
+            -LogonType ServiceAccount -RunLevel Highest
+        $settings = New-ScheduledTaskSettingsSet `
+            -AllowStartIfOnBatteries -DontStopIfGoingOnBatteries
+
+        Unregister-ScheduledTask -TaskName $taskName -Confirm:$false -ErrorAction SilentlyContinue
+        Register-ScheduledTask -TaskName $taskName -Action $action -Principal $principal -Settings $settings | Out-Null
+        Start-ScheduledTask -TaskName $taskName
+
+        # Wait for completion (wolfsshd -t exits quickly)
+        $timeout = 30
+        $elapsed = 0
+        while ($elapsed -lt $timeout) {
+          Start-Sleep -Seconds 1
+          $elapsed++
+          $task = Get-ScheduledTask -TaskName $taskName -ErrorAction SilentlyContinue
+          if ($task.State -eq "Ready") { break }
+        }
+
+        # Get exit code
+        $taskInfo = Get-ScheduledTaskInfo -TaskName $taskName -ErrorAction SilentlyContinue
+        if ($taskInfo) {
+          Write-Host "Scheduled task last result: $($taskInfo.LastTaskResult)"
+        }
+
+        # Show output
+        Write-Host "=== wolfsshd dry-run as LocalSystem ==="
+        if (Test-Path $outFile) {
+          Get-Content $outFile
+        } else {
+          Write-Host "(no output file generated)"
+        }
+        Write-Host "=== end LocalSystem dry-run ==="
+
+        # Cleanup
+        Unregister-ScheduledTask -TaskName $taskName -Confirm:$false -ErrorAction SilentlyContinue
+        Remove-Item $outFile -ErrorAction SilentlyContinue
+
     - name: Start echoserver with cert store (cert store matrix – more debug logs)
       if: matrix.server_key_source == 'store'
       working-directory: ${{ github.workspace }}\wolfssh
@@ -1393,6 +1460,43 @@ jobs:
         # Clear the env var so cleanup step doesn't try again
         Add-Content -Path $env:GITHUB_ENV -Value "ECHOSERVER_PID="
 
+    - name: Validate wolfsshd config (non-daemon dry run)
+      working-directory: ${{ github.workspace }}\wolfssh
+      shell: pwsh
+      run: |
+        # Run wolfsshd in non-daemon test mode (-D -t -d) to validate
+        # config loading and cert store access.  This gives us visible
+        # stdout/stderr output, unlike the service which logs to
+        # OutputDebugString.
+        $sshdPath = (Get-Content env:SSHD_PATH)
+        if (-not (Test-Path $sshdPath)) {
+            Write-Host "Skipping dry-run: wolfsshd.exe not found"
+            exit 0
+        }
+        $configPathFull = (Resolve-Path "sshd_config_test").Path
+        $port = ${{env.TEST_PORT}}
+
+        Write-Host "=== wolfsshd dry-run: $sshdPath -D -t -d -f $configPathFull -p $port ==="
+        $proc = Start-Process -FilePath $sshdPath `
+            -ArgumentList "-D", "-t", "-d", "-f", $configPathFull, "-p", $port `
+            -RedirectStandardOutput "wolfsshd_dryrun_out.txt" `
+            -RedirectStandardError  "wolfsshd_dryrun_err.txt" `
+            -Wait -NoNewWindow -PassThru
+
+        Write-Host "Exit code: $($proc.ExitCode)"
+        Write-Host "=== stdout ==="
+        if (Test-Path wolfsshd_dryrun_out.txt) { Get-Content wolfsshd_dryrun_out.txt }
+        Write-Host "=== stderr ==="
+        if (Test-Path wolfsshd_dryrun_err.txt) { Get-Content wolfsshd_dryrun_err.txt }
+        Write-Host "=== end dry-run ==="
+
+        if ($proc.ExitCode -ne 0) {
+            Write-Host "WARNING: wolfsshd dry-run failed (exit $($proc.ExitCode))"
+            Write-Host "The service will likely also fail to start."
+        } else {
+            Write-Host "wolfsshd dry-run succeeded - config is valid"
+        }
+
     - name: Start wolfSSHd as Windows service
       working-directory: ${{ github.workspace }}\wolfssh
       shell: pwsh
@@ -1501,6 +1605,10 @@ jobs:
         # Create the service with proper binpath
         # Note: sc.exe requires the binPath to have the executable path and arguments
         # The entire command line goes in binPath, with the exe path in quotes
+        # We do NOT include -E <log> here because LocalSystem only has RX on
+        # the wolfssh directory and cannot create a log file.  Debug output
+        # from the service goes to OutputDebugString; for visible diagnostics
+        # we rely on the "Validate wolfsshd config" dry-run step.
         $binPath = "`"$sshdPathFull`" -f `"$configPathFull`" -p ${{env.TEST_PORT}}"
         Write-Host "Creating service with binpath: $binPath"
         
diff --git a/apps/wolfsshd/configuration.c b/apps/wolfsshd/configuration.c
@@ -406,14 +406,17 @@ static const CONFIG_OPTION options[NUM_OPTIONS] = {
     {OPT_ACCEPT_ENV,              "AcceptEnv"},
     {OPT_PROTOCOL,                "Protocol"},
     {OPT_LOGIN_GRACE_TIME,        "LoginGraceTime"},
-    {OPT_HOST_KEY,                "HostKey"},
+    /* HostKeyStore* must come BEFORE HostKey because the config parser uses
+     * strncmp with the option-name length.  If HostKey (7 chars) appeared
+     * first, "HostKeyStore …" would match "HostKey" as a prefix. */
 #ifdef USE_WINDOWS_API
 #ifdef WOLFSSH_CERTS
     {OPT_HOST_KEY_STORE,          "HostKeyStore"},
     {OPT_HOST_KEY_STORE_SUBJECT,  "HostKeyStoreSubject"},
     {OPT_HOST_KEY_STORE_FLAGS,    "HostKeyStoreFlags"},
 #endif /* WOLFSSH_CERTS */
 #endif /* USE_WINDOWS_API */
+    {OPT_HOST_KEY,                "HostKey"},
     {OPT_PASSWORD_AUTH,           "PasswordAuthentication"},
     {OPT_PORT,                    "Port"},
     {OPT_PERMIT_ROOT,             "PermitRootLogin"},
@@ -1096,13 +1099,19 @@ static int HandleConfigOption(WOLFSSHD_CONFIG** conf, int opt,
     #ifdef USE_WINDOWS_API
     #ifdef WOLFSSH_CERTS
         case OPT_HOST_KEY_STORE:
+            wolfSSH_Log(WS_LOG_INFO,
+                "[SSHD] Parsed HostKeyStore = '%s'", value);
             ret = SetFileString(&(*conf)->hostKeyStore, value, (*conf)->heap);
             break;
         case OPT_HOST_KEY_STORE_SUBJECT:
+            wolfSSH_Log(WS_LOG_INFO,
+                "[SSHD] Parsed HostKeyStoreSubject = '%s'", value);
             ret = SetFileString(&(*conf)->hostKeyStoreSubject, value,
                 (*conf)->heap);
             break;
         case OPT_HOST_KEY_STORE_FLAGS:
+            wolfSSH_Log(WS_LOG_INFO,
+                "[SSHD] Parsed HostKeyStoreFlags = '%s'", value);
             ret = SetFileString(&(*conf)->hostKeyStoreFlags, value,
                 (*conf)->heap);
             break;
diff --git a/apps/wolfsshd/wolfsshd.c b/apps/wolfsshd/wolfsshd.c
@@ -359,7 +359,14 @@ static int SetupCTX(WOLFSSHD_CONFIG* conf, WOLFSSH_CTX** ctx,
         char* hostKeyStore = wolfSSHD_ConfigGetHostKeyStore(conf);
         char* hostKeyStoreSubject = wolfSSHD_ConfigGetHostKeyStoreSubject(conf);
         char* hostKeyStoreFlags = wolfSSHD_ConfigGetHostKeyStoreFlags(conf);
-        
+
+        wolfSSH_Log(WS_LOG_INFO,
+            "[SSHD] Cert store code compiled in. "
+            "hostKeyStore=%s, hostKeyStoreSubject=%s, hostKeyStoreFlags=%s",
+            hostKeyStore ? hostKeyStore : "(null)",
+            hostKeyStoreSubject ? hostKeyStoreSubject : "(null)",
+            hostKeyStoreFlags ? hostKeyStoreFlags : "(null)");
+
         if (hostKeyStore != NULL && hostKeyStoreSubject != NULL) {
             /* Use cert store host key */
             wchar_t* wStoreName = NULL;
@@ -401,11 +408,21 @@ static int SetupCTX(WOLFSSHD_CONFIG* conf, WOLFSSH_CTX** ctx,
                 WFREE(wSubjectName, heap, DYNTYPE_SSHD);
             }
         } else
+#else
+        wolfSSH_Log(WS_LOG_INFO,
+            "[SSHD] WOLFSSH_CERTS not defined - cert store support disabled");
 #endif /* WOLFSSH_CERTS */
+#else
+        wolfSSH_Log(WS_LOG_INFO,
+            "[SSHD] USE_WINDOWS_API not defined - cert store support disabled");
 #endif /* USE_WINDOWS_API */
         {
             char* hostKey = wolfSSHD_ConfigGetHostKeyFile(conf);
 
+            wolfSSH_Log(WS_LOG_INFO,
+                "[SSHD] File-based host key path entered. hostKey=%s",
+                hostKey ? hostKey : "(null)");
+
             if (hostKey == NULL) {
                 wolfSSH_Log(WS_LOG_ERROR, "[SSHD] No host private key set");
                 ret = WS_BAD_ARGUMENT;
@@ -2521,6 +2538,24 @@ static int StartSSHD(int argc, char** argv)
         }
     }
 
+    if (logFile == NULL) {
+        logFile = stderr;
+    }
+#ifdef _WIN32
+    /* The early -D detection (wide-string comparison of cmdArgs before
+     * conversion) may have set ServiceDebugCb even when -D was supplied.
+     * Now that mygetopt has been processed, restore the file-based
+     * callback in any case where output should go to logFile:
+     *   - isDaemon==0  → running interactively, logs to logFile (stderr)
+     *   - isDaemon==1 but -E was used → logs to the specified file
+     * This must happen BEFORE config/SetupCTX so their log messages are
+     * captured in the file (or stderr) rather than lost to
+     * OutputDebugString. */
+    if (!isDaemon || logFile != stderr) {
+        wolfSSH_SetLoggingCb(wolfSSHDLoggingCb);
+    }
+#endif
+
     if (ret == WS_SUCCESS) {
         ret = wolfSSHD_ConfigLoad(conf, configFile);
         if (ret != WS_SUCCESS) {
@@ -2552,10 +2587,6 @@ static int StartSSHD(int argc, char** argv)
         }
     }
 
-    if (logFile == NULL) {
-        logFile = stderr;
-    }
-
     /* run as a daemon or service */
 #ifndef WIN32
     if (ret == WS_SUCCESS && isDaemon) {
