From 574506bcbf9e8d61d4272b5f306bc8f616817c28 Mon Sep 17 00:00:00 2001 From: Abner <22141172+Silentely@users.noreply.github.com> Date: Fri, 26 Jun 2026 21:28:21 +0800 Subject: [PATCH] =?UTF-8?q?=E2=9C=A8=20feat:=20=E6=B7=BB=E5=8A=A0=E7=BB=93?= =?UTF-8?q?=E6=9E=84=E5=8C=96=E6=97=A5=E5=BF=97=E6=94=AF=E6=8C=81=E5=B9=B6?= =?UTF-8?q?=E4=BC=98=E5=8C=96=E9=94=99=E8=AF=AF=E5=A4=84=E7=90=86?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - 在 netlify/functions/_shared/server-logger.js 中重构日志函数，统一日志输出格式，支持 context 字段覆盖基础字段（如 message） - 在 netlify/functions/_shared/middleware.js 中增强 withAuth 中间件，注入结构化 logger 到上下文，增加 request_start / request_end / request_error 日志追踪，并记录请求耗时 - 为所有 Netlify Function（giffgaff-sms-activate、giffgaff-graphql、auto-activate-esim、verify-cookie、giffgaff-token-exchange、giffgaff-mfa-challenge、giffgaff-mfa-validation、health）添加结构化日志，替换原有 console 输出，包含请求入参、状态和耗时 - 在 netlify/edge-functions/bff-proxy.js 和 markdown-negotiation.js 中实现 Deno 内联结构化日志，生成 requestId 并统一日志输出格式，支持 INFO/WARN/ERROR/DEBUG 级别控制 - 更新测试用例 tests/modules/server-logger.test.js 和 tests/functions/middleware-logging.test.js，新增日志级别过滤、context 覆盖、多实例隔离、OPTIONS 预检处理等测试场景 --- netlify/edge-functions/bff-proxy.js | 66 ++++++++++--- .../edge-functions/markdown-negotiation.js | 20 ++++ netlify/functions/_shared/middleware.js | 48 +++++++-- netlify/functions/_shared/server-logger.js | 6 +- netlify/functions/auto-activate-esim.js | 16 ++- netlify/functions/giffgaff-graphql.js | 42 +++++--- netlify/functions/giffgaff-mfa-challenge.js | 16 ++- netlify/functions/giffgaff-mfa-validation.js | 14 ++- netlify/functions/giffgaff-sms-activate.js | 30 ++++-- netlify/functions/giffgaff-token-exchange.js | 17 +++- netlify/functions/health.js | 9 ++ netlify/functions/verify-cookie.js | 13 ++- tests/functions/middleware-logging.test.js | 97 ++++++++++++++++++- tests/modules/server-logger.test.js | 63 ++++++++++++ 14 files changed, 402 insertions(+), 55 deletions(-) diff --git a/netlify/edge-functions/bff-proxy.js b/netlify/edge-functions/bff-proxy.js index 79629eb..7af971d 100644 --- a/netlify/edge-functions/bff-proxy.js +++ b/netlify/edge-functions/bff-proxy.js @@ -8,6 +8,34 @@ import qrCodeLib from './qrcode-lib.js'; +// === Deno 环境内联结构化日志（与 netlify/functions/_shared/server-logger.js 输出格式一致） === +const EDGE_LOG_LEVELS = { DEBUG: 0, INFO: 1, WARN: 2, ERROR: 3 }; + +function createEdgeLogger(functionName, requestId) { + const currentLevel = EDGE_LOG_LEVELS[getEnv('LOG_LEVEL')] ?? EDGE_LOG_LEVELS.INFO; + function log(level, message, context = {}) { + if (EDGE_LOG_LEVELS[level] < currentLevel) return; + const entry = { + level, + message, + function: functionName, + requestId, + timestamp: new Date().toISOString(), + ...context, + }; + const line = JSON.stringify(entry); + if (level === 'ERROR') console.error(line); + else if (level === 'WARN') console.warn(line); + else console.log(line); + } + return { + info: (msg, ctx) => log('INFO', msg, ctx), + warn: (msg, ctx) => log('WARN', msg, ctx), + error: (msg, ctx) => log('ERROR', msg, ctx), + debug: (msg, ctx) => log('DEBUG', msg, ctx), + }; +} + const BFF_ROUTES = new Map([ ['giffgaff-token-exchange', ['POST', 'OPTIONS']], ['giffgaff-graphql', ['POST', 'OPTIONS']], @@ -64,7 +92,8 @@ function buildCorsHeaders(origin) { export default async (request, context) => { const url = new URL(request.url); - const ts = new Date().toISOString(); + const requestId = crypto.randomUUID?.() || `${Date.now()}-${Math.random().toString(36).slice(2)}`; + const logger = createEdgeLogger('bff-proxy', requestId); // 仅处理 /bff/* 路径 if (!url.pathname.startsWith('/bff/')) { @@ -78,7 +107,7 @@ export default async (request, context) => { const allowedMethods = BFF_ROUTES.get(targetName); if (!allowedMethods) { - console.warn(`[BFF] ${ts} | blocked unknown target=${targetName}`); + logger.warn('blocked_unknown_target', { target: targetName }); return jsonResponse(404, { error: 'Not Found', message: 'BFF target not allowed' }); } @@ -96,7 +125,7 @@ export default async (request, context) => { const errorCorsHeaders = buildCorsHeaders(corsOrigin || fallbackCorsOrigin); if (!corsOrigin && !allowMissingOriginForPublicGet) { - console.warn(`[BFF] ${ts} | blocked origin=${requestOrigin || 'missing'} target=${targetName}`); + logger.warn('blocked_origin', { origin: requestOrigin || 'missing', target: targetName }); return jsonResponse(403, { error: 'Forbidden', message: 'Origin not allowed' }, errorCorsHeaders); } @@ -105,7 +134,12 @@ export default async (request, context) => { return new Response('', { status: 200, headers: corsHeaders }); } - console.log(`[BFF] ${ts} | ${request.method} ${url.pathname} → target=${targetName}`); + logger.info('request_start', { + method: request.method, + path: url.pathname, + target: targetName, + origin: requestOrigin || 'same-origin', + }); // === QR 码生成：Edge Function 直接处理（无冷启动） === // 安全模型：此端点不使用 ACCESS_KEY 认证，仅依赖 CORS origin 检查。 @@ -125,7 +159,7 @@ export default async (request, context) => { throw new Error('body must be a JSON object'); } } catch { - console.warn('[edge:qrcode-generate] Invalid JSON body'); + logger.warn('qr_invalid_body'); return jsonResponse(400, { error: 'Invalid JSON body' }, corsHeaders); } @@ -133,7 +167,7 @@ export default async (request, context) => { // 参数校验（与 src/js/modules/qrcode-generator.js 的 validateQRCodeData/normalizeQRCodeSize 保持同步） if (typeof data !== 'string' || data.length < 1 || data.length > QR_MAX_DATA_LENGTH) { - console.warn(`[edge:qrcode-generate] Invalid data: type=${typeof data}, length=${data ? data.length : 0}`); + logger.warn('qr_invalid_data', { type: typeof data, length: data ? data.length : 0 }); return jsonResponse(400, { error: `data must be a string between 1 and ${QR_MAX_DATA_LENGTH} characters` }, corsHeaders); @@ -141,7 +175,7 @@ export default async (request, context) => { const numSize = Number(size); if (!Number.isInteger(numSize) || numSize < QR_MIN_SIZE || numSize > QR_MAX_SIZE) { - console.warn(`[edge:qrcode-generate] Invalid size: ${size}`); + logger.warn('qr_invalid_size', { size }); return jsonResponse(400, { error: `size must be an integer between ${QR_MIN_SIZE} and ${QR_MAX_SIZE}` }, corsHeaders); @@ -157,14 +191,14 @@ export default async (request, context) => { const qrcode = qr.createDataURL(cellSize, cellSize * 4); const duration = Date.now() - qrStartTime; - console.log(`[edge:qrcode-generate] Success: size=${numSize}, modules=${moduleCount}, cellSize=${cellSize}, duration=${duration}ms, qrcodeLength=${qrcode.length}`); + logger.info('qr_generate_ok', { size: numSize, modules: moduleCount, cellSize, duration, qrcodeLength: qrcode.length }); return jsonResponse(200, { success: true, qrcode }, corsHeaders); } catch (error) { // qrcode-generator 库可能 throw 字符串而非 Error 对象，统一转换 const err = error instanceof Error ? error : new Error(String(error)); const duration = Date.now() - qrStartTime; - console.error(`[edge:qrcode-generate] Failed: error=${err.message}, duration=${duration}ms`); + logger.error('qr_generate_failed', { errorMessage: err.message, duration }); return jsonResponse(500, { error: err.message }, corsHeaders); } } @@ -176,10 +210,10 @@ export default async (request, context) => { // Netlify Edge 使用 Deno 运行时 const accessKey = getEnv('ACCESS_KEY'); if (!accessKey) { - console.error(`[BFF] ${ts} | ACCESS_KEY missing in Edge env`); + logger.error('access_key_missing'); return jsonResponse(500, { error: 'Server Misconfigured', message: 'ACCESS_KEY not configured' }, corsHeaders); } - console.log(`[BFF] ${ts} | ACCESS_KEY present, proceeding`); + logger.debug('access_key_present'); // 复制请求头并添加服务端密钥头；客户端提供的内部密钥一律不透传。 const headers = new Headers(request.headers); @@ -192,9 +226,9 @@ export default async (request, context) => { if (isMutating) { try { body = await request.arrayBuffer(); - console.log(`[BFF] ${ts} | body read OK, size=${body.byteLength} bytes`); + logger.info('body_read', { size: body.byteLength }); } catch (bodyErr) { - console.error(`[BFF] ${ts} | body read FAILED: ${bodyErr.message}`); + logger.error('body_read_failed', { errorMessage: bodyErr.message }); return jsonResponse(400, { error: 'Bad Request', message: 'Failed to read request body' }, corsHeaders); } } @@ -205,17 +239,17 @@ export default async (request, context) => { body }); - console.log(`[BFF] ${ts} | forwarding to ${functionUrl.pathname}`); + logger.info('forwarding', { targetPath: functionUrl.pathname }); let response; try { response = await fetch(proxiedRequest); } catch (fetchErr) { - console.error(`[BFF] ${ts} | fetch to Function FAILED: ${fetchErr.message}`); + logger.error('fetch_failed', { errorMessage: fetchErr.message }); return jsonResponse(502, { error: 'Bad Gateway', message: 'Failed to reach upstream function' }, corsHeaders); } // 响应日志（不包含敏感信息） - console.log(`[BFF] ${ts} | response from ${functionUrl.pathname}: status=${response.status} ok=${response.ok}`); + logger.info('response_received', { targetPath: functionUrl.pathname, status: response.status, ok: response.ok }); const responseHeaders = new Headers(response.headers); Object.entries(corsHeaders).forEach(([key, value]) => responseHeaders.set(key, value)); diff --git a/netlify/edge-functions/markdown-negotiation.js b/netlify/edge-functions/markdown-negotiation.js index 047241d..e617996 100644 --- a/netlify/edge-functions/markdown-negotiation.js +++ b/netlify/edge-functions/markdown-negotiation.js @@ -5,6 +5,18 @@ * - 浏览器请求保持 HTML 默认响应 */ +// Deno 环境内联结构化日志（与 bff-proxy.js 格式一致） +const MD_LOG_LEVELS = { DEBUG: 0, INFO: 1, WARN: 2, ERROR: 3 }; +function createMdLogger(functionName, requestId) { + const currentLevel = MD_LOG_LEVELS.INFO; + function log(level, message, context = {}) { + if (MD_LOG_LEVELS[level] < currentLevel) return; + const entry = { level, message, function: functionName, requestId, timestamp: new Date().toISOString(), ...context }; + console.log(JSON.stringify(entry)); + } + return { info: (msg, ctx) => log('INFO', msg, ctx), warn: (msg, ctx) => log('WARN', msg, ctx), error: (msg, ctx) => log('ERROR', msg, ctx) }; +} + // HTML 到 Markdown 的简易转换器 function htmlToMarkdown(html) { if (!html) return ''; @@ -174,6 +186,8 @@ A: 所有数据处理均在本地浏览器完成。但使用第三方工具可 `; export default async (request, context) => { + const requestId = crypto.randomUUID?.() || `${Date.now()}-${Math.random().toString(36).slice(2)}`; + const logger = createMdLogger('markdown-negotiation', requestId); const accept = request.headers.get('Accept') || ''; // 仅在请求 Accept 包含 text/markdown 时处理 @@ -206,6 +220,12 @@ export default async (request, context) => { } // 返回 Markdown 响应 + logger.info('markdown_conversion', { + path: pathname, + tokenCount: markdown.split(/\s+/).length, + source: pathname === '/' || pathname === '/index.html' ? 'preset' : 'converted', + }); + return new Response(markdown, { status: 200, headers: { diff --git a/netlify/functions/_shared/middleware.js b/netlify/functions/_shared/middleware.js index 5c22236..6fb0b73 100644 --- a/netlify/functions/_shared/middleware.js +++ b/netlify/functions/_shared/middleware.js @@ -3,8 +3,10 @@ * 提供鉴权、CORS、错误处理等功能 */ +const crypto = require('crypto'); const { captureException, flush, setContext } = require('./sentry'); const { parseOrigins, isAllowedOrigin: _isAllowedOrigin, resolveCorsOrigin: _resolveCorsOrigin } = require('./cors'); +const { createLogger } = require('./server-logger'); const ACCESS_KEY = process.env.ACCESS_KEY; const origins = parseOrigins(process.env.ALLOWED_ORIGIN); @@ -124,16 +126,17 @@ function createHeaders(origin = null, additionalHeaders = {}) { * 统一错误处理 * @param {Error} error - 错误对象 * @param {string} context - 错误上下文 + * @param {Object} [logger] - 结构化日志实例（可选，优先使用） * @returns {Object} Netlify response 对象 */ -function handleError(error, context = 'unknown') { +function handleError(error, context = 'unknown', logger) { const isDev = process.env.NODE_ENV === 'development'; const statusCode = error.statusCode || (error.response?.status) || 500; // 结构化日志（生产环境应集成专业日志服务） const logData = { context, - message: error.message, + errorMessage: error.message, status: statusCode, timestamp: new Date().toISOString() }; @@ -143,7 +146,10 @@ function handleError(error, context = 'unknown') { logData.data = error.response?.data; } - console.error(`[${context}] Error:`, JSON.stringify(logData)); + // 仅在无 logger 时输出兜底日志（withAuth 已通过 request_error 覆盖错误场景） + if (!logger) { + console.error(`[${context}] Error:`, JSON.stringify(logData)); + } // Sentry 错误上报（仅上报 5xx 服务端错误，4xx 客户端错误不上报） if (statusCode >= 500) { @@ -225,7 +231,7 @@ function validateInput(schema, data) { } /** - * 包装 Function Handler，自动处理鉴权和错误 + * 包装 Function Handler，自动处理鉴权、错误和结构化日志 * @param {Function} handler - 业务逻辑处理函数 * @param {Object} options - 配置选项 * @returns {Function} 包装后的 handler @@ -233,6 +239,16 @@ function validateInput(schema, data) { function withAuth(handler, options = {}) { return async (event, context) => { const functionName = context.functionName || 'unknown'; + const requestId = crypto.randomUUID(); + const startTime = Date.now(); + const logger = createLogger(functionName, requestId); + + // 请求开始日志（requestId 已在 logger 基础字段中，无需重复传入） + logger.info('request_start', { + method: event.httpMethod || 'GET', + path: event.path || '/', + source: (event.headers?.origin || event.headers?.['x-forwarded-for'] || '').substring(0, 100), + }); try { // 鉴权（requireAuth: false 时跳过密钥校验，仅保留 CORS 检查） @@ -293,10 +309,18 @@ function withAuth(handler, options = {}) { validateInput(options.validateSchema, parsedBody); } - // 执行业务逻辑 - const result = await handler(event, context, { auth, body: parsedBody }); + // 执行业务逻辑（注入 logger 到 context） + const result = await handler(event, { ...context, logger }, { auth, body: parsedBody }); const responseOrigin = auth.origin; + const duration = Date.now() - startTime; + const statusCode = result.statusCode || 200; + + // 请求结束日志 + logger.info('request_end', { + status: statusCode, + duration, + }); // 确保返回正确的响应格式 if (!result.statusCode) { @@ -312,7 +336,17 @@ function withAuth(handler, options = {}) { return result; } catch (error) { - const response = handleError(error, functionName); + const response = handleError(error, functionName, logger); + const duration = Date.now() - startTime; + + // 请求错误日志 + logger.error('request_error', { + status: response.statusCode, + errorMessage: error.message, + errorName: error.name || 'Error', + duration, + }); + // Serverless 环境需要显式 flush 确保错误发送到 Sentry await flush(2000); return response; diff --git a/netlify/functions/_shared/server-logger.js b/netlify/functions/_shared/server-logger.js index ff95c99..5e7ddf3 100644 --- a/netlify/functions/_shared/server-logger.js +++ b/netlify/functions/_shared/server-logger.js @@ -54,7 +54,7 @@ function createLogger(functionName, requestId) { * @param {Object} [context] - 附加字段 * @param {Function} [outputFn] - 输出函数（默认 console.log） */ - function log(level, message, context, outputFn) { + function log(level, message, context = {}, outputFn) { if (LOG_LEVELS[level] < getCurrentLevel()) return; const entry = { @@ -65,9 +65,7 @@ function createLogger(functionName, requestId) { timestamp: new Date().toISOString(), }; - if (context && typeof context === 'object') { - Object.assign(entry, context); - } + Object.assign(entry, context); outputFn(JSON.stringify(entry)); } diff --git a/netlify/functions/auto-activate-esim.js b/netlify/functions/auto-activate-esim.js index 5bf32da..b08a444 100644 --- a/netlify/functions/auto-activate-esim.js +++ b/netlify/functions/auto-activate-esim.js @@ -16,7 +16,16 @@ const autoActivateSchema = { } }; -exports.handler = withAuth(async (event, context, { auth, body }) => { +exports.handler = withAuth(async (event, ctx, { auth, body }) => { + const logger = ctx.logger; + const startTime = Date.now(); + + logger.info('invoked', { + hasActivationCode: !!body.activationCode, + hasCookie: !!body.cookie, + hasAccessToken: !!body.accessToken, + }); + // 输入验证 validateInput(autoActivateSchema, body); @@ -25,6 +34,11 @@ exports.handler = withAuth(async (event, context, { auth, body }) => { // 调用Giffgaff激活API const result = await callGiffgaffActivationAPI(activationCode, cookie, accessToken); + logger.info('activation_result', { + success: result.success, + duration: Date.now() - startTime, + }); + if (result.success) { return { statusCode: 200, diff --git a/netlify/functions/giffgaff-graphql.js b/netlify/functions/giffgaff-graphql.js index 2288d51..7f143bd 100644 --- a/netlify/functions/giffgaff-graphql.js +++ b/netlify/functions/giffgaff-graphql.js @@ -21,9 +21,14 @@ const graphqlSchema = { } }; -exports.handler = withAuth(async (event, context, { auth, body }) => { - const ts = new Date().toISOString(); - console.log(`[GGQL] ${ts} | invoked, operationName=${body.operationName || 'none'}, hasAccessToken=${!!body.accessToken}, hasMfaSignature=${!!body.mfaSignature}, hasCookie=${!!body.cookie}`); +exports.handler = withAuth(async (event, ctx, { auth, body }) => { + const logger = ctx.logger; + logger.info('invoked', { + operationName: body.operationName || 'none', + hasAccessToken: !!body.accessToken, + hasMfaSignature: !!body.mfaSignature, + hasCookie: !!body.cookie, + }); // 解析请求体 const { mfaSignature, mfaRef, query, variables, operationName, cookie } = body; @@ -130,7 +135,12 @@ exports.handler = withAuth(async (event, context, { auth, body }) => { const verifyCookieUrl = hostHdr ? `${protoHdr}://${hostHdr}/.netlify/functions/verify-cookie` : ((process.env.URL || '').replace(/\/$/, '') + '/.netlify/functions/verify-cookie'); // 调用Giffgaff GraphQL API - console.log(`[GGQL] ${ts} | calling upstream: op=${opName}, isSwap=${isSwap}, hasMfaSignature=${!!mfaSignature}, hasResolvedMfaRef=${!!resolvedMfaRef}`); + logger.info('calling_upstream', { + operationName: opName, + isSwap, + hasMfaSignature: !!mfaSignature, + hasResolvedMfaRef: !!resolvedMfaRef, + }); // swapSim 操作在遇到上游 500 错误时自动重试（最多 2 次） const maxRetries = isSwap ? 2 : 0; @@ -139,7 +149,7 @@ exports.handler = withAuth(async (event, context, { auth, body }) => { for (let attempt = 0; attempt <= maxRetries; attempt++) { if (attempt > 0) { const delayMs = attempt * 1500; - console.log(`[GGQL] ${ts} | retry #${attempt} for ${opName} after ${delayMs}ms`); + logger.info('retry_attempt', { attempt, operationName: opName, delayMs }); await new Promise(r => setTimeout(r, delayMs)); } @@ -149,18 +159,22 @@ exports.handler = withAuth(async (event, context, { auth, body }) => { graphqlBody, { headers: requestHeaders, timeout: 30000 } ); - console.log(`[GGQL] ${ts} | upstream OK: status=${response.status}, hasData=${!!response.data}, hasErrors=${!!response.data?.errors}`); + logger.info('upstream_ok', { + status: response.status, + hasData: !!response.data, + hasErrors: !!response.data?.errors, + }); // Giffgaff 返回 HTTP 200 但 GraphQL body 包含 errors 时，视为业务失败 if (response.data?.errors?.length > 0) { const gqlErr = response.data.errors[0]; const gqlMsg = gqlErr?.message || gqlErr?.error || JSON.stringify(gqlErr); - console.error(`[GGQL] ${ts} | GraphQL errors from upstream: ${gqlMsg}`); + logger.error('upstream_graphql_errors', { errorMessage: gqlMsg }); // 区分上游服务器错误（500）和业务校验错误 const isUpstream500 = /500|internal.?server.?error/i.test(gqlMsg); if (isUpstream500 && attempt < maxRetries) { - console.warn(`[GGQL] ${ts} | upstream 500 on attempt #${attempt}, will retry`); + logger.warn('upstream_500_retry', { attempt, operationName: opName }); continue; // 重试 } @@ -177,11 +191,11 @@ exports.handler = withAuth(async (event, context, { auth, body }) => { const status = err.response?.status; const data = err.response?.data || {}; const isUnauthorized = status === 401 || data?.error === 'unauthorized' || /invalid_token/i.test(String(data?.error || '')); - console.error(`[GGQL] ${ts} | upstream FAILED: status=${status}, isUnauthorized=${isUnauthorized}, errMsg=${err.message}`); + logger.error('upstream_failed', { status, isUnauthorized, errorMessage: err.message }); // 失败 401 时尝试用 cookie 刷新后重试一次 if (isUnauthorized && cookie) { - console.log(`[GGQL] ${ts} | attempting cookie-based token refresh`); + logger.info('attempting_token_refresh'); try { const r = await axios.post(verifyCookieUrl, { cookie }, { headers: getInternalHeaders(), @@ -191,20 +205,20 @@ exports.handler = withAuth(async (event, context, { auth, body }) => { if (r.data?.valid && r.data?.accessToken) { accessToken = r.data.accessToken; requestHeaders['Authorization'] = `Bearer ${accessToken}`; - console.log(`[GGQL] ${ts} | token refreshed, retrying upstream call`); + logger.info('token_refreshed'); response = await axios.post( 'https://publicapi.giffgaff.com/gateway/graphql', graphqlBody, { headers: requestHeaders, timeout: 30000 } ); - console.log(`[GGQL] ${ts} | retry OK: status=${response.status}`); + logger.info('retry_ok', { status: response.status }); break; // 重试成功，跳出循环 } else { - console.error(`[GGQL] ${ts} | cookie refresh failed: valid=${r.data?.valid}`); + logger.error('cookie_refresh_failed', { valid: r.data?.valid }); throw err; } } catch (reErr) { - console.error(`[GGQL] ${ts} | token refresh/retry FAILED: ${reErr.message}`); + logger.error('token_refresh_retry_failed', { errorMessage: reErr.message }); throw new AuthError('Access token expired. Please re-login with cookie.', 401); } } else { diff --git a/netlify/functions/giffgaff-mfa-challenge.js b/netlify/functions/giffgaff-mfa-challenge.js index 70f5fa0..4ab047a 100644 --- a/netlify/functions/giffgaff-mfa-challenge.js +++ b/netlify/functions/giffgaff-mfa-challenge.js @@ -20,9 +20,16 @@ const mfaChallengeSchema = { } }; -exports.handler = withAuth(async (event, context, { auth, body }) => { +exports.handler = withAuth(async (event, ctx, { auth, body }) => { + const logger = ctx.logger; const { source = "esim", preferredChannels = ["EMAIL"], cookie } = body; + logger.info('invoked', { + source, + preferredChannels: Array.isArray(preferredChannels) ? preferredChannels.join(',') : 'unknown', + hasCookie: !!cookie, + }); + // 从请求体或 Authorization 头提取 accessToken（兼容两种方式） const lowerCaseHeaders = Object.fromEntries( Object.entries(event.headers || {}).map(([k, v]) => [String(k).toLowerCase(), v]) @@ -154,6 +161,7 @@ exports.handler = withAuth(async (event, context, { auth, body }) => { ); let response; + const challengeStartTime = Date.now(); try { // 优先走 Cookie 的 Web 通道 if (mergedCookie) { @@ -200,6 +208,12 @@ exports.handler = withAuth(async (event, context, { auth, body }) => { } } + logger.info('challenge_sent', { + status: response?.status, + method: mergedCookie ? 'v3_cookie' : 'v4_token', + duration: Date.now() - challengeStartTime, + }); + return { statusCode: 200, body: JSON.stringify(response.data) diff --git a/netlify/functions/giffgaff-mfa-validation.js b/netlify/functions/giffgaff-mfa-validation.js index f15d732..dc8a1e6 100644 --- a/netlify/functions/giffgaff-mfa-validation.js +++ b/netlify/functions/giffgaff-mfa-validation.js @@ -22,7 +22,15 @@ const mfaValidationSchema = { } }; -exports.handler = withAuth(async (event, context, { auth, body }) => { +exports.handler = withAuth(async (event, ctx, { auth, body }) => { + const logger = ctx.logger; + + logger.info('invoked', { + hasRef: !!body.ref, + hasCode: !!body.code, + hasCookie: !!body.cookie, + }); + // 输入验证 validateInput(mfaValidationSchema, body); @@ -127,6 +135,10 @@ exports.handler = withAuth(async (event, context, { auth, body }) => { } } + logger.info('validation_ok', { + hasSignature: !!response?.data?.signature, + }); + return { statusCode: 200, body: JSON.stringify(response.data) diff --git a/netlify/functions/giffgaff-sms-activate.js b/netlify/functions/giffgaff-sms-activate.js index d9ecaa5..87c2a1a 100644 --- a/netlify/functions/giffgaff-sms-activate.js +++ b/netlify/functions/giffgaff-sms-activate.js @@ -21,7 +21,19 @@ const smsActivateSchema = { } }; -exports.handler = withAuth(async (event, context, { auth, body }) => { +exports.handler = withAuth(async (event, ctx, { auth, body }) => { + const logger = ctx.logger; + const startTime = Date.now(); + + logger.info('invoked', { + hasRef: !!body.ref, + hasAccessToken: !!body.accessToken, + hasCookie: !!body.cookie, + hasMemberId: !!body.memberId, + hasSsn: !!body.ssn, + hasActivationCode: !!body.activationCode, + }); + // 输入验证 validateInput(smsActivateSchema, body); @@ -35,12 +47,6 @@ exports.handler = withAuth(async (event, context, { auth, body }) => { activationCode } = body; - // 站点URL用于内部调用其他函数 - const lower = Object.fromEntries(Object.entries(event.headers || {}).map(([k, v]) => [String(k).toLowerCase(), v])); - const host = lower['x-forwarded-host'] || lower['host'] || ''; - const proto = lower['x-forwarded-proto'] || 'https'; - const baseUrl = host ? `${proto}://${host}` : String(process.env.URL || '').replace(/\/$/, ''); - // 统一创建 GraphQL 客户端 const createGraphql = (token, extraHeaders = {}) => (body) => axios.post( 'https://publicapi.giffgaff.com/gateway/graphql', @@ -146,9 +152,12 @@ exports.handler = withAuth(async (event, context, { auth, body }) => { const mfaSignature = validationResp.data?.signature; if (!mfaSignature) { + logger.error('mfa_signature_missing'); throw new AuthError('未获取到MFA签名', 500); } + logger.info('mfa_validation_ok', { hasMfaSignature: !!mfaSignature }); + // 3) 若无 ssn/activationCode,则获取 memberId → 预订 eSIM let currentMemberId = memberId || null; let currentSSN = ssn || null; @@ -183,6 +192,8 @@ exports.handler = withAuth(async (event, context, { auth, body }) => { } currentSSN = reservation.esim.ssn; currentActivationCode = reservation.esim.activationCode; + + logger.info('esim_reserved', { hasSsn: !!currentSSN, hasActivationCode: !!currentActivationCode }); } // 4) 执行 swapSim @@ -206,8 +217,10 @@ exports.handler = withAuth(async (event, context, { auth, body }) => { if (sw?.new?.ssn) { currentSSN = sw.new.ssn; currentActivationCode = sw.new.activationCode || currentActivationCode; + logger.info('swap_completed', { hasNewSsn: !!sw.new.ssn }); } } catch (e) { + logger.warn('swap_failed_continuing_poll', { errorMessage: e.message }); // 允许继续轮询 } @@ -225,6 +238,7 @@ exports.handler = withAuth(async (event, context, { auth, body }) => { const r = await gql(downloadQuery); lastData = r.data?.data?.eSimDownloadToken || null; if (lastData?.lpaString) { + logger.info('lpa_obtained', { duration: Date.now() - startTime }); return { statusCode: 200, body: JSON.stringify({ @@ -242,6 +256,8 @@ exports.handler = withAuth(async (event, context, { auth, body }) => { await new Promise(r => setTimeout(r, 4000)); } + logger.warn('lpa_poll_timeout', { duration: Date.now() - startTime }); + return { statusCode: 202, body: JSON.stringify({ diff --git a/netlify/functions/giffgaff-token-exchange.js b/netlify/functions/giffgaff-token-exchange.js index 33476d4..58cfc4a 100644 --- a/netlify/functions/giffgaff-token-exchange.js +++ b/netlify/functions/giffgaff-token-exchange.js @@ -49,7 +49,14 @@ const tokenExchangeSchema = { } }; -exports.handler = withAuth(async (event, context, { auth, body }) => { +exports.handler = withAuth(async (event, ctx, { auth, body }) => { + const logger = ctx.logger; + + logger.info('invoked', { + hasCode: !!body.code, + hasCodeVerifier: !!body.code_verifier, + }); + // 输入验证 validateInput(tokenExchangeSchema, body); @@ -61,6 +68,8 @@ exports.handler = withAuth(async (event, context, { auth, body }) => { const tokenUrl = process.env.GIFFGAFF_TOKEN_URL || 'https://id.giffgaff.com/auth/oauth/token'; const defaultRedirectUri = process.env.GIFFGAFF_REDIRECT_URI || 'giffgaff://auth/callback/'; + logger.info('exchanging_token'); + // 构建 Basic Auth header（不再自动修复密钥） const authHeader = Buffer.from(`${clientId}:${clientSecret}`).toString('base64'); @@ -81,6 +90,12 @@ exports.handler = withAuth(async (event, context, { auth, body }) => { timeout: 30000 }); + logger.info('token_exchange_ok', { + hasAccessToken: !!response.data?.access_token, + hasRefreshToken: !!response.data?.refresh_token, + expiresIn: response.data?.expires_in, + }); + return { statusCode: 200, body: JSON.stringify(response.data) diff --git a/netlify/functions/health.js b/netlify/functions/health.js index 32fc293..cd970f4 100644 --- a/netlify/functions/health.js +++ b/netlify/functions/health.js @@ -43,9 +43,18 @@ function checkEnvStatus() { } const handler = async (event, context, { auth }) => { + const logger = context.logger; + // 基础健康信息（公开） const envStatus = checkEnvStatus(); const isHealthy = envStatus.missing === 0; + + logger.info('health_check', { + isHealthy, + configured: envStatus.configured, + missing: envStatus.missing, + }); + const health = { status: isHealthy ? 'healthy' : 'degraded', service: 'eSIM-Tools', diff --git a/netlify/functions/verify-cookie.js b/netlify/functions/verify-cookie.js index 8f8ffcb..958082f 100644 --- a/netlify/functions/verify-cookie.js +++ b/netlify/functions/verify-cookie.js @@ -19,7 +19,12 @@ const verifyCookieSchema = { } }; -exports.handler = withAuth(async (event, context, { auth, body }) => { +exports.handler = withAuth(async (event, ctx, { auth, body }) => { + const logger = ctx.logger; + const startTime = Date.now(); + + logger.info('invoked', { hasCookie: !!body.cookie }); + // 输入验证 validateInput(verifyCookieSchema, body); @@ -41,6 +46,12 @@ exports.handler = withAuth(async (event, context, { auth, body }) => { // success: Cookie 验证请求本身是否成功（HTTP 层面） // valid: Cookie 是否可用于后续 API 调用（需同时拿到可用的 JWT 令牌） // 调用方（前端 & 内部函数）应以 valid 字段作为能否继续的唯一判断依据。 + logger.info('cookie_verify_result', { + success: result.success, + hasAccessToken: !!result.accessToken, + duration: Date.now() - startTime, + }); + if (result.success) { const looksLikeJwt = typeof result.accessToken === 'string' && result.accessToken.includes('.') && diff --git a/tests/functions/middleware-logging.test.js b/tests/functions/middleware-logging.test.js index e4c57ff..dc13bb8 100644 --- a/tests/functions/middleware-logging.test.js +++ b/tests/functions/middleware-logging.test.js @@ -131,14 +131,14 @@ describe('withAuth 日志集成', () => { { httpMethod: 'GET', path: '/a', headers: { origin: 'https://esim.cosr.eu.org' } }, { functionName: 'fn1' } ); - const reqId1 = mockLogs[0]?.ctx?.requestId; + const reqId1 = mockLogs[0]?.reqId; mockLogs.length = 0; await wrapped( { httpMethod: 'GET', path: '/b', headers: { origin: 'https://esim.cosr.eu.org' } }, { functionName: 'fn2' } ); - const reqId2 = mockLogs[0]?.ctx?.requestId; + const reqId2 = mockLogs[0]?.reqId; expect(reqId1).toBeDefined(); expect(reqId2).toBeDefined(); @@ -156,4 +156,97 @@ describe('withAuth 日志集成', () => { expect(createLogger).toHaveBeenCalledWith('my-function', expect.any(String)); }); + + it('CORS 鉴权失败时应该输出 request_error 日志', async () => { + const mockHandler = jest.fn(async () => ({ statusCode: 200, body: '{}' })); + const wrapped = withAuth(mockHandler, { requireAuth: false }); + + await wrapped( + { httpMethod: 'GET', path: '/bff/test', headers: { origin: 'https://evil.com' } }, + { functionName: 'test-fn' } + ); + + const errorLog = mockLogs.find((l) => l.msg === 'request_error'); + expect(errorLog).toBeDefined(); + expect(errorLog.ctx.status).toBe(403); + expect(errorLog.ctx.errorName).toBe('AuthError'); + // handler 不应被调用 + expect(mockHandler).not.toHaveBeenCalled(); + }); + + it('无效 JSON body 时应该输出 request_error 日志', async () => { + const mockHandler = jest.fn(async () => ({ statusCode: 200, body: '{}' })); + const wrapped = withAuth(mockHandler, { requireAuth: false }); + + await wrapped( + { + httpMethod: 'POST', + path: '/bff/test', + headers: { origin: 'https://esim.cosr.eu.org' }, + body: 'not-valid-json{{{', + }, + { functionName: 'test-fn' } + ); + + const errorLog = mockLogs.find((l) => l.msg === 'request_error'); + expect(errorLog).toBeDefined(); + expect(errorLog.ctx.status).toBe(400); + expect(errorLog.ctx.errorMessage).toBe('Invalid JSON body'); + expect(mockHandler).not.toHaveBeenCalled(); + }); + + it('输入验证失败时应该输出 request_error 日志', async () => { + const mockHandler = jest.fn(async () => ({ statusCode: 200, body: '{}' })); + const schema = { name: { required: true, type: 'string' } }; + const wrapped = withAuth(mockHandler, { requireAuth: false, validateSchema: schema }); + + await wrapped( + { + httpMethod: 'POST', + path: '/bff/test', + headers: { origin: 'https://esim.cosr.eu.org' }, + body: JSON.stringify({}), + }, + { functionName: 'test-fn' } + ); + + const errorLog = mockLogs.find((l) => l.msg === 'request_error'); + expect(errorLog).toBeDefined(); + expect(errorLog.ctx.status).toBe(400); + expect(errorLog.ctx.errorMessage).toMatch(/name is required/); + expect(mockHandler).not.toHaveBeenCalled(); + }); + + it('error 日志应包含耗时字段', async () => { + const mockHandler = jest.fn(async () => { + throw new Error('slow fail'); + }); + const wrapped = withAuth(mockHandler, { requireAuth: false }); + + await wrapped( + { httpMethod: 'GET', path: '/bff/test', headers: { origin: 'https://esim.cosr.eu.org' } }, + { functionName: 'test-fn' } + ); + + const errorLog = mockLogs.find((l) => l.msg === 'request_error'); + expect(errorLog.ctx.duration).toBeDefined(); + expect(typeof errorLog.ctx.duration).toBe('number'); + expect(errorLog.ctx.duration).toBeGreaterThanOrEqual(0); + }); + + it('OPTIONS 预检请求不输出 request_start 日志（提前返回）', async () => { + const mockHandler = jest.fn(async () => ({ statusCode: 200, body: '{}' })); + const wrapped = withAuth(mockHandler, { requireAuth: false }); + + await wrapped( + { httpMethod: 'OPTIONS', path: '/bff/test', headers: { origin: 'https://esim.cosr.eu.org' } }, + { functionName: 'test-fn' } + ); + + // request_start 仍然会输出（在鉴权之前），但 request_end 不会（预检提前返回） + const startLog = mockLogs.find((l) => l.msg === 'request_start'); + expect(startLog).toBeDefined(); + // handler 不应被调用 + expect(mockHandler).not.toHaveBeenCalled(); + }); }); diff --git a/tests/modules/server-logger.test.js b/tests/modules/server-logger.test.js index 12f7e2a..b4af4f7 100644 --- a/tests/modules/server-logger.test.js +++ b/tests/modules/server-logger.test.js @@ -51,6 +51,25 @@ describe('server-logger', () => { expect(output.duration).toBe(42); }); + it('context 为 null 或 undefined 时不应报错', () => { + const logger = createLogger('test-fn', 'req-1'); + expect(() => logger.info('msg', null)).not.toThrow(); + expect(() => logger.info('msg', undefined)).not.toThrow(); + expect(() => logger.warn('msg', null)).not.toThrow(); + expect(() => logger.error('msg', null)).not.toThrow(); + const output = JSON.parse(consoleSpy.log.mock.calls[0][0]); + expect(output.message).toBe('msg'); + expect(output.requestId).toBe('req-1'); + }); + + it('context 中同名字段应覆盖基础字段（Object.assign 语义）', () => { + const logger = createLogger('test-fn', 'req-1'); + logger.info('override test', { message: 'overridden' }); + const output = JSON.parse(consoleSpy.log.mock.calls[0][0]); + // Object.assign 后 context 中的 message 覆盖基础字段 + expect(output.message).toBe('overridden'); + }); + it('warn 应该输出到 console.warn', () => { const logger = createLogger('test-fn', 'req-1'); logger.warn('warning msg'); @@ -88,6 +107,50 @@ describe('server-logger', () => { if (originalLevel) process.env.LOG_LEVEL = originalLevel; else delete process.env.LOG_LEVEL; }); + + it('LOG_LEVEL=ERROR 时应该抑制 INFO 和 WARN', () => { + const originalLevel = process.env.LOG_LEVEL; + process.env.LOG_LEVEL = 'ERROR'; + const logger = createLogger('test-fn', 'req-1'); + logger.info('should not appear'); + logger.warn('should not appear'); + expect(consoleSpy.log).not.toHaveBeenCalled(); + expect(consoleSpy.warn).not.toHaveBeenCalled(); + // ERROR 仍然输出 + logger.error('should appear'); + expect(consoleSpy.error).toHaveBeenCalledTimes(1); + if (originalLevel) process.env.LOG_LEVEL = originalLevel; + else delete process.env.LOG_LEVEL; + }); + + it('LOG_LEVEL=WARN 时应该抑制 INFO 和 DEBUG', () => { + const originalLevel = process.env.LOG_LEVEL; + process.env.LOG_LEVEL = 'WARN'; + const logger = createLogger('test-fn', 'req-1'); + logger.info('should not appear'); + logger.debug('should not appear'); + expect(consoleSpy.log).not.toHaveBeenCalled(); + // WARN 和 ERROR 仍然输出 + logger.warn('should appear'); + logger.error('should appear'); + expect(consoleSpy.warn).toHaveBeenCalledTimes(1); + expect(consoleSpy.error).toHaveBeenCalledTimes(1); + if (originalLevel) process.env.LOG_LEVEL = originalLevel; + else delete process.env.LOG_LEVEL; + }); + + it('多个 logger 实例应该互不干扰', () => { + const logger1 = createLogger('fn-a', 'req-1'); + const logger2 = createLogger('fn-b', 'req-2'); + logger1.info('from a'); + logger2.info('from b'); + const out1 = JSON.parse(consoleSpy.log.mock.calls[0][0]); + const out2 = JSON.parse(consoleSpy.log.mock.calls[1][0]); + expect(out1.function).toBe('fn-a'); + expect(out1.requestId).toBe('req-1'); + expect(out2.function).toBe('fn-b'); + expect(out2.requestId).toBe('req-2'); + }); }); describe('parseLogLevel', () => {