mirror of
https://github.com/Silentely/eSIM-Tools.git
synced 2026-09-03 06:24:20 +08:00
✨ feat: 添加结构化日志支持并优化错误处理
- 在 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 预检处理等测试场景
This commit is contained in:
@@ -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));
|
||||
|
||||
@@ -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: {
|
||||
|
||||
@@ -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;
|
||||
|
||||
@@ -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));
|
||||
}
|
||||
|
||||
@@ -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,
|
||||
|
||||
@@ -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 {
|
||||
|
||||
@@ -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)
|
||||
|
||||
@@ -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)
|
||||
|
||||
@@ -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({
|
||||
|
||||
@@ -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)
|
||||
|
||||
@@ -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',
|
||||
|
||||
@@ -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('.') &&
|
||||
|
||||
@@ -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();
|
||||
});
|
||||
});
|
||||
|
||||
@@ -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', () => {
|
||||
|
||||
Reference in New Issue
Block a user