fix(scm-github): silence HTTP 304 warnings in ETag guards (#1581)

* fix(scm-github): silence HTTP 304 warnings in ETag guards and use observer logging

ETag guard functions and the GraphQL batch handler used raw console.warn()/
console.error() that fired on every poll cycle, including expected HTTP 304
(Not Modified) responses. This flooded the orchestrator terminal with noise.

- Add 304 fallback check in error message for cases where gh CLI doesn't
  populate stdout/stderr on non-zero exit
- Migrate all 4 raw console.warn()/console.error() calls to observer?.log()
  for consistency with the rest of the file
- Thread observer parameter through shouldRefreshPREnrichment and the three
  ETag guard functions (checkPRListETag, checkCommitStatusETag,
  checkReviewCommentsETag)
- Update test to verify observer-based logging instead of console spy

Closes #1580

* fix(scm-github): use word boundary in 304 regex to prevent false positives

Use \b304\b instead of /304/ to avoid matching substrings like "3040"
or "30400" in error messages.

Closes #1580

* fix(scm-github): use is304() for error message fallback and thread observer into getReviewThreads

1. Replace \b304\b regex with is304() (anchored to HTTP status line) in all
   three ETag guard fallback paths. Prevents false positives from URL paths
   like "pulls/304/comments" appearing in Node's execFile error messages.

2. Capture instance-level observer in createGitHubSCM() and pass it to
   checkReviewCommentsETag and getReviewThreads error logging. Non-304
   errors on the review polling path are now visible via observer instead
   of being silently swallowed by lifecycle's catch.

3. Restore "error" severity for partial batch failures in
   enrichSessionsPRBatchImpl (was incorrectly downgraded to "warn").

4. Add tests for Guard 1 URL false-positive, Guard 2 error logging,
   and Guard 2 HTTP 304 fallback paths.

Closes #1580

* test(scm-github): add Guard 3 (checkReviewCommentsETag) tests

Add 5 tests for the review comments ETag guard covering:
- 200 response (changed) and 304 response (unchanged)
- Error with observer logging
- HTTP 304 in error message treated as cache hit
- URL containing "304" NOT treated as cache hit (false-positive prevention)

This completes the test coverage for all three ETag guard functions'
error and 304-fallback paths, as requested in review.

Closes #1580
This commit is contained in:
Adil Shaikh 2026-05-03 18:30:27 +05:30 committed by GitHub
parent ab65d12356
commit cf5a418a48
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
3 changed files with 207 additions and 17 deletions

View File

@ -214,6 +214,7 @@ function updatePRMetadataCache(
export async function shouldRefreshPREnrichment(
prs: PRInfo[],
extraRepos: string[] = [],
observer?: BatchObserver,
): Promise<ETagGuardResult> {
const details: string[] = [];
let shouldRefresh = false;
@ -248,7 +249,7 @@ export async function shouldRefreshPREnrichment(
const prListUnchangedRepos = new Set<string>();
for (const [repoKey] of repos) {
const [owner, repo] = repoKey.split("/");
const prListChanged = await checkPRListETag(owner, repo);
const prListChanged = await checkPRListETag(owner, repo, observer);
if (prListChanged) {
guard1DetectedChanges = true;
shouldRefresh = true;
@ -292,6 +293,7 @@ export async function shouldRefreshPREnrichment(
pr.owner,
pr.repo,
cached.headSha,
observer,
);
if (statusChanged) {
shouldRefresh = true;
@ -414,6 +416,7 @@ function extractETag(output: string): string | undefined {
async function checkPRListETag(
owner: string,
repo: string,
observer?: BatchObserver,
): Promise<boolean> {
const repoKey = `${owner}/${repo}`;
const cachedETag = etagCache.prList.get(repoKey);
@ -456,8 +459,13 @@ async function checkPRListETag(
}
const errorMsg = err instanceof Error ? err.message : String(err);
// eslint-disable-next-line no-console -- Observability logging for ETag errors
console.warn(`[ETag Guard 1] PR list check failed for ${repoKey}: ${errorMsg}`);
// HTTP 304 may surface as an error message without stdout/stderr (e.g. gh cli versions
// that don't populate stdout on non-zero exit). Use is304() anchored to the HTTP status
// line to avoid false positives from URL paths like "pulls/304/comments".
if (is304(errorMsg)) {
return false;
}
observer?.log("warn", `[ETag Guard 1] PR list check failed for ${repoKey}: ${errorMsg}`);
return true; // Assume changed to be safe
}
}
@ -479,6 +487,7 @@ async function checkCommitStatusETag(
owner: string,
repo: string,
sha: string,
observer?: BatchObserver,
): Promise<boolean> {
const commitKey = `${owner}/${repo}#${sha}`;
const cachedETag = etagCache.commitStatus.get(commitKey);
@ -521,10 +530,10 @@ async function checkCommitStatusETag(
}
const errorMsg = err instanceof Error ? err.message : String(err);
// eslint-disable-next-line no-console -- Observability logging for ETag errors
console.warn(
`[ETag Guard 2] Commit status check failed for ${commitKey}: ${errorMsg}`,
);
if (is304(errorMsg)) {
return false;
}
observer?.log("warn", `[ETag Guard 2] Commit status check failed for ${commitKey}: ${errorMsg}`);
return true; // Assume changed to be safe
}
}
@ -548,6 +557,7 @@ export async function checkReviewCommentsETag(
owner: string,
repo: string,
prNumber: number,
observer?: BatchObserver,
): Promise<boolean> {
const cacheKey = `${owner}/${repo}#${prNumber}`;
const cachedETag = etagCache.reviewComments.get(cacheKey);
@ -583,8 +593,10 @@ export async function checkReviewCommentsETag(
}
const errorMsg = err instanceof Error ? err.message : String(err);
// eslint-disable-next-line no-console -- Observability logging for ETag errors
console.warn(`[ETag Guard 3] Review comments check failed for ${cacheKey}: ${errorMsg}`);
if (is304(errorMsg)) {
return false;
}
observer?.log("warn", `[ETag Guard 3] Review comments check failed for ${cacheKey}: ${errorMsg}`);
return true; // Assume changed to be safe
}
}
@ -1046,7 +1058,7 @@ export async function enrichSessionsPRBatch(
// Step 1: Check if we need to refresh using 2-Guard ETag Strategy
// Guard 1 runs for all repos (including those with no PRs yet) so the
// lifecycle manager knows whether detectPR can be skipped.
const guardResult = await shouldRefreshPREnrichment(prs, repos);
const guardResult = await shouldRefreshPREnrichment(prs, repos, observer);
// Report which repos had no PR list changes so the lifecycle can skip detectPR
observer?.reportPRListUnchangedRepos?.(guardResult.prListUnchangedRepos);
@ -1152,8 +1164,7 @@ export async function enrichSessionsPRBatch(
});
// Log error for observability but don't fail entirely
// eslint-disable-next-line no-console -- Observability logging for batch errors
console.error(`[GraphQL Batch Warning] Batch enrichment partially failed: ${errorMsg}`);
observer?.log("error", `[GraphQL Batch] Batch enrichment partially failed: ${errorMsg}`);
// Don't add placeholder entries to result or cache.
// This allows lifecycle-manager to fall back to individual API calls

View File

@ -486,6 +486,10 @@ function createGitHubSCM(): SCM {
// ETag-controlled cache for review threads + reviews. Freshness is managed by
// Guard 3 (checkReviewCommentsETag) — not a TTL timer.
const reviewThreadsCache = new Map<string, ReviewThreadsResult>();
// Instance-level observer captured from enrichSessionsPRBatch calls.
// Used by getReviewThreads (which can't accept observer via the SCM interface)
// to log non-304 errors that would otherwise be swallowed by lifecycle's catch.
let instanceObserver: BatchObserver | undefined;
function prCacheKey(owner: string, repo: string, prKey: string, method: PRCacheMethod): string {
return `${owner}/${repo}#${prKey}:${method}`;
@ -1006,7 +1010,7 @@ function createGitHubSCM(): SCM {
const cacheKey = `${pr.owner}/${pr.repo}#${pr.number}`;
// Guard 3: check if review comments changed via REST ETag
const reviewsChanged = await checkReviewCommentsETag(pr.owner, pr.repo, pr.number);
const reviewsChanged = await checkReviewCommentsETag(pr.owner, pr.repo, pr.number, instanceObserver);
if (!reviewsChanged) {
const cached = reviewThreadsCache.get(cacheKey);
if (cached) return cached;
@ -1133,6 +1137,8 @@ function createGitHubSCM(): SCM {
reviewThreadsCache.set(cacheKey, result);
return result;
} catch (err) {
const errorMsg = err instanceof Error ? err.message : String(err);
instanceObserver?.log("warn", `[getReviewThreads] Failed for ${cacheKey}: ${errorMsg}`);
throw new Error("Failed to fetch review threads", { cause: err });
}
},
@ -1241,6 +1247,7 @@ function createGitHubSCM(): SCM {
observer?: BatchObserver,
repos?: string[],
): Promise<Map<string, PREnrichmentData>> {
if (observer) instanceObserver = observer;
const batchResult = await enrichSessionsPRBatchImpl(prs, observer, repos);
return batchResult.enrichment;
},

View File

@ -26,6 +26,7 @@ import {
getPRMetadataCache,
clearPRMetadataCache,
shouldRefreshPREnrichment,
checkReviewCommentsETag,
setExecFileAsync,
} from "../src/graphql-batch.js";
@ -898,14 +899,69 @@ describe("shouldRefreshPREnrichment - ETag Guard Strategy", () => {
];
// Mock gh CLI error
const consoleWarnSpy = vi.spyOn(console, "warn").mockImplementation(() => {});
const mockObserver = {
recordSuccess: vi.fn(),
recordFailure: vi.fn(),
log: vi.fn(),
};
mockExecFileImpl.mockRejectedValueOnce(new Error("gh CLI failed"));
const result = await shouldRefreshPREnrichment(prs, [], mockObserver);
expect(result.shouldRefresh).toBe(true); // Fail-safe: assume changed on error
expect(mockObserver.log).toHaveBeenCalledWith("warn", expect.stringContaining("[ETag Guard 1]"));
});
it("should treat error message with HTTP 304 status line as cache hit", async () => {
const prs = [
{
owner: "owner",
repo: "repo",
number: 123,
url: "https://github.com/owner/repo/pull/123",
title: "Test PR",
branch: "feature",
baseBranch: "main",
isDraft: false,
},
];
// Error where stdout/stderr extraction fails but message contains HTTP 304 status
const err = new Error("HTTP/1.1 304 Not Modified");
mockExecFileImpl.mockRejectedValueOnce(err);
const result = await shouldRefreshPREnrichment(prs);
expect(result.shouldRefresh).toBe(true); // Fail-safe: assume changed on error
expect(consoleWarnSpy).toHaveBeenCalled();
consoleWarnSpy.mockRestore();
expect(result.shouldRefresh).toBe(false); // Treated as cache hit
});
it("should NOT treat error message with '304' in a URL path as cache hit", async () => {
const prs = [
{
owner: "owner",
repo: "repo",
number: 304,
url: "https://github.com/owner/repo/pull/304",
title: "Test PR",
branch: "feature",
baseBranch: "main",
isDraft: false,
},
];
const mockObserver = {
recordSuccess: vi.fn(),
recordFailure: vi.fn(),
log: vi.fn(),
};
// Error message contains "304" in URL path but not as HTTP status
const err = new Error("failed to fetch pulls/304/comments");
mockExecFileImpl.mockRejectedValueOnce(err);
const result = await shouldRefreshPREnrichment(prs, [], mockObserver);
expect(result.shouldRefresh).toBe(true); // Not a cache hit — real error
expect(mockObserver.log).toHaveBeenCalledWith("warn", expect.stringContaining("[ETag Guard 1]"));
});
});
@ -1043,6 +1099,65 @@ describe("shouldRefreshPREnrichment - ETag Guard Strategy", () => {
// Guard 1 called for PR list, Guard 2 skipped (no head SHA to check)
expect(mockExecFileImpl).toHaveBeenCalledTimes(1);
});
it("should refresh on Guard 2 error and log warning", async () => {
setPRMetadata("owner/repo#123", { headSha: "abc123", ciStatus: "pending" });
const prs = [
{
owner: "owner",
repo: "repo",
number: 123,
url: "https://github.com/owner/repo/pull/123",
title: "Test PR",
branch: "feature",
baseBranch: "main",
isDraft: false,
},
];
const mockObserver = {
recordSuccess: vi.fn(),
recordFailure: vi.fn(),
log: vi.fn(),
};
// Guard 1: 304 (no change), Guard 2: error
mockExecFileImpl
.mockResolvedValueOnce({ stdout: "HTTP/2 304", stderr: "" })
.mockRejectedValueOnce(new Error("gh CLI failed on commit status"));
const result = await shouldRefreshPREnrichment(prs, [], mockObserver);
expect(result.shouldRefresh).toBe(true);
expect(mockObserver.log).toHaveBeenCalledWith("warn", expect.stringContaining("[ETag Guard 2]"));
});
it("should treat Guard 2 error with HTTP 304 status line as cache hit", async () => {
setPRMetadata("owner/repo#123", { headSha: "abc123", ciStatus: "pending" });
const prs = [
{
owner: "owner",
repo: "repo",
number: 123,
url: "https://github.com/owner/repo/pull/123",
title: "Test PR",
branch: "feature",
baseBranch: "main",
isDraft: false,
},
];
// Guard 1: 304, Guard 2: error with HTTP 304 in message
mockExecFileImpl
.mockResolvedValueOnce({ stdout: "HTTP/2 304", stderr: "" })
.mockRejectedValueOnce(new Error("HTTP/1.1 304 Not Modified"));
const result = await shouldRefreshPREnrichment(prs);
expect(result.shouldRefresh).toBe(false);
});
});
describe("Multiple Repositories", () => {
@ -1170,6 +1285,63 @@ describe("shouldRefreshPREnrichment - ETag Guard Strategy", () => {
expect(callsWithHeader).toHaveLength(2); // Both Guard 1 and Guard 2
});
});
describe("Guard 3: Review Comments ETag", () => {
it("should return true (changed) on 200 response", async () => {
mockExecFileImpl.mockResolvedValueOnce({
stdout: 'HTTP/2 200\netag: "review-etag"',
stderr: "",
});
const result = await checkReviewCommentsETag("owner", "repo", 42);
expect(result).toBe(true);
});
it("should return false (unchanged) on 304 response", async () => {
mockExecFileImpl.mockResolvedValueOnce({
stdout: "HTTP/2 304",
stderr: "",
});
const result = await checkReviewCommentsETag("owner", "repo", 42);
expect(result).toBe(false);
});
it("should return true on error and log warning via observer", async () => {
const mockObserver = {
recordSuccess: vi.fn(),
recordFailure: vi.fn(),
log: vi.fn(),
};
mockExecFileImpl.mockRejectedValueOnce(new Error("gh CLI failed"));
const result = await checkReviewCommentsETag("owner", "repo", 42, mockObserver);
expect(result).toBe(true); // Fail-safe: assume changed
expect(mockObserver.log).toHaveBeenCalledWith("warn", expect.stringContaining("[ETag Guard 3]"));
});
it("should treat error with HTTP 304 status line as cache hit", async () => {
mockExecFileImpl.mockRejectedValueOnce(new Error("HTTP/1.1 304 Not Modified"));
const result = await checkReviewCommentsETag("owner", "repo", 42);
expect(result).toBe(false);
});
it("should NOT treat error with '304' in URL path as cache hit", async () => {
const mockObserver = {
recordSuccess: vi.fn(),
recordFailure: vi.fn(),
log: vi.fn(),
};
mockExecFileImpl.mockRejectedValueOnce(new Error("failed to fetch pulls/304/comments"));
const result = await checkReviewCommentsETag("owner", "repo", 304, mockObserver);
expect(result).toBe(true); // Not a cache hit
expect(mockObserver.log).toHaveBeenCalledWith("warn", expect.stringContaining("[ETag Guard 3]"));
});
});
});
describe("extractPREnrichment ciChecks", () => {