From 918a86c3dca8f9dc6eb0bd1359f8999613392d8d Mon Sep 17 00:00:00 2001 From: Banjo Oladele Samuel Date: Wed, 27 May 2026 18:22:26 +0100 Subject: [PATCH] propagate requestId to the logger --- backend/package-lock.json | 20 --- backend/replace_logger.cjs | 42 ++++++ backend/src/__tests__/requestId.test.ts | 29 ++++ backend/src/__tests__/userProfile.test.ts | 7 +- backend/src/app.ts | 6 +- backend/src/config/swagger.ts | 3 +- .../src/controllers/eventStreamController.ts | 8 +- backend/src/controllers/indexerController.ts | 46 +++--- backend/src/controllers/loanController.ts | 64 ++++---- .../src/controllers/notificationController.ts | 2 +- backend/src/controllers/poolController.ts | 8 +- .../src/controllers/remittanceController.ts | 12 +- backend/src/controllers/userController.ts | 140 +++++++++--------- backend/src/middleware/metrics.ts | 8 +- backend/src/schemas/userSchemas.ts | 7 +- backend/src/services/cacheService.ts | 28 ++-- backend/src/services/defaultChecker.ts | 44 ++++-- backend/src/services/eventIndexer.ts | 52 ++++--- backend/src/services/eventStreamService.ts | 26 ++-- backend/src/services/indexerManager.ts | 16 +- backend/src/services/notificationService.ts | 94 +++++++----- backend/src/services/rateLimitService.ts | 14 +- backend/src/services/remittanceService.ts | 8 +- .../services/scoreReconciliationService.ts | 36 +++-- backend/src/services/scoresService.ts | 22 ++- backend/src/services/sorobanService.ts | 72 +++++---- backend/src/services/webhookRetryProcessor.ts | 10 +- backend/src/services/webhookRetryScheduler.ts | 20 ++- backend/src/services/webhookService.ts | 79 +++++----- backend/src/utils/logger.ts | 29 +++- 30 files changed, 581 insertions(+), 371 deletions(-) create mode 100644 backend/replace_logger.cjs diff --git a/backend/package-lock.json b/backend/package-lock.json index 75dc238e..5e82208a 100644 --- a/backend/package-lock.json +++ b/backend/package-lock.json @@ -134,7 +134,6 @@ "integrity": "sha512-CGOfOJqWjg2qW/Mb6zNsDm+u5vFQ8DxXfbM09z69p5Z6+mE1ikP2jUXw+j42Pf1XTYED2Rni5f95npYeuwMDQA==", "dev": true, "license": "MIT", - "peer": true, "dependencies": { "@babel/code-frame": "^7.29.0", "@babel/generator": "^7.29.0", @@ -2492,7 +2491,6 @@ "resolved": "https://registry.npmjs.org/@opentelemetry/api/-/api-1.9.0.tgz", "integrity": "sha512-3giAOQvZiH5F9bMlMiv8+GSPMeqg0dbaeo58/0SlA9sxSqZhnUtxzX9/2FzyhS9sWQf5S0GJE0AKBrFqjpeYcg==", "license": "Apache-2.0", - "peer": true, "engines": { "node": ">=8.0.0" } @@ -2514,7 +2512,6 @@ "resolved": "https://registry.npmjs.org/@opentelemetry/context-async-hooks/-/context-async-hooks-2.6.0.tgz", "integrity": "sha512-L8UyDwqpTcbkIK5cgwDRDYDoEhQoj8wp8BwsO19w3LB1Z41yEQm2VJyNfAi9DrLP/YTqXqWpKHyZfR9/tFYo1Q==", "license": "Apache-2.0", - "peer": true, "engines": { "node": "^18.19.0 || >=20.6.0" }, @@ -2527,7 +2524,6 @@ "resolved": "https://registry.npmjs.org/@opentelemetry/core/-/core-2.6.0.tgz", "integrity": "sha512-HLM1v2cbZ4TgYN6KEOj+Bbj8rAKriOdkF9Ed3tG25FoprSiQl7kYc+RRT6fUZGOvx0oMi5U67GoFdT+XUn8zEg==", "license": "Apache-2.0", - "peer": true, "dependencies": { "@opentelemetry/semantic-conventions": "^1.29.0" }, @@ -2947,7 +2943,6 @@ "resolved": "https://registry.npmjs.org/@opentelemetry/resources/-/resources-2.6.0.tgz", "integrity": "sha512-D4y/+OGe3JSuYUCBxtH5T9DSAWNcvCb/nQWIga8HNtXTVPQn59j0nTBAgaAXxUVBDl40mG3Tc76b46wPlZaiJQ==", "license": "Apache-2.0", - "peer": true, "dependencies": { "@opentelemetry/core": "2.6.0", "@opentelemetry/semantic-conventions": "^1.29.0" @@ -2964,7 +2959,6 @@ "resolved": "https://registry.npmjs.org/@opentelemetry/sdk-trace-base/-/sdk-trace-base-2.6.0.tgz", "integrity": "sha512-g/OZVkqlxllgFM7qMKqbPV9c1DUPhQ7d4n3pgZFcrnrNft9eJXZM2TNHTPYREJBrtNdRytYyvwjgL5geDKl3EQ==", "license": "Apache-2.0", - "peer": true, "dependencies": { "@opentelemetry/core": "2.6.0", "@opentelemetry/resources": "2.6.0", @@ -2982,7 +2976,6 @@ "resolved": "https://registry.npmjs.org/@opentelemetry/semantic-conventions/-/semantic-conventions-1.40.0.tgz", "integrity": "sha512-cifvXDhcqMwwTlTK04GBNeIe7yyo28Mfby85QXFe1Yk8nmi36Ab/5UQwptOx84SsoGNRg+EVSjwzfSZMy6pmlw==", "license": "Apache-2.0", - "peer": true, "engines": { "node": ">=14" } @@ -3095,7 +3088,6 @@ "resolved": "https://registry.npmjs.org/@redis/client/-/client-5.11.0.tgz", "integrity": "sha512-GHoprlNQD51Xq2Ztd94HHV94MdFZQ3CVrpA04Fz8MVoHM0B7SlbmPEVIjwTbcv58z8QyjnrOuikS0rWF03k5dQ==", "license": "MIT", - "peer": true, "dependencies": { "cluster-key-slot": "1.1.2" }, @@ -3653,7 +3645,6 @@ "resolved": "https://registry.npmjs.org/@types/node/-/node-25.2.0.tgz", "integrity": "sha512-DZ8VwRFUNzuqJ5khrvwMXHmvPe+zGayJhr2CDNiKB1WBE1ST8Djl00D0IC4vvNmHMdj6DlbYRIaFE7WHjlDl5w==", "license": "MIT", - "peer": true, "dependencies": { "undici-types": "~7.16.0" } @@ -3835,7 +3826,6 @@ "integrity": "sha512-IgSWvLobTDOjnaxAfDTIHaECbkNlAlKv2j5SjpB2v7QHKv1FIfjwMy8FsDbVfDX/KjmCmYICcw7uGaXLhtsLNg==", "dev": true, "license": "MIT", - "peer": true, "dependencies": { "@typescript-eslint/scope-manager": "8.56.0", "@typescript-eslint/types": "8.56.0", @@ -4085,7 +4075,6 @@ "resolved": "https://registry.npmjs.org/acorn/-/acorn-8.15.0.tgz", "integrity": "sha512-NZyJarBfL7nWwIq+FDL6Zp/yHEhePMNnnJ0y3qfieCrmNvYct8uvtiV41UvlSe6apAfk0fY1FbWx+NwfmpvtTg==", "license": "MIT", - "peer": true, "bin": { "acorn": "bin/acorn" }, @@ -4563,7 +4552,6 @@ } ], "license": "MIT", - "peer": true, "dependencies": { "baseline-browser-mapping": "^2.9.0", "caniuse-lite": "^1.0.30001759", @@ -5718,7 +5706,6 @@ "deprecated": "This version is no longer supported. Please see https://eslint.org/version-support for other options.", "dev": true, "license": "MIT", - "peer": true, "dependencies": { "@eslint-community/eslint-utils": "^4.2.0", "@eslint-community/regexpp": "^4.6.1", @@ -5775,7 +5762,6 @@ "integrity": "sha512-82GZUjRS0p/jganf6q1rEO25VSoHH0hKPCTrgillPjdI/3bgBhAE1QzHrHTizjpRvy6pGAvKjDJtk2pF9NDq8w==", "dev": true, "license": "MIT", - "peer": true, "bin": { "eslint-config-prettier": "bin/cli.js" }, @@ -6198,7 +6184,6 @@ "resolved": "https://registry.npmjs.org/express/-/express-5.2.1.tgz", "integrity": "sha512-hIS4idWWai69NezIdRt2xFVofaF4j+6INOpJlVOLDO8zXGpUVEVzIYk12UUi2JzjEzWL3IOAxcTubgz9Po0yXw==", "license": "MIT", - "peer": true, "dependencies": { "accepts": "^2.0.0", "body-parser": "^2.2.1", @@ -10751,7 +10736,6 @@ "resolved": "https://registry.npmjs.org/pg/-/pg-8.18.0.tgz", "integrity": "sha512-xqrUDL1b9MbkydY/s+VZ6v+xiMUmOUk7SS9d/1kpyQxoJ6U9AO1oIJyUWVZojbfe5Cc/oluutcgFG4L9RDP1iQ==", "license": "MIT", - "peer": true, "dependencies": { "pg-connection-string": "^2.11.0", "pg-pool": "^3.11.0", @@ -10943,7 +10927,6 @@ "integrity": "sha512-UOnG6LftzbdaHZcKoPFtOcCKztrQ57WkHDeRD9t/PTQtmT0NHSeWWepj6pS0z/N7+08BHFDQVUrfmfMRcZwbMg==", "dev": true, "license": "MIT", - "peer": true, "bin": { "prettier": "bin/prettier.cjs" }, @@ -12201,7 +12184,6 @@ "integrity": "sha512-5gTmgEY/sqK6gFXLIsQNH19lWb4ebPDLA4SdLP7dsWkIXHWlG66oPuVvXSGFPppYZz8ZDZq0dYYrbHfBCVUb1Q==", "dev": true, "license": "MIT", - "peer": true, "engines": { "node": ">=12" }, @@ -12360,7 +12342,6 @@ "integrity": "sha512-f0FFpIdcHgn8zcPSbf1dRevwt047YMnaiJM3u2w2RewrB+fob/zePZcrOyQoLMMO7aBIddLcQIEK5dYjkLnGrQ==", "dev": true, "license": "MIT", - "peer": true, "dependencies": { "@cspotcode/source-map-support": "^0.8.0", "@tsconfig/node10": "^1.0.7", @@ -12605,7 +12586,6 @@ "integrity": "sha512-jl1vZzPDinLr9eUt3J/t7V6FgNEw9QjvBPdysz9KfQDD41fQrC2Y4vKQdiaUpFT4bXlb1RHhLpp8wtm6M5TgSw==", "dev": true, "license": "Apache-2.0", - "peer": true, "bin": { "tsc": "bin/tsc", "tsserver": "bin/tsserver" diff --git a/backend/replace_logger.cjs b/backend/replace_logger.cjs new file mode 100644 index 00000000..3538cd35 --- /dev/null +++ b/backend/replace_logger.cjs @@ -0,0 +1,42 @@ +const fs = require("fs"); +const path = require("path"); + +const files = [ + "src/services/sorobanService.ts", + "src/controllers/loanController.ts", + "src/services/notificationService.ts", + "src/services/eventIndexer.ts", + "src/controllers/indexerController.ts", + "src/services/webhookService.ts", + "src/services/defaultChecker.ts", + "src/services/scoreReconciliationService.ts", + "src/services/eventStreamService.ts", + "src/services/cacheService.ts", + "src/services/webhookRetryScheduler.ts", + "src/services/indexerManager.ts", + "src/services/webhookRetryProcessor.ts", + "src/services/scoresService.ts", + "src/services/remittanceService.ts", + "src/services/rateLimitService.ts", + "src/controllers/remittanceController.ts", + "src/controllers/poolController.ts", + "src/controllers/eventStreamController.ts", + "src/controllers/notificationController.ts", +]; + +for (const file of files) { + const filePath = path.join(__dirname, file); + if (!fs.existsSync(filePath)) { + console.error(`File not found: ${filePath}`); + continue; + } + let content = fs.readFileSync(filePath, "utf8"); + // replace logger.info( -> logger.withContext().info( + // and so on for warn, error + content = content.replace( + /\blogger\.(info|warn|error)\s*\(/g, + "logger.withContext().$1(", + ); + fs.writeFileSync(filePath, content, "utf8"); + console.log(`Updated ${file}`); +} diff --git a/backend/src/__tests__/requestId.test.ts b/backend/src/__tests__/requestId.test.ts index 8382c38d..6e268740 100644 --- a/backend/src/__tests__/requestId.test.ts +++ b/backend/src/__tests__/requestId.test.ts @@ -1,5 +1,10 @@ import request from "supertest"; import app from "../app.js"; +import logger from "../utils/logger.js"; +import { jest } from "@jest/globals"; + +import express from "express"; +import { requestIdMiddleware } from "../middleware/requestId.js"; describe("Request ID middleware", () => { it("adds x-request-id when missing", async () => { @@ -20,4 +25,28 @@ describe("Request ID middleware", () => { expect(response.status).toBe(200); expect(response.headers["x-request-id"]).toBe(requestId); }); + + it("correlates logger requestId with x-request-id via withContext", async () => { + const tempApp = express(); + tempApp.use(requestIdMiddleware); + tempApp.get("/test", (req, res) => { + logger.withContext().info("Testing withContext correlation"); + res.sendStatus(200); + }); + + const infoSpy = jest + .spyOn(logger, "info") + .mockImplementation(() => logger as any); + + const response = await request(tempApp).get("/test"); + const requestId = response.headers["x-request-id"]; + + expect(response.status).toBe(200); + expect(infoSpy).toHaveBeenCalledWith( + "Testing withContext correlation", + expect.objectContaining({ requestId }), + ); + + infoSpy.mockRestore(); + }); }); diff --git a/backend/src/__tests__/userProfile.test.ts b/backend/src/__tests__/userProfile.test.ts index ae421ef1..eafffac5 100644 --- a/backend/src/__tests__/userProfile.test.ts +++ b/backend/src/__tests__/userProfile.test.ts @@ -87,9 +87,10 @@ describe("/user/profile", () => { displayName: "", phone: "", }); - expect(queryMock).toHaveBeenCalledWith(expect.stringContaining("INSERT INTO user_profiles"), [ - publicKey, - ]); + expect(queryMock).toHaveBeenCalledWith( + expect.stringContaining("INSERT INTO user_profiles"), + [publicKey], + ); }); it("updates allowed profile fields after validation", async () => { diff --git a/backend/src/app.ts b/backend/src/app.ts index 55d0812e..f1c42e58 100644 --- a/backend/src/app.ts +++ b/backend/src/app.ts @@ -25,13 +25,11 @@ import userRoutes from "./routes/userRoutes.js"; import notificationsRoutes from "./routes/notificationsRoutes.js"; import eventRoutes from "./routes/eventRoutes.js"; import remittanceRoutes from "./routes/remittanceRoutes.js"; +import transactionRoutes from "./routes/transactionRoutes.js"; import { requireApiKey } from "./middleware/auth.js"; import { globalRateLimiter } from "./middleware/rateLimiter.js"; import { errorHandler } from "./middleware/errorHandler.js"; -import { - metricsHandler, - metricsMiddleware, -} from "./middleware/metrics.js"; +import { metricsHandler, metricsMiddleware } from "./middleware/metrics.js"; import { requestLogger } from "./middleware/requestLogger.js"; import { requestIdMiddleware } from "./middleware/requestId.js"; import { asyncHandler } from "./utils/asyncHandler.js"; diff --git a/backend/src/config/swagger.ts b/backend/src/config/swagger.ts index 3ced0328..9784b146 100644 --- a/backend/src/config/swagger.ts +++ b/backend/src/config/swagger.ts @@ -20,7 +20,8 @@ export const swaggerSpec = swaggerJSDoc({ info: { title: "RemitLend API", version: "1.0.0", - description: "Backend API for RemitLend lending, scoring, remittance, and indexer flows.", + description: + "Backend API for RemitLend lending, scoring, remittance, and indexer flows.", }, servers: [ { diff --git a/backend/src/controllers/eventStreamController.ts b/backend/src/controllers/eventStreamController.ts index 00c0cbd5..5598ac4a 100644 --- a/backend/src/controllers/eventStreamController.ts +++ b/backend/src/controllers/eventStreamController.ts @@ -108,7 +108,9 @@ export const streamEvents = asyncHandler( ); } } catch (err) { - logger.error("SSE replay fetch error", { borrower, lastEventId, err }); + logger + .withContext() + .error("SSE replay fetch error", { borrower, lastEventId, err }); } unsubscribe = eventStreamService.subscribeAddress(userKey, borrower, res); @@ -135,7 +137,9 @@ export const streamEvents = asyncHandler( } } } catch (err) { - logger.error("SSE admin replay fetch error", { lastEventId, err }); + logger + .withContext() + .error("SSE admin replay fetch error", { lastEventId, err }); } const counts = eventStreamService.getConnectionCount(); diff --git a/backend/src/controllers/indexerController.ts b/backend/src/controllers/indexerController.ts index 8650a2d5..3ab8fe9e 100644 --- a/backend/src/controllers/indexerController.ts +++ b/backend/src/controllers/indexerController.ts @@ -171,7 +171,7 @@ const decodeQuarantinedRawEvent = ( : row.contract_id, }; } catch (error) { - logger.warn("Failed to decode quarantined raw event", { + logger.withContext().warn("Failed to decode quarantined raw event", { quarantineId: row.id, eventId: row.event_id, error, @@ -226,7 +226,7 @@ export const getIndexerStatus = async (req: Request, res: Response) => { }, }); } catch (error) { - logger.error("Failed to get indexer status", { error }); + logger.withContext().error("Failed to get indexer status", { error }); res.status(500).json({ success: false, message: "Failed to get indexer status", @@ -313,7 +313,7 @@ export const getBorrowerEvents = async (req: Request, res: Response) => { await cacheService.set(cacheKey, response, 300); res.json(response); } catch (error) { - logger.error("Failed to get borrower events", { error }); + logger.withContext().error("Failed to get borrower events", { error }); res.status(500).json({ success: false, message: "Failed to get borrower events", @@ -390,7 +390,7 @@ export const getLoanEvents = async (req: Request, res: Response) => { await cacheService.set(cacheKey, response, 300); res.json(response); } catch (error) { - logger.error("Failed to get loan events", { error }); + logger.withContext().error("Failed to get loan events", { error }); res.status(500).json({ success: false, message: "Failed to get loan events", @@ -456,7 +456,7 @@ export const getRecentEvents = async (req: Request, res: Response) => { await cacheService.set(cacheKey, response, 120); res.json(response); } catch (error) { - logger.error("Failed to get recent events", { error }); + logger.withContext().error("Failed to get recent events", { error }); res.status(500).json({ success: false, message: "Failed to get recent events", @@ -478,7 +478,9 @@ export const listWebhookSubscriptions = async ( }, }); } catch (error) { - logger.error("Failed to list webhook subscriptions", { error }); + logger + .withContext() + .error("Failed to list webhook subscriptions", { error }); res.status(500).json({ success: false, message: "Failed to list webhook subscriptions", @@ -554,7 +556,9 @@ export const createWebhookSubscription = async ( }, }); } catch (error) { - logger.error("Failed to create webhook subscription", { error }); + logger + .withContext() + .error("Failed to create webhook subscription", { error }); res.status(500).json({ success: false, message: "Failed to create webhook subscription", @@ -589,7 +593,9 @@ export const deleteWebhookSubscription = async ( message: "Webhook subscription deleted", }); } catch (error) { - logger.error("Failed to delete webhook subscription", { error }); + logger + .withContext() + .error("Failed to delete webhook subscription", { error }); res.status(500).json({ success: false, message: "Failed to delete webhook subscription", @@ -622,7 +628,7 @@ export const getWebhookDeliveries = async (req: Request, res: Response) => { }, }); } catch (error) { - logger.error("Failed to fetch webhook deliveries", { error }); + logger.withContext().error("Failed to fetch webhook deliveries", { error }); res.status(500).json({ success: false, message: "Failed to fetch webhook deliveries", @@ -662,7 +668,9 @@ export const reindexLedgerRange = async (req: Request, res: Response) => { try { indexer = buildIndexerFromConfig(); } catch (error) { - logger.error("Failed to initialize indexer for reindex", { error }); + logger + .withContext() + .error("Failed to initialize indexer for reindex", { error }); return res.status(500).json({ success: false, message: "Indexer is not configured", @@ -676,7 +684,7 @@ export const reindexLedgerRange = async (req: Request, res: Response) => { data: result, }); } catch (error) { - logger.error("Failed to reindex ledger range", { error }); + logger.withContext().error("Failed to reindex ledger range", { error }); res.status(500).json({ success: false, message: "Failed to reindex ledger range", @@ -726,7 +734,7 @@ export const listQuarantinedEvents = async (req: Request, res: Response) => { res.json(response); } catch (error) { - logger.error("Failed to list quarantined events", { error }); + logger.withContext().error("Failed to list quarantined events", { error }); res.status(500).json({ success: false, message: "Failed to list quarantined events", @@ -783,9 +791,11 @@ export const reprocessQuarantinedEvents = async ( try { indexer = buildIndexerFromConfig(); } catch (error) { - logger.error("Failed to initialize indexer for quarantine reprocess", { - error, - }); + logger + .withContext() + .error("Failed to initialize indexer for quarantine reprocess", { + error, + }); return res.status(500).json({ success: false, message: "Indexer is not configured", @@ -808,7 +818,7 @@ export const reprocessQuarantinedEvents = async ( deleted += 1; } catch (error) { failed += 1; - logger.warn("Failed to reprocess quarantined event", { + logger.withContext().warn("Failed to reprocess quarantined event", { quarantineId: row.id, eventId: row.event_id, error, @@ -831,7 +841,9 @@ export const reprocessQuarantinedEvents = async ( }, }); } catch (error) { - logger.error("Failed to reprocess quarantined events", { error }); + logger + .withContext() + .error("Failed to reprocess quarantined events", { error }); res.status(500).json({ success: false, message: "Failed to reprocess quarantined events", diff --git a/backend/src/controllers/loanController.ts b/backend/src/controllers/loanController.ts index 749279c7..53556642 100644 --- a/backend/src/controllers/loanController.ts +++ b/backend/src/controllers/loanController.ts @@ -122,7 +122,9 @@ export const contestDefault = asyncHandler( [loanId, borrower], ); - logger.info("Loan default contested", { loanId, borrower, reason }); + logger + .withContext() + .info("Loan default contested", { loanId, borrower, reason }); // Notify admins via email, SSE, and optional webhook await notificationService.notifyAdmins({ @@ -462,10 +464,12 @@ export const getLoanDetails = asyncHandler( (event: any) => event.event_type === "LoanApproved", ); if (approvalEvents.length > 1) { - logger.warn("Duplicate LoanApproved events detected for loan", { - loanId, - duplicateCount: approvalEvents.length, - }); + logger + .withContext() + .warn("Duplicate LoanApproved events detected for loan", { + loanId, + duplicateCount: approvalEvents.length, + }); } const approvalEvent = approvalEvents.length > 0 @@ -665,7 +669,7 @@ export const requestLoan = asyncHandler(async (req: Request, res: Response) => { }>(cacheKey); if (cachedTx) { - logger.info("Returning cached unsigned loan request tx", { + logger.withContext().info("Returning cached unsigned loan request tx", { borrower: borrowerPublicKey, amount, }); @@ -685,7 +689,7 @@ export const requestLoan = asyncHandler(async (req: Request, res: Response) => { // Cache for 60 seconds to prevent sequence number collisions from rapid requests await cacheService.set(cacheKey, result, 60); - logger.info("Loan request transaction built", { + logger.withContext().info("Loan request transaction built", { borrower: borrowerPublicKey, amount, }); @@ -732,7 +736,7 @@ export const repayLoan = asyncHandler(async (req: Request, res: Response) => { }>(cacheKey); if (cachedTx) { - logger.info("Returning cached unsigned repay tx", { + logger.withContext().info("Returning cached unsigned repay tx", { borrower: borrowerPublicKey, loanId: loanIdNum, amount, @@ -755,7 +759,7 @@ export const repayLoan = asyncHandler(async (req: Request, res: Response) => { // Cache for 60 seconds await cacheService.set(cacheKey, result, 60); - logger.info("Repay transaction built", { + logger.withContext().info("Repay transaction built", { borrower: borrowerPublicKey, loanId: loanIdNum, amount, @@ -804,11 +808,13 @@ export const depositCollateral = asyncHandler( }>(cacheKey); if (cachedTx) { - logger.info("Returning cached unsigned deposit_collateral tx", { - borrower: borrowerPublicKey, - loanId: loanIdNum, - amount, - }); + logger + .withContext() + .info("Returning cached unsigned deposit_collateral tx", { + borrower: borrowerPublicKey, + loanId: loanIdNum, + amount, + }); res.json({ success: true, loanId: loanIdNum, @@ -826,7 +832,7 @@ export const depositCollateral = asyncHandler( await cacheService.set(cacheKey, result, 60); - logger.info("Deposit collateral transaction built", { + logger.withContext().info("Deposit collateral transaction built", { borrower: borrowerPublicKey, loanId: loanIdNum, amount, @@ -874,10 +880,12 @@ export const releaseCollateral = asyncHandler( }>(cacheKey); if (cachedTx) { - logger.info("Returning cached unsigned release_collateral tx", { - borrower: borrowerPublicKey, - loanId: loanIdNum, - }); + logger + .withContext() + .info("Returning cached unsigned release_collateral tx", { + borrower: borrowerPublicKey, + loanId: loanIdNum, + }); res.json({ success: true, loanId: loanIdNum, @@ -894,7 +902,7 @@ export const releaseCollateral = asyncHandler( await cacheService.set(cacheKey, result, 60); - logger.info("Release collateral transaction built", { + logger.withContext().info("Release collateral transaction built", { borrower: borrowerPublicKey, loanId: loanIdNum, }); @@ -943,7 +951,7 @@ export const refinanceLoan = asyncHandler( }>(cacheKey); if (cachedTx) { - logger.info("Returning cached unsigned refinance tx", { + logger.withContext().info("Returning cached unsigned refinance tx", { borrower: borrowerPublicKey, loanId: loanIdNum, newAmount, @@ -967,7 +975,7 @@ export const refinanceLoan = asyncHandler( await cacheService.set(cacheKey, result, 60); - logger.info("Refinance loan transaction built", { + logger.withContext().info("Refinance loan transaction built", { borrower: borrowerPublicKey, loanId: loanIdNum, newAmount, @@ -1016,7 +1024,7 @@ export const extendLoan = asyncHandler(async (req: Request, res: Response) => { }>(cacheKey); if (cachedTx) { - logger.info("Returning cached unsigned extend tx", { + logger.withContext().info("Returning cached unsigned extend tx", { borrower: borrowerPublicKey, loanId: loanIdNum, extraLedgers, @@ -1038,7 +1046,7 @@ export const extendLoan = asyncHandler(async (req: Request, res: Response) => { await cacheService.set(cacheKey, result, 60); - logger.info("Extend loan transaction built", { + logger.withContext().info("Extend loan transaction built", { borrower: borrowerPublicKey, loanId: loanIdNum, extraLedgers, @@ -1085,7 +1093,7 @@ export const buildLiquidateLoan = asyncHandler( }>(cacheKey); if (cachedTx) { - logger.info("Returning cached unsigned liquidate tx", { + logger.withContext().info("Returning cached unsigned liquidate tx", { liquidator: liquidatorPublicKey, loanId: loanIdNum, }); @@ -1105,7 +1113,7 @@ export const buildLiquidateLoan = asyncHandler( await cacheService.set(cacheKey, result, 60); - logger.info("Liquidate loan transaction built", { + logger.withContext().info("Liquidate loan transaction built", { liquidator: liquidatorPublicKey, loanId: loanIdNum, }); @@ -1157,7 +1165,7 @@ export const submitTransaction = asyncHandler( ], ); - logger.info("Transaction submission recorded", { + logger.withContext().info("Transaction submission recorded", { txHash: stellarResult.txHash, status: stellarResult.status, submittedBy: req.user?.publicKey, @@ -1167,7 +1175,7 @@ export const submitTransaction = asyncHandler( }, ); - logger.info("Transaction submitted successfully", { + logger.withContext().info("Transaction submitted successfully", { txHash: result.stellarResult.txHash, status: result.stellarResult.status, }); diff --git a/backend/src/controllers/notificationController.ts b/backend/src/controllers/notificationController.ts index cd0ef060..b75efdc8 100644 --- a/backend/src/controllers/notificationController.ts +++ b/backend/src/controllers/notificationController.ts @@ -144,7 +144,7 @@ export const streamNotifications = asyncHandler( ); } } catch (err) { - logger.error("SSE init fetch error", { userId, err }); + logger.withContext().error("SSE init fetch error", { userId, err }); } const unsubscribe = notificationService.subscribe(userId, res); diff --git a/backend/src/controllers/poolController.ts b/backend/src/controllers/poolController.ts index 2a308f22..ca3d40e9 100644 --- a/backend/src/controllers/poolController.ts +++ b/backend/src/controllers/poolController.ts @@ -162,7 +162,7 @@ export const depositToPool = asyncHandler( amount, ); - logger.info("Deposit transaction built", { + logger.withContext().info("Deposit transaction built", { depositor: depositorPublicKey, token, amount, @@ -207,7 +207,7 @@ export const withdrawFromPool = asyncHandler( amount, ); - logger.info("Withdraw transaction built", { + logger.withContext().info("Withdraw transaction built", { depositor: depositorPublicKey, token, shares: amount, @@ -256,7 +256,7 @@ export const submitPoolTransaction = asyncHandler( ], ); - logger.info("Pool transaction submission recorded", { + logger.withContext().info("Pool transaction submission recorded", { txHash: stellarResult.txHash, status: stellarResult.status, submittedBy: req.user?.publicKey, @@ -267,7 +267,7 @@ export const submitPoolTransaction = asyncHandler( }, ); - logger.info("Pool transaction submitted successfully", { + logger.withContext().info("Pool transaction submitted successfully", { txHash: result.stellarResult.txHash, status: result.stellarResult.status, }); diff --git a/backend/src/controllers/remittanceController.ts b/backend/src/controllers/remittanceController.ts index 02cb8a6a..d04f4ac0 100644 --- a/backend/src/controllers/remittanceController.ts +++ b/backend/src/controllers/remittanceController.ts @@ -25,7 +25,7 @@ export const createRemittance = asyncHandler( throw AppError.unauthorized("Wallet address not found in request"); } - logger.info("Creating remittance", { + logger.withContext().info("Creating remittance", { sender: senderAddress, recipient: recipientAddress, amount, @@ -141,7 +141,9 @@ export const submitRemittanceTransaction = asyncHandler( throw AppError.badRequest("Remittance ID is required"); } - logger.info("Submitting remittance transaction", { remittanceId: id }); + logger + .withContext() + .info("Submitting remittance transaction", { remittanceId: id }); try { const remittance = await remittanceService.getRemittance(id); @@ -167,7 +169,7 @@ export const submitRemittanceTransaction = asyncHandler( stellarResult.txHash, ); - logger.info("Remittance transaction confirmed", { + logger.withContext().info("Remittance transaction confirmed", { remittanceId: id, txHash: stellarResult.txHash, status: stellarResult.status, @@ -191,7 +193,9 @@ export const submitRemittanceTransaction = asyncHandler( }, }); } catch (error) { - logger.error("Error submitting remittance transaction:", error); + logger + .withContext() + .error("Error submitting remittance transaction:", error); if (id) { await remittanceService.updateRemittanceStatus( diff --git a/backend/src/controllers/userController.ts b/backend/src/controllers/userController.ts index 16cc29e5..9a742072 100644 --- a/backend/src/controllers/userController.ts +++ b/backend/src/controllers/userController.ts @@ -22,7 +22,9 @@ function metadataFrom(row: UserProfileRow): Record { } function toIsoString(value: Date | string): string { - return value instanceof Date ? value.toISOString() : new Date(value).toISOString(); + return value instanceof Date + ? value.toISOString() + : new Date(value).toISOString(); } function serializeProfile(row: UserProfileRow) { @@ -32,7 +34,9 @@ function serializeProfile(row: UserProfileRow) { id: String(row.id), email: row.email ?? "", walletAddress: row.public_key, - kycVerified: Boolean(metadata.kycVerified ?? metadata.kyc_verified ?? false), + kycVerified: Boolean( + metadata.kycVerified ?? metadata.kyc_verified ?? false, + ), displayName: row.display_name ?? "", phone: row.phone ?? "", locale: typeof metadata.locale === "string" ? metadata.locale : undefined, @@ -72,84 +76,88 @@ async function getOrCreateProfile(publicKey: string): Promise { return profile; } -export const getUserProfile = asyncHandler(async (req: Request, res: Response) => { - const publicKey = req.user?.publicKey; - if (!publicKey) { - throw AppError.unauthorized("Authentication required"); - } - - const profile = await getOrCreateProfile(publicKey); - res.json(serializeProfile(profile)); -}); - -export const updateUserProfile = asyncHandler(async (req: Request, res: Response) => { - const publicKey = req.user?.publicKey; - if (!publicKey) { - throw AppError.unauthorized("Authentication required"); - } - - const input = req.body as UpdateUserProfileInput; - const current = await getOrCreateProfile(publicKey); - const updates: string[] = []; - const values: unknown[] = []; - let paramIndex = 1; +export const getUserProfile = asyncHandler( + async (req: Request, res: Response) => { + const publicKey = req.user?.publicKey; + if (!publicKey) { + throw AppError.unauthorized("Authentication required"); + } - if (input.displayName !== undefined) { - updates.push(`display_name = $${paramIndex++}`); - values.push(input.displayName); - } + const profile = await getOrCreateProfile(publicKey); + res.json(serializeProfile(profile)); + }, +); - if (input.email !== undefined) { - updates.push(`email = $${paramIndex++}`); - values.push(input.email); - } +export const updateUserProfile = asyncHandler( + async (req: Request, res: Response) => { + const publicKey = req.user?.publicKey; + if (!publicKey) { + throw AppError.unauthorized("Authentication required"); + } - if (input.phone !== undefined) { - updates.push(`phone = $${paramIndex++}`); - values.push(input.phone); - } + const input = req.body as UpdateUserProfileInput; + const current = await getOrCreateProfile(publicKey); + const updates: string[] = []; + const values: unknown[] = []; + let paramIndex = 1; - if (input.locale !== undefined || input.avatarUrl !== undefined) { - const metadata = { ...metadataFrom(current) }; + if (input.displayName !== undefined) { + updates.push(`display_name = $${paramIndex++}`); + values.push(input.displayName); + } - if (input.locale === null) { - delete metadata.locale; - } else if (input.locale !== undefined) { - metadata.locale = input.locale; + if (input.email !== undefined) { + updates.push(`email = $${paramIndex++}`); + values.push(input.email); } - if (input.avatarUrl === null) { - delete metadata.avatarUrl; - delete metadata.avatar_url; - } else if (input.avatarUrl !== undefined) { - metadata.avatarUrl = input.avatarUrl; - delete metadata.avatar_url; + if (input.phone !== undefined) { + updates.push(`phone = $${paramIndex++}`); + values.push(input.phone); } - updates.push(`metadata = $${paramIndex++}::jsonb`); - values.push(JSON.stringify(metadata)); - } + if (input.locale !== undefined || input.avatarUrl !== undefined) { + const metadata = { ...metadataFrom(current) }; + + if (input.locale === null) { + delete metadata.locale; + } else if (input.locale !== undefined) { + metadata.locale = input.locale; + } + + if (input.avatarUrl === null) { + delete metadata.avatarUrl; + delete metadata.avatar_url; + } else if (input.avatarUrl !== undefined) { + metadata.avatarUrl = input.avatarUrl; + delete metadata.avatar_url; + } + + updates.push(`metadata = $${paramIndex++}::jsonb`); + values.push(JSON.stringify(metadata)); + } - if (updates.length === 0) { - res.json(serializeProfile(current)); - return; - } + if (updates.length === 0) { + res.json(serializeProfile(current)); + return; + } - updates.push("updated_at = CURRENT_TIMESTAMP"); - values.push(publicKey); + updates.push("updated_at = CURRENT_TIMESTAMP"); + values.push(publicKey); - const result = await query( - `UPDATE user_profiles + const result = await query( + `UPDATE user_profiles SET ${updates.join(", ")} WHERE public_key = $${paramIndex} RETURNING *`, - values, - ); + values, + ); - const updated = result.rows[0] as UserProfileRow | undefined; - if (!updated) { - throw AppError.notFound("User profile not found"); - } + const updated = result.rows[0] as UserProfileRow | undefined; + if (!updated) { + throw AppError.notFound("User profile not found"); + } - res.json(serializeProfile(updated)); -}); + res.json(serializeProfile(updated)); + }, +); diff --git a/backend/src/middleware/metrics.ts b/backend/src/middleware/metrics.ts index f7676270..e802ae31 100644 --- a/backend/src/middleware/metrics.ts +++ b/backend/src/middleware/metrics.ts @@ -85,7 +85,9 @@ export function recordIndexerLedgers( } export function recordScoreReconciliationRun(date = new Date()): void { - scoreReconciliationLastRunTimestampGauge.set(Math.floor(date.getTime() / 1000)); + scoreReconciliationLastRunTimestampGauge.set( + Math.floor(date.getTime() / 1000), + ); } export async function refreshWebhookRetryQueueDepth(): Promise { @@ -99,7 +101,9 @@ export async function refreshWebhookRetryQueueDepth(): Promise { ); webhookRetryQueueDepthGauge.set(Number(result.rows[0]?.count ?? 0)); } catch (error) { - logger.warn("Failed to refresh webhook retry queue depth metric", { error }); + logger.warn("Failed to refresh webhook retry queue depth metric", { + error, + }); } } diff --git a/backend/src/schemas/userSchemas.ts b/backend/src/schemas/userSchemas.ts index ddf62098..e9dae22e 100644 --- a/backend/src/schemas/userSchemas.ts +++ b/backend/src/schemas/userSchemas.ts @@ -1,12 +1,7 @@ import { z } from "zod"; const nullableTrimmedString = (max: number) => - z - .string() - .trim() - .max(max) - .nullable() - .optional(); + z.string().trim().max(max).nullable().optional(); export const updateUserProfileSchema = z .object({ diff --git a/backend/src/services/cacheService.ts b/backend/src/services/cacheService.ts index 713bd2c0..43432559 100644 --- a/backend/src/services/cacheService.ts +++ b/backend/src/services/cacheService.ts @@ -15,20 +15,20 @@ class CacheService { this.client.on("error", (err) => { // In tests, we don't want to spam the console with ECONNREFUSED if Redis isn't running if (process.env.NODE_ENV !== "test" || err.code !== "ECONNREFUSED") { - logger.error("Redis Client Error", err); + logger.withContext().error("Redis Client Error", err); } this.isConnected = false; }); this.client.on("connect", () => { - logger.info("Redis Client Connected"); + logger.withContext().info("Redis Client Connected"); this.isConnected = true; }); this.client.on("reconnecting", () => { // Only log reconnecting in non-test environments to keep test output clean if (process.env.NODE_ENV !== "test") { - logger.info("Redis Client Reconnecting"); + logger.withContext().info("Redis Client Reconnecting"); } }); @@ -43,7 +43,7 @@ class CacheService { } catch (err) { // Silently fail in tests if connection fails, but log in production if (process.env.NODE_ENV !== "test") { - logger.error("Failed to connect to Redis", err); + logger.withContext().error("Failed to connect to Redis", err); } throw err; } @@ -67,7 +67,9 @@ class CacheService { await this.client!.setEx(key, ttlSeconds, stringValue); } catch (error) { if (process.env.NODE_ENV !== "test") { - logger.error(`Error setting cache for key ${key}`, { error }); + logger + .withContext() + .error(`Error setting cache for key ${key}`, { error }); } } } @@ -86,7 +88,9 @@ class CacheService { return JSON.parse(value) as T; } catch (error) { if (process.env.NODE_ENV !== "test") { - logger.error(`Error getting cache for key ${key}`, { error }); + logger + .withContext() + .error(`Error getting cache for key ${key}`, { error }); } return null; } @@ -117,7 +121,9 @@ class CacheService { }); return result === "OK"; } catch (error) { - logger.error(`Error setting NX cache for key ${key}`, { error }); + logger + .withContext() + .error(`Error setting NX cache for key ${key}`, { error }); return false; } } @@ -132,7 +138,9 @@ class CacheService { await this.client!.del(key); } catch (error) { if (process.env.NODE_ENV !== "test") { - logger.error(`Error deleting cache for key ${key}`, { error }); + logger + .withContext() + .error(`Error deleting cache for key ${key}`, { error }); } } } @@ -150,7 +158,9 @@ class CacheService { } } catch (error) { if (process.env.NODE_ENV !== "test") { - logger.error(`Error invalidating pattern ${pattern}`, { error }); + logger + .withContext() + .error(`Error invalidating pattern ${pattern}`, { error }); } } } diff --git a/backend/src/services/defaultChecker.ts b/backend/src/services/defaultChecker.ts index eb042e79..5e87ba01 100644 --- a/backend/src/services/defaultChecker.ts +++ b/backend/src/services/defaultChecker.ts @@ -320,7 +320,7 @@ export class DefaultChecker { txStatus = polled.status; } catch (error) { const message = error instanceof Error ? error.message : String(error); - logger.warn("Default check transaction polling failed", { + logger.withContext().warn("Default check transaction polling failed", { txHash, message, }); @@ -372,7 +372,7 @@ export class DefaultChecker { } if (result.timedOut) { - logger.warn("Default check batch timed out", { + logger.withContext().warn("Default check batch timed out", { loanIds, timeoutMs: this.batchTimeoutMs, }); @@ -395,7 +395,9 @@ export class DefaultChecker { ); return acquired; } catch (error) { - logger.error("Failed to acquire default checker lock", { error }); + logger + .withContext() + .error("Failed to acquire default checker lock", { error }); return false; } } @@ -407,7 +409,9 @@ export class DefaultChecker { try { await cacheService.delete(LOCK_KEY); } catch (error) { - logger.error("Failed to release default checker lock", { error }); + logger + .withContext() + .error("Failed to release default checker lock", { error }); } } @@ -422,9 +426,11 @@ export class DefaultChecker { // Try to acquire distributed lock to prevent overlapping runs const lockAcquired = await this.acquireLock(); if (!lockAcquired) { - logger.warn( - "Default checker run skipped - another instance is already running", - ); + logger + .withContext() + .warn( + "Default checker run skipped - another instance is already running", + ); return null; } @@ -448,7 +454,7 @@ export class DefaultChecker { ? explicitIds : await this.fetchOverdueLoanIds(currentLedger); - logger.info("default_check.run.start", { + logger.withContext().info("default_check.run.start", { runId, currentLedger, termLedgers: this.termLedgers, @@ -476,7 +482,7 @@ export class DefaultChecker { batch, ); - logger.info("default_check.batch", { + logger.withContext().info("default_check.batch", { runId, loanIds: result.loanIds, txHash: result.txHash, @@ -498,7 +504,7 @@ export class DefaultChecker { (b) => b.error || !b.txHash, ).length; - logger.info("default_check.run.complete", { + logger.withContext().info("default_check.run.complete", { runId, batches: batchResults.length, loansChecked, @@ -549,9 +555,11 @@ export function startDefaultCheckerScheduler(): void { !process.env.LOAN_MANAGER_CONTRACT_ID || !process.env.LOAN_MANAGER_ADMIN_SECRET ) { - logger.warn( - "Default checker scheduler disabled (set LOAN_MANAGER_CONTRACT_ID and LOAN_MANAGER_ADMIN_SECRET)", - ); + logger + .withContext() + .warn( + "Default checker scheduler disabled (set LOAN_MANAGER_CONTRACT_ID and LOAN_MANAGER_ADMIN_SECRET)", + ); return; } @@ -567,18 +575,22 @@ export function startDefaultCheckerScheduler(): void { try { await defaultChecker.checkOverdueLoans(); } catch (error) { - logger.error("Default checker scheduled run failed", { error }); + logger + .withContext() + .error("Default checker scheduled run failed", { error }); } finally { inFlight = false; } })(); }, intervalMs); - logger.info("Default checker scheduler started", { intervalMs }); + logger + .withContext() + .info("Default checker scheduler started", { intervalMs }); } export function stopDefaultCheckerScheduler(): void { if (interval) clearInterval(interval); interval = undefined; - logger.info("Default checker scheduler stopped"); + logger.withContext().info("Default checker scheduler stopped"); } diff --git a/backend/src/services/eventIndexer.ts b/backend/src/services/eventIndexer.ts index 4c2433a0..0a84102d 100644 --- a/backend/src/services/eventIndexer.ts +++ b/backend/src/services/eventIndexer.ts @@ -163,7 +163,9 @@ export class EventIndexer { async start(): Promise { if (this.running) { - logger.warn("Indexer start requested while already running"); + logger + .withContext() + .warn("Indexer start requested while already running"); return; } @@ -184,7 +186,9 @@ export class EventIndexer { try { await this.activePollPromise; } catch (error) { - logger.warn("Indexer stop awaited a failing poll iteration", { error }); + logger + .withContext() + .warn("Indexer stop awaited a failing poll iteration", { error }); } finally { this.activePollPromise = null; } @@ -240,7 +244,7 @@ export class EventIndexer { this.activePollPromise = pollPromise; await pollPromise; } catch (error) { - logger.error("Indexer poll iteration failed", { error }); + logger.withContext().error("Indexer poll iteration failed", { error }); } finally { if (this.activePollPromise === pollPromise) { this.activePollPromise = null; @@ -283,7 +287,9 @@ export class EventIndexer { return Number.isFinite(sequence) && sequence > 0 ? sequence : 0; } catch (error) { - logger.warn("Failed to fetch latest ledger sequence", { error }); + logger + .withContext() + .warn("Failed to fetch latest ledger sequence", { error }); return 0; } } @@ -340,7 +346,7 @@ export class EventIndexer { return runWithRequestContext(correlationId, async () => { if (endLedger < startLedger) { - logger.warn("Skipping invalid ledger range", { + logger.withContext().warn("Skipping invalid ledger range", { startLedger, endLedger, }); @@ -370,7 +376,7 @@ export class EventIndexer { startLedger, ); - logger.info("Indexer processed chunk", { + logger.withContext().info("Indexer processed chunk", { startLedger, endLedger, fetchedEvents: events.length, @@ -383,7 +389,7 @@ export class EventIndexer { insertedEvents: storeResult.insertedCount, }; } catch (error) { - logger.error("Error processing event chunk", { + logger.withContext().error("Error processing event chunk", { startLedger, endLedger, error, @@ -451,7 +457,7 @@ export class EventIndexer { parsedEvents.push(parsed); } } catch (error) { - logger.warn("Failed to parse event", { + logger.withContext().warn("Failed to parse event", { eventId: event.id, error, }); @@ -573,7 +579,7 @@ export class EventIndexer { for (const event of insertedEvents) { webhookService.dispatch(event).catch((error) => { - logger.error("Webhook dispatch failed", { + logger.withContext().error("Webhook dispatch failed", { eventId: event.eventId, error, }); @@ -591,7 +597,7 @@ export class EventIndexer { }); this.triggerNotification(event).catch((error) => { - logger.error("Notification trigger failed", { + logger.withContext().error("Notification trigger failed", { eventId: event.eventId, error, }); @@ -874,12 +880,14 @@ export class EventIndexer { updated_at = CURRENT_TIMESTAMP`, [userId, 500 + delta, delta], ); - logger.info("Updated user score from indexed event", { + logger.withContext().info("Updated user score from indexed event", { userId, delta, }); } catch (error) { - logger.error("Failed to update user score", { userId, error }); + logger + .withContext() + .error("Failed to update user score", { userId, error }); } } @@ -1026,7 +1034,7 @@ export class EventIndexer { contractId: event.contractId, }; - logger.warn("Quarantining malformed event", { + logger.withContext().warn("Quarantining malformed event", { eventId: event.id, ledger: event.ledger, txHash: event.txHash, @@ -1049,7 +1057,7 @@ export class EventIndexer { ], ); } catch (dbError) { - logger.error("Failed to quarantine malformed event", { + logger.withContext().error("Failed to quarantine malformed event", { eventId: event.id, dbError, }); @@ -1066,7 +1074,7 @@ export class EventIndexer { const previousCount = this.lastObservedQuarantineCount; if (totalCount > previousCount) { - logger.warn("Quarantine event count increased", { + logger.withContext().warn("Quarantine event count increased", { previousCount, totalCount, delta: totalCount - previousCount, @@ -1077,16 +1085,20 @@ export class EventIndexer { previousCount < this.quarantineAlertThreshold && totalCount >= this.quarantineAlertThreshold ) { - logger.error("Quarantine event count exceeded alert threshold", { - threshold: this.quarantineAlertThreshold, - totalCount, - }); + logger + .withContext() + .error("Quarantine event count exceeded alert threshold", { + threshold: this.quarantineAlertThreshold, + totalCount, + }); } } this.lastObservedQuarantineCount = Math.max(previousCount, totalCount); } catch (error) { - logger.error("Failed to check quarantine event count", { error }); + logger + .withContext() + .error("Failed to check quarantine event count", { error }); } } diff --git a/backend/src/services/eventStreamService.ts b/backend/src/services/eventStreamService.ts index e2f7a24a..8d542ddb 100644 --- a/backend/src/services/eventStreamService.ts +++ b/backend/src/services/eventStreamService.ts @@ -56,7 +56,7 @@ class EventStreamService { } const counts = this.getConnectionCount(); - logger.info("SSE heartbeat", { + logger.withContext().info("SSE heartbeat", { borrower: counts.borrower, admin: counts.admin, total: counts.total, @@ -164,7 +164,7 @@ class EventStreamService { this.registerUserClient(userKey, res); this.startHeartbeat(); - logger.info("SSE client subscribed to borrower events", { + logger.withContext().info("SSE client subscribed to borrower events", { address, userKey, activeConnections: this.getUserConnectionCount(userKey), @@ -177,7 +177,7 @@ class EventStreamService { } this.unregisterUserClient(userKey, res); this.stopHeartbeatIfEmpty(); - logger.info("SSE client unsubscribed from address events", { + logger.withContext().info("SSE client unsubscribed from address events", { address, userKey, activeConnections: this.getUserConnectionCount(userKey), @@ -195,7 +195,7 @@ class EventStreamService { this.registerUserClient(userKey, res); this.startHeartbeat(); - logger.info("SSE admin client subscribed to all events", { + logger.withContext().info("SSE admin client subscribed to all events", { userKey, activeConnections: this.getUserConnectionCount(userKey), }); @@ -204,10 +204,12 @@ class EventStreamService { adminClients.delete(clientInfo); this.unregisterUserClient(userKey, res); this.stopHeartbeatIfEmpty(); - logger.info("SSE admin client unsubscribed from all events", { - userKey, - activeConnections: this.getUserConnectionCount(userKey), - }); + logger + .withContext() + .info("SSE admin client unsubscribed from all events", { + userKey, + activeConnections: this.getUserConnectionCount(userKey), + }); }; } @@ -227,7 +229,7 @@ class EventStreamService { // Verify user identity before sending (fixes #471) this.sendEvent(clientInfo.res, event); } catch (err) { - logger.error("SSE write error (address)", { + logger.withContext().error("SSE write error (address)", { address: event.address, userKey: clientInfo.userKey, err, @@ -248,7 +250,7 @@ class EventStreamService { try { this.sendEvent(clientInfo.res, event); } catch (err) { - logger.error("SSE write error (admin)", { + logger.withContext().error("SSE write error (admin)", { userKey: clientInfo.userKey, err, }); @@ -296,7 +298,7 @@ class EventStreamService { try { clientInfo.res.write(shutdownPayload); } catch (err) { - logger.error("SSE shutdown write error", { + logger.withContext().error("SSE shutdown write error", { userKey: clientInfo.userKey, err, }); @@ -305,7 +307,7 @@ class EventStreamService { try { clientInfo.res.end(); } catch (err) { - logger.error("SSE shutdown close error", { + logger.withContext().error("SSE shutdown close error", { userKey: clientInfo.userKey, err, }); diff --git a/backend/src/services/indexerManager.ts b/backend/src/services/indexerManager.ts index c7f01059..91cba5f9 100644 --- a/backend/src/services/indexerManager.ts +++ b/backend/src/services/indexerManager.ts @@ -9,7 +9,7 @@ let indexerInstance: EventIndexer | null = null; */ export const startIndexer = (): void => { if (indexerInstance) { - logger.warn("Indexer already running"); + logger.withContext().warn("Indexer already running"); return; } @@ -25,9 +25,11 @@ export const startIndexer = (): void => { const batchSize = parseInt(process.env.INDEXER_BATCH_SIZE || "100"); if (contractIds.length === 0) { - logger.warn( - "No contract IDs set for indexer. Set LOAN_MANAGER_CONTRACT_ID, LENDING_POOL_CONTRACT_ID, REMITTANCE_NFT_CONTRACT_ID, or MULTISIG_GOVERNANCE_CONTRACT_ID.", - ); + logger + .withContext() + .warn( + "No contract IDs set for indexer. Set LOAN_MANAGER_CONTRACT_ID, LENDING_POOL_CONTRACT_ID, REMITTANCE_NFT_CONTRACT_ID, or MULTISIG_GOVERNANCE_CONTRACT_ID.", + ); return; } @@ -41,10 +43,10 @@ export const startIndexer = (): void => { }); indexerInstance.start().catch((error) => { - logger.error("Failed to start indexer", { error }); + logger.withContext().error("Failed to start indexer", { error }); }); - logger.info("Event indexer initialized", { + logger.withContext().info("Event indexer initialized", { rpcUrl, contractIds, pollIntervalMs, @@ -59,7 +61,7 @@ export const stopIndexer = async (): Promise => { if (indexerInstance) { await indexerInstance.stop(); indexerInstance = null; - logger.info("Event indexer stopped"); + logger.withContext().info("Event indexer stopped"); } }; diff --git a/backend/src/services/notificationService.ts b/backend/src/services/notificationService.ts index 2171a644..0f7b532a 100644 --- a/backend/src/services/notificationService.ts +++ b/backend/src/services/notificationService.ts @@ -101,9 +101,11 @@ async function sendEmail( const fromEmail = process.env.FROM_EMAIL; if (!process.env.SENDGRID_API_KEY || !fromEmail) { - logger.info( - `[Email] SendGrid not configured. Would send to ${email}: ${message}`, - ); + logger + .withContext() + .info( + `[Email] SendGrid not configured. Would send to ${email}: ${message}`, + ); return; } @@ -118,9 +120,11 @@ async function sendEmail( subject: template.subject, html: template.html, }); - logger.info(`[Email] Sent to ${email}`, { subject: template.subject }); + logger + .withContext() + .info(`[Email] Sent to ${email}`, { subject: template.subject }); } catch (error) { - logger.error(`[Email] SendGrid failed for ${email}`, { + logger.withContext().error(`[Email] SendGrid failed for ${email}`, { error: error instanceof Error ? error.message : String(error), }); // Swallow error — email failure must not break the main flow @@ -129,9 +133,9 @@ async function sendEmail( async function sendSMS(phone: string, message: string) { if (!twilioClient || !process.env.TWILIO_PHONE_NUMBER) { - logger.warn( - `[SMS] Twilio not configured. Would send to ${phone}: ${message}`, - ); + logger + .withContext() + .warn(`[SMS] Twilio not configured. Would send to ${phone}: ${message}`); return; } @@ -141,9 +145,11 @@ async function sendSMS(phone: string, message: string) { from: process.env.TWILIO_PHONE_NUMBER, to: phone, }); - logger.info(`[SMS] Sent to ${phone}: ${message}`, { sid: result.sid }); + logger + .withContext() + .info(`[SMS] Sent to ${phone}: ${message}`, { sid: result.sid }); } catch (error) { - logger.error(`[SMS] Failed to send to ${phone}`, { + logger.withContext().error(`[SMS] Failed to send to ${phone}`, { error: error instanceof Error ? error.message : String(error), phone, }); @@ -270,7 +276,9 @@ class NotificationService { await sendSMS(user.phone, message); } } catch (error) { - logger.error("Error sending external notifications", { userId, error }); + logger + .withContext() + .error("Error sending external notifications", { userId, error }); } } @@ -358,10 +366,12 @@ class NotificationService { if (adminEmail) { await sendEmail(adminEmail, message); } else { - logger.warn("[Admin] ADMIN_EMAIL not set — logging dispute only", { - title, - message, - }); + logger + .withContext() + .warn("[Admin] ADMIN_EMAIL not set — logging dispute only", { + title, + message, + }); } // 2. Push SSE notification to every admin currently connected @@ -383,9 +393,11 @@ class NotificationService { this.broadcast(adminId, notification); } } catch (err) { - logger.error("[Admin] Failed to persist/push admin notifications", { - err, - }); + logger + .withContext() + .error("[Admin] Failed to persist/push admin notifications", { + err, + }); } // 3. Optional webhook (Slack / Discord / custom) @@ -398,7 +410,9 @@ class NotificationService { body: JSON.stringify({ text: `[RemitLend] ${title}: ${message}` }), }); } catch (err) { - logger.error("[Admin] Webhook POST failed", { webhookUrl, err }); + logger + .withContext() + .error("[Admin] Webhook POST failed", { webhookUrl, err }); } } } @@ -436,7 +450,7 @@ class NotificationService { try { res.write(data); } catch (err) { - logger.error("SSE write error", { userId, err }); + logger.withContext().error("SSE write error", { userId, err }); clients.delete(res); } } @@ -456,16 +470,18 @@ class NotificationService { ); const deletedCount = result.rowCount ?? 0; if (deletedCount > 0) { - logger.info( - `Notification cleanup completed: ${deletedCount} rows deleted`, - { - retentionDays, - }, - ); + logger + .withContext() + .info( + `Notification cleanup completed: ${deletedCount} rows deleted`, + { + retentionDays, + }, + ); } return deletedCount; } catch (error) { - logger.error("Error during notification cleanup", { + logger.withContext().error("Error during notification cleanup", { error, retentionDays, }); @@ -489,17 +505,21 @@ class NotificationService { ); const deletedCount = result.rowCount ?? 0; if (deletedCount > 0) { - logger.info( - `Read/archived notification cleanup completed: ${deletedCount} rows deleted`, - { retentionDays }, - ); + logger + .withContext() + .info( + `Read/archived notification cleanup completed: ${deletedCount} rows deleted`, + { retentionDays }, + ); } return deletedCount; } catch (error) { - logger.error("Error during read/archived notification cleanup", { - error, - retentionDays, - }); + logger + .withContext() + .error("Error during read/archived notification cleanup", { + error, + retentionDays, + }); return 0; } } @@ -555,7 +575,7 @@ export function startNotificationCleanupScheduler(): void { await notificationService.deleteReadAndArchived(readRetentionDays); }, intervalMs); - logger.info("Notification cleanup scheduler started", { + logger.withContext().info("Notification cleanup scheduler started", { retentionDays, readRetentionDays, intervalMs, @@ -569,6 +589,6 @@ export function stopNotificationCleanupScheduler(): void { if (cleanupInterval) { clearInterval(cleanupInterval); cleanupInterval = undefined; - logger.info("Notification cleanup scheduler stopped"); + logger.withContext().info("Notification cleanup scheduler stopped"); } } diff --git a/backend/src/services/rateLimitService.ts b/backend/src/services/rateLimitService.ts index 5cf77039..9ff2d211 100644 --- a/backend/src/services/rateLimitService.ts +++ b/backend/src/services/rateLimitService.ts @@ -88,7 +88,9 @@ class RateLimitService { currentCount, }; } catch (error) { - logger.error("Rate limit check failed", { identifier, error }); + logger + .withContext() + .error("Rate limit check failed", { identifier, error }); // Fail open: allow the request if Redis is unavailable // This prevents the entire service from failing due to rate limiting issues @@ -111,9 +113,11 @@ class RateLimitService { const key = `rate_limit:${identifier}`; try { await cacheService.delete(key); - logger.info("Rate limit reset", { identifier }); + logger.withContext().info("Rate limit reset", { identifier }); } catch (error) { - logger.error("Failed to reset rate limit", { identifier, error }); + logger + .withContext() + .error("Failed to reset rate limit", { identifier, error }); } } @@ -171,7 +175,9 @@ class RateLimitService { resetTime, }; } catch (error) { - logger.error("Failed to get rate limit status", { identifier, error }); + logger + .withContext() + .error("Failed to get rate limit status", { identifier, error }); // Return conservative values on error return { diff --git a/backend/src/services/remittanceService.ts b/backend/src/services/remittanceService.ts index 95476f29..5ef20a7d 100644 --- a/backend/src/services/remittanceService.ts +++ b/backend/src/services/remittanceService.ts @@ -169,7 +169,7 @@ export const remittanceService = { }; }); } catch (error) { - logger.error("Error creating remittance:", error); + logger.withContext().error("Error creating remittance:", error); if (error instanceof AppError) throw error; @@ -250,7 +250,7 @@ export const remittanceService = { nextCursor, }; } catch (error) { - logger.error("Error fetching remittances:", error); + logger.withContext().error("Error fetching remittances:", error); if (error instanceof AppError) { throw error; @@ -285,7 +285,7 @@ export const remittanceService = { updatedAt: r.updated_at.toISOString(), }; } catch (error) { - logger.error("Error fetching remittance:", error); + logger.withContext().error("Error fetching remittance:", error); if (error instanceof AppError) { throw error; @@ -337,7 +337,7 @@ export const remittanceService = { updatedAt: r.updated_at.toISOString(), }; } catch (error) { - logger.error("Error updating remittance:", error); + logger.withContext().error("Error updating remittance:", error); if (error instanceof AppError) { throw error; diff --git a/backend/src/services/scoreReconciliationService.ts b/backend/src/services/scoreReconciliationService.ts index e257d649..8152c14b 100644 --- a/backend/src/services/scoreReconciliationService.ts +++ b/backend/src/services/scoreReconciliationService.ts @@ -137,7 +137,7 @@ class ScoreReconciliationService { let checkedBorrowerCount = 0; let failedBorrowerCount = 0; - logger.info("score_reconciliation.run.start", { + logger.withContext().info("score_reconciliation.run.start", { activeBorrowerCount: activeBorrowers.length, batchSize, autoCorrectEnabled, @@ -161,7 +161,7 @@ class ScoreReconciliationService { const address = batch[index]?.address ?? "unknown"; if (result.status === "rejected") { failedBorrowerCount += 1; - logger.error("score_reconciliation.borrower.failed", { + logger.withContext().error("score_reconciliation.borrower.failed", { address, error: result.reason, }); @@ -186,7 +186,7 @@ class ScoreReconciliationService { }; divergences.push(divergence); - logger.warn("score_reconciliation.mismatch", divergence); + logger.withContext().warn("score_reconciliation.mismatch", divergence); const exceedsThreshold = absoluteDifference === null || @@ -198,14 +198,14 @@ class ScoreReconciliationService { }); } - logger.info("score_divergence_count", { + logger.withContext().info("score_divergence_count", { metric: "score_divergence_count", value: divergences.length, }); if (corrections.size > 0) { await setAbsoluteUserScoresBulk(corrections); - logger.warn("score_reconciliation.autocorrect.applied", { + logger.withContext().warn("score_reconciliation.autocorrect.applied", { correctedCount: corrections.size, threshold: autoCorrectThreshold, }); @@ -222,7 +222,7 @@ class ScoreReconciliationService { divergences, }; - logger.info("score_reconciliation.run.complete", { + logger.withContext().info("score_reconciliation.run.complete", { activeBorrowerCount: result.activeBorrowerCount, checkedBorrowerCount: result.checkedBorrowerCount, failedBorrowerCount: result.failedBorrowerCount, @@ -248,9 +248,11 @@ export function startScoreReconciliationScheduler(): void { } if (!process.env.REMITTANCE_NFT_CONTRACT_ID) { - logger.warn( - "Score reconciliation scheduler disabled (set REMITTANCE_NFT_CONTRACT_ID)", - ); + logger + .withContext() + .warn( + "Score reconciliation scheduler disabled (set REMITTANCE_NFT_CONTRACT_ID)", + ); return; } @@ -261,9 +263,11 @@ export function startScoreReconciliationScheduler(): void { const run = async () => { if (reconciliationInFlight) { - logger.warn( - "Score reconciliation run skipped because a previous run is still in flight", - ); + logger + .withContext() + .warn( + "Score reconciliation run skipped because a previous run is still in flight", + ); return; } @@ -271,7 +275,9 @@ export function startScoreReconciliationScheduler(): void { try { await scoreReconciliationService.reconcileActiveBorrowerScores(); } catch (error) { - logger.error("Score reconciliation scheduled run failed", { error }); + logger + .withContext() + .error("Score reconciliation scheduled run failed", { error }); } finally { reconciliationInFlight = false; } @@ -284,7 +290,7 @@ export function startScoreReconciliationScheduler(): void { }, intervalMs); reconciliationInterval.unref?.(); - logger.info("Score reconciliation scheduler started", { + logger.withContext().info("Score reconciliation scheduler started", { intervalMs, }); } @@ -293,6 +299,6 @@ export function stopScoreReconciliationScheduler(): void { if (reconciliationInterval) { clearInterval(reconciliationInterval); reconciliationInterval = undefined; - logger.info("Score reconciliation scheduler stopped"); + logger.withContext().info("Score reconciliation scheduler stopped"); } } diff --git a/backend/src/services/scoresService.ts b/backend/src/services/scoresService.ts index e84789e7..3f32d788 100644 --- a/backend/src/services/scoresService.ts +++ b/backend/src/services/scoresService.ts @@ -49,7 +49,7 @@ export async function updateUserScoresBulk( } else { await query(sql, params); } - logger.info("Applied bulk user score updates", { + logger.withContext().info("Applied bulk user score updates", { updatedCount: params.length / 2, }); @@ -59,7 +59,9 @@ export async function updateUserScoresBulk( await cacheService.delete(`score:breakdown:${userId}`); } } catch (error) { - logger.error("Failed to apply bulk user score updates", { error }); + logger + .withContext() + .error("Failed to apply bulk user score updates", { error }); throw error; } } @@ -100,9 +102,11 @@ export async function setAbsoluteUserScoresBulk( try { await query(sql, params); - logger.info("Applied absolute user score reconciliation updates", { - updatedCount: valuePlaceholders.length, - }); + logger + .withContext() + .info("Applied absolute user score reconciliation updates", { + updatedCount: valuePlaceholders.length, + }); // Invalidate Redis cache for reconciled users for (const [userId] of scores) { @@ -112,9 +116,11 @@ export async function setAbsoluteUserScoresBulk( } } } catch (error) { - logger.error("Failed to apply absolute user score reconciliation updates", { - error, - }); + logger + .withContext() + .error("Failed to apply absolute user score reconciliation updates", { + error, + }); throw error; } } diff --git a/backend/src/services/sorobanService.ts b/backend/src/services/sorobanService.ts index d88a65c1..32ad1926 100644 --- a/backend/src/services/sorobanService.ts +++ b/backend/src/services/sorobanService.ts @@ -164,7 +164,7 @@ class SorobanService { const prepared = await server.prepareTransaction(tx); const unsignedTxXdr = prepared.toXDR(); - logger.info("Built request_loan transaction", { + logger.withContext().info("Built request_loan transaction", { borrower: borrowerPublicKey, amount, }); @@ -210,7 +210,7 @@ class SorobanService { const prepared = await server.prepareTransaction(tx); const unsignedTxXdr = prepared.toXDR(); - logger.info("Built repay transaction", { + logger.withContext().info("Built repay transaction", { borrower: borrowerPublicKey, loanId, amount, @@ -260,7 +260,7 @@ class SorobanService { const prepared = await server.prepareTransaction(tx); const unsignedTxXdr = prepared.toXDR(); - logger.info("Built deposit transaction", { + logger.withContext().info("Built deposit transaction", { provider: providerPublicKey, token: tokenAddress, amount, @@ -310,7 +310,7 @@ class SorobanService { const prepared = await server.prepareTransaction(tx); const unsignedTxXdr = prepared.toXDR(); - logger.info("Built withdraw transaction", { + logger.withContext().info("Built withdraw transaction", { provider: providerPublicKey, token: tokenAddress, shares, @@ -353,7 +353,7 @@ class SorobanService { const prepared = await server.prepareTransaction(tx); const unsignedTxXdr = prepared.toXDR(); - logger.info("Built approve_loan transaction", { + logger.withContext().info("Built approve_loan transaction", { admin: adminPublicKey, loanId, }); @@ -396,7 +396,7 @@ class SorobanService { const prepared = await server.prepareTransaction(tx); const unsignedTxXdr = prepared.toXDR(); - logger.info("Built deposit_collateral transaction", { + logger.withContext().info("Built deposit_collateral transaction", { borrower: borrowerPublicKey, loanId, amount, @@ -438,7 +438,7 @@ class SorobanService { const prepared = await server.prepareTransaction(tx); const unsignedTxXdr = prepared.toXDR(); - logger.info("Built release_collateral transaction", { + logger.withContext().info("Built release_collateral transaction", { borrower: borrowerPublicKey, loanId, }); @@ -483,7 +483,7 @@ class SorobanService { const prepared = await server.prepareTransaction(tx); const unsignedTxXdr = prepared.toXDR(); - logger.info("Built refinance_loan transaction", { + logger.withContext().info("Built refinance_loan transaction", { borrower: borrowerPublicKey, loanId, newAmount, @@ -531,7 +531,7 @@ class SorobanService { const prepared = await server.prepareTransaction(tx); const unsignedTxXdr = prepared.toXDR(); - logger.info("Built extend_loan transaction", { + logger.withContext().info("Built extend_loan transaction", { borrower: borrowerPublicKey, loanId, extraLedgers, @@ -579,7 +579,7 @@ class SorobanService { const prepared = await server.prepareTransaction(tx); const unsignedTxXdr = prepared.toXDR(); - logger.info("Built liquidate transaction", { + logger.withContext().info("Built liquidate transaction", { liquidator: liquidatorPublicKey, loanId, }); @@ -635,7 +635,7 @@ class SorobanService { ); } - logger.info("Soroban configuration validated", { + logger.withContext().info("Soroban configuration validated", { loanManagerContractId: process.env.LOAN_MANAGER_CONTRACT_ID, lendingPoolContractId: process.env.LENDING_POOL_CONTRACT_ID, rpcUrl, @@ -665,7 +665,7 @@ class SorobanService { throw AppError.internal("Transaction submission returned no hash"); } - logger.info("Transaction submitted", { + logger.withContext().info("Transaction submitted", { txHash, status: sendResult.status, }); @@ -740,18 +740,22 @@ class SorobanService { break; } - logger.warn("Retrying get_score simulation after transient RPC failure", { - borrower: userPublicKey, - attempt, - error: message, - }); + logger + .withContext() + .warn("Retrying get_score simulation after transient RPC failure", { + borrower: userPublicKey, + attempt, + error: message, + }); } if (!simulation) { - logger.warn("Falling back to default credit score: empty simulation", { - borrower: userPublicKey, - defaultScore, - }); + logger + .withContext() + .warn("Falling back to default credit score: empty simulation", { + borrower: userPublicKey, + defaultScore, + }); return defaultScore; } @@ -761,7 +765,7 @@ class SorobanService { this.isMissingScoreError(message) || this.isTransientRpcError(message) ) { - logger.warn("Falling back to default credit score", { + logger.withContext().warn("Falling back to default credit score", { borrower: userPublicKey, defaultScore, reason: message, @@ -776,21 +780,25 @@ class SorobanService { const retval = simulation.result?.retval; if (!retval) { - logger.warn("Falling back to default credit score: no score returned", { - borrower: userPublicKey, - defaultScore, - }); + logger + .withContext() + .warn("Falling back to default credit score: no score returned", { + borrower: userPublicKey, + defaultScore, + }); return defaultScore; } const nativeScore = scValToNative(retval); const score = Number(nativeScore); if (!Number.isFinite(score)) { - logger.warn("Falling back to default credit score: invalid score value", { - borrower: userPublicKey, - defaultScore, - nativeScore, - }); + logger + .withContext() + .warn("Falling back to default credit score: invalid score value", { + borrower: userPublicKey, + defaultScore, + nativeScore, + }); return defaultScore; } @@ -1014,7 +1022,7 @@ class SorobanService { } } - logger.info("Score delta configuration validated", { + logger.withContext().info("Score delta configuration validated", { repaymentDelta: process.env.SCORE_DELTA_REPAY ?? "15", defaultPenalty: process.env.SCORE_DELTA_DEFAULT ?? "50", latePenalty: process.env.SCORE_DELTA_LATE ?? "5", diff --git a/backend/src/services/webhookRetryProcessor.ts b/backend/src/services/webhookRetryProcessor.ts index cd91399e..5fb08e07 100644 --- a/backend/src/services/webhookRetryProcessor.ts +++ b/backend/src/services/webhookRetryProcessor.ts @@ -12,11 +12,11 @@ let retryProcessorInterval: NodeJS.Timeout | null = null; */ export function startWebhookRetryProcessor(): void { if (retryProcessorInterval) { - logger.warn("Webhook retry processor already running"); + logger.withContext().warn("Webhook retry processor already running"); return; } - logger.info("Starting webhook retry processor"); + logger.withContext().info("Starting webhook retry processor"); // Run retry processor every 10 seconds retryProcessorInterval = setInterval(async () => { @@ -25,7 +25,9 @@ export function startWebhookRetryProcessor(): void { await WebhookService.processRetries(); await refreshWebhookRetryQueueDepth(); } catch (error) { - logger.error("Error in webhook retry processor interval", { error }); + logger + .withContext() + .error("Error in webhook retry processor interval", { error }); } }, 10 * 1000); } @@ -35,7 +37,7 @@ export function startWebhookRetryProcessor(): void { */ export function stopWebhookRetryProcessor(): void { if (retryProcessorInterval) { - logger.info("Stopping webhook retry processor"); + logger.withContext().info("Stopping webhook retry processor"); clearInterval(retryProcessorInterval); retryProcessorInterval = null; } diff --git a/backend/src/services/webhookRetryScheduler.ts b/backend/src/services/webhookRetryScheduler.ts index fe65d1f6..5d6cfb29 100644 --- a/backend/src/services/webhookRetryScheduler.ts +++ b/backend/src/services/webhookRetryScheduler.ts @@ -15,7 +15,9 @@ async function markAsFailed(deliveryId: number) { WHERE id = $2`, ["Permanently failed after max attempts reached", deliveryId], ); - logger.error(`Webhook delivery ${deliveryId} marked as permanently failed.`); + logger + .withContext() + .error(`Webhook delivery ${deliveryId} marked as permanently failed.`); } function shouldRetry(delivery: any, delay: number): boolean { @@ -25,9 +27,11 @@ function shouldRetry(delivery: any, delay: number): boolean { } async function sendWebhookAgain(delivery: any) { - logger.info( - `Retrying webhook delivery ${delivery.id} (attempt ${delivery.attempt_count + 1})`, - ); + logger + .withContext() + .info( + `Retrying webhook delivery ${delivery.id} (attempt ${delivery.attempt_count + 1})`, + ); await WebhookService.retryWebhookDelivery( delivery.id, @@ -66,23 +70,23 @@ export async function retryFailedWebhooks() { } } } catch (error) { - logger.error("Error in webhook retry scheduler", { error }); + logger.withContext().error("Error in webhook retry scheduler", { error }); } } export function startWebhookRetryScheduler() { if (schedulerInterval) { - logger.warn("Webhook retry scheduler already running"); + logger.withContext().warn("Webhook retry scheduler already running"); return; } - logger.info("Starting webhook retry scheduler (60s interval)"); + logger.withContext().info("Starting webhook retry scheduler (60s interval)"); schedulerInterval = setInterval(retryFailedWebhooks, 60000); } export function stopWebhookRetryScheduler() { if (schedulerInterval) { - logger.info("Stopping webhook retry scheduler"); + logger.withContext().info("Stopping webhook retry scheduler"); clearInterval(schedulerInterval); schedulerInterval = null; } diff --git a/backend/src/services/webhookService.ts b/backend/src/services/webhookService.ts index a9ada19d..e3aa24e7 100644 --- a/backend/src/services/webhookService.ts +++ b/backend/src/services/webhookService.ts @@ -223,12 +223,14 @@ function prepareWebhookPayload( ); } - logger.warn("Webhook payload exceeds size limit, sending summary payload", { - eventId, - eventType, - payloadBytes, - maxPayloadBytes, - }); + logger + .withContext() + .warn("Webhook payload exceeds size limit, sending summary payload", { + eventId, + eventType, + payloadBytes, + maxPayloadBytes, + }); return { body: summarizedBody, @@ -237,7 +239,7 @@ function prepareWebhookPayload( } if (payloadBytes >= Math.floor(maxPayloadBytes * 0.9)) { - logger.warn("Webhook payload is near size limit", { + logger.withContext().warn("Webhook payload is near size limit", { eventId, eventType, payloadBytes, @@ -302,7 +304,7 @@ export const getRetryDelayMs = (attemptNumber: number): number => { export class WebhookService { // Retry processor that polls for pending retries static async processRetries(): Promise { - logger.info("Starting webhook retry processor"); + logger.withContext().info("Starting webhook retry processor"); try { const now = new Date(); @@ -325,7 +327,9 @@ export class WebhookService { return; } - logger.info(`Processing ${result.rows.length} pending webhook retries`); + logger + .withContext() + .info(`Processing ${result.rows.length} pending webhook retries`); for (const row of result.rows) { const delivery = row as unknown as { @@ -350,7 +354,7 @@ export class WebhookService { ); } } catch (error) { - logger.error("Error in webhook retry processor", { error }); + logger.withContext().error("Error in webhook retry processor", { error }); } } @@ -399,7 +403,7 @@ export class WebhookService { ], ); - logger.info("Webhook delivery succeeded after retry", { + logger.withContext().info("Webhook delivery succeeded after retry", { deliveryId, subscriptionId, eventId, @@ -432,26 +436,27 @@ export class WebhookService { ); if (nextRetryTime) { - logger.warn("Webhook delivery failed, scheduled retry", { - deliveryId, - subscriptionId, - eventId, - attemptCount: newAttemptCount, - statusCode: response.status, - nextRetryAt: nextRetryTime, - }); + logger + .withContext() + .warn("Webhook delivery failed, scheduled retry", { + deliveryId, + subscriptionId, + eventId, + attemptCount: newAttemptCount, + statusCode: response.status, + nextRetryAt: nextRetryTime, + }); } else { - logger.error( - "Webhook delivery permanently failed after max retries", - { + logger + .withContext() + .error("Webhook delivery permanently failed after max retries", { deliveryId, subscriptionId, eventId, attemptCount: newAttemptCount, statusCode: response.status, payload: body, - }, - ); + }); } } } catch (error) { @@ -475,7 +480,7 @@ export class WebhookService { ); if (nextRetryTime) { - logger.warn("Webhook delivery error, scheduled retry", { + logger.withContext().warn("Webhook delivery error, scheduled retry", { deliveryId, subscriptionId, eventId, @@ -484,13 +489,15 @@ export class WebhookService { nextRetryAt: nextRetryTime, }); } else { - logger.error("Webhook delivery permanently failed after max retries", { - deliveryId, - subscriptionId, - eventId, - attemptCount: newAttemptCount, - error, - }); + logger + .withContext() + .error("Webhook delivery permanently failed after max retries", { + deliveryId, + subscriptionId, + eventId, + attemptCount: newAttemptCount, + error, + }); } } } @@ -558,7 +565,7 @@ export class WebhookService { } async dispatch(event: IndexedLoanEvent): Promise { - logger.info("Dispatching webhook event", { + logger.withContext().info("Dispatching webhook event", { eventId: event.eventId, eventType: event.eventType, loanId: event.loanId, @@ -589,7 +596,7 @@ export class WebhookService { ), ); } catch (error) { - logger.error("Error during webhook dispatch", { + logger.withContext().error("Error during webhook dispatch", { eventId: event.eventId, eventType: event.eventType, error, @@ -663,7 +670,7 @@ export class WebhookService { ], ); - logger.warn("Webhook delivery failed, scheduled retry", { + logger.withContext().warn("Webhook delivery failed, scheduled retry", { subscriptionId, callbackUrl, eventId: payload.payload.eventId, @@ -695,7 +702,7 @@ export class WebhookService { ], ); - logger.error("Failed to send webhook, scheduled retry", { + logger.withContext().error("Failed to send webhook, scheduled retry", { subscriptionId, callbackUrl, eventId: payload.payload.eventId, diff --git a/backend/src/utils/logger.ts b/backend/src/utils/logger.ts index e295c9e7..08f9db19 100644 --- a/backend/src/utils/logger.ts +++ b/backend/src/utils/logger.ts @@ -69,4 +69,31 @@ const logger = winston.createLogger({ transports, }); -export default logger; +export interface LogContext { + requestId?: string; + userId?: string; + loanId?: string; + [key: string]: any; +} + +const withContext = (context: LogContext = {}) => { + const requestId = context.requestId || getRequestId(); + const baseMeta: Record = {}; + + if (requestId) baseMeta.requestId = requestId; + if (context.userId) baseMeta.userId = context.userId; + if (context.loanId) baseMeta.loanId = context.loanId; + + return { + info: (message: string, meta?: any) => + logger.info(message, { ...baseMeta, ...meta }), + warn: (message: string, meta?: any) => + logger.warn(message, { ...baseMeta, ...meta }), + error: (message: string, meta?: any) => + logger.error(message, { ...baseMeta, ...meta }), + }; +}; + +const loggerWithContext = Object.assign(logger, { withContext }); + +export default loggerWithContext;