From f0d69d8405da7ae8af679aac08505e7df9d9f60b Mon Sep 17 00:00:00 2001 From: Michal Struck Date: Fri, 7 Feb 2025 14:14:53 +0100 Subject: [PATCH 1/7] remove legacy logger --- web/legacy/backend/errors.ts | 2 +- web/legacy/backend/jwks.ts | 6 +- web/legacy/backend/kms.ts | 2 +- web/legacy/backend/oidc.ts | 2 +- web/legacy/backend/verify.ts | 2 +- web/legacy/lib/logger.ts | 143 -------------------- web/pages/api/_delete-expired-auth-codes.ts | 6 +- web/pages/api/_delete-jwks.ts | 8 +- web/pages/api/v1/oidc/authorize.ts | 2 +- web/tests/api/delete-jwks.test.ts | 4 +- 10 files changed, 17 insertions(+), 160 deletions(-) delete mode 100644 web/legacy/lib/logger.ts diff --git a/web/legacy/backend/errors.ts b/web/legacy/backend/errors.ts index 892dc65e4..59d1651cd 100644 --- a/web/legacy/backend/errors.ts +++ b/web/legacy/backend/errors.ts @@ -1,4 +1,4 @@ -import { logger } from "@/legacy/lib/logger"; +import { logger } from "@/lib/logger"; import { NextApiRequest, NextApiResponse } from "next"; export function errorResponse( diff --git a/web/legacy/backend/jwks.ts b/web/legacy/backend/jwks.ts index 7c5f1218d..649b52f54 100644 --- a/web/legacy/backend/jwks.ts +++ b/web/legacy/backend/jwks.ts @@ -1,11 +1,11 @@ +import { JWK_TIME_TO_LIVE, JWK_TTL_USABLE } from "@/legacy/lib/constants"; +import { JWKModel } from "@/legacy/lib/models"; +import { logger } from "@/lib/logger"; import { gql } from "@apollo/client"; import { createPublicKey } from "crypto"; import dayjs from "dayjs"; -import { JWKModel } from "@/legacy/lib/models"; import { getAPIServiceClient } from "./graphql"; import { createKMSKey, getKMSClient, scheduleKeyDeletion } from "./kms"; -import { JWK_TIME_TO_LIVE, JWK_TTL_USABLE } from "@/legacy/lib/constants"; -import { logger } from "@/legacy/lib/logger"; export type CreateJWKResult = { keyId: string; diff --git a/web/legacy/backend/kms.ts b/web/legacy/backend/kms.ts index 16c2dc6cf..485090614 100644 --- a/web/legacy/backend/kms.ts +++ b/web/legacy/backend/kms.ts @@ -2,6 +2,7 @@ * Contains all functions for interacting with Amazon KMS */ +import { logger } from "@/lib/logger"; import { CreateKeyCommand, DescribeKeyCommand, @@ -13,7 +14,6 @@ import { } from "@aws-sdk/client-kms"; import { base64url } from "jose"; import { retrieveJWK } from "./jwks"; -import { logger } from "@/legacy/lib/logger"; export type CreateKeyResult = | { diff --git a/web/legacy/backend/oidc.ts b/web/legacy/backend/oidc.ts index 705b2727e..e095feabc 100644 --- a/web/legacy/backend/oidc.ts +++ b/web/legacy/backend/oidc.ts @@ -1,5 +1,5 @@ -import { logger } from "@/legacy/lib/logger"; import { ActionModel, AppModel, RedirectModel } from "@/legacy/lib/models"; +import { logger } from "@/lib/logger"; import { IInternalError, OIDCFlowType, OIDCResponseType } from "@/lib/types"; import { gql } from "@apollo/client"; import { VerificationLevel } from "@worldcoin/idkit-core"; diff --git a/web/legacy/backend/verify.ts b/web/legacy/backend/verify.ts index 642f6d240..95bd12d9b 100644 --- a/web/legacy/backend/verify.ts +++ b/web/legacy/backend/verify.ts @@ -1,6 +1,6 @@ import { validateABILikeEncoding } from "@/legacy/lib/hashing"; -import { logger } from "@/legacy/lib/logger"; import { IInternalError } from "@/legacy/lib/types"; +import { logger } from "@/lib/logger"; import { sequencerMapping } from "@/lib/utils"; import { ApolloClient, NormalizedCacheObject, gql } from "@apollo/client"; import { VerificationLevel } from "@worldcoin/idkit-core"; diff --git a/web/legacy/lib/logger.ts b/web/legacy/lib/logger.ts deleted file mode 100644 index 0919b99a4..000000000 --- a/web/legacy/lib/logger.ts +++ /dev/null @@ -1,143 +0,0 @@ -import { tryParseJSON } from "@/lib/utils"; -import { IncomingMessage } from "http"; -import { NextApiRequest } from "next"; -import winston from "winston"; - -const apiKey = process.env.NEXT_SERVER_DD_API_KEY; -const serviceName = process.env.NEXT_SERVER_DD_SERVICE_NAME; - -const httpTransportOptions = { - host: "http-intake.logs.datadoghq.com", - path: `/api/v2/logs?dd-api-key=${apiKey}&ddsource=nodejs&service=${serviceName}&env=${ - process.env.VERCEL_ENV ?? process.env.NODE_ENV ?? undefined - }`, - ssl: true, -}; - -const transports: winston.LoggerOptions["transports"] = []; - -const errorFormatter = winston.format((info) => { - return { - ...info, - - // Winston doesn't serialize Error objects well - ...(info.error instanceof Error - ? { - error: { message: info.error.message, stack: info.error.stack }, - message: info.message || info.error.message, - } - : {}), - - // Calling logger.error({error: new Error('Some error')}) will produce {message: {error: ...}} - ...(info.message instanceof Object && info.message?.error instanceof Error - ? { - error: { - message: info.message.error?.message, - stack: info.message.error?.stack, - }, - message: info.message.error.message, - } - : {}), - }; -}); - -if (process.env.NODE_ENV === "production") { - transports.push(new winston.transports.Http(httpTransportOptions)); -} else { - transports.push(new winston.transports.Console()); -} - -const _logger = winston.createLogger({ - level: "info", - exitOnError: false, - format: winston.format.combine( - errorFormatter(), - winston.format.timestamp(), - winston.format.json(), - ), - transports, -}); - -// NOTE: this is wrapper and formatter for debug request data (this is workaround, because winston don't support async formatters) -async function requestFormatter(req: NextApiRequest | IncomingMessage) { - if (!req) { - return {}; - } - - const ip = req.socket.remoteAddress; - const url = req.url?.replace(/\?.*$/, ""); - const method = req.method; - const userAgent = req.headers["user-agent"]; - - const query = req.url?.includes("?") - ? Object.fromEntries( - new URLSearchParams(req.url?.replace(/^.*\?/, "")).entries(), - ) - : {}; - - let body: any = null; - - if ("body" in req) { - body = req.body; - } else { - body = await (async () => - await new Promise((resolve) => { - let data: Array = []; - req - .on("data", (chunk) => data.push(chunk)) - .on("end", () => { - resolve(Buffer.concat(data).toString("utf8")); - }); - }))(); - } - - if (typeof body === "string") { - body = tryParseJSON(body); - } - - if ( - body === null || - (typeof body === "string" && body === "") || - (typeof body === "object" && Object.keys(body).length === 0) - ) { - body = null; - } - - return { - body, - env: process.env.VERCEL_ENV ?? process.env.NODE_ENV ?? undefined, - host: process.env.VERCEL_URL ?? undefined, - ip, - method, - query, - url, - userAgent: userAgent, - }; -} - -async function loggerWrapper( - handler: "error" | "warn" | "info" | "debug", - msg: string, - data?: Record, -) { - if (data && data.req) { - data.request = await requestFormatter(data.req); - delete data.req; - } - - _logger[handler](msg, data); -} - -export const logger = { - error: (msg: string, data?: Record) => - loggerWrapper("error", msg, data), - - warn: (msg: string, data?: Record) => - loggerWrapper("warn", msg, data), - - info: (msg: string, data?: Record) => - loggerWrapper("info", msg, data), - - debug: (msg: string, data?: Record) => - loggerWrapper("debug", msg, data), -}; diff --git a/web/pages/api/_delete-expired-auth-codes.ts b/web/pages/api/_delete-expired-auth-codes.ts index 428252d80..de4efa42a 100644 --- a/web/pages/api/_delete-expired-auth-codes.ts +++ b/web/pages/api/_delete-expired-auth-codes.ts @@ -1,9 +1,9 @@ -import { gql } from "@apollo/client"; +import { errorNotAllowed } from "@/legacy/backend/errors"; import { getAPIServiceClient } from "@/legacy/backend/graphql"; import { protectInternalEndpoint } from "@/legacy/backend/utils"; +import { logger } from "@/lib/logger"; +import { gql } from "@apollo/client"; import { NextApiRequest, NextApiResponse } from "next"; -import { errorNotAllowed } from "@/legacy/backend/errors"; -import { logger } from "@/legacy/lib/logger"; /** * Deletes expired auth codes diff --git a/web/pages/api/_delete-jwks.ts b/web/pages/api/_delete-jwks.ts index c7574d888..e71d75f64 100644 --- a/web/pages/api/_delete-jwks.ts +++ b/web/pages/api/_delete-jwks.ts @@ -1,8 +1,8 @@ -import { NextApiRequest, NextApiResponse } from "next"; -import { _deleteExpiredJWKs, createAndStoreJWK } from "@/legacy/backend/jwks"; -import { protectInternalEndpoint } from "@/legacy/backend/utils"; import { errorNotAllowed } from "@/legacy/backend/errors"; -import { logger } from "@/legacy/lib/logger"; +import { _deleteExpiredJWKs } from "@/legacy/backend/jwks"; +import { protectInternalEndpoint } from "@/legacy/backend/utils"; +import { logger } from "@/lib/logger"; +import { NextApiRequest, NextApiResponse } from "next"; /** * Generates JWKs to verify proofs offline diff --git a/web/pages/api/v1/oidc/authorize.ts b/web/pages/api/v1/oidc/authorize.ts index 0d65d553d..734e0244f 100644 --- a/web/pages/api/v1/oidc/authorize.ts +++ b/web/pages/api/v1/oidc/authorize.ts @@ -17,8 +17,8 @@ import { } from "@/legacy/backend/oidc"; import { validateRequestSchema } from "@/legacy/backend/utils"; import { verifyProof } from "@/legacy/backend/verify"; -import { logger } from "@/legacy/lib/logger"; import { OIDCFlowType, OIDCResponseType } from "@/legacy/lib/types"; +import { logger } from "@/lib/logger"; import { captureEvent } from "@/services/posthogClient"; import { gql } from "@apollo/client"; import { VerificationLevel } from "@worldcoin/idkit-core"; diff --git a/web/tests/api/delete-jwks.test.ts b/web/tests/api/delete-jwks.test.ts index c978c0dfc..96d822b40 100644 --- a/web/tests/api/delete-jwks.test.ts +++ b/web/tests/api/delete-jwks.test.ts @@ -1,8 +1,8 @@ -import { createMocks } from "node-mocks-http"; +import { logger } from "@/lib/logger"; import handleDeleteJWKS from "@/pages/api/_delete-jwks"; import { when } from "jest-when"; -import { logger } from "@/legacy/lib/logger"; import { NextApiRequest, NextApiResponse } from "next"; +import { createMocks } from "node-mocks-http"; let consoleInfoSpy: jest.SpyInstance; const requestReturnFn = jest.fn(); From 15122a9af013590eb7398faa00bbdbc1e2a6de78 Mon Sep 17 00:00:00 2001 From: Michal Struck Date: Fri, 7 Feb 2025 16:08:08 +0100 Subject: [PATCH 2/7] NEXT_SERVER_DD_SERVICE_NAME update in tests --- web/.env.test | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/web/.env.test b/web/.env.test index 2a8b35a80..94095a674 100644 --- a/web/.env.test +++ b/web/.env.test @@ -37,7 +37,7 @@ SENDGRID_TEAM_INVITE_TEMPLATE_ID=temporary_test_id # Datadog NEXT_SERVER_DD_API_KEY= -NEXT_SERVER_DD_SERVICE_NAME=developer-portal +NEXT_SERVER_DD_SERVICE_NAME=worldcoin-developer-portal # Auth0 From 34d9141c057e917082ef887fb33ea31226e331d7 Mon Sep 17 00:00:00 2001 From: Michal Struck Date: Mon, 10 Feb 2025 13:57:41 +0100 Subject: [PATCH 3/7] fix: handle app router logs in logger --- web/lib/logger.ts | 27 +++++++++++++++++++++------ 1 file changed, 21 insertions(+), 6 deletions(-) diff --git a/web/lib/logger.ts b/web/lib/logger.ts index 149fe9783..7e26ea606 100644 --- a/web/lib/logger.ts +++ b/web/lib/logger.ts @@ -1,5 +1,6 @@ import { IncomingMessage } from "http"; import { NextApiRequest } from "next"; +import { NextRequest } from "next/server"; import winston from "winston"; const apiKey = process.env.NEXT_SERVER_DD_API_KEY; @@ -58,18 +59,32 @@ const _logger = winston.createLogger({ }); // NOTE: this is wrapper and formatter for debug request data (this is workaround, because winston don't support async formatters) -async function requestFormatter(req: NextApiRequest | IncomingMessage) { +async function requestFormatter( + req: NextApiRequest | IncomingMessage | NextRequest, +) { if (!req) { return {}; } - const ip = - req.socket?.remoteAddress || - req.headers["x-forwarded-for"] || - "IP not available"; + let ip: string | string[] | undefined; + if (req instanceof NextRequest) { + ip = req.ip; + } else { + ip = + req.socket?.remoteAddress || + req.headers["x-forwarded-for"] || + "IP not available"; + } + const url = req.url?.replace(/\?.*$/, ""); const method = req.method; - const userAgent = req.headers["user-agent"]; + let userAgent: string | undefined; + + if (req instanceof NextRequest) { + userAgent = req.headers.get("user-agent") ?? undefined; + } else { + userAgent = req.headers["user-agent"] ?? undefined; + } const query = req.url?.includes("?") ? Object.fromEntries( From 6054270a1ab7f9728a8682929d540c6e9c27850a Mon Sep 17 00:00:00 2001 From: Michal Struck Date: Mon, 10 Feb 2025 14:01:40 +0100 Subject: [PATCH 4/7] refactor: subsitute console logs with logger --- web/api/v2/public/apps/index.ts | 5 +++-- web/scenes/Onboarding/CreateTeam/page/Form/index.tsx | 2 +- .../Actions/ActionId/Components/Kiosk/IDKitBridge/index.tsx | 4 ++-- .../Apps/AppId/Actions/page/CreateActionModal/index.tsx | 2 +- 4 files changed, 7 insertions(+), 6 deletions(-) diff --git a/web/api/v2/public/apps/index.ts b/web/api/v2/public/apps/index.ts index d4e3c1f6c..f88ce2ed4 100644 --- a/web/api/v2/public/apps/index.ts +++ b/web/api/v2/public/apps/index.ts @@ -15,6 +15,7 @@ import { import { getSdk as getWebHighlightsSdk } from "./graphql/get-app-web-highlights.generated"; import { formatAppMetadata, rankApps } from "@/api/helpers/app-store"; +import { logger } from "@/lib/logger"; import { GetHighlightsQuery, getSdk as getHighlightsSdk, @@ -83,7 +84,7 @@ export const GET = async (request: NextRequest) => { const { app_rankings } = await getWebHighlightsSdk(client).GetHighlights(); highlightsIds = app_rankings[0]?.rankings ?? []; } catch (error) { - console.log(error); + logger.error("Error fetching highlights", { error, req: request }); return errorResponse({ statusCode: 500, code: "server_error", @@ -115,7 +116,7 @@ export const GET = async (request: NextRequest) => { }); highlightsApps = highlights; } catch (error) { - console.log(error); + logger.error("Error fetching app rankings", { error, req: request }); return errorResponse({ statusCode: 500, code: "server_error", diff --git a/web/scenes/Onboarding/CreateTeam/page/Form/index.tsx b/web/scenes/Onboarding/CreateTeam/page/Form/index.tsx index e4d8b2cc7..3bcfd8d28 100644 --- a/web/scenes/Onboarding/CreateTeam/page/Form/index.tsx +++ b/web/scenes/Onboarding/CreateTeam/page/Form/index.tsx @@ -77,7 +77,7 @@ export const Form = (props: { hasUser: boolean }) => { } if (!data || !data.returnTo) { - return console.log("Something went wrong"); + return; } await checkSession(); diff --git a/web/scenes/Portal/Teams/TeamId/Apps/AppId/Actions/ActionId/Components/Kiosk/IDKitBridge/index.tsx b/web/scenes/Portal/Teams/TeamId/Apps/AppId/Actions/ActionId/Components/Kiosk/IDKitBridge/index.tsx index a608cc20e..8c045078d 100644 --- a/web/scenes/Portal/Teams/TeamId/Apps/AppId/Actions/ActionId/Components/Kiosk/IDKitBridge/index.tsx +++ b/web/scenes/Portal/Teams/TeamId/Apps/AppId/Actions/ActionId/Components/Kiosk/IDKitBridge/index.tsx @@ -1,3 +1,4 @@ +import { logger } from "@/lib/logger"; import { KioskScreen } from "@/lib/types"; import { VerificationLevel, @@ -70,8 +71,7 @@ export const IDKitBridge = memo(function IDKitBridge(props: IDKitBridgeProps) { }) .catch((error) => { if (process.env.NODE_ENV === "development") { - console.log("Error creating client"); - console.error(error); + logger.debug("Error creating client", { error }); } }); }, [ diff --git a/web/scenes/Portal/Teams/TeamId/Apps/AppId/Actions/page/CreateActionModal/index.tsx b/web/scenes/Portal/Teams/TeamId/Apps/AppId/Actions/page/CreateActionModal/index.tsx index 1c4668ca6..af8d3f35a 100644 --- a/web/scenes/Portal/Teams/TeamId/Apps/AppId/Actions/page/CreateActionModal/index.tsx +++ b/web/scenes/Portal/Teams/TeamId/Apps/AppId/Actions/page/CreateActionModal/index.tsx @@ -125,7 +125,7 @@ export const CreateActionModal = (props: CreateActionModalProps) => { }); const refetchResult = await refetchActions(); - console.log("refetchResult", refetchResult); + reset(); if (firstAction) { router.prefetch(`${pathname}/${action_id}/settings`); From f79e658e7b8a227f573637375da057ea4d6872b1 Mon Sep 17 00:00:00 2001 From: Michal Struck Date: Mon, 10 Feb 2025 15:30:01 +0100 Subject: [PATCH 5/7] remove winston from client side --- .../Actions/ActionId/Components/Kiosk/IDKitBridge/index.tsx | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/web/scenes/Portal/Teams/TeamId/Apps/AppId/Actions/ActionId/Components/Kiosk/IDKitBridge/index.tsx b/web/scenes/Portal/Teams/TeamId/Apps/AppId/Actions/ActionId/Components/Kiosk/IDKitBridge/index.tsx index 8c045078d..09b0874b4 100644 --- a/web/scenes/Portal/Teams/TeamId/Apps/AppId/Actions/ActionId/Components/Kiosk/IDKitBridge/index.tsx +++ b/web/scenes/Portal/Teams/TeamId/Apps/AppId/Actions/ActionId/Components/Kiosk/IDKitBridge/index.tsx @@ -1,4 +1,3 @@ -import { logger } from "@/lib/logger"; import { KioskScreen } from "@/lib/types"; import { VerificationLevel, @@ -71,7 +70,7 @@ export const IDKitBridge = memo(function IDKitBridge(props: IDKitBridgeProps) { }) .catch((error) => { if (process.env.NODE_ENV === "development") { - logger.debug("Error creating client", { error }); + console.debug("Error creating client", { error }); } }); }, [ From 6692d6d28ed3e36e3f6ac06768f4457488ca1009 Mon Sep 17 00:00:00 2001 From: Michal Struck Date: Mon, 10 Feb 2025 16:21:43 +0100 Subject: [PATCH 6/7] update dd-trace in dockerfile --- web/Dockerfile | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/web/Dockerfile b/web/Dockerfile index a6f7a13a5..ea587b1b1 100644 --- a/web/Dockerfile +++ b/web/Dockerfile @@ -23,7 +23,7 @@ WORKDIR /app RUN npm install -g corepack@0.31.0 && corepack --version # TODO: Can be further optimized to remove next peer dependency -RUN corepack enable pnpm && pnpm i next-logger@5.0.0 pino@9.2.0 dd-trace@5.12.0 +RUN corepack enable pnpm && pnpm i next-logger@5.0.0 pino@9.2.0 dd-trace@5.35.0 # Rebuild the source code only when needed FROM base AS builder From 4c1a55b5054bfa61a02adde7d95119395c0afac7 Mon Sep 17 00:00:00 2001 From: Michal Struck Date: Tue, 11 Feb 2025 11:32:55 +0100 Subject: [PATCH 7/7] add skip logs --- web/api/helpers/errors.ts | 18 +++++++++++++++++- .../v2/minikit/app-metadata/[app_id]/index.ts | 2 ++ web/api/v2/verify/index.ts | 5 ++++- 3 files changed, 23 insertions(+), 2 deletions(-) diff --git a/web/api/helpers/errors.ts b/web/api/helpers/errors.ts index d1d181322..433d0ad1c 100644 --- a/web/api/helpers/errors.ts +++ b/web/api/helpers/errors.ts @@ -8,6 +8,7 @@ export function errorResponse(params: { detail?: string; attribute?: string | null; req: NextRequest; + skipLogging?: boolean; }) { const { statusCode, @@ -15,8 +16,16 @@ export function errorResponse(params: { detail = "Something went wrong", attribute = null, req, + skipLogging = false, } = params; + if (skipLogging) { + return NextResponse.json( + { code, detail, attribute }, + { status: statusCode }, + ); + } + if (statusCode >= 500) { logger.error(detail, { req, error: { statusCode, code, attribute } }); } else { @@ -89,7 +98,14 @@ export function errorValidation( attribute: string | null, req: NextRequest, ) { - return errorResponse({ statusCode: 400, code, detail, attribute, req }); + return errorResponse({ + statusCode: 400, + code, + detail, + attribute, + req, + skipLogging: true, + }); } export function errorOIDCResponse( diff --git a/web/api/v2/minikit/app-metadata/[app_id]/index.ts b/web/api/v2/minikit/app-metadata/[app_id]/index.ts index df899e7d7..d33ae977f 100644 --- a/web/api/v2/minikit/app-metadata/[app_id]/index.ts +++ b/web/api/v2/minikit/app-metadata/[app_id]/index.ts @@ -51,6 +51,7 @@ export const GET = async ( detail: "API key not found.", attribute: "api_key", req, + skipLogging: true, }); } @@ -61,6 +62,7 @@ export const GET = async ( detail: "API key is inactive.", attribute: "api_key", req, + skipLogging: true, }); } diff --git a/web/api/v2/verify/index.ts b/web/api/v2/verify/index.ts index 57f16fae8..662745f2f 100644 --- a/web/api/v2/verify/index.ts +++ b/web/api/v2/verify/index.ts @@ -135,6 +135,7 @@ export async function POST( detail: "This action does not have a valid external nullifier set.", attribute: null, req, + skipLogging: true, }); } @@ -173,16 +174,17 @@ export async function POST( detail: error?.message || "There was an error verifying this proof.", attribute: error?.attribute || null, req, + skipLogging: true, }); } } catch (e: any) { - console.warn("Error verifying proof", { error: e }); return errorResponse({ statusCode: 400, code: "verification_error", detail: e.message, attribute: null, req, + skipLogging: true, }); } @@ -244,6 +246,7 @@ export async function POST( : e.message, attribute: null, req, + skipLogging: true, }); } }