From f3bfaf54ec25eaec672da7daab463673617c5e22 Mon Sep 17 00:00:00 2001 From: shiftinv Date: Tue, 6 Sep 2022 03:56:57 +0200 Subject: [PATCH] feat: add github event ID to log messages --- lib/filter.ts | 10 +++++++--- lib/handler.ts | 7 ++++--- lib/util.ts | 29 +++++++++++++++++++++++++++++ lib/webhook.ts | 14 +++++++------- main.ts | 8 +++++--- 5 files changed, 52 insertions(+), 16 deletions(-) diff --git a/lib/filter.ts b/lib/filter.ts index d526dc3..1779cbc 100644 --- a/lib/filter.ts +++ b/lib/filter.ts @@ -1,9 +1,11 @@ -import { log, TTL } from "../deps.ts"; +import { TTL } from "../deps.ts"; import { UrlConfig } from "./types.d.ts"; +import { requestLog } from "./util.ts"; const reviewComments = new TTL(2 * 1000); export default function filter(headers: Headers, json: any, config: UrlConfig): string | null { + const reqLog = requestLog(headers); const event = headers.get("x-github-event") || "unknown"; const login: string | undefined = json.sender?.login?.toLowerCase(); @@ -44,8 +46,10 @@ export default function filter(headers: Headers, json: any, config: UrlConfig): const reviewId: number = json.comment?.pull_request_review_id; if (config.commentBurstLimit && reviewId) { const cacheKey = `${reviewId}-${login}`; - log.debug(`filter: checking cache key ${cacheKey}`); - log.debug(`filter: full comment cache ${JSON.stringify(Array.from(reviewComments))}`); + reqLog.debug(`filter: checking cache key ${cacheKey}`); + reqLog.debug( + `filter: full comment cache ${JSON.stringify(Array.from(reviewComments))}`, + ); const curr = reviewComments.get(cacheKey); if (curr && curr >= config.commentBurstLimit) { return `exceeded comment burst limit (${config.commentBurstLimit}) for review ${reviewId}`; diff --git a/lib/handler.ts b/lib/handler.ts index 92a1bde..102fbef 100644 --- a/lib/handler.ts +++ b/lib/handler.ts @@ -1,9 +1,9 @@ -import { http, log } from "../deps.ts"; +import { http } from "../deps.ts"; import config from "./config.ts"; import { hasKey, verify } from "./crypto.ts"; import filterWebhook from "./filter.ts"; import { UrlConfig } from "./types.d.ts"; -import { parseBool } from "./util.ts"; +import { parseBool, requestLog } from "./util.ts"; import { sendWebhook } from "./webhook.ts"; export default async function handle(req: Request): Promise { @@ -40,7 +40,8 @@ export default async function handle(req: Request): Promise { // do the thing const filterReason = filterWebhook(req.headers, json, urlConfig); if (filterReason !== null) { - log.debug(`handler: ignored due to '${filterReason}'`); + const reqLog = requestLog(req.headers); + reqLog.debug(`handler: ignored due to '${filterReason}'`); return new Response(`Ignored by webhook filter (reason: ${filterReason})`, { status: 203 }); } diff --git a/lib/util.ts b/lib/util.ts index d33510a..42b8e04 100644 --- a/lib/util.ts +++ b/lib/util.ts @@ -1,3 +1,5 @@ +import { log } from "../deps.ts"; + export function parseBool(s: string): boolean { return ["1", "true", "on", "y", "yes"].includes(s.toLowerCase()); } @@ -5,3 +7,30 @@ export function parseBool(s: string): boolean { export function sleep(ms: number): Promise { return new Promise((resolve) => setTimeout(resolve, ms)); } + +function getLogString(data: unknown): string { + return log.getLogger().asString(data); +} + +/** + * logging proxy that adds some metadata to log messages + */ +export function requestLog(headers: Headers) { + const deliveryId = headers.get("x-github-delivery"); + const prefix = deliveryId ? `[${deliveryId}] ` : ""; + + // ugh + // is there a better way to do this? certainly. + // does this work? also yes. + const proxyLog: (func: (s: any) => string) => (msg: any) => string = (func) => { + return (msg) => func(prefix + getLogString(msg)); + }; + + return { + debug: proxyLog(log.debug), + info: proxyLog(log.info), + warning: proxyLog(log.warning), + error: proxyLog(log.error), + critical: proxyLog(log.critical), + }; +} diff --git a/lib/webhook.ts b/lib/webhook.ts index 82dbe16..582127e 100644 --- a/lib/webhook.ts +++ b/lib/webhook.ts @@ -1,13 +1,13 @@ -import { log } from "../deps.ts"; import config from "./config.ts"; -import { sleep } from "./util.ts"; +import { requestLog, sleep } from "./util.ts"; export async function sendWebhook( id: string, token: string, - headers: HeadersInit, + headers: Headers, body: string, ): Promise { + const reqLog = requestLog(headers); const url = `https://discord.com/api/webhooks/${id}/${token}/github?wait=1`; let res: Response; @@ -19,7 +19,7 @@ export async function sendWebhook( body: body, }); - log.info(`sending webhook request to ${url}`); + reqLog.info(`sending webhook request to ${url}`); res = await fetch(req); // return response if everything's fine @@ -38,7 +38,7 @@ export async function sendWebhook( // if we'd wait longer than the configured limit, just return the 429 if (resetms > config.maxWebhookRetryMs) { - log.warning( + reqLog.warning( `ratelimited for ${resetms}ms (> ${config.maxWebhookRetryMs}ms), not retrying`, ); break; @@ -46,11 +46,11 @@ export async function sendWebhook( // maybe wait and retry if (retries >= config.maxWebhookRetries) { - log.warning(`reached maximum number of retries (${retries})`); + reqLog.warning(`reached maximum number of retries (${retries})`); break; } retries++; - log.warning(`retrying after ${resetms}ms (retry ${retries})`); + reqLog.warning(`retrying after ${resetms}ms (retry ${retries})`); await sleep(resetms); } while (true); diff --git a/main.ts b/main.ts index 2f116c2..ac60de8 100644 --- a/main.ts +++ b/main.ts @@ -1,6 +1,7 @@ import { http, log } from "./deps.ts"; import config from "./lib/config.ts"; import handler from "./lib/handler.ts"; +import { requestLog } from "./lib/util.ts"; async function setupLogs(): Promise { await log.setup({ @@ -19,22 +20,23 @@ async function setupLogs(): Promise { } async function handleRequest(req: Request, connInfo: http.ConnInfo): Promise { + const reqLog = requestLog(req.headers); let resp: Response; try { resp = await handler(req); } catch (err) { if (http.isHttpError(err) && err.expose) { - log.warning(`http error: ${err.message}`); + reqLog.warning(`http error: ${err.message}`); resp = new Response(err.message, { status: err.status }); } else { - log.critical(err); + reqLog.critical(err); resp = new Response("Internal Server Error", { status: 500 }); } } const respLen = resp.headers.get("content-length") || 0; const addr = connInfo.remoteAddr as Deno.NetAddr; - log.info( + reqLog.info( `http: ${addr.hostname}:${addr.port} - ${req.method} ${req.url} ${resp.status} ${respLen}`, );