Add structured JSON logging across webhook and review flow.

Improve observability with correlation IDs, skip/success/failure lifecycle events, and retry diagnostics while documenting log level configuration.

Co-authored-by: Cursor <cursoragent@cursor.com>
This commit is contained in:
Daan Schouteden
2026-06-02 15:00:29 +02:00
parent 7233ab3f32
commit e9aafdf8c4
6 changed files with 125 additions and 26 deletions
+1
View File
@@ -9,3 +9,4 @@ DEFAULT_BASE_BRANCH=main
MAX_INLINE_COMMENTS=5 MAX_INLINE_COMMENTS=5
REVIEW_TIMEOUT_MS=120000 REVIEW_TIMEOUT_MS=120000
DEDUPE_TTL_SECONDS=1800 DEDUPE_TTL_SECONDS=1800
LOG_LEVEL=info
+2
View File
@@ -156,6 +156,7 @@ Optional:
- `MAX_INLINE_COMMENTS` (default: `5`) - `MAX_INLINE_COMMENTS` (default: `5`)
- `REVIEW_TIMEOUT_MS` (default: `120000`) - `REVIEW_TIMEOUT_MS` (default: `120000`)
- `DEDUPE_TTL_SECONDS` (default: `1800`) - `DEDUPE_TTL_SECONDS` (default: `1800`)
- `LOG_LEVEL` (default: `info`; options: `debug`, `info`, `warn`, `error`)
See `.env.example`. See `.env.example`.
@@ -201,3 +202,4 @@ Post-validation rules:
- Do not log tokens or raw auth headers. - Do not log tokens or raw auth headers.
- Dedupe is in-memory (resets on restart). - Dedupe is in-memory (resets on restart).
- Best deployment model is a central service with org-level webhook and per-repo opt-out config. - Best deployment model is a central service with org-level webhook and per-repo opt-out config.
- Logs are structured JSON to simplify filtering in Docker/log collectors.
+41
View File
@@ -0,0 +1,41 @@
type LogLevel = "debug" | "info" | "warn" | "error";
const levelOrder: Record<LogLevel, number> = {
debug: 10,
info: 20,
warn: 30,
error: 40
};
const currentLevel = resolveLevel(process.env.LOG_LEVEL);
export function log(level: LogLevel, message: string, context: Record<string, unknown> = {}): void {
if (levelOrder[level] < levelOrder[currentLevel]) {
return;
}
const payload = {
timestamp: new Date().toISOString(),
level,
message,
...context
};
const line = JSON.stringify(payload);
if (level === "error" || level === "warn") {
console.error(line);
return;
}
console.log(line);
}
function resolveLevel(level: string | undefined): LogLevel {
if (!level) {
return "info";
}
const normalized = level.toLowerCase();
if (normalized === "debug" || normalized === "info" || normalized === "warn" || normalized === "error") {
return normalized;
}
return "info";
}
+11
View File
@@ -1,8 +1,12 @@
import { log } from "../logging/logger.js";
export async function retry<T>(input: { export async function retry<T>(input: {
fn: () => Promise<T>; fn: () => Promise<T>;
retries: number; retries: number;
initialDelayMs: number; initialDelayMs: number;
shouldRetry?: (error: unknown) => boolean; shouldRetry?: (error: unknown) => boolean;
operationName?: string;
correlationId?: string;
}): Promise<T> { }): Promise<T> {
let attempt = 0; let attempt = 0;
let delay = input.initialDelayMs; let delay = input.initialDelayMs;
@@ -15,6 +19,13 @@ export async function retry<T>(input: {
if (!retryable || attempt > input.retries) { if (!retryable || attempt > input.retries) {
throw error; throw error;
} }
log("warn", "Retrying operation after error", {
operation: input.operationName ?? "unknown",
attempt,
retries: input.retries,
correlation_id: input.correlationId,
error: error instanceof Error ? error.message : String(error)
});
await sleep(delay); await sleep(delay);
delay *= 2; delay *= 2;
} }
+45 -17
View File
@@ -8,6 +8,7 @@ import { deletePriorBotReviews, postReview } from "../gitea/review-api.js";
import { removeBotFromReviewers } from "../gitea/reviewer-api.js"; import { removeBotFromReviewers } from "../gitea/reviewer-api.js";
import { buildReviewPrompt } from "../prompt/build-review-prompt.js"; import { buildReviewPrompt } from "../prompt/build-review-prompt.js";
import { RoutedEvent } from "../types/events.js"; import { RoutedEvent } from "../types/events.js";
import { log } from "../logging/logger.js";
import { retry } from "./retry.js"; import { retry } from "./retry.js";
export async function runReview(input: { export async function runReview(input: {
@@ -28,6 +29,13 @@ export async function runReview(input: {
headSha headSha
}); });
if (input.dedupe.has(dedupeKey)) { if (input.dedupe.has(dedupeKey)) {
log("info", "Review skipped: duplicate webhook", {
correlation_id: input.correlationId,
owner,
repo,
pr_number: prNumber,
head_sha: headSha
});
return "skipped"; return "skipped";
} }
input.dedupe.mark(dedupeKey); input.dedupe.mark(dedupeKey);
@@ -36,7 +44,9 @@ export async function runReview(input: {
const pull = await retry({ const pull = await retry({
fn: () => gitea.getPull(owner, repo, prNumber), fn: () => gitea.getPull(owner, repo, prNumber),
retries: 2, retries: 2,
initialDelayMs: 300 initialDelayMs: 300,
operationName: "getPull",
correlationId: input.correlationId
}); });
const { config: repoConfig, ruleFiles } = await retry({ const { config: repoConfig, ruleFiles } = await retry({
fn: () => fn: () =>
@@ -47,7 +57,9 @@ export async function runReview(input: {
ref: pull.head.ref ref: pull.head.ref
}), }),
retries: 2, retries: 2,
initialDelayMs: 300 initialDelayMs: 300,
operationName: "loadRepoConfig",
correlationId: input.correlationId
}); });
const should = shouldProcessEvent({ const should = shouldProcessEvent({
@@ -57,13 +69,23 @@ export async function runReview(input: {
botLogin: input.env.GITEA_BOT_LOGIN botLogin: input.env.GITEA_BOT_LOGIN
}); });
if (!should.process) { if (!should.process) {
log("info", "Review skipped by policy", {
correlation_id: input.correlationId,
owner,
repo,
pr_number: prNumber,
head_sha: headSha,
reason: should.reason ?? "unknown"
});
return "skipped"; return "skipped";
} }
const files = await retry({ const files = await retry({
fn: () => gitea.getPullFiles(owner, repo, prNumber), fn: () => gitea.getPullFiles(owner, repo, prNumber),
retries: 2, retries: 2,
initialDelayMs: 300 initialDelayMs: 300,
operationName: "getPullFiles",
correlationId: input.correlationId
}); });
const maxInlineComments = repoConfig.max_inline_comments ?? input.env.MAX_INLINE_COMMENTS; const maxInlineComments = repoConfig.max_inline_comments ?? input.env.MAX_INLINE_COMMENTS;
const prompt = buildReviewPrompt({ const prompt = buildReviewPrompt({
@@ -83,7 +105,9 @@ export async function runReview(input: {
model: repoConfig.model model: repoConfig.model
}), }),
retries: 2, retries: 2,
initialDelayMs: 500 initialDelayMs: 500,
operationName: "runCursorReview",
correlationId: input.correlationId
}); });
await retry({ await retry({
@@ -96,7 +120,9 @@ export async function runReview(input: {
botLogin: input.env.GITEA_BOT_LOGIN botLogin: input.env.GITEA_BOT_LOGIN
}), }),
retries: 2, retries: 2,
initialDelayMs: 300 initialDelayMs: 300,
operationName: "deletePriorBotReviews",
correlationId: input.correlationId
}); });
await retry({ await retry({
@@ -111,7 +137,9 @@ export async function runReview(input: {
maxInlineComments maxInlineComments
}), }),
retries: 2, retries: 2,
initialDelayMs: 300 initialDelayMs: 300,
operationName: "postReview",
correlationId: input.correlationId
}); });
await retry({ await retry({
@@ -124,18 +152,18 @@ export async function runReview(input: {
botLogin: input.env.GITEA_BOT_LOGIN botLogin: input.env.GITEA_BOT_LOGIN
}), }),
retries: 2, retries: 2,
initialDelayMs: 300 initialDelayMs: 300,
operationName: "removeBotFromReviewers",
correlationId: input.correlationId
}); });
console.log( log("info", "Review completed", {
JSON.stringify({ correlation_id: input.correlationId,
correlation_id: input.correlationId, owner,
owner, repo,
repo, pr_number: prNumber,
pr_number: prNumber, head_sha: headSha,
head_sha: headSha, outcome: "success"
outcome: "success" });
})
);
return "success"; return "success";
} }
+25 -9
View File
@@ -2,6 +2,7 @@ import crypto from "node:crypto";
import http from "node:http"; import http from "node:http";
import { loadEnv } from "./config/env.js"; import { loadEnv } from "./config/env.js";
import { DedupeStore } from "./domain/dedupe-store.js"; import { DedupeStore } from "./domain/dedupe-store.js";
import { log } from "./logging/logger.js";
import { runReview } from "./run/review-runner.js"; import { runReview } from "./run/review-runner.js";
import { PullRequestWebhookPayload } from "./types/events.js"; import { PullRequestWebhookPayload } from "./types/events.js";
import { routeEvent } from "./webhook/event-router.js"; import { routeEvent } from "./webhook/event-router.js";
@@ -24,9 +25,13 @@ const server = http.createServer(async (req, res) => {
} }
const body = await readBody(req); const body = await readBody(req);
const correlationId = crypto.randomUUID();
const signature = req.headers["x-gitea-signature"]; const signature = req.headers["x-gitea-signature"];
const signatureValue = Array.isArray(signature) ? signature[0] : signature; const signatureValue = Array.isArray(signature) ? signature[0] : signature;
if (!verifySignature({ secret: env.WEBHOOK_SECRET, body, signatureHeader: signatureValue })) { if (!verifySignature({ secret: env.WEBHOOK_SECRET, body, signatureHeader: signatureValue })) {
log("warn", "Webhook rejected: invalid signature", {
correlation_id: correlationId
});
res.writeHead(401); res.writeHead(401);
res.end("invalid signature"); res.end("invalid signature");
return; return;
@@ -35,6 +40,15 @@ const server = http.createServer(async (req, res) => {
const eventNameHeader = req.headers["x-gitea-event"]; const eventNameHeader = req.headers["x-gitea-event"];
const eventName = Array.isArray(eventNameHeader) ? eventNameHeader[0] : eventNameHeader; const eventName = Array.isArray(eventNameHeader) ? eventNameHeader[0] : eventNameHeader;
const payload = JSON.parse(body) as PullRequestWebhookPayload; const payload = JSON.parse(body) as PullRequestWebhookPayload;
log("info", "Webhook received", {
correlation_id: correlationId,
event: eventName ?? "unknown",
action: payload.action,
owner: payload.repository.owner.login,
repo: payload.repository.name,
pr_number: payload.pull_request.number,
head_sha: payload.pull_request.head.sha
});
const routed = routeEvent({ const routed = routeEvent({
eventName, eventName,
payload, payload,
@@ -42,12 +56,16 @@ const server = http.createServer(async (req, res) => {
}); });
if (!routed) { if (!routed) {
log("info", "Webhook ignored by router", {
correlation_id: correlationId,
event: eventName ?? "unknown",
action: payload.action
});
res.writeHead(202); res.writeHead(202);
res.end("ignored"); res.end("ignored");
return; return;
} }
const correlationId = crypto.randomUUID();
try { try {
const outcome = await runReview({ const outcome = await runReview({
env, env,
@@ -58,20 +76,18 @@ const server = http.createServer(async (req, res) => {
res.writeHead(200); res.writeHead(200);
res.end(outcome); res.end(outcome);
} catch (error) { } catch (error) {
console.error( log("error", "Webhook processing failed", {
JSON.stringify({ correlation_id: correlationId,
correlation_id: correlationId, outcome: "failed",
outcome: "failed", error: error instanceof Error ? error.message : String(error)
error: error instanceof Error ? error.message : String(error) });
})
);
res.writeHead(500); res.writeHead(500);
res.end("failed"); res.end("failed");
} }
}); });
server.listen(env.PORT, () => { server.listen(env.PORT, () => {
console.log(`gitea-pr-review-bot listening on :${env.PORT}`); log("info", "Service started", { port: env.PORT });
}); });
function readBody(req: http.IncomingMessage): Promise<string> { function readBody(req: http.IncomingMessage): Promise<string> {