fix: add parentheses to JSDoc type cast in copilot_driver.cjs for TypeScript compatibility (#25406)

* feat: increase logging in copilot driver for silent startup failures (#issue) (#25390)

* feat(logging): add debug logging to 5 CLI files for improved troubleshooting (#25393)

* fix: add parentheses to JSDoc type cast in copilot_driver.cjs for TypeScript compatibility

Agent-Logs-Url: https://github.com/github/gh-aw/sessions/34f7e8b3-df09-41bc-b786-8bb4b22ebb7e

Co-authored-by: lpcox <15877973+lpcox@users.noreply.github.com>

---------

Co-authored-by: Copilot <198982749+Copilot@users.noreply.github.com>
Co-authored-by: github-actions[bot] <41898282+github-actions[bot]@users.noreply.github.com>
Co-authored-by: lpcox <15877973+lpcox@users.noreply.github.com>

Author: 3 people

actions/setup/js/copilot_driver.cjs

@@ -25,6 +25,7 @@
 "use strict";
 
 const { spawn } = require("child_process");
+const fs = require("fs");
 
 // Maximum number of retry attempts after the initial run
 const MAX_RETRIES = 3;
@@ -67,6 +68,29 @@ function sleep(ms) {
   return new Promise(resolve => setTimeout(resolve, ms));
 }
 
+/**
+ * Check whether a command path is accessible and executable, logging the result.
+ * Returns true if the command is usable, false otherwise.
+ * @param {string} command - Absolute or relative path to the executable
+ * @returns {Promise<boolean>}
+ */
+async function checkCommandAccessible(command) {
+  try {
+    await fs.promises.access(command, fs.constants.F_OK);
+  } catch {
+    log(`pre-flight: command not found: ${command} (F_OK check failed — binary does not exist at this path)`);
+    return false;
+  }
+  try {
+    await fs.promises.access(command, fs.constants.X_OK);
+    log(`pre-flight: command is accessible and executable: ${command}`);
+    return true;
+  } catch {
+    log(`pre-flight: command exists but is not executable: ${command} (X_OK check failed — permission denied)`);
+    return false;
+  }
+}
+
 /**
  * Format elapsed milliseconds as a human-readable string (e.g. "3m 12s").
  * @param {number} ms
@@ -148,7 +172,11 @@ function runProcess(command, args, attempt) {
 
     child.on("error", err => {
       const durationMs = Date.now() - startTime;
-      log(`attempt ${attempt + 1}: failed to start process '${command}': ${err.message}`);
+      // prettier-ignore
+      const errno = /** @type {NodeJS.ErrnoException} */ (err);
+      const errCode = errno.code ?? "unknown";
+      const errSyscall = errno.syscall ?? "unknown";
+      log(`attempt ${attempt + 1}: failed to start process '${command}': ${err.message}` + ` (code=${errCode} syscall=${errSyscall})`);
       resolve({
         exitCode: 1,
         output: collectedOutput,
@@ -170,7 +198,9 @@ async function main() {
     process.exit(1);
   }
 
-  log(`starting: command=${command} maxRetries=${MAX_RETRIES} initialDelayMs=${INITIAL_DELAY_MS} backoffMultiplier=${BACKOFF_MULTIPLIER} maxDelayMs=${MAX_DELAY_MS}`);
+  log(`starting: command=${command} maxRetries=${MAX_RETRIES} initialDelayMs=${INITIAL_DELAY_MS}` + ` backoffMultiplier=${BACKOFF_MULTIPLIER} maxDelayMs=${MAX_DELAY_MS}` + ` nodeVersion=${process.version} platform=${process.platform}`);
+
+  await checkCommandAccessible(command);
 
   let delay = INITIAL_DELAY_MS;
   let lastExitCode = 1;
@@ -212,7 +242,7 @@ async function main() {
     if (attempt >= MAX_RETRIES) {
       log(`all ${MAX_RETRIES} retries exhausted — giving up (exitCode=${lastExitCode})`);
     } else {
-      log(`attempt ${attempt + 1}: no output produced — not retrying (process may have failed to start)`);
+      log(`attempt ${attempt + 1}: no output produced — not retrying` + ` (possible causes: binary not found, permission denied, auth failure, or silent startup crash)`);
     }
 
     // Non-retryable error or retries exhausted — propagate exit code

actions/setup/js/copilot_driver.test.cjs

@@ -153,4 +153,35 @@ describe("copilot_driver.cjs", () => {
       expect(logLine).toMatch(/^\[copilot-driver\] \d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}/);
     });
   });
+
+  describe("startup log includes node version and platform", () => {
+    it("starting log line contains nodeVersion and platform fields", () => {
+      const command = "/usr/local/bin/copilot";
+      const startingLine = `starting: command=${command} maxRetries=3 initialDelayMs=5000` + ` backoffMultiplier=2 maxDelayMs=60000` + ` nodeVersion=${process.version} platform=${process.platform}`;
+      expect(startingLine).toContain("nodeVersion=");
+      expect(startingLine).toContain("platform=");
+      expect(startingLine).toMatch(/nodeVersion=v\d+\.\d+/);
+    });
+  });
+
+  describe("no-output failure message", () => {
+    it("includes actionable possible causes", () => {
+      const msg = `attempt 1: no output produced — not retrying` + ` (possible causes: binary not found, permission denied, auth failure, or silent startup crash)`;
+      expect(msg).toContain("binary not found");
+      expect(msg).toContain("permission denied");
+      expect(msg).toContain("auth failure");
+      expect(msg).toContain("silent startup crash");
+    });
+  });
+
+  describe("error event message", () => {
+    it("includes code and syscall fields", () => {
+      const errMessage = "spawn /usr/local/bin/copilot ENOENT";
+      const errCode = "ENOENT";
+      const errSyscall = "spawn";
+      const logMsg = `attempt 1: failed to start process '/usr/local/bin/copilot': ${errMessage}` + ` (code=${errCode} syscall=${errSyscall})`;
+      expect(logMsg).toContain("code=ENOENT");
+      expect(logMsg).toContain("syscall=spawn");
+    });
+  });
 });

pkg/cli/audit.go

@@ -636,6 +636,7 @@ func auditJobRun(runID int64, jobID int64, stepNumber int, owner, repo, hostname
 
 // extractStepOutput extracts the output of a specific step from job logs
 func extractStepOutput(jobLog string, stepNumber int) (string, error) {
+	auditLog.Printf("Extracting output for step %d from job logs (%d bytes)", stepNumber, len(jobLog))
 	lines := strings.Split(jobLog, "\n")
 	var stepOutput []string
 	inStep := false
@@ -662,14 +663,17 @@ func extractStepOutput(jobLog string, stepNumber int) (string, error) {
 	}
 
 	if len(stepOutput) == 0 {
+		auditLog.Printf("Step %d not found in job logs (scanned %d lines)", stepNumber, len(lines))
 		return "", fmt.Errorf("step %d not found in job logs", stepNumber)
 	}
 
+	auditLog.Printf("Extracted %d lines for step %d", len(stepOutput), stepNumber)
 	return strings.Join(stepOutput, "\n"), nil
 }
 
 // findFirstFailingStep finds the first step that failed in the job logs
 func findFirstFailingStep(jobLog string) (int, string) {
+	auditLog.Printf("Searching for first failing step in job logs (%d bytes)", len(jobLog))
 	lines := strings.Split(jobLog, "\n")
 	var stepOutput []string
 	inStep := false
@@ -700,9 +704,11 @@ func findFirstFailingStep(jobLog string) (int, string) {
 	}
 
 	if foundFailure && len(stepOutput) > 0 {
+		auditLog.Printf("Found failing step %d with %d lines of output", currentStep, len(stepOutput))
 		return currentStep, strings.Join(stepOutput, "\n")
 	}
 
+	auditLog.Print("No failing step found in job logs")
 	return 0, ""
 }
 

pkg/cli/deps_security.go

@@ -134,6 +134,7 @@ func querySecurityAdvisories(depVersions map[string]string, verbose bool) ([]Sec
 	// GitHub Security Advisory API endpoint
 	url := "https://api.github.com/advisories?ecosystem=go&per_page=100"
 
+	depsSecurityLog.Printf("Querying GitHub Security Advisory API: url=%s, dep_count=%d", url, len(depVersions))
 	client := &http.Client{Timeout: 30 * time.Second}
 	req, err := http.NewRequest(http.MethodGet, url, nil)
 	if err != nil {
@@ -190,6 +191,7 @@ func querySecurityAdvisories(depVersions map[string]string, verbose bool) ([]Sec
 						adv.PatchedVers = []string{vuln.FirstPatchedVersion}
 					}
 
+					depsSecurityLog.Printf("Advisory matched dependency: package=%s, version=%s, severity=%s, id=%s", vuln.Package.Name, currentVersion, apiAdv.Severity, apiAdv.GHSAID)
 					matchingAdvisories = append(matchingAdvisories, adv)
 
 					if verbose {

pkg/cli/firewall_policy.go

@@ -271,6 +271,7 @@ func findMatchingRule(entry AuditLogEntry, rules []PolicyRule) *PolicyRule {
 	if isEntryAllowed(entry) {
 		expectedAction = "allow"
 	}
+	firewallPolicyLog.Printf("Finding matching rule for host=%s, expected_action=%s, rules=%d", entry.Host, expectedAction, len(rules))
 
 	for i := range rules {
 		rule := &rules[i]
@@ -283,6 +284,7 @@ func findMatchingRule(entry AuditLogEntry, rules []PolicyRule) *PolicyRule {
 		// aclName "all" is a catch-all rule (typically the default deny)
 		if rule.ACLName == "all" {
 			if rule.Action == expectedAction {
+				firewallPolicyLog.Printf("Matched catch-all rule (action=%s) for host=%s", rule.Action, entry.Host)
 				return rule
 			}
 			continue
@@ -291,10 +293,12 @@ func findMatchingRule(entry AuditLogEntry, rules []PolicyRule) *PolicyRule {
 		// Domain match
 		if domainMatchesRule(entry.Host, *rule) {
 			if rule.Action == expectedAction {
+				firewallPolicyLog.Printf("Matched rule %s (action=%s) for host=%s", rule.ACLName, rule.Action, entry.Host)
 				return rule
 			}
 		}
 	}
+	firewallPolicyLog.Printf("No matching rule found for host=%s", entry.Host)
 	return nil
 }
 

pkg/cli/mcp_safe_update_cache.go

@@ -59,6 +59,7 @@ func CollectLockFileManifests(workflowsDir string) map[string]*workflow.GHAWMani
 // WritePriorManifestFile serialises the manifest cache to a temporary JSON file and
 // returns its path.  The caller is responsible for removing the file when done.
 func WritePriorManifestFile(cache map[string]*workflow.GHAWManifest) (string, error) {
+	mcpLog.Printf("Writing prior manifest cache to temp file: %d entries", len(cache))
 	data, err := json.Marshal(cache)
 	if err != nil {
 		return "", fmt.Errorf("marshal manifest cache: %w", err)
@@ -75,5 +76,6 @@ func WritePriorManifestFile(cache map[string]*workflow.GHAWManifest) (string, er
 		return "", fmt.Errorf("write manifest cache file: %w", err)
 	}
 
+	mcpLog.Printf("Prior manifest cache written to: %s (%d bytes)", f.Name(), len(data))
 	return f.Name(), nil
 }

pkg/cli/workflows.go

@@ -242,8 +242,11 @@ func suggestWorkflowNames(target string) []string {
 	// Normalize target: strip .md extension and get basename if it's a path
 	normalizedTarget := strings.TrimSuffix(filepath.Base(target), ".md")
 
+	workflowsLog.Printf("Suggesting workflow names for %q (available: %d)", normalizedTarget, len(availableNames))
 	// Use the existing FindClosestMatches function from parser package
-	return parser.FindClosestMatches(normalizedTarget, availableNames, 3)
+	suggestions := parser.FindClosestMatches(normalizedTarget, availableNames, 3)
+	workflowsLog.Printf("Found %d suggestion(s) for %q: %v", len(suggestions), normalizedTarget, suggestions)
+	return suggestions
 }
 
 // isWorkflowFile returns true if the file should be treated as a workflow file.
@@ -266,6 +269,8 @@ func getMarkdownWorkflowFiles(workflowDir string) ([]string, error) {
 		workflowsDir = getWorkflowsDir()
 	}
 
+	workflowsLog.Printf("Scanning for markdown workflow files in: %s", workflowsDir)
+
 	if _, err := os.Stat(workflowsDir); os.IsNotExist(err) {
 		return nil, fmt.Errorf("no %s directory found", workflowsDir)
 	}
@@ -279,6 +284,7 @@ func getMarkdownWorkflowFiles(workflowDir string) ([]string, error) {
 	// Filter out README.md files
 	mdFiles = filterWorkflowFiles(mdFiles)
 
+	workflowsLog.Printf("Found %d markdown workflow file(s) in %s", len(mdFiles), workflowsDir)
 	return mdFiles, nil
 }